Postfix randomly losing the mail

Bug #67149 reported by dario
4
Affects Status Importance Assigned to Milestone
postfix (Ubuntu)
Invalid
Undecided
Unassigned

Bug Description

Binary package hint: postfix

A user complained that her e-mail was not delivered to a recipient.
When inspecting logs of SMTP gateway, it was confirmed that qmgr dropped the message without even trying to deliver the message.

In the following log snippet pay attention to the message CFF81171B16 that was "resent" by a content-filter to localhost.
Note that you truly can't find any kind of delivery information ("status=..."). It was simply just "removed" without any further notice.

Oct 13 11:29:01 mailsystem postfix/smtpd[9205]: CFF81171B16: client=localhost.YYY.ZZ[127.0.0.1]
Oct 13 11:29:01 mailsystem postfix/smtpd[7659]: NOQUEUE: reject: RCPT from chello212186108027.15.11.vie.surfer.at[212.186.108.27]: 450 <email address hidden>: Sender address rejected: undeliverable address: host mgate.telekabel.at[213.46.255.2] said: 550 Invalid recipient: <email address hidden> (in reply to RCPT TO command); from=<email address hidden> to=<email address hidden> proto=ESMTP helo=<chello212186108027.15.11.vie.surfer.at>
Oct 13 11:29:01 mailsystem postfix/smtpd[7659]: lost connection after RCPT from chello212186108027.15.11.vie.surfer.at[212.186.108.27]
Oct 13 11:29:01 mailsystem postfix/smtpd[7659]: disconnect from chello212186108027.15.11.vie.surfer.at[212.186.108.27]
Oct 13 11:29:01 mailsystem postfix/smtpd[31842]: connect from unknown[203.188.40.191]
Oct 13 11:29:01 mailsystem postfix/smtpd[31842]: lost connection after CONNECT from unknown[203.188.40.191]
Oct 13 11:29:01 mailsystem postfix/smtpd[31842]: disconnect from unknown[203.188.40.191]
Oct 13 11:29:01 mailsystem postfix/smtpd[3698]: disconnect from d150-172-59.home.cgocable.net[24.150.172.59]
Oct 13 11:29:02 mailsystem postfix/smtpd[9205]: disconnect from localhost.YYY.ZZ[127.0.0.1]
Oct 13 11:29:02 mailsystem postfix/qmgr[31734]: CFF81171B16: from=<email address hidden>, size=400113, nrcpt=1 (queue active)
Oct 13 11:29:02 mailsystem postfix/smtpd[7649]: connect from DDD.EEE.YYY.ZZ[-----]
Oct 13 11:29:02 mailsystem postfix/smtpd[7649]: 546C7178C13: client=DDD.EEE.YYY.ZZ[-----]
Oct 13 11:29:02 mailsystem postfix/smtpd[31727]: D9208178C1B: client=unknown[221.134.254.225]
Oct 13 11:29:03 mailsystem postfix/qmgr[31734]: A6666178C2B: removed
Oct 13 11:29:03 mailsystem postfix/qmgr[31734]: B6041178C2B: from=<email address hidden>, size=254, nrcpt=1 (queue active)
Oct 13 11:29:03 mailsystem postfix/qmgr[31734]: B6041178C2B: removed
Oct 13 11:29:04 mailsystem postfix/qmgr[31734]: CFF81171B16: removed

(Seemingly irrelevant parts of log intentionally kept here for overall illustration; DNS and IP addresses relevant to my employer changed intentionally.)

Not reproducible, unpredictable, IMHO critical.

The machine is a month old installion of Ubuntu 6.06 w/all updates with no other apparent HW or SW problems, dealing with >30,000 e-mails/day.

Details upon request.

Revision history for this message
LaMont Jones (lamont) wrote :

Any chance that syslog was restarted after postfix was started? That can cause chrooted services to quit logging, which could explain the log file appearance.

Revision history for this message
dario (dario-morgendorffer) wrote :

While it is possible (syslog-ng package was installed a week earlier), but let me note that:

1. the log was investigated after <s>user</s> two users had complained. Ignoring this would be inappropriate usage of Ockham's razor.
2. it is not obvious from the first log snippet, but you can actually find logs like

Oct 13 10:47:03 mailsystem postfix/smtp[29587]: 3418D171B96: to=<email address hidden>, orig_to=<email address hidden>, relay=pop3.YYY.ZZ[-----], delay=0,
status=sent (250 Ok: queued as 4EFBD4C53D)

Revision history for this message
Scott Kitterman (kitterman) wrote :

If you still have the log from this, what does grepping for that queue ID (CFF81171B16) produce?

Changed in postfix:
status: Unconfirmed → Needs Info
Revision history for this message
Scott Kitterman (kitterman) wrote :

Marking invalid due to lack of response. If you can replicate this or provide the requested information, please reopen the bug.

Changed in postfix:
status: Incomplete → Invalid
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.