Skip to content
New issue

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

Sign up for GitHub

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

Already on GitHub? Sign in to your account

Jump to bottom

random call trace on heavy load #3148

Closed
tobias-k opened this issue Mar 3, 2015 · 10 comments
Closed

random call trace on heavy load #3148

tobias-k opened this issue Mar 3, 2015 · 10 comments

Comments

@tobias-k
Copy link

tobias-k commented Mar 3, 2015

random call traces on heavy load an diffrent boxes on diffrent tasks.
3.13.0-24-generic # 47-Ubuntu
ZFS v0.6.3-5~trusty from ubuntu ppa repo

SPL: Loaded module v0.6.3-3trusty
ZFS: Loaded module v0.6.3-5trusty, ZFS pool version 5000, ZFS filesystem version 5

Box 1

21721.005454] INFO: task spl_system_task:350 blocked for more than 120 seconds.
[21721.005585]       Tainted: PF          O 3.13.0-24-generic #47-Ubuntu
[21721.005673] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[21721.005784] spl_system_task D ffff88042fc94440     0   350      2 0x00000000
[21721.005790]  ffff88003602d660 0000000000000002 ffff880414845fc0 ffff88003602dfd8
[21721.005796]  0000000000014440 0000000000014440 ffff880414845fc0 ffff88015d24cf30
[21721.005799]  ffff88015d24cf00 ffff88015d24cf38 ffff88015d24cf28 0000000000000000
[21721.005803] Call Trace:
[21721.005815]  [<ffffffff81719ee9>] schedule+0x29/0x70
[21721.005841]  [<ffffffffa01437b5>] cv_wait_common+0x125/0x1c0 [spl]
[21721.005849]  [<ffffffff810aae90>] ? prepare_to_wait_event+0x100/0x100
[21721.005859]  [<ffffffffa0143865>] __cv_wait+0x15/0x20 [spl]
[21721.005910]  [<ffffffffa01d033b>] traverse_prefetcher+0x9b/0x160 [zfs]
[21721.005936]  [<ffffffffa01d07dd>] traverse_visitbp+0x2dd/0x750 [zfs]
[21721.005957]  [<ffffffffa01b69a0>] ? arc_buf_remove_ref+0x110/0x110 [zfs]
[21721.005983]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21721.006009]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21721.006035]  [<ffffffffa01d1335>] traverse_dnode+0x75/0x120 [zfs]
[21721.006060]  [<ffffffffa01d0a7c>] traverse_visitbp+0x57c/0x750 [zfs]
[21721.006086]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21721.006111]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21721.006137]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21721.006162]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21721.006188]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21721.006213]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21721.006239]  [<ffffffffa01d1335>] traverse_dnode+0x75/0x120 [zfs]
[21721.006264]  [<ffffffffa01d0b41>] traverse_visitbp+0x641/0x750 [zfs]
[21721.006268]  [<ffffffff8109df24>] ? arch_vtime_task_switch+0x94/0xa0
[21721.006294]  [<ffffffffa01d1263>] traverse_prefetch_thread+0x83/0xe0 [zfs]
[21721.006319]  [<ffffffffa01d02a0>] ? prefetch_dnode_metadata+0xc0/0xc0 [zfs]
[21721.006329]  [<ffffffffa013db57>] taskq_thread+0x237/0x4b0 [spl]
[21721.006334]  [<ffffffff81097498>] ? finish_task_switch+0x128/0x170
[21721.006338]  [<ffffffff8109a790>] ? wake_up_state+0x20/0x20
[21721.006347]  [<ffffffffa013d920>] ? taskq_cancel_id+0x1f0/0x1f0 [spl]
[21721.006352]  [<ffffffff8108b312>] kthread+0xd2/0xf0
[21721.006356]  [<ffffffff8108b240>] ? kthread_create_on_node+0x1d0/0x1d0
[21721.006361]  [<ffffffff817263fc>] ret_from_fork+0x7c/0xb0
[21721.006364]  [<ffffffff8108b240>] ? kthread_create_on_node+0x1d0/0x1d0
[21841.006869] INFO: task spl_system_task:350 blocked for more than 120 seconds.
[21841.006981]       Tainted: PF          O 3.13.0-24-generic #47-Ubuntu
[21841.007069] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[21841.007180] spl_system_task D ffff88042fc94440     0   350      2 0x00000000
[21841.007186]  ffff88003602d660 0000000000000002 ffff880414845fc0 ffff88003602dfd8
[21841.007192]  0000000000014440 0000000000014440 ffff880414845fc0 ffff88015d24cf30
[21841.007195]  ffff88015d24cf00 ffff88015d24cf38 ffff88015d24cf28 0000000000000000
[21841.007200] Call Trace:
[21841.007211]  [<ffffffff81719ee9>] schedule+0x29/0x70
[21841.007236]  [<ffffffffa01437b5>] cv_wait_common+0x125/0x1c0 [spl]
[21841.007244]  [<ffffffff810aae90>] ? prepare_to_wait_event+0x100/0x100
[21841.007254]  [<ffffffffa0143865>] __cv_wait+0x15/0x20 [spl]
[21841.007307]  [<ffffffffa01d033b>] traverse_prefetcher+0x9b/0x160 [zfs]
[21841.007333]  [<ffffffffa01d07dd>] traverse_visitbp+0x2dd/0x750 [zfs]
[21841.007354]  [<ffffffffa01b69a0>] ? arc_buf_remove_ref+0x110/0x110 [zfs]
[21841.007380]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21841.007406]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21841.007432]  [<ffffffffa01d1335>] traverse_dnode+0x75/0x120 [zfs]
[21841.007458]  [<ffffffffa01d0a7c>] traverse_visitbp+0x57c/0x750 [zfs]
[21841.007483]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21841.007509]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21841.007534]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21841.007560]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21841.007585]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21841.007610]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[21841.007636]  [<ffffffffa01d1335>] traverse_dnode+0x75/0x120 [zfs]
[21841.007661]  [<ffffffffa01d0b41>] traverse_visitbp+0x641/0x750 [zfs]
[21841.007666]  [<ffffffff8109df24>] ? arch_vtime_task_switch+0x94/0xa0
[21841.007691]  [<ffffffffa01d1263>] traverse_prefetch_thread+0x83/0xe0 [zfs]
[21841.007717]  [<ffffffffa01d02a0>] ? prefetch_dnode_metadata+0xc0/0xc0 [zfs]
[21841.007727]  [<ffffffffa013db57>] taskq_thread+0x237/0x4b0 [spl]
[21841.007732]  [<ffffffff81097498>] ? finish_task_switch+0x128/0x170
[21841.007736]  [<ffffffff8109a790>] ? wake_up_state+0x20/0x20
[21841.007745]  [<ffffffffa013d920>] ? taskq_cancel_id+0x1f0/0x1f0 [spl]
[21841.007750]  [<ffffffff8108b312>] kthread+0xd2/0xf0
[21841.007753]  [<ffffffff8108b240>] ? kthread_create_on_node+0x1d0/0x1d0
[21841.007758]  [<ffffffff817263fc>] ret_from_fork+0x7c/0xb0
[21841.007761]  [<ffffffff8108b240>] ? kthread_create_on_node+0x1d0/0x1d0
[56761.028037] INFO: task spl_system_task:350 blocked for more than 120 seconds.
[56761.028142]       Tainted: PF          O 3.13.0-24-generic #47-Ubuntu
[56761.028230] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[56761.028341] spl_system_task D ffff88042fdd4440     0   350      2 0x00000000
[56761.028347]  ffff88003602d660 0000000000000002 ffff880414845fc0 ffff88003602dfd8
[56761.028352]  0000000000014440 0000000000014440 ffff880414845fc0 ffff880199222630
[56761.028355]  ffff880199222600 ffff880199222638 ffff880199222628 0000000000000000
[56761.028360] Call Trace:
[56761.028370]  [<ffffffff81719ee9>] schedule+0x29/0x70
[56761.028394]  [<ffffffffa01437b5>] cv_wait_common+0x125/0x1c0 [spl]
[56761.028401]  [<ffffffff810aae90>] ? prepare_to_wait_event+0x100/0x100
[56761.028411]  [<ffffffffa0143865>] __cv_wait+0x15/0x20 [spl]
[56761.028458]  [<ffffffffa01d033b>] traverse_prefetcher+0x9b/0x160 [zfs]
[56761.028484]  [<ffffffffa01d07dd>] traverse_visitbp+0x2dd/0x750 [zfs]
[56761.028505]  [<ffffffffa01b69a0>] ? arc_buf_remove_ref+0x110/0x110 [zfs]
[56761.028531]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.028557]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.028583]  [<ffffffffa01d1335>] traverse_dnode+0x75/0x120 [zfs]
[56761.028608]  [<ffffffffa01d0a7c>] traverse_visitbp+0x57c/0x750 [zfs]
[56761.028634]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.028659]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.028685]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.028710]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.028735]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.028761]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.028786]  [<ffffffffa01d1335>] traverse_dnode+0x75/0x120 [zfs]
[56761.028812]  [<ffffffffa01d0b41>] traverse_visitbp+0x641/0x750 [zfs]
[56761.028816]  [<ffffffff8109df24>] ? arch_vtime_task_switch+0x94/0xa0
[56761.028841]  [<ffffffffa01d1263>] traverse_prefetch_thread+0x83/0xe0 [zfs]
[56761.028867]  [<ffffffffa01d02a0>] ? prefetch_dnode_metadata+0xc0/0xc0 [zfs]
[56761.028876]  [<ffffffffa013db57>] taskq_thread+0x237/0x4b0 [spl]
[56761.028881]  [<ffffffff81097498>] ? finish_task_switch+0x128/0x170
[56761.028886]  [<ffffffff8109a790>] ? wake_up_state+0x20/0x20
[56761.028894]  [<ffffffffa013d920>] ? taskq_cancel_id+0x1f0/0x1f0 [spl]
[56761.028899]  [<ffffffff8108b312>] kthread+0xd2/0xf0
[56761.028903]  [<ffffffff8108b240>] ? kthread_create_on_node+0x1d0/0x1d0
[56761.028907]  [<ffffffff817263fc>] ret_from_fork+0x7c/0xb0
[56761.028910]  [<ffffffff8108b240>] ? kthread_create_on_node+0x1d0/0x1d0
[56761.028949] INFO: task zfs:19210 blocked for more than 120 seconds.
[56761.029048]       Tainted: PF          O 3.13.0-24-generic #47-Ubuntu
[56761.029136] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[56761.029245] zfs             D ffff88042fd54440     0 19210  19209 0x00000000
[56761.029249]  ffff880342d17518 0000000000000002 ffff88027c3bafe0 ffff880342d17fd8
[56761.029253]  0000000000014440 0000000000014440 ffff88027c3bafe0 ffff8804153e8e00
[56761.029257]  0000000000c2bf5c ffff8804153e8ec0 0000000000000000 ffff880412739940
[56761.029261] Call Trace:
[56761.029264]  [<ffffffff81719ee9>] schedule+0x29/0x70
[56761.029274]  [<ffffffffa013d33d>] taskq_wait_id+0x4d/0x90 [spl]
[56761.029277]  [<ffffffff810aae90>] ? prepare_to_wait_event+0x100/0x100
[56761.029303]  [<ffffffffa01cd580>] ? backup_cb+0x860/0x860 [zfs]
[56761.029338]  [<ffffffffa020027c>] spa_taskq_dispatch_sync+0x6c/0x90 [zfs]
[56761.029364]  [<ffffffffa01cca12>] dump_bytes+0x42/0x50 [zfs]
[56761.029389]  [<ffffffffa01cd170>] backup_cb+0x450/0x860 [zfs]
[56761.029392]  [<ffffffff810aaa34>] ? __wake_up+0x44/0x50
[56761.029418]  [<ffffffffa01d07dd>] traverse_visitbp+0x2dd/0x750 [zfs]
[56761.029438]  [<ffffffffa01b69a0>] ? arc_buf_remove_ref+0x110/0x110 [zfs]
[56761.029464]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.029490]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.029515]  [<ffffffffa01d1335>] traverse_dnode+0x75/0x120 [zfs]
[56761.029541]  [<ffffffffa01d0a7c>] traverse_visitbp+0x57c/0x750 [zfs]
[56761.029566]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.029592]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.029617]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.029643]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.029668]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.029694]  [<ffffffffa01d094b>] traverse_visitbp+0x44b/0x750 [zfs]
[56761.029719]  [<ffffffffa01d1335>] traverse_dnode+0x75/0x120 [zfs]
[56761.029745]  [<ffffffffa01d0b41>] traverse_visitbp+0x641/0x750 [zfs]
[56761.029754]  [<ffffffffa013c976>] ? taskq_dispatch+0x66/0x340 [spl]
[56761.029779]  [<ffffffffa01d0dc8>] traverse_impl+0x178/0x360 [zfs]
[56761.029783]  [<ffffffff810aae90>] ? prepare_to_wait_event+0x100/0x100
[56761.029816]  [<ffffffffa020027c>] ? spa_taskq_dispatch_sync+0x6c/0x90 [zfs]
[56761.029842]  [<ffffffffa01d0ff4>] traverse_dataset+0x44/0x50 [zfs]
[56761.029867]  [<ffffffffa01ccd20>] ? dump_free+0x1a0/0x1a0 [zfs]
[56761.029892]  [<ffffffffa01ce37b>] dmu_send_impl+0x3fb/0x590 [zfs]
[56761.029918]  [<ffffffffa01cf02d>] dmu_send_obj+0xad/0x110 [zfs]
[56761.029958]  [<ffffffffa02329c6>] zfs_ioc_send+0xa6/0x280 [zfs]
[56761.029995]  [<ffffffffa0235f96>] zfsdev_ioctl+0x466/0x4e0 [zfs]
[56761.030001]  [<ffffffff811cc6e0>] do_vfs_ioctl+0x2e0/0x4c0
[56761.030004]  [<ffffffff8109dd84>] ? vtime_account_user+0x54/0x60
[56761.030008]  [<ffffffff811cc941>] SyS_ioctl+0x81/0xa0
[56761.030011]  [<ffffffff817266bf>] tracesys+0xe1/0xe6

Box 6

[549570.021484] INFO: task zfs_iput_taskq/:1168 blocked for more than 120 seconds.
[549570.023092]       Tainted: P           OX 3.13.0-45-generic #74-Ubuntu
[549570.024536] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[549570.026335] zfs_iput_taskq/ D ffff88063fc534c0     0  1168      2 0x00000000
[549570.026340]  ffff88062b08b910 0000000000000046 ffff88060fceb000 ffff88062b08bfd8
[549570.026344]  00000000000134c0 00000000000134c0 ffff88060fceb000 ffff88063fc53d58
[549570.026350]  ffff88060af20750 ffff88060af20788 ffff88060af20778 0000000000000001
[549570.026353] Call Trace:
[549570.026363]  [<ffffffff817255fd>] io_schedule+0x9d/0x140
[549570.026383]  [<ffffffffa0181742>] cv_wait_common+0xb2/0x1c0 [spl]
[549570.026389]  [<ffffffff810ab0b0>] ? prepare_to_wait_event+0x100/0x100
[549570.026396]  [<ffffffffa01818a8>] __cv_wait_io+0x18/0x20 [spl]
[549570.026444]  [<ffffffffa0354053>] zio_wait+0x103/0x1e0 [zfs]
[549570.026459]  [<ffffffffa02b9d2c>] dbuf_read+0x34c/0x930 [zfs]
[549570.026475]  [<ffffffffa02c1b39>] dmu_buf_hold+0xe9/0x1b0 [zfs]
[549570.026503]  [<ffffffffa031b7e6>] zap_get_leaf_byblk+0x46/0x2c0 [zfs]
[549570.026532]  [<ffffffffa031b224>] ? zap_idx_to_blk+0xd4/0x140 [zfs]
[549570.026560]  [<ffffffffa031bac4>] zap_deref_leaf+0x64/0x80 [zfs]
[549570.026588]  [<ffffffffa031d697>] fzap_cursor_retrieve+0x107/0x2a0 [zfs]
[549570.026603]  [<ffffffffa02b9396>] ? dmu_buf_rele+0x26/0x30 [zfs]
[549570.026631]  [<ffffffffa0320bbc>] zap_cursor_retrieve+0x5c/0x2f0 [zfs]
[549570.026640]  [<ffffffffa0000001>] ? linear_mergeable_bvec+0x1/0x140 [linear]
[549570.026669]  [<ffffffffa032a75f>] zfs_unlinked_drain+0x5f/0x120 [zfs]
[549570.026673]  [<ffffffff8101bc99>] ? sched_clock+0x9/0x10
[549570.026679]  [<ffffffffa017531b>] ? kmem_free_debug+0x4b/0x150 [spl]
[549570.026684]  [<ffffffff811a208d>] ? kfree+0xfd/0x140
[549570.026689]  [<ffffffffa017531b>] ? kmem_free_debug+0x4b/0x150 [spl]
[549570.026693]  [<ffffffff810aac54>] ? __wake_up+0x44/0x50
[549570.026699]  [<ffffffffa017bb57>] taskq_thread+0x237/0x4b0 [spl]
[549570.026703]  [<ffffffff8109a9b0>] ? wake_up_state+0x20/0x20
[549570.026709]  [<ffffffffa017b920>] ? taskq_cancel_id+0x1f0/0x1f0 [spl]
[549570.026713]  [<ffffffff8108b572>] kthread+0xd2/0xf0
[549570.026716]  [<ffffffff8108b4a0>] ? kthread_create_on_node+0x1c0/0x1c0
[549570.026719]  [<ffffffff817318bc>] ret_from_fork+0x7c/0xb0
[549570.026721]  [<ffffffff8108b4a0>] ? kthread_create_on_node+0x1c0/0x1c0
[549690.123171] INFO: task kswapd0:194 blocked for more than 120 seconds.
[549690.124606]       Tainted: P           OX 3.13.0-45-generic #74-Ubuntu
[549690.162526] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[549690.240218] kswapd0         D ffff880333c334c0     0   194      2 0x00000000
[549690.240225]  ffff88032ca7d9b0 0000000000000046 ffff88062cba4800 ffff88032ca7dfd8
[549690.240231]  00000000000134c0 00000000000134c0 ffff88062cba4800 ffffffffa0391250
[549690.240236]  ffffffffa0391254 ffff88062cba4800 00000000ffffffff ffffffffa0391258
[549690.240241] Call Trace:
[549690.240259]  [<ffffffff817257f9>] schedule_preempt_disabled+0x29/0x70
[549690.240263]  [<ffffffff81727665>] __mutex_lock_slowpath+0x135/0x1b0
[549690.240267]  [<ffffffff817276f2>] ? mutex_lock+0x12/0x2f
[549690.240271]  [<ffffffff817276ff>] mutex_lock+0x1f/0x2f
[549690.240313]  [<ffffffffa02b292c>] arc_buf_remove_ref+0x9c/0x110 [zfs]
[549690.240347]  [<ffffffffa02b910f>] dbuf_rele_and_unlock+0x12f/0x280 [zfs]
[549690.240371]  [<ffffffffa02b9396>] dmu_buf_rele+0x26/0x30 [zfs]
[549690.240400]  [<ffffffffa02d2790>] dnode_rele+0x80/0x90 [zfs]
[549690.240425]  [<ffffffffa02b91fd>] dbuf_rele_and_unlock+0x21d/0x280 [zfs]
[549690.240446]  [<ffffffffa02b9396>] dmu_buf_rele+0x26/0x30 [zfs]
[549690.240482]  [<ffffffffa02f3366>] sa_handle_destroy+0x66/0xb0 [zfs]
[549690.240530]  [<ffffffffa034b925>] zfs_zinactive+0xe5/0x170 [zfs]
[549690.240575]  [<ffffffffa0345544>] zfs_inactive+0x64/0x210 [zfs]
[549690.240620]  [<ffffffffa035aef4>] zpl_evict_inode+0x24/0x30 [zfs]
[549690.240626]  [<ffffffff811d8f60>] evict+0xb0/0x1b0
[549690.240630]  [<ffffffff811d9099>] dispose_list+0x39/0x50
[549690.240634]  [<ffffffff811d9fc7>] prune_icache_sb+0x47/0x60
[549690.240640]  [<ffffffff811c1385>] super_cache_scan+0x105/0x170
[549690.240644]  [<ffffffff81160f27>] shrink_slab+0x1c7/0x370
[549690.240648]  [<ffffffff81164a68>] balance_pgdat+0x3e8/0x610
[549690.240652]  [<ffffffff81164deb>] kswapd+0x15b/0x420
[549690.240658]  [<ffffffff810ab0b0>] ? prepare_to_wait_event+0x100/0x100
[549690.240661]  [<ffffffff81164c90>] ? balance_pgdat+0x610/0x610
[549690.240666]  [<ffffffff8108b572>] kthread+0xd2/0xf0
[549690.240670]  [<ffffffff8108b4a0>] ? kthread_create_on_node+0x1c0/0x1c0
[549690.240674]  [<ffffffff817318bc>] ret_from_fork+0x7c/0xb0
[549690.240678]  [<ffffffff8108b4a0>] ? kthread_create_on_node+0x1c0/0x1c0
[549690.240690] INFO: task spl_system_task:587 blocked for more than 120 seconds.
[549690.319244]       Tainted: P           OX 3.13.0-45-generic #74-Ubuntu
[549690.359219] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[549690.437715] spl_system_task D ffff880333cb34c0     0   587      2 0x00000000
[549690.437721]  ffff88062c08d810 0000000000000046 ffff88062c263000 ffff88062c08dfd8
[549690.437726]  00000000000134c0 00000000000134c0 ffff88062c263000 ffffffffa0391250
[549690.437730]  ffffffffa0391254 ffff88062c263000 00000000ffffffff ffffffffa0391258
[549690.437735] Call Trace:
[549690.437752]  [<ffffffff817257f9>] schedule_preempt_disabled+0x29/0x70
[549690.437756]  [<ffffffff81727665>] __mutex_lock_slowpath+0x135/0x1b0
[549690.437817]  [<ffffffffa035086a>] ? zio_wait_for_children+0x6a/0x80 [zfs]
[549690.437832]  [<ffffffff817276ff>] mutex_lock+0x1f/0x2f
[549690.437852]  [<ffffffffa02ad4c3>] buf_hash_find+0x83/0x110 [zfs]
[549690.437871]  [<ffffffffa02b2a77>] arc_read+0x67/0x960 [zfs]
[549690.437899]  [<ffffffffa02cc1d2>] traverse_prefetch_metadata+0x92/0xa0 [zfs]
[549690.437930]  [<ffffffffa02cc8e0>] traverse_visitbp+0x3e0/0x750 [zfs]
[549690.437957]  [<ffffffffa02cc94b>] traverse_visitbp+0x44b/0x750 [zfs]
[549690.437984]  [<ffffffffa02cc94b>] traverse_visitbp+0x44b/0x750 [zfs]
[549690.438011]  [<ffffffffa02cc94b>] traverse_visitbp+0x44b/0x750 [zfs]
[549690.438038]  [<ffffffffa02cc94b>] traverse_visitbp+0x44b/0x750 [zfs]
[549690.438065]  [<ffffffffa02cc94b>] traverse_visitbp+0x44b/0x750 [zfs]
[549690.438092]  [<ffffffffa02cd335>] traverse_dnode+0x75/0x120 [zfs]
[549690.438119]  [<ffffffffa02ccb41>] traverse_visitbp+0x641/0x750 [zfs]
[549690.438146]  [<ffffffffa02cd263>] traverse_prefetch_thread+0x83/0xe0 [zfs]
[549690.438173]  [<ffffffffa02cc2a0>] ? prefetch_dnode_metadata+0xc0/0xc0 [zfs]
[549690.438188]  [<ffffffffa017bb57>] taskq_thread+0x237/0x4b0 [spl]
[549690.438194]  [<ffffffff8109a9b0>] ? wake_up_state+0x20/0x20
[549690.438204]  [<ffffffffa017b920>] ? taskq_cancel_id+0x1f0/0x1f0 [spl]
[549690.438209]  [<ffffffff8108b572>] kthread+0xd2/0xf0
[549690.438213]  [<ffffffff8108b4a0>] ? kthread_create_on_node+0x1c0/0x1c0
[549690.438217]  [<ffffffff817318bc>] ret_from_fork+0x7c/0xb0
[549690.438220]  [<ffffffff8108b4a0>] ? kthread_create_on_node+0x1c0/0x1c0
[549690.438242] INFO: task z_wr_int/4:1088 blocked for more than 120 seconds.
[549690.478023]       Tainted: P           OX 3.13.0-45-generic #74-Ubuntu
[549690.517618] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[549690.596143] z_wr_int/4      D ffff880333cd34c0     0  1088      2 0x00000000
[549690.596149]  ffff8806103a1b50 0000000000000046 ffff88061039b000 ffff8806103a1fd8
[549690.596154]  00000000000134c0 00000000000134c0 ffff88061039b000 ffffffffa0391250
[549690.596158]  ffffffffa0391254 ffff88061039b000 00000000ffffffff ffffffffa0391258
[549690.596163] Call Trace:
[549690.596180]  [<ffffffff817257f9>] schedule_preempt_disabled+0x29/0x70
[549690.596183]  [<ffffffff81727665>] __mutex_lock_slowpath+0x135/0x1b0
[549690.596187]  [<ffffffff817276ff>] mutex_lock+0x1f/0x2f
[549690.596227]  [<ffffffffa02ad332>] buf_hash_insert+0x72/0x180 [zfs]
[549690.596255]  [<ffffffffa02b0e92>] arc_write_done+0x92/0x350 [zfs]
[549690.596308]  [<ffffffffa0355e29>] zio_done+0x299/0xd80 [zfs]
[549690.596347]  [<ffffffffa03062b4>] ? spa_config_exit+0x84/0xb0 [zfs]
[549690.596389]  [<ffffffffa0316900>] ? vdev_mirror_map_free+0x20/0x30 [zfs]
[549690.596433]  [<ffffffffa035637c>] zio_done+0x7ec/0xd80 [zfs]
[549690.596475]  [<ffffffffa0318c48>] ? vdev_raidz_map_free+0xb8/0xc0 [zfs]
[549690.596519]  [<ffffffffa035637c>] zio_done+0x7ec/0xd80 [zfs]
[549690.596564]  [<ffffffffa035637c>] zio_done+0x7ec/0xd80 [zfs]
[549690.596610]  [<ffffffffa03520b6>] zio_execute+0xa6/0x140 [zfs]
[549690.596624]  [<ffffffffa017bb57>] taskq_thread+0x237/0x4b0 [spl]
[549690.596630]  [<ffffffff8109a9b0>] ? wake_up_state+0x20/0x20
[549690.596640]  [<ffffffffa017b920>] ? taskq_cancel_id+0x1f0/0x1f0 [spl]
[549690.596644]  [<ffffffff8108b572>] kthread+0xd2/0xf0
[549690.596648]  [<ffffffff8108b4a0>] ? kthread_create_on_node+0x1c0/0x1c0
[549690.596653]  [<ffffffff817318bc>] ret_from_fork+0x7c/0xb0
[549690.596656]  [<ffffffff8108b4a0>] ? kthread_create_on_node+0x1c0/0x1c0
[549690.596667] INFO: task zfs_iput_taskq/:1168 blocked for more than 120 seconds.
[549690.675504]       Tainted: P           OX 3.13.0-45-generic #74-Ubuntu
[549690.715080] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[549690.793767] zfs_iput_taskq/ D ffff88063fc534c0     0  1168      2 0x00000000
[549690.793773]  ffff88062b08b910 0000000000000046 ffff88060fceb000 ffff88062b08bfd8
[549690.793777]  00000000000134c0 00000000000134c0 ffff88060fceb000 ffff88063fc53d58
[549690.793780]  ffff88060af20750 ffff88060af20788 ffff88060af20778 0000000000000001
[549690.793786] Call Trace:
[549690.793798]  [<ffffffff817255fd>] io_schedule+0x9d/0x140
[549690.793816]  [<ffffffffa0181742>] cv_wait_common+0xb2/0x1c0 [spl]
[549690.793821]  [<ffffffff810ab0b0>] ? prepare_to_wait_event+0x100/0x100
[549690.793828]  [<ffffffffa01818a8>] __cv_wait_io+0x18/0x20 [spl]
[549690.793875]  [<ffffffffa0354053>] zio_wait+0x103/0x1e0 [zfs]
[549690.793893]  [<ffffffffa02b9d2c>] dbuf_read+0x34c/0x930 [zfs]
[549690.793910]  [<ffffffffa02c1b39>] dmu_buf_hold+0xe9/0x1b0 [zfs]
[549690.793938]  [<ffffffffa031b7e6>] zap_get_leaf_byblk+0x46/0x2c0 [zfs]
[549690.793966]  [<ffffffffa031b224>] ? zap_idx_to_blk+0xd4/0x140 [zfs]
[549690.793994]  [<ffffffffa031bac4>] zap_deref_leaf+0x64/0x80 [zfs]
[549690.794023]  [<ffffffffa031d697>] fzap_cursor_retrieve+0x107/0x2a0 [zfs]
[549690.794037]  [<ffffffffa02b9396>] ? dmu_buf_rele+0x26/0x30 [zfs]
[549690.794066]  [<ffffffffa0320bbc>] zap_cursor_retrieve+0x5c/0x2f0 [zfs]
[549690.794075]  [<ffffffffa0000001>] ? linear_mergeable_bvec+0x1/0x140 [linear]
[549690.794103]  [<ffffffffa032a75f>] zfs_unlinked_drain+0x5f/0x120 [zfs]
[549690.794107]  [<ffffffff8101bc99>] ? sched_clock+0x9/0x10
[549690.794114]  [<ffffffffa017531b>] ? kmem_free_debug+0x4b/0x150 [spl]
[549690.794119]  [<ffffffff811a208d>] ? kfree+0xfd/0x140
[549690.794124]  [<ffffffffa017531b>] ? kmem_free_debug+0x4b/0x150 [spl]
[549690.794127]  [<ffffffff810aac54>] ? __wake_up+0x44/0x50
[549690.794134]  [<ffffffffa017bb57>] taskq_thread+0x237/0x4b0 [spl]
[549690.794138]  [<ffffffff8109a9b0>] ? wake_up_state+0x20/0x20
[549690.794144]  [<ffffffffa017b920>] ? taskq_cancel_id+0x1f0/0x1f0 [spl]
[549690.794148]  [<ffffffff8108b572>] kthread+0xd2/0xf0
[549690.794150]  [<ffffffff8108b4a0>] ? kthread_create_on_node+0x1c0/0x1c0
[549690.794153]  [<ffffffff817318bc>] ret_from_fork+0x7c/0xb0
[549690.794156]  [<ffffffff8108b4a0>] ? kthread_create_on_node+0x1c0/0x1c0
[549690.794158] INFO: task txg_sync:1172 blocked for more than 120 seconds.
[549690.834122]       Tainted: P           OX 3.13.0-45-generic #74-Ubuntu
[549690.873774] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[549690.951917] txg_sync        D ffff88063fc934c0     0  1172      2 0x00000000
[549690.951922]  ffff8806043d1be0 0000000000000046 ffff88060e061800 ffff8806043d1fd8
[549690.951926]  00000000000134c0 00000000000134c0 ffff88060e061800 ffff88063fc93d58
[549690.951929]  ffff8805deb56090 ffff8805deb560c8 ffff8805deb560b8 0000000000000001
[549690.951932] Call Trace:
[549690.951941]  [<ffffffff817255fd>] io_schedule+0x9d/0x140
[549690.951958]  [<ffffffffa0181742>] cv_wait_common+0xb2/0x1c0 [spl]
[549690.951962]  [<ffffffff810ab0b0>] ? prepare_to_wait_event+0x100/0x100
[549690.951970]  [<ffffffffa01818a8>] __cv_wait_io+0x18/0x20 [spl]
[549690.952018]  [<ffffffffa0354053>] zio_wait+0x103/0x1e0 [zfs]
[549690.952040]  [<ffffffffa02e3671>] dsl_pool_sync+0xb1/0x470 [zfs]
[549690.952065]  [<ffffffffa02fb835>] spa_sync+0x425/0xb10 [zfs]
[549690.952069]  [<ffffffff810cda98>] ? ktime_get_ts+0x48/0xe0
[549690.952096]  [<ffffffffa030c666>] txg_sync_thread+0x3b6/0x600 [zfs]
[549690.952123]  [<ffffffffa030c2b0>] ? txg_fini+0x2b0/0x2b0 [zfs]
[549690.952129]  [<ffffffffa0179aba>] thread_generic_wrapper+0x7a/0x90 [spl]
[549690.952136]  [<ffffffffa0179a40>] ? __thread_exit+0xa0/0xa0 [spl]
[549690.952139]  [<ffffffff8108b572>] kthread+0xd2/0xf0
[549690.952142]  [<ffffffff8108b4a0>] ? kthread_create_on_node+0x1c0/0x1c0
[549690.952145]  [<ffffffff817318bc>] ret_from_fork+0x7c/0xb0
[549690.952147]  [<ffffffff8108b4a0>] ? kthread_create_on_node+0x1c0/0x1c0

Box 7

1392413.029160] INFO: task zfs:4704 blocked for more than 120 seconds.
[1392413.029182]       Tainted: P           OX 3.13.0-39-generic #66-Ubuntu
[1392413.029198] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[1392413.029216] zfs             D ffff88063fd14480     0  4704   4701 0x00000002
[1392413.029222]  ffff88011b241940 0000000000000086 ffff88003615e000 ffff88011b241fd8
[1392413.029228]  0000000000014480 0000000000014480 ffff88003615e000 ffff88032595c160
[1392413.029232]  ffff88032595c138 ffff88032595c168 0000000000000000 0000000000000002
[1392413.029237] Call Trace:
[1392413.029250]  [<ffffffff81723109>] schedule+0x29/0x70
[1392413.029273]  [<ffffffffa01e6485>] cv_wait_common+0x105/0x1a0 [spl]
[1392413.029282]  [<ffffffff810aafd0>] ? prepare_to_wait_event+0x100/0x100
[1392413.029294]  [<ffffffffa01e6535>] __cv_wait+0x15/0x20 [spl]
[1392413.029339]  [<ffffffffa02fd62b>] dmu_tx_wait+0x8b/0x2a0 [zfs]
[1392413.029368]  [<ffffffffa02fd8cc>] dmu_tx_assign+0x8c/0x460 [zfs]
[1392413.029396]  [<ffffffffa02fcecb>] ? dmu_tx_count_dnode+0x5b/0xa0 [zfs]
[1392413.029424]  [<ffffffffa02fa3a0>] restore_write+0xb0/0x150 [zfs]
[1392413.029452]  [<ffffffffa02fb4b1>] dmu_recv_stream+0x591/0xa80 [zfs]
[1392413.029501]  [<ffffffffa0360c30>] zfs_ioc_recv+0x210/0xc40 [zfs]
[1392413.029510]  [<ffffffffa0203899>] ? zprop_iter_common+0xd9/0x130 [zcommon]
[1392413.029516]  [<ffffffffa0203a50>] ? zprop_string_to_index+0xb0/0xb0 [zcommon]
[1392413.029522]  [<ffffffffa020392c>] ? zprop_name_to_prop+0x3c/0x60 [zcommon]
[1392413.029536]  [<ffffffffa01e7dee>] ? tsd_set+0xee/0x710 [spl]
[1392413.029545]  [<ffffffffa01da31b>] ? kmem_free_debug+0x4b/0x150 [spl]
[1392413.029583]  [<ffffffffa0320f39>] ? rrw_exit+0x39/0x120 [zfs]
[1392413.029592]  [<ffffffff811a1d95>] ? __kmalloc+0x55/0x230
[1392413.029601]  [<ffffffffa01de4c8>] ? strdup+0x48/0x90 [spl]
[1392413.029648]  [<ffffffffa035f2c6>] zfsdev_ioctl+0x466/0x4e0 [zfs]
[1392413.029655]  [<ffffffff811d03c0>] do_vfs_ioctl+0x2e0/0x4c0
[1392413.029659]  [<ffffffff811d0621>] SyS_ioctl+0x81/0xa0
[1392413.029664]  [<ffffffff8172f7ed>] system_call_fastpath+0x1a/0x1f
[1392413.029669] INFO: task VeeamAgent39ddd:5959 blocked for more than 120 seconds.
[1392413.029687]       Tainted: P           OX 3.13.0-39-generic #66-Ubuntu
[1392413.029702] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[1392413.029720] VeeamAgent39ddd D ffff88063fc74480     0  5959   5950 0x20020000
[1392413.029723]  ffff8801c84bbb38 0000000000000086 ffff88021bd33000 ffff8801c84bbfd8
[1392413.029728]  0000000000014480 0000000000014480 ffff88021bd33000 ffff88032595c160
[1392413.029732]  ffff88032595c138 ffff88032595c168 0000000000000000 0000000000000002
[1392413.029736] Call Trace:
[1392413.029741]  [<ffffffff81723109>] schedule+0x29/0x70
[1392413.029753]  [<ffffffffa01e6485>] cv_wait_common+0x105/0x1a0 [spl]
[1392413.029757]  [<ffffffff810aafd0>] ? prepare_to_wait_event+0x100/0x100
[1392413.029769]  [<ffffffffa01e6535>] __cv_wait+0x15/0x20 [spl]
[1392413.029798]  [<ffffffffa02fd62b>] dmu_tx_wait+0x8b/0x2a0 [zfs]
[1392413.029827]  [<ffffffffa02fd8cc>] dmu_tx_assign+0x8c/0x460 [zfs]
[1392413.029855]  [<ffffffffa02fcecb>] ? dmu_tx_count_dnode+0x5b/0xa0 [zfs]
[1392413.029901]  [<ffffffffa0371548>] zfs_write+0x3f8/0xc50 [zfs]
[1392413.029906]  [<ffffffff81199cd9>] ? mpol_misplaced+0x189/0x250
[1392413.029954]  [<ffffffffa0386822>] zpl_write_common+0x52/0x90 [zfs]
[1392413.030000]  [<ffffffffa03868c0>] zpl_write+0x60/0x90 [zfs]
[1392413.030006]  [<ffffffff811bd214>] vfs_write+0xb4/0x1f0
[1392413.030010]  [<ffffffff811bdc49>] SyS_write+0x49/0xa0
[1392413.030016]  [<ffffffff81731949>] ia32_do_call+0x13/0x13
[1392413.030057] INFO: task rm:13998 blocked for more than 120 seconds.
[1392413.030072]       Tainted: P           OX 3.13.0-39-generic #66-Ubuntu
[1392413.030087] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[1392413.030105] rm              D ffff880333c34480     0 13998  13997 0x00000002
[1392413.030108]  ffff88007cd1db90 0000000000000086 ffff88016f82c800 ffff88007cd1dfd8
[1392413.030113]  0000000000014480 0000000000014480 ffff88016f82c800 ffff88032595c160
[1392413.030117]  ffff88032595c138 ffff88032595c168 0000000000000000 0000000000000002
[1392413.030122] Call Trace:
[1392413.030126]  [<ffffffff81723109>] schedule+0x29/0x70
[1392413.030138]  [<ffffffffa01e6485>] cv_wait_common+0x105/0x1a0 [spl]
[1392413.030143]  [<ffffffff810aafd0>] ? prepare_to_wait_event+0x100/0x100
[1392413.030154]  [<ffffffffa01e6535>] __cv_wait+0x15/0x20 [spl]
[1392413.030184]  [<ffffffffa02fd62b>] dmu_tx_wait+0x8b/0x2a0 [zfs]
[1392413.030212]  [<ffffffffa02fd8cc>] dmu_tx_assign+0x8c/0x460 [zfs]
[1392413.030237]  [<ffffffffa02f084c>] dmu_free_long_range+0x19c/0x260 [zfs]
[1392413.030282]  [<ffffffffa0356d3d>] zfs_rmnode+0x5d/0x340 [zfs]
[1392413.030287]  [<ffffffff81725522>] ? mutex_lock+0x12/0x2f
[1392413.030334]  [<ffffffffa03785d8>] zfs_zinactive+0x78/0xd0 [zfs]
[1392413.030381]  [<ffffffffa0372504>] zfs_inactive+0x64/0x200 [zfs]
[1392413.030389]  [<ffffffff8115df29>] ? truncate_pagecache+0x59/0x60
[1392413.030436]  [<ffffffffa03876f4>] zpl_evict_inode+0x24/0x30 [zfs]
[1392413.030440]  [<ffffffff811d84f0>] evict+0xb0/0x1b0
[1392413.030444]  [<ffffffff811d8d05>] iput+0xf5/0x180
[1392413.030448]  [<ffffffff811cd63e>] do_unlinkat+0x18e/0x2b0
[1392413.030453]  [<ffffffff811c24b5>] ? SYSC_newfstatat+0x25/0x30
[1392413.030459]  [<ffffffff8172b15a>] ? do_page_fault+0x1a/0x70
[1392413.030463]  [<ffffffff811ce55b>] SyS_unlinkat+0x1b/0x40
[1392413.030466]  [<ffffffff8172f7ed>] system_call_fastpath+0x1a/0x1f
[1392533.126643] INFO: task zfs:4704 blocked for more than 120 seconds.
[1392533.126665]       Tainted: P           OX 3.13.0-39-generic #66-Ubuntu
[1392533.126681] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[1392533.126699] zfs             D ffff88063fd14480     0  4704   4701 0x00000002
[1392533.126704]  ffff88011b241940 0000000000000086 ffff88003615e000 ffff88011b241fd8
[1392533.126710]  0000000000014480 0000000000014480 ffff88003615e000 ffff88032595c160
[1392533.126715]  ffff88032595c138 ffff88032595c168 0000000000000000 0000000000000002
[1392533.126719] Call Trace:
[1392533.126732]  [<ffffffff81723109>] schedule+0x29/0x70
[1392533.126755]  [<ffffffffa01e6485>] cv_wait_common+0x105/0x1a0 [spl]
[1392533.126764]  [<ffffffff810aafd0>] ? prepare_to_wait_event+0x100/0x100
[1392533.126776]  [<ffffffffa01e6535>] __cv_wait+0x15/0x20 [spl]
[1392533.126821]  [<ffffffffa02fd62b>] dmu_tx_wait+0x8b/0x2a0 [zfs]
[1392533.126849]  [<ffffffffa02fd8cc>] dmu_tx_assign+0x8c/0x460 [zfs]
[1392533.126878]  [<ffffffffa02fcecb>] ? dmu_tx_count_dnode+0x5b/0xa0 [zfs]
[1392533.126906]  [<ffffffffa02fa3a0>] restore_write+0xb0/0x150 [zfs]
[1392533.126934]  [<ffffffffa02fb4b1>] dmu_recv_stream+0x591/0xa80 [zfs]
[1392533.126983]  [<ffffffffa0360c30>] zfs_ioc_recv+0x210/0xc40 [zfs]
[1392533.126990]  [<ffffffffa0203899>] ? zprop_iter_common+0xd9/0x130 [zcommon]
[1392533.126997]  [<ffffffffa0203a50>] ? zprop_string_to_index+0xb0/0xb0 [zcommon]
[1392533.127003]  [<ffffffffa020392c>] ? zprop_name_to_prop+0x3c/0x60 [zcommon]
[1392533.127017]  [<ffffffffa01e7dee>] ? tsd_set+0xee/0x710 [spl]
[1392533.127026]  [<ffffffffa01da31b>] ? kmem_free_debug+0x4b/0x150 [spl]
[1392533.127064]  [<ffffffffa0320f39>] ? rrw_exit+0x39/0x120 [zfs]
[1392533.127070]  [<ffffffff811a1d95>] ? __kmalloc+0x55/0x230
[1392533.127079]  [<ffffffffa01de4c8>] ? strdup+0x48/0x90 [spl]
[1392533.127126]  [<ffffffffa035f2c6>] zfsdev_ioctl+0x466/0x4e0 [zfs]
[1392533.127132]  [<ffffffff811d03c0>] do_vfs_ioctl+0x2e0/0x4c0
[1392533.127136]  [<ffffffff811d0621>] SyS_ioctl+0x81/0xa0
[1392533.127141]  [<ffffffff8172f7ed>] system_call_fastpath+0x1a/0x1f
[1392533.127146] INFO: task VeeamAgent39ddd:5959 blocked for more than 120 seconds.
[1392533.127163]       Tainted: P           OX 3.13.0-39-generic #66-Ubuntu
[1392533.127179] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[1392533.127225] VeeamAgent39ddd D ffff88063fc74480     0  5959   5950 0x20020000
[1392533.127229]  ffff8801c84bbb38 0000000000000086 ffff88021bd33000 ffff8801c84bbfd8
[1392533.127233]  0000000000014480 0000000000014480 ffff88021bd33000 ffff88032595c160
[1392533.127237]  ffff88032595c138 ffff88032595c168 0000000000000000 0000000000000002
[1392533.127242] Call Trace:
[1392533.127246]  [<ffffffff81723109>] schedule+0x29/0x70
[1392533.127259]  [<ffffffffa01e6485>] cv_wait_common+0x105/0x1a0 [spl]
[1392533.127263]  [<ffffffff810aafd0>] ? prepare_to_wait_event+0x100/0x100
[1392533.127274]  [<ffffffffa01e6535>] __cv_wait+0x15/0x20 [spl]
[1392533.127304]  [<ffffffffa02fd62b>] dmu_tx_wait+0x8b/0x2a0 [zfs]
[1392533.127332]  [<ffffffffa02fd8cc>] dmu_tx_assign+0x8c/0x460 [zfs]
[1392533.127360]  [<ffffffffa02fcecb>] ? dmu_tx_count_dnode+0x5b/0xa0 [zfs]
[1392533.127407]  [<ffffffffa0371548>] zfs_write+0x3f8/0xc50 [zfs]
[1392533.127411]  [<ffffffff81199cd9>] ? mpol_misplaced+0x189/0x250
[1392533.127459]  [<ffffffffa0386822>] zpl_write_common+0x52/0x90 [zfs]
[1392533.127505]  [<ffffffffa03868c0>] zpl_write+0x60/0x90 [zfs]
[1392533.127511]  [<ffffffff811bd214>] vfs_write+0xb4/0x1f0
[1392533.127515]  [<ffffffff811bdc49>] SyS_write+0x49/0xa0
[1392533.127522]  [<ffffffff81731949>] ia32_do_call+0x13/0x13
[1392533.127562] INFO: task rm:13998 blocked for more than 120 seconds.
[1392533.127591]       Tainted: P           OX 3.13.0-39-generic #66-Ubuntu
[1392533.127620] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[1392533.127666] rm              D ffff880333c34480     0 13998  13997 0x00000002
[1392533.127669]  ffff88007cd1db90 0000000000000086 ffff88016f82c800 ffff88007cd1dfd8
[1392533.127674]  0000000000014480 0000000000014480 ffff88016f82c800 ffff88032595c160
[1392533.127678]  ffff88032595c138 ffff88032595c168 0000000000000000 0000000000000002
[1392533.127683] Call Trace:
[1392533.127687]  [<ffffffff81723109>] schedule+0x29/0x70
[1392533.127699]  [<ffffffffa01e6485>] cv_wait_common+0x105/0x1a0 [spl]
[1392533.127704]  [<ffffffff810aafd0>] ? prepare_to_wait_event+0x100/0x100
[1392533.127716]  [<ffffffffa01e6535>] __cv_wait+0x15/0x20 [spl]
[1392533.127745]  [<ffffffffa02fd62b>] dmu_tx_wait+0x8b/0x2a0 [zfs]
[1392533.127773]  [<ffffffffa02fd8cc>] dmu_tx_assign+0x8c/0x460 [zfs]
[1392533.127798]  [<ffffffffa02f084c>] dmu_free_long_range+0x19c/0x260 [zfs]
[1392533.127843]  [<ffffffffa0356d3d>] zfs_rmnode+0x5d/0x340 [zfs]
[1392533.127849]  [<ffffffff81725522>] ? mutex_lock+0x12/0x2f
[1392533.127895]  [<ffffffffa03785d8>] zfs_zinactive+0x78/0xd0 [zfs]
[1392533.127942]  [<ffffffffa0372504>] zfs_inactive+0x64/0x200 [zfs]
[1392533.127950]  [<ffffffff8115df29>] ? truncate_pagecache+0x59/0x60
[1392533.127997]  [<ffffffffa03876f4>] zpl_evict_inode+0x24/0x30 [zfs]
[1392533.128001]  [<ffffffff811d84f0>] evict+0xb0/0x1b0
[1392533.128005]  [<ffffffff811d8d05>] iput+0xf5/0x180
[1392533.128010]  [<ffffffff811cd63e>] do_unlinkat+0x18e/0x2b0
[1392533.128014]  [<ffffffff811c24b5>] ? SYSC_newfstatat+0x25/0x30
[1392533.128020]  [<ffffffff8172b15a>] ? do_page_fault+0x1a/0x70
[1392533.128024]  [<ffffffff811ce55b>] SyS_unlinkat+0x1b/0x40
[1392533.128028]  [<ffffffff8172f7ed>] system_call_fastpath+0x1a/0x1f
[1392893.418923] INFO: task zfs:4704 blocked for more than 120 seconds.
[1392893.418959]       Tainted: P           OX 3.13.0-39-generic #66-Ubuntu
[1392893.418989] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[1392893.419035] zfs             D ffff88063fc14480     0  4704   4701 0x00000002
[1392893.419040]  ffff88011b241940 0000000000000086 ffff88003615e000 ffff88011b241fd8
[1392893.419046]  0000000000014480 0000000000014480 ffff88003615e000 ffff88032595c160
[1392893.419050]  ffff88032595c138 ffff88032595c168 0000000000000000 0000000000000002
[1392893.419055] Call Trace:
[1392893.419068]  [<ffffffff81723109>] schedule+0x29/0x70
[1392893.419090]  [<ffffffffa01e6485>] cv_wait_common+0x105/0x1a0 [spl]
[1392893.419099]  [<ffffffff810aafd0>] ? prepare_to_wait_event+0x100/0x100
[1392893.419111]  [<ffffffffa01e6535>] __cv_wait+0x15/0x20 [spl]
[1392893.419155]  [<ffffffffa02fd62b>] dmu_tx_wait+0x8b/0x2a0 [zfs]
[1392893.419184]  [<ffffffffa02fd8cc>] dmu_tx_assign+0x8c/0x460 [zfs]
[1392893.419213]  [<ffffffffa02fcecb>] ? dmu_tx_count_dnode+0x5b/0xa0 [zfs]
[1392893.419241]  [<ffffffffa02fa3a0>] restore_write+0xb0/0x150 [zfs]
[1392893.419269]  [<ffffffffa02fb4b1>] dmu_recv_stream+0x591/0xa80 [zfs]
[1392893.419318]  [<ffffffffa0360c30>] zfs_ioc_recv+0x210/0xc40 [zfs]
[1392893.419326]  [<ffffffffa0203899>] ? zprop_iter_common+0xd9/0x130 [zcommon]
[1392893.419333]  [<ffffffffa0203a50>] ? zprop_string_to_index+0xb0/0xb0 [zcommon]
[1392893.419339]  [<ffffffffa020392c>] ? zprop_name_to_prop+0x3c/0x60 [zcommon]
[1392893.419353]  [<ffffffffa01e7dee>] ? tsd_set+0xee/0x710 [spl]
[1392893.419362]  [<ffffffffa01da31b>] ? kmem_free_debug+0x4b/0x150 [spl]
[1392893.419399]  [<ffffffffa0320f39>] ? rrw_exit+0x39/0x120 [zfs]
[1392893.419406]  [<ffffffff811a1d95>] ? __kmalloc+0x55/0x230
[1392893.419416]  [<ffffffffa01de4c8>] ? strdup+0x48/0x90 [spl]
[1392893.419462]  [<ffffffffa035f2c6>] zfsdev_ioctl+0x466/0x4e0 [zfs]
[1392893.419468]  [<ffffffff811d03c0>] do_vfs_ioctl+0x2e0/0x4c0
[1392893.419473]  [<ffffffff811d0621>] SyS_ioctl+0x81/0xa0
[1392893.419478]  [<ffffffff8172f7ed>] system_call_fastpath+0x1a/0x1f
[1392893.419483] INFO: task VeeamAgent39ddd:5959 blocked for more than 120 seconds.
[1392893.419528]       Tainted: P           OX 3.13.0-39-generic #66-Ubuntu
[1392893.419556] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[1392893.419601] VeeamAgent39ddd D ffff88063fcb4480     0  5959   5950 0x20020000
[1392893.419605]  ffff8801c84bbb38 0000000000000086 ffff88021bd33000 ffff8801c84bbfd8
[1392893.419609]  0000000000014480 0000000000014480 ffff88021bd33000 ffff88032595c160
[1392893.419614]  ffff88032595c138 ffff88032595c168 0000000000000000 0000000000000002
[1392893.419618] Call Trace:
[1392893.419623]  [<ffffffff81723109>] schedule+0x29/0x70
[1392893.419635]  [<ffffffffa01e6485>] cv_wait_common+0x105/0x1a0 [spl]
[1392893.419639]  [<ffffffff810aafd0>] ? prepare_to_wait_event+0x100/0x100
[1392893.419650]  [<ffffffffa01e6535>] __cv_wait+0x15/0x20 [spl]
[1392893.419680]  [<ffffffffa02fd62b>] dmu_tx_wait+0x8b/0x2a0 [zfs]
[1392893.419708]  [<ffffffffa02fd8cc>] dmu_tx_assign+0x8c/0x460 [zfs]
[1392893.419736]  [<ffffffffa02fcecb>] ? dmu_tx_count_dnode+0x5b/0xa0 [zfs]
[1392893.419783]  [<ffffffffa0371548>] zfs_write+0x3f8/0xc50 [zfs]
[1392893.419787]  [<ffffffff81199cd9>] ? mpol_misplaced+0x189/0x250
[1392893.419791]  [<ffffffff810a24a0>] ? task_numa_fault+0x670/0x890
[1392893.419840]  [<ffffffffa0386822>] zpl_write_common+0x52/0x90 [zfs]
[1392893.419886]  [<ffffffffa03868c0>] zpl_write+0x60/0x90 [zfs]
[1392893.419892]  [<ffffffff811bd214>] vfs_write+0xb4/0x1f0
[1392893.419895]  [<ffffffff811bdc49>] SyS_write+0x49/0xa0
[1392893.419902]  [<ffffffff81731949>] ia32_do_call+0x13/0x13
[1392893.419942] INFO: task scp:15665 blocked for more than 120 seconds.
[1392893.419971]       Tainted: P           OX 3.13.0-39-generic #66-Ubuntu
[1392893.420000] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[1392893.420045] scp             D ffff88063fcb4480     0 15665  12723 0x00000000
[1392893.420048]  ffff8801bf31ba38 0000000000000082 ffff8802ffaa6000 ffff8801bf31bfd8
[1392893.420053]  0000000000014480 0000000000014480 ffff8802ffaa6000 ffff88032595c160
[1392893.420057]  ffff88032595c138 ffff88032595c168 0000000000000000 0000000000000002
[1392893.420062] Call Trace:
[1392893.420066]  [<ffffffff81723109>] schedule+0x29/0x70
[1392893.420078]  [<ffffffffa01e6485>] cv_wait_common+0x105/0x1a0 [spl]
[1392893.420113]  [<ffffffffa0312492>] ? dsl_pool_need_dirty_delay+0x72/0x90 [zfs]
[1392893.420117]  [<ffffffff810aafd0>] ? prepare_to_wait_event+0x100/0x100
[1392893.420129]  [<ffffffffa01e6535>] __cv_wait+0x15/0x20 [spl]
[1392893.420158]  [<ffffffffa02fd62b>] dmu_tx_wait+0x8b/0x2a0 [zfs]
[1392893.420204]  [<ffffffffa0374831>] zfs_trunc+0xa1/0x210 [zfs]
[1392893.420241]  [<ffffffffa032481d>] ? sa_lookup+0x4d/0x60 [zfs]
[1392893.420288]  [<ffffffffa0378b8c>] zfs_freesp+0x10c/0x3b0 [zfs]
[1392893.420294]  [<ffffffff81725522>] ? mutex_lock+0x12/0x2f
[1392893.420300]  [<ffffffff81176bc3>] ? unmap_mapping_range+0x83/0x160
[1392893.420308]  [<ffffffff8115df29>] ? truncate_pagecache+0x59/0x60
[1392893.420355]  [<ffffffffa036f525>] zfs_setattr+0xcc5/0x18d0 [zfs]
[1392893.420362]  [<ffffffff811503f5>] ? filemap_fault+0xa5/0x410
[1392893.420366]  [<ffffffff81175529>] ? __do_fault+0x429/0x530
[1392893.420370]  [<ffffffff811a1f29>] ? __kmalloc+0x1e9/0x230
[1392893.420380]  [<ffffffffa01dd2a6>] ? kmem_alloc_debug+0x96/0x3c0 [spl]
[1392893.420389]  [<ffffffffa01dd2a6>] ? kmem_alloc_debug+0x96/0x3c0 [spl]
[1392893.420436]  [<ffffffffa0386b2b>] zpl_setattr+0xdb/0x120 [zfs]
[1392893.420441]  [<ffffffff811d9951>] notify_change+0x231/0x390
[1392893.420445]  [<ffffffff811ba2fd>] do_truncate+0x6d/0xa0
[1392893.420449]  [<ffffffff811bf7f9>] ? __sb_start_write+0x49/0xe0
[1392893.420453]  [<ffffffff811bb378>] do_sys_ftruncate.constprop.13+0x118/0x170
[1392893.420457]  [<ffffffff811bb40e>] SyS_ftruncate+0xe/0x10
[1392893.420461]  [<ffffffff8172f7ed>] system_call_fastpath+0x1a/0x1f
[1393013.516356] INFO: task zfs:4704 blocked for more than 120 seconds.
[1393013.516393]       Tainted: P           OX 3.13.0-39-generic #66-Ubuntu
[1393013.516422] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[1393013.516468] zfs             D ffff88063fc14480     0  4704   4701 0x00000002
[1393013.516473]  ffff88011b241940 0000000000000086 ffff88003615e000 ffff88011b241fd8
[1393013.516479]  0000000000014480 0000000000014480 ffff88003615e000 ffff88032595c160
[1393013.516484]  ffff88032595c138 ffff88032595c168 0000000000000000 0000000000000002
[1393013.516489] Call Trace:
[1393013.516501]  [<ffffffff81723109>] schedule+0x29/0x70
[1393013.516524]  [<ffffffffa01e6485>] cv_wait_common+0x105/0x1a0 [spl]
[1393013.516534]  [<ffffffff810aafd0>] ? prepare_to_wait_event+0x100/0x100
[1393013.516546]  [<ffffffffa01e6535>] __cv_wait+0x15/0x20 [spl]
[1393013.516594]  [<ffffffffa02fd62b>] dmu_tx_wait+0x8b/0x2a0 [zfs]
[1393013.516622]  [<ffffffffa02fd8cc>] dmu_tx_assign+0x8c/0x460 [zfs]
[1393013.516651]  [<ffffffffa02fcecb>] ? dmu_tx_count_dnode+0x5b/0xa0 [zfs]
[1393013.516678]  [<ffffffffa02fa3a0>] restore_write+0xb0/0x150 [zfs]
[1393013.516706]  [<ffffffffa02fb4b1>] dmu_recv_stream+0x591/0xa80 [zfs]
[1393013.516756]  [<ffffffffa0360c30>] zfs_ioc_recv+0x210/0xc40 [zfs]
[1393013.516763]  [<ffffffffa0203899>] ? zprop_iter_common+0xd9/0x130 [zcommon]
[1393013.516770]  [<ffffffffa0203a50>] ? zprop_string_to_index+0xb0/0xb0 [zcommon]
[1393013.516776]  [<ffffffffa020392c>] ? zprop_name_to_prop+0x3c/0x60 [zcommon]
[1393013.516790]  [<ffffffffa01e7dee>] ? tsd_set+0xee/0x710 [spl]
[1393013.516799]  [<ffffffffa01da31b>] ? kmem_free_debug+0x4b/0x150 [spl]
[1393013.516837]  [<ffffffffa0320f39>] ? rrw_exit+0x39/0x120 [zfs]
[1393013.516843]  [<ffffffff811a1d95>] ? __kmalloc+0x55/0x230
[1393013.516853]  [<ffffffffa01de4c8>] ? strdup+0x48/0x90 [spl]
[1393013.516899]  [<ffffffffa035f2c6>] zfsdev_ioctl+0x466/0x4e0 [zfs]
[1393013.516906]  [<ffffffff811d03c0>] do_vfs_ioctl+0x2e0/0x4c0
[1393013.516910]  [<ffffffff811d0621>] SyS_ioctl+0x81/0xa0
[1393013.516915]  [<ffffffff8172f7ed>] system_call_fastpath+0x1a/0x1f
@tobias-k tobias-k changed the title random call trace on heavy load. random call trace on heavy load Mar 3, 2015
@dasjoe
Copy link
Contributor

dasjoe commented Mar 3, 2015

That's usually just an information about a stuck process: INFO: task spl_system_task:350 blocked for more than 120 seconds.

This can happen when your disks are too busy, preventing the named processes from being switched out by the scheduler in the last /proc/sys/kernel/hung_task_timeout_secs (here: 120) seconds.

If the boxes stay unresponsive and have to be rebooted to be usable again you're seeing a bug, but if the boxes become responsive again by themselves you are getting harmless warnings.

@kernelOfTruth
Copy link
Contributor

looks, like it might be related to #3142

and the pull-request #3132 , openzfs/spl#435 on SPL

@tobias-k
Copy link
Author

tobias-k commented Mar 3, 2015

@dasjoe You are right. somestime these call traces are harmles. From time to time the "hang" needs several seconds till the box is respondig again. Some of these "hangs" are more impacting. After the call trace sometimes some zfs processes are runnig at 100% CPU. Mostly arc_adapt and/or zfs_input_taskq are at 100 %. The box responses but at extrem low performance. This is persistent till reboot.

@eolson78
Copy link

eolson78 commented May 1, 2015

@kernelOfTruth I do not believe that is his issue at all. the issue @tobias-k is experiencing is a bit different. I have actually appeared to reproduce something similar running 0.6.3.1 with Kernel 3.14.4. Heavy work load of SMB traffic with constant ZFS send and rcv running. Below is the out put of my stack traces. Please note I applied #3348 to this system and it did not fully solve the issue although it did stop subsequent ZFS commands from hanging while these initial hangs occured.

Apr 30 11:45:10 ip-172-26-0-157 kernel: INFO: task spl_system_task:2153 blocked for more than 120 seconds.
Apr 30 11:45:10 ip-172-26-0-157 kernel: Tainted: P O 3.14.4 #1
Apr 30 11:45:10 ip-172-26-0-157 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr 30 11:45:10 ip-172-26-0-157 kernel: spl_system_task D ffffffff8181d000 0 2153 2 0x00000000
Apr 30 11:45:10 ip-172-26-0-157 kernel: ffff880f049e95b8 0000000000000046 0000000000040000 ffff880f049e8010
Apr 30 11:45:10 ip-172-26-0-157 kernel: 0000000000014440 0000000000014440 ffff880f05eccf30 ffff880f05cbaf70
Apr 30 11:45:10 ip-172-26-0-157 kernel: ffff880f049e95c8 ffff880565b9d9b0 ffff880565b9d980 ffff880f049e95f8
Apr 30 11:45:10 ip-172-26-0-157 kernel: Call Trace:
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] schedule+0x29/0x70
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] cv_wait_common+0x135/0x1c0 [spl]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] ? bit_waitqueue+0xe0/0xe0
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] __cv_wait+0x15/0x20 [spl]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] traverse_prefetcher+0xb5/0x170 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x2ce/0x6f0 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] ? kmem_alloc_debug+0x53/0x230 [spl]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] ? arc_buf_evict+0x380/0x380 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] traverse_dnode+0x6c/0xf0 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x56d/0x6f0 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] traverse_dnode+0x6c/0xf0 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x610/0x6f0 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] ? sched_clock_cpu+0x98/0xc0
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] ? __switch_to+0x17d/0x5e0
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] traverse_prefetch_thread+0x83/0xe0 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] ? traverse_prefetch_thread+0xe0/0xe0 [zfs]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] taskq_thread+0x22d/0x4f0 [spl]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] ? try_to_wake_up+0x230/0x230
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] ? task_expire+0x120/0x120 [spl]
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] kthread+0xce/0xf0
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] ret_from_fork+0x7c/0xb0
Apr 30 11:45:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:47:10 ip-172-26-0-157 kernel: INFO: task spl_system_task:2153 blocked for more than 120 seconds.
Apr 30 11:47:10 ip-172-26-0-157 kernel: Tainted: P O 3.14.4 #1
Apr 30 11:47:10 ip-172-26-0-157 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr 30 11:47:10 ip-172-26-0-157 kernel: spl_system_task D ffffffff8181d000 0 2153 2 0x00000000
Apr 30 11:47:10 ip-172-26-0-157 kernel: ffff880f049e95b8 0000000000000046 0000000000040000 ffff880f049e8010
Apr 30 11:47:10 ip-172-26-0-157 kernel: 0000000000014440 0000000000014440 ffff880f05eccf30 ffff880f05cbaf70
Apr 30 11:47:10 ip-172-26-0-157 kernel: ffff880f049e95c8 ffff880565b9d9b0 ffff880565b9d980 ffff880f049e95f8
Apr 30 11:47:10 ip-172-26-0-157 kernel: Call Trace:
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] schedule+0x29/0x70
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] cv_wait_common+0x135/0x1c0 [spl]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] ? bit_waitqueue+0xe0/0xe0
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] __cv_wait+0x15/0x20 [spl]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] traverse_prefetcher+0xb5/0x170 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x2ce/0x6f0 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] ? kmem_alloc_debug+0x53/0x230 [spl]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] ? arc_buf_evict+0x380/0x380 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] traverse_dnode+0x6c/0xf0 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x56d/0x6f0 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] traverse_dnode+0x6c/0xf0 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x610/0x6f0 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] ? sched_clock_cpu+0x98/0xc0
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] ? __switch_to+0x17d/0x5e0
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] traverse_prefetch_thread+0x83/0xe0 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] ? traverse_prefetch_thread+0xe0/0xe0 [zfs]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] taskq_thread+0x22d/0x4f0 [spl]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] ? try_to_wake_up+0x230/0x230
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] ? task_expire+0x120/0x120 [spl]
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] kthread+0xce/0xf0
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] ret_from_fork+0x7c/0xb0
Apr 30 11:47:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:51:10 ip-172-26-0-157 kernel: INFO: task spl_system_task:2157 blocked for more than 120 seconds.
Apr 30 11:51:10 ip-172-26-0-157 kernel: Tainted: P O 3.14.4 #1
Apr 30 11:51:10 ip-172-26-0-157 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr 30 11:51:10 ip-172-26-0-157 kernel: spl_system_task D ffffffff8181d000 0 2157 2 0x00000000
Apr 30 11:51:10 ip-172-26-0-157 kernel: ffff880f047e17d8 0000000000000046 0000000000000040 ffff880f047e0010
Apr 30 11:51:10 ip-172-26-0-157 kernel: 0000000000014440 0000000000014440 ffff880f03a36390 ffff880f05caaef0
Apr 30 11:51:10 ip-172-26-0-157 kernel: ffff880f047e17e8 ffff880410e21e70 ffff880410e21e40 ffff880f047e1818
Apr 30 11:51:10 ip-172-26-0-157 kernel: Call Trace:
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] schedule+0x29/0x70
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] cv_wait_common+0x135/0x1c0 [spl]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] ? bit_waitqueue+0xe0/0xe0
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] __cv_wait+0x15/0x20 [spl]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] traverse_prefetcher+0xb5/0x170 [zfs]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] ? arc_buf_remove_ref+0xe6/0x130 [zfs]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x2ce/0x6f0 [zfs]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] traverse_dnode+0x6c/0xf0 [zfs]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x610/0x6f0 [zfs]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] ? __switch_to+0x17d/0x5e0
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] traverse_prefetch_thread+0x83/0xe0 [zfs]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] ? traverse_prefetch_thread+0xe0/0xe0 [zfs]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] taskq_thread+0x22d/0x4f0 [spl]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] ? try_to_wake_up+0x230/0x230
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] ? task_expire+0x120/0x120 [spl]
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] kthread+0xce/0xf0
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] ret_from_fork+0x7c/0xb0
Apr 30 11:51:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:53:07 ip-172-26-0-157 dhclient[2815]: DHCPREQUEST on eth0 to 172.26.0.1 port 67 (xid=0x2ec91cb9)
Apr 30 11:53:07 ip-172-26-0-157 dhclient[2815]: DHCPACK from 172.26.0.1 (xid=0x2ec91cb9)
Apr 30 11:53:09 ip-172-26-0-157 dhclient[2815]: bound to 172.26.0.157 -- renewal in 1600 seconds.
Apr 30 11:53:10 ip-172-26-0-157 kernel: INFO: task spl_system_task:2153 blocked for more than 120 seconds.
Apr 30 11:53:10 ip-172-26-0-157 kernel: Tainted: P O 3.14.4 #1
Apr 30 11:53:10 ip-172-26-0-157 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr 30 11:53:10 ip-172-26-0-157 kernel: spl_system_task D ffffffff8181d000 0 2153 2 0x00000000
Apr 30 11:53:10 ip-172-26-0-157 kernel: ffff880f049e9748 0000000000000046 0000000000000001 ffff880f049e8010
Apr 30 11:53:10 ip-172-26-0-157 kernel: 0000000000014440 0000000000014440 ffff880f05eccf30 ffff880f05caaef0
Apr 30 11:53:10 ip-172-26-0-157 kernel: ffff880f049e9758 ffff8801ad962530 ffff8801ad962500 ffff880f049e9788
Apr 30 11:53:10 ip-172-26-0-157 kernel: Call Trace:
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] schedule+0x29/0x70
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] cv_wait_common+0x135/0x1c0 [spl]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? bit_waitqueue+0xe0/0xe0
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] __cv_wait+0x15/0x20 [spl]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_prefetcher+0xb5/0x170 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x2ce/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? traverse_prefetch_metadata+0x92/0xa0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_dnode+0x6c/0xf0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x610/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? sched_clock_cpu+0x98/0xc0
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? __switch_to+0x17d/0x5e0
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_prefetch_thread+0x83/0xe0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? traverse_prefetch_thread+0xe0/0xe0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] taskq_thread+0x22d/0x4f0 [spl]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? try_to_wake_up+0x230/0x230
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? task_expire+0x120/0x120 [spl]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] kthread+0xce/0xf0
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ret_from_fork+0x7c/0xb0
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:53:10 ip-172-26-0-157 kernel: INFO: task spl_system_task:2157 blocked for more than 120 seconds.
Apr 30 11:53:10 ip-172-26-0-157 kernel: Tainted: P O 3.14.4 #1
Apr 30 11:53:10 ip-172-26-0-157 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr 30 11:53:10 ip-172-26-0-157 kernel: spl_system_task D ffffffff8181d000 0 2157 2 0x00000000
Apr 30 11:53:10 ip-172-26-0-157 kernel: ffff880f047e17d8 0000000000000046 0000000000000040 ffff880f047e0010
Apr 30 11:53:10 ip-172-26-0-157 kernel: 0000000000014440 0000000000014440 ffff880f03a36390 ffff880f05caaef0
Apr 30 11:53:10 ip-172-26-0-157 kernel: ffff880f047e17e8 ffff880410e21e70 ffff880410e21e40 ffff880f047e1818
Apr 30 11:53:10 ip-172-26-0-157 kernel: Call Trace:
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] schedule+0x29/0x70
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] cv_wait_common+0x135/0x1c0 [spl]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? bit_waitqueue+0xe0/0xe0
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] __cv_wait+0x15/0x20 [spl]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_prefetcher+0xb5/0x170 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? arc_buf_remove_ref+0xe6/0x130 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x2ce/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_dnode+0x6c/0xf0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x610/0x6f0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? __switch_to+0x17d/0x5e0
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] traverse_prefetch_thread+0x83/0xe0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? traverse_prefetch_thread+0xe0/0xe0 [zfs]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] taskq_thread+0x22d/0x4f0 [spl]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? try_to_wake_up+0x230/0x230
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? task_expire+0x120/0x120 [spl]
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] kthread+0xce/0xf0
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ret_from_fork+0x7c/0xb0
Apr 30 11:53:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:57:10 ip-172-26-0-157 kernel: INFO: task spl_system_task:2158 blocked for more than 120 seconds.
Apr 30 11:57:10 ip-172-26-0-157 kernel: Tainted: P O 3.14.4 #1
Apr 30 11:57:10 ip-172-26-0-157 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr 30 11:57:10 ip-172-26-0-157 kernel: spl_system_task D ffffffff8181d000 0 2158 2 0x00000000
Apr 30 11:57:10 ip-172-26-0-157 kernel: ffff880f040b75b8 0000000000000046 0000000000040000 ffff880f040b6010
Apr 30 11:57:10 ip-172-26-0-157 kernel: 0000000000014440 0000000000014440 ffff880f035def70 ffff880f05caa150
Apr 30 11:57:10 ip-172-26-0-157 kernel: ffff880f040b75c8 ffff8801ade91570 ffff8801ade91540 ffff880f040b75f8
Apr 30 11:57:10 ip-172-26-0-157 kernel: Call Trace:
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] schedule+0x29/0x70
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] cv_wait_common+0x135/0x1c0 [spl]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] ? bit_waitqueue+0xe0/0xe0
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] __cv_wait+0x15/0x20 [spl]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] traverse_prefetcher+0xb5/0x170 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x2ce/0x6f0 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] ? kmem_alloc_debug+0x53/0x230 [spl]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] ? arc_buf_evict+0x380/0x380 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] traverse_dnode+0x6c/0xf0 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x56d/0x6f0 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] traverse_dnode+0x6c/0xf0 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x610/0x6f0 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] ? sched_clock_cpu+0x98/0xc0
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] ? __switch_to+0x17d/0x5e0
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] traverse_prefetch_thread+0x83/0xe0 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] ? traverse_prefetch_thread+0xe0/0xe0 [zfs]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] taskq_thread+0x22d/0x4f0 [spl]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] ? try_to_wake_up+0x230/0x230
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] ? task_expire+0x120/0x120 [spl]
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] kthread+0xce/0xf0
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] ret_from_fork+0x7c/0xb0
Apr 30 11:57:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:59:10 ip-172-26-0-157 kernel: INFO: task spl_system_task:2153 blocked for more than 120 seconds.
Apr 30 11:59:10 ip-172-26-0-157 kernel: Tainted: P O 3.14.4 #1
Apr 30 11:59:10 ip-172-26-0-157 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr 30 11:59:10 ip-172-26-0-157 kernel: spl_system_task D ffffffff8181d000 0 2153 2 0x00000000
Apr 30 11:59:10 ip-172-26-0-157 kernel: ffff880f049e9748 0000000000000046 ffff880f049e9738 ffff880f049e8010
Apr 30 11:59:10 ip-172-26-0-157 kernel: 0000000000014440 0000000000014440 ffff880f05eccf30 ffff880f05cc2fb0
Apr 30 11:59:10 ip-172-26-0-157 kernel: ffff880f049e9758 ffff880cee7929b0 ffff880cee792980 ffff880f049e9788
Apr 30 11:59:10 ip-172-26-0-157 kernel: Call Trace:
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] schedule+0x29/0x70
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] cv_wait_common+0x135/0x1c0 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? add_reference+0xf1/0x120 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? zio_data_buf_free+0x30/0x30 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? bit_waitqueue+0xe0/0xe0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] __cv_wait+0x15/0x20 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_prefetcher+0xb5/0x170 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? arc_buf_remove_ref+0xe6/0x130 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x2ce/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_dnode+0x6c/0xf0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x610/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? sched_clock_cpu+0x98/0xc0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? __switch_to+0x17d/0x5e0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_prefetch_thread+0x83/0xe0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? traverse_prefetch_thread+0xe0/0xe0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] taskq_thread+0x22d/0x4f0 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? try_to_wake_up+0x230/0x230
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? task_expire+0x120/0x120 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] kthread+0xce/0xf0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ret_from_fork+0x7c/0xb0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:59:10 ip-172-26-0-157 kernel: INFO: task spl_system_task:2156 blocked for more than 120 seconds.
Apr 30 11:59:10 ip-172-26-0-157 kernel: Tainted: P O 3.14.4 #1
Apr 30 11:59:10 ip-172-26-0-157 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr 30 11:59:10 ip-172-26-0-157 kernel: spl_system_task D 0000000000000002 0 2156 2 0x00000000
Apr 30 11:59:10 ip-172-26-0-157 kernel: ffff880f02e6b748 0000000000000046 ffff880f02e6b738 ffff880f02e6a010
Apr 30 11:59:10 ip-172-26-0-157 kernel: 0000000000014440 0000000000014440 ffff880f03a37130 ffff880ee8ed4350
Apr 30 11:59:10 ip-172-26-0-157 kernel: ffff880f02e6b758 ffff88005ec96f30 ffff88005ec96f00 ffff880f02e6b788
Apr 30 11:59:10 ip-172-26-0-157 kernel: Call Trace:
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] schedule+0x29/0x70
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] cv_wait_common+0x135/0x1c0 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? add_reference+0xf1/0x120 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? bit_waitqueue+0xe0/0xe0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] __cv_wait+0x15/0x20 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_prefetcher+0xb5/0x170 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? arc_buf_remove_ref+0xe6/0x130 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x2ce/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_dnode+0x6c/0xf0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x610/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? __switch_to+0x17d/0x5e0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_prefetch_thread+0x83/0xe0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? traverse_prefetch_thread+0xe0/0xe0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] taskq_thread+0x22d/0x4f0 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? try_to_wake_up+0x230/0x230
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? task_expire+0x120/0x120 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] kthread+0xce/0xf0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ret_from_fork+0x7c/0xb0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:59:10 ip-172-26-0-157 kernel: INFO: task spl_system_task:2157 blocked for more than 120 seconds.
Apr 30 11:59:10 ip-172-26-0-157 kernel: Tainted: P O 3.14.4 #1
Apr 30 11:59:10 ip-172-26-0-157 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr 30 11:59:10 ip-172-26-0-157 kernel: spl_system_task D ffffffff8181d000 0 2157 2 0x00000000
Apr 30 11:59:10 ip-172-26-0-157 kernel: ffff880f047e1748 0000000000000046 0000000000000001 ffff880f047e0010
Apr 30 11:59:10 ip-172-26-0-157 kernel: 0000000000014440 0000000000014440 ffff880f03a36390 ffff880f05cbaf70
Apr 30 11:59:10 ip-172-26-0-157 kernel: ffff880f047e1758 ffff880518c5e870 ffff880518c5e840 ffff880f047e1788
Apr 30 11:59:10 ip-172-26-0-157 kernel: Call Trace:
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] schedule+0x29/0x70
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] cv_wait_common+0x135/0x1c0 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? bit_waitqueue+0xe0/0xe0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] __cv_wait+0x15/0x20 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_prefetcher+0xb5/0x170 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x2ce/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? traverse_prefetch_metadata+0x92/0xa0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_dnode+0x6c/0xf0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x610/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? sched_clock_cpu+0x98/0xc0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? __switch_to+0x17d/0x5e0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_prefetch_thread+0x83/0xe0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? traverse_prefetch_thread+0xe0/0xe0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] taskq_thread+0x22d/0x4f0 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? try_to_wake_up+0x230/0x230
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? task_expire+0x120/0x120 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] kthread+0xce/0xf0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ret_from_fork+0x7c/0xb0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? kthread_freezable_should_stop+0x70/0x70
Apr 30 11:59:10 ip-172-26-0-157 kernel: INFO: task spl_system_task:2158 blocked for more than 120 seconds.
Apr 30 11:59:10 ip-172-26-0-157 kernel: Tainted: P O 3.14.4 #1
Apr 30 11:59:10 ip-172-26-0-157 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr 30 11:59:10 ip-172-26-0-157 kernel: spl_system_task D ffffffff8181d000 0 2158 2 0x00000000
Apr 30 11:59:10 ip-172-26-0-157 kernel: ffff880f040b75b8 0000000000000046 0000000000040000 ffff880f040b6010
Apr 30 11:59:10 ip-172-26-0-157 kernel: 0000000000014440 0000000000014440 ffff880f035def70 ffff880f05caa150
Apr 30 11:59:10 ip-172-26-0-157 kernel: ffff880f040b75c8 ffff8801ade91570 ffff8801ade91540 ffff880f040b75f8
Apr 30 11:59:10 ip-172-26-0-157 kernel: Call Trace:
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] schedule+0x29/0x70
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] cv_wait_common+0x135/0x1c0 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? bit_waitqueue+0xe0/0xe0
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] __cv_wait+0x15/0x20 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_prefetcher+0xb5/0x170 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x2ce/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? kmem_alloc_debug+0x53/0x230 [spl]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] ? arc_buf_evict+0x380/0x380 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_visitbp+0x458/0x6f0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [] traverse_dnode+0x6c/0xf0 [zfs]
Apr 30 11:59:10 ip-172-26-0-157 kernel: [

@kernelOfTruth
Copy link
Contributor

@eolson78 , @tobias-k for good measure you might want to add #3367 which solves #3349 , but also doesn't appear to be closely related to your output

perhaps that mitigates things ?

@kernelOfTruth
Copy link
Contributor

@behlendorf Houston, we've got a (stack) problem: #675

(?)

Below is a real world example of traverse_visitbp() causing a stack overrun. It's responsible for nearly 2k of the stack, if this recursive function could be reworked to an iterative implementation it would help considerably.

#675 (comment)

@kernelOfTruth
Copy link
Contributor

Also related ?

https://www.illumos.org/issues/4820

Panic in zfs_ereport_start_checksum when checksum error is EINVAL

Crash stack is the following:

ffffff005ca12cc0 zfs_ereport_start_checksum+0xa6(ffffff0d34a0f000, 0, ffffff11106134b0, 0, 18200, 0, ffffff005ca12ce0)
ffffff005ca12d50 zio_checksum_verify+0x7b(ffffff11106134b0)
ffffff005ca12d90 zio_execute+0x88(ffffff11106134b0)
ffffff005ca12dd0 zio_wait+0x37(ffffff11106134b0)
ffffff005ca12ec0 arc_read+0x5bd(0, ffffff0d34a0f000, ffffff0d8f559980, fffffffff799fde0, ffffff005ca12f10, 2, ffffff0000000040, ffffff005ca12f1c, ffffff005ca13080)
ffffff005ca12f80 backup_cb+0x119(ffffff0d34a0f000, 0, ffffff0d8f559980, ffffff005ca13080, ffffff0d8f559800, ffffff0e02ca53c0)
ffffff005ca13060 traverse_visitbp+0x231(ffffff005ca138b0, ffffff0d8f559800, ffffff0d8f559980, ffffff005ca13080)
ffffff005ca130f0 traverse_dnode+0xf6(ffffff005ca138b0, ffffff0d8f559800, 119a, 64)
ffffff005ca131d0 traverse_visitbp+0x55e(ffffff005ca138b0, ffffff0dbb114000, ffffff0e09832180, ffffff005ca13230)
ffffff005ca132b0 traverse_visitbp+0x43a(ffffff005ca138b0, ffffff0dbb114000, ffffff0d7bde7000, ffffff005ca13310)
ffffff005ca13390 traverse_visitbp+0x43a(ffffff005ca138b0, ffffff0dbb114000, ffffff0e098a9000, ffffff005ca133f0)
ffffff005ca13470 traverse_visitbp+0x43a(ffffff005ca138b0, ffffff0dbb114000, ffffff0d8f4fd000, ffffff005ca134d0)
ffffff005ca13550 traverse_visitbp+0x43a(ffffff005ca138b0, ffffff0dbb114000, ffffff0da8479000, ffffff005ca135b0)
ffffff005ca13630 traverse_visitbp+0x43a(ffffff005ca138b0, ffffff0dbb114000, ffffff0db577c000, ffffff005ca13690)
ffffff005ca13710 traverse_visitbp+0x43a(ffffff005ca138b0, ffffff0dbb114000, ffffff0dbb114040, ffffff005ca13730)
ffffff005ca137a0 traverse_dnode+0x8b(ffffff005ca138b0, ffffff0dbb114000, 119a, 0)
ffffff005ca13880 traverse_visitbp+0x625(ffffff005ca138b0, 0, ffffff0d5b076280, ffffff005ca13900)
ffffff005ca139b0 traverse_impl+0x158(ffffff0d34a0f000, ffffff0d5e8c9cc0, 119a, ffffff0d5b076280, 0, 0, ffffff000000000d, fffffffff79b0040, ffffff0e02ca53c0)
ffffff005ca13a10 traverse_dataset+0x54(ffffff0d5e8c9cc0, 0, d, fffffffff79b0040, ffffff0e02ca53c0)
ffffff005ca13ab0 dmu_send_impl+0x2ea(fffffffff7a57726, ffffff0d5a4b8600, ffffff0d5e8c9cc0, 0, 0, 1, ffffff0d360d6480, ffffff005ca13b98)
ffffff005ca13b70 dmu_send_obj+0x175(ffffff0e08507000, 119a, 0, 1, ffffff0d360d6480, ffffff005ca13b98)
ffffff005ca13bd0 zfs_ioc_send+0xc1(ffffff0e08507000)
ffffff005ca13c80 zfsdev_ioctl+0x4a7(8600000000, 5a1c, 8044c40, 100003, ffffff0d662ef910, ffffff005ca13e68)
ffffff005ca13cc0 cdev_ioctl+0x39(8600000000, 5a1c, 8044c40, 100003, ffffff0d662ef910, ffffff005ca13e68)
ffffff005ca13d10 spec_ioctl+0x60(ffffff0d5ba69980, 5a1c, 8044c40, 100003, ffffff0d662ef910, ffffff005ca13e68, 0)
ffffff005ca13da0 fop_ioctl+0x55(ffffff0d5ba69980, 5a1c, 8044c40, 100003, ffffff0d662ef910, ffffff005ca13e68, 0)
ffffff005ca13ec0 ioctl+0x9b(4, 5a1c, 8044c40)
ffffff005ca13f10 _sys_sysenter_post_swapgs+0x149()

This happens during a zfs send, but it could happen in other cases. The mechanism that created this situation is different, and this case does not attempt to discuss the motives for creating this situation.
What this case is about is the problem in zio_checksum_verify that does not look at take a harder look at the return value from zio_checksum_error. The problem there is that the info structure (the checksum error details) is not allocated unless the error is CHKSUM. When the error is EINVAL (as in this crash), the info will contain whatever was previously on the stack and this will trigger a panic when reporting the checksum error.

@kernelOfTruth
Copy link
Contributor

Referencing:

#2873 (issue, kernel error on 3.16.7 during zfs send #2873)
#1948 (issue, ZFS/zpool hang on zfs destroying a ZVOL with a snapshot #1948)
#3148 (issue, random call trace on heavy load #3148)

a168788 (commit, Reduce stack for traverse_visitbp() recursion)

#3348 (pull, Fix misuse of input argument in traverse_visitbp #3348)

#2060 (issue, Possible bug in traverse_visitbp #2060)

@kernelOfTruth kernelOfTruth mentioned this issue Jul 25, 2015
Closed
@behlendorf
Copy link
Contributor

@kernelOfTruth I wondered about a stack issue since we've had that issue down this call path before. But I didn't see any conclusive evidence of that in the the stack trace. One fairly easy way to confirm this would be to jump forward to a 3.15 or newer kernel when the default kernel stack size was doubled. If this is a stack issue that will resolve it.

@kernelOfTruth kernelOfTruth mentioned this issue Aug 1, 2015
Closed
@kernelOfTruth kernelOfTruth mentioned this issue Sep 6, 2015
Closed
@kernelOfTruth kernelOfTruth mentioned this issue Nov 7, 2015
Closed
@kernelOfTruth kernelOfTruth mentioned this issue Feb 4, 2016
Closed
@behlendorf
Copy link
Contributor

Closing, this is believed to have been resolved.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@behlendorf @dasjoe @kernelOfTruth @eolson78 @tobias-k