fs/namespace: inconsistent lock state

From: Sudeep Holla
Date: Tue Dec 13 2016 - 12:19:40 EST


Hi Al,

I started seeing these message this morning when I picked up today's
linux-next. It could be due to commit a1de523a3197 ("move mnt_free_id()
into free_vfsmnt()"). Reverting it makes this error disappear.

=================================
[ INFO: inconsistent lock state ]
4.9.0-next-20161213-00006-g733bb9f77ddb #244 Not tainted
---------------------------------
inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage.
swapper/4/0 [HC0[0]:SC1[1]:HE1:SE0] takes:
(mnt_id_lock){+.?...}, at: [<ffff0000082d886c>]
mnt_free_id.isra.7+0x2c/0x70
{SOFTIRQ-ON-W} state was registered at:
mark_lock+0x1a0/0x698
__lock_acquire+0x4d4/0x690
lock_acquire+0xcc/0x298
_raw_spin_lock+0x4c/0x60
alloc_vfsmnt+0x80/0x248
vfs_kern_mount+0x3c/0x160
mnt_init+0x1a8/0x260
vfs_caches_init+0x78/0xe8
start_kernel+0x3ac/0x414
__primary_switched+0x64/0x6c
irq event stamp: 23366
hardirqs last enabled at (23366): rcu_process_callbacks+0x56c/0x940
hardirqs last disabled at (23365): rcu_process_callbacks+0x160/0x940
softirqs last enabled at (23352): _local_bh_enable+0x28/0x50
softirqs last disabled at (23353): irq_exit+0xe8/0x148

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

CPU0
----
lock(mnt_id_lock);
<Interrupt>
lock(mnt_id_lock);

*** DEADLOCK ***

1 lock held by swapper/4/0:
#0: (rcu_callback){......}, at: rcu_process_callbacks+0x28c/0x940

stack backtrace:
CPU: 4 PID: 0 Comm: swapper/4 Not tainted
4.9.0-next-20161213-00006-g733bb9f77ddb #244
Call trace:
dump_backtrace+0x0/0x258
show_stack+0x24/0x30
dump_stack+0xac/0xe8
print_usage_bug+0x20c/0x2b0
mark_lock+0x5bc/0x698
__lock_acquire+0x530/0x690
lock_acquire+0xcc/0x298
_raw_spin_lock+0x4c/0x60
mnt_free_id.isra.7+0x2c/0x70
free_vfsmnt+0x20/0x50
delayed_free_vfsmnt+0x20/0x30
rcu_process_callbacks+0x2cc/0x940
__do_softirq+0x12c/0x63c
irq_exit+0xe8/0x148
__handle_domain_irq+0x6c/0xc0
gic_handle_irq+0x5c/0xb0