zfs related deadlock in kswapd

[akorn]

Hi,

I just received the following:

kern: kern.err: Jan 13 02:49:23 kernel: INFO: task kswapd0:549 blocked for more than 3600 seconds.
kern: kern.err: Jan 13 02:49:23 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kern: kern.info: Jan 13 02:49:23 kernel: kswapd0         D ffff8804032bb148     0   549      2 0x00000000
kern: kern.notice: Jan 13 02:49:23 kernel:  ffff8804032c3960 0000000000000046 ffff8804032bada0 0000000000000008
kern: kern.notice: Jan 13 02:49:23 kernel:  ffff8804032bada0 ffff8804032c3fd8 ffff8804032c3fd8 ffff8804032c3fd8
kern: kern.notice: Jan 13 02:49:23 kernel:  ffff8804054d5b40 ffff8804032bada0 ffff8804032c3980 0000000000000297
kern: kern.notice: Jan 13 02:49:23 kernel: Call Trace:
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff815e0dca>] schedule+0x3a/0x50
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff815e289d>] rwsem_down_failed_common+0xcd/0x160
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff815e2943>] rwsem_down_write_failed+0x13/0x20
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff81308a33>] call_rwsem_down_write_failed+0x13/0x20
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff815e1e10>] ? down_write+0x20/0x22
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffffa0191566>] dnode_evict_dbufs+0x1a6/0x310 [zfs]
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff81132a9c>] ? move_active_pages_to_lru+0x16c/0x1b0
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff815e2999>] ? _raw_spin_lock+0x9/0x10
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff81053609>] ? sched_clock+0x9/0x10
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff8108c3f8>] ? try_to_wake_up+0x228/0x290
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff815e1a3e>] ? __mutex_lock_slowpath+0x3e/0x140
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffffa0184490>] dmu_objset_evict_dbufs+0x170/0x1d0 [zfs]
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffffa0205487>] zpl_free_cached_objects+0x17/0x20 [zfs]
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff8117f739>] prune_super+0x109/0x1a0
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff81132d59>] shrink_slab+0x139/0x2e0
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff811365c2>] balance_pgdat+0x522/0x6e0
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff81136888>] kswapd+0x108/0x3d0
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff815e082c>] ? __schedule+0x3bc/0x890
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff810b6090>] ? add_wait_queue+0x60/0x60
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff81136780>] ? balance_pgdat+0x6e0/0x6e0
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff810b5667>] kthread+0x87/0x90
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff815e4d34>] kernel_thread_helper+0x4/0x10
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff810b55e0>] ? flush_kthread_worker+0xa0/0xa0
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff815e4d30>] ? gs_change+0x13/0x13
kern: kern.notice: Jan 13 02:49:23 kernel: Pid: 543, comm: khungtaskd Tainted: P            3.1.6-vs2.3.2.5-newjayhawk #4
2012-01-13T02:49:23+01:00 kern: <0>Jan 13 02:49:23 kernel: Kernel panic - not syncing: hung_task: blocked tasks
kern: kern.notice: Jan 13 02:49:23 kernel: Call Trace:
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff815d8818>] panic+0x8c/0x19b
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff810f5016>] watchdog+0x206/0x210
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff810f4e10>] ? hung_task_panic+0x20/0x20
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff810b5667>] kthread+0x87/0x90
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff815e4d34>] kernel_thread_helper+0x4/0x10
kern: kern.notice: Jan 13 02:49:23 kernel:  [<ffffffff810b55e0>] ? flush_kthread_worker+0xa0/0xa0

Note that I had increased the hung task timeout to 3600s.

Andras

[behlendorf]

Thanks for the heads up, there may be some subtle issue which crept in with commit ab26409

[chrisrd]

Looks like I may have just run into this w/ openzfs/spl@5d139aa, 49be0cc + behlendorf/zfs@2a349bd, linux-3.3.0:

[12582.873335] INFO: task kswapd0:78 blocked for more than 120 seconds.
[12582.873401] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[12582.873480] kswapd0         D 0000000000000009     0    78      2 0x00000000
[12582.873606]  ffff88062040f848 0000000000000046 ffff880c2032aca0 0000000000013200
[12582.873812]  ffff88062040ffd8 ffff88062040e010 0000000000013200 0000000000013200
[12582.874018]  ffff88062040ffd8 0000000000013200 ffff88060a3eaca0 ffff880c2032aca0
[12582.874223] Call Trace:
[12582.874280]  [<ffffffff813cc7ae>] ? _raw_spin_lock+0xe/0x20
[12582.874339]  [<ffffffff813cbacf>] schedule+0x3f/0x60
[12582.874397]  [<ffffffff813cc69d>] rwsem_down_failed_common+0xcd/0x170
[12582.874457]  [<ffffffff813cc775>] rwsem_down_read_failed+0x15/0x17
[12582.874517]  [<ffffffff811f8634>] call_rwsem_down_read_failed+0x14/0x30
[12582.874580]  [<ffffffff813ca987>] ? down_read+0x17/0x20
[12582.874663]  [<ffffffffa04afe24>] dnode_hold_impl+0xb4/0x550 [zfs]
[12582.874723]  [<ffffffff8113145a>] ? discard_slab+0x3a/0x50
[12582.874781]  [<ffffffff811327e7>] ? __slab_free+0x307/0x350
[12582.874853]  [<ffffffffa0495f99>] ? dbuf_rele_and_unlock+0x159/0x210 [zfs]
[12582.874930]  [<ffffffffa04b02d9>] dnode_hold+0x19/0x20 [zfs]
[12582.875002]  [<ffffffffa049dbc2>] dmu_free_long_range+0x32/0x70 [zfs]
[12582.875085]  [<ffffffffa0500070>] zfs_rmnode+0x60/0x340 [zfs]
[12582.875165]  [<ffffffffa04cfa8f>] ? sa_handle_destroy+0x8f/0xa0 [zfs]
[12582.876482]  [<ffffffffa051bebe>] zfs_zinactive+0x9e/0x100 [zfs]
[12582.876564]  [<ffffffffa051af4a>] zfs_inactive+0x6a/0x1e0 [zfs]
[12582.876625]  [<ffffffff810f549e>] ? truncate_pagecache+0x5e/0x70
[12582.876706]  [<ffffffffa052bcc8>] zpl_evict_inode+0x28/0x30 [zfs]
[12582.876766]  [<ffffffff8115986f>] evict+0xaf/0x1b0
[12582.876822]  [<ffffffff81159ecf>] dispose_list+0x4f/0x60
[12582.876880]  [<ffffffff8115a07d>] prune_icache_sb+0x19d/0x390
[12582.876938]  [<ffffffff8115819d>] ? prune_dcache_sb+0x18d/0x1c0
[12582.876998]  [<ffffffff811426e8>] prune_super+0xe8/0x1d0
[12582.877057]  [<ffffffff810f8f9f>] shrink_slab+0x19f/0x2e0
[12582.877115]  [<ffffffff810fbd67>] balance_pgdat+0x667/0x8d0
[12582.877173]  [<ffffffff810fc1ad>] kswapd+0x1dd/0x410
[12582.877231]  [<ffffffff8106b8b0>] ? wake_up_bit+0x40/0x40
[12582.877289]  [<ffffffff810fbfd0>] ? balance_pgdat+0x8d0/0x8d0
[12582.877347]  [<ffffffff8106b35e>] kthread+0x9e/0xb0
[12582.877405]  [<ffffffff813d5be4>] kernel_thread_helper+0x4/0x10
[12582.877464]  [<ffffffff8106b2c0>] ? kthread_freezable_should_stop+0x70/0x70
[12582.877524]  [<ffffffff813d5be0>] ? gs_change+0x13/0x13

[12582.877604] INFO: task zfs_iput_taskq/:8933 blocked for more than 120 seconds.
[12582.877677] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[12582.877751] zfs_iput_taskq/ D 0000000000000000     0  8933      2 0x00000000
[12582.877877]  ffff8806090a5868 0000000000000046 ffff880609d50000 0000000000013200
[12582.878082]  ffff8806090a5fd8 ffff8806090a4010 0000000000013200 0000000000013200
[12582.878287]  ffff8806090a5fd8 0000000000013200 ffff880623938000 ffff880609d50000
[12582.878493] Call Trace:
[12582.878545]  [<ffffffff813cbacf>] schedule+0x3f/0x60
[12582.878602]  [<ffffffff813cc69d>] rwsem_down_failed_common+0xcd/0x170
[12582.878663]  [<ffffffff813cc775>] rwsem_down_read_failed+0x15/0x17
[12582.878722]  [<ffffffff811f8634>] call_rwsem_down_read_failed+0x14/0x30
[12582.878782]  [<ffffffff813ca987>] ? down_read+0x17/0x20
[12582.878856]  [<ffffffffa04afe24>] dnode_hold_impl+0xb4/0x550 [zfs]
[12582.878915]  [<ffffffff81133989>] ? __kmalloc+0x39/0x150
[12582.878990]  [<ffffffffa04b02d9>] dnode_hold+0x19/0x20 [zfs]
[12582.879062]  [<ffffffffa049e44d>] dmu_buf_hold+0x4d/0x1a0 [zfs]
[12582.879144]  [<ffffffffa04f2f70>] ? zap_idx_to_blk+0x140/0x140 [zfs]
[12582.879226]  [<ffffffffa04f41ef>] zap_get_leaf_byblk+0x4f/0x290 [zfs]
[12582.879296]  [<ffffffffa048e265>] ? arc_buf_remove_ref+0xd5/0x130 [zfs]
[12582.879380]  [<ffffffffa04f449a>] zap_deref_leaf+0x6a/0x80 [zfs]
[12582.879463]  [<ffffffffa04f549c>] fzap_cursor_retrieve+0xfc/0x290 [zfs]
[12582.879523]  [<ffffffff813cc7ae>] ? _raw_spin_lock+0xe/0x20
[12582.879581]  [<ffffffff81159add>] ? iput+0x16d/0x230
[12582.879661]  [<ffffffffa04f9edb>] zap_cursor_retrieve+0x13b/0x2a0 [zfs]
[12582.879744]  [<ffffffffa04fff63>] zfs_unlinked_drain+0x63/0x110 [zfs]
[12582.879803]  [<ffffffff811326c6>] ? __slab_free+0x1e6/0x350
[12582.879862]  [<ffffffff810786e5>] ? ttwu_do_wakeup+0x45/0x100
[12582.879921]  [<ffffffff81080458>] ? update_curr+0x168/0x170
[12582.879979]  [<ffffffff8107da40>] ? __dequeue_entity+0x30/0x50
[12582.880039]  [<ffffffff81011563>] ? __switch_to+0x153/0x440
[12582.880097]  [<ffffffff81080123>] ? set_next_entity+0x93/0xa0
[12582.880155]  [<ffffffff81078e73>] ? finish_task_switch+0x53/0x100
[12582.880222]  [<ffffffffa03dc2b7>] taskq_thread+0x237/0x5e0 [spl]
[12582.880281]  [<ffffffff8107b480>] ? try_to_wake_up+0x2d0/0x2d0
[12582.880343]  [<ffffffffa03dc080>] ? task_alloc+0x380/0x380 [spl]
[12582.880402]  [<ffffffff8106b35e>] kthread+0x9e/0xb0
[12582.880459]  [<ffffffff813d5be4>] kernel_thread_helper+0x4/0x10
[12582.880518]  [<ffffffff8106b2c0>] ? kthread_freezable_should_stop+0x70/0x70
[12582.880578]  [<ffffffff813d5be0>] ? gs_change+0x13/0x13

[12582.880635] INFO: task txg_quiesce:8935 blocked for more than 120 seconds.
[12582.880694] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[12582.880769] txg_quiesce     D ffffffff81407920     0  8935      2 0x00000000
[12582.880894]  ffff880607977d40 0000000000000046 ffff880609d542f0 0000000000013200
[12582.881099]  ffff880607977fd8 ffff880607976010 0000000000013200 0000000000013200
[12582.881305]  ffff880607977fd8 0000000000013200 ffff8806245d8000 ffff880609d542f0
[12582.881509] Call Trace:
[12582.881562]  [<ffffffff813cbacf>] schedule+0x3f/0x60
[12582.881624]  [<ffffffffa03e2f6c>] cv_wait_common+0x9c/0x1a0 [spl]
[12582.881683]  [<ffffffff8106b8b0>] ? wake_up_bit+0x40/0x40
[12582.881745]  [<ffffffffa03e30a3>] __cv_wait+0x13/0x20 [spl]
[12582.881825]  [<ffffffffa04e51db>] txg_quiesce_thread+0x1eb/0x330 [zfs]
[12582.881886]  [<ffffffff81077a80>] ? set_user_nice+0xf0/0x190
[12582.881965]  [<ffffffffa04e4ff0>] ? txg_sync_thread+0x490/0x490 [zfs]
[12582.882029]  [<ffffffffa03db290>] ? __thread_create+0x360/0x360 [spl]
[12582.882092]  [<ffffffffa03db308>] thread_generic_wrapper+0x78/0x90 [spl]
[12582.882156]  [<ffffffffa03db290>] ? __thread_create+0x360/0x360 [spl]
[12582.882215]  [<ffffffff8106b35e>] kthread+0x9e/0xb0
[12582.882272]  [<ffffffff813d5be4>] kernel_thread_helper+0x4/0x10
[12582.882331]  [<ffffffff8106b2c0>] ? kthread_freezable_should_stop+0x70/0x70
[12582.882391]  [<ffffffff813d5be0>] ? gs_change+0x13/0x13

[12582.882452] INFO: task tar-otn:16310 blocked for more than 120 seconds.
[12582.882510] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[12582.882584] tar-otn         D ffffffff81407920     0 16310  16309 0x00000000
[12582.882710]  ffff8804c6af9938 0000000000000086 ffff8806226a2ca0 0000000000013200
[12582.882915]  ffff8804c6af9fd8 ffff8804c6af8010 0000000000013200 0000000000013200
[12582.883120]  ffff8804c6af9fd8 0000000000013200 ffff880624650000 ffff8806226a2ca0
[12582.883332] Call Trace:
[12582.883387]  [<ffffffff813cbacf>] schedule+0x3f/0x60
[12582.883445]  [<ffffffff813cc69d>] rwsem_down_failed_common+0xcd/0x170
[12582.883506]  [<ffffffff813cc753>] rwsem_down_write_failed+0x13/0x20
[12582.883566]  [<ffffffff811f8663>] call_rwsem_down_write_failed+0x13/0x20
[12582.883627]  [<ffffffff813ca9b5>] ? down_write+0x25/0x30
[12582.883701]  [<ffffffffa04b0374>] dnode_new_blkid+0x94/0x2f0 [zfs]
[12582.883773]  [<ffffffffa04985a6>] dbuf_dirty+0x576/0x780 [zfs]
[12582.883847]  [<ffffffffa04a4057>] ? dmu_objset_userquota_get_ids+0x2d7/0x400 [zfs]
[12582.883939]  [<ffffffffa04adbd2>] dnode_setdirty+0x112/0x1a0 [zfs]
[12582.884014]  [<ffffffffa04adf56>] dnode_allocate+0x126/0x240 [zfs]
[12582.884089]  [<ffffffffa04a0695>] dmu_object_alloc+0x175/0x1c0 [zfs]
[12582.884171]  [<ffffffffa04f93b2>] zap_create_norm+0x32/0x60 [zfs]
[12582.884252]  [<ffffffffa051e9bc>] zfs_mknode+0xbbc/0xc70 [zfs]
[12582.884330]  [<ffffffffa04be61f>] ? dsl_dir_tempreserve_space+0x1bf/0x1f0 [zfs]
[12582.884427]  [<ffffffffa04e4331>] ? txg_rele_to_quiesce+0x11/0x20 [zfs]
[12582.884503]  [<ffffffffa04aa4e1>] ? dmu_tx_assign+0x3e1/0x480 [zfs]
[12582.884585]  [<ffffffffa051749c>] zfs_mkdir+0x45c/0x590 [zfs]
[12582.884666]  [<ffffffffa052b87e>] zpl_mkdir+0x9e/0xe0 [zfs]
[12582.884726]  [<ffffffff8114b905>] vfs_mkdir+0x85/0xc0
[12582.884783]  [<ffffffff8114f2c4>] sys_mkdirat+0xc4/0xe0
[12582.884842]  [<ffffffff813d4929>] system_call_fastpath+0x16/0x1b

[12582.884905] INFO: task rsync:30514 blocked for more than 120 seconds.
[12582.884963] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[12582.885038] rsync           D ffffffff81407920     0 30514  30513 0x00000000
[12582.885163]  ffff8803523058f0 0000000000000082 ffff880609d142f0 0000000000013200
[12582.885369]  ffff880352305fd8 ffff880352304010 0000000000013200 0000000000013200
[12582.885575]  ffff880352305fd8 0000000000013200 ffff8806245c0000 ffff880609d142f0
[12582.885783] Call Trace:
[12582.885835]  [<ffffffff81078e73>] ? finish_task_switch+0x53/0x100
[12582.885895]  [<ffffffff813cbacf>] schedule+0x3f/0x60
[12582.885952]  [<ffffffff813cc69d>] rwsem_down_failed_common+0xcd/0x170
[12582.886013]  [<ffffffff813cc775>] rwsem_down_read_failed+0x15/0x17
[12582.886072]  [<ffffffff811f8634>] call_rwsem_down_read_failed+0x14/0x30
[12582.886133]  [<ffffffff813ca987>] ? down_read+0x17/0x20
[12582.886207]  [<ffffffffa04afe24>] dnode_hold_impl+0xb4/0x550 [zfs]
[12582.886289]  [<ffffffffa0527663>] ? zio_wait+0x113/0x160 [zfs]
[12582.886364]  [<ffffffffa04b02d9>] dnode_hold+0x19/0x20 [zfs]
[12582.886436]  [<ffffffffa049e44d>] dmu_buf_hold+0x4d/0x1a0 [zfs]
[12582.886495]  [<ffffffff81133a1d>] ? __kmalloc+0xcd/0x150
[12582.886575]  [<ffffffffa04f41ef>] zap_get_leaf_byblk+0x4f/0x290 [zfs]
[12582.886657]  [<ffffffffa04f8160>] ? mzap_normalization_conflict+0x140/0x140 [zfs]
[12582.886756]  [<ffffffffa04f449a>] zap_deref_leaf+0x6a/0x80 [zfs]
[12582.886838]  [<ffffffffa04f549c>] fzap_cursor_retrieve+0xfc/0x290 [zfs]
[12582.886921]  [<ffffffffa04f9edb>] zap_cursor_retrieve+0x13b/0x2a0 [zfs]
[12582.886982]  [<ffffffff81038d59>] ? default_spin_lock_flags+0x9/0x10
[12582.887056]  [<ffffffffa049e9b0>] ? dmu_prefetch+0x130/0x1f0 [zfs]
[12582.887138]  [<ffffffffa0516d1d>] zfs_readdir+0x15d/0x480 [zfs]
[12582.887197]  [<ffffffff811519c0>] ? sys_ioctl+0x80/0x80
[12582.887256]  [<ffffffff81002e2e>] ? xen_apic_write+0x1e/0x20
[12582.887315]  [<ffffffff8114e33b>] ? path_openat+0x10b/0x3b0
[12582.887374]  [<ffffffff8110ed70>] ? handle_mm_fault+0x1d0/0x360
[12582.887432]  [<ffffffff811519c0>] ? sys_ioctl+0x80/0x80
[12582.887511]  [<ffffffffa052ac5c>] zpl_readdir+0x5c/0x90 [zfs]
[12582.887570]  [<ffffffff81151b30>] vfs_readdir+0xa0/0xc0
[12582.887627]  [<ffffffff811519c0>] ? sys_ioctl+0x80/0x80
[12582.887684]  [<ffffffff81151cb5>] sys_getdents+0x85/0xf0
[12582.887741]  [<ffffffff813ccef5>] ? page_fault+0x25/0x30
[12582.887799]  [<ffffffff813d4929>] system_call_fastpath+0x16/0x1b

[12582.887862] INFO: task tar-otn:32334 blocked for more than 120 seconds.
[12582.887921] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[12582.887995] tar-otn         D 0000000000000002     0 32334  32333 0x00000000
[12582.888120]  ffff880a37997170 0000000000000082 ffff88081147aca0 0000000000013200
[12582.888326]  ffff880a37997fd8 ffff880a37996010 0000000000013200 0000000000013200
[12582.888532]  ffff880a37997fd8 0000000000013200 ffff88062393aca0 ffff88081147aca0
[12582.888736] Call Trace:
[12582.888789]  [<ffffffff813cbacf>] schedule+0x3f/0x60
[12582.888846]  [<ffffffff813cc69d>] rwsem_down_failed_common+0xcd/0x170
[12582.888907]  [<ffffffff813cc775>] rwsem_down_read_failed+0x15/0x17
[12582.888966]  [<ffffffff811f8634>] call_rwsem_down_read_failed+0x14/0x30
[12582.889026]  [<ffffffff813ca987>] ? down_read+0x17/0x20
[12582.889100]  [<ffffffffa04afe24>] dnode_hold_impl+0xb4/0x550 [zfs]
[12582.890351]  [<ffffffffa048e265>] ? arc_buf_remove_ref+0xd5/0x130 [zfs]
[12582.890425]  [<ffffffffa0495f99>] ? dbuf_rele_and_unlock+0x159/0x210 [zfs]
[12582.890502]  [<ffffffffa04b02d9>] dnode_hold+0x19/0x20 [zfs]
[12582.890574]  [<ffffffffa049dbc2>] dmu_free_long_range+0x32/0x70 [zfs]
[12582.890656]  [<ffffffffa0500070>] zfs_rmnode+0x60/0x340 [zfs]
[12582.890735]  [<ffffffffa04cfa8f>] ? sa_handle_destroy+0x8f/0xa0 [zfs]
[12582.890817]  [<ffffffffa051bebe>] zfs_zinactive+0x9e/0x100 [zfs]
[12582.890898]  [<ffffffffa051af4a>] zfs_inactive+0x6a/0x1e0 [zfs]
[12582.890958]  [<ffffffff810f549e>] ? truncate_pagecache+0x5e/0x70
[12582.891038]  [<ffffffffa052bcc8>] zpl_evict_inode+0x28/0x30 [zfs]
[12582.891098]  [<ffffffff8115986f>] evict+0xaf/0x1b0
[12582.891154]  [<ffffffff81159ecf>] dispose_list+0x4f/0x60
[12582.891212]  [<ffffffff8115a07d>] prune_icache_sb+0x19d/0x390
[12582.891270]  [<ffffffff8115819d>] ? prune_dcache_sb+0x18d/0x1c0
[12582.891330]  [<ffffffff811426e8>] prune_super+0xe8/0x1d0
[12582.891387]  [<ffffffff810f8f9f>] shrink_slab+0x19f/0x2e0
[12582.891445]  [<ffffffff810faf39>] do_try_to_free_pages+0x1e9/0x460
[12582.891504]  [<ffffffff810fb24b>] try_to_free_pages+0x9b/0x120
[12582.891563]  [<ffffffff810efbdb>] __alloc_pages_nodemask+0x44b/0x810
[12582.891636]  [<ffffffffa048d61e>] ? arc_buf_destroy+0x4e/0x170 [zfs]
[12582.891697]  [<ffffffff81128333>] alloc_pages_current+0x83/0xf0
[12582.891755]  [<ffffffff81130be5>] new_slab+0x275/0x320
[12582.891813]  [<ffffffff81132c41>] __slab_alloc+0x131/0x480
[12582.891874]  [<ffffffffa03d9c8b>] ? kmem_alloc_debug+0x1eb/0x350 [spl]
[12582.891934]  [<ffffffff81133a30>] __kmalloc+0xe0/0x150
[12582.891991]  [<ffffffff81131ec8>] ? get_partial_node+0x1e8/0x1f0
[12582.892054]  [<ffffffffa03d9c8b>] kmem_alloc_debug+0x1eb/0x350 [spl]
[12582.892128]  [<ffffffffa0497a58>] dbuf_hold_impl+0x58/0xc0 [zfs]
[12582.892200]  [<ffffffffa0498b60>] dbuf_hold+0x20/0x30 [zfs]
[12582.892275]  [<ffffffffa04afe45>] dnode_hold_impl+0xd5/0x550 [zfs]
[12582.892334]  [<ffffffff81133a1d>] ? __kmalloc+0xcd/0x150
[12582.892408]  [<ffffffffa04b02d9>] dnode_hold+0x19/0x20 [zfs]
[12582.892482]  [<ffffffffa04a9841>] dmu_tx_hold_object_impl+0x31/0xf0 [zfs]
[12582.892558]  [<ffffffffa04a9c30>] dmu_tx_hold_bonus+0x20/0x40 [zfs]
[12582.892633]  [<ffffffffa04ab2bb>] dmu_tx_hold_sa+0x4b/0x1a0 [zfs]
[12582.892715]  [<ffffffffa0518c19>] zfs_write+0x369/0xc80 [zfs]
[12582.892776]  [<ffffffff8104f2b7>] ? current_fs_time+0x27/0x30
[12582.892836]  [<ffffffff8113fad2>] ? do_sync_read+0xe2/0x120
[12582.892916]  [<ffffffffa052af02>] zpl_write_common+0x52/0x70 [zfs]
[12582.892997]  [<ffffffffa052af88>] zpl_write+0x68/0xa0 [zfs]
[12582.893055]  [<ffffffff8113fee8>] vfs_write+0xc8/0x190
[12582.893113]  [<ffffffff811400a1>] sys_write+0x51/0x90
[12582.893170]  [<ffffffff813d4929>] system_call_fastpath+0x16/0x1b

[12702.712264] INFO: task kswapd0:78 blocked for more than 120 seconds.
[12702.712329] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[12702.712408] kswapd0         D 0000000000000009     0    78      2 0x00000000
[12702.712534]  ffff88062040f848 0000000000000046 ffff880c2032aca0 0000000000013200
[12702.712740]  ffff88062040ffd8 ffff88062040e010 0000000000013200 0000000000013200
[12702.712946]  ffff88062040ffd8 0000000000013200 ffff88060a3eaca0 ffff880c2032aca0
[12702.713151] Call Trace:
[12702.713209]  [<ffffffff813cc7ae>] ? _raw_spin_lock+0xe/0x20
[12702.713267]  [<ffffffff813cbacf>] schedule+0x3f/0x60
[12702.713325]  [<ffffffff813cc69d>] rwsem_down_failed_common+0xcd/0x170
[12702.713385]  [<ffffffff813cc775>] rwsem_down_read_failed+0x15/0x17
[12702.713445]  [<ffffffff811f8634>] call_rwsem_down_read_failed+0x14/0x30
[12702.713508]  [<ffffffff813ca987>] ? down_read+0x17/0x20
[12702.713591]  [<ffffffffa04afe24>] dnode_hold_impl+0xb4/0x550 [zfs]
[12702.713652]  [<ffffffff8113145a>] ? discard_slab+0x3a/0x50
[12702.713709]  [<ffffffff811327e7>] ? __slab_free+0x307/0x350
[12702.713779]  [<ffffffffa0495f99>] ? dbuf_rele_and_unlock+0x159/0x210 [zfs]
[12702.713856]  [<ffffffffa04b02d9>] dnode_hold+0x19/0x20 [zfs]
[12702.713928]  [<ffffffffa049dbc2>] dmu_free_long_range+0x32/0x70 [zfs]
[12702.714011]  [<ffffffffa0500070>] zfs_rmnode+0x60/0x340 [zfs]
[12702.714090]  [<ffffffffa04cfa8f>] ? sa_handle_destroy+0x8f/0xa0 [zfs]
[12702.714173]  [<ffffffffa051bebe>] zfs_zinactive+0x9e/0x100 [zfs]
[12702.714255]  [<ffffffffa051af4a>] zfs_inactive+0x6a/0x1e0 [zfs]
[12702.714315]  [<ffffffff810f549e>] ? truncate_pagecache+0x5e/0x70
[12702.714397]  [<ffffffffa052bcc8>] zpl_evict_inode+0x28/0x30 [zfs]
[12702.714457]  [<ffffffff8115986f>] evict+0xaf/0x1b0
[12702.714513]  [<ffffffff81159ecf>] dispose_list+0x4f/0x60
[12702.714571]  [<ffffffff8115a07d>] prune_icache_sb+0x19d/0x390
[12702.714629]  [<ffffffff8115819d>] ? prune_dcache_sb+0x18d/0x1c0
[12702.714689]  [<ffffffff811426e8>] prune_super+0xe8/0x1d0
[12702.714747]  [<ffffffff810f8f9f>] shrink_slab+0x19f/0x2e0
[12702.714808]  [<ffffffff810fbd67>] balance_pgdat+0x667/0x8d0
[12702.714866]  [<ffffffff810fc1ad>] kswapd+0x1dd/0x410
[12702.714925]  [<ffffffff8106b8b0>] ? wake_up_bit+0x40/0x40
[12702.714983]  [<ffffffff810fbfd0>] ? balance_pgdat+0x8d0/0x8d0
[12702.715041]  [<ffffffff8106b35e>] kthread+0x9e/0xb0
[12702.715099]  [<ffffffff813d5be4>] kernel_thread_helper+0x4/0x10
[12702.715158]  [<ffffffff8106b2c0>] ? kthread_freezable_should_stop+0x70/0x70
[12702.715218]  [<ffffffff813d5be0>] ? gs_change+0x13/0x13

[12702.715297] INFO: task zfs_iput_taskq/:8933 blocked for more than 120 seconds.
[12702.715371] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[12702.715445] zfs_iput_taskq/ D 0000000000000000     0  8933      2 0x00000000
[12702.715571]  ffff8806090a5868 0000000000000046 ffff880609d50000 0000000000013200
[12702.715777]  ffff8806090a5fd8 ffff8806090a4010 0000000000013200 0000000000013200
[12702.715982]  ffff8806090a5fd8 0000000000013200 ffff880623938000 ffff880609d50000
[12702.716189] Call Trace:
[12702.716241]  [<ffffffff813cbacf>] schedule+0x3f/0x60
[12702.716299]  [<ffffffff813cc69d>] rwsem_down_failed_common+0xcd/0x170
[12702.716359]  [<ffffffff813cc775>] rwsem_down_read_failed+0x15/0x17
[12702.716417]  [<ffffffff811f8634>] call_rwsem_down_read_failed+0x14/0x30
[12702.716478]  [<ffffffff813ca987>] ? down_read+0x17/0x20
[12702.716552]  [<ffffffffa04afe24>] dnode_hold_impl+0xb4/0x550 [zfs]
[12702.716611]  [<ffffffff81133989>] ? __kmalloc+0x39/0x150
[12702.716686]  [<ffffffffa04b02d9>] dnode_hold+0x19/0x20 [zfs]
[12702.716758]  [<ffffffffa049e44d>] dmu_buf_hold+0x4d/0x1a0 [zfs]
[12702.716840]  [<ffffffffa04f2f70>] ? zap_idx_to_blk+0x140/0x140 [zfs]
[12702.716922]  [<ffffffffa04f41ef>] zap_get_leaf_byblk+0x4f/0x290 [zfs]
[12702.716992]  [<ffffffffa048e265>] ? arc_buf_remove_ref+0xd5/0x130 [zfs]
[12702.717076]  [<ffffffffa04f449a>] zap_deref_leaf+0x6a/0x80 [zfs]
[12702.717158]  [<ffffffffa04f549c>] fzap_cursor_retrieve+0xfc/0x290 [zfs]
[12702.717219]  [<ffffffff813cc7ae>] ? _raw_spin_lock+0xe/0x20
[12702.717277]  [<ffffffff81159add>] ? iput+0x16d/0x230
[12702.717356]  [<ffffffffa04f9edb>] zap_cursor_retrieve+0x13b/0x2a0 [zfs]
[12702.717439]  [<ffffffffa04fff63>] zfs_unlinked_drain+0x63/0x110 [zfs]
[12702.717499]  [<ffffffff811326c6>] ? __slab_free+0x1e6/0x350
[12702.717559]  [<ffffffff810786e5>] ? ttwu_do_wakeup+0x45/0x100
[12702.717619]  [<ffffffff81080458>] ? update_curr+0x168/0x170
[12702.717678]  [<ffffffff8107da40>] ? __dequeue_entity+0x30/0x50
[12702.717738]  [<ffffffff81011563>] ? __switch_to+0x153/0x440
[12702.717796]  [<ffffffff81080123>] ? set_next_entity+0x93/0xa0
[12702.717854]  [<ffffffff81078e73>] ? finish_task_switch+0x53/0x100
[12702.717921]  [<ffffffffa03dc2b7>] taskq_thread+0x237/0x5e0 [spl]
[12702.717980]  [<ffffffff8107b480>] ? try_to_wake_up+0x2d0/0x2d0
[12702.718042]  [<ffffffffa03dc080>] ? task_alloc+0x380/0x380 [spl]
[12702.718101]  [<ffffffff8106b35e>] kthread+0x9e/0xb0
[12702.718158]  [<ffffffff813d5be4>] kernel_thread_helper+0x4/0x10
[12702.718217]  [<ffffffff8106b2c0>] ? kthread_freezable_should_stop+0x70/0x70
[12702.718277]  [<ffffffff813d5be0>] ? gs_change+0x13/0x13

[12702.718334] INFO: task txg_quiesce:8935 blocked for more than 120 seconds.
[12702.718393] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[12702.718467] txg_quiesce     D ffffffff81407920     0  8935      2 0x00000000
[12702.718592]  ffff880607977d40 0000000000000046 ffff880609d542f0 0000000000013200
[12702.718797]  ffff880607977fd8 ffff880607976010 0000000000013200 0000000000013200
[12702.719001]  ffff880607977fd8 0000000000013200 ffff8806245d8000 ffff880609d542f0
[12702.719206] Call Trace:
[12702.719259]  [<ffffffff813cbacf>] schedule+0x3f/0x60
[12702.719321]  [<ffffffffa03e2f6c>] cv_wait_common+0x9c/0x1a0 [spl]
[12702.719380]  [<ffffffff8106b8b0>] ? wake_up_bit+0x40/0x40
[12702.719442]  [<ffffffffa03e30a3>] __cv_wait+0x13/0x20 [spl]
[12702.719522]  [<ffffffffa04e51db>] txg_quiesce_thread+0x1eb/0x330 [zfs]
[12702.719583]  [<ffffffff81077a80>] ? set_user_nice+0xf0/0x190
[12702.719663]  [<ffffffffa04e4ff0>] ? txg_sync_thread+0x490/0x490 [zfs]
[12702.719726]  [<ffffffffa03db290>] ? __thread_create+0x360/0x360 [spl]
[12702.719790]  [<ffffffffa03db308>] thread_generic_wrapper+0x78/0x90 [spl]
[12702.719853]  [<ffffffffa03db290>] ? __thread_create+0x360/0x360 [spl]
[12702.719913]  [<ffffffff8106b35e>] kthread+0x9e/0xb0
[12702.719970]  [<ffffffff813d5be4>] kernel_thread_helper+0x4/0x10
[12702.720029]  [<ffffffff8106b2c0>] ? kthread_freezable_should_stop+0x70/0x70
[12702.720089]  [<ffffffff813d5be0>] ? gs_change+0x13/0x13

[12702.720148] INFO: task tar-otn:16310 blocked for more than 120 seconds.
[12702.720207] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[12702.720281] tar-otn         D ffffffff81407920     0 16310  16309 0x00000004
[12702.720406]  ffff8804c6af9938 0000000000000086 ffff8806226a2ca0 0000000000013200
[12702.720611]  ffff8804c6af9fd8 ffff8804c6af8010 0000000000013200 0000000000013200
[12702.720816]  ffff8804c6af9fd8 0000000000013200 ffff880624650000 ffff8806226a2ca0
[12702.721021] Call Trace:
[12702.721074]  [<ffffffff813cbacf>] schedule+0x3f/0x60
[12702.721131]  [<ffffffff813cc69d>] rwsem_down_failed_common+0xcd/0x170
[12702.721191]  [<ffffffff813cc753>] rwsem_down_write_failed+0x13/0x20
[12702.721250]  [<ffffffff811f8663>] call_rwsem_down_write_failed+0x13/0x20
[12702.721310]  [<ffffffff813ca9b5>] ? down_write+0x25/0x30
[12702.721385]  [<ffffffffa04b0374>] dnode_new_blkid+0x94/0x2f0 [zfs]
[12702.721456]  [<ffffffffa04985a6>] dbuf_dirty+0x576/0x780 [zfs]
[12702.721530]  [<ffffffffa04a4057>] ? dmu_objset_userquota_get_ids+0x2d7/0x400 [zfs]
[12702.721622]  [<ffffffffa04adbd2>] dnode_setdirty+0x112/0x1a0 [zfs]
[12702.721697]  [<ffffffffa04adf56>] dnode_allocate+0x126/0x240 [zfs]
[12702.721771]  [<ffffffffa04a0695>] dmu_object_alloc+0x175/0x1c0 [zfs]
[12702.721853]  [<ffffffffa04f93b2>] zap_create_norm+0x32/0x60 [zfs]
[12702.721935]  [<ffffffffa051e9bc>] zfs_mknode+0xbbc/0xc70 [zfs]
[12702.723195]  [<ffffffffa04be61f>] ? dsl_dir_tempreserve_space+0x1bf/0x1f0 [zfs]
[12702.723294]  [<ffffffffa04e4331>] ? txg_rele_to_quiesce+0x11/0x20 [zfs]
[12702.723371]  [<ffffffffa04aa4e1>] ? dmu_tx_assign+0x3e1/0x480 [zfs]
[12702.723455]  [<ffffffffa051749c>] zfs_mkdir+0x45c/0x590 [zfs]
[12702.723536]  [<ffffffffa052b87e>] zpl_mkdir+0x9e/0xe0 [zfs]
[12702.723596]  [<ffffffff8114b905>] vfs_mkdir+0x85/0xc0
[12702.723654]  [<ffffffff8114f2c4>] sys_mkdirat+0xc4/0xe0
[12702.723713]  [<ffffffff813d4929>] system_call_fastpath+0x16/0x1b

[ryao]

How much RAM do you have? Try decreasing the zfs_arc_max to 1/4 of your RAM.

[chrisrd]

I have 96 GB. Thanks for the zfs_arc_max suggestion, I normally run with it set to 8 GB but in this case I was really trying to see if behlendorf/zfs@2a349bd (now #618) would work well with default tunings.

[behlendorf]

This issue is believed to be resolved by the recent memory management improvements