Debugging Procmail Recipes: Some Tips

This is just an assortment of ideas for those who are interested in making sure their Procmail recipes work as intended before you put them in your real .procmailrc file.

There are also some thoughts for when you have trouble with getting procmail to run in the first place.

If you find any errors or otherwise wish to comment, please do get in touch!

If you have questions about any of this, hopefully you should find an answer on my other Procmail pages.

Table of Contents

Opening Remarks

All too often, you get bounces from people who put together a quick and dirty Procmail recipe and never got around to verifying that it worked right. (I've been guilty of this myself, a number of times. It's just too easy to forget to test things that are "easy".)

Besides the obvious wish to avoid snafus with your mail -- whether those include embarrassing bounces to the senders or not -- there are a number of additional reasons you might want to play around with Procmail. For one thing, when you can fool around without the risk of losing mail, it's much easier and safer to really try to learn how the program works. Until I got some experience with debugging Procmail recipes, I was too chicken to even try out -- much less learn -- any of the advanced constructs.

An often cited maxim is RTFM. I'd like to coin another principle which I think is just as important: Try It And See What Happens. This is of course not to be construed as "put some crufty hack in your production .procmailrc and see if you lose any mail". :-)

A Framework

First of all, it's probably a good idea to keep a skeletal .procmailrc file around. There's not much you can put in there by default but on the other hand, if you really just want to try something quick and dirty, you'll probably be too lazy to put in the obligatory SHELL=/bin/sh DEFAULT=/tmp/$LOGNAME yada yada and thus end up shooting yourself in the foot one way or another more often than you'd like.

The (not so mini) FAQ comes with a skeletal experiments.rc which should do as a starting point. It's something I cooked up for the FAQ and so I wanted to keep it clean and simple. Needless to say, my own "skeletal" .procmailrc is not exactly clean and simple -- I tend to leave in my old experiments just in case I'd like to pick up on them again later (and thus I end up shooting myself in the foot one way or another more often than I like :-)

Here are some highlights from mine:

	SHELL=/bin/sh           # always always always always always always
	MAILDIR=$HOME/scratch   # this is a symlink to a scratch disk
	DEFAULT=$HOME/scratch/prc.out
	VERBOSE=${VERBOSE:-yeah}
That last one is important; it lets me pass in VERBOSE=no on the command line if I want to override it. This is a useful construct for a lot of things -- actually the LOGFILE setting in my real files follows this convention (so I can debug a module on its own and get logging somewhere else than in my regular procmail.log if I run it with LOGFILE unset. In other words, LOGFILE normally gets set in my top .procmailrc, obviously, and the module will not override it, but if I start up the module on its own, it will redirect logging elsewhere.)

The first line is also important. Procmail's inability to interact with some csh:s and tcsh:s is probably the biggest source of frustrating and "inexplicable" Procmail problems. (It's still not clear to me why this happens, or why Procmail is not compiled by default to always use /bin/sh unless specifically instructed otherwise.)

Examining What's Going On

The most effective debugging tool is still careful thought, coupled with judiciously placed print statements.
-- Brian W. Kernighan, in the paper Unix for Beginners (1979)

Learn to Use the Log

It is useful to be able to see what Procmail is doing at various stages of processing. The fundamental tool for this is the log file, although for interactive tests, it's usually nicer to not set LOGFILE to anything, in which case any logging will be sent to standard error.

Obviously, you will need some familiarity with what goes in the log so you can decode it. The normal LOGABSTRACT fields are explained in the manual, and most of the rest (what you get with VERBOSE logging) should be fairly easy to understand.

Here are some things which are not so self-evident:

Very often, your own little LOG= messages can be the most useful part of the log file. Don't be afraid to log too much -- you never know when you are going to need to see what exactly is going on.

On the other hand, most logging should probably be enabled only when you are debugging. You could of course use LOG={VERBOSE:+"Message"} but I find this cumbersome to type in (and it's probably also a slight waste of resources when you're not debugging) -- I just take care to format my code so that I can enable my diagnostic logging messages with a trivial search-and-replace operation (i.e. always use a particular spacing pattern before the LOG= assignments so I can replace those with #LOG= and vice versa. Commenting and uncommenting like this doesn't work all that trivially if you have multi-line log strings, obviously).

Tangentially, you should also pay attention to your system's log files.

Getting Information About Procmail's Environment

Don't forget that Procmail actually gives you the opportunity to run basically any command on the host where the mail is being processed. That means you can make it e.g. identify itself. Here's one thing that is easy to rig and use:

	:0
        * ^Subject: envdump please$
	{
	    LOG="envdump: uname -a
`uname -a`
envdump: ls -l / /var /var/spool /var/spool/mail /var/spool/mail/$LOGNAME
`ls -l / /var /var/spool /var/spool/mail /var/spool/mail/$LOGNAME`
envdump: ls -l /usr/local/bin/procmail
`ls -l /usr/local/bin/procmail`
envdump: (done)
"
	    :0
	    /dev/null
	}
You should probably use a different Subject: line (otherwise others who have read this page can fool around with your server). Clearly, anything that you are wondering about which can be found out by some sort of Unix command line can be included in this recipe. Output goes to the log file as usual.

Just to make the obvious explicit, you'd trigger this by sending yourself a test message which matches the Subject: regular expression.

Saving Data to a Temporary File

Another useful trick you are going to need is saving the message you're dealing with in a temporary file, so you can examine what was there at some point during Procmail's execution. This is usually no more complicated than

	:0c
	/tmp/tmpdir/.
where /tmp/tmpdir is a directory you have made sure exists and is writable. (You can append to an mbox file, too, of course, or use any other folder format you find convenient. In practice, I end up writing to mbox files most of the time, although having individual messages as separate files in a directory makes some things simpler.)

In more involved cases, tee is your friend. To see what exactly goes into a Sendmail invocation you are having problems with, try something like

	:0
	* conditions, probably (including loop checking)
	| ( whatever ) \
	  | tee /tmp/tmpdir/$$ \
	  | $SENDMAIL $SENDMAILFLAGS
(The expression $$ expands to the process-id of your currently running Procmail. Use tee -a to append to an existing file.)

If you're creating a lot of diagnostic files, it's good form to remember to clean up after yourself. Your system administrator might have set up a partition other than /tmp for your temporary files (on many Unix systems, the /tmp disk is rather small, and/or sacred for the use of the system administration. Many places have a /scratch disk for users' temporary file storage needs. This is usually not backed up, and probably subject to disappear without notice if one of the "real" disks needs to be replaced or something).

Sending Yourself Diagnostic Messages

If you are having trouble with a recipe which sends a response of some sort, you could add an address of your own to the recipient list. That means you will receive a copy of the outgoing message (if indeed it's going out at all. Make sure to check it's not stuck in the queue before you assume nothing is happening).

In order to better reflect reality, and also in order to avoid creating mail loops, this should probably be a remote address (perhaps Hotmail if you don't have any "real" addresses in other domains, or a friend who doesn't mind receiving oodles of test messages ... a good way to find out who are not your true friends).

If you are constructing your response message's headers on the fly, and sending it off with sendmail -t, just add a Cc: or Bcc: header with your debugging address.

	:0
	* some conditions, no doubt
	| ( formail -yada yada \
	        -I "Bcc: deodorant-tester@hotmail.com" \
		-and yaaada ) \
	  | $SENDMAIL $SENDMAILFLAGS -t
If you are explicitly naming the recipient(s) on Sendmail's command line, you can just add more addresses.

On the other hand, if you aren't sure the message you are generating is even syntactically valid, it's probably better to simply replace the call to Sendmail with a save to a temporary file where you can examine the generated response message. Remember, if you can send it from the command line, it will probably work from within Procmail, too (and vice versa. But see the tee trick in the previous section if you want the best of both worlds).

Additional Logging

(The subhead should perhaps read "Beyond Last Resort". :-)

If you suspect your Sendmail or your shell of being faulty, or just want to be really sure of what they are doing, you can start messing around with their flags.

I am willing to bet money that you are on the wrong track if you are seriously considering this. I am also willing to bet that if you don't have SHELL=/bin/sh right at the top of your .procmailrc, adding that will solve your problem.

To get a few lines in the log file for each command the shell executes, add something like

	SHELLFLAGS=${SHELLFLAGS:--}vx
You can probably omit either x or v -- see the manual page for your shell to find out what they do. (The output is usually slightly unreadable but still decipherable.)

In the same vein, it might be useful to pass a -v flag to Sendmail to see what it's up to. (See below for what the results look like.)

Other programs you use might also have the capability to produce optional extended information about what they are doing. In your own scripts, this is always a good facility to provide.

In Perl, liberally sprinkle your code with warn "$0: reached checkpoint after init\n" if $debug; -- in shell scripts, this is a little bit harder to do idiomatically. Here's one approach:

	#!/bin/sh
	IFDEBUG=:
	case $1 in --debug) shift ; IFDEBUG= ; IFNODEBUG=: ;; esac
	# ... real option processing here
	$IFDEBUG	echo "$0: reached checkpoint after init" >&2
	# ...
I define IFNODEBUG as the complement of IFDEBUG because I often find it useful (unlike in Perl scripts, but I guess in the end it's not all that strange -- it's more important in shell scripts to have things in a particular order, etc). If you decide your script is sufficiently debugged at some point, cleaning out the debugging stuff is again a matter of regex search and replace. (Corollary to Murphy's law: This will break your script, or ruin your day when you find that you need to put that stuff back in somehow.)

Getting Procmail to Run in the First Place

This is not particularly something I wanted to write about, but here are some quick tips if you seem to not be able to get Procmail to do anything at all. If you think you know what you are doing, you will probably want to go over this list more or less in reverse order.

Is Procmail Installed Correctly?

Can you run Procmail from the command line and not get a core dump?

	$ procmail -v
If this works as expected, what happens if you actually try to deliver a message?
	$ procmail DEFAULT=/dev/null VERBOSE=yes /dev/null </dev/null
This means: Run Procmail. The place to deliver mail to is /dev/null unless the rc file says otherwise. We want verbose logging (to standard error, as long as LOGFILE doesn't get set to something) and use /dev/null as the rc file (i.e., effectively, just deliver to DEFAULT). The message to deliver is standard input, which is redirected to come from /dev/null as well.

Here are the results of a sample run:

	procmail: [8532] Thu Mar 25 15:08:16 1999
	procmail: Rcfile: "/dev/null"
	procmail: Assigning "MAILDIR=/home/era"
	procmail: Assigning "LASTFOLDER=/dev/null"
	procmail: Opening "/dev/null"
	  Folder: /dev/null							      0

If this works as expected, are you sure the permissions on the Procmail binary are such that e.g. Sendmail can run it? (When called from your own private .forward, Procmail only needs to have execute permissions set for yourself, of course.)

Are Things Happening on the Host Where You Think They Should Happen?

Many sites have a designated mail host which mounts users' home directories over NFS or something, but which has completely its own idea of what's in e.g. /usr/local/bin and so if you installed Procmail on a different host, your problems might simply boil down to this fact.

The FAQ has an appendix with more information on this.

There is a nasty twist to watch out for: In principle, the mail host could have mounted the user's home directory under a different name than what the user sees in interactive logins. Thus some absolute path names you try to write to might not be valid on the mail host. See below.

Do You Know How to Run Procmail in Your Setting?

This means: If your site is not using Sendmail, do you know what mechanism you should use to invoke Procmail?

If Procmail is installed as your MDA, you should be able to use it simply by creating a .procmailrc file in your home directory. If you are unsure of whether Procmail is your MDA, this is easy enough to test: Create a minimal .procmailrc with LOGFILE set, send yourself mail (perhaps from a Hotmail account or something) and see if stuff appears in the log file you designated.

The advanced document from the distribution contains some tips for installing Procmail as your MDA but I am unaware of any good collection of tips for forwarding using different MTA:s other than the only indirectly relevant discussion in the Mail Addressing FAQ by Eli the Bearded, which contains some tips for MMDF and Exim users (and Qmail, to a lesser extent).

For Sendmail and compatibles, if Procmail is not your MDA, you will need to create a .forward file with reasonably strict permissions. The manual page for Procmail has instructions (they differ slightly depending on other factors in your installation, which the Procmail installation script figures out before it creates the manual pages).

The .forward file seems to be the mechanism of choice in most other environments, too, although the syntax of the file apparently varies with different MTA:s.

Is Procmail Doing What You Think it Should be Doing?

If you can get Procmail to produce output somewhere (i.e. it runs and you can write to the log or to some file in your home directory) it's probably a good idea to put in some diagnostic tests in your .rc file (perhaps you should install a testing .procmailrc for now and put back the real .procmailrc you want to use when you have sorted out your problems).

Some useful things to get into these diagnostics include

See the remarks on logging on the first half of this page.

A very confusing misfeature is Procmail's inability to cooperate with csh-related shells. This is probably one of the most important reasons for problems which are not trivial to diagnose. Before you do anything else, put in SHELL=/bin/sh at the top of your .procmailrc file. Actually you should get in the habit of putting this at the start of all your Procmail scripts. As long as your login shell is not a csh or tcsh, you probably won't even notice the difference -- until you try to share your scripts with someone less fortunate.

Do the system log files tell you anything?

The first place to check, if you have the permissions, is your system's log file. If you try to run Procmail and nothing happens, some sort of logging information is virtually certain to get written somewhere.

Unfortunately, not all admins feel comfortable leaving the log files readable to mortal users.

Also unfortunately, the locations of various log files are not very firmly standardized. Some places to look are /var/log or /var/adm -- if you have permission to look there. But the syslog(3) interface documentation and/or the syslogd(8) manual page should tell you what you need to know.

If Procmail doesn't have permission to do anything, it will spew something to the system console. On modern systems, console log messages will also be written to a file somewhere, typically something like /var/log/messages.

Sendmail usually logs every message it tries to deliver, either to its own log file (perhaps /var/log/mail.log or perhaps even into the regular /var/log/messages file)

As with all log files, you should probably have a look at them sometime just to get a feel for what's supposed to be there when the system is working.

Check For Permission Problems

The permissions of the .procmailrc file need to be rather tight. chmod 600 .procmailrc is probably not a bad idea before you proceed with testing.

The same applies to .forward, if you need one.

Procmail 3.13 will also check the permissions on your home directory, and bail out if they are too lax (i.e. anybody who can write there can overwrite your .procmailrc with a sinister one).

(Incidentally, the most frequently asked question from Red Hat users recently has been "how come Procmail stopped working when I upgraded". Red Hat has group write permissions on everything, which is okay because each user is in her own group, but the guys who made the 3.13.1-1 RPM didn't bother to tell Procmail when they compiled it. See the FAQ for a bit more on this.)

It's also a good idea to check for write permission in various other places; files which control what's supposed to happen should generally be writable only by owner, and directories where Procmail will need to write out logging information or mail will obviously need to be writable.

Desperation, Part II: Can You Run Procmail Under a Debugger?

Different Unix variants offer different tracing, debugging, and profiling programs, but usually something like a call tracer is available. (Not so under e.g. HP-UX, where the call tracing facility is powerful enough to be a security hole, and so it is usually made unavailable to mortal users.)

On Linux, look for strace. On SunOS/Solaris, try truss. On various BSD-derived systems, trace is probably the thing you're looking for.

Whatever it's called, by running Procmail (or any other program) via the call tracer, it executes as normal, but you also get a file (perhaps on standard error or standard output) with all the system calls made by the program you're tracing. That means, among other things, that you get to see which files it attempts to open and how and when it tries to allocate memory.

Like the headline suggests, this is for truly desperate situations (but fooling around with the call tracer just to familiarize yourself with the facility is probably time well spent).

If you are comfortable with a source debugger, compiling Procmail and single-stepping through the code can be a great way to understand the program.

Can You Talk to the MTA?

This might be too complicated for newbies, but nothing really beats a direct telnet to the SMTP port on the mail host. If you don't know the protocol, a brief overview of RFC821 might be in place here -- it's by no means complicated. You want to understand HELO, MAIL FROM, RCPT TO, VRFY, EXPN. and QUIT.

$ telnet host.name.here 25
Trying 127.0.0.1...
Connected to localhost.
Escape character is '^]'.
220 host.name.here ESMTP Sendmail 8.8.5/8.8.0; Thu, 25 Mar 1999 16:29:52 +0200 (EET)
helo buddy
250 host.name.here Hello era@iki.fi [194.100.45.83], can you behave yourself?
vrfy era
550 era... User unknown
expn era
550 era... User unknown
quit
221 host.name.here closing connection
Connection closed by foreign host.

Of course, in this case, the host might simply have been configured to not reveal anything about its local users, in order to foil spammers and other abusers. You can try to actually type in a real mail message and see what kind of response to get, but at that point, it's probably already better to work with a couple of layers of convenient wrapping between yourself and the raw SMTP connection.

Here's a session which worked out better:

$ telnet kantti.helsinki.fi 25
Trying 128.214.205.12...
Connected to kantti.helsinki.fi.
Escape character is '^]'.
220 kantti.Helsinki.FI ESMTP Sendmail 8.8.8/8.8.5-SPAMmers-sod-off; Thu, 25 Mar 1999 16:39:18 +0200 (EET)
helo foo
250 kantti.Helsinki.FI Hello reriksso@tuuri.ling.helsinki.fi [128.214.78.4], pleased to meet you, unless you are a SPAMmer
expn reriksso
250 Era Eriksson <"|ifs=' ' && p=/etc/local/bin/procmail && test -x $p && exec $p -yf- || exit 75 #reriksso"@kantti.Helsinki.FI>
quit
221 kantti.Helsinki.FI closing connection
Connection closed by foreign host.

Talk to the MTA Some More

This is unfortunately specific to Sendmail and compatibles. Tips for other MTA:s will be gratefully accepted.

To see whether the MTA is willing to accept mail for the user in question, you need to have shell access on the mailhost and run this there:

	$ sendmail -bv username
	username... deliverable: mailer local, user username

If you get an answer mentioning a remote host name and so forth, it means you are on the wrong host, and need to figure out where the mail ultimately gets delivered.

To actually try to deliver something and watch while Sendmail is doing it, try this:

	$ sendmail -v username </dev/null
	username... Connecting to local...
	username... Sent

If there is an error, sendmail will be delivering a bounce message back to you using normal means.

Here is a more involved session, namely one involving a .forward file:

	$ sendmail -v era </dev/null
	/home/era/.forward: line 1: forwarding to era@iki.fi
	era@iki.fi... Connecting to mail.iki.fi. via esmtp...
	era@iki.fi... Connecting to mail2.iki.fi. via esmtp...
	220 taas.iki.fi ESMTP Sendmail 8.8.8/8.8.8; Thu, 25 Mar 1999 16:53:17 +0200 (EET)
	>>> EHLO away.lingsoft.fi
	250-taas.iki.fi Hello era@away.lingsoft.fi [128.214.78.4], pleased to meet you
	250-EXPN
	250-VERB
	250-8BITMIME
	250-SIZE
	250-DSN
	250-ONEX
	250-ETRN
	250-XUSR
	250 HELP
	>>> MAIL From:<era@away.lingsoft.fi>
	250 <era@away.lingsoft.fi>... Sender ok
	>>> RCPT To:<era@iki.fi>
	250 <era@iki.fi>... Recipient ok
	>>> DATA
	354 Enter mail, end with "." on a line by itself
	>>> .
	250 QAA26453 Message accepted for delivery
	era@iki.fi... Sent (QAA26453 Message accepted for delivery)
	Closing connection to mail2.iki.fi.
	>>> QUIT
	221 taas.iki.fi closing connection

(You should perhaps not try to deliver to a nonexistent user just to see what it looks like, unless you are the postmaster or know for a fact that the local postmaster will not also get a copy of the needless bounce message. Signed, been there, done that. Blush.)

There are numerous debugging options you can pass in to Sendmail in order to see -- even in excruciating detail -- what's going on at every stage of the delivery process. See the documentation for ideas.

Do You Get a Bounce Message?

If things work out okay this far, chances are the problem is not with Procmail itself anymore. Some possibilities:

Procmail was compiled for the wrong architecture
You would see something like "unknown mailer error 1" in the bounce message if this is the case (but this message will of course vary between architectures)
Something in the .procmailrc file is wrong
If you get a log file, examining that should be helpful

If you get really desperate, you could always add various debugging aids to either the .forward file or to your .procmailrc, if things get as far as to actually starting up Procmail. The second alternative is vastly preferrable; logging diagnostics directly from the .forward file is always hairy.

A thread from the Procmail mailing list which touches on this briefly is at http://www.xray.mpe.mpg.de/mailing-lists/procmail/1997-09/msg00526.html -- the mailing list will obviously have lots of other old threads about troubleshooting different scenarios; try a search for e.g. some string you get in the bounce message and see if you get any promising matches.

The first half of this page also has some remarks on logging.

Oh No, It's One of His Link Collections Again

The new Kernighan / Pike book has a debugging chapter, parts of which is available on-line.

If you thought this was boring, you'll hate the Procmail FAQ by yours truly. It comes with an even more boring even more extensive links page, too.

And then there's http://www.procmail.org/ and the searchable archive of the Procmail mailing list where you can look for problems similar to your own.


$Id: procmail-debug.prep,v 1.25 1999/09/14 02:46:56 reriksso Exp $