System wedge/lock. #477

ryantig · 2011-12-01T09:01:15Z

I just had a hard hang/lock I was running a scrub, while rsyncing over some files. network died, numlock, etc non responsive, Had to do an ATX power off.
Last events before the power off had 'z_wr_iss/0: page allocation failure. order:3, mode:0x4020' type messages - but I even had those when I was running zfs-fuse (but without crash): "zfs-fuse: page allocation failure. order:3, mode:0x4020"

This occurred with the up to date git version downloaded as zip files:
zfsonlinux-spl-spl-0.6.0-rc6-13-ge05bec8.zip
zfsonlinux-zfs-zfs-0.6.0-rc6-20-gb9c59ec.zip

ubuntu 11.04: 2.6.38-13-server #52-Ubuntu SMP Tue Nov 8 17:11:08 UTC 2011 x86_64 x86_64

zfs tests passed:
zconfig.sh -c
1 persistent zpool.cache Pass
2 scan disks for pools to import Pass
3 zpool import/export device Pass
4 zpool insmod/rmmod device Pass
5 zvol+ext3 volume Pass
6 zvol+ext2 snapshot Pass
7 zvol+ext2 clone Pass
8 zfs send/receive Pass
9 zpool events Pass
10 zpool add/remove vdev Pass

egrep '^Nov 30 23:42' kern.log|head -700
is here: http://pastebin.com/6DKqN4nB
subset here

$ egrep '^Nov 30 23:42' kern.log|head -70
Nov 30 23:42:49 r1501 kernel: [133589.275863] __alloc_pages_slowpath: 5571 callbacks suppressed
Nov 30 23:42:49 r1501 kernel: [133589.275871] z_wr_iss/0: page allocation failure. order:3, mode:0x4020
Nov 30 23:42:49 r1501 kernel: [133589.275879] Pid: 28631, comm: z_wr_iss/0 Tainted: P 2.6.38-13-server #52-Ubuntu
Nov 30 23:42:49 r1501 kernel: [133589.275885] Call Trace:
Nov 30 23:42:49 r1501 kernel: [133589.275889] [] ? __alloc_pages_nodemask+0x5f4/0x830
Nov 30 23:42:49 r1501 kernel: [133589.275914] [] ? kmalloc_large_node+0x6b/0xc0
Nov 30 23:42:49 r1501 kernel: [133589.275922] [] ? __kmalloc_node_track_caller+0x155/0x1a0
Nov 30 23:42:49 r1501 kernel: [133589.275940] [] ? rx_submit+0x3f/0x310 [asix]
Nov 30 23:42:49 r1501 kernel: [133589.275949] [] ? __alloc_skb+0x83/0x170
Nov 30 23:42:49 r1501 kernel: [133589.275959] [] ? rx_submit+0x3f/0x310 [asix]
Nov 30 23:42:49 r1501 kernel: [133589.275968] [] ? defer_bh+0xba/0xf0 [asix]
Nov 30 23:42:49 r1501 kernel: [133589.275978] [] ? rx_complete+0x238/0x2a0 [asix]
Nov 30 23:42:49 r1501 kernel: [133589.275987] [] ? usb_hcd_giveback_urb+0x64/0xe0
Nov 30 23:42:49 r1501 kernel: [133589.275996] [] ? ehci_urb_done+0xe2/0x120
Nov 30 23:42:49 r1501 kernel: [133589.276004] [] ? qh_completions+0x1f6/0x470
Nov 30 23:42:49 r1501 kernel: [133589.276013] [] ? scan_async+0x11b/0x1f0
Nov 30 23:42:49 r1501 kernel: [133589.276021] [] ? ehci_work+0x3b/0x80
Nov 30 23:42:49 r1501 kernel: [133589.276028] [] ? ehci_irq+0x1cc/0x240
Nov 30 23:42:49 r1501 kernel: [133589.276035] [] ? ftrace_call+0x5/0x2b
Nov 30 23:42:49 r1501 kernel: [133589.276043] [] ? usb_hcd_irq+0x3d/0x70
Nov 30 23:42:49 r1501 kernel: [133589.276051] [] ? handle_IRQ_event+0x54/0x180
Nov 30 23:42:49 r1501 kernel: [133589.276060] [] ? handle_fasteoi_irq+0x87/0x110
Nov 30 23:42:49 r1501 kernel: [133589.276068] [] ? handle_irq+0x22/0x40
Nov 30 23:42:49 r1501 kernel: [133589.276076] [] ? do_IRQ+0x5d/0xe0
Nov 30 23:42:49 r1501 kernel: [133589.276084] [] ? ret_from_intr+0x0/0x15
Nov 30 23:42:49 r1501 kernel: [133589.276089] [] ? mutex_unlock+0x0/0x20
Nov 30 23:42:49 r1501 kernel: [133589.276170] [] ? zio_add_child+0x100/0x120 [zfs]
Nov 30 23:42:49 r1501 kernel: [133589.276213] [] ? zio_create+0x3dd/0x490 [zfs]
Nov 30 23:42:49 r1501 kernel: [133589.276257] [] ? zio_vdev_child_io+0xb3/0xe0 [zfs]
Nov 30 23:42:49 r1501 kernel: [133589.276299] [] ? vdev_raidz_child_done+0x0/0x30 [zfs]
Nov 30 23:42:49 r1501 kernel: [133589.276344] [] ? vdev_raidz_io_start+0x602/0x6f0 [zfs]
Nov 30 23:42:49 r1501 kernel: [133589.276387] [] ? vdev_raidz_child_done+0x0/0x30 [zfs]
Nov 30 23:42:49 r1501 kernel: [133589.276432] [] ? zio_vdev_io_start+0xab/0x300 [zfs]
Nov 30 23:42:49 r1501 kernel: [133589.276474] [] ? zio_nowait+0xb0/0x180 [zfs]
Nov 30 23:42:49 r1501 kernel: [133589.276518] [] ? vdev_mirror_io_start+0x186/0x3d0 [zfs]
Nov 30 23:42:49 r1501 kernel: [133589.276561] [] ? vdev_mirror_child_done+0x0/0x30 [zfs]
Nov 30 23:42:49 r1501 kernel: [133589.276604] [] ? zio_vdev_io_start+0x237/0x300 [zfs]
Nov 30 23:42:49 r1501 kernel: [133589.276648] [] ? zio_execute+0xb0/0x150 [zfs]
Nov 30 23:42:49 r1501 kernel: [133589.276655] [] ? ftrace_call+0x5/0x2b
Nov 30 23:42:49 r1501 kernel: [133589.276675] [] ? taskq_thread+0x1c0/0x390 [spl]
Nov 30 23:42:49 r1501 kernel: [133589.276684] [] ? default_wake_function+0x0/0x20
Nov 30 23:42:49 r1501 kernel: [133589.276697] [] ? taskq_thread+0x0/0x390 [spl]
Nov 30 23:42:49 r1501 kernel: [133589.276705] [] ? kthread+0x96/0xa0
Nov 30 23:42:49 r1501 kernel: [133589.276713] [] ? kernel_thread_helper+0x4/0x10
Nov 30 23:42:49 r1501 kernel: [133589.276722] [] ? kthread+0x0/0xa0
Nov 30 23:42:49 r1501 kernel: [133589.276729] [] ? kernel_thread_helper+0x0/0x10
Nov 30 23:42:49 r1501 kernel: [133589.276734] Mem-Info:
Nov 30 23:42:50 r1501 kernel: [133589.276737] Node 0 DMA per-cpu:
Nov 30 23:42:50 r1501 kernel: [133589.276743] CPU 0: hi: 0, btch: 1 usd: 0
Nov 30 23:42:50 r1501 kernel: [133589.276747] Node 0 DMA32 per-cpu:
Nov 30 23:42:50 r1501 kernel: [133589.276752] CPU 0: hi: 186, btch: 31 usd: 174
Nov 30 23:42:50 r1501 kernel: [133589.276761] active_anon:16830 inactive_anon:10513 isolated_anon:0
Nov 30 23:42:50 r1501 kernel: [133589.276764] active_file:21286 inactive_file:14619 isolated_file:0
Nov 30 23:42:50 r1501 kernel: [133589.276767] unevictable:0 dirty:7 writeback:0 unstable:0
Nov 30 23:42:50 r1501 kernel: [133589.276770] free:2485 slab_reclaimable:7502 slab_unreclaimable:8018
Nov 30 23:42:50 r1501 kernel: [133589.276774] mapped:3566 shmem:110 pagetables:1010 bounce:0
Nov 30 23:42:50 r1501 kernel: [133589.276779] Node 0 DMA free:5524kB min:52kB low:64kB high:76kB active_anon:0kB inactive_anon:56kB active_file:16kB inactive_file:80kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15676kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:36kB slab_unreclaimable:620kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Nov 30 23:42:50 r1501 kernel: [133589.276805] lowmem_reserve[]: 0 1371 1371 1371
Nov 30 23:42:50 r1501 kernel: [133589.276813] Node 0 DMA32 free:4416kB min:4708kB low:5884kB high:7060kB active_anon:67320kB inactive_anon:41996kB active_file:85128kB inactive_file:58396kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1404340kB mlocked:0kB dirty:28kB writeback:0kB mapped:14264kB shmem:440kB slab_reclaimable:29972kB slab_unreclaimable:31452kB kernel_stack:2304kB pagetables:4040kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Nov 30 23:42:50 r1501 kernel: [133589.276840] lowmem_reserve[]: 0 0 0 0
Nov 30 23:42:50 r1501 kernel: [133589.276848] Node 0 DMA: 9_4kB 4_8kB 9_16kB 8_32kB 5_64kB 7_128kB 3_256kB 0_512kB 1_1024kB 1_2048kB 0_4096kB = 5524kB
Nov 30 23:42:50 r1501 kernel: [133589.276868] Node 0 DMA32: 844_4kB 68_8kB 15_16kB 0_32kB 0_64kB 0_128kB 1_256kB 0_512kB 0_1024kB 0_2048kB 0_4096kB = 4416kB
Nov 30 23:42:50 r1501 kernel: [133589.276888] 36070 total pagecache pages
Nov 30 23:42:50 r1501 kernel: [133589.276892] 55 pages in swap cache
Nov 30 23:42:50 r1501 kernel: [133589.276896] Swap cache stats: add 212, delete 157, find 405/415
Nov 30 23:42:50 r1501 kernel: [133589.276901] Free swap = 1951296kB
Nov 30 23:42:50 r1501 kernel: [133589.276904] Total swap = 1951740kB
Nov 30 23:42:50 r1501 kernel: [133589.280016] 360032 pages RAM
Nov 30 23:42:50 r1501 kernel: [133589.280016] 8052 pages reserved
Nov 30 23:42:50 r1501 kernel: [133589.280016] 33092 pages shared

Any thoughts?

Cheers,
Ryan

behlendorf · 2011-12-01T17:32:30Z

It's clear your putting quite the strain on the Linux VM and I may have a decent idea why. Typically, the system can reclaim enough memory when it's low and move on with just a warning. This was actually happened for quite some time on your system until that was no longer possible I suspect due to fragmentation.

Now the unique thing about your configuration which I think helped cause this has to do with how your network stack is configured... your using jumbo 9000 byte packets aren't you? While one of the zfs threads was writing out data it was forced to handle an interrupt from you network adapter. This isn't uncommon, it happens all the time, what is uncommon through is the fact that it needed an order 3 allocation (32k, 8 physically consecutive pages). With the added zfs kernel memory pressure, the size of the required allocation, the potential memory fragmentation of the system, and the fact that we're in an interrupt context memory and this can't reclaim memory... a very rare failure mode becomes slightly more common. (As an aside this is why you saw the same warning with zfs-fuse, the root of the problem is in the network stack)

Now I know for experience that many Linux network driver don't handle this case gracefully since its so uncommon and there's very little they can do other just throw away the packet. What your driver does I'm not sure off hand, I've never used the asix module. But a panic or hang certainly isn't out of the question particularly since interrupts are disabled.

Anyway, to mitigate the issue I would suggest decreasing your MTU size. Even decreasing it slightly to say 7500 bytes may be enough to drop you to an order 2 allocation size. Going all the way down to 1500 bytes would be the best for stability since they your just talking about allocating a single page of memory. Alternately you could further restrict the zfs arc size to try and leave more of the system memory available for the network stack.

ryantig · 2011-12-01T21:07:20Z

MTU was/is 1500.

The sending system fwiw is only 802.11n, so it's not that much traffic - would guess the zpool scan was the main memory consumer. fwiw When I was running zfs-fuse I had set "max-arc-size = 100"

For zfsonlinux - do you have a recommendation for a value on the modprobe.d/zfs.conf for 'options zfs zfs_arc_max='?
Thanks

ryantig · 2011-12-02T01:49:45Z

[it's what I get for making two changes around the same time - harder to troubleshoot...]
I hit the same issue again. Now I've reverted to the BCM4401 based network, and added options zfs zfs_arc_max=100, (glance at source, it appears to want a setting in MB) and we'll see if it hit again. (if not, will try adding back the asix adapter, and keeping the zfs_arc_max setting.)
tks

behlendorf · 2011-12-02T17:02:53Z

Drat, from the stack it really looked like a large MTU. Ahh well, if that's not the case I'd suggest limiting the zfs_arc_max to about 1/2 of total system memory. That will become basically the Linux default shortly since most people are finding they need to tuning things. As for zfs_arc_max it is actually set in bytes, which is ridiculous, but what the upstream Solaris code does. At some point I'll make it smarter to accept values like 2G, etc. Let me know if limiting the ARC helps.

ryantig · 2011-12-02T20:14:22Z

On the BCM401, and with reduced zfs_arc_max - wedged again. Now trying zfs-fuse again, to verify I didn't break something else.

Dec 2 11:41:36 r1501 kernel: [66188.090711] __alloc_pages_slowpath: 106 callbacks suppressed
Dec 2 11:41:36 r1501 kernel: [66188.090722] z_wr_int/11: page allocation failure. order:0, mode:0x4020
Dec 2 11:41:36 r1501 kernel: [66188.090732] Pid: 784, comm: z_wr_int/11 Tainted: P 2.6.38-13-server #52-Ubuntu
Dec 2 11:41:36 r1501 kernel: [66188.090739] Call Trace:
Dec 2 11:41:36 r1501 kernel: [66188.090745] [] ? __alloc_pages_nodemask+0x5f4/0x830
Dec 2 11:41:36 r1501 kernel: [66188.090775] [] ? alloc_pages_current+0xa5/0x110
Dec 2 11:41:36 r1501 kernel: [66188.090786] [] ? new_slab+0x282/0x290
Dec 2 11:41:36 r1501 kernel: [66188.090795] [] ? __slab_alloc+0x262/0x390
Dec 2 11:41:36 r1501 kernel: [66188.090805] [] ? __netdev_alloc_skb+0x24/0x50
Dec 2 11:41:36 r1501 kernel: [66188.090815] [] ? __kmalloc_node_track_caller+0x8d/0x1a0
Dec 2 11:41:36 r1501 kernel: [66188.090823] [] ? __netdev_alloc_skb+0x24/0x50
Dec 2 11:41:36 r1501 kernel: [66188.090831] [] ? __alloc_skb+0x83/0x170
Dec 2 11:41:36 r1501 kernel: [66188.090839] [] ? __netdev_alloc_skb+0x24/0x50
Dec 2 11:41:36 r1501 kernel: [66188.090871] [] ? b44_rx+0x27b/0x2f0 [b44]
Dec 2 11:41:36 r1501 kernel: [66188.090884] [] ? b44_poll+0x11b/0x1dc [b44]
Dec 2 11:41:36 r1501 kernel: [66188.090894] [] ? scsi_finish_command+0xc5/0x130
Dec 2 11:41:36 r1501 kernel: [66188.090906] [] ? net_rx_action+0x128/0x270
Dec 2 11:41:36 r1501 kernel: [66188.090928] [] ? ssb_pci_read32+0x2f/0x50 [ssb]
Dec 2 11:41:36 r1501 kernel: [66188.090940] [] ? b44_interrupt+0xad/0x120 [b44]
Dec 2 11:41:36 r1501 kernel: [66188.090950] [] ? __do_softirq+0xa8/0x1c0
Dec 2 11:41:36 r1501 kernel: [66188.090961] [] ? ack_apic_level+0x78/0x1a0
Dec 2 11:41:36 r1501 kernel: [66188.090971] [] ? call_softirq+0x1c/0x30
Dec 2 11:41:36 r1501 kernel: [66188.090980] [] ? do_softirq+0x65/0xa0
Dec 2 11:41:36 r1501 kernel: [66188.090987] [] ? irq_exit+0x85/0x90
Dec 2 11:41:36 r1501 kernel: [66188.090996] [] ? do_IRQ+0x66/0xe0
Dec 2 11:41:36 r1501 kernel: [66188.091007] [] ? ret_from_intr+0x0/0x15
Dec 2 11:41:36 r1501 kernel: [66188.091012] [] ? memmove+0x81/0x1a0
Dec 2 11:41:36 r1501 kernel: [66188.091152] [] ? vdev_queue_io_to_issue+0x4f3/0x530 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.091232] [] ? vdev_queue_agg_io_done+0x0/0x80 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.091313] [] ? zio_wait_for_children+0x63/0x80 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.091393] [] ? vdev_queue_io_done+0x82/0xd0 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.091471] [] ? zio_vdev_io_done+0x88/0x190 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.091549] [] ? zio_execute+0xb0/0x150 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.091559] [] ? default_spin_lock_flags+0x9/0x10
Dec 2 11:41:36 r1501 kernel: [66188.091591] [] ? taskq_thread+0x1c0/0x390 [spl]
Dec 2 11:41:36 r1501 kernel: [66188.091601] [] ? default_wake_function+0x0/0x20
Dec 2 11:41:36 r1501 kernel: [66188.091621] [] ? taskq_thread+0x0/0x390 [spl]
Dec 2 11:41:36 r1501 kernel: [66188.091630] [] ? kthread+0x96/0xa0
Dec 2 11:41:36 r1501 kernel: [66188.091639] [] ? kernel_thread_helper+0x4/0x10
Dec 2 11:41:36 r1501 kernel: [66188.091647] [] ? kthread+0x0/0xa0
Dec 2 11:41:36 r1501 kernel: [66188.091655] [] ? kernel_thread_helper+0x0/0x10
Dec 2 11:41:36 r1501 kernel: [66188.091660] Mem-Info:
Dec 2 11:41:36 r1501 kernel: [66188.091664] Node 0 DMA per-cpu:
Dec 2 11:41:36 r1501 kernel: [66188.091672] CPU 0: hi: 0, btch: 1 usd: 0
Dec 2 11:41:36 r1501 kernel: [66188.091676] Node 0 DMA32 per-cpu:
Dec 2 11:41:36 r1501 kernel: [66188.091683] CPU 0: hi: 186, btch: 31 usd: 166
Dec 2 11:41:36 r1501 kernel: [66188.091696] active_anon:17400 inactive_anon:6480 isolated_anon:0
Dec 2 11:41:36 r1501 kernel: [66188.091699] active_file:19568 inactive_file:182537 isolated_file:0
Dec 2 11:41:36 r1501 kernel: [66188.091702] unevictable:0 dirty:9056 writeback:0 unstable:0
Dec 2 11:41:36 r1501 kernel: [66188.091705] free:1043 slab_reclaimable:8408 slab_unreclaimable:11649
Dec 2 11:41:36 r1501 kernel: [66188.091708] mapped:3851 shmem:133 pagetables:979 bounce:0
Dec 2 11:41:36 r1501 kernel: [66188.091715] Node 0 DMA free:4172kB min:52kB low:64kB high:76kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:9724kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15676kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:128kB slab_unreclaimable:428kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Dec 2 11:41:36 r1501 kernel: [66188.091743] lowmem_reserve[]: 0 1371 1371 1371
Dec 2 11:41:36 r1501 kernel: [66188.091752] Node 0 DMA32 free:0kB min:4708kB low:5884kB high:7060kB active_anon:69600kB inactive_anon:25920kB active_file:78272kB inactive_file:720424kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1404340kB mlocked:0kB dirty:36224kB writeback:0kB mapped:15404kB shmem:532kB slab_reclaimable:33504kB slab_unreclaimable:46168kB kernel_stack:2216kB pagetables:3916kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Dec 2 11:41:36 r1501 kernel: [66188.091782] lowmem_reserve[]: 0 0 0 0
Dec 2 11:41:36 r1501 kernel: [66188.091790] Node 0 DMA: 1_4kB 0_8kB 2_16kB 1_32kB 2_64kB 1_128kB 1_256kB 1_512kB 1_1024kB 1_2048kB 0_4096kB = 4164kB
Dec 2 11:41:36 r1501 kernel: [66188.091813] Node 0 DMA32: 0_4kB 0_8kB 0_16kB 0_32kB 0_64kB 0_128kB 0_256kB 0_512kB 0_1024kB 0_2048kB 0_4096kB = 0kB
Dec 2 11:41:36 r1501 kernel: [66188.091835] 202255 total pagecache pages
Dec 2 11:41:36 r1501 kernel: [66188.091839] 17 pages in swap cache
Dec 2 11:41:36 r1501 kernel: [66188.091845] Swap cache stats: add 81, delete 64, find 2/4
Dec 2 11:41:36 r1501 kernel: [66188.091849] Free swap = 1951488kB
Dec 2 11:41:36 r1501 kernel: [66188.091853] Total swap = 1951740kB
Dec 2 11:41:36 r1501 kernel: [66188.100026] 360032 pages RAM
Dec 2 11:41:36 r1501 kernel: [66188.100026] 8052 pages reserved
Dec 2 11:41:36 r1501 kernel: [66188.100026] 111216 pages shared
Dec 2 11:41:36 r1501 kernel: [66188.100026] 225380 pages non-shared
Dec 2 11:41:36 r1501 kernel: [66188.100026] SLUB: Unable to allocate memory on node -1 (gfp=0x20)
Dec 2 11:41:36 r1501 kernel: [66188.100026] cache: kmalloc-2048, object size: 2048, buffer size: 2048, default order: 2, min order: 0
Dec 2 11:41:36 r1501 kernel: [66188.100026] node 0: slabs: 73, objs: 584, free: 0
Dec 2 11:41:36 r1501 kernel: [66188.109042] z_wr_int/11: page allocation failure. order:0, mode:0x4020
Dec 2 11:41:36 r1501 kernel: [66188.109051] Pid: 784, comm: z_wr_int/11 Tainted: P 2.6.38-13-server #52-Ubuntu
Dec 2 11:41:36 r1501 kernel: [66188.109057] Call Trace:
Dec 2 11:41:36 r1501 kernel: [66188.109061] [] ? __alloc_pages_nodemask+0x5f4/0x830
Dec 2 11:41:36 r1501 kernel: [66188.109084] [] ? nommu_map_sg+0x72/0xf0
Dec 2 11:41:36 r1501 kernel: [66188.109096] [] ? ata_scsi_rw_xlat+0x0/0x1d0
Dec 2 11:41:36 r1501 kernel: [66188.109107] [] ? alloc_pages_current+0xa5/0x110
Dec 2 11:41:36 r1501 kernel: [66188.109116] [] ? new_slab+0x282/0x290
Dec 2 11:41:36 r1501 kernel: [66188.109125] [] ? __slab_alloc+0x262/0x390
Dec 2 11:41:36 r1501 kernel: [66188.109134] [] ? __netdev_alloc_skb+0x24/0x50
Dec 2 11:41:36 r1501 kernel: [66188.109144] [] ? __kmalloc_node_track_caller+0x8d/0x1a0
Dec 2 11:41:36 r1501 kernel: [66188.109152] [] ? __netdev_alloc_skb+0x24/0x50
Dec 2 11:41:36 r1501 kernel: [66188.109160] [] ? __alloc_skb+0x83/0x170
Dec 2 11:41:36 r1501 kernel: [66188.109168] [] ? __netdev_alloc_skb+0x24/0x50
Dec 2 11:41:36 r1501 kernel: [66188.109193] [] ? b44_rx+0x27b/0x2f0 [b44]
Dec 2 11:41:36 r1501 kernel: [66188.109205] [] ? b44_poll+0x11b/0x1dc [b44]
Dec 2 11:41:36 r1501 kernel: [66188.109215] [] ? scsi_finish_command+0xc5/0x130
Dec 2 11:41:36 r1501 kernel: [66188.109225] [] ? net_rx_action+0x128/0x270
Dec 2 11:41:36 r1501 kernel: [66188.109236] [] ? __do_softirq+0xa8/0x1c0
Dec 2 11:41:36 r1501 kernel: [66188.109246] [] ? ack_apic_level+0x78/0x1a0
Dec 2 11:41:36 r1501 kernel: [66188.109255] [] ? call_softirq+0x1c/0x30
Dec 2 11:41:36 r1501 kernel: [66188.109263] [] ? do_softirq+0x65/0xa0
Dec 2 11:41:36 r1501 kernel: [66188.109271] [] ? irq_exit+0x85/0x90
Dec 2 11:41:36 r1501 kernel: [66188.109280] [] ? do_IRQ+0x66/0xe0
Dec 2 11:41:36 r1501 kernel: [66188.109289] [] ? ret_from_intr+0x0/0x15
Dec 2 11:41:36 r1501 kernel: [66188.109294] [] ? memmove+0x81/0x1a0
Dec 2 11:41:36 r1501 kernel: [66188.109424] [] ? vdev_queue_io_to_issue+0x4f3/0x530 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.109504] [] ? vdev_queue_agg_io_done+0x0/0x80 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.109584] [] ? zio_wait_for_children+0x63/0x80 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.109664] [] ? vdev_queue_io_done+0x82/0xd0 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.109742] [] ? zio_vdev_io_done+0x88/0x190 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.109821] [] ? zio_execute+0xb0/0x150 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.109830] [] ? default_spin_lock_flags+0x9/0x10
Dec 2 11:41:36 r1501 kernel: [66188.109860] [] ? taskq_thread+0x1c0/0x390 [spl]
Dec 2 11:41:36 r1501 kernel: [66188.109870] [] ? default_wake_function+0x0/0x20
Dec 2 11:41:36 r1501 kernel: [66188.109889] [] ? taskq_thread+0x0/0x390 [spl]
Dec 2 11:41:36 r1501 kernel: [66188.109899] [] ? kthread+0x96/0xa0
Dec 2 11:41:36 r1501 kernel: [66188.109907] [] ? kernel_thread_helper+0x4/0x10
Dec 2 11:41:36 r1501 kernel: [66188.109916] [] ? kthread+0x0/0xa0
Dec 2 11:41:36 r1501 kernel: [66188.109924] [] ? kernel_thread_helper+0x0/0x10
Dec 2 11:41:36 r1501 kernel: [66188.109929] Mem-Info:
Dec 2 11:41:36 r1501 kernel: [66188.109933] Node 0 DMA per-cpu:
Dec 2 11:41:36 r1501 kernel: [66188.109939] CPU 0: hi: 0, btch: 1 usd: 0
Dec 2 11:41:36 r1501 kernel: [66188.109944] Node 0 DMA32 per-cpu:
Dec 2 11:41:36 r1501 kernel: [66188.109950] CPU 0: hi: 186, btch: 31 usd: 166
Dec 2 11:41:36 r1501 kernel: [66188.109962] active_anon:17400 inactive_anon:6480 isolated_anon:0
Dec 2 11:41:36 r1501 kernel: [66188.109965] active_file:19568 inactive_file:182537 isolated_file:0
Dec 2 11:41:36 r1501 kernel: [66188.109968] unevictable:0 dirty:9056 writeback:0 unstable:0
Dec 2 11:41:36 r1501 kernel: [66188.109971] free:1043 slab_reclaimable:8408 slab_unreclaimable:11649
Dec 2 11:41:36 r1501 kernel: [66188.109974] mapped:3851 shmem:133 pagetables:979 bounce:0
Dec 2 11:41:36 r1501 kernel: [66188.109981] Node 0 DMA free:4172kB min:52kB low:64kB high:76kB active_anon:0kB inactive_anon:0kB active_file:0kB inactive_file:9724kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:15676kB mlocked:0kB dirty:0kB writeback:0kB mapped:0kB shmem:0kB slab_reclaimable:128kB slab_unreclaimable:428kB kernel_stack:0kB pagetables:0kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Dec 2 11:41:36 r1501 kernel: [66188.110008] lowmem_reserve[]: 0 1371 1371 1371
Dec 2 11:41:36 r1501 kernel: [66188.110017] Node 0 DMA32 free:0kB min:4708kB low:5884kB high:7060kB active_anon:69600kB inactive_anon:25920kB active_file:78272kB inactive_file:720424kB unevictable:0kB isolated(anon):0kB isolated(file):0kB present:1404340kB mlocked:0kB dirty:36224kB writeback:0kB mapped:15404kB shmem:532kB slab_reclaimable:33504kB slab_unreclaimable:46168kB kernel_stack:2216kB pagetables:3916kB unstable:0kB bounce:0kB writeback_tmp:0kB pages_scanned:0 all_unreclaimable? no
Dec 2 11:41:36 r1501 kernel: [66188.110046] lowmem_reserve[]: 0 0 0 0
Dec 2 11:41:36 r1501 kernel: [66188.110054] Node 0 DMA: 1_4kB 0_8kB 2_16kB 1_32kB 2_64kB 1_128kB 1_256kB 1_512kB 1_1024kB 1_2048kB 0_4096kB = 4164kB
Dec 2 11:41:36 r1501 kernel: [66188.110078] Node 0 DMA32: 0_4kB 0_8kB 0_16kB 0_32kB 0_64kB 0_128kB 0_256kB 0_512kB 0_1024kB 0_2048kB 0_4096kB = 0kB
Dec 2 11:41:36 r1501 kernel: [66188.110099] 202255 total pagecache pages
Dec 2 11:41:36 r1501 kernel: [66188.110103] 17 pages in swap cache
Dec 2 11:41:36 r1501 kernel: [66188.110109] Swap cache stats: add 81, delete 64, find 2/4
Dec 2 11:41:36 r1501 kernel: [66188.110113] Free swap = 1951488kB
Dec 2 11:41:36 r1501 kernel: [66188.110117] Total swap = 1951740kB
Dec 2 11:41:36 r1501 kernel: [66188.118743] 360032 pages RAM
Dec 2 11:41:36 r1501 kernel: [66188.118743] 8052 pages reserved
Dec 2 11:41:36 r1501 kernel: [66188.118743] 111216 pages shared
Dec 2 11:41:36 r1501 kernel: [66188.118743] 225380 pages non-shared
Dec 2 11:41:36 r1501 kernel: [66188.118743] SLUB: Unable to allocate memory on node -1 (gfp=0x20)
Dec 2 11:41:36 r1501 kernel: [66188.118743] cache: kmalloc-2048, object size: 2048, buffer size: 2048, default order: 2, min order: 0
Dec 2 11:41:36 r1501 kernel: [66188.118743] node 0: slabs: 73, objs: 584, free: 0
Dec 2 11:41:36 r1501 kernel: [66188.126739] z_wr_int/11: page allocation failure. order:0, mode:0x4020
Dec 2 11:41:36 r1501 kernel: [66188.126748] Pid: 784, comm: z_wr_int/11 Tainted: P 2.6.38-13-server #52-Ubuntu
Dec 2 11:41:36 r1501 kernel: [66188.126753] Call Trace:
Dec 2 11:41:36 r1501 kernel: [66188.126757] [] ? __alloc_pages_nodemask+0x5f4/0x830
Dec 2 11:41:36 r1501 kernel: [66188.126779] [] ? radix_tree_lookup+0xb/0x10
Dec 2 11:41:36 r1501 kernel: [66188.126790] [] ? alloc_pages_current+0xa5/0x110
Dec 2 11:41:36 r1501 kernel: [66188.126800] [] ? new_slab+0x282/0x290
Dec 2 11:41:36 r1501 kernel: [66188.126810] [] ? ret_from_intr+0x0/0x15
Dec 2 11:41:36 r1501 kernel: [66188.126818] [] ? __slab_alloc+0x262/0x390
Dec 2 11:41:36 r1501 kernel: [66188.126828] [] ? __netdev_alloc_skb+0x24/0x50
Dec 2 11:41:36 r1501 kernel: [66188.126838] [] ? __kmalloc_node_track_caller+0x8d/0x1a0
Dec 2 11:41:36 r1501 kernel: [66188.126846] [] ? __netdev_alloc_skb+0x24/0x50
Dec 2 11:41:36 r1501 kernel: [66188.126854] [] ? __alloc_skb+0x83/0x170
Dec 2 11:41:36 r1501 kernel: [66188.126862] [] ? __netdev_alloc_skb+0x24/0x50
Dec 2 11:41:36 r1501 kernel: [66188.126884] [] ? b44_rx+0x27b/0x2f0 [b44]
Dec 2 11:41:36 r1501 kernel: [66188.126896] [] ? b44_poll+0x11b/0x1dc [b44]
Dec 2 11:41:36 r1501 kernel: [66188.126906] [] ? scsi_finish_command+0xc5/0x130
Dec 2 11:41:36 r1501 kernel: [66188.126917] [] ? net_rx_action+0x128/0x270
Dec 2 11:41:36 r1501 kernel: [66188.126927] [] ? __do_softirq+0xa8/0x1c0
Dec 2 11:41:36 r1501 kernel: [66188.126937] [] ? ack_apic_level+0x78/0x1a0
Dec 2 11:41:36 r1501 kernel: [66188.126947] [] ? call_softirq+0x1c/0x30
Dec 2 11:41:36 r1501 kernel: [66188.126955] [] ? do_softirq+0x65/0xa0
Dec 2 11:41:36 r1501 kernel: [66188.126963] [] ? irq_exit+0x85/0x90
Dec 2 11:41:36 r1501 kernel: [66188.126971] [] ? do_IRQ+0x66/0xe0
Dec 2 11:41:36 r1501 kernel: [66188.126979] [] ? ret_from_intr+0x0/0x15
Dec 2 11:41:36 r1501 kernel: [66188.126984] [] ? memmove+0x81/0x1a0
Dec 2 11:41:36 r1501 kernel: [66188.127106] [] ? vdev_queue_io_to_issue+0x4f3/0x530 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.127185] [] ? vdev_queue_agg_io_done+0x0/0x80 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.127265] [] ? zio_wait_for_children+0x63/0x80 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.127345] [] ? vdev_queue_io_done+0x82/0xd0 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.127423] [] ? zio_vdev_io_done+0x88/0x190 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.127502] [] ? zio_execute+0xb0/0x150 [zfs]
Dec 2 11:41:36 r1501 kernel: [66188.127511] [] ? default_spin_lock_flags+0x9/0x10
Dec 2 11:41:36 r1501 kernel: [66188.127540] [] ? taskq_thread+0x1c0/0x390 [spl]
Dec 2 11:41:36 r1501 kernel: [66188.127549] [] ? default_wake_function+0x0/0x20
Dec 2 11:41:36 r1501 kernel: [66188.127569] [] ? taskq_thread+0x0/0x390 [spl]
Dec 2 11:41:36 r1501 kernel: [66188.127578] [] ? kthread+0x96/0xa0
Dec 2 11:41:36 r1501 kernel: [66188.127587] [] ? kernel_thread_helper+0x4/0x10
Dec 2 11:41:36 r1501 kernel: [66188.127596] [] ? kthread+0x0/0xa0
Dec 2 11:41:36 r1501 kernel: [66188.127603] [] ? kernel_thread_helper+0x0/0x10

ryantig · 2011-12-16T21:35:10Z

fwiw - Now been back on zfs-fuse + BCM401, zero messages to kernel log. Working happy again. Think this system (low memory) will have to stick with zfs-fuse.

behlendorf · 2011-12-16T21:58:38Z

Definitely, stick with what works. Hopefully, we'll get zfs working better on low memory systems in the future.

behlendorf · 2012-09-18T01:43:40Z

The memory management improvements in master should resolve this issue.

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 <ryao@gentoo.org>

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 <richard.yao@clusterhq.com>

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 <richard.yao@clusterhq.com>

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 <ryao@gentoo.org>

Signed-off-by: Paul Dagnelie <pcd@delphix.com>

behlendorf closed this as completed Sep 18, 2012

ryao mentioned this issue Oct 9, 2014

vdev_raidz_io_start: Ignore empty writes #2778

Closed

ryao mentioned this issue Oct 10, 2014

Redispatch ZIOs in deep call graphs #2786

Closed

pcd1193182 added a commit to pcd1193182/zfs that referenced this issue Jun 27, 2022

DLPX-81523 test_repeated_reboots failed with core.zcachedb (openzfs#477)

2a65d44

Signed-off-by: Paul Dagnelie <pcd@delphix.com>

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

System wedge/lock. #477

System wedge/lock. #477

ryantig commented Dec 1, 2011

behlendorf commented Dec 1, 2011

ryantig commented Dec 1, 2011

ryantig commented Dec 2, 2011

behlendorf commented Dec 2, 2011

ryantig commented Dec 2, 2011

ryantig commented Dec 16, 2011

behlendorf commented Dec 16, 2011

behlendorf commented Sep 18, 2012

System wedge/lock. #477

System wedge/lock. #477

Comments

ryantig commented Dec 1, 2011

behlendorf commented Dec 1, 2011

ryantig commented Dec 1, 2011

ryantig commented Dec 2, 2011

behlendorf commented Dec 2, 2011

ryantig commented Dec 2, 2011

ryantig commented Dec 16, 2011

behlendorf commented Dec 16, 2011

behlendorf commented Sep 18, 2012