Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
Uhh, sorry, just found the original submission [1]. [1] https://marc.info/?l=linux-netdev&m=151009763926816&w=2 10.11.2017 14:15, Oleksandr Natalenko wrote: Hi. I'm running the machine with this patch applied for 7 hours now, and the warning hasn't appeared yet. Typically, it should be there within the first hour. I'll keep an eye on it for a longer time, but as of now it looks good. Some explanation on this please? Thanks! 06.11.2017 23:27, Yuchung Cheng wrote: ...snip... hi guys can you try if the warning goes away w/ this quick fix? diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c index 0ada8bfc2ebd..072aab2a8226 100644 --- a/net/ipv4/tcp_input.c +++ b/net/ipv4/tcp_input.c @@ -2626,7 +2626,7 @@ void tcp_simple_retransmit(struct sock *sk) tcp_clear_retrans_hints_partial(tp); - if (prior_lost == tp->lost_out) + if (!tp->lost_out) return; if (tcp_is_reno(tp)) ...snip...
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
Hi. I'm running the machine with this patch applied for 7 hours now, and the warning hasn't appeared yet. Typically, it should be there within the first hour. I'll keep an eye on it for a longer time, but as of now it looks good. Some explanation on this please? Thanks! 06.11.2017 23:27, Yuchung Cheng wrote: ...snip... hi guys can you try if the warning goes away w/ this quick fix? diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c index 0ada8bfc2ebd..072aab2a8226 100644 --- a/net/ipv4/tcp_input.c +++ b/net/ipv4/tcp_input.c @@ -2626,7 +2626,7 @@ void tcp_simple_retransmit(struct sock *sk) tcp_clear_retrans_hints_partial(tp); - if (prior_lost == tp->lost_out) + if (!tp->lost_out) return; if (tcp_is_reno(tp)) ...snip...
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Fri, Oct 27, 2017 at 1:38 PM, Eric Dumazet wrote: > > On Wed, Oct 25, 2017 at 10:37 PM, Yuchung Cheng wrote: > > On Wed, Oct 25, 2017 at 7:07 PM, Alexei Starovoitov > > wrote: > >> > >> On Thu, Sep 28, 2017 at 04:36:58PM -0700, Yuchung Cheng wrote: > >> > On Thu, Sep 28, 2017 at 1:14 AM, Oleksandr Natalenko > >> > wrote: > >> > > Hi. > >> > > > >> > > Won't tell about panic in tcp_sacktag_walk() since I cannot trigger it > >> > > intentionally, but setting net.ipv4.tcp_retrans_collapse to 0 *does > >> > > not* fix > >> > > warning in tcp_fastretrans_alert() for me. > >> > > >> > Hi Oleksandr: no retrans_collapse should not matter for that warning > >> > in tcp_fstretrans_alert(). the warning as I explained earlier is hi guys can you try if the warning goes away w/ this quick fix? diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c index 0ada8bfc2ebd..072aab2a8226 100644 --- a/net/ipv4/tcp_input.c +++ b/net/ipv4/tcp_input.c @@ -2626,7 +2626,7 @@ void tcp_simple_retransmit(struct sock *sk) tcp_clear_retrans_hints_partial(tp); - if (prior_lost == tp->lost_out) + if (!tp->lost_out) return; if (tcp_is_reno(tp)) > >> > likely false. Neal and I are more concerned the panic in > >> > tcp_sacktag_walk. This is just a blind shot but thx for retrying. > >> > > >> > We can submit a one-liner to remove the fast retrans warning but want > >> > to nail the bigger issue first. > >> > >> we're still seeing the warnings followed by crashes and it's very > >> concerning. > >> We hoped that most recent Neal's patches from Sep 18 around this area may > >> magically fix the issue, but no. The panics are still there. > >> It's confirmed that net.ipv4.tcp_retrans_collapse=0 does not help > >> whereas net.ipv4.tcp_recovery=0 works, but obviously undesirable. > >> We're out of ideas on how to debug this. > > Can you try Eric's latest SACK rb-tree patches? > > https://patchwork.ozlabs.org/cover/822218/ > > > > Roman's SNMP data suggests MTU probing is enabled. Another blind shot > > is to disable it. > > > Or alternatively try this fix : > > diff --git a/net/ipv4/tcp_output.c b/net/ipv4/tcp_output.c > index > 1151870018e345592853b035a0902121c41e268d..6a849c7028f06f31b36a906be37995b28b579a40 > 100644 > --- a/net/ipv4/tcp_output.c > +++ b/net/ipv4/tcp_output.c > @@ -2062,6 +2062,8 @@ static int tcp_mtu_probe(struct sock *sk) > nskb->ip_summed = skb->ip_summed; > > tcp_insert_write_queue_before(nskb, skb, sk); > + if (skb == tp->highest_sack) > + tp->highest_sack = nskb; > > len = 0; > tcp_for_write_queue_from_safe(skb, next, sk) {
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Wed, Oct 25, 2017 at 10:37 PM, Yuchung Cheng wrote: > On Wed, Oct 25, 2017 at 7:07 PM, Alexei Starovoitov > wrote: >> >> On Thu, Sep 28, 2017 at 04:36:58PM -0700, Yuchung Cheng wrote: >> > On Thu, Sep 28, 2017 at 1:14 AM, Oleksandr Natalenko >> > wrote: >> > > Hi. >> > > >> > > Won't tell about panic in tcp_sacktag_walk() since I cannot trigger it >> > > intentionally, but setting net.ipv4.tcp_retrans_collapse to 0 *does not* >> > > fix >> > > warning in tcp_fastretrans_alert() for me. >> > >> > Hi Oleksandr: no retrans_collapse should not matter for that warning >> > in tcp_fstretrans_alert(). the warning as I explained earlier is >> > likely false. Neal and I are more concerned the panic in >> > tcp_sacktag_walk. This is just a blind shot but thx for retrying. >> > >> > We can submit a one-liner to remove the fast retrans warning but want >> > to nail the bigger issue first. >> >> we're still seeing the warnings followed by crashes and it's very concerning. >> We hoped that most recent Neal's patches from Sep 18 around this area may >> magically fix the issue, but no. The panics are still there. >> It's confirmed that net.ipv4.tcp_retrans_collapse=0 does not help >> whereas net.ipv4.tcp_recovery=0 works, but obviously undesirable. >> We're out of ideas on how to debug this. > Can you try Eric's latest SACK rb-tree patches? > https://patchwork.ozlabs.org/cover/822218/ > > Roman's SNMP data suggests MTU probing is enabled. Another blind shot > is to disable it. Or alternatively try this fix : diff --git a/net/ipv4/tcp_output.c b/net/ipv4/tcp_output.c index 1151870018e345592853b035a0902121c41e268d..6a849c7028f06f31b36a906be37995b28b579a40 100644 --- a/net/ipv4/tcp_output.c +++ b/net/ipv4/tcp_output.c @@ -2062,6 +2062,8 @@ static int tcp_mtu_probe(struct sock *sk) nskb->ip_summed = skb->ip_summed; tcp_insert_write_queue_before(nskb, skb, sk); + if (skb == tp->highest_sack) + tp->highest_sack = nskb; len = 0; tcp_for_write_queue_from_safe(skb, next, sk) {
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Wed, Oct 25, 2017 at 7:07 PM, Alexei Starovoitov wrote: > > On Thu, Sep 28, 2017 at 04:36:58PM -0700, Yuchung Cheng wrote: > > On Thu, Sep 28, 2017 at 1:14 AM, Oleksandr Natalenko > > wrote: > > > Hi. > > > > > > Won't tell about panic in tcp_sacktag_walk() since I cannot trigger it > > > intentionally, but setting net.ipv4.tcp_retrans_collapse to 0 *does not* > > > fix > > > warning in tcp_fastretrans_alert() for me. > > > > Hi Oleksandr: no retrans_collapse should not matter for that warning > > in tcp_fstretrans_alert(). the warning as I explained earlier is > > likely false. Neal and I are more concerned the panic in > > tcp_sacktag_walk. This is just a blind shot but thx for retrying. > > > > We can submit a one-liner to remove the fast retrans warning but want > > to nail the bigger issue first. > > we're still seeing the warnings followed by crashes and it's very concerning. > We hoped that most recent Neal's patches from Sep 18 around this area may > magically fix the issue, but no. The panics are still there. > It's confirmed that net.ipv4.tcp_retrans_collapse=0 does not help > whereas net.ipv4.tcp_recovery=0 works, but obviously undesirable. > We're out of ideas on how to debug this. Can you try Eric's latest SACK rb-tree patches? https://patchwork.ozlabs.org/cover/822218/ Roman's SNMP data suggests MTU probing is enabled. Another blind shot is to disable it. > > Warning + panic: > [ 7678.309043] Call Trace: > [ 7678.313925] > [ 7678.317955] dump_stack+0x4d/0x70 > [ 7678.324573] __warn+0xd3/0xf0 > [ 7678.330497] warn_slowpath_null+0x1e/0x20 > [ 7678.338510] tcp_fastretrans_alert+0xacf/0xbd0 > [ 7678.347380] tcp_ack+0xbce/0x1390 > [ 7678.354006] tcp_rcv_established+0x1ce/0x740 > [ 7678.362536] tcp_v6_do_rcv+0x15b/0x400 > [ 7678.370025] tcp_v6_rcv+0x94c/0x9f0 > [ 7678.376989] ? tcp_rcv_established+0x42b/0x740 > [ 7678.385866] ip6_input_finish+0xea/0x430 > [ 7678.393702] ip6_input+0x32/0xa0 > [ 7678.400155] ? ip6_rcv_finish+0xa0/0xa0 > [ 7678.407834] ip6_rcv_finish+0x4b/0xa0 > [ 7678.415164] ipv6_rcv+0x2ec/0x4f0 > [ 7678.421778] ? ip6_make_skb+0x1c0/0x1c0 > [ 7678.429447] __netif_receive_skb_core+0x2d5/0x9a0 > [ 7678.438845] ? tcp6_gro_receive+0x11d/0x1c0 > [ 7678.447211] ? ipv6_gro_receive+0x1d0/0x380 > [ 7678.455566] __netif_receive_skb+0x16/0x70 > [ 7678.463748] netif_receive_skb_internal+0x32/0x3b0 > [ 7678.473318] ? dev_gro_receive+0x27c/0x470 > [ 7678.481502] napi_gro_receive+0x113/0x1d0 > [ 7678.489510] mlx5e_handle_rx_cqe_mpwrq+0x5b6/0x8d0 > [ 7678.499077] mlx5e_poll_rx_cq+0x79/0x830 > [ 7678.506911] mlx5e_napi_poll+0x8c/0x3d0 > [ 7678.514579] ? mlx5_cq_completion+0x54/0xb0 > [ 7678.522950] net_rx_action+0x22e/0x380 > [ 7678.530450] __do_softirq+0x106/0x2e8 > [ 7678.537768] irq_exit+0xb0/0xc0 > [ 7678.544042] do_IRQ+0x4f/0xd0 > [ 7678.549970] common_interrupt+0x86/0x86 > ... > [ 7685.690697] BUG: unable to handle kernel > [ 7685.698737] NULL pointer dereference > [ 7685.705889] at 0035 > [ 7685.712357] IP: tcp_sacktag_walk+0xfd/0x460 > [ 7685.720726] PGD 1002d75067 > [ 7685.726320] PUD 102c506067 > [ 7685.731902] PMD 0 > ... > [ 7686.070541] task: 880ff5959b00 task.stack: c90024708000 > [ 7686.082363] RIP: 0010:tcp_sacktag_walk+0xfd/0x460 > [ 7686.091754] RSP: :88203eec38b0 EFLAGS: 00010217 > [ 7686.102188] RAX: 881953620a00 RBX: 881009273200 RCX: > fbfa50ec > [ 7686.116439] RDX: fbfa54a0 RSI: RDI: > 881009273200 > [ 7686.130688] RBP: 88203eec3908 R08: 0048 R09: > fbfa55fb > [ 7686.144936] R10: R11: R12: > 881ec9ff98c0 > [ 7686.159184] R13: 88203eec3a10 R14: R15: > 881ec9ff9a18 > [ 7686.173431] FS: 7f2b235ff700() GS:88203eec() > knlGS: > [ 7686.189589] CS: 0010 DS: ES: CR0: 80050033 > [ 7686.201062] CR2: 0035 CR3: 000fd8229000 CR4: > 003406e0 > [ 7686.215310] DR0: DR1: DR2: > > [ 7686.229560] DR3: DR6: fffe0ff0 DR7: > 0400 > [ 7686.243807] Call Trace: > [ 7686.248696] > [ 7686.252727] tcp_sacktag_write_queue+0x5ff/0x9e0 > [ 7686.261943] tcp_ack+0x677/0x1390 > [ 7686.268569] ? select_task_rq_fair+0x9e3/0xf70 > [ 7686.277437] ? tcp_write_xmit+0x230/0x10a0 > [ 7686.285619] tcp_rcv_established+0x1ce/0x740 > [ 7686.294151] tcp_v6_do_rcv+0x15b/0x400 > [ 7686.301636] tcp_v6_rcv+0x94c/0x9f0 > [ 7686.308606] ? default_wake_function+0x12/0x20 > [ 7686.317483] ? __wake_up_common+0x53/0x90 > [ 7686.325492] ip6_input_finish+0xea/0x430 > [ 7686.29] ip6_input+0x32/0xa0 > [ 7686.339791] ? ip6_rcv_finish+0xa0/0xa0 > [ 7686.347451] ip6_rcv_finish+0x4b/0xa0 > [ 7686.354767] ipv6_rcv+0x2ec/0x4f0 > [ 7686.361389] ? ip6_make_skb+0x1c0/0x1c0 > [ 7686.369050] __netif_receive_skb_core+0x2d5/0x9a0 > [ 7686.378449] ? tcp6_gr
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Thu, Sep 28, 2017 at 04:36:58PM -0700, Yuchung Cheng wrote: > On Thu, Sep 28, 2017 at 1:14 AM, Oleksandr Natalenko > wrote: > > Hi. > > > > Won't tell about panic in tcp_sacktag_walk() since I cannot trigger it > > intentionally, but setting net.ipv4.tcp_retrans_collapse to 0 *does not* fix > > warning in tcp_fastretrans_alert() for me. > > Hi Oleksandr: no retrans_collapse should not matter for that warning > in tcp_fstretrans_alert(). the warning as I explained earlier is > likely false. Neal and I are more concerned the panic in > tcp_sacktag_walk. This is just a blind shot but thx for retrying. > > We can submit a one-liner to remove the fast retrans warning but want > to nail the bigger issue first. we're still seeing the warnings followed by crashes and it's very concerning. We hoped that most recent Neal's patches from Sep 18 around this area may magically fix the issue, but no. The panics are still there. It's confirmed that net.ipv4.tcp_retrans_collapse=0 does not help whereas net.ipv4.tcp_recovery=0 works, but obviously undesirable. We're out of ideas on how to debug this. Warning + panic: [ 7678.309043] Call Trace: [ 7678.313925] [ 7678.317955] dump_stack+0x4d/0x70 [ 7678.324573] __warn+0xd3/0xf0 [ 7678.330497] warn_slowpath_null+0x1e/0x20 [ 7678.338510] tcp_fastretrans_alert+0xacf/0xbd0 [ 7678.347380] tcp_ack+0xbce/0x1390 [ 7678.354006] tcp_rcv_established+0x1ce/0x740 [ 7678.362536] tcp_v6_do_rcv+0x15b/0x400 [ 7678.370025] tcp_v6_rcv+0x94c/0x9f0 [ 7678.376989] ? tcp_rcv_established+0x42b/0x740 [ 7678.385866] ip6_input_finish+0xea/0x430 [ 7678.393702] ip6_input+0x32/0xa0 [ 7678.400155] ? ip6_rcv_finish+0xa0/0xa0 [ 7678.407834] ip6_rcv_finish+0x4b/0xa0 [ 7678.415164] ipv6_rcv+0x2ec/0x4f0 [ 7678.421778] ? ip6_make_skb+0x1c0/0x1c0 [ 7678.429447] __netif_receive_skb_core+0x2d5/0x9a0 [ 7678.438845] ? tcp6_gro_receive+0x11d/0x1c0 [ 7678.447211] ? ipv6_gro_receive+0x1d0/0x380 [ 7678.455566] __netif_receive_skb+0x16/0x70 [ 7678.463748] netif_receive_skb_internal+0x32/0x3b0 [ 7678.473318] ? dev_gro_receive+0x27c/0x470 [ 7678.481502] napi_gro_receive+0x113/0x1d0 [ 7678.489510] mlx5e_handle_rx_cqe_mpwrq+0x5b6/0x8d0 [ 7678.499077] mlx5e_poll_rx_cq+0x79/0x830 [ 7678.506911] mlx5e_napi_poll+0x8c/0x3d0 [ 7678.514579] ? mlx5_cq_completion+0x54/0xb0 [ 7678.522950] net_rx_action+0x22e/0x380 [ 7678.530450] __do_softirq+0x106/0x2e8 [ 7678.537768] irq_exit+0xb0/0xc0 [ 7678.544042] do_IRQ+0x4f/0xd0 [ 7678.549970] common_interrupt+0x86/0x86 ... [ 7685.690697] BUG: unable to handle kernel [ 7685.698737] NULL pointer dereference [ 7685.705889] at 0035 [ 7685.712357] IP: tcp_sacktag_walk+0xfd/0x460 [ 7685.720726] PGD 1002d75067 [ 7685.726320] PUD 102c506067 [ 7685.731902] PMD 0 ... [ 7686.070541] task: 880ff5959b00 task.stack: c90024708000 [ 7686.082363] RIP: 0010:tcp_sacktag_walk+0xfd/0x460 [ 7686.091754] RSP: :88203eec38b0 EFLAGS: 00010217 [ 7686.102188] RAX: 881953620a00 RBX: 881009273200 RCX: fbfa50ec [ 7686.116439] RDX: fbfa54a0 RSI: RDI: 881009273200 [ 7686.130688] RBP: 88203eec3908 R08: 0048 R09: fbfa55fb [ 7686.144936] R10: R11: R12: 881ec9ff98c0 [ 7686.159184] R13: 88203eec3a10 R14: R15: 881ec9ff9a18 [ 7686.173431] FS: 7f2b235ff700() GS:88203eec() knlGS: [ 7686.189589] CS: 0010 DS: ES: CR0: 80050033 [ 7686.201062] CR2: 0035 CR3: 000fd8229000 CR4: 003406e0 [ 7686.215310] DR0: DR1: DR2: [ 7686.229560] DR3: DR6: fffe0ff0 DR7: 0400 [ 7686.243807] Call Trace: [ 7686.248696] [ 7686.252727] tcp_sacktag_write_queue+0x5ff/0x9e0 [ 7686.261943] tcp_ack+0x677/0x1390 [ 7686.268569] ? select_task_rq_fair+0x9e3/0xf70 [ 7686.277437] ? tcp_write_xmit+0x230/0x10a0 [ 7686.285619] tcp_rcv_established+0x1ce/0x740 [ 7686.294151] tcp_v6_do_rcv+0x15b/0x400 [ 7686.301636] tcp_v6_rcv+0x94c/0x9f0 [ 7686.308606] ? default_wake_function+0x12/0x20 [ 7686.317483] ? __wake_up_common+0x53/0x90 [ 7686.325492] ip6_input_finish+0xea/0x430 [ 7686.29] ip6_input+0x32/0xa0 [ 7686.339791] ? ip6_rcv_finish+0xa0/0xa0 [ 7686.347451] ip6_rcv_finish+0x4b/0xa0 [ 7686.354767] ipv6_rcv+0x2ec/0x4f0 [ 7686.361389] ? ip6_make_skb+0x1c0/0x1c0 [ 7686.369050] __netif_receive_skb_core+0x2d5/0x9a0 [ 7686.378449] ? tcp6_gro_receive+0x11d/0x1c0 [ 7686.386797] ? ipv6_gro_receive+0x1d0/0x380 [ 7686.395160] __netif_receive_skb+0x16/0x70 [ 7686.403342] netif_receive_skb_internal+0x32/0x3b0 [ 7686.412931] ? dev_gro_receive+0x27c/0x470 [ 7686.421110] napi_gro_receive+0x113/0x1d0 [ 7686.429136] mlx5e_handle_rx_cqe_mpwrq+0x5b6/0x8d0 [ 7686.438722] mlx5e_poll_rx_cq+0x79/0x830 [ 7686.446572] mlx5e_napi_poll+0x8c/0x3d0 [ 7686.454233] ? mlx5_cq_completion+0x54/0xb0 [ 7686.462591] n
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Thu, Sep 28, 2017 at 1:14 AM, Oleksandr Natalenko wrote: > Hi. > > Won't tell about panic in tcp_sacktag_walk() since I cannot trigger it > intentionally, but setting net.ipv4.tcp_retrans_collapse to 0 *does not* fix > warning in tcp_fastretrans_alert() for me. Hi Oleksandr: no retrans_collapse should not matter for that warning in tcp_fstretrans_alert(). the warning as I explained earlier is likely false. Neal and I are more concerned the panic in tcp_sacktag_walk. This is just a blind shot but thx for retrying. We can submit a one-liner to remove the fast retrans warning but want to nail the bigger issue first. > > On středa 27. září 2017 2:18:32 CEST Yuchung Cheng wrote: >> On Tue, Sep 26, 2017 at 5:12 PM, Yuchung Cheng wrote: >> > On Tue, Sep 26, 2017 at 6:10 AM, Roman Gushchin wrote: >> >>> On Wed, Sep 20, 2017 at 6:46 PM, Roman Gushchin 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. >> >>> > > >> >>> > > Also, I have custom settings regarding TCP stack, shown below as >> >>> > > well. ifb is used to shape traffic with tc. >> >>> > > >> >>> > > Please note this regression was already reported as BZ [1] and as a >> >>> > > letter to ML [2], but got neither attention nor resolution. It is >> >>> > > reproducible for (not only) me on my home router since v4.11 till >> >>> > > v4.13.1 incl. >> >>> > > >> >>> > > Please advise on how to deal with it. I'll provide any additional >> >>> > > info if >> >>> > > necessary, also ready to test patches if any. >> >>> > > >> >>> > > Thanks. >> >>> > > >> >>> > > [1] https://bugzilla.kernel.org/show_bug.cgi?id=195835 >> >>> > > [2] >> >>> > > https://urldefense.proofpoint.com/v2/url?u=https-3A__www.spinics.ne >> >>> > > t_lists_netdev_msg436158.html&d=DwIBaQ&c=5VD0RTtNlTh3ycd41b3MUw&r=jJ >> >>> > > YgtDM7QT-W-Fz_d29HYQ&m=MDDRfLG5DvdOeniMpaZDJI8ulKQ6PQ6OX_1YtRsiTMA&s >> >>> > > =-n3dGZw-pQ95kMBUfq5G9nYZFcuWtbTDlYFkcvQPoKc&e=>>> > >> >>> > We're experiencing the same problems on some machines in our fleet. >> >>> > Exactly the same symptoms: tcp_fastretrans_alert() warnings and >> >>> > sometimes panics in tcp_sacktag_walk(). >> >> >> >>> > Here is an example of a backtrace with the panic log: >> >> Hi Yuchung! >> >> >> >>> do you still see the panics if you disable RACK? >> >>> sysctl net.ipv4.tcp_recovery=0? >> >> >> >> No, we haven't seen any crash since that. >> > >> > I am out of ideas how RACK can potentially cause tcp_sacktag_walk to >> > take an empty skb :-( Do you have stack trace or any hint on which call >> > to tcp-sacktag_walk triggered the panic? internally at Google we never >> > see that. >> >> hmm something just struck me: could you try >> sysctl net.ipv4.tcp_recovery=1 net.ipv4.tcp_retrans_collapse=0 >> and see if kernel still panics on sack processing? >> >> >>> also have you experience any sack reneg? could you post the output of >> >>> ' nstat |grep -i TCP' thanks >> >> >> >> hostnameTcpActiveOpens 22896800.0 >> >> hostnameTcpPassiveOpens 35927580.0 >> >> hostnameTcpAttemptFails 746910 0.0 >> >> hostnameTcpEstabResets 154988 0.0 >> >> hostnameTcpInSegs 162586782550.0 >> >> hostnameTcpOutSegs 469670116110.0 >> >> hostnameTcpRetransSegs 13724310 0.0 >> >> hostnameTcpInErrs 2 0.0 >> >> hostnameTcpOutRsts 94187980.0 >> >> hostnameTcpExtEmbryonicRsts 2303 0.0 >> >> hostnameTcpExtPruneCalled 90192 0.0 >> >> hostnameTcpExtOfoPruned 57274 0.0 >> >> hostnameTcpExtOutOfWindowIcmps 3 0.0 >> >> hostnameTcpExtTW11647050.0 >> >> hostnameTcpExtTWRecycled2 0.0 >> >> hostnameTcpExtPAWSEstab 1590.0 >> >> hostnameTcpExtDelayedACKs 209207209 0.0 >> >> hostnameTcpExtDelayedACKLocked 508571 0.0 >> >> hostnameTcpExtDelayedACKLost17132480.0 >> >> hostnameTcpExtListenOverflows 6250.0 >> >> hostnameTcpExtListenDrops 6250.0 >> >> hostnam
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
Hi. Won't tell about panic in tcp_sacktag_walk() since I cannot trigger it intentionally, but setting net.ipv4.tcp_retrans_collapse to 0 *does not* fix warning in tcp_fastretrans_alert() for me. On středa 27. září 2017 2:18:32 CEST Yuchung Cheng wrote: > On Tue, Sep 26, 2017 at 5:12 PM, Yuchung Cheng wrote: > > On Tue, Sep 26, 2017 at 6:10 AM, Roman Gushchin wrote: > >>> On Wed, Sep 20, 2017 at 6:46 PM, Roman Gushchin 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. > >>> > > > >>> > > Also, I have custom settings regarding TCP stack, shown below as > >>> > > well. ifb is used to shape traffic with tc. > >>> > > > >>> > > Please note this regression was already reported as BZ [1] and as a > >>> > > letter to ML [2], but got neither attention nor resolution. It is > >>> > > reproducible for (not only) me on my home router since v4.11 till > >>> > > v4.13.1 incl. > >>> > > > >>> > > Please advise on how to deal with it. I'll provide any additional > >>> > > info if > >>> > > necessary, also ready to test patches if any. > >>> > > > >>> > > Thanks. > >>> > > > >>> > > [1] https://bugzilla.kernel.org/show_bug.cgi?id=195835 > >>> > > [2] > >>> > > https://urldefense.proofpoint.com/v2/url?u=https-3A__www.spinics.ne > >>> > > t_lists_netdev_msg436158.html&d=DwIBaQ&c=5VD0RTtNlTh3ycd41b3MUw&r=jJ > >>> > > YgtDM7QT-W-Fz_d29HYQ&m=MDDRfLG5DvdOeniMpaZDJI8ulKQ6PQ6OX_1YtRsiTMA&s > >>> > > =-n3dGZw-pQ95kMBUfq5G9nYZFcuWtbTDlYFkcvQPoKc&e=>>> > > >>> > We're experiencing the same problems on some machines in our fleet. > >>> > Exactly the same symptoms: tcp_fastretrans_alert() warnings and > >>> > sometimes panics in tcp_sacktag_walk(). > >> > >>> > Here is an example of a backtrace with the panic log: > >> Hi Yuchung! > >> > >>> do you still see the panics if you disable RACK? > >>> sysctl net.ipv4.tcp_recovery=0? > >> > >> No, we haven't seen any crash since that. > > > > I am out of ideas how RACK can potentially cause tcp_sacktag_walk to > > take an empty skb :-( Do you have stack trace or any hint on which call > > to tcp-sacktag_walk triggered the panic? internally at Google we never > > see that. > > hmm something just struck me: could you try > sysctl net.ipv4.tcp_recovery=1 net.ipv4.tcp_retrans_collapse=0 > and see if kernel still panics on sack processing? > > >>> also have you experience any sack reneg? could you post the output of > >>> ' nstat |grep -i TCP' thanks > >> > >> hostnameTcpActiveOpens 22896800.0 > >> hostnameTcpPassiveOpens 35927580.0 > >> hostnameTcpAttemptFails 746910 0.0 > >> hostnameTcpEstabResets 154988 0.0 > >> hostnameTcpInSegs 162586782550.0 > >> hostnameTcpOutSegs 469670116110.0 > >> hostnameTcpRetransSegs 13724310 0.0 > >> hostnameTcpInErrs 2 0.0 > >> hostnameTcpOutRsts 94187980.0 > >> hostnameTcpExtEmbryonicRsts 2303 0.0 > >> hostnameTcpExtPruneCalled 90192 0.0 > >> hostnameTcpExtOfoPruned 57274 0.0 > >> hostnameTcpExtOutOfWindowIcmps 3 0.0 > >> hostnameTcpExtTW11647050.0 > >> hostnameTcpExtTWRecycled2 0.0 > >> hostnameTcpExtPAWSEstab 1590.0 > >> hostnameTcpExtDelayedACKs 209207209 0.0 > >> hostnameTcpExtDelayedACKLocked 508571 0.0 > >> hostnameTcpExtDelayedACKLost17132480.0 > >> hostnameTcpExtListenOverflows 6250.0 > >> hostnameTcpExtListenDrops 6250.0 > >> hostnameTcpExtTCPHPHits 9341188489 0.0 > >> hostnameTcpExtTCPPureAcks 1434646465 0.0 > >> hostnameTcpExtTCPHPAcks 5733614672 0.0 > >> hostnameTcpExtTCPSackRecovery 32616980.0 > >> hostnameTcpExtTCPSACKReneging 12203 0.0 > >> hostnameTcpExtTCPSACKReorder433189 0.0 > >> hostnameTcpExtTCPTSReorder 226
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Tue, Sep 26, 2017 at 5:12 PM, Yuchung Cheng wrote: > On Tue, Sep 26, 2017 at 6:10 AM, Roman Gushchin wrote: >>> On Wed, Sep 20, 2017 at 6:46 PM, Roman Gushchin 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. >>> > > >>> > > Also, I have custom settings regarding TCP stack, shown below as well. >>> > > ifb is >>> > > used to shape traffic with tc. >>> > > >>> > > Please note this regression was already reported as BZ [1] and as a >>> > > letter to >>> > > ML [2], but got neither attention nor resolution. It is reproducible >>> > > for (not >>> > > only) me on my home router since v4.11 till v4.13.1 incl. >>> > > >>> > > Please advise on how to deal with it. I'll provide any additional info >>> > > if >>> > > necessary, also ready to test patches if any. >>> > > >>> > > Thanks. >>> > > >>> > > [1] https://bugzilla.kernel.org/show_bug.cgi?id=195835 >>> > > [2] >>> > > https://urldefense.proofpoint.com/v2/url?u=https-3A__www.spinics.net_lists_netdev_msg436158.html&d=DwIBaQ&c=5VD0RTtNlTh3ycd41b3MUw&r=jJYgtDM7QT-W-Fz_d29HYQ&m=MDDRfLG5DvdOeniMpaZDJI8ulKQ6PQ6OX_1YtRsiTMA&s=-n3dGZw-pQ95kMBUfq5G9nYZFcuWtbTDlYFkcvQPoKc&e= >>> > >>> > We're experiencing the same problems on some machines in our fleet. >>> > Exactly the same symptoms: tcp_fastretrans_alert() warnings and >>> > sometimes panics in tcp_sacktag_walk(). >>> > >>> > Here is an example of a backtrace with the panic log: >> >> Hi Yuchung! >> >>> do you still see the panics if you disable RACK? >>> sysctl net.ipv4.tcp_recovery=0? >> >> No, we haven't seen any crash since that. > I am out of ideas how RACK can potentially cause tcp_sacktag_walk to > take an empty skb :-( Do you have stack trace or any hint on which call > to tcp-sacktag_walk triggered the panic? internally at Google we never > see that. hmm something just struck me: could you try sysctl net.ipv4.tcp_recovery=1 net.ipv4.tcp_retrans_collapse=0 and see if kernel still panics on sack processing? > > >> >>> >>> also have you experience any sack reneg? could you post the output of >>> ' nstat |grep -i TCP' thanks >> >> hostnameTcpActiveOpens 22896800.0 >> hostnameTcpPassiveOpens 35927580.0 >> hostnameTcpAttemptFails 746910 0.0 >> hostnameTcpEstabResets 154988 0.0 >> hostnameTcpInSegs 162586782550.0 >> hostnameTcpOutSegs 469670116110.0 >> hostnameTcpRetransSegs 13724310 0.0 >> hostnameTcpInErrs 2 0.0 >> hostnameTcpOutRsts 94187980.0 >> hostnameTcpExtEmbryonicRsts 2303 0.0 >> hostnameTcpExtPruneCalled 90192 0.0 >> hostnameTcpExtOfoPruned 57274 0.0 >> hostnameTcpExtOutOfWindowIcmps 3 0.0 >> hostnameTcpExtTW11647050.0 >> hostnameTcpExtTWRecycled2 0.0 >> hostnameTcpExtPAWSEstab 1590.0 >> hostnameTcpExtDelayedACKs 209207209 0.0 >> hostnameTcpExtDelayedACKLocked 508571 0.0 >> hostnameTcpExtDelayedACKLost17132480.0 >> hostnameTcpExtListenOverflows 6250.0 >> hostnameTcpExtListenDrops 6250.0 >> hostnameTcpExtTCPHPHits 9341188489 0.0 >> hostnameTcpExtTCPPureAcks 1434646465 0.0 >> hostnameTcpExtTCPHPAcks 5733614672 0.0 >> hostnameTcpExtTCPSackRecovery 32616980.0 >> hostnameTcpExtTCPSACKReneging 12203 0.0 >> hostnameTcpExtTCPSACKReorder433189 0.0 >> hostnameTcpExtTCPTSReorder 22694 0.0 >> hostnameTcpExtTCPFullUndo 45092 0.0 >> hostnameTcpExtTCPPartialUndo22016 0.0 >> hostnameTcpExtTCPLossUndo 21500400.0 >> hostnameTcpExtTCPLostRetransmit 60119 0.0 >> hostnameTcpExtTCPSackFailures 26267820.0 >> hostnameTcpExtTCPLossFailures
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Tue, Sep 26, 2017 at 6:10 AM, Roman Gushchin wrote: >> On Wed, Sep 20, 2017 at 6:46 PM, Roman Gushchin 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. >> > > >> > > Also, I have custom settings regarding TCP stack, shown below as well. >> > > ifb is >> > > used to shape traffic with tc. >> > > >> > > Please note this regression was already reported as BZ [1] and as a >> > > letter to >> > > ML [2], but got neither attention nor resolution. It is reproducible for >> > > (not >> > > only) me on my home router since v4.11 till v4.13.1 incl. >> > > >> > > Please advise on how to deal with it. I'll provide any additional info if >> > > necessary, also ready to test patches if any. >> > > >> > > Thanks. >> > > >> > > [1] https://bugzilla.kernel.org/show_bug.cgi?id=195835 >> > > [2] >> > > https://urldefense.proofpoint.com/v2/url?u=https-3A__www.spinics.net_lists_netdev_msg436158.html&d=DwIBaQ&c=5VD0RTtNlTh3ycd41b3MUw&r=jJYgtDM7QT-W-Fz_d29HYQ&m=MDDRfLG5DvdOeniMpaZDJI8ulKQ6PQ6OX_1YtRsiTMA&s=-n3dGZw-pQ95kMBUfq5G9nYZFcuWtbTDlYFkcvQPoKc&e= >> > >> > We're experiencing the same problems on some machines in our fleet. >> > Exactly the same symptoms: tcp_fastretrans_alert() warnings and >> > sometimes panics in tcp_sacktag_walk(). >> > >> > Here is an example of a backtrace with the panic log: > > Hi Yuchung! > >> do you still see the panics if you disable RACK? >> sysctl net.ipv4.tcp_recovery=0? > > No, we haven't seen any crash since that. I am out of ideas how RACK can potentially cause tcp_sacktag_walk to take an empty skb :-( Do you have stack trace or any hint on which call to tcp-sacktag_walk triggered the panic? internally at Google we never see that. > >> >> also have you experience any sack reneg? could you post the output of >> ' nstat |grep -i TCP' thanks > > hostnameTcpActiveOpens 22896800.0 > hostnameTcpPassiveOpens 35927580.0 > hostnameTcpAttemptFails 746910 0.0 > hostnameTcpEstabResets 154988 0.0 > hostnameTcpInSegs 162586782550.0 > hostnameTcpOutSegs 469670116110.0 > hostnameTcpRetransSegs 13724310 0.0 > hostnameTcpInErrs 2 0.0 > hostnameTcpOutRsts 94187980.0 > hostnameTcpExtEmbryonicRsts 2303 0.0 > hostnameTcpExtPruneCalled 90192 0.0 > hostnameTcpExtOfoPruned 57274 0.0 > hostnameTcpExtOutOfWindowIcmps 3 0.0 > hostnameTcpExtTW11647050.0 > hostnameTcpExtTWRecycled2 0.0 > hostnameTcpExtPAWSEstab 1590.0 > hostnameTcpExtDelayedACKs 209207209 0.0 > hostnameTcpExtDelayedACKLocked 508571 0.0 > hostnameTcpExtDelayedACKLost17132480.0 > hostnameTcpExtListenOverflows 6250.0 > hostnameTcpExtListenDrops 6250.0 > hostnameTcpExtTCPHPHits 9341188489 0.0 > hostnameTcpExtTCPPureAcks 1434646465 0.0 > hostnameTcpExtTCPHPAcks 5733614672 0.0 > hostnameTcpExtTCPSackRecovery 32616980.0 > hostnameTcpExtTCPSACKReneging 12203 0.0 > hostnameTcpExtTCPSACKReorder433189 0.0 > hostnameTcpExtTCPTSReorder 22694 0.0 > hostnameTcpExtTCPFullUndo 45092 0.0 > hostnameTcpExtTCPPartialUndo22016 0.0 > hostnameTcpExtTCPLossUndo 21500400.0 > hostnameTcpExtTCPLostRetransmit 60119 0.0 > hostnameTcpExtTCPSackFailures 26267820.0 > hostnameTcpExtTCPLossFailures 182999 0.0 > hostnameTcpExtTCPFastRetrans43342750.0 > hostnameTcpExtTCPSlowStartRetrans 34533480.0 > hostnameTcpExtTCPTimeouts 10709970.0 > hostnameTcpExtTCPLossProbes 2633545
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
> On Wed, Sep 20, 2017 at 6:46 PM, Roman Gushchin 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. > > > > > > Also, I have custom settings regarding TCP stack, shown below as well. > > > ifb is > > > used to shape traffic with tc. > > > > > > Please note this regression was already reported as BZ [1] and as a > > > letter to > > > ML [2], but got neither attention nor resolution. It is reproducible for > > > (not > > > only) me on my home router since v4.11 till v4.13.1 incl. > > > > > > Please advise on how to deal with it. I'll provide any additional info if > > > necessary, also ready to test patches if any. > > > > > > Thanks. > > > > > > [1] https://bugzilla.kernel.org/show_bug.cgi?id=195835 > > > [2] > > > https://urldefense.proofpoint.com/v2/url?u=https-3A__www.spinics.net_lists_netdev_msg436158.html&d=DwIBaQ&c=5VD0RTtNlTh3ycd41b3MUw&r=jJYgtDM7QT-W-Fz_d29HYQ&m=MDDRfLG5DvdOeniMpaZDJI8ulKQ6PQ6OX_1YtRsiTMA&s=-n3dGZw-pQ95kMBUfq5G9nYZFcuWtbTDlYFkcvQPoKc&e= > > > > > > > We're experiencing the same problems on some machines in our fleet. > > Exactly the same symptoms: tcp_fastretrans_alert() warnings and > > sometimes panics in tcp_sacktag_walk(). > > > > Here is an example of a backtrace with the panic log: Hi Yuchung! > do you still see the panics if you disable RACK? > sysctl net.ipv4.tcp_recovery=0? No, we haven't seen any crash since that. > > also have you experience any sack reneg? could you post the output of > ' nstat |grep -i TCP' thanks hostnameTcpActiveOpens 22896800.0 hostnameTcpPassiveOpens 35927580.0 hostnameTcpAttemptFails 746910 0.0 hostnameTcpEstabResets 154988 0.0 hostnameTcpInSegs 162586782550.0 hostnameTcpOutSegs 469670116110.0 hostnameTcpRetransSegs 13724310 0.0 hostnameTcpInErrs 2 0.0 hostnameTcpOutRsts 94187980.0 hostnameTcpExtEmbryonicRsts 2303 0.0 hostnameTcpExtPruneCalled 90192 0.0 hostnameTcpExtOfoPruned 57274 0.0 hostnameTcpExtOutOfWindowIcmps 3 0.0 hostnameTcpExtTW11647050.0 hostnameTcpExtTWRecycled2 0.0 hostnameTcpExtPAWSEstab 1590.0 hostnameTcpExtDelayedACKs 209207209 0.0 hostnameTcpExtDelayedACKLocked 508571 0.0 hostnameTcpExtDelayedACKLost17132480.0 hostnameTcpExtListenOverflows 6250.0 hostnameTcpExtListenDrops 6250.0 hostnameTcpExtTCPHPHits 9341188489 0.0 hostnameTcpExtTCPPureAcks 1434646465 0.0 hostnameTcpExtTCPHPAcks 5733614672 0.0 hostnameTcpExtTCPSackRecovery 32616980.0 hostnameTcpExtTCPSACKReneging 12203 0.0 hostnameTcpExtTCPSACKReorder433189 0.0 hostnameTcpExtTCPTSReorder 22694 0.0 hostnameTcpExtTCPFullUndo 45092 0.0 hostnameTcpExtTCPPartialUndo22016 0.0 hostnameTcpExtTCPLossUndo 21500400.0 hostnameTcpExtTCPLostRetransmit 60119 0.0 hostnameTcpExtTCPSackFailures 26267820.0 hostnameTcpExtTCPLossFailures 182999 0.0 hostnameTcpExtTCPFastRetrans43342750.0 hostnameTcpExtTCPSlowStartRetrans 34533480.0 hostnameTcpExtTCPTimeouts 10709970.0 hostnameTcpExtTCPLossProbes 26335450.0 hostnameTcpExtTCPLossProbeRecovery 941647 0.0 hostnameTcpExtTCPSackRecoveryFail 336302 0.0 hostnameTcpExtTCPRcvCollapsed 461354 0.0 hostnameTcpExtTCPAbortOnData349196 0.0 hostnameTcpExtTCPAbortOnClose 3395 0.0 hostnameTcpExtTCPAbortOnTimeout
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Wed, Sep 20, 2017 at 6:46 PM, Roman Gushchin 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. > > > > Also, I have custom settings regarding TCP stack, shown below as well. ifb > > is > > used to shape traffic with tc. > > > > Please note this regression was already reported as BZ [1] and as a letter > > to > > ML [2], but got neither attention nor resolution. It is reproducible for > > (not > > only) me on my home router since v4.11 till v4.13.1 incl. > > > > Please advise on how to deal with it. I'll provide any additional info if > > necessary, also ready to test patches if any. > > > > Thanks. > > > > [1] https://bugzilla.kernel.org/show_bug.cgi?id=195835 > > [2] https://www.spinics.net/lists/netdev/msg436158.html > > We're experiencing the same problems on some machines in our fleet. > Exactly the same symptoms: tcp_fastretrans_alert() warnings and > sometimes panics in tcp_sacktag_walk(). > > Here is an example of a backtrace with the panic log: do you still see the panics if you disable RACK? sysctl net.ipv4.tcp_recovery=0? also have you experience any sack reneg? could you post the output of ' nstat |grep -i TCP' thanks > > 978.210080] fuse > [973978.214099] sg > [973978.217789] loop > [973978.221829] efivarfs > [973978.226544] autofs4 > [973978.231109] CPU: 12 PID: 3806320 Comm: ld:srv:W20 Tainted: GW > 4.11.3-7_fbk1_1174_ga56eebf #7 > [973978.250563] Hardware name: Wiwynn Leopard-Orv2/Leopard-DDR BW, BIOS LBM06 > 10/28/2016 > [973978.266558] Call Trace: > [973978.271615] > [973978.275817] dump_stack+0x4d/0x70 > [973978.282626] __warn+0xd3/0xf0 > [973978.288727] warn_slowpath_null+0x1e/0x20 > [973978.296910] tcp_fastretrans_alert+0xacf/0xbd0 > [973978.305974] tcp_ack+0xbce/0x1390 > [973978.312770] tcp_rcv_established+0x1ce/0x740 > [973978.321488] tcp_v6_do_rcv+0x195/0x440 > [973978.329166] tcp_v6_rcv+0x94c/0x9f0 > [973978.336323] ip6_input_finish+0xea/0x430 > [973978.344330] ip6_input+0x32/0xa0 > [973978.350968] ? ip6_rcv_finish+0xa0/0xa0 > [973978.358799] ip6_rcv_finish+0x4b/0xa0 > [973978.366289] ipv6_rcv+0x2ec/0x4f0 > [973978.373082] ? ip6_make_skb+0x1c0/0x1c0 > [973978.380919] __netif_receive_skb_core+0x2d5/0x9a0 > [973978.390505] __netif_receive_skb+0x16/0x70 > [973978.398875] netif_receive_skb_internal+0x23/0x80 > [973978.408462] napi_gro_receive+0x113/0x1d0 > [973978.416657] mlx5e_handle_rx_cqe_mpwrq+0x5b6/0x8d0 > [973978.426398] mlx5e_poll_rx_cq+0x7c/0x7f0 > [973978.434405] mlx5e_napi_poll+0x8c/0x380 > [973978.442238] ? mlx5_cq_completion+0x54/0xb0 > [973978.450770] net_rx_action+0x22e/0x380 > [973978.458447] __do_softirq+0x106/0x2e8 > [973978.465950] irq_exit+0xb0/0xc0 > [973978.472396] do_IRQ+0x4f/0xd0 > [973978.478495] common_interrupt+0x86/0x86 > [973978.486329] RIP: 0033:0x7f8dee58d8ae > [973978.493642] RSP: 002b:7f8cb925f078 EFLAGS: 0206 > [973978.504251] ORIG_RAX: ff5f > [973978.512085] RAX: 7f8cb925f1a8 RBX: 4800 RCX: > 7f8764bd6a80 > [973978.526508] RDX: 01ba RSI: 7f7cb4ca3410 RDI: > 7f7cb4ca3410 > [973978.540927] RBP: 000d R08: 7f8764bd6b00 R09: > 7f8764bd6b80 > [973978.555347] R10: 2400 R11: 7f8dee58e240 R12: > d3273c84146e8c29 > [973978.569766] R13: 9dac83ddf04c235c R14: 7f7cb4ca33b0 R15: > 7f7cb4ca4f50 > [973978.584189] > [973978.588650] ---[ end trace 5d1c83e12a57d039 ]--- > [973995.178183] BUG: unable to handle kernel > [973995.186385] NULL pointer dereference > [973995.193692] at 0028 > [973995.200323] IP: tcp_sacktag_walk+0x2b7/0x460 > [973995.209032] PGD 102d856067 > [973995.214789] PUD fded0d067 > [973995.220385] PMD 0 > [973995.224577] > [973995.227732] [ cut here ] > [973995.237128] Oops: [#1] SMP > [973995.243575] Modules linked in: > [973995.249868] mptctl > [973995.254251] mptbase > [973995.258792] xt_DSCP > [973995.263331] xt_set > [973995.267698] ip_set_hash_ip > [973995.273452] cls_u32 > [973995.277993] sch_sfq > [973995.282535] cls_fw > [973995.286904] sch_htb > [973995.291444] mpt3sas > [973995.295982] raid_class > [973995.301044] ip6table_mangle > [973995.306973] iptable_mangle > [973995.312726] cls_bpf > [973995.317268] tcp_diag > [973995.321983] udp_diag > [973995.326697] inet_diag > [973995.331585] ip6table_filter > [973995.337513] xt_NFLOG > [973995.342226] nfnetlink_log > [973995.347807] xt_comment > [973995.352866] xt_statistic > [973995.358276] iptable_filter > [973995.364029] xt_mark > [973995.368572] sb_edac > [973995.373113] ed
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
> 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. > > Also, I have custom settings regarding TCP stack, shown below as well. ifb is > used to shape traffic with tc. > > Please note this regression was already reported as BZ [1] and as a letter to > ML [2], but got neither attention nor resolution. It is reproducible for (not > only) me on my home router since v4.11 till v4.13.1 incl. > > Please advise on how to deal with it. I'll provide any additional info if > necessary, also ready to test patches if any. > > Thanks. > > [1] https://bugzilla.kernel.org/show_bug.cgi?id=195835 > [2] https://www.spinics.net/lists/netdev/msg436158.html We're experiencing the same problems on some machines in our fleet. Exactly the same symptoms: tcp_fastretrans_alert() warnings and sometimes panics in tcp_sacktag_walk(). Here is an example of a backtrace with the panic log: 978.210080] fuse [973978.214099] sg [973978.217789] loop [973978.221829] efivarfs [973978.226544] autofs4 [973978.231109] CPU: 12 PID: 3806320 Comm: ld:srv:W20 Tainted: GW 4.11.3-7_fbk1_1174_ga56eebf #7 [973978.250563] Hardware name: Wiwynn Leopard-Orv2/Leopard-DDR BW, BIOS LBM06 10/28/2016 [973978.266558] Call Trace: [973978.271615] [973978.275817] dump_stack+0x4d/0x70 [973978.282626] __warn+0xd3/0xf0 [973978.288727] warn_slowpath_null+0x1e/0x20 [973978.296910] tcp_fastretrans_alert+0xacf/0xbd0 [973978.305974] tcp_ack+0xbce/0x1390 [973978.312770] tcp_rcv_established+0x1ce/0x740 [973978.321488] tcp_v6_do_rcv+0x195/0x440 [973978.329166] tcp_v6_rcv+0x94c/0x9f0 [973978.336323] ip6_input_finish+0xea/0x430 [973978.344330] ip6_input+0x32/0xa0 [973978.350968] ? ip6_rcv_finish+0xa0/0xa0 [973978.358799] ip6_rcv_finish+0x4b/0xa0 [973978.366289] ipv6_rcv+0x2ec/0x4f0 [973978.373082] ? ip6_make_skb+0x1c0/0x1c0 [973978.380919] __netif_receive_skb_core+0x2d5/0x9a0 [973978.390505] __netif_receive_skb+0x16/0x70 [973978.398875] netif_receive_skb_internal+0x23/0x80 [973978.408462] napi_gro_receive+0x113/0x1d0 [973978.416657] mlx5e_handle_rx_cqe_mpwrq+0x5b6/0x8d0 [973978.426398] mlx5e_poll_rx_cq+0x7c/0x7f0 [973978.434405] mlx5e_napi_poll+0x8c/0x380 [973978.442238] ? mlx5_cq_completion+0x54/0xb0 [973978.450770] net_rx_action+0x22e/0x380 [973978.458447] __do_softirq+0x106/0x2e8 [973978.465950] irq_exit+0xb0/0xc0 [973978.472396] do_IRQ+0x4f/0xd0 [973978.478495] common_interrupt+0x86/0x86 [973978.486329] RIP: 0033:0x7f8dee58d8ae [973978.493642] RSP: 002b:7f8cb925f078 EFLAGS: 0206 [973978.504251] ORIG_RAX: ff5f [973978.512085] RAX: 7f8cb925f1a8 RBX: 4800 RCX: 7f8764bd6a80 [973978.526508] RDX: 01ba RSI: 7f7cb4ca3410 RDI: 7f7cb4ca3410 [973978.540927] RBP: 000d R08: 7f8764bd6b00 R09: 7f8764bd6b80 [973978.555347] R10: 2400 R11: 7f8dee58e240 R12: d3273c84146e8c29 [973978.569766] R13: 9dac83ddf04c235c R14: 7f7cb4ca33b0 R15: 7f7cb4ca4f50 [973978.584189] [973978.588650] ---[ end trace 5d1c83e12a57d039 ]--- [973995.178183] BUG: unable to handle kernel [973995.186385] NULL pointer dereference [973995.193692] at 0028 [973995.200323] IP: tcp_sacktag_walk+0x2b7/0x460 [973995.209032] PGD 102d856067 [973995.214789] PUD fded0d067 [973995.220385] PMD 0 [973995.224577] [973995.227732] [ cut here ] [973995.237128] Oops: [#1] SMP [973995.243575] Modules linked in: [973995.249868] mptctl [973995.254251] mptbase [973995.258792] xt_DSCP [973995.263331] xt_set [973995.267698] ip_set_hash_ip [973995.273452] cls_u32 [973995.277993] sch_sfq [973995.282535] cls_fw [973995.286904] sch_htb [973995.291444] mpt3sas [973995.295982] raid_class [973995.301044] ip6table_mangle [973995.306973] iptable_mangle [973995.312726] cls_bpf [973995.317268] tcp_diag [973995.321983] udp_diag [973995.326697] inet_diag [973995.331585] ip6table_filter [973995.337513] xt_NFLOG [973995.342226] nfnetlink_log [973995.347807] xt_comment [973995.352866] xt_statistic [973995.358276] iptable_filter [973995.364029] xt_mark [973995.368572] sb_edac [973995.373113] edac_core [973995.378001] x86_pkg_temp_thermal [973995.384795] intel_powerclamp [973995.390897] coretemp [973995.395608] kvm_intel [973995.400498] kvm [973995.404345] irqbypass [973995.409235] ses [973995.413078] iTCO_wdt [973995.417794] iTCO_vendor_support [973995.424415] enclosure [973995.429301] lpc_ich [973995.433843] scsi_transport_sas [973995.440292] mfd_core [973995.445007] efivars [973995.449548] ipmi_si [973995.454087] ipmi_devintf [973995.459496] i2c
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Tue, Sep 19, 2017 at 4:04 AM, Oleksandr Natalenko wrote: > Hi. > > 18.09.2017 23:40, Yuchung Cheng wrote: >> >> 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? 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
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
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 > > 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. > > > === > > Sep 18 22:44:32 defiant kernel: [ cut here ] > > Sep 18 22:44:32 defiant kernel: WARNING: CPU: 1 PID: 702 at net/ipv4/ > > tcp_input.c:2392 tcp_undo_cwnd_reduction+0xbd/0xd0 > > Sep 18 22:44:32 defiant kernel: Modules linked in: netconsole ctr ccm > > cls_bpf sch_htb act_mirred cls_u32 sch_ingress sit tunnel4 ip_tunnel > > 8021q mrp nf_conntrack_ipv6 nf_defrag_ipv6 nft_ct nft_set_bitmap > > nft_set_hash nft_set_rbtree nf_tables_inet nf_tables_ipv6 nft_masq_ipv4 > > nf_nat_masquerade_ipv4 nft_masq nft_nat nft_counter nft_meta > > nft_chain_nat_ipv4 nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat > > nf_conntrack libcrc32c crc32c_generic nf_tables_ipv4 nf_tables tun nct6775 > > nfnetlink hwmon_vid nls_iso8859_1 nls_cp437 vfat fat ext4 > > snd_hda_codec_hdmi mbcache jbd2 snd_hda_codec_realtek > > snd_hda_codec_generic f2fs arc4 fscrypto intel_rapl iTCO_wdt ath9k > > iTCO_vendor_support intel_powerclamp ath9k_common ath9k_hw coretemp > > kvm_intel ath mac80211 kvm irqbypass intel_cstate cfg80211 pcspkr > > snd_hda_intel snd_hda_codec r8169 > > Sep 18 22:44:32 defiant kernel: joydev evdev mii snd_hda_core mousedev > > mei_txe input_leds i2c_i801 mac_hid i915 lpc_ich mei shpchp snd_hwdep > > snd_intel_sst_acpi snd_intel_sst_core snd_soc_rt5670 > > snd_soc_sst_atom_hifi2_platform battery snd_soc_sst_match snd_soc_rl6231 > > drm_kms_helper hci_uart ov5693(C) ov2722(C) lm3554(C) btbcm btqca > > v4l2_common snd_soc_core btintel snd_compress videodev snd_pcm_dmaengine > > snd_pcm video bluetooth snd_timer drm media tpm_tis snd i2c_hid soundcore > > tpm_tis_core rfkill_gpio ac97_bus soc_button_array ecdh_generic rfkill > > crc16 tpm 8250_dw intel_gtt syscopyarea sysfillrect acpi_pad sysimgblt > > intel_int0002_vgpio fb_sys_fops pinctrl_cherryview i2c_algo_bit button > > sch_fq_codel tcp_bbr ifb ip_tables x_tables btrfs xor raid6_pq > > algif_skcipher af_alg hid_logitech_hidpp hid_logitech_dj usbhid hid uas > > Sep 18 22:44:32 defiant kernel: usb_storage dm_crypt dm_mod dax raid10 > > md_mod sd_mod crct10dif_pclmul crc32_pclmul crc32c_intel > > ghash_clmulni_intel pcbc ahci aesni_intel xhci_pci libahci aes_x86_64 > > crypto_simd glue_helper xhci_hcd cryptd libata usbcore scsi_mod > > usb_common serio sdhci_acpi sdhci led_class mmc_core > > Sep 18 22:44:32 defiant kernel: CPU: 1 PID: 702 Comm: irq/123-enp3s0 > > Tainted: GWC 4.13.0-pf4 #1 > > Sep 18 22:44:32 defiant kernel: Hardware name: To Be Filled By O.E.M. To > > Be > > Filled By O.E.M./J3710-ITX, BIOS P1.30 03/30/2016 > > Sep 18 22:44:32 defiant kernel: task: 88923a738000 task.stack: > > 95800150 > > Sep 18 22:44:32 defiant kernel: RIP: > > 0010:tcp_undo_cwnd_reduction+0xbd/0xd0 > > Sep 18 22:44:32 defiant kernel: RSP: 0018:88927fc83a48 EFLAGS: > > 00010202 > > Sep 18 22:44:32 defiant kernel: RAX: 0001 RBX: > > 8892412d9800 > > RCX: 88927fc83b0c > > Sep 18 22:44:32 defiant kernel: RDX: 7fff RSI: > > 0001 > > RDI: 8892412d9800 > > Sep 18 22:44:32 defiant kernel: RBP: 88927fc83a50 R08: > > > > R09: 18dfb063 > > Sep 18 22:44:32 defiant kernel: R10: 18dfd223 R11: > > 18dfb063 > > R12: 5320 > > Sep 18 22:44:32 defiant kernel: R13: 88927fc83b10 R14: > > 0001 > > R15: 88927fc83b0c > > Sep 18 22:44:32 defiant kernel: FS: () > > GS:88927fc8() knlGS: > > Sep 18 22:44:32 defiant kernel: CS: 0010 DS: ES: CR0: > > 80050033 > > Sep 18 22:44:32 defiant kernel: CR2: 7f1cd1a43620 CR3: > > 000114a09000 > > CR4: 001006e0 > > Sep 18 22:44:32 defiant kernel: Call Trace: > > Sep 18 22:44:32 defiant kernel: > > Sep 18 22:44:32 defiant kernel: tcp_try_undo_loss+0xb3/0x
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
Hi. 18.09.2017 23:40, Yuchung Cheng wrote: 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?
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Mon, Sep 18, 2017 at 1:46 PM, Oleksandr Natalenko 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. > > === > Sep 18 22:44:32 defiant kernel: [ cut here ] > Sep 18 22:44:32 defiant kernel: WARNING: CPU: 1 PID: 702 at net/ipv4/ > tcp_input.c:2392 tcp_undo_cwnd_reduction+0xbd/0xd0 > Sep 18 22:44:32 defiant kernel: Modules linked in: netconsole ctr ccm cls_bpf > sch_htb act_mirred cls_u32 sch_ingress sit tunnel4 ip_tunnel 8021q mrp > nf_conntrack_ipv6 nf_defrag_ipv6 nft_ct nft_set_bitmap nft_set_hash > nft_set_rbtree nf_tables_inet nf_tables_ipv6 nft_masq_ipv4 > nf_nat_masquerade_ipv4 nft_masq nft_nat nft_counter nft_meta > nft_chain_nat_ipv4 nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat > nf_conntrack libcrc32c crc32c_generic nf_tables_ipv4 nf_tables tun nct6775 > nfnetlink hwmon_vid nls_iso8859_1 nls_cp437 vfat fat ext4 snd_hda_codec_hdmi > mbcache jbd2 snd_hda_codec_realtek snd_hda_codec_generic f2fs arc4 fscrypto > intel_rapl iTCO_wdt ath9k iTCO_vendor_support intel_powerclamp ath9k_common > ath9k_hw coretemp kvm_intel ath mac80211 kvm irqbypass intel_cstate cfg80211 > pcspkr snd_hda_intel snd_hda_codec r8169 > Sep 18 22:44:32 defiant kernel: joydev evdev mii snd_hda_core mousedev > mei_txe input_leds i2c_i801 mac_hid i915 lpc_ich mei shpchp snd_hwdep > snd_intel_sst_acpi snd_intel_sst_core snd_soc_rt5670 > snd_soc_sst_atom_hifi2_platform battery snd_soc_sst_match snd_soc_rl6231 > drm_kms_helper hci_uart ov5693(C) ov2722(C) lm3554(C) btbcm btqca v4l2_common > snd_soc_core btintel snd_compress videodev snd_pcm_dmaengine snd_pcm video > bluetooth snd_timer drm media tpm_tis snd i2c_hid soundcore tpm_tis_core > rfkill_gpio ac97_bus soc_button_array ecdh_generic rfkill crc16 tpm 8250_dw > intel_gtt syscopyarea sysfillrect acpi_pad sysimgblt intel_int0002_vgpio > fb_sys_fops pinctrl_cherryview i2c_algo_bit button sch_fq_codel tcp_bbr ifb > ip_tables x_tables btrfs xor raid6_pq algif_skcipher af_alg hid_logitech_hidpp > hid_logitech_dj usbhid hid uas > Sep 18 22:44:32 defiant kernel: usb_storage dm_crypt dm_mod dax raid10 md_mod > sd_mod crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel pcbc > ahci aesni_intel xhci_pci libahci aes_x86_64 crypto_simd glue_helper xhci_hcd > cryptd libata usbcore scsi_mod usb_common serio sdhci_acpi sdhci led_class > mmc_core > Sep 18 22:44:32 defiant kernel: CPU: 1 PID: 702 Comm: irq/123-enp3s0 Tainted: > GWC 4.13.0-pf4 #1 > Sep 18 22:44:32 defiant kernel: Hardware name: To Be Filled By O.E.M. To Be > Filled By O.E.M./J3710-ITX, BIOS P1.30 03/30/2016 > Sep 18 22:44:32 defiant kernel: task: 88923a738000 task.stack: > 95800150 > Sep 18 22:44:32 defiant kernel: RIP: 0010:tcp_undo_cwnd_reduction+0xbd/0xd0 > Sep 18 22:44:32 defiant kernel: RSP: 0018:88927fc83a48 EFLAGS: 00010202 > Sep 18 22:44:32 defiant kernel: RAX: 0001 RBX: 8892412d9800 > RCX: 88927fc83b0c > Sep 18 22:44:32 defiant kernel: RDX: 7fff RSI: 0001 > RDI: 8892412d9800 > Sep 18 22:44:32 defiant kernel: RBP: 88927fc83a50 R08: > R09: 18dfb063 > Sep 18 22:44:32 defiant kernel: R10: 18dfd223 R11: 18dfb063 > R12: 5320 > Sep 18 22:44:32 defiant kernel: R13: 88927fc83b10 R14: 0001 > R15: 88927fc83b0c > Sep 18 22:44:32 defiant kernel: FS: () > GS:88927fc8() knlGS: > Sep 18 22:44:32 defiant kernel: CS: 0010 DS: ES: CR0: > 80050033 > Sep 18 22:44:32 defiant kernel: CR2: 7f1cd1a43620 CR3: 000114a09000 > CR4: 001006e0 > Sep 18 22:44:32 defiant kernel: Call Trace: > Sep 18 22:44:32 defiant kernel: > Sep 18 22:44:32 defiant kernel: tcp_try_undo_loss+0xb3/0xf0 > Sep 18 22:44:32 defiant kernel: tcp_fastretrans_alert+0x746/0x990 > Sep 18 22:44:32 defiant kernel: tcp_ack+0x741/0x1110 > Sep 18 22:44:32 defiant kernel: tcp_rcv_established+0x325/0x770 > Sep 18 22:44:32 defiant kernel: ? sk_filter_trim_cap+0xd4/0x1a0 > Sep 18 22:44:32 defiant kernel: tcp_v4_do_rcv+0x90/0x1e0 > Sep 18 22:44:32 defiant kernel: tcp_v4_rcv+0x950/0xa10 > Sep 18 22:44:32 defiant kernel: ? nf_ct_deliver_cached_events+0xb8/0x110 > [nf_conntrack] > Sep 18 22:44:32 defiant kernel: ip_local_deliver_finish+0x68/0x210 > Sep 18 22:44:32 defiant kernel: ip_local_deliver+0xfa/0x110 > Sep 18 22:44:32 defiant kernel: ? ip_rcv_finish+0x410/0x410 > Sep 18 22:44:32 defiant kernel: ip_rcv_finish+0x120/0x410 > Sep 18 22:44:32 defiant kernel: ip_rcv+0x28e/0x
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
Actually, same warning was just triggered with RACK enabled. But main warning was not triggered in this case. === Sep 18 22:44:32 defiant kernel: [ cut here ] Sep 18 22:44:32 defiant kernel: WARNING: CPU: 1 PID: 702 at net/ipv4/ tcp_input.c:2392 tcp_undo_cwnd_reduction+0xbd/0xd0 Sep 18 22:44:32 defiant kernel: Modules linked in: netconsole ctr ccm cls_bpf sch_htb act_mirred cls_u32 sch_ingress sit tunnel4 ip_tunnel 8021q mrp nf_conntrack_ipv6 nf_defrag_ipv6 nft_ct nft_set_bitmap nft_set_hash nft_set_rbtree nf_tables_inet nf_tables_ipv6 nft_masq_ipv4 nf_nat_masquerade_ipv4 nft_masq nft_nat nft_counter nft_meta nft_chain_nat_ipv4 nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack libcrc32c crc32c_generic nf_tables_ipv4 nf_tables tun nct6775 nfnetlink hwmon_vid nls_iso8859_1 nls_cp437 vfat fat ext4 snd_hda_codec_hdmi mbcache jbd2 snd_hda_codec_realtek snd_hda_codec_generic f2fs arc4 fscrypto intel_rapl iTCO_wdt ath9k iTCO_vendor_support intel_powerclamp ath9k_common ath9k_hw coretemp kvm_intel ath mac80211 kvm irqbypass intel_cstate cfg80211 pcspkr snd_hda_intel snd_hda_codec r8169 Sep 18 22:44:32 defiant kernel: joydev evdev mii snd_hda_core mousedev mei_txe input_leds i2c_i801 mac_hid i915 lpc_ich mei shpchp snd_hwdep snd_intel_sst_acpi snd_intel_sst_core snd_soc_rt5670 snd_soc_sst_atom_hifi2_platform battery snd_soc_sst_match snd_soc_rl6231 drm_kms_helper hci_uart ov5693(C) ov2722(C) lm3554(C) btbcm btqca v4l2_common snd_soc_core btintel snd_compress videodev snd_pcm_dmaengine snd_pcm video bluetooth snd_timer drm media tpm_tis snd i2c_hid soundcore tpm_tis_core rfkill_gpio ac97_bus soc_button_array ecdh_generic rfkill crc16 tpm 8250_dw intel_gtt syscopyarea sysfillrect acpi_pad sysimgblt intel_int0002_vgpio fb_sys_fops pinctrl_cherryview i2c_algo_bit button sch_fq_codel tcp_bbr ifb ip_tables x_tables btrfs xor raid6_pq algif_skcipher af_alg hid_logitech_hidpp hid_logitech_dj usbhid hid uas Sep 18 22:44:32 defiant kernel: usb_storage dm_crypt dm_mod dax raid10 md_mod sd_mod crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel pcbc ahci aesni_intel xhci_pci libahci aes_x86_64 crypto_simd glue_helper xhci_hcd cryptd libata usbcore scsi_mod usb_common serio sdhci_acpi sdhci led_class mmc_core Sep 18 22:44:32 defiant kernel: CPU: 1 PID: 702 Comm: irq/123-enp3s0 Tainted: GWC 4.13.0-pf4 #1 Sep 18 22:44:32 defiant kernel: Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./J3710-ITX, BIOS P1.30 03/30/2016 Sep 18 22:44:32 defiant kernel: task: 88923a738000 task.stack: 95800150 Sep 18 22:44:32 defiant kernel: RIP: 0010:tcp_undo_cwnd_reduction+0xbd/0xd0 Sep 18 22:44:32 defiant kernel: RSP: 0018:88927fc83a48 EFLAGS: 00010202 Sep 18 22:44:32 defiant kernel: RAX: 0001 RBX: 8892412d9800 RCX: 88927fc83b0c Sep 18 22:44:32 defiant kernel: RDX: 7fff RSI: 0001 RDI: 8892412d9800 Sep 18 22:44:32 defiant kernel: RBP: 88927fc83a50 R08: R09: 18dfb063 Sep 18 22:44:32 defiant kernel: R10: 18dfd223 R11: 18dfb063 R12: 5320 Sep 18 22:44:32 defiant kernel: R13: 88927fc83b10 R14: 0001 R15: 88927fc83b0c Sep 18 22:44:32 defiant kernel: FS: () GS:88927fc8() knlGS: Sep 18 22:44:32 defiant kernel: CS: 0010 DS: ES: CR0: 80050033 Sep 18 22:44:32 defiant kernel: CR2: 7f1cd1a43620 CR3: 000114a09000 CR4: 001006e0 Sep 18 22:44:32 defiant kernel: Call Trace: Sep 18 22:44:32 defiant kernel: Sep 18 22:44:32 defiant kernel: tcp_try_undo_loss+0xb3/0xf0 Sep 18 22:44:32 defiant kernel: tcp_fastretrans_alert+0x746/0x990 Sep 18 22:44:32 defiant kernel: tcp_ack+0x741/0x1110 Sep 18 22:44:32 defiant kernel: tcp_rcv_established+0x325/0x770 Sep 18 22:44:32 defiant kernel: ? sk_filter_trim_cap+0xd4/0x1a0 Sep 18 22:44:32 defiant kernel: tcp_v4_do_rcv+0x90/0x1e0 Sep 18 22:44:32 defiant kernel: tcp_v4_rcv+0x950/0xa10 Sep 18 22:44:32 defiant kernel: ? nf_ct_deliver_cached_events+0xb8/0x110 [nf_conntrack] Sep 18 22:44:32 defiant kernel: ip_local_deliver_finish+0x68/0x210 Sep 18 22:44:32 defiant kernel: ip_local_deliver+0xfa/0x110 Sep 18 22:44:32 defiant kernel: ? ip_rcv_finish+0x410/0x410 Sep 18 22:44:32 defiant kernel: ip_rcv_finish+0x120/0x410 Sep 18 22:44:32 defiant kernel: ip_rcv+0x28e/0x3b0 Sep 18 22:44:32 defiant kernel: ? inet_del_offload+0x40/0x40 Sep 18 22:44:32 defiant kernel: __netif_receive_skb_core+0x39b/0xb00 Sep 18 22:44:32 defiant kernel: ? netif_receive_skb_internal+0xa0/0x480 Sep 18 22:44:32 defiant kernel: ? dev_gro_receive+0x2eb/0x4a0 Sep 18 22:44:32 defiant kernel: __netif_receive_skb+0x18/0x60 Sep 18 22:44:32 defiant kernel: netif_receive_skb_internal+0x98/0x480 Sep 18 22:44:32 defiant kernel: netif_receive_skb+0x1c/0x80 Sep 18 22:44:32 defiant kernel: ifb_ri_tasklet+0x109/0x26a [ifb] Sep 18
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
OK, with: net.ipv4.tcp_recovery = 0 net.ipv4.tcp_fack = 0 and your patch I got the following warning within 10 min uptime: === Sep 18 22:18:34 defiant kernel: [ cut here ] Sep 18 22:18:34 defiant kernel: WARNING: CPU: 0 PID: 702 at net/ipv4/ tcp_input.c:2392 tcp_undo_cwnd_reduction+0xbd/0xd0 Sep 18 22:18:34 defiant kernel: Modules linked in: netconsole ctr ccm cls_bpf sch_htb act_mirred cls_u32 sch_ingress sit tunnel4 ip_tunnel 8021q mrp nf_conntrack_ipv6 nf_defrag_ipv6 nft_ct nft_set_bitmap nft_set_hash nft_set_rbtree nf_tables_inet nf_tables_ipv6 nft_masq_ipv4 nf_nat_masquerade_ipv4 nft_masq nft_nat nft_counter nft_meta nft_chain_nat_ipv4 nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack libcrc32c crc32c_generic nf_tables_ipv4 nf_tables tun nct6775 nfnetlink hwmon_vid nls_iso8859_1 nls_cp437 vfat fat ext4 snd_hda_codec_hdmi mbcache jbd2 snd_hda_codec_realtek snd_hda_codec_generic f2fs arc4 fscrypto intel_rapl iTCO_wdt ath9k iTCO_vendor_support intel_powerclamp ath9k_common ath9k_hw coretemp kvm_intel ath mac80211 kvm irqbypass intel_cstate cfg80211 pcspkr snd_hda_intel snd_hda_codec r8169 Sep 18 22:18:34 defiant kernel: joydev evdev mii snd_hda_core mousedev mei_txe input_leds i2c_i801 mac_hid i915 lpc_ich mei shpchp snd_hwdep snd_intel_sst_acpi snd_intel_sst_core snd_soc_rt5670 snd_soc_sst_atom_hifi2_platform battery snd_soc_sst_match snd_soc_rl6231 drm_kms_helper hci_uart ov5693(C) ov2722(C) lm3554(C) btbcm btqca v4l2_common snd_soc_core btintel snd_compress videodev snd_pcm_dmaengine snd_pcm video bluetooth snd_timer drm media tpm_tis snd i2c_hid soundcore tpm_tis_core rfkill_gpio ac97_bus soc_button_array ecdh_generic rfkill crc16 tpm 8250_dw intel_gtt syscopyarea sysfillrect acpi_pad sysimgblt intel_int0002_vgpio fb_sys_fops pinctrl_cherryview i2c_algo_bit button sch_fq_codel tcp_bbr ifb ip_tables x_tables btrfs xor raid6_pq algif_skcipher af_alg hid_logitech_hidpp hid_logitech_dj usbhid hid uas Sep 18 22:18:34 defiant kernel: usb_storage dm_crypt dm_mod dax raid10 md_mod sd_mod crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel pcbc ahci aesni_intel xhci_pci libahci aes_x86_64 crypto_simd glue_helper xhci_hcd cryptd libata usbcore scsi_mod usb_common serio sdhci_acpi sdhci led_class mmc_core Sep 18 22:18:34 defiant kernel: CPU: 0 PID: 702 Comm: irq/123-enp3s0 Tainted: G C 4.13.0-pf4 #1 Sep 18 22:18:34 defiant kernel: Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./J3710-ITX, BIOS P1.30 03/30/2016 Sep 18 22:18:34 defiant kernel: task: 88923a738000 task.stack: 95800150 Sep 18 22:18:34 defiant kernel: RIP: 0010:tcp_undo_cwnd_reduction+0xbd/0xd0 Sep 18 22:18:34 defiant kernel: RSP: 0018:88927fc03a48 EFLAGS: 00010202 Sep 18 22:18:34 defiant kernel: RAX: 0001 RBX: 889241130800 RCX: 88927fc03b0c Sep 18 22:18:34 defiant kernel: RDX: 7fff RSI: 0001 RDI: 889241130800 Sep 18 22:18:34 defiant kernel: RBP: 88927fc03a50 R08: R09: 7b3e89be Sep 18 22:18:34 defiant kernel: R10: 7b3ea2f6 R11: 7b3e89be R12: 5320 Sep 18 22:18:34 defiant kernel: R13: 88927fc03b10 R14: 0001 R15: 88927fc03b0c Sep 18 22:18:34 defiant kernel: FS: () GS:88927fc0() knlGS: Sep 18 22:18:34 defiant kernel: CS: 0010 DS: ES: CR0: 80050033 Sep 18 22:18:34 defiant kernel: CR2: 7fe9c4106898 CR3: 000114a09000 CR4: 001006f0 Sep 18 22:18:34 defiant kernel: Call Trace: Sep 18 22:18:34 defiant kernel: Sep 18 22:18:34 defiant kernel: tcp_try_undo_loss+0xb3/0xf0 Sep 18 22:18:34 defiant kernel: tcp_fastretrans_alert+0x746/0x990 Sep 18 22:18:34 defiant kernel: tcp_ack+0x741/0x1110 Sep 18 22:18:34 defiant kernel: tcp_rcv_established+0x325/0x770 Sep 18 22:18:34 defiant kernel: ? sk_filter_trim_cap+0xd4/0x1a0 Sep 18 22:18:34 defiant kernel: tcp_v4_do_rcv+0x90/0x1e0 Sep 18 22:18:34 defiant kernel: tcp_v4_rcv+0x950/0xa10 Sep 18 22:18:34 defiant kernel: ? nf_ct_deliver_cached_events+0xb8/0x110 [nf_conntrack] Sep 18 22:18:34 defiant kernel: ip_local_deliver_finish+0x68/0x210 Sep 18 22:18:34 defiant kernel: ip_local_deliver+0xfa/0x110 Sep 18 22:18:34 defiant kernel: ? ip_rcv_finish+0x410/0x410 Sep 18 22:18:34 defiant kernel: ip_rcv_finish+0x120/0x410 Sep 18 22:18:34 defiant kernel: ip_rcv+0x28e/0x3b0 Sep 18 22:18:34 defiant kernel: ? inet_del_offload+0x40/0x40 Sep 18 22:18:34 defiant kernel: __netif_receive_skb_core+0x39b/0xb00 Sep 18 22:18:34 defiant kernel: ? skb_release_all+0x24/0x30 Sep 18 22:18:34 defiant kernel: ? consume_skb+0x38/0xa0 Sep 18 22:18:34 defiant kernel: __netif_receive_skb+0x18/0x60 Sep 18 22:18:34 defiant kernel: netif_receive_skb_internal+0x98/0x480 Sep 18 22:18:34 defiant kernel: netif_receive_skb+0x1c/0x80 Sep 18 22:18:34 defiant kernel: ifb_ri_tasklet+0x109/0x26a [ifb] Sep 18 22:
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On pondělí 18. září 2017 20:01:42 CEST Yuchung Cheng wrote: > Yes since it is disabled in the upstream by default. Although you can > experiment FACK enabled additionally. OK. > Do we know the crash you first experienced is tied to this issue? No, unfortunately. I wasn't able to re-create it again, so lets focus on tcp_fastretrans_alert warning only.
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Mon, Sep 18, 2017 at 10:59 AM, Oleksandr Natalenko 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: >> Can you try this patch to verify my theory with tcp_recovery=0 and 1? thanks >> >> diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c >> index 5af2f04f8859..9253d9ee7d0e 100644 >> --- a/net/ipv4/tcp_input.c >> +++ b/net/ipv4/tcp_input.c >> @@ -2381,6 +2381,7 @@ static void tcp_undo_cwnd_reduction(struct sock >> *sk, bool unmark_loss) >> } >> tp->snd_cwnd_stamp = tcp_time_stamp; >> tp->undo_marker = 0; >> + WARN_ON(tp->retrans_out); >> } >
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
OK. Should I keep FACK disabled? On pondělí 18. září 2017 19:51:21 CEST Yuchung Cheng wrote: > Can you try this patch to verify my theory with tcp_recovery=0 and 1? thanks > > diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c > index 5af2f04f8859..9253d9ee7d0e 100644 > --- a/net/ipv4/tcp_input.c > +++ b/net/ipv4/tcp_input.c > @@ -2381,6 +2381,7 @@ static void tcp_undo_cwnd_reduction(struct sock > *sk, bool unmark_loss) > } > tp->snd_cwnd_stamp = tcp_time_stamp; > tp->undo_marker = 0; > + WARN_ON(tp->retrans_out); > }
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Mon, Sep 18, 2017 at 10:18 AM, Yuchung Cheng wrote: > On Sun, Sep 17, 2017 at 11:43 AM, Oleksandr Natalenko > 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. Can you try this patch to verify my theory with tcp_recovery=0 and 1? thanks diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c index 5af2f04f8859..9253d9ee7d0e 100644 --- a/net/ipv4/tcp_input.c +++ b/net/ipv4/tcp_input.c @@ -2381,6 +2381,7 @@ static void tcp_undo_cwnd_reduction(struct sock *sk, bool unmark_loss) } tp->snd_cwnd_stamp = tcp_time_stamp; tp->undo_marker = 0; + WARN_ON(tp->retrans_out); } > > >> >> 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 %MEMVSZ RSS TTY STAT START TIME COMMAND >>> root 711 4.3 0.0 0 0 ?S18: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...] >> >>
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Sun, Sep 17, 2017 at 11:43 AM, Oleksandr Natalenko 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: >> 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 %MEMVSZ RSS TTY STAT START TIME COMMAND >> root 711 4.3 0.0 0 0 ?S18: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...] > >
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
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 %MEMVSZ RSS TTY STAT START TIME COMMAND > root 711 4.3 0.0 0 0 ?S18: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...]
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
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 %MEMVSZ RSS TTY STAT START TIME COMMAND root 711 4.3 0.0 0 0 ?S18: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...]
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Fri, Sep 15, 2017 at 1:03 AM, Oleksandr Natalenko 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...]
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
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: > 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: > > diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c > index 659d1baefb2b..730a2de9d2b0 100644 > --- a/net/ipv4/tcp_input.c > +++ b/net/ipv4/tcp_input.c > @@ -2439,7 +2439,7 @@ static bool tcp_try_undo_loss(struct sock *sk, > 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
Re: [REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
On Sun, Sep 10, 2017 at 4:53 PM, Oleksandr Natalenko 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: diff --git a/net/ipv4/tcp_input.c b/net/ipv4/tcp_input.c index 659d1baefb2b..730a2de9d2b0 100644 --- a/net/ipv4/tcp_input.c +++ b/net/ipv4/tcp_input.c @@ -2439,7 +2439,7 @@ static bool tcp_try_undo_loss(struct sock *sk, 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
[REGRESSION] Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
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. Also, I have custom settings regarding TCP stack, shown below as well. ifb is used to shape traffic with tc. Please note this regression was already reported as BZ [1] and as a letter to ML [2], but got neither attention nor resolution. It is reproducible for (not only) me on my home router since v4.11 till v4.13.1 incl. Please advise on how to deal with it. I'll provide any additional info if necessary, also ready to test patches if any. Thanks. [1] https://bugzilla.kernel.org/show_bug.cgi?id=195835 [2] https://www.spinics.net/lists/netdev/msg436158.html === warning [14407.060066] [ cut here ] [14407.060353] WARNING: CPU: 0 PID: 719 at net/ipv4/tcp_input.c:2826 tcp_fastretrans_alert+0x7c8/0x990 [14407.060747] Modules linked in: netconsole ctr ccm cls_bpf sch_htb act_mirred cls_u32 sch_ingress sit tunnel4 ip_tunnel 8021q mrp nf _conntrack_ipv6 nf_defrag_ipv6 nft_ct nft_set_bitmap nft_set_hash nft_set_rbtree nf_tables_inet nf_tables_ipv6 nft_masq_ipv4 nf_nat_ma squerade_ipv4 nft_masq nft_nat nft_counter nft_meta nft_chain_nat_ipv4 nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrac k libcrc32c crc32c_generic nf_tables_ipv4 tun nf_tables nfnetlink nct6775 hwmon_vid nls_iso8859_1 nls_cp437 vfat fat ext4 mbcache jbd2 arc4 f2fs snd_hda_codec_hdmi fscrypto snd_hda_codec_realtek snd_hda_codec_generic intel_rapl intel_powerclamp coretemp iTCO_wdt iTCO_ vendor_support ath9k ath9k_common kvm_intel ath9k_hw kvm ath irqbypass intel_cstate mac80211 pcspkr snd_intel_sst_acpi i2c_i801 i915 s nd_hda_intel [14407.063800] snd_intel_sst_core r8169 cfg80211 evdev mii snd_hda_codec joydev mousedev input_leds snd_soc_rt5670 mei_txe snd_soc_ss t_atom_hifi2_platform snd_hda_core snd_soc_rl6231 snd_soc_sst_match mac_hid mei lpc_ich shpchp drm_kms_helper snd_hwdep snd_soc_core s nd_compress battery snd_pcm_dmaengine drm hci_uart ov2722(C) snd_pcm lm3554(C) ov5693(C) snd_timer v4l2_common btbcm snd intel_gtt btq ca btintel videodev syscopyarea bluetooth video soundcore sysfillrect media sysimgblt ac97_bus ecdh_generic rfkill_gpio i2c_hid rfkill tpm_tis crc16 fb_sys_fops i2c_algo_bit 8250_dw tpm_tis_core tpm soc_button_array pinctrl_cherryview intel_int0002_vgpio acpi_pad butt on sch_fq_codel tcp_bbr ifb ip_tables x_tables btrfs xor raid6_pq algif_skcipher af_alg hid_logitech_hidpp hid_logitech_dj usbhid hid uas usb_storage [14407.066873] dm_crypt dm_mod dax raid10 md_mod sd_mod crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel pcbc aesni_int el aes_x86_64 crypto_simd glue_helper cryptd ahci xhci_pci libahci xhci_hcd libata usbcore scsi_mod usb_common serio sdhci_acpi sdhci led_class mmc_core [14407.068034] CPU: 0 PID: 719 Comm: irq/123-enp3s0 Tainted: G C 4.13.0-pf2 #1 [14407.068403] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./ J3710-ITX, BIOS P1.30 03/30/2016 [14407.068827] task: 98b1c0a05400 task.stack: bb59c15c [14407.069111] RIP: 0010:tcp_fastretrans_alert+0x7c8/0x990 [14407.069358] RSP: 0018:98b1ffc03a78 EFLAGS: 00010202 [14407.069607] RAX: RBX: 98b135ae RCX: 98b1ffc03b0c [14407.069928] RDX: 0001 RSI: 0001 RDI: 98b135ae [14407.070248] RBP: 98b1ffc03ab8 R08: R09: 98b1ffc03b60 [14407.070565] R10: R11: R12: 5120 [14407.070884] R13: 98b1ffc03b10 R14: 0001 R15: 98b1ffc03b0c [14407.071205] FS: () GS:98b1ffc0() knlGS: [14407.071564] CS: 0010 DS: ES: CR0: 80050033 [14407.071827] CR2: 7ffc580b2f0f CR3: 10a09000 CR4: 001006f0 [14407.072146] Call Trace: [14407.072279] [14407.072412] ? sk_reset_timer+0x18/0x30 [14407.072610] tcp_ack+0x741/0x1110 [14407.072810] tcp_rcv_established+0x325/0x770 [14407.073033] ? sk_filter_trim_cap+0xd4/0x1a0 [14407.073249] tcp_v4_do_rcv+0x90/0x1e0 [14407.073449] tcp_v4_rcv+0x950/0xa10 [14407.073647] ? nf_ct_deliver_cached_events+0xb8/0x110 [nf_conntrack] [14407.073955] ip_local_deliver_finish+0x68/0x210 [14407.074183] ip_local_deliver+0xfa/0x110 [14407.074385] ? ip_rcv_finish+0x410/0x410 [14407.074589] ip_rcv_finish+0x120/0x410 [14407.074782] ip_rcv+0x28e/0x3b0 [14407.074952] ? inet_del_offload+0x40/0x40 [14407.075154] __netif_receive_skb_core+0x39b/0xb00 [14407.075389] ? netif_receive_skb_internal+0xa0/0x480 [14407.075635] ? skb_release_all+0x24/0x30 [14407.075832] ? consume_skb+0x38/0xa0 [14407.076025] __netif_receive_skb+0x18/0x