Running test_progs on a LOCKDEP enabled kernel (latest David Miller net tree)
I got the following splat.
It is not immediately obvious to me. Any idea ?
[ 4169.908826] ======================================================
[ 4169.914996] WARNING: possible circular locking dependency detected
[ 4169.921172] 5.0.0-dbg-DEV #597 Not tainted
[ 4169.925294] ------------------------------------------------------
[ 4169.931482] swapper/29/0 is trying to acquire lock:
[ 4169.936379] 00000000541e3f72 (&htab->buckets[i].lock){....}, at:
htab_map_update_elem+0x1b6/0x3a0
[ 4169.945262]
but task is already holding lock:
[ 4169.951084] 00000000e213eabd (&rq->lock){-.-.}, at: __schedule+0xd6/0xb80
[ 4169.957904]
which lock already depends on the new lock.
[ 4169.966101]
the existing dependency chain (in reverse order) is:
[ 4169.973605]
-> #4 (&rq->lock){-.-.}:
[ 4169.978651] _raw_spin_lock+0x2f/0x40
[ 4169.982866] task_fork_fair+0x37/0x160
[ 4169.987150] sched_fork+0x206/0x310
[ 4169.991167] copy_process.part.41+0x7eb/0x2370
[ 4169.996128] _do_fork+0xda/0x6a0
[ 4169.999872] kernel_thread+0x29/0x30
[ 4170.003962] rest_init+0x22/0x260
[ 4170.007820] arch_call_rest_init+0xe/0x10
[ 4170.012382] start_kernel+0x4d8/0x4f9
[ 4170.016557] x86_64_start_reservations+0x24/0x26
[ 4170.021697] x86_64_start_kernel+0x6f/0x72
[ 4170.026312] secondary_startup_64+0xa4/0xb0
[ 4170.031039]
-> #3 (&p->pi_lock){-.-.}:
[ 4170.036265] _raw_spin_lock_irqsave+0x3a/0x50
[ 4170.041172] try_to_wake_up+0x41/0x610
[ 4170.045466] wake_up_process+0x15/0x20
[ 4170.049745] create_worker+0x16b/0x1e0
[ 4170.054039] workqueue_init+0x1ff/0x31d
[ 4170.058397] kernel_init_freeable+0x116/0x2a5
[ 4170.063291] kernel_init+0xf/0x180
[ 4170.067212] ret_from_fork+0x24/0x30
[ 4170.071307]
-> #2 (&(&pool->lock)->rlock){-.-.}:
[ 4170.077425] _raw_spin_lock+0x2f/0x40
[ 4170.081602] __queue_work+0xb2/0x540
[ 4170.085709] queue_work_on+0x38/0x80
[ 4170.089827] free_percpu+0x231/0x270
[ 4170.093933] array_map_free+0x47/0x80
[ 4170.098131] bpf_map_free_deferred+0x3c/0x50
[ 4170.102926] process_one_work+0x1f4/0x590
[ 4170.107466] worker_thread+0x6f/0x430
[ 4170.111654] kthread+0x132/0x170
[ 4170.115431] ret_from_fork+0x24/0x30
[ 4170.119520]
-> #1 (pcpu_lock){..-.}:
[ 4170.124562] _raw_spin_lock_irqsave+0x3a/0x50
[ 4170.129448] pcpu_alloc+0xfa/0x790
[ 4170.133383] __alloc_percpu_gfp+0x12/0x20
[ 4170.137905] alloc_htab_elem+0x182/0x2b0
[ 4170.142351] __htab_percpu_map_update_elem+0x270/0x2c0
[ 4170.148036] bpf_percpu_hash_update+0x7c/0x130
[ 4170.153035] __do_sys_bpf+0x194a/0x1c10
[ 4170.157385] __x64_sys_bpf+0x1a/0x20
[ 4170.161485] do_syscall_64+0x5a/0x460
[ 4170.165674] entry_SYSCALL_64_after_hwframe+0x49/0xbe
[ 4170.171255]
-> #0 (&htab->buckets[i].lock){....}:
[ 4170.177433] lock_acquire+0xa7/0x190
[ 4170.181549] _raw_spin_lock_irqsave+0x3a/0x50
[ 4170.186448] htab_map_update_elem+0x1b6/0x3a0
[ 4170.191347]
other info that might help us debug this:
[ 4170.199345] Chain exists of:
&htab->buckets[i].lock --> &p->pi_lock --> &rq->lock
[ 4170.209867] Possible unsafe locking scenario:
[ 4170.215776] CPU0 CPU1
[ 4170.220301] ---- ----
[ 4170.224823] lock(&rq->lock);
[ 4170.227882] lock(&p->pi_lock);
[ 4170.233646] lock(&rq->lock);
[ 4170.239208] lock(&htab->buckets[i].lock);
[ 4170.243384]
*** DEADLOCK ***
[ 4170.249297] 2 locks held by swapper/29/0:
[ 4170.253307] #0: 00000000e213eabd (&rq->lock){-.-.}, at:
__schedule+0xd6/0xb80
[ 4170.260558] #1: 000000006891c367 (rcu_read_lock){....}, at:
trace_call_bpf+0x40/0x260
[ 4170.268476]
stack backtrace:
[ 4170.272838] CPU: 29 PID: 0 Comm: swapper/29 Not tainted 5.0.0-dbg-DEV #597
[ 4170.279708] Hardware name: Intel RML,PCH/Iota_QC_19, BIOS 2.54.0 06/07/2018
[ 4170.286658] Call Trace:
[ 4170.289108] dump_stack+0x67/0x95
[ 4170.292424] print_circular_bug.isra.36+0x1fd/0x20b
[ 4170.297302] __lock_acquire+0x15b3/0x1850
[ 4170.301308] ? __pcpu_freelist_pop+0x87/0xb0
[ 4170.305579] lock_acquire+0xa7/0x190
[ 4170.309157] ? lock_acquire+0xa7/0x190
[ 4170.312900] ? htab_map_update_elem+0x1b6/0x3a0
[ 4170.317434] _raw_spin_lock_irqsave+0x3a/0x50
[ 4170.321791] ? htab_map_update_elem+0x1b6/0x3a0
[ 4170.326324] htab_map_update_elem+0x1b6/0x3a0
[ 4170.330684] ? trace_call_bpf+0x100/0x260
[ 4170.334695] ? perf_trace_run_bpf_submit+0x42/0xb0
[ 4170.339487] ? perf_trace_sched_switch+0x129/0x1a0
[ 4170.344279] ? __schedule+0x44d/0xb80
[ 4170.347943] ? lockdep_hardirqs_on+0x14d/0x1d0
[ 4170.352388] ? trace_hardirqs_on+0x3f/0xf0
[ 4170.356487] ? schedule_idle+0x2c/0x40
[ 4170.360237] ? do_idle+0x184/0x280
[ 4170.363634] ? cpu_startup_entry+0x1d/0x20
[ 4170.367735] ? start_secondary+0x184/0x1d0
[ 4170.371830] ? secondary_startup_64+0xa4/0xb0
