Bug 984174

Summary: Rawhide-F20[ INFO: possible recursive locking detected ] nfsv4
Product: [Fedora] Fedora Reporter: Frank Murphy <frankly3d>
Component: kernelAssignee: Jeff Layton <jlayton>
Status: CLOSED DUPLICATE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: rawhideCC: gansalmon, itamar, jlayton, jonathan, kernel-maint, madhu.chinakonda, nfs-maint, steved
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2013-09-16 12:54:11 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description Frank Murphy 2013-07-13 09:04:35 UTC
Description of problem: Recursive Locking possibly?


Version-Release number of selected component (if applicable):
3.11.0-0.rc0.git3.1.fc20.x86_64

How reproducible: noticeable at bootups

dmesg <snip>


[  213.518014] =============================================
[  213.518014] [ INFO: possible recursive locking detected ]
[  213.518014] 3.11.0-0.rc0.git3.1.fc20.x86_64 #1 Not tainted
[  213.518014] ---------------------------------------------
[  213.518014] mount.nfs/1349 is trying to acquire lock:
[  213.518014]  (&sn->pipefs_sb_lock){+.+.+.}, at: [<ffffffffa0044898>] rpc_get_sb_net+0xe8/0x200 [sunrpc]
[  213.518014] 
but task is already holding lock:
[  213.518014]  (&sn->pipefs_sb_lock){+.+.+.}, at: [<ffffffffa0044898>] rpc_get_sb_net+0xe8/0x200 [sunrpc]
[  213.518014] 
other info that might help us debug this:
[  213.518014]  Possible unsafe locking scenario:

[  213.518014]        CPU0
[  213.518014]        ----
[  213.518014]   lock(&sn->pipefs_sb_lock);
[  213.518014]   lock(&sn->pipefs_sb_lock);
[  213.518014] 
 *** DEADLOCK ***

[  213.518014]  May be due to missing lock nesting notation

[  213.518014] 1 lock held by mount.nfs/1349:
[  213.518014]  #0:  (&sn->pipefs_sb_lock){+.+.+.}, at: [<ffffffffa0044898>] rpc_get_sb_net+0xe8/0x200 [sunrpc]
[  213.518014] 
stack backtrace:
[  213.518014] CPU: 0 PID: 1349 Comm: mount.nfs Not tainted 3.11.0-0.rc0.git3.1.fc20.x86_64 #1
[  213.518014] Hardware name: Dell Inc. Vostro 200/0CU409, BIOS 1.0.15 06/23/2008
[  213.518014]  ffff8800c39a26e0 ffff8800c39c7680 ffffffff8172a840 ffffffff825dcbc0
[  213.518014]  ffff8800c39c7740 ffffffff810eb70f ffff8800c39c76a0 ffffffff81021869
[  213.518014]  ffff8800c39c76c8 ffffffff00000000 00000000007543aa ffffffff8220a300
[  213.518014] Call Trace:
[  213.518014]  [<ffffffff8172a840>] dump_stack+0x54/0x74
[  213.518014]  [<ffffffff810eb70f>] __lock_acquire+0x1a1f/0x1b30
[  213.518014]  [<ffffffff81021869>] ? sched_clock+0x9/0x10
[  213.518014]  [<ffffffff810bb818>] ? sched_clock_cpu+0xa8/0x100
[  213.518014]  [<ffffffff810ec012>] lock_acquire+0xa2/0x1f0
[  213.518014]  [<ffffffffa0044898>] ? rpc_get_sb_net+0xe8/0x200 [sunrpc]
[  213.518014]  [<ffffffff8172e037>] mutex_lock_nested+0x87/0x3e0
[  213.518014]  [<ffffffffa0044898>] ? rpc_get_sb_net+0xe8/0x200 [sunrpc]
[  213.518014]  [<ffffffff810bb95f>] ? local_clock+0x5f/0x70
[  213.518014]  [<ffffffffa0044898>] ? rpc_get_sb_net+0xe8/0x200 [sunrpc]
[  213.518014]  [<ffffffff810e6cef>] ? lock_release_holdtime.part.28+0xf/0x1a0
[  213.518014]  [<ffffffffa0044898>] rpc_get_sb_net+0xe8/0x200 [sunrpc]
[  213.518014]  [<ffffffffa00447b5>] ? rpc_get_sb_net+0x5/0x200 [sunrpc]
[  213.518014]  [<ffffffffa0024ec8>] ? rpc_net_ns+0xa8/0x1a0 [sunrpc]
[  213.518014]  [<ffffffffa00718d1>] gss_create+0x131/0x240 [auth_rpcgss]
[  213.518014]  [<ffffffffa00329ae>] rpcauth_create+0xae/0x120 [sunrpc]
[  213.518014]  [<ffffffffa002675b>] rpc_new_client+0x28b/0x5c0 [sunrpc]
[  213.518014]  [<ffffffff81197959>] ? kstrdup+0x49/0x60
[  213.518014]  [<ffffffffa0027d0c>] rpc_create+0xcc/0x260 [sunrpc]
[  213.518014]  [<ffffffff810217f5>] ? native_sched_clock+0x15/0x80
[  213.518014]  [<ffffffff81021869>] ? sched_clock+0x9/0x10
[  213.518014]  [<ffffffff810bb68d>] ? sched_clock_local+0x1d/0x80
[  213.518014]  [<ffffffff810217f5>] ? native_sched_clock+0x15/0x80
[  213.518014]  [<ffffffffa03ae46e>] nfs_create_rpc_client+0xbe/0x100 [nfs]
[  213.518014]  [<ffffffffa0400e60>] nfs4_init_client+0xa0/0x360 [nfsv4]
[  213.518014]  [<ffffffff81021869>] ? sched_clock+0x9/0x10
[  213.518014]  [<ffffffff810bb68d>] ? sched_clock_local+0x1d/0x80
[  213.518014]  [<ffffffff810bb818>] ? sched_clock_cpu+0xa8/0x100
[  213.518014]  [<ffffffff810e611d>] ? trace_hardirqs_off+0xd/0x10
[  213.518014]  [<ffffffff810bb95f>] ? local_clock+0x5f/0x70
[  213.518014]  [<ffffffff810e6cef>] ? lock_release_holdtime.part.28+0xf/0x1a0
[  213.518014]  [<ffffffffa03b0f96>] nfs_get_client+0x486/0x640 [nfs]
[  213.518014]  [<ffffffffa03b0c50>] ? nfs_get_client+0x140/0x640 [nfs]
[  213.518014]  [<ffffffffa04006aa>] nfs4_set_client+0x8a/0x110 [nfsv4]
[  213.518014]  [<ffffffffa0402244>] nfs4_create_server+0xc4/0x310 [nfsv4]
[  213.518014]  [<ffffffffa03f7a0e>] nfs4_remote_mount+0x2e/0x60 [nfsv4]
[  213.518014]  [<ffffffff811f6c99>] mount_fs+0x39/0x1b0
[  213.518014]  [<ffffffff8119d100>] ? __alloc_percpu+0x10/0x20
[  213.518014]  [<ffffffff812148d3>] vfs_kern_mount+0x63/0xf0
[  213.518014]  [<ffffffffa03f78e6>] nfs_do_root_mount+0x86/0xc0 [nfsv4]
[  213.518014]  [<ffffffffa03f7cea>] nfs4_try_mount+0x4a/0xd0 [nfsv4]
[  213.518014]  [<ffffffffa03b1d07>] ? get_nfs_version+0x27/0x80 [nfs]
[  213.518014]  [<ffffffffa03bcafd>] nfs_fs_mount+0x3dd/0xd00 [nfs]
[  213.518014]  [<ffffffffa03bdb80>] ? nfs_clone_super+0x140/0x140 [nfs]
[  213.518014]  [<ffffffffa03bb350>] ? param_set_portnr+0x60/0x60 [nfs]
[  213.518014]  [<ffffffff811f6c99>] mount_fs+0x39/0x1b0
[  213.518014]  [<ffffffff8119d100>] ? __alloc_percpu+0x10/0x20
[  213.518014]  [<ffffffff812148d3>] vfs_kern_mount+0x63/0xf0
[  213.518014]  [<ffffffff8121719e>] do_mount+0x23e/0xa20
[  213.518014]  [<ffffffff81217a03>] SyS_mount+0x83/0xc0
[  213.518014]  [<ffffffff8173d9d9>] system_call_fastpath+0x16/0x1b
[  213.773243] NFSD: starting 90-second grace period (net ffffffff81d06580)
[  328.856178] fuse init (API version 7.22)
[  329.057207] SELinux: initialized (dev fuse, type fuse), uses genfs_contexts
[  329.120535] SELinux: initialized (dev fusectl, type fusectl), uses genfs_contexts
[  362.207058] INFO: task mount.nfs:1349 blocked for more than 120 seconds.
[  362.207065] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[  362.207069] mount.nfs       D ffff8800c5980000  4048  1349      1 0x00000084
[  362.207077]  ffff8800c39c7798 0000000000000046 00000000001d5300 ffff8800c39c7fd8
[  362.207083]  ffff8800c39c7fd8 00000000001d5300 ffff8800c39a26e0 ffff88010ed26490
[  362.207089]  0000000000000246 ffff8800c39a26e0 ffff88010ed26488 ffff880123364ef0
[  362.207094] Call Trace:
[  362.207106]  [<ffffffff81732329>] schedule_preempt_disabled+0x39/0x90
[  362.207110]  [<ffffffff8172e155>] mutex_lock_nested+0x1a5/0x3e0
[  362.207147]  [<ffffffffa0044898>] ? rpc_get_sb_net+0xe8/0x200 [sunrpc]
[  362.207165]  [<ffffffffa0044898>] ? rpc_get_sb_net+0xe8/0x200 [sunrpc]
[  362.207184]  [<ffffffffa0044898>] rpc_get_sb_net+0xe8/0x200 [sunrpc]
[  362.207202]  [<ffffffffa00447b5>] ? rpc_get_sb_net+0x5/0x200 [sunrpc]
[  362.207216]  [<ffffffffa0024ec8>] ? rpc_net_ns+0xa8/0x1a0 [sunrpc]
[  362.207225]  [<ffffffffa00718d1>] gss_create+0x131/0x240 [auth_rpcgss]
[  362.207243]  [<ffffffffa00329ae>] rpcauth_create+0xae/0x120 [sunrpc]
[  362.207257]  [<ffffffffa002675b>] rpc_new_client+0x28b/0x5c0 [sunrpc]
[  362.207263]  [<ffffffff81197959>] ? kstrdup+0x49/0x60
[  362.207278]  [<ffffffffa0027d0c>] rpc_create+0xcc/0x260 [sunrpc]
[  362.207283]  [<ffffffff810217f5>] ? native_sched_clock+0x15/0x80
[  362.207288]  [<ffffffff81021869>] ? sched_clock+0x9/0x10
[  362.207294]  [<ffffffff810bb68d>] ? sched_clock_local+0x1d/0x80
[  362.207298]  [<ffffffff810217f5>] ? native_sched_clock+0x15/0x80
[  362.207309]  [<ffffffffa03ae46e>] nfs_create_rpc_client+0xbe/0x100 [nfs]
[  362.207329]  [<ffffffffa0400e60>] nfs4_init_client+0xa0/0x360 [nfsv4]
[  362.207333]  [<ffffffff81021869>] ? sched_clock+0x9/0x10
[  362.207338]  [<ffffffff810bb68d>] ? sched_clock_local+0x1d/0x80
[  362.207343]  [<ffffffff810bb818>] ? sched_clock_cpu+0xa8/0x100
[  362.207348]  [<ffffffff810e611d>] ? trace_hardirqs_off+0xd/0x10
[  362.207352]  [<ffffffff810bb95f>] ? local_clock+0x5f/0x70
[  362.207357]  [<ffffffff810e6cef>] ? lock_release_holdtime.part.28+0xf/0x1a0
[  362.207367]  [<ffffffffa03b0f96>] nfs_get_client+0x486/0x640 [nfs]
[  362.207375]  [<ffffffffa03b0c50>] ? nfs_get_client+0x140/0x640 [nfs]
[  362.207390]  [<ffffffffa04006aa>] nfs4_set_client+0x8a/0x110 [nfsv4]
[  362.207405]  [<ffffffffa0402244>] nfs4_create_server+0xc4/0x310 [nfsv4]
[  362.207418]  [<ffffffffa03f7a0e>] nfs4_remote_mount+0x2e/0x60 [nfsv4]
[  362.207424]  [<ffffffff811f6c99>] mount_fs+0x39/0x1b0
[  362.207429]  [<ffffffff8119d100>] ? __alloc_percpu+0x10/0x20
[  362.207434]  [<ffffffff812148d3>] vfs_kern_mount+0x63/0xf0
[  362.207447]  [<ffffffffa03f78e6>] nfs_do_root_mount+0x86/0xc0 [nfsv4]
[  362.207461]  [<ffffffffa03f7cea>] nfs4_try_mount+0x4a/0xd0 [nfsv4]
[  362.207470]  [<ffffffffa03b1d07>] ? get_nfs_version+0x27/0x80 [nfs]
[  362.207481]  [<ffffffffa03bcafd>] nfs_fs_mount+0x3dd/0xd00 [nfs]
[  362.207492]  [<ffffffffa03bdb80>] ? nfs_clone_super+0x140/0x140 [nfs]
[  362.207502]  [<ffffffffa03bb350>] ? param_set_portnr+0x60/0x60 [nfs]
[  362.207507]  [<ffffffff811f6c99>] mount_fs+0x39/0x1b0
[  362.207511]  [<ffffffff8119d100>] ? __alloc_percpu+0x10/0x20
[  362.207515]  [<ffffffff812148d3>] vfs_kern_mount+0x63/0xf0
[  362.207520]  [<ffffffff8121719e>] do_mount+0x23e/0xa20
[  362.207524]  [<ffffffff81217a03>] SyS_mount+0x83/0xc0
[  362.207530]  [<ffffffff8173d9d9>] system_call_fastpath+0x16/0x1b
[  362.207532] INFO: lockdep is turned off.

Comment 1 Jeff Layton 2013-09-16 12:54:11 UTC

*** This bug has been marked as a duplicate of bug 984115 ***