Consider a configuration like the following (a minor
adaptation of the default in the exim distribution):
address_pipe:
driver = pipe
return_fail_output
transport_filter = /path/to/script
transport_filter_timeout = 10s
where /path/to/script is some filter which usually
completes quickly but sometimes takes a long time, for
instance:
#!/usr/bin/perl -w
use strict;
my $mail = join('', <STDIN>);
if ($mail =~ /GO_WRONG/) {
sleep(20);
}
print $mail;
In the situation where the script waits before returning
any output, I find that exim (4.50, from a Debian package,
and also in 4.34, compiled from the source) will pass on a
blank mail to whatever the target of the address_pipe
transport is (i.e., procmail or whatever). What seems to
be happening is that exim gives up on the transport filter
after the timeout, but the fact that the filter timed out
is ignored.
Any suggestions? The problem with this is that a perfectly
reasonable transport_filter could time out under heavy
load (for instance waiting for a connection to some
external resource or simply because the machine is bogged
down), but the transport_filter_timeout mechanism doesn't
seem to achieve what is desired....
Below is a debug log excerpt with this behaviour:
(generated with exim -d -t < testmail where test is a mail
having Subject: GO_WRONG, and is being delivered to a user
with a forward file which passes incoming mail to
procmail)
>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
After routing:
Local deliveries:
|/usr/bin/procmail -Y .procmailrc-bar
Remote deliveries:
Failed addresses:
Deferred addresses:
search_tidyup called
>>>>>>>>>>>>>>>> Local deliveries >>>>>>>>>>>>>>>>
--------> |/usr/bin/procmail -Y .procmailrc-bar <--------
locking /var/spool/exim4/db/retry.lockfile
locked /var/spool/exim4/db/retry.lockfile
opened hints database /var/spool/exim4/db/retry: flags=0
dbfn_read: key=T:|/usr/bin/procmail -Y .procmailrc-bar:chris@???
no retry record exists
search_tidyup called
changed uid/gid: local delivery to |/usr/bin/procmail -Y .procmailrc-bar <|/usr/bin/procmail -Y .procmailrc-bar> transport=address_pipe
uid=1000 gid=1000 pid=7592
auxiliary group list: <none>
home=/home/chris current=/home/chris
set_process_info: 7592 delivering 1DaXZz-0001yP-4M to |/usr/bin/procmail -Y .procmailrc-bar using address_pipe
direct command:
argv[0] = /path/to/script
direct command after expansion:
argv[0] = /path/to/script
T: address_pipe for chris@???
address_pipe transport entered
direct command:
argv[0] = /usr/bin/procmail
argv[1] = -Y
argv[2] = .procmailrc-bar
Writing message to pipe
set_process_info: 7594 reading output from |/usr/bin/procmail -Y .procmailrc-bar
writing data block fd=9 size=59 timeout=3600
process 7595 running as transport filter: write=10 read=11
process 7596 writing to transport filter
copying from the filter
writing data block fd=10 size=339 timeout=3600
waiting for filter process
waiting for writing process
end of filtering transport writing: yield=0
errno=110 more_errno=0
address_pipe transport yielded 0
search_tidyup called
journalling |/usr/bin/procmail -Y .procmailrc-bar:chris@???
address_pipe transport returned OK for |/usr/bin/procmail -Y .procmailrc-bar
post-process |/usr/bin/procmail -Y .procmailrc-bar (0)
|/usr/bin/procmail -Y .procmailrc-bar delivered
chris@???: children all complete
chris@shedu: children all complete
LOG: MAIN
=> |/usr/bin/procmail -Y .procmailrc-bar (chris@???) <chris@shedu> R=userforward T=address_pipe
>>>>>>>>>>>>>>>> deliveries are done >>>>>>>>>>>>>>>>
changed uid/gid: post-delivery tidying
uid=102 gid=102 pid=7590
auxiliary group list: <none>
set_process_info: 7590 tidying up after delivering 1DaXZz-0001yP-4M
Processing retry items
Succeeded addresses:
|/usr/bin/procmail -Y .procmailrc-bar: no retry items
chris@???: no retry items
chris@shedu: no retry items
chris@???: no retry items
chris@shedu: no retry items
Failed addresses:
Deferred addresses:
end of retry processing
LOG: MAIN
Completed
end delivery of 1DaXZz-0001yP-4M
search_tidyup called
search_tidyup called
>>>>>>>>>>>>>>>> Exim pid=7590 terminating with rc=0 >>>>>>>>>>>>>>>>
--
``It was a time of happy, shiny people.
The shiniest were in the uranium mines.''
(caption on postcard sold by the Museum of Communism in Prague)
