Re: "tcpflags 0x18<PUSH,ACK>; tcp_do_segment" kernel messages

From: Eygene Ryabinkin <rea-fbsd_at_codelabs.ru>
Date: Wed, 15 Aug 2007 21:27:31 +0400
Stefan,

Wed, Aug 15, 2007 at 06:21:01PM +0300, Stefan Lambrev wrote:
> Here is the part that does not have anything sensible:
> 
> 16:10:13.206555 IP mb7.intra.net.60906 > mb4.intra.net.smtp: S 
> 219272317:219272317(0) win 65535 <mss 1460,nop,wscale 8,sackOK,timestamp 
> 108147619 0>
>        0x0000:  4500 003c 2747 4000 4006 0000 c0a8 0d07  E..<'G_at_._at_.......
>        0x0010:  c0a8 0d04 edea 0019 0d11 d47d 0000 0000  ...........}....
>        0x0020:  a002 ffff 9b8a 0000 0204 05b4 0103 0308  ................
>        0x0030:  0402 080a 0672 33a3 0000 0000            .....r3.....
> 16:10:13.206789 IP mb4.intra.net.smtp > mb7.intra.net.60906: S 
> 1948405606:1948405606(0) ack 219272318 win 65535 <mss 1460,nop,wscale 
> 1,nop,nop,timestamp 3042169350 108147619,sackOK,eol>
>        0x0000:  4500 0040 b86e 4000 4006 e6ed c0a8 0d04  E.._at_.n_at_._at_.......
>        0x0010:  c0a8 0d07 0019 edea 7422 4f66 0d11 d47e  ........t"Of...~
>        0x0020:  b012 ffff 4709 0000 0204 05b4 0103 0301  ....G...........
>        0x0030:  0101 080a b553 d206 0672 33a3 0402 0000  .....S...r3.....
> 16:10:13.206824 IP mb7.intra.net.60906 > mb4.intra.net.smtp: . ack 1 win 260 
> <nop,nop,timestamp 108147620 3042169350>
>        0x0000:  4500 0034 2748 4000 4006 0000 c0a8 0d07  E..4'H_at_._at_.......
>        0x0010:  c0a8 0d04 edea 0019 0d11 d47e 7422 4f67  ...........~t"Og
>        0x0020:  8010 0104 9b82 0000 0101 080a 0672 33a4  .............r3.
>        0x0030:  b553 d206                                .S..

Three-way handshake.

> 16:10:13.208261 IP mb4.intra.net.smtp > mb7.intra.net.60906: P 1:48(47) ack 1 
> win 33304 <nop,nop,timestamp 3042169351 108147620>
>        0x0000:  4500 0063 b873 4000 4006 e6c5 c0a8 0d04  E..c.s_at_._at_.......
>        0x0010:  c0a8 0d07 0019 edea 7422 4f67 0d11 d47e  ........t"Og...~
>        0x0020:  8018 8218 fca6 0000 0101 080a b553 d207  .............S..
>        0x0030:  0672 33a4 3232 3020 6d62 342e 6d6f 6e65  .r3.220.mb4.mone
>        0x0040:  7962 6f6f 6b65 7273 2e63 6f6d 2045 534d  ybookers.com.ESM
>        0x0050:  5450 206d 6169 6c2d 6578 6368 616e 6765  TP.mail-exchange
>        0x0060:  720d 0a                                  r..

SMTP banner and greeting.

> 16:10:13.208347 IP mb7.intra.net.60906 > mb4.intra.net.smtp: P 1:21(20) ack 48
> win 260 <nop,nop,timestamp 108147621 3042169351>
>        0x0000:  4500 0048 2749 4000 4006 0000 c0a8 0d07  E..H'I_at_._at_.......
>        0x0010:  c0a8 0d04 edea 0019 0d11 d47e 7422 4f96  ...........~t"O.
>        0x0020:  8018 0104 9b96 0000 0101 080a 0672 33a5  .............r3.
>        0x0030:  b553 d207 4845 4c4f 206d 6237 2e69 6e74  .S..HELO.mb7.int
>        0x0040:  7261 2e6e 6574 0d0a                      ra.net..

Client sent his HELO.

> 16:10:13.208690 IP mb4.intra.net.smtp > mb7.intra.net.60906: P 48:74(26) ack 21 
> win 33304 <nop,nop,timestamp 3042169352 108147621>
>        0x0000:  4500 004e b877 4000 4006 e6d6 c0a8 0d04  E..N.w_at_._at_.......
>        0x0010:  c0a8 0d07 0019 edea 7422 4f96 0d11 d492  ........t"O.....
>        0x0020:  8018 8218 b312 0000 0101 080a b553 d208  .............S..
>        0x0030:  0672 33a5 3235 3020 6d62 342e 6d6f 6e65  .r3.250.mb4.mone
>        0x0040:  7962 6f6f 6b65 7273 2e63 6f6d 0d0a       ybookers.com..

Server sent 250, 'pleased to meet you' message.

> 16:10:13.208715 IP mb7.intra.net.60906 > mb4.intra.net.smtp: P 21:27(6) ack 74
> win 260 <nop,nop,timestamp 108147621 3042169352>
>        0x0000:  4500 003a 274a 4000 4006 0000 c0a8 0d07  E..:'J_at_._at_.......
>        0x0010:  c0a8 0d04 edea 0019 0d11 d492 7422 4fb0  ............t"O.
>        0x0020:  8018 0104 9b88 0000 0101 080a 0672 33a5  .............r3.
>        0x0030:  b553 d208 5155 4954 0d0a                 .S..QUIT..

For some odd reason client issued QUIT.

> I'm not sure why this QUIT is here. But I noticed that the app normaly use 
> "quit" (small letters)
> May be the problem is in the application itself ?

I don't know for sure, but what I am seeing with Apache, -CURRENT
and keep-alived connections is that Apache sometimes drop them
without any reason.  Your SMTP symptoms are strange, as the Apache
ones.  May be FreeBSD TCP stack does something that provokes
applications to behave weirdly.  Can you tell what client and server
software you're running: if client has sources, maybe we can see
if it issues uppercase QUIT in some curcumstances, and the lowercase
quit in other cases.

I have Apache debugging in my TODO list, but currently I have no
spare time for it.  But your case can give some clues, so I will
try to debug Apache soon.  And the facts about your SMTP client
will also help.

> Anyway here are the rest of the packets (and one of them trigger
> the error msg):

And I can tell you, which one ;))

> 16:10:13.208729 IP mb7.intra.net.60906 > mb4.intra.net.smtp: F 27:27(0) ack 74
> win 260 <nop,nop,timestamp 108147621 3042169352>
>        0x0000:  4500 0034 274b 4000 4006 0000 c0a8 0d07  E..4'K_at_._at_.......
>        0x0010:  c0a8 0d04 edea 0019 0d11 d498 7422 4fb0  ............t"O.
>        0x0020:  8011 0104 9b82 0000 0101 080a 0672 33a5  .............r3.
>        0x0030:  b553 d208                                .S..
> 16:10:13.208835 IP mb4.intra.net.smtp > mb7.intra.net.60906: . ack 28 win 33301 
> <nop,nop,timestamp 3042169352 108147621>
>        0x0000:  4500 0034 b878 4000 4006 e6ef c0a8 0d04  E..4.x_at_._at_.......
>        0x0010:  c0a8 0d07 0019 edea 7422 4fb0 0d11 d499  ........t"O.....
>        0x0020:  8010 8215 0457 0000 0101 080a b553 d208  .....W.......S..
>        0x0030:  0672 33a5                                .r3.
> 16:10:13.208986 IP mb4.intra.net.smtp > mb7.intra.net.60906: P 74:89(15) ack 28 
> win 33304 <nop,nop,timestamp 3042169352 108147621>
>        0x0000:  4500 0043 b879 4000 4006 e6df c0a8 0d04  E..C.y_at_._at_.......
>        0x0010:  c0a8 0d07 0019 edea 7422 4fb0 0d11 d499  ........t"O.....
>        0x0020:  8018 8218 5ce7 0000 0101 080a b553 d208  ....\........S..
>        0x0030:  0672 33a5 3232 3120 322e 302e 3020 4279  .r3.221.2.0.0.By
>        0x0040:  650d 0a                                  e..

The previous one: client  mb7.intra.net had thrown his 'QUIT' and
closed the socket, thus he is not interested in the server's response.
Judging by the normal end of the task that you're citing below, the
normal client workflow is to wait for the server's response to the
'quit' message and to close the socket only after it.  So something
unusual happening to the client and it is really interesting to
look at the client's sources to see what's up.

To clarify a bit: are all two servers running -CURRENT, or just the
client one?

Thank you!

> 16:10:13.209069 IP mb7.intra.net.60906 > mb4.intra.net.smtp: R 
> 219272345:219272345(0) win 0
>        0x0000:  4500 0028 274c 4000 4006 0000 c0a8 0d07  E..('L_at_._at_.......
>        0x0010:  c0a8 0d04 edea 0019 0d11 d499 0000 0000  ................
>        0x0020:  5004 0000 9b76 0000 0000 0000 0000       P....v........
> 16:10:13.209074 IP mb4.intra.net.smtp > mb7.intra.net.60906: F 89:89(0) ack 28 
> win 33304 <nop,nop,timestamp 3042169352 108147621>
>        0x0000:  4500 0034 b87a 4000 4006 e6ed c0a8 0d04  E..4.z_at_._at_.......
>        0x0010:  c0a8 0d07 0019 edea 7422 4fbf 0d11 d499  ........t"O.....
>        0x0020:  8011 8218 0444 0000 0101 080a b553 d208  .....D.......S..
>        0x0030:  0672 33a5                                .r3.
> 16:10:13.209079 IP mb7.intra.net.60906 > mb4.intra.net.smtp: R 
> 219272345:219272345(0) win 0
>        0x0000:  4500 0028 274d 4000 4006 0000 c0a8 0d07  E..('M_at_._at_.......
>        0x0010:  c0a8 0d04 edea 0019 0d11 d499 0000 0000  ................
>        0x0020:  5004 0000 9b76 0000 0000 0000 0000       P....v........
> 
> And here is the normal end of the task (same socket used ~9 min earlier) :
> 
> 16:01:20.298645 IP mb4.intra.net.smtp > mb7.intra.net.60906: P 246:283(37) ack 
> 24881 win 33304 <nop,nop,timestamp 3041636321 107614566>
>        0x0000:  4500 0059 f4bc 4000 4006 aa86 c0a8 0d04  E..Y.._at_._at_.......
>        0x0010:  c0a8 0d07 0019 edea a76e cce8 ebc6 8f74  .........n.....t
>        0x0020:  8018 8218 3e15 0000 0101 080a b54b afe1  ....>........K..
>        0x0030:  066a 1166 3235 3020 322e 302e 3020 4f6b  .j.f250.2.0.0.Ok
>        0x0040:  3a20 7175 6575 6564 2061 7320 3546 4541  :.queued.as.5FEA
>        0x0050:  4532 3044 3539 430d 0a                   E20D59C..
> 16:01:20.298900 IP mb7.intra.net.60906 > mb4.intra.net.smtp: P 24881:24887(6) 
> ack 283 win 260 <nop,nop,timestamp 107614592 3041636321>
>        0x0000:  4500 003a d953 4000 4006 0000 c0a8 0d07  E..:.S_at_._at_.......
>        0x0010:  c0a8 0d04 edea 0019 ebc6 8f74 a76e cd0d  ...........t.n..
>        0x0020:  8018 0104 9b88 0000 0101 080a 066a 1180  .............j..
>        0x0030:  b54b afe1 7175 6974 0d0a                 .K..quit..
> 16:01:20.299675 IP mb4.intra.net.smtp > mb7.intra.net.60906: P 283:298(15) ack 
> 24887 win 33304 <nop,nop,timestamp 3041636322 107614592>
>        0x0000:  4500 0043 f4c2 4000 4006 aa96 c0a8 0d04  E..C.._at_._at_.......
>        0x0010:  c0a8 0d07 0019 edea a76e cd0d ebc6 8f7a  .........n.....z
>        0x0020:  8018 8218 5702 0000 0101 080a b54b afe2  ....W........K..
>        0x0030:  066a 1180 3232 3120 322e 302e 3020 4279  .j..221.2.0.0.By
>        0x0040:  650d 0a                                  e..
> 16:01:20.299688 IP mb4.intra.net.smtp > mb7.intra.net.60906: F 298:298(0) ack 
> 24887 win 33304 <nop,nop,timestamp 3041636322 107614592>
>        0x0000:  4500 0034 f4c3 4000 4006 aaa4 c0a8 0d04  E..4.._at_._at_.......
>        0x0010:  c0a8 0d07 0019 edea a76e cd1c ebc6 8f7a  .........n.....z
>        0x0020:  8011 8218 fe5e 0000 0101 080a b54b afe2  .....^.......K..
>        0x0030:  066a 1180                                .j..
> 16:01:20.299700 IP mb7.intra.net.60906 > mb4.intra.net.smtp: . ack 299 win 260 
> <nop,nop,timestamp 107614593 3041636322>
>        0x0000:  4500 0034 d954 4000 4006 0000 c0a8 0d07  E..4.T_at_._at_.......
>        0x0010:  c0a8 0d04 edea 0019 ebc6 8f7a a76e cd1d  ...........z.n..
>        0x0020:  8010 0104 9b82 0000 0101 080a 066a 1181  .............j..
>        0x0030:  b54b afe2                                .K..
> 16:01:20.299746 IP mb7.intra.net.60906 > mb4.intra.net.smtp: F 24887:24887(0) 
> ack 299 win 260 <nop,nop,timestamp 107614593 3041636322>
>        0x0000:  4500 0034 d955 4000 4006 0000 c0a8 0d07  E..4.U_at_._at_.......
>        0x0010:  c0a8 0d04 edea 0019 ebc6 8f7a a76e cd1d  ...........z.n..
>        0x0020:  8011 0104 9b82 0000 0101 080a 066a 1181  .............j..
>        0x0030:  b54b afe2                                .K..
> 16:01:20.299972 IP mb4.intra.net.smtp > mb7.intra.net.60906: . ack 24888 win 
> 33303 <nop,nop,timestamp 3041636322 107614593>
>        0x0000:  4500 0034 f4c4 4000 4006 aaa3 c0a8 0d04  E..4.._at_._at_.......
>        0x0010:  c0a8 0d07 0019 edea a76e cd1d ebc6 8f7b  .........n.....{
>        0x0020:  8010 8217 fe5d 0000 0101 080a b54b afe2  .....].......K..
>        0x0030:  066a 1181                                .j..
-- 
Eygene
Received on Wed Aug 15 2007 - 15:27:38 UTC

This archive was generated by hypermail 2.4.0 : Wed May 19 2021 - 11:39:16 UTC