zfsonlinux/zfs — Issue #496: zio deadlock
Author: behlendorf
Created: 2011-12-14 17:55:32+00:00
State: open
Labels: Bug

After ZFS running smoothly after I reverted to a 3.0 kernel and limited the ARC size to 2GB (1/8th of memory), I got a lock up this morning.

At the time, there was a rsync going on from a remote machine onto a 6TiB ext4 FS mounted on top of a sparse zvol (with compression), and a ddrescue running on remote host onto a zvol served over nbd (nbd-server exporting the zvol) again with
compression and with a block size of 4kiB.

At the time, ddrescue was dumping zeros so highly compressable data.

Hold on, another similar lockup again after I've rebooted it and resumed the ddrescue. This time, no rsync running, just the
nbd-server, but it booted into 3.1.4 (my mistake). Here is some serial console capture (on the first occurrence)

[501360.008635] zvol/2 D ffffffff81605120 0 496 2 0x00000000
[501360.008635] ffff88020c7adc20 0000000000000046 0000000000000001 ffff8804124902e0
[501360.008635] ffff88020c7adfd8 ffff88020c7adfd8 ffff88020c7adfd8 0000000000012a40
[501360.008635] ffff8802130e1720 ffff88020c7a2e40 ffff88020c7adc30 ffff880412490330
[501360.008635] Call Trace:
[501360.008635] [] schedule+0x3f/0x60
[501360.008635] [] cv_wait_common+0x77/0xd0 [spl]
[501360.008635] [] ? add_wait_queue+0x60/0x60
[501360.008635] [] __cv_wait+0x13/0x20 [spl]
[501360.008635] [] txg_wait_open+0x73/0xa0 [zfs]
[501360.008635] [] dmu_tx_wait+0xed/0xf0 [zfs]
[501360.008635] [] dmu_tx_assign+0x66/0x420 [zfs]
[501360.008635] [] ? dsl_dataset_block_freeable+0x40/0x60 [zfs]
[501360.008635] [] zvol_write+0x7f/0x3a0 [zfs]
[501360.008635] [] ? default_spin_lock_flags+0x9/0x10
[501360.008635] [] taskq_thread+0x1b5/0x390 [spl]
[501360.008635] [] ? try_to_wake_up+0x200/0x200
[501360.008635] [] ? task_alloc+0x160/0x160 [spl]
[501360.008635] [] kthread+0x8c/0xa0
[501360.008635] [] kernel_thread_helper+0x4/0x10
[501360.008635] [] ? flush_kthread_worker+0xa0/0xa0
[501360.008635] [] ? gs_change+0x13/0x13

[501360.008635] txg_sync D 0000000000000002 0 901 2 0x00000000
[501360.008635] ffff880207679580 0000000000000046 ffffffff815f318e ffff880207679600
[501360.008635] ffff880207679fd8 ffff880207679fd8 ffff880207679fd8 0000000000012a40
[501360.008635] ffff880209d90000 ffff88020983ae40 ffff880207679fd8 ffff8800218d24c0
[501360.008635] Call Trace:
[501360.008635] [] ? apic_timer_interrupt+0xe/0x20
[501360.008635] [] schedule+0x3f/0x60
[501360.008635] [] __mutex_lock_slowpath+0xd7/0x150
[501360.008635] [] ? __kmalloc+0x13d/0x190
[501360.008635] [] mutex_lock+0x2a/0x50
[501360.008635] [] zio_add_child+0x61/0x120 [zfs]
[501360.008635] [] zio_create+0x426/0x520 [zfs]
[501360.008635] [] zio_write+0x7c/0xa0 [zfs]
[501360.008635] [] ? arc_evict_ghost+0x350/0x350 [zfs]
[501360.008635] [] arc_write+0xcf/0xf0 [zfs]
[501360.008635] [] ? arc_cksum_compute.isra.16+0xc0/0xc0 [zfs]
[501360.008635] [] ? arc_evict_ghost+0x350/0x350 [zfs]
[501360.008635] [] dbuf_write.isra.8+0x19d/0x330 [zfs]
[501360.008635] [] ? dbuf_destroy+0x170/0x170 [zfs]
[501360.008635] [] ? dbuf_rele_and_unlock+0x210/0x210 [zfs]
[501360.008635] [] ? mutex_lock+0x1d/0x50
[501360.008635] [] dbuf_sync_leaf+0xd4/0x320 [zfs]
[501360.008635] [] dbuf_sync_list+0x95/0xa0 [zfs]
[501360.008635] [] dbuf_sync_indirect+0xa2/0x110 [zfs]
[501360.008635] [] dbuf_sync_list+0x77/0xa0 [zfs]
[501360.008635] [] dbuf_sync_indirect+0xa2/0x110 [zfs]
[501360.008635] [] dbuf_sync_list+0x77/0xa0 [zfs]
[501360.008635] [] dbuf_sync_indirect+0xa2/0x110 [zfs]
[501360.008635] [] dbuf_sync_list+0x77/0xa0 [zfs]
[501360.008635] [] dbuf_sync_indirect+0xa2/0x110 [zfs]
[501360.008635] [] dbuf_sync_list+0x77/0xa0 [zfs]
[501360.008635] [] dnode_sync+0x557/0xa40 [zfs]
[501360.008635] [] ? dbuf_sync_list+0x77/0xa0 [zfs]
[501360.008635] [] ? arc_write+0xcf/0xf0 [zfs]
[501360.008635] [] dmu_objset_sync_dnodes+0xbb/0xe0 [zfs]
[501360.008635] [] dmu_objset_sync+0x198/0x330 [zfs]
[501360.008635] [] ? secondary_cache_changed_cb+0x20/0x20 [zfs]
[501360.008635] [] ? dmu_objset_sync+0x330/0x330 [zfs]
[501360.008635] [] ? mutex_lock+0x1d/0x50
[501360.008635] [] dsl_dataset_sync+0x57/0x70 [zfs]
[501360.008635] [] dsl_pool_sync+0xb1/0x450 [zfs]
[501360.008635] [] spa_sync+0x38e/0xa00 [zfs]
[501360.008635] [] ? __wake_up+0x53/0x70
[501360.008635] [] ? __wake_up+0x53/0x70
[501360.008635] [] txg_sync_thread+0x216/0x390 [zfs]
[501360.008635] [] ? txg_init+0x260/0x260 [zfs]
[501360.008635] [] ? txg_init+0x260/0x260 [zfs]
[501360.008635] [] thread_generic_wrapper+0x78/0x90 [spl]
[501360.008635] [] ? __thread_create+0x160/0x160 [spl]
[501360.008635] [] kthread+0x8c/0xa0
[501360.008635] [] kernel_thread_helper+0x4/0x10

[501360.008635] z_wr_iss/0 D 0000000000000000 0 737 2 0x00000000
[501360.008635] ffff880209d89d00 0000000000000046 ffffffff815f318e ffff880209d89d80
[501360.008635] ffff880209d89fd8 ffff880209d89fd8 ffff880209d89fd8 0000000000012a40
[501360.008635] ffff88020fa31720 ffff880209d84560 ffff8800218d24c0 ffff8800218d24c0
[501360.008635] Call Trace:
[501360.008635] [] ? apic_timer_interrupt+0xe/0x20
[501360.008635] [] schedule+0x3f/0x60
[501360.008635] [] __mutex_lock_slowpath+0xd7/0x150
[501360.008635] [] ? dbuf_write_ready+0x122/0x1c0 [zfs]
[501360.008635] [] mutex_lock+0x2a/0x50
[501360.008635] [] zio_ready+0x1e0/0x3b0 [zfs]
[501360.008635] [] zio_execute+0x9f/0xf0 [zfs]
[501360.008635] [] taskq_thread+0x1b5/0x390 [spl]
[501360.008635] [] ? try_to_wake_up+0x200/0x200
[501360.008635] [] ? task_alloc+0x160/0x160 [spl]
[501360.008635] [] kthread+0x8c/0xa0
[501360.008635] [] kernel_thread_helper+0x4/0x10
[501360.008635] [] ? flush_kthread_worker+0xa0/0xa0
[501360.008635] [] ? gs_change+0x13/0x13
[501360.008635] z_wr_iss/6 D 0000000000000006 0 743 2 0x00000000
[501360.008635] ffff880209d9dd00 0000000000000046 ffffffff815f318e ffff880209d9dd80
[501360.008635] ffff880209d9dfd8 ffff880209d9dfd8 ffff880209d9dfd8 0000000000012a40
[501360.008635] ffff880209d6ae40 ffff880209d95c80 ffff8800218d24c0 ffff8800218d24c0
[501360.008635] Call Trace:
[501360.008635] [] ? apic_timer_interrupt+0xe/0x20
[501360.008635] [] schedule+0x3f/0x60
[501360.008635] [] __mutex_lock_slowpath+0xd7/0x150
[501360.008635] [] ? dbuf_write_ready+0x122/0x1c0 [zfs]
[501360.008635] [] mutex_lock+0x2a/0x50
[501360.008635] [] zio_ready+0x1e0/0x3b0 [zfs]
[501360.008635] [] zio_execute+0x9f/0xf0 [zfs]
[501360.008635] [] taskq_thread+0x1b5/0x390 [spl]
[501360.008635] [] ? try_to_wake_up+0x200/0x200
[501360.008635] [] ? task_alloc+0x160/0x160 [spl]
[501360.008635] [] kthread+0x8c/0xa0
[501360.008635] [] kernel_thread_helper+0x4/0x10
[501360.008635] [] ? flush_kthread_worker+0xa0/0xa0
[501360.008635] [] ? gs_change+0x13/0x13
[501360.008635] z_wr_iss/11 D 000000000000000b 0 748 2 0x00000000
[501360.008635] ffff880209dbfd00 0000000000000046 ffffffff815f318e ffff880209dbfd80
[501360.008635] ffff880209dbffd8 ffff880209dbffd8 ffff880209dbffd8 0000000000012a40
[501360.008635] ffff880209d82e40 ffff880209dadc80 ffff8800218d24c0 ffff8800218d24c0
[501360.008635] Call Trace:
[501360.008635] [] ? apic_timer_interrupt+0xe/0x20
[501360.008635] [] schedule+0x3f/0x60
[501360.008635] [] __mutex_lock_slowpath+0xd7/0x150
[501360.008635] [] ? dbuf_write_ready+0x122/0x1c0 [zfs]
[501360.008635] [] mutex_lock+0x2a/0x50
[501360.008635] [] zio_ready+0x1e0/0x3b0 [zfs]
[501360.008635] [] zio_execute+0x9f/0xf0 [zfs]
[501360.008635] [] taskq_thread+0x1b5/0x390 [spl]
[501360.008635] [] ? try_to_wake_up+0x200/0x200
[501360.008635] [] ? task_alloc+0x160/0x160 [spl]
[501360.008635] [] kthread+0x8c/0xa0
[501360.008635] [] kernel_thread_helper+0x4/0x10
[501360.008635] [] ? flush_kthread_worker+0xa0/0xa0
[501360.008635] [] ? gs_change+0x13/0x13