nfs_lookup_revalidate() NULL deref #456

behlendorf · 2011-11-21T19:02:53Z

Reported by Chris Dunlop [email protected]

Just trying zfsonlinux for the first time, and I'm getting the kernel oops below when doing "zpool create" when using nfs-root. There's no oops with "zpool create" on the same kernel when using local root.

This is with Linux 3.1.1, spl/zfs current git (spl: 1114ae6 zfs: ca5fd24)

SPL: Loaded module v0.6.0, using hostid 0xc80a843f
zunicode: module license 'CDDL' taints kernel.
Disabling lock debugging due to kernel taint
ZFS: Loaded module v0.6.0, ZFS pool version 28, ZFS filesystem version 5
BUG: unable to handle kernel NULL pointer dereference at 0000000000000038
IP: [] nfs_lookup_revalidate+0x1c/0x3f4 [nfs]
PGD 212e067 PUD 9f487067 PMD 0
Oops: 0000 [#1] SMP
CPU 0

Pid: 3334, comm: zpool Tainted: P 3.1.1-otn-00008-gd50247e #2 System manufacturer System Product Na me/M4A88TD-M
RIP: e030:[] [] nfs_lookup_revalidate+0x1c/0x3f4 [nfs]
RSP: e02b:ffff8800b7a41a58 EFLAGS: 00010292
RAX: 00000000fffffff6 RBX: ffff8800a33c2cc0 RCX: 0000000000000070
RDX: 0000000000000000 RSI: 0000000000000000 RDI: ffff8800a33c2cc0
RBP: ffff8800b7a41a98 R08: 000000000000000f R09: ffff8800a33c2d06
R10: 000000000e8ca8a5 R11: ffff8800b78cfcd0 R12: ffff8800a1010cc0
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
FS: 00007f6f419bec00(0000) GS:ffff8800bb727000(0000) knlGS:0000000000000000
CS: e033 DS: 0000 ES: 0000 CR0: 000000008005003b [ 1042.779009] CR2: 0000000000000038 CR3: 00000000023e1000 CR4: 0000000000000660
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Process zpool (pid: 3334, threadinfo ffff8800b7a40000, task ffff8800a47f2780)
Stack:
ffff8800b7a41ae8 0000000000000000 ffff8800b7a41a98 ffff8800a33c2cc0
ffff8800a1010cc0 0000000000000000 ffff8800b7a41ae8 0000000000000000
ffff8800b7a41ad8 ffffffff811077d0 ffff8800b7ba09a0 ffff8800a1010cc0
Call Trace:
[] __lookup_hash+0x7e/0xc9
[] lookup_one_len+0xb8/0xcc
[] vn_rename+0xac/0x1e0 [spl]
[] ? bit_waitqueue+0x16/0xa4
[] ? wake_up_bit+0x20/0x25
[] ? nfs_commit_clear_lock+0x20/0x22 [nfs]
[] ? nfs_commit_inode+0x18f/0x1b2 [nfs]
[] ? nfs_file_fsync+0xd4/0xe6 [nfs]
[] spa_config_sync+0x32e/0x44f [zfs]
[] spa_create+0x6be/0x72f [zfs]
[] ? kmem_alloc_debug+0x92/0xd1 [spl]
[] zfs_ioc_pool_create+0x1c2/0x22f [zfs]
[] zfsdev_ioctl+0x11b/0x176 [zfs]
[] ? xen_force_evtchn_callback+0xd/0xf
[] do_vfs_ioctl+0x3ed/0x43c
[] ? xen_restore_fl_direct_reloc+0x4/0x4
[] ? xen_clts+0xfc/0x107
[] sys_ioctl+0x42/0x65
[] system_call_fastpath+0x16/0x1b
RIP [] nfs_lookup_revalidate+0x1c/0x3f4 [nfs]
RSP
CR2: 0000000000000038

The text was updated successfully, but these errors were encountered:

chrisrd · 2011-11-21T22:13:30Z

Sorry, false alarm: the problem is in NFS rather than ZoL. With this patch (for NFS and other FSs, now submitted upstream), I can "zpool create" on NFS root:

http://article.gmane.org/gmane.linux.nfs/45039

Cheers!

behlendorf · 2011-11-21T23:40:57Z

Great, thanks for letting me know. I'll close this issue.

chrisrd · 2011-12-01T04:48:37Z

Oops, bad news I'm afraid: it seems that ZoL is at fault after all. It's use of lookup_one_len() (in spl-vnode.c, vn_lookup_hash()) apparently isn't allowed:

http://article.gmane.org/gmane.linux.nfs/40395

"lookup_one_len must only be called by a filesystem or a library function called by the filesystem. You are not allowed to call it on a random filesystem like nfs that doesn't support the underlying assumptions."

I'm trying to get an alternate patch into NFS (and other file systems) to fix the immediate Oops:

http://article.gmane.org/gmane.linux.file-systems/59310

That patch also enables me to run ZoL on NFS root, but ultimately I guess ZoL needs to use something other than lookup_one_len(). I tried tracking down what had been done to ecryptfs for this exact problem as mentioned here:

http://article.gmane.org/gmane.linux.nfs/40376

...but it turns out that fix (linux commits 21edad3 and 93c3fe4) was later reverted (linux commit 8787c7a).

At this point it's all waaaayyyy beyond my current understanding and I'm not able to provide any other help in getting ZoL fixed - sorry!

Chris.

behlendorf · 2011-12-01T16:52:58Z

Interesting, OK let me reopen this issue so we can continue to track it and thank you for doing the legwork on this.

chrisrd · 2011-12-01T22:48:22Z

In case you haven't followed the whole can of wormsBB~B thread I opened, it contains a reference to this previous thread:

http://thread.gmane.org/gmane.linux.kernel/1139127

...where Linus himself takes an interest and was of the opinion that something like my original patch should be done, even if just as a stopgap. But it seems that Al Viro had intentions of doing "something" to fix this situation, although that was back in May 11 and I can't see anything related in current linux-HEAD.

behlendorf · 2012-09-18T02:56:53Z

Any update on this?

Hadron2 · 2013-01-20T23:52:01Z

While attempting to set up an NFS server running on ZFS, I got an Oops
that generated this stack trace. Was advised to post it here by the denizens
of #zfsonlinux. :^)

ETA: This was trying to use NFSv4. Seems to work OK using v3.

ETA2: Spoke too soon. Second Opps/Trace is from a v3 attempt.

Jan 20 16:18:45 shasta kernel: [  201.708805] NFSD: Unable to end grace period: -110
Jan 20 16:23:57 shasta kernel: [  512.225459] BUG: unable to handle kernel NULL pointer dereference at 0000000000000038
Jan 20 16:23:57 shasta kernel: [  512.225487] IP: [] zpl_revalidate+0x1d/0xb0 [zfs]
Jan 20 16:23:57 shasta kernel: [  512.225550] PGD 0 
Jan 20 16:23:57 shasta kernel: [  512.225557] Oops: 0000 [#1] SMP 
Jan 20 16:23:57 shasta kernel: [  512.225566] CPU 2 
Jan 20 16:23:57 shasta kernel: [  512.225571] Modules linked in: pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) snd_hda_codec_realtek snd_hda_intel snd_hda_codec bnep rfcomm bluetooth coretemp snd_hwdep snd_pcm snd_seq_midi snd_rawmidi snd_seq_midi_event snd_seq snd_timer gpio_ich kvm_intel joydev snd_seq_device lpc_ich psmouse kvm snd i7core_edac parport_pc edac_core soundcore mac_hid ppdev lp snd_page_alloc serio_raw microcode parport nfsd nfs lockd fscache auth_rpcgss bonding nfs_acl sunrpc raid10 raid456 async_pq async_xor xor async_memcpy async_raid6_recov raid6_pq async_tx raid0 multipath linear zfs(PO) zcommon(PO) znvpair(PO) zavl(PO) zunicode(PO) spl(O) zlib_deflate dm_crypt nouveau hid_generic firewire_ohci firewire_core hid_logitech ff_memless raid1 crc_itu_t ttm drm_kms_helper drm usbhid hid i2c_algo_bit pata_marvell mxm_wmi video wmi sky2
Jan 20 16:23:57 shasta kernel: [  512.225961] 
Jan 20 16:23:57 shasta kernel: [  512.225965] Pid: 4267, comm: nfsd Tainted: P          IO 3.5.0-22-generic #34-Ubuntu    /EVGA P55 SLI E657
Jan 20 16:23:57 shasta kernel: [  512.225982] RIP: 0010:[]  [] zpl_revalidate+0x1d/0xb0 [zfs]
Jan 20 16:23:57 shasta kernel: [  512.226042] RSP: 0018:ffff880407e71bf0  EFLAGS: 00010286
Jan 20 16:23:57 shasta kernel: [  512.226051] RAX: ffffffffa0369740 RBX: ffff880464fbb900 RCX: 0000000000000018
Jan 20 16:23:57 shasta kernel: [  512.226061] RDX: ffff880407d47080 RSI: 0000000000000000 RDI: ffff880464fbb900
Jan 20 16:23:57 shasta kernel: [  512.226071] RBP: ffff880407e71c10 R08: 0a00000000767273 R09: 0000000000000000
Jan 20 16:23:57 shasta kernel: [  512.226081] R10: ffff880464fbb900 R11: 2100000000000000 R12: ffff880462dd1c00
Jan 20 16:23:57 shasta kernel: [  512.226091] R13: ffff880407e71c60 R14: 0000000000000000 R15: ffff880407d47080
Jan 20 16:23:57 shasta kernel: [  512.226102] FS:  0000000000000000(0000) GS:ffff88047fc80000(0000) knlGS:0000000000000000
Jan 20 16:23:57 shasta kernel: [  512.226113] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Jan 20 16:23:57 shasta kernel: [  512.226121] CR2: 0000000000000038 CR3: 0000000001c0b000 CR4: 00000000000007e0
Jan 20 16:23:57 shasta kernel: [  512.226132] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jan 20 16:23:57 shasta kernel: [  512.226142] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jan 20 16:23:57 shasta kernel: [  512.226152] Process nfsd (pid: 4267, threadinfo ffff880407e70000, task ffff8804261a5c00)
Jan 20 16:23:57 shasta kernel: [  512.226163] Stack:
Jan 20 16:23:57 shasta kernel: [  512.226167]  ffff880464fbb900 ffff880462dd1c00 ffff880407e71c60 0000000000000000
Jan 20 16:23:57 shasta kernel: [  512.226184]  ffff880407e71c50 ffffffff8118ca4c ffff8803f9cac900 ffff880407d47083
Jan 20 16:23:57 shasta kernel: [  512.226199]  ffff880407d47083 0000000000000002 ffff880462dd1c00 ffff880407e71d38
Jan 20 16:23:57 shasta kernel: [  512.226215] Call Trace:
Jan 20 16:23:57 shasta kernel: [  512.226230]  [] __lookup_hash+0xac/0x120
Jan 20 16:23:57 shasta kernel: [  512.226242]  [] lookup_one_len+0xd6/0x110
Jan 20 16:23:57 shasta kernel: [  512.226261]  [] nfsd_lookup_dentry+0x10b/0x470 [nfsd]
Jan 20 16:23:57 shasta kernel: [  512.226279]  [] ? fh_verify+0x14a/0x560 [nfsd]
Jan 20 16:23:57 shasta kernel: [  512.226297]  [] nfsd_lookup+0x79/0x140 [nfsd]
Jan 20 16:23:57 shasta kernel: [  512.226317]  [] nfsd4_lookup+0x1a/0x20 [nfsd]
Jan 20 16:23:57 shasta kernel: [  512.226337]  [] nfsd4_proc_compound+0x2fc/0x650 [nfsd]
Jan 20 16:23:57 shasta kernel: [  512.226355]  [] nfsd_dispatch+0xbe/0x1c0 [nfsd]
Jan 20 16:23:57 shasta kernel: [  512.227210]  [] svc_process_common+0x30b/0x610 [sunrpc]
Jan 20 16:23:57 shasta kernel: [  512.228058]  [] svc_process+0x106/0x160 [sunrpc]
Jan 20 16:23:57 shasta kernel: [  512.228895]  [] nfsd+0xb5/0x1a0 [nfsd]
Jan 20 16:23:57 shasta kernel: [  512.229724]  [] ? nfsd_get_default_max_blksize+0x60/0x60 [nfsd]
Jan 20 16:23:57 shasta kernel: [  512.230546]  [] kthread+0x93/0xa0
Jan 20 16:23:57 shasta kernel: [  512.231358]  [] kernel_thread_helper+0x4/0x10
Jan 20 16:23:57 shasta kernel: [  512.232173]  [] ? kthread_freezable_should_stop+0x70/0x70
Jan 20 16:23:57 shasta kernel: [  512.232980]  [] ? gs_change+0x13/0x13
Jan 20 16:23:57 shasta kernel: [  512.233778] Code: 2a ff ff ff 5d c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 48 83 ec 20 48 89 5d e0 4c 89 65 e8 4c 89 6d f0 4c 89 75 f8 66 66 66 66 90  46 38 40 48 8b 47 68 48 89 fb 4c 8b a0 f0 02 00 00 75 77 48 
Jan 20 16:23:57 shasta kernel: [  512.234719] RIP  [] zpl_revalidate+0x1d/0xb0 [zfs]
Jan 20 16:23:57 shasta kernel: [  512.235639]  RSP 
Jan 20 16:23:57 shasta kernel: [  512.236494] CR2: 0000000000000038
Jan 20 16:23:57 shasta kernel: [  512.280779] ---[ end trace 30b16bd40d69613c ]---

Jan 20 18:02:24 shasta kernel: [  349.838020] NFSD: Using /var/lib/nfs/v4recovery as the NFSv4 state recovery directory
Jan 20 18:02:24 shasta kernel: [  349.854789] NFSD: starting 90-second grace period
Jan 20 18:02:24 shasta rpc.mountd[4881]: Version 1.2.6 starting
Jan 20 18:02:32 shasta rpc.mountd[4881]: authenticated mount request from 10.50.50.3:993 for /srv/Media (/srv/Media)
Jan 20 18:04:54 shasta kernel: [  499.758773] BUG: unable to handle kernel NULL pointer dereference at 0000000000000038
Jan 20 18:04:54 shasta kernel: [  499.758800] IP: [] zpl_revalidate+0x1d/0xb0 [zfs]
Jan 20 18:04:54 shasta kernel: [  499.758865] PGD 0 
Jan 20 18:04:54 shasta kernel: [  499.758872] Oops: 0000 [#1] SMP 
Jan 20 18:04:54 shasta kernel: [  499.758881] CPU 2 
Jan 20 18:04:54 shasta kernel: [  499.758886] Modules linked in: pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) bnep rfcomm bluetooth parport_pc ppdev lp parport snd_hda_codec_realtek snd_hda_intel snd_hda_codec coretemp snd_hwdep snd_pcm snd_seq_midi snd_rawmidi kvm_intel snd_seq_midi_event kvm snd_seq snd_timer snd_seq_device psmouse microcode joydev snd serio_raw gpio_ich mac_hid i7core_edac lpc_ich edac_core soundcore snd_page_alloc nfsd nfs lockd fscache auth_rpcgss nfs_acl bonding sunrpc raid10 raid456 async_pq async_xor xor async_memcpy async_raid6_recov raid6_pq async_tx raid0 multipath linear zfs(PO) zcommon(PO) znvpair(PO) zavl(PO) zunicode(PO) spl(O) zlib_deflate dm_crypt hid_logitech ff_memless nouveau ttm drm_kms_helper drm firewire_ohci i2c_algo_bit firewire_core video hid_generic raid1 mxm_wmi crc_itu_t wmi usbhid hid sky2 pata_marvell
Jan 20 18:04:54 shasta kernel: [  499.759116] 
Jan 20 18:04:54 shasta kernel: [  499.759120] Pid: 4874, comm: nfsd Tainted: P          IO 3.5.0-22-generic #34-Ubuntu    /EVGA P55 SLI E657
Jan 20 18:04:54 shasta kernel: [  499.759137] RIP: 0010:[]  [] zpl_revalidate+0x1d/0xb0 [zfs]
Jan 20 18:04:54 shasta kernel: [  499.759196] RSP: 0018:ffff880450d33a70  EFLAGS: 00010282
Jan 20 18:04:54 shasta kernel: [  499.759205] RAX: ffffffffa0371740 RBX: ffff88042cf51cc0 RCX: 0000000000000038
Jan 20 18:04:54 shasta kernel: [  499.759215] RDX: ffff8804089b3018 RSI: 0000000000000000 RDI: ffff88042cf51cc0
Jan 20 18:04:54 shasta kernel: [  499.759225] RBP: ffff880450d33a90 R08: 006664702e61684a R09: 0000000000000000
Jan 20 18:04:54 shasta kernel: [  499.759235] R10: ffff88042cf51cc0 R11: 0000000000000002 R12: ffff88042cf169c0
Jan 20 18:04:54 shasta kernel: [  499.759245] R13: ffff880450d33ae0 R14: 0000000000000000 R15: ffff88040fc43e00
Jan 20 18:04:54 shasta kernel: [  499.759255] FS:  0000000000000000(0000) GS:ffff88047fc80000(0000) knlGS:0000000000000000
Jan 20 18:04:54 shasta kernel: [  499.759267] CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Jan 20 18:04:54 shasta kernel: [  499.759275] CR2: 0000000000000038 CR3: 0000000001c0b000 CR4: 00000000000007e0
Jan 20 18:04:54 shasta kernel: [  499.759286] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jan 20 18:04:54 shasta kernel: [  499.759296] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jan 20 18:04:54 shasta kernel: [  499.759306] Process nfsd (pid: 4874, threadinfo ffff880450d32000, task ffff88040258c500)
Jan 20 18:04:54 shasta kernel: [  499.759318] Stack:
Jan 20 18:04:54 shasta kernel: [  499.759322]  ffff88042cf51cc0 ffff88042cf169c0 ffff880450d33ae0 0000000000000000
Jan 20 18:04:54 shasta kernel: [  499.759339]  ffff880450d33ad0 ffffffff8118ca4c ffff880450d33af8 ffff8804089b301f
Jan 20 18:04:54 shasta kernel: [  499.759354]  ffff8804089b301f 0000000000000006 ffff88042cf169c0 ffff88044b552020
Jan 20 18:04:54 shasta kernel: [  499.759370] Call Trace:
Jan 20 18:04:54 shasta kernel: [  499.759385]  [] __lookup_hash+0xac/0x120
Jan 20 18:04:54 shasta kernel: [  499.759396]  [] lookup_one_len+0xd6/0x110
Jan 20 18:04:54 shasta kernel: [  499.759418]  [] encode_entryplus_baggage+0x75/0x180 [nfsd]
Jan 20 18:04:54 shasta kernel: [  499.759440]  [] encode_entry.isra.9+0x313/0x350 [nfsd]
Jan 20 18:04:54 shasta kernel: [  499.759462]  [] ? nfs3svc_encode_entry+0x20/0x20 [nfsd]
Jan 20 18:04:54 shasta kernel: [  499.759482]  [] nfs3svc_encode_entry_plus+0x14/0x20 [nfsd]
Jan 20 18:04:54 shasta kernel: [  499.759501]  [] nfsd_readdir+0x15f/0x240 [nfsd]
Jan 20 18:04:54 shasta kernel: [  499.759521]  [] nfsd3_proc_readdirplus+0xb5/0x1d0 [nfsd]
Jan 20 18:04:54 shasta kernel: [  499.759539]  [] nfsd_dispatch+0xbe/0x1c0 [nfsd]
Jan 20 18:04:54 shasta kernel: [  499.759567]  [] svc_process_common+0x30b/0x610 [sunrpc]
Jan 20 18:04:54 shasta kernel: [  499.759593]  [] svc_process+0x106/0x160 [sunrpc]
Jan 20 18:04:54 shasta kernel: [  499.759609]  [] nfsd+0xb5/0x1a0 [nfsd]
Jan 20 18:04:54 shasta kernel: [  499.759624]  [] ? nfsd_get_default_max_blksize+0x60/0x60 [nfsd]
Jan 20 18:04:54 shasta kernel: [  499.759637]  [] kthread+0x93/0xa0
Jan 20 18:04:54 shasta kernel: [  499.760461]  [] kernel_thread_helper+0x4/0x10
Jan 20 18:04:54 shasta kernel: [  499.761285]  [] ? kthread_freezable_should_stop+0x70/0x70
Jan 20 18:04:54 shasta kernel: [  499.762270]  [] ? gs_change+0x13/0x13
Jan 20 18:04:54 shasta kernel: [  499.763083] Code: 2a ff ff ff 5d c3 0f 1f 84 00 00 00 00 00 55 48 89 e5 48 83 ec 20 48 89 5d e0 4c 89 65 e8 4c 89 6d f0 4c 89 75 f8 66 66 66 66 90  46 38 40 48 8b 47 68 48 89 fb 4c 8b a0 f0 02 00 00 75 77 48 
Jan 20 18:04:54 shasta kernel: [  499.764045] RIP  [] zpl_revalidate+0x1d/0xb0 [zfs]
Jan 20 18:04:54 shasta kernel: [  499.764978]  RSP 
Jan 20 18:04:54 shasta kernel: [  499.765856] CR2: 0000000000000038
Jan 20 18:04:54 shasta kernel: [  499.808902] ---[ end trace 2bfd4c5a57d655e9 ]---

mk01 · 2013-01-21T05:29:52Z

Jan 21 02:56:55 media kernel: [ 298.469352] BUG: unable to handle kernel NULL pointer dereference at 0000000000000038
Jan 21 02:56:55 media kernel: [ 298.469467] IP: [] zpl_revalidate+0x1d/0xa0 [zfs]
Jan 21 02:56:55 media kernel: [ 298.469639] PGD 0
Jan 21 02:56:55 media kernel: [ 298.469707] Oops: 0000 [#1] SMP
Jan 21 02:56:55 media kernel: [ 298.469807] CPU 1
Jan 21 02:56:55 media kernel: [ 298.469842] Modules linked in: rpcsec_gss_krb5 zram(C) bnep rfcomm parport_pc bluetooth ppdev lp parport binfmt_misc nfsd snd_hda_codec_realtek snd_hda_codec_hdmi psmouse snd_hda_intel snd_hda_codec snd_hw
dep pwc serio_raw videobuf2_core videodev v4l2_compat_ioctl32 videobuf2_vmalloc k10temp videobuf2_memops snd_pcm i2c_piix4 snd_seq_midi snd_rawmidi fglrx(P) joydev snd_seq_midi_event snd_seq snd_timer snd_seq_device snd mac_hid soundcore
snd_page_alloc w83627ehf hwmon_vid nfs lockd fscache auth_rpcgss nfs_acl sunrpc zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl(O) zlib_deflate raid10 raid456 async_pq async_xor xor async_memcpy async_raid6_recov usbhid hid r8169 rai
d6_pq async_tx raid1 raid0 multipath linear
Jan 21 02:56:55 media kernel: [ 298.472200]
Jan 21 02:56:55 media kernel: [ 298.472238] Pid: 2099, comm: nfsd Tainted: P C O 3.2.0-35-generic #55-Ubuntu To Be Filled By O.E.M. To Be Filled By O.E.M./A75M-ITX
Jan 21 02:56:55 media kernel: [ 298.472385] RIP: 0010:[] [] zpl_revalidate+0x1d/0xa0 [zfs]
Jan 21 02:56:55 media kernel: [ 298.472534] RSP: 0018:ffff8803e3c71c10 EFLAGS: 00010282
Jan 21 02:56:55 media kernel: [ 298.472579] RAX: ffffffffa0232740 RBX: ffff880402214000 RCX: 0000000000000004
Jan 21 02:56:55 media kernel: [ 298.472626] RDX: ffff8803e4a5a060 RSI: 0000000000000000 RDI: ffff880402214000
Jan 21 02:56:55 media kernel: [ 298.472673] RBP: ffff8803e3c71c30 R08: 0000000000000004 R09: ffff880402214038
Jan 21 02:56:55 media kernel: [ 298.472719] R10: ffff880402214000 R11: ffff8803f28ff1a8 R12: ffff8804022aff00
Jan 21 02:56:55 media kernel: [ 298.472766] R13: ffff8803e3c71c90 R14: 0000000000000000 R15: ffff8803e4370000
Jan 21 02:56:55 media kernel: [ 298.472814] FS: 00007fe646e4d740(0000) GS:ffff88041dc80000(0000) knlGS:0000000000000000
Jan 21 02:56:55 media kernel: [ 298.472866] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b
Jan 21 02:56:55 media kernel: [ 298.472910] CR2: 0000000000000038 CR3: 0000000001c05000 CR4: 00000000000006e0
Jan 21 02:56:55 media kernel: [ 298.472957] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
Jan 21 02:56:55 media kernel: [ 298.473004] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
Jan 21 02:56:55 media kernel: [ 298.473051] Process nfsd (pid: 2099, threadinfo ffff8803e3c70000, task ffff8803eed7ae00)
Jan 21 02:56:55 media kernel: [ 298.473097] Stack:
Jan 21 02:56:55 media kernel: [ 298.473131] ffff880402214000 ffff8804022aff00 ffff8803e3c71c90 0000000000000000
Jan 21 02:56:55 media kernel: [ 298.473290] ffff8803e3c71c70 ffffffff81184b52 ffff8803e3c71c70 ffffffff81184daa
Jan 21 02:56:55 media kernel: [ 298.473305] ffff8804022aff00 ffff8803e4a5a064 ffff8803e4a5a060 ffff8804022aff00
Jan 21 02:56:55 media kernel: [ 298.473305] Call Trace:
Jan 21 02:56:55 media kernel: [ 298.473305] [] __lookup_hash.part.28+0x92/0xe0
Jan 21 02:56:55 media kernel: [ 298.473305] [] ? inode_permission+0x4a/0x110
Jan 21 02:56:55 media kernel: [ 298.473305] [] lookup_one_len+0xee/0x120
Jan 21 02:56:55 media kernel: [ 298.473305] [] ? nfsd_permission+0x9f/0x160 [nfsd]
Jan 21 02:56:55 media kernel: [ 298.473305] [] nfsd_lookup_dentry+0x113/0x2f0 [nfsd]
Jan 21 02:56:55 media kernel: [ 298.473305] [] nfsd_lookup+0x79/0x110 [nfsd]
Jan 21 02:56:55 media kernel: [ 298.473305] [] nfsd4_lookup+0x1a/0x20 [nfsd]
Jan 21 02:56:55 media kernel: [ 298.473305] [] nfsd4_proc_compound+0x518/0x6d0 [nfsd]
Jan 21 02:56:55 media kernel: [ 298.473305] [] nfsd_dispatch+0xeb/0x230 [nfsd]
Jan 21 02:56:55 media kernel: [ 298.473305] [] svc_process_common+0x345/0x690 [sunrpc]
Jan 21 02:56:55 media kernel: [ 298.473305] [] ? try_to_wake_up+0x200/0x200
Jan 21 02:56:55 media kernel: [ 298.473305] [] svc_process+0x102/0x150 [sunrpc]
Jan 21 02:56:55 media kernel: [ 298.473305] [] nfsd+0xbd/0x160 [nfsd]
Jan 21 02:56:55 media kernel: [ 298.473305] [] ? nfsd_startup+0xf0/0xf0 [nfsd]
Jan 21 02:56:55 media kernel: [ 298.473305] [] kthread+0x8c/0xa0
Jan 21 02:56:55 media kernel: [ 298.473305] [] kernel_thread_helper+0x4/0x10
Jan 21 02:56:55 media kernel: [ 298.473305] [] ? flush_kthread_worker+0xa0/0xa0
Jan 21 02:56:55 media kernel: [ 298.473305] [] ? gs_change+0x13/0x13
Jan 21 02:56:55 media kernel: [ 298.473305] Code: 2a ff ff ff 5d c3 90 90 90 90 90 90 90 90 55 48 89 e5 48 83 ec 20 48 89 5d e0 4c 89 65 e8 4c 89 6d f0 4c 89 75 f8 66 66 66 66 90 46 38 40 48 8b 47 68 48 89 fb 4c 8b b0 b0 02 00 00 b8
f6 ff
Jan 21 02:56:55 media kernel: [ 298.473305] RIP [] zpl_revalidate+0x1d/0xa0 [zfs]
Jan 21 02:56:55 media kernel: [ 298.473305] RSP
Jan 21 02:56:55 media kernel: [ 298.473305] CR2: 0000000000000038
Jan 21 02:56:55 media kernel: [ 298.477713] ---[ end trace a30ada5bcf6c3256 ]---

mk01 · 2013-01-21T05:41:53Z

I was experiencing this with latest daily after upgrade yesterday. .0.93-rc13 0.92 was ok.

behlendorf · 2013-01-22T17:03:29Z

This original issue was quite stale. The new failure your hitting is caused by #1226 which we'll get sorted out shortly. As for this issue I'm just closing it out as out of date.

The below excerpt of a backtrace is from a ztest failure when running ZoL's ztest. /openzfs#453 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#454 0x00007f03c806106e in vdev_queue_io (zio=zio@entry=0x7f0350003de0) at ../../module/zfs/vdev_queue.c:747 /openzfs#455 0x00007f03c80818c1 in zio_vdev_io_start (zio=0x7f0350003de0) at ../../module/zfs/zio.c:2659 /openzfs#456 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003de0) at ../../module/zfs/zio.c:1399 /openzfs#457 zio_nowait (zio=0x7f0350003de0) at ../../module/zfs/zio.c:1456 /openzfs#458 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350003a10) at ../../module/zfs/vdev_mirror.c:374 /openzfs#459 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003a10) at ../../module/zfs/zio.c:1399 /openzfs#460 zio_nowait (zio=0x7f0350003a10) at ../../module/zfs/zio.c:1456 /openzfs#461 0x00007f03c806464c in vdev_raidz_io_start (zio=0x7f0350003380) at ../../module/zfs/vdev_raidz.c:1607 /openzfs#462 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003380) at ../../module/zfs/zio.c:1399 /openzfs#463 zio_nowait (zio=0x7f0350003380) at ../../module/zfs/zio.c:1456 /openzfs#464 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350002fb0) at ../../module/zfs/vdev_mirror.c:374 /openzfs#465 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002fb0) at ../../module/zfs/zio.c:1399 /openzfs#466 zio_nowait (zio=0x7f0350002fb0) at ../../module/zfs/zio.c:1456 /openzfs#467 0x00007f03c805ed43 in vdev_mirror_io_done (zio=0x7f033957ebf0) at ../../module/zfs/vdev_mirror.c:499 /openzfs#468 0x00007f03c807a0c0 in zio_vdev_io_done (zio=0x7f033957ebf0) at ../../module/zfs/zio.c:2707 /openzfs#469 0x00007f03c808285b in __zio_execute (zio=0x7f033957ebf0) at ../../module/zfs/zio.c:1399 /openzfs#470 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f0390001330, pio=0x7f033957ebf0) at ../../module/zfs/zio.c:547 /openzfs#471 zio_done (zio=0x7f0390001330) at ../../module/zfs/zio.c:3278 /openzfs#472 0x00007f03c808285b in __zio_execute (zio=0x7f0390001330) at ../../module/zfs/zio.c:1399 /openzfs#473 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4013a00, pio=0x7f0390001330) at ../../module/zfs/zio.c:547 /openzfs#474 zio_done (zio=0x7f03b4013a00) at ../../module/zfs/zio.c:3278 /openzfs#475 0x00007f03c808285b in __zio_execute (zio=0x7f03b4013a00) at ../../module/zfs/zio.c:1399 /openzfs#476 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4014210, pio=0x7f03b4013a00) at ../../module/zfs/zio.c:547 /openzfs#477 zio_done (zio=0x7f03b4014210) at ../../module/zfs/zio.c:3278 /openzfs#478 0x00007f03c808285b in __zio_execute (zio=0x7f03b4014210) at ../../module/zfs/zio.c:1399 /openzfs#479 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4014620, pio=0x7f03b4014210) at ../../module/zfs/zio.c:547 /openzfs#480 zio_done (zio=0x7f03b4014620) at ../../module/zfs/zio.c:3278 /openzfs#481 0x00007f03c807a6d3 in __zio_execute (zio=0x7f03b4014620) at ../../module/zfs/zio.c:1399 /openzfs#482 zio_execute (zio=zio@entry=0x7f03b4014620) at ../../module/zfs/zio.c:1337 /openzfs#483 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#484 0x00007f03c806106e in vdev_queue_io (zio=zio@entry=0x7f0350002be0) at ../../module/zfs/vdev_queue.c:747 /openzfs#485 0x00007f03c80818c1 in zio_vdev_io_start (zio=0x7f0350002be0) at ../../module/zfs/zio.c:2659 /openzfs#486 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002be0) at ../../module/zfs/zio.c:1399 /openzfs#487 zio_nowait (zio=0x7f0350002be0) at ../../module/zfs/zio.c:1456 /openzfs#488 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350002810) at ../../module/zfs/vdev_mirror.c:374 /openzfs#489 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002810) at ../../module/zfs/zio.c:1399 /openzfs#490 zio_nowait (zio=0x7f0350002810) at ../../module/zfs/zio.c:1456 /openzfs#491 0x00007f03c8064593 in vdev_raidz_io_start (zio=0x7f0350001270) at ../../module/zfs/vdev_raidz.c:1591 /openzfs#492 0x00007f03c807f243 in __zio_execute (zio=0x7f0350001270) at ../../module/zfs/zio.c:1399 /openzfs#493 zio_nowait (zio=0x7f0350001270) at ../../module/zfs/zio.c:1456 /openzfs#494 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350001e60) at ../../module/zfs/vdev_mirror.c:374 /openzfs#495 0x00007f03c807f243 in __zio_execute (zio=0x7f0350001e60) at ../../module/zfs/zio.c:1399 /openzfs#496 zio_nowait (zio=0x7f0350001e60) at ../../module/zfs/zio.c:1456 /openzfs#497 0x00007f03c805ed43 in vdev_mirror_io_done (zio=0x7f033a0c39c0) at ../../module/zfs/vdev_mirror.c:499 /openzfs#498 0x00007f03c807a0c0 in zio_vdev_io_done (zio=0x7f033a0c39c0) at ../../module/zfs/zio.c:2707 /openzfs#499 0x00007f03c808285b in __zio_execute (zio=0x7f033a0c39c0) at ../../module/zfs/zio.c:1399 /openzfs#500 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03a8003c00, pio=0x7f033a0c39c0) at ../../module/zfs/zio.c:547 /openzfs#501 zio_done (zio=0x7f03a8003c00) at ../../module/zfs/zio.c:3278 /openzfs#502 0x00007f03c808285b in __zio_execute (zio=0x7f03a8003c00) at ../../module/zfs/zio.c:1399 /openzfs#503 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800c400, pio=0x7f03a8003c00) at ../../module/zfs/zio.c:547 /openzfs#504 zio_done (zio=0x7f038800c400) at ../../module/zfs/zio.c:3278 /openzfs#505 0x00007f03c808285b in __zio_execute (zio=0x7f038800c400) at ../../module/zfs/zio.c:1399 /openzfs#506 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800da00, pio=0x7f038800c400) at ../../module/zfs/zio.c:547 /openzfs#507 zio_done (zio=0x7f038800da00) at ../../module/zfs/zio.c:3278 /openzfs#508 0x00007f03c808285b in __zio_execute (zio=0x7f038800da00) at ../../module/zfs/zio.c:1399 /openzfs#509 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800fd80, pio=0x7f038800da00) at ../../module/zfs/zio.c:547 /openzfs#510 zio_done (zio=0x7f038800fd80) at ../../module/zfs/zio.c:3278 /openzfs#511 0x00007f03c807a6d3 in __zio_execute (zio=0x7f038800fd80) at ../../module/zfs/zio.c:1399 /openzfs#512 zio_execute (zio=zio@entry=0x7f038800fd80) at ../../module/zfs/zio.c:1337 /openzfs#513 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#514 0x00007f03c806119d in vdev_queue_io_done (zio=zio@entry=0x7f03a0010950) at ../../module/zfs/vdev_queue.c:775 /openzfs#515 0x00007f03c807a0e8 in zio_vdev_io_done (zio=0x7f03a0010950) at ../../module/zfs/zio.c:2686 /openzfs#516 0x00007f03c807a6d3 in __zio_execute (zio=0x7f03a0010950) at ../../module/zfs/zio.c:1399 /openzfs#517 zio_execute (zio=0x7f03a0010950) at ../../module/zfs/zio.c:1337 /openzfs#518 0x00007f03c7fcd0c4 in taskq_thread (arg=0x966d50) at ../../lib/libzpool/taskq.c:215 /openzfs#519 0x00007f03c7fc7937 in zk_thread_helper (arg=0x967e90) at ../../lib/libzpool/kernel.c:135 /openzfs#520 0x00007f03c78890a3 in start_thread (arg=0x7f03c2703700) at pthread_create.c:309 /openzfs#521 0x00007f03c75c50fd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111 The backtrace was an infinite loop of `vdev_queue_io_to_issue()` invoking `zio_execute()` until it overran the stack. vdev_queue_io_to_issue() will ony invoke `zio_execute()` on raidz vdevs when aggregation I/Os are generated to improve aggregation continuity. These I/Os do not trigger any writes. However, it appears that they can be generated in such a way that they recurse infinitely upon return to `vdev_queue_io_to_issue()`. As a consequence, we see the number of parents by 1 each time the recursion returns to `vdev_raidz_io_start()`. Signed-off-by: Richard Yao <[email protected]>

The below excerpt of a backtrace is from a ztest failure when running ZoL's ztest. /openzfs#453 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#454 0x00007f03c806106e in vdev_queue_io (zio=zio@entry=0x7f0350003de0) at ../../module/zfs/vdev_queue.c:747 /openzfs#455 0x00007f03c80818c1 in zio_vdev_io_start (zio=0x7f0350003de0) at ../../module/zfs/zio.c:2659 /openzfs#456 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003de0) at ../../module/zfs/zio.c:1399 /openzfs#457 zio_nowait (zio=0x7f0350003de0) at ../../module/zfs/zio.c:1456 /openzfs#458 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350003a10) at ../../module/zfs/vdev_mirror.c:374 /openzfs#459 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003a10) at ../../module/zfs/zio.c:1399 /openzfs#460 zio_nowait (zio=0x7f0350003a10) at ../../module/zfs/zio.c:1456 /openzfs#461 0x00007f03c806464c in vdev_raidz_io_start (zio=0x7f0350003380) at ../../module/zfs/vdev_raidz.c:1607 /openzfs#462 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003380) at ../../module/zfs/zio.c:1399 /openzfs#463 zio_nowait (zio=0x7f0350003380) at ../../module/zfs/zio.c:1456 /openzfs#464 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350002fb0) at ../../module/zfs/vdev_mirror.c:374 /openzfs#465 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002fb0) at ../../module/zfs/zio.c:1399 /openzfs#466 zio_nowait (zio=0x7f0350002fb0) at ../../module/zfs/zio.c:1456 /openzfs#467 0x00007f03c805ed43 in vdev_mirror_io_done (zio=0x7f033957ebf0) at ../../module/zfs/vdev_mirror.c:499 /openzfs#468 0x00007f03c807a0c0 in zio_vdev_io_done (zio=0x7f033957ebf0) at ../../module/zfs/zio.c:2707 /openzfs#469 0x00007f03c808285b in __zio_execute (zio=0x7f033957ebf0) at ../../module/zfs/zio.c:1399 /openzfs#470 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f0390001330, pio=0x7f033957ebf0) at ../../module/zfs/zio.c:547 /openzfs#471 zio_done (zio=0x7f0390001330) at ../../module/zfs/zio.c:3278 /openzfs#472 0x00007f03c808285b in __zio_execute (zio=0x7f0390001330) at ../../module/zfs/zio.c:1399 /openzfs#473 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4013a00, pio=0x7f0390001330) at ../../module/zfs/zio.c:547 /openzfs#474 zio_done (zio=0x7f03b4013a00) at ../../module/zfs/zio.c:3278 /openzfs#475 0x00007f03c808285b in __zio_execute (zio=0x7f03b4013a00) at ../../module/zfs/zio.c:1399 /openzfs#476 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4014210, pio=0x7f03b4013a00) at ../../module/zfs/zio.c:547 /openzfs#477 zio_done (zio=0x7f03b4014210) at ../../module/zfs/zio.c:3278 /openzfs#478 0x00007f03c808285b in __zio_execute (zio=0x7f03b4014210) at ../../module/zfs/zio.c:1399 /openzfs#479 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4014620, pio=0x7f03b4014210) at ../../module/zfs/zio.c:547 /openzfs#480 zio_done (zio=0x7f03b4014620) at ../../module/zfs/zio.c:3278 /openzfs#481 0x00007f03c807a6d3 in __zio_execute (zio=0x7f03b4014620) at ../../module/zfs/zio.c:1399 /openzfs#482 zio_execute (zio=zio@entry=0x7f03b4014620) at ../../module/zfs/zio.c:1337 /openzfs#483 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#484 0x00007f03c806106e in vdev_queue_io (zio=zio@entry=0x7f0350002be0) at ../../module/zfs/vdev_queue.c:747 /openzfs#485 0x00007f03c80818c1 in zio_vdev_io_start (zio=0x7f0350002be0) at ../../module/zfs/zio.c:2659 /openzfs#486 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002be0) at ../../module/zfs/zio.c:1399 /openzfs#487 zio_nowait (zio=0x7f0350002be0) at ../../module/zfs/zio.c:1456 /openzfs#488 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350002810) at ../../module/zfs/vdev_mirror.c:374 /openzfs#489 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002810) at ../../module/zfs/zio.c:1399 /openzfs#490 zio_nowait (zio=0x7f0350002810) at ../../module/zfs/zio.c:1456 /openzfs#491 0x00007f03c8064593 in vdev_raidz_io_start (zio=0x7f0350001270) at ../../module/zfs/vdev_raidz.c:1591 /openzfs#492 0x00007f03c807f243 in __zio_execute (zio=0x7f0350001270) at ../../module/zfs/zio.c:1399 /openzfs#493 zio_nowait (zio=0x7f0350001270) at ../../module/zfs/zio.c:1456 /openzfs#494 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350001e60) at ../../module/zfs/vdev_mirror.c:374 /openzfs#495 0x00007f03c807f243 in __zio_execute (zio=0x7f0350001e60) at ../../module/zfs/zio.c:1399 /openzfs#496 zio_nowait (zio=0x7f0350001e60) at ../../module/zfs/zio.c:1456 /openzfs#497 0x00007f03c805ed43 in vdev_mirror_io_done (zio=0x7f033a0c39c0) at ../../module/zfs/vdev_mirror.c:499 /openzfs#498 0x00007f03c807a0c0 in zio_vdev_io_done (zio=0x7f033a0c39c0) at ../../module/zfs/zio.c:2707 /openzfs#499 0x00007f03c808285b in __zio_execute (zio=0x7f033a0c39c0) at ../../module/zfs/zio.c:1399 /openzfs#500 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03a8003c00, pio=0x7f033a0c39c0) at ../../module/zfs/zio.c:547 /openzfs#501 zio_done (zio=0x7f03a8003c00) at ../../module/zfs/zio.c:3278 /openzfs#502 0x00007f03c808285b in __zio_execute (zio=0x7f03a8003c00) at ../../module/zfs/zio.c:1399 /openzfs#503 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800c400, pio=0x7f03a8003c00) at ../../module/zfs/zio.c:547 /openzfs#504 zio_done (zio=0x7f038800c400) at ../../module/zfs/zio.c:3278 /openzfs#505 0x00007f03c808285b in __zio_execute (zio=0x7f038800c400) at ../../module/zfs/zio.c:1399 /openzfs#506 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800da00, pio=0x7f038800c400) at ../../module/zfs/zio.c:547 /openzfs#507 zio_done (zio=0x7f038800da00) at ../../module/zfs/zio.c:3278 /openzfs#508 0x00007f03c808285b in __zio_execute (zio=0x7f038800da00) at ../../module/zfs/zio.c:1399 /openzfs#509 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800fd80, pio=0x7f038800da00) at ../../module/zfs/zio.c:547 /openzfs#510 zio_done (zio=0x7f038800fd80) at ../../module/zfs/zio.c:3278 /openzfs#511 0x00007f03c807a6d3 in __zio_execute (zio=0x7f038800fd80) at ../../module/zfs/zio.c:1399 /openzfs#512 zio_execute (zio=zio@entry=0x7f038800fd80) at ../../module/zfs/zio.c:1337 /openzfs#513 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#514 0x00007f03c806119d in vdev_queue_io_done (zio=zio@entry=0x7f03a0010950) at ../../module/zfs/vdev_queue.c:775 /openzfs#515 0x00007f03c807a0e8 in zio_vdev_io_done (zio=0x7f03a0010950) at ../../module/zfs/zio.c:2686 /openzfs#516 0x00007f03c807a6d3 in __zio_execute (zio=0x7f03a0010950) at ../../module/zfs/zio.c:1399 /openzfs#517 zio_execute (zio=0x7f03a0010950) at ../../module/zfs/zio.c:1337 /openzfs#518 0x00007f03c7fcd0c4 in taskq_thread (arg=0x966d50) at ../../lib/libzpool/taskq.c:215 /openzfs#519 0x00007f03c7fc7937 in zk_thread_helper (arg=0x967e90) at ../../lib/libzpool/kernel.c:135 /openzfs#520 0x00007f03c78890a3 in start_thread (arg=0x7f03c2703700) at pthread_create.c:309 /openzfs#521 0x00007f03c75c50fd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111 The backtrace was an infinite loop of `vdev_queue_io_to_issue()` invoking `zio_execute()` until it overran the stack. vdev_queue_io_to_issue() will ony invoke `zio_execute()` on raidz vdevs when aggregation I/Os are generated to improve aggregation continuity. These I/Os do not trigger any writes. However, it appears that they can be generated in such a way that they recurse infinitely upon return to `vdev_queue_io_to_issue()`. Signed-off-by: Richard Yao <[email protected]>

The below excerpt of a backtrace is from a ztest failure when running ZoL's ztest: /openzfs#453 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#454 0x00007f03c806106e in vdev_queue_io (zio=zio@entry=0x7f0350003de0) at ../../module/zfs/vdev_queue.c:747 /openzfs#455 0x00007f03c80818c1 in zio_vdev_io_start (zio=0x7f0350003de0) at ../../module/zfs/zio.c:2659 /openzfs#456 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003de0) at ../../module/zfs/zio.c:1399 /openzfs#457 zio_nowait (zio=0x7f0350003de0) at ../../module/zfs/zio.c:1456 /openzfs#458 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350003a10) at ../../module/zfs/vdev_mirror.c:374 /openzfs#459 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003a10) at ../../module/zfs/zio.c:1399 /openzfs#460 zio_nowait (zio=0x7f0350003a10) at ../../module/zfs/zio.c:1456 /openzfs#461 0x00007f03c806464c in vdev_raidz_io_start (zio=0x7f0350003380) at ../../module/zfs/vdev_raidz.c:1607 /openzfs#462 0x00007f03c807f243 in __zio_execute (zio=0x7f0350003380) at ../../module/zfs/zio.c:1399 /openzfs#463 zio_nowait (zio=0x7f0350003380) at ../../module/zfs/zio.c:1456 /openzfs#464 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350002fb0) at ../../module/zfs/vdev_mirror.c:374 /openzfs#465 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002fb0) at ../../module/zfs/zio.c:1399 /openzfs#466 zio_nowait (zio=0x7f0350002fb0) at ../../module/zfs/zio.c:1456 /openzfs#467 0x00007f03c805ed43 in vdev_mirror_io_done (zio=0x7f033957ebf0) at ../../module/zfs/vdev_mirror.c:499 /openzfs#468 0x00007f03c807a0c0 in zio_vdev_io_done (zio=0x7f033957ebf0) at ../../module/zfs/zio.c:2707 /openzfs#469 0x00007f03c808285b in __zio_execute (zio=0x7f033957ebf0) at ../../module/zfs/zio.c:1399 /openzfs#470 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f0390001330, pio=0x7f033957ebf0) at ../../module/zfs/zio.c:547 /openzfs#471 zio_done (zio=0x7f0390001330) at ../../module/zfs/zio.c:3278 /openzfs#472 0x00007f03c808285b in __zio_execute (zio=0x7f0390001330) at ../../module/zfs/zio.c:1399 /openzfs#473 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4013a00, pio=0x7f0390001330) at ../../module/zfs/zio.c:547 /openzfs#474 zio_done (zio=0x7f03b4013a00) at ../../module/zfs/zio.c:3278 /openzfs#475 0x00007f03c808285b in __zio_execute (zio=0x7f03b4013a00) at ../../module/zfs/zio.c:1399 /openzfs#476 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4014210, pio=0x7f03b4013a00) at ../../module/zfs/zio.c:547 /openzfs#477 zio_done (zio=0x7f03b4014210) at ../../module/zfs/zio.c:3278 /openzfs#478 0x00007f03c808285b in __zio_execute (zio=0x7f03b4014210) at ../../module/zfs/zio.c:1399 /openzfs#479 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03b4014620, pio=0x7f03b4014210) at ../../module/zfs/zio.c:547 /openzfs#480 zio_done (zio=0x7f03b4014620) at ../../module/zfs/zio.c:3278 /openzfs#481 0x00007f03c807a6d3 in __zio_execute (zio=0x7f03b4014620) at ../../module/zfs/zio.c:1399 /openzfs#482 zio_execute (zio=zio@entry=0x7f03b4014620) at ../../module/zfs/zio.c:1337 /openzfs#483 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#484 0x00007f03c806106e in vdev_queue_io (zio=zio@entry=0x7f0350002be0) at ../../module/zfs/vdev_queue.c:747 /openzfs#485 0x00007f03c80818c1 in zio_vdev_io_start (zio=0x7f0350002be0) at ../../module/zfs/zio.c:2659 /openzfs#486 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002be0) at ../../module/zfs/zio.c:1399 /openzfs#487 zio_nowait (zio=0x7f0350002be0) at ../../module/zfs/zio.c:1456 /openzfs#488 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350002810) at ../../module/zfs/vdev_mirror.c:374 /openzfs#489 0x00007f03c807f243 in __zio_execute (zio=0x7f0350002810) at ../../module/zfs/zio.c:1399 /openzfs#490 zio_nowait (zio=0x7f0350002810) at ../../module/zfs/zio.c:1456 /openzfs#491 0x00007f03c8064593 in vdev_raidz_io_start (zio=0x7f0350001270) at ../../module/zfs/vdev_raidz.c:1591 /openzfs#492 0x00007f03c807f243 in __zio_execute (zio=0x7f0350001270) at ../../module/zfs/zio.c:1399 /openzfs#493 zio_nowait (zio=0x7f0350001270) at ../../module/zfs/zio.c:1456 /openzfs#494 0x00007f03c805f71b in vdev_mirror_io_start (zio=0x7f0350001e60) at ../../module/zfs/vdev_mirror.c:374 /openzfs#495 0x00007f03c807f243 in __zio_execute (zio=0x7f0350001e60) at ../../module/zfs/zio.c:1399 /openzfs#496 zio_nowait (zio=0x7f0350001e60) at ../../module/zfs/zio.c:1456 /openzfs#497 0x00007f03c805ed43 in vdev_mirror_io_done (zio=0x7f033a0c39c0) at ../../module/zfs/vdev_mirror.c:499 /openzfs#498 0x00007f03c807a0c0 in zio_vdev_io_done (zio=0x7f033a0c39c0) at ../../module/zfs/zio.c:2707 /openzfs#499 0x00007f03c808285b in __zio_execute (zio=0x7f033a0c39c0) at ../../module/zfs/zio.c:1399 /openzfs#500 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f03a8003c00, pio=0x7f033a0c39c0) at ../../module/zfs/zio.c:547 /openzfs#501 zio_done (zio=0x7f03a8003c00) at ../../module/zfs/zio.c:3278 /openzfs#502 0x00007f03c808285b in __zio_execute (zio=0x7f03a8003c00) at ../../module/zfs/zio.c:1399 /openzfs#503 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800c400, pio=0x7f03a8003c00) at ../../module/zfs/zio.c:547 /openzfs#504 zio_done (zio=0x7f038800c400) at ../../module/zfs/zio.c:3278 /openzfs#505 0x00007f03c808285b in __zio_execute (zio=0x7f038800c400) at ../../module/zfs/zio.c:1399 /openzfs#506 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800da00, pio=0x7f038800c400) at ../../module/zfs/zio.c:547 /openzfs#507 zio_done (zio=0x7f038800da00) at ../../module/zfs/zio.c:3278 /openzfs#508 0x00007f03c808285b in __zio_execute (zio=0x7f038800da00) at ../../module/zfs/zio.c:1399 /openzfs#509 zio_notify_parent (wait=ZIO_WAIT_DONE, zio=0x7f038800fd80, pio=0x7f038800da00) at ../../module/zfs/zio.c:547 /openzfs#510 zio_done (zio=0x7f038800fd80) at ../../module/zfs/zio.c:3278 /openzfs#511 0x00007f03c807a6d3 in __zio_execute (zio=0x7f038800fd80) at ../../module/zfs/zio.c:1399 /openzfs#512 zio_execute (zio=zio@entry=0x7f038800fd80) at ../../module/zfs/zio.c:1337 /openzfs#513 0x00007f03c8060b35 in vdev_queue_io_to_issue (vq=vq@entry=0x99f8a8) at ../../module/zfs/vdev_queue.c:706 /openzfs#514 0x00007f03c806119d in vdev_queue_io_done (zio=zio@entry=0x7f03a0010950) at ../../module/zfs/vdev_queue.c:775 /openzfs#515 0x00007f03c807a0e8 in zio_vdev_io_done (zio=0x7f03a0010950) at ../../module/zfs/zio.c:2686 /openzfs#516 0x00007f03c807a6d3 in __zio_execute (zio=0x7f03a0010950) at ../../module/zfs/zio.c:1399 /openzfs#517 zio_execute (zio=0x7f03a0010950) at ../../module/zfs/zio.c:1337 /openzfs#518 0x00007f03c7fcd0c4 in taskq_thread (arg=0x966d50) at ../../lib/libzpool/taskq.c:215 /openzfs#519 0x00007f03c7fc7937 in zk_thread_helper (arg=0x967e90) at ../../lib/libzpool/kernel.c:135 /openzfs#520 0x00007f03c78890a3 in start_thread (arg=0x7f03c2703700) at pthread_create.c:309 /openzfs#521 0x00007f03c75c50fd in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:111 This occurred when ztest was simulating a scrub under heavy I/O load. Under those circumstances, it was possible for a mix of noop I/Os for aggregation continuity and the I/O elevator to generate arbitrarily deep recursion. This patch modifies ZFS to propapage a recursion counter inside the zio_t objects such that IOs will be redispatched upon reaching a given recursion depth. We can detect long call chains and dispatch to another ZIO taskq. We cut in-line when we do this to minimize the potential for taskq exhaustion that can prevent a zio from notifying its parent. Signed-off-by: Richard Yao <[email protected]>

Commit f752b46 added the cv_wait_interruptible() function to allow condition variables to be woken by signals. This function and its timed wait counterpart should have been named cv_wait_sig() to match the illumos interface which provides the same functionality. This patch renames the symbol but leaves a #define compatibility wrapper in place until the ZFS code can be moved to the correct name. This patch also makes a small number of cosmetic changes to make the condvar source and header cstyle clean. Signed-off-by: Brian Behlendorf <[email protected]> Closes openzfs#456

When `zfs send` has to retrieve the data from the object store (as opposed to zettacache), we can benefit from a larger prefetch queue depth, similar to what we see for predictive prefetching. This is because we need a high GetObject queue depth (dozens of requests, covering dozends of MB's of data) to get good throughput from S3. This commit increases the zfs send prefetching to 64MB (from 16MB), and clarifies the comment around it (there's really no downside to increasing it aside from RAM usage, since this is not using ARC prefetching any more).

behlendorf closed this as completed Nov 21, 2011

behlendorf reopened this Dec 1, 2011

behlendorf closed this as completed Jan 22, 2013

ryao mentioned this issue Oct 9, 2014

vdev_raidz_io_start: Ignore empty writes #2778

Closed

ryao mentioned this issue Oct 10, 2014

Redispatch ZIOs in deep call graphs #2786

Closed

behlendorf modified the milestone: 0.6.5 Nov 8, 2014

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

nfs_lookup_revalidate() NULL deref #456

nfs_lookup_revalidate() NULL deref #456

behlendorf commented Nov 21, 2011

chrisrd commented Nov 21, 2011

behlendorf commented Nov 21, 2011

chrisrd commented Dec 1, 2011

behlendorf commented Dec 1, 2011

chrisrd commented Dec 1, 2011

behlendorf commented Sep 18, 2012

Hadron2 commented Jan 20, 2013

mk01 commented Jan 21, 2013

mk01 commented Jan 21, 2013

behlendorf commented Jan 22, 2013

nfs_lookup_revalidate() NULL deref #456

nfs_lookup_revalidate() NULL deref #456

Comments

behlendorf commented Nov 21, 2011

chrisrd commented Nov 21, 2011

behlendorf commented Nov 21, 2011

chrisrd commented Dec 1, 2011

behlendorf commented Dec 1, 2011

chrisrd commented Dec 1, 2011

behlendorf commented Sep 18, 2012

Hadron2 commented Jan 20, 2013

mk01 commented Jan 21, 2013

mk01 commented Jan 21, 2013

behlendorf commented Jan 22, 2013