Warning in tcp_fastretrans_alert() of net/ipv4/tcp_input.c
Subsystems (3)
Quoted 16 lines
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()(becausesk_buffpassed 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.
Quoted 7 lines
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: G W 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] <IRQ> [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:00007f8cb925f078 EFLAGS: 00000206 [973978.504251] ORIG_RAX: ffffffffffffff5f [973978.512085] RAX: 00007f8cb925f1a8 RBX: 0000000048000000 RCX: 00007f8764bd6a80 [973978.526508] RDX: 00000000000001ba RSI: 00007f7cb4ca3410 RDI: 00007f7cb4ca3410 [973978.540927] RBP: 000000000000000d R08: 00007f8764bd6b00 R09: 00007f8764bd6b80 [973978.555347] R10: 0000000000002400 R11: 00007f8dee58e240 R12: d3273c84146e8c29 [973978.569766] R13: 9dac83ddf04c235c R14: 00007f7cb4ca33b0 R15: 00007f7cb4ca4f50 [973978.584189] </IRQ> [973978.588650] ---[ end trace 5d1c83e12a57d039 ]--- [973995.178183] BUG: unable to handle kernel [973995.186385] NULL pointer dereference [973995.193692] at 0000000000000028 [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: 0000 [#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_i801 [973995.464209] ipmi_msghandler [973995.470138] acpi_cpufreq [973995.475545] button [973995.479914] sch_fq_codel [973995.485319] nfsd [973995.489341] auth_rpcgss [973995.494573] nfs_acl [973995.499114] oid_registry [973995.504524] lockd [973995.508717] grace [973995.512912] sunrpc [973995.517280] megaraid_sas [973995.522689] fuse [973995.526709] sg [973995.530382] loop [973995.534405] efivarfs [973995.539118] autofs4 [973995.543660] CPU: 19 PID: 3806297 Comm: ld:srv:W0 Tainted: G W 4.11.3-7_fbk1_1174_ga56eebf #7 [973995.562936] Hardware name: Wiwynn Leopard-Orv2/Leopard-DDR BW, BIOS LBM06 10/28/2016 [973995.578914] task: ffff880129e5c380 task.stack: ffffc900210cc000 [973995.590914] RIP: 0010:tcp_sacktag_walk+0x2b7/0x460 [973995.600648] RSP: 0000:ffff88203ef438e8 EFLAGS: 00010207 [973995.611254] RAX: 0000000000000001 RBX: 0000000000000000 RCX: 000000004e4ec474 [973995.625677] RDX: 000000004e4ec2ad RSI: ffff8810361faa00 RDI: ffff881ffecf8840 [973995.640102] RBP: ffff88203ef43940 R08: 0000000045729921 R09: 0000000000000000 [973995.654519] R10: 00000000000085d6 R11: ffff881ffecf8998 R12: ffff881ffecf8840 [973995.668938] R13: ffff88203ef43a48 R14: 0000000000000000 R15: ffff881ffecf8998 [973995.683362] FS: 00007f8cc8cf7700(0000) GS:ffff88203ef40000(0000) knlGS:0000000000000000 [973995.699686] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [973995.711331] CR2: 0000000000000028 CR3: 0000000104c1b000 CR4: 00000000003406e0 [973995.725755] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [973995.740175] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [973995.754595] Call Trace: [973995.759652] <IRQ> [973995.763855] ? kprobe_perf_func+0x28/0x210 [973995.772210] tcp_sacktag_write_queue+0x5ff/0x9e0 [973995.781615] tcp_ack+0x677/0x1390 [973995.788408] tcp_rcv_established+0x1ce/0x740 [973995.797112] tcp_v6_do_rcv+0x195/0x440 [973995.804767] tcp_v6_rcv+0x94c/0x9f0 [973995.811911] ip6_input_finish+0xea/0x430 [973995.819917] ip6_input+0x32/0xa0 [973995.826538] ? ip6_rcv_finish+0xa0/0xa0 [973995.834373] ip6_rcv_finish+0x4b/0xa0 [973995.841859] ipv6_rcv+0x2ec/0x4f0 [973995.848653] ? ip6_fragment+0x9f0/0x9f0 [973995.856489] ? ip6_make_skb+0x1c0/0x1c0 [973995.864323] __netif_receive_skb_core+0x2d5/0x9a0 [973995.873891] __netif_receive_skb+0x16/0x70 [973995.882244] netif_receive_skb_internal+0x23/0x80 [973995.891812] napi_gro_receive+0x113/0x1d0 [973995.899993] mlx5e_handle_rx_cqe_mpwrq+0x5b6/0x8d0 [973995.909735] mlx5e_poll_rx_cq+0x7c/0x7f0 [973995.917740] mlx5e_napi_poll+0x8c/0x380 [973995.925576] ? mlx5_cq_completion+0x54/0xb0 [973995.934101] net_rx_action+0x22e/0x380 [973995.941764] __do_softirq+0x106/0x2e8 [973995.949255] irq_exit+0xb0/0xc0 [973995.955696] do_IRQ+0x4f/0xd0 [973995.961798] common_interrupt+0x86/0x86 [973995.969634] RIP: 0033:0x7f8dec97a557 [973995.976945] RSP: 002b:00007f8cc8cf2f48 EFLAGS: 00000206 [973995.987552] ORIG_RAX: ffffffffffffff20 [973995.995386] RAX: 00007f7fa9e15230 RBX: 00007f8c2153a160 RCX: 00007f7fa9e15230 [973996.009810] RDX: 0000000000000000 RSI: 00007f8cc8cf3040 RDI: 00007f8c204f90c0 [973996.024230] RBP: 00007f8cc8cf2f80 R08: 0000000000000001 R09: 000131aa4c002c01 [973996.038652] R10: 0000000000000000 R11: 0000000000000001 R12: 00007f8c2153a170 [973996.053073] R13: 00007f8cc8cf3040 R14: 00007f8c204f90c0 R15: 00007f8c2153a120 [973996.067494] </IRQ> [973996.071858] Code: [973996.076051] b9 [973996.079723] 01 [973996.083383] 00 [973996.087056] 00 [973996.090730] 00 [973996.094388] 85 [973996.098062] c0 [973996.101738] 0f [973996.105410] 8e [973996.109087] da [973996.112759] fd [973996.116433] ff [973996.120109] ff [973996.123783] 85 [973996.127457] c0 [973996.131132] 75 [973996.134806] 28 [973996.138481] 0f [973996.142156] b7 [973996.145831] 43 [973996.149504] 30 [973996.153180] 41 [973996.156835] 01 [973996.160511] 45 [973996.164168] 04 [973996.167843] 48 [973996.171517] 8b [973996.175190] 1b [973996.178848] 4c [973996.182521] 39 [973996.186198] fb [973996.189872] 74 [973996.193529] 8c [973996.197202] 49 [973996.200877] 3b [973996.204534] 9c [973996.208209] 24 [973996.211883] 50 [973996.215559] 01 [973996.219215] 00 [973996.222889] 00 [973996.226562] 74 [973996.230221] c1 [973996.233894] <8b> [973996.237916] 43 [973996.241590] 28 [973996.245264] 3b [973996.248921] 45 [973996.252596] d4 [973996.256271] 0f [973996.259929] 88 [973996.263601] 9f [973996.267276] fd [973996.270935] ff [973996.274592] ff [973996.278267] eb [973996.281938] b3 [973996.285614] 48 [973996.289289] 8d [973996.292964] 43 [973996.296638] 10 [973996.300296] 8b [973996.303969] 4b [973996.307642] 28 [973996.311325] RIP: tcp_sacktag_walk+0x2b7/0x460 RSP: ffff88203ef438e8 [973996.324007] ------------[ cut here ]------------ [973996.333399] CR2: 0000000000000028 [973996.340218] ---[ end trace 5d1c83e12a57d03a ]--- [973996.349605] Kernel panic - not syncing: Fatal exception in interrupt [973996.362521] Kernel Offset: disabled
TBOOT: wait until all APs ready for txt shutdown
TBOOT: IA32_FEATURE_CONTROL_MSR: 0000ff07
TBOOT: CPU is SMX-capable
TBOOT: CPU is VMX-capable
TBOOT: SMX is enabled
TBOOT: TXT chipset and all needed capabilities present
TBOOT: TPM: Pcr 17 extend, return value = 0000003D
TBOOT: TPM: Pcr 18 extend, return value = 0000003D
TBOOT: TPM: Pcr 19 extend, return value = 0000003D
TBOOT: cap'ed dynamic PCRs
TBOOT: waiting for APs (0) to exit guests...
TBOOT: .
TBOOT:
TBOOT: all APs exited guests
TBOOT: calling txt_shutdown on AP
Thanks!
Quoted 22 lines · Roman Gushchin
Quoted 22 lines
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()(becausesk_buffpassed 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.
Quoted 8 lines
Quoted 2 lines
[1] https://bugzilla.kernel.org/show_bug.cgi?id=195835
[2] https://www.spinics.net/lists/netdev/msg436158.htmlWe're experiencing the same problems on some machines in our fleet. Exactly the same symptoms:
tcp_fastretrans_alert()warnings and sometimes panics intcp_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
Quoted 259 lines
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: G W 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] <IRQ> [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:00007f8cb925f078 EFLAGS: 00000206 [973978.504251] ORIG_RAX: ffffffffffffff5f [973978.512085] RAX: 00007f8cb925f1a8 RBX: 0000000048000000 RCX: 00007f8764bd6a80 [973978.526508] RDX: 00000000000001ba RSI: 00007f7cb4ca3410 RDI: 00007f7cb4ca3410 [973978.540927] RBP: 000000000000000d R08: 00007f8764bd6b00 R09: 00007f8764bd6b80 [973978.555347] R10: 0000000000002400 R11: 00007f8dee58e240 R12: d3273c84146e8c29 [973978.569766] R13: 9dac83ddf04c235c R14: 00007f7cb4ca33b0 R15: 00007f7cb4ca4f50 [973978.584189] </IRQ> [973978.588650] ---[ end trace 5d1c83e12a57d039 ]--- [973995.178183] BUG: unable to handle kernel [973995.186385] NULL pointer dereference [973995.193692] at 0000000000000028 [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: 0000 [#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_i801 [973995.464209] ipmi_msghandler [973995.470138] acpi_cpufreq [973995.475545] button [973995.479914] sch_fq_codel [973995.485319] nfsd [973995.489341] auth_rpcgss [973995.494573] nfs_acl [973995.499114] oid_registry [973995.504524] lockd [973995.508717] grace [973995.512912] sunrpc [973995.517280] megaraid_sas [973995.522689] fuse [973995.526709] sg [973995.530382] loop [973995.534405] efivarfs [973995.539118] autofs4 [973995.543660] CPU: 19 PID: 3806297 Comm: ld:srv:W0 Tainted: G W 4.11.3-7_fbk1_1174_ga56eebf #7 [973995.562936] Hardware name: Wiwynn Leopard-Orv2/Leopard-DDR BW, BIOS LBM06 10/28/2016 [973995.578914] task: ffff880129e5c380 task.stack: ffffc900210cc000 [973995.590914] RIP: 0010:tcp_sacktag_walk+0x2b7/0x460 [973995.600648] RSP: 0000:ffff88203ef438e8 EFLAGS: 00010207 [973995.611254] RAX: 0000000000000001 RBX: 0000000000000000 RCX: 000000004e4ec474 [973995.625677] RDX: 000000004e4ec2ad RSI: ffff8810361faa00 RDI: ffff881ffecf8840 [973995.640102] RBP: ffff88203ef43940 R08: 0000000045729921 R09: 0000000000000000 [973995.654519] R10: 00000000000085d6 R11: ffff881ffecf8998 R12: ffff881ffecf8840 [973995.668938] R13: ffff88203ef43a48 R14: 0000000000000000 R15: ffff881ffecf8998 [973995.683362] FS: 00007f8cc8cf7700(0000) GS:ffff88203ef40000(0000) knlGS:0000000000000000 [973995.699686] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [973995.711331] CR2: 0000000000000028 CR3: 0000000104c1b000 CR4: 00000000003406e0 [973995.725755] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [973995.740175] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [973995.754595] Call Trace: [973995.759652] <IRQ> [973995.763855] ? kprobe_perf_func+0x28/0x210 [973995.772210] tcp_sacktag_write_queue+0x5ff/0x9e0 [973995.781615] tcp_ack+0x677/0x1390 [973995.788408] tcp_rcv_established+0x1ce/0x740 [973995.797112] tcp_v6_do_rcv+0x195/0x440 [973995.804767] tcp_v6_rcv+0x94c/0x9f0 [973995.811911] ip6_input_finish+0xea/0x430 [973995.819917] ip6_input+0x32/0xa0 [973995.826538] ? ip6_rcv_finish+0xa0/0xa0 [973995.834373] ip6_rcv_finish+0x4b/0xa0 [973995.841859] ipv6_rcv+0x2ec/0x4f0 [973995.848653] ? ip6_fragment+0x9f0/0x9f0 [973995.856489] ? ip6_make_skb+0x1c0/0x1c0 [973995.864323] __netif_receive_skb_core+0x2d5/0x9a0 [973995.873891] __netif_receive_skb+0x16/0x70 [973995.882244] netif_receive_skb_internal+0x23/0x80 [973995.891812] napi_gro_receive+0x113/0x1d0 [973995.899993] mlx5e_handle_rx_cqe_mpwrq+0x5b6/0x8d0 [973995.909735] mlx5e_poll_rx_cq+0x7c/0x7f0 [973995.917740] mlx5e_napi_poll+0x8c/0x380 [973995.925576] ? mlx5_cq_completion+0x54/0xb0 [973995.934101] net_rx_action+0x22e/0x380 [973995.941764] __do_softirq+0x106/0x2e8 [973995.949255] irq_exit+0xb0/0xc0 [973995.955696] do_IRQ+0x4f/0xd0 [973995.961798] common_interrupt+0x86/0x86 [973995.969634] RIP: 0033:0x7f8dec97a557 [973995.976945] RSP: 002b:00007f8cc8cf2f48 EFLAGS: 00000206 [973995.987552] ORIG_RAX: ffffffffffffff20 [973995.995386] RAX: 00007f7fa9e15230 RBX: 00007f8c2153a160 RCX: 00007f7fa9e15230 [973996.009810] RDX: 0000000000000000 RSI: 00007f8cc8cf3040 RDI: 00007f8c204f90c0 [973996.024230] RBP: 00007f8cc8cf2f80 R08: 0000000000000001 R09: 000131aa4c002c01 [973996.038652] R10: 0000000000000000 R11: 0000000000000001 R12: 00007f8c2153a170 [973996.053073] R13: 00007f8cc8cf3040 R14: 00007f8c204f90c0 R15: 00007f8c2153a120 [973996.067494] </IRQ> [973996.071858] Code: [973996.076051] b9 [973996.079723] 01 [973996.083383] 00 [973996.087056] 00 [973996.090730] 00 [973996.094388] 85 [973996.098062] c0 [973996.101738] 0f [973996.105410] 8e [973996.109087] da [973996.112759] fd [973996.116433] ff [973996.120109] ff [973996.123783] 85 [973996.127457] c0 [973996.131132] 75 [973996.134806] 28 [973996.138481] 0f [973996.142156] b7 [973996.145831] 43 [973996.149504] 30 [973996.153180] 41 [973996.156835] 01 [973996.160511] 45 [973996.164168] 04 [973996.167843] 48 [973996.171517] 8b [973996.175190] 1b [973996.178848] 4c [973996.182521] 39 [973996.186198] fb [973996.189872] 74 [973996.193529] 8c [973996.197202] 49 [973996.200877] 3b [973996.204534] 9c [973996.208209] 24 [973996.211883] 50 [973996.215559] 01 [973996.219215] 00 [973996.222889] 00 [973996.226562] 74 [973996.230221] c1 [973996.233894] <8b> [973996.237916] 43 [973996.241590] 28 [973996.245264] 3b [973996.248921] 45 [973996.252596] d4 [973996.256271] 0f [973996.259929] 88 [973996.263601] 9f [973996.267276] fd [973996.270935] ff [973996.274592] ff [973996.278267] eb [973996.281938] b3 [973996.285614] 48 [973996.289289] 8d [973996.292964] 43 [973996.296638] 10 [973996.300296] 8b [973996.303969] 4b [973996.307642] 28 [973996.311325] RIP: tcp_sacktag_walk+0x2b7/0x460 RSP: ffff88203ef438e8 [973996.324007] ------------[ cut here ]------------ [973996.333399] CR2: 0000000000000028 [973996.340218] ---[ end trace 5d1c83e12a57d03a ]--- [973996.349605] Kernel panic - not syncing: Fatal exception in interrupt [973996.362521] Kernel Offset: disabledTBOOT: wait until all APs ready for txt shutdown
TBOOT:IA32_FEATURE_CONTROL_MSR:0000ff07
TBOOT: CPU is SMX-capable
TBOOT: CPU is VMX-capable
TBOOT: SMX is enabled
TBOOT: TXT chipset and all needed capabilities present
TBOOT: TPM: Pcr 17 extend, return value = 0000003D
TBOOT: TPM: Pcr 18 extend, return value = 0000003D
TBOOT: TPM: Pcr 19 extend, return value = 0000003D
TBOOT: cap'ed dynamic PCRs
TBOOT: waiting for APs (0) to exit guests...
TBOOT: .
TBOOT:
TBOOT: all APs exited guests
TBOOT: callingtxt_shutdownon APThanks!
Quoted 23 lines · Roman Gushchin
Quoted 22 lines
Quoted 22 lines
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()(becausesk_buffpassed 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.
Quoted 8 lines
Quoted 8 lines
Quoted 2 lines
[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 intcp_sacktag_walk().Here is an example of a backtrace with the panic log:
Hi Yuchung!
Quoted 2 lines
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.
Quoted 3 lines
also have you experience any sack reneg? could you post the output of ' nstat |grep -i TCP' thanks
hostname TcpActiveOpens 2289680 0.0 hostname TcpPassiveOpens 3592758 0.0 hostname TcpAttemptFails 746910 0.0 hostname TcpEstabResets 154988 0.0 hostname TcpInSegs 16258678255 0.0 hostname TcpOutSegs 46967011611 0.0 hostname TcpRetransSegs 13724310 0.0 hostname TcpInErrs 2 0.0 hostname TcpOutRsts 9418798 0.0 hostname TcpExtEmbryonicRsts 2303 0.0 hostname TcpExtPruneCalled 90192 0.0 hostname TcpExtOfoPruned 57274 0.0 hostname TcpExtOutOfWindowIcmps 3 0.0 hostname TcpExtTW 1164705 0.0 hostname TcpExtTWRecycled 2 0.0 hostname TcpExtPAWSEstab 159 0.0 hostname TcpExtDelayedACKs 209207209 0.0 hostname TcpExtDelayedACKLocked 508571 0.0 hostname TcpExtDelayedACKLost 1713248 0.0 hostname TcpExtListenOverflows 625 0.0 hostname TcpExtListenDrops 625 0.0 hostname TcpExtTCPHPHits 9341188489 0.0 hostname TcpExtTCPPureAcks 1434646465 0.0 hostname TcpExtTCPHPAcks 5733614672 0.0 hostname TcpExtTCPSackRecovery 3261698 0.0 hostname TcpExtTCPSACKReneging 12203 0.0 hostname TcpExtTCPSACKReorder 433189 0.0 hostname TcpExtTCPTSReorder 22694 0.0 hostname TcpExtTCPFullUndo 45092 0.0 hostname TcpExtTCPPartialUndo 22016 0.0 hostname TcpExtTCPLossUndo 2150040 0.0 hostname TcpExtTCPLostRetransmit 60119 0.0 hostname TcpExtTCPSackFailures 2626782 0.0 hostname TcpExtTCPLossFailures 182999 0.0 hostname TcpExtTCPFastRetrans 4334275 0.0 hostname TcpExtTCPSlowStartRetrans 3453348 0.0 hostname TcpExtTCPTimeouts 1070997 0.0 hostname TcpExtTCPLossProbes 2633545 0.0 hostname TcpExtTCPLossProbeRecovery 941647 0.0 hostname TcpExtTCPSackRecoveryFail 336302 0.0 hostname TcpExtTCPRcvCollapsed 461354 0.0 hostname TcpExtTCPAbortOnData 349196 0.0 hostname TcpExtTCPAbortOnClose 3395 0.0 hostname TcpExtTCPAbortOnTimeout 51201 0.0 hostname TcpExtTCPMemoryPressures 2 0.0 hostname TcpExtTCPSpuriousRTOs 2120503 0.0 hostname TcpExtTCPSackShifted 2613736 0.0 hostname TcpExtTCPSackMerged 21358743 0.0 hostname TcpExtTCPSackShiftFallback 8769387 0.0 hostname TcpExtTCPBacklogDrop 5 0.0 hostname TcpExtTCPRetransFail 843 0.0 hostname TcpExtTCPRcvCoalesce 949068035 0.0 hostname TcpExtTCPOFOQueue 470118 0.0 hostname TcpExtTCPOFODrop 9915 0.0 hostname TcpExtTCPOFOMerge 9 0.0 hostname TcpExtTCPChallengeACK 90 0.0 hostname TcpExtTCPSYNChallenge 3 0.0 hostname TcpExtTCPFastOpenActive 2089 0.0 hostname TcpExtTCPSpuriousRtxHostQueues 896596 0.0 hostname TcpExtTCPAutoCorking 547386735 0.0 hostname TcpExtTCPFromZeroWindowAdv 28757 0.0 hostname TcpExtTCPToZeroWindowAdv 28761 0.0 hostname TcpExtTCPWantZeroWindowAdv 322431 0.0 hostname TcpExtTCPSynRetrans 3026 0.0 hostname TcpExtTCPOrigDataSent 40976870977 0.0 hostname TcpExtTCPHystartTrainDetect 453920 0.0 hostname TcpExtTCPHystartTrainCwnd 11586273 0.0 hostname TcpExtTCPHystartDelayDetect 10943 0.0 hostname TcpExtTCPHystartDelayCwnd 763554 0.0 hostname TcpExtTCPACKSkippedPAWS 30 0.0 hostname TcpExtTCPACKSkippedSeq 218 0.0 hostname TcpExtTCPWinProbe 2408 0.0 hostname TcpExtTCPKeepAlive 213768 0.0 hostname TcpExtTCPMTUPFail 69 0.0 hostname TcpExtTCPMTUPSuccess 8811 0.0
Thanks!
Quoted 30 lines · Roman Gushchin
Quoted 30 lines · Roman Gushchin
Quoted 29 lines
Quoted 17 lines
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()(becausesk_buffpassed 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.
Quoted 7 lines
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 intcp_sacktag_walk().
Quoted 8 lines
Quoted 1 line
Quoted 1 line
Here is an example of a backtrace with the panic log:
Hi Yuchung!
Quoted 2 lines
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.
Quoted 82 lines
Quoted 4 lines
also have you experience any sack reneg? could you post the output of ' nstat |grep -i TCP' thanks
hostname TcpActiveOpens 2289680 0.0 hostname TcpPassiveOpens 3592758 0.0 hostname TcpAttemptFails 746910 0.0 hostname TcpEstabResets 154988 0.0 hostname TcpInSegs 16258678255 0.0 hostname TcpOutSegs 46967011611 0.0 hostname TcpRetransSegs 13724310 0.0 hostname TcpInErrs 2 0.0 hostname TcpOutRsts 9418798 0.0 hostname TcpExtEmbryonicRsts 2303 0.0 hostname TcpExtPruneCalled 90192 0.0 hostname TcpExtOfoPruned 57274 0.0 hostname TcpExtOutOfWindowIcmps 3 0.0 hostname TcpExtTW 1164705 0.0 hostname TcpExtTWRecycled 2 0.0 hostname TcpExtPAWSEstab 159 0.0 hostname TcpExtDelayedACKs 209207209 0.0 hostname TcpExtDelayedACKLocked 508571 0.0 hostname TcpExtDelayedACKLost 1713248 0.0 hostname TcpExtListenOverflows 625 0.0 hostname TcpExtListenDrops 625 0.0 hostname TcpExtTCPHPHits 9341188489 0.0 hostname TcpExtTCPPureAcks 1434646465 0.0 hostname TcpExtTCPHPAcks 5733614672 0.0 hostname TcpExtTCPSackRecovery 3261698 0.0 hostname TcpExtTCPSACKReneging 12203 0.0 hostname TcpExtTCPSACKReorder 433189 0.0 hostname TcpExtTCPTSReorder 22694 0.0 hostname TcpExtTCPFullUndo 45092 0.0 hostname TcpExtTCPPartialUndo 22016 0.0 hostname TcpExtTCPLossUndo 2150040 0.0 hostname TcpExtTCPLostRetransmit 60119 0.0 hostname TcpExtTCPSackFailures 2626782 0.0 hostname TcpExtTCPLossFailures 182999 0.0 hostname TcpExtTCPFastRetrans 4334275 0.0 hostname TcpExtTCPSlowStartRetrans 3453348 0.0 hostname TcpExtTCPTimeouts 1070997 0.0 hostname TcpExtTCPLossProbes 2633545 0.0 hostname TcpExtTCPLossProbeRecovery 941647 0.0 hostname TcpExtTCPSackRecoveryFail 336302 0.0 hostname TcpExtTCPRcvCollapsed 461354 0.0 hostname TcpExtTCPAbortOnData 349196 0.0 hostname TcpExtTCPAbortOnClose 3395 0.0 hostname TcpExtTCPAbortOnTimeout 51201 0.0 hostname TcpExtTCPMemoryPressures 2 0.0 hostname TcpExtTCPSpuriousRTOs 2120503 0.0 hostname TcpExtTCPSackShifted 2613736 0.0 hostname TcpExtTCPSackMerged 21358743 0.0 hostname TcpExtTCPSackShiftFallback 8769387 0.0 hostname TcpExtTCPBacklogDrop 5 0.0 hostname TcpExtTCPRetransFail 843 0.0 hostname TcpExtTCPRcvCoalesce 949068035 0.0 hostname TcpExtTCPOFOQueue 470118 0.0 hostname TcpExtTCPOFODrop 9915 0.0 hostname TcpExtTCPOFOMerge 9 0.0 hostname TcpExtTCPChallengeACK 90 0.0 hostname TcpExtTCPSYNChallenge 3 0.0 hostname TcpExtTCPFastOpenActive 2089 0.0 hostname TcpExtTCPSpuriousRtxHostQueues 896596 0.0 hostname TcpExtTCPAutoCorking 547386735 0.0 hostname TcpExtTCPFromZeroWindowAdv 28757 0.0 hostname TcpExtTCPToZeroWindowAdv 28761 0.0 hostname TcpExtTCPWantZeroWindowAdv 322431 0.0 hostname TcpExtTCPSynRetrans 3026 0.0 hostname TcpExtTCPOrigDataSent 40976870977 0.0 hostname TcpExtTCPHystartTrainDetect 453920 0.0 hostname TcpExtTCPHystartTrainCwnd 11586273 0.0 hostname TcpExtTCPHystartDelayDetect 10943 0.0 hostname TcpExtTCPHystartDelayCwnd 763554 0.0 hostname TcpExtTCPACKSkippedPAWS 30 0.0 hostname TcpExtTCPACKSkippedSeq 218 0.0 hostname TcpExtTCPWinProbe 2408 0.0 hostname TcpExtTCPKeepAlive 213768 0.0 hostname TcpExtTCPMTUPFail 69 0.0 hostname TcpExtTCPMTUPSuccess 8811 0.0Thanks!
Quoted 35 lines · Yuchung Cheng
Quoted 34 lines · Roman Gushchin
Quoted 23 lines · Roman Gushchin
Quoted 22 lines
Quoted 22 lines
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()(becausesk_buffpassed 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.
Quoted 8 lines
Quoted 8 lines
Quoted 2 lines
[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 intcp_sacktag_walk().Here is an example of a backtrace with the panic log:
Hi Yuchung!
Quoted 8 lines
Quoted 4 lines
Quoted 2 lines
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_walkto 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?
Quoted 84 lines
Quoted 84 lines
Quoted 6 lines
also have you experience any sack reneg? could you post the output of ' nstat |grep -i TCP' thanks
hostname TcpActiveOpens 2289680 0.0 hostname TcpPassiveOpens 3592758 0.0 hostname TcpAttemptFails 746910 0.0 hostname TcpEstabResets 154988 0.0 hostname TcpInSegs 16258678255 0.0 hostname TcpOutSegs 46967011611 0.0 hostname TcpRetransSegs 13724310 0.0 hostname TcpInErrs 2 0.0 hostname TcpOutRsts 9418798 0.0 hostname TcpExtEmbryonicRsts 2303 0.0 hostname TcpExtPruneCalled 90192 0.0 hostname TcpExtOfoPruned 57274 0.0 hostname TcpExtOutOfWindowIcmps 3 0.0 hostname TcpExtTW 1164705 0.0 hostname TcpExtTWRecycled 2 0.0 hostname TcpExtPAWSEstab 159 0.0 hostname TcpExtDelayedACKs 209207209 0.0 hostname TcpExtDelayedACKLocked 508571 0.0 hostname TcpExtDelayedACKLost 1713248 0.0 hostname TcpExtListenOverflows 625 0.0 hostname TcpExtListenDrops 625 0.0 hostname TcpExtTCPHPHits 9341188489 0.0 hostname TcpExtTCPPureAcks 1434646465 0.0 hostname TcpExtTCPHPAcks 5733614672 0.0 hostname TcpExtTCPSackRecovery 3261698 0.0 hostname TcpExtTCPSACKReneging 12203 0.0 hostname TcpExtTCPSACKReorder 433189 0.0 hostname TcpExtTCPTSReorder 22694 0.0 hostname TcpExtTCPFullUndo 45092 0.0 hostname TcpExtTCPPartialUndo 22016 0.0 hostname TcpExtTCPLossUndo 2150040 0.0 hostname TcpExtTCPLostRetransmit 60119 0.0 hostname TcpExtTCPSackFailures 2626782 0.0 hostname TcpExtTCPLossFailures 182999 0.0 hostname TcpExtTCPFastRetrans 4334275 0.0 hostname TcpExtTCPSlowStartRetrans 3453348 0.0 hostname TcpExtTCPTimeouts 1070997 0.0 hostname TcpExtTCPLossProbes 2633545 0.0 hostname TcpExtTCPLossProbeRecovery 941647 0.0 hostname TcpExtTCPSackRecoveryFail 336302 0.0 hostname TcpExtTCPRcvCollapsed 461354 0.0 hostname TcpExtTCPAbortOnData 349196 0.0 hostname TcpExtTCPAbortOnClose 3395 0.0 hostname TcpExtTCPAbortOnTimeout 51201 0.0 hostname TcpExtTCPMemoryPressures 2 0.0 hostname TcpExtTCPSpuriousRTOs 2120503 0.0 hostname TcpExtTCPSackShifted 2613736 0.0 hostname TcpExtTCPSackMerged 21358743 0.0 hostname TcpExtTCPSackShiftFallback 8769387 0.0 hostname TcpExtTCPBacklogDrop 5 0.0 hostname TcpExtTCPRetransFail 843 0.0 hostname TcpExtTCPRcvCoalesce 949068035 0.0 hostname TcpExtTCPOFOQueue 470118 0.0 hostname TcpExtTCPOFODrop 9915 0.0 hostname TcpExtTCPOFOMerge 9 0.0 hostname TcpExtTCPChallengeACK 90 0.0 hostname TcpExtTCPSYNChallenge 3 0.0 hostname TcpExtTCPFastOpenActive 2089 0.0 hostname TcpExtTCPSpuriousRtxHostQueues 896596 0.0 hostname TcpExtTCPAutoCorking 547386735 0.0 hostname TcpExtTCPFromZeroWindowAdv 28757 0.0 hostname TcpExtTCPToZeroWindowAdv 28761 0.0 hostname TcpExtTCPWantZeroWindowAdv 322431 0.0 hostname TcpExtTCPSynRetrans 3026 0.0 hostname TcpExtTCPOrigDataSent 40976870977 0.0 hostname TcpExtTCPHystartTrainDetect 453920 0.0 hostname TcpExtTCPHystartTrainCwnd 11586273 0.0 hostname TcpExtTCPHystartDelayDetect 10943 0.0 hostname TcpExtTCPHystartDelayCwnd 763554 0.0 hostname TcpExtTCPACKSkippedPAWS 30 0.0 hostname TcpExtTCPACKSkippedSeq 218 0.0 hostname TcpExtTCPWinProbe 2408 0.0 hostname TcpExtTCPKeepAlive 213768 0.0 hostname TcpExtTCPMTUPFail 69 0.0 hostname TcpExtTCPMTUPSuccess 8811 0.0Thanks!
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.
Quoted 136 lines · On středa 27. září 2017 2:18:32 CEST Yuchung Cheng wrote:
Quoted 44 lines · Yuchung Cheng
Quoted 43 lines · Roman Gushchin
Quoted 33 lines · Roman Gushchin
Quoted 32 lines
Quoted 32 lines
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 intcp_sacktag_walk()(becausesk_buffpassed 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=>>> >Quoted 5 lines
Quoted 5 lines
We're experiencing the same problems on some machines in our fleet. Exactly the same symptoms:
tcp_fastretrans_alert()warnings and sometimes panics intcp_sacktag_walk().Here is an example of a backtrace with the panic log:
Hi Yuchung!
Quoted 2 lines
do you still see the panics if you disable RACK?
sysctl net.ipv4.tcp_recovery=0?Quoted 6 lines
Quoted 1 line
No, we haven't seen any crash since that.
I am out of ideas how RACK can potentially cause
tcp_sacktag_walkto 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?Quoted 80 lines
Quoted 80 lines
Quoted 2 lines
also have you experience any sack reneg? could you post the output of ' nstat |grep -i TCP' thanks
hostname TcpActiveOpens 2289680 0.0 hostname TcpPassiveOpens 3592758 0.0 hostname TcpAttemptFails 746910 0.0 hostname TcpEstabResets 154988 0.0 hostname TcpInSegs 16258678255 0.0 hostname TcpOutSegs 46967011611 0.0 hostname TcpRetransSegs 13724310 0.0 hostname TcpInErrs 2 0.0 hostname TcpOutRsts 9418798 0.0 hostname TcpExtEmbryonicRsts 2303 0.0 hostname TcpExtPruneCalled 90192 0.0 hostname TcpExtOfoPruned 57274 0.0 hostname TcpExtOutOfWindowIcmps 3 0.0 hostname TcpExtTW 1164705 0.0 hostname TcpExtTWRecycled 2 0.0 hostname TcpExtPAWSEstab 159 0.0 hostname TcpExtDelayedACKs 209207209 0.0 hostname TcpExtDelayedACKLocked 508571 0.0 hostname TcpExtDelayedACKLost 1713248 0.0 hostname TcpExtListenOverflows 625 0.0 hostname TcpExtListenDrops 625 0.0 hostname TcpExtTCPHPHits 9341188489 0.0 hostname TcpExtTCPPureAcks 1434646465 0.0 hostname TcpExtTCPHPAcks 5733614672 0.0 hostname TcpExtTCPSackRecovery 3261698 0.0 hostname TcpExtTCPSACKReneging 12203 0.0 hostname TcpExtTCPSACKReorder 433189 0.0 hostname TcpExtTCPTSReorder 22694 0.0 hostname TcpExtTCPFullUndo 45092 0.0 hostname TcpExtTCPPartialUndo 22016 0.0 hostname TcpExtTCPLossUndo 2150040 0.0 hostname TcpExtTCPLostRetransmit 60119 0.0 hostname TcpExtTCPSackFailures 2626782 0.0 hostname TcpExtTCPLossFailures 182999 0.0 hostname TcpExtTCPFastRetrans 4334275 0.0 hostname TcpExtTCPSlowStartRetrans 3453348 0.0 hostname TcpExtTCPTimeouts 1070997 0.0 hostname TcpExtTCPLossProbes 2633545 0.0 hostname TcpExtTCPLossProbeRecovery 941647 0.0 hostname TcpExtTCPSackRecoveryFail 336302 0.0 hostname TcpExtTCPRcvCollapsed 461354 0.0 hostname TcpExtTCPAbortOnData 349196 0.0 hostname TcpExtTCPAbortOnClose 3395 0.0 hostname TcpExtTCPAbortOnTimeout 51201 0.0 hostname TcpExtTCPMemoryPressures 2 0.0 hostname TcpExtTCPSpuriousRTOs 2120503 0.0 hostname TcpExtTCPSackShifted 2613736 0.0 hostname TcpExtTCPSackMerged 21358743 0.0 hostname TcpExtTCPSackShiftFallback 8769387 0.0 hostname TcpExtTCPBacklogDrop 5 0.0 hostname TcpExtTCPRetransFail 843 0.0 hostname TcpExtTCPRcvCoalesce 949068035 0.0 hostname TcpExtTCPOFOQueue 470118 0.0 hostname TcpExtTCPOFODrop 9915 0.0 hostname TcpExtTCPOFOMerge 9 0.0 hostname TcpExtTCPChallengeACK 90 0.0 hostname TcpExtTCPSYNChallenge 3 0.0 hostname TcpExtTCPFastOpenActive 2089 0.0 hostname TcpExtTCPSpuriousRtxHostQueues 896596 0.0 hostname TcpExtTCPAutoCorking 547386735 0.0 hostname TcpExtTCPFromZeroWindowAdv 28757 0.0 hostname TcpExtTCPToZeroWindowAdv 28761 0.0 hostname TcpExtTCPWantZeroWindowAdv 322431 0.0 hostname TcpExtTCPSynRetrans 3026 0.0 hostname TcpExtTCPOrigDataSent 40976870977 0.0 hostname TcpExtTCPHystartTrainDetect 453920 0.0 hostname TcpExtTCPHystartTrainCwnd 11586273 0.0 hostname TcpExtTCPHystartDelayDetect 10943 0.0 hostname TcpExtTCPHystartDelayCwnd 763554 0.0 hostname TcpExtTCPACKSkippedPAWS 30 0.0 hostname TcpExtTCPACKSkippedSeq 218 0.0 hostname TcpExtTCPWinProbe 2408 0.0 hostname TcpExtTCPKeepAlive 213768 0.0 hostname TcpExtTCPMTUPFail 69 0.0 hostname TcpExtTCPMTUPSuccess 8811 0.0Thanks!
Quoted 5 lines · Oleksandr Natalenko
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 intcp_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.
Quoted 140 lines · On středa 27. září 2017 2:18:32 CEST Yuchung Cheng wrote:
Quoted 136 lines · Yuchung Cheng
Quoted 44 lines · Roman Gushchin
Quoted 43 lines
Quoted 33 lines · Roman Gushchin
Quoted 32 lines
Quoted 32 lines
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 intcp_sacktag_walk()(becausesk_buffpassed 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=>>> >Quoted 5 lines
Quoted 5 lines
We're experiencing the same problems on some machines in our fleet. Exactly the same symptoms:
tcp_fastretrans_alert()warnings and sometimes panics intcp_sacktag_walk().Here is an example of a backtrace with the panic log:
Hi Yuchung!
Quoted 2 lines
do you still see the panics if you disable RACK?
sysctl net.ipv4.tcp_recovery=0?Quoted 6 lines
Quoted 1 line
No, we haven't seen any crash since that.
I am out of ideas how RACK can potentially cause
tcp_sacktag_walkto 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?Quoted 80 lines
Quoted 80 lines
Quoted 2 lines
also have you experience any sack reneg? could you post the output of ' nstat |grep -i TCP' thanks
hostname TcpActiveOpens 2289680 0.0 hostname TcpPassiveOpens 3592758 0.0 hostname TcpAttemptFails 746910 0.0 hostname TcpEstabResets 154988 0.0 hostname TcpInSegs 16258678255 0.0 hostname TcpOutSegs 46967011611 0.0 hostname TcpRetransSegs 13724310 0.0 hostname TcpInErrs 2 0.0 hostname TcpOutRsts 9418798 0.0 hostname TcpExtEmbryonicRsts 2303 0.0 hostname TcpExtPruneCalled 90192 0.0 hostname TcpExtOfoPruned 57274 0.0 hostname TcpExtOutOfWindowIcmps 3 0.0 hostname TcpExtTW 1164705 0.0 hostname TcpExtTWRecycled 2 0.0 hostname TcpExtPAWSEstab 159 0.0 hostname TcpExtDelayedACKs 209207209 0.0 hostname TcpExtDelayedACKLocked 508571 0.0 hostname TcpExtDelayedACKLost 1713248 0.0 hostname TcpExtListenOverflows 625 0.0 hostname TcpExtListenDrops 625 0.0 hostname TcpExtTCPHPHits 9341188489 0.0 hostname TcpExtTCPPureAcks 1434646465 0.0 hostname TcpExtTCPHPAcks 5733614672 0.0 hostname TcpExtTCPSackRecovery 3261698 0.0 hostname TcpExtTCPSACKReneging 12203 0.0 hostname TcpExtTCPSACKReorder 433189 0.0 hostname TcpExtTCPTSReorder 22694 0.0 hostname TcpExtTCPFullUndo 45092 0.0 hostname TcpExtTCPPartialUndo 22016 0.0 hostname TcpExtTCPLossUndo 2150040 0.0 hostname TcpExtTCPLostRetransmit 60119 0.0 hostname TcpExtTCPSackFailures 2626782 0.0 hostname TcpExtTCPLossFailures 182999 0.0 hostname TcpExtTCPFastRetrans 4334275 0.0 hostname TcpExtTCPSlowStartRetrans 3453348 0.0 hostname TcpExtTCPTimeouts 1070997 0.0 hostname TcpExtTCPLossProbes 2633545 0.0 hostname TcpExtTCPLossProbeRecovery 941647 0.0 hostname TcpExtTCPSackRecoveryFail 336302 0.0 hostname TcpExtTCPRcvCollapsed 461354 0.0 hostname TcpExtTCPAbortOnData 349196 0.0 hostname TcpExtTCPAbortOnClose 3395 0.0 hostname TcpExtTCPAbortOnTimeout 51201 0.0 hostname TcpExtTCPMemoryPressures 2 0.0 hostname TcpExtTCPSpuriousRTOs 2120503 0.0 hostname TcpExtTCPSackShifted 2613736 0.0 hostname TcpExtTCPSackMerged 21358743 0.0 hostname TcpExtTCPSackShiftFallback 8769387 0.0 hostname TcpExtTCPBacklogDrop 5 0.0 hostname TcpExtTCPRetransFail 843 0.0 hostname TcpExtTCPRcvCoalesce 949068035 0.0 hostname TcpExtTCPOFOQueue 470118 0.0 hostname TcpExtTCPOFODrop 9915 0.0 hostname TcpExtTCPOFOMerge 9 0.0 hostname TcpExtTCPChallengeACK 90 0.0 hostname TcpExtTCPSYNChallenge 3 0.0 hostname TcpExtTCPFastOpenActive 2089 0.0 hostname TcpExtTCPSpuriousRtxHostQueues 896596 0.0 hostname TcpExtTCPAutoCorking 547386735 0.0 hostname TcpExtTCPFromZeroWindowAdv 28757 0.0 hostname TcpExtTCPToZeroWindowAdv 28761 0.0 hostname TcpExtTCPWantZeroWindowAdv 322431 0.0 hostname TcpExtTCPSynRetrans 3026 0.0 hostname TcpExtTCPOrigDataSent 40976870977 0.0 hostname TcpExtTCPHystartTrainDetect 453920 0.0 hostname TcpExtTCPHystartTrainCwnd 11586273 0.0 hostname TcpExtTCPHystartDelayDetect 10943 0.0 hostname TcpExtTCPHystartDelayCwnd 763554 0.0 hostname TcpExtTCPACKSkippedPAWS 30 0.0 hostname TcpExtTCPACKSkippedSeq 218 0.0 hostname TcpExtTCPWinProbe 2408 0.0 hostname TcpExtTCPKeepAlive 213768 0.0 hostname TcpExtTCPMTUPFail 69 0.0 hostname TcpExtTCPMTUPSuccess 8811 0.0Thanks!
Quoted 8 lines · Yuchung Cheng
Quoted 5 lines · Oleksandr Natalenko
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 intcp_fastretrans_alert()for me.
Quoted 7 lines
Hi Oleksandr: no
retrans_collapseshould not matter for that warning intcp_fstretrans_alert(). the warning as I explained earlier is likely false. Neal and I are more concerned the panic intcp_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] <IRQ> [ 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 0000000000000035 [ 7685.712357] IP: tcp_sacktag_walk+0xfd/0x460 [ 7685.720726] PGD 1002d75067 [ 7685.726320] PUD 102c506067 [ 7685.731902] PMD 0 ... [ 7686.070541] task: ffff880ff5959b00 task.stack: ffffc90024708000 [ 7686.082363] RIP: 0010:tcp_sacktag_walk+0xfd/0x460 [ 7686.091754] RSP: 0000:ffff88203eec38b0 EFLAGS: 00010217 [ 7686.102188] RAX: ffff881953620a00 RBX: ffff881009273200 RCX: 00000000fbfa50ec [ 7686.116439] RDX: 00000000fbfa54a0 RSI: 0000000000000000 RDI: ffff881009273200 [ 7686.130688] RBP: ffff88203eec3908 R08: 0000000000000048 R09: 00000000fbfa55fb [ 7686.144936] R10: 0000000000000000 R11: 0000000000000000 R12: ffff881ec9ff98c0 [ 7686.159184] R13: ffff88203eec3a10 R14: 0000000000000000 R15: ffff881ec9ff9a18 [ 7686.173431] FS: 00007f2b235ff700(0000) GS:ffff88203eec0000(0000) knlGS:0000000000000000 [ 7686.189589] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 7686.201062] CR2: 0000000000000035 CR3: 0000000fd8229000 CR4: 00000000003406e0 [ 7686.215310] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 7686.229560] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 7686.243807] Call Trace: [ 7686.248696] <IRQ> [ 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.333329] 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] net_rx_action+0x22e/0x380 [ 7686.470099] __do_softirq+0x106/0x2e8 [ 7686.477431] irq_exit+0xb0/0xc0 [ 7686.483700] do_IRQ+0x4f/0xd0 [ 7686.489629] common_interrupt+0x86/0x86
Sometimes soft lockup is also seen:
[2676627.345885] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [swapper/0:0] [2676627.717771] RIP: 0010:queued_spin_lock_slowpath+0x15c/0x180 [2676627.729239] RSP: 0018:ffff88103f603e78 EFLAGS: 00000202 [2676627.740019] ORIG_RAX: ffffffffffffff10 [2676627.748027] RAX: 0000000000000101 RBX: ffff8811181d8840 RCX: 0000000000000101 [2676627.762622] RDX: 0000000000000101 RSI: 0000000000000001 RDI: ffff8811181d88c8 [2676627.777217] RBP: ffff88103f603e88 R08: 0000000000000001 R09: ffff88103f95a800 [2676627.791811] R10: 0000000000037a13 R11: 000000001a37bb20 R12: 0000000000000100 [2676627.806405] R13: ffff8811181d8c18 R14: ffffffff81857270 R15: ffff8811181d8840 [2676627.821000] FS: 0000000000000000(0000) GS:ffff88103f600000(0000) knlGS:0000000000000000 [2676627.837500] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [2676627.849318] CR2: 00007f6e44c1f000 CR3: 0000000001e09000 CR4: 00000000003406f0 [2676627.863916] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [2676627.878508] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [2676627.893103] Call Trace: [2676627.898338] <IRQ> [2676627.902711] ? _raw_spin_lock+0x21/0x30 [2676627.910715] tcp_write_timer+0x19/0x70 [2676627.918548] call_timer_fn+0x35/0x150 [2676627.926214] run_timer_softirq+0x1be/0x3e0 [2676627.934742] ? timerqueue_add+0x59/0xb0 [2676627.942745] ? ktime_get+0x3c/0xb0 [2676627.949889] __do_softirq+0x106/0x2e8 [2676627.957551] irq_exit+0xb0/0xc0 [2676627.964174] smp_apic_timer_interrupt+0x68/0x90 [2676627.973563] apic_timer_interrupt+0x86/0x90 [2676628.084861] NMI watchdog: BUG: soft lockup - CPU#11 stuck for 21s! [swapper/11:0] [2676628.084896] RIP: 0010:tcp_match_skb_to_sack+0x2d/0xb0 [2676628.084897] RSP: 0018:ffff88103f8c38a8 EFLAGS: 00000297 [2676628.084897] ORIG_RAX: ffffffffffffff10 [2676628.084898] RAX: 0000000000000000 RBX: ffff88010f9dbb18 RCX: 000000002d5da350 [2676628.084899] RDX: 000000002d5da141 RSI: ffff88010f9dbb18 RDI: ffff8811181d8840 [2676628.084899] RBP: ffff88103f8c3908 R08: 00000000ffffffff R09: 00000000d2a25ebe [2676628.084900] R10: 000000000000e323 R11: ffff8811181d8998 R12: ffff8811181d8840 [2676628.084900] R13: ffff88103f8c3a10 R14: 0000000000000000 R15: ffff8811181d8998 [2676628.084901] FS: 0000000000000000(0000) GS:ffff88103f8c0000(0000) knlGS:0000000000000000 [2676628.084902] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [2676628.084903] CR2: 00007fbc07410000 CR3: 0000000001e09000 CR4: 00000000003406e0 [2676628.084903] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [2676628.084904] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [2676628.084904] Call Trace: [2676628.084905] <IRQ> [2676628.084907] ? tcp_sacktag_walk+0x270/0x460 [2676628.084909] tcp_sacktag_write_queue+0x5ff/0x9e0 [2676628.084911] tcp_ack+0x677/0x1390 [2676628.084913] ? tcp_write_xmit+0x230/0x10a0 [2676628.084915] tcp_rcv_established+0x1ce/0x740 [2676628.084919] tcp_v6_do_rcv+0x15b/0x400 [2676628.084921] tcp_v6_rcv+0x94c/0x9f0 [2676628.084924] ? __dev_queue_xmit+0x251/0x650 [2676628.084928] ip6_input_finish+0xea/0x430 [2676628.084930] ip6_input+0x32/0xa0 [2676628.084932] ? ip6_rcv_finish+0xa0/0xa0 [2676628.084933] ip6_rcv_finish+0x4b/0xa0 [2676628.084935] ipv6_rcv+0x2ec/0x4f0 [2676628.084937] ? ip6_make_skb+0x1c0/0x1c0 [2676628.084938] __netif_receive_skb_core+0x2d5/0x9a0 [2676628.084941] ? tcp6_gro_receive+0x11d/0x1c0 [2676628.084943] ? ipv6_gro_receive+0x1d0/0x380 [2676628.084944] __netif_receive_skb+0x16/0x70 [2676628.084945] netif_receive_skb_internal+0x32/0x3b0 [2676628.084947] ? dev_gro_receive+0x27c/0x470 [2676628.084948] napi_gro_receive+0x113/0x1d0 [2676628.084952] mlx5e_handle_rx_cqe_mpwrq+0x5b6/0x8d0 [2676628.084954] mlx5e_poll_rx_cq+0x79/0x830 [2676628.084956] mlx5e_napi_poll+0x8c/0x3d0 [2676628.084959] ? mlx5_cq_completion+0x54/0xb0 [2676628.084960] net_rx_action+0x22e/0x380 [2676628.084962] __do_softirq+0x106/0x2e8 [2676628.084965] irq_exit+0xb0/0xc0 [2676628.084967] do_IRQ+0x4f/0xd0 [2676656.083964] NMI watchdog: BUG: soft lockup - CPU#11 stuck for 23s! [swapper/11:0] [2676656.083992] RIP: 0010:tcp_sacktag_walk+0x25f/0x460 [2676656.083993] RSP: 0018:ffff88103f8c38b0 EFLAGS: 00000207 [2676656.083993] ORIG_RAX: ffffffffffffff10 [2676656.083994] RAX: 0000000000021500 RBX: ffff8810d84c3600 RCX: 000000002d5d9e41 [2676656.083994] RDX: 00000000f15de229 RSI: ffff8810d84c0200 RDI: ffff8811181d8840 [2676656.083995] RBP: ffff88103f8c3908 R08: 000000000000ff21 R09: 0000000000000000 [2676656.083996] R10: 000000000000e323 R11: ffff8811181d8998 R12: ffff8811181d8840 [2676656.083996] R13: ffff88103f8c3a10 R14: 0000000000000000 R15: ffff8811181d8998 [2676656.083997] FS: 0000000000000000(0000) GS:ffff88103f8c0000(0000) knlGS:0000000000000000 [2676656.083998] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [2676656.083998] CR2: 00007fbc07410000 CR3: 0000000001e09000 CR4: 00000000003406e0 [2676656.083999] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [2676656.083999] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [2676656.084000] Call Trace: [2676656.084001] <IRQ> [2676656.084003] tcp_sacktag_write_queue+0x5ff/0x9e0 [2676656.084005] tcp_ack+0x677/0x1390 [2676656.084007] ? tcp_write_xmit+0x230/0x10a0 [2676656.084009] tcp_rcv_established+0x1ce/0x740 [2676656.084013] tcp_v6_do_rcv+0x15b/0x400 [2676656.084015] tcp_v6_rcv+0x94c/0x9f0 [2676656.084018] ? __dev_queue_xmit+0x251/0x650 [2676656.084022] ip6_input_finish+0xea/0x430 [2676656.084024] ip6_input+0x32/0xa0 [2676656.084026] ? ip6_rcv_finish+0xa0/0xa0 [2676656.084027] ip6_rcv_finish+0x4b/0xa0 [2676656.084029] ipv6_rcv+0x2ec/0x4f0 [2676656.084031] ? ip6_make_skb+0x1c0/0x1c0 [2676656.084032] __netif_receive_skb_core+0x2d5/0x9a0 [2676656.084035] ? tcp6_gro_receive+0x11d/0x1c0 [2676656.084037] ? ipv6_gro_receive+0x1d0/0x380 [2676656.084038] __netif_receive_skb+0x16/0x70 [2676656.084039] netif_receive_skb_internal+0x32/0x3b0 [2676656.084041] ? dev_gro_receive+0x27c/0x470 [2676656.084042] napi_gro_receive+0x113/0x1d0 [2676656.084046] mlx5e_handle_rx_cqe_mpwrq+0x5b6/0x8d0 [2676656.084048] mlx5e_poll_rx_cq+0x79/0x830 [2676656.084050] mlx5e_napi_poll+0x8c/0x3d0
Any help greatly appreciated.
Quoted 18 lines · Alexei Starovoitov
Quoted 8 lines · Yuchung Cheng
Quoted 5 lines · Oleksandr Natalenko
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 intcp_fastretrans_alert()for me.Quoted 7 lines
Hi Oleksandr: no
retrans_collapseshould not matter for that warning intcp_fstretrans_alert(). the warning as I explained earlier is likely false. Neal and I are more concerned the panic intcp_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.
Quoted 6 lines
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.
Quoted 206 lines
Warning + panic:
[ 7678.309043] Call Trace: [ 7678.313925] <IRQ> [ 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 0000000000000035 [ 7685.712357] IP: tcp_sacktag_walk+0xfd/0x460 [ 7685.720726] PGD 1002d75067 [ 7685.726320] PUD 102c506067 [ 7685.731902] PMD 0 ... [ 7686.070541] task: ffff880ff5959b00 task.stack: ffffc90024708000 [ 7686.082363] RIP: 0010:tcp_sacktag_walk+0xfd/0x460 [ 7686.091754] RSP: 0000:ffff88203eec38b0 EFLAGS: 00010217 [ 7686.102188] RAX: ffff881953620a00 RBX: ffff881009273200 RCX: 00000000fbfa50ec [ 7686.116439] RDX: 00000000fbfa54a0 RSI: 0000000000000000 RDI: ffff881009273200 [ 7686.130688] RBP: ffff88203eec3908 R08: 0000000000000048 R09: 00000000fbfa55fb [ 7686.144936] R10: 0000000000000000 R11: 0000000000000000 R12: ffff881ec9ff98c0 [ 7686.159184] R13: ffff88203eec3a10 R14: 0000000000000000 R15: ffff881ec9ff9a18 [ 7686.173431] FS: 00007f2b235ff700(0000) GS:ffff88203eec0000(0000) knlGS:0000000000000000 [ 7686.189589] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 7686.201062] CR2: 0000000000000035 CR3: 0000000fd8229000 CR4: 00000000003406e0 [ 7686.215310] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [ 7686.229560] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [ 7686.243807] Call Trace: [ 7686.248696] <IRQ> [ 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.333329] 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] net_rx_action+0x22e/0x380 [ 7686.470099] __do_softirq+0x106/0x2e8 [ 7686.477431] irq_exit+0xb0/0xc0 [ 7686.483700] do_IRQ+0x4f/0xd0 [ 7686.489629] common_interrupt+0x86/0x86Sometimes soft lockup is also seen:
[2676627.345885] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 22s! [swapper/0:0] [2676627.717771] RIP: 0010:queued_spin_lock_slowpath+0x15c/0x180 [2676627.729239] RSP: 0018:ffff88103f603e78 EFLAGS: 00000202 [2676627.740019] ORIG_RAX: ffffffffffffff10 [2676627.748027] RAX: 0000000000000101 RBX: ffff8811181d8840 RCX: 0000000000000101 [2676627.762622] RDX: 0000000000000101 RSI: 0000000000000001 RDI: ffff8811181d88c8 [2676627.777217] RBP: ffff88103f603e88 R08: 0000000000000001 R09: ffff88103f95a800 [2676627.791811] R10: 0000000000037a13 R11: 000000001a37bb20 R12: 0000000000000100 [2676627.806405] R13: ffff8811181d8c18 R14: ffffffff81857270 R15: ffff8811181d8840 [2676627.821000] FS: 0000000000000000(0000) GS:ffff88103f600000(0000) knlGS:0000000000000000 [2676627.837500] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [2676627.849318] CR2: 00007f6e44c1f000 CR3: 0000000001e09000 CR4: 00000000003406f0 [2676627.863916] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [2676627.878508] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [2676627.893103] Call Trace: [2676627.898338] <IRQ> [2676627.902711] ? _raw_spin_lock+0x21/0x30 [2676627.910715] tcp_write_timer+0x19/0x70 [2676627.918548] call_timer_fn+0x35/0x150 [2676627.926214] run_timer_softirq+0x1be/0x3e0 [2676627.934742] ? timerqueue_add+0x59/0xb0 [2676627.942745] ? ktime_get+0x3c/0xb0 [2676627.949889] __do_softirq+0x106/0x2e8 [2676627.957551] irq_exit+0xb0/0xc0 [2676627.964174] smp_apic_timer_interrupt+0x68/0x90 [2676627.973563] apic_timer_interrupt+0x86/0x90 [2676628.084861] NMI watchdog: BUG: soft lockup - CPU#11 stuck for 21s! [swapper/11:0] [2676628.084896] RIP: 0010:tcp_match_skb_to_sack+0x2d/0xb0 [2676628.084897] RSP: 0018:ffff88103f8c38a8 EFLAGS: 00000297 [2676628.084897] ORIG_RAX: ffffffffffffff10 [2676628.084898] RAX: 0000000000000000 RBX: ffff88010f9dbb18 RCX: 000000002d5da350 [2676628.084899] RDX: 000000002d5da141 RSI: ffff88010f9dbb18 RDI: ffff8811181d8840 [2676628.084899] RBP: ffff88103f8c3908 R08: 00000000ffffffff R09: 00000000d2a25ebe [2676628.084900] R10: 000000000000e323 R11: ffff8811181d8998 R12: ffff8811181d8840 [2676628.084900] R13: ffff88103f8c3a10 R14: 0000000000000000 R15: ffff8811181d8998 [2676628.084901] FS: 0000000000000000(0000) GS:ffff88103f8c0000(0000) knlGS:0000000000000000 [2676628.084902] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [2676628.084903] CR2: 00007fbc07410000 CR3: 0000000001e09000 CR4: 00000000003406e0 [2676628.084903] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [2676628.084904] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [2676628.084904] Call Trace: [2676628.084905] <IRQ> [2676628.084907] ? tcp_sacktag_walk+0x270/0x460 [2676628.084909] tcp_sacktag_write_queue+0x5ff/0x9e0 [2676628.084911] tcp_ack+0x677/0x1390 [2676628.084913] ? tcp_write_xmit+0x230/0x10a0 [2676628.084915] tcp_rcv_established+0x1ce/0x740 [2676628.084919] tcp_v6_do_rcv+0x15b/0x400 [2676628.084921] tcp_v6_rcv+0x94c/0x9f0 [2676628.084924] ? __dev_queue_xmit+0x251/0x650 [2676628.084928] ip6_input_finish+0xea/0x430 [2676628.084930] ip6_input+0x32/0xa0 [2676628.084932] ? ip6_rcv_finish+0xa0/0xa0 [2676628.084933] ip6_rcv_finish+0x4b/0xa0 [2676628.084935] ipv6_rcv+0x2ec/0x4f0 [2676628.084937] ? ip6_make_skb+0x1c0/0x1c0 [2676628.084938] __netif_receive_skb_core+0x2d5/0x9a0 [2676628.084941] ? tcp6_gro_receive+0x11d/0x1c0 [2676628.084943] ? ipv6_gro_receive+0x1d0/0x380 [2676628.084944] __netif_receive_skb+0x16/0x70 [2676628.084945] netif_receive_skb_internal+0x32/0x3b0 [2676628.084947] ? dev_gro_receive+0x27c/0x470 [2676628.084948] napi_gro_receive+0x113/0x1d0 [2676628.084952] mlx5e_handle_rx_cqe_mpwrq+0x5b6/0x8d0 [2676628.084954] mlx5e_poll_rx_cq+0x79/0x830 [2676628.084956] mlx5e_napi_poll+0x8c/0x3d0 [2676628.084959] ? mlx5_cq_completion+0x54/0xb0 [2676628.084960] net_rx_action+0x22e/0x380 [2676628.084962] __do_softirq+0x106/0x2e8 [2676628.084965] irq_exit+0xb0/0xc0 [2676628.084967] do_IRQ+0x4f/0xd0 [2676656.083964] NMI watchdog: BUG: soft lockup - CPU#11 stuck for 23s! [swapper/11:0] [2676656.083992] RIP: 0010:tcp_sacktag_walk+0x25f/0x460 [2676656.083993] RSP: 0018:ffff88103f8c38b0 EFLAGS: 00000207 [2676656.083993] ORIG_RAX: ffffffffffffff10 [2676656.083994] RAX: 0000000000021500 RBX: ffff8810d84c3600 RCX: 000000002d5d9e41 [2676656.083994] RDX: 00000000f15de229 RSI: ffff8810d84c0200 RDI: ffff8811181d8840 [2676656.083995] RBP: ffff88103f8c3908 R08: 000000000000ff21 R09: 0000000000000000 [2676656.083996] R10: 000000000000e323 R11: ffff8811181d8998 R12: ffff8811181d8840 [2676656.083996] R13: ffff88103f8c3a10 R14: 0000000000000000 R15: ffff8811181d8998 [2676656.083997] FS: 0000000000000000(0000) GS:ffff88103f8c0000(0000) knlGS:0000000000000000 [2676656.083998] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [2676656.083998] CR2: 00007fbc07410000 CR3: 0000000001e09000 CR4: 00000000003406e0 [2676656.083999] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 [2676656.083999] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400 [2676656.084000] Call Trace: [2676656.084001] <IRQ> [2676656.084003] tcp_sacktag_write_queue+0x5ff/0x9e0 [2676656.084005] tcp_ack+0x677/0x1390 [2676656.084007] ? tcp_write_xmit+0x230/0x10a0 [2676656.084009] tcp_rcv_established+0x1ce/0x740 [2676656.084013] tcp_v6_do_rcv+0x15b/0x400 [2676656.084015] tcp_v6_rcv+0x94c/0x9f0 [2676656.084018] ? __dev_queue_xmit+0x251/0x650 [2676656.084022] ip6_input_finish+0xea/0x430 [2676656.084024] ip6_input+0x32/0xa0 [2676656.084026] ? ip6_rcv_finish+0xa0/0xa0 [2676656.084027] ip6_rcv_finish+0x4b/0xa0 [2676656.084029] ipv6_rcv+0x2ec/0x4f0 [2676656.084031] ? ip6_make_skb+0x1c0/0x1c0 [2676656.084032] __netif_receive_skb_core+0x2d5/0x9a0 [2676656.084035] ? tcp6_gro_receive+0x11d/0x1c0 [2676656.084037] ? ipv6_gro_receive+0x1d0/0x380 [2676656.084038] __netif_receive_skb+0x16/0x70 [2676656.084039] netif_receive_skb_internal+0x32/0x3b0 [2676656.084041] ? dev_gro_receive+0x27c/0x470 [2676656.084042] napi_gro_receive+0x113/0x1d0 [2676656.084046] mlx5e_handle_rx_cqe_mpwrq+0x5b6/0x8d0 [2676656.084048] mlx5e_poll_rx_cq+0x79/0x830 [2676656.084050] mlx5e_napi_poll+0x8c/0x3d0Any help greatly appreciated.
Quoted 26 lines · Yuchung Cheng
Quoted 18 lines · Alexei Starovoitov
Quoted 8 lines · Yuchung Cheng
Quoted 5 lines · Oleksandr Natalenko
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 intcp_fastretrans_alert()for me.Quoted 7 lines
Hi Oleksandr: no
retrans_collapseshould not matter for that warning intcp_fstretrans_alert(). the warning as I explained earlier is likely false. Neal and I are more concerned the panic intcp_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.
Quoted 6 lines
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.
Quoted 5 lines
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 :
net/ipv4/tcp_output.c +0 -0
100644
net/ipv4/tcp_output.c +2 -0
@@ -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) {
PATCH 1/1 tcp: fix tcp_mtu_probe() vs highest_sack
From: Eric Dumazet <[email protected]>
Based on SNMP values provided by Roman, Yuchung made the observation that some crashes in tcp_sacktag_walk() might be caused by MTU probing.
Looking at tcp_mtu_probe(), I found that when a new skb was placed in front of the write queue, we were not updating tcp highest sack.
If one skb is freed because all its content was copied to the new skb (for MTU probing), then tp->highest_sack could point to a now freed skb.
Bad things would then happen, including infinite loops.
This patch renames tcp_highest_sack_combine() and uses it from tcp_mtu_probe() to fix the bug.
Note that I also removed one test against tp->sacked_out, since we want to replace tp->highest_sack regardless of whatever condition, since keeping a stale pointer to freed skb is a recipe for disaster.
--- include/net/tcp.h | 6 +++--- net/ipv4/tcp_output.c | 3 ++- 2 files changed, 5 insertions(+), 4 deletions(-)
include/net/tcp.h +3 -3
@@ -1771,12 +1771,12 @@ static inline void tcp_highest_sack_reset(struct sock *sk)tcp_sk (sk)->highest_sack =tcp_write_queue_head (sk); } -/* Called when old skb is about to be deleted (to be combined with new skb) */ -static inline void tcp_highest_sack_combine (struct sock *sk, +/* Called when old skb is about to be deleted and replaced by new skb */ +static inline void tcp_highest_sack_replace (struct sock *sk,struct sk_buff *old,struct sk_buff *new) { -if (tcp_sk (sk)->sacked_out && (old ==tcp_sk (sk)->highest_sack)) +if (old ==tcp_highest_sack (sk))tcp_sk (sk)->highest_sack = new; }
net/ipv4/tcp_output.c +2 -1
@@ -2062,6 +2062,7 @@ static int tcp_mtu_probe(struct sock *sk) nskb->ip_summed = skb->ip_summed;tcp_insert_write_queue_before (nskb, skb, sk); +tcp_highest_sack_replace (sk, skb, nskb); len =0 ; tcp_for_write_queue_from_safe(skb, next, sk) {
@@ -2665,7 +2666,7 @@ static bool tcp_collapse_retrans(struct sock *sk, struct sk_buff *skb)else if (!skb_shift (skb, next_skb, next_skb_size))return false; } -tcp_highest_sack_combine (sk, next_skb, skb); +tcp_highest_sack_replace (sk, next_skb, skb);tcp_unlink_write_queue (next_skb, sk);
Re: [PATCH net] tcp: fix tcp_mtu_probe() vs highest_sack
Quoted 21 lines · Eric Dumazet
From: Eric Dumazet <[email protected]>
Based on SNMP values provided by Roman, Yuchung made the observation that some crashes in
tcp_sacktag_walk()might be caused by MTU probing.Looking at
tcp_mtu_probe(), I found that when a new skb was placed in front of the write queue, we were not updating tcp highest sack.If one skb is freed because all its content was copied to the new skb (for MTU probing), then
tp->highest_sackcould point to a now freed skb.Bad things would then happen, including infinite loops.
This patch renames
tcp_highest_sack_combine()and uses it fromtcp_mtu_probe()to fix the bug.Note that I also removed one test against
tp->sacked_out, since we want to replacetp->highest_sackregardless of whatever condition, since keeping a stale pointer to freed skb is a recipe for disaster.
Quoted 5 lines
Fixes a47e5a988a57 ("[TCP]: Convert highest_sack to sk_buff to allow direct access")Signed-off-by Eric Dumazet <[email protected]>Reported-by Alexei Starovoitov <[email protected]>Reported-by Roman Gushchin <[email protected]>Reported-by Oleksandr Natalenko <[email protected]>
Thanks!
wow. a bug from 2007.
Any idea why it only started to bite us in 4.11 ?
It's not trivial for us to reproduce it, but we will definitely test the patch as soon as we can.
Do you have packet drill test or something for easy repro?
Re: [PATCH net] tcp: fix tcp_mtu_probe() vs highest_sack
Quoted 30 lines · Alexei Starovoitov
Quoted 21 lines · Eric Dumazet
From: Eric Dumazet <[email protected]>
Based on SNMP values provided by Roman, Yuchung made the observation that some crashes in
tcp_sacktag_walk()might be caused by MTU probing.Looking at
tcp_mtu_probe(), I found that when a new skb was placed in front of the write queue, we were not updating tcp highest sack.If one skb is freed because all its content was copied to the new skb (for MTU probing), then
tp->highest_sackcould point to a now freed skb.Bad things would then happen, including infinite loops.
This patch renames
tcp_highest_sack_combine()and uses it fromtcp_mtu_probe()to fix the bug.Note that I also removed one test against
tp->sacked_out, since we want to replacetp->highest_sackregardless of whatever condition, since keeping a stale pointer to freed skb is a recipe for disaster.Quoted 5 lines
Fixes a47e5a988a57 ("[TCP]: Convert highest_sack to sk_buff to allow direct access")Signed-off-by Eric Dumazet <[email protected]>Reported-by Alexei Starovoitov <[email protected]>Reported-by Roman Gushchin <[email protected]>Reported-by Oleksandr Natalenko <[email protected]>Thanks!
Quoted 8 lines
wow. a bug from 2007.
Any idea why it only started to bite us in 4.11 ?It's not trivial for us to reproduce it, but we will definitely test the patch as soon as we can.
Do you have packet drill test or something for easy repro?
I tried to cook a packetdrill test but could not trigger the issue.
When have you started to enable mtu probing ?
(Linux defaults to not enabling it )
Re: [PATCH net] tcp: fix tcp_mtu_probe() vs highest_sack
Quoted 36 lines · Eric Dumazet
Quoted 35 lines · Alexei Starovoitov
Quoted 21 lines · Eric Dumazet
From: Eric Dumazet <[email protected]>
Based on SNMP values provided by Roman, Yuchung made the observation that some crashes in
tcp_sacktag_walk()might be caused by MTU probing.Looking at
tcp_mtu_probe(), I found that when a new skb was placed in front of the write queue, we were not updating tcp highest sack.If one skb is freed because all its content was copied to the new skb (for MTU probing), then
tp->highest_sackcould point to a now freed skb.Bad things would then happen, including infinite loops.
This patch renames
tcp_highest_sack_combine()and uses it fromtcp_mtu_probe()to fix the bug.Note that I also removed one test against
tp->sacked_out, since we want to replacetp->highest_sackregardless of whatever condition, since keeping a stale pointer to freed skb is a recipe for disaster.Quoted 5 lines
Fixes a47e5a988a57 ("[TCP]: Convert highest_sack to sk_buff to allow direct access")Signed-off-by Eric Dumazet <[email protected]>Reported-by Alexei Starovoitov <[email protected]>Reported-by Roman Gushchin <[email protected]>Reported-by Oleksandr Natalenko <[email protected]>Thanks!
wow. a bug from 2007.
Any idea why it only started to bite us in 4.11 ?
Quoted 7 lines
Quoted 3 lines
It's not trivial for us to reproduce it, but we will definitely test the patch as soon as we can.
Do you have packet drill test or something for easy repro?I tried to cook a packetdrill test but could not trigger the issue.
When have you started to enable mtu probing ?
for some time. somehow 4.6 based kernel didn't trigger it. May be it's a different bug still...
Re: [PATCH net] tcp: fix tcp_mtu_probe() vs highest_sack
In reply to Eric DumazetQuoted 26 lines · Eric Dumazet
From: Eric Dumazet <[email protected]>
Based on SNMP values provided by Roman, Yuchung made the observation that some crashes in
tcp_sacktag_walk()might be caused by MTU probing.Looking at
tcp_mtu_probe(), I found that when a new skb was placed in front of the write queue, we were not updating tcp highest sack.If one skb is freed because all its content was copied to the new skb (for MTU probing), then
tp->highest_sackcould point to a now freed skb.Bad things would then happen, including infinite loops.
This patch renames
tcp_highest_sack_combine()and uses it fromtcp_mtu_probe()to fix the bug.Note that I also removed one test against
tp->sacked_out, since we want to replacetp->highest_sackregardless of whatever condition, since keeping a stale pointer to freed skb is a recipe for disaster.Fixes a47e5a988a57 ("[TCP]: Convert highest_sack to sk_buff to allow direct access")Signed-off-by Eric Dumazet <[email protected]>Reported-by Alexei Starovoitov <[email protected]>Reported-by Roman Gushchin <[email protected]>Reported-by Oleksandr Natalenko <[email protected]>
Quoted 4 lines
--- include/net/tcp.h | 6 +++--- net/ipv4/tcp_output.c | 3 ++- 2 files changed, 5 insertions(+), 4 deletions(-)
Nice catch, indeed. Thanks, Eric!
neal
Yuchung Cheng
Acked-byRe: [PATCH net] tcp: fix tcp_mtu_probe() vs highest_sack
In reply to Alexei StarovoitovQuoted 29 lines · Alexei Starovoitov
Quoted 21 lines · Eric Dumazet
From: Eric Dumazet <[email protected]>
Based on SNMP values provided by Roman, Yuchung made the observation that some crashes in
tcp_sacktag_walk()might be caused by MTU probing.Looking at
tcp_mtu_probe(), I found that when a new skb was placed in front of the write queue, we were not updating tcp highest sack.If one skb is freed because all its content was copied to the new skb (for MTU probing), then
tp->highest_sackcould point to a now freed skb.Bad things would then happen, including infinite loops.
This patch renames
tcp_highest_sack_combine()and uses it fromtcp_mtu_probe()to fix the bug.Note that I also removed one test against
tp->sacked_out, since we want to replacetp->highest_sackregardless of whatever condition, since keeping a stale pointer to freed skb is a recipe for disaster.Quoted 5 lines
Fixes a47e5a988a57 ("[TCP]: Convert highest_sack to sk_buff to allow direct access")Signed-off-by Eric Dumazet <[email protected]>Reported-by Alexei Starovoitov <[email protected]>Reported-by Roman Gushchin <[email protected]>Reported-by Oleksandr Natalenko <[email protected]>
Quoted 6 lines
Thanks!
wow. a bug from 2007.
Any idea why it only started to bite us in 4.11 ?
FWIW some random guess:
Since RACK was confirmed to trigger the issue, and RACK enables detecting lost retransmission w/o limited-transmit in CA_Loss state, I guess RACK create a new type of "fast retransmit" that caused some previously impossible SACK during MTU probing.
Quoted 5 lines
It's not trivial for us to reproduce it, but we will definitely test the patch as soon as we can.
Do you have packet drill test or something for easy repro?
David Miller
maintainerRe: [PATCH net] tcp: fix tcp_mtu_probe() vs highest_sack
In reply to Eric DumazetFrom: Eric Dumazet <[email protected]>
Date: Mon, 30 Oct 2017 23:08:20 -0700
Quoted 21 lines
From: Eric Dumazet <[email protected]>
Based on SNMP values provided by Roman, Yuchung made the observation that some crashes in
tcp_sacktag_walk()might be caused by MTU probing.Looking at
tcp_mtu_probe(), I found that when a new skb was placed in front of the write queue, we were not updating tcp highest sack.If one skb is freed because all its content was copied to the new skb (for MTU probing), then
tp->highest_sackcould point to a now freed skb.Bad things would then happen, including infinite loops.
This patch renames
tcp_highest_sack_combine()and uses it fromtcp_mtu_probe()to fix the bug.Note that I also removed one test against
tp->sacked_out, since we want to replacetp->highest_sackregardless of whatever condition, since keeping a stale pointer to freed skb is a recipe for disaster.
Quoted 5 lines
Fixes a47e5a988a57 ("[TCP]: Convert highest_sack to sk_buff to allow direct access")Signed-off-by Eric Dumazet <[email protected]>Reported-by Alexei Starovoitov <[email protected]>Reported-by Roman Gushchin <[email protected]>Reported-by Oleksandr Natalenko <[email protected]>
Applied and queued up for -stable.
Re: [PATCH net] tcp: fix tcp_mtu_probe() vs highest_sack
In reply to Eric DumazetHi.
Thanks for the fix.
However, tcp_fastretrans_alert() warning case still remains open even with this patch. Do I understand correctly that these are 2 different issues?
Currently, I use latest 4.13 stable kernel + this patch and still get:
WARNING: CPU: 1 PID: 736 at net/ipv4/tcp_input.c:2826 tcp_fastretrans_alert +0x7c8/0x990
Any idea on this?
Quoted 73 lines · On úterý 31. října 2017 7:08:20 CET Eric Dumazet wrote:
From: Eric Dumazet <[email protected]>
Based on SNMP values provided by Roman, Yuchung made the observation that some crashes in
tcp_sacktag_walk()might be caused by MTU probing.Looking at
tcp_mtu_probe(), I found that when a new skb was placed in front of the write queue, we were not updating tcp highest sack.If one skb is freed because all its content was copied to the new skb (for MTU probing), then
tp->highest_sackcould point to a now freed skb.Bad things would then happen, including infinite loops.
This patch renames
tcp_highest_sack_combine()and uses it fromtcp_mtu_probe()to fix the bug.Note that I also removed one test against
tp->sacked_out, since we want to replacetp->highest_sackregardless of whatever condition, since keeping a stale pointer to freed skb is a recipe for disaster.Fixes a47e5a988a57 ("[TCP]: Convert highest_sack to sk_buff to allow directaccess") Signed-off-by: Eric Dumazet <[email protected]>
Reported-by Alexei Starovoitov <[email protected]>Reported-by Roman Gushchin <[email protected]>Reported-by Oleksandr Natalenko <[email protected]>--- include/net/tcp.h | 6 +++--- net/ipv4/tcp_output.c | 3 ++- 2 files changed, 5 insertions(+), 4 deletions(-)include/net/tcp.h +0
-0index
33599d17522d6a19b9d9a316cc1579cd5e71ee32..e6d0002a1b0bc5f28c331a760823c8dc92f8fe24 100644 ---a/include/net/tcp.h
+++b/include/net/tcp.hinclude/net/tcp.h +3
-2@@ -1771,12 +1771,12 @@ static inline void tcp_highest_sack_reset(structsock *sk) tcp_sk(sk)->highest_sack = tcp_write_queue_head(sk); } -/* Called when old skb is about to be deleted (to be combined with new skb) */ -static inline void tcp_highest_sack_combine(struct sock *sk, +/* Called when old skb is about to be deleted and replaced by new skb */ +static inline void tcp_highest_sack_replace (struct sock *sk,struct sk_buff *old, struct sk_buff *new) { -if (tcp_sk (sk)->sacked_out && (old ==tcp_sk (sk)->highest_sack)) +if (old ==tcp_highest_sack (sk))tcp_sk (sk)->highest_sack = new; }net/ipv4/tcp_output.c +0
-0index
ae60dd3faed0adc71731bc686f878afd4c628d32..823003eef3a21a5cc5c27e0be9f46159afa060df 100644 ---a/net/ipv4/tcp_output.c
+++b/net/ipv4/tcp_output.cnet/ipv4/tcp_output.c +2
-1@@ -2062,6 +2062,7 @@ static int tcp_mtu_probe(struct sock *sk) nskb->ip_summed = skb->ip_summed;tcp_insert_write_queue_before (nskb, skb, sk); +tcp_highest_sack_replace (sk, skb, nskb); len =0 ; tcp_for_write_queue_from_safe(skb, next, sk) {@@ -2665,7 +2666,7 @@ static bool tcp_collapse_retrans(struct sock *sk, struct sk_buff *skb) else if (!skb_shift(skb, next_skb, next_skb_size))return false; } -tcp_highest_sack_combine (sk, next_skb, skb); +tcp_highest_sack_replace (sk, next_skb, skb);tcp_unlink_write_queue (next_skb, sk);
Re: [PATCH net] tcp: fix tcp_mtu_probe() vs highest_sack
Quoted 11 lines · Oleksandr Natalenko
Hi.
Thanks for the fix.
However,
tcp_fastretrans_alert()warning case still remains open even with this patch. Do I understand correctly that these are 2 different issues?Currently, I use latest 4.13 stable kernel + this patch and still get:
WARNING: CPU: 1 PID: 736 at net/ipv4/tcp_input.c:2826 tcp_fastretrans_alert +0x7c8/
My patch only fixed the panics that you guys reported.
The warning issue in fastretrans is a separate problem, we are still working on it, but at least the effects are not catastrophic.
Quoted 8 lines · Eric Dumazet
Quoted 6 lines · Yuchung Cheng
Quoted 4 lines · Alexei Starovoitov
Quoted 2 lines · Yuchung Cheng
On Thu, Sep 28, 2017 at 1:14 AM, Oleksandr Natalenko <[email protected]> wrote:
Quoted 8 lines
Quoted 8 lines
Quoted 8 lines
Quoted 8 lines
Quoted 5 lines
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 intcp_fastretrans_alert()for me.Hi Oleksandr: no
retrans_collapseshould not matter for that warning intcp_fstretrans_alert(). the warning as I explained earlier is
hi guys can you try if the warning goes away w/ this quick fix?
net/ipv4/tcp_input.c +1 -1
@@ -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))
Quoted 35 lines
Quoted 12 lines
Quoted 6 lines
Quoted 5 lines
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.
Quoted 6 lines
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.Quoted 5 lines
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 :
net/ipv4/tcp_output.c +0
-0100644
net/ipv4/tcp_output.c +2
-0@@ -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) {
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...
Quoted 16 lines
hi guys can you try if the warning goes away w/ this quick fix?
net/ipv4/tcp_input.c +1
-1@@ -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...
Uhh, sorry, just found the original submission [1].
[1] https://marc.info/?l=linux-netdev&m=151009763926816&w=2
Quoted 31 lines · Oleksandr Natalenko
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...Quoted 16 lines
hi guys can you try if the warning goes away w/ this quick fix?
net/ipv4/tcp_input.c +1
-1@@ -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...