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

Re: timeout after DATA Error

Expand Messages
  • dogbert
    ... I believe that EOM stand for End Of Message and I hope that if Ethereal can understand is as part of an SMTP transaction it somehow comply with smtp
    Message 1 of 11 , Dec 1, 2005
    • 0 Attachment
      Wietse Venema wrote:
      > Wietse:
      >>> To diagnose the problem you will need to record a failed session
      >>> with, for example tcpdump. Record the full packet content:
      >>>
      >>> tcpdump -s 2000 -i interface -w /file/name
      >>>
      >>> There has been a recent flurry of "timeout after DATA" problems
      >>> with MS Exchange 5 because it was sending mail that did not end in
      >>> "<CR><LF>.<CR><LF>".
      >
      > dogbert:
      >> I've analyzed some sessions with Ethereal and found that the main difference
      >> between a working mail (that pass through postifx) and a bad message (that
      >> stuck) is that the latter doesn't terminate with a \r\n.\r\n but with a packet
      >> of EOM (if I decode with ethereal the full SMTP transmission it contain the last
      >> . for ending the session but it is not present in the MESSAGE BODY part of the
      >> session).
      >
      > What is EOM?
      >
      > Can I see the data that is actually sent? I hate it when helpful
      > software changes the evidence.
      >
      > If the mail does not end in "<CR><LF>.<CR><LF>" then it does
      > not comply with the SMTP protocol, and all bets are off.
      >
      > Wietse
      >

      I believe that EOM stand for End Of Message and I hope that if Ethereal can
      understand is as part of an SMTP transaction it somehow comply with smtp standard.

      Here is what Ethereal decode of the transaction:
      ------------------------------------------------
      220 mailfilter.testdomain.it

      EHLO mail1.testdomain.it

      250-mailfilter.testdomain.it
      250-SIZE 1000000000
      250-VRFY
      250-ETRN
      250 8BITMIME

      MAIL FROM: <dogbert@...> SIZE=757

      250 Ok

      RCPT TO: <riccardo.fontana@...>

      250 Ok

      DATA

      354 End data with <CR><LF>.<CR><LF>

      X-SEF-Processed: 5_0_0_713__2005_12_01_17_01_52
      X-SEF-AE0723B2-1DB9-4A10-B06E-C6DC66A014F9: 1
      Received: from Unknown [172.28.253.1] by mail1.testdomain.it - SurfControl
      E-mail Filter (5.0); gio, 01 dic 2005 17:01:52 +0100
      Message-ID: <438F1E70.1060608@...>
      Date: Thu, 01 Dec 2005 17:01:52 +0100
      From: dogbert <dogbert@...>
      User-Agent: Thunderbird 1.5 (Windows/20051025)
      MIME-Version: 1.0
      To: riccardo.fontana@...
      Subject: test message
      Content-Type: text/plain; charset=ISO-8859-1; format=flowed
      Content-Transfer-Encoding: 7bit

      this is a test message.

      .

      ------------------------------------------------
      the last dot is the <CR><LF>.<CR><LF> but I'm going to make a tcpdump of the
      session if you prefer it as it is (without decoding).
    • Wietse Venema
      dogbert: [ Charset ISO-8859-1 unsupported, converting... ] ... If the text does not end on . then it does not comply with SMTP. Can I have a
      Message 2 of 11 , Dec 1, 2005
      • 0 Attachment
        dogbert:
        [ Charset ISO-8859-1 unsupported, converting... ]
        > Wietse Venema wrote:
        > > Wietse:
        > >>> To diagnose the problem you will need to record a failed session
        > >>> with, for example tcpdump. Record the full packet content:
        > >>>
        > >>> tcpdump -s 2000 -i interface -w /file/name
        > >>>
        > >>> There has been a recent flurry of "timeout after DATA" problems
        > >>> with MS Exchange 5 because it was sending mail that did not end in
        > >>> "<CR><LF>.<CR><LF>".
        > >
        > > dogbert:
        > >> I've analyzed some sessions with Ethereal and found that the main difference
        > >> between a working mail (that pass through postifx) and a bad message (that
        > >> stuck) is that the latter doesn't terminate with a \r\n.\r\n but with a packet
        > >> of EOM (if I decode with ethereal the full SMTP transmission it contain the last
        > >> . for ending the session but it is not present in the MESSAGE BODY part of the
        > >> session).
        > >
        > > What is EOM?
        > >
        > > Can I see the data that is actually sent? I hate it when helpful
        > > software changes the evidence.
        > >
        > > If the mail does not end in "<CR><LF>.<CR><LF>" then it does
        > > not comply with the SMTP protocol, and all bets are off.
        > >
        > > Wietse
        > >
        >
        > I believe that EOM stand for End Of Message and I hope that if Ethereal can
        > understand is as part of an SMTP transaction it somehow comply with smtp standard.

        If the text does not end on "<CR><LF>.<CR><LF>" then it does not
        comply with SMTP.

        Can I have a copy of the UNENCODED recording of a session that
        fails with "timeout after DATA".

        Can I have a copy of the logging that corresponds to that failed
        delivery.

        Wietse
      • Wietse Venema
        ... The time stamps in the recording are 14 minutes 8 seconds after the hour, and the logging is 15 minutes 36 seconds, but it does not matter. This recording
        Message 3 of 11 , Dec 2, 2005
        • 0 Attachment
          dogbert:
          > > If the text does not end on "<CR><LF>.<CR><LF>" then it does not
          > > comply with SMTP.
          > >
          > > Can I have a copy of the UNENCODED recording of a session that
          > > fails with "timeout after DATA".
          > >
          > > Can I have a copy of the logging that corresponds to that failed
          > > delivery.
          > >
          > > Wietse
          >
          > I've used tcpdump to gather a plain binary snapshot of the tcpip session. You
          > will find it attached to this e-mail.
          >
          > Here is the corresponding log of the transaction:

          The time stamps in the recording are 14 minutes 8 seconds after
          the hour, and the logging is 15 minutes 36 seconds, but it does
          not matter. This recording shows all the symptoms that I needed.

          > Dec 2 08:15:36 derlnx-antispam postfix/smtpd[28439]: connect from
          > dddddddddddd.dddddd.aaa-aaa.it[192.168.40.33]
          > Dec 2 08:15:36 derlnx-antispam postfix/smtpd[28439]: discarding EHLO keywords:
          > PIPELINING
          > Dec 2 08:15:36 derlnx-antispam postfix/smtpd[28439]: AB5E038003:
          > client=dddddddddddd.dddddd.aaa-aaa.it[192.168.40.33]
          > Dec 2 08:20:36 derlnx-antispam postfix/smtpd[28439]: timeout after DATA from
          > dddddddddddd.dddddd.aaa-aaa.it[192.168.40.33]
          > Dec 2 08:20:36 derlnx-antispam postfix/smtpd[28439]: disconnect from
          > dddddddddddd.dddddd.aaa-aaa.it[192.168.40.33]
          >
          > If the problem is the total absence of "<CR><LF>.<CR><LF>" how can I resolve it
          > ? I don't like the solution "Don't use postfix". I'd like to understand if this
          > problem is a common issue also with mail server from internet or if it's limited
          > to a few servers.

          SMTP mail must end in "<CR><LF>.<CR><LF>".

          If it does not, all SMTP servers will have problems, not just Postfix.

          Running ethereal on your file shows your claim about EOM is inaccurate.

          ethereal sees no end of message, because no "<CR><LF>.<CR><LF>" was sent.

          Wietse

          1 11:14:08.407158 192.168.40.33 -> 192.168.40.34 TCP 2447 > smtp [SYN] Seq=0 Ack=0 Win=64240 Len=0 MSS=1460
          2 11:14:08.407304 192.168.40.34 -> 192.168.40.33 TCP smtp > 2447 [SYN, ACK] Seq=0 Ack=1 Win=5840 Len=0 MSS=1460
          3 11:14:08.407503 192.168.40.33 -> 192.168.40.34 TCP 2447 > smtp [ACK] Seq=1 Ack=1 Win=64240 Len=0
          4 11:14:08.419630 192.168.40.34 -> 192.168.40.33 SMTP Response: 220 mailfilter.aaaaaaa.it
          5 11:14:08.421914 192.168.40.33 -> 192.168.40.34 SMTP Command: EHLO mail1.aaaaaaa.it
          6 11:14:08.421957 192.168.40.34 -> 192.168.40.33 TCP smtp > 2447 [ACK] Seq=28 Ack=24 Win=5840 Len=0
          7 11:14:08.422363 192.168.40.34 -> 192.168.40.33 SMTP Response: 250-derlnx-antispam.dddddd.aaa-aaa.it
          8 11:14:08.425494 192.168.40.33 -> 192.168.40.34 SMTP Command: MAIL FROM: <ddddddd@...> SIZE=753
          9 11:14:08.426345 192.168.40.34 -> 192.168.40.33 SMTP Response: 250 Ok
          10 11:14:08.427694 192.168.40.33 -> 192.168.40.34 SMTP Command: RCPT TO: <rrrrrrrr.fffffff@...>
          11 11:14:08.438597 192.168.40.34 -> 192.168.40.33 SMTP Response: 250 Ok
          12 11:14:08.440710 192.168.40.33 -> 192.168.40.34 SMTP Command: DATA
          13 11:14:08.440949 192.168.40.34 -> 192.168.40.33 SMTP Response: 354 End data with <CR><LF>.<CR><LF>
          14 11:14:08.441396 192.168.40.33 -> 192.168.40.34 SMTP Message Body
          15 11:14:08.478940 192.168.40.34 -> 192.168.40.33 TCP smtp > 2447 [ACK] Seq=175 Ack=697 Win=6996 Len=0

          Note that ethereal reports no EOM, because there is no <CR><LF>.<CR><LF>.
        • dogbert
          ... Only because I took a different log track, I was unable to find the original one and eventually every log reported the same errors. ... Actually the first
          Message 4 of 11 , Dec 2, 2005
          • 0 Attachment
            Wietse Venema wrote:
            > dogbert:
            >>> If the text does not end on "<CR><LF>.<CR><LF>" then it does not
            >>> comply with SMTP.
            >>>
            >>> Can I have a copy of the UNENCODED recording of a session that
            >>> fails with "timeout after DATA".
            >>>
            >>> Can I have a copy of the logging that corresponds to that failed
            >>> delivery.
            >>>
            >>> Wietse
            >> I've used tcpdump to gather a plain binary snapshot of the tcpip session. You
            >> will find it attached to this e-mail.
            >>
            >> Here is the corresponding log of the transaction:
            >
            > The time stamps in the recording are 14 minutes 8 seconds after
            > the hour, and the logging is 15 minutes 36 seconds, but it does
            > not matter. This recording shows all the symptoms that I needed.
            >

            Only because I took a different log track, I was unable to find the original one
            and eventually every log reported the same errors.

            >> Dec 2 08:15:36 derlnx-antispam postfix/smtpd[28439]: connect from
            >> dddddddddddd.dddddd.aaa-aaa.it[192.168.40.33]
            >> Dec 2 08:15:36 derlnx-antispam postfix/smtpd[28439]: discarding EHLO keywords:
            >> PIPELINING
            >> Dec 2 08:15:36 derlnx-antispam postfix/smtpd[28439]: AB5E038003:
            >> client=dddddddddddd.dddddd.aaa-aaa.it[192.168.40.33]
            >> Dec 2 08:20:36 derlnx-antispam postfix/smtpd[28439]: timeout after DATA from
            >> dddddddddddd.dddddd.aaa-aaa.it[192.168.40.33]
            >> Dec 2 08:20:36 derlnx-antispam postfix/smtpd[28439]: disconnect from
            >> dddddddddddd.dddddd.aaa-aaa.it[192.168.40.33]
            >>
            >> If the problem is the total absence of "<CR><LF>.<CR><LF>" how can I resolve it
            >> ? I don't like the solution "Don't use postfix". I'd like to understand if this
            >> problem is a common issue also with mail server from internet or if it's limited
            >> to a few servers.
            >
            > SMTP mail must end in "<CR><LF>.<CR><LF>".
            >
            > If it does not, all SMTP servers will have problems, not just Postfix.
            >

            Actually the first mail relay is working in my infrastructure and it's not
            giving me a lot of problems. Maybe oll of my mail servers accept a less strictly
            implementation of SMTP while Postfix stick to the RFC (it's not a bad thing).

            > Running ethereal on your file shows your claim about EOM is inaccurate.
            >
            > ethereal sees no end of message, because no "<CR><LF>.<CR><LF>" was sent.
            >
            > Wietse
            >
            > 1 11:14:08.407158 192.168.40.33 -> 192.168.40.34 TCP 2447 > smtp [SYN] Seq=0 Ack=0 Win=64240 Len=0 MSS=1460
            > 2 11:14:08.407304 192.168.40.34 -> 192.168.40.33 TCP smtp > 2447 [SYN, ACK] Seq=0 Ack=1 Win=5840 Len=0 MSS=1460
            > 3 11:14:08.407503 192.168.40.33 -> 192.168.40.34 TCP 2447 > smtp [ACK] Seq=1 Ack=1 Win=64240 Len=0
            > 4 11:14:08.419630 192.168.40.34 -> 192.168.40.33 SMTP Response: 220 mailfilter.aaaaaaa.it
            > 5 11:14:08.421914 192.168.40.33 -> 192.168.40.34 SMTP Command: EHLO mail1.aaaaaaa.it
            > 6 11:14:08.421957 192.168.40.34 -> 192.168.40.33 TCP smtp > 2447 [ACK] Seq=28 Ack=24 Win=5840 Len=0
            > 7 11:14:08.422363 192.168.40.34 -> 192.168.40.33 SMTP Response: 250-derlnx-antispam.dddddd.aaa-aaa.it
            > 8 11:14:08.425494 192.168.40.33 -> 192.168.40.34 SMTP Command: MAIL FROM: <ddddddd@...> SIZE=753
            > 9 11:14:08.426345 192.168.40.34 -> 192.168.40.33 SMTP Response: 250 Ok
            > 10 11:14:08.427694 192.168.40.33 -> 192.168.40.34 SMTP Command: RCPT TO: <rrrrrrrr.fffffff@...>
            > 11 11:14:08.438597 192.168.40.34 -> 192.168.40.33 SMTP Response: 250 Ok
            > 12 11:14:08.440710 192.168.40.33 -> 192.168.40.34 SMTP Command: DATA
            > 13 11:14:08.440949 192.168.40.34 -> 192.168.40.33 SMTP Response: 354 End data with <CR><LF>.<CR><LF>
            > 14 11:14:08.441396 192.168.40.33 -> 192.168.40.34 SMTP Message Body
            > 15 11:14:08.478940 192.168.40.34 -> 192.168.40.33 TCP smtp > 2447 [ACK] Seq=175 Ack=697 Win=6996 Len=0
            >
            > Note that ethereal reports no EOM, because there is no <CR><LF>.<CR><LF>.
            >

            I'm sending you another packet dump taken with ethereal from a third machine
            inside the network while the one I sent you last time is taken with tcpdump
            directly from the postfix server.
            Opening it with Ethereal I can see a packet marked EOM:.

            Regards,
            Riccardo
          • Wietse Venema
            ... SMTP mail must end in . . If you disagree, then I challenge you to provide the evidence in the form of a tcpdump recording. So far you have
            Message 5 of 11 , Dec 2, 2005
            • 0 Attachment
              dogbert:
              > >> If the problem is the total absence of "<CR><LF>.<CR><LF>" how can I resolve it
              > >> ? I don't like the solution "Don't use postfix". I'd like to understand if this
              > >> problem is a common issue also with mail server from internet or if it's limited
              > >> to a few servers.
              > >
              > > SMTP mail must end in "<CR><LF>.<CR><LF>".
              > >
              > > If it does not, all SMTP servers will have problems, not just Postfix.
              > >
              >
              > Actually the first mail relay is working in my infrastructure and it's not
              > giving me a lot of problems. Maybe oll of my mail servers accept a less strictly
              > implementation of SMTP while Postfix stick to the RFC (it's not a bad thing).

              SMTP mail must end in <CR><LF>.<CR><LF>.

              If you disagree, then I challenge you to provide the evidence in
              the form of a tcpdump recording.

              So far you have not provided a tcpdump recording that shows mail
              going through without <CR><LF>.<CR><LF> at the end, where the SMTP
              server recognizes the end of the message.

              > > Running ethereal on your file shows your claim about EOM is inaccurate.
              > >
              > > ethereal sees no end of message, because no "<CR><LF>.<CR><LF>" was sent.
              >
              > I'm sending you another packet dump taken with ethereal from a third machine
              > inside the network while the one I sent you last time is taken with tcpdump
              > directly from the postfix server.
              > Opening it with Ethereal I can see a packet marked EOM:.

              I challenge you to provide the evidence in the form of a tcpdump
              recording.

              So far you have not provided a tcpdump recording without
              <CR><LF>.<CR><LF> at the end, where ethereal recognizes EOM.

              Wietse
            • Wietse Venema
              Well there is your problem. The TCP segment with . is NEVER received by the KERNEL TCP/IP stack. When Postfix replies with 421 timeout
              Message 6 of 11 , Dec 2, 2005
              • 0 Attachment
                Well there is your problem. The TCP segment with <CR><LF>.<CR><LF>
                is NEVER received by the KERNEL TCP/IP stack.

                When Postfix replies with 421 timeout exceeded, the KERNEL TCP/IP
                stack sends an ACK for TCP offset 696. That is the offset BEFORE
                the <CR><LF>.<CR><LF>.

                Note that the KERNEL TCP/IP stack does not ACK for TCP offset 701,
                which would be AFTER the <CR><LF>.<CR><LF>.

                The KERNEL TCP/IP stack never receives the <CR><LF>.<CR><LF>,
                therefore the SMTP server never receives it, either.

                Wietse

                08:51:52.715646 192.168.40.33.3504 > 192.168.40.34.25: P 696:701(5) ack 191 win
                64050 (DF)

                IP_HDR=20 IP_OPT=0 TCP_HDR=20 TCP_OPT=0 DATA=5 FLAGS=PUSH ACK

                IP_HDR 45 00 00 2d 92 fd 40 00 80 06
                vhl tos len len id id off off ttl pro
                IP_HDR 96 39 c0 a8 28 21 c0 a8 28 22
                sum sum src src src src dst dst dst dst
                TCP_HDR 0d b0 00 19 3e d3 89 1c 9f ca
                src src dst dst seq seq seq seq ack ack
                TCP_HDR 01 83 50 18 fa 32 27 e3 00 00
                ack ack off flg win win sum sum urp urp
                DATA 0d 0a 2e 0d 0a
                ^M ^J . ^M ^J .....

                08:56:11.975483 192.168.40.34.25 > 192.168.40.33.3504: P 191:254(63) ack 696 win
                6984 (DF)

                IP_HDR=20 IP_OPT=0 TCP_HDR=20 TCP_OPT=0 DATA=63 FLAGS=PUSH ACK

                IP_HDR 45 00 00 67 b4 41 40 00 40 06
                vhl tos len len id id off off ttl pro
                IP_HDR b4 bb c0 a8 28 22 c0 a8 28 21
                sum sum src src src src dst dst dst dst
                TCP_HDR 00 19 0d b0 9f ca 01 83 3e d3
                src src dst dst seq seq seq seq ack ack
                TCP_HDR 89 1c 50 18 1b 48 52 55 00 00
                ack ack off flg win win sum sum urp urp
                DATA 34 32 31 20 64 65 72 6c 6e 78
                4 2 1 d e r l n x 421 derlnx
                DATA 2d 61 6e 74 69 73 70 61 6d 2e
                - a n t i s p a m . -antispam.
                DATA 64 65 72 75 74 61 2e 61 61 61
                d e r u t a . a a a deruta.aaa
                DATA 2d 67 61 6e 2e 69 74 20 45 72
                - g a n . i t E r -gan.it Er
                DATA 72 6f 72 3a 20 74 69 6d 65 6f
                r o r : t i m e o ror: timeo
                DATA 75 74 20 65 78 63 65 65 64 65
                u t e x c e e d e ut exceede
                DATA 64 0d 0a
                d ^M ^J d..
              • dogbert
                ... I don t want to fight for this problem. ;-) I m in accord with you that every mail transaction MUST end with a . string. As you have
                Message 7 of 11 , Dec 2, 2005
                • 0 Attachment
                  Wietse Venema wrote:
                  > dogbert:
                  >>>> If the problem is the total absence of "<CR><LF>.<CR><LF>" how can I resolve it
                  >>>> ? I don't like the solution "Don't use postfix". I'd like to understand if this
                  >>>> problem is a common issue also with mail server from internet or if it's limited
                  >>>> to a few servers.
                  >>> SMTP mail must end in "<CR><LF>.<CR><LF>".
                  >>>
                  >>> If it does not, all SMTP servers will have problems, not just Postfix.
                  >>>
                  >> Actually the first mail relay is working in my infrastructure and it's not
                  >> giving me a lot of problems. Maybe oll of my mail servers accept a less strictly
                  >> implementation of SMTP while Postfix stick to the RFC (it's not a bad thing).
                  >
                  > SMTP mail must end in <CR><LF>.<CR><LF>.
                  >
                  > If you disagree, then I challenge you to provide the evidence in
                  > the form of a tcpdump recording.
                  >
                  > So far you have not provided a tcpdump recording that shows mail
                  > going through without <CR><LF>.<CR><LF> at the end, where the SMTP
                  > server recognizes the end of the message.
                  >

                  I don't want to fight for this problem. ;-)
                  I'm in accord with you that every mail transaction MUST end with a
                  "<CR><LF>.<CR><LF>" string.
                  As you have analyzed in your other message it seems that there is a problem at
                  TCP Kernel level.

                  Now I'm trying to understand why the linux box lost that packet.

                  Thank for you help.

                  Riccardo
                • Wietse Venema
                  ... Maybe some filter rejects it as too small . The problem may even be on the sending box. Good luck. Wietse
                  Message 8 of 11 , Dec 2, 2005
                  • 0 Attachment
                    dogbert:
                    > As you have analyzed in your other message it seems that there is a problem at
                    > TCP Kernel level.
                    >
                    > Now I'm trying to understand why the linux box lost that packet.

                    Maybe some filter rejects it as "too small".

                    The problem may even be on the sending box.

                    Good luck.

                    Wietse
                  Your message has been successfully submitted and would be delivered to recipients shortly.