ORC Owl Logo 2  

Owl River Company

 
  Your IP is: 54.81.174.180

Up More Tips

SMTP packet dumping and analysis outline

http://www.owlriver.com/tips/trace-sendmail/


  Disclaimer: Electronic mail is a 'best efforts' content delivery mechanism. It is not a mechanism with guarantee of delivery; guarantee of 'in order' delivery; nor guarantee of timely delivery. Many people have come to think of email as such, but this is not part of the design specification. If a customer thinks they need any of those attributes, contact us for a system design to meet stated needs.
 



Tracking down a failing email connection is tricky. There is an elaborate specification in the RFC's - also here. A brief retrospective and history about the RFC process itself is set out here (new window).

Briefly, compliance with the elaborate RFC specifications permits software from heterogeneous vendors to inter-operate. The transfer may not be as fast as some proprietary sub-set or partially specified vendor internal approach, but it will always permit protocol conformant products to inter-operate.

We have had recent issues with mail delivery from some small market share SMTP products. They connect, but hand us no email content, leaving logfile messages like this in our mail transfer log files:

Aug 26 11:00:03 compaq2 sendmail[14200]: NOQUEUE: dhcp9591xxx.columbus.rr.com [24.95.91.xxx] did not issue MAIL/EXPN/VRFY/ETRN during connection to MTA

[an MTA is a Mail Transfer Agent -- a superset of electronic mail handlers which includes hosts which implement the SMTP - Simple Mail Transfer Protocol]. This particular message is harmless -- it was a copy of Microsoft Outlook attempting to hand SMTP outbound email directly to the same host which handles its POP service. Outlook was seeking to act as a SMTP sender.

But sometimes the email is NOT going through. This one:

Aug 26 11:05:15 compaq2 sendmail[5360]: g7QF3MW05360: lost input channel from outbox.attcanada.ca [207.245.244.xxx] to MTA after rcpt

is less harmless. [note: 'rcpt' is an RFC 2821 command, stating that the remote MTA has identified a person to whom it proposes to hand content, once it has been told to 'go ahead' and do so by the receiving MTA] The implementation of the remote SMTP sender is broken, in that it did not offer content to our inbound mailserver after starting a 'conversation' indicating its intent to do so. When it fails to do so, our MTA logs this error message for help in identifying servers which are having problems.

Let's see what the remote SMTP sender is:

[root@compaq2 log]# telnet 207.245.244.xxx 25 Trying 207.245.244.xxx... Connected to 207.245.244.xxx. Escape character is '^]'. 220 outbox.attcanada.ca - AT&T Canada ESMTP service starting HELO asdf 250 outbox.attcanada.ca HELP 502 Error: command not implemented QUIT 221 Bye Connection closed by foreign host. [root@compaq2 log]#
Not much help there. The server 'outbox.attcanada.ca' is compliant with RFC 2821, section 3.1, but just barely so. That section provides:

3.1 Session Initiation An SMTP session is initiated when a client opens a connection to a server and the server responds with an opening message. SMTP server implementations MAY include identification of their software and version information in the connection greeting reply after the 220 code, a practice that permits more efficient isolation and repair of any problems. Implementations MAY make provision for SMTP servers to disable the software and version announcement where it causes security concerns. ...
The administrators of that server have chosen to provide less debugging information and not to foster "efficient isolation and repair of any problems" by allowing determination of their software version. That is their right and their decision, on their side of the 'demarc' -- the point of protocol demarcation.

About all that can be done by us to address the matter under the RFC is to send an email outlining the issue, to the postmaster account (required under RFC 2821, section 4.5.1 Minimum Implementation:

... Any system that includes an SMTP server supporting mail relaying or delivery MUST support the reserved mailbox "postmaster" as a case- insensitive local name. ...
and hope they are interested in fixing it. It is, after all, their issue to address.

As a side note, we most commonly find that non-compliant MTA's are not waiting for the proper 'go-ahead' in the protocol conversation under RFC 2821, section 4.2.1 multi-line replies, which we set out in full here toward the bottom of the outline. Basically the remote sender has to wait until it receives a 3 digit numeric response code followed by a SPace or CRLF sequence. In the case at hand, our MTA has received the following:

RCPT TO: {whowever@domain.com} 250 2.1.5 whomever@domain.com ... Recipient ok DATA 354 Enter mail, end with "." on a line by itself When it does not wait for <SP> or <CRLF> segment (here: 250 2.1.5 ...) before sending its DATA command, it has spoken out of turn, and not conformed to the protocol. RFC 2821 permits up to 5 minutes here:

4.5.3.2 Timeouts An SMTP client MUST provide a timeout mechanism. It MUST use per- command timeouts rather than somehow trying to time the entire mail transaction. ... Based on extensive experience with busy mail-relay hosts, the minimum per-command timeout values SHOULD be as follows: ... RCPT Command: 5 minutes A longer timeout is required if processing of mailing lists and aliases is not deferred until after the message was accepted.


So what else can the local sysadmin do...

Another approach to rule out local misconfigurations, is to locally trace the SMTP mail exchange conversation under RFC 2921, to determine where it is falling apart. This requires having a host with packet sniffing and dumping capability on a network segment which must be transited during the exchange of packets between the remote and local MTA's.

Locally tracing an SMTP conversation at the protocol level, to determine where it is falling apart is not a task for the timid, but it is not beyond understanding, either.

RFC 2821 gives the script for the session; tcpdump provides one tool to listen in on the conversation. For very detailed examination of protocol compliance, a relatively unknown tool, tcpflow (local copy) is quite good.

The tcpdump options are described in the man page; here we use:
  • -nn Do no host IP or protocol number to name expansion
  • -x Dump in hex format
  • -X Dump in ASCII format as well
  • -s 96 Show a window of the first 96 characters of each packet
  • We listen on the local host port 25, which is the inbound SMTP port, and for a connection to or from a remote host at 206.21.174.5



    Receiving SMTP server side

    [root@bo mail]# tcpdump -nn -x -X -s 96 port 25 and host 206.21.174.5 tcpdump: listening on eth0 10:08:14.025667 206.21.174.5.41028 > 198.30.168.13.25: S 889061662:889061662(0) win 5840 (DF) [tos 0x10] 0x0000 4510 003c e659 4000 3b06 6f0b ce15 ae05 E..<.Y@.;.o..... 0x0010 c61e a80d a044 0019 34fe 011e 0000 0000 .....D..4....... 0x0020 a002 16d0 83b1 0000 0204 05b4 0402 080a ................ 0x0030 057d e747 0000 0000 0103 0300 .}.G........ 10:08:14.025667 198.30.168.13.25 > 206.21.174.5.41028: S 862143247:862143247(0) ack 889061663 win 5792 (DF) 0x0000 4500 003c 0000 4000 4006 5075 c61e a80d E..<..@.@.Pu.... 0x0010 ce15 ae05 0019 a044 3363 430f 34fe 011f .......D3cC.4... 0x0020 a012 16a0 034e 0000 0204 05b4 0402 080a .....N.......... 0x0030 1901 f10e 057d e747 0103 0300 .....}.G.... 10:08:14.025667 198.30.168.13.25 > 206.21.174.5.41028: S 862143247:862143247(0) ack 889061663 win 5792 (DF) 0x0000 4500 003c 0000 4000 3f06 5175 c61e a80d E..<..@.?.Qu.... 0x0010 ce15 ae05 0019 a044 3363 430f 34fe 011f .......D3cC.4... 0x0020 a012 16a0 034e 0000 0204 05b4 0402 080a .....N.......... 0x0030 1901 f10e 057d e747 0103 0300 .....}.G.... 10:08:14.035672 206.21.174.5.41028 > 198.30.168.13.25: . ack 1 win 5840 (DF) [tos 0x10] 0x0000 4510 0034 e65a 4000 3b06 6f12 ce15 ae05 E..4.Z@.;.o..... 0x0010 c61e a80d a044 0019 34fe 011f 3363 4310 .....D..4...3cC. 0x0020 8010 16d0 31e2 0000 0101 080a 057d e748 ....1........}.H 0x0030 1901 f10e .... 10:08:14.155732 198.30.168.13.25 > 206.21.174.5.41028: . 1:1449(1448) ack 1 win 5792 (DF) 0x0000 4500 05dc b21f 4000 4006 98b5 c61e a80d E.....@.@....... 0x0010 ce15 ae05 0019 a044 3363 4310 34fe 011f .......D3cC.4... 0x0020 8010 16a0 e9b4 0000 0101 080a 1901 f11b ................ 0x0030 057d e748 3232 302d 626f 2e65 706f 6869 .}.H220-bo.epohi 0x0040 2e63 6f6d 2045 534d 5450 2052 424c 2054 .com.ESMTP.RBL.T 0x0050 6573 es 10:08:14.155732 198.30.168.13.25 > 206.21.174.5.41028: P 1449:1858(409) ack 1 win 5792 (DF) 0x0000 4500 01cd b220 4000 4006 9cc3 c61e a80d E.....@.@....... 0x0010 ce15 ae05 0019 a044 3363 48b8 34fe 011f .......D3cH.4... 0x0020 8018 16a0 dedc 0000 0101 080a 1901 f11b ................ 0x0030 057d e748 2020 5365 6e64 696e 6720 666f .}.H..Sending.fo 0x0040 7267 6564 2065 6d61 696c 206d 6179 2063 rged.email.may.c 0x0050 6f6e on 10:08:14.185747 206.21.174.5.41028 > 198.30.168.13.25: . ack 1449 win 8688 (DF) [tos 0x10] 0x0000 4510 0034 e65b 4000 3b06 6f11 ce15 ae05 E..4.[@.;.o..... 0x0010 c61e a80d a044 0019 34fe 011f 3363 48b8 .....D..4...3cH. 0x0020 8010 21f0 20fe 0000 0101 080a 057d e757 ..!..........}.W 0x0030 1901 f11b .... 10:08:14.185747 206.21.174.5.41028 > 198.30.168.13.25: . ack 1858 win 11584 (DF) [tos 0x10] 0x0000 4510 0034 e65c 4000 3b06 6f10 ce15 ae05 E..4.\@.;.o..... 0x0010 c61e a80d a044 0019 34fe 011f 3363 4a51 .....D..4...3cJQ 0x0020 8010 2d40 1415 0000 0101 080a 057d e757 ..-@.........}.W 0x0030 1901 f11b .... 10:08:37.977637 206.21.174.5.41028 > 198.30.168.13.25: P 1:12(11) ack 1858 win 11584 (DF) [tos 0x10] 0x0000 4510 003f e65d 4000 3b06 6f04 ce15 ae05 E..?.]@.;.o..... 0x0010 c61e a80d a044 0019 34fe 011f 3363 4a51 .....D..4...3cJQ 0x0020 8018 2d40 7949 0000 0101 080a 057d f0a1 ..-@yI.......}.. 0x0030 1901 f11b 454c 484f 2061 7364 660d 0a ....ELHO.asdf.. 10:08:37.977637 198.30.168.13.25 > 206.21.174.5.41028: . ack 12 win 5792 (DF) 0x0000 4500 0034 b221 4000 4006 9e5b c61e a80d E..4.!@.@..[.... 0x0010 ce15 ae05 0019 a044 3363 4a51 34fe 012a .......D3cJQ4..* 0x0020 8010 16a0 1813 0000 0101 080a 1901 fa68 ...............h 0x0030 057d f0a1 .}.. 10:08:37.977637 198.30.168.13.25 > 206.21.174.5.41028: P 1858:1903(45) ack 12 win 5792 (DF) 0x0000 4500 0061 b222 4000 4006 9e2d c61e a80d E..a."@.@..-.... 0x0010 ce15 ae05 0019 a044 3363 4a51 34fe 012a .......D3cJQ4..* 0x0020 8018 16a0 3560 0000 0101 080a 1901 fa68 ....5.........h 0x0030 057d f0a1 3530 3020 352e 352e 3120 436f .}..500.5.5.1.Co 0x0040 6d6d 616e 6420 756e 7265 636f 676e 697a mmand.unrecogniz 0x0050 6564 ed 10:08:37.997647 206.21.174.5.41028 > 198.30.168.13.25: . ack 1903 win 11584 (DF) [tos 0x10] 0x0000 4510 0034 e65e 4000 3b06 6f0e ce15 ae05 E..4.^@.;.o..... 0x0010 c61e a80d a044 0019 34fe 012a 3363 4a7e .....D..4..*3cJ~ 0x0020 8010 2d40 0144 0000 0101 080a 057d f0a3 ..-@.D.......}.. 0x0030 1901 fa68 ...h 10:08:45.551422 206.21.174.5.41028 > 198.30.168.13.25: P 12:23(11) ack 1903 win 11584 (DF) [tos 0x10] 0x0000 4510 003f e65f 4000 3b06 6f02 ce15 ae05 E..?._@.;.o..... 0x0010 c61e a80d a044 0019 34fe 012a 3363 4a7e .....D..4..*3cJ~ 0x0020 8018 2d40 68d4 0000 0101 080a 057d f395 ..-@h........}.. 0x0030 1901 fa68 4548 4c4f 2061 7364 660d 0a ...hEHLO.asdf.. 10:08:45.551422 198.30.168.13.25 > 206.21.174.5.41028: P 1903:2116(213) ack 23 win 5792 (DF) 0x0000 4500 0109 b223 4000 4006 9d84 c61e a80d E....#@.@....... 0x0010 ce15 ae05 0019 a044 3363 4a7e 34fe 0135 .......D3cJ~4..5 0x0020 8018 16a0 e096 0000 0101 080a 1901 fd5d ...............] 0x0030 057d f395 3235 302d 626f 2e65 706f 6869 .}..250-bo.epohi 0x0040 2e63 6f6d 2048 656c 6c6f 2073 6572 7665 .com.Hello.serve 0x0050 7261 ra 10:08:45.571432 206.21.174.5.41028 > 198.30.168.13.25: . ack 2116 win 11584 (DF) [tos 0x10] 0x0000 4510 0034 e660 4000 3b06 6f0c ce15 ae05 E..4..;.o..... 0x0010 c61e a80d a044 0019 34fe 0135 3363 4b53 .....D..4..53cKS 0x0020 8010 2d40 fa7a 0000 0101 080a 057d f397 ..-@.z.......}.. 0x0030 1901 fd5d ...] 10:09:10.653967 206.21.174.5.41028 > 198.30.168.13.25: P 23:29(6) ack 2116 win 11584 (DF) [tos 0x10] 0x0000 4510 003a e661 4000 3b06 6f05 ce15 ae05 E..:.a@.;.o..... 0x0010 c61e a80d a044 0019 34fe 0135 3363 4b53 .....D..4..53cKS 0x0020 8018 2d40 48ed 0000 0101 080a 057d fd63 ..-@H........}.c 0x0030 1901 fd5d 5155 4954 0d0a ...]QUIT.. 10:09:10.653967 198.30.168.13.25 > 206.21.174.5.41028: P 2116:2159(43) ack 29 win 5792 (DF) 0x0000 4500 005f b224 4000 4006 9e2d c61e a80d E.._.$@.@..-.... 0x0010 ce15 ae05 0019 a044 3363 4b53 34fe 013b .......D3cKS4..; 0x0020 8018 16a0 4e30 0000 0101 080a 1902 072a ....N0.........* 0x0030 057d fd63 3232 3120 322e 302e 3020 626f .}.c221.2.0.0.bo 0x0040 2e65 706f 6869 2e63 6f6d 2063 6c6f 7369 .epohi.com.closi 0x0050 6e67 ng 10:09:10.653967 198.30.168.13.25 > 206.21.174.5.41028: F 2159:2159(0) ack 29 win 5792 (DF) 0x0000 4500 0034 b225 4000 4006 9e57 c61e a80d E..4.%@.@..W.... 0x0010 ce15 ae05 0019 a044 3363 4b7e 34fe 013b .......D3cK~4..; 0x0020 8011 16a0 fd4f 0000 0101 080a 1902 072a .....O.........* 0x0030 057d fd63 .}.c 10:09:10.663972 206.21.174.5.41028 > 198.30.168.13.25: . ack 2159 win 11584 (DF) [tos 0x10] 0x0000 4510 0034 e662 4000 3b06 6f0a ce15 ae05 E..4.b@.;.o..... 0x0010 c61e a80d a044 0019 34fe 013b 3363 4b7e .....D..4..;3cK~ 0x0020 8010 2d40 e6af 0000 0101 080a 057d fd64 ..-@.........}.d 0x0030 1902 072a ...* 10:09:10.663972 206.21.174.5.41028 > 198.30.168.13.25: F 29:29(0) ack 2160 win 11584 (DF) [tos 0x10] 0x0000 4510 0034 e663 4000 3b06 6f09 ce15 ae05 E..4.c@.;.o..... 0x0010 c61e a80d a044 0019 34fe 013b 3363 4b7f .....D..4..;3cK. 0x0020 8011 2d40 e6ad 0000 0101 080a 057d fd64 ..-@.........}.d 0x0030 1902 072a ...* 10:09:10.663972 198.30.168.13.25 > 206.21.174.5.41028: . ack 30 win 5792 (DF) 0x0000 4500 0034 b226 4000 4006 9e56 c61e a80d E..4.&@.@..V.... 0x0010 ce15 ae05 0019 a044 3363 4b7f 34fe 013c .......D3cK.4..< 0x0020 8010 16a0 fd4c 0000 0101 080a 1902 072b .....L.........+ 0x0030 057d fd64 .}.d

    Sending SMTP server side

    [herrold@oldnews herrold]$ telnet bo.epohi.com 25 Trying 198.30.168.13... Connected to bo.epohi.com. Escape character is '^]'. 220-bo.epohi.com ESMTP RBL Testing and Publishing Notice Variant 220- Sendmail 8.12.4/8.12.4/nullclient 220- ready at Mon, 26 Aug 2002 10:08:14 -0400 220- 220- ------------ NOTICE - and - TERMS OF USE ---------------------- 220- We reserve the right to test all offerings and intermediate 220- relay hosts used by you for Open Relay and related status, 220- and to report for public publishing the results of our tests. 220- All content offered to this mailserver is done without any 220- further expectation of privacy by you, and you grant to us 220- full rights of republication at our sole discretion. 220- We also infer irrevocable explicit consent to our test of 220- those hosts, once you have further used our resources. 220- 220- Do not like these polices? Okay -- Go away. 220- Type "quit" to disconnect NOW, and send paper mail 220- to our domain mailing address if you disagree with any of 220- these terms and reporting. 220- --------------------------------------------------------------- 220- This mailserver is located in Ohio ; Unsolicited commercial 220- email (so-called SPAM) is unwanted under Ohio R C 2307.64 ; 220- It is under administration by Owl River Company, as an 220- Electronic mail service provider under R C 2307.64(A)(5). 220- Sending forged email may constitute criminal forgery under 220- R C 2307.64(H) -- See http://www.owlriver.com/nospam/ for 220- our Notice to you of these policies under R C 2307.64(C). 220- --------------------------------------------------------------- 220- Revised: RPH 020804; prior 020415 220- --------------------------------------------------------------- 220 ELHO asdf 500 5.5.1 Command unrecognized: "ELHO asdf" EHLO asdf 250-bo.epohi.com Hello servera.qn.net [206.21.174.5], pleased to meet you 250-ENHANCEDSTATUSCODES 250-PIPELINING 250-8BITMIME 250-SIZE 250-DSN 250-ETRN 250-AUTH GSSAPI LOGIN PLAIN 250-DELIVERBY 250 HELP QUIT 221 2.0.0 bo.epohi.com closing connection Connection closed by foreign host. [herrold@oldnews herrold]$ We can increase the size of the dump window by increasing the tcpdump -s option up to say 1500 characters (Why 1500 is beyond the scope of this piece, but it has to do with the maximum packet size readily transferred under the IP protocol in a ethernet environment. And this is used to solve really gory ISO layer two hard-core technical issues.) This would allow us to see every character of every packet. This is an overwhelming level of detail in most cases.

    And so we are satisfied that we are conformant to the protocol, and that the problem lies elsewhere beyond our demarc.


    Phase Two:

    We were invited to subscribe to a mailing list, on a host running the Lyris mailing list manager. Unfortunately, it is too impatient to wait the RFC 2821 sugggested 300 seconds between conversation elements. We mark the conversation, and the timestamps, showing its impatience. Additionally, that software changed the userid to a leading CAPITAL "H"; how rude. Ahhh well.
    Lyris non-compliance


    Phase Three: Try you hand at it

    We have made yet another trace web browser freindly, and snapshotted three tries at mail delivery to us. We have NOT colorized or done the linebreaks, so you can have an example to mark up and diagnose.

    Send your analysis to: info+socal@owlriver.com, and we will offer a critique.


    SoCal RR example



    We make this available for non-commercial and individual use. Please respect our copyright, and consider contacting us for all your Open Source and *nix design, architect / systems analysis, and administration needs.


    Copyright (C) 2002 R P Herrold
          herrold@owlriver.com  NIC: RPH5 (US)
       My words are not deathless prose,
          but they are mine.
    
           Owl River Company
       "The World is Open to Linux (tm)"
       ... Open Source LINUX solutions ...
          info@owlriver.com
             Columbus, OH
    

    - initial 020825 RPH
    http://www.owlriver.com/tips/trace-sendmail/

    Up More Tips
           

    Back to Top Page
    [legal] [ no spam policy ] [ Copyright] © 2008 Owl River Company
    All rights reserved.

    Last modified: Sat, 16 Nov 2002 10:06:17 -0500
    http://www.owlriver.com/tips/trace-sendmail/index.php