Re: [net-next] tcp_delack_timer circular locking dependancy
On Mon, 2017-10-30 at 15:20 -0400, Dave Jones wrote:
> [ 105.316650] ==
> [ 105.316818] WARNING: possible circular locking dependency detected
> [ 105.316986] 4.14.0-rc7-think+ #1 Not tainted
> [ 105.317108] --
> [ 105.317273] swapper/2/0 is trying to acquire lock:
> [ 105.317407] (
> [ 105.317476] slock-AF_INET6
> [ 105.317564] ){+.-.}
> [ 105.317642] , at: [] tcp_delack_timer+0x26/0x130
> [ 105.317807]
>but task is already holding lock:
> [ 105.317961] (
> [ 105.318024] (timer)
> [ 105.318097] #5
> [ 105.318168] ){+.-.}
> [ 105.318241] , at: [] call_timer_fn+0x5/0x5e0
> [ 105.318393]
>which lock already depends on the new lock.
>
> [ 105.318594]
>the existing dependency chain (in reverse order) is:
> [ 105.318781]
>-> #1
> [ 105.318879] (
> [ 105.318939] (timer)
> [ 105.319009] #5
> [ 105.319068] ){+.-.}
> [ 105.319137] :
> [ 105.319195]del_timer_sync+0x3c/0xb0
> [ 105.319313]inet_csk_reqsk_queue_drop+0x26c/0x4e0
> [ 105.319459]inet_csk_complete_hashdance+0x1e/0x90
> [ 105.319598]tcp_check_req+0x787/0x9a0
> [ 105.319716]tcp_v6_rcv+0x914/0x1060
> [ 105.319828]ip6_input_finish+0x291/0xba0
> [ 105.319950]ip6_input+0xb2/0x380
> [ 105.320059]ip6_rcv_finish+0x103/0x350
> [ 105.320180]ipv6_rcv+0x93f/0xff0
> [ 105.320291]__netif_receive_skb_core+0x13ef/0x1900
> [ 105.320436]netif_receive_skb_internal+0xea/0x4c0
> [ 105.320579]napi_gro_receive+0x28e/0x320
> [ 105.320705]e1000_clean_rx_irq+0x3e9/0x6f0
> [ 105.320838]e1000e_poll+0x14e/0x570
> [ 105.320954]net_rx_action+0x4db/0xc80
> [ 105.321075]__do_softirq+0x1ca/0x7bf
> [ 105.321194]irq_exit+0x104/0x110
> [ 105.321303]do_IRQ+0xb2/0x130
> [ 105.321407]ret_from_intr+0x0/0x19
> [ 105.321523]cpuidle_enter_state+0x223/0x5b0
> [ 105.321655]do_idle+0x110/0x1b0
> [ 105.321766]cpu_startup_entry+0xdb/0xe0
> [ 105.321891]start_secondary+0x2e9/0x360
> [ 105.322014]verify_cpu+0x0/0xf1
> [ 105.322121]
>-> #0
> [ 105.322215] (
> [ 105.322276] slock-AF_INET6
> [ 105.322359] ){+.-.}
> [ 105.322428] :
> [ 105.322487]lock_acquire+0x12e/0x350
> [ 105.322602]_raw_spin_lock+0x30/0x70
> [ 105.322722]tcp_delack_timer+0x26/0x130
> [ 105.322846]call_timer_fn+0x188/0x5e0
> [ 105.322966]__run_timers+0x54d/0x670
> [ 105.323084]run_timer_softirq+0x2a/0x50
> [ 105.323208]__do_softirq+0x1ca/0x7bf
> [ 105.323325]irq_exit+0x104/0x110
> [ 105.323435]smp_apic_timer_interrupt+0x14b/0x510
> [ 105.323576]apic_timer_interrupt+0x9a/0xa0
> [ 105.323705]cpuidle_enter_state+0x223/0x5b0
> [ 105.323836]do_idle+0x110/0x1b0
> [ 105.323944]cpu_startup_entry+0xdb/0xe0
> [ 105.324067]start_secondary+0x2e9/0x360
> [ 105.324189]verify_cpu+0x0/0xf1
> [ 105.324295]
>other info that might help us debug this:
>
> [ 105.324489] Possible unsafe locking scenario:
>
> [ 105.324644]CPU0CPU1
> [ 105.324767]
> [ 105.324890] lock(
> [ 105.324963] (timer)
> [ 105.325033] #5
> [ 105.325093] );
> [ 105.325152]lock(
> [ 105.325278] slock-AF_INET6
> [ 105.325360] );
> [ 105.325419]lock(
> [ 105.325544] (timer)
> [ 105.325612] #5
> [ 105.325670] );
> [ 105.325729] lock(
> [ 105.325797] slock-AF_INET6
> [ 105.325879] );
> [ 105.325938]
> *** DEADLOCK ***
>
> [ 105.326086] 1 lock held by swapper/2/0:
> [ 105.326193] #0:
> [ 105.326257] (
> [ 105.331697] (timer)
> [ 105.337038] #5
> [ 105.342339] ){+.-.}
> [ 105.347620] , at: [] call_timer_fn+0x5/0x5e0
> [ 105.353021]
>stack backtrace:
> [ 105.363515] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 4.14.0-rc7-think+ #1
> [ 105.368886] Hardware name: LENOVO ThinkServer TS140/ThinkServer TS140,
> BIOS FBKTB3AUS 06/16/2015
> [ 105.374330] Call Trace:
> [ 105.379697]
> [ 105.384997] dump_stack+0xbc/0x145
> [ 105.390339] ? dma_virt_map_sg+0xfb/0xfb
> [ 105.395733] ? call_timer_fn+0x5/0x5e0
> [ 105.401076] ? print_lock+0x54/0x68
> [ 105.406344] print_circular_bug.isra.42+0x283/0x2bc
> [ 105.411695] ? print_circular_bug_header+0xda/0xda
> [ 105.417054] ? graph_lock+0x8d/0x100
> [ 105.422419] ? check_noncircular+0x20/0x20
> [ 105.427857] ? sched_clock_cpu+0x14/0xf0
> [ 105.433309] __lock_acquire+0x1f4a/0x2050
> [ 105.438725] ? debug_check_no_locks_freed+0x1a0/0x1a0
> [ 105.444160] ? __lock_acquire+0x6b3/0x2050
> [ 105.449580] ? debug_check_no_locks_freed+0x1a0/0x1a0
> [ 105.455015] ? sched_
[net-next] tcp_delack_timer circular locking dependancy
[ 105.316650] ==
[ 105.316818] WARNING: possible circular locking dependency detected
[ 105.316986] 4.14.0-rc7-think+ #1 Not tainted
[ 105.317108] --
[ 105.317273] swapper/2/0 is trying to acquire lock:
[ 105.317407] (
[ 105.317476] slock-AF_INET6
[ 105.317564] ){+.-.}
[ 105.317642] , at: [] tcp_delack_timer+0x26/0x130
[ 105.317807]
but task is already holding lock:
[ 105.317961] (
[ 105.318024] (timer)
[ 105.318097] #5
[ 105.318168] ){+.-.}
[ 105.318241] , at: [] call_timer_fn+0x5/0x5e0
[ 105.318393]
which lock already depends on the new lock.
[ 105.318594]
the existing dependency chain (in reverse order) is:
[ 105.318781]
-> #1
[ 105.318879] (
[ 105.318939] (timer)
[ 105.319009] #5
[ 105.319068] ){+.-.}
[ 105.319137] :
[ 105.319195]del_timer_sync+0x3c/0xb0
[ 105.319313]inet_csk_reqsk_queue_drop+0x26c/0x4e0
[ 105.319459]inet_csk_complete_hashdance+0x1e/0x90
[ 105.319598]tcp_check_req+0x787/0x9a0
[ 105.319716]tcp_v6_rcv+0x914/0x1060
[ 105.319828]ip6_input_finish+0x291/0xba0
[ 105.319950]ip6_input+0xb2/0x380
[ 105.320059]ip6_rcv_finish+0x103/0x350
[ 105.320180]ipv6_rcv+0x93f/0xff0
[ 105.320291]__netif_receive_skb_core+0x13ef/0x1900
[ 105.320436]netif_receive_skb_internal+0xea/0x4c0
[ 105.320579]napi_gro_receive+0x28e/0x320
[ 105.320705]e1000_clean_rx_irq+0x3e9/0x6f0
[ 105.320838]e1000e_poll+0x14e/0x570
[ 105.320954]net_rx_action+0x4db/0xc80
[ 105.321075]__do_softirq+0x1ca/0x7bf
[ 105.321194]irq_exit+0x104/0x110
[ 105.321303]do_IRQ+0xb2/0x130
[ 105.321407]ret_from_intr+0x0/0x19
[ 105.321523]cpuidle_enter_state+0x223/0x5b0
[ 105.321655]do_idle+0x110/0x1b0
[ 105.321766]cpu_startup_entry+0xdb/0xe0
[ 105.321891]start_secondary+0x2e9/0x360
[ 105.322014]verify_cpu+0x0/0xf1
[ 105.322121]
-> #0
[ 105.322215] (
[ 105.322276] slock-AF_INET6
[ 105.322359] ){+.-.}
[ 105.322428] :
[ 105.322487]lock_acquire+0x12e/0x350
[ 105.322602]_raw_spin_lock+0x30/0x70
[ 105.322722]tcp_delack_timer+0x26/0x130
[ 105.322846]call_timer_fn+0x188/0x5e0
[ 105.322966]__run_timers+0x54d/0x670
[ 105.323084]run_timer_softirq+0x2a/0x50
[ 105.323208]__do_softirq+0x1ca/0x7bf
[ 105.323325]irq_exit+0x104/0x110
[ 105.323435]smp_apic_timer_interrupt+0x14b/0x510
[ 105.323576]apic_timer_interrupt+0x9a/0xa0
[ 105.323705]cpuidle_enter_state+0x223/0x5b0
[ 105.323836]do_idle+0x110/0x1b0
[ 105.323944]cpu_startup_entry+0xdb/0xe0
[ 105.324067]start_secondary+0x2e9/0x360
[ 105.324189]verify_cpu+0x0/0xf1
[ 105.324295]
other info that might help us debug this:
[ 105.324489] Possible unsafe locking scenario:
[ 105.324644]CPU0CPU1
[ 105.324767]
[ 105.324890] lock(
[ 105.324963] (timer)
[ 105.325033] #5
[ 105.325093] );
[ 105.325152]lock(
[ 105.325278] slock-AF_INET6
[ 105.325360] );
[ 105.325419]lock(
[ 105.325544] (timer)
[ 105.325612] #5
[ 105.325670] );
[ 105.325729] lock(
[ 105.325797] slock-AF_INET6
[ 105.325879] );
[ 105.325938]
*** DEADLOCK ***
[ 105.326086] 1 lock held by swapper/2/0:
[ 105.326193] #0:
[ 105.326257] (
[ 105.331697] (timer)
[ 105.337038] #5
[ 105.342339] ){+.-.}
[ 105.347620] , at: [] call_timer_fn+0x5/0x5e0
[ 105.353021]
stack backtrace:
[ 105.363515] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 4.14.0-rc7-think+ #1
[ 105.368886] Hardware name: LENOVO ThinkServer TS140/ThinkServer TS140, BIOS
FBKTB3AUS 06/16/2015
[ 105.374330] Call Trace:
[ 105.379697]
[ 105.384997] dump_stack+0xbc/0x145
[ 105.390339] ? dma_virt_map_sg+0xfb/0xfb
[ 105.395733] ? call_timer_fn+0x5/0x5e0
[ 105.401076] ? print_lock+0x54/0x68
[ 105.406344] print_circular_bug.isra.42+0x283/0x2bc
[ 105.411695] ? print_circular_bug_header+0xda/0xda
[ 105.417054] ? graph_lock+0x8d/0x100
[ 105.422419] ? check_noncircular+0x20/0x20
[ 105.427857] ? sched_clock_cpu+0x14/0xf0
[ 105.433309] __lock_acquire+0x1f4a/0x2050
[ 105.438725] ? debug_check_no_locks_freed+0x1a0/0x1a0
[ 105.444160] ? __lock_acquire+0x6b3/0x2050
[ 105.449580] ? debug_check_no_locks_freed+0x1a0/0x1a0
[ 105.455015] ? sched_clock_cpu+0x14/0xf0
[ 105.460514] ? __lock_acquire+0x6b3/0x2050
[ 105.465984] ? cyc2ns_read_end+0x10/0x10
[ 105.471395] ? debug_check_no_locks_freed+0x1a0/0x1a0
[ 105.476934] ? mark_lock+0x16f/0x9b0
[ 105.482507] ? print_irqtrace_events+0x110/0x110
[ 105.488150] ? native_sched_clock+0xf9/0x
