[Exim] Duplicate message delivery in Exim 4.14

Top Page
Delete this message
Reply to this message
Author: Rennie deGraaf
Date:  
To: exim-users
Subject: [Exim] Duplicate message delivery in Exim 4.14
I have a user complaining that some messages are being delivered twice
to some recipients. From the log files, I have determined that the
duplication *appears* to occur somwhere within Exim, but have so far
been unable to determine why or how.

Some explanation of my mail system: one Exim process accepts incoming
SMTP connections, delivers outbound messages, delivers inbound messages
whose sender addresses are not in a particular list, and writes all
other inbound messages to a queue (because not all inbound messages get
queued, I can't use the queue_only=true option, and thus I get a "defer
(-1)" error every time something is queued). MailScanner, a spam and
virus filtering framework, reads messages from that queue, and writes
them to another queue. A second Exim process reads from the second
queue and delivers the inbound messages. I'm using Exim 4.14 on SELinux
2.4.19.

If I understand how Exim works correctly, the main daemon forks off a
child every time it recieves a message. That child then forks off a
grandchild, which attempts to make the delivery. If this is correct,
then in the following log fragment, 16296 is the PID of the child of the
first Exim process, and 16300 is the PID of the grandchild. 16357
should be the PID of a (grand)child of the second Exim process (after
the message has been re-queued by MailScanner).

This log fragment was obtainied by grepping the message ID out of
/var/log/maillog. There was nothing that looked relevant in any of the
other log traffic between these messages. All personal information has
been removed. It appears that all messages were handled properly by
the first Exim process (PID 16300), but then the second process (PID
16357), which should only deliver the message to user17@??? (as
this is a local alias), actually delivered the message to most, but not
all, of the other addresses as well. I have not been able to duplicate
this problem, but this happens to messages from "veranouser" on a
regular basis. The only common properties I have found between such
messages are that they are all addressed to at least 10 people, and the
recpients include both remote and local accounts. "veranouser"'s MUA is
MS Outlook 98 (8.5.5104.6).

Jul 17 08:18:52 mailhost exim[16296]: 2003-07-17 08:18:52
19d9at-0004Eq-Va <= veranouser@??? H=somehost.somenet.zz
(veranouser) [abc.def.ghi.jkl] P=asmtp X=TLSv1:RC4-MD5:128
A=login:veranouser S=4086 id=003001c34c6e$316e6da0$5aa52b41@???
T="FW: Read the Link!" from <veranouser@???> for
user1@??? user2@??? user3@??? user4@???
user5@??? user6@??? user7@??? user8@???
user9@??? user10@??? user11@??? user12@???
user13@??? user14@??? user15@??? user16@???
user17@??? Jul 17 08:18:52 mailhost exim[16300]: 2003-07-17
08:18:52 19d9at-0004Eq-Va == user17@??? R=defer_router defer
(-1): remote host address is the local host
Jul 17 08:19:01 mailhost exim[16300]: 2003-07-17 08:19:01
19d9at-0004Eq-Va => user2@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4247 H=mail.vitaz.net [24.123.202.186]
Jul 17 08:19:11 mailhost exim[16300]: 2003-07-17 08:19:11
19d9at-0004Eq-Va => user3@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4247 H=mx3.hotmail.com [65.54.253.99]
Jul 17 08:19:15 mailhost exim[16300]: 2003-07-17 08:19:15
19d9at-0004Eq-Va => user1@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4247 H=mail.charter.net [209.225.8.223]
Jul 17 08:19:17 mailhost exim[16300]: 2003-07-17 08:19:17
19d9at-0004Eq-Va => user5@??? F=<veranouser@???> R=dnslookup
T=remote_smtp S=4247 H=mailin-03.mx.aol.com [64.12.136.217]
Jul 17 08:19:17 mailhost exim[16300]: 2003-07-17 08:19:17
19d9at-0004Eq-Va -> user7@??? <user7@???>
F=<veranouser@???> R=dnslookup T=remote_smtp S=4247
H=mailin-03.mx.aol.com [64.12.136.217]
Jul 17 08:19:17 mailhost exim[16300]: 2003-07-17 08:19:17
19d9at-0004Eq-Va -> user8@??? F=<veranouser@???> R=dnslookup
T=remote_smtp S=4247 H=mailin-03.mx.aol.com [64.12.136.217]
Jul 17 08:19:17 mailhost exim[16300]: 2003-07-17 08:19:17
19d9at-0004Eq-Va -> user15@??? F=<veranouser@???> R=dnslookup
T=remote_smtp S=4247 H=mailin-03.mx.aol.com [64.12.136.217]
Jul 17 08:19:17 mailhost exim[16300]: 2003-07-17 08:19:17
19d9at-0004Eq-Va -> user16@??? F=<veranouser@???> R=dnslookup
T=remote_smtp S=4247 H=mailin-03.mx.aol.com [64.12.136.217]
Jul 17 08:19:19 mailhost exim[16300]: 2003-07-17 08:19:19
19d9at-0004Eq-Va => user4@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4247 H=e33.co.us.ibm.com [32.97.110.131]
X=TLSv1:EDH-RSA-DES-CBC3-SHA:168
Jul 17 08:19:19 mailhost exim[16300]: 2003-07-17 08:19:19
19d9at-0004Eq-Va => user6@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4247 H=relay.verizon.net [206.46.170.12]
Jul 17 08:19:19 mailhost exim[16314]: 2003-07-17 08:19:19
19d9at-0004Eq-Va smtpinvite.mx.webtv.net [209.240.213.200]: Connection
refused
Jul 17 08:19:20 mailhost exim[16300]: 2003-07-17 08:19:20
19d9at-0004Eq-Va => user9@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4247 H=eforward4.enom.com [64.74.96.229]
Jul 17 08:19:24 mailhost exim[16300]: 2003-07-17 08:19:24
19d9at-0004Eq-Va => user11@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4247 H=smtp.wideopenwest.com [64.233.207.12]
Jul 17 08:19:38 mailhost exim[16300]: 2003-07-17 08:19:38
19d9at-0004Eq-Va => user12@??? F=<veranouser@???> R=dnslookup
T=remote_smtp S=4247 H=in-mail.apk.net [207.54.158.17]
Jul 17 08:19:55 mailhost exim[16300]: 2003-07-17 08:19:55
19d9at-0004Eq-Va => user10@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4247 H=smtpin.mx.webtv.net [209.240.213.109]
Jul 17 08:20:03 mailhost exim[16300]: 2003-07-17 08:20:03
19d9at-0004Eq-Va => user14@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4247 H=mx2.neod.net [63.147.251.250]
Jul 17 08:21:47 mailhost exim[16300]: 2003-07-17 08:21:47
19d9at-0004Eq-Va => user13@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4247 H=mkerelay1.ifsna.com [207.67.54.35]
Jul 17 08:21:52 mailhost exim[16357]: 2003-07-17 08:21:52
19d9at-0004Eq-Va => user17@??? <user17@???>
F=veranouser@???> R=dnslookup T=remote_smtp S=4473
H=vnt-ex1.verano.com [192.168.1.5]
Jul 17 08:22:05 mailhost exim[16357]: 2003-07-17 08:22:05
19d9at-0004Eq-Va => user1@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4473 H=mail.charter.net [209.225.8.223]
Jul 17 08:22:07 mailhost exim[16357]: 2003-07-17 08:22:07
19d9at-0004Eq-Va => user3@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4473 H=mx4.hotmail.com [65.54.253.230]
Jul 17 08:22:18 mailhost exim[16357]: 2003-07-17 08:22:18
19d9at-0004Eq-Va => user4@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4473 H=e4.ny.us.ibm.com [32.97.182.104]
X=TLSv1:EDH-RSA-DES-CBC3-SHA:168
Jul 17 08:22:20 mailhost exim[16357]: 2003-07-17 08:22:20
19d9at-0004Eq-Va => user6@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4473 H=relay.verizon.net [206.46.170.12]
Jul 17 08:22:31 mailhost exim[16357]: 2003-07-17 08:22:31
19d9at-0004Eq-Va => user8@??? F=<veranouser@???> R=dnslookup
T=remote_smtp S=4473 H=mailin-03.mx.aol.com [64.12.137.121]
Jul 17 08:22:31 mailhost exim[16357]: 2003-07-17 08:22:31
19d9at-0004Eq-Va -> user15@??? F=<veranouser@???> R=dnslookup
T=remote_smtp S=4473 H=mailin-03.mx.aol.com [64.12.137.121]
Jul 17 08:22:31 mailhost exim[16357]: 2003-07-17 08:22:31
19d9at-0004Eq-Va -> user16@??? F=<veranouser@???> R=dnslookup
T=remote_smtp S=4473 H=mailin-03.mx.aol.com [64.12.137.121]
Jul 17 08:22:44 mailhost exim[16357]: 2003-07-17 08:22:44
19d9at-0004Eq-Va => user9@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4473 H=eforward4.enom.com [64.74.96.229]
Jul 17 08:22:44 mailhost exim[16379]: 2003-07-17 08:22:44
19d9at-0004Eq-Va smtpinvite.mx.webtv.net [209.240.213.200]: Connection
refused
Jul 17 08:22:48 mailhost exim[16357]: 2003-07-17 08:22:48
19d9at-0004Eq-Va => user10@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4473 H=smtpin.mx.webtv.net [209.240.213.109]
Jul 17 08:22:50 mailhost exim[16357]: 2003-07-17 08:22:50
19d9at-0004Eq-Va => user11@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4473 H=smtp.wideopenwest.com [64.233.207.12]
Jul 17 08:22:50 mailhost exim[16357]: 2003-07-17 08:22:50
19d9at-0004Eq-Va => user2@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4473 H=mail.vitaz.net [24.123.202.186]
Jul 17 08:23:24 mailhost exim[16357]: 2003-07-17 08:23:24
19d9at-0004Eq-Va => user13@??? F=<veranouser@???>
R=dnslookup T=remote_smtp S=4473 H=mkerelay1.ifsna.com [207.67.54.35]
Jul 17 08:23:24 mailhost exim[16357]: 2003-07-17 08:23:24
19d9at-0004Eq-Va Completed

Does anyone know what is going on here? Any help would be appreciated.
If the exim configuration files are needed, I can post them.

Rennie deGraaf
System Administrator,
Verano <www.verano.com>