* TCP SACK issue, hung connection, tcpdump included
@ 2007-07-29 5:59 Darryl L. Miles
2007-07-29 6:45 ` Willy Tarreau
2007-07-29 15:30 ` Phil Oester
0 siblings, 2 replies; 15+ messages in thread
From: Darryl L. Miles @ 2007-07-29 5:59 UTC (permalink / raw)
To: linux-kernel
CLIENT = Linux 2.6.20.1-smp [Customer build]
SERVER = Linux 2.6.9-55.ELsmp [Red Hat Enterprise Linux AS release 4 (Nahant Update 5)]
The problems start around time index 09:21:39.860302 when the CLIENT issues a TCP packet with SACK option set (seemingly for a data segment which has already been seen) from that point on the connection hangs.
Full dump available via email.
09:12:13.444999 IP CLIENT.50727 > SERVER.ssh: S 2919512080:2919512080(0) win 5840 <mss 1460,sackOK,timestamp 799860259 0,nop,wscale 7>
09:12:13.535643 IP SERVER.ssh > CLIENT.50727: S 492909547:492909547(0) ack 2919512081 win 5792 <mss 1460,sackOK,timestamp 7126976 799860259,nop,wscale 2>
09:12:13.535717 IP CLIENT.50727 > SERVER.ssh: . ack 1 win 46 <nop,nop,timestamp 799860282 7126976>
09:12:13.665481 IP SERVER.ssh > CLIENT.50727: P 1:24(23) ack 1 win 1448 <nop,nop,timestamp 7127074 799860282>
09:12:13.665895 IP CLIENT.50727 > SERVER.ssh: . ack 24 win 46 <nop,nop,timestamp 799860314 7127074>
09:12:13.666044 IP CLIENT.50727 > SERVER.ssh: P 1:23(22) ack 24 win 46 <nop,nop,timestamp 799860314 7127074>
09:12:13.776318 IP SERVER.ssh > CLIENT.50727: . ack 23 win 1448 <nop,nop,timestamp 7127216 799860314>
...SNIPPED SUCCESSFUL TRAFFIC...
09:21:39.490740 IP SERVER.ssh > CLIENT.50727: P 18200:18464(264) ack 2991 win 2728 <nop,nop,timestamp 7692910 800001727>
09:21:39.490775 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800001755 7692910>
09:21:39.860245 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 7693293 800001749>
09:21:39.860302 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800001847 7692910,nop,nop,sack sack 1 {12408:13856} >
09:21:40.453440 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 7693887 800001749>
09:21:40.453495 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800001996 7692910,nop,nop,sack sack 1 {12408:13856} >
09:21:41.641821 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 7695075 800001749>
09:21:41.641938 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800002293 7692910,nop,nop,sack sack 1 {12408:13856} >
09:21:44.017552 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 7697451 800001749>
09:21:44.017622 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800002887 7692910,nop,nop,sack sack 1 {12408:13856} >
09:21:48.770051 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 7702203 800001749>
09:21:48.770099 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800004075 7692910,nop,nop,sack sack 1 {12408:13856} >
09:21:58.274061 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 7711707 800001749>
09:21:58.274180 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800006450 7692910,nop,nop,sack sack 1 {12408:13856} >
09:22:17.282035 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 7730715 800001749>
09:22:17.282153 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800011202 7692910,nop,nop,sack sack 1 {12408:13856} >
09:22:55.298955 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 7768731 800001749>
09:22:55.299023 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800020705 7692910,nop,nop,sack sack 1 {12408:13856} >
09:24:11.329853 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 7844763 800001749>
09:24:11.329923 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800039711 7692910,nop,nop,sack sack 1 {12408:13856} >
09:26:11.331578 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 7964763 800001749>
09:26:11.331699 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800069708 7692910,nop,nop,sack sack 1 {12408:13856} >
09:26:13.011885 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800070128 7692910>
09:26:13.309032 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800070202 7692910>
09:26:13.901048 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800070350 7692910>
09:26:15.085103 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800070646 7692910>
09:26:17.453195 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800071238 7692910>
09:26:22.189378 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800072422 7692910>
09:26:31.661696 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800074790 7692910>
09:26:50.610374 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800079526 7692910>
09:27:28.499729 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800088998 7692910>
09:28:11.331256 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 8084763 800001749>
09:28:11.331354 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800099704 7692910,nop,nop,sack sack 1 {12408:13856} >
09:28:44.286495 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800107942 7692910>
09:30:11.330959 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 8204763 800001749>
09:30:11.331074 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800129701 7692910,nop,nop,sack sack 1 {12408:13856} >
09:30:44.298756 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800137942 7692910>
09:32:11.331661 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 8324763 800001749>
09:32:11.331727 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800159698 7692910,nop,nop,sack sack 1 {12408:13856} >
09:32:44.311051 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800167942 7692910>
09:34:11.332375 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 8444763 800001749>
09:34:11.332447 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800189695 7692910,nop,nop,sack sack 1 {12408:13856} >
09:34:44.323298 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800197942 7692910>
09:36:11.332073 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 8564763 800001749>
09:36:11.332166 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800219692 7692910,nop,nop,sack sack 1 {12408:13856} >
09:36:44.335591 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800227942 7692910>
09:38:44.351950 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800257942 7692910>
09:40:44.368172 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800287943 7692910>
At the end of the dump here the connection is dropped by the client side.
Darryl
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: TCP SACK issue, hung connection, tcpdump included
2007-07-29 5:59 TCP SACK issue, hung connection, tcpdump included Darryl L. Miles
@ 2007-07-29 6:45 ` Willy Tarreau
2007-07-29 8:26 ` Ilpo Järvinen
2007-07-29 8:39 ` Jan Engelhardt
2007-07-29 15:30 ` Phil Oester
1 sibling, 2 replies; 15+ messages in thread
From: Willy Tarreau @ 2007-07-29 6:45 UTC (permalink / raw)
To: Darryl L. Miles; +Cc: linux-kernel, netdev
Hi,
[CCing netdev as it's where people competent on the subject are]
On Sun, Jul 29, 2007 at 06:59:26AM +0100, Darryl L. Miles wrote:
> CLIENT = Linux 2.6.20.1-smp [Customer build]
> SERVER = Linux 2.6.9-55.ELsmp [Red Hat Enterprise Linux AS release 4
> (Nahant Update 5)]
>
> The problems start around time index 09:21:39.860302 when the CLIENT issues
> a TCP packet with SACK option set (seemingly for a data segment which has
> already been seen) from that point on the connection hangs.
Where was the capture taken ? on CLIENT or on SERVER (I suspect client from
the timers) ? A possible, but very unlikely reason would be an MTU limitation
somewhere, because the segment which never gets correctly ACKed is also the
largest one in this trace. It would be strange as the SACKs are send
immediately after, but it should be something to consider anyway.
Also, if everything is right with the packets on the server side, then
it would means that it's the RHEL kernel which is buggy (which does not
mean that the same bug does not exist in mainline).
Regards,
Willy
> Full dump available via email.
>
>
> 09:12:13.444999 IP CLIENT.50727 > SERVER.ssh: S 2919512080:2919512080(0)
> win 5840 <mss 1460,sackOK,timestamp 799860259 0,nop,wscale 7>
> 09:12:13.535643 IP SERVER.ssh > CLIENT.50727: S 492909547:492909547(0) ack
> 2919512081 win 5792 <mss 1460,sackOK,timestamp 7126976 799860259,nop,wscale
> 2>
> 09:12:13.535717 IP CLIENT.50727 > SERVER.ssh: . ack 1 win 46
> <nop,nop,timestamp 799860282 7126976>
> 09:12:13.665481 IP SERVER.ssh > CLIENT.50727: P 1:24(23) ack 1 win 1448
> <nop,nop,timestamp 7127074 799860282>
> 09:12:13.665895 IP CLIENT.50727 > SERVER.ssh: . ack 24 win 46
> <nop,nop,timestamp 799860314 7127074>
> 09:12:13.666044 IP CLIENT.50727 > SERVER.ssh: P 1:23(22) ack 24 win 46
> <nop,nop,timestamp 799860314 7127074>
> 09:12:13.776318 IP SERVER.ssh > CLIENT.50727: . ack 23 win 1448
> <nop,nop,timestamp 7127216 799860314>
>
> ...SNIPPED SUCCESSFUL TRAFFIC...
>
> 09:21:39.490740 IP SERVER.ssh > CLIENT.50727: P 18200:18464(264) ack 2991
> win 2728 <nop,nop,timestamp 7692910 800001727>
> 09:21:39.490775 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800001755 7692910>
> 09:21:39.860245 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 7693293 800001749>
> 09:21:39.860302 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800001847 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:21:40.453440 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 7693887 800001749>
> 09:21:40.453495 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800001996 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:21:41.641821 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 7695075 800001749>
> 09:21:41.641938 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800002293 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:21:44.017552 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 7697451 800001749>
> 09:21:44.017622 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800002887 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:21:48.770051 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 7702203 800001749>
> 09:21:48.770099 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800004075 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:21:58.274061 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 7711707 800001749>
> 09:21:58.274180 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800006450 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:22:17.282035 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 7730715 800001749>
> 09:22:17.282153 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800011202 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:22:55.298955 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 7768731 800001749>
> 09:22:55.299023 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800020705 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:24:11.329853 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 7844763 800001749>
> 09:24:11.329923 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800039711 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:26:11.331578 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 7964763 800001749>
> 09:26:11.331699 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800069708 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:26:13.011885 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800070128 7692910>
> 09:26:13.309032 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800070202 7692910>
> 09:26:13.901048 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800070350 7692910>
> 09:26:15.085103 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800070646 7692910>
> 09:26:17.453195 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800071238 7692910>
> 09:26:22.189378 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800072422 7692910>
> 09:26:31.661696 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800074790 7692910>
> 09:26:50.610374 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800079526 7692910>
> 09:27:28.499729 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800088998 7692910>
> 09:28:11.331256 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 8084763 800001749>
> 09:28:11.331354 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800099704 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:28:44.286495 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800107942 7692910>
> 09:30:11.330959 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 8204763 800001749>
> 09:30:11.331074 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800129701 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:30:44.298756 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800137942 7692910>
> 09:32:11.331661 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 8324763 800001749>
> 09:32:11.331727 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800159698 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:32:44.311051 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800167942 7692910>
> 09:34:11.332375 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 8444763 800001749>
> 09:34:11.332447 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800189695 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:34:44.323298 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800197942 7692910>
> 09:36:11.332073 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> win 2728 <nop,nop,timestamp 8564763 800001749>
> 09:36:11.332166 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> <nop,nop,timestamp 800219692 7692910,nop,nop,sack sack 1 {12408:13856} >
> 09:36:44.335591 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800227942 7692910>
> 09:38:44.351950 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800257942 7692910>
> 09:40:44.368172 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> 378 <nop,nop,timestamp 800287943 7692910>
>
> At the end of the dump here the connection is dropped by the client side.
>
>
> Darryl
>
>
> -
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: TCP SACK issue, hung connection, tcpdump included
2007-07-29 6:45 ` Willy Tarreau
@ 2007-07-29 8:26 ` Ilpo Järvinen
2007-07-29 8:54 ` Willy Tarreau
2007-07-29 8:56 ` David Miller
2007-07-29 8:39 ` Jan Engelhardt
1 sibling, 2 replies; 15+ messages in thread
From: Ilpo Järvinen @ 2007-07-29 8:26 UTC (permalink / raw)
To: Willy Tarreau; +Cc: Darryl L. Miles, linux-kernel, Netdev
On Sun, 29 Jul 2007, Willy Tarreau wrote:
> On Sun, Jul 29, 2007 at 06:59:26AM +0100, Darryl L. Miles wrote:
> > CLIENT = Linux 2.6.20.1-smp [Customer build]
> > SERVER = Linux 2.6.9-55.ELsmp [Red Hat Enterprise Linux AS release 4
> > (Nahant Update 5)]
> >
> > The problems start around time index 09:21:39.860302 when the CLIENT issues
> > a TCP packet with SACK option set (seemingly for a data segment which has
> > already been seen) from that point on the connection hangs.
...That's DSACK and it's being correctly sent. To me, it seems unlikely to
be the cause for this breakage...
> Where was the capture taken ? on CLIENT or on SERVER (I suspect client from
> the timers) ?
...I would guess the same based on SYN timestamps (and from the DSACK
timestamps)...
> A possible, but very unlikely reason would be an MTU limitation
> somewhere, because the segment which never gets correctly ACKed is also the
> largest one in this trace.
Limitation for 48 byte segments? You have to be kidding... :-) But yes,
it seems that one of the directions is dropping packets for some reason
though I would not assume MTU limitation... Or did you mean some other
segment?
> Also, if everything is right with the packets on the server side, then
> it would means that it's the RHEL kernel which is buggy (which does not
> mean that the same bug does not exist in mainline).
...There are two independed signs that server side is not getting the
packets (ack field is not advanced nor do the retransmissions of an old
data cease) so IMHO that would the first thing to rule out.
> > Full dump available via email.
> >
> >
> > 09:12:13.444999 IP CLIENT.50727 > SERVER.ssh: S 2919512080:2919512080(0)
> > win 5840 <mss 1460,sackOK,timestamp 799860259 0,nop,wscale 7>
> > 09:12:13.535643 IP SERVER.ssh > CLIENT.50727: S 492909547:492909547(0) ack
> > 2919512081 win 5792 <mss 1460,sackOK,timestamp 7126976 799860259,nop,wscale
> > 2>
> > 09:12:13.535717 IP CLIENT.50727 > SERVER.ssh: . ack 1 win 46
> > <nop,nop,timestamp 799860282 7126976>
> > 09:12:13.665481 IP SERVER.ssh > CLIENT.50727: P 1:24(23) ack 1 win 1448
> > <nop,nop,timestamp 7127074 799860282>
> > 09:12:13.665895 IP CLIENT.50727 > SERVER.ssh: . ack 24 win 46
> > <nop,nop,timestamp 799860314 7127074>
> > 09:12:13.666044 IP CLIENT.50727 > SERVER.ssh: P 1:23(22) ack 24 win 46
> > <nop,nop,timestamp 799860314 7127074>
> > 09:12:13.776318 IP SERVER.ssh > CLIENT.50727: . ack 23 win 1448
> > <nop,nop,timestamp 7127216 799860314>
> >
> > ...SNIPPED SUCCESSFUL TRAFFIC...
> >
> > 09:21:39.490740 IP SERVER.ssh > CLIENT.50727: P 18200:18464(264) ack 2991
> > win 2728 <nop,nop,timestamp 7692910 800001727>
> > 09:21:39.490775 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800001755 7692910>
> > 09:21:39.860245 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 7693293 800001749>
> > 09:21:39.860302 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800001847 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:21:40.453440 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 7693887 800001749>
> > 09:21:40.453495 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800001996 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:21:41.641821 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 7695075 800001749>
> > 09:21:41.641938 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800002293 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:21:44.017552 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 7697451 800001749>
> > 09:21:44.017622 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800002887 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:21:48.770051 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 7702203 800001749>
> > 09:21:48.770099 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800004075 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:21:58.274061 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 7711707 800001749>
> > 09:21:58.274180 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800006450 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:22:17.282035 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 7730715 800001749>
> > 09:22:17.282153 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800011202 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:22:55.298955 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 7768731 800001749>
> > 09:22:55.299023 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800020705 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:24:11.329853 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 7844763 800001749>
> > 09:24:11.329923 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800039711 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:26:11.331578 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 7964763 800001749>
> > 09:26:11.331699 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800069708 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:26:13.011885 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800070128 7692910>
> > 09:26:13.309032 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800070202 7692910>
> > 09:26:13.901048 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800070350 7692910>
> > 09:26:15.085103 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800070646 7692910>
> > 09:26:17.453195 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800071238 7692910>
> > 09:26:22.189378 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800072422 7692910>
> > 09:26:31.661696 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800074790 7692910>
> > 09:26:50.610374 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800079526 7692910>
> > 09:27:28.499729 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800088998 7692910>
> > 09:28:11.331256 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 8084763 800001749>
> > 09:28:11.331354 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800099704 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:28:44.286495 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800107942 7692910>
> > 09:30:11.330959 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 8204763 800001749>
> > 09:30:11.331074 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800129701 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:30:44.298756 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800137942 7692910>
> > 09:32:11.331661 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 8324763 800001749>
> > 09:32:11.331727 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800159698 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:32:44.311051 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800167942 7692910>
> > 09:34:11.332375 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 8444763 800001749>
> > 09:34:11.332447 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800189695 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:34:44.323298 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800197942 7692910>
> > 09:36:11.332073 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > win 2728 <nop,nop,timestamp 8564763 800001749>
> > 09:36:11.332166 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > <nop,nop,timestamp 800219692 7692910,nop,nop,sack sack 1 {12408:13856} >
> > 09:36:44.335591 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800227942 7692910>
> > 09:38:44.351950 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800257942 7692910>
> > 09:40:44.368172 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > 378 <nop,nop,timestamp 800287943 7692910>
> >
> > At the end of the dump here the connection is dropped by the client side.
...There a limit on how many times a retransmission of a segment is tried,
and in the dump both directions are trying to retransmit (and then they
finally gave up), perhaps CLIENT->SERVER direction drops all packets after
09:21:39.490740 (or even before that), so that no cumulative ACK for seq
18464 ever reaches SERVER (which is still having snd_una @ 12408 I guess)
nor the retransmissions of 2991:3039 from the CLIENT.
Is this reproducable? Can you somehow verify that the packets CLIENT is
sending are indeed received by the SERVER...?
--
i.
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: TCP SACK issue, hung connection, tcpdump included
2007-07-29 6:45 ` Willy Tarreau
2007-07-29 8:26 ` Ilpo Järvinen
@ 2007-07-29 8:39 ` Jan Engelhardt
1 sibling, 0 replies; 15+ messages in thread
From: Jan Engelhardt @ 2007-07-29 8:39 UTC (permalink / raw)
To: Willy Tarreau; +Cc: Darryl L. Miles, linux-kernel, netdev
On Jul 29 2007 08:45, Willy Tarreau wrote:
>On Sun, Jul 29, 2007 at 06:59:26AM +0100, Darryl L. Miles wrote:
>> CLIENT = Linux 2.6.20.1-smp [Customer build]
>> SERVER = Linux 2.6.9-55.ELsmp [Red Hat Enterprise Linux AS release 4
>> (Nahant Update 5)]
>>
>> The problems start around time index 09:21:39.860302 when the CLIENT issues
>> a TCP packet with SACK option set (seemingly for a data segment which has
>> already been seen) from that point on the connection hangs.
>
>Where was the capture taken ? on CLIENT or on SERVER (I suspect client from
>the timers) ? A possible, but very unlikely reason would be an MTU limitation
>somewhere, because the segment which never gets correctly ACKed is also the
>largest one in this trace.[...]
I had something similar (and most strangely enough, it only seemed to happen
when the source and/or destination address was outside a given subnet). It
boiled down to that some switch acted really strange and God knows why. A
tcpdump on *both* sides (server+client) each showed that the *other* peer sent
a FIN/RST. Well in the end I settled with setting sys.net.ipv4.tcp_sack=0,
no idea if the broken switch got replaced in the meantime.
Well, just letting you know that it is not limited to computers.
Jan
--
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: TCP SACK issue, hung connection, tcpdump included
2007-07-29 8:26 ` Ilpo Järvinen
@ 2007-07-29 8:54 ` Willy Tarreau
2007-07-29 9:28 ` Ilpo Järvinen
2007-07-29 8:56 ` David Miller
1 sibling, 1 reply; 15+ messages in thread
From: Willy Tarreau @ 2007-07-29 8:54 UTC (permalink / raw)
To: Ilpo Järvinen; +Cc: Darryl L. Miles, linux-kernel, Netdev
On Sun, Jul 29, 2007 at 11:26:00AM +0300, Ilpo Järvinen wrote:
> On Sun, 29 Jul 2007, Willy Tarreau wrote:
>
> > On Sun, Jul 29, 2007 at 06:59:26AM +0100, Darryl L. Miles wrote:
> > > CLIENT = Linux 2.6.20.1-smp [Customer build]
> > > SERVER = Linux 2.6.9-55.ELsmp [Red Hat Enterprise Linux AS release 4
> > > (Nahant Update 5)]
> > >
> > > The problems start around time index 09:21:39.860302 when the CLIENT issues
> > > a TCP packet with SACK option set (seemingly for a data segment which has
> > > already been seen) from that point on the connection hangs.
>
> ...That's DSACK and it's being correctly sent. To me, it seems unlikely to
> be the cause for this breakage...
>
> > Where was the capture taken ? on CLIENT or on SERVER (I suspect client from
> > the timers) ?
>
> ...I would guess the same based on SYN timestamps (and from the DSACK
> timestamps)...
>
> > A possible, but very unlikely reason would be an MTU limitation
> > somewhere, because the segment which never gets correctly ACKed is also the
> > largest one in this trace.
>
> Limitation for 48 byte segments? You have to be kidding... :-) But yes,
> it seems that one of the directions is dropping packets for some reason
> though I would not assume MTU limitation... Or did you mean some other
> segment?
No, I was talking about the 1448 bytes segments. But in fact I don't
believe it much because the SACKs are always retransmitted just afterwards.
BTW, some information are missing. It would have been better if the trace
had been read with tcpdump -Svv. We would have got seq numbers and ttl.
Also, we do not know if there's a firewall between both sides. Sometimes,
some IDS identify attacks in crypted traffic and kill connections. It
might have been the case here, with the connection closed one way on an
intermediate firewall.
Regards,
Willy
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: TCP SACK issue, hung connection, tcpdump included
2007-07-29 8:26 ` Ilpo Järvinen
2007-07-29 8:54 ` Willy Tarreau
@ 2007-07-29 8:56 ` David Miller
1 sibling, 0 replies; 15+ messages in thread
From: David Miller @ 2007-07-29 8:56 UTC (permalink / raw)
To: ilpo.jarvinen; +Cc: w, darryl-mailinglists, linux-kernel, netdev
From: "Ilpo_Järvinen" <ilpo.jarvinen@helsinki.fi>
Date: Sun, 29 Jul 2007 11:26:00 +0300 (EEST)
> Is this reproducable? Can you somehow verify that the packets CLIENT is
> sending are indeed received by the SERVER...?
One possibility is drops due to checksum errors on the receiver, this
tends to pop up from time to time, let's see some SNMP statistics.
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: TCP SACK issue, hung connection, tcpdump included
2007-07-29 8:54 ` Willy Tarreau
@ 2007-07-29 9:28 ` Ilpo Järvinen
2007-07-29 16:07 ` Willy Tarreau
0 siblings, 1 reply; 15+ messages in thread
From: Ilpo Järvinen @ 2007-07-29 9:28 UTC (permalink / raw)
To: Willy Tarreau; +Cc: Darryl L. Miles, linux-kernel, Netdev
[-- Attachment #1: Type: TEXT/PLAIN, Size: 3481 bytes --]
On Sun, 29 Jul 2007, Willy Tarreau wrote:
> On Sun, Jul 29, 2007 at 11:26:00AM +0300, Ilpo Järvinen wrote:
> > On Sun, 29 Jul 2007, Willy Tarreau wrote:
> >
> > > On Sun, Jul 29, 2007 at 06:59:26AM +0100, Darryl L. Miles wrote:
> > > > CLIENT = Linux 2.6.20.1-smp [Customer build]
> > > > SERVER = Linux 2.6.9-55.ELsmp [Red Hat Enterprise Linux AS release 4
> > > > (Nahant Update 5)]
> > > >
> > > > The problems start around time index 09:21:39.860302 when the CLIENT issues
> > > > a TCP packet with SACK option set (seemingly for a data segment which has
> > > > already been seen) from that point on the connection hangs.
> >
> > ...That's DSACK and it's being correctly sent. To me, it seems unlikely to
> > be the cause for this breakage...
> >
> > > Where was the capture taken ? on CLIENT or on SERVER (I suspect client from
> > > the timers) ?
> >
> > ...I would guess the same based on SYN timestamps (and from the DSACK
> > timestamps)...
> >
> > > A possible, but very unlikely reason would be an MTU limitation
> > > somewhere, because the segment which never gets correctly ACKed is also the
> > > largest one in this trace.
> >
> > Limitation for 48 byte segments? You have to be kidding... :-) But yes,
> > it seems that one of the directions is dropping packets for some reason
> > though I would not assume MTU limitation... Or did you mean some other
> > segment?
>
> No, I was talking about the 1448 bytes segments. But in fact I don't
> believe it much because the SACKs are always retransmitted just afterwards.
Ah, but it's ACKed correctly right below it...:
[...snip...]
> > > > 09:21:39.490740 IP SERVER.ssh > CLIENT.50727: P 18200:18464(264) ack 2991
> > > > win 2728 <nop,nop,timestamp 7692910 800001727>
> > > > 09:21:39.490775 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > > > <nop,nop,timestamp 800001755 7692910>
> > > > 09:21:39.860245 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > > > win 2728 <nop,nop,timestamp 7693293 800001749>
...segment below snd_una arrived => snd_una remains 18464, receiver
generates a duplicate ACK:
> > > > 09:21:39.860302 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > > > <nop,nop,timestamp 800001847 7692910,nop,nop,sack sack 1 {12408:13856} >
The cumulative ACK field of it covers _everything_ below 18464 (i.e., it
ACKs them), including the 1448 bytes in 12408:13856... In addition, the
SACK block is DSACK information [RFC2883] telling explicitly the address
of the received duplicate block. However, if this ACK doesn't reach the
SERVER TCP, RTO is triggered and the first not yet cumulatively ACKed
segment is retransmitted (I guess cumulative ACKs up to 12408 arrived
without problems to the SERVER):
> > > > 09:21:40.453440 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > > > win 2728 <nop,nop,timestamp 7693887 800001749>
[...snip...]
> BTW, some information are missing. It would have been better if the trace
> had been read with tcpdump -Svv. We would have got seq numbers and ttl.
> Also, we do not know if there's a firewall between both sides. Sometimes,
> some IDS identify attacks in crypted traffic and kill connections. It
> might have been the case here, with the connection closed one way on an
> intermediate firewall.
Yeah, firewall or some other issue, I'd say it's quite unlikely a bug in
TCP because behavior to both directions indicate client -> sender
blackhole independently of each other...
--
i.
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: TCP SACK issue, hung connection, tcpdump included
2007-07-29 5:59 TCP SACK issue, hung connection, tcpdump included Darryl L. Miles
2007-07-29 6:45 ` Willy Tarreau
@ 2007-07-29 15:30 ` Phil Oester
1 sibling, 0 replies; 15+ messages in thread
From: Phil Oester @ 2007-07-29 15:30 UTC (permalink / raw)
To: Darryl L. Miles; +Cc: linux-kernel
On Sun, Jul 29, 2007 at 06:59:26AM +0100, Darryl L. Miles wrote:
> The problems start around time index 09:21:39.860302 when the CLIENT issues
> a TCP packet with SACK option set (seemingly for a data segment which has
> already been seen) from that point on the connection hangs.
I'd say most likely scenario is the SERVER is behind a Cisco Pix firewall,
which has known bugs in handling packets with sack option. By default the Cisco
has sequence number randomization enabled, but it's a half-assed implementation
which doesn't bother adjusting the sequence numbers inside sack options.
This has been reported to Cisco, and they don't seem to care. As a workaround,
you can do this:
echo 0 > /proc/sys/net/ipv4/tcp_sack
and it will probably fix it up. It'd be really nice, however, to have a per-route
option for sack, similar to how we can clamp window scaling per route. Something
like the below
ip r a <host> <gw> <nosack>
Phil
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: TCP SACK issue, hung connection, tcpdump included
2007-07-29 9:28 ` Ilpo Järvinen
@ 2007-07-29 16:07 ` Willy Tarreau
2007-07-29 16:28 ` Ilpo Järvinen
2007-07-31 5:03 ` Darryl L. Miles
0 siblings, 2 replies; 15+ messages in thread
From: Willy Tarreau @ 2007-07-29 16:07 UTC (permalink / raw)
To: Ilpo Järvinen; +Cc: Darryl L. Miles, linux-kernel, Netdev
On Sun, Jul 29, 2007 at 12:28:04PM +0300, Ilpo Järvinen wrote:
(...)
> > > Limitation for 48 byte segments? You have to be kidding... :-) But yes,
> > > it seems that one of the directions is dropping packets for some reason
> > > though I would not assume MTU limitation... Or did you mean some other
> > > segment?
> >
> > No, I was talking about the 1448 bytes segments. But in fact I don't
> > believe it much because the SACKs are always retransmitted just afterwards.
>
> Ah, but it's ACKed correctly right below it...:
>
> [...snip...]
> > > > > 09:21:39.490740 IP SERVER.ssh > CLIENT.50727: P 18200:18464(264) ack 2991
> > > > > win 2728 <nop,nop,timestamp 7692910 800001727>
> > > > > 09:21:39.490775 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > > > > <nop,nop,timestamp 800001755 7692910>
> > > > > 09:21:39.860245 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991
> > > > > win 2728 <nop,nop,timestamp 7693293 800001749>
>
> ...segment below snd_una arrived => snd_una remains 18464, receiver
> generates a duplicate ACK:
>
> > > > > 09:21:39.860302 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378
> > > > > <nop,nop,timestamp 800001847 7692910,nop,nop,sack sack 1 {12408:13856} >
>
> The cumulative ACK field of it covers _everything_ below 18464 (i.e., it
> ACKs them), including the 1448 bytes in 12408:13856... In addition, the
> SACK block is DSACK information [RFC2883] telling explicitly the address
> of the received duplicate block. However, if this ACK doesn't reach the
> SERVER TCP, RTO is triggered and the first not yet cumulatively ACKed
> segment is retransmitted (I guess cumulative ACKs up to 12408 arrived
> without problems to the SERVER):
Oh yes, you're damn right. I did not notice that the ACK was higher than
the SACK, I'm more used to read traces with absolute rather than relative
seq/acks.
So I agree, it is this ACK which is lost between client and server,
reinforcing the supposition about the location of the capture (client side).
> [...snip...]
>
> > BTW, some information are missing. It would have been better if the trace
> > had been read with tcpdump -Svv. We would have got seq numbers and ttl.
> > Also, we do not know if there's a firewall between both sides. Sometimes,
> > some IDS identify attacks in crypted traffic and kill connections. It
> > might have been the case here, with the connection closed one way on an
> > intermediate firewall.
>
> Yeah, firewall or some other issue, I'd say it's quite unlikely a bug in
> TCP because behavior to both directions indicate client -> sender
> blackhole independently of each other...
It would also be possible that something stupid between both ends simply
drops packets with the SACK option set. Also something which sometimes
happen is that some firewalls automatically translate sequence numbers
but not necessarily SACK values, which could pretty well lead to this
packet being received but ignored on the server side.
I'm pretty sure that the same trace taken on the server side will reveal
the reason for the problem.
Willy
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: TCP SACK issue, hung connection, tcpdump included
2007-07-29 16:07 ` Willy Tarreau
@ 2007-07-29 16:28 ` Ilpo Järvinen
2007-07-31 5:03 ` Darryl L. Miles
1 sibling, 0 replies; 15+ messages in thread
From: Ilpo Järvinen @ 2007-07-29 16:28 UTC (permalink / raw)
To: Willy Tarreau; +Cc: Ilpo Järvinen, Darryl L. Miles, linux-kernel, Netdev
[-- Attachment #1: Type: TEXT/PLAIN, Size: 1861 bytes --]
On Sun, 29 Jul 2007, Willy Tarreau wrote:
> On Sun, Jul 29, 2007 at 12:28:04PM +0300, Ilpo Järvinen wrote:
>
> > [...snip...]
> >
> > > BTW, some information are missing. It would have been better if the trace
> > > had been read with tcpdump -Svv. We would have got seq numbers and ttl.
> > > Also, we do not know if there's a firewall between both sides. Sometimes,
> > > some IDS identify attacks in crypted traffic and kill connections. It
> > > might have been the case here, with the connection closed one way on an
> > > intermediate firewall.
> >
> > Yeah, firewall or some other issue, I'd say it's quite unlikely a bug in
> > TCP because behavior to both directions indicate client -> sender
> > blackhole independently of each other...
>
> It would also be possible that something stupid between both ends simply
> drops packets with the SACK option set. Also something which sometimes
> happen is that some firewalls automatically translate sequence numbers
> but not necessarily SACK values, which could pretty well lead to this
> packet being received but ignored on the server side.
...One can toggle those off with /proc/sys/net/ipv4/tcp_dsack but I
suspect DSACKs are not the cause because these retransmissions neither
are making it through (there are many of them also earlier in the log,
just quoted the easiest ones :-) ):
> > > > 09:36:44.335591 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > > > 378 <nop,nop,timestamp 800227942 7692910>
> > > > 09:38:44.351950 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > > > 378 <nop,nop,timestamp 800257942 7692910>
> > > > 09:40:44.368172 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win
> > > > 378 <nop,nop,timestamp 800287943 7692910>
...there are no SACKs involved in them, yet no cumulative ACK ever
arrives from SERVER...
--
i.
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: TCP SACK issue, hung connection, tcpdump included
@ 2007-07-29 17:31 Darryl L. Miles
0 siblings, 0 replies; 15+ messages in thread
From: Darryl L. Miles @ 2007-07-29 17:31 UTC (permalink / raw)
To: linux-kernel
[-- Attachment #1: Type: text/plain, Size: 2301 bytes --]
This is a reproducible problem (would take me between 30 mins and a day
to reproduce it). Please feel free to provide me with tcpdump options
to be sure I include to get the information you need.
I've been informed there is no firewall at all, the only firewalling
that takes place is the local Linux netfilter, I've never audited the
kit at the SERVER end to know for sure.
I have run a tcpdump from the server side before now (not for the
tcpdump I enclosed) when try to diagnose the problem in the first place
and the triplet of packets:
09:28:11.331256 IP SERVER.ssh > CLIENT.50727: . 12408:13856(1448) ack 2991 win 2728 <nop,nop,timestamp 8084763 800001749>
09:28:11.331354 IP CLIENT.50727 > SERVER.ssh: . ack 18464 win 378 <nop,nop,timestamp 800099704 7692910,nop,nop,sack sack 1 {12408:13856} >
09:28:44.286495 IP CLIENT.50727 > SERVER.ssh: P 2991:3039(48) ack 18464 win 378 <nop,nop,timestamp 800107942 7692910>
That keeps repeating from that point in was observable at both sides.
No checksum errors have ever been shown on any tcpdump I saw.
The dump I posted was the first dump I was able to reliably reproduce
(observing from the CLIENT end), I'm pretty sure given some time
tomorrow I could create you 2 dumps of the same session (the view from
each end). Looking a little more at the dump today I see that at time
index 09:21:39.860245 to server sends data from seq 12408:13856 again.
Here is a snippet that backs up a little more around the time the
trouble starts, as SERVER send sequence 12408 seems to be the problem
maybe I need to illustrate what happened when that sequence was first sent.
Excuse my understanding if it seems a bit limited. SACK is only used
when segments are dropped and from inspecting the dump I can't spot
where a lost segment occurs. My main question is why does the CLIENT
ack data 12408:13856 and beyond all the way up to 18464 (@
09:21:39.490775) and then start to SACK {12408:13856} (@ 09:21:39.860302) ?
Does this mean the client is the buggy end for going back on data it has
already acked cleanly, that would be my interpretation of events.
Enclosed should be a tcpdump with -vvS of the same session as before
observing from the client side.
I hope I've answered all the points raised in this thread.
Darryl
[-- Attachment #2: linux.tcpdump.txt --]
[-- Type: text/plain, Size: 39037 bytes --]
09:12:13.444999 IP (tos 0x0, ttl 64, id 56883, offset 0, flags [DF], proto 6, length: 60) CLIENT.50727 > SERVER.ssh: S [tcp sum ok] 2919512080:2919512080(0) win 5840 <mss 1460,sackOK,timestamp 799860259 0,nop,wscale 7>
09:12:13.535643 IP (tos 0x0, ttl 50, id 0, offset 0, flags [DF], proto 6, length: 60) SERVER.ssh > CLIENT.50727: S [tcp sum ok] 492909547:492909547(0) ack 2919512081 win 5792 <mss 1460,sackOK,timestamp 7126976 799860259,nop,wscale 2>
09:12:13.535717 IP (tos 0x0, ttl 64, id 56884, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919512081:2919512081(0) ack 492909548 win 46 <nop,nop,timestamp 799860282 7126976>
09:12:13.665481 IP (tos 0x0, ttl 50, id 62454, offset 0, flags [DF], proto 6, length: 75) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492909548:492909571(23) ack 2919512081 win 1448 <nop,nop,timestamp 7127074 799860282>
09:12:13.665895 IP (tos 0x0, ttl 64, id 56885, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919512081:2919512081(0) ack 492909571 win 46 <nop,nop,timestamp 799860314 7127074>
09:12:13.666044 IP (tos 0x0, ttl 64, id 56886, offset 0, flags [DF], proto 6, length: 74) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919512081:2919512103(22) ack 492909571 win 46 <nop,nop,timestamp 799860314 7127074>
09:12:13.776318 IP (tos 0x0, ttl 50, id 62456, offset 0, flags [DF], proto 6, length: 52) SERVER.ssh > CLIENT.50727: . [tcp sum ok] 492909571:492909571(0) ack 2919512103 win 1448 <nop,nop,timestamp 7127216 799860314>
09:12:13.776438 IP (tos 0x0, ttl 64, id 56887, offset 0, flags [DF], proto 6, length: 692) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919512103:2919512743(640) ack 492909571 win 46 <nop,nop,timestamp 799860342 7127216>
09:12:13.780319 IP (tos 0x0, ttl 50, id 62458, offset 0, flags [DF], proto 6, length: 692) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492909571:492910211(640) ack 2919512103 win 1448 <nop,nop,timestamp 7127218 799860314>
09:12:13.823098 IP (tos 0x0, ttl 64, id 56888, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919512743:2919512743(0) ack 492910211 win 56 <nop,nop,timestamp 799860353 7127218>
09:12:13.927103 IP (tos 0x0, ttl 50, id 62460, offset 0, flags [DF], proto 6, length: 52) SERVER.ssh > CLIENT.50727: . [tcp sum ok] 492910211:492910211(0) ack 2919512743 win 1768 <nop,nop,timestamp 7127367 799860342>
09:12:13.927174 IP (tos 0x0, ttl 64, id 56889, offset 0, flags [DF], proto 6, length: 76) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919512743:2919512767(24) ack 492910211 win 56 <nop,nop,timestamp 799860379 7127367>
09:12:14.016977 IP (tos 0x0, ttl 50, id 62462, offset 0, flags [DF], proto 6, length: 52) SERVER.ssh > CLIENT.50727: . [tcp sum ok] 492910211:492910211(0) ack 2919512767 win 1768 <nop,nop,timestamp 7127457 799860379>
09:12:14.019975 IP (tos 0x0, ttl 50, id 62464, offset 0, flags [DF], proto 6, length: 204) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492910211:492910363(152) ack 2919512767 win 1768 <nop,nop,timestamp 7127460 799860379>
09:12:14.020010 IP (tos 0x0, ttl 64, id 56890, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919512767:2919512767(0) ack 492910363 win 66 <nop,nop,timestamp 799860403 7127460>
09:12:14.024613 IP (tos 0x0, ttl 64, id 56891, offset 0, flags [DF], proto 6, length: 196) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919512767:2919512911(144) ack 492910363 win 66 <nop,nop,timestamp 799860404 7127460>
09:12:14.130830 IP (tos 0x0, ttl 50, id 62466, offset 0, flags [DF], proto 6, length: 516) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492910363:492910827(464) ack 2919512911 win 2088 <nop,nop,timestamp 7127569 799860404>
09:12:14.137330 IP (tos 0x0, ttl 64, id 56892, offset 0, flags [DF], proto 6, length: 68) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919512911:2919512927(16) ack 492910827 win 76 <nop,nop,timestamp 799860432 7127569>
09:12:14.267637 IP (tos 0x0, ttl 50, id 62468, offset 0, flags [DF], proto 6, length: 52) SERVER.ssh > CLIENT.50727: . [tcp sum ok] 492910827:492910827(0) ack 2919512927 win 2088 <nop,nop,timestamp 7127708 799860432>
09:12:14.267694 IP (tos 0x0, ttl 64, id 56893, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919512927:2919512975(48) ack 492910827 win 76 <nop,nop,timestamp 799860465 7127708>
09:12:14.360511 IP (tos 0x0, ttl 50, id 62470, offset 0, flags [DF], proto 6, length: 52) SERVER.ssh > CLIENT.50727: . [tcp sum ok] 492910827:492910827(0) ack 2919512975 win 2088 <nop,nop,timestamp 7127800 799860465>
09:12:14.360519 IP (tos 0x0, ttl 50, id 62472, offset 0, flags [DF], proto 6, length: 100) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492910827:492910875(48) ack 2919512975 win 2088 <nop,nop,timestamp 7127801 799860465>
09:12:14.362148 IP (tos 0x0, ttl 64, id 56894, offset 0, flags [DF], proto 6, length: 116) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919512975:2919513039(64) ack 492910875 win 76 <nop,nop,timestamp 799860488 7127801>
09:12:14.454385 IP (tos 0x0, ttl 50, id 62474, offset 0, flags [DF], proto 6, length: 132) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492910875:492910955(80) ack 2919513039 win 2088 <nop,nop,timestamp 7127895 799860488>
09:12:14.456614 IP (tos 0x0, ttl 64, id 56895, offset 0, flags [DF], proto 6, length: 148) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919513039:2919513135(96) ack 492910955 win 76 <nop,nop,timestamp 799860512 7127895>
09:12:14.554241 IP (tos 0x0, ttl 50, id 62476, offset 0, flags [DF], proto 6, length: 132) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492910955:492911035(80) ack 2919513135 win 2088 <nop,nop,timestamp 7127994 799860512>
09:12:14.555478 IP (tos 0x0, ttl 64, id 56896, offset 0, flags [DF], proto 6, length: 148) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919513135:2919513231(96) ack 492911035 win 76 <nop,nop,timestamp 799860536 7127994>
09:12:14.649117 IP (tos 0x0, ttl 50, id 62478, offset 0, flags [DF], proto 6, length: 132) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911035:492911115(80) ack 2919513231 win 2088 <nop,nop,timestamp 7128089 799860536>
09:12:14.649329 IP (tos 0x0, ttl 64, id 56897, offset 0, flags [DF], proto 6, length: 292) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919513231:2919513471(240) ack 492911115 win 76 <nop,nop,timestamp 799860560 7128089>
09:12:14.748977 IP (tos 0x0, ttl 50, id 62480, offset 0, flags [DF], proto 6, length: 244) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911115:492911307(192) ack 2919513471 win 2088 <nop,nop,timestamp 7128188 799860560>
09:12:14.751894 IP (tos 0x0, ttl 64, id 56898, offset 0, flags [DF], proto 6, length: 436) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919513471:2919513855(384) ack 492911307 win 86 <nop,nop,timestamp 799860586 7128188>
09:12:14.856839 IP (tos 0x0, ttl 50, id 62482, offset 0, flags [DF], proto 6, length: 84) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911307:492911339(32) ack 2919513855 win 2408 <nop,nop,timestamp 7128297 799860586>
09:12:14.857277 IP (tos 0x0, ttl 64, id 56899, offset 0, flags [DF], proto 6, length: 116) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919513855:2919513919(64) ack 492911339 win 86 <nop,nop,timestamp 799860612 7128297>
09:12:14.949708 IP (tos 0x0, ttl 50, id 62484, offset 0, flags [DF], proto 6, length: 100) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911339:492911387(48) ack 2919513919 win 2408 <nop,nop,timestamp 7128389 799860612>
09:12:14.950029 IP (tos 0x10, ttl 64, id 56900, offset 0, flags [DF], proto 6, length: 436) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919513919:2919514303(384) ack 492911387 win 86 <nop,nop,timestamp 799860635 7128389>
09:12:15.055558 IP (tos 0x0, ttl 50, id 62486, offset 0, flags [DF], proto 6, length: 100) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911387:492911435(48) ack 2919514303 win 2728 <nop,nop,timestamp 7128495 799860635>
09:12:15.095129 IP (tos 0x10, ttl 64, id 56901, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514303:2919514303(0) ack 492911435 win 86 <nop,nop,timestamp 799860671 7128495>
09:12:15.463999 IP (tos 0x0, ttl 50, id 62488, offset 0, flags [DF], proto 6, length: 180) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911435:492911563(128) ack 2919514303 win 2728 <nop,nop,timestamp 7128904 799860671>
09:12:15.464049 IP (tos 0x10, ttl 64, id 56902, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514303:2919514303(0) ack 492911563 win 96 <nop,nop,timestamp 799860764 7128904>
09:12:15.512928 IP (tos 0x0, ttl 50, id 62490, offset 0, flags [DF], proto 6, length: 116) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911563:492911627(64) ack 2919514303 win 2728 <nop,nop,timestamp 7128953 799860671>
09:12:15.512970 IP (tos 0x10, ttl 64, id 56903, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514303:2919514303(0) ack 492911627 win 96 <nop,nop,timestamp 799860776 7128953>
09:12:15.554874 IP (tos 0x0, ttl 50, id 62492, offset 0, flags [DF], proto 6, length: 132) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911627:492911707(80) ack 2919514303 win 2728 <nop,nop,timestamp 7128995 799860764>
09:12:15.554924 IP (tos 0x10, ttl 64, id 56904, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514303:2919514303(0) ack 492911707 win 96 <nop,nop,timestamp 799860786 7128995>
09:12:17.241429 IP (tos 0x10, ttl 64, id 56905, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514303:2919514351(48) ack 492911707 win 96 <nop,nop,timestamp 799861208 7128995>
09:12:17.333440 IP (tos 0x0, ttl 50, id 62494, offset 0, flags [DF], proto 6, length: 100) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911707:492911755(48) ack 2919514351 win 2728 <nop,nop,timestamp 7130773 799861208>
09:12:17.333494 IP (tos 0x10, ttl 64, id 56906, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514351:2919514351(0) ack 492911755 win 96 <nop,nop,timestamp 799861231 7130773>
09:12:17.413945 IP (tos 0x10, ttl 64, id 56907, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514351:2919514399(48) ack 492911755 win 96 <nop,nop,timestamp 799861251 7130773>
09:12:17.451470 IP (tos 0x10, ttl 64, id 56908, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514399:2919514447(48) ack 492911755 win 96 <nop,nop,timestamp 799861260 7130773>
09:12:17.506205 IP (tos 0x0, ttl 50, id 62496, offset 0, flags [DF], proto 6, length: 100) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911755:492911803(48) ack 2919514399 win 2728 <nop,nop,timestamp 7130947 799861251>
09:12:17.506256 IP (tos 0x10, ttl 64, id 56909, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514447:2919514447(0) ack 492911803 win 96 <nop,nop,timestamp 799861274 7130947>
09:12:17.529044 IP (tos 0x10, ttl 64, id 56910, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514447:2919514495(48) ack 492911803 win 96 <nop,nop,timestamp 799861280 7130947>
09:12:17.544148 IP (tos 0x0, ttl 50, id 62498, offset 0, flags [DF], proto 6, length: 100) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911803:492911851(48) ack 2919514447 win 2728 <nop,nop,timestamp 7130984 799861260>
09:12:17.587209 IP (tos 0x10, ttl 64, id 56911, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514495:2919514495(0) ack 492911851 win 96 <nop,nop,timestamp 799861294 7130984>
09:12:17.622042 IP (tos 0x0, ttl 50, id 62500, offset 0, flags [DF], proto 6, length: 100) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911851:492911899(48) ack 2919514495 win 2728 <nop,nop,timestamp 7131062 799861280>
09:12:17.622079 IP (tos 0x10, ttl 64, id 56912, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514495:2919514495(0) ack 492911899 win 96 <nop,nop,timestamp 799861303 7131062>
09:12:17.694314 IP (tos 0x10, ttl 64, id 56913, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514495:2919514543(48) ack 492911899 win 96 <nop,nop,timestamp 799861321 7131062>
09:12:17.756916 IP (tos 0x10, ttl 64, id 56914, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514543:2919514591(48) ack 492911899 win 96 <nop,nop,timestamp 799861337 7131062>
09:12:17.786827 IP (tos 0x0, ttl 50, id 62502, offset 0, flags [DF], proto 6, length: 100) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911899:492911947(48) ack 2919514543 win 2728 <nop,nop,timestamp 7131227 799861321>
09:12:17.786976 IP (tos 0x10, ttl 64, id 56915, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514591:2919514591(0) ack 492911947 win 96 <nop,nop,timestamp 799861344 7131227>
09:12:17.799913 IP (tos 0x10, ttl 64, id 56916, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514591:2919514639(48) ack 492911947 win 96 <nop,nop,timestamp 799861347 7131227>
09:12:17.849734 IP (tos 0x0, ttl 50, id 62504, offset 0, flags [DF], proto 6, length: 100) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911947:492911995(48) ack 2919514591 win 2728 <nop,nop,timestamp 7131290 799861337>
09:12:17.891225 IP (tos 0x10, ttl 64, id 56917, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514639:2919514639(0) ack 492911995 win 96 <nop,nop,timestamp 799861370 7131290>
09:12:17.892674 IP (tos 0x0, ttl 50, id 62506, offset 0, flags [DF], proto 6, length: 100) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492911995:492912043(48) ack 2919514639 win 2728 <nop,nop,timestamp 7131332 799861347>
09:12:17.892737 IP (tos 0x10, ttl 64, id 56918, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514639:2919514639(0) ack 492912043 win 96 <nop,nop,timestamp 799861371 7131332>
09:12:17.894672 IP (tos 0x0, ttl 50, id 62508, offset 0, flags [DF], proto 6, length: 164) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492912043:492912155(112) ack 2919514639 win 2728 <nop,nop,timestamp 7131334 799861347>
09:12:17.894743 IP (tos 0x10, ttl 64, id 56919, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514639:2919514639(0) ack 492912155 win 96 <nop,nop,timestamp 799861371 7131334>
09:12:17.982558 IP (tos 0x0, ttl 50, id 62510, offset 0, flags [DF], proto 6, length: 196) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492912155:492912299(144) ack 2919514639 win 2728 <nop,nop,timestamp 7131422 799861370>
09:12:17.982614 IP (tos 0x10, ttl 64, id 56920, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514639:2919514639(0) ack 492912299 win 106 <nop,nop,timestamp 799861393 7131422>
09:14:17.167894 IP (tos 0x10, ttl 64, id 56921, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514639:2919514687(48) ack 492912299 win 106 <nop,nop,timestamp 799891186 7131422>
09:14:17.261238 IP (tos 0x0, ttl 50, id 62512, offset 0, flags [DF], proto 6, length: 100) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492912299:492912347(48) ack 2919514687 win 2728 <nop,nop,timestamp 7250700 799891186>
09:14:17.261317 IP (tos 0x10, ttl 64, id 56922, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514687:2919514687(0) ack 492912347 win 106 <nop,nop,timestamp 799891210 7250700>
09:14:17.500671 IP (tos 0x10, ttl 64, id 56923, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514687:2919514735(48) ack 492912347 win 106 <nop,nop,timestamp 799891269 7250700>
09:14:17.592778 IP (tos 0x0, ttl 50, id 62514, offset 0, flags [DF], proto 6, length: 100) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492912347:492912395(48) ack 2919514735 win 2728 <nop,nop,timestamp 7251033 799891269>
09:14:17.592821 IP (tos 0x10, ttl 64, id 56924, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514735:2919514735(0) ack 492912395 win 106 <nop,nop,timestamp 799891292 7251033>
09:14:17.913715 IP (tos 0x10, ttl 64, id 56925, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514735:2919514783(48) ack 492912395 win 106 <nop,nop,timestamp 799891373 7251033>
09:14:18.006215 IP (tos 0x0, ttl 50, id 62516, offset 0, flags [DF], proto 6, length: 148) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492912395:492912491(96) ack 2919514783 win 2728 <nop,nop,timestamp 7251446 799891373>
09:14:18.006262 IP (tos 0x10, ttl 64, id 56926, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514783:2919514783(0) ack 492912491 win 106 <nop,nop,timestamp 799891396 7251446>
09:14:18.106615 IP (tos 0x10, ttl 64, id 56927, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514783:2919514831(48) ack 492912491 win 106 <nop,nop,timestamp 799891421 7251446>
09:14:18.146506 IP (tos 0x10, ttl 64, id 56928, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514831:2919514879(48) ack 492912491 win 106 <nop,nop,timestamp 799891431 7251446>
09:14:18.198965 IP (tos 0x0, ttl 50, id 62518, offset 0, flags [DF], proto 6, length: 116) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492912491:492912555(64) ack 2919514831 win 2728 <nop,nop,timestamp 7251638 799891421>
09:14:18.199102 IP (tos 0x10, ttl 64, id 56929, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514879:2919514879(0) ack 492912555 win 106 <nop,nop,timestamp 799891444 7251638>
09:14:18.238897 IP (tos 0x0, ttl 50, id 62520, offset 0, flags [DF], proto 6, length: 148) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492912555:492912651(96) ack 2919514879 win 2728 <nop,nop,timestamp 7251678 799891431>
09:14:18.238936 IP (tos 0x10, ttl 64, id 56930, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514879:2919514879(0) ack 492912651 win 106 <nop,nop,timestamp 799891454 7251678>
09:14:18.253235 IP (tos 0x10, ttl 64, id 56931, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514879:2919514927(48) ack 492912651 win 106 <nop,nop,timestamp 799891458 7251678>
09:14:18.345749 IP (tos 0x0, ttl 50, id 62522, offset 0, flags [DF], proto 6, length: 132) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492912651:492912731(80) ack 2919514927 win 2728 <nop,nop,timestamp 7251786 799891458>
09:14:18.387524 IP (tos 0x10, ttl 64, id 56932, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514927:2919514927(0) ack 492912731 win 106 <nop,nop,timestamp 799891491 7251786>
09:14:18.712692 IP (tos 0x10, ttl 64, id 56933, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514927:2919514975(48) ack 492912731 win 106 <nop,nop,timestamp 799891572 7251786>
09:14:18.805120 IP (tos 0x0, ttl 50, id 62524, offset 0, flags [DF], proto 6, length: 164) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492912731:492912843(112) ack 2919514975 win 2728 <nop,nop,timestamp 7252245 799891572>
09:14:18.805177 IP (tos 0x10, ttl 64, id 56934, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514975:2919514975(0) ack 492912843 win 106 <nop,nop,timestamp 799891596 7252245>
09:14:18.813107 IP (tos 0x0, ttl 50, id 62526, offset 0, flags [DF], proto 6, length: 148) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492912843:492912939(96) ack 2919514975 win 2728 <nop,nop,timestamp 7252253 799891572>
09:14:18.813138 IP (tos 0x10, ttl 64, id 56935, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514975:2919514975(0) ack 492912939 win 106 <nop,nop,timestamp 799891598 7252253>
09:14:18.902004 IP (tos 0x0, ttl 50, id 62528, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492912939:492914387(1448) ack 2919514975 win 2728 <nop,nop,timestamp 7252336 799891596>
09:14:18.902036 IP (tos 0x10, ttl 64, id 56936, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514975:2919514975(0) ack 492914387 win 129 <nop,nop,timestamp 799891620 7252336>
09:14:18.907996 IP (tos 0x0, ttl 50, id 62530, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492914387:492915835(1448) ack 2919514975 win 2728 <nop,nop,timestamp 7252336 799891596>
09:14:18.908027 IP (tos 0x10, ttl 64, id 56937, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514975:2919514975(0) ack 492915835 win 151 <nop,nop,timestamp 799891621 7252336>
09:14:18.913988 IP (tos 0x0, ttl 50, id 62532, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492915835:492917283(1448) ack 2919514975 win 2728 <nop,nop,timestamp 7252343 799891598>
09:14:18.914031 IP (tos 0x10, ttl 64, id 56938, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514975:2919514975(0) ack 492917283 win 174 <nop,nop,timestamp 799891623 7252343>
09:14:18.919984 IP (tos 0x0, ttl 50, id 62534, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492917283:492918731(1448) ack 2919514975 win 2728 <nop,nop,timestamp 7252343 799891598>
09:14:18.920016 IP (tos 0x10, ttl 64, id 56939, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514975:2919514975(0) ack 492918731 win 197 <nop,nop,timestamp 799891624 7252343>
09:14:18.999899 IP (tos 0x0, ttl 50, id 62536, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492918731:492920179(1448) ack 2919514975 win 2728 <nop,nop,timestamp 7252433 799891620>
09:14:19.000023 IP (tos 0x10, ttl 64, id 56940, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514975:2919514975(0) ack 492920179 win 219 <nop,nop,timestamp 799891644 7252433>
09:14:18.999913 IP (tos 0x0, ttl 50, id 62538, offset 0, flags [DF], proto 6, length: 60) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492920179:492920187(8) ack 2919514975 win 2728 <nop,nop,timestamp 7252433 799891620>
09:14:19.000069 IP (tos 0x10, ttl 64, id 56941, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919514975:2919514975(0) ack 492920187 win 219 <nop,nop,timestamp 799891644 7252433>
09:21:38.811134 IP (tos 0x10, ttl 64, id 56942, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919514975:2919515023(48) ack 492920187 win 219 <nop,nop,timestamp 800001585 7252433>
09:21:38.903536 IP (tos 0x0, ttl 50, id 62540, offset 0, flags [DF], proto 6, length: 100) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492920187:492920235(48) ack 2919515023 win 2728 <nop,nop,timestamp 7692342 800001585>
09:21:38.903622 IP (tos 0x10, ttl 64, id 56943, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515023:2919515023(0) ack 492920235 win 219 <nop,nop,timestamp 800001608 7692342>
09:21:39.276350 IP (tos 0x10, ttl 64, id 56944, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515023:2919515071(48) ack 492920235 win 219 <nop,nop,timestamp 800001701 7692342>
09:21:39.368907 IP (tos 0x0, ttl 50, id 62542, offset 0, flags [DF], proto 6, length: 100) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492920235:492920283(48) ack 2919515071 win 2728 <nop,nop,timestamp 7692807 800001701>
09:21:39.368980 IP (tos 0x10, ttl 64, id 56945, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492920283 win 219 <nop,nop,timestamp 800001725 7692807>
09:21:39.377887 IP (tos 0x0, ttl 50, id 62544, offset 0, flags [DF], proto 6, length: 148) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492920283:492920379(96) ack 2919515071 win 2728 <nop,nop,timestamp 7692816 800001701>
09:21:39.377919 IP (tos 0x10, ttl 64, id 56946, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492920379 win 219 <nop,nop,timestamp 800001727 7692816>
09:21:39.378889 IP (tos 0x0, ttl 50, id 62546, offset 0, flags [DF], proto 6, length: 180) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492920379:492920507(128) ack 2919515071 win 2728 <nop,nop,timestamp 7692816 800001701>
09:21:39.378920 IP (tos 0x10, ttl 64, id 56947, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492920507 win 242 <nop,nop,timestamp 800001727 7692816>
09:21:39.465799 IP (tos 0x0, ttl 50, id 62548, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492920507:492921955(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7692898 800001725>
09:21:39.465869 IP (tos 0x10, ttl 64, id 56948, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492921955 win 264 <nop,nop,timestamp 800001749 7692898>
09:21:39.471778 IP (tos 0x0, ttl 50, id 62550, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7692898 800001725>
09:21:39.471825 IP (tos 0x10, ttl 64, id 56949, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492923403 win 287 <nop,nop,timestamp 800001750 7692898>
09:21:39.477768 IP (tos 0x0, ttl 50, id 62552, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492923403:492924851(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7692907 800001727>
09:21:39.477801 IP (tos 0x10, ttl 64, id 56950, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492924851 win 310 <nop,nop,timestamp 800001752 7692907>
09:21:39.483760 IP (tos 0x0, ttl 50, id 62554, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492924851:492926299(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7692907 800001727>
09:21:39.483793 IP (tos 0x10, ttl 64, id 56951, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492926299 win 332 <nop,nop,timestamp 800001753 7692907>
09:21:39.489756 IP (tos 0x0, ttl 50, id 62556, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492926299:492927747(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7692910 800001727>
09:21:39.489800 IP (tos 0x10, ttl 64, id 56952, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492927747 win 355 <nop,nop,timestamp 800001755 7692910>
09:21:39.490740 IP (tos 0x0, ttl 50, id 62558, offset 0, flags [DF], proto 6, length: 316) SERVER.ssh > CLIENT.50727: P [tcp sum ok] 492927747:492928011(264) ack 2919515071 win 2728 <nop,nop,timestamp 7692910 800001727>
09:21:39.490775 IP (tos 0x10, ttl 64, id 56953, offset 0, flags [DF], proto 6, length: 52) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492928011 win 378 <nop,nop,timestamp 800001755 7692910>
09:21:39.860245 IP (tos 0x0, ttl 50, id 62560, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7693293 800001749>
09:21:39.860302 IP (tos 0x10, ttl 64, id 56954, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492928011 win 378 <nop,nop,timestamp 800001847 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:21:40.453440 IP (tos 0x0, ttl 50, id 62562, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7693887 800001749>
09:21:40.453495 IP (tos 0x10, ttl 64, id 56955, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492928011 win 378 <nop,nop,timestamp 800001996 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:21:41.641821 IP (tos 0x0, ttl 50, id 62564, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7695075 800001749>
09:21:41.641938 IP (tos 0x10, ttl 64, id 56956, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492928011 win 378 <nop,nop,timestamp 800002293 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:21:44.017552 IP (tos 0x0, ttl 50, id 62566, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7697451 800001749>
09:21:44.017622 IP (tos 0x10, ttl 64, id 56957, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492928011 win 378 <nop,nop,timestamp 800002887 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:21:48.770051 IP (tos 0x0, ttl 50, id 62568, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7702203 800001749>
09:21:48.770099 IP (tos 0x10, ttl 64, id 56958, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492928011 win 378 <nop,nop,timestamp 800004075 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:21:58.274061 IP (tos 0x0, ttl 50, id 62570, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7711707 800001749>
09:21:58.274180 IP (tos 0x10, ttl 64, id 56959, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492928011 win 378 <nop,nop,timestamp 800006450 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:22:17.282035 IP (tos 0x0, ttl 50, id 62572, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7730715 800001749>
09:22:17.282153 IP (tos 0x10, ttl 64, id 56960, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492928011 win 378 <nop,nop,timestamp 800011202 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:22:55.298955 IP (tos 0x0, ttl 50, id 62574, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7768731 800001749>
09:22:55.299023 IP (tos 0x10, ttl 64, id 56961, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492928011 win 378 <nop,nop,timestamp 800020705 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:24:11.329853 IP (tos 0x0, ttl 50, id 62576, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7844763 800001749>
09:24:11.329923 IP (tos 0x10, ttl 64, id 56962, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492928011 win 378 <nop,nop,timestamp 800039711 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:26:11.331578 IP (tos 0x0, ttl 50, id 62578, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 7964763 800001749>
09:26:11.331699 IP (tos 0x10, ttl 64, id 56963, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515071:2919515071(0) ack 492928011 win 378 <nop,nop,timestamp 800069708 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:26:13.011885 IP (tos 0x10, ttl 64, id 56964, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800070128 7692910>
09:26:13.309032 IP (tos 0x10, ttl 64, id 56965, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800070202 7692910>
09:26:13.901048 IP (tos 0x10, ttl 64, id 56966, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800070350 7692910>
09:26:15.085103 IP (tos 0x10, ttl 64, id 56967, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800070646 7692910>
09:26:17.453195 IP (tos 0x10, ttl 64, id 56968, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800071238 7692910>
09:26:22.189378 IP (tos 0x10, ttl 64, id 56969, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800072422 7692910>
09:26:31.661696 IP (tos 0x10, ttl 64, id 56970, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800074790 7692910>
09:26:50.610374 IP (tos 0x10, ttl 64, id 56971, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800079526 7692910>
09:27:28.499729 IP (tos 0x10, ttl 64, id 56972, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800088998 7692910>
09:27:43.240418 IP (tos 0x0, ttl 63, id 0, offset 0, flags [DF], proto 1, length: 84) CLIENT > SERVER: icmp 64: echo request seq 0
09:27:43.339568 IP (tos 0x0, ttl 50, id 14266, offset 0, flags [none], proto 1, length: 84) SERVER > CLIENT: icmp 64: echo reply seq 0
09:27:44.245669 IP (tos 0x0, ttl 63, id 0, offset 0, flags [DF], proto 1, length: 84) CLIENT > SERVER: icmp 64: echo request seq 1
09:27:44.339196 IP (tos 0x0, ttl 50, id 14267, offset 0, flags [none], proto 1, length: 84) SERVER > CLIENT: icmp 64: echo reply seq 1
09:28:11.331256 IP (tos 0x0, ttl 50, id 62580, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 8084763 800001749>
09:28:11.331354 IP (tos 0x10, ttl 64, id 56973, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515119:2919515119(0) ack 492928011 win 378 <nop,nop,timestamp 800099704 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:28:44.286495 IP (tos 0x10, ttl 64, id 56974, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800107942 7692910>
09:30:11.330959 IP (tos 0x0, ttl 50, id 62582, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 8204763 800001749>
09:30:11.331074 IP (tos 0x10, ttl 64, id 56975, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515119:2919515119(0) ack 492928011 win 378 <nop,nop,timestamp 800129701 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:30:44.298756 IP (tos 0x10, ttl 64, id 56976, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800137942 7692910>
09:32:11.331661 IP (tos 0x0, ttl 50, id 62584, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 8324763 800001749>
09:32:11.331727 IP (tos 0x10, ttl 64, id 56977, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515119:2919515119(0) ack 492928011 win 378 <nop,nop,timestamp 800159698 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:32:44.311051 IP (tos 0x10, ttl 64, id 56978, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800167942 7692910>
09:34:11.332375 IP (tos 0x0, ttl 50, id 62586, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 8444763 800001749>
09:34:11.332447 IP (tos 0x10, ttl 64, id 56979, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515119:2919515119(0) ack 492928011 win 378 <nop,nop,timestamp 800189695 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:34:44.323298 IP (tos 0x10, ttl 64, id 56980, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800197942 7692910>
09:36:11.332073 IP (tos 0x0, ttl 50, id 62588, offset 0, flags [DF], proto 6, length: 1500) SERVER.ssh > CLIENT.50727: . 492921955:492923403(1448) ack 2919515071 win 2728 <nop,nop,timestamp 8564763 800001749>
09:36:11.332166 IP (tos 0x10, ttl 64, id 56981, offset 0, flags [DF], proto 6, length: 64) CLIENT.50727 > SERVER.ssh: . [tcp sum ok] 2919515119:2919515119(0) ack 492928011 win 378 <nop,nop,timestamp 800219692 7692910,nop,nop,sack sack 1 {492921955:492923403} >
09:36:44.335591 IP (tos 0x10, ttl 64, id 56982, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800227942 7692910>
09:38:44.351950 IP (tos 0x10, ttl 64, id 56983, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800257942 7692910>
09:40:44.368172 IP (tos 0x10, ttl 64, id 56984, offset 0, flags [DF], proto 6, length: 100) CLIENT.50727 > SERVER.ssh: P [tcp sum ok] 2919515071:2919515119(48) ack 492928011 win 378 <nop,nop,timestamp 800287943 7692910>
09:46:02.051649 IP (tos 0x0, ttl 63, id 0, offset 0, flags [DF], proto 1, length: 84) CLIENT > SERVER: icmp 64: echo request seq 0
09:46:02.149135 IP (tos 0x0, ttl 50, id 14877, offset 0, flags [none], proto 1, length: 84) SERVER > CLIENT: icmp 64: echo reply seq 0
09:46:03.056134 IP (tos 0x0, ttl 63, id 0, offset 0, flags [DF], proto 1, length: 84) CLIENT > SERVER: icmp 64: echo request seq 1
09:46:03.144778 IP (tos 0x0, ttl 50, id 14878, offset 0, flags [none], proto 1, length: 84) SERVER > CLIENT: icmp 64: echo reply seq 1
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: TCP SACK issue, hung connection, tcpdump included
2007-07-29 16:07 ` Willy Tarreau
2007-07-29 16:28 ` Ilpo Järvinen
@ 2007-07-31 5:03 ` Darryl L. Miles
2007-08-02 9:23 ` Ilpo Järvinen
1 sibling, 1 reply; 15+ messages in thread
From: Darryl L. Miles @ 2007-07-31 5:03 UTC (permalink / raw)
To: linux-kernel; +Cc: Netdev
I've been able to capture a tcpdump from both ends during the problem
and its my belief there is a bug in 2.6.20.1 (at the client side) in
that it issues a SACK option for an old sequence which the current
window being advertised is beyond it. This is the most concerning issue
as the integrity of the sequence numbers doesn't seem right (to my
limited understanding anyhow).
There is another concern of why the SERVER performed a retransmission in
the first place, when the tcpdump shows the ack covering it has been seen.
I have made available the full dumps at:
http://darrylmiles.org/snippets/lkml/20070731/
There are some changes in 2.6.22 that appear to affect TCP SACK handling
does this fix a known issue ?
This sequence is interesting from the client side:
03:58:56.419034 IP SERVER.ssh > CLIENT.43726: . 26016:27464(1448) ack
4239 win 2728 <nop,nop,timestamp 16345815 819458859> # S1
03:58:56.419100 IP CLIENT.43726 > SERVER.ssh: . ack 27464 win 501
<nop,nop,timestamp 819458884 16345815> # C1
03:58:56.422019 IP SERVER.ssh > CLIENT.43726: P 27464:28176(712) ack
4239 win 2728 <nop,nop,timestamp 16345815 819458859> # S2
03:58:56.422078 IP CLIENT.43726 > SERVER.ssh: . ack 28176 win 501
<nop,nop,timestamp 819458884 16345815> # C2
The above 4 packets look as expect to me. Then we suddenly see a
retransmission of 26016:27464.
03:58:56.731597 IP SERVER.ssh > CLIENT.43726: . 26016:27464(1448) ack
4239 win 2728 <nop,nop,timestamp 16346128 819458864> # S3
So the client instead of discarding the retransmission of duplicate
segment, issues a SACK.
03:58:56.731637 IP CLIENT.43726 > SERVER.ssh: . ack 28176 win 501
<nop,nop,timestamp 819458962 16345815,nop,nop,sack sack 1 {26016:27464}
> # C3
In response to this the server is confused ??? It responds to
sack{26016:27464} but the client is also saying "wnd 28176". Wouldn't
the server expect "wnd < 26016" to there is a segment to retransmit ?
03:58:57.322800 IP SERVER.ssh > CLIENT.43726: . 26016:27464(1448) ack
4239 win 2728 <nop,nop,timestamp 16346718 819458864> # S4
Now viewed from the server side:
03:58:56.365655 IP SERVER.ssh > CLIENT.43726: . 26016:27464(1448) ack
4239 win 2728 <nop,nop,timestamp 16345815 819458859> # S1
03:58:56.365662 IP SERVER.ssh > CLIENT.43726: P 27464:28176(712) ack
4239 win 2728 <nop,nop,timestamp 16345815 819458859> # S2
03:58:56.374633 IP CLIENT.43726 > SERVER.ssh: . ack 24144 win 488
<nop,nop,timestamp 819458861 16345731> # propagation delay
03:58:56.381630 IP CLIENT.43726 > SERVER.ssh: . ack 25592 win 501
<nop,nop,timestamp 819458863 16345734> # propagation delay
03:58:56.384503 IP CLIENT.43726 > SERVER.ssh: . ack 26016 win 501
<nop,nop,timestamp 819458864 16345734> # propagation delay
03:58:56.462583 IP CLIENT.43726 > SERVER.ssh: . ack 27464 win 501
<nop,nop,timestamp 819458884 16345815> # C1
03:58:56.465707 IP CLIENT.43726 > SERVER.ssh: . ack 28176 win 501
<nop,nop,timestamp 819458884 16345815> # C2
The above packets just as expected.
03:58:56.678546 IP SERVER.ssh > CLIENT.43726: . 26016:27464(1448) ack
4239 win 2728 <nop,nop,timestamp 16346128 819458864> # S3
I guess the above packet is indeed a retransmission of "# S1" but why
was it retransmitted, when we can clearly see "# C1" above acks this
segment ? It is not even as if the retransmission escaped before the
kernel had time to process the ack, as 200ms elapsed. CONCERN NUMBER TWO
03:58:56.774778 IP CLIENT.43726 > SERVER.ssh: . ack 28176 win 501
<nop,nop,timestamp 819458962 16345815,nop,nop,sack sack 1 {26016:27464}
> # C3
CONCERN NUMBER ONE, why in response to that escaped retransmission was a
SACK the appropriate response ? When at the time the client sent the
SACK it had received all data upto 28176, a fact it continues to
advertise in the "# C3" packet above.
There is nothing wrong is the CLIENT expecting to see a retransmission
of that segment at this point in time that is an expected circumstance.
03:58:57.269529 IP SERVER.ssh > CLIENT.43726: . 26016:27464(1448) ack
4239 win 2728 <nop,nop,timestamp 16346718 819458864> # S4
Darryl
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: TCP SACK issue, hung connection, tcpdump included
2007-07-31 5:03 ` Darryl L. Miles
@ 2007-08-02 9:23 ` Ilpo Järvinen
2007-08-02 9:26 ` David Miller
2007-08-02 16:58 ` Darryl Miles
0 siblings, 2 replies; 15+ messages in thread
From: Ilpo Järvinen @ 2007-08-02 9:23 UTC (permalink / raw)
To: Darryl L. Miles; +Cc: LKML, Netdev
On Tue, 31 Jul 2007, Darryl L. Miles wrote:
> I've been able to capture a tcpdump from both ends during the problem and its
> my belief there is a bug in 2.6.20.1 (at the client side) in that it issues a
> SACK option for an old sequence which the current window being advertised is
> beyond it. This is the most concerning issue as the integrity of the sequence
> numbers doesn't seem right (to my limited understanding anyhow).
You probably didn't check the reference I explicitly gave to those who
are not familiar how DSACK works, just in case you didn't pick it up last
time, here it is again for you: RFC2883... However, if DSACKs really
bother you still (though it shouldn't :-)), IIRC I also told you how
you're able to turn it off (tcp_dsack sysctl) but I assure you that it's
not a bug but feature called DSACK [RFC2883], there's _absolutely_ nothing
wrong with it, instead, it would be wrong to _not_ send the below snd_una
SACK in this scenario when tcp_dsack set to 1.
> There is another concern of why the SERVER performed a retransmission in the
> first place, when the tcpdump shows the ack covering it has been seen.
There are only three possible reasons to this thing:
1) The ACK didn't reach the SERVER (your logs prove this to not be the
case)
2) The ACK got discarded by the SERVER
3) The SERVER (not the client) is buggy and sends an incorrect
retransmission
...So we have just two options remaining...
> I have made available the full dumps at:
>
> http://darrylmiles.org/snippets/lkml/20070731/
Thanks about these... Based on a quick check, it is rather clear that the
SERVER is for some reason discarding the packets it's receiving:
04:11:26.833935 IP CLIENT.43726 > SERVER.ssh: P 4239:4287(48) ack 28176 win 501 <nop,nop,timestamp 819646456 16345815>
04:11:27.132425 IP SERVER.ssh > CLIENT.43726: . 26016:27464(1448) ack 4239 win 2728 <nop,nop,timestamp 17096579 819458864>
04:11:27.230081 IP CLIENT.43726 > SERVER.ssh: . ack 28176 win 501 <nop,nop,timestamp 819646555 16345815,nop,nop
Notice, (cumulative) ack field didn't advance though new data arrived, and
for the record, it's in advertised window too. There are no DSACK in here
so your theory about below snd_una SACK won't help to explain this one
at all... We'll just have to figure out why it's discarding it. And
there's even more to prove this...
> This sequence is interesting from the client side:
>
> 03:58:56.419034 IP SERVER.ssh > CLIENT.43726: . 26016:27464(1448) ack 4239
> win 2728 <nop,nop,timestamp 16345815 819458859> # S1
> 03:58:56.419100 IP CLIENT.43726 > SERVER.ssh: . ack 27464 win 501
> <nop,nop,timestamp 819458884 16345815> # C1
> 03:58:56.422019 IP SERVER.ssh > CLIENT.43726: P 27464:28176(712) ack 4239
> win 2728 <nop,nop,timestamp 16345815 819458859> # S2
> 03:58:56.422078 IP CLIENT.43726 > SERVER.ssh: . ack 28176 win 501
> <nop,nop,timestamp 819458884 16345815> # C2
>
> The above 4 packets look as expect to me. Then we suddenly see a
> retransmission of 26016:27464.
>
> 03:58:56.731597 IP SERVER.ssh > CLIENT.43726: . 26016:27464(1448) ack 4239
> win 2728 <nop,nop,timestamp 16346128 819458864> # S3
...Look at this on the retransmission:
... timestamp 16346128 819458864>
...it tells us what really got received by the TCP. The corresponding ACK
with matching timestamp is, surprise, surprise, this one:
> 03:58:56.340180 IP CLIENT.43726 > SERVER.ssh: . ack 26016 win 501
> <nop,nop,timestamp 819458864 16345734>
...thus the SERVER has _not_ received but discarded the subsequent
cumulative ACKs!!! Therefore it's retransmitting from 26016 onward but
never receives any reply as everything seems to get discarded...
There was one bad checksum btw:
> 03:58:56.365662 IP (tos 0x10, ttl 64, id 28685, offset 0, flags [DF],
> proto 6, length: 764) SERVER.ssh > CLIENT.43726: P [bad tcp cksum 6662
> (->ef2b)!] 617734888:617735600(712) ack 2634113543 win 2728
> <nop,nop,timestamp 16345815 819458859>
> There are some changes in 2.6.22 that appear to affect TCP SACK handling
> does this fix a known issue ?
There is no such "known issue" :-)... This issue has nothing to do with
TCP SACK handling, since that code _won't_ be reached... We could verify
that from the timestamps. But if you still insist that SACK under snd_una
is the issue, please turn tcp_dsack to 0 on the CLIENT, you will not get
them after that and you can be happy as your out-of-window SACK "issue"
is then fixed :-)...
...Seriously, somebody else than me is probably better in suggesting what
could cause the discarding at the SERVER in this case. SNMP stuff Dave was
asking could help, you can find them from /proc/net/{netstat,snmp}...
--
i.
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: TCP SACK issue, hung connection, tcpdump included
2007-08-02 9:23 ` Ilpo Järvinen
@ 2007-08-02 9:26 ` David Miller
2007-08-02 16:58 ` Darryl Miles
1 sibling, 0 replies; 15+ messages in thread
From: David Miller @ 2007-08-02 9:26 UTC (permalink / raw)
To: ilpo.jarvinen; +Cc: darryl-mailinglists, linux-kernel, netdev
From: "Ilpo_Järvinen" <ilpo.jarvinen@helsinki.fi>
Date: Thu, 2 Aug 2007 12:23:23 +0300 (EEST)
> ...Seriously, somebody else than me is probably better in suggesting what
> could cause the discarding at the SERVER in this case. SNMP stuff Dave was
> asking could help, you can find them from /proc/net/{netstat,snmp}...
That will also tell us if TCP discarded the packet due to
timestamps tests or similar.
^ permalink raw reply [flat|nested] 15+ messages in thread
* Re: TCP SACK issue, hung connection, tcpdump included
2007-08-02 9:23 ` Ilpo Järvinen
2007-08-02 9:26 ` David Miller
@ 2007-08-02 16:58 ` Darryl Miles
1 sibling, 0 replies; 15+ messages in thread
From: Darryl Miles @ 2007-08-02 16:58 UTC (permalink / raw)
To: Ilpo Järvinen; +Cc: LKML, Netdev
Ilpo Järvinen wrote:
> On Tue, 31 Jul 2007, Darryl L. Miles wrote:
>
>> I've been able to capture a tcpdump from both ends during the problem and its
>> my belief there is a bug in 2.6.20.1 (at the client side) in that it issues a
>> SACK option for an old sequence which the current window being advertised is
>> beyond it. This is the most concerning issue as the integrity of the sequence
>> numbers doesn't seem right (to my limited understanding anyhow).
>
> You probably didn't check the reference I explicitly gave to those who
> are not familiar how DSACK works, just in case you didn't pick it up last
> time, here it is again for you: RFC2883...
I've now squinted the D-SACK RFC and understand a little about this,
however the RFC does make the claim "This extension is compatible with
current implementations of the SACK option in TCP. That is, if one of
the TCP end-nodes does not implement this D-SACK extension and the other
TCP end-node does, we believe that this use of the D-SACK extension by
one of the end nodes will not introduce problems."
What if it turns out that is not true for a large enough number of SACK
implementations out there; in the timeframe that SACK was supported but
D-SACK was not supported. Would it be possible to clearly catagorise an
implementation to be:
* 100% SACK RFC compliant. SACK works and by virtue of the mandatory
requirements written into the previous SACK RFCs then this
implementation would never see a problem with receiving D-SACK even
through the stack itself does not support D-SACK.
* Mostly SACK RFC compliant. SACK works but if it saw D-SACK it would
have a problems dealing with it, possibly resulting in fatal TCP
lockups. Are there SACK implementation mandatory requirements in place
for to be able to clearly draw the line and state that the 2.6.9 SACK
implementation was not RFC compliant.
* 100% SACK and D-DACK RFC compliant. Such an implementation was
written to support D-SACK on top of SACK.
So if there is a problem whos fault would it be:
* The original SACK RFCs for not specifying a mandatory course of
action to take which D-SACK exploits. Thus making the claim in RFC2883
unsound.
* The older linux kernel for not being 100% SACK RFC compliant in its
implementation ? Not a lot we can do about this now, but if we're able
to identify there maybe backward compatibility issues with the same
implementation thats a useful point to take forward.
* The newer linux kernel for enabling D-SACK by default when RFC2883
doesn't even claim a cast iron case for D-SACK to be compatible with any
100% RFC compliant SACK implementation.
Does TCP support the concept of vendor dependent options, that would be
TCP options which are in a special range that would both identify the
vendor and the vendors-specific option id. Such a system would allow
Linux to implement a <D-SACK Ok> option, even if the RFC claims one is
not needed. This would allow moving forward through this era until such
point in time when it was officially agreed it was just a linux problem
or an RFC problem. If its an RFC problem then IANA (or whoever) would
issue a generic TCP option for it.
If the dump on this problem really does identify a risk/problem when as
its between 2 version of linux a vendor specific option also makes sense.
I don't really want to switch new useful stuff off by default (so it
never gets used), I'm all for experimentation but not to the point of
failure between default configurations of widely distributed version of
the kernel.
So thats the technical approaches I can come up with to discuss. Does
Ilpo have a particular vested interest in D-SACK that should be disclosed?
> However, if DSACKs really
> bother you still (though it shouldn't :-)), IIRC I also told you how
> you're able to turn it off (tcp_dsack sysctl) but I assure you that it's
> not a bug but feature called DSACK [RFC2883], there's _absolutely_
nothing
> wrong with it, instead, it would be wrong to _not_ send the below
snd_una
> SACK in this scenario when tcp_dsack set to 1.
So it is necessary to turn off a TCP option (that is enabled by default)
to be sure to have reliable TCP connections (that don't lock up) in the
bugfree Linux networking stack ? This is absurd.
If such an option causes such a problem; then that option should not be
enabled by default. If however the problem is because of a bug then let
us continue to try to isolate the cause rather than wallpaper over the
cracks with the voodoo of turning things that are enabled by default off.
It only makes sense to turn options off when there is a 3rd party
involved (or other means beyond your control) which is affecting
function, the case here is that two Linux kernel stacks are affected and
no 3rd party device has been shown to be affecting function.
>> There is another concern of why the SERVER performed a retransmission in the
>> first place, when the tcpdump shows the ack covering it has been seen.
>
> There are only three possible reasons to this thing:
> 1) The ACK didn't reach the SERVER (your logs prove this to not be the
> case)
> 2) The ACK got discarded by the SERVER
I'd thought about that one, its a possibility. The server in question
does have period of high UDP load on a fair number of UDP sockets at
once (a few 1000). Both systems have 2Gb of RAM. The server has maybe
just 250Mb of RSS of all apps combined.
> 3) The SERVER (not the client) is buggy and sends an incorrect
> retransmission
This was my initial stab at the cause, simply due to the sequence like
this (from when the lockup starts) :
03:58:56.731637 IP (tos 0x10, ttl 64, id 53311, offset 0, flags [DF],
proto 6, length: 64) CLIENT.43726 > SERVER.ssh: . [tcp sum ok]
2634113543:2634113543(0) ack 617735600 win 501 <nop,nop,timestamp
819458962 16345815,nop,nop,sack sack 1 {617733440:617734888} >
03:58:57.322800 IP (tos 0x0, ttl 50, id 28689, offset 0, flags [DF],
proto 6, length: 1500) SERVER.ssh > CLIENT.43726: .
617733440:617734888(1448) ack 2634113543 win 2728 <nop,nop,timestamp
16346718 819458864>
The client sent a SACK. But from understanding more about D-SACK, this
is a valid D-SACK response, but it appears to confuse the older Linux
kernel at the server end.
> ...So we have just two options remaining...
>
>> I have made available the full dumps at:
>>
>> http://darrylmiles.org/snippets/lkml/20070731/
>
> Thanks about these... Based on a quick check, it is rather clear that the
> SERVER is for some reason discarding the packets it's receiving:
>
> 04:11:26.833935 IP CLIENT.43726 > SERVER.ssh: P 4239:4287(48) ack 28176 win 501 <nop,nop,timestamp 819646456 16345815>
> 04:11:27.132425 IP SERVER.ssh > CLIENT.43726: . 26016:27464(1448) ack 4239 win 2728 <nop,nop,timestamp 17096579 819458864>
> 04:11:27.230081 IP CLIENT.43726 > SERVER.ssh: . ack 28176 win 501 <nop,nop,timestamp 819646555 16345815,nop,nop
>
> Notice, (cumulative) ack field didn't advance though new data arrived, and
> for the record, it's in advertised window too. There are no DSACK in here
> so your theory about below snd_una SACK won't help to explain this one
> at all... We'll just have to figure out why it's discarding it. And
> there's even more to prove this...
Agreed on this. However discarding data is allowed (providing it is
intentional discarding not a bug where the TCP stack is discarding
segments it shouldn't), TCP should recover providing sufficient packets
get through.
So the SNMP data would show up intentional discards (due to
memory/resource issues). So I'll get some of those too.
>> ...SNIPPED...MORE SIGNS OF UNEXPLAINED DISCARDING BY THE SERVER...
>
> There was one bad checksum btw:
>
>> 03:58:56.365662 IP (tos 0x10, ttl 64, id 28685, offset 0, flags [DF],
>> proto 6, length: 764) SERVER.ssh > CLIENT.43726: P [bad tcp cksum 6662
>> (->ef2b)!] 617734888:617735600(712) ack 2634113543 win 2728
>> <nop,nop,timestamp 16345815 819458859>
I noticed this one too, but discarded the "[bad tcp cksum 6662
->ef2b)!]" as bogus on the basis of the following packet turning up at
the client:
03:58:56.422019 IP (tos 0x0, ttl 50, id 28685, offset 0, flags [DF],
proto 6, length: 764) SERVER.ssh > CLIENT.43726: P [tcp sum ok]
617734888:617735600(712) ack 2634113543 win 2728 <nop,nop,timestamp
16345815 819458859>
Forgive me if I am mistaken, but while the server reports a checksum
error, the client did not. I took this to be a misreporting by tcpdump
at the server, probably due to the "e1000" network card checksum
offloading (I'd guess this level of card does offloading, I've never
audited the driver before). If you search both dumps for the timestamps
"16345815 819458859" two packets were sent by the server and two
received by the server with those timestamps.
>> There are some changes in 2.6.22 that appear to affect TCP SACK handling
>> does this fix a known issue ?
>
> There is no such "known issue" :-)... This issue has nothing to do with
> TCP SACK handling, since that code _won't_ be reached... We could verify
> that from the timestamps. But if you still insist that SACK under snd_una
> is the issue, please turn tcp_dsack to 0 on the CLIENT, you will not get
> them after that and you can be happy as your out-of-window SACK "issue"
> is then fixed :-)...
I had thrown up one interpretation of events for others to comment, so
thanks for your comments and viewpoint on the issue.
> ...Seriously, somebody else than me is probably better in suggesting what
> could cause the discarding at the SERVER in this case. SNMP stuff Dave was
> asking could help, you can find them from /proc/net/{netstat,snmp}...
The SNMP stats aren't so useful right now as
the box has been rebooted since then but I shall attempt to capture
/proc/net/* data, cause the problem, then capture /proc/net/* data again
if those numbers can help.
Darryl
^ permalink raw reply [flat|nested] 15+ messages in thread
end of thread, other threads:[~2007-08-02 16:59 UTC | newest]
Thread overview: 15+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2007-07-29 5:59 TCP SACK issue, hung connection, tcpdump included Darryl L. Miles
2007-07-29 6:45 ` Willy Tarreau
2007-07-29 8:26 ` Ilpo Järvinen
2007-07-29 8:54 ` Willy Tarreau
2007-07-29 9:28 ` Ilpo Järvinen
2007-07-29 16:07 ` Willy Tarreau
2007-07-29 16:28 ` Ilpo Järvinen
2007-07-31 5:03 ` Darryl L. Miles
2007-08-02 9:23 ` Ilpo Järvinen
2007-08-02 9:26 ` David Miller
2007-08-02 16:58 ` Darryl Miles
2007-07-29 8:56 ` David Miller
2007-07-29 8:39 ` Jan Engelhardt
2007-07-29 15:30 ` Phil Oester
-- strict thread matches above, loose matches on Subject: below --
2007-07-29 17:31 Darryl L. Miles
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox