Debugging Tips

[previous] [next] [table of contents] [index]

NOTE: for users of the online version of this book: This section has a long example followed by long explanation. To avoid jumping between the example and its explanation, it's a good idea to open a new browser window to show an example. (Check your browser's menu for a command like New Web Browser or Open in New Window). Then, use the original browser to read the explanation while you view the example in the second browser window.

If your mail-handling setup doesn't seem to work, read these sections.

The first thing to do is to look through the instructions for setting up your .maildelivery file (Sections The .maildelivery File: Overview and The .maildelivery File in Detail) and executing it (the Section Running Your .maildelivery File). Look for:

Missing arguments.
Extra or missing double quotes (").
Double quotes that should be escaped (\").
Spaces or commas that should be inside double quotes.

Display or print a few messages. Follow them through .maildelivery in your mind. Make sure you understand what conditions each message should match and how each condition is related to others. The Section slocal Documentation vs. Real Life can help here; it has more about the way that slocal reads your .maildelivery file.

The debugging in slocal is pretty lousy. A lot can go wrong that the debugging won't tell you about; for example, slocal can silently skip an error without printing anything (the Section Even -debug Doesn't Show Syntax Errors explains that). There are some helpful debugging tips here.

NOTE: Many of these sections below apply to the slocal program that runs your .maildelivery file on many systems. If your system doesn't use slocal, the tips in the Section Most Environment Variables Hidden should still be helpful -- others may help, too.

slocal Documentation vs. Real Life

If you're having trouble with your .maildelivery file, try comparing it to the list below. It tells what slocal does, step by step, as it reads an entry in .maildelivery. If that doesn't help, look at the source code yourself or call a guru. The usr_delivery() function parses the entries in .maildelivery.

First, when slocal reads a .maildelivery entry, it checks a list of conditions that make it skip the entry. The entry will be skipped if:

It's a comment or it has less than five arguments.
It has an N result and the previous entry with a field other than * (asterisk) did not match.
It has a ? result and the message has been delivered by any previous entry.
It has the undocumented select arguments 6-8 and these tell slocal to skip the message.
It has a default field (first argument) and some previous entry has delivered the message.
It has a field (first argument) with a message header named (but not an *, asterisk) -- and no header in the message matches that field.
It has an invalid action argument.

If the message isn't skipped by any of the tests in the list above, slocal will try to perform the action. The message will be marked "delivered" if the action succeeds, unless the result was R.

Catching slocal Errors

When you run a program from your terminal -- usually by typing its name at a shell prompt -- the process has a "controlling tty": your terminal. The standard input, standard output, and standard error of the process usually come to your terminal unless they're redirected.

When sendmail runs a program like slocal, the process doesn't have a controlling tty. (That is, the TTY column in the ps output has a ? character.) Errors won't come to your terminal.

To see errors from slocal, you can run it by hand. Or, if you can't reproduce the errors running slocal by hand, grab the stdout and stderr before they're "thrown away." The following two sections show how.

Even with those tips, you still won't see any output from the individual programs in .maildelivery. The Section slocal Eats .maildelivery Errors shows how to handle that.

Running slocal by Hand

The Example Sample slocal -debug -verbose output, in the next section, shows a long chunk of slocal debugging output. It's made automatically, by a setup in the .forward file, for every new message that comes in.

For most .maildelivery debugging, that's more than you need. You want to send a test message through the .maildelivery file and watch what happens. The next Example, Running slocal -verbose interactively, shows the steps. To do that, first store a test message in a file. If you use mhl to show your messages, give -noshowproc to bypass mhl when you store the message. You can edit the test message if you want to change some address in the header (or any other part of the header). Then, run slocal with its -verbose switch; give the message to slocal's standard input:

Example: Running slocal -verbose interactively

% show -noshowproc > testmsg
% vi testmsg
% /usr/local/lib/mh/slocal -verbose -user jerry < testmsg
    delivering to pipe "/usr/local/lib/mh/rcvstore +DELETE", wins.
    delivering to pipe "/usr/local/lib/mh/rcvtty"
17:43:   307 Jerry Peek      testing slocal<<test test
, wins.
    delivering to file "/usr/spool/mail/jerry"
slocal: /usr/spool/mail/.jerry.map:
pointer mismatch or incomplete index (67054!=1920524), continuing...
, done.

That example is choppy -- the output was broken up by the line from rcvtty and the error message near the end. The -verbose switch prints the lines that start with delivering to .... If I'd used -debug, I'd have seen slocal parse the message and the .maildelivery file (the Example Sample slocal -debug -verbose output shows that).

First, slocal delivers a copy of the message to my backup DELETE directory (I use it for debugging). As slocal starts the program, you can see the pause until ,wins. is printed to show that the program returned a zero ("true") exit status. Next, slocal runs rcvtty; you can see the rcvtty.format output on my screen before slocal prints the verbose ,wins.. Finally, slocal tried to deliver to my system mailbox. I saw what I needed: an error from slocal, caused by a bug in MH 6.7.2. (When the MH 6.7.2 slocal appends to a system maildrop in UUCP format, with the [RPATHS] configuration option, it can fail once in a while. Then it defaults to the MMDF format. It also leaves a file named .yourname.map in the /usr/spool/mail directory.) Because of the error, slocal delivered the message another way (see the footnote); it printed ,done. when it had delivered the message to the file.

Save slocal Debugging Output with Real Messages

When you run slocal and a .maildelivery file, it can be hard to see what's happening if something goes wrong in "real time" as a message is being delivered. If an individual command in your .maildelivery file prints error (or other) messages, you won't see them because slocal throws away that output. It's especially important to see "real time" output for errors that happen intermittently, that you can't reproduce by hand -- like the error at the end of the Example Running slocal -verbose interactively, errors when the filesystem fills up, and so on.

Here are some tricks with the Bourne shell to work around those problems. The basic idea: instead of running slocal, rcvstore, and other programs directly, run a Bourne shell. Have the shell execute slocal or whatever program you want to debug. Use the shell command exec 2>>logfile to make the shell append its standard error to a log file. To see the program's output, read the log file. I'll start with an example using slocal.

The usual way to start slocal, with debugging, is by a line like this in your .forward file:

"| /x/y/slocal -debug -verbose -user jerry"

Instead, use a line like the one below.

"| /bin/sh -c 'exec >>/tmp/sllog.jerry 2>&1; /x/y/slocal -debug -verbose -user jerry'"

That appends the standard output and standard error from slocal into the file /tmp/sllog.jerry. (/tmp is a system temporary-file directory. /tmp is a good place for files like these because it's world-writable, also because files in /tmp are usually erased periodically and during reboots.)

The next Example, Sample slocal -debug -verbose output, shows the contents of my sllog.jerry file after I got a message from a friend in Germany. First, here's the .maildelivery file I was using:

# toss anything from uucp (save for a few days, in case):
From     uucp  |  A   "/usr/local/lib/mh/rcvstore +DELETE"
# put other stuff into mailbox
default  -     >  ?   /usr/spool/mail/jerry
# always run rcvtty
*        -     |  R   "/usr/local/lib/mh/rcvtty -nobell"

And the header of the message I got:

From martinek@agpsa.de  Sun Jun 28 18:32:31 1992
Delivery-Date: Sun, 28 Jun 92 10:47:00 -0400
Return-Path: <martinek@agpsa.de>
Received: from mail.Germany.EU.net by ora.com (5.65c/Spike-2.1)
    id AA08683; Sun, 28 Jun 1992 10:46:52 -0400
Received: from apgwdf
    by mail.Germany.EU.net with UUCP (5.65+/UNIDO-2.1.0.b)
    via EUnet for ora.com
    id AA08647; Sun, 28 Jun 92 16:48:00 +0200
Received: from is0001 by agpsa.de (5.52.1/APG-1.1)
    id AA21195; Sun, 28 Jun 92 15:26:58  +0100
    for ora.com!jerry
Received: from localhost by is0001 (AIX 3.1/UCB 5.61/4.03)
	  id AA56358; Sun, 28 Jun 92 16:32:32 +0200
      for jpeek@jpeek.com
Message-Id: <9206281432.AA56358@is0001>
To: Jerry Peek <jpeek@jpeek.com>
Phone: +49 6239-000000  Home: +49 6241-000000
Subject: Re: your book
In-Reply-To: Jerry Peek's message of Fri, 26 Jun 92 14:42:35 -0400
	     <13386.709584155@babble.ora.com>
Reply-To: Hans Martinek <martinek@agpsa.de>
Date: Sun, 28 Jun 92 16:32:31 +0200
From: Hans Martinek <martinek@agpsa.de>

Example: Sample slocal -debug -verbose output

 1> temporary file "/tmp/slocala08688" selected
 2> addr="jerry" user="jerry" info="" file="/tmp/slocala08688"
 3> sender="martinek@agpsa.de" mbox="/usr/spool/mail/jerry" home="/home/jerry" from="From martinek@agpsa.de  Sun Jun 28 18:32:31 1992
 4> "
 5> ddate="Delivery-Date: Sun, 28 Jun 92 10:47:00 -0400
 6> " now=10:47
 7> vec[0]: "From"
 8> vec[1]: "uucp"
 9> vec[2]: "|"
10> vec[3]: "A"
11> vec[4]: "/usr/local/lib/mh/rcvstore +DELETE"
12> vars[3]: name="reply-to" value=" Hans Martinek <martinek@agpsa.de>
13> "
14> hdrs[0]: name="source" value="martinek@agpsa.de"
15> hdrs[1]: name="addr" value="jerry"
16> hdrs[2]: name="Return-Path" value=" <martinek@agpsa.de>
17> "
18> hdrs[3]: name="Reply-To" value=" Hans Martinek <martinek@agpsa.de>
19> "
20> hdrs[4]: name="From" value=" Hans Martinek <martinek@agpsa.de>
21> "
22> hdrs[5]: name="Sender" value="(null)"
23> hdrs[6]: name="To" value=" Jerry Peek <jpeek@jpeek.com>
24> "
25> hdrs[7]: name="cc" value="(null)"
26> hdrs[8]: name="Resent-Reply-To" value="(null)"
27> hdrs[9]: name="Resent-From" value="(null)"
28> hdrs[10]: name="Resent-Sender" value="(null)"
29> hdrs[11]: name="Resent-To" value="(null)"
30> hdrs[12]: name="Resent-cc" value="(null)"
31> hdrs[13]: name="Received" value=" from mail.Germany.EU.net by ora.com (5.65c/Spike-2.1)
32>     id AA08683; Sun, 28 Jun 1992 10:46:52 -0400
33>      from apgwdf
34>     by mail.Germany.EU.net with UUCP (5.65+/UNIDO-2.1.0.b)
35>     via EUnet for ora.com
36>     id AA08647; Sun, 28 Jun 92 16:48:00 +0200
37>      from is0001 by agpsa.de (5.52.1/APG-1.1)
38>     id AA21195; Sun, 28 Jun 92 15:26:58  +0100
39>     for ora.com!jerry
40>      from localhost by is0001 (AIX 3.1/UCB 5.61/4.03)
41>           id AA56358; Sun, 28 Jun 92 16:32:32 +0200
42>       for jpeek@jpeek.com
43> "
44> hdrs[14]: name="Message-Id" value=" <9206281432.AA56358@is0001>
45> "
46> hdrs[15]: name="Phone" value=" +49 6239-000000  Home: +49 6241-000000
47> "
48> hdrs[16]: name="Subject" value=" Re: your book
49> "
50> hdrs[17]: name="In-Reply-To" value=" Jerry Peek's message of Fri, 26 Jun 92 14:42:35 -0400
51>              <13386.709584155@babble.ora.com>
52> "
53> hdrs[18]: name="Date" value=" Sun, 28 Jun 92 16:32:31 +0200
54> "
55> vec[0]: "default"
56> vec[1]: "-"
57> vec[2]: ">"
58> vec[3]: "?"
59> vec[4]: "/usr/spool/mail/jerry"
60>     delivering to file "/usr/spool/mail/jerry" (uucp style), done.
61> vec[0]: "*"
62> vec[1]: "-"
63> vec[2]: "|"
64> vec[3]: "R"
65> vec[4]: "/usr/local/lib/mh/rcvtty -nobell"
66> vars[0]: name="sender" value="martinek@agpsa.de"
67> vars[1]: name="address" value="jerry"
68> vars[2]: name="size" value="1235"
69> vars[3]: name="reply-to" value=" Hans Martinek <martinek@agpsa.de>
70> "
71> vars[4]: name="info" value=""
72>     delivering to pipe "/usr/local/lib/mh/rcvtty -nobell", wins.

Line 1 shows the name of the temporary file where slocal stores the message it's processing.

Lines 2-6 list some internal variables:

ddate= shows the header field that slocal will add if the message is dropped into a file with the file or > action.
now= is the time used by the undocumented select argument.

Line 5 is an example of a variable holding a line of characters that ends with a newline. The closing double quote mark will be on the following line (here, line 6).

In line 7, slocal is starting to read and parse the .maildelivery entries. If you compare lines 7-11 of the debugging output to the first uncommented entry of the .maildelivery file above it, you can see that the five arguments in the entry have been split into the array members vec[0] through vec[4]. The first vec array member, vec[0], always holds the field argument, vec[1] always holds the pattern argument, and so on.

Lines similar to lines 12-54 will be printed the first time slocal calls its internal parse() function. That reads the message and splits out the header. You can use these header field names (shown as name= in the debugging output) as the field argument on .maildelivery entries. The pattern argument in .maildelivery entries is compared to the value= here.

First slocal shows the setting of the $(reply-to) variable (line 12). It contains the Reply-to: address if the message had one; otherwise it has the From: address. (This message has both, and they're both the same.)
Then slocal reads all other header fields in the message and assigns each to its own hdrs[] array member.
There are some fields slocal always looks for; these are hdrs[0] through hdrs[12] (shown in lines 14-30). Notice that the message doesn't always have all of those fields; missing ones are shown with value="(null)".
The rest of the fields in the header go into more hdrs[] array members, as many as it takes. The information from all header fields with the same name all go into the same array member. In this case, it takes all of lines 31-43 to show all of the Received: information in the message. A .maildelivery file can match any part of this. For example, if you needed to catch mail that had been relayed through the host Germany.EU.net (see line 34), this .maildelivery entry would do it:
```
received   germany.eu.net  ...
```

The message didn't match the first entry in my .maildelivery file because it isn't from uucp. So, slocal checks the next .maildelivery entry; lines 55-59 show the five arguments on it.

It matches, so the action is performed; line 60 shows that. By the way, this is the first line that we'd have seen if I'd only used the slocal -verbose option!

Lines 66-72 show the last entry of the .maildelivery file being parsed and the pipe executed. In case you didn't notice, successful pipe actions "win" but deliveries to files (like line 60) are just "done".

Even -debug Doesn't Show Syntax Errors

The slocal -debug switch will show some problems. There are other problems that -debug won't tell you about. For example, if a .maildelivery entry has less than five arguments, it's skipped silently. If you have the MH source tree on your computer and you can read C programs, take a look at the uip/slocal.c file. Search for the expression if (debug) to see the places that debugging messages are printed. In the usr_delivery() function, look at the continue and return NOTOK statements that silently skip .maildelivery entries.

Choosing the lines that debug prints was a design decision. As it is, debug can give you an overwhelming amount of information. If you're having debugging trouble, though, you might recompile your your slocal code with more of if (debug) and fprintf (stderr ...).

slocal Eats .maildelivery Errors

When slocal runs .maildelivery, it throws away error messages from the commands run by pipe, |, qpipe, and ^ actions. Here's a trick that should help you see the errors. slocal runs the pipe action with a Bourne shell. You can set that shell's debugging options with set -xv. Also, redirect the shell's stdout and stderr to a file in your home directory with a command like:

exec >/home/jerry/rcvstore.debug 2>&1

What I mean is: change the entry in your .maildelivery file to something like the one below:

to    gripe  |  R  "set -xv; exec >/home/jerry/rcvstore.debug 2>&1; /usr/local/lib/mh/rvcstore +gripes"

Send a message and look at the debugging file. The shell shows a plus sign (+) before every command it runs:

% cat rcvstore.debug
+ /usr/local/lib/mh/rvcstore +gripes
sh: /usr/local/lib/mh/rvcstore: not found

Oh! I typed rvcstore instead of rcvstore...

Most Environment Variables Hidden

Programs in .maildelivery are run in a different environment, not from your login shell. Environment variables, aliases, shell functions, and other things set in your .cshrc, .login or .profile files probably won't reach your programs in .maildelivery. For instance, your MH profile file has to be in the standard place, $HOME/.mh_profile, unless you use a trick to reset your MH environment variable. (slocal passes in the system default settings of three environment variables: HOME, SHELL, and USER.)

For example, on my workstation I keep my mail on a separate filesystem named /Mail. But my .maildelivery file is read on a fileserver where /Mail doesn't exist. I have a separate MH profile for the fileserver named .mh_profile.server. But unless I do something, the programs in .maildelivery won't know that.

Here's the trick for running programs from .maildelivery. Don't use the qpipe or ^ action. Instead, use the pipe or | action and give the shell the environment settings it needs. Here's my .maildelivery entry for running rcvtty:

*   -  |  R  "MH=$HOME/.mh_profile.server /x/y/rcvtty"

What's that? In the Bourne shell, which runs when you use the pipe or | action, you can set an environment variable before a command is run. Before starting rcvtty, I set the MH environment variable.

[Table of Contents] [Index] [Previous: Practical Tips] [Next: Chapter Introduction: Introduction to UNIX Programming with MH]

Last change $Date: 1996/06/06 15:09:35 $

This file is from the third edition of the book MH & xmh: Email for Users & Programmers, ISBN 1-56592-093-7, by Jerry Peek. Copyright © 1991, 1992, 1995 by O'Reilly & Associates, Inc. This file is freely-available; you can redistribute it and/or modify it under the terms of the GNU General Public License as published by the Free Software Foundation. For more information, see the file copying.htm.

Suggestions are welcome: Jerry Peek <jpeek@jpeek.com>