Created attachment 504121
debug patch -- instrument nfs_d_automount
Taking Ian's suggestion on IRC into account, I decided to instrument nfs_d_automount. I turned all of the dprintk's into printk's, had them print current->pid. I also added a printk of the string representation of the struct path.
It looks like we do have 2 concurrent nfs_d_automount requests going on here. They both return different vfsmounts, though. The second vfsmount does not show up in the mount table (as shown by crash's mount command). Here's the snippet of dmesg when I did the reproducer to trigger a mount. Unfortunately, the dump_stack() got a little muddled, but it gives you an idea of what's going on...
Created attachment 504121
debug patch -- instrument nfs_d_automount
Taking Ian's suggestion on IRC into account, I decided to instrument nfs_d_automount. I turned all of the dprintk's into printk's, had them print current->pid. I also added a printk of the string representation of the struct path.
It looks like we do have 2 concurrent nfs_d_automount requests going on here. They both return different vfsmounts, though. The second vfsmount does not show up in the mount table (as shown by crash's mount command). Here's the snippet of dmesg when I did the reproducer to trigger a mount. Unfortunately, the dump_stack() got a little muddled, but it gives you an idea of what's going on...
[ 214.444300] 1670: --> nfs_d_automount() 1.fc16. x86_64. debug #1 897>] nfs_d_automount +0x60/0x579 [nfs] 1.fc16. x86_64. debug #1 897>] nfs_d_automount +0x60/0x579 [nfs] a15>] ? _raw_spin_ unlock+ 0x28/0x2c 5b4>] ? dput+0xdc/0xfc 347>] ? nfs_lookup_ revalidate+ 0x227/0x366 [nfs] 463>] follow_ managed+ 0x12a/0x1ce 7b8>] walk_component+ 0x22c/0x335 715>] ? security_ inode_exec_ permission+ 0x25/0x27 a60>] link_path_ walk+0x19f/ 0x439 e1e>] path_lookupat+ 0x5a/0x2e1 170>] ? might_fault+ 0xa5/0xac 127>] ? might_fault+ 0x5c/0xac 8ee>] ? getname_ flags+0x31/ 0x1ca f4f>] do_path_ lookup+ 0x28/0x96 374>] user_path_ at+0x59/ 0x96 4b6>] ? up_read+0x28/0x2c f30>] ? do_page_ fault+0x360/ 0x3b4 03f>] vfs_fstatat+ 0x44/0x6e 127>] ? might_fault+ 0x5c/0xac 087>] vfs_lstat+0x1e/0x20 1d6>] sys_newlstat+ 0x1a/0x33 0f3>] ? trace_hardirqs_ on_caller+ 0x10b/0x12f e5f>] ? audit_syscall_ entry+0x11c/ 0x148 e1e>] ? trace_hardirqs_ on_thunk+ 0x3a/0x3f 5c2>] system_ call_fastpath+ 0x16/0x1b (1677): enter ffff88001005c54 0 path=/misc/ salusa/ scratch (1677): done, success a0d>] ? sched_clock_ local+0x12/ 0x75 764>] ? trace_hardirqs_ off+0xd/ 0xf bda>] ? local_clock+ 0x36/0x4d e91>] ? lock_release_ holdtime. part.8+ 0x6b/0x72 49f>] ? __mutex_ unlock_ slowpath+ 0x112/0x122 463>] follow_ managed+ 0x12a/0x1ce 7b8>] walk_component+ 0x22c/0x335 956>] ? link_path_ walk+0x95/ 0x439 4f0>] do_last+0x13f/0x5ad 4fe>] path_openat+ 0xcb/0x31f a0d>] ? sched_clock_ local+0x12/ 0x75 78a>] do_filp_ open+0x38/ 0x86 a15>] ? _raw_spin_ unlock+ 0x28/0x2c 164>] ? alloc_fd+ 0x17f/0x191 7a0>] do_sys_ open+0x6e/ 0x100 e5f>] ? audit_syscall_ entry+0x11c/ 0x148 852>] sys_open+0x20/0x22 5c2>] system_ call_fastpath+ 0x16/0x1b (1670): enter ffff88001005c54 0 path=/misc/ salusa/ scratch (1670): done, success
[ 214.445701] Pid: 1670, comm: claws-mail Not tainted 2.6.39-
[ 214.448353] Call Trace:
[ 214.449301] [<ffffffffa01dc
[ 214.451247] 1677: --> nfs_d_automount()
[ 214.451251] Pid: 1677, comm: claws-mail Not tainted 2.6.39-
[ 214.451253] Call Trace:
[ 214.451279] [<ffffffffa01dc
[ 214.451334] [<ffffffff814b9
[ 214.451362] [<ffffffff81145
[ 214.451373] [<ffffffffa01cc
[ 214.451377] [<ffffffff8113c
[ 214.451381] [<ffffffff8113d
[ 214.451402] [<ffffffff81207
[ 214.451406] [<ffffffff8113d
[ 214.451409] [<ffffffff8113d
[ 214.451432] [<ffffffff81101
[ 214.451435] [<ffffffff81101
[ 214.451438] [<ffffffff8113c
[ 214.451441] [<ffffffff8113e
[ 214.451444] [<ffffffff8113f
[ 214.451462] [<ffffffff81077
[ 214.451471] [<ffffffff814bc
[ 214.451475] [<ffffffff81137
[ 214.451478] [<ffffffff81101
[ 214.451481] [<ffffffff81137
[ 214.451484] [<ffffffff81137
[ 214.451493] [<ffffffff81087
[ 214.451502] [<ffffffff810a9
[ 214.451523] [<ffffffff81256
[ 214.451526] [<ffffffff814c0
[ 214.451532] nfs_d_automount
[ 214.451548] 1677: dentry=
[ 214.471100] SELinux: initialized (dev 0:2b, type nfs4), uses genfs_contexts
[ 214.471587] nfs_d_automount
[ 214.471607] 1677: <-- nfs_d_automount() = ffff88001194d140
[ 214.511636] [<ffffffff81078
[ 214.514001] [<ffffffff81083
[ 214.515589] [<ffffffff81078
[ 214.517049] [<ffffffff81083
[ 214.518857] [<ffffffff814b8
[ 214.521946] [<ffffffff8113c
[ 214.523395] [<ffffffff8113d
[ 214.524896] [<ffffffff8113d
[ 214.526307] [<ffffffff8113e
[ 214.527571] [<ffffffff8113f
[ 214.528964] [<ffffffff81078
[ 214.530742] [<ffffffff8113f
[ 214.532133] [<ffffffff814b9
[ 214.533579] [<ffffffff8114a
[ 214.534965] [<ffffffff81132
[ 214.536294] [<ffffffff810a9
[ 214.537889] [<ffffffff81132
[ 214.539129] [<ffffffff814c0
[ 214.540601] nfs_d_automount
[ 214.541958] 1670: dentry=
[ 214.553643] nfs_d_automount
[ 214.555077] 1670: <-- nfs_d_automount() = ffff88001194d280