Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

NULL pointer dereference in ddt_prefetch from zfs_sa_set_xattr #513

Closed
chrisrd opened this issue Jan 4, 2012 · 10 comments
Closed

NULL pointer dereference in ddt_prefetch from zfs_sa_set_xattr #513

chrisrd opened this issue Jan 4, 2012 · 10 comments
Milestone

Comments

@chrisrd
Copy link
Contributor

chrisrd commented Jan 4, 2012

I received this with linux 3.0.14, zfs 30a9524, spl e05bec8 + cherry-pick 791dc87:

[10141.730149] BUG: unable to handle kernel NULL pointer dereference at 0000000000000090
[10141.730202] IP: [] ddt_prefetch+0x5a/0x92 [zfs]
[10141.730272] PGD 510c1b067 PUD 4c096c067 PMD 0
[10141.730305] Oops: 0000 [#1] SMP
[10141.730333] CPU 8
[10141.730340] Modules linked in: fuse nfsd exportfs zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate sha256_generic aesni_intel cryptd aes_x86_64 aes_generic cbc dm_crypt dm_mod nfs lockd auth_rpcgss nfs_acl sunrpc bridge stp llc sg sd_mod usbhid hid uhci_hcd mpt2sas psmouse scsi_transport_sas raid_class scsi_mod i2c_i801 i2c_core ioatdma ehci_hcd igb dca button processor thermal_sys
[10141.730623]
[10141.730645] Pid: 27491, comm: rsync Tainted: P 3.0.14-otn-00018-g2c7c13d #1 Supermicro X8DTH-i/6/iF/6F/X8DTH
[10141.730704] RIP: 0010:[] [] ddt_prefetch+0x5a/0x92 [zfs]
[10141.730777] RSP: 0018:ffff8804cd9059a8 EFLAGS: 00010206
[10141.730805] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000037353963
[10141.730835] RDX: 0000003337353963 RSI: 0000000000003963 RDI: ffff8804cd9059c8
[10141.730866] RBP: ffff8804cd905b98 R08: ffff88063fd14a80 R09: 0000000000000000
[10141.730897] R10: 00000000013192c8 R11: 6635343664626462 R12: 0000000000000000
[10141.730928] R13: 0000000000000000 R14: ffff8804cd9059a8 R15: 0000000013c85377
[10141.730960] FS: 00007f7084412700(0000) GS:ffff88063fd00000(0000) knlGS:0000000000000000
[10141.731006] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[10141.731035] CR2: 0000000000000090 CR3: 0000000510c1a000 CR4: 00000000000006e0
[10141.731065] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[10141.731096] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[10141.731128] Process rsync (pid: 27491, threadinfo ffff8804cd904000, task ffff880627771670)
[10141.731174] Stack:
[10141.731195] 373731340e000000 3a3020302c302035 0000000000003038 0000000000000000
[10141.731249] 0000003337353963 0000000000000000 0000000000000000 0000000000000000
[10141.731303] 0000000000000000 0000000000000000 0000000000000000 0000000000000000
[10141.731356] Call Trace:
[10141.731405] [] ? dbuf_read+0x15e/0x60b [zfs]
[10141.731437] [] ? kfree+0x56/0xec
[10141.731472] [] ? kmem_alloc_debug+0x76/0xd1 [spl]
[10141.731523] [] ? dbuf_rele_and_unlock+0x192/0x197 [zfs]
[10141.731555] [] ? __kmalloc+0xa5/0x118
[10141.731589] [] ? kmem_alloc_debug+0x76/0xd1 [spl]
[10141.731649] [] dsl_dataset_block_freeable+0x37/0x43 [zfs]
[10141.731705] [] dmu_tx_hold_spill+0x61/0x8f [zfs]
[10141.731753] [] dmu_tx_hold_sa+0x10c/0x152 [zfs]
[10141.736805] [] zfs_sa_set_xattr+0xa6/0x10c [zfs]
[10141.736860] [] zpl_xattr_set+0x172/0x226 [zfs]
[10141.736914] [] zpl_xattr_user_set+0x70/0x89 [zfs]
[10141.736944] [] generic_setxattr+0x68/0x6a
[10141.736973] [] __vfs_setxattr_noperm+0x6b/0xd0
[10141.737002] [] vfs_setxattr+0x79/0x97
[10141.737029] [] setxattr+0xb8/0xd6
[10141.737055] [] ? putname+0x2d/0x36
[10141.737083] [] ? user_path_at_empty+0x5e/0x8f
[10141.737113] [] ? kfree+0x56/0xec
[10141.737141] [] sys_lsetxattr+0x5d/0x82
[10141.737171] [] system_call_fastpath+0x16/0x1b
[10141.737199] Code: 85 d0 74 4f 48 c1 e8 28 4c 8d b5 10 fe ff ff 45 31 e4 25 ff 00 00 00 31 db 4c 8b ac c7 a0 09 00 00 4c 89 f7 e8 3d fc ff ff 89 d8
[10141.737422] RIP [] ddt_prefetch+0x5a/0x92 [zfs]
[10141.737469] RSP
[10141.737492] CR2: 0000000000000090
[10141.737846] ---[ end trace 013bdb5332844955 ]---

@chrisrd
Copy link
Contributor Author

chrisrd commented Jan 5, 2012

And again:

[57470.618574] BUG: unable to handle kernel NULL pointer dereference at 0000000000000090
[57470.618625] IP: [<ffffffffa03a07a2>] ddt_prefetch+0x5a/0x92 [zfs]
[57470.618681] PGD 4ea90c067 PUD 58d04a067 PMD 0 
[57470.618712] Oops: 0000 [#2] SMP 
[57470.618740] CPU 1 
[57470.618746] Modules linked in: fuse nfsd exportfs zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate sha256_generic aesni_intel cryptd aes_x86_64
aes_generic cbc dm_crypt dm_mod nfs lockd auth_rpcgss nfs_acl sunrpc bridge stp llc sg sd_mod usbhid hid uhci_hcd mpt2sas psmouse scsi_transport_sas raid_class scsi_mod i2c_i801 i2c_core io
atdma ehci_hcd igb dca button processor thermal_sys
[57470.619012] 
[57470.619032] Pid: 23047, comm: rsync Tainted: P      D     3.0.14-otn-00018-g2c7c13d #1 Supermicro X8DTH-i/6/iF/6F/X8DTH
[57470.619089] RIP: 0010:[<ffffffffa03a07a2>]  [<ffffffffa03a07a2>] ddt_prefetch+0x5a/0x92 [zfs]
[57470.619153] RSP: 0018:ffff8805abad99a8  EFLAGS: 00010206
[57470.619179] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000037353963
[57470.619209] RDX: 0000003337353963 RSI: 0000000000003963 RDI: ffff8805abad99c8
[57470.619238] RBP: ffff8805abad9b98 R08: ffff88063fc54a80 R09: 0000000000000000
[57470.619267] R10: ffff8805abad9b10 R11: 6231326634373965 R12: 0000000000000000
[57470.619296] R13: 0000000000000000 R14: ffff8805abad99a8 R15: 000000000061fc11
[57470.619326] FS:  00007ff426353700(0000) GS:ffff88063fc40000(0000) knlGS:0000000000000000
[57470.619371] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[57470.619398] CR2: 0000000000000090 CR3: 00000004fd9d0000 CR4: 00000000000006e0
[57470.619427] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[57470.619456] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[57470.619486] Process rsync (pid: 23047, threadinfo ffff8805abad8000, task ffff880482d9c350)
[57470.619530] Stack:
[57470.619550]  373731340e000000 3a3020302c302035 0000000000003038 0000000000000000
[57470.619601]  0000003337353963 0000000000000000 0000000000000000 0000000000000000
[57470.619653]  0000000000000000 0000000000000000 0000000000000000 0000000000000000
[57470.619704] Call Trace:
[57470.619742]  [<ffffffffa039dab5>] ? dbuf_read+0x15e/0x60b [zfs]
[57470.619772]  [<ffffffff810f0443>] ? kfree+0x56/0xec
[57470.619804]  [<ffffffffa02f16a4>] ? kmem_free_debug+0x11/0x13 [spl]
[57470.619846]  [<ffffffffa039d030>] ? dbuf_rele_and_unlock+0x192/0x197 [zfs]
[57470.619890]  [<ffffffffa039d364>] ? dmu_buf_rele+0x25/0x2c [zfs]
[57470.619919]  [<ffffffff810f00d7>] ? __kmalloc+0x47/0x118
[57470.619949]  [<ffffffffa02f193b>] ? kmem_alloc_debug+0x76/0xd1 [spl]
[57470.620000]  [<ffffffffa03bb098>] dsl_dataset_block_freeable+0x37/0x43 [zfs]
[57470.620048]  [<ffffffffa03ad558>] dmu_tx_hold_spill+0x61/0x8f [zfs]
[57470.620096]  [<ffffffffa03ae830>] dmu_tx_hold_sa+0x10c/0x152 [zfs]
[57470.620152]  [<ffffffffa04007fb>] zfs_sa_set_xattr+0xa6/0x10c [zfs]
[57470.620207]  [<ffffffffa04180b7>] zpl_xattr_set+0x172/0x226 [zfs]
[57470.620261]  [<ffffffffa041824b>] zpl_xattr_user_set+0x70/0x89 [zfs]
[57470.620290]  [<ffffffff811121fa>] generic_setxattr+0x68/0x6a
[57470.620318]  [<ffffffff81112ae3>] __vfs_setxattr_noperm+0x6b/0xd0
[57470.620346]  [<ffffffff81112bc1>] vfs_setxattr+0x79/0x97
[57470.620373]  [<ffffffff81112c97>] setxattr+0xb8/0xd6
[57470.620399]  [<ffffffff81103e38>] ? putname+0x2d/0x36
[57470.620425]  [<ffffffff81104823>] ? user_path_at_empty+0x5e/0x8f
[57470.620454]  [<ffffffff810f0443>] ? kfree+0x56/0xec
[57470.620480]  [<ffffffff81112dbd>] sys_lsetxattr+0x5d/0x82
[57470.620508]  [<ffffffff812c23d2>] system_call_fastpath+0x16/0x1b
[57470.620534] Code: 85 d0 74 4f 48 c1 e8 28 4c 8d b5 10 fe ff ff 45 31 e4 25 ff 00 00 00 31 db 4c 8b ac c7 a0 09 00 00 4c 89 f7 e8 3d fc ff ff 89 d8 
[57470.620748] RIP  [<ffffffffa03a07a2>] ddt_prefetch+0x5a/0x92 [zfs]
[57470.620748] RIP  [<ffffffffa03a07a2>] ddt_prefetch+0x5a/0x92 [zfs]
[57470.620794]  RSP <ffff8805abad99a8>
[57470.620816] CR2: 0000000000000090
[57470.621158] ---[ end trace 013bdb5332844956 ]---

@behlendorf
Copy link
Contributor

Thanks, we'll look in to it. That's a bit odd. Related to SA based xattrs have you observed any other troubles aside from this and issue #503?

@chrisrd
Copy link
Contributor Author

chrisrd commented Jan 16, 2012

No, I haven't had any other troubles related to SA based xattrs other than #503.

(On returning from leave I can see my kern.log has a few more of these same NULL pointer in ddt_prefetch messages.)

@behlendorf
Copy link
Contributor

OK, thanks. We'll certainly try and get these two issues nailed down since in the relatively near future we expect to be using SA based xattrs as well here at LLNL. That's after all why I added the original support. :)

@chrisrd
Copy link
Contributor Author

chrisrd commented Jan 21, 2012

The whole "Busy hang" problem (#539) may have been related to this NULL pointer problem rather than anything to do with openzfs/spl@ec2b410.

I had a case where a 'getfattr -d' on a particular directory would just hang (on the directory itself rather than on the contents). In trying to use stap to see if it could tell me anything useful I rebooted (due to the stap module unload problem described in #503), and after the reboot the getfattr on that same directory succeeded.

I was then able to 'getfattr -d' on a large list of directories without problems. Some time later, after a number of NULL pointer dereferences, I was getting a getfattr hang on one of the directories that was previously ok.

I suspect the NULL pointer dereference problem then causes later xattr accesses to the same (or some other?) file or directory to hang.

So the "Busy hang" was likely due to rsync and other utilities (e.g. "ls -l" will access xattrs) coming across one of the previously-faulted xattrs.

The scenario for thinking that the hangs were related to openzfs/spl@ec2b410 was because rebooting into the kernel with that commit reverted (and later rebooting into the kernel with the openzfs/spl@3c6ed54 fix) cleared the previously-seen xattr errors.

@chrisrd chrisrd mentioned this issue Jan 21, 2012
@chrisrd
Copy link
Contributor Author

chrisrd commented Jan 24, 2012

FYI, still getting these (with the same call trace) with linux-3.1.10, openzfs/spl@3c6ed54, b4b599d.

Is there anything I can do to help track this down?

In case it matters... as mentioned, I suspect this issue is the underlying cause for my processes getting "stuck" in zfs operations and becoming unkillable, to the point of requiring a reboot. 'ps' shows the unkillable processes with WCHAN of 'call_rwsem_down_read_failed'.

@behlendorf
Copy link
Contributor

Yes, the #539 issue could have been caused by the NULL deref. Once you've had a NULL dereferences basically all bets are off and you should really reboot your kernel.

As for this bug I haven't looked in to it closely yet but I can probably propose a short term work around. If you set the zfs_dedup_prefetch=0 module option you should be able to avoid this code path. Please give it a try and let me know if you still observe problems.

@chrisrd
Copy link
Contributor Author

chrisrd commented Jan 26, 2012

Was running most yesterday with xattr=dir without any NULL derefs. But that could have been coincidence as I've also had previous days without any. Now running with xattr=dir and zfs_dedup_prefetch=0. Let's see how that goes!

@chrisrd
Copy link
Contributor Author

chrisrd commented Feb 2, 2012

FYI, got the following possibly related BUGs (i.e. via zfs_sa_set_xattr) on linux-3.0.18, openzfs/spl@3c6ed54, b4b599d.

This was with zfs_dedup_prefetch=0, xattr=sa.

This happened on a fs where I'd forgotten to revert to xattr=dir and we were testing gluster which does a lot of trusted xattr rewriting, as opposed to the previous BUGs which came from being a target of 'rsync -X', i.e. mostly user xattr writing. I think this may explain the different code paths.

I.e. the zfs_dedup_prefetch=0 may not have helped.

On the other hand, the fs where we saw the previous BUGs has been running the rsync target workload trouble free for the last 8 days with zfs_dedup_prefetch=0, xattr=dir.

[462944.374871] BUG: unable to handle kernel NULL pointer dereference at 0000000000000018
[462944.374926] IP: [<ffffffffa0377c16>] sa_build_layouts+0x39b/0x70b [zfs]
[462944.375004] PGD 4dde58067 PUD 4f70c9067 PMD 0 
[462944.375037] Oops: 0000 [#1] SMP 
[462944.375066] CPU 8 
[462944.375073] Modules linked in: configfs fuse nfsd exportfs zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate sha256_generic aesni_intel cryptd aes_x86_64 aes_generic cbc dm_crypt dm_mod nfs lockd auth_rpcgss nfs_acl sunrpc bridge stp llc sg sd_mod usbhid hid uhci_hcd mpt2sas scsi_transport_sas raid_class psmouse scsi_mod i2c_i801 i2c_core ioatdma ehci_hcd igb dca button processor thermal_sys
[462944.375361] 
[462944.375383] Pid: 26722, comm: glusterfsd Tainted: P            3.0.18-otn-00020-gb06ea41 #1 Supermicro X8DTH-i/6/iF/6F/X8DTH
[462944.375442] RIP: 0010:[<ffffffffa0377c16>]  [<ffffffffa0377c16>] sa_build_layouts+0x39b/0x70b [zfs]
[462944.375579] RSP: 0018:ffff8805ef8fd988  EFLAGS: 00010206
[462944.375607] RAX: 0000000000000000 RBX: ffff880ae19e0928 RCX: 000000000000000e
[462944.375652] RDX: 0000000000000803 RSI: ffff8805fdee9b60 RDI: ffff880620982480
[462944.375696] RBP: ffff8805ef8fda58 R08: ffff8805cb0a8f00 R09: ffff8805ef8fda08
[462944.375742] R10: 7472632e746f6f52 R11: 2e746f6f525f7365 R12: ffff880bb3618200
[462944.375787] R13: ffff880bb3618300 R14: ffff880620982480 R15: ffff880529088400
[462944.375833] FS:  00007eff375e0700(0000) GS:ffff88063fd00000(0000) knlGS:0000000000000000
[462944.375930] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[462944.375958] CR2: 0000000000000018 CR3: 00000005b1e0b000 CR4: 00000000000006e0
[462944.376003] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[462944.376048] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[462944.376093] Process glusterfsd (pid: 26722, threadinfo ffff8805ef8fc000, task ffff88062757ace0)
[462944.376140] Stack:
[462944.376161]  ffff8805ef8fda20 ffff8805ef8fda18 0000000000000000 0000000000000000
[462944.376216]  2e184cf536f3067f 0000000000000020 00000044000080d0 ffff8804a5c57a00
[462944.376271]  0000000100000010 000000020000002c 62c9ffb4caaba6ef 000000000000000f
[462944.376325] Call Trace:
[462944.376385]  [<ffffffffa0378256>] sa_modify_attrs+0x2d0/0x311 [zfs]
[462944.376450]  [<ffffffffa03785e0>] sa_attr_op+0x2f8/0x320 [zfs]
[462944.376514]  [<ffffffffa0378665>] sa_bulk_update_impl+0x5d/0x8e [zfs]
[462944.376578]  [<ffffffffa037876d>] sa_update+0x41/0x56 [zfs]
[462944.376645]  [<ffffffffa03abb35>] zfs_sa_set_xattr+0xdc/0x10c [zfs]
[462944.376711]  [<ffffffffa03c3433>] zpl_xattr_set+0x172/0x226 [zfs]
[462944.376777]  [<ffffffffa03c3832>] zpl_xattr_trusted_set+0x6c/0x85 [zfs]
[462944.376810]  [<ffffffff811124aa>] generic_setxattr+0x68/0x6a
[462944.376839]  [<ffffffff81112d93>] __vfs_setxattr_noperm+0x6b/0xd0
[462944.376870]  [<ffffffff81112e71>] vfs_setxattr+0x79/0x97
[462944.376898]  [<ffffffff81112f47>] setxattr+0xb8/0xd6
[462944.376927]  [<ffffffff8110402c>] ? putname+0x2d/0x36
[462944.376955]  [<ffffffff81104a17>] ? user_path_at_empty+0x5e/0x8f
[462944.376986]  [<ffffffff8111306d>] sys_lsetxattr+0x5d/0x82
[462944.377016]  [<ffffffff812c2b12>] system_call_fastpath+0x16/0x1b
[462944.377045] Code: c1 e8 0a 33 45 ac c1 e0 0a 31 d0 66 41 89 44 24 04 48 8b 55 b0 8b 52 30 31 c2 66 81 e2 ff 03 31 c2 66 41 89 54 24 04 48 8b 43 28 <4c> 8b 60 18 41 c7 04 24 5a 50 2f 00 48 8b 85 48 ff ff ff 48 8b 
[462944.377273] RIP  [<ffffffffa0377c16>] sa_build_layouts+0x39b/0x70b [zfs]
[462944.377341]  RSP <ffff8805ef8fd988>
[462944.377365] CR2: 0000000000000018
[462944.377722] ---[ end trace c68c9b00f66de06e ]---

And again, soon after rebooting:

[ 2651.828448] BUG: unable to handle kernel NULL pointer dereference at 0000000000000018
[ 2651.828500] IP: [<ffffffffa0370c16>] sa_build_layouts+0x39b/0x70b [zfs]
[ 2651.828563] PGD 627198067 PUD 6211aa067 PMD 0 
[ 2651.828595] Oops: 0000 [#1] SMP 
[ 2651.828622] CPU 0 
[ 2651.828628] Modules linked in: configfs fuse nfsd exportfs zfs(P) zcommon(P) znvpair(P) zavl(P) zunicode(P) spl zlib_deflate sha256_generic aesni_intel cryptd aes_x86_64 aes_generic cbc dm_crypt dm_mod nfs lockd auth_rpcgss nfs_acl sunrpc bridge stp llc sg sd_mod usbhid hid uhci_hcd mpt2sas psmouse scsi_transport_sas raid_class scsi_mod i2c_i801 i2c_core ioatdma ehci_hcd igb dca button processor thermal_sys
[ 2651.828898] 
[ 2651.828918] Pid: 9549, comm: glusterfsd Tainted: P            3.0.18-otn-00020-gb06ea41 #1 Supermicro X8DTH-i/6/iF/6F/X8DTH
[ 2651.828975] RIP: 0010:[<ffffffffa0370c16>]  [<ffffffffa0370c16>] sa_build_layouts+0x39b/0x70b [zfs]
[ 2651.829048] RSP: 0018:ffff8806084a3988  EFLAGS: 00010206
[ 2651.829074] RAX: 0000000000000000 RBX: ffff88060f085388 RCX: 000000000000000e
[ 2651.829103] RDX: 0000000000000803 RSI: ffff880623941940 RDI: ffff880600972cc0
[ 2651.829133] RBP: ffff8806084a3a58 R08: ffff8806125b6a80 R09: ffff8806084a3a08
[ 2651.829162] R10: 7472632e746f6f52 R11: 2e746f6f525f7365 R12: ffff8806084f2600
[ 2651.829191] R13: ffff8806084f2700 R14: ffff880600972cc0 R15: ffff880615abf400
[ 2651.829221] FS:  00007fac220c7700(0000) GS:ffff88063fc00000(0000) knlGS:0000000000000000
[ 2651.829266] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2651.829293] CR2: 0000000000000018 CR3: 00000005ff27f000 CR4: 00000000000006f0
[ 2651.829322] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 2651.829352] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
[ 2651.829381] Process glusterfsd (pid: 9549, threadinfo ffff8806084a2000, task ffff880621702ce0)
[ 2651.829427] Stack:
[ 2651.829446]  ffff8806084a3a20 ffff8806084a3a18 0000000000000000 0000000000000000
[ 2651.829498]  2e184cf536f3067f 0000000000000020 000000440002c1dc ffff88060a181d20
[ 2651.829550]  0000000100000010 000000020000002c 62c9ffb4caaba6ef 000000000000000f
[ 2651.829601] Call Trace:
[ 2651.829647]  [<ffffffffa0371256>] sa_modify_attrs+0x2d0/0x311 [zfs]
[ 2651.829699]  [<ffffffffa03715e0>] sa_attr_op+0x2f8/0x320 [zfs]
[ 2651.829750]  [<ffffffffa0371665>] sa_bulk_update_impl+0x5d/0x8e [zfs]
[ 2651.829802]  [<ffffffffa037176d>] sa_update+0x41/0x56 [zfs]
[ 2651.829855]  [<ffffffffa03a4b35>] zfs_sa_set_xattr+0xdc/0x10c [zfs]
[ 2651.829907]  [<ffffffffa03bc433>] zpl_xattr_set+0x172/0x226 [zfs]
[ 2651.829959]  [<ffffffffa03bc832>] zpl_xattr_trusted_set+0x6c/0x85 [zfs]
[ 2651.829990]  [<ffffffff811124aa>] generic_setxattr+0x68/0x6a
[ 2651.830018]  [<ffffffff81112d93>] __vfs_setxattr_noperm+0x6b/0xd0
[ 2651.830046]  [<ffffffff81112e71>] vfs_setxattr+0x79/0x97
[ 2651.830073]  [<ffffffff81112f47>] setxattr+0xb8/0xd6
[ 2651.830100]  [<ffffffff8110402c>] ? putname+0x2d/0x36
[ 2651.830126]  [<ffffffff81104a17>] ? user_path_at_empty+0x5e/0x8f
[ 2651.830155]  [<ffffffff8111306d>] sys_lsetxattr+0x5d/0x82
[ 2651.830183]  [<ffffffff812c2b12>] system_call_fastpath+0x16/0x1b
[ 2651.830210] Code: c1 e8 0a 33 45 ac c1 e0 0a 31 d0 66 41 89 44 24 04 48 8b 55 b0 8b 52 30 31 c2 66 81 e2 ff 03 31 c2 66 41 89 54 24 04 48 8b 43 28 <4c> 8b 60 18 41 c7 04 24 5a 50 2f 00 48 8b 85 48 ff ff ff 48 8b 
[ 2651.830419] RIP  [<ffffffffa0370c16>] sa_build_layouts+0x39b/0x70b [zfs]
[ 2651.830473]  RSP <ffff8806084a3988>
[ 2651.830496] CR2: 0000000000000018
[ 2651.830890] ---[ end trace 57211a6f56ea1676 ]---

behlendorf added a commit to behlendorf/zfs that referenced this issue Mar 2, 2012
A private SA handle must be used to ensure we can drop the dbuf
hold on the spill block prior to calling dmu_tx_commit().  If we
call dmu_tx_commit() before sa_handle_destroy(), then our hold
will trigger a copy of the dbuf to be made.  This is done to
prevent data from leaking in to the syncing txg.  As a result
the original dirty spill block will remain cached.

Additionally, relying on the shared zp->z_sa_hdl is unsafe in
the xattr context because the znode may be asynchronously dropped
from the cache.  It's far safer and simpler just to use a private
handle for xattrs.  Plus any additional overhead is offset by
the avoidance of the previously mentioned memory copy.

These forever dirty buffers can be noticed in the arcstats under
the anon_size.  On a quiescent system the value should be zero.
Without this fix and a SA xattr write workload you will see
anon_size increase.  Eventually, if enough dirty data builds up
your system it will appear to hang.  This occurs because the dmu
won't allow new txs to be assigned until that dirty data is
flushed, and it won't be because it's not part of an assigned tx.

As an aside, I typically see anon_size lurk around 16k so I think
there is another place in the code which needs a similar fix.
However, this value doesn't grow over time so it isn't critical.

Signed-off-by: Brian Behlendorf <[email protected]>
Issue openzfs#503
Issue openzfs#513
@behlendorf
Copy link
Contributor

Closing issue the SA_HDL_PRIVATE change should have addressed this. Please file a new issue if this is observed again.

behlendorf pushed a commit to behlendorf/zfs that referenced this issue Aug 25, 2012
When calling sa_update() and friends it is possible that a spill
buffer will be needed to accomidate the update.  When this happens
a hold is taken on the new dbuf and that hold must be released
before calling dmu_tx_commit().  Failing to release the hold will
cause a copy of the dbuf to be made in dbuf_sync_leaf().  This is
done to ensure further updates to the dbuf never sneak in to the
syncing txg.

This could be left to the sa_update() caller.  But then the caller
would need to be aware of this internal SA implementation detail.
It is therefore preferable to handle this all internally in the
SA implementation.

Signed-off-by: Brian Behlendorf <[email protected]>
Issue openzfs#503
Issue openzfs#513
behlendorf pushed a commit that referenced this issue Aug 25, 2012
When calling sa_update() and friends it is possible that a spill
buffer will be needed to accomidate the update.  When this happens
a hold is taken on the new dbuf and that hold must be released
before calling dmu_tx_commit().  Failing to release the hold will
cause a copy of the dbuf to be made in dbuf_sync_leaf().  This is
done to ensure further updates to the dbuf never sneak in to the
syncing txg.

This could be left to the sa_update() caller.  But then the caller
would need to be aware of this internal SA implementation detail.
It is therefore preferable to handle this all internally in the
SA implementation.

Signed-off-by: Brian Behlendorf <[email protected]>
Closes #503
Closes #513
ryao added a commit to ryao/zfs that referenced this issue Oct 9, 2014
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]>
ryao added a commit to ryao/zfs that referenced this issue Oct 9, 2014
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]>
ryao added a commit to ryao/zfs that referenced this issue Oct 9, 2014
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]>
ryao added a commit to ryao/zfs that referenced this issue Oct 10, 2014
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]>
ryao added a commit to ryao/zfs that referenced this issue Oct 10, 2014
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]>
ryao added a commit to ryao/zfs that referenced this issue Oct 10, 2014
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]>
ryao added a commit to ryao/zfs that referenced this issue Oct 10, 2014
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]>
ryao added a commit to ryao/zfs that referenced this issue Oct 10, 2014
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]>
ryao added a commit to ryao/zfs that referenced this issue Oct 10, 2014
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]>
ryao added a commit to ryao/zfs that referenced this issue Oct 11, 2014
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]>
ryao added a commit to ryao/zfs that referenced this issue Oct 11, 2014
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]>
behlendorf pushed a commit to behlendorf/zfs that referenced this issue May 21, 2018
I noticed that the SPL implementation of kobj_read_file is not correct
after comparing it with the userland implementation of kobj_read_file()
in openzfs#4104.

Note that we no longer pass RLIM64_INFINITY with this, but our vn_rdwr
implementation did not support it anyway, so there is no difference.

Signed-off-by: Richard Yao <[email protected]>
Signed-off-by: Brian Behlendorf <[email protected]>
Closes openzfs#513
behlendorf added a commit to behlendorf/zfs that referenced this issue May 21, 2018
Previous commit be29e6a updated kobj_read_file() so it no longer
unconditionally passes RLIM64_INFINITY.  The vn_rdwr() function
needs to be updated accordingly.

Signed-off-by: Brian Behlendorf <[email protected]>
Issue openzfs#513
sdimitro pushed a commit to sdimitro/zfs that referenced this issue Jul 18, 2022
* Support for running tests with azure blob

PR URL: https://www.github.com/delphix/zfs/pull/513
- zpool import object store tests.
- background freeing.
- zpool destroy object store tests.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants