On Wed, 14 Aug 2002, Philip Hazel wrote:
> > It would be useful if the FAQ or log message indicated why and when this
> > "SMTP data timeout (message abandoned) on connection from" happens (like
> > during or after RCPT TO or DATA for example).
>
> It's during DATA. Maybe it should say "DATA timeout" instead of "data
> timeout"? To be pedantic, you can't get an SMTP timeout _during_ RCPT.
> It either receives RCPT, or it times out waiting for the next command
> (which may or may not be RCPT).
Just to say the timeout occured after a "RCPT TO" or after a "MAIL FROM"
or after a succesful DATA or whatever. Maybe it would help in
troubleshooting. (But of course, tcpdump helps too.)
> You might also consider adding +smtp_connection to your log_selector
> setting.
I overlooked that. Thanks. I can use log_smtp_connections to see when it
connected. (That is why I wanted the other log so I could see if my new
20 minute timeout was in effect.)
Also, as David W. suggested here is a more complete tcpdump for one
problem session. (I used "tcpdump -vvvXnli eth0 net 12.155.196 and port
25" and manually searched and copied the data to here.)
20:45:16.383738 12.155.196.8.28253 > 209.45.208.4.smtp: S [tcp sum ok]
45722677:45722677(0) win 2144 <mss 1460,nop,nop,sackOK> (DF)
(ttl 126, id 9502, len 48)
0x0000 4500 0030 251e 4000 7e06 65d4 0c9b c408 E..0%.@.~.e.....
0x0010 d12d d004 6e5d 0019 02b9 ac35 0000 0000 .-..n].....5....
0x0020 7002 0860 eb84 0000 0204 05b4 0101 0402 p..`............
20:45:16.383738 209.45.208.4.smtp > 12.155.196.8.28253: S [tcp sum ok]
1974791002:1974791002(0) ack 45722678 win 5840 <mss 1460,nop,nop,sackOK>
(DF) (ttl 64, id 0, len 48)
0x0000 4500 0030 0000 4000 4006 c8f2 d12d d004 E..0..@.@....-..
0x0010 0c9b c408 0019 6e5d 75b4 eb5a 02b9 ac36 ......n]u..Z...6
0x0020 7012 16d0 7bf4 0000 0204 05b4 0101 0402 p...{...........
20:45:16.423738 12.155.196.8.28253 > 209.45.208.4.smtp: . [tcp sum ok]
1:1(0) ack 1 win 2144 (DF) (ttl 126, id 9758, len 40)
0x0000 4500 0028 261e 4000 7e06 64dc 0c9b c408 E..(&.@.~.d.....
0x0010 d12d d004 6e5d 0019 02b9 ac36 75b4 eb5b .-..n].....6u..[
0x0020 5010 0860 b728 0000 0000 0000 0000 P..`.(........
20:45:54.523738 209.45.208.4.smtp > 12.155.196.8.28253: P 1:76(75) ack 1
win 5840 (DF) (ttl 64, id 49189, len 115)
0x0000 4500 0073 c025 4000 4006 088a d12d d004 E..s.%@.@....-..
0x0010 0c9b c408 0019 6e5d 75b4 eb5b 02b9 ac36 ......n]u..[...6
0x0020 5018 16d0 caaf 0000 3232 3020 6d61 696c P.......220.mail
0x0030 2e6f 6373 6f6e 6c69 6e65 2e63 6f6d 2045 .ocsonline.com.E
0x0040 534d 5450 2045 7869 6d20 332e 3232 2023 SMTP.Exim.3.22.#
0x0050 3120 1.
20:45:54.563738 12.155.196.8.28253 > 209.45.208.4.smtp: P [tcp sum ok]
1:11(10) ack 76 win 2069 (DF) (ttl 126, id 10014, len 50)
0x0000 4500 0032 271e 4000 7e06 63d2 0c9b c408 E..2'.@.~.c.....
0x0010 d12d d004 6e5d 0019 02b9 ac36 75b4 eba6 .-..n].....6u...
0x0020 5018 0815 9195 0000 4845 4c4f 206f 6373 P.......HELO.ocs
0x0030 0d0a ..
20:45:54.563738 209.45.208.4.smtp > 12.155.196.8.28253: . [tcp sum ok]
76:76(0) ack 11 win 5840 (DF) (ttl 64, id 49190, len 40)
0x0000 4500 0028 c026 4000 4006 08d4 d12d d004 E..(.&@.@....-..
0x0010 0c9b c408 0019 6e5d 75b4 eba6 02b9 ac40 ......n]u......@
0x0020 5010 16d0 a863 0000 P....c..
20:45:54.563738 209.45.208.4.smtp > 12.155.196.8.28253: P 76:144(68) ack
11 win 5840 (DF) (ttl 64, id 49191, len 108)
0x0000 4500 006c c027 4000 4006 088f d12d d004 E..l.'@.@....-..
0x0010 0c9b c408 0019 6e5d 75b4 eba6 02b9 ac40 ......n]u......@
0x0020 5018 16d0 86f5 0000 3235 3020 6d61 696c P.......250.mail
0x0030 2e6f 6373 6f6e 6c69 6e65 2e63 6f6d 2048 .ocsonline.com.H
0x0040 656c 6c6f 2033 3831 302d 312d 312e 6f63 ello.3810-1-1.oc
0x0050 736f so
20:45:54.603738 12.155.196.8.28253 > 209.45.208.4.smtp: P [tcp sum ok]
11:47(36) ack 144 win 2001 (DF) (ttl 126, id 10270, len 76)
0x0000 4500 004c 281e 4000 7e06 62b8 0c9b c408 E..L(.@.~.b.....
0x0010 d12d d004 6e5d 0019 02b9 ac40 75b4 ebea .-..n].....@u...
0x0020 5018 07d1 9f2f 0000 4d41 494c 2046 524f P..../..MAIL.FRO
0x0030 4d3a 203c 6173 6d6f 6f72 6540 6f63 736f M:.<asmoore@ocso
0x0040 6e6c 696e 652e 636f 6d3e 0d0a nline.com>..
20:45:54.613738 209.45.208.4.smtp > 12.155.196.8.28253: P 144:198(54) ack
47 win 5840 (DF) (ttl 64, id 49192, len 94)
0x0000 4500 005e c028 4000 4006 089c d12d d004 E..^.(@.@....-..
0x0010 0c9b c408 0019 6e5d 75b4 ebea 02b9 ac64 ......n]u......d
0x0020 5018 16d0 6486 0000 3235 3020 3c61 736d P...d...250.<asm
0x0030 6f6f 7265 406f 6373 6f6e 6c69 6e65 2e63 oore@???
0x0040 6f6d 3e20 6973 2073 796e 7461 6374 6963 om>.is.syntactic
0x0050 616c al
20:45:54.653738 12.155.196.8.28253 > 209.45.208.4.smtp: P [tcp sum ok]
47:74(27) ack 198 win 1947 (DF) (ttl 126, id 10526, len 67)
0x0000 4500 0043 291e 4000 7e06 61c1 0c9b c408 E..C).@.~.a.....
0x0010 d12d d004 6e5d 0019 02b9 ac64 75b4 ec20 .-..n].....du...
0x0020 5018 079b 70aa 0000 5243 5054 2054 4f3a P...p...RCPT.TO:
0x0030 203c 7461 7475 6d40 6361 7474 2e63 6f6d .<tatum@???
0x0040 3e0d 0a >..
20:45:54.693738 209.45.208.4.smtp > 12.155.196.8.28253: . [tcp sum ok]
198:198(0) ack 74 win 5840 (DF) (ttl 64, id 49193, len 40)
0x0000 4500 0028 c029 4000 4006 08d1 d12d d004 E..(.)@.@....-..
0x0010 0c9b c408 0019 6e5d 75b4 ec20 02b9 ac7f ......n]u.......
0x0020 5010 16d0 a7aa 0000 P.......
20:45:55.203738 209.45.208.4.smtp > 12.155.196.8.28253: P [tcp sum ok]
198:229(31) ack 74 win 5840 (DF) (ttl 64, id 49194, len 71)
0x0000 4500 0047 c02a 4000 4006 08b1 d12d d004 E..G.*@.@....-..
0x0010 0c9b c408 0019 6e5d 75b4 ec20 02b9 ac7f ......n]u.......
0x0020 5018 16d0 8462 0000 3235 3020 3c74 6174 P....b..250.<tat
0x0030 756d 4063 6174 742e 636f 6d3e 2076 6572 um@???>.ver
0x0040 6966 6965 640d 0a ified..
20:45:55.253738 12.155.196.8.28253 > 209.45.208.4.smtp: P [tcp sum ok]
74:80(6) ack 229 win 1916 (DF) (ttl 126, id 10782, len 46)
0x0000 4500 002e 2a1e 4000 7e06 60d6 0c9b c408 E...*.@.~.`.....
0x0010 d12d d004 6e5d 0019 02b9 ac7f 75b4 ec3f .-..n]......u..?
0x0020 5018 077c 1145 0000 4441 5441 0d0a P..|.E..DATA..
20:45:55.253738 209.45.208.4.smtp > 12.155.196.8.28253: . [tcp sum ok]
229:229(0) ack 80 win 5840 (DF) (ttl 64, id 49195, len 40)
0x0000 4500 0028 c02b 4000 4006 08cf d12d d004 E..(.+@.@....-..
0x0010 0c9b c408 0019 6e5d 75b4 ec3f 02b9 ac85 ......n]u..?....
0x0020 5010 16d0 a785 0000 P.......
20:45:55.253738 209.45.208.4.smtp > 12.155.196.8.28253: P 229:285(56) ack
80 win 5840 (DF) (ttl 64, id 49196, len 96)
0x0000 4500 0060 c02c 4000 4006 0896 d12d d004 E..`.,@.@....-..
0x0010 0c9b c408 0019 6e5d 75b4 ec3f 02b9 ac85 ......n]u..?....
0x0020 5018 16d0 18d5 0000 3335 3420 456e 7465 P.......354.Ente
0x0030 7220 6d65 7373 6167 652c 2065 6e64 696e r.message,.endin
0x0040 6720 7769 7468 2022 2e22 206f 6e20 6120 g.with.".".on.a.
0x0050 6c69 li
20:45:55.493738 209.45.208.4.smtp > 12.155.196.8.28253: P 229:285(56) ack
80 win 5840 (DF) (ttl 64, id 49197, len 96)
0x0000 4500 0060 c02d 4000 4006 0895 d12d d004 E..`.-@.@....-..
0x0010 0c9b c408 0019 6e5d 75b4 ec3f 02b9 ac85 ......n]u..?....
0x0020 5018 16d0 18d5 0000 3335 3420 456e 7465 P.......354.Ente
0x0030 7220 6d65 7373 6167 652c 2065 6e64 696e r.message,.endin
0x0040 6720 7769 7468 2022 2e22 206f 6e20 6120 g.with.".".on.a.
0x0050 6c69 li
20:45:55.533738 12.155.196.8.28253 > 209.45.208.4.smtp: . [tcp sum ok]
5920:5920 (0) ack 285 win 1860 (DF) (ttl 126, id 12062, len 40)
0x0000 4500 0028 2f1e 4000 7e06 5bdc 0c9b c408 E..(/.@.~.[.....
0x0010 d12d d004 6e5d 0019 02b9 c355 75b4 ec77 .-..n].....Uu..w
0x0020 5010 0744 a009 0000 0000 0000 0000 P..D..........
20 minutes (my smtp_receive_timeout) later:
21:05:55.253738 209.45.208.4.smtp > 12.155.196.8.28253: P 285:358(73) ack
80 win 5840 (DF) (ttl 64, id 49198, len 113)
0x0000 4500 0071 c02e 4000 4006 0883 d12d d004 E..q..@.@....-..
0x0010 0c9b c408 0019 6e5d 75b4 ec77 02b9 ac85 ......n]u..w....
0x0020 5018 16d0 be62 0000 3432 3120 6d61 696c P....b..421.mail
0x0030 2e6f 6373 6f6e 6c69 6e65 2e63 6f6d 2053 .ocsonline.com.S
0x0040 4d54 5020 696e 636f 6d69 6e67 2064 6174 MTP.incoming.dat
0x0050 6120 a.
21:05:55.253738 209.45.208.4.smtp > 12.155.196.8.28253: F [tcp sum ok]
358:358(0) ack 80 win 5840 (DF) (ttl 64, id 49199, len 40)
0x0000 4500 0028 c02f 4000 4006 08cb d12d d004 E..(./@.@....-..
0x0010 0c9b c408 0019 6e5d 75b4 ecc0 02b9 ac85 ......n]u.......
0x0020 5011 16d0 a703 0000 P.......
21:05:55.303738 12.155.196.8.28253 > 209.45.208.4.smtp: R [tcp sum ok]
45722757:45722757(0) win 0 (ttl 126, id 64542, len 40)
0x0000 4500 0028 fc1e 0000 7e06 cedb 0c9b c408 E..(....~.......
0x0010 d12d d004 6e5d 0019 02b9 ac85 02b9 ac85 .-..n]..........
0x0020 5004 0000 7117 0000 0000 0000 0000 P...q.........
21:05:55.303738 12.155.196.8.28253 > 209.45.208.4.smtp: R [tcp sum ok]
45722757:45722757(0) win 0 (ttl 126, id 64798, len 40)
0x0000 4500 0028 fd1e 0000 7e06 cddb 0c9b c408 E..(....~.......
0x0010 d12d d004 6e5d 0019 02b9 ac85 02b9 ac85 .-..n]..........
0x0020 5004 0000 7117 0000 0000 0000 0000 P...q.........
Thanks Philip and David.
Jeremy C. Reed
http://www.bsdnewsletter.com/
