|
Neohapsis is currently accepting applications for employment. For more information, please visit our website www.neohapsis.com or email hr@neohapsis.com |
Re: Weird bounces with Postfix, LMTP and Cyrus
From: Christian Theune (theuni
gmail.com)
Date: Fri Dec 02 2005 - 00:22:16 CST
- Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]
Hmm. Ok, I've taken a bit more log data that might help you:
This is a first mail that bounces:
Dec 1 15:02:41 uter postfix/lmtp[11210]: deliver_message: from
plone-users-adminlists.sourceforge.net
Dec 1 15:02:41 uter postfix/lmtp[11210]: >
/var/imap/socket/lmtp[/var/imap/socket/lmtp]: RSET
Dec 1 15:02:41 uter postfix/lmtp[11210]: <
/var/imap/socket/lmtp[/var/imap/socket/lmtp]: 250 2.0.0 ok
Dec 1 15:02:41 uter postfix/lmtp[11210]: deliver_message: reusing
(count 5) session with: /var/imap/socket/lmtp
Dec 1 15:02:41 uter postfix/lmtp[11210]: >
/var/imap/socket/lmtp[/var/imap/socket/lmtp]: MAIL
FROM:<plone-users-adminlists.sourceforge.net> SIZE=6620
Dec 1 15:02:41 uter postfix/lmtp[11210]: >
/var/imap/socket/lmtp[/var/imap/socket/lmtp]: RCPT
TO:<ctheuneimap.whq.gocept.com>
Dec 1 15:02:41 uter postfix/lmtp[11210]: >
/var/imap/socket/lmtp[/var/imap/socket/lmtp]: RCPT
TO:<niloimap.whq.gocept.com>
Dec 1 15:02:41 uter postfix/lmtp[11210]: >
/var/imap/socket/lmtp[/var/imap/socket/lmtp]: DATA
Dec 1 15:02:41 uter postfix/lmtp[11210]: <
/var/imap/socket/lmtp[/var/imap/socket/lmtp]: 250 2.1.0 ok
Dec 1 15:02:41 uter postfix/lmtp[11210]: <
/var/imap/socket/lmtp[/var/imap/socket/lmtp]: 250 2.0.0 ok
Dec 1 15:02:41 uter postfix/lmtp[11210]: <
/var/imap/socket/lmtp[/var/imap/socket/lmtp]: 250 2.0.0 ok
Dec 1 15:02:41 uter postfix/lmtp[11210]: <
/var/imap/socket/lmtp[/var/imap/socket/lmtp]: 250 2.1.0 ok
Dec 1 15:02:41 uter postfix/lmtp[11210]: connect to subsystem private/bounce
Dec 1 15:02:41 uter postfix/bounce[11366]: connection established
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr nrequest = 0
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr flags = 0
Dec 1 15:02:41 uter postfix/bounce[11366]: master_notify: status 0
Dec 1 15:02:41 uter postfix/bounce[11366]: bounce socket: wanted
attribute: nrequest
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr queue_id = 2BAE72974
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr original_recipient
= ctgocept.com
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr recipient =
ctheuneimap.whq.gocept.com
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr offset = 355
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr status = 5.0.0
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr action = failed
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr reason = host
/var/imap/socket/lmtp[/var/imap/socket/lmtp] said: 250 2.1.0 ok (in
reply to DATA command)
Dec 1 15:02:41 uter postfix/lmtp[11210]: private/bounce socket:
wanted attribute: status
The next mail is related to that, it looks like the bounce
notification and seems to get through to me (as I get those bounces):
Dec 1 15:02:41 uter postfix/bounce[11366]: bounce_append_proto:
flags=0x0 service=bounce id=2BAE72974 org_to=ctgocept.com
to=ctheuneimap.whq.gocept.com off=355 stat=5.0.0 act=failed why=host
/var/imap/socket/lmtp[/var/imap/socket/lmtp] said: 250 2.1.0 ok (in
reply to DATA command)
Dec 1 15:02:41 uter postfix/bounce[11366]: send attr status = 0
Dec 1 15:02:41 uter postfix/bounce[11366]: master_notify: status 1
Dec 1 15:02:41 uter postfix/lmtp[11210]: input attribute name: status
Dec 1 15:02:41 uter postfix/lmtp[11210]: input attribute value: 0
Dec 1 15:02:41 uter postfix/bounce[11366]: connection closed
Dec 1 15:02:41 uter postfix/lmtp[11210]: private/bounce socket:
wanted attribute: (list terminator)
Dec 1 15:02:41 uter postfix/lmtp[11210]: input attribute name: (end)
Dec 1 15:02:41 uter postfix/lmtp[11210]: 2BAE72974:
to=<ctheuneimap.whq.gocept.com>, orig_to=<ctgocept.com>,
relay=/var/imap/socket/lmtp[/var/imap/socket/lmtp], delay=0,
status=bounced (host /var/imap/socket/lmtp[/var/imap/socket/lmtp]
said: 250 2.1.0 ok (in reply to DATA command))
Dec 1 15:02:41 uter postfix/bounce[11366]: connection established
Dec 1 15:02:41 uter postfix/lmtp[11210]: connect to subsystem private/bounce
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr nrequest = 0
Dec 1 15:02:41 uter postfix/bounce[11366]: master_notify: status 0
Dec 1 15:02:41 uter postfix/bounce[11366]: bounce socket: wanted
attribute: nrequest
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr flags = 0
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr queue_id = 2BAE72974
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr original_recipient
= dhgocept.com
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr recipient =
niloimap.whq.gocept.com
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr offset = 399
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr status = 5.0.0
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr action = failed
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr reason = host
/var/imap/socket/lmtp[/var/imap/socket/lmtp] said: 250 2.1.0 ok (in
reply to DATA command)
Dec 1 15:02:41 uter postfix/lmtp[11210]: private/bounce socket:
wanted attribute: status
After that the same mail tries again on dhgocept.com (rewritten to
niloimap.whq.gocept.com) and fails again while talking to the lmtp:
Dec 1 15:02:41 uter postfix/bounce[11366]: bounce_append_proto:
flags=0x0 service=bounce id=2BAE72974 org_to=dhgocept.com
to=niloimap.whq.gocept.com off=399 stat=5.0.0 act=failed why=host
/var/imap/socket/lmtp[/var/imap/socket/lmtp] said: 250 2.1.0 ok (in
reply to DATA command)
Dec 1 15:02:41 uter postfix/bounce[11366]: send attr status = 0
Dec 1 15:02:41 uter postfix/bounce[11366]: master_notify: status 1
Dec 1 15:02:41 uter postfix/lmtp[11210]: input attribute name: status
Dec 1 15:02:41 uter postfix/lmtp[11210]: input attribute value: 0
Dec 1 15:02:41 uter postfix/bounce[11366]: connection closed
Dec 1 15:02:41 uter postfix/lmtp[11210]: private/bounce socket:
wanted attribute: (list terminator)
Dec 1 15:02:41 uter postfix/lmtp[11210]: input attribute name: (end)
Dec 1 15:02:41 uter postfix/lmtp[11210]: 2BAE72974:
to=<niloimap.whq.gocept.com>, orig_to=<dhgocept.com>,
relay=/var/imap/socket/lmtp[/var/imap/socket/lmtp], delay=0,
status=bounced (host /var/imap/socket/lmtp[/var/imap/socket/lmtp]
said: 250 2.1.0 ok (in reply to DATA command))
Dec 1 15:02:41 uter postfix/lmtp[11210]: >
/var/imap/socket/lmtp[/var/imap/socket/lmtp]: RSET
Dec 1 15:02:41 uter postfix/lmtp[11210]: <
/var/imap/socket/lmtp[/var/imap/socket/lmtp]: 250 2.1.5 ok
Dec 1 15:02:41 uter postfix/lmtp[11210]: name_mask: resource
Dec 1 15:02:41 uter postfix/lmtp[11210]: name_mask: software
Dec 1 15:02:41 uter postfix/lmtp[11210]: deliver_request_final: send: "" 0
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr reason =
Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr status = 0
On 12/1/05, Wietse Venema <wietseporcupine.org> wrote:
> It would still be worthwhile to find out if the last
> delivery was OK by the process with the failed RSET.
I hope this is enough information. I'm not sure, but it looks like the
mail before the RSET was broken already.
After switching off connection reuse everything works fine. I haven't
found another bounce with those errors in the last 15 hours.
Thanks,
Christian
- Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]