On Wed, 25 May 2011 16:08:15 -0400 Jeff Layton <jlay...@redhat.com> wrote:
> On Wed, 27 Apr 2011 16:23:07 -0700 > Mark Moseley <moseleym...@gmail.com> wrote: > > > > > I posted this to bugzilla a while back but I figured I'd paste it here too: > > > > ----------------------------------------------------------------------------------------------------- > > > > I've been getting bit by the exact same bug and been bisecting for the past > > couple of weeks. It's slow going as it can sometimes take a day for the > > BUG() > > to show up (though can also at time take 10 minutes). And I've also seen it > > more than once where something was good after a day and then BUG()'d later > > on, > > just to make things more complicated. So the upshot is that while I feel > > confident enough about this latest batch of bisecting to post it here, I > > wouldn't bet my life on it. I hope this isn't a case where bisecting just > > shows > > where the bug gets exposed but not where it actually got planted :) > > > > Incidentally, I tried the patch from the top of this thread and it didn't > > seem > > to make a difference. I still got bit. > > > > I've posted on the linux-fsdevel thread that Jeff Layton started about it, > > http://www.spinics.net/lists/linux-nfs/msg20280.html if you need more > > details > > on my setup (though I'll be happy to provide anything else you need). > > Though in > > that thread you'll see that I'm not using autofs explicitly, the Netapp GX > > cluster NFS appears to use autofs to do the implicit submounts (I'm not 100% > > sure that's the correct terminology, so hopefully you know what I mean). > > > > Here's my bisect log, ending up at commit > > e61da20a50d21725ff27571a6dff9468e4fb7146 > > > > git bisect start 'fs' > > # good: [3c0eee3fe6a3a1c745379547c7e7c904aa64f6d5] Linux 2.6.37 > > git bisect good 3c0eee3fe6a3a1c745379547c7e7c904aa64f6d5 > > # bad: [c56eb8fb6dccb83d9fe62fd4dc00c834de9bc470] Linux 2.6.38-rc1 > > git bisect bad c56eb8fb6dccb83d9fe62fd4dc00c834de9bc470 > > # good: [7c955fca3e1d8132982148267d9efcafae849bb6] Merge branch 'for_linus' > > of > > git://git.kernel.org/pub/scm/linux/kernel/git/jack/linux-udf-2.6 > > git bisect good 7c955fca3e1d8132982148267d9efcafae849bb6 > > # good: [c32b0d4b3f19c2f5d29568f8b7b72b61693f1277] fs/mpage.c: consolidate > > code > > git bisect good c32b0d4b3f19c2f5d29568f8b7b72b61693f1277 > > # bad: [f8206b925fb0eba3a11839419be118b09105d7b1] Merge branch 'for-linus' > > of > > git://git.kernel.org/pub/scm/linux/kernel/git/viro/vfs-2.6 > > git bisect bad f8206b925fb0eba3a11839419be118b09105d7b1 > > # good: [a8f2800b4f7b76cecb7209cb6a7d2b14904fc711] nfsd4: fix callback > > restarting > > git bisect good a8f2800b4f7b76cecb7209cb6a7d2b14904fc711 > > # bad: [6651149371b842715906311b4631b8489cebf7e8] autofs4: Clean up > > autofs4_free_ino() > > git bisect bad 6651149371b842715906311b4631b8489cebf7e8 > > # good: [0ad53eeefcbb2620b6a71ffdaad4add20b450b8b] afs: add afs_wq and use > > it > > instead of the system workqueue > > git bisect good 0ad53eeefcbb2620b6a71ffdaad4add20b450b8b > > # good: [01c64feac45cea1317263eabc4f7ee1b240f297f] CIFS: Use d_automount() > > rather than abusing follow_link() > > git bisect good 01c64feac45cea1317263eabc4f7ee1b240f297f > > # good: [b5b801779d59165c4ecf1009009109545bd1f642] autofs4: Add d_manage() > > dentry operation > > git bisect good b5b801779d59165c4ecf1009009109545bd1f642 > > # bad: [e61da20a50d21725ff27571a6dff9468e4fb7146] autofs4: Clean up inode > > operations > > git bisect bad e61da20a50d21725ff27571a6dff9468e4fb7146 > > # good: [8c13a676d5a56495c350f3141824a5ef6c6b4606] autofs4: Remove unused > > code > > git bisect good 8c13a676d5a56495c350f3141824a5ef6c6b4606 > > I can more or less reproduce this at will now, I think even with very > few NFS operations on an automounted nfsv4 mount. Here's an oops from a > 2.6.39 kernel: > > [ 119.419789] tun0: Features changed: 0x00004800 -> 0x00004000 > [ 178.242917] FS-Cache: Netfs 'nfs' registered for caching > [ 178.269980] SELinux: initialized (dev 0:2c, type nfs4), uses genfs_contexts > [ 178.282296] SELinux: initialized (dev 0:2d, type nfs4), uses genfs_contexts > [ 523.953284] BUG: Dentry ffff8801f3084180{i=2,n=} still in use (1) [unmount > of nfs4 0:2c] > [ 523.953306] ------------[ cut here ]------------ > [ 523.954013] kernel BUG at fs/dcache.c:925! > [ 523.954013] invalid opcode: 0000 [#1] SMP > [ 523.954013] last sysfs file: /sys/devices/virtual/bdi/0:45/uevent > [ 523.954013] CPU 1 > [ 523.954013] Modules linked in: nfs lockd auth_rpcgss nfs_acl tun fuse > ip6table_filter ip6_tables ebtable_nat ebtables sunrpc cachefiles fscache > cpufreq_ondemand powernow_k8 freq_table mperf it87 adt7475 hwmon_vid xfs > snd_hda_codec_hdmi snd_hda_codec_realtek snd_hda_intel raid1 snd_hda_codec > snd_usb_audio snd_usbmidi_lib snd_hwdep snd_seq snd_rawmidi snd_seq_device > snd_pcm snd_timer snd uvcvideo ppdev videodev soundcore media sp5100_tco > v4l2_compat_ioctl32 edac_core parport_pc snd_page_alloc i2c_piix4 > edac_mce_amd k10temp parport wmi r8169 microcode mii virtio_net kvm_amd kvm > ipv6 ata_generic pata_acpi pata_atiixp radeon ttm drm_kms_helper drm > i2c_algo_bit i2c_core [last unloaded: scsi_wait_scan] > [ 523.954013] > [ 523.954013] Pid: 8387, comm: umount.nfs4 Not tainted 2.6.39-1.fc16.x86_64 > #1 BIOSTAR Group TA790GX 128M/TA790GX 128M > [ 523.954013] RIP: 0010:[<ffffffff81131788>] [<ffffffff81131788>] > shrink_dcache_for_umount_subtree+0x104/0x1c9 > [ 523.954013] RSP: 0018:ffff8801f2385d98 EFLAGS: 00010296 > [ 523.954013] RAX: 0000000000000062 RBX: ffff8801f3084180 RCX: > 00000000000027a7 > [ 523.954013] RDX: 0000000000000000 RSI: 0000000000000046 RDI: > 0000000000000246 > [ 523.954013] RBP: ffff8801f2385dc8 R08: 0000000000000002 R09: > 0000ffff00066c0a > [ 523.954013] R10: 0000ffff00066c0a R11: 0000000000000003 R12: > ffff8801f3084180 > [ 523.954013] R13: ffff8801f31305f0 R14: ffff8801f30ec5f0 R15: > 0000000000000000 > [ 523.954013] FS: 00007f08e468d720(0000) GS:ffff88022fc80000(0000) > knlGS:00000000f770f870 > [ 523.954013] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [ 523.954013] CR2: 00007fff8fc29ff8 CR3: 00000001f7ac4000 CR4: > 00000000000006e0 > [ 523.954013] DR0: 0000000000000000 DR1: 0000000000000000 DR2: > 0000000000000000 > [ 523.954013] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: > 0000000000000400 > [ 523.954013] Process umount.nfs4 (pid: 8387, threadinfo ffff8801f2384000, > task ffff8801f7a61710) > [ 523.954013] Stack: > [ 523.954013] ffff8801fdd74a58 0000000000000000 ffff8801fdd74800 > ffff8801f3084240 > [ 523.954013] ffff8801f2385f28 ffff8801f30ec540 ffff8801f2385de8 > ffffffff81132063 > [ 523.954013] ffff8801fdd74800 ffffffffa0542300 ffff8801f2385e18 > ffffffff81121f15 > [ 523.954013] Call Trace: > [ 523.954013] [<ffffffff81132063>] shrink_dcache_for_umount+0x4d/0x5f > [ 523.954013] [<ffffffff81121f15>] generic_shutdown_super+0x23/0xde > [ 523.954013] [<ffffffff8112204d>] kill_anon_super+0x13/0x4c > [ 523.954013] [<ffffffffa051c436>] nfs4_kill_super+0x44/0x77 [nfs] > [ 523.954013] [<ffffffff81122271>] deactivate_locked_super+0x26/0x4b > [ 523.954013] [<ffffffff81122a83>] deactivate_super+0x37/0x3b > [ 523.954013] [<ffffffff811375b3>] mntput_no_expire+0xcc/0xd1 > [ 523.954013] [<ffffffff811375de>] mntput+0x26/0x28 > [ 523.954013] [<ffffffff81137bef>] release_mounts+0x59/0x73 > [ 523.954013] [<ffffffff81138155>] sys_umount+0x28d/0x2da > [ 523.954013] [<ffffffff814828c2>] system_call_fastpath+0x16/0x1b > [ 523.954013] Code: 8b 40 28 4c 8b 08 48 8b 43 30 48 85 c0 74 07 48 8b 90 a8 > 00 00 00 48 89 34 24 48 c7 c7 f9 ed 7a 81 48 89 de 31 c0 e8 4e 17 34 00 <0f> > 0b 4c 8b 63 18 4c 39 e3 75 11 48 8d bb 90 00 00 00 45 31 e4 > [ 523.954013] RIP [<ffffffff81131788>] > shrink_dcache_for_umount_subtree+0x104/0x1c9 > [ 523.954013] RSP <ffff8801f2385d98> > [ 523.954013] [drm] force priority to high > [ 523.954013] [drm] force priority to high > [ 524.042397] ---[ end trace ff21a3f70c461b5e ]--- > [ 534.621786] [drm] force priority to high > [ 534.621866] [drm] force priority to high > > Client rpc stats: > calls retrans authrefrsh > 44 0 44 > > Client nfs v4: > null read write commit open open_conf > 0 0% 0 0% 1 2% 0 0% 1 2% 1 2% > open_noat open_dgrd close setattr fsinfo renew > 0 0% 0 0% 1 2% 1 2% 4 9% 0 0% > setclntid confirm lock lockt locku access > 1 2% 1 2% 0 0% 0 0% 0 0% 6 13% > getattr lookup lookup_root remove rename link > 7 16% 5 11% 1 2% 0 0% 0 0% 0 0% > symlink create pathconf statfs readlink readdir > 0 0% 0 0% 3 6% 0 0% 0 0% 3 6% > server_caps delegreturn getacl setacl fs_locations rel_lkowner > 7 16% 0 0% 0 0% 0 0% 0 0% 0 0% > exchange_id create_ses destroy_ses sequence get_lease_t reclaim_comp > 0 0% 0 0% 0 0% 0 0% 0 0% 0 0% > layoutget layoutcommit layoutreturn getdevlist getdevinfo ds_write > 0 0% 0 0% 0 0% 0 0% 0 0% 0 0% > ds_commit > 0 0% > > That's good because I think it may help narrow down the codepaths that > lead to this... > > All I did was save a file to the mount using claws-mail and wait for > autofs to unmount it. I'm going to see if I can narrow down the > reproducer somewhat and whether I can take autofs out of the picture. > (cc'ing autofs mailing list too) Taking autofs out of the picture seems to make the problem go away, so this seems to be related to that. Why, exactly, I'm not sure yet. It's always been my understanding that autofs basically gets out of the way once the fs is mounted, but I suppose it needs some way to check for expiration so maybe that mechanism is causing issues. -- Jeff Layton <jlay...@redhat.com> _______________________________________________ autofs mailing list autofs@linux.kernel.org http://linux.kernel.org/mailman/listinfo/autofs
