Re: workqueue, pci: INFO: possible recursive locking detected

From: Srivatsa S. Bhat
Date: Thu Jul 18 2013 - 16:27:51 EST



On 07/17/2013 03:37 PM, Lai Jiangshan wrote:
> On 07/16/2013 10:41 PM, Srivatsa S. Bhat wrote:
>> Hi,
>>
>> I have been seeing this warning every time during boot. I haven't
>> spent time digging through it though... Please let me know if
>> any machine-specific info is needed.
>>
>> Regards,
>> Srivatsa S. Bhat
>>
>>
>> ----------------------------------------------------
>>
>> =============================================
>> [ INFO: possible recursive locking detected ]
>> 3.11.0-rc1-lockdep-fix-a #6 Not tainted
>> ---------------------------------------------
>> kworker/0:1/142 is trying to acquire lock:
>> ((&wfc.work)){+.+.+.}, at: [<ffffffff81077100>] flush_work+0x0/0xb0
>>
>> but task is already holding lock:
>> ((&wfc.work)){+.+.+.}, at: [<ffffffff81075dd9>] process_one_work+0x169/0x610
>>
>> other info that might help us debug this:
>> Possible unsafe locking scenario:
>>
>> CPU0
>> ----
>> lock((&wfc.work));
>> lock((&wfc.work));
>
>


Hi Lai,

Thanks for taking a look into this!

>
> This is false negative,

I believe you meant false-positive...

> the two "wfc"s are different, they are
> both on stack. flush_work() can't be deadlock in such case:
>
> void foo(void *)
> {
> ...
> if (xxx)
> work_on_cpu(..., foo, ...);
> ...
> }
>
> bar()
> {
> work_on_cpu(..., foo, ...);
> }
>
> The complaint is caused by "work_on_cpu() uses a static lock_class_key".
> we should fix work_on_cpu().
> (but the caller should also be careful, the foo()/local_pci_probe() is re-entering)
>
> But I can't find an elegant fix.
>
> long work_on_cpu(int cpu, long (*fn)(void *), void *arg)
> {
> struct work_for_cpu wfc = { .fn = fn, .arg = arg };
>
> +#ifdef CONFIG_LOCKDEP
> + static struct lock_class_key __key;
> + INIT_WORK_ONSTACK(&wfc.work, work_for_cpu_fn);
> + lockdep_init_map(&wfc.work.lockdep_map, &wfc.work, &__key, 0);
> +#else
> INIT_WORK_ONSTACK(&wfc.work, work_for_cpu_fn);
> +#endif
> schedule_work_on(cpu, &wfc.work);
> flush_work(&wfc.work);
> return wfc.ret;
> }
>

Unfortunately that didn't seem to fix it.. I applied the patch
shown below, and I got the same old warning.

---

kernel/workqueue.c | 6 ++++++
1 file changed, 6 insertions(+)


diff --git a/kernel/workqueue.c b/kernel/workqueue.c
index f02c4a4..07d9a67 100644
--- a/kernel/workqueue.c
+++ b/kernel/workqueue.c
@@ -4754,7 +4754,13 @@ long work_on_cpu(int cpu, long (*fn)(void *), void *arg)
{
struct work_for_cpu wfc = { .fn = fn, .arg = arg };

+#ifdef CONFIG_LOCKDEP
+ static struct lock_class_key __key;
+ INIT_WORK_ONSTACK(&wfc.work, work_for_cpu_fn);
+ lockdep_init_map(&wfc.work.lockdep_map, "&wfc.work", &__key, 0);
+#else
INIT_WORK_ONSTACK(&wfc.work, work_for_cpu_fn);
+#endif
schedule_work_on(cpu, &wfc.work);
flush_work(&wfc.work);
return wfc.ret;



Warning:
--------

wmi: Mapper loaded
be2net 0000:11:00.0: irq 102 for MSI/MSI-X
be2net 0000:11:00.0: enabled 1 MSI-x vector(s)
be2net 0000:11:00.0: created 0 RSS queue(s) and 1 default RX queue
be2net 0000:11:00.0: created 1 TX queue(s)
pci 0000:11:04.0: [19a2:0710] type 00 class 0x020000

=============================================
[ INFO: possible recursive locking detected ]
3.11.0-rc1-wq-fix #10 Not tainted
---------------------------------------------
kworker/0:1/126 is trying to acquire lock:
(&wfc.work){+.+.+.}, at: [<ffffffff810770f0>] flush_work+0x0/0xb0

but task is already holding lock:
(&wfc.work){+.+.+.}, at: [<ffffffff81075dc9>] process_one_work+0x169/0x610

other info that might help us debug this:
Possible unsafe locking scenario:

CPU0
----
lock(&wfc.work);
lock(&wfc.work);

*** DEADLOCK ***

May be due to missing lock nesting notation

3 locks held by kworker/0:1/126:
#0: (events){.+.+.+}, at: [<ffffffff81075dc9>] process_one_work+0x169/0x610
#1: (&wfc.work){+.+.+.}, at: [<ffffffff81075dc9>] process_one_work+0x169/0x610
#2: (&__lockdep_no_validate__){......}, at: [<ffffffff81398ada>] device_attach+0x2a/0xc0

stack backtrace:
CPU: 0 PID: 126 Comm: kworker/0:1 Not tainted 3.11.0-rc1-wq-fix #10
Hardware name: IBM -[8737R2A]-/00Y2738, BIOS -[B2E120RUS-1.20]- 11/30/2012
Workqueue: events work_for_cpu_fn
ffff881036887408 ffff881036889668 ffffffff81619059 0000000000000003
ffff881036886a80 ffff881036889698 ffffffff810c1624 ffff881036886a80
ffff881036887408 ffff881036886a80 0000000000000000 ffff8810368896f8
Call Trace:
[<ffffffff81619059>] dump_stack+0x59/0x80
[<ffffffff810c1624>] print_deadlock_bug+0xf4/0x100
[<ffffffff810c3104>] validate_chain+0x504/0x750
[<ffffffff810c365d>] __lock_acquire+0x30d/0x580
[<ffffffff810c3967>] lock_acquire+0x97/0x170
[<ffffffff810770f0>] ? start_flush_work+0x220/0x220
[<ffffffff81077138>] flush_work+0x48/0xb0
[<ffffffff810770f0>] ? start_flush_work+0x220/0x220
[<ffffffff810c2000>] ? mark_held_locks+0x80/0x130
[<ffffffff81074ceb>] ? queue_work_on+0x4b/0xa0
[<ffffffff810c2375>] ? trace_hardirqs_on_caller+0x105/0x1d0
[<ffffffff810c244d>] ? trace_hardirqs_on+0xd/0x10
[<ffffffff81077334>] work_on_cpu+0xa4/0xc0
[<ffffffff8106f940>] ? wqattrs_hash+0x190/0x190
[<ffffffff812d1ed0>] ? pci_pm_prepare+0x60/0x60
[<ffffffff812d1ffa>] __pci_device_probe+0x9a/0xe0
[<ffffffff8161ef90>] ? _raw_spin_unlock_irq+0x30/0x50
[<ffffffff812d3302>] ? pci_dev_get+0x22/0x30
[<ffffffff812d334a>] pci_device_probe+0x3a/0x60
[<ffffffff8161ef90>] ? _raw_spin_unlock_irq+0x30/0x50
[<ffffffff81398bdc>] really_probe+0x6c/0x320
[<ffffffff81398ed7>] driver_probe_device+0x47/0xa0
[<ffffffff81398fe0>] ? __driver_attach+0xb0/0xb0
[<ffffffff81399033>] __device_attach+0x53/0x60
[<ffffffff81396b24>] bus_for_each_drv+0x74/0xa0
[<ffffffff81398b50>] device_attach+0xa0/0xc0
[<ffffffff812c99f9>] pci_bus_add_device+0x39/0x60
[<ffffffff812ed341>] virtfn_add+0x251/0x3e0
[<ffffffff810c244d>] ? trace_hardirqs_on+0xd/0x10
[<ffffffff812ed9bf>] sriov_enable+0x22f/0x3d0
[<ffffffff812edbad>] pci_enable_sriov+0x4d/0x60
[<ffffffffa0127045>] be_vf_setup+0x175/0x410 [be2net]
[<ffffffffa012d3ca>] be_setup+0x37a/0x4b0 [be2net]
[<ffffffffa012dac0>] be_probe+0x5c0/0x820 [be2net]
[<ffffffff812d1f1e>] local_pci_probe+0x4e/0x90
[<ffffffff8106f958>] work_for_cpu_fn+0x18/0x30
[<ffffffff81075e3a>] process_one_work+0x1da/0x610
[<ffffffff81075dc9>] ? process_one_work+0x169/0x610
[<ffffffff810764fc>] worker_thread+0x28c/0x3a0
[<ffffffff81076270>] ? process_one_work+0x610/0x610
[<ffffffff8107da5e>] kthread+0xee/0x100
[<ffffffff8107d970>] ? __init_kthread_worker+0x70/0x70
[<ffffffff81628e5c>] ret_from_fork+0x7c/0xb0
[<ffffffff8107d970>] ? __init_kthread_worker+0x70/0x70
be2net 0000:11:04.0: enabling device (0040 -> 0042)
be2net 0000:11:04.0: Could not use PCIe error reporting
be2net 0000:11:04.0: VF is not privileged to issue opcode 89-1
be2net 0000:11:04.0: VF is not privileged to issue opcode 125-1


Regards,
Srivatsa S. Bhat

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/