Loading ...
Sorry, an error occurred while loading the content.

Re: Weird bounces with Postfix, LMTP and Cyrus

Expand Messages
  • Wietse Venema
    Christian Theune: [ Charset ISO-8859-1 unsupported, converting... ] ... Cyrus is screwed up. Postfix sends a valid RESET command. ... Cyrus is screwed up. Same
    Message 1 of 17 , Dec 1, 2005
    • 0 Attachment
      Christian Theune:
      [ Charset ISO-8859-1 unsupported, converting... ]
      > Ok, I increased the log level and here is what I got for one of the
      > error messages:
      >
      > Dec 1 13:00:41 uter postfix/lmtp[4407]: deliver_message: from
      > zope-dev-bounces@...
      > Dec 1 13:00:41 uter postfix/lmtp[4407]: >
      > /var/imap/socket/lmtp[/var/imap/socket/lmtp]: RSET
      > Dec 1 13:00:41 uter postfix/lmtp[4407]: <
      > /var/imap/socket/lmtp[/var/imap/socket/lmtp]: 500 5.5.2 Syntax error
      > Dec 1 13:00:41 uter postfix/lmtp[4407]: deliver_message: reusing

      Cyrus is screwed up. Postfix sends a valid RESET command.

      > (count 3) session with: /var/imap/socket/lmtp
      > Dec 1 13:00:41 uter postfix/lmtp[4407]: >
      > /var/imap/socket/lmtp[/var/imap/socket/lmtp]: MAIL
      > FROM:<zope-dev-bounces@...> SIZE=4246
      > Dec 1 13:00:41 uter postfix/lmtp[4407]: <
      > /var/imap/socket/lmtp[/var/imap/socket/lmtp]: 500 5.5.2 Syntax error

      Cyrus is screwed up. Same reply as RSET.

      If Cyrus mis-handles something as simple as RSET, then all bets
      are off with more complex commands.

      You can turn off connection reuse with "lmtp_cache_connection = no".

      Wietse

      > I remember having found a posting somewhere that said, cyrus complains
      > about the SIZE=... parameter in the MAIL FROM ... I thought that was
      > solved already ...
      >
      >
    • Wietse Venema
      ... Surprise: the LMTP client reuses the session after 5xx error reply. The Postfix SMTP client would never do that. You can work around this with
      Message 2 of 17 , Dec 1, 2005
      • 0 Attachment
        Wietse Venema:
        > Christian Theune:
        > > Ok, I increased the log level and here is what I got for one of the
        > > error messages:
        > >
        > > Dec 1 13:00:41 uter postfix/lmtp[4407]: deliver_message: from
        > > zope-dev-bounces@...
        > > Dec 1 13:00:41 uter postfix/lmtp[4407]: >
        > > /var/imap/socket/lmtp[/var/imap/socket/lmtp]: RSET
        > > Dec 1 13:00:41 uter postfix/lmtp[4407]: <
        > > /var/imap/socket/lmtp[/var/imap/socket/lmtp]: 500 5.5.2 Syntax error
        > > Dec 1 13:00:41 uter postfix/lmtp[4407]: deliver_message: reusing
        >
        > Cyrus is screwed up. Postfix sends a valid RESET command.
        >
        > > (count 3) session with: /var/imap/socket/lmtp

        Surprise: the LMTP client reuses the session after 5xx error reply.
        The Postfix SMTP client would never do that.

        You can work around this with lmtp_cache_connection=no.

        > > Dec 1 13:00:41 uter postfix/lmtp[4407]: >
        > > /var/imap/socket/lmtp[/var/imap/socket/lmtp]: MAIL
        > > FROM:<zope-dev-bounces@...> SIZE=4246
        > > Dec 1 13:00:41 uter postfix/lmtp[4407]: <
        > > /var/imap/socket/lmtp[/var/imap/socket/lmtp]: 500 5.5.2 Syntax error
        >
        > Cyrus is screwed up. Same reply as RSET.

        Now, what may be happening here is that server and client have
        somehow gotten out of step.

        For example (I am not saying that this is the cause!), if Cyrus
        "detects" end-of-data too early it will spit out a gazillion "500
        5.5.2 Syntax error" responses for every line of email content that
        follows. Postfix won't flush the input buffers, and will read
        these replies as if they are replies to commands sent after the
        real end-of-data.

        The 2.3 Postfix has a "purge" primitive for streams that discards
        whatever is buffered in Postfix itself. This could be used to clear
        the input buffer before sending RSET. However, this primitive does
        not discard data that's still buffered in the kernel, and would
        have to be extended to handle that.

        But all this is academic. The LMTP client should not reuse the
        session after a 5XX reply. Worse it's not even my own bug.

        Wietse
      • Wietse Venema
        ... With the patch below, the Postfix LMTP client will not reuse a session after the RSET command gets a negative reply. There are versions for Postfix 2.2 and
        Message 3 of 17 , Dec 1, 2005
        • 0 Attachment
          Wietse Venema:
          > Wietse Venema:
          > > Christian Theune:
          > > > Ok, I increased the log level and here is what I got for one of the
          > > > error messages:
          > > >
          > > > Dec 1 13:00:41 uter postfix/lmtp[4407]: deliver_message: from
          > > > zope-dev-bounces@...
          > > > Dec 1 13:00:41 uter postfix/lmtp[4407]: >
          > > > /var/imap/socket/lmtp[/var/imap/socket/lmtp]: RSET
          > > > Dec 1 13:00:41 uter postfix/lmtp[4407]: <
          > > > /var/imap/socket/lmtp[/var/imap/socket/lmtp]: 500 5.5.2 Syntax error
          > > > Dec 1 13:00:41 uter postfix/lmtp[4407]: deliver_message: reusing
          > >
          > > Cyrus is screwed up. Postfix sends a valid RESET command.
          > >
          > > > (count 3) session with: /var/imap/socket/lmtp
          >
          > Surprise: the LMTP client reuses the session after 5xx error reply.
          > The Postfix SMTP client would never do that.
          >
          > You can work around this with lmtp_cache_connection=no.

          With the patch below, the Postfix LMTP client will not reuse
          a session after the RSET command gets a negative reply.
          There are versions for Postfix 2.2 and 2.3.

          It would still be interesting to learn if the delivery right before
          the above logfile fragment went well or not.

          Wietse
        • Christian Theune
          Ok. I think I was able to follow your excellent explanation. I ll switch off the connection re-use and cross my fingers for now... I hope the other bounces I
          Message 4 of 17 , Dec 1, 2005
          • 0 Attachment
            Ok. I think I was able to follow your excellent explanation. I'll
            switch off the connection re-use and cross my fingers for now... I
            hope the other bounces I saw have the same cause...

            Thanks,
            Christian
          • Wietse Venema
            ... It would still be worthwhile to find out if the last delivery was OK by the process with the failed RSET. Wietse
            Message 5 of 17 , Dec 1, 2005
            • 0 Attachment
              Christian Theune:
              > Ok. I think I was able to follow your excellent explanation. I'll
              > switch off the connection re-use and cross my fingers for now... I
              > hope the other bounces I saw have the same cause...

              It would still be worthwhile to find out if the last
              delivery was OK by the process with the failed RSET.

              Wietse
            • Christian Theune
              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
              Message 6 of 17 , Dec 1, 2005
              • 0 Attachment
                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-admin@...
                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-admin@...> SIZE=6620
                Dec 1 15:02:41 uter postfix/lmtp[11210]: >
                /var/imap/socket/lmtp[/var/imap/socket/lmtp]: RCPT
                TO:<ctheune@...>
                Dec 1 15:02:41 uter postfix/lmtp[11210]: >
                /var/imap/socket/lmtp[/var/imap/socket/lmtp]: RCPT
                TO:<nilo@...>
                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
                = ct@...
                Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr recipient =
                ctheune@...
                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=ct@...
                to=ctheune@... 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=<ctheune@...>, orig_to=<ct@...>,
                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
                = dh@...
                Dec 1 15:02:41 uter postfix/lmtp[11210]: send attr recipient =
                nilo@...
                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 dh@... (rewritten to
                nilo@...) 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=dh@...
                to=nilo@... 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=<nilo@...>, orig_to=<dh@...>,
                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 <wietse@...> 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
              • Victor Duchovni
                ... Please also show what happens before this! We are already out of sync at this point. Show all the logs for process 11210 changing only the sender and
                Message 7 of 17 , Dec 1, 2005
                • 0 Attachment
                  On Fri, Dec 02, 2005 at 07:22:16AM +0100, Christian Theune wrote:

                  > 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-admin@...
                  > 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-admin@...> SIZE=6620
                  > Dec 1 15:02:41 uter postfix/lmtp[11210]: >
                  > /var/imap/socket/lmtp[/var/imap/socket/lmtp]: RCPT
                  > TO:<ctheune@...>
                  > Dec 1 15:02:41 uter postfix/lmtp[11210]: >
                  > /var/imap/socket/lmtp[/var/imap/socket/lmtp]: RCPT
                  > TO:<nilo@...>
                  > 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

                  Please also show what happens before this! We are already out of sync
                  at this point. Show all the logs for process 11210 changing only the
                  sender and recipient addresses if you want to protect their identities.
                  The specific addresses don't matter in this context

                  --
                  Viktor.

                  Disclaimer: off-list followups get on-list replies or get ignored.
                  Please do not ignore the "Reply-To" header.

                  To unsubscribe from the postfix-users list, visit
                  http://www.postfix.org/lists.html or click the link below:
                  <mailto:majordomo@...?body=unsubscribe%20postfix-users>

                  If my response solves your problem, the best way to thank me is to not
                  send an "it worked, thanks" follow-up. If you must respond, please put
                  "It worked, thanks" in the "Subject" so I can delete these quickly.
                • Christian Theune
                  Damn. That log file was too large. Anyway, I posted an excerpt here: http://amy.gocept.com/~ctheune/postfix.log
                  Message 8 of 17 , Dec 1, 2005
                  • 0 Attachment
                    Damn. That log file was too large. Anyway, I posted an excerpt here:

                    http://amy.gocept.com/~ctheune/postfix.log

                    On 12/2/05, Christian Theune <theuni@...> wrote:
                    > Oh, ok. I'm sorry. You find a larger snippet as an attachment.
                    >
                    > I grepped the log for process 11210 only, I hope this is enough.
                  • Victor Duchovni
                    ... Super! 14:59:32 LHLO uter.whq.gocept.com 14:59:32
                    Message 9 of 17 , Dec 2, 2005
                    • 0 Attachment
                      On Fri, Dec 02, 2005 at 08:02:45AM +0100, Christian Theune wrote:

                      > Damn. That log file was too large. Anyway, I posted an excerpt here:
                      >
                      > http://amy.gocept.com/~ctheune/postfix.log
                      >

                      Super!

                      14:59:32 < 220 uter LMTP Cyrus v2.2.12-Gentoo ready
                      14:59:32 > LHLO uter.whq.gocept.com
                      14:59:32 < 250-uter
                      14:59:32 < 250-8BITMIME
                      14:59:32 < 250-ENHANCEDSTATUSCODES
                      14:59:32 < 250-PIPELINING
                      14:59:32 < 250-SIZE
                      14:59:32 < 250-AUTH EXTERNAL
                      14:59:32 < 250 IGNOREQUOTA
                      14:59:32 > MAIL FROM:<root@...> SIZE=4594
                      14:59:32 > RCPT TO:<zagy+ptd@...>
                      14:59:32 > DATA
                      14:59:32 < 250 2.1.0 ok
                      14:59:32 < 250 2.1.5 ok
                      14:59:32 < 354 go ahead
                      14:59:32 > .
                      14:59:32 < 250 2.1.5 Ok

                      So far so good.

                      15:00:02 > RSET
                      15:00:02 < 250 2.0.0 ok
                      15:00:02 > MAIL FROM:<amavis@...> SIZE=570
                      15:00:02 > RCPT TO:<ctheune@...>
                      15:00:02 > DATA
                      15:00:02 < 250 2.1.0 ok
                      15:00:02 < 250 2.1.5 ok
                      15:00:02 < 354 go ahead
                      15:00:02 > .
                      15:00:02 < 250 2.1.5 Ok

                      This one also.

                      15:00:02 > RSET
                      15:00:02 < 250 2.0.0 ok
                      15:00:02 > MAIL FROM:<ct@...> SIZE=4064
                      15:00:02 > RCPT TO:<ctheune@...>
                      15:00:02 > DATA
                      15:00:02 < 250 2.1.0 ok
                      15:00:02 < 250 2.1.5 ok
                      15:00:02 < 354 go ahead
                      15:00:02 > .
                      15:00:02 < 250 2.1.5 Ok

                      And this.

                      15:00:08 > RSET
                      15:00:08 < 250 2.0.0 ok
                      15:00:08 > MAIL FROM:<nilo@...> SIZE=1274
                      15:00:08 > RCPT TO:<nilo@...>
                      15:00:08 > DATA
                      15:00:08 < 250 2.1.0 ok
                      15:00:08 < 250 2.1.5 ok
                      15:00:08 < 354 go ahead
                      15:00:08 > .
                      15:00:08 < 250 2.1.5 Ok

                      And this is fine too! But from below all hell breaks loose:

                      15:01:10 > RSET
                      15:01:10 < 500 5.5.2 Syntax error

                      WTF? There is no reason to complain about this RSET. It looks
                      as though the LMTP server saw something sent before RSET, even
                      though Postfix did not send anything between "." and RSET.

                      Only two possibilities:

                      1. The LMTP server saw end-of-body prematurely and responded to
                      the last three lines of the body as invalid SMTP commands.

                      2. There is a bug in the I/O chain from Postfix to the LMTP
                      server (Postfix buffering, kernel socket I/O or LMTP server
                      buffering) that caused double writes or double reads of
                      previous data.

                      It would be very interesting to see the last 5 lines of body
                      content from the above message from <nilo@...> SIZE=1274 to
                      <nilo@...>. How big is the received message (counting line
                      breaks as two bytes for <CRLF> and not counting any Received header added
                      by the LMTP server). Does the message appear to end abruptly? Is there
                      a problem with the "." stuffing (transparency) in the LMTP server or
                      the Postfix LMTP client?

                      15:01:10 > MAIL FROM:<back@...> SIZE=13831
                      15:01:10 < 500 5.5.2 Syntax error
                      15:01:10 > RSET
                      15:01:10 < 500 5.5.2 Syntax error

                      Two more invalid commands Postfix did not send are being responded to out
                      of sequence. This transaction fails and Postfix aborts it with an RSET,
                      which is again rejected, though we are well out of sync and the game
                      is lost. So there are three phantom invalid SMTP commands before RSET.

                      15:02:41 > RSET
                      15:02:41 < 250 2.0.0 ok

                      A false glimmer of hope, but this 2.0.0 is really a response for the
                      first of the two RSET commands above.

                      15:02:41 > MAIL FROM:<plone-users-admin@...> SIZE=6620
                      15:02:41 > RCPT TO:<ctheune@...>
                      15:02:41 > RCPT TO:<nilo@...>
                      15:02:41 > DATA
                      15:02:41 < 250 2.1.0 ok

                      This is for the previously rejected (500 5.5.2) MAIL FROM.

                      15:02:41 < 250 2.0.0 ok

                      This is for the RSET that followed it.

                      15:02:41 < 250 2.0.0 ok

                      This is for the RSET that started this delivery.

                      15:02:41 < 250 2.1.0 ok

                      This is for the current "MAIL FROM:". The LMTP server saw 3 extra
                      commands that Postfix did not send. From here on the game is lost.

                      15:02:41 > RSET
                      15:02:41 < 250 2.1.5 ok
                      15:03:38 > RSET
                      15:03:38 < 250 2.1.5 ok
                      15:03:38 > MAIL FROM:<zope-bounces@...> SIZE=4333
                      15:03:38 < 354 go ahead
                      15:03:38 > RSET

                      There is really no point in Postfix even trying...

                      --
                      Viktor.

                      Disclaimer: off-list followups get on-list replies or get ignored.
                      Please do not ignore the "Reply-To" header.

                      To unsubscribe from the postfix-users list, visit
                      http://www.postfix.org/lists.html or click the link below:
                      <mailto:majordomo@...?body=unsubscribe%20postfix-users>

                      If my response solves your problem, the best way to thank me is to not
                      send an "it worked, thanks" follow-up. If you must respond, please put
                      "It worked, thanks" in the "Subject" so I can delete these quickly.
                    Your message has been successfully submitted and would be delivered to recipients shortly.