Duplicate local message deliveries in qmail
DennyK
Hey folks,
I was hoping someone could offer some suggestions for us. We have a
high-volume qmail mail system that is having an issue with some local
messages being duplicated during delivery. There are no errors being
reported and the messages are not being requeued; during the initial
delivery attempt, instead of attempting a single delivery to the recipient
address like normal, qmail attempts to deliver the message to the recipient
multiple times (randomly ranging from as few as three or four to as many as
a dozen or more, and generating a new delivery number for each attempt),
without waiting for the earlier attempts to complete. All attempts complete
successfully in a timely fashion (generally less than one second).
Essentially, the behavior is what you would expect to see if you were to
send a message with the same recipient address repeated multiple times in
the To:, CC:, or BCC: fields, but the affected messages only have a single
recipient address, specified once.
This is happening both with messages originating from external addresses
outside the server and messages originating locally from local email
accounts on the same domain, but there is no consistency in which messages
are being duplicated; it happens with messages sent from various places and
sent to various recipients at various domains hosted on our qmail system.
Only a small fraction of the messages processed by the server are being
affected overall. Although we have a high-volume system, the issue does not
appear to be related to load; it happens regardless of how heavily the
system is being used at the time.
Here's an example of what is showing up in the qmail logs for one of the
duplicated messages (email addresses have been changed to protect the
innocent). This is a single normal email message sent from the external
address sen...@sender.com to our local email address
recipi...@recipientdomain.com.
2011 Apr 15 12:39:08 qmail: 1302885548.822480 new msg 4948245
2011 Apr 15 12:39:08 qmail: 1302885548.822517 info msg 4948245: bytes 2270
from <sen...@sender.com> qp 15036 uid 80
2011 Apr 15 12:39:08 qmail: 1302885548.825302 starting delivery 4192516: msg
4948245 to local recipientdomain....@recipientdomain.com
2011 Apr 15 12:39:08 qmail: 1302885548.825336 status: local 1/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.825820 starting delivery 4192517: msg
4948245 to local recipientdomain....@recipientdomain.com
2011 Apr 15 12:39:08 qmail: 1302885548.825855 status: local 2/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.840641 starting delivery 4192518: msg
4948245 to local recipientdomain....@recipientdomain.com
2011 Apr 15 12:39:08 qmail: 1302885548.840675 status: local 3/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.843722 starting delivery 4192519: msg
4948245 to local recipientdomain....@recipientdomain.com
2011 Apr 15 12:39:08 qmail: 1302885548.843806 status: local 4/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.847588 starting delivery 4192520: msg
4948245 to local recipientdomain....@recipientdomain.com
2011 Apr 15 12:39:08 qmail: 1302885548.847631 status: local 5/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.854437 starting delivery 4192521: msg
4948245 to local recipientdomain....@recipientdomain.com
2011 Apr 15 12:39:08 qmail: 1302885548.854471 status: local 6/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.860540 starting delivery 4192522: msg
4948245 to local recipientdomain....@recipientdomain.com
2011 Apr 15 12:39:08 qmail: 1302885548.860571 status: local 7/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.862349 starting delivery 4192523: msg
4948245 to local recipientdomain....@recipientdomain.com
2011 Apr 15 12:39:08 qmail: 1302885548.862381 status: local 8/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.960195 delivery 4192518: success:
did_0+0+1/
2011 Apr 15 12:39:08 qmail: 1302885548.960312 status: local 7/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.960372 end msg 4948245
2011 Apr 15 12:39:08 qmail: 1302885548.967877 delivery 4192520: success:
did_0+0+1/
2011 Apr 15 12:39:08 qmail: 1302885548.967962 status: local 6/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.970752 delivery 4192521: success:
did_0+0+1/
2011 Apr 15 12:39:08 qmail: 1302885548.970837 status: local 5/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.976349 delivery 4192523: success:
did_0+0+1/
2011 Apr 15 12:39:08 qmail: 1302885548.976432 status: local 4/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.981543 delivery 4192522: success:
did_0+0+1/
2011 Apr 15 12:39:08 qmail: 1302885548.981625 status: local 3/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.984641 delivery 4192517: success:
did_0+0+1/
2011 Apr 15 12:39:08 qmail: 1302885548.984719 status: local 2/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.989709 delivery 4192519: success:
did_0+0+1/
2011 Apr 15 12:39:08 qmail: 1302885548.989797 status: local 1/100 remote
1/255
2011 Apr 15 12:39:08 qmail: 1302885548.994360 delivery 4192516: success:
did_0+0+1/
2011 Apr 15 12:39:08 qmail: 1302885548.994445 status: local 0/100 remote
1/255
I've searched around this mailing list and via Google and found people
reporting messages duplicating due to messages being requeued, delivery
timeouts, or POP3 clients not deleting messages from mailboxes, but no one
reporting this particular duplicate delivery issue. Can anyone here offer
any suggestions as to what might cause this behavior?
Thanks,
Denny K.
--
View this message in context: http://old.nabble.com/Duplicate-local-message-deliveries-in-qmail-tp31409082p31409082.html
Sent from the cr.yp.to - qmail mailing list archive at Nabble.com.
--
Posted automagically by a mail2news gateway at muc.de e.V.
Please direct questions, flames, donations, etc. to news-...@muc.de
Andy Bradford
> 2011 Apr 15 12:39:08 qmail: 1302885548.822480 new msg 4948245
> 2011 Apr 15 12:39:08 qmail: 1302885548.822517 info msg 4948245: bytes 2270
> from <sen...@sender.com> qp 15036 uid 80
Who is uid 80?
> 2011 Apr 15 12:39:08 qmail: 1302885548.825302 starting delivery 4192516: msg
> 4948245 to local recipientdomain....@recipientdomain.com
Given the format if this delivery, I would guess you're running
vpopmail. What do you have in the .qmail-default for this domain? Do you
have a .qmail-recipientuser in the domain's root? Basically, what does
the dot-qmail file that controls deliveries for this user (the user is
recipientdomain.com) look like?
> Can anyone here offer any suggestions as to what might cause this
> behavior?
Either something is intentionally injecting a message with multiple
delivery instructions to the same recipient, or you have a buggy MDA
(e.g. vpopmail).
Andy
Joseph Maxwell
But my server settings is set to clear messages after 14 days?
Denny K
On Fri, Apr 15, 2011 at 7:56 PM, Andy Bradford <amb-sendok-1305503814...@bradfords.org> wrote:
>Who is uid 80?
UID 80 is the vpopmail user.
>Given the format if this delivery, I would guess you're running
>vpopmail. What do you have in the .qmail-default for this domain? Do you
>have a .qmail-recipientuser in the domain's root? Basically, what does
>the dot-qmail file that controls deliveries for this user (the user is
>recipientdomain.com) look like?
On Fri, Apr 15, 2011 at 5:51 PM, Erwin Hoffmann <f...@fehcom.de> wrote:
>Lately, I have seen similar (b) problems on CentOS 5.x. In particular, even after changing some
>qmail control files, the system did ignore those and used the (obvious) cached version. The
>problem disappeared after rebooting the machine.
Interesting. Our system is actually a load-balanced cluster of RHES 4 servers running qmail with vpopmail. The qmail config files and the mail queue directory are located on a local disk on each node, but users' mail directories are on a shared volume mounted via nfs. As an experiment, we tried rebooting one of the nodes in the cluster yesterday, and since that time, the rebooted node has not had the problem with duplicated messages, while the rest of the nodes in the cluster have continued to experience the duplication issue. Seems that whatever's causing it might be resolved by a reboot.
We have three other load-balanced mail clusters running the same configuration. Initially we were storing the qmail queue on a ramdisk on all of the clusters. The first two clusters have never had issues with mail duplication like this, but the third cluster had some sort of a problem with duplicate messages a while back that was resolved by moving the queue directory from a ramdisk to the local hard disk volume. Unfortunately I was not involved in working on that particular issue, so I don't know if the duplication problem was exactly the same as the current issue or not, but at the time they believed it to be a problem with the ramdisk, and moving the queue to the hard disk volume appeared to resolve it. We hadn't seen any further duplicate message issues for months, until this issue recently cropped up on our fourth mail cluster, which also has the queue on the hard disk.
In any case, we are rebooting the rest of the nodes in the affected cluster now. Guess we'll see if that clears up the issue entirely.
Thanks for the input, guys!
Denny K.
Erwin Hoffmann
On Fri, 15 Apr 2011 13:19:30 -0700 (PDT)
DennyK <denny...@gmail.com> wrote:
>
> Hey folks,
>
> I was hoping someone could offer some suggestions for us. We have a
> high-volume qmail mail system that is having an issue with some local
> messages being duplicated during delivery. There are no errors being
> reported and the messages are not being requeued; during the initial
> delivery attempt, instead of attempting a single delivery to the recipient
> address like normal, qmail attempts to deliver the message to the recipient
> multiple times (randomly ranging from as few as three or four to as many as
> a dozen or more, and generating a new delivery number for each attempt),
> without waiting for the earlier attempts to complete. All attempts complete
> successfully in a timely fashion (generally less than one second).
> Essentially, the behavior is what you would expect to see if you were to
> send a message with the same recipient address repeated multiple times in
> the To:, CC:, or BCC: fields, but the affected messages only have a single
> recipient address, specified once.
Those things are handled by qmail-send(.c), in particular:
void markdone(c,id,pos)
int c;
unsigned long id;
seek_pos pos;
{
struct stat st;
int fd;
fnmake_chanaddr(id,c);
for (;;)
{
fd = open_write(fn.s);
if (fd == -1) break;
if (fstat(fd,&st) == -1) { close(fd); break; }
if (seek_set(fd,pos) == -1) { close(fd); break; }
if (write(fd,"D",1) != 1) { close(fd); break; }
/* further errors -> double delivery without us knowing about it, oh well */
close(fd);
return;
}
log3("warning: trouble marking ",fn.s,"; message will be delivered twice!\n");
}
---
Since nobody has reported a similar problem (to my knowledge) in the last ten years, I assume a local problem of your machine.
I guess, (a) your filesystem might be corrupted, or (b) your buffercache is 'filtering' the above action. This may happen on an I/O busy system.
Lately, I have seen similar (b) problems on CentOS 5.x. In particular, even after changing some qmail control files, the system did ignore those and used the (obvious) cached version. The problem disappeared after rebooting the machine.
Sorry, not to be more explicit.
regards.
--eh.
--
Dr. Erwin Hoffmann | FEHCom | http://www.fehcom.de