Re: Kernel 4.1 hang, apparently in __inet_lookup_established

[Eric Dumazet]

On Mon, 2016-01-11 at 12:27 -0800, Grant Zhang wrote:

> Hi Eric,
> 
> One of my 4.1.13 server(have been up 50+ days) under testing got into a 
> similar kernel hang (stack trace attached). Looking back at the initial 
> conversation on this issue you also mentioned the following patch in
> https://lkml.org/lkml/2015/9/23/433
> 
> http://git.kernel.org/cgit/linux/kernel/git/davem/net.git/commit/?id=ed2e923945892a8372ab70d2f61d364b0b6d9054
> tcp/dccp: fix timewait races in timer handling
> 
> Which does not seem to be part of stable 4.1 tree. Would the above patch 
> fix the kernel hang issue?
> 
> Thanks,
> 
> Grant
> 
> ----stacktrace----
> Jan  9 19:12:42 kernel:[4544972.126385] INFO: rcu_sched self-detected 
> stall on CPU { 13}  (t=15001 jiffies g=422586407 c=422586406 q=3730083)
> Jan  9 19:12:42 kernel:[4544972.134383] INFO: rcu_sched detected stalls 
> on CPUs/tasks: { 13} (detected by 5, t=15002 jiffies, g=422586407, 
> c=422586406, q=3730200)
> Jan  9 19:12:42 kernel:[4544972.134384] Task dump for CPU 13:
> Jan  9 19:12:42 kernel:[4544972.134387] swapper/13      R  running task 
>         0     0      1 0x00000008
> Jan  9 19:12:42 kernel:[4544972.134389]  0000000000000010 
> 0000000000000246 ffff885ecde0be68 0000000000000018
> Jan  9 19:12:42 kernel:[4544972.134390]  ffffffff8164045d 
> ffffffff00000007 00102982b9fa1875 ffffffff81c7fc80
> Jan  9 19:12:42 kernel:[4544972.134391]  0000000d00000000 
> ffff88beff0e0300 ffffffff81ce5448 ffff885ecde08000
> Jan  9 19:12:42 kernel:[4544972.134391] Call Trace:
> Jan  9 19:12:42 kernel:[4544972.134397]  [<ffffffff8164045d>] ? 
> cpuidle_enter_state+0x7d/0x1f0
> Jan  9 19:12:42 kernel:[4544972.134398]  [<ffffffff81640607>] ? 
> cpuidle_enter+0x17/0x20
> Jan  9 19:12:42 kernel:[4544972.134401]  [<ffffffff810b6c41>] ? 
> cpu_startup_entry+0x2d1/0x350
> Jan  9 19:12:42 kernel:[4544972.134403]  [<ffffffff810e0aac>] ? 
> clockevents_config_and_register+0x2c/0x40
> Jan  9 19:12:42 kernel:[4544972.134406]  [<ffffffff81034aa3>] ? 
> start_secondary+0x123/0x130
> Jan  9 19:12:42 kernel:[4544972.149242] Task dump for CPU 13:
> Jan  9 19:12:42 kernel:[4544972.149244] swapper/13      R  running task 
>         0     0      1 0x00000008
> Jan  9 19:12:42 kernel:[4544972.149248]  ffffffff81c3f300 
> ffff88beff0c3820 ffffffff810a5791 000000000000000d
> Jan  9 19:12:42 kernel:[4544972.149250]  ffffffff81c3f300 
> ffff88beff0c3840 ffffffff810a8c4f ffff88beff0c3880
> Jan  9 19:12:42 kernel:[4544972.149251]  ffffffff81c3f3c0 
> ffff88beff0c3870 ffffffff810ca763 ffff88beff0d6c80
> Jan  9 19:12:42 kernel:[4544972.149253] Call Trace:
> Jan  9 19:12:42 kernel:[4544972.149255]  <IRQ>  [<ffffffff810a5791>] 
> sched_show_task+0xb1/0x120
> Jan  9 19:12:42 kernel:[4544972.149267]  [<ffffffff810a8c4f>] 
> dump_cpu_task+0x3f/0x50
> Jan  9 19:12:42 kernel:[4544972.149270]  [<ffffffff810ca763>] 
> rcu_dump_cpu_stacks+0x93/0xc0
> Jan  9 19:12:42 kernel:[4544972.149272]  [<ffffffff810cdcaa>] 
> rcu_check_callbacks+0x4aa/0x760
> Jan  9 19:12:42 kernel:[4544972.149277]  [<ffffffff8110e27c>] ? 
> acct_account_cputime+0x1c/0x20
> Jan  9 19:12:42 kernel:[4544972.149279]  [<ffffffff810d3868>] 
> update_process_times+0x38/0x70
> Jan  9 19:12:42 kernel:[4544972.149283]  [<ffffffff810e2a38>] 
> tick_sched_timer+0x58/0x190
> Jan  9 19:12:42 kernel:[4544972.149284]  [<ffffffff810d41ad>] 
> __run_hrtimer+0x6d/0x220
> Jan  9 19:12:42 kernel:[4544972.149285]  [<ffffffff810e29e0>] ? 
> tick_init_highres+0x20/0x20
> Jan  9 19:12:42 kernel:[4544972.149287]  [<ffffffff810d4893>] 
> hrtimer_interrupt+0x103/0x240
> Jan  9 19:12:42 kernel:[4544972.149292]  [<ffffffff810363f9>] 
> local_apic_timer_interrupt+0x39/0x60
> Jan  9 19:12:42 kernel:[4544972.149296]  [<ffffffff817b5275>] 
> smp_apic_timer_interrupt+0x45/0x60
> Jan  9 19:12:42 kernel:[4544972.149299]  [<ffffffff817b39bb>] 
> apic_timer_interrupt+0x6b/0x70
> Jan  9 19:12:42 kernel:[4544972.149304]  [<ffffffff816f36f0>] ? 
> __inet_lookup_established+0x70/0x170
> Jan  9 19:12:42 kernel:[4544972.149306]  [<ffffffff816f36c6>] ? 
> __inet_lookup_established+0x46/0x170
> Jan  9 19:12:42 kernel:[4544972.149309]  [<ffffffff8170eb7d>] 
> tcp_v4_early_demux+0xad/0x160
> Jan  9 19:12:42 kernel:[4544972.149311]  [<ffffffff816e9428>] 
> ip_rcv_finish+0x158/0x380
> Jan  9 19:12:42 kernel:[4544972.149312]  [<ffffffff816e9cf2>] 
> ip_rcv+0x292/0x3b0
> Jan  9 19:12:42 kernel:[4544972.149318]  [<ffffffffa04f0102>] ? 
> macvlan_handle_frame+0x1f2/0x310 [macvlan]
> Jan  9 19:12:42 kernel:[4544972.149320]  [<ffffffff816e92d0>] ? 
> inet_add_protocol+0x50/0x50
> Jan  9 19:12:42 kernel:[4544972.149324]  [<ffffffff81693bf0>] 
> __netif_receive_skb_core+0x300/0x7b0
> Jan  9 19:12:42 kernel:[4544972.149325]  [<ffffffff817b5185>] ? 
> do_IRQ+0x65/0x110
> Jan  9 19:12:42 kernel:[4544972.149327]  [<ffffffff816940c1>] 
> __netif_receive_skb+0x21/0x70
> Jan  9 19:12:42 kernel:[4544972.149329]  [<ffffffff81694271>] 
> netif_receive_skb_internal+0x31/0xa0
> Jan  9 19:12:42 kernel:[4544972.149331]  [<ffffffff81694ff0>] 
> napi_gro_receive+0x130/0x1b0
> Jan  9 19:12:42 kernel:[4544972.149341]  [<ffffffffa005f389>] 
> ixgbe_clean_rx_irq+0x7b9/0xa20 [ixgbe]
> Jan  9 19:12:42 kernel:[4544972.149344]  [<ffffffffa006024b>] 
> ixgbe_poll+0x42b/0x7e0 [ixgbe]
> Jan  9 19:12:42 kernel:[4544972.149346]  [<ffffffff816949ce>] 
> net_rx_action+0x13e/0x320
> Jan  9 19:12:42 kernel:[4544972.149350]  [<ffffffff8107fcce>] 
> __do_softirq+0xde/0x2d0
> Jan  9 19:12:42 kernel:[4544972.149352]  [<ffffffff8108009d>] 
> irq_exit+0x4d/0x60
> Jan  9 19:12:42 kernel:[4544972.149353]  [<ffffffff817b5185>] 
> do_IRQ+0x65/0x110
> Jan  9 19:12:42 kernel:[4544972.149356]  [<ffffffff817b36eb>] 
> common_interrupt+0x6b/0x6b
> Jan  9 19:12:42 kernel:[4544972.149356]  <EOI>  [<ffffffff8164048e>] ? 
> cpuidle_enter_state+0xae/0x1f0
> Jan  9 19:12:42 kernel:[4544972.149360]  [<ffffffff8164045d>] ? 
> cpuidle_enter_state+0x7d/0x1f0
> Jan  9 19:12:42 kernel:[4544972.149361]  [<ffffffff81640607>] 
> cpuidle_enter+0x17/0x20
> Jan  9 19:12:42 kernel:[4544972.149364]  [<ffffffff810b6c41>] 
> cpu_startup_entry+0x2d1/0x350
> Jan  9 19:12:42 kernel:[4544972.149366]  [<ffffffff810e0aac>] ? 
> clockevents_config_and_register+0x2c/0x40
> Jan  9 19:12:42 kernel:[4544972.149368]  [<ffffffff81034aa3>] 
> start_secondary+0x123/0x130
> 

Hi Grant

Most probably the commit would help ;)

David, can you make sure ed2e923945892a8372ab70d2f61d364b0b6d9054 is
pushed to stable trees (4.1 & 4.2)

Thanks.