Connection tracking and soft lockups with certain field values

Connection tracking and soft lockups with certain field values

[Andrey Korolyov]

[-- Attachment #1: Type: text/plain, Size: 781 bytes --]

Hi,

I am currently playing with SYNPROXY target to optimize SYN filtering
performance and by occasion found that TCP SYN packets containing port
0 can result in a soft lockup when conntrack is enabled just by
itself, given high packet ratio (I`ve reached 450kpps so far with 60b
packets on a /32<->/32 flood with enabled flow control at the media
level and middle-level E3 Xeon on receiver side). Same flood with port
> 0 going just well, producing same ceil numbers but without visible
lockups in kernel log. I`ve tested the issue on a broad range of 3.x
kernels and all of them are seemingly affected. Fast and dirty grep
revealed special conditions for port 0 only for protocol-specific
helpers, but there are none of them.

Please find both same captures and traceback below.

[-- Attachment #2: conntrack-port-0-trace.txt --]
[-- Type: text/plain, Size: 4051 bytes --]

[  152.001957] ixgbe 0000:01:00.0 eth8: NIC Link is Up 10 Gbps, Flow Control: RX/TX
[  157.326410] sched: RT throttling activated
[  180.038105] NMI watchdog: BUG: soft lockup - CPU#0 stuck for 21s! [rcuos/0:9]
[  180.038128] Modules linked in: xt_CT iptable_raw ipt_SYNPROXY nf_synproxy_core nf_conntrack_ipv4 nf_defrag_ipv4 xt_tcpudp xt_conntrack nf_conntrack iptable_filter ip_tables x_tables tun openvswitch(O) libcrc32c nfsd auth_rpcgss nfs_acl nfs lockd grace fscache sunrpc bridge stp llc w83627ehf hwmon_vid jc42 loop fuse dm_crypt joydev hid_generic usbhid x86_pkg_temp_thermal intel_powerclamp ast coretemp igb ttm drm_kms_helper kvm_intel(O) drm iTCO_wdt iTCO_vendor_support sg pcspkr kvm(O) syscopyarea sysfillrect sysimgblt video thermal tpm_tis i2c_algo_bit ipmi_si ipmi_msghandler tpm i2c_i801 8250_fintek fan battery shpchp button ie31200_edac edac_core xhci_pci lpc_ich mfd_core xhci_hcd processor crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel aesni_intel aes_x86_64 lrw gf128mul glue_helper
[  180.038157]  ablk_helper cryptd mpt2sas raid_class ehci_pci ixgbe(O) ehci_hcd vxlan ip6_udp_tunnel udp_tunnel usbcore ptp usb_common pps_core dca dm_mirror dm_region_hash dm_log dm_mod
[  180.038165] CPU: 0 PID: 9 Comm: rcuos/0 Tainted: G           O   3.18.10-default #5
[  180.038166] Hardware name: Supermicro X10SL7-F/X10SL7-F, BIOS 2.00 04/24/2014
[  180.038167] task: ffff880409624c20 ti: ffff880409630000 task.ti: ffff880409630000
[  180.038168] RIP: 0010:[<ffffffff8155b972>]  [<ffffffff8155b972>] dev_gro_receive+0x182/0x370
[  180.038172] RSP: 0018:ffff88041fc03d48  EFLAGS: 00000296
[  180.038173] RAX: ffffffff81cf6920 RBX: 0000000180200020 RCX: 0000000067632533
[  180.038174] RDX: ffff880405580000 RSI: ffff8800d8392100 RDI: ffff8804054dc440
[  180.038175] RBP: ffff88041fc03d98 R08: 000000000000002e R09: 0000000000000000
[  180.038175] R10: ffff8800d8392100 R11: ffffea001019de00 R12: ffff88041fc03cb8
[  180.038176] R13: ffffffff8165b83d R14: ffff88041fc03d98 R15: ffff8800d8392100
[  180.038177] FS:  0000000000000000(0000) GS:ffff88041fc00000(0000) knlGS:0000000000000000
[  180.038178] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  180.038179] CR2: 00007fed089d21b0 CR3: 0000000001c15000 CR4: 00000000001407f0
[  180.038180] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[  180.038180] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[  180.038181] Stack:
[  180.038181]  0000000000000280 000000000000000e 000000000000000b ffffffff81cf8860
[  180.038183]  ffff88041fc03d98 ffff8804054dc640 ffff8800d8392100 ffff8804054dc440
[  180.038184]  000000000000000c ffff880407023fb0 ffff88041fc03dc8 ffffffff8155c0d0
[  180.038185] Call Trace:
[  180.038186]  <IRQ> 

[  180.038189]  [<ffffffff8155c0d0>] napi_gro_receive+0x30/0x100
[  180.038196]  [<ffffffffa012cc39>] ixgbe_clean_rx_irq+0x8d9/0x1030 [ixgbe]
[  180.038200]  [<ffffffffa012e588>] ixgbe_poll+0x478/0x690 [ixgbe]
[  180.038203]  [<ffffffff8150da90>] ? show_no_turbo+0x90/0x90
[  180.038204]  [<ffffffff8155bd99>] net_rx_action+0x149/0x250
[  180.038208]  [<ffffffff8106629f>] __do_softirq+0xdf/0x260
[  180.038210]  [<ffffffff8165c4fc>] do_softirq_own_stack+0x1c/0x30
[  180.038211]  <EOI> 

[  180.038213]  [<ffffffff810664d5>] do_softirq+0x65/0x70
[  180.038214]  [<ffffffff81066574>] __local_bh_enable_ip+0x94/0xa0
[  180.038216]  [<ffffffff810bfa15>] rcu_nocb_kthread+0x155/0x580
[  180.038219]  [<ffffffff8109fcc0>] ? finish_wait+0x80/0x80
[  180.038220]  [<ffffffff810bf8c0>] ? rcu_eqs_exit_common.isra.60+0xe0/0xe0
[  180.038222]  [<ffffffff8107fad9>] kthread+0xc9/0xe0
[  180.038224]  [<ffffffff8107fa10>] ? kthread_create_on_node+0x1a0/0x1a0
[  180.038226]  [<ffffffff8165a798>] ret_from_fork+0x58/0x90
[  180.038227]  [<ffffffff8107fa10>] ? kthread_create_on_node+0x1a0/0x1a0
[  180.038228] Code: 00 48 8b 05 91 8a 79 00 48 89 45 c8 4c 8b 75 c8 49 81 fe e0 43 cf 81 49 8d 46 e0 0f 84 b6 01 00 00 66 44 39 28 74 0a 48 8b 40 20 <eb> db 0f 1f 40 00 48 83 78 10 00 74 ef 48 8b 93 d8 00 00 00 48

[-- Attachment #3: 0-80.pcap --]
[-- Type: application/vnd.tcpdump.pcap, Size: 766 bytes --]

[-- Attachment #4: 80-80.pcap --]
[-- Type: application/vnd.tcpdump.pcap, Size: 766 bytes --]

Re: Connection tracking and soft lockups with certain field values

[Andrey Korolyov]

[-- Attachment #1: Type: text/plain, Size: 1059 bytes --]

On Thu, May 28, 2015 at 10:41 PM, Andrey Korolyov <andrey@xdel.ru> wrote:
> Hi,
>
> I am currently playing with SYNPROXY target to optimize SYN filtering
> performance and by occasion found that TCP SYN packets containing port
> 0 can result in a soft lockup when conntrack is enabled just by
> itself, given high packet ratio (I`ve reached 450kpps so far with 60b
> packets on a /32<->/32 flood with enabled flow control at the media
> level and middle-level E3 Xeon on receiver side). Same flood with port
>> 0 going just well, producing same ceil numbers but without visible
> lockups in kernel log. I`ve tested the issue on a broad range of 3.x
> kernels and all of them are seemingly affected. Fast and dirty grep
> revealed special conditions for port 0 only for protocol-specific
> helpers, but there are none of them.
>
> Please find both same captures and traceback below.

Attached trace without GSO, at its presence can be somehow confusing
in a previous sample. The testbed using net.nf_conntrack_max =
2000000, forgot to mention that previously.

[-- Attachment #2: conntrack-port-0-gso-off.txt --]
[-- Type: text/plain, Size: 4494 bytes --]

[52671.706307] BUG: soft lockup - CPU#0 stuck for 24s! [rcuos/0:18]
[52671.706331] Modules linked in: ixgbe mdio xt_CT iptable_raw ipt_SYNPROXY nf_synproxy_core nf_conntrack_ipv4 nf_defrag_ipv4 xt_tcpudp xt_conntrack nf_conntrack iptable_filter ip_tables x_tables tun openvswitch nfsd auth_rpcgss oid_registry nfs_acl nfs lockd dns_resolver fscache sunrpc bridge stp llc w83627ehf hwmon_vid loop fuse dm_crypt dm_mod coretemp kvm_intel snd_pcm kvm snd_page_alloc snd_timer crc32c_intel ghash_clmulni_intel aesni_intel aes_x86_64 ablk_helper snd cryptd lrw iTCO_wdt soundcore iTCO_vendor_support gf128mul glue_helper joydev evdev pcspkr video processor button i2c_i801 lpc_ich mfd_core shpchp ext4 crc16 jbd2 mbcache microcode sg sd_mod crc_t10dif hid_generic usbhid hid ahci libahci libata mpt2sas igb raid_class i2c_algo_bit dca scsi_transport_sas ptp pps_core i2c_core ehci_pci
[52671.706364]  scsi_mod ehci_hcd xhci_hcd usbcore usb_common thermal fan thermal_sys
[52671.706369] CPU: 0 PID: 18 Comm: rcuos/0 Not tainted 3.10-0.bpo.3-amd64 #1 Debian 3.10.11-1~bpo70+19
[52671.706370] Hardware name: Supermicro X10SL7-F/X10SL7-F, BIOS 2.00 04/24/2014
[52671.706372] task: ffff88040d528790 ti: ffff88040d532000 task.ti: ffff88040d532000
[52671.706373] RIP: 0010:[<ffffffff812bf927>]  [<ffffffff812bf927>] sock_wfree+0x42/0x5b
[52671.706377] RSP: 0018:ffff88041fc03b18  EFLAGS: 00000202
[52671.706378] RAX: ffffffff812bf801 RBX: ffff88041fc10110 RCX: 0000000000000024
[52671.706379] RDX: ffff8802e0751610 RSI: 00000000ffffffff RDI: ffff88041fc0fe40
[52671.706380] RBP: 0000000000000300 R08: 0000000000000000 R09: 0000000000000000
[52671.706381] R10: ffff88041fc0ff44 R11: 0000000000000001 R12: ffff88041fc03a88
[52671.706382] R13: ffffffff8139705d R14: 0000000000000300 R15: ffff88041fc0fe40
[52671.706383] FS:  0000000000000000(0000) GS:ffff88041fc00000(0000) knlGS:0000000000000000
[52671.706384] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[52671.706385] CR2: 00007fb866cc2140 CR3: 000000000160c000 CR4: 00000000001407f0
[52671.706386] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[52671.706387] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[52671.706388] Stack:
[52671.706389]  ffff88040ac7b000 ffff88040ac7aa00 ffff88040ac7b000 ffffffff812f8747
[52671.706391]  ffff88041fc0fe40 ffffffff812fb0d8 ffff88041fc03b80 ffff88041fc03b78
[52671.706392]  ffffffff00000040 0000000000000286 ffffffff817dda00 ffffffff0214140a
[52671.706394] Call Trace:
[52671.706395]  <IRQ> 

[52671.706399]  [<ffffffff812f8747>] ? skb_orphan+0x12/0x27
[52671.706402]  [<ffffffff812fb0d8>] ? ip_send_unicast_reply+0x243/0x297
[52671.706406]  [<ffffffff810477bf>] ? mod_timer+0x7b/0x89
[52671.706409]  [<ffffffff813120c2>] ? tcp_v4_send_reset+0x2db/0x324
[52671.706411]  [<ffffffff81312e56>] ? tcp_v4_rcv+0x387/0x559
[52671.706413]  [<ffffffff812f6017>] ? __xfrm_policy_check2.constprop.9+0x50/0x50
[52671.706415]  [<ffffffff812f6117>] ? ip_local_deliver_finish+0x100/0x176
[52671.706418]  [<ffffffff812cd640>] ? __netif_receive_skb_core+0x447/0x4bf
[52671.706420]  [<ffffffff812cd893>] ? netif_receive_skb+0x4c/0x7d
[52671.706422]  [<ffffffff812ce013>] ? napi_gro_receive+0x35/0x76
[52671.706427]  [<ffffffffa04ab24c>] ? ixgbe_poll+0xbc9/0xe0a [ixgbe]
[52671.706429]  [<ffffffff812cddaa>] ? net_rx_action+0xa7/0x1e1
[52671.706431]  [<ffffffff8106442c>] ? account_system_time+0x113/0x12c
[52671.706433]  [<ffffffff81041683>] ? __do_softirq+0xf1/0x216
[52671.706436]  [<ffffffff8139781c>] ? call_softirq+0x1c/0x30
[52671.706436]  <EOI> 

[52671.706439]  [<ffffffff8100eade>] ? do_softirq+0x3a/0x78
[52671.706440]  [<ffffffff8104142e>] ? _local_bh_enable_ip.isra.11+0x6a/0x88
[52671.706443]  [<ffffffff810a2413>] ? rcu_nocb_kthread+0x25e/0x298
[52671.706445]  [<ffffffff810573e3>] ? abort_exclusive_wait+0x79/0x79
[52671.706447]  [<ffffffff810a21b5>] ? force_qs_rnp+0x120/0x120
[52671.706448]  [<ffffffff810a21b5>] ? force_qs_rnp+0x120/0x120
[52671.706450]  [<ffffffff81056a54>] ? kthread+0x81/0x89
[52671.706452]  [<ffffffff810126f9>] ? paravirt_read_tsc+0x5/0x8
[52671.706454]  [<ffffffff810569d3>] ? __kthread_parkme+0x5d/0x5d
[52671.706457]  [<ffffffff813963bc>] ? ret_from_fork+0x7c/0xb0
[52671.706458]  [<ffffffff810569d3>] ? __kthread_parkme+0x5d/0x5d
[52671.706459] Code: e6 ff ff 84 c0 75 1d 8d 7d ff bd 01 00 00 00 48 8d b3 04 01 00 00 e8 7d e3 ff ff 48 89 df ff 93 70 02 00 00 f0 29 ab 04 01 00 00 <40> 0f 94 c5 40 84 ed 74 0b 48 89 df 5b 5b 5d e9 94 fe ff ff 41