On Sun, Sep 10, 2017 at 4:53 PM, Oleksandr Natalenko
[off-list ref] wrote:
Hello.
Since, IIRC, v4.11, there is some regression in TCP stack resulting in the
warning shown below. Most of the time it is harmless, but rarely it just
causes either freeze or (I believe, this is related too) panic in
tcp_sacktag_walk() (because sk_buff passed to this function is NULL).
Unfortunately, I still do not have proper stacktrace from panic, but will try
to capture it if possible.
...
[14407.060066] ------------[ cut here ]------------
[14407.060353] WARNING: CPU: 0 PID: 719 at net/ipv4/tcp_input.c:2826
tcp_fastretrans_alert+0x7c8/0x990
...
2823 /* D. Check state exit conditions. State can be terminated
2824 * when high_seq is ACKed. */
2825 if (icsk->icsk_ca_state == TCP_CA_Open) {
2826 WARN_ON(tp->retrans_out != 0); // here
2827 tp->retrans_stamp = 0;
Thanks for the detailed report!
I suspect this is due to the following commit, which happened between
4.10 and 4.11:
89fe18e44f7e tcp: extend F-RTO to catch more spurious timeouts
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?id=89fe18e44f7e
This commit expanded the set of scenarios where we would undo a
CA_Loss cwnd reduction and return to TCP_CA_Open, but did not include
a check to see if there were any in-flight retransmissions. I think we
need a fix like the following:
bool frto_undo)
{
struct tcp_sock *tp = tcp_sk(sk);
- if (frto_undo || tcp_may_undo(tp)) {
+ if ((frto_undo || tcp_may_undo(tp)) && !tp->retrans_out) {
tcp_undo_cwnd_reduction(sk, true);
DBGUNDO(sk, "partial loss");
I will try a packetdrill test to see if I can reproduce this issue and
verify the fix.
thanks,
neal
Hi.
I've applied your test patch but it doesn't fix the issue for me since the
warning is still there.
Were you able to reproduce it?
On pondělí 11. září 2017 1:59:02 CEST Neal Cardwell wrote:
quoted hunk
Thanks for the detailed report!
I suspect this is due to the following commit, which happened between
4.10 and 4.11:
89fe18e44f7e tcp: extend F-RTO to catch more spurious timeouts
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/commit/?
id=89fe18e44f7e
This commit expanded the set of scenarios where we would undo a
CA_Loss cwnd reduction and return to TCP_CA_Open, but did not include
a check to see if there were any in-flight retransmissions. I think we
need a fix like the following:
bool frto_undo)
{
struct tcp_sock *tp = tcp_sk(sk);
- if (frto_undo || tcp_may_undo(tp)) {
+ if ((frto_undo || tcp_may_undo(tp)) && !tp->retrans_out) {
tcp_undo_cwnd_reduction(sk, true);
DBGUNDO(sk, "partial loss");
I will try a packetdrill test to see if I can reproduce this issue and
verify the fix.
thanks,
neal
On Fri, Sep 15, 2017 at 1:03 AM, Oleksandr Natalenko
[off-list ref] wrote:
Hi.
I've applied your test patch but it doesn't fix the issue for me since the
warning is still there.
Were you able to reproduce it?
Hi,
Thanks for testing that. That is a very useful data point.
I was able to cook up a packetdrill test that could put the connection
in CA_Disorder with retransmitted packets out, but not in CA_Open. So
we do not yet have a test case to reproduce this.
We do not see this warning on our fleet at Google. One significant
difference I see between our environment and yours is that it seems
you run with FACK enabled:
net.ipv4.tcp_fack = 1
Note that FACK was disabled by default (since it was replaced by RACK)
between kernel v4.10 and v4.11. And this is exactly the time when this
bug started manifesting itself for you and some others, but not our
fleet. So my new working hypothesis would be that this warning is due
to a behavior that only shows up in kernels >=4.11 when FACK is
enabled.
Would you be able to disable FACK ("sysctl net.ipv4.tcp_fack=0" at
boot, or net.ipv4.tcp_fack=0 in /etc/sysctl.conf, or equivalent),
reboot, and test the kernel for a few days to see if the warning still
pops up?
thanks,
neal
[ps: apologies for the previous, mis-formatted post...]
Hello.
With net.ipv4.tcp_fack set to 0 the warning still appears:
===
» sysctl net.ipv4.tcp_fack
net.ipv4.tcp_fack = 0
» LC_TIME=C dmesg -T | grep WARNING
[Fri Sep 15 20:40:30 2017] WARNING: CPU: 1 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
[Fri Sep 15 20:40:30 2017] WARNING: CPU: 0 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
[Fri Sep 15 20:48:37 2017] WARNING: CPU: 1 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
[Fri Sep 15 20:48:55 2017] WARNING: CPU: 0 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
» ps -up 711
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 711 4.3 0.0 0 0 ? S 18:12 7:23 [irq/123-
enp3s0]
===
Any suggestions?
On pátek 15. září 2017 16:03:00 CEST Neal Cardwell wrote:
Thanks for testing that. That is a very useful data point.
I was able to cook up a packetdrill test that could put the connection
in CA_Disorder with retransmitted packets out, but not in CA_Open. So
we do not yet have a test case to reproduce this.
We do not see this warning on our fleet at Google. One significant
difference I see between our environment and yours is that it seems
you run with FACK enabled:
net.ipv4.tcp_fack = 1
Note that FACK was disabled by default (since it was replaced by RACK)
between kernel v4.10 and v4.11. And this is exactly the time when this
bug started manifesting itself for you and some others, but not our
fleet. So my new working hypothesis would be that this warning is due
to a behavior that only shows up in kernels >=4.11 when FACK is
enabled.
Would you be able to disable FACK ("sysctl net.ipv4.tcp_fack=0" at
boot, or net.ipv4.tcp_fack=0 in /etc/sysctl.conf, or equivalent),
reboot, and test the kernel for a few days to see if the warning still
pops up?
thanks,
neal
[ps: apologies for the previous, mis-formatted post...]
Hi.
Just to note that it looks like disabling RACK and re-enabling FACK prevents
warning from happening:
net.ipv4.tcp_fack = 1
net.ipv4.tcp_recovery = 0
Hope I get semantics of these tunables right.
On pátek 15. září 2017 21:04:36 CEST Oleksandr Natalenko wrote:
Hello.
With net.ipv4.tcp_fack set to 0 the warning still appears:
===
» sysctl net.ipv4.tcp_fack
net.ipv4.tcp_fack = 0
» LC_TIME=C dmesg -T | grep WARNING
[Fri Sep 15 20:40:30 2017] WARNING: CPU: 1 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
[Fri Sep 15 20:40:30 2017] WARNING: CPU: 0 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
[Fri Sep 15 20:48:37 2017] WARNING: CPU: 1 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
[Fri Sep 15 20:48:55 2017] WARNING: CPU: 0 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
» ps -up 711
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 711 4.3 0.0 0 0 ? S 18:12 7:23 [irq/123-
enp3s0]
===
Any suggestions?
On pátek 15. září 2017 16:03:00 CEST Neal Cardwell wrote:
quoted
Thanks for testing that. That is a very useful data point.
I was able to cook up a packetdrill test that could put the connection
in CA_Disorder with retransmitted packets out, but not in CA_Open. So
we do not yet have a test case to reproduce this.
We do not see this warning on our fleet at Google. One significant
difference I see between our environment and yours is that it seems
you run with FACK enabled:
net.ipv4.tcp_fack = 1
Note that FACK was disabled by default (since it was replaced by RACK)
between kernel v4.10 and v4.11. And this is exactly the time when this
bug started manifesting itself for you and some others, but not our
fleet. So my new working hypothesis would be that this warning is due
to a behavior that only shows up in kernels >=4.11 when FACK is
enabled.
Would you be able to disable FACK ("sysctl net.ipv4.tcp_fack=0" at
boot, or net.ipv4.tcp_fack=0 in /etc/sysctl.conf, or equivalent),
reboot, and test the kernel for a few days to see if the warning still
pops up?
thanks,
neal
[ps: apologies for the previous, mis-formatted post...]
On Sun, Sep 17, 2017 at 11:43 AM, Oleksandr Natalenko
[off-list ref] wrote:
Hi.
Just to note that it looks like disabling RACK and re-enabling FACK prevents
warning from happening:
net.ipv4.tcp_fack = 1
net.ipv4.tcp_recovery = 0
Hope I get semantics of these tunables right.
Thanks.
One difference between RACK and FACK is that RACK can detect lost
retransmission in CA_Recovery (fast recovery) and CA_Loss (post RTO)
mode, while the current FACK can not. A previous FACK version can also
detect lost retransmission in CA_recovery with limited-transmit. I
suspect it is RACK's special ability that triggers this warning.
IMO, however, this warning itself is questionably valid: with undo
(TCP Eifel), the sender can detect and revert a false CA_Recovery /
CA_Loss to CA_Open, with spurious retransmission in-flight
(tp->retrans_out > 0). Then another SACK after undo triggers this
warning. Neal and I are not sure if this is causing the panics you're
seeing, but personally I'd argue this warning is false, or at least
should be revised to skip undo case.
On pátek 15. září 2017 21:04:36 CEST Oleksandr Natalenko wrote:
quoted
Hello.
With net.ipv4.tcp_fack set to 0 the warning still appears:
===
» sysctl net.ipv4.tcp_fack
net.ipv4.tcp_fack = 0
» LC_TIME=C dmesg -T | grep WARNING
[Fri Sep 15 20:40:30 2017] WARNING: CPU: 1 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
[Fri Sep 15 20:40:30 2017] WARNING: CPU: 0 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
[Fri Sep 15 20:48:37 2017] WARNING: CPU: 1 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
[Fri Sep 15 20:48:55 2017] WARNING: CPU: 0 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
» ps -up 711
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 711 4.3 0.0 0 0 ? S 18:12 7:23 [irq/123-
enp3s0]
===
Any suggestions?
On pátek 15. září 2017 16:03:00 CEST Neal Cardwell wrote:
quoted
Thanks for testing that. That is a very useful data point.
I was able to cook up a packetdrill test that could put the connection
in CA_Disorder with retransmitted packets out, but not in CA_Open. So
we do not yet have a test case to reproduce this.
We do not see this warning on our fleet at Google. One significant
difference I see between our environment and yours is that it seems
you run with FACK enabled:
net.ipv4.tcp_fack = 1
Note that FACK was disabled by default (since it was replaced by RACK)
between kernel v4.10 and v4.11. And this is exactly the time when this
bug started manifesting itself for you and some others, but not our
fleet. So my new working hypothesis would be that this warning is due
to a behavior that only shows up in kernels >=4.11 when FACK is
enabled.
Would you be able to disable FACK ("sysctl net.ipv4.tcp_fack=0" at
boot, or net.ipv4.tcp_fack=0 in /etc/sysctl.conf, or equivalent),
reboot, and test the kernel for a few days to see if the warning still
pops up?
thanks,
neal
[ps: apologies for the previous, mis-formatted post...]
On Mon, Sep 18, 2017 at 10:18 AM, Yuchung Cheng [off-list ref] wrote:
On Sun, Sep 17, 2017 at 11:43 AM, Oleksandr Natalenko
[off-list ref] wrote:
quoted
Hi.
Just to note that it looks like disabling RACK and re-enabling FACK prevents
warning from happening:
net.ipv4.tcp_fack = 1
net.ipv4.tcp_recovery = 0
Hope I get semantics of these tunables right.
Thanks.
One difference between RACK and FACK is that RACK can detect lost
retransmission in CA_Recovery (fast recovery) and CA_Loss (post RTO)
mode, while the current FACK can not. A previous FACK version can also
detect lost retransmission in CA_recovery with limited-transmit. I
suspect it is RACK's special ability that triggers this warning.
IMO, however, this warning itself is questionably valid: with undo
(TCP Eifel), the sender can detect and revert a false CA_Recovery /
CA_Loss to CA_Open, with spurious retransmission in-flight
(tp->retrans_out > 0). Then another SACK after undo triggers this
warning. Neal and I are not sure if this is causing the panics you're
seeing, but personally I'd argue this warning is false, or at least
should be revised to skip undo case.
Can you try this patch to verify my theory with tcp_recovery=0 and 1? thanks
On pátek 15. září 2017 21:04:36 CEST Oleksandr Natalenko wrote:
quoted
Hello.
With net.ipv4.tcp_fack set to 0 the warning still appears:
===
» sysctl net.ipv4.tcp_fack
net.ipv4.tcp_fack = 0
» LC_TIME=C dmesg -T | grep WARNING
[Fri Sep 15 20:40:30 2017] WARNING: CPU: 1 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
[Fri Sep 15 20:40:30 2017] WARNING: CPU: 0 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
[Fri Sep 15 20:48:37 2017] WARNING: CPU: 1 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
[Fri Sep 15 20:48:55 2017] WARNING: CPU: 0 PID: 711 at net/ipv4/tcp_input.c:
2826 tcp_fastretrans_alert+0x7c8/0x990
» ps -up 711
USER PID %CPU %MEM VSZ RSS TTY STAT START TIME COMMAND
root 711 4.3 0.0 0 0 ? S 18:12 7:23 [irq/123-
enp3s0]
===
Any suggestions?
On pátek 15. září 2017 16:03:00 CEST Neal Cardwell wrote:
quoted
Thanks for testing that. That is a very useful data point.
I was able to cook up a packetdrill test that could put the connection
in CA_Disorder with retransmitted packets out, but not in CA_Open. So
we do not yet have a test case to reproduce this.
We do not see this warning on our fleet at Google. One significant
difference I see between our environment and yours is that it seems
you run with FACK enabled:
net.ipv4.tcp_fack = 1
Note that FACK was disabled by default (since it was replaced by RACK)
between kernel v4.10 and v4.11. And this is exactly the time when this
bug started manifesting itself for you and some others, but not our
fleet. So my new working hypothesis would be that this warning is due
to a behavior that only shows up in kernels >=4.11 when FACK is
enabled.
Would you be able to disable FACK ("sysctl net.ipv4.tcp_fack=0" at
boot, or net.ipv4.tcp_fack=0 in /etc/sysctl.conf, or equivalent),
reboot, and test the kernel for a few days to see if the warning still
pops up?
thanks,
neal
[ps: apologies for the previous, mis-formatted post...]
On Mon, Sep 18, 2017 at 10:59 AM, Oleksandr Natalenko
[off-list ref] wrote:
OK. Should I keep FACK disabled?
Yes since it is disabled in the upstream by default. Although you can
experiment FACK enabled additionally.
Do we know the crash you first experienced is tied to this issue?
On pondělí 18. září 2017 19:51:21 CEST Yuchung Cheng wrote:
quoted
Can you try this patch to verify my theory with tcp_recovery=0 and 1? thanks
On Mon, Sep 18, 2017 at 10:59 AM, Oleksandr Natalenko
[off-list ref] wrote:
quoted
OK. Should I keep FACK disabled?
Yes since it is disabled in the upstream by default. Although you can
experiment FACK enabled additionally.
Do we know the crash you first experienced is tied to this issue?
quoted
On pondělí 18. září 2017 19:51:21 CEST Yuchung Cheng wrote:
quoted
Can you try this patch to verify my theory with tcp_recovery=0 and 1?
thanks
On Mon, Sep 18, 2017 at 10:59 AM, Oleksandr Natalenko
[off-list ref] wrote:
quoted
OK. Should I keep FACK disabled?
Yes since it is disabled in the upstream by default. Although you can
experiment FACK enabled additionally.
Do we know the crash you first experienced is tied to this issue?
quoted
On pondělí 18. září 2017 19:51:21 CEST Yuchung Cheng wrote:
quoted
Can you try this patch to verify my theory with tcp_recovery=0 and 1?
thanks
On Mon, Sep 18, 2017 at 1:46 PM, Oleksandr Natalenko
[off-list ref] wrote:
Actually, same warning was just triggered with RACK enabled. But main warning
was not triggered in this case.
Thanks.
I assume this kernel does not have the patch that Neal proposed in his
first reply?
The main warning needs to be triggered by another peculiar SACK that
kicks the sender into recovery again (after undo). Please let it run
longer if possible to see if we can get both. But the new data does
indicate the we can (validly) be in CA_Open with retrans_out > 0.
On Mon, Sep 18, 2017 at 10:59 AM, Oleksandr Natalenko
[off-list ref] wrote:
quoted
OK. Should I keep FACK disabled?
Yes since it is disabled in the upstream by default. Although you can
experiment FACK enabled additionally.
Do we know the crash you first experienced is tied to this issue?
quoted
On pondělí 18. září 2017 19:51:21 CEST Yuchung Cheng wrote:
quoted
Can you try this patch to verify my theory with tcp_recovery=0 and 1?
thanks
I assume this kernel does not have the patch that Neal proposed in his
first reply?
Correct.
The main warning needs to be triggered by another peculiar SACK that
kicks the sender into recovery again (after undo). Please let it run
longer if possible to see if we can get both. But the new data does
indicate the we can (validly) be in CA_Open with retrans_out > 0.
OK, here it is:
===
» LC_TIME=C jctl -kb | grep RIP
…
Sep 19 12:54:03 defiant kernel: RIP:
0010:tcp_undo_cwnd_reduction+0xbd/0xd0
Sep 19 12:54:22 defiant kernel: RIP:
0010:tcp_undo_cwnd_reduction+0xbd/0xd0
Sep 19 12:54:25 defiant kernel: RIP:
0010:tcp_undo_cwnd_reduction+0xbd/0xd0
Sep 19 12:56:00 defiant kernel: RIP:
0010:tcp_fastretrans_alert+0x7c8/0x990
Sep 19 12:57:07 defiant kernel: RIP:
0010:tcp_undo_cwnd_reduction+0xbd/0xd0
Sep 19 12:57:14 defiant kernel: RIP:
0010:tcp_undo_cwnd_reduction+0xbd/0xd0
Sep 19 12:58:04 defiant kernel: RIP:
0010:tcp_undo_cwnd_reduction+0xbd/0xd0
…
===
Note timestamps — two types of warning are distant in time, so didn't
happen at once.
While still running this kernel, anything else I can check for you?
And 2 more events:
===
$ dmesg --time-format iso | grep RIP
…
2017-09-19T16:52:21,623328+0200 RIP: 0010:tcp_undo_cwnd_reduction+0xbd/0xd0
2017-09-19T16:52:40,455296+0200 RIP: 0010:tcp_fastretrans_alert+0x7c8/0x990
2017-09-19T16:52:41,047378+0200 RIP: 0010:tcp_undo_cwnd_reduction+0xbd/0xd0
…
2017-09-19T16:54:59,930726+0200 RIP: 0010:tcp_undo_cwnd_reduction+0xbd/0xd0
2017-09-19T16:55:07,985767+0200 RIP: 0010:tcp_fastretrans_alert+0x7c8/0x990
2017-09-19T16:55:41,911527+0200 RIP: 0010:tcp_undo_cwnd_reduction+0xbd/0xd0
…
===
On pondělí 18. září 2017 23:40:08 CEST Yuchung Cheng wrote:
On Mon, Sep 18, 2017 at 1:46 PM, Oleksandr Natalenko
[off-list ref] wrote:
quoted
Actually, same warning was just triggered with RACK enabled. But main
warning was not triggered in this case.
Thanks.
I assume this kernel does not have the patch that Neal proposed in his
first reply?
The main warning needs to be triggered by another peculiar SACK that
kicks the sender into recovery again (after undo). Please let it run
longer if possible to see if we can get both. But the new data does
indicate the we can (validly) be in CA_Open with retrans_out > 0.
On Mon, Sep 18, 2017 at 10:59 AM, Oleksandr Natalenko
[off-list ref] wrote:
quoted
OK. Should I keep FACK disabled?
Yes since it is disabled in the upstream by default. Although you can
experiment FACK enabled additionally.
Do we know the crash you first experienced is tied to this issue?
quoted
On pondělí 18. září 2017 19:51:21 CEST Yuchung Cheng wrote:
quoted
Can you try this patch to verify my theory with tcp_recovery=0 and 1?
thanks
On Tue, Sep 19, 2017 at 4:04 AM, Oleksandr Natalenko
[off-list ref] wrote:
Hi.
18.09.2017 23:40, Yuchung Cheng wrote:
quoted
I assume this kernel does not have the patch that Neal proposed in his
first reply?
Correct.
quoted
The main warning needs to be triggered by another peculiar SACK that
kicks the sender into recovery again (after undo). Please let it run
longer if possible to see if we can get both. But the new data does
indicate the we can (validly) be in CA_Open with retrans_out > 0.
OK, here it is:
===
» LC_TIME=C jctl -kb | grep RIP
…
Sep 19 12:54:03 defiant kernel: RIP: 0010:tcp_undo_cwnd_reduction+0xbd/0xd0
Sep 19 12:54:22 defiant kernel: RIP: 0010:tcp_undo_cwnd_reduction+0xbd/0xd0
Sep 19 12:54:25 defiant kernel: RIP: 0010:tcp_undo_cwnd_reduction+0xbd/0xd0
Sep 19 12:56:00 defiant kernel: RIP: 0010:tcp_fastretrans_alert+0x7c8/0x990
Sep 19 12:57:07 defiant kernel: RIP: 0010:tcp_undo_cwnd_reduction+0xbd/0xd0
Sep 19 12:57:14 defiant kernel: RIP: 0010:tcp_undo_cwnd_reduction+0xbd/0xd0
Sep 19 12:58:04 defiant kernel: RIP: 0010:tcp_undo_cwnd_reduction+0xbd/0xd0
…
===
Note timestamps — two types of warning are distant in time, so didn't happen
at once.
While still running this kernel, anything else I can check for you?
Thanks. Based on all the experiments you did I believe there's other
code path than my hypothesis that'd cause the warning:
1) Neal's proposed F-RTO fix didn't work
2) the main warning is not being triggered together with the newly-instrumented
warning in undo
3) Disabling RACK stopped the warning
We couldn't figure out exactly what. So we'll do a bit code auditing
first to find more suspects