* Re: Crazy TCP bug (keepalive flood?) in 2.6.32?
@ 2009-12-26 15:03 Denys Fedoryshchenko
2009-12-26 19:24 ` Ilpo Järvinen
2010-01-11 13:02 ` Ilpo Järvinen
0 siblings, 2 replies; 24+ messages in thread
From: Denys Fedoryshchenko @ 2009-12-26 15:03 UTC (permalink / raw)
To: Ilpo Järvinen, netdev
Few more dumps. I notice:
1)Ack always equal 1
2)It is usually first segment of data sent (?)
Maybe some value not initialised properly?
17:03:50.406118 IP (tos 0x0, ttl 64, id 57958, offset 0, flags [DF], proto TCP
(6), length 1492)
194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
win 7479, length 1452
17:03:50.407413 IP (tos 0x0, ttl 64, id 57959, offset 0, flags [DF], proto TCP
(6), length 1492)
194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
win 7479, length 1452
17:03:50.408516 IP (tos 0x0, ttl 64, id 57960, offset 0, flags [DF], proto TCP
(6), length 1492)
194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
win 7479, length 1452
17:03:50.409553 IP (tos 0x0, ttl 64, id 57961, offset 0, flags [DF], proto TCP
(6), length 1492)
194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
win 7479, length 1452
17:03:50.410424 IP (tos 0x0, ttl 64, id 57962, offset 0, flags [DF], proto TCP
(6), length 1492)
194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
win 7479, length 1452
17:04:39.801149 IP (tos 0x0, ttl 64, id 19431, offset 0, flags [DF], proto TCP
(6), length 517)
194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
(correct), seq 0:477, ack 1, win 8730, length 477
17:04:39.802538 IP (tos 0x0, ttl 64, id 19432, offset 0, flags [DF], proto TCP
(6), length 517)
194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
(correct), seq 0:477, ack 1, win 8730, length 477
17:04:39.803438 IP (tos 0x0, ttl 64, id 19433, offset 0, flags [DF], proto TCP
(6), length 517)
194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
(correct), seq 0:477, ack 1, win 8730, length 477
17:04:39.804251 IP (tos 0x0, ttl 64, id 19434, offset 0, flags [DF], proto TCP
(6), length 517)
194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
(correct), seq 0:477, ack 1, win 8730, length 477
17:04:39.805050 IP (tos 0x0, ttl 64, id 19435, offset 0, flags [DF], proto TCP
(6), length 517)
194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
(correct), seq 0:477, ack 1, win 8730, length 477
17:06:22.123862 IP (tos 0x0, ttl 64, id 25912, offset 0, flags [DF], proto TCP
(6), length 1492)
194.146.153.114.8080 > 172.16.180.148.50101: Flags [.], seq 0:1452, ack 1,
win 108, length 1452
17:06:22.124440 IP (tos 0x0, ttl 64, id 25913, offset 0, flags [DF], proto TCP
(6), length 1492)
194.146.153.114.8080 > 172.16.180.148.50101: Flags [.], seq 0:1452, ack 1,
win 108, length 1452
17:06:22.125600 IP (tos 0x0, ttl 64, id 25914, offset 0, flags [DF], proto TCP
(6), length 1492)
194.146.153.114.8080 > 172.16.180.148.50101: Flags [.], seq 0:1452, ack 1,
win 108, length 1452
^C17:06:22.126243 IP (tos 0x0, ttl 64, id 25915, offset 0, flags [DF], proto
TCP (6), length 1492)
194.146.153.114.8080 > 172.16.180.148.50101: Flags [.], seq 0:1452, ack 1,
win 108, length 1452
17:06:43.404279 IP (tos 0x0, ttl 64, id 10279, offset 0, flags [DF], proto TCP
(6), length 768)
194.146.153.114.8080 > 172.16.199.151.49404: Flags [FP.], cksum 0x4ac3
(correct), seq 0:728, ack 1, win 9816, length 728
17:06:43.405819 IP (tos 0x0, ttl 64, id 10281, offset 0, flags [DF], proto TCP
(6), length 768)
194.146.153.114.8080 > 172.16.199.151.49404: Flags [FP.], cksum 0x4ac3
(correct), seq 0:728, ack 1, win 9816, length 728
17:06:43.406670 IP (tos 0x0, ttl 64, id 10282, offset 0, flags [DF], proto TCP
(6), length 768)
194.146.153.114.8080 > 172.16.199.151.49404: Flags [FP.], cksum 0x4ac3
(correct), seq 0:728, ack 1, win 9816, length 728
17:06:43.407821 IP (tos 0x0, ttl 64, id 10283, offset 0, flags [DF], proto TCP
(6), length 768)
194.146.153.114.8080 > 172.16.199.151.49404: Flags [FP.], cksum 0x4ac3
(correct), seq 0:728, ack 1, win 9816, length 728
17:07:09.933303 IP (tos 0x0, ttl 64, id 41731, offset 0, flags [DF], proto TCP
(6), length 555)
194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
(correct), seq 0:515, ack 1, win 6432, length 515
17:07:09.934305 IP (tos 0x0, ttl 64, id 41732, offset 0, flags [DF], proto TCP
(6), length 555)
194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
(correct), seq 0:515, ack 1, win 6432, length 515
17:07:09.935076 IP (tos 0x0, ttl 64, id 41733, offset 0, flags [DF], proto TCP
(6), length 555)
194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
(correct), seq 0:515, ack 1, win 6432, length 515
17:07:09.935887 IP (tos 0x0, ttl 64, id 41734, offset 0, flags [DF], proto TCP
(6), length 555)
194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
(correct), seq 0:515, ack 1, win 6432, length 515
17:07:09.937096 IP (tos 0x0, ttl 64, id 41735, offset 0, flags [DF], proto TCP
(6), length 555)
194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
(correct), seq 0:515, ack 1, win 6432, length 515
17:07:09.938083 IP (tos 0x0, ttl 64, id 41736, offset 0, flags [DF], proto TCP
(6), length 555)
194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
(correct), seq 0:515, ack 1, win 6432, length 515
17:09:21.672761 IP (tos 0x0, ttl 64, id 48515, offset 0, flags [DF], proto TCP
(6), length 412)
194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
(correct), seq 0:372, ack 1, win 181, length 372
17:09:21.673756 IP (tos 0x0, ttl 64, id 48516, offset 0, flags [DF], proto TCP
(6), length 412)
194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
(correct), seq 0:372, ack 1, win 181, length 372
17:09:21.674574 IP (tos 0x0, ttl 64, id 48517, offset 0, flags [DF], proto TCP
(6), length 412)
194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
(correct), seq 0:372, ack 1, win 181, length 372
17:09:21.675440 IP (tos 0x0, ttl 64, id 48518, offset 0, flags [DF], proto TCP
(6), length 412)
194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
(correct), seq 0:372, ack 1, win 181, length 372
17:09:21.676625 IP (tos 0x0, ttl 64, id 48519, offset 0, flags [DF], proto TCP
(6), length 412)
194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
(correct), seq 0:372, ack 1, win 181, length 372
17:09:21.678963 IP (tos 0x0, ttl 64, id 48521, offset 0, flags [DF], proto TCP
(6), length 412)
194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
(correct), seq 0:372, ack 1, win 181, length 372
17:11:12.032679 IP (tos 0x0, ttl 64, id 39699, offset 0, flags [DF], proto TCP
(6), length 552)
194.146.153.114.8080 > 172.16.15.13.63145: Flags [P.], cksum 0x1559
(correct), seq 0:512, ack 1, win 6432, length 512
17:11:12.033882 IP (tos 0x0, ttl 64, id 39700, offset 0, flags [DF], proto TCP
(6), length 552)
194.146.153.114.8080 > 172.16.15.13.63145: Flags [P.], cksum 0x1559
(correct), seq 0:512, ack 1, win 6432, length 512
17:11:12.034835 IP (tos 0x0, ttl 64, id 39701, offset 0, flags [DF], proto TCP
(6), length 552)
194.146.153.114.8080 > 172.16.15.13.63145: Flags [P.], cksum 0x1559
(correct), seq 0:512, ack 1, win 6432, length 512
17:11:12.035720 IP (tos 0x0, ttl 64, id 39702, offset 0, flags [DF], proto TCP
(6), length 552)
194.146.153.114.8080 > 172.16.15.13.63145: Flags [P.], cksum 0x1559
(correct), seq 0:512, ack 1, win 6432, length 512
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: Crazy TCP bug (keepalive flood?) in 2.6.32?
2009-12-26 15:03 Crazy TCP bug (keepalive flood?) in 2.6.32? Denys Fedoryshchenko
@ 2009-12-26 19:24 ` Ilpo Järvinen
2010-01-11 13:02 ` Ilpo Järvinen
1 sibling, 0 replies; 24+ messages in thread
From: Ilpo Järvinen @ 2009-12-26 19:24 UTC (permalink / raw)
To: Denys Fedoryshchenko; +Cc: Netdev
On Sat, 26 Dec 2009, Denys Fedoryshchenko wrote:
> Few more dumps. I notice:
> 1)Ack always equal 1
> 2)It is usually first segment of data sent (?)
Is it that you take the tcpdump right from the beginning? Otherwise
tcpdump will get the base sequence numbers from the first segment which
might be in the middle of the flow already.
> Maybe some value not initialised properly?
>
>
> 17:03:50.406118 IP (tos 0x0, ttl 64, id 57958, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
> win 7479, length 1452
> 17:03:50.407413 IP (tos 0x0, ttl 64, id 57959, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
> win 7479, length 1452
> 17:03:50.408516 IP (tos 0x0, ttl 64, id 57960, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
> win 7479, length 1452
> 17:03:50.409553 IP (tos 0x0, ttl 64, id 57961, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
> win 7479, length 1452
> 17:03:50.410424 IP (tos 0x0, ttl 64, id 57962, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
> win 7479, length 1452
>
>
>
> 17:04:39.801149 IP (tos 0x0, ttl 64, id 19431, offset 0, flags [DF], proto TCP
> (6), length 517)
> 194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
> (correct), seq 0:477, ack 1, win 8730, length 477
> 17:04:39.802538 IP (tos 0x0, ttl 64, id 19432, offset 0, flags [DF], proto TCP
> (6), length 517)
> 194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
> (correct), seq 0:477, ack 1, win 8730, length 477
> 17:04:39.803438 IP (tos 0x0, ttl 64, id 19433, offset 0, flags [DF], proto TCP
> (6), length 517)
> 194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
> (correct), seq 0:477, ack 1, win 8730, length 477
> 17:04:39.804251 IP (tos 0x0, ttl 64, id 19434, offset 0, flags [DF], proto TCP
> (6), length 517)
> 194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
> (correct), seq 0:477, ack 1, win 8730, length 477
> 17:04:39.805050 IP (tos 0x0, ttl 64, id 19435, offset 0, flags [DF], proto TCP
> (6), length 517)
> 194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
> (correct), seq 0:477, ack 1, win 8730, length 477
>
> 17:06:22.123862 IP (tos 0x0, ttl 64, id 25912, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.180.148.50101: Flags [.], seq 0:1452, ack 1,
> win 108, length 1452
> 17:06:22.124440 IP (tos 0x0, ttl 64, id 25913, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.180.148.50101: Flags [.], seq 0:1452, ack 1,
> win 108, length 1452
> 17:06:22.125600 IP (tos 0x0, ttl 64, id 25914, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.180.148.50101: Flags [.], seq 0:1452, ack 1,
> win 108, length 1452
> ^C17:06:22.126243 IP (tos 0x0, ttl 64, id 25915, offset 0, flags [DF], proto
> TCP (6), length 1492)
> 194.146.153.114.8080 > 172.16.180.148.50101: Flags [.], seq 0:1452, ack 1,
> win 108, length 1452
>
>
>
> 17:06:43.404279 IP (tos 0x0, ttl 64, id 10279, offset 0, flags [DF], proto TCP
> (6), length 768)
> 194.146.153.114.8080 > 172.16.199.151.49404: Flags [FP.], cksum 0x4ac3
> (correct), seq 0:728, ack 1, win 9816, length 728
> 17:06:43.405819 IP (tos 0x0, ttl 64, id 10281, offset 0, flags [DF], proto TCP
> (6), length 768)
> 194.146.153.114.8080 > 172.16.199.151.49404: Flags [FP.], cksum 0x4ac3
> (correct), seq 0:728, ack 1, win 9816, length 728
> 17:06:43.406670 IP (tos 0x0, ttl 64, id 10282, offset 0, flags [DF], proto TCP
> (6), length 768)
> 194.146.153.114.8080 > 172.16.199.151.49404: Flags [FP.], cksum 0x4ac3
> (correct), seq 0:728, ack 1, win 9816, length 728
> 17:06:43.407821 IP (tos 0x0, ttl 64, id 10283, offset 0, flags [DF], proto TCP
> (6), length 768)
> 194.146.153.114.8080 > 172.16.199.151.49404: Flags [FP.], cksum 0x4ac3
> (correct), seq 0:728, ack 1, win 9816, length 728
>
>
> 17:07:09.933303 IP (tos 0x0, ttl 64, id 41731, offset 0, flags [DF], proto TCP
> (6), length 555)
> 194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
> (correct), seq 0:515, ack 1, win 6432, length 515
> 17:07:09.934305 IP (tos 0x0, ttl 64, id 41732, offset 0, flags [DF], proto TCP
> (6), length 555)
> 194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
> (correct), seq 0:515, ack 1, win 6432, length 515
> 17:07:09.935076 IP (tos 0x0, ttl 64, id 41733, offset 0, flags [DF], proto TCP
> (6), length 555)
> 194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
> (correct), seq 0:515, ack 1, win 6432, length 515
> 17:07:09.935887 IP (tos 0x0, ttl 64, id 41734, offset 0, flags [DF], proto TCP
> (6), length 555)
> 194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
> (correct), seq 0:515, ack 1, win 6432, length 515
> 17:07:09.937096 IP (tos 0x0, ttl 64, id 41735, offset 0, flags [DF], proto TCP
> (6), length 555)
> 194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
> (correct), seq 0:515, ack 1, win 6432, length 515
> 17:07:09.938083 IP (tos 0x0, ttl 64, id 41736, offset 0, flags [DF], proto TCP
> (6), length 555)
> 194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
> (correct), seq 0:515, ack 1, win 6432, length 515
>
> 17:09:21.672761 IP (tos 0x0, ttl 64, id 48515, offset 0, flags [DF], proto TCP
> (6), length 412)
> 194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
> (correct), seq 0:372, ack 1, win 181, length 372
> 17:09:21.673756 IP (tos 0x0, ttl 64, id 48516, offset 0, flags [DF], proto TCP
> (6), length 412)
> 194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
> (correct), seq 0:372, ack 1, win 181, length 372
> 17:09:21.674574 IP (tos 0x0, ttl 64, id 48517, offset 0, flags [DF], proto TCP
> (6), length 412)
> 194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
> (correct), seq 0:372, ack 1, win 181, length 372
> 17:09:21.675440 IP (tos 0x0, ttl 64, id 48518, offset 0, flags [DF], proto TCP
> (6), length 412)
> 194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
> (correct), seq 0:372, ack 1, win 181, length 372
> 17:09:21.676625 IP (tos 0x0, ttl 64, id 48519, offset 0, flags [DF], proto TCP
> (6), length 412)
> 194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
> (correct), seq 0:372, ack 1, win 181, length 372
> 17:09:21.678963 IP (tos 0x0, ttl 64, id 48521, offset 0, flags [DF], proto TCP
> (6), length 412)
> 194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
> (correct), seq 0:372, ack 1, win 181, length 372
>
> 17:11:12.032679 IP (tos 0x0, ttl 64, id 39699, offset 0, flags [DF], proto TCP
> (6), length 552)
> 194.146.153.114.8080 > 172.16.15.13.63145: Flags [P.], cksum 0x1559
> (correct), seq 0:512, ack 1, win 6432, length 512
> 17:11:12.033882 IP (tos 0x0, ttl 64, id 39700, offset 0, flags [DF], proto TCP
> (6), length 552)
> 194.146.153.114.8080 > 172.16.15.13.63145: Flags [P.], cksum 0x1559
> (correct), seq 0:512, ack 1, win 6432, length 512
> 17:11:12.034835 IP (tos 0x0, ttl 64, id 39701, offset 0, flags [DF], proto TCP
> (6), length 552)
> 194.146.153.114.8080 > 172.16.15.13.63145: Flags [P.], cksum 0x1559
> (correct), seq 0:512, ack 1, win 6432, length 512
> 17:11:12.035720 IP (tos 0x0, ttl 64, id 39702, offset 0, flags [DF], proto TCP
> (6), length 552)
> 194.146.153.114.8080 > 172.16.15.13.63145: Flags [P.], cksum 0x1559
> (correct), seq 0:512, ack 1, win 6432, length 512
>
...I'll try to think this more on next week.
--
i.
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: Crazy TCP bug (keepalive flood?) in 2.6.32?
2009-12-26 15:03 Crazy TCP bug (keepalive flood?) in 2.6.32? Denys Fedoryshchenko
2009-12-26 19:24 ` Ilpo Järvinen
@ 2010-01-11 13:02 ` Ilpo Järvinen
2010-01-16 14:12 ` Denys Fedoryshchenko
1 sibling, 1 reply; 24+ messages in thread
From: Ilpo Järvinen @ 2010-01-11 13:02 UTC (permalink / raw)
To: Denys Fedoryshchenko; +Cc: Netdev
On Sat, 26 Dec 2009, Denys Fedoryshchenko wrote:
> Few more dumps. I notice:
> 1)Ack always equal 1
> 2)It is usually first segment of data sent (?)
>
> Maybe some value not initialised properly?
>
>
> 17:03:50.406118 IP (tos 0x0, ttl 64, id 57958, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
> win 7479, length 1452
> 17:03:50.407413 IP (tos 0x0, ttl 64, id 57959, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
> win 7479, length 1452
> 17:03:50.408516 IP (tos 0x0, ttl 64, id 57960, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
> win 7479, length 1452
> 17:03:50.409553 IP (tos 0x0, ttl 64, id 57961, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
> win 7479, length 1452
> 17:03:50.410424 IP (tos 0x0, ttl 64, id 57962, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.199.39.1472: Flags [.], seq 0:1452, ack 1,
> win 7479, length 1452
>
>
>
> 17:04:39.801149 IP (tos 0x0, ttl 64, id 19431, offset 0, flags [DF], proto TCP
> (6), length 517)
> 194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
> (correct), seq 0:477, ack 1, win 8730, length 477
> 17:04:39.802538 IP (tos 0x0, ttl 64, id 19432, offset 0, flags [DF], proto TCP
> (6), length 517)
> 194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
> (correct), seq 0:477, ack 1, win 8730, length 477
> 17:04:39.803438 IP (tos 0x0, ttl 64, id 19433, offset 0, flags [DF], proto TCP
> (6), length 517)
> 194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
> (correct), seq 0:477, ack 1, win 8730, length 477
> 17:04:39.804251 IP (tos 0x0, ttl 64, id 19434, offset 0, flags [DF], proto TCP
> (6), length 517)
> 194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
> (correct), seq 0:477, ack 1, win 8730, length 477
> 17:04:39.805050 IP (tos 0x0, ttl 64, id 19435, offset 0, flags [DF], proto TCP
> (6), length 517)
> 194.146.153.114.8080 > 172.16.107.14.1405: Flags [P.], cksum 0x51c6
> (correct), seq 0:477, ack 1, win 8730, length 477
>
> 17:06:22.123862 IP (tos 0x0, ttl 64, id 25912, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.180.148.50101: Flags [.], seq 0:1452, ack 1,
> win 108, length 1452
> 17:06:22.124440 IP (tos 0x0, ttl 64, id 25913, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.180.148.50101: Flags [.], seq 0:1452, ack 1,
> win 108, length 1452
> 17:06:22.125600 IP (tos 0x0, ttl 64, id 25914, offset 0, flags [DF], proto TCP
> (6), length 1492)
> 194.146.153.114.8080 > 172.16.180.148.50101: Flags [.], seq 0:1452, ack 1,
> win 108, length 1452
> ^C17:06:22.126243 IP (tos 0x0, ttl 64, id 25915, offset 0, flags [DF], proto
> TCP (6), length 1492)
> 194.146.153.114.8080 > 172.16.180.148.50101: Flags [.], seq 0:1452, ack 1,
> win 108, length 1452
>
>
>
> 17:06:43.404279 IP (tos 0x0, ttl 64, id 10279, offset 0, flags [DF], proto TCP
> (6), length 768)
> 194.146.153.114.8080 > 172.16.199.151.49404: Flags [FP.], cksum 0x4ac3
> (correct), seq 0:728, ack 1, win 9816, length 728
> 17:06:43.405819 IP (tos 0x0, ttl 64, id 10281, offset 0, flags [DF], proto TCP
> (6), length 768)
> 194.146.153.114.8080 > 172.16.199.151.49404: Flags [FP.], cksum 0x4ac3
> (correct), seq 0:728, ack 1, win 9816, length 728
> 17:06:43.406670 IP (tos 0x0, ttl 64, id 10282, offset 0, flags [DF], proto TCP
> (6), length 768)
> 194.146.153.114.8080 > 172.16.199.151.49404: Flags [FP.], cksum 0x4ac3
> (correct), seq 0:728, ack 1, win 9816, length 728
> 17:06:43.407821 IP (tos 0x0, ttl 64, id 10283, offset 0, flags [DF], proto TCP
> (6), length 768)
> 194.146.153.114.8080 > 172.16.199.151.49404: Flags [FP.], cksum 0x4ac3
> (correct), seq 0:728, ack 1, win 9816, length 728
>
>
> 17:07:09.933303 IP (tos 0x0, ttl 64, id 41731, offset 0, flags [DF], proto TCP
> (6), length 555)
> 194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
> (correct), seq 0:515, ack 1, win 6432, length 515
> 17:07:09.934305 IP (tos 0x0, ttl 64, id 41732, offset 0, flags [DF], proto TCP
> (6), length 555)
> 194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
> (correct), seq 0:515, ack 1, win 6432, length 515
> 17:07:09.935076 IP (tos 0x0, ttl 64, id 41733, offset 0, flags [DF], proto TCP
> (6), length 555)
> 194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
> (correct), seq 0:515, ack 1, win 6432, length 515
> 17:07:09.935887 IP (tos 0x0, ttl 64, id 41734, offset 0, flags [DF], proto TCP
> (6), length 555)
> 194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
> (correct), seq 0:515, ack 1, win 6432, length 515
> 17:07:09.937096 IP (tos 0x0, ttl 64, id 41735, offset 0, flags [DF], proto TCP
> (6), length 555)
> 194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
> (correct), seq 0:515, ack 1, win 6432, length 515
> 17:07:09.938083 IP (tos 0x0, ttl 64, id 41736, offset 0, flags [DF], proto TCP
> (6), length 555)
> 194.146.153.114.8080 > 172.16.175.130.1692: Flags [P.], cksum 0x7d98
> (correct), seq 0:515, ack 1, win 6432, length 515
>
> 17:09:21.672761 IP (tos 0x0, ttl 64, id 48515, offset 0, flags [DF], proto TCP
> (6), length 412)
> 194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
> (correct), seq 0:372, ack 1, win 181, length 372
> 17:09:21.673756 IP (tos 0x0, ttl 64, id 48516, offset 0, flags [DF], proto TCP
> (6), length 412)
> 194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
> (correct), seq 0:372, ack 1, win 181, length 372
> 17:09:21.674574 IP (tos 0x0, ttl 64, id 48517, offset 0, flags [DF], proto TCP
> (6), length 412)
> 194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
> (correct), seq 0:372, ack 1, win 181, length 372
> 17:09:21.675440 IP (tos 0x0, ttl 64, id 48518, offset 0, flags [DF], proto TCP
> (6), length 412)
> 194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
> (correct), seq 0:372, ack 1, win 181, length 372
> 17:09:21.676625 IP (tos 0x0, ttl 64, id 48519, offset 0, flags [DF], proto TCP
> (6), length 412)
> 194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
> (correct), seq 0:372, ack 1, win 181, length 372
> 17:09:21.678963 IP (tos 0x0, ttl 64, id 48521, offset 0, flags [DF], proto TCP
> (6), length 412)
> 194.146.153.114.8080 > 172.16.163.219.47653: Flags [P.], cksum 0x584c
> (correct), seq 0:372, ack 1, win 181, length 372
>
> 17:11:12.032679 IP (tos 0x0, ttl 64, id 39699, offset 0, flags [DF], proto TCP
> (6), length 552)
> 194.146.153.114.8080 > 172.16.15.13.63145: Flags [P.], cksum 0x1559
> (correct), seq 0:512, ack 1, win 6432, length 512
> 17:11:12.033882 IP (tos 0x0, ttl 64, id 39700, offset 0, flags [DF], proto TCP
> (6), length 552)
> 194.146.153.114.8080 > 172.16.15.13.63145: Flags [P.], cksum 0x1559
> (correct), seq 0:512, ack 1, win 6432, length 512
> 17:11:12.034835 IP (tos 0x0, ttl 64, id 39701, offset 0, flags [DF], proto TCP
> (6), length 552)
> 194.146.153.114.8080 > 172.16.15.13.63145: Flags [P.], cksum 0x1559
> (correct), seq 0:512, ack 1, win 6432, length 512
> 17:11:12.035720 IP (tos 0x0, ttl 64, id 39702, offset 0, flags [DF], proto TCP
> (6), length 552)
> 194.146.153.114.8080 > 172.16.15.13.63145: Flags [P.], cksum 0x1559
> (correct), seq 0:512, ack 1, win 6432, length 512
>
Can you see if the RTO lower bound is violated (I added some printing of
vars there too already now if it turns out to be something):
diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
index 65b8ebf..d84469f 100644
--- a/net/ipv4/tcp_ipv4.c
+++ b/net/ipv4/tcp_ipv4.c
@@ -327,6 +327,22 @@ static void do_pmtu_discovery(struct sock *sk, struct iphdr *iph, u32 mtu)
* is probably better.
*
*/
+static int prints = 0;
+
+static void tcp_debug_rto(struct sock *sk, struct sk_buff *skb, u32 remaining, int locked)
+{
+ struct inet_connection_sock *icsk = inet_csk(sk);
+ struct tcp_sock *tp = tcp_sk(sk);
+
+ if (prints++ < 1000) {
+ printk("rto: %u (%u >> 3 + %u, %u) time: %u sent: %u pen: %u %lu rem: %u %s\n",
+ icsk->icsk_rto, tp->srtt, tp->rttvar,
+ (u32)icsk->icsk_backoff,
+ tcp_time_stamp, TCP_SKB_CB(skb)->when,
+ (u32)icsk->icsk_pending, icsk->icsk_timeout, remaining,
+ locked ? "locked" : "");
+ }
+}
void tcp_v4_err(struct sk_buff *icmp_skb, u32 info)
{
@@ -409,6 +425,11 @@ void tcp_v4_err(struct sk_buff *icmp_skb, u32 info)
inet_csk(sk)->icsk_rto = __tcp_set_rto(tp) <<
icsk->icsk_backoff;
tcp_bound_rto(sk);
+ if (icsk->icsk_rto < TCP_RTO_MIN) {
+ if (net_ratelimit())
+ printk("lower bound violation: %u\n", icsk->icsk_rto);
+ icsk->icsk_rto = TCP_RTO_MIN;
+ }
skb = tcp_write_queue_head(sk);
BUG_ON(!skb);
@@ -417,14 +438,17 @@ void tcp_v4_err(struct sk_buff *icmp_skb, u32 info)
tcp_time_stamp - TCP_SKB_CB(skb)->when);
if (remaining) {
+ tcp_debug_rto(sk, skb, remaining, 0);
inet_csk_reset_xmit_timer(sk, ICSK_TIME_RETRANS,
remaining, TCP_RTO_MAX);
} else if (sock_owned_by_user(sk)) {
+ tcp_debug_rto(sk, skb, remaining, 1);
/* RTO revert clocked out retransmission,
* but socket is locked. Will defer. */
inet_csk_reset_xmit_timer(sk, ICSK_TIME_RETRANS,
HZ/20, TCP_RTO_MAX);
} else {
+ tcp_debug_rto(sk, skb, remaining, 0);
/* RTO revert clocked out retransmission.
* Will retransmit now */
tcp_retransmit_timer(sk);
^ permalink raw reply related [flat|nested] 24+ messages in thread
* Re: Crazy TCP bug (keepalive flood?) in 2.6.32?
2010-01-11 13:02 ` Ilpo Järvinen
@ 2010-01-16 14:12 ` Denys Fedoryshchenko
2010-01-19 9:10 ` Damian Lukowski
0 siblings, 1 reply; 24+ messages in thread
From: Denys Fedoryshchenko @ 2010-01-16 14:12 UTC (permalink / raw)
To: Ilpo Järvinen, netdev
On Monday 11 January 2010 15:02:34 you wrote:
> On Sat, 26 Dec 2009, Denys Fedoryshchenko wrote:
> > Few more dumps. I notice:
> > 1)Ack always equal 1
> > 2)It is usually first segment of data sent (?)
> >
> > Maybe some value not initialised properly?
> >
> >
> Can you see if the RTO lower bound is violated (I added some printing of
> vars there too already now if it turns out to be something):
>
> diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
> index 65b8ebf..d84469f 100644
> --- a/net/ipv4/tcp_ipv4.c
> +++ b/net/ipv4/tcp_ipv4.c
> @@ -327,6 +327,22 @@ static void do_pmtu_discovery(struct sock *sk, struct
Hi, i'm very sorry for delay. Just having problem with Lebanese ISP's (u pay
20k for 20mbit, u get 20% packetloss at peak time, and they say it is normal).
I did test, here is some things from dmesg
[ 396.496765] lower bound violation: 0
[ 396.496833] rto: 200 (0 >> 3 + 0, 4) time: 96496 sent: 96496 pen: 1 96696
rem: 200
[ 399.442640] lower bound violation: 0
[ 399.442721] rto: 200 (0 >> 3 + 0, 16) time: 99442 sent: 99421 pen: 1 102621
rem: 179
[ 399.444802] lower bound violation: 0
[ 399.444881] rto: 200 (0 >> 3 + 0, 10) time: 99444 sent: 99233 pen: 1 102433
rem: 0
[ 399.446444] lower bound violation: 0
[ 399.446521] rto: 200 (0 >> 3 + 0, 15) time: 99446 sent: 99421 pen: 1 99621
rem: 175
[ 399.539751] lower bound violation: 0
[ 399.539832] rto: 200 (0 >> 3 + 0, 7) time: 99539 sent: 99496 pen: 1 102696
rem: 157
[ 399.539964] rto: 200 (0 >> 3 + 0, 6) time: 99539 sent: 99496 pen: 1 99696
rem: 157
[ 399.540650] rto: 200 (0 >> 3 + 0, 5) time: 99540 sent: 99496 pen: 1 99696
rem: 156
[ 402.445674] __ratelimit: 2 callbacks suppressed
[ 402.445756] lower bound violation: 0
[ 402.445833] rto: 200 (0 >> 3 + 0, 18) time: 102445 sent: 102421 pen: 1
105621 rem: 176
[ 402.445958] lower bound violation: 0
[ 402.446026] rto: 200 (0 >> 3 + 0, 13) time: 102445 sent: 102244 pen: 1
105444 rem: 0
[ 402.446150] lower bound violation: 0
[ 402.446217] rto: 200 (0 >> 3 + 0, 17) time: 102446 sent: 102421 pen: 1
102621 rem: 175
[ 402.742463] lower bound violation: 0
[ 402.742544] rto: 200 (0 >> 3 + 0, 8) time: 102742 sent: 102496 pen: 1
105696 rem: 0
[ 402.743567] lower bound violation: 0
[ 402.744361] rto: 200 (0 >> 3 + 0, 8) time: 102744 sent: 102742 pen: 1
103142 rem: 198
[ 402.744478] lower bound violation: 0
[ 402.744545] rto: 200 (0 >> 3 + 0, 7) time: 102744 sent: 102742 pen: 1
102942 rem: 198
[ 405.446861] lower bound violation: 0
[ 405.446943] rto: 200 (0 >> 3 + 0, 20) time: 105446 sent: 105421 pen: 1
108621 rem: 175
[ 405.447075] lower bound violation: 0
[ 405.447142] rto: 200 (0 >> 3 + 0, 16) time: 105446 sent: 105246 pen: 1
108446 rem: 0
[ 405.447265] lower bound violation: 0
[ 405.447332] rto: 200 (0 >> 3 + 0, 19) time: 105446 sent: 105421 pen: 1
105621 rem: 175
[ 405.759226] lower bound violation: 0
[ 405.759307] rto: 200 (0 >> 3 + 0, 10) time: 105759 sent: 105742 pen: 1
108942 rem: 183
[ 405.763529] rto: 200 (0 >> 3 + 0, 9) time: 105763 sent: 105742 pen: 1
105942 rem: 179
[ 405.764344] rto: 200 (0 >> 3 + 0, 8) time: 105764 sent: 105742 pen: 1
105942 rem: 178
[ 408.450964] __ratelimit: 2 callbacks suppressed
[ 408.451045] lower bound violation: 0
[ 408.451121] rto: 200 (0 >> 3 + 0, 22) time: 108450 sent: 108421 pen: 1
111621 rem: 171
[ 408.451246] lower bound violation: 0
[ 408.451314] rto: 200 (0 >> 3 + 0, 19) time: 108450 sent: 108246 pen: 1
111446 rem: 0
[ 408.451437] lower bound violation: 0
[ 408.451504] rto: 200 (0 >> 3 + 0, 21) time: 108450 sent: 108421 pen: 1
108621 rem: 171
[ 408.792229] lower bound violation: 0
[ 408.792307] rto: 200 (0 >> 3 + 0, 11) time: 108792 sent: 108742 pen: 1
111942 rem: 150
[ 408.792821] lower bound violation: 0
[ 408.792897] rto: 200 (0 >> 3 + 0, 10) time: 108792 sent: 108742 pen: 1
108942 rem: 150
[ 408.793033] lower bound violation: 0
[ 408.793109] rto: 200 (0 >> 3 + 0, 9) time: 108793 sent: 108742 pen: 1
108943 rem: 149
[ 411.478006] lower bound violation: 0
[ 411.478088] rto: 200 (0 >> 3 + 0, 24) time: 111478 sent: 111421 pen: 1
114621 rem: 143
[ 411.478220] lower bound violation: 0
[ 411.478287] rto: 200 (0 >> 3 + 0, 22) time: 111478 sent: 111250 pen: 1
114450 rem: 0
[ 411.478411] lower bound violation: 0
[ 411.478478] rto: 200 (0 >> 3 + 0, 23) time: 111478 sent: 111421 pen: 1
111621 rem: 143
[ 411.804382] lower bound violation: 0
[ 411.804464] rto: 200 (0 >> 3 + 0, 12) time: 111804 sent: 111742 pen: 1
114942 rem: 138
[ 411.804598] rto: 200 (0 >> 3 + 0, 11) time: 111804 sent: 111742 pen: 1
111942 rem: 138
[ 414.498996] __ratelimit: 1 callbacks suppressed
[ 414.499080] lower bound violation: 0
[ 414.499160] rto: 200 (0 >> 3 + 0, 26) time: 114498 sent: 114421 pen: 1
117621 rem: 123
[ 414.513129] lower bound violation: 0
[ 414.513207] rto: 200 (0 >> 3 + 0, 25) time: 114513 sent: 114278 pen: 1
117478 rem: 0
[ 414.513344] lower bound violation: 0
[ 414.513412] rto: 200 (0 >> 3 + 0, 25) time: 114513 sent: 114421 pen: 1
114621 rem: 108
[ 414.784717] lower bound violation: 0
[ 414.784799] rto: 200 (0 >> 3 + 0, 14) time: 114784 sent: 114742 pen: 1
117942 rem: 158
[ 414.786072] lower bound violation: 0
[ 414.786152] rto: 200 (0 >> 3 + 0, 13) time: 114786 sent: 114742 pen: 1
114942 rem: 156
[ 417.515995] lower bound violation: 0
[ 417.516077] rto: 200 (0 >> 3 + 0, 28) time: 117516 sent: 117421 pen: 1
120621 rem: 105
[ 417.516213] lower bound violation: 0
[ 417.516289] rto: 200 (0 >> 3 + 0, 28) time: 117516 sent: 117313 pen: 1
120513 rem: 0
[ 417.516413] lower bound violation: 0
[ 417.516481] rto: 200 (0 >> 3 + 0, 27) time: 117516 sent: 117421 pen: 1
117621 rem: 105
[ 417.803533] lower bound violation: 0
[ 417.803615] rto: 200 (0 >> 3 + 0, 16) time: 117803 sent: 117742 pen: 1
120942 rem: 139
[ 417.803745] lower bound violation: 0
[ 417.803812] rto: 200 (0 >> 3 + 0, 15) time: 117803 sent: 117742 pen: 1
117942 rem: 139
[ 417.803930] rto: 200 (0 >> 3 + 0, 14) time: 117803 sent: 117742 pen: 1
117942 rem: 139
[ 420.556115] __ratelimit: 1 callbacks suppressed
[ 420.556198] lower bound violation: 0
[ 420.556274] rto: 200 (0 >> 3 + 0, 30) time: 120556 sent: 120421 pen: 1
123621 rem: 65
[ 420.556399] lower bound violation: 0
[ 420.556466] rto: 200 (0 >> 3 + 0, 31) time: 120556 sent: 120316 pen: 1
123516 rem: 0
[ 420.556591] lower bound violation: 0
[ 420.556659] rto: 200 (0 >> 3 + 0, 29) time: 120556 sent: 120421 pen: 1
120621 rem: 65
[ 420.965666] lower bound violation: 0
[ 420.965749] rto: 200 (0 >> 3 + 0, 17) time: 120965 sent: 120742 pen: 1
123942 rem: 0
[ 420.967717] lower bound violation: 0
[ 420.967796] rto: 200 (0 >> 3 + 0, 17) time: 120967 sent: 120965 pen: 1
121365 rem: 198
[ 420.972139] lower bound violation: 0
[ 420.972216] rto: 200 (0 >> 3 + 0, 16) time: 120972 sent: 120965 pen: 1
121165 rem: 193
[ 423.564843] lower bound violation: 0
[ 423.564924] rto: 200 (0 >> 3 + 0, 32) time: 123564 sent: 123421 pen: 1
126621 rem: 57
[ 423.565062] lower bound violation: 0
[ 423.565130] rto: 200 (0 >> 3 + 0, 34) time: 123565 sent: 123356 pen: 1
126556 rem: 0
[ 423.565254] lower bound violation: 0
[ 423.565322] rto: 200 (0 >> 3 + 0, 31) time: 123565 sent: 123421 pen: 1
123622 rem: 56
[ 424.001854] lower bound violation: 0
[ 424.001936] rto: 200 (0 >> 3 + 0, 19) time: 124001 sent: 123965 pen: 1
127165 rem: 164
[ 424.005665] rto: 200 (0 >> 3 + 0, 18) time: 124005 sent: 123965 pen: 1
124166 rem: 160
[ 424.007636] rto: 200 (0 >> 3 + 0, 17) time: 124007 sent: 123965 pen: 1
124165 rem: 158
[ 426.580172] __ratelimit: 2 callbacks suppressed
[ 426.580254] lower bound violation: 0
[ 426.580337] rto: 200 (0 >> 3 + 0, 34) time: 126580 sent: 126421 pen: 1
129621 rem: 41
[ 426.580456] lower bound violation: 0
[ 426.580524] rto: 200 (0 >> 3 + 0, 37) time: 126580 sent: 126365 pen: 1
129565 rem: 0
[ 426.580647] lower bound violation: 0
[ 426.580715] rto: 200 (0 >> 3 + 0, 33) time: 126580 sent: 126421 pen: 1
126621 rem: 41
[ 427.210363] lower bound violation: 0
[ 427.210443] rto: 200 (0 >> 3 + 0, 20) time: 127210 sent: 126965 pen: 1
130165 rem: 0
[ 427.210587] lower bound violation: 0
[ 427.210654] rto: 200 (0 >> 3 + 0, 20) time: 127210 sent: 127210 pen: 1
127610 rem: 200
[ 427.210770] lower bound violation: 0
[ 427.210837] rto: 200 (0 >> 3 + 0, 19) time: 127210 sent: 127210 pen: 1
127410 rem: 200
[ 429.586539] lower bound violation: 0
[ 429.586628] rto: 200 (0 >> 3 + 0, 36) time: 129586 sent: 129421 pen: 1
132621 rem: 35
[ 429.588735] lower bound violation: 0
[ 429.588814] rto: 200 (0 >> 3 + 0, 40) time: 129588 sent: 129380 pen: 1
132580 rem: 0
[ 429.589880] lower bound violation: 0
[ 429.589957] rto: 200 (0 >> 3 + 0, 35) time: 129589 sent: 129421 pen: 1
129621 rem: 32
[ 430.231164] lower bound violation: 0
[ 430.231246] rto: 200 (0 >> 3 + 0, 22) time: 130231 sent: 130210 pen: 1
133410 rem: 179
[ 430.253497] rto: 200 (0 >> 3 + 0, 21) time: 130253 sent: 130210 pen: 1
130410 rem: 157
[ 432.600005] __ratelimit: 1 callbacks suppressed
[ 432.600087] lower bound violation: 0
[ 432.600164] rto: 200 (0 >> 3 + 0, 38) time: 132600 sent: 132421 pen: 1
135621 rem: 21
[ 432.601516] lower bound violation: 0
[ 432.601593] rto: 200 (0 >> 3 + 0, 43) time: 132601 sent: 132388 pen: 1
135588 rem: 0
[ 432.601729] lower bound violation: 0
[ 432.601796] rto: 200 (0 >> 3 + 0, 37) time: 132601 sent: 132421 pen: 1
132621 rem: 20
[ 433.292095] lower bound violation: 0
[ 433.292177] rto: 200 (0 >> 3 + 0, 24) time: 133292 sent: 133210 pen: 1
136410 rem: 118
[ 433.292308] lower bound violation: 0
[ 433.292375] rto: 200 (0 >> 3 + 0, 23) time: 133292 sent: 133210 pen: 1
133410 rem: 118
[ 433.292491] lower bound violation: 0
[ 433.292558] rto: 200 (0 >> 3 + 0, 22) time: 133292 sent: 133210 pen: 1
133410 rem: 118
[ 435.624429] lower bound violation: 0
[ 435.624512] rto: 200 (0 >> 3 + 0, 40) time: 135624 sent: 135421 pen: 1
138621 rem: 0
[ 435.624649] lower bound violation: 0
[ 435.624717] rto: 200 (0 >> 3 + 0, 46) time: 135624 sent: 135401 pen: 1
138601 rem: 0
[ 435.625410] lower bound violation: 0
[ 435.625410] rto: 200 (0 >> 3 + 0, 40) time: 135624 sent: 135624 pen: 1
136024 rem: 200
[ 436.455058] lower bound violation: 0
[ 436.455140] rto: 200 (0 >> 3 + 0, 25) time: 136455 sent: 136210 pen: 1
139410 rem: 0
[ 436.455279] rto: 200 (0 >> 3 + 0, 25) time: 136455 sent: 136455 pen: 1
136855 rem: 200
[ 436.455397] rto: 200 (0 >> 3 + 0, 24) time: 136455 sent: 136455 pen: 1
136655 rem: 200
[ 439.507877] __ratelimit: 2 callbacks suppressed
[ 439.507959] lower bound violation: 0
[ 439.508037] rto: 200 (0 >> 3 + 0, 27) time: 139507 sent: 139455 pen: 1
142655 rem: 148
[ 439.508161] lower bound violation: 0
[ 439.508228] rto: 200 (0 >> 3 + 0, 26) time: 139507 sent: 139455 pen: 1
139655 rem: 148
[ 442.507756] lower bound violation: 0
[ 442.507838] rto: 200 (0 >> 3 + 0, 29) time: 142507 sent: 142455 pen: 1
145655 rem: 148
[ 442.507969] lower bound violation: 0
[ 442.508035] rto: 200 (0 >> 3 + 0, 28) time: 142507 sent: 142455 pen: 1
142655 rem: 148
[ 442.508152] lower bound violation: 0
[ 442.508219] rto: 200 (0 >> 3 + 0, 27) time: 142507 sent: 142455 pen: 1
142655 rem: 148
[ 445.498049] lower bound violation: 0
[ 445.498130] rto: 200 (0 >> 3 + 0, 30) time: 145498 sent: 145455 pen: 1
148655 rem: 157
[ 445.499105] lower bound violation: 0
[ 445.499194] rto: 200 (0 >> 3 + 0, 29) time: 145499 sent: 145455 pen: 1
145655 rem: 156
[ 445.501524] lower bound violation: 0
[ 445.501600] rto: 200 (0 >> 3 + 0, 28) time: 145501 sent: 145455 pen: 1
145655 rem: 154
[ 448.678590] lower bound violation: 0
[ 448.678671] rto: 200 (0 >> 3 + 0, 31) time: 148678 sent: 148455 pen: 1
151655 rem: 0
[ 448.678808] lower bound violation: 0
[ 448.678876] rto: 200 (0 >> 3 + 0, 31) time: 148678 sent: 148678 pen: 1
149078 rem: 200
[ 451.716905] lower bound violation: 0
[ 451.716987] rto: 200 (0 >> 3 + 0, 34) time: 151716 sent: 151678 pen: 1
154878 rem: 162
[ 451.763041] lower bound violation: 0
[ 451.763121] rto: 200 (0 >> 3 + 0, 33) time: 151763 sent: 151678 pen: 1
151878 rem: 115
[ 451.763252] lower bound violation: 0
[ 451.763320] rto: 200 (0 >> 3 + 0, 32) time: 151763 sent: 151678 pen: 1
151878 rem: 115
[ 454.732396] lower bound violation: 0
[ 454.732478] rto: 200 (0 >> 3 + 0, 35) time: 154732 sent: 154678 pen: 1
157878 rem: 146
[ 454.736990] lower bound violation: 0
[ 454.737072] rto: 200 (0 >> 3 + 0, 34) time: 154737 sent: 154678 pen: 1
154878 rem: 141
[ 454.738128] lower bound violation: 0
[ 454.738206] rto: 200 (0 >> 3 + 0, 33) time: 154738 sent: 154678 pen: 1
154878 rem: 140
[ 457.894010] lower bound violation: 0
[ 457.894098] rto: 200 (0 >> 3 + 0, 36) time: 157894 sent: 157678 pen: 1
160878 rem: 0
[ 457.913672] lower bound violation: 0
[ 457.913751] rto: 200 (0 >> 3 + 0, 36) time: 157913 sent: 157894 pen: 1
158294 rem: 181
[ 457.913883] lower bound violation: 0
[ 457.913950] rto: 200 (0 >> 3 + 0, 35) time: 157913 sent: 157894 pen: 1
158094 rem: 181
[ 460.932992] lower bound violation: 0
[ 460.933073] rto: 200 (0 >> 3 + 0, 38) time: 160932 sent: 160894 pen: 1
164094 rem: 162
[ 460.933206] lower bound violation: 0
[ 460.933273] rto: 200 (0 >> 3 + 0, 37) time: 160932 sent: 160894 pen: 1
161094 rem: 162
[ 460.933390] lower bound violation: 0
[ 460.933457] rto: 200 (0 >> 3 + 0, 36) time: 160932 sent: 160894 pen: 1
161094 rem: 162
[ 463.928470] lower bound violation: 0
[ 463.928551] rto: 200 (0 >> 3 + 0, 39) time: 163928 sent: 163894 pen: 1
167094 rem: 166
[ 466.953674] lower bound violation: 0
[ 466.953755] rto: 200 (0 >> 3 + 0, 42) time: 166953 sent: 166894 pen: 1
170094 rem: 141
[ 466.953887] lower bound violation: 0
[ 466.953954] rto: 200 (0 >> 3 + 0, 41) time: 166953 sent: 166894 pen: 1
167094 rem: 141
[ 470.112498] lower bound violation: 0
[ 470.112580] rto: 200 (0 >> 3 + 0, 44) time: 170112 sent: 169894 pen: 1
173094 rem: 0
[ 470.127286] lower bound violation: 0
[ 470.127364] rto: 200 (0 >> 3 + 0, 44) time: 170127 sent: 170112 pen: 1
170512 rem: 185
[ 473.167817] lower bound violation: 0
[ 473.167899] rto: 200 (0 >> 3 + 0, 47) time: 173167 sent: 173112 pen: 1
176312 rem: 145
[ 473.168030] lower bound violation: 0
[ 473.168098] rto: 200 (0 >> 3 + 0, 46) time: 173168 sent: 173112 pen: 1
173313 rem: 144
[ 473.169413] lower bound violation: 0
[ 473.169491] rto: 200 (0 >> 3 + 0, 45) time: 173169 sent: 173112 pen: 1
173312 rem: 143
[ 522.630573] lower bound violation: 0
[ 522.630655] rto: 200 (0 >> 3 + 0, 0) time: 222630 sent: 222630 pen: 1
228630 rem: 200
[ 627.844099] lower bound violation: 0
[ 627.844176] rto: 200 (0 >> 3 + 0, 8) time: 327844 sent: 324830 pen: 1
427230 rem: 0
[ 630.848249] lower bound violation: 0
[ 630.848333] rto: 200 (0 >> 3 + 0, 11) time: 330848 sent: 330644 pen: 1
333844 rem: 0
[ 735.859328] lower bound violation: 0
[ 735.859388] rto: 200 (0 >> 3 + 0, 19) time: 435859 sent: 432848 pen: 1
535248 rem: 0
[ 738.864261] lower bound violation: 0
[ 738.864322] rto: 200 (0 >> 3 + 0, 22) time: 438864 sent: 438659 pen: 1
441859 rem: 0
[ 738.865358] lower bound violation: 0
[ 738.865415] rto: 200 (0 >> 3 + 0, 22) time: 438865 sent: 438864 pen: 1
439264 rem: 199
[ 741.864947] lower bound violation: 0
[ 741.865007] rto: 200 (0 >> 3 + 0, 25) time: 441864 sent: 441864 pen: 1
445064 rem: 200
[ 741.867651] lower bound violation: 0
[ 741.867709] rto: 200 (0 >> 3 + 0, 24) time: 441867 sent: 441864 pen: 1
442065 rem: 197
[ 741.867821] lower bound violation: 0
[ 741.867875] rto: 200 (0 >> 3 + 0, 23) time: 441867 sent: 441864 pen: 1
442064 rem: 197
[ 744.874165] lower bound violation: 0
[ 744.874225] rto: 200 (0 >> 3 + 0, 26) time: 444874 sent: 444864 pen: 1
448064 rem: 190
[ 744.874340] lower bound violation: 0
[ 744.874388] rto: 200 (0 >> 3 + 0, 25) time: 444874 sent: 444864 pen: 1
445064 rem: 190
[ 744.874486] lower bound violation: 0
[ 744.874535] rto: 200 (0 >> 3 + 0, 24) time: 444874 sent: 444864 pen: 1
445064 rem: 190
[ 747.874311] lower bound violation: 0
[ 747.874373] rto: 200 (0 >> 3 + 0, 27) time: 447874 sent: 447864 pen: 1
451064 rem: 190
[ 747.874474] lower bound violation: 0
[ 747.874523] rto: 200 (0 >> 3 + 0, 26) time: 447874 sent: 447864 pen: 1
448064 rem: 190
[ 747.874628] lower bound violation: 0
[ 747.874677] rto: 200 (0 >> 3 + 0, 25) time: 447874 sent: 447864 pen: 1
448064 rem: 190
[ 750.870109] lower bound violation: 0
[ 750.870170] rto: 200 (0 >> 3 + 0, 28) time: 450870 sent: 450864 pen: 1
454064 rem: 194
[ 750.870281] lower bound violation: 0
[ 750.870330] rto: 200 (0 >> 3 + 0, 27) time: 450870 sent: 450864 pen: 1
451064 rem: 194
[ 750.870435] lower bound violation: 0
[ 750.870484] rto: 200 (0 >> 3 + 0, 26) time: 450870 sent: 450864 pen: 1
451064 rem: 194
[ 753.882598] lower bound violation: 0
[ 753.882661] rto: 200 (0 >> 3 + 0, 29) time: 453882 sent: 453864 pen: 1
457064 rem: 182
[ 753.882779] lower bound violation: 0
[ 753.882842] rto: 200 (0 >> 3 + 0, 28) time: 453882 sent: 453864 pen: 1
454064 rem: 182
[ 753.882975] lower bound violation: 0
[ 753.883050] rto: 200 (0 >> 3 + 0, 27) time: 453883 sent: 453864 pen: 1
454064 rem: 181
[ 756.874204] lower bound violation: 0
[ 756.874265] rto: 200 (0 >> 3 + 0, 30) time: 456874 sent: 456864 pen: 1
460064 rem: 190
[ 756.874376] lower bound violation: 0
[ 756.874424] rto: 200 (0 >> 3 + 0, 29) time: 456874 sent: 456864 pen: 1
457064 rem: 190
[ 756.874527] lower bound violation: 0
[ 756.874576] rto: 200 (0 >> 3 + 0, 28) time: 456874 sent: 456864 pen: 1
457064 rem: 190
[ 759.891416] lower bound violation: 0
[ 759.891480] rto: 200 (0 >> 3 + 0, 31) time: 459891 sent: 459864 pen: 1
463064 rem: 173
[ 759.891591] lower bound violation: 0
[ 759.891647] rto: 200 (0 >> 3 + 0, 30) time: 459891 sent: 459864 pen: 1
460064 rem: 173
[ 759.891746] lower bound violation: 0
[ 759.892390] rto: 200 (0 >> 3 + 0, 29) time: 459891 sent: 459864 pen: 1
460064 rem: 173
[ 763.066046] lower bound violation: 0
[ 763.066106] rto: 200 (0 >> 3 + 0, 32) time: 463066 sent: 462864 pen: 1
466064 rem: 0
[ 763.066224] lower bound violation: 0
[ 763.066273] rto: 200 (0 >> 3 + 0, 32) time: 463066 sent: 463066 pen: 1
463466 rem: 200
[ 763.066371] lower bound violation: 0
[ 763.066419] rto: 200 (0 >> 3 + 0, 31) time: 463066 sent: 463066 pen: 1
463266 rem: 200
[ 766.065427] lower bound violation: 0
[ 766.065501] rto: 200 (0 >> 3 + 0, 33) time: 466065 sent: 464466 pen: 1
466066 rem: 0
[ 766.069012] lower bound violation: 0
[ 766.069070] rto: 200 (0 >> 3 + 0, 33) time: 466068 sent: 466065 pen: 1
466465 rem: 197
[ 766.069184] lower bound violation: 0
[ 766.069242] rto: 200 (0 >> 3 + 0, 32) time: 466069 sent: 466065 pen: 1
466266 rem: 196
[ 769.077813] lower bound violation: 0
[ 769.077873] rto: 200 (0 >> 3 + 0, 35) time: 469077 sent: 469065 pen: 1
472265 rem: 188
[ 769.077985] lower bound violation: 0
[ 769.078043] rto: 200 (0 >> 3 + 0, 34) time: 469078 sent: 469065 pen: 1
469265 rem: 187
[ 772.078686] lower bound violation: 0
[ 772.078746] rto: 200 (0 >> 3 + 0, 37) time: 472078 sent: 472065 pen: 1
475265 rem: 187
[ 772.078859] lower bound violation: 0
[ 772.078907] rto: 200 (0 >> 3 + 0, 36) time: 472078 sent: 472065 pen: 1
472265 rem: 187
[ 772.079674] lower bound violation: 0
[ 772.079731] rto: 200 (0 >> 3 + 0, 35) time: 472079 sent: 472065 pen: 1
472265 rem: 186
[ 775.269432] lower bound violation: 0
[ 775.269494] rto: 200 (0 >> 3 + 0, 38) time: 475269 sent: 475065 pen: 1
478265 rem: 0
[ 775.270671] lower bound violation: 0
[ 775.270733] rto: 200 (0 >> 3 + 0, 38) time: 475270 sent: 475269 pen: 1
475669 rem: 199
[ 775.270848] lower bound violation: 0
[ 775.270897] rto: 200 (0 >> 3 + 0, 37) time: 475270 sent: 475269 pen: 1
475469 rem: 199
[ 778.277343] lower bound violation: 0
[ 778.277404] rto: 200 (0 >> 3 + 0, 40) time: 478277 sent: 478269 pen: 1
481469 rem: 192
[ 778.277536] lower bound violation: 0
[ 778.277602] rto: 200 (0 >> 3 + 0, 39) time: 478277 sent: 478269 pen: 1
478469 rem: 192
[ 778.277722] lower bound violation: 0
[ 778.277778] rto: 200 (0 >> 3 + 0, 38) time: 478277 sent: 478269 pen: 1
478469 rem: 192
[ 781.272677] lower bound violation: 0
[ 781.272737] rto: 200 (0 >> 3 + 0, 41) time: 481272 sent: 481269 pen: 1
484469 rem: 197
[ 781.272850] lower bound violation: 0
[ 781.272898] rto: 200 (0 >> 3 + 0, 40) time: 481272 sent: 481269 pen: 1
481469 rem: 197
[ 784.274886] lower bound violation: 0
[ 784.274946] rto: 200 (0 >> 3 + 0, 43) time: 484274 sent: 484269 pen: 1
487469 rem: 195
[ 784.275064] lower bound violation: 0
[ 784.275112] rto: 200 (0 >> 3 + 0, 42) time: 484275 sent: 484269 pen: 1
484470 rem: 194
[ 784.275212] lower bound violation: 0
[ 784.275260] rto: 200 (0 >> 3 + 0, 41) time: 484275 sent: 484269 pen: 1
484469 rem: 194
[ 787.274753] lower bound violation: 0
[ 787.274814] rto: 200 (0 >> 3 + 0, 44) time: 487274 sent: 487269 pen: 1
490469 rem: 195
[ 787.276560] lower bound violation: 0
[ 787.276615] rto: 200 (0 >> 3 + 0, 43) time: 487276 sent: 487269 pen: 1
487469 rem: 193
[ 787.276725] lower bound violation: 0
[ 787.276781] rto: 200 (0 >> 3 + 0, 42) time: 487276 sent: 487269 pen: 1
487469 rem: 193
[ 790.488206] lower bound violation: 0
[ 790.488262] rto: 200 (0 >> 3 + 0, 45) time: 490488 sent: 490269 pen: 1
493469 rem: 0
[ 790.488375] lower bound violation: 0
[ 790.488425] rto: 200 (0 >> 3 + 0, 45) time: 490488 sent: 490488 pen: 1
490888 rem: 200
[ 790.488523] lower bound violation: 0
[ 790.488570] rto: 200 (0 >> 3 + 0, 44) time: 490488 sent: 490488 pen: 1
490688 rem: 200
[ 793.498782] lower bound violation: 0
[ 793.498842] rto: 200 (0 >> 3 + 0, 47) time: 493498 sent: 493488 pen: 1
496688 rem: 190
[ 793.498953] lower bound violation: 0
[ 793.499007] rto: 200 (0 >> 3 + 0, 46) time: 493498 sent: 493488 pen: 1
493688 rem: 190
[ 793.499118] lower bound violation: 0
[ 793.499172] rto: 200 (0 >> 3 + 0, 45) time: 493499 sent: 493488 pen: 1
493689 rem: 189
[ 796.499231] lower bound violation: 0
[ 796.499296] rto: 200 (0 >> 3 + 0, 48) time: 496499 sent: 496488 pen: 1
499688 rem: 189
[ 796.499414] lower bound violation: 0
[ 796.499463] rto: 200 (0 >> 3 + 0, 47) time: 496499 sent: 496488 pen: 1
496688 rem: 189
[ 796.500131] lower bound violation: 0
[ 796.500185] rto: 200 (0 >> 3 + 0, 46) time: 496500 sent: 496488 pen: 1
496688 rem: 188
[ 799.709974] lower bound violation: 0
[ 799.710036] rto: 200 (0 >> 3 + 0, 49) time: 499710 sent: 499488 pen: 1
502688 rem: 0
[ 799.711369] lower bound violation: 0
[ 799.711428] rto: 200 (0 >> 3 + 0, 49) time: 499711 sent: 499710 pen: 1
500110 rem: 199
[ 799.711547] lower bound violation: 0
[ 799.711602] rto: 200 (0 >> 3 + 0, 48) time: 499711 sent: 499710 pen: 1
499910 rem: 199
[ 802.718498] lower bound violation: 0
[ 802.718560] rto: 200 (0 >> 3 + 0, 51) time: 502718 sent: 502710 pen: 1
505910 rem: 192
[ 802.718689] lower bound violation: 0
[ 802.718753] rto: 200 (0 >> 3 + 0, 50) time: 502718 sent: 502710 pen: 1
502910 rem: 192
[ 802.718869] lower bound violation: 0
[ 802.718921] rto: 200 (0 >> 3 + 0, 49) time: 502718 sent: 502710 pen: 1
502910 rem: 192
[ 805.714361] lower bound violation: 0
[ 805.714422] rto: 200 (0 >> 3 + 0, 52) time: 505714 sent: 505710 pen: 1
508910 rem: 196
[ 805.714533] lower bound violation: 0
[ 805.714590] rto: 200 (0 >> 3 + 0, 51) time: 505714 sent: 505710 pen: 1
505910 rem: 196
[ 805.714688] lower bound violation: 0
[ 805.714736] rto: 200 (0 >> 3 + 0, 50) time: 505714 sent: 505710 pen: 1
505910 rem: 196
[ 808.715859] lower bound violation: 0
[ 808.715919] rto: 200 (0 >> 3 + 0, 53) time: 508715 sent: 508710 pen: 1
511910 rem: 195
[ 808.716030] lower bound violation: 0
[ 808.716086] rto: 200 (0 >> 3 + 0, 52) time: 508715 sent: 508710 pen: 1
508910 rem: 195
[ 808.716185] lower bound violation: 0
[ 808.716233] rto: 200 (0 >> 3 + 0, 51) time: 508715 sent: 508710 pen: 1
508910 rem: 195
[ 811.723842] lower bound violation: 0
[ 811.723903] rto: 200 (0 >> 3 + 0, 54) time: 511723 sent: 511710 pen: 1
514910 rem: 187
[ 811.724015] lower bound violation: 0
[ 811.724073] rto: 200 (0 >> 3 + 0, 53) time: 511724 sent: 511710 pen: 1
511910 rem: 186
[ 811.724185] lower bound violation: 0
[ 811.724234] rto: 200 (0 >> 3 + 0, 52) time: 511724 sent: 511710 pen: 1
511910 rem: 186
[ 814.717152] lower bound violation: 0
[ 814.717212] rto: 200 (0 >> 3 + 0, 55) time: 514717 sent: 514710 pen: 1
517910 rem: 193
[ 814.717325] lower bound violation: 0
[ 814.717373] rto: 200 (0 >> 3 + 0, 54) time: 514717 sent: 514710 pen: 1
514910 rem: 193
[ 814.718354] lower bound violation: 0
[ 814.718407] rto: 200 (0 >> 3 + 0, 53) time: 514718 sent: 514710 pen: 1
514910 rem: 192
[ 817.907863] lower bound violation: 0
[ 817.907923] rto: 200 (0 >> 3 + 0, 56) time: 517907 sent: 517710 pen: 1
520910 rem: 3
[ 817.912287] lower bound violation: 0
[ 817.912346] rto: 200 (0 >> 3 + 0, 56) time: 517912 sent: 517911 pen: 1
518311 rem: 199
[ 817.912456] lower bound violation: 0
[ 817.912511] rto: 200 (0 >> 3 + 0, 55) time: 517912 sent: 517911 pen: 1
518111 rem: 199
[ 820.941479] lower bound violation: 0
[ 820.941539] rto: 200 (0 >> 3 + 0, 58) time: 520941 sent: 520911 pen: 1
524111 rem: 170
[ 820.941671] lower bound violation: 0
[ 820.941733] rto: 200 (0 >> 3 + 0, 57) time: 520941 sent: 520911 pen: 1
521111 rem: 170
[ 820.941846] lower bound violation: 0
[ 820.941895] rto: 200 (0 >> 3 + 0, 56) time: 520941 sent: 520911 pen: 1
521111 rem: 170
[ 824.121180] lower bound violation: 0
[ 824.121242] rto: 200 (0 >> 3 + 0, 59) time: 524121 sent: 523911 pen: 1
527111 rem: 0
[ 824.121346] lower bound violation: 0
[ 824.122108] rto: 200 (0 >> 3 + 0, 59) time: 524121 sent: 524121 pen: 1
524521 rem: 200
[ 824.123817] lower bound violation: 0
[ 824.123887] rto: 200 (0 >> 3 + 0, 58) time: 524123 sent: 524121 pen: 1
524322 rem: 198
[ 827.122286] lower bound violation: 0
[ 827.122347] rto: 200 (0 >> 3 + 0, 61) time: 527122 sent: 527121 pen: 1
530321 rem: 199
[ 827.124167] lower bound violation: 0
[ 827.124223] rto: 200 (0 >> 3 + 0, 60) time: 527124 sent: 527121 pen: 1
527321 rem: 197
[ 827.124332] lower bound violation: 0
[ 827.124389] rto: 200 (0 >> 3 + 0, 59) time: 527124 sent: 527121 pen: 1
527321 rem: 197
[ 830.124556] lower bound violation: 0
[ 830.124617] rto: 200 (0 >> 3 + 0, 62) time: 530124 sent: 530121 pen: 1
533321 rem: 197
[ 830.124729] lower bound violation: 0
[ 830.124777] rto: 200 (0 >> 3 + 0, 61) time: 530124 sent: 530121 pen: 1
530321 rem: 197
[ 830.124874] lower bound violation: 0
[ 830.124922] rto: 200 (0 >> 3 + 0, 60) time: 530124 sent: 530121 pen: 1
530321 rem: 197
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: Crazy TCP bug (keepalive flood?) in 2.6.32?
2010-01-16 14:12 ` Denys Fedoryshchenko
@ 2010-01-19 9:10 ` Damian Lukowski
2010-01-19 11:09 ` Denys Fedoryshchenko
0 siblings, 1 reply; 24+ messages in thread
From: Damian Lukowski @ 2010-01-19 9:10 UTC (permalink / raw)
To: Denys Fedoryshchenko; +Cc: Ilpo Järvinen, netdev
Hi,
thank you for testing. So srtt and rttvar is zero in any of those cases.
Ilpo, it is a bug in tcp_rtt_estimator then, I suppose?
There is also a code comment in tcp_input.c, saying:
> * NOTE: clamping at TCP_RTO_MIN is not required, current algo
> * guarantees that rto is higher.
So we either fix tcp_rtt_estimator or simply clamp at TCP_RTO_MIN?
Damian
> On Monday 11 January 2010 15:02:34 you wrote:
>> On Sat, 26 Dec 2009, Denys Fedoryshchenko wrote:
>>> Few more dumps. I notice:
>>> 1)Ack always equal 1
>>> 2)It is usually first segment of data sent (?)
>>>
>>> Maybe some value not initialised properly?
>>>
>>>
>> Can you see if the RTO lower bound is violated (I added some printing of
>> vars there too already now if it turns out to be something):
>>
>> diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
>> index 65b8ebf..d84469f 100644
>> --- a/net/ipv4/tcp_ipv4.c
>> +++ b/net/ipv4/tcp_ipv4.c
>> @@ -327,6 +327,22 @@ static void do_pmtu_discovery(struct sock *sk, struct
> Hi, i'm very sorry for delay. Just having problem with Lebanese ISP's (u pay
> 20k for 20mbit, u get 20% packetloss at peak time, and they say it is normal).
>
> I did test, here is some things from dmesg
> [ 396.496765] lower bound violation: 0
> [ 396.496833] rto: 200 (0 >> 3 + 0, 4) time: 96496 sent: 96496 pen: 1 96696
> rem: 200
> [ 399.442640] lower bound violation: 0
> [ 399.442721] rto: 200 (0 >> 3 + 0, 16) time: 99442 sent: 99421 pen: 1 102621
> rem: 179
> [ 399.444802] lower bound violation: 0
> [ 399.444881] rto: 200 (0 >> 3 + 0, 10) time: 99444 sent: 99233 pen: 1 102433
> rem: 0
> [ 399.446444] lower bound violation: 0
> [ 399.446521] rto: 200 (0 >> 3 + 0, 15) time: 99446 sent: 99421 pen: 1 99621
> rem: 175
> [ 399.539751] lower bound violation: 0
> [ 399.539832] rto: 200 (0 >> 3 + 0, 7) time: 99539 sent: 99496 pen: 1 102696
> rem: 157
> [ 399.539964] rto: 200 (0 >> 3 + 0, 6) time: 99539 sent: 99496 pen: 1 99696
> rem: 157
> [ 399.540650] rto: 200 (0 >> 3 + 0, 5) time: 99540 sent: 99496 pen: 1 99696
> rem: 156
> [ 402.445674] __ratelimit: 2 callbacks suppressed
> [ 402.445756] lower bound violation: 0
> [ 402.445833] rto: 200 (0 >> 3 + 0, 18) time: 102445 sent: 102421 pen: 1
> 105621 rem: 176
> [ 402.445958] lower bound violation: 0
> [ 402.446026] rto: 200 (0 >> 3 + 0, 13) time: 102445 sent: 102244 pen: 1
> 105444 rem: 0
> [ 402.446150] lower bound violation: 0
> [ 402.446217] rto: 200 (0 >> 3 + 0, 17) time: 102446 sent: 102421 pen: 1
> 102621 rem: 175
> [ 402.742463] lower bound violation: 0
> [ 402.742544] rto: 200 (0 >> 3 + 0, 8) time: 102742 sent: 102496 pen: 1
> 105696 rem: 0
> [ 402.743567] lower bound violation: 0
> [ 402.744361] rto: 200 (0 >> 3 + 0, 8) time: 102744 sent: 102742 pen: 1
> 103142 rem: 198
> [ 402.744478] lower bound violation: 0
> [ 402.744545] rto: 200 (0 >> 3 + 0, 7) time: 102744 sent: 102742 pen: 1
> 102942 rem: 198
> [ 405.446861] lower bound violation: 0
> [ 405.446943] rto: 200 (0 >> 3 + 0, 20) time: 105446 sent: 105421 pen: 1
> 108621 rem: 175
> [ 405.447075] lower bound violation: 0
> [ 405.447142] rto: 200 (0 >> 3 + 0, 16) time: 105446 sent: 105246 pen: 1
> 108446 rem: 0
> [ 405.447265] lower bound violation: 0
> [ 405.447332] rto: 200 (0 >> 3 + 0, 19) time: 105446 sent: 105421 pen: 1
> 105621 rem: 175
> [ 405.759226] lower bound violation: 0
> [ 405.759307] rto: 200 (0 >> 3 + 0, 10) time: 105759 sent: 105742 pen: 1
> 108942 rem: 183
> [ 405.763529] rto: 200 (0 >> 3 + 0, 9) time: 105763 sent: 105742 pen: 1
> 105942 rem: 179
> [ 405.764344] rto: 200 (0 >> 3 + 0, 8) time: 105764 sent: 105742 pen: 1
> 105942 rem: 178
> [ 408.450964] __ratelimit: 2 callbacks suppressed
> [ 408.451045] lower bound violation: 0
> [ 408.451121] rto: 200 (0 >> 3 + 0, 22) time: 108450 sent: 108421 pen: 1
> 111621 rem: 171
> [ 408.451246] lower bound violation: 0
> [ 408.451314] rto: 200 (0 >> 3 + 0, 19) time: 108450 sent: 108246 pen: 1
> 111446 rem: 0
> [ 408.451437] lower bound violation: 0
> [ 408.451504] rto: 200 (0 >> 3 + 0, 21) time: 108450 sent: 108421 pen: 1
> 108621 rem: 171
> [ 408.792229] lower bound violation: 0
> [ 408.792307] rto: 200 (0 >> 3 + 0, 11) time: 108792 sent: 108742 pen: 1
> 111942 rem: 150
> [ 408.792821] lower bound violation: 0
> [ 408.792897] rto: 200 (0 >> 3 + 0, 10) time: 108792 sent: 108742 pen: 1
> 108942 rem: 150
> [ 408.793033] lower bound violation: 0
> [ 408.793109] rto: 200 (0 >> 3 + 0, 9) time: 108793 sent: 108742 pen: 1
> 108943 rem: 149
> [ 411.478006] lower bound violation: 0
> [ 411.478088] rto: 200 (0 >> 3 + 0, 24) time: 111478 sent: 111421 pen: 1
> 114621 rem: 143
> [ 411.478220] lower bound violation: 0
> [ 411.478287] rto: 200 (0 >> 3 + 0, 22) time: 111478 sent: 111250 pen: 1
> 114450 rem: 0
> [ 411.478411] lower bound violation: 0
> [ 411.478478] rto: 200 (0 >> 3 + 0, 23) time: 111478 sent: 111421 pen: 1
> 111621 rem: 143
> [ 411.804382] lower bound violation: 0
> [ 411.804464] rto: 200 (0 >> 3 + 0, 12) time: 111804 sent: 111742 pen: 1
> 114942 rem: 138
> [ 411.804598] rto: 200 (0 >> 3 + 0, 11) time: 111804 sent: 111742 pen: 1
> 111942 rem: 138
> [ 414.498996] __ratelimit: 1 callbacks suppressed
> [ 414.499080] lower bound violation: 0
> [ 414.499160] rto: 200 (0 >> 3 + 0, 26) time: 114498 sent: 114421 pen: 1
> 117621 rem: 123
> [ 414.513129] lower bound violation: 0
> [ 414.513207] rto: 200 (0 >> 3 + 0, 25) time: 114513 sent: 114278 pen: 1
> 117478 rem: 0
> [ 414.513344] lower bound violation: 0
> [ 414.513412] rto: 200 (0 >> 3 + 0, 25) time: 114513 sent: 114421 pen: 1
> 114621 rem: 108
> [ 414.784717] lower bound violation: 0
> [ 414.784799] rto: 200 (0 >> 3 + 0, 14) time: 114784 sent: 114742 pen: 1
> 117942 rem: 158
> [ 414.786072] lower bound violation: 0
> [ 414.786152] rto: 200 (0 >> 3 + 0, 13) time: 114786 sent: 114742 pen: 1
> 114942 rem: 156
> [ 417.515995] lower bound violation: 0
> [ 417.516077] rto: 200 (0 >> 3 + 0, 28) time: 117516 sent: 117421 pen: 1
> 120621 rem: 105
> [ 417.516213] lower bound violation: 0
> [ 417.516289] rto: 200 (0 >> 3 + 0, 28) time: 117516 sent: 117313 pen: 1
> 120513 rem: 0
> [ 417.516413] lower bound violation: 0
> [ 417.516481] rto: 200 (0 >> 3 + 0, 27) time: 117516 sent: 117421 pen: 1
> 117621 rem: 105
> [ 417.803533] lower bound violation: 0
> [ 417.803615] rto: 200 (0 >> 3 + 0, 16) time: 117803 sent: 117742 pen: 1
> 120942 rem: 139
> [ 417.803745] lower bound violation: 0
> [ 417.803812] rto: 200 (0 >> 3 + 0, 15) time: 117803 sent: 117742 pen: 1
> 117942 rem: 139
> [ 417.803930] rto: 200 (0 >> 3 + 0, 14) time: 117803 sent: 117742 pen: 1
> 117942 rem: 139
> [ 420.556115] __ratelimit: 1 callbacks suppressed
> [ 420.556198] lower bound violation: 0
> [ 420.556274] rto: 200 (0 >> 3 + 0, 30) time: 120556 sent: 120421 pen: 1
> 123621 rem: 65
> [ 420.556399] lower bound violation: 0
> [ 420.556466] rto: 200 (0 >> 3 + 0, 31) time: 120556 sent: 120316 pen: 1
> 123516 rem: 0
> [ 420.556591] lower bound violation: 0
> [ 420.556659] rto: 200 (0 >> 3 + 0, 29) time: 120556 sent: 120421 pen: 1
> 120621 rem: 65
> [ 420.965666] lower bound violation: 0
> [ 420.965749] rto: 200 (0 >> 3 + 0, 17) time: 120965 sent: 120742 pen: 1
> 123942 rem: 0
> [ 420.967717] lower bound violation: 0
> [ 420.967796] rto: 200 (0 >> 3 + 0, 17) time: 120967 sent: 120965 pen: 1
> 121365 rem: 198
> [ 420.972139] lower bound violation: 0
> [ 420.972216] rto: 200 (0 >> 3 + 0, 16) time: 120972 sent: 120965 pen: 1
> 121165 rem: 193
> [ 423.564843] lower bound violation: 0
> [ 423.564924] rto: 200 (0 >> 3 + 0, 32) time: 123564 sent: 123421 pen: 1
> 126621 rem: 57
> [ 423.565062] lower bound violation: 0
> [ 423.565130] rto: 200 (0 >> 3 + 0, 34) time: 123565 sent: 123356 pen: 1
> 126556 rem: 0
> [ 423.565254] lower bound violation: 0
> [ 423.565322] rto: 200 (0 >> 3 + 0, 31) time: 123565 sent: 123421 pen: 1
> 123622 rem: 56
> [ 424.001854] lower bound violation: 0
> [ 424.001936] rto: 200 (0 >> 3 + 0, 19) time: 124001 sent: 123965 pen: 1
> 127165 rem: 164
> [ 424.005665] rto: 200 (0 >> 3 + 0, 18) time: 124005 sent: 123965 pen: 1
> 124166 rem: 160
> [ 424.007636] rto: 200 (0 >> 3 + 0, 17) time: 124007 sent: 123965 pen: 1
> 124165 rem: 158
> [ 426.580172] __ratelimit: 2 callbacks suppressed
> [ 426.580254] lower bound violation: 0
> [ 426.580337] rto: 200 (0 >> 3 + 0, 34) time: 126580 sent: 126421 pen: 1
> 129621 rem: 41
> [ 426.580456] lower bound violation: 0
> [ 426.580524] rto: 200 (0 >> 3 + 0, 37) time: 126580 sent: 126365 pen: 1
> 129565 rem: 0
> [ 426.580647] lower bound violation: 0
> [ 426.580715] rto: 200 (0 >> 3 + 0, 33) time: 126580 sent: 126421 pen: 1
> 126621 rem: 41
> [ 427.210363] lower bound violation: 0
> [ 427.210443] rto: 200 (0 >> 3 + 0, 20) time: 127210 sent: 126965 pen: 1
> 130165 rem: 0
> [ 427.210587] lower bound violation: 0
> [ 427.210654] rto: 200 (0 >> 3 + 0, 20) time: 127210 sent: 127210 pen: 1
> 127610 rem: 200
> [ 427.210770] lower bound violation: 0
> [ 427.210837] rto: 200 (0 >> 3 + 0, 19) time: 127210 sent: 127210 pen: 1
> 127410 rem: 200
> [ 429.586539] lower bound violation: 0
> [ 429.586628] rto: 200 (0 >> 3 + 0, 36) time: 129586 sent: 129421 pen: 1
> 132621 rem: 35
> [ 429.588735] lower bound violation: 0
> [ 429.588814] rto: 200 (0 >> 3 + 0, 40) time: 129588 sent: 129380 pen: 1
> 132580 rem: 0
> [ 429.589880] lower bound violation: 0
> [ 429.589957] rto: 200 (0 >> 3 + 0, 35) time: 129589 sent: 129421 pen: 1
> 129621 rem: 32
> [ 430.231164] lower bound violation: 0
> [ 430.231246] rto: 200 (0 >> 3 + 0, 22) time: 130231 sent: 130210 pen: 1
> 133410 rem: 179
> [ 430.253497] rto: 200 (0 >> 3 + 0, 21) time: 130253 sent: 130210 pen: 1
> 130410 rem: 157
> [ 432.600005] __ratelimit: 1 callbacks suppressed
> [ 432.600087] lower bound violation: 0
> [ 432.600164] rto: 200 (0 >> 3 + 0, 38) time: 132600 sent: 132421 pen: 1
> 135621 rem: 21
> [ 432.601516] lower bound violation: 0
> [ 432.601593] rto: 200 (0 >> 3 + 0, 43) time: 132601 sent: 132388 pen: 1
> 135588 rem: 0
> [ 432.601729] lower bound violation: 0
> [ 432.601796] rto: 200 (0 >> 3 + 0, 37) time: 132601 sent: 132421 pen: 1
> 132621 rem: 20
> [ 433.292095] lower bound violation: 0
> [ 433.292177] rto: 200 (0 >> 3 + 0, 24) time: 133292 sent: 133210 pen: 1
> 136410 rem: 118
> [ 433.292308] lower bound violation: 0
> [ 433.292375] rto: 200 (0 >> 3 + 0, 23) time: 133292 sent: 133210 pen: 1
> 133410 rem: 118
> [ 433.292491] lower bound violation: 0
> [ 433.292558] rto: 200 (0 >> 3 + 0, 22) time: 133292 sent: 133210 pen: 1
> 133410 rem: 118
> [ 435.624429] lower bound violation: 0
> [ 435.624512] rto: 200 (0 >> 3 + 0, 40) time: 135624 sent: 135421 pen: 1
> 138621 rem: 0
> [ 435.624649] lower bound violation: 0
> [ 435.624717] rto: 200 (0 >> 3 + 0, 46) time: 135624 sent: 135401 pen: 1
> 138601 rem: 0
> [ 435.625410] lower bound violation: 0
> [ 435.625410] rto: 200 (0 >> 3 + 0, 40) time: 135624 sent: 135624 pen: 1
> 136024 rem: 200
> [ 436.455058] lower bound violation: 0
> [ 436.455140] rto: 200 (0 >> 3 + 0, 25) time: 136455 sent: 136210 pen: 1
> 139410 rem: 0
> [ 436.455279] rto: 200 (0 >> 3 + 0, 25) time: 136455 sent: 136455 pen: 1
> 136855 rem: 200
> [ 436.455397] rto: 200 (0 >> 3 + 0, 24) time: 136455 sent: 136455 pen: 1
> 136655 rem: 200
> [ 439.507877] __ratelimit: 2 callbacks suppressed
> [ 439.507959] lower bound violation: 0
> [ 439.508037] rto: 200 (0 >> 3 + 0, 27) time: 139507 sent: 139455 pen: 1
> 142655 rem: 148
> [ 439.508161] lower bound violation: 0
> [ 439.508228] rto: 200 (0 >> 3 + 0, 26) time: 139507 sent: 139455 pen: 1
> 139655 rem: 148
> [ 442.507756] lower bound violation: 0
> [ 442.507838] rto: 200 (0 >> 3 + 0, 29) time: 142507 sent: 142455 pen: 1
> 145655 rem: 148
> [ 442.507969] lower bound violation: 0
> [ 442.508035] rto: 200 (0 >> 3 + 0, 28) time: 142507 sent: 142455 pen: 1
> 142655 rem: 148
> [ 442.508152] lower bound violation: 0
> [ 442.508219] rto: 200 (0 >> 3 + 0, 27) time: 142507 sent: 142455 pen: 1
> 142655 rem: 148
> [ 445.498049] lower bound violation: 0
> [ 445.498130] rto: 200 (0 >> 3 + 0, 30) time: 145498 sent: 145455 pen: 1
> 148655 rem: 157
> [ 445.499105] lower bound violation: 0
> [ 445.499194] rto: 200 (0 >> 3 + 0, 29) time: 145499 sent: 145455 pen: 1
> 145655 rem: 156
> [ 445.501524] lower bound violation: 0
> [ 445.501600] rto: 200 (0 >> 3 + 0, 28) time: 145501 sent: 145455 pen: 1
> 145655 rem: 154
> [ 448.678590] lower bound violation: 0
> [ 448.678671] rto: 200 (0 >> 3 + 0, 31) time: 148678 sent: 148455 pen: 1
> 151655 rem: 0
> [ 448.678808] lower bound violation: 0
> [ 448.678876] rto: 200 (0 >> 3 + 0, 31) time: 148678 sent: 148678 pen: 1
> 149078 rem: 200
> [ 451.716905] lower bound violation: 0
> [ 451.716987] rto: 200 (0 >> 3 + 0, 34) time: 151716 sent: 151678 pen: 1
> 154878 rem: 162
> [ 451.763041] lower bound violation: 0
> [ 451.763121] rto: 200 (0 >> 3 + 0, 33) time: 151763 sent: 151678 pen: 1
> 151878 rem: 115
> [ 451.763252] lower bound violation: 0
> [ 451.763320] rto: 200 (0 >> 3 + 0, 32) time: 151763 sent: 151678 pen: 1
> 151878 rem: 115
> [ 454.732396] lower bound violation: 0
> [ 454.732478] rto: 200 (0 >> 3 + 0, 35) time: 154732 sent: 154678 pen: 1
> 157878 rem: 146
> [ 454.736990] lower bound violation: 0
> [ 454.737072] rto: 200 (0 >> 3 + 0, 34) time: 154737 sent: 154678 pen: 1
> 154878 rem: 141
> [ 454.738128] lower bound violation: 0
> [ 454.738206] rto: 200 (0 >> 3 + 0, 33) time: 154738 sent: 154678 pen: 1
> 154878 rem: 140
> [ 457.894010] lower bound violation: 0
> [ 457.894098] rto: 200 (0 >> 3 + 0, 36) time: 157894 sent: 157678 pen: 1
> 160878 rem: 0
> [ 457.913672] lower bound violation: 0
> [ 457.913751] rto: 200 (0 >> 3 + 0, 36) time: 157913 sent: 157894 pen: 1
> 158294 rem: 181
> [ 457.913883] lower bound violation: 0
> [ 457.913950] rto: 200 (0 >> 3 + 0, 35) time: 157913 sent: 157894 pen: 1
> 158094 rem: 181
> [ 460.932992] lower bound violation: 0
> [ 460.933073] rto: 200 (0 >> 3 + 0, 38) time: 160932 sent: 160894 pen: 1
> 164094 rem: 162
> [ 460.933206] lower bound violation: 0
> [ 460.933273] rto: 200 (0 >> 3 + 0, 37) time: 160932 sent: 160894 pen: 1
> 161094 rem: 162
> [ 460.933390] lower bound violation: 0
> [ 460.933457] rto: 200 (0 >> 3 + 0, 36) time: 160932 sent: 160894 pen: 1
> 161094 rem: 162
> [ 463.928470] lower bound violation: 0
> [ 463.928551] rto: 200 (0 >> 3 + 0, 39) time: 163928 sent: 163894 pen: 1
> 167094 rem: 166
> [ 466.953674] lower bound violation: 0
> [ 466.953755] rto: 200 (0 >> 3 + 0, 42) time: 166953 sent: 166894 pen: 1
> 170094 rem: 141
> [ 466.953887] lower bound violation: 0
> [ 466.953954] rto: 200 (0 >> 3 + 0, 41) time: 166953 sent: 166894 pen: 1
> 167094 rem: 141
> [ 470.112498] lower bound violation: 0
> [ 470.112580] rto: 200 (0 >> 3 + 0, 44) time: 170112 sent: 169894 pen: 1
> 173094 rem: 0
> [ 470.127286] lower bound violation: 0
> [ 470.127364] rto: 200 (0 >> 3 + 0, 44) time: 170127 sent: 170112 pen: 1
> 170512 rem: 185
> [ 473.167817] lower bound violation: 0
> [ 473.167899] rto: 200 (0 >> 3 + 0, 47) time: 173167 sent: 173112 pen: 1
> 176312 rem: 145
> [ 473.168030] lower bound violation: 0
> [ 473.168098] rto: 200 (0 >> 3 + 0, 46) time: 173168 sent: 173112 pen: 1
> 173313 rem: 144
> [ 473.169413] lower bound violation: 0
> [ 473.169491] rto: 200 (0 >> 3 + 0, 45) time: 173169 sent: 173112 pen: 1
> 173312 rem: 143
> [ 522.630573] lower bound violation: 0
> [ 522.630655] rto: 200 (0 >> 3 + 0, 0) time: 222630 sent: 222630 pen: 1
> 228630 rem: 200
> [ 627.844099] lower bound violation: 0
> [ 627.844176] rto: 200 (0 >> 3 + 0, 8) time: 327844 sent: 324830 pen: 1
> 427230 rem: 0
> [ 630.848249] lower bound violation: 0
> [ 630.848333] rto: 200 (0 >> 3 + 0, 11) time: 330848 sent: 330644 pen: 1
> 333844 rem: 0
> [ 735.859328] lower bound violation: 0
> [ 735.859388] rto: 200 (0 >> 3 + 0, 19) time: 435859 sent: 432848 pen: 1
> 535248 rem: 0
> [ 738.864261] lower bound violation: 0
> [ 738.864322] rto: 200 (0 >> 3 + 0, 22) time: 438864 sent: 438659 pen: 1
> 441859 rem: 0
> [ 738.865358] lower bound violation: 0
> [ 738.865415] rto: 200 (0 >> 3 + 0, 22) time: 438865 sent: 438864 pen: 1
> 439264 rem: 199
> [ 741.864947] lower bound violation: 0
> [ 741.865007] rto: 200 (0 >> 3 + 0, 25) time: 441864 sent: 441864 pen: 1
> 445064 rem: 200
> [ 741.867651] lower bound violation: 0
> [ 741.867709] rto: 200 (0 >> 3 + 0, 24) time: 441867 sent: 441864 pen: 1
> 442065 rem: 197
> [ 741.867821] lower bound violation: 0
> [ 741.867875] rto: 200 (0 >> 3 + 0, 23) time: 441867 sent: 441864 pen: 1
> 442064 rem: 197
> [ 744.874165] lower bound violation: 0
> [ 744.874225] rto: 200 (0 >> 3 + 0, 26) time: 444874 sent: 444864 pen: 1
> 448064 rem: 190
> [ 744.874340] lower bound violation: 0
> [ 744.874388] rto: 200 (0 >> 3 + 0, 25) time: 444874 sent: 444864 pen: 1
> 445064 rem: 190
> [ 744.874486] lower bound violation: 0
> [ 744.874535] rto: 200 (0 >> 3 + 0, 24) time: 444874 sent: 444864 pen: 1
> 445064 rem: 190
> [ 747.874311] lower bound violation: 0
> [ 747.874373] rto: 200 (0 >> 3 + 0, 27) time: 447874 sent: 447864 pen: 1
> 451064 rem: 190
> [ 747.874474] lower bound violation: 0
> [ 747.874523] rto: 200 (0 >> 3 + 0, 26) time: 447874 sent: 447864 pen: 1
> 448064 rem: 190
> [ 747.874628] lower bound violation: 0
> [ 747.874677] rto: 200 (0 >> 3 + 0, 25) time: 447874 sent: 447864 pen: 1
> 448064 rem: 190
> [ 750.870109] lower bound violation: 0
> [ 750.870170] rto: 200 (0 >> 3 + 0, 28) time: 450870 sent: 450864 pen: 1
> 454064 rem: 194
> [ 750.870281] lower bound violation: 0
> [ 750.870330] rto: 200 (0 >> 3 + 0, 27) time: 450870 sent: 450864 pen: 1
> 451064 rem: 194
> [ 750.870435] lower bound violation: 0
> [ 750.870484] rto: 200 (0 >> 3 + 0, 26) time: 450870 sent: 450864 pen: 1
> 451064 rem: 194
> [ 753.882598] lower bound violation: 0
> [ 753.882661] rto: 200 (0 >> 3 + 0, 29) time: 453882 sent: 453864 pen: 1
> 457064 rem: 182
> [ 753.882779] lower bound violation: 0
> [ 753.882842] rto: 200 (0 >> 3 + 0, 28) time: 453882 sent: 453864 pen: 1
> 454064 rem: 182
> [ 753.882975] lower bound violation: 0
> [ 753.883050] rto: 200 (0 >> 3 + 0, 27) time: 453883 sent: 453864 pen: 1
> 454064 rem: 181
> [ 756.874204] lower bound violation: 0
> [ 756.874265] rto: 200 (0 >> 3 + 0, 30) time: 456874 sent: 456864 pen: 1
> 460064 rem: 190
> [ 756.874376] lower bound violation: 0
> [ 756.874424] rto: 200 (0 >> 3 + 0, 29) time: 456874 sent: 456864 pen: 1
> 457064 rem: 190
> [ 756.874527] lower bound violation: 0
> [ 756.874576] rto: 200 (0 >> 3 + 0, 28) time: 456874 sent: 456864 pen: 1
> 457064 rem: 190
> [ 759.891416] lower bound violation: 0
> [ 759.891480] rto: 200 (0 >> 3 + 0, 31) time: 459891 sent: 459864 pen: 1
> 463064 rem: 173
> [ 759.891591] lower bound violation: 0
> [ 759.891647] rto: 200 (0 >> 3 + 0, 30) time: 459891 sent: 459864 pen: 1
> 460064 rem: 173
> [ 759.891746] lower bound violation: 0
> [ 759.892390] rto: 200 (0 >> 3 + 0, 29) time: 459891 sent: 459864 pen: 1
> 460064 rem: 173
> [ 763.066046] lower bound violation: 0
> [ 763.066106] rto: 200 (0 >> 3 + 0, 32) time: 463066 sent: 462864 pen: 1
> 466064 rem: 0
> [ 763.066224] lower bound violation: 0
> [ 763.066273] rto: 200 (0 >> 3 + 0, 32) time: 463066 sent: 463066 pen: 1
> 463466 rem: 200
> [ 763.066371] lower bound violation: 0
> [ 763.066419] rto: 200 (0 >> 3 + 0, 31) time: 463066 sent: 463066 pen: 1
> 463266 rem: 200
> [ 766.065427] lower bound violation: 0
> [ 766.065501] rto: 200 (0 >> 3 + 0, 33) time: 466065 sent: 464466 pen: 1
> 466066 rem: 0
> [ 766.069012] lower bound violation: 0
> [ 766.069070] rto: 200 (0 >> 3 + 0, 33) time: 466068 sent: 466065 pen: 1
> 466465 rem: 197
> [ 766.069184] lower bound violation: 0
> [ 766.069242] rto: 200 (0 >> 3 + 0, 32) time: 466069 sent: 466065 pen: 1
> 466266 rem: 196
> [ 769.077813] lower bound violation: 0
> [ 769.077873] rto: 200 (0 >> 3 + 0, 35) time: 469077 sent: 469065 pen: 1
> 472265 rem: 188
> [ 769.077985] lower bound violation: 0
> [ 769.078043] rto: 200 (0 >> 3 + 0, 34) time: 469078 sent: 469065 pen: 1
> 469265 rem: 187
> [ 772.078686] lower bound violation: 0
> [ 772.078746] rto: 200 (0 >> 3 + 0, 37) time: 472078 sent: 472065 pen: 1
> 475265 rem: 187
> [ 772.078859] lower bound violation: 0
> [ 772.078907] rto: 200 (0 >> 3 + 0, 36) time: 472078 sent: 472065 pen: 1
> 472265 rem: 187
> [ 772.079674] lower bound violation: 0
> [ 772.079731] rto: 200 (0 >> 3 + 0, 35) time: 472079 sent: 472065 pen: 1
> 472265 rem: 186
> [ 775.269432] lower bound violation: 0
> [ 775.269494] rto: 200 (0 >> 3 + 0, 38) time: 475269 sent: 475065 pen: 1
> 478265 rem: 0
> [ 775.270671] lower bound violation: 0
> [ 775.270733] rto: 200 (0 >> 3 + 0, 38) time: 475270 sent: 475269 pen: 1
> 475669 rem: 199
> [ 775.270848] lower bound violation: 0
> [ 775.270897] rto: 200 (0 >> 3 + 0, 37) time: 475270 sent: 475269 pen: 1
> 475469 rem: 199
> [ 778.277343] lower bound violation: 0
> [ 778.277404] rto: 200 (0 >> 3 + 0, 40) time: 478277 sent: 478269 pen: 1
> 481469 rem: 192
> [ 778.277536] lower bound violation: 0
> [ 778.277602] rto: 200 (0 >> 3 + 0, 39) time: 478277 sent: 478269 pen: 1
> 478469 rem: 192
> [ 778.277722] lower bound violation: 0
> [ 778.277778] rto: 200 (0 >> 3 + 0, 38) time: 478277 sent: 478269 pen: 1
> 478469 rem: 192
> [ 781.272677] lower bound violation: 0
> [ 781.272737] rto: 200 (0 >> 3 + 0, 41) time: 481272 sent: 481269 pen: 1
> 484469 rem: 197
> [ 781.272850] lower bound violation: 0
> [ 781.272898] rto: 200 (0 >> 3 + 0, 40) time: 481272 sent: 481269 pen: 1
> 481469 rem: 197
> [ 784.274886] lower bound violation: 0
> [ 784.274946] rto: 200 (0 >> 3 + 0, 43) time: 484274 sent: 484269 pen: 1
> 487469 rem: 195
> [ 784.275064] lower bound violation: 0
> [ 784.275112] rto: 200 (0 >> 3 + 0, 42) time: 484275 sent: 484269 pen: 1
> 484470 rem: 194
> [ 784.275212] lower bound violation: 0
> [ 784.275260] rto: 200 (0 >> 3 + 0, 41) time: 484275 sent: 484269 pen: 1
> 484469 rem: 194
> [ 787.274753] lower bound violation: 0
> [ 787.274814] rto: 200 (0 >> 3 + 0, 44) time: 487274 sent: 487269 pen: 1
> 490469 rem: 195
> [ 787.276560] lower bound violation: 0
> [ 787.276615] rto: 200 (0 >> 3 + 0, 43) time: 487276 sent: 487269 pen: 1
> 487469 rem: 193
> [ 787.276725] lower bound violation: 0
> [ 787.276781] rto: 200 (0 >> 3 + 0, 42) time: 487276 sent: 487269 pen: 1
> 487469 rem: 193
> [ 790.488206] lower bound violation: 0
> [ 790.488262] rto: 200 (0 >> 3 + 0, 45) time: 490488 sent: 490269 pen: 1
> 493469 rem: 0
> [ 790.488375] lower bound violation: 0
> [ 790.488425] rto: 200 (0 >> 3 + 0, 45) time: 490488 sent: 490488 pen: 1
> 490888 rem: 200
> [ 790.488523] lower bound violation: 0
> [ 790.488570] rto: 200 (0 >> 3 + 0, 44) time: 490488 sent: 490488 pen: 1
> 490688 rem: 200
> [ 793.498782] lower bound violation: 0
> [ 793.498842] rto: 200 (0 >> 3 + 0, 47) time: 493498 sent: 493488 pen: 1
> 496688 rem: 190
> [ 793.498953] lower bound violation: 0
> [ 793.499007] rto: 200 (0 >> 3 + 0, 46) time: 493498 sent: 493488 pen: 1
> 493688 rem: 190
> [ 793.499118] lower bound violation: 0
> [ 793.499172] rto: 200 (0 >> 3 + 0, 45) time: 493499 sent: 493488 pen: 1
> 493689 rem: 189
> [ 796.499231] lower bound violation: 0
> [ 796.499296] rto: 200 (0 >> 3 + 0, 48) time: 496499 sent: 496488 pen: 1
> 499688 rem: 189
> [ 796.499414] lower bound violation: 0
> [ 796.499463] rto: 200 (0 >> 3 + 0, 47) time: 496499 sent: 496488 pen: 1
> 496688 rem: 189
> [ 796.500131] lower bound violation: 0
> [ 796.500185] rto: 200 (0 >> 3 + 0, 46) time: 496500 sent: 496488 pen: 1
> 496688 rem: 188
> [ 799.709974] lower bound violation: 0
> [ 799.710036] rto: 200 (0 >> 3 + 0, 49) time: 499710 sent: 499488 pen: 1
> 502688 rem: 0
> [ 799.711369] lower bound violation: 0
> [ 799.711428] rto: 200 (0 >> 3 + 0, 49) time: 499711 sent: 499710 pen: 1
> 500110 rem: 199
> [ 799.711547] lower bound violation: 0
> [ 799.711602] rto: 200 (0 >> 3 + 0, 48) time: 499711 sent: 499710 pen: 1
> 499910 rem: 199
> [ 802.718498] lower bound violation: 0
> [ 802.718560] rto: 200 (0 >> 3 + 0, 51) time: 502718 sent: 502710 pen: 1
> 505910 rem: 192
> [ 802.718689] lower bound violation: 0
> [ 802.718753] rto: 200 (0 >> 3 + 0, 50) time: 502718 sent: 502710 pen: 1
> 502910 rem: 192
> [ 802.718869] lower bound violation: 0
> [ 802.718921] rto: 200 (0 >> 3 + 0, 49) time: 502718 sent: 502710 pen: 1
> 502910 rem: 192
> [ 805.714361] lower bound violation: 0
> [ 805.714422] rto: 200 (0 >> 3 + 0, 52) time: 505714 sent: 505710 pen: 1
> 508910 rem: 196
> [ 805.714533] lower bound violation: 0
> [ 805.714590] rto: 200 (0 >> 3 + 0, 51) time: 505714 sent: 505710 pen: 1
> 505910 rem: 196
> [ 805.714688] lower bound violation: 0
> [ 805.714736] rto: 200 (0 >> 3 + 0, 50) time: 505714 sent: 505710 pen: 1
> 505910 rem: 196
> [ 808.715859] lower bound violation: 0
> [ 808.715919] rto: 200 (0 >> 3 + 0, 53) time: 508715 sent: 508710 pen: 1
> 511910 rem: 195
> [ 808.716030] lower bound violation: 0
> [ 808.716086] rto: 200 (0 >> 3 + 0, 52) time: 508715 sent: 508710 pen: 1
> 508910 rem: 195
> [ 808.716185] lower bound violation: 0
> [ 808.716233] rto: 200 (0 >> 3 + 0, 51) time: 508715 sent: 508710 pen: 1
> 508910 rem: 195
> [ 811.723842] lower bound violation: 0
> [ 811.723903] rto: 200 (0 >> 3 + 0, 54) time: 511723 sent: 511710 pen: 1
> 514910 rem: 187
> [ 811.724015] lower bound violation: 0
> [ 811.724073] rto: 200 (0 >> 3 + 0, 53) time: 511724 sent: 511710 pen: 1
> 511910 rem: 186
> [ 811.724185] lower bound violation: 0
> [ 811.724234] rto: 200 (0 >> 3 + 0, 52) time: 511724 sent: 511710 pen: 1
> 511910 rem: 186
> [ 814.717152] lower bound violation: 0
> [ 814.717212] rto: 200 (0 >> 3 + 0, 55) time: 514717 sent: 514710 pen: 1
> 517910 rem: 193
> [ 814.717325] lower bound violation: 0
> [ 814.717373] rto: 200 (0 >> 3 + 0, 54) time: 514717 sent: 514710 pen: 1
> 514910 rem: 193
> [ 814.718354] lower bound violation: 0
> [ 814.718407] rto: 200 (0 >> 3 + 0, 53) time: 514718 sent: 514710 pen: 1
> 514910 rem: 192
> [ 817.907863] lower bound violation: 0
> [ 817.907923] rto: 200 (0 >> 3 + 0, 56) time: 517907 sent: 517710 pen: 1
> 520910 rem: 3
> [ 817.912287] lower bound violation: 0
> [ 817.912346] rto: 200 (0 >> 3 + 0, 56) time: 517912 sent: 517911 pen: 1
> 518311 rem: 199
> [ 817.912456] lower bound violation: 0
> [ 817.912511] rto: 200 (0 >> 3 + 0, 55) time: 517912 sent: 517911 pen: 1
> 518111 rem: 199
> [ 820.941479] lower bound violation: 0
> [ 820.941539] rto: 200 (0 >> 3 + 0, 58) time: 520941 sent: 520911 pen: 1
> 524111 rem: 170
> [ 820.941671] lower bound violation: 0
> [ 820.941733] rto: 200 (0 >> 3 + 0, 57) time: 520941 sent: 520911 pen: 1
> 521111 rem: 170
> [ 820.941846] lower bound violation: 0
> [ 820.941895] rto: 200 (0 >> 3 + 0, 56) time: 520941 sent: 520911 pen: 1
> 521111 rem: 170
> [ 824.121180] lower bound violation: 0
> [ 824.121242] rto: 200 (0 >> 3 + 0, 59) time: 524121 sent: 523911 pen: 1
> 527111 rem: 0
> [ 824.121346] lower bound violation: 0
> [ 824.122108] rto: 200 (0 >> 3 + 0, 59) time: 524121 sent: 524121 pen: 1
> 524521 rem: 200
> [ 824.123817] lower bound violation: 0
> [ 824.123887] rto: 200 (0 >> 3 + 0, 58) time: 524123 sent: 524121 pen: 1
> 524322 rem: 198
> [ 827.122286] lower bound violation: 0
> [ 827.122347] rto: 200 (0 >> 3 + 0, 61) time: 527122 sent: 527121 pen: 1
> 530321 rem: 199
> [ 827.124167] lower bound violation: 0
> [ 827.124223] rto: 200 (0 >> 3 + 0, 60) time: 527124 sent: 527121 pen: 1
> 527321 rem: 197
> [ 827.124332] lower bound violation: 0
> [ 827.124389] rto: 200 (0 >> 3 + 0, 59) time: 527124 sent: 527121 pen: 1
> 527321 rem: 197
> [ 830.124556] lower bound violation: 0
> [ 830.124617] rto: 200 (0 >> 3 + 0, 62) time: 530124 sent: 530121 pen: 1
> 533321 rem: 197
> [ 830.124729] lower bound violation: 0
> [ 830.124777] rto: 200 (0 >> 3 + 0, 61) time: 530124 sent: 530121 pen: 1
> 530321 rem: 197
> [ 830.124874] lower bound violation: 0
> [ 830.124922] rto: 200 (0 >> 3 + 0, 60) time: 530124 sent: 530121 pen: 1
> 530321 rem: 197
> --
> To unsubscribe from this list: send the line "unsubscribe netdev" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: Crazy TCP bug (keepalive flood?) in 2.6.32?
2010-01-19 9:10 ` Damian Lukowski
@ 2010-01-19 11:09 ` Denys Fedoryshchenko
2010-01-19 11:17 ` Ilpo Järvinen
0 siblings, 1 reply; 24+ messages in thread
From: Denys Fedoryshchenko @ 2010-01-19 11:09 UTC (permalink / raw)
To: Damian Lukowski, Ilpo Järvinen, netdev
On Tuesday 19 January 2010 11:10:12 you wrote:
> Hi,
> thank you for testing. So srtt and rttvar is zero in any of those cases.
> Ilpo, it is a bug in tcp_rtt_estimator then, I suppose?
>
> There is also a code comment in tcp_input.c, saying:
> > * NOTE: clamping at TCP_RTO_MIN is not required, current algo
> > * guarantees that rto is higher.
>
> So we either fix tcp_rtt_estimator or simply clamp at TCP_RTO_MIN?
>
> Damian
>
> > On Monday 11 January 2010 15:02:34 you wrote:
> >> On Sat, 26 Dec 2009, Denys Fedoryshchenko wrote:
> >>> Few more dumps. I notice:
> >>> 1)Ack always equal 1
> >>> 2)It is usually first segment of data sent (?)
> >>>
> >>> Maybe some value not initialised properly?
> >>
> >> Can you see if the RTO lower bound is violated (I added some printing of
> >> vars there too already now if it turns out to be something):
> >>
> >> diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
> >> index 65b8ebf..d84469f 100644
> >> --- a/net/ipv4/tcp_ipv4.c
> >> +++ b/net/ipv4/tcp_ipv4.c
As i see in code it is rounding RTO to minimum value.
It fixes my problem seems.
Btw just a bit about my environment - wireless networks (sometimes lossy!)
with low speed (128-512Kbps) customers working over pppoe. Maybe it will give
a tip why rtt value is too low.
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: Crazy TCP bug (keepalive flood?) in 2.6.32?
2010-01-19 11:09 ` Denys Fedoryshchenko
@ 2010-01-19 11:17 ` Ilpo Järvinen
2010-01-23 21:37 ` Denys Fedoryshchenko
0 siblings, 1 reply; 24+ messages in thread
From: Ilpo Järvinen @ 2010-01-19 11:17 UTC (permalink / raw)
To: Denys Fedoryshchenko; +Cc: Damian Lukowski, Netdev
On Tue, 19 Jan 2010, Denys Fedoryshchenko wrote:
> On Tuesday 19 January 2010 11:10:12 you wrote:
> > Hi,
> > thank you for testing. So srtt and rttvar is zero in any of those cases.
> > Ilpo, it is a bug in tcp_rtt_estimator then, I suppose?
> >
> > There is also a code comment in tcp_input.c, saying:
> > > * NOTE: clamping at TCP_RTO_MIN is not required, current algo
> > > * guarantees that rto is higher.
> >
> > So we either fix tcp_rtt_estimator or simply clamp at TCP_RTO_MIN?
> >
> > Damian
> >
> > > On Monday 11 January 2010 15:02:34 you wrote:
> > >> On Sat, 26 Dec 2009, Denys Fedoryshchenko wrote:
> > >>> Few more dumps. I notice:
> > >>> 1)Ack always equal 1
> > >>> 2)It is usually first segment of data sent (?)
> > >>>
> > >>> Maybe some value not initialised properly?
> > >>
> > >> Can you see if the RTO lower bound is violated (I added some printing of
> > >> vars there too already now if it turns out to be something):
> > >>
> > >> diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
> > >> index 65b8ebf..d84469f 100644
> > >> --- a/net/ipv4/tcp_ipv4.c
> > >> +++ b/net/ipv4/tcp_ipv4.c
> As i see in code it is rounding RTO to minimum value.
> It fixes my problem seems.
>
> Btw just a bit about my environment - wireless networks (sometimes lossy!)
> with low speed (128-512Kbps) customers working over pppoe. Maybe it will give
> a tip why rtt value is too low.
What I find most strange in it is the fact that when it triggers for the
first time, the srtt and mdev are zero, not some value in between 0 and
200ms. Therefore I suspect that this case might be something that we've
overlooked where srtt/mdev are not valid at all.
Maybe the patch below helps...
--
i.
--
diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
index 65b8ebf..c8166d7 100644
--- a/net/ipv4/tcp_ipv4.c
+++ b/net/ipv4/tcp_ipv4.c
@@ -401,6 +417,9 @@ void tcp_v4_err(struct sk_buff *icmp_skb, u32 info)
* (see draft-zimmermann-tcp-lcd) */
if (code != ICMP_NET_UNREACH && code != ICMP_HOST_UNREACH)
break;
+ /* A bit too strict, just want to be on the safe side for now */
+ if (sk->sk_state != TCP_ESTABLISHED)
+ break;
if (seq != tp->snd_una || !icsk->icsk_retransmits ||
!icsk->icsk_backoff)
break;
^ permalink raw reply related [flat|nested] 24+ messages in thread
* Re: Crazy TCP bug (keepalive flood?) in 2.6.32?
2010-01-19 11:17 ` Ilpo Järvinen
@ 2010-01-23 21:37 ` Denys Fedoryshchenko
2010-01-23 22:34 ` [PATCH] tcp: fix ICMP-RTO war Ilpo Järvinen
0 siblings, 1 reply; 24+ messages in thread
From: Denys Fedoryshchenko @ 2010-01-23 21:37 UTC (permalink / raw)
To: Ilpo Järvinen, netdev
On Tuesday 19 January 2010 13:17:51 you wrote:
> On Tue, 19 Jan 2010, Denys Fedoryshchenko wrote:
> > On Tuesday 19 January 2010 11:10:12 you wrote:
> > > Hi,
> > > thank you for testing. So srtt and rttvar is zero in any of those
> > > cases. Ilpo, it is a bug in tcp_rtt_estimator then, I suppose?
> > >
> > > There is also a code comment in tcp_input.c, saying:
> > > > * NOTE: clamping at TCP_RTO_MIN is not required, current algo
> > > > * guarantees that rto is higher.
> > >
> > > So we either fix tcp_rtt_estimator or simply clamp at TCP_RTO_MIN?
> > >
> > > Damian
> > >
> > > > On Monday 11 January 2010 15:02:34 you wrote:
> > > >> On Sat, 26 Dec 2009, Denys Fedoryshchenko wrote:
> > > >>> Few more dumps. I notice:
> > > >>> 1)Ack always equal 1
> > > >>> 2)It is usually first segment of data sent (?)
> > > >>>
> > > >>> Maybe some value not initialised properly?
> > > >>
> > > >> Can you see if the RTO lower bound is violated (I added some
> > > >> printing of vars there too already now if it turns out to be
> > > >> something):
> > > >>
> > > >> diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
> > > >> index 65b8ebf..d84469f 100644
> > > >> --- a/net/ipv4/tcp_ipv4.c
> > > >> +++ b/net/ipv4/tcp_ipv4.c
> >
> > As i see in code it is rounding RTO to minimum value.
> > It fixes my problem seems.
> >
> > Btw just a bit about my environment - wireless networks (sometimes
> > lossy!) with low speed (128-512Kbps) customers working over pppoe. Maybe
> > it will give a tip why rtt value is too low.
>
> What I find most strange in it is the fact that when it triggers for the
> first time, the srtt and mdev are zero, not some value in between 0 and
> 200ms. Therefore I suspect that this case might be something that we've
> overlooked where srtt/mdev are not valid at all.
>
> Maybe the patch below helps...
>
Seems after this patch (and debug patch with warnings) my dmesg is clean.
^ permalink raw reply [flat|nested] 24+ messages in thread
* [PATCH] tcp: fix ICMP-RTO war
2010-01-23 21:37 ` Denys Fedoryshchenko
@ 2010-01-23 22:34 ` Ilpo Järvinen
2010-01-23 22:45 ` Denys Fedoryshchenko
` (2 more replies)
0 siblings, 3 replies; 24+ messages in thread
From: Ilpo Järvinen @ 2010-01-23 22:34 UTC (permalink / raw)
To: Denys Fedoryshchenko; +Cc: Damian Lukowski, Netdev, David Miller
[-- Attachment #1: Type: TEXT/PLAIN, Size: 3482 bytes --]
Restored Damian cc, please keep them.
On Sat, 23 Jan 2010, Denys Fedoryshchenko wrote:
> On Tuesday 19 January 2010 13:17:51 you wrote:
> > On Tue, 19 Jan 2010, Denys Fedoryshchenko wrote:
> > > On Tuesday 19 January 2010 11:10:12 you wrote:
> > > > Hi,
> > > > thank you for testing. So srtt and rttvar is zero in any of those
> > > > cases. Ilpo, it is a bug in tcp_rtt_estimator then, I suppose?
> > > >
> > > > There is also a code comment in tcp_input.c, saying:
> > > > > * NOTE: clamping at TCP_RTO_MIN is not required, current algo
> > > > > * guarantees that rto is higher.
> > > >
> > > > So we either fix tcp_rtt_estimator or simply clamp at TCP_RTO_MIN?
> > > >
> > > > Damian
> > > >
> > > > > On Monday 11 January 2010 15:02:34 you wrote:
> > > > >> On Sat, 26 Dec 2009, Denys Fedoryshchenko wrote:
> > > > >>> Few more dumps. I notice:
> > > > >>> 1)Ack always equal 1
> > > > >>> 2)It is usually first segment of data sent (?)
> > > > >>>
> > > > >>> Maybe some value not initialised properly?
> > > > >>
> > > > >> Can you see if the RTO lower bound is violated (I added some
> > > > >> printing of vars there too already now if it turns out to be
> > > > >> something):
> > > > >>
> > > > >> diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
> > > > >> index 65b8ebf..d84469f 100644
> > > > >> --- a/net/ipv4/tcp_ipv4.c
> > > > >> +++ b/net/ipv4/tcp_ipv4.c
> > >
> > > As i see in code it is rounding RTO to minimum value.
> > > It fixes my problem seems.
> > >
> > > Btw just a bit about my environment - wireless networks (sometimes
> > > lossy!) with low speed (128-512Kbps) customers working over pppoe. Maybe
> > > it will give a tip why rtt value is too low.
> >
> > What I find most strange in it is the fact that when it triggers for the
> > first time, the srtt and mdev are zero, not some value in between 0 and
> > 200ms. Therefore I suspect that this case might be something that we've
> > overlooked where srtt/mdev are not valid at all.
> >
> > Maybe the patch below helps...
> >
> Seems after this patch (and debug patch with warnings) my dmesg is clean.
Cool, thanks for testing.
Dave, please send into stable too (besides net-2.6). If we want less strict
state check we can continue playing with that in net-next, IMHO.
--
i.
--
[PATCH] tcp: fix ICMP-RTO war
When destination is not reachable, ICMP of that is processed
here. In some TCP state srtt and mdev are not valid, yielding
to zero rto. Since the code below then immediately forces
timeout, a segment is sent which again triggers another ICMP
causing ICMP-RTO war to happen.
Broken since f1ecd5d9e736660 (Revert Backoff [v3]: Revert RTO
on ICMP destination unreachable).
Signed-off-by: Ilpo Järvinen <ilpo.jarvinen@helsinki.fi>
Reported-by: Denys Fedoryshchenko <denys@visp.net.lb>
Tested-by: Denys Fedoryshchenko <denys@visp.net.lb>
---
net/ipv4/tcp_ipv4.c | 3 +++
1 files changed, 3 insertions(+), 0 deletions(-)
diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
index 65b8ebf..ebcfcf6 100644
--- a/net/ipv4/tcp_ipv4.c
+++ b/net/ipv4/tcp_ipv4.c
@@ -401,6 +401,9 @@ void tcp_v4_err(struct sk_buff *icmp_skb, u32 info)
* (see draft-zimmermann-tcp-lcd) */
if (code != ICMP_NET_UNREACH && code != ICMP_HOST_UNREACH)
break;
+ /* A bit too strict, just want to be on the safe side for now */
+ if (sk->sk_state != TCP_ESTABLISHED)
+ break;
if (seq != tp->snd_una || !icsk->icsk_retransmits ||
!icsk->icsk_backoff)
break;
--
1.5.6.5
^ permalink raw reply related [flat|nested] 24+ messages in thread
* Re: [PATCH] tcp: fix ICMP-RTO war
2010-01-23 22:34 ` [PATCH] tcp: fix ICMP-RTO war Ilpo Järvinen
@ 2010-01-23 22:45 ` Denys Fedoryshchenko
2010-01-25 15:07 ` Damian Lukowski
2010-01-23 23:28 ` Denys Fedoryshchenko
2010-01-25 12:12 ` Damian Lukowski
2 siblings, 1 reply; 24+ messages in thread
From: Denys Fedoryshchenko @ 2010-01-23 22:45 UTC (permalink / raw)
To: Ilpo Järvinen; +Cc: Damian Lukowski, Netdev, David Miller
>
> Cool, thanks for testing.
>
> Dave, please send into stable too (besides net-2.6). If we want less strict
> state check we can continue playing with that in net-next, IMHO.
>
Maybe better to wait. Sad news, got messages after while (before they was
appearing almost immediately on such load).
Here it is
[ 1253.821745] rto: 26496 (58 >> 3 + 200, 7) time: 953821 sent: 953283 pen: 1
1006275 rem: 25958
[ 1278.791976] rto: 75264 (398 >> 3 + 245, 8) time: 978791 sent: 977749 pen: 1
1097749 rem: 74222
[ 1299.537823] lower bound violation: 0
[ 1299.537846] rto: 200 (0 >> 3 + 0, 1) time: 999537 sent: 997699 pen: 1
1009699 rem: 0
[ 1324.022158] rto: 11072 (2512 >> 3 + 1070, 3) time: 1024022 sent: 1023672
pen: 1 1045816 rem: 10722
[ 1333.112517] rto: 52992 (58 >> 3 + 200, 8) time: 1033112 sent: 1032771 pen:
1 1138755 rem: 52651
[ 1336.152839] rto: 11072 (2512 >> 3 + 1070, 3) time: 1036152 sent: 1034744
pen: 1 1056888 rem: 9664
[ 1426.219799] lower bound violation: 0
[ 1426.219858] rto: 200 (0 >> 3 + 0, 1) time: 1126219 sent: 1125040 pen: 1
1137040 rem: 0
[ 1429.235911] lower bound violation: 0
[ 1429.235964] rto: 200 (0 >> 3 + 0, 4) time: 1129235 sent: 1129019 pen: 1
1132219 rem: 0
[ 1432.279829] lower bound violation: 0
[ 1432.279887] rto: 200 (0 >> 3 + 0, 7) time: 1132279 sent: 1132036 pen: 1
1135236 rem: 0
[ 1435.311008] lower bound violation: 0
[ 1435.311068] rto: 200 (0 >> 3 + 0, 10) time: 1135311 sent: 1135079 pen: 1
1138279 rem: 0
[ 1479.029269] lower bound violation: 0
[ 1479.029323] rto: 200 (0 >> 3 + 0, 9) time: 1179029 sent: 1174129 pen: 1
1294129 rem: 0
[ 1483.851712] lower bound violation: 0
[ 1483.851773] rto: 200 (0 >> 3 + 0, 12) time: 1183851 sent: 1181829 pen: 1
1185029 rem: 0
[ 1483.851878] lower bound violation: 0
[ 1483.851926] rto: 200 (0 >> 3 + 0, 12) time: 1183851 sent: 1183851 pen: 1
1184251 rem: 200
[ 1483.852034] lower bound violation: 0
[ 1483.852082] rto: 200 (0 >> 3 + 0, 11) time: 1183852 sent: 1183851 pen: 1
1184052 rem: 199
[ 1486.934283] lower bound violation: 0
[ 1486.934339] rto: 200 (0 >> 3 + 0, 14) time: 1186934 sent: 1186851 pen: 1
1190051 rem: 117
[ 1486.934500] lower bound violation: 0
[ 1486.934554] rto: 200 (0 >> 3 + 0, 13) time: 1186934 sent: 1186851 pen: 1
1187051 rem: 117
[ 1490.170941] lower bound violation: 0
[ 1490.171000] rto: 200 (0 >> 3 + 0, 16) time: 1190170 sent: 1189851 pen: 1
1193051 rem: 0
[ 1490.171126] lower bound violation: 0
[ 1490.171189] rto: 200 (0 >> 3 + 0, 16) time: 1190171 sent: 1190171 pen: 1
1190571 rem: 200
[ 1490.171312] lower bound violation: 0
[ 1490.171361] rto: 200 (0 >> 3 + 0, 15) time: 1190171 sent: 1190171 pen: 1
1190371 rem: 200
[ 1494.052047] lower bound violation: 0
[ 1494.052105] rto: 200 (0 >> 3 + 0, 18) time: 1194052 sent: 1193171 pen: 1
1196371 rem: 0
[ 1494.052704] lower bound violation: 0
[ 1494.052760] rto: 200 (0 >> 3 + 0, 18) time: 1194052 sent: 1194052 pen: 1
1194452 rem: 200
[ 1497.678945] lower bound violation: 0
[ 1497.679004] rto: 200 (0 >> 3 + 0, 21) time: 1197678 sent: 1197052 pen: 1
1200252 rem: 0
[ 1497.679205] lower bound violation: 0
[ 1497.679255] rto: 200 (0 >> 3 + 0, 21) time: 1197679 sent: 1197679 pen: 1
1198079 rem: 200
[ 1497.679356] rto: 120000 (18111 >> 3 + 2633, 7) time: 1197679 sent: 1195423
pen: 1 1315423 rem: 117744
[ 1501.113733] lower bound violation: 0
[ 1501.113786] rto: 200 (0 >> 3 + 0, 24) time: 1201113 sent: 1200679 pen: 1
1203879 rem: 0
[ 1501.116064] rto: 120000 (17704 >> 3 + 4426, 8) time: 1201116 sent: 1198638
pen: 1 1318638 rem: 117522
[ 1501.116168] lower bound violation: 0
[ 1501.116216] rto: 200 (0 >> 3 + 0, 24) time: 1201116 sent: 1201113 pen: 1
1201513 rem: 197
[ 1504.165893] lower bound violation: 0
[ 1504.165953] rto: 200 (0 >> 3 + 0, 27) time: 1204165 sent: 1204113 pen: 1
1207313 rem: 148
[ 1504.168090] lower bound violation: 0
[ 1504.168151] rto: 200 (0 >> 3 + 0, 26) time: 1204168 sent: 1204113 pen: 1
1204313 rem: 145
[ 1504.168272] lower bound violation: 0
[ 1504.168327] rto: 200 (0 >> 3 + 0, 25) time: 1204168 sent: 1204113 pen: 1
1204313 rem: 145
[ 1507.280037] lower bound violation: 0
[ 1507.280096] rto: 200 (0 >> 3 + 0, 28) time: 1207280 sent: 1207113 pen: 1
1210313 rem: 33
[ 1507.280207] lower bound violation: 0
[ 1507.280255] rto: 200 (0 >> 3 + 0, 27) time: 1207280 sent: 1207113 pen: 1
1207313 rem: 33
[ 1510.974508] lower bound violation: 0
[ 1510.974574] rto: 200 (0 >> 3 + 0, 30) time: 1210974 sent: 1210113 pen: 1
1213313 rem: 0
[ 1510.974716] lower bound violation: 0
[ 1510.974766] rto: 200 (0 >> 3 + 0, 30) time: 1210974 sent: 1210974 pen: 1
1211374 rem: 200
[ 1514.436146] lower bound violation: 0
[ 1514.436214] rto: 200 (0 >> 3 + 0, 33) time: 1214436 sent: 1213974 pen: 1
1217174 rem: 0
[ 1514.436329] lower bound violation: 0
[ 1514.436378] rto: 200 (0 >> 3 + 0, 33) time: 1214436 sent: 1214436 pen: 1
1214836 rem: 200
[ 1514.436477] lower bound violation: 0
[ 1514.436525] rto: 200 (0 >> 3 + 0, 32) time: 1214436 sent: 1214436 pen: 1
1214636 rem: 200
[ 1517.516478] lower bound violation: 0
[ 1517.516537] rto: 200 (0 >> 3 + 0, 35) time: 1217516 sent: 1217436 pen: 1
1220636 rem: 120
[ 1517.520665] lower bound violation: 0
[ 1517.520724] rto: 200 (0 >> 3 + 0, 34) time: 1217520 sent: 1217436 pen: 1
1217636 rem: 116
[ 1517.520865] lower bound violation: 0
[ 1517.520919] rto: 200 (0 >> 3 + 0, 33) time: 1217520 sent: 1217436 pen: 1
1217636 rem: 116
[ 1520.579941] lower bound violation: 0
[ 1520.580000] rto: 200 (0 >> 3 + 0, 36) time: 1220579 sent: 1220436 pen: 1
1223636 rem: 57
[ 1520.580111] lower bound violation: 0
[ 1520.580165] rto: 200 (0 >> 3 + 0, 35) time: 1220580 sent: 1220436 pen: 1
1220637 rem: 56
[ 1520.580686] lower bound violation: 0
[ 1520.580744] rto: 200 (0 >> 3 + 0, 34) time: 1220580 sent: 1220436 pen: 1
1220636 rem: 56
[ 1523.693352] lower bound violation: 0
[ 1523.693412] rto: 200 (0 >> 3 + 0, 37) time: 1223693 sent: 1223436 pen: 1
1226636 rem: 0
[ 1523.693538] lower bound violation: 0
[ 1523.693588] rto: 200 (0 >> 3 + 0, 37) time: 1223693 sent: 1223693 pen: 1
1224093 rem: 200
[ 1523.693686] lower bound violation: 0
[ 1523.693735] rto: 200 (0 >> 3 + 0, 36) time: 1223693 sent: 1223693 pen: 1
1223893 rem: 200
[ 1526.737059] lower bound violation: 0
[ 1526.737125] rto: 200 (0 >> 3 + 0, 39) time: 1226737 sent: 1226693 pen: 1
1229893 rem: 156
[ 1526.737271] lower bound violation: 0
[ 1526.737323] rto: 200 (0 >> 3 + 0, 38) time: 1226737 sent: 1226693 pen: 1
1226893 rem: 156
[ 1526.737557] lower bound violation: 0
[ 1526.737607] rto: 200 (0 >> 3 + 0, 37) time: 1226737 sent: 1226693 pen: 1
1226893 rem: 156
[ 1529.979070] lower bound violation: 0
[ 1529.979130] rto: 200 (0 >> 3 + 0, 40) time: 1229979 sent: 1229693 pen: 1
1232893 rem: 0
[ 1529.979249] lower bound violation: 0
[ 1529.979304] rto: 200 (0 >> 3 + 0, 40) time: 1229979 sent: 1229979 pen: 1
1230379 rem: 200
[ 1529.979412] lower bound violation: 0
[ 1529.979461] rto: 200 (0 >> 3 + 0, 39) time: 1229979 sent: 1229979 pen: 1
1230179 rem: 200
[ 1533.211875] lower bound violation: 0
[ 1533.211934] rto: 200 (0 >> 3 + 0, 42) time: 1233211 sent: 1232979 pen: 1
1236179 rem: 0
[ 1533.212049] lower bound violation: 0
[ 1533.212098] rto: 200 (0 >> 3 + 0, 42) time: 1233211 sent: 1233211 pen: 1
1233611 rem: 200
[ 1533.212203] lower bound violation: 0
[ 1533.212259] rto: 200 (0 >> 3 + 0, 41) time: 1233212 sent: 1233211 pen: 1
1233412 rem: 199
[ 1536.287558] lower bound violation: 0
[ 1536.287611] rto: 200 (0 >> 3 + 0, 44) time: 1236287 sent: 1236211 pen: 1
1239411 rem: 124
[ 1536.287712] lower bound violation: 0
[ 1536.287760] rto: 200 (0 >> 3 + 0, 43) time: 1236287 sent: 1236211 pen: 1
1236411 rem: 124
[ 1536.291704] lower bound violation: 0
[ 1536.291767] rto: 200 (0 >> 3 + 0, 42) time: 1236291 sent: 1236211 pen: 1
1236411 rem: 120
[ 1539.530596] lower bound violation: 0
[ 1539.530657] rto: 200 (0 >> 3 + 0, 45) time: 1239530 sent: 1239211 pen: 1
1242411 rem: 0
[ 1539.530804] lower bound violation: 0
[ 1539.530862] rto: 200 (0 >> 3 + 0, 45) time: 1239530 sent: 1239530 pen: 1
1239930 rem: 200
[ 1544.020855] lower bound violation: 0
[ 1544.020916] rto: 200 (0 >> 3 + 0, 48) time: 1244020 sent: 1242530 pen: 1
1245730 rem: 0
[ 1544.021022] lower bound violation: 0
[ 1544.021071] rto: 200 (0 >> 3 + 0, 48) time: 1244021 sent: 1244020 pen: 1
1244421 rem: 199
[ 1544.021186] lower bound violation: 0
[ 1544.021243] rto: 200 (0 >> 3 + 0, 47) time: 1244021 sent: 1244020 pen: 1
1244220 rem: 199
[ 1547.214143] lower bound violation: 0
[ 1547.214212] rto: 200 (0 >> 3 + 0, 50) time: 1247214 sent: 1247020 pen: 1
1250220 rem: 6
[ 1547.214330] lower bound violation: 0
[ 1547.214388] rto: 200 (0 >> 3 + 0, 49) time: 1247214 sent: 1247020 pen: 1
1247220 rem: 6
[ 1547.215213] lower bound violation: 0
[ 1547.215269] rto: 200 (0 >> 3 + 0, 48) time: 1247215 sent: 1247020 pen: 1
1247221 rem: 5
[ 1551.820989] lower bound violation: 0
[ 1551.821059] rto: 200 (0 >> 3 + 0, 51) time: 1251821 sent: 1250020 pen: 1
1253220 rem: 0
[ 1551.821211] lower bound violation: 0
[ 1551.821265] rto: 200 (0 >> 3 + 0, 51) time: 1251821 sent: 1251821 pen: 1
1252221 rem: 200
[ 1551.824378] lower bound violation: 0
[ 1551.824437] rto: 200 (0 >> 3 + 0, 50) time: 1251824 sent: 1251821 pen: 1
1252021 rem: 197
[ 1556.833941] lower bound violation: 0
[ 1556.834001] rto: 200 (0 >> 3 + 0, 53) time: 1256833 sent: 1254821 pen: 1
1258021 rem: 0
[ 1556.834120] lower bound violation: 0
[ 1556.834168] rto: 200 (0 >> 3 + 0, 53) time: 1256834 sent: 1256834 pen: 1
1257234 rem: 200
[ 1556.834280] lower bound violation: 0
[ 1556.834335] rto: 200 (0 >> 3 + 0, 52) time: 1256834 sent: 1256834 pen: 1
1257034 rem: 200
[ 1559.862274] lower bound violation: 0
[ 1559.862332] rto: 200 (0 >> 3 + 0, 55) time: 1259862 sent: 1259834 pen: 1
1263034 rem: 172
[ 1559.862439] lower bound violation: 0
[ 1559.862488] rto: 200 (0 >> 3 + 0, 54) time: 1259862 sent: 1259834 pen: 1
1260034 rem: 172
[ 1559.862599] lower bound violation: 0
[ 1559.862653] rto: 200 (0 >> 3 + 0, 53) time: 1259862 sent: 1259834 pen: 1
1260034 rem: 172
[ 1563.299323] lower bound violation: 0
[ 1563.299392] rto: 200 (0 >> 3 + 0, 56) time: 1263299 sent: 1262834 pen: 1
1266034 rem: 0
[ 1563.299544] lower bound violation: 0
[ 1563.299593] rto: 200 (0 >> 3 + 0, 56) time: 1263299 sent: 1263299 pen: 1
1263699 rem: 200
[ 1563.299692] lower bound violation: 0
[ 1563.299740] rto: 200 (0 >> 3 + 0, 55) time: 1263299 sent: 1263299 pen: 1
1263499 rem: 200
[ 1566.413518] lower bound violation: 0
[ 1566.413571] rto: 200 (0 >> 3 + 0, 58) time: 1266413 sent: 1266299 pen: 1
1269499 rem: 86
[ 1566.413689] lower bound violation: 0
[ 1566.413745] rto: 200 (0 >> 3 + 0, 57) time: 1266413 sent: 1266299 pen: 1
1266499 rem: 86
[ 1566.413844] lower bound violation: 0
[ 1566.413892] rto: 200 (0 >> 3 + 0, 56) time: 1266413 sent: 1266299 pen: 1
1266499 rem: 86
[ 1569.443770] lower bound violation: 0
[ 1569.443829] rto: 200 (0 >> 3 + 0, 59) time: 1269443 sent: 1269299 pen: 1
1272499 rem: 56
[ 1569.444010] lower bound violation: 0
[ 1569.444064] rto: 200 (0 >> 3 + 0, 58) time: 1269444 sent: 1269299 pen: 1
1269499 rem: 55
[ 1569.451656] lower bound violation: 0
[ 1569.451714] rto: 200 (0 >> 3 + 0, 57) time: 1269451 sent: 1269299 pen: 1
1269499 rem: 48
[ 1573.751979] lower bound violation: 0
[ 1573.752048] rto: 200 (0 >> 3 + 0, 60) time: 1273752 sent: 1272299 pen: 1
1275499 rem: 0
[ 1573.752172] lower bound violation: 0
[ 1573.752229] rto: 200 (0 >> 3 + 0, 60) time: 1273752 sent: 1273752 pen: 1
1274152 rem: 200
[ 1573.752343] lower bound violation: 0
[ 1573.752392] rto: 200 (0 >> 3 + 0, 59) time: 1273752 sent: 1273752 pen: 1
1273952 rem: 200
[ 1579.041006] lower bound violation: 0
[ 1579.041068] rto: 200 (0 >> 3 + 0, 62) time: 1279041 sent: 1276752 pen: 1
1279952 rem: 0
[ 1579.041177] lower bound violation: 0
[ 1579.041226] rto: 200 (0 >> 3 + 0, 62) time: 1279041 sent: 1279041 pen: 1
1279441 rem: 200
[ 1579.041325] lower bound violation: 0
[ 1579.041373] rto: 200 (0 >> 3 + 0, 61) time: 1279041 sent: 1279041 pen: 1
1279241 rem: 200
[ 1584.072083] lower bound violation: 0
[ 1584.072149] rto: 200 (0 >> 3 + 0, 64) time: 1284072 sent: 1282041 pen: 1
1285241 rem: 0
[ 1587.094402] lower bound violation: 0
[ 1587.094461] rto: 200 (0 >> 3 + 0, 67) time: 1287094 sent: 1286872 pen: 1
1290072 rem: 0
[ 1587.095380] lower bound violation: 0
[ 1587.095442] rto: 200 (0 >> 3 + 0, 67) time: 1287095 sent: 1287094 pen: 1
1287494 rem: 199
[ 1590.118759] lower bound violation: 0
[ 1590.118818] rto: 200 (0 >> 3 + 0, 70) time: 1290118 sent: 1290094 pen: 1
1293294 rem: 176
[ 1590.118931] lower bound violation: 0
[ 1590.118979] rto: 200 (0 >> 3 + 0, 69) time: 1290118 sent: 1290094 pen: 1
1290294 rem: 176
[ 1590.119085] lower bound violation: 0
[ 1590.119142] rto: 200 (0 >> 3 + 0, 68) time: 1290119 sent: 1290094 pen: 1
1290295 rem: 175
[ 1593.342497] lower bound violation: 0
[ 1593.342556] rto: 200 (0 >> 3 + 0, 71) time: 1293342 sent: 1293094 pen: 1
1296294 rem: 0
[ 1593.342675] lower bound violation: 0
[ 1593.342723] rto: 200 (0 >> 3 + 0, 71) time: 1293342 sent: 1293342 pen: 1
1293742 rem: 200
[ 1593.342822] lower bound violation: 0
[ 1593.342870] rto: 200 (0 >> 3 + 0, 70) time: 1293342 sent: 1293342 pen: 1
1293542 rem: 200
[ 1597.517273] lower bound violation: 0
[ 1597.517326] rto: 200 (0 >> 3 + 0, 73) time: 1297517 sent: 1296342 pen: 1
1299542 rem: 0
[ 1597.517433] lower bound violation: 0
[ 1597.517481] rto: 200 (0 >> 3 + 0, 73) time: 1297517 sent: 1297517 pen: 1
1297917 rem: 200
[ 1597.517579] lower bound violation: 0
[ 1597.517627] rto: 200 (0 >> 3 + 0, 72) time: 1297517 sent: 1297517 pen: 1
1297717 rem: 200
[ 1600.931564] lower bound violation: 0
[ 1600.931625] rto: 200 (0 >> 3 + 0, 75) time: 1300931 sent: 1300517 pen: 1
1303717 rem: 0
[ 1600.931743] lower bound violation: 0
[ 1600.931792] rto: 200 (0 >> 3 + 0, 75) time: 1300931 sent: 1300931 pen: 1
1301331 rem: 200
[ 1600.931903] lower bound violation: 0
[ 1600.931954] rto: 200 (0 >> 3 + 0, 74) time: 1300931 sent: 1300931 pen: 1
1301131 rem: 200
[ 1603.939116] lower bound violation: 0
[ 1603.939176] rto: 200 (0 >> 3 + 0, 77) time: 1303939 sent: 1303932 pen: 1
1307132 rem: 193
[ 1603.939289] lower bound violation: 0
[ 1603.939337] rto: 200 (0 >> 3 + 0, 76) time: 1303939 sent: 1303932 pen: 1
1304132 rem: 193
[ 1603.939436] lower bound violation: 0
[ 1603.939484] rto: 200 (0 >> 3 + 0, 75) time: 1303939 sent: 1303932 pen: 1
1304132 rem: 193
[ 1607.414745] lower bound violation: 0
[ 1607.414808] rto: 200 (0 >> 3 + 0, 78) time: 1307414 sent: 1306932 pen: 1
1310132 rem: 0
[ 1607.414956] lower bound violation: 0
[ 1607.415015] rto: 200 (0 >> 3 + 0, 78) time: 1307414 sent: 1307414 pen: 1
1307814 rem: 200
[ 1610.428738] lower bound violation: 0
[ 1610.428797] rto: 200 (0 >> 3 + 0, 81) time: 1310428 sent: 1310414 pen: 1
1313614 rem: 186
[ 1610.428909] lower bound violation: 0
[ 1610.428957] rto: 200 (0 >> 3 + 0, 80) time: 1310428 sent: 1310414 pen: 1
1310614 rem: 186
[ 1610.429061] lower bound violation: 0
[ 1610.429118] rto: 200 (0 >> 3 + 0, 79) time: 1310428 sent: 1310414 pen: 1
1310614 rem: 186
[ 1613.744633] lower bound violation: 0
[ 1613.744696] rto: 200 (0 >> 3 + 0, 82) time: 1313744 sent: 1313415 pen: 1
1316615 rem: 0
[ 1613.745417] lower bound violation: 0
[ 1613.745480] rto: 200 (0 >> 3 + 0, 82) time: 1313745 sent: 1313744 pen: 1
1314144 rem: 199
[ 1617.868468] lower bound violation: 0
[ 1617.868531] rto: 200 (0 >> 3 + 0, 85) time: 1317868 sent: 1316744 pen: 1
1319944 rem: 0
[ 1617.868657] lower bound violation: 0
[ 1617.868716] rto: 200 (0 >> 3 + 0, 85) time: 1317868 sent: 1317868 pen: 1
1318268 rem: 200
[ 1617.868831] rto: 120000 (18111 >> 3 + 2633, 7) time: 1317868 sent: 1315423
pen: 1 1435423 rem: 117555
[ 1621.001005] lower bound violation: 0
[ 1621.001064] rto: 200 (0 >> 3 + 0, 88) time: 1321000 sent: 1320868 pen: 1
1324068 rem: 68
[ 1621.001176] lower bound violation: 0
[ 1621.001225] rto: 200 (0 >> 3 + 0, 87) time: 1321000 sent: 1320868 pen: 1
1321068 rem: 68
[ 1621.002106] rto: 120000 (17704 >> 3 + 4426, 8) time: 1321002 sent: 1318638
pen: 1 1438638 rem: 117636
[ 1624.776425] lower bound violation: 0
[ 1624.776484] rto: 200 (0 >> 3 + 0, 90) time: 1324776 sent: 1323868 pen: 1
1327068 rem: 0
[ 1624.776602] lower bound violation: 0
[ 1624.776651] rto: 200 (0 >> 3 + 0, 90) time: 1324776 sent: 1324776 pen: 1
1325176 rem: 200
[ 1624.776766] lower bound violation: 0
[ 1624.776815] rto: 200 (0 >> 3 + 0, 89) time: 1324776 sent: 1324776 pen: 1
1324976 rem: 200
[ 1628.635107] lower bound violation: 0
[ 1628.635166] rto: 200 (0 >> 3 + 0, 92) time: 1328635 sent: 1327776 pen: 1
1330976 rem: 0
[ 1628.635292] lower bound violation: 0
[ 1628.635340] rto: 200 (0 >> 3 + 0, 92) time: 1328635 sent: 1328635 pen: 1
1329035 rem: 200
[ 1628.636141] lower bound violation: 0
[ 1628.636189] rto: 200 (0 >> 3 + 0, 91) time: 1328636 sent: 1328635 pen: 1
1328836 rem: 199
[ 1632.229674] lower bound violation: 0
[ 1632.229736] rto: 200 (0 >> 3 + 0, 94) time: 1332229 sent: 1331635 pen: 1
1334835 rem: 0
[ 1632.231588] lower bound violation: 0
[ 1632.231645] rto: 200 (0 >> 3 + 0, 94) time: 1332231 sent: 1332229 pen: 1
1332629 rem: 198
[ 1636.335644] lower bound violation: 0
[ 1636.335704] rto: 200 (0 >> 3 + 0, 97) time: 1336335 sent: 1335229 pen: 1
1338429 rem: 0
[ 1636.335821] lower bound violation: 0
[ 1636.335870] rto: 200 (0 >> 3 + 0, 97) time: 1336335 sent: 1336335 pen: 1
1336735 rem: 200
[ 1636.335968] lower bound violation: 0
[ 1636.336015] rto: 200 (0 >> 3 + 0, 96) time: 1336335 sent: 1336335 pen: 1
1336535 rem: 200
[ 1639.557760] lower bound violation: 0
[ 1639.557819] rto: 200 (0 >> 3 + 0, 99) time: 1339557 sent: 1339336 pen: 1
1342536 rem: 0
[ 1639.557937] lower bound violation: 0
[ 1639.557985] rto: 200 (0 >> 3 + 0, 99) time: 1339557 sent: 1339557 pen: 1
1339957 rem: 200
[ 1639.558575] lower bound violation: 0
[ 1639.558631] rto: 200 (0 >> 3 + 0, 98) time: 1339558 sent: 1339557 pen: 1
1339758 rem: 199
[ 1642.786990] lower bound violation: 0
[ 1642.787060] rto: 200 (0 >> 3 + 0, 101) time: 1342787 sent: 1342557 pen: 1
1345757 rem: 0
[ 1642.787238] lower bound violation: 0
[ 1642.787296] rto: 200 (0 >> 3 + 0, 101) time: 1342787 sent: 1342787 pen: 1
1343187 rem: 200
[ 1642.787395] lower bound violation: 0
[ 1642.787444] rto: 200 (0 >> 3 + 0, 100) time: 1342787 sent: 1342787 pen: 1
1342987 rem: 200
[ 1647.154582] lower bound violation: 0
[ 1647.154634] rto: 200 (0 >> 3 + 0, 103) time: 1347154 sent: 1345787 pen: 1
1348987 rem: 0
[ 1647.154744] lower bound violation: 0
[ 1647.154792] rto: 200 (0 >> 3 + 0, 103) time: 1347154 sent: 1347154 pen: 1
1347554 rem: 200
[ 1647.154904] lower bound violation: 0
[ 1647.154952] rto: 200 (0 >> 3 + 0, 102) time: 1347154 sent: 1347154 pen: 1
1347354 rem: 200
[ 1650.574345] lower bound violation: 0
[ 1650.574406] rto: 200 (0 >> 3 + 0, 105) time: 1350574 sent: 1350155 pen: 1
1353355 rem: 0
[ 1650.574532] lower bound violation: 0
[ 1650.574591] rto: 200 (0 >> 3 + 0, 105) time: 1350574 sent: 1350574 pen: 1
1350974 rem: 200
[ 1650.574691] lower bound violation: 0
[ 1650.574739] rto: 200 (0 >> 3 + 0, 104) time: 1350574 sent: 1350574 pen: 1
1350774 rem: 200
[ 1653.629874] lower bound violation: 0
[ 1653.629937] rto: 200 (0 >> 3 + 0, 107) time: 1353629 sent: 1353574 pen: 1
1356774 rem: 145
[ 1653.630037] lower bound violation: 0
[ 1653.630086] rto: 200 (0 >> 3 + 0, 106) time: 1353629 sent: 1353574 pen: 1
1353774 rem: 145
[ 1653.630185] lower bound violation: 0
[ 1653.630233] rto: 200 (0 >> 3 + 0, 105) time: 1353629 sent: 1353574 pen: 1
1353774 rem: 145
[ 1656.859174] lower bound violation: 0
[ 1656.859236] rto: 200 (0 >> 3 + 0, 108) time: 1356859 sent: 1356574 pen: 1
1359774 rem: 0
[ 1656.860594] lower bound violation: 0
[ 1656.860650] rto: 200 (0 >> 3 + 0, 108) time: 1356860 sent: 1356859 pen: 1
1357259 rem: 199
[ 1656.860770] lower bound violation: 0
[ 1656.860818] rto: 200 (0 >> 3 + 0, 107) time: 1356860 sent: 1356859 pen: 1
1357059 rem: 199
[ 1661.395294] lower bound violation: 0
[ 1661.395347] rto: 200 (0 >> 3 + 0, 110) time: 1361395 sent: 1359859 pen: 1
1363059 rem: 0
[ 1661.395716] lower bound violation: 0
[ 1661.395772] rto: 200 (0 >> 3 + 0, 110) time: 1361395 sent: 1361395 pen: 1
1361795 rem: 200
[ 1700.995078] rto: 120000 (2636 >> 3 + 542, 8) time: 1400995 sent: 1397985
pen: 1 1517985 rem: 116990
[ 1730.706641] lower bound violation: 0
[ 1730.706700] rto: 200 (0 >> 3 + 0, 7) time: 1430706 sent: 1429991 pen: 1
1549991 rem: 0
[ 1733.727118] lower bound violation: 0
[ 1733.727186] rto: 200 (0 >> 3 + 0, 10) time: 1433727 sent: 1433506 pen: 1
1436706 rem: 0
[ 1736.737622] lower bound violation: 0
[ 1736.737674] rto: 200 (0 >> 3 + 0, 13) time: 1436737 sent: 1436527 pen: 1
1439727 rem: 0
[ 1739.769166] lower bound violation: 0
[ 1739.769219] rto: 200 (0 >> 3 + 0, 16) time: 1439769 sent: 1439537 pen: 1
1442737 rem: 0
[ 1739.818141] lower bound violation: 0
[ 1739.818197] rto: 200 (0 >> 3 + 0, 16) time: 1439818 sent: 1439769 pen: 1
1440169 rem: 151
[ 1742.779541] lower bound violation: 0
[ 1742.779610] rto: 200 (0 >> 3 + 0, 19) time: 1442779 sent: 1442769 pen: 1
1445969 rem: 190
[ 1742.828450] lower bound violation: 0
[ 1742.828509] rto: 200 (0 >> 3 + 0, 18) time: 1442828 sent: 1442769 pen: 1
1442969 rem: 141
[ 1745.838989] lower bound violation: 0
[ 1745.839059] rto: 200 (0 >> 3 + 0, 21) time: 1445839 sent: 1445769 pen: 1
1448969 rem: 130
[ 1748.849390] lower bound violation: 0
[ 1748.849450] rto: 200 (0 >> 3 + 0, 24) time: 1448849 sent: 1448769 pen: 1
1451969 rem: 120
[ 1751.851312] lower bound violation: 0
[ 1751.851371] rto: 200 (0 >> 3 + 0, 27) time: 1451851 sent: 1451769 pen: 1
1454969 rem: 118
[ 1755.020232] lower bound violation: 0
[ 1755.020294] rto: 200 (0 >> 3 + 0, 30) time: 1455020 sent: 1454769 pen: 1
1457969 rem: 0
[ 1758.032994] lower bound violation: 0
[ 1758.033065] rto: 200 (0 >> 3 + 0, 33) time: 1458032 sent: 1457820 pen: 1
1461020 rem: 0
[ 1761.044708] lower bound violation: 0
[ 1761.044766] rto: 200 (0 >> 3 + 0, 36) time: 1461044 sent: 1460833 pen: 1
1464033 rem: 0
[ 1764.057713] lower bound violation: 0
[ 1764.057773] rto: 200 (0 >> 3 + 0, 39) time: 1464057 sent: 1463844 pen: 1
1467044 rem: 0
[ 1767.081929] lower bound violation: 0
[ 1767.082002] rto: 200 (0 >> 3 + 0, 42) time: 1467081 sent: 1466857 pen: 1
1470057 rem: 0
[ 1770.093869] lower bound violation: 0
[ 1770.093928] rto: 200 (0 >> 3 + 0, 45) time: 1470093 sent: 1469882 pen: 1
1473082 rem: 0
[ 1773.152744] lower bound violation: 0
[ 1773.152796] rto: 200 (0 >> 3 + 0, 48) time: 1473152 sent: 1472893 pen: 1
1476093 rem: 0
[ 1818.986470] rto: 120000 (2636 >> 3 + 542, 8) time: 1518986 sent: 1517985
pen: 1 1637985 rem: 118999
[ 1939.433063] rto: 120000 (2636 >> 3 + 542, 8) time: 1639432 sent: 1637985
pen: 1 1757985 rem: 118553
[ 2127.032954] lower bound violation: 0
[ 2127.033019] rto: 200 (0 >> 3 + 0, 5) time: 1827033 sent: 1824734 pen: 1
1944734 rem: 0
[ 2130.198949] lower bound violation: 0
[ 2130.199008] rto: 200 (0 >> 3 + 0, 8) time: 1830198 sent: 1829833 pen: 1
1833033 rem: 0
[ 2130.199134] lower bound violation: 0
[ 2130.199191] rto: 200 (0 >> 3 + 0, 8) time: 1830199 sent: 1830199 pen: 1
1830599 rem: 200
[ 2130.199289] lower bound violation: 0
[ 2130.199336] rto: 200 (0 >> 3 + 0, 7) time: 1830199 sent: 1830199 pen: 1
1830399 rem: 200
[ 2133.313262] lower bound violation: 0
[ 2133.313321] rto: 200 (0 >> 3 + 0, 10) time: 1833313 sent: 1833199 pen: 1
1836399 rem: 86
[ 2133.313430] lower bound violation: 0
[ 2133.313483] rto: 200 (0 >> 3 + 0, 9) time: 1833313 sent: 1833199 pen: 1
1833399 rem: 86
[ 2136.355135] lower bound violation: 0
[ 2136.355194] rto: 200 (0 >> 3 + 0, 12) time: 1836355 sent: 1836199 pen: 1
1839399 rem: 44
[ 2136.355302] lower bound violation: 0
[ 2136.355355] rto: 200 (0 >> 3 + 0, 11) time: 1836355 sent: 1836199 pen: 1
1836399 rem: 44
[ 2136.355462] lower bound violation: 0
[ 2136.355510] rto: 200 (0 >> 3 + 0, 10) time: 1836355 sent: 1836199 pen: 1
1836399 rem: 44
[ 2139.336730] lower bound violation: 0
[ 2139.336790] rto: 200 (0 >> 3 + 0, 13) time: 1839336 sent: 1839199 pen: 1
1842399 rem: 63
[ 2139.336911] lower bound violation: 0
[ 2139.336960] rto: 200 (0 >> 3 + 0, 12) time: 1839336 sent: 1839199 pen: 1
1839399 rem: 63
[ 2142.603552] lower bound violation: 0
[ 2142.603612] rto: 200 (0 >> 3 + 0, 15) time: 1842603 sent: 1842200 pen: 1
1845400 rem: 0
[ 2142.603729] lower bound violation: 0
[ 2142.603777] rto: 200 (0 >> 3 + 0, 15) time: 1842603 sent: 1842603 pen: 1
1843003 rem: 200
[ 2145.821472] lower bound violation: 0
[ 2145.821533] rto: 200 (0 >> 3 + 0, 18) time: 1845821 sent: 1845603 pen: 1
1848803 rem: 0
[ 2145.821638] lower bound violation: 0
[ 2145.821687] rto: 200 (0 >> 3 + 0, 18) time: 1845821 sent: 1845821 pen: 1
1846221 rem: 200
[ 2149.113311] lower bound violation: 0
[ 2149.113371] rto: 200 (0 >> 3 + 0, 21) time: 1849113 sent: 1848822 pen: 1
1852022 rem: 0
[ 2149.124655] lower bound violation: 0
[ 2149.124717] rto: 200 (0 >> 3 + 0, 21) time: 1849124 sent: 1849113 pen: 1
1849513 rem: 189
[ 2152.214537] lower bound violation: 0
[ 2152.214596] rto: 200 (0 >> 3 + 0, 24) time: 1852214 sent: 1852113 pen: 1
1855313 rem: 99
[ 2152.214836] lower bound violation: 0
[ 2152.214892] rto: 200 (0 >> 3 + 0, 23) time: 1852214 sent: 1852113 pen: 1
1852313 rem: 99
[ 2152.216836] lower bound violation: 0
[ 2152.216892] rto: 200 (0 >> 3 + 0, 22) time: 1852216 sent: 1852113 pen: 1
1852313 rem: 97
[ 2155.212630] lower bound violation: 0
[ 2155.212683] rto: 200 (0 >> 3 + 0, 25) time: 1855212 sent: 1855113 pen: 1
1858313 rem: 101
[ 2155.271403] lower bound violation: 0
[ 2155.271462] rto: 200 (0 >> 3 + 0, 24) time: 1855271 sent: 1855113 pen: 1
1855313 rem: 42
[ 2155.271570] lower bound violation: 0
[ 2155.271624] rto: 200 (0 >> 3 + 0, 23) time: 1855271 sent: 1855113 pen: 1
1855313 rem: 42
[ 2158.247617] lower bound violation: 0
[ 2158.247676] rto: 200 (0 >> 3 + 0, 26) time: 1858247 sent: 1858113 pen: 1
1861313 rem: 66
[ 2158.308891] lower bound violation: 0
[ 2158.308949] rto: 200 (0 >> 3 + 0, 25) time: 1858308 sent: 1858113 pen: 1
1858313 rem: 5
[ 2161.267856] lower bound violation: 0
[ 2161.267918] rto: 200 (0 >> 3 + 0, 28) time: 1861267 sent: 1861114 pen: 1
1864314 rem: 47
[ 2161.268020] lower bound violation: 0
[ 2161.268068] rto: 200 (0 >> 3 + 0, 27) time: 1861268 sent: 1861114 pen: 1
1861315 rem: 46
[ 2161.268283] lower bound violation: 0
[ 2161.268339] rto: 200 (0 >> 3 + 0, 26) time: 1861268 sent: 1861114 pen: 1
1861314 rem: 46
[ 2164.483740] lower bound violation: 0
[ 2164.483799] rto: 200 (0 >> 3 + 0, 29) time: 1864483 sent: 1864114 pen: 1
1867314 rem: 0
[ 2164.485758] lower bound violation: 0
[ 2164.485809] rto: 200 (0 >> 3 + 0, 29) time: 1864485 sent: 1864483 pen: 1
1864883 rem: 198
[ 2460.739324] rto: 7040 (757 >> 3 + 346, 4) time: 2160739 sent: 2160696 pen:
1 2174776 rem: 6997
[ 2477.769916] rto: 120000 (17147 >> 3 + 1705, 6) time: 2177769 sent: 2174642
pen: 1 2294642 rem: 116873
[ 2484.364919] rto: 69440 (3542 >> 3 + 643, 6) time: 2184364 sent: 2182505
pen: 1 2302505 rem: 67581
[ 2555.105348] rto: 69440 (3542 >> 3 + 643, 6) time: 2255105 sent: 2251946
pen: 1 2371946 rem: 66281
[ 2597.920272] rto: 120000 (17147 >> 3 + 1705, 6) time: 2297920 sent: 2294643
pen: 1 2414643 rem: 116723
[ 2624.616823] rto: 69440 (3542 >> 3 + 643, 6) time: 2324616 sent: 2321386
pen: 1 2441386 rem: 66210
[ 2693.911647] rto: 69440 (3542 >> 3 + 643, 6) time: 2393911 sent: 2390826
pen: 1 2510826 rem: 66355
[ 2763.385982] rto: 69440 (3542 >> 3 + 643, 6) time: 2463385 sent: 2460266
pen: 1 2580266 rem: 66321
[ 2779.512699] rto: 1256 (1556 >> 3 + 434, 1) time: 2479512 sent: 2478219 pen:
1 2480731 rem: 0
[ 2832.786161] rto: 69440 (3542 >> 3 + 643, 6) time: 2532786 sent: 2529707
pen: 1 2649707 rem: 66361
[ 2851.953268] rto: 120000 (9704 >> 3 + 2426, 7) time: 2551953 sent: 2548934
pen: 1 2668934 rem: 116981
[ 2902.338631] rto: 69440 (3542 >> 3 + 643, 6) time: 2602338 sent: 2599147
pen: 1 2719147 rem: 66249
[ 2957.718611] rto: 120000 (17147 >> 3 + 1705, 8) time: 2657718 sent: 2654643
pen: 1 2774643 rem: 116925
[ 2971.736295] rto: 69440 (3542 >> 3 + 643, 6) time: 2671736 sent: 2668587
pen: 1 2788587 rem: 66291
[ 2972.118479] rto: 120000 (9704 >> 3 + 2426, 7) time: 2672118 sent: 2668934
pen: 1 2788934 rem: 116816
[ 3041.036185] rto: 69440 (3542 >> 3 + 643, 6) time: 2741036 sent: 2738027
pen: 1 2858027 rem: 66431
[ 3091.942676] rto: 120000 (9704 >> 3 + 2426, 7) time: 2791942 sent: 2788934
pen: 1 2908934 rem: 116992
[ 3110.560285] rto: 69440 (3542 >> 3 + 643, 6) time: 2810560 sent: 2807467
pen: 1 2927467 rem: 66347
[ 3180.044502] rto: 69440 (3542 >> 3 + 643, 6) time: 2880044 sent: 2876907
pen: 1 2996907 rem: 66303
[ 3211.952300] rto: 120000 (9704 >> 3 + 2426, 7) time: 2911952 sent: 2908934
pen: 1 3028934 rem: 116982
[ 3288.275909] rto: 120000 (9674 >> 3 + 2484, 9) time: 2988275 sent: 2987173
pen: 1 3107173 rem: 118898
[ 3330.221683] rto: 120000 (200 >> 3 + 200, 13) time: 3030221 sent: 3027658
pen: 1 3147658 rem: 117437
[ 3383.376964] rto: 13296 (1388 >> 3 + 658, 4) time: 3083376 sent: 3082998
pen: 1 3109590 rem: 12918
[ 3408.805976] rto: 120000 (9674 >> 3 + 2484, 9) time: 3108805 sent: 3107174
pen: 1 3227174 rem: 118369
[ 3447.968663] rto: 120000 (200 >> 3 + 200, 13) time: 3147968 sent: 3147658
pen: 1 3267658 rem: 119690
[ 3798.180697] rto: 1482 (1976 >> 3 + 494, 1) time: 3498180 sent: 3497035 pen:
1 3499999 rem: 337
[ 3798.180827] rto: 741 (1976 >> 3 + 494, 0) time: 3498180 sent: 3497035 pen:
1 3498517 rem: 0
[ 3801.277029] rto: 1482 (1976 >> 3 + 494, 1) time: 3501276 sent: 3499662 pen:
1 3502626 rem: 0
[ 3801.277184] rto: 1482 (1976 >> 3 + 494, 1) time: 3501277 sent: 3501277 pen:
1 3504241 rem: 1482
[ 3804.486861] rto: 1482 (1976 >> 3 + 494, 1) time: 3504486 sent: 3502759 pen:
1 3505723 rem: 0
[ 3804.487007] rto: 1482 (1976 >> 3 + 494, 1) time: 3504486 sent: 3504486 pen:
1 3507450 rem: 1482
[ 3812.053012] rto: 2964 (1976 >> 3 + 494, 2) time: 3512052 sent: 3508933 pen:
1 3514861 rem: 0
[ 3815.238764] rto: 2964 (1976 >> 3 + 494, 2) time: 3515238 sent: 3512053 pen:
1 3517981 rem: 0
[ 3818.394748] rto: 2964 (1976 >> 3 + 494, 2) time: 3518394 sent: 3515238 pen:
1 3521166 rem: 0
[ 3821.481936] rto: 2964 (1976 >> 3 + 494, 2) time: 3521481 sent: 3518394 pen:
1 3524322 rem: 0
[ 3824.873120] rto: 2964 (1976 >> 3 + 494, 2) time: 3524873 sent: 3521482 pen:
1 3527410 rem: 0
[ 3827.898656] rto: 2964 (1976 >> 3 + 494, 2) time: 3527898 sent: 3524873 pen:
1 3530801 rem: 0
[ 3830.943112] rto: 2964 (1976 >> 3 + 494, 2) time: 3530943 sent: 3527898 pen:
1 3533826 rem: 0
[ 3833.974064] rto: 2964 (1976 >> 3 + 494, 2) time: 3533974 sent: 3530943 pen:
1 3536871 rem: 0
[ 3837.112487] rto: 2964 (1976 >> 3 + 494, 2) time: 3537112 sent: 3533974 pen:
1 3539902 rem: 0
[ 3840.130296] rto: 2964 (1976 >> 3 + 494, 2) time: 3540130 sent: 3537112 pen:
1 3543040 rem: 0
[ 3843.191881] rto: 2964 (1976 >> 3 + 494, 2) time: 3543191 sent: 3540130 pen:
1 3546058 rem: 0
[ 3846.633862] rto: 2964 (1976 >> 3 + 494, 2) time: 3546633 sent: 3543191 pen:
1 3549119 rem: 0
[ 3849.682215] rto: 2964 (1976 >> 3 + 494, 2) time: 3549682 sent: 3546633 pen:
1 3552561 rem: 0
[ 3852.728190] rto: 2964 (1976 >> 3 + 494, 2) time: 3552728 sent: 3549682 pen:
1 3555610 rem: 0
[ 3869.778290] rto: 79136 (14257 >> 3 + 691, 5) time: 3569778 sent: 3564894
pen: 1 3684894 rem: 74252
[ 3942.001467] rto: 47424 (1976 >> 3 + 494, 6) time: 3642001 sent: 3641648
pen: 1 3736496 rem: 47071
[ 3948.754452] rto: 79136 (14257 >> 3 + 691, 5) time: 3648754 sent: 3644030
pen: 1 3764030 rem: 74412
[ 3972.841345] rto: 47168 (1911 >> 3 + 499, 6) time: 3672841 sent: 3672158
pen: 1 3766494 rem: 46485
[ 3992.364664] rto: 47424 (1976 >> 3 + 494, 6) time: 3692364 sent: 3689072
pen: 1 3783920 rem: 44132
[ 4019.342183] rto: 47168 (1911 >> 3 + 499, 6) time: 3719342 sent: 3719326
pen: 1 3813662 rem: 47152
[ 4028.049905] rto: 79136 (14257 >> 3 + 691, 5) time: 3728049 sent: 3723166
pen: 1 3843166 rem: 74253
[ 4039.530444] rto: 47424 (1976 >> 3 + 494, 6) time: 3739530 sent: 3736496
pen: 1 3831344 rem: 44390
[ 4067.954752] rto: 47168 (1911 >> 3 + 499, 6) time: 3767954 sent: 3766494
pen: 1 3860830 rem: 45708
[ 4087.534683] rto: 47424 (1976 >> 3 + 494, 6) time: 3787534 sent: 3783920
pen: 1 3878768 rem: 43810
[ 4116.817143] rto: 47168 (1911 >> 3 + 499, 6) time: 3816817 sent: 3813662
pen: 1 3907998 rem: 44013
[ 4134.515420] rto: 47424 (1976 >> 3 + 494, 6) time: 3834515 sent: 3831344
pen: 1 3926192 rem: 44253
[ 4146.622061] rto: 40592 (3300 >> 3 + 2125, 4) time: 3846622 sent: 3846199
pen: 1 3927383 rem: 40169
[ 4182.217172] rto: 47424 (1976 >> 3 + 494, 6) time: 3882217 sent: 3878768
pen: 1 3973616 rem: 43975
[ 4226.387945] rto: 120000 (14257 >> 3 + 691, 6) time: 3926387 sent: 3922303
pen: 1 4042303 rem: 115916
[ 4228.876327] rto: 85152 (11055 >> 3 + 1280, 5) time: 3928876 sent: 3925792
pen: 1 4045792 rem: 82068
[ 4229.248393] rto: 47424 (1976 >> 3 + 494, 6) time: 3929248 sent: 3926192
pen: 1 4021040 rem: 44368
[ 4264.022196] rto: 103072 (11062 >> 3 + 1839, 5) time: 3964022 sent: 3963411
pen: 1 4083411 rem: 102461
[ 4271.074364] rto: 81184 (3300 >> 3 + 2125, 5) time: 3971074 sent: 3967975
pen: 1 4087975 rem: 78085
[ 4276.683784] rto: 47424 (1976 >> 3 + 494, 6) time: 3976683 sent: 3973616
pen: 1 4068464 rem: 44357
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: [PATCH] tcp: fix ICMP-RTO war
2010-01-23 22:34 ` [PATCH] tcp: fix ICMP-RTO war Ilpo Järvinen
2010-01-23 22:45 ` Denys Fedoryshchenko
@ 2010-01-23 23:28 ` Denys Fedoryshchenko
2010-01-25 12:12 ` Damian Lukowski
2 siblings, 0 replies; 24+ messages in thread
From: Denys Fedoryshchenko @ 2010-01-23 23:28 UTC (permalink / raw)
To: Ilpo Järvinen; +Cc: Damian Lukowski, Netdev, David Miller
On Sunday 24 January 2010 00:34:43 Ilpo Järvinen wrote:
> Restored Damian cc, please keep them.
>
> On Sat, 23 Jan 2010, Denys Fedoryshchenko wrote:
> > On Tuesday 19 January 2010 13:17:51 you wrote:
> > > On Tue, 19 Jan 2010, Denys Fedoryshchenko wrote:
> > > > On Tuesday 19 January 2010 11:10:12 you wrote:
> > > > > Hi,
> > > > > thank you for testing. So srtt and rttvar is zero in any of those
> > > > > cases. Ilpo, it is a bug in tcp_rtt_estimator then, I suppose?
> > > > >
> > > > > There is also a code comment in tcp_input.c, saying:
> > > > > > * NOTE: clamping at TCP_RTO_MIN is not required, current algo
> > > > > > * guarantees that rto is higher.
> > > > >
> > > > > So we either fix tcp_rtt_estimator or simply clamp at TCP_RTO_MIN?
> > > > >
> > > > > Damian
> > > > >
> > > > > > On Monday 11 January 2010 15:02:34 you wrote:
> > > > > >> On Sat, 26 Dec 2009, Denys Fedoryshchenko wrote:
> > > > > >>> Few more dumps. I notice:
> > > > > >>> 1)Ack always equal 1
> > > > > >>> 2)It is usually first segment of data sent (?)
> > > > > >>>
> > > > > >>> Maybe some value not initialised properly?
> > > > > >>
> > > > > >> Can you see if the RTO lower bound is violated (I added some
> > > > > >> printing of vars there too already now if it turns out to be
> > > > > >> something):
> > > > > >>
> > > > > >> diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
> > > > > >> index 65b8ebf..d84469f 100644
> > > > > >> --- a/net/ipv4/tcp_ipv4.c
> > > > > >> +++ b/net/ipv4/tcp_ipv4.c
> > > >
> > > > As i see in code it is rounding RTO to minimum value.
> > > > It fixes my problem seems.
> > > >
> > > > Btw just a bit about my environment - wireless networks (sometimes
> > > > lossy!) with low speed (128-512Kbps) customers working over pppoe.
> > > > Maybe it will give a tip why rtt value is too low.
> > >
> > > What I find most strange in it is the fact that when it triggers for
> > > the first time, the srtt and mdev are zero, not some value in between 0
> > > and 200ms. Therefore I suspect that this case might be something that
> > > we've overlooked where srtt/mdev are not valid at all.
> > >
> > > Maybe the patch below helps...
> >
> > Seems after this patch (and debug patch with warnings) my dmesg is clean.
>
> Cool, thanks for testing.
>
> Dave, please send into stable too (besides net-2.6). If we want less strict
> state check we can continue playing with that in net-next, IMHO.
>
I extend a little bit debug to
printk("lower bound violation: %u code %u sk_state %u\n", icsk->icsk_rto,
code,sk->sk_state);
Here is result:
[ 566.990065] lower bound violation: 0 code 1 sk_state 1
[ 566.990111] rto: 200 (0 >> 3 + 0, 5) time: 266990 sent: 263925 pen: 1
383925 rem: 0
[ 570.058555] lower bound violation: 0 code 1 sk_state 1
[ 570.058603] rto: 200 (0 >> 3 + 0, 8) time: 270058 sent: 269790 pen: 1
272990 rem: 0
[ 570.058660] lower bound violation: 0 code 1 sk_state 1
[ 570.058698] rto: 200 (0 >> 3 + 0, 8) time: 270058 sent: 270058 pen: 1
270458 rem: 200
[ 573.122550] lower bound violation: 0 code 1 sk_state 1
[ 573.122626] rto: 200 (0 >> 3 + 0, 11) time: 273122 sent: 273058 pen: 1
276258 rem: 136
[ 573.122745] lower bound violation: 0 code 1 sk_state 1
[ 573.122815] rto: 200 (0 >> 3 + 0, 10) time: 273122 sent: 273058 pen: 1
273258 rem: 136
[ 573.122931] lower bound violation: 0 code 1 sk_state 1
[ 573.123001] rto: 200 (0 >> 3 + 0, 9) time: 273122 sent: 273058 pen: 1
273258 rem: 136
[ 576.304338] lower bound violation: 0 code 1 sk_state 1
[ 576.304423] rto: 200 (0 >> 3 + 0, 12) time: 276304 sent: 276059 pen: 1
279259 rem: 0
[ 576.326167] lower bound violation: 0 code 1 sk_state 1
[ 576.326251] rto: 200 (0 >> 3 + 0, 12) time: 276326 sent: 276304 pen: 1
276704 rem: 178
[ 579.360343] lower bound violation: 0 code 1 sk_state 1
[ 579.360427] rto: 200 (0 >> 3 + 0, 15) time: 279360 sent: 279304 pen: 1
282504 rem: 144
[ 582.566834] lower bound violation: 0 code 1 sk_state 1
[ 582.566919] rto: 200 (0 >> 3 + 0, 18) time: 282566 sent: 282304 pen: 1
285504 rem: 0
[ 582.567085] lower bound violation: 0 code 1 sk_state 1
[ 582.567162] rto: 200 (0 >> 3 + 0, 18) time: 282567 sent: 282567 pen: 1
282967 rem: 200
[ 582.567280] lower bound violation: 0 code 1 sk_state 1
[ 582.567351] rto: 200 (0 >> 3 + 0, 17) time: 282567 sent: 282567 pen: 1
282767 rem: 200
[ 585.649877] lower bound violation: 0 code 1 sk_state 1
[ 585.649962] rto: 200 (0 >> 3 + 0, 20) time: 285649 sent: 285567 pen: 1
288767 rem: 118
[ 585.650097] lower bound violation: 0 code 1 sk_state 1
[ 585.650178] rto: 200 (0 >> 3 + 0, 19) time: 285650 sent: 285567 pen: 1
285768 rem: 117
[ 588.836754] lower bound violation: 0 code 1 sk_state 1
[ 588.836845] rto: 200 (0 >> 3 + 0, 22) time: 288836 sent: 288567 pen: 1
291767 rem: 0
[ 588.836970] lower bound violation: 0 code 1 sk_state 1
[ 588.837042] rto: 200 (0 >> 3 + 0, 22) time: 288836 sent: 288836 pen: 1
289236 rem: 200
[ 591.902908] lower bound violation: 0 code 1 sk_state 1
[ 591.902996] rto: 200 (0 >> 3 + 0, 25) time: 291902 sent: 291837 pen: 1
295037 rem: 135
[ 591.903129] lower bound violation: 0 code 1 sk_state 1
[ 591.903205] rto: 200 (0 >> 3 + 0, 24) time: 291903 sent: 291837 pen: 1
292038 rem: 134
[ 595.091391] lower bound violation: 0 code 1 sk_state 1
[ 595.091477] rto: 200 (0 >> 3 + 0, 27) time: 295091 sent: 294837 pen: 1
298037 rem: 0
[ 595.091627] lower bound violation: 0 code 1 sk_state 1
[ 595.091702] rto: 200 (0 >> 3 + 0, 27) time: 295091 sent: 295091 pen: 1
295491 rem: 200
[ 598.141828] lower bound violation: 0 code 1 sk_state 1
[ 598.141913] rto: 200 (0 >> 3 + 0, 30) time: 298141 sent: 298091 pen: 1
301291 rem: 150
[ 598.142043] lower bound violation: 0 code 1 sk_state 1
[ 598.142114] rto: 200 (0 >> 3 + 0, 29) time: 298141 sent: 298091 pen: 1
298291 rem: 150
[ 598.142252] lower bound violation: 0 code 1 sk_state 1
[ 598.142344] rto: 200 (0 >> 3 + 0, 28) time: 298142 sent: 298091 pen: 1
298291 rem: 149
[ 601.146649] lower bound violation: 0 code 1 sk_state 1
[ 601.146734] rto: 200 (0 >> 3 + 0, 31) time: 301146 sent: 301091 pen: 1
304291 rem: 145
[ 601.178998] lower bound violation: 0 code 1 sk_state 1
[ 601.179090] rto: 200 (0 >> 3 + 0, 30) time: 301179 sent: 301091 pen: 1
301291 rem: 112
[ 601.179227] lower bound violation: 0 code 1 sk_state 1
[ 601.179298] rto: 200 (0 >> 3 + 0, 29) time: 301179 sent: 301091 pen: 1
301291 rem: 112
[ 604.193304] lower bound violation: 0 code 1 sk_state 1
[ 604.193389] rto: 200 (0 >> 3 + 0, 32) time: 304193 sent: 304091 pen: 1
307291 rem: 98
[ 604.193518] lower bound violation: 0 code 1 sk_state 1
[ 604.193589] rto: 200 (0 >> 3 + 0, 31) time: 304193 sent: 304091 pen: 1
304291 rem: 98
[ 604.193706] lower bound violation: 0 code 1 sk_state 1
[ 604.193776] rto: 200 (0 >> 3 + 0, 30) time: 304193 sent: 304091 pen: 1
304291 rem: 98
[ 607.341327] lower bound violation: 0 code 1 sk_state 1
[ 607.341412] rto: 200 (0 >> 3 + 0, 33) time: 307341 sent: 307091 pen: 1
310291 rem: 0
[ 607.370345] lower bound violation: 0 code 1 sk_state 1
[ 607.370427] rto: 200 (0 >> 3 + 0, 33) time: 307370 sent: 307341 pen: 1
307741 rem: 171
[ 607.370657] lower bound violation: 0 code 1 sk_state 1
[ 607.370730] rto: 200 (0 >> 3 + 0, 32) time: 307370 sent: 307341 pen: 1
307541 rem: 171
[ 610.437075] lower bound violation: 0 code 1 sk_state 1
[ 610.437161] rto: 200 (0 >> 3 + 0, 35) time: 310437 sent: 310341 pen: 1
313541 rem: 104
[ 610.437302] lower bound violation: 0 code 1 sk_state 1
[ 610.437374] rto: 200 (0 >> 3 + 0, 34) time: 310437 sent: 310341 pen: 1
310541 rem: 104
[ 610.437497] lower bound violation: 0 code 1 sk_state 1
[ 610.437567] rto: 200 (0 >> 3 + 0, 33) time: 310437 sent: 310341 pen: 1
310541 rem: 104
[ 613.429680] lower bound violation: 0 code 1 sk_state 1
[ 613.429770] rto: 200 (0 >> 3 + 0, 36) time: 313429 sent: 313341 pen: 1
316541 rem: 112
[ 613.429899] lower bound violation: 0 code 1 sk_state 1
[ 613.429970] rto: 200 (0 >> 3 + 0, 35) time: 313429 sent: 313341 pen: 1
313541 rem: 112
[ 613.430087] lower bound violation: 0 code 1 sk_state 1
[ 613.430164] rto: 200 (0 >> 3 + 0, 34) time: 313430 sent: 313341 pen: 1
313542 rem: 111
[ 616.644279] lower bound violation: 0 code 1 sk_state 1
[ 616.644364] rto: 200 (0 >> 3 + 0, 37) time: 316644 sent: 316341 pen: 1
319541 rem: 0
[ 616.644500] lower bound violation: 0 code 1 sk_state 1
[ 616.644572] rto: 200 (0 >> 3 + 0, 37) time: 316644 sent: 316644 pen: 1
317044 rem: 200
[ 616.644689] lower bound violation: 0 code 1 sk_state 1
[ 616.644760] rto: 200 (0 >> 3 + 0, 36) time: 316644 sent: 316644 pen: 1
316844 rem: 200
[ 617.028542] rto: 120000 (788 >> 3 + 266, 10) time: 317028 sent: 313993 pen:
1 433993 rem: 116965
[ 619.711969] lower bound violation: 0 code 1 sk_state 1
[ 619.712050] rto: 200 (0 >> 3 + 0, 39) time: 319712 sent: 319644 pen: 1
322844 rem: 132
[ 619.712169] lower bound violation: 0 code 1 sk_state 1
[ 619.712240] rto: 200 (0 >> 3 + 0, 38) time: 319712 sent: 319644 pen: 1
319844 rem: 132
[ 619.712364] lower bound violation: 0 code 1 sk_state 1
[ 619.712435] rto: 200 (0 >> 3 + 0, 37) time: 319712 sent: 319644 pen: 1
319844 rem: 132
[ 622.908447] lower bound violation: 0 code 1 sk_state 1
[ 622.908531] rto: 200 (0 >> 3 + 0, 40) time: 322908 sent: 322644 pen: 1
325844 rem: 0
[ 622.909274] lower bound violation: 0 code 1 sk_state 1
[ 622.909347] rto: 200 (0 >> 3 + 0, 40) time: 322909 sent: 322908 pen: 1
323308 rem: 199
[ 622.914930] lower bound violation: 0 code 1 sk_state 1
[ 622.915014] rto: 200 (0 >> 3 + 0, 39) time: 322914 sent: 322908 pen: 1
323108 rem: 194
[ 625.975145] lower bound violation: 0 code 1 sk_state 1
[ 625.975232] rto: 200 (0 >> 3 + 0, 42) time: 325975 sent: 325909 pen: 1
329109 rem: 134
[ 625.975350] lower bound violation: 0 code 1 sk_state 1
[ 625.975422] rto: 200 (0 >> 3 + 0, 41) time: 325975 sent: 325909 pen: 1
326109 rem: 134
[ 625.975538] lower bound violation: 0 code 1 sk_state 1
[ 625.975609] rto: 200 (0 >> 3 + 0, 40) time: 325975 sent: 325909 pen: 1
326109 rem: 134
[ 629.187199] lower bound violation: 0 code 1 sk_state 1
[ 629.187286] rto: 200 (0 >> 3 + 0, 43) time: 329187 sent: 328909 pen: 1
332109 rem: 0
[ 629.187454] lower bound violation: 0 code 1 sk_state 1
[ 629.187529] rto: 200 (0 >> 3 + 0, 43) time: 329187 sent: 329187 pen: 1
329587 rem: 200
[ 629.187646] lower bound violation: 0 code 1 sk_state 1
[ 629.187717] rto: 200 (0 >> 3 + 0, 42) time: 329187 sent: 329187 pen: 1
329387 rem: 200
[ 632.232822] lower bound violation: 0 code 1 sk_state 1
[ 632.232907] rto: 200 (0 >> 3 + 0, 45) time: 332232 sent: 332187 pen: 1
335387 rem: 155
[ 632.250500] lower bound violation: 0 code 1 sk_state 1
[ 632.250585] rto: 200 (0 >> 3 + 0, 44) time: 332250 sent: 332187 pen: 1
332388 rem: 137
[ 632.250714] lower bound violation: 0 code 1 sk_state 1
[ 632.250785] rto: 200 (0 >> 3 + 0, 43) time: 332250 sent: 332187 pen: 1
332387 rem: 137
[ 635.247889] lower bound violation: 0 code 1 sk_state 1
[ 635.247974] rto: 200 (0 >> 3 + 0, 46) time: 335247 sent: 335187 pen: 1
338387 rem: 140
[ 635.248416] lower bound violation: 0 code 1 sk_state 1
[ 635.248490] rto: 200 (0 >> 3 + 0, 45) time: 335248 sent: 335187 pen: 1
335387 rem: 139
[ 635.251046] lower bound violation: 0 code 1 sk_state 1
[ 635.251122] rto: 200 (0 >> 3 + 0, 44) time: 335251 sent: 335187 pen: 1
335387 rem: 136
[ 638.434799] lower bound violation: 0 code 1 sk_state 1
[ 638.434883] rto: 200 (0 >> 3 + 0, 47) time: 338434 sent: 338187 pen: 1
341387 rem: 0
[ 638.435018] lower bound violation: 0 code 1 sk_state 1
[ 638.435090] rto: 200 (0 >> 3 + 0, 47) time: 338435 sent: 338434 pen: 1
338834 rem: 199
[ 638.435215] lower bound violation: 0 code 1 sk_state 1
[ 638.435993] rto: 200 (0 >> 3 + 0, 46) time: 338435 sent: 338434 pen: 1
338634 rem: 199
[ 641.501303] lower bound violation: 0 code 1 sk_state 1
[ 641.501380] rto: 200 (0 >> 3 + 0, 49) time: 341501 sent: 341435 pen: 1
344635 rem: 134
[ 641.501501] lower bound violation: 0 code 1 sk_state 1
[ 641.501571] rto: 200 (0 >> 3 + 0, 48) time: 341501 sent: 341435 pen: 1
341635 rem: 134
[ 641.501687] lower bound violation: 0 code 1 sk_state 1
[ 641.501757] rto: 200 (0 >> 3 + 0, 47) time: 341501 sent: 341435 pen: 1
341635 rem: 134
[ 644.518586] lower bound violation: 0 code 1 sk_state 1
[ 644.518672] rto: 200 (0 >> 3 + 0, 50) time: 344518 sent: 344435 pen: 1
347635 rem: 117
[ 644.518849] lower bound violation: 0 code 1 sk_state 1
[ 644.518930] rto: 200 (0 >> 3 + 0, 49) time: 344518 sent: 344435 pen: 1
344635 rem: 117
[ 644.519071] lower bound violation: 0 code 1 sk_state 1
[ 644.519158] rto: 200 (0 >> 3 + 0, 48) time: 344519 sent: 344435 pen: 1
344636 rem: 116
[ 647.725632] lower bound violation: 0 code 1 sk_state 1
[ 647.725717] rto: 200 (0 >> 3 + 0, 51) time: 347725 sent: 347435 pen: 1
350635 rem: 0
[ 647.725850] lower bound violation: 0 code 1 sk_state 1
[ 647.725921] rto: 200 (0 >> 3 + 0, 51) time: 347725 sent: 347725 pen: 1
348125 rem: 200
[ 647.729343] lower bound violation: 0 code 1 sk_state 1
[ 647.729417] rto: 200 (0 >> 3 + 0, 50) time: 347729 sent: 347725 pen: 1
347925 rem: 196
[ 650.787543] lower bound violation: 0 code 1 sk_state 1
[ 650.787619] rto: 200 (0 >> 3 + 0, 53) time: 350787 sent: 350726 pen: 1
353926 rem: 139
[ 650.798651] lower bound violation: 0 code 1 sk_state 1
[ 650.798749] rto: 200 (0 >> 3 + 0, 52) time: 350798 sent: 350726 pen: 1
350926 rem: 128
[ 650.805039] lower bound violation: 0 code 1 sk_state 1
[ 650.805123] rto: 200 (0 >> 3 + 0, 51) time: 350805 sent: 350726 pen: 1
350926 rem: 121
[ 653.801712] lower bound violation: 0 code 1 sk_state 1
[ 653.801788] rto: 200 (0 >> 3 + 0, 54) time: 353801 sent: 353726 pen: 1
356926 rem: 125
[ 653.801937] lower bound violation: 0 code 1 sk_state 1
[ 653.802023] rto: 200 (0 >> 3 + 0, 53) time: 353802 sent: 353726 pen: 1
353926 rem: 124
[ 653.802475] lower bound violation: 0 code 1 sk_state 1
[ 653.802548] rto: 200 (0 >> 3 + 0, 52) time: 353802 sent: 353726 pen: 1
353926 rem: 124
[ 656.985567] lower bound violation: 0 code 1 sk_state 1
[ 656.985653] rto: 200 (0 >> 3 + 0, 55) time: 356985 sent: 356726 pen: 1
359926 rem: 0
[ 656.986226] lower bound violation: 0 code 1 sk_state 1
[ 656.986299] rto: 200 (0 >> 3 + 0, 55) time: 356986 sent: 356985 pen: 1
357385 rem: 199
[ 656.986416] lower bound violation: 0 code 1 sk_state 1
[ 656.986486] rto: 200 (0 >> 3 + 0, 54) time: 356986 sent: 356985 pen: 1
357185 rem: 199
[ 660.042091] lower bound violation: 0 code 1 sk_state 1
[ 660.042168] rto: 200 (0 >> 3 + 0, 57) time: 360042 sent: 359985 pen: 1
363185 rem: 143
[ 660.042286] lower bound violation: 0 code 1 sk_state 1
[ 660.042357] rto: 200 (0 >> 3 + 0, 56) time: 360042 sent: 359985 pen: 1
360185 rem: 143
[ 660.076230] lower bound violation: 0 code 1 sk_state 1
[ 660.076315] rto: 200 (0 >> 3 + 0, 55) time: 360076 sent: 359985 pen: 1
360185 rem: 109
[ 663.256655] lower bound violation: 0 code 1 sk_state 1
[ 663.256731] rto: 200 (0 >> 3 + 0, 58) time: 363256 sent: 362985 pen: 1
366185 rem: 0
[ 663.341934] lower bound violation: 0 code 1 sk_state 1
[ 663.342010] rto: 200 (0 >> 3 + 0, 58) time: 363341 sent: 363256 pen: 1
363656 rem: 115
[ 663.428067] lower bound violation: 0 code 1 sk_state 1
[ 663.428156] rto: 200 (0 >> 3 + 0, 57) time: 363428 sent: 363256 pen: 1
363457 rem: 28
[ 666.308896] lower bound violation: 0 code 1 sk_state 1
[ 666.308980] rto: 200 (0 >> 3 + 0, 60) time: 366308 sent: 366256 pen: 1
369456 rem: 148
[ 666.309110] lower bound violation: 0 code 1 sk_state 1
[ 666.309186] rto: 200 (0 >> 3 + 0, 59) time: 366309 sent: 366256 pen: 1
366457 rem: 147
[ 666.309315] lower bound violation: 0 code 1 sk_state 1
[ 666.309386] rto: 200 (0 >> 3 + 0, 58) time: 366309 sent: 366256 pen: 1
366456 rem: 147
[ 669.519782] lower bound violation: 0 code 1 sk_state 1
[ 669.519866] rto: 200 (0 >> 3 + 0, 61) time: 369519 sent: 369256 pen: 1
372456 rem: 0
[ 669.520011] lower bound violation: 0 code 1 sk_state 1
[ 669.520083] rto: 200 (0 >> 3 + 0, 61) time: 369520 sent: 369519 pen: 1
369919 rem: 199
[ 669.520206] lower bound violation: 0 code 1 sk_state 1
[ 669.520286] rto: 200 (0 >> 3 + 0, 60) time: 369520 sent: 369519 pen: 1
369719 rem: 199
[ 672.641672] lower bound violation: 0 code 1 sk_state 1
[ 672.641756] rto: 200 (0 >> 3 + 0, 63) time: 372641 sent: 372519 pen: 1
375719 rem: 78
[ 672.642325] lower bound violation: 0 code 1 sk_state 1
[ 672.642407] rto: 200 (0 >> 3 + 0, 62) time: 372642 sent: 372519 pen: 1
372719 rem: 77
[ 672.642524] lower bound violation: 0 code 1 sk_state 1
[ 672.642596] rto: 200 (0 >> 3 + 0, 61) time: 372642 sent: 372519 pen: 1
372719 rem: 77
[ 675.789437] lower bound violation: 0 code 1 sk_state 1
[ 675.789522] rto: 200 (0 >> 3 + 0, 64) time: 375789 sent: 375519 pen: 1
378719 rem: 0
[ 675.789657] lower bound violation: 0 code 1 sk_state 1
[ 675.789727] rto: 200 (0 >> 3 + 0, 64) time: 375789 sent: 375789 pen: 1
376189 rem: 200
[ 675.813158] lower bound violation: 0 code 1 sk_state 1
[ 675.813242] rto: 200 (0 >> 3 + 0, 63) time: 375813 sent: 375789 pen: 1
375989 rem: 176
[ 678.902625] lower bound violation: 0 code 1 sk_state 1
[ 678.902689] rto: 200 (0 >> 3 + 0, 66) time: 378902 sent: 378789 pen: 1
381989 rem: 87
[ 678.902808] lower bound violation: 0 code 1 sk_state 1
[ 678.902869] rto: 200 (0 >> 3 + 0, 65) time: 378902 sent: 378789 pen: 1
378989 rem: 87
[ 678.902967] lower bound violation: 0 code 1 sk_state 1
[ 678.903027] rto: 200 (0 >> 3 + 0, 64) time: 378903 sent: 378789 pen: 1
378989 rem: 86
[ 682.086610] lower bound violation: 0 code 1 sk_state 1
[ 682.086673] rto: 200 (0 >> 3 + 0, 67) time: 382086 sent: 381789 pen: 1
384989 rem: 0
[ 682.086823] lower bound violation: 0 code 1 sk_state 1
[ 682.086885] rto: 200 (0 >> 3 + 0, 67) time: 382086 sent: 382086 pen: 1
382486 rem: 200
[ 682.086988] lower bound violation: 0 code 1 sk_state 1
[ 682.087042] rto: 200 (0 >> 3 + 0, 66) time: 382087 sent: 382086 pen: 1
382286 rem: 199
[ 685.177400] lower bound violation: 0 code 1 sk_state 1
[ 685.177460] rto: 200 (0 >> 3 + 0, 69) time: 385177 sent: 385086 pen: 1
388286 rem: 109
[ 685.177566] lower bound violation: 0 code 1 sk_state 1
[ 685.177630] rto: 200 (0 >> 3 + 0, 68) time: 385177 sent: 385086 pen: 1
385286 rem: 109
[ 685.177734] lower bound violation: 0 code 1 sk_state 1
[ 685.177790] rto: 200 (0 >> 3 + 0, 67) time: 385177 sent: 385086 pen: 1
385286 rem: 109
[ 688.339503] lower bound violation: 0 code 1 sk_state 1
[ 688.339565] rto: 200 (0 >> 3 + 0, 70) time: 388339 sent: 388086 pen: 1
391286 rem: 0
[ 688.339684] lower bound violation: 0 code 1 sk_state 1
[ 688.339745] rto: 200 (0 >> 3 + 0, 70) time: 388339 sent: 388339 pen: 1
388739 rem: 200
[ 688.339844] lower bound violation: 0 code 1 sk_state 1
[ 688.339896] rto: 200 (0 >> 3 + 0, 69) time: 388339 sent: 388339 pen: 1
388539 rem: 200
[ 691.925180] lower bound violation: 0 code 1 sk_state 1
[ 691.925242] rto: 200 (0 >> 3 + 0, 72) time: 391925 sent: 391339 pen: 1
394539 rem: 0
[ 692.010074] lower bound violation: 0 code 1 sk_state 1
[ 692.010131] rto: 200 (0 >> 3 + 0, 72) time: 392009 sent: 391925 pen: 1
392325 rem: 116
[ 692.096188] lower bound violation: 0 code 1 sk_state 1
[ 692.096254] rto: 200 (0 >> 3 + 0, 71) time: 392096 sent: 391925 pen: 1
392126 rem: 29
[ 694.474680] lower bound violation: 0 code 1 sk_state 1
[ 694.474742] rto: 200 (0 >> 3 + 0, 73) time: 394474 sent: 393325 pen: 1
394925 rem: 0
[ 694.475751] lower bound violation: 0 code 1 sk_state 1
[ 694.475810] rto: 200 (0 >> 3 + 0, 73) time: 394475 sent: 394474 pen: 1
394874 rem: 199
[ 694.475918] lower bound violation: 0 code 1 sk_state 1
[ 694.475975] rto: 200 (0 >> 3 + 0, 72) time: 394475 sent: 394474 pen: 1
394674 rem: 199
[ 697.572814] lower bound violation: 0 code 1 sk_state 1
[ 697.572877] rto: 200 (0 >> 3 + 0, 75) time: 397572 sent: 397474 pen: 1
400674 rem: 102
[ 697.572986] lower bound violation: 0 code 1 sk_state 1
[ 697.573052] rto: 200 (0 >> 3 + 0, 74) time: 397573 sent: 397474 pen: 1
397674 rem: 101
[ 697.573159] lower bound violation: 0 code 1 sk_state 1
[ 697.573211] rto: 200 (0 >> 3 + 0, 73) time: 397573 sent: 397474 pen: 1
397674 rem: 101
[ 700.728072] lower bound violation: 0 code 1 sk_state 1
[ 700.728135] rto: 200 (0 >> 3 + 0, 76) time: 400728 sent: 400474 pen: 1
403674 rem: 0
[ 700.734010] lower bound violation: 0 code 1 sk_state 1
[ 700.734079] rto: 200 (0 >> 3 + 0, 76) time: 400734 sent: 400728 pen: 1
401128 rem: 194
[ 700.734191] lower bound violation: 0 code 1 sk_state 1
[ 700.734944] rto: 200 (0 >> 3 + 0, 75) time: 400734 sent: 400728 pen: 1
400928 rem: 194
[ 703.779459] lower bound violation: 0 code 1 sk_state 1
[ 703.779521] rto: 200 (0 >> 3 + 0, 78) time: 403779 sent: 403729 pen: 1
406929 rem: 150
[ 703.779628] lower bound violation: 0 code 1 sk_state 1
[ 703.779680] rto: 200 (0 >> 3 + 0, 77) time: 403779 sent: 403729 pen: 1
403929 rem: 150
[ 703.779797] lower bound violation: 0 code 1 sk_state 1
[ 703.779850] rto: 200 (0 >> 3 + 0, 76) time: 403779 sent: 403729 pen: 1
403929 rem: 150
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: [PATCH] tcp: fix ICMP-RTO war
2010-01-23 22:34 ` [PATCH] tcp: fix ICMP-RTO war Ilpo Järvinen
2010-01-23 22:45 ` Denys Fedoryshchenko
2010-01-23 23:28 ` Denys Fedoryshchenko
@ 2010-01-25 12:12 ` Damian Lukowski
2010-01-27 12:36 ` Ilpo Järvinen
2 siblings, 1 reply; 24+ messages in thread
From: Damian Lukowski @ 2010-01-25 12:12 UTC (permalink / raw)
To: Ilpo Järvinen; +Cc: Denys Fedoryshchenko, Netdev, David Miller
Hi,
considering Denys' latest tests, I think we should bound
at TCP_RTO_MIN inside __tcp_set_rto().
Look at the following piece:
> [ 604.193389] rto: 200 (0 >> 3 + 0, 32) time: 304193 sent: 304091 pen: 1 307291 rem: 98
> [ 604.193518] lower bound violation: 0 code 1 sk_state 1
> [ 604.193589] rto: 200 (0 >> 3 + 0, 31) time: 304193 sent: 304091 pen: 1 304291 rem: 98
> [ 604.193706] lower bound violation: 0 code 1 sk_state 1
> [ 604.193776] rto: 200 (0 >> 3 + 0, 30) time: 304193 sent: 304091 pen: 1 304291 rem: 98
> [ 607.341327] lower bound violation: 0 code 1 sk_state 1
> [ 607.341412] rto: 200 (0 >> 3 + 0, 33) time: 307341 sent: 307091 pen: 1 310291 rem: 0
We have a burst of three incoming ICMPs, not triggering retransmissions because
of rem > 0. Nevertheless, there is an increase of icsk_backoff by four
within 3100ms, with no ICMPs in between.
For me, this is explainable by the broken mdev/rtt issue together with
bursty ICMP replies.
- At t=0, RTT is at 0.2 seconds when connectivity breaks
- At t=3, TCP has emitted 4 eponentially backed-off retransmits,
and icsk_rto is at 3.2s.
- At t=3+eps, three of four ICMPs arrive in one burst.
- Due to broken mdev, rto is reset to 0.2s inside tcp_v4_err(),
independent of icsk_backoff.
Damian
> Restored Damian cc, please keep them.
>
> On Sat, 23 Jan 2010, Denys Fedoryshchenko wrote:
>> On Tuesday 19 January 2010 13:17:51 you wrote:
>>> On Tue, 19 Jan 2010, Denys Fedoryshchenko wrote:
>>>> On Tuesday 19 January 2010 11:10:12 you wrote:
>>>>> Hi,
>>>>> thank you for testing. So srtt and rttvar is zero in any of those
>>>>> cases. Ilpo, it is a bug in tcp_rtt_estimator then, I suppose?
>>>>>
>>>>> There is also a code comment in tcp_input.c, saying:
>>>>>> * NOTE: clamping at TCP_RTO_MIN is not required, current algo
>>>>>> * guarantees that rto is higher.
>>>>> So we either fix tcp_rtt_estimator or simply clamp at TCP_RTO_MIN?
>>>>>
>>>>> Damian
>>>>>
>>>>>> On Monday 11 January 2010 15:02:34 you wrote:
>>>>>>> On Sat, 26 Dec 2009, Denys Fedoryshchenko wrote:
>>>>>>>> Few more dumps. I notice:
>>>>>>>> 1)Ack always equal 1
>>>>>>>> 2)It is usually first segment of data sent (?)
>>>>>>>>
>>>>>>>> Maybe some value not initialised properly?
>>>>>>> Can you see if the RTO lower bound is violated (I added some
>>>>>>> printing of vars there too already now if it turns out to be
>>>>>>> something):
>>>>>>>
>>>>>>> diff --git a/net/ipv4/tcp_ipv4.c b/net/ipv4/tcp_ipv4.c
>>>>>>> index 65b8ebf..d84469f 100644
>>>>>>> --- a/net/ipv4/tcp_ipv4.c
>>>>>>> +++ b/net/ipv4/tcp_ipv4.c
>>>> As i see in code it is rounding RTO to minimum value.
>>>> It fixes my problem seems.
>>>>
>>>> Btw just a bit about my environment - wireless networks (sometimes
>>>> lossy!) with low speed (128-512Kbps) customers working over pppoe. Maybe
>>>> it will give a tip why rtt value is too low.
>>> What I find most strange in it is the fact that when it triggers for the
>>> first time, the srtt and mdev are zero, not some value in between 0 and
>>> 200ms. Therefore I suspect that this case might be something that we've
>>> overlooked where srtt/mdev are not valid at all.
>>>
>>> Maybe the patch below helps...
>>>
>> Seems after this patch (and debug patch with warnings) my dmesg is clean.
>
> Cool, thanks for testing.
>
> Dave, please send into stable too (besides net-2.6). If we want less strict
> state check we can continue playing with that in net-next, IMHO.
>
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: [PATCH] tcp: fix ICMP-RTO war
2010-01-23 22:45 ` Denys Fedoryshchenko
@ 2010-01-25 15:07 ` Damian Lukowski
2010-01-26 7:45 ` David Miller
0 siblings, 1 reply; 24+ messages in thread
From: Damian Lukowski @ 2010-01-25 15:07 UTC (permalink / raw)
To: Denys Fedoryshchenko; +Cc: Ilpo Järvinen, Netdev, David Miller
Denys Fedoryshchenko schrieb:
>> Cool, thanks for testing.
>>
>> Dave, please send into stable too (besides net-2.6). If we want less strict
>> state check we can continue playing with that in net-next, IMHO.
>>
> Maybe better to wait. Sad news, got messages after while (before they was
> appearing almost immediately on such load).
>
> [ ... ]
Hi Denys,
could you test the following patch, please?
Damian
diff --git a/include/net/tcp.h b/include/net/tcp.h
index 34f5cc2..ec2fc91 100644
--- a/include/net/tcp.h
+++ b/include/net/tcp.h
@@ -530,7 +530,11 @@ static inline void tcp_bound_rto(const struct sock *sk)
static inline u32 __tcp_set_rto(const struct tcp_sock *tp)
{
- return (tp->srtt >> 3) + tp->rttvar;
+ u32 rto = (tp->srtt >> 3) + tp->rttvar;
+ if (unlikely(rto < TCP_RTO_MIN))
+ return TCP_RTO_MIN;
+ else
+ return rto;
}
static inline void __tcp_fast_path_on(struct tcp_sock *tp, u32 snd_wnd)
^ permalink raw reply related [flat|nested] 24+ messages in thread
* Re: [PATCH] tcp: fix ICMP-RTO war
2010-01-25 15:07 ` Damian Lukowski
@ 2010-01-26 7:45 ` David Miller
2010-01-27 12:41 ` Ilpo Järvinen
0 siblings, 1 reply; 24+ messages in thread
From: David Miller @ 2010-01-26 7:45 UTC (permalink / raw)
To: damian; +Cc: denys, ilpo.jarvinen, netdev
From: Damian Lukowski <damian@tvk.rwth-aachen.de>
Date: Mon, 25 Jan 2010 16:07:43 +0100
> @@ -530,7 +530,11 @@ static inline void tcp_bound_rto(const struct sock *sk)
>
> static inline u32 __tcp_set_rto(const struct tcp_sock *tp)
> {
> - return (tp->srtt >> 3) + tp->rttvar;
> + u32 rto = (tp->srtt >> 3) + tp->rttvar;
> + if (unlikely(rto < TCP_RTO_MIN))
> + return TCP_RTO_MIN;
> + else
> + return rto;
> }
The min RTO is now a runtime variable, TCP_RTO_MIN is merely the
default, so we should use tcp_rto_min() for obtaining that value.
And if we make this change, we might want to delete the comment in
tcp_set_rto() which claims:
/* NOTE: clamping at TCP_RTO_MIN is not required, current algo
* guarantees that rto is higher.
*/
tcp_bound_rto(sk);
And we have shown here at least one case where that is not true.
:-)
I've looked at Denys's traces and your analysis, and I still
can't figure out who the true culprit is that lets us get into
such a state that RTO is evaluated so low...
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: [PATCH] tcp: fix ICMP-RTO war
2010-01-25 12:12 ` Damian Lukowski
@ 2010-01-27 12:36 ` Ilpo Järvinen
0 siblings, 0 replies; 24+ messages in thread
From: Ilpo Järvinen @ 2010-01-27 12:36 UTC (permalink / raw)
To: Damian Lukowski
Cc: Denys Fedoryshchenko, Netdev, David Miller, Alexey Kuznetsov
On Mon, 25 Jan 2010, Damian Lukowski wrote:
> considering Denys' latest tests, I think we should bound
> at TCP_RTO_MIN inside __tcp_set_rto().
> Look at the following piece:
> > [ 604.193389] rto: 200 (0 >> 3 + 0, 32) time: 304193 sent: 304091 pen: 1 307291 rem: 98
> > [ 604.193518] lower bound violation: 0 code 1 sk_state 1
> > [ 604.193589] rto: 200 (0 >> 3 + 0, 31) time: 304193 sent: 304091 pen: 1 304291 rem: 98
> > [ 604.193706] lower bound violation: 0 code 1 sk_state 1
> > [ 604.193776] rto: 200 (0 >> 3 + 0, 30) time: 304193 sent: 304091 pen: 1 304291 rem: 98
> > [ 607.341327] lower bound violation: 0 code 1 sk_state 1
> > [ 607.341412] rto: 200 (0 >> 3 + 0, 33) time: 307341 sent: 307091 pen: 1 310291 rem: 0
>
> We have a burst of three incoming ICMPs, not triggering retransmissions because
> of rem > 0. Nevertheless, there is an increase of icsk_backoff by four
> within 3100ms, with no ICMPs in between.
> For me, this is explainable by the broken mdev/rtt issue together with
> bursty ICMP replies.
Unless they are for a different connection? We might have to print sk (%p)
in all those printouts to be sure which maps to which. If a peer becomes
unreachable, it may well have multiple connections open (this was a
proxy, iirc?).
--
i.
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: [PATCH] tcp: fix ICMP-RTO war
2010-01-26 7:45 ` David Miller
@ 2010-01-27 12:41 ` Ilpo Järvinen
2010-01-27 14:14 ` Alexey Kuznetsov
0 siblings, 1 reply; 24+ messages in thread
From: Ilpo Järvinen @ 2010-01-27 12:41 UTC (permalink / raw)
To: David Miller; +Cc: damian, denys, Netdev, Alexey Kuznetsov
On Mon, 25 Jan 2010, David Miller wrote:
> From: Damian Lukowski <damian@tvk.rwth-aachen.de>
> Date: Mon, 25 Jan 2010 16:07:43 +0100
>
> > @@ -530,7 +530,11 @@ static inline void tcp_bound_rto(const struct sock *sk)
> >
> > static inline u32 __tcp_set_rto(const struct tcp_sock *tp)
> > {
> > - return (tp->srtt >> 3) + tp->rttvar;
> > + u32 rto = (tp->srtt >> 3) + tp->rttvar;
> > + if (unlikely(rto < TCP_RTO_MIN))
> > + return TCP_RTO_MIN;
> > + else
> > + return rto;
> > }
>
> The min RTO is now a runtime variable, TCP_RTO_MIN is merely the
> default, so we should use tcp_rto_min() for obtaining that value.
>
> And if we make this change, we might want to delete the comment in
> tcp_set_rto() which claims:
>
> /* NOTE: clamping at TCP_RTO_MIN is not required, current algo
> * guarantees that rto is higher.
> */
> tcp_bound_rto(sk);
>
> And we have shown here at least one case where that is not true.
> :-)
I went through some history, it seems that this comment about the lower
bound originates from Alexey [1]:
commit 893e1302654a9bcdc0e7d9ac95159657a8f5e0e8
Author: davem <davem>
Date: Wed Dec 13 04:10:12 2000 +0000
Fix numerous RTO bugs.
Withdraw CWR when DSACKs are seen.
Do not allow recvmsg on unbound socket, it is
senseless.
All from Alexey.
> I've looked at Denys's traces and your analysis, and I still
> can't figure out who the true culprit is that lets us get into
> such a state that RTO is evaluated so low...
--
i.
[1] http://git.kernel.org/?p=linux/kernel/git/davem/netdev-vger-cvs.git;a=commit;h=893e1302654a9bcdc0e7d9ac95159657a8f5e0e8
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: [PATCH] tcp: fix ICMP-RTO war
2010-01-27 12:41 ` Ilpo Järvinen
@ 2010-01-27 14:14 ` Alexey Kuznetsov
0 siblings, 0 replies; 24+ messages in thread
From: Alexey Kuznetsov @ 2010-01-27 14:14 UTC (permalink / raw)
To: Ilpo J?rvinen; +Cc: David Miller, damian, denys, Netdev
Hello!
> I went through some history, it seems that this comment about the lower
> bound originates from Alexey [1]:
Yes, I even remember why it was done.
Actual comment starts with "If rtt variance happened to be less 50msec...".
It was observed that sometimes due to high burstiness of ACKs
(found originally when linux commuinitected to solaris tcp stack,
which issued huge burst of acks each 50msec. I think he data can be found
in netdev archives), rtt deviation tends to collapse to 0 during such burst,
rto was calculated as plain rtt and obviously we falled to retransmit.
So, the algorithm was repaired. First, to avoid glitches in the future
mdev was clamped to 50ms (rttvar, contribution to rto, is 200msec).
That's what the comment is about.
Second, Linux used to sample rtt each ack, not each rtt (which is technically
main source of the problem). Instead of decreasing sampling rate
I used different sampling rates for growing and dropping rtt:
it grows with rate of arriving acks and drops each rtt i.e. rto grows
quickly, but drops slowly.
Alexey
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: Crazy TCP bug (keepalive flood?) in 2.6.32?
2009-12-10 10:24 ` Ilpo Järvinen
@ 2009-12-26 14:54 ` Denys Fedoryshchenko
0 siblings, 0 replies; 24+ messages in thread
From: Denys Fedoryshchenko @ 2009-12-26 14:54 UTC (permalink / raw)
To: Ilpo Järvinen, netdev
>
> ...I thought that myself too but after some thinking I concluded that
> zero packets_out alone would not end up into a loop. ...As the when field
> would then get set to a rather valid value on the first (bogus)
> transmission of the not yet sent segment, so no loop for the next ICMP
> anymore because there should then be plenty of time remaining. I couldn't
> immediately determine whether that packets_out == 0 could occur (I suppose
> we need to think that through but I'm a bit skeptic that it is the reason
> here).
>
> Another alternative to cause this is that icsk_rto become very small for
> some reason.
>
Is there anything i can do?
2.6.32.2 have same issue, and actually hosts doing DDoS for my network. It is
local network with limited capacity and i can manage it, but i imagine if real
world network will have such issue...
Is there anything i can help to debug this?
I try to disable frto,
to put keepalive to default value (2 hours) - issue triggered much earlier
after program restart
tried to disable also timestamps.
All hosts have similar hardware, but not completely same.
r8169, Intel motherboards, Dual core processors(E5300), nothing unusual.
Clocksource tsc
Nothing helps to workaround this bug. And weird thing, why it does ignore ICMP
unreachable?
It seems keeps 10400 bytes in buffer and trying to send them non-stop.
tcp 0 10400 194.146.153.114:8080 172.16.120.230:49435
ESTABLISHED2078/squid
Proxy-16 ~ # ss -et|grep 120.230
ESTAB 0 0 194.146.153.114:http-alt 172.16.16.120:2307
uid:101 ino:97182030 sk:d884e3c0
ESTAB 0 10400 194.146.153.114:http-alt 172.16.120.230:49435
timer:(on,,207) uid:101 ino:97063205 sk:dcdf9c80
Proxy-16 ~ # ss -et|grep 120.230
ESTAB 0 0 194.146.153.114:http-alt 172.16.16.120:2307
uid:101 ino:97182030 sk:d884e3c0
ESTAB 0 10400 194.146.153.114:http-alt 172.16.120.230:49435
timer:(on,,88) uid:101 ino:97063205 sk:dcdf9c80
Proxy-16 ~ # ss -et|grep 120.230
ESTAB 0 0 194.146.153.114:http-alt 172.16.16.120:2307
uid:101 ino:97182030 sk:d884e3c0
ESTAB 0 10400 194.146.153.114:http-alt 172.16.120.230:49435
timer:(on,,113) uid:101 ino:97063205 sk:dcdf9c80
Proxy-16 ~ # ss -aet|grep 120.230
ESTAB 0 10400 194.146.153.114:http-alt 172.16.120.230:49435
timer:(on,,7) uid:101 ino:97063205 sk:dcdf9c80
Proxy-16 ~ # ss -aet|grep 120.230
ESTAB 0 10400 194.146.153.114:http-alt 172.16.120.230:49435
timer:(on,,3) uid:101 ino:97063205 sk:dcdf9c80
Proxy-16 ~ # ss -aet|grep 120.230
ESTAB 0 10400 194.146.153.114:http-alt 172.16.120.230:49435
timer:(on,,9) uid:101 ino:97063205 sk:dcdf9c80
Proxy-16 ~ # ss -aet|grep 120.230
ESTAB 0 10400 194.146.153.114:http-alt 172.16.120.230:49435
timer:(on,,221) uid:101 ino:97063205 sk:dcdf9c80
16:39:43.167575 IP (tos 0x0, ttl 64, id 33482, offset 0, flags [DF], proto TCP
(6), length 1219)
194.146.153.114.8080 > 172.16.120.230.49435: Flags [P.], cksum 0xe340
(correct), seq 0:1179, ack 1, win 118, length 1179
16:39:43.168580 IP (tos 0x0, ttl 64, id 33483, offset 0, flags [DF], proto TCP
(6), length 1219)
194.146.153.114.8080 > 172.16.120.230.49435: Flags [P.], cksum 0xe340
(correct), seq 0:1179, ack 1, win 118, length 1179
16:39:43.169571 IP (tos 0x0, ttl 64, id 33484, offset 0, flags [DF], proto TCP
(6), length 1219)
194.146.153.114.8080 > 172.16.120.230.49435: Flags [P.], cksum 0xe340
(correct), seq 0:1179, ack 1, win 118, length 1179
Proxy-16 /config # tcpdump -ni eth0 src host 172.16.120.230 -vvv -s 1500
tcpdump: WARNING:
tcpdump: listening on eth0, link-type EN10MB (Ethernet), capture size 1500
bytes
16:41:54.774385 IP (tos 0xc0, ttl 59, id 31922, offset 0, flags [none], proto
ICMP (1), length 576)
172.16.120.230 > 194.146.153.114: ICMP host 172.16.120.230 unreachable,
length 556
IP (tos 0x0, ttl 58, id 31545, offset 0, flags [DF], proto TCP (6),
length 1219)
194.146.153.114.8080 > 172.16.120.230.49435: Flags [P.], seq
3520354182:3520355361, ack 598087346, win 118, length 1179
16:41:54.774509 IP (tos 0xc0, ttl 59, id 31923, offset 0, flags [none], proto
ICMP (1), length 576)
172.16.120.230 > 194.146.153.114: ICMP host 172.16.120.230 unreachable,
length 556
IP (tos 0x0, ttl 58, id 31634, offset 0, flags [DF], proto TCP (6),
length 1219)
194.146.153.114.8080 > 172.16.120.230.49435: Flags [P.], seq 0:1179, ack
1, win 118, length 1179
16:41:54.774389 IP (tos 0xc0, ttl 59, id 31924, offset 0, flags [none], proto
ICMP (1), length 576)
172.16.120.230 > 194.146.153.114: ICMP host 172.16.120.230 unreachable,
length 556
IP (tos 0x0, ttl 58, id 31732, offset 0, flags [DF], proto TCP (6),
length 1219)
194.146.153.114.8080 > 172.16.120.230.49435: Flags [P.], seq 0:1179, ack
1, win 118, length 1179
16:41:57.741989 IP (tos 0xc0, ttl 59, id 31925, offset 0, flags [none], proto
ICMP (1), length 576)
172.16.120.230 > 194.146.153.114: ICMP host 172.16.120.230 unreachable,
length 556
IP (tos 0x0, ttl 58, id 34579, offset 0, flags [DF], proto TCP (6),
length 1219)
194.146.153.114.8080 > 172.16.120.230.49435: Flags [P.], seq 0:1179, ack
1, win 118, length 1179
16:41:57.742169 IP (tos 0xc0, ttl 59, id 31926, offset 0, flags [none], proto
ICMP (1), length 576)
172.16.120.230 > 194.146.153.114: ICMP host 172.16.120.230 unreachable,
length 556
IP (tos 0x0, ttl 58, id 34689, offset 0, flags [DF], proto TCP (6),
length 1219)
194.146.153.114.8080 > 172.16.120.230.49435: Flags [P.], seq 0:1179, ack
1, win 118, length 1179
16:41:57.742174 IP (tos 0xc0, ttl 59, id 31927, offset 0, flags [none], proto
ICMP (1), length 576)
172.16.120.230 > 194.146.153.114: ICMP host 172.16.120.230 unreachable,
length 556
IP (tos 0x0, ttl 58, id 34723, offset 0, flags [DF], proto TCP (6),
length 1219)
194.146.153.114.8080 > 172.16.120.230.49435: Flags [P.], seq 0:1179, ack
1, win 118, length 1179
16:42:00.748848 IP (tos 0xc0, ttl 59, id 31928, offset 0, flags [none], proto
ICMP (1), length 576)
172.16.120.230 > 194.146.153.114: ICMP host 172.16.120.230 unreachable,
length 556
IP (tos 0x0, ttl 58, id 37556, offset 0, flags [DF], proto TCP (6),
length 1219)
194.146.153.114.8080 > 172.16.120.230.49435: Flags [P.], seq 0:1179, ack
1, win 118, length 1179
16:42:00.748856 IP (tos 0xc0, ttl 59, id 31929, offset 0, flags [none], proto
ICMP (1), length 576)
172.16.120.230 > 194.146.153.114: ICMP host 172.16.120.230 unreachable,
length 556
IP (tos 0x0, ttl 58, id 37597, offset 0, flags [DF], proto TCP (6),
length 1219)
194.146.153.114.8080 > 172.16.120.230.49435: Flags [P.], seq 0:1179, ack
1, win 118, length 1179
16:42:00.759461 IP (tos 0xc0, ttl 59, id 31930, offset 0, flags [none], proto
ICMP (1), length 576)
172.16.120.230 > 194.146.153.114: ICMP host 172.16.120.230 unreachable,
length 556
IP (tos 0x0, ttl 58, id 37715, offset 0, flags [DF], proto TCP (6),
length 1219)
194.146.153.114.8080 > 172.16.120.230.49435: Flags [P.], seq 0:1179, ack
1, win 118, length 1179
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: Crazy TCP bug (keepalive flood?) in 2.6.32?
2009-12-10 10:05 ` Damian Lukowski
@ 2009-12-10 10:24 ` Ilpo Järvinen
2009-12-26 14:54 ` Denys Fedoryshchenko
0 siblings, 1 reply; 24+ messages in thread
From: Ilpo Järvinen @ 2009-12-10 10:24 UTC (permalink / raw)
To: Damian Lukowski; +Cc: Denys Fedoryshchenko, Netdev
[-- Attachment #1: Type: TEXT/PLAIN, Size: 6367 bytes --]
On Thu, 10 Dec 2009, Damian Lukowski wrote:
> Ilpo Järvinen schrieb:
> > On Thu, 10 Dec 2009, Ilpo Järvinen wrote:
> >
> >> On Thu, 10 Dec 2009, Ilpo Järvinen wrote:
> >>
> >>> Cc Damian.
> >>>
> >>> On Wed, 9 Dec 2009, Denys Fedoryshchenko wrote:
> >>>
> >>>> Hi
> >>>>
> >>>> I did upgrade of my lusca(squid) proxies and notice that some users getting up
> >>>> to 8-15 Mbit/s flood (while they are shaped to 128Kbit/s). After tracing i end
> >>>> up on one of proxies host and seems it is bug in kernel tcp stack.
> >>>>
> >>>> I check packets inside - it is same repeating content (and even same tcp
> >>>> sequence, so it is almost sure tcp bug). Sender also ignoring ICMP unreachable
> >>>> packets and continue flooding destination
>
> By "also" you mean, that the sender is flooding with and without ICMPs?
>
> >>>>
> >>>> Here is some examples
> >>>> ss output for corresponding entry
> >>>>
> >>>> ESTAB 0 8267 194.146.153.114:8080 172.16.67.243:2512
> >>>>
> >>>>
> >>>> 20:32:08.491470 IP (tos 0x0, ttl 64, id 49493, offset 0, flags [DF], proto TCP
> >>>> (6), length 655)
> >>>> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> >>>> (correct), seq 0:615, ack 1, win 7504, length 615
> >>>> 20:32:08.492487 IP (tos 0x0, ttl 64, id 49494, offset 0, flags [DF], proto TCP
> >>>> (6), length 655)
> >>>> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> >>>> (correct), seq 0:615, ack 1, win 7504, length 615
> >>>> 20:32:08.493468 IP (tos 0x0, ttl 64, id 49495, offset 0, flags [DF], proto TCP
> >>>> (6), length 655)
> >>>> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> >>>> (correct), seq 0:615, ack 1, win 7504, length 615
> >>>> 20:32:08.494463 IP (tos 0x0, ttl 64, id 49496, offset 0, flags [DF], proto TCP
> >>>> (6), length 655)
> >>>> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> >>>> (correct), seq 0:615, ack 1, win 7504, length 615
> >>>> 20:32:08.495463 IP (tos 0x0, ttl 64, id 49497, offset 0, flags [DF], proto TCP
> >>>> (6), length 655)
> >>>> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> >>>> (correct), seq 0:615, ack 1, win 7504, length 615
> >>>> 20:32:08.496467 IP (tos 0x0, ttl 64, id 49498, offset 0, flags [DF], proto TCP
> >>>> (6), length 655)
> >>>>
> >>>>
> >>>> One more
> >>>> 20:36:13.310718 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> >>>> win 7469, length 1440
> >>>> 20:36:13.311725 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> >>>> win 7469, length 1440
> >>>> 20:36:13.312729 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> >>>> win 7469, length 1440
> >>>> 20:36:13.313717 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> >>>> win 7469, length 1440
> >>>> 20:36:13.314717 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> >>>> win 7469, length 1440
> >>>> 20:36:13.315718 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> >>>> win 7469, length 1440
> >>>> 20:36:13.316725 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> >>>> win 7469, length 1440
> >>>>
> >>>> I run multiple times ss
> >>>>
> >>>> ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
> >>>> timer:(on,,172) uid:101 ino:4772596 sk:c0ce84c0
> >>>> ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
> >>>> timer:(on,,43) uid:101 ino:4772596 sk:c0ce84c0
> >>>> ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
> >>>> timer:(on,,17) uid:101 ino:4772596 sk:c0ce84c0
> >>>>
> >>>> After i kill squid it will switch socket to FIN-WAIT state and flood will
> >>>> stop.
> >>>>
> >>>> Some sysctl tuning done during boot (maybe related)
> >>>> sysctl -w net.ipv4.tcp_frto=2
> >>>> sysctl -w net.ipv4.tcp_frto_response=2
> >>>>
> >>>> And most probably it is related to keepalive. I have it set on this socket:
> >>>> http_port 8080 transparent tcpkeepalive=30,30,60 http11
> >>>>
> >>>> From manual
> >>>> #<-----> tcpkeepalive[=idle,interval,timeout]
> >>>> #<-----><------><------>Enable TCP keepalive probes of idle connections
> >>>> #<-----><------><------>idle is the initial time before TCP starts probing
> >>>> #<-----><------><------>the connection, interval how often to probe, and
> >>>> #<-----><------><------>timeout the time before giving up.
> >>>>
> >>>> I am not able to reproduce reliably bug, but it is appearing on different
> >>>> cluster pc's randomly for single connection each 5-10 minutes (around 8000
> >>>> established connections to each at moment, 8 pc's in cluster) and dissapearing
> >>>> after 10-50 seconds of flood.
> >>> Damian, can you please take a look. ...It's a bit weird after a very brief
> >>> look (as if RTO would trigger way too often). Maybe its backoff is broken
> >>> now?
> >> ...I meant broken when keepalives are in use.
> >
> > I guess it's that the ICMPs are somehow triggering the
> > tcp_retransmit_timer call in tcp_ipv4 even though they're not supposed
> > to do that until the RTO timeout would have fired. I've no idea why
> > remaining doesn't do what it's supposed to.
> >
>
> Hm.
> Those ICMPs will trigger only, if icsk_backoff and retransmits is non-zero.
> If that's because of a retransmission (which was thought to be), then
> packets_out is non-zero and tcp_probe_timer will return before sending anything.
> Correct me, if I'm wrong here.
> I'll try to think of a case, where those are non-zero with no packets_out.
...I thought that myself too but after some thinking I concluded that
zero packets_out alone would not end up into a loop. ...As the when field
would then get set to a rather valid value on the first (bogus)
transmission of the not yet sent segment, so no loop for the next ICMP
anymore because there should then be plenty of time remaining. I couldn't
immediately determine whether that packets_out == 0 could occur (I suppose
we need to think that through but I'm a bit skeptic that it is the reason
here).
Another alternative to cause this is that icsk_rto become very small for
some reason.
--
i.
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: Crazy TCP bug (keepalive flood?) in 2.6.32?
2009-12-10 8:50 ` Ilpo Järvinen
@ 2009-12-10 10:05 ` Damian Lukowski
2009-12-10 10:24 ` Ilpo Järvinen
0 siblings, 1 reply; 24+ messages in thread
From: Damian Lukowski @ 2009-12-10 10:05 UTC (permalink / raw)
To: Ilpo Järvinen; +Cc: Denys Fedoryshchenko, Netdev
Ilpo Järvinen schrieb:
> On Thu, 10 Dec 2009, Ilpo Järvinen wrote:
>
>> On Thu, 10 Dec 2009, Ilpo Järvinen wrote:
>>
>>> Cc Damian.
>>>
>>> On Wed, 9 Dec 2009, Denys Fedoryshchenko wrote:
>>>
>>>> Hi
>>>>
>>>> I did upgrade of my lusca(squid) proxies and notice that some users getting up
>>>> to 8-15 Mbit/s flood (while they are shaped to 128Kbit/s). After tracing i end
>>>> up on one of proxies host and seems it is bug in kernel tcp stack.
>>>>
>>>> I check packets inside - it is same repeating content (and even same tcp
>>>> sequence, so it is almost sure tcp bug). Sender also ignoring ICMP unreachable
>>>> packets and continue flooding destination
By "also" you mean, that the sender is flooding with and without ICMPs?
>>>>
>>>> Here is some examples
>>>> ss output for corresponding entry
>>>>
>>>> ESTAB 0 8267 194.146.153.114:8080 172.16.67.243:2512
>>>>
>>>>
>>>> 20:32:08.491470 IP (tos 0x0, ttl 64, id 49493, offset 0, flags [DF], proto TCP
>>>> (6), length 655)
>>>> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
>>>> (correct), seq 0:615, ack 1, win 7504, length 615
>>>> 20:32:08.492487 IP (tos 0x0, ttl 64, id 49494, offset 0, flags [DF], proto TCP
>>>> (6), length 655)
>>>> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
>>>> (correct), seq 0:615, ack 1, win 7504, length 615
>>>> 20:32:08.493468 IP (tos 0x0, ttl 64, id 49495, offset 0, flags [DF], proto TCP
>>>> (6), length 655)
>>>> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
>>>> (correct), seq 0:615, ack 1, win 7504, length 615
>>>> 20:32:08.494463 IP (tos 0x0, ttl 64, id 49496, offset 0, flags [DF], proto TCP
>>>> (6), length 655)
>>>> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
>>>> (correct), seq 0:615, ack 1, win 7504, length 615
>>>> 20:32:08.495463 IP (tos 0x0, ttl 64, id 49497, offset 0, flags [DF], proto TCP
>>>> (6), length 655)
>>>> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
>>>> (correct), seq 0:615, ack 1, win 7504, length 615
>>>> 20:32:08.496467 IP (tos 0x0, ttl 64, id 49498, offset 0, flags [DF], proto TCP
>>>> (6), length 655)
>>>>
>>>>
>>>> One more
>>>> 20:36:13.310718 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
>>>> win 7469, length 1440
>>>> 20:36:13.311725 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
>>>> win 7469, length 1440
>>>> 20:36:13.312729 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
>>>> win 7469, length 1440
>>>> 20:36:13.313717 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
>>>> win 7469, length 1440
>>>> 20:36:13.314717 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
>>>> win 7469, length 1440
>>>> 20:36:13.315718 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
>>>> win 7469, length 1440
>>>> 20:36:13.316725 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
>>>> win 7469, length 1440
>>>>
>>>> I run multiple times ss
>>>>
>>>> ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
>>>> timer:(on,,172) uid:101 ino:4772596 sk:c0ce84c0
>>>> ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
>>>> timer:(on,,43) uid:101 ino:4772596 sk:c0ce84c0
>>>> ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
>>>> timer:(on,,17) uid:101 ino:4772596 sk:c0ce84c0
>>>>
>>>> After i kill squid it will switch socket to FIN-WAIT state and flood will
>>>> stop.
>>>>
>>>> Some sysctl tuning done during boot (maybe related)
>>>> sysctl -w net.ipv4.tcp_frto=2
>>>> sysctl -w net.ipv4.tcp_frto_response=2
>>>>
>>>> And most probably it is related to keepalive. I have it set on this socket:
>>>> http_port 8080 transparent tcpkeepalive=30,30,60 http11
>>>>
>>>> From manual
>>>> #<-----> tcpkeepalive[=idle,interval,timeout]
>>>> #<-----><------><------>Enable TCP keepalive probes of idle connections
>>>> #<-----><------><------>idle is the initial time before TCP starts probing
>>>> #<-----><------><------>the connection, interval how often to probe, and
>>>> #<-----><------><------>timeout the time before giving up.
>>>>
>>>> I am not able to reproduce reliably bug, but it is appearing on different
>>>> cluster pc's randomly for single connection each 5-10 minutes (around 8000
>>>> established connections to each at moment, 8 pc's in cluster) and dissapearing
>>>> after 10-50 seconds of flood.
>>> Damian, can you please take a look. ...It's a bit weird after a very brief
>>> look (as if RTO would trigger way too often). Maybe its backoff is broken
>>> now?
>> ...I meant broken when keepalives are in use.
>
> I guess it's that the ICMPs are somehow triggering the
> tcp_retransmit_timer call in tcp_ipv4 even though they're not supposed
> to do that until the RTO timeout would have fired. I've no idea why
> remaining doesn't do what it's supposed to.
>
Hm.
Those ICMPs will trigger only, if icsk_backoff and retransmits is non-zero.
If that's because of a retransmission (which was thought to be), then
packets_out is non-zero and tcp_probe_timer will return before sending anything.
Correct me, if I'm wrong here.
I'll try to think of a case, where those are non-zero with no packets_out.
Damian
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: Crazy TCP bug (keepalive flood?) in 2.6.32?
2009-12-10 8:28 ` Ilpo Järvinen
@ 2009-12-10 8:50 ` Ilpo Järvinen
2009-12-10 10:05 ` Damian Lukowski
0 siblings, 1 reply; 24+ messages in thread
From: Ilpo Järvinen @ 2009-12-10 8:50 UTC (permalink / raw)
To: Denys Fedoryshchenko, Damian Lukowski; +Cc: Netdev
[-- Attachment #1: Type: TEXT/PLAIN, Size: 5143 bytes --]
On Thu, 10 Dec 2009, Ilpo Järvinen wrote:
> On Thu, 10 Dec 2009, Ilpo Järvinen wrote:
>
> > Cc Damian.
> >
> > On Wed, 9 Dec 2009, Denys Fedoryshchenko wrote:
> >
> > > Hi
> > >
> > > I did upgrade of my lusca(squid) proxies and notice that some users getting up
> > > to 8-15 Mbit/s flood (while they are shaped to 128Kbit/s). After tracing i end
> > > up on one of proxies host and seems it is bug in kernel tcp stack.
> > >
> > > I check packets inside - it is same repeating content (and even same tcp
> > > sequence, so it is almost sure tcp bug). Sender also ignoring ICMP unreachable
> > > packets and continue flooding destination
> > >
> > > Here is some examples
> > > ss output for corresponding entry
> > >
> > > ESTAB 0 8267 194.146.153.114:8080 172.16.67.243:2512
> > >
> > >
> > > 20:32:08.491470 IP (tos 0x0, ttl 64, id 49493, offset 0, flags [DF], proto TCP
> > > (6), length 655)
> > > 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> > > (correct), seq 0:615, ack 1, win 7504, length 615
> > > 20:32:08.492487 IP (tos 0x0, ttl 64, id 49494, offset 0, flags [DF], proto TCP
> > > (6), length 655)
> > > 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> > > (correct), seq 0:615, ack 1, win 7504, length 615
> > > 20:32:08.493468 IP (tos 0x0, ttl 64, id 49495, offset 0, flags [DF], proto TCP
> > > (6), length 655)
> > > 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> > > (correct), seq 0:615, ack 1, win 7504, length 615
> > > 20:32:08.494463 IP (tos 0x0, ttl 64, id 49496, offset 0, flags [DF], proto TCP
> > > (6), length 655)
> > > 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> > > (correct), seq 0:615, ack 1, win 7504, length 615
> > > 20:32:08.495463 IP (tos 0x0, ttl 64, id 49497, offset 0, flags [DF], proto TCP
> > > (6), length 655)
> > > 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> > > (correct), seq 0:615, ack 1, win 7504, length 615
> > > 20:32:08.496467 IP (tos 0x0, ttl 64, id 49498, offset 0, flags [DF], proto TCP
> > > (6), length 655)
> > >
> > >
> > > One more
> > > 20:36:13.310718 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> > > win 7469, length 1440
> > > 20:36:13.311725 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> > > win 7469, length 1440
> > > 20:36:13.312729 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> > > win 7469, length 1440
> > > 20:36:13.313717 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> > > win 7469, length 1440
> > > 20:36:13.314717 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> > > win 7469, length 1440
> > > 20:36:13.315718 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> > > win 7469, length 1440
> > > 20:36:13.316725 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> > > win 7469, length 1440
> > >
> > > I run multiple times ss
> > >
> > > ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
> > > timer:(on,,172) uid:101 ino:4772596 sk:c0ce84c0
> > > ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
> > > timer:(on,,43) uid:101 ino:4772596 sk:c0ce84c0
> > > ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
> > > timer:(on,,17) uid:101 ino:4772596 sk:c0ce84c0
> > >
> > > After i kill squid it will switch socket to FIN-WAIT state and flood will
> > > stop.
> > >
> > > Some sysctl tuning done during boot (maybe related)
> > > sysctl -w net.ipv4.tcp_frto=2
> > > sysctl -w net.ipv4.tcp_frto_response=2
> > >
> > > And most probably it is related to keepalive. I have it set on this socket:
> > > http_port 8080 transparent tcpkeepalive=30,30,60 http11
> > >
> > > From manual
> > > #<-----> tcpkeepalive[=idle,interval,timeout]
> > > #<-----><------><------>Enable TCP keepalive probes of idle connections
> > > #<-----><------><------>idle is the initial time before TCP starts probing
> > > #<-----><------><------>the connection, interval how often to probe, and
> > > #<-----><------><------>timeout the time before giving up.
> > >
> > > I am not able to reproduce reliably bug, but it is appearing on different
> > > cluster pc's randomly for single connection each 5-10 minutes (around 8000
> > > established connections to each at moment, 8 pc's in cluster) and dissapearing
> > > after 10-50 seconds of flood.
> >
> > Damian, can you please take a look. ...It's a bit weird after a very brief
> > look (as if RTO would trigger way too often). Maybe its backoff is broken
> > now?
>
> ...I meant broken when keepalives are in use.
I guess it's that the ICMPs are somehow triggering the
tcp_retransmit_timer call in tcp_ipv4 even though they're not supposed
to do that until the RTO timeout would have fired. I've no idea why
remaining doesn't do what it's supposed to.
--
i.
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: Crazy TCP bug (keepalive flood?) in 2.6.32?
2009-12-10 8:24 ` Ilpo Järvinen
@ 2009-12-10 8:28 ` Ilpo Järvinen
2009-12-10 8:50 ` Ilpo Järvinen
0 siblings, 1 reply; 24+ messages in thread
From: Ilpo Järvinen @ 2009-12-10 8:28 UTC (permalink / raw)
To: Denys Fedoryshchenko, Damian Lukowski; +Cc: Netdev
[-- Attachment #1: Type: TEXT/PLAIN, Size: 4662 bytes --]
On Thu, 10 Dec 2009, Ilpo Järvinen wrote:
> Cc Damian.
>
> On Wed, 9 Dec 2009, Denys Fedoryshchenko wrote:
>
> > Hi
> >
> > I did upgrade of my lusca(squid) proxies and notice that some users getting up
> > to 8-15 Mbit/s flood (while they are shaped to 128Kbit/s). After tracing i end
> > up on one of proxies host and seems it is bug in kernel tcp stack.
> >
> > I check packets inside - it is same repeating content (and even same tcp
> > sequence, so it is almost sure tcp bug). Sender also ignoring ICMP unreachable
> > packets and continue flooding destination
> >
> > Here is some examples
> > ss output for corresponding entry
> >
> > ESTAB 0 8267 194.146.153.114:8080 172.16.67.243:2512
> >
> >
> > 20:32:08.491470 IP (tos 0x0, ttl 64, id 49493, offset 0, flags [DF], proto TCP
> > (6), length 655)
> > 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> > (correct), seq 0:615, ack 1, win 7504, length 615
> > 20:32:08.492487 IP (tos 0x0, ttl 64, id 49494, offset 0, flags [DF], proto TCP
> > (6), length 655)
> > 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> > (correct), seq 0:615, ack 1, win 7504, length 615
> > 20:32:08.493468 IP (tos 0x0, ttl 64, id 49495, offset 0, flags [DF], proto TCP
> > (6), length 655)
> > 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> > (correct), seq 0:615, ack 1, win 7504, length 615
> > 20:32:08.494463 IP (tos 0x0, ttl 64, id 49496, offset 0, flags [DF], proto TCP
> > (6), length 655)
> > 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> > (correct), seq 0:615, ack 1, win 7504, length 615
> > 20:32:08.495463 IP (tos 0x0, ttl 64, id 49497, offset 0, flags [DF], proto TCP
> > (6), length 655)
> > 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> > (correct), seq 0:615, ack 1, win 7504, length 615
> > 20:32:08.496467 IP (tos 0x0, ttl 64, id 49498, offset 0, flags [DF], proto TCP
> > (6), length 655)
> >
> >
> > One more
> > 20:36:13.310718 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> > win 7469, length 1440
> > 20:36:13.311725 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> > win 7469, length 1440
> > 20:36:13.312729 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> > win 7469, length 1440
> > 20:36:13.313717 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> > win 7469, length 1440
> > 20:36:13.314717 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> > win 7469, length 1440
> > 20:36:13.315718 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> > win 7469, length 1440
> > 20:36:13.316725 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> > win 7469, length 1440
> >
> > I run multiple times ss
> >
> > ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
> > timer:(on,,172) uid:101 ino:4772596 sk:c0ce84c0
> > ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
> > timer:(on,,43) uid:101 ino:4772596 sk:c0ce84c0
> > ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
> > timer:(on,,17) uid:101 ino:4772596 sk:c0ce84c0
> >
> > After i kill squid it will switch socket to FIN-WAIT state and flood will
> > stop.
> >
> > Some sysctl tuning done during boot (maybe related)
> > sysctl -w net.ipv4.tcp_frto=2
> > sysctl -w net.ipv4.tcp_frto_response=2
> >
> > And most probably it is related to keepalive. I have it set on this socket:
> > http_port 8080 transparent tcpkeepalive=30,30,60 http11
> >
> > From manual
> > #<-----> tcpkeepalive[=idle,interval,timeout]
> > #<-----><------><------>Enable TCP keepalive probes of idle connections
> > #<-----><------><------>idle is the initial time before TCP starts probing
> > #<-----><------><------>the connection, interval how often to probe, and
> > #<-----><------><------>timeout the time before giving up.
> >
> > I am not able to reproduce reliably bug, but it is appearing on different
> > cluster pc's randomly for single connection each 5-10 minutes (around 8000
> > established connections to each at moment, 8 pc's in cluster) and dissapearing
> > after 10-50 seconds of flood.
>
> Damian, can you please take a look. ...It's a bit weird after a very brief
> look (as if RTO would trigger way too often). Maybe its backoff is broken
> now?
...I meant broken when keepalives are in use.
--
i.
^ permalink raw reply [flat|nested] 24+ messages in thread
* Re: Crazy TCP bug (keepalive flood?) in 2.6.32?
2009-12-09 18:51 Crazy TCP bug (keepalive flood?) in 2.6.32? Denys Fedoryshchenko
@ 2009-12-10 8:24 ` Ilpo Järvinen
2009-12-10 8:28 ` Ilpo Järvinen
0 siblings, 1 reply; 24+ messages in thread
From: Ilpo Järvinen @ 2009-12-10 8:24 UTC (permalink / raw)
To: Denys Fedoryshchenko, Damian Lukowski; +Cc: Netdev
Cc Damian.
On Wed, 9 Dec 2009, Denys Fedoryshchenko wrote:
> Hi
>
> I did upgrade of my lusca(squid) proxies and notice that some users getting up
> to 8-15 Mbit/s flood (while they are shaped to 128Kbit/s). After tracing i end
> up on one of proxies host and seems it is bug in kernel tcp stack.
>
> I check packets inside - it is same repeating content (and even same tcp
> sequence, so it is almost sure tcp bug). Sender also ignoring ICMP unreachable
> packets and continue flooding destination
>
> Here is some examples
> ss output for corresponding entry
>
> ESTAB 0 8267 194.146.153.114:8080 172.16.67.243:2512
>
>
> 20:32:08.491470 IP (tos 0x0, ttl 64, id 49493, offset 0, flags [DF], proto TCP
> (6), length 655)
> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> (correct), seq 0:615, ack 1, win 7504, length 615
> 20:32:08.492487 IP (tos 0x0, ttl 64, id 49494, offset 0, flags [DF], proto TCP
> (6), length 655)
> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> (correct), seq 0:615, ack 1, win 7504, length 615
> 20:32:08.493468 IP (tos 0x0, ttl 64, id 49495, offset 0, flags [DF], proto TCP
> (6), length 655)
> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> (correct), seq 0:615, ack 1, win 7504, length 615
> 20:32:08.494463 IP (tos 0x0, ttl 64, id 49496, offset 0, flags [DF], proto TCP
> (6), length 655)
> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> (correct), seq 0:615, ack 1, win 7504, length 615
> 20:32:08.495463 IP (tos 0x0, ttl 64, id 49497, offset 0, flags [DF], proto TCP
> (6), length 655)
> 194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
> (correct), seq 0:615, ack 1, win 7504, length 615
> 20:32:08.496467 IP (tos 0x0, ttl 64, id 49498, offset 0, flags [DF], proto TCP
> (6), length 655)
>
>
> One more
> 20:36:13.310718 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> win 7469, length 1440
> 20:36:13.311725 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> win 7469, length 1440
> 20:36:13.312729 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> win 7469, length 1440
> 20:36:13.313717 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> win 7469, length 1440
> 20:36:13.314717 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> win 7469, length 1440
> 20:36:13.315718 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> win 7469, length 1440
> 20:36:13.316725 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
> win 7469, length 1440
>
> I run multiple times ss
>
> ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
> timer:(on,,172) uid:101 ino:4772596 sk:c0ce84c0
> ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
> timer:(on,,43) uid:101 ino:4772596 sk:c0ce84c0
> ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
> timer:(on,,17) uid:101 ino:4772596 sk:c0ce84c0
>
> After i kill squid it will switch socket to FIN-WAIT state and flood will
> stop.
>
> Some sysctl tuning done during boot (maybe related)
> sysctl -w net.ipv4.tcp_frto=2
> sysctl -w net.ipv4.tcp_frto_response=2
>
> And most probably it is related to keepalive. I have it set on this socket:
> http_port 8080 transparent tcpkeepalive=30,30,60 http11
>
> From manual
> #<-----> tcpkeepalive[=idle,interval,timeout]
> #<-----><------><------>Enable TCP keepalive probes of idle connections
> #<-----><------><------>idle is the initial time before TCP starts probing
> #<-----><------><------>the connection, interval how often to probe, and
> #<-----><------><------>timeout the time before giving up.
>
> I am not able to reproduce reliably bug, but it is appearing on different
> cluster pc's randomly for single connection each 5-10 minutes (around 8000
> established connections to each at moment, 8 pc's in cluster) and dissapearing
> after 10-50 seconds of flood.
Damian, can you please take a look. ...It's a bit weird after a very brief
look (as if RTO would trigger way too often). Maybe its backoff is broken
now?
--
i.
^ permalink raw reply [flat|nested] 24+ messages in thread
* Crazy TCP bug (keepalive flood?) in 2.6.32?
@ 2009-12-09 18:51 Denys Fedoryshchenko
2009-12-10 8:24 ` Ilpo Järvinen
0 siblings, 1 reply; 24+ messages in thread
From: Denys Fedoryshchenko @ 2009-12-09 18:51 UTC (permalink / raw)
To: netdev
Hi
I did upgrade of my lusca(squid) proxies and notice that some users getting up
to 8-15 Mbit/s flood (while they are shaped to 128Kbit/s). After tracing i end
up on one of proxies host and seems it is bug in kernel tcp stack.
I check packets inside - it is same repeating content (and even same tcp
sequence, so it is almost sure tcp bug). Sender also ignoring ICMP unreachable
packets and continue flooding destination
Here is some examples
ss output for corresponding entry
ESTAB 0 8267 194.146.153.114:8080 172.16.67.243:2512
20:32:08.491470 IP (tos 0x0, ttl 64, id 49493, offset 0, flags [DF], proto TCP
(6), length 655)
194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
(correct), seq 0:615, ack 1, win 7504, length 615
20:32:08.492487 IP (tos 0x0, ttl 64, id 49494, offset 0, flags [DF], proto TCP
(6), length 655)
194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
(correct), seq 0:615, ack 1, win 7504, length 615
20:32:08.493468 IP (tos 0x0, ttl 64, id 49495, offset 0, flags [DF], proto TCP
(6), length 655)
194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
(correct), seq 0:615, ack 1, win 7504, length 615
20:32:08.494463 IP (tos 0x0, ttl 64, id 49496, offset 0, flags [DF], proto TCP
(6), length 655)
194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
(correct), seq 0:615, ack 1, win 7504, length 615
20:32:08.495463 IP (tos 0x0, ttl 64, id 49497, offset 0, flags [DF], proto TCP
(6), length 655)
194.146.153.114.8080 > 172.16.67.243.2512: Flags [P.], cksum 0xce63
(correct), seq 0:615, ack 1, win 7504, length 615
20:32:08.496467 IP (tos 0x0, ttl 64, id 49498, offset 0, flags [DF], proto TCP
(6), length 655)
One more
20:36:13.310718 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
win 7469, length 1440
20:36:13.311725 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
win 7469, length 1440
20:36:13.312729 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
win 7469, length 1440
20:36:13.313717 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
win 7469, length 1440
20:36:13.314717 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
win 7469, length 1440
20:36:13.315718 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
win 7469, length 1440
20:36:13.316725 IP 194.146.153.114.8080 > 172.16.49.30.1319: Flags [.], ack 1,
win 7469, length 1440
I run multiple times ss
ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
timer:(on,,172) uid:101 ino:4772596 sk:c0ce84c0
ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
timer:(on,,43) uid:101 ino:4772596 sk:c0ce84c0
ESTAB 0 7730 194.146.153.114:8080 172.16.49.30:1319
timer:(on,,17) uid:101 ino:4772596 sk:c0ce84c0
After i kill squid it will switch socket to FIN-WAIT state and flood will
stop.
Some sysctl tuning done during boot (maybe related)
sysctl -w net.ipv4.tcp_frto=2
sysctl -w net.ipv4.tcp_frto_response=2
And most probably it is related to keepalive. I have it set on this socket:
http_port 8080 transparent tcpkeepalive=30,30,60 http11
>From manual
#<-----> tcpkeepalive[=idle,interval,timeout]
#<-----><------><------>Enable TCP keepalive probes of idle connections
#<-----><------><------>idle is the initial time before TCP starts probing
#<-----><------><------>the connection, interval how often to probe, and
#<-----><------><------>timeout the time before giving up.
I am not able to reproduce reliably bug, but it is appearing on different
cluster pc's randomly for single connection each 5-10 minutes (around 8000
established connections to each at moment, 8 pc's in cluster) and dissapearing
after 10-50 seconds of flood.
^ permalink raw reply [flat|nested] 24+ messages in thread
end of thread, other threads:[~2010-01-27 15:15 UTC | newest]
Thread overview: 24+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2009-12-26 15:03 Crazy TCP bug (keepalive flood?) in 2.6.32? Denys Fedoryshchenko
2009-12-26 19:24 ` Ilpo Järvinen
2010-01-11 13:02 ` Ilpo Järvinen
2010-01-16 14:12 ` Denys Fedoryshchenko
2010-01-19 9:10 ` Damian Lukowski
2010-01-19 11:09 ` Denys Fedoryshchenko
2010-01-19 11:17 ` Ilpo Järvinen
2010-01-23 21:37 ` Denys Fedoryshchenko
2010-01-23 22:34 ` [PATCH] tcp: fix ICMP-RTO war Ilpo Järvinen
2010-01-23 22:45 ` Denys Fedoryshchenko
2010-01-25 15:07 ` Damian Lukowski
2010-01-26 7:45 ` David Miller
2010-01-27 12:41 ` Ilpo Järvinen
2010-01-27 14:14 ` Alexey Kuznetsov
2010-01-23 23:28 ` Denys Fedoryshchenko
2010-01-25 12:12 ` Damian Lukowski
2010-01-27 12:36 ` Ilpo Järvinen
-- strict thread matches above, loose matches on Subject: below --
2009-12-09 18:51 Crazy TCP bug (keepalive flood?) in 2.6.32? Denys Fedoryshchenko
2009-12-10 8:24 ` Ilpo Järvinen
2009-12-10 8:28 ` Ilpo Järvinen
2009-12-10 8:50 ` Ilpo Järvinen
2009-12-10 10:05 ` Damian Lukowski
2009-12-10 10:24 ` Ilpo Järvinen
2009-12-26 14:54 ` Denys Fedoryshchenko
This is an external index of several public inboxes,
see mirroring instructions on how to clone and mirror
all data and code used by this external index.