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

[load-related ?] INFO: task arc_adapt:10568 blocked for more than 180 seconds. #3142

Closed
kernelOfTruth opened this issue Mar 1, 2015 · 4 comments
Closed

[load-related ?] INFO: task arc_adapt:10568 blocked for more than 180 seconds. #3142

kernelOfTruth opened this issue Mar 1, 2015 · 4 comments
Milestone
0.6.4

Comments

@kernelOfTruth
Copy link
Contributor

Hi,

I just had a system semi to full-hang while having it do the two taxing tasks:

  • btrfsck (in the past or still - at least Btrfs scrub was known to cause OOMs - no OOM or out of memory error though)
  • compilation of llvm 3.6

while doing that firefox & chromium (youtube background music) were also running a few additional minor apps

No swap was used at all, zswap is used, a swap-device on zram 12 GB, a 12 GB /var/tmp/portage partition via zram on which llvm was compiled

In addition to that two 60 GB partitions (currently no other use for those) with ZFS, one zvol on each with 8 GB were activated

I'll see if that error occurs again but this time leaving the swaps on the zvols out of the picture

Does this ring a bell for someone ?

dmesg output was as follows:

[24490.384353] INFO: task arc_adapt:10568 blocked for more than 180 seconds.
[24490.384357]       Tainted: P        W  O   3.19.0-plus-v8-r4 #1
[24490.384357] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24490.384359] arc_adapt       D ffff8807e4ff7d18     0 10568      2 0x00000000
[24490.384362]  ffff8807e4ff7d18 ffff8807e4ff7c78 0000000000013040 ffff8807ea6a03a0
[24490.384363]  ffff8806afe71e40 000000000000d090 000000000000d088 000015fb1dfbe549
[24490.384365]  0000000000000005 ffff8807fa808790 ffffffff81b1c501 ffff8806afe71e40
[24490.384367] Call Trace:
[24490.384373]  [<ffffffff81b1c501>] ? _raw_spin_trylock+0x41/0x80
[24490.384377]  [<ffffffff811068f4>] ? mutex_optimistic_spin+0x54/0x1f0
[24490.384384]  [<ffffffff81b18b6e>] schedule_preempt_disabled+0x2e/0x80
[24490.384386]  [<ffffffff81b1aa65>] __mutex_lock_slowpath+0xa5/0x140
[24490.384389]  [<ffffffff81b1ab16>] mutex_lock+0x16/0x30
[24490.384394]  [<ffffffffc0642eed>] __cv_wait_io+0xdd/0x180 [spl]
[24490.384396]  [<ffffffff81105ca0>] ? wait_woken+0x90/0x90
[24490.384404]  [<ffffffffc06a3b50>] ? arc_space_return+0x1910/0x3e60 [zfs]
[24490.384407]  [<ffffffffc0642fae>] __cv_timedwait_interruptible+0xe/0x10 [spl]
[24490.384411]  [<ffffffffc06a3caf>] arc_space_return+0x1a6f/0x3e60 [zfs]
[24490.384414]  [<ffffffffc06a3b50>] ? arc_space_return+0x1910/0x3e60 [zfs]
[24490.384417]  [<ffffffffc063e4a5>] __thread_exit+0x95/0xb0 [spl]
[24490.384419]  [<ffffffffc063e430>] ? __thread_exit+0x20/0xb0 [spl]
[24490.384421]  [<ffffffff810f7a85>] kthread+0xe5/0x100
[24490.384423]  [<ffffffff810f79a0>] ? kthread_create_on_node+0x1b0/0x1b0
[24490.384425]  [<ffffffff81b1ceac>] ret_from_fork+0x7c/0xb0
[24490.384427]  [<ffffffff810f79a0>] ? kthread_create_on_node+0x1b0/0x1b0
[24490.384429] INFO: task l2arc_feed:10577 blocked for more than 180 seconds.
[24490.384430]       Tainted: P        W  O   3.19.0-plus-v8-r4 #1
[24490.384431] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24490.384432] l2arc_feed      D ffff8807e481b3b8     0 10577      2 0x00000000
[24490.384433]  ffff8807e481b3b8 ffff8807ecf7f170 0000000000013040 ffff8807ecf7f510
[24490.384435]  ffff8800d1a9c410 000000000000d090 000000000000d088 000015fb0978b48e
[24490.384436]  0000000000000002 ffff8807fb2869e0 ffffffff81102701 ffff8800d1a9c410
[24490.384438] Call Trace:
[24490.384440]  [<ffffffff81102701>] ? preempt_count_add+0x41/0xb0
[24490.384441]  [<ffffffff81b18b78>] ? schedule_preempt_disabled+0x38/0x80
[24490.384443]  [<ffffffff81106a2d>] ? mutex_optimistic_spin+0x18d/0x1f0
[24490.384446]  [<ffffffff81b18b6e>] schedule_preempt_disabled+0x2e/0x80
[24490.384447]  [<ffffffff81b1aa65>] __mutex_lock_slowpath+0xa5/0x140
[24490.384449]  [<ffffffff81b1ab16>] mutex_lock+0x16/0x30
[24490.384453]  [<ffffffffc06a25c4>] arc_space_return+0x384/0x3e60 [zfs]
[24490.384459]  [<ffffffffc06a3b0b>] arc_space_return+0x18cb/0x3e60 [zfs]
[24490.384463]  [<ffffffffc06a7469>] arc_shrink+0xa9/0x340 [zfs]
[24490.384466]  [<ffffffffc06a7561>] arc_shrink+0x1a1/0x340 [zfs]
[24490.384470]  [<ffffffffc06a75e8>] arc_shrink+0x228/0x340 [zfs]
[24490.384473]  [<ffffffffc06a76b2>] arc_shrink+0x2f2/0x340 [zfs]
[24490.384476]  [<ffffffff811a40e1>] shrink_node_slabs+0x1c1/0x3b0
[24490.384478]  [<ffffffff811a6ab3>] shrink_zone+0x153/0x1b0
[24490.384480]  [<ffffffff811a6ccf>] do_try_to_free_pages+0x1bf/0x3b0
[24490.384481]  [<ffffffff811a6f9a>] try_to_free_pages+0xda/0x1c0
[24490.384484]  [<ffffffff8119ac70>] __alloc_pages_nodemask+0x5c0/0xaf0
[24490.384487]  [<ffffffffc063dab8>] ? spl_kmem_cache_alloc+0x88/0x840 [spl]
[24490.384489]  [<ffffffff811eac1a>] new_slab+0x6a/0x2e0
[24490.384491]  [<ffffffffc063dab8>] ? spl_kmem_cache_alloc+0x88/0x840 [spl]
[24490.384493]  [<ffffffff811ed620>] __slab_alloc.constprop.65+0x410/0x530
[24490.384495]  [<ffffffffc063dab8>] ? spl_kmem_cache_alloc+0x88/0x840 [spl]
[24490.384499]  [<ffffffff815a6977>] ? debug_smp_processor_id+0x17/0x20
[24490.384501]  [<ffffffff81b1c5b2>] ? _raw_spin_unlock_irq+0x12/0x30
[24490.384504]  [<ffffffff810fc5de>] ? finish_task_switch+0x4e/0xb0
[24490.384505]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.384507]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.384509]  [<ffffffffc063dab8>] ? spl_kmem_cache_alloc+0x88/0x840 [spl]
[24490.384510]  [<ffffffff811eeb41>] kmem_cache_alloc+0x141/0x190
[24490.384513]  [<ffffffffc063dab8>] spl_kmem_cache_alloc+0x88/0x840 [spl]
[24490.384515]  [<ffffffff81125879>] ? try_to_del_timer_sync+0x59/0x90
[24490.384516]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.384518]  [<ffffffffc063dab8>] ? spl_kmem_cache_alloc+0x88/0x840 [spl]
[24490.384524]  [<ffffffffc074e1cd>] zio_add_child+0x17d/0x7c0 [zfs]
[24490.384529]  [<ffffffffc074e86c>] zio_null+0x5c/0x60 [zfs]
[24490.384532]  [<ffffffffc06a5db0>] ? arc_space_return+0x3b70/0x3e60 [zfs]
[24490.384537]  [<ffffffffc074e889>] zio_root+0x19/0x20 [zfs]
[24490.384540]  [<ffffffffc06a5a86>] arc_space_return+0x3846/0x3e60 [zfs]
[24490.384545]  [<ffffffffc06a50d0>] ? arc_space_return+0x2e90/0x3e60 [zfs]
[24490.384547]  [<ffffffffc063e4a5>] __thread_exit+0x95/0xb0 [spl]
[24490.384549]  [<ffffffffc063e430>] ? __thread_exit+0x20/0xb0 [spl]
[24490.384551]  [<ffffffff810f7a85>] kthread+0xe5/0x100
[24490.384552]  [<ffffffff810f79a0>] ? kthread_create_on_node+0x1b0/0x1b0
[24490.384554]  [<ffffffff81b1ceac>] ret_from_fork+0x7c/0xb0
[24490.384555]  [<ffffffff810f79a0>] ? kthread_create_on_node+0x1b0/0x1b0
[24490.384620] INFO: task BrowserBlocking:4235 blocked for more than 180 seconds.
[24490.384621]       Tainted: P        W  O   3.19.0-plus-v8-r4 #1
[24490.384621] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24490.384622] BrowserBlocking D ffff8805aac138a8     0  4235   4218 0x00000000
[24490.384623]  ffff8805aac138a8 0000000000000003 0000000000013040 ffff8807fab92970
[24490.384625]  ffff8801ed78e250 000000000000d090 000000000000d088 000057fb435ae5d8
[24490.384627]  0000000000000007 ffff8807fa8096b0 ffff8807f69ef801 ffff8801ed78e250
[24490.384628] Call Trace:
[24490.384630]  [<ffffffff811068f4>] ? mutex_optimistic_spin+0x54/0x1f0
[24490.384633]  [<ffffffff81b18b6e>] schedule_preempt_disabled+0x2e/0x80
[24490.384634]  [<ffffffff81b1aa65>] __mutex_lock_slowpath+0xa5/0x140
[24490.384636]  [<ffffffff81b1ab16>] mutex_lock+0x16/0x30
[24490.384640]  [<ffffffffc06a1b68>] arc_write+0x758/0xb50 [zfs]
[24490.384644]  [<ffffffffc06a6367>] arc_buf_add_ref+0xc7/0x1a0 [zfs]
[24490.384649]  [<ffffffffc06ae6e6>] dbuf_read+0x9c6/0xe90 [zfs]
[24490.384651]  [<ffffffffc063bc59>] ? spl_kmem_zalloc+0x99/0x1d0 [spl]
[24490.384656]  [<ffffffffc06aec1d>] dbuf_hold_impl+0x6d/0x90 [zfs]
[24490.384660]  [<ffffffffc06aef79>] dbuf_hold_level+0x29/0x60 [zfs]
[24490.384666]  [<ffffffffc06c3cda>] dmu_tx_assign+0x4ea/0xca0 [zfs]
[24490.384673]  [<ffffffffc06c41b6>] dmu_tx_assign+0x9c6/0xca0 [zfs]
[24490.384676]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.384678]  [<ffffffff815a6977>] ? debug_smp_processor_id+0x17/0x20
[24490.384680]  [<ffffffff811ed922>] ? __kmalloc+0x1e2/0x1f0
[24490.384683]  [<ffffffffc063bc59>] ? spl_kmem_zalloc+0x99/0x1d0 [spl]
[24490.384688]  [<ffffffffc06c44c5>] dmu_tx_hold_write+0x35/0x50 [zfs]
[24490.384694]  [<ffffffffc073e9db>] zfs_write+0x39b/0xc70 [zfs]
[24490.384696]  [<ffffffff8112719a>] ? hrtimer_cancel+0x1a/0x30
[24490.384699]  [<ffffffff81138cf1>] ? futex_wait+0x201/0x280
[24490.384700]  [<ffffffff81126600>] ? hrtimer_get_res+0x50/0x50
[24490.384702]  [<ffffffff81137bbb>] ? futex_wake+0x7b/0x160
[24490.384705]  [<ffffffff811bf6ff>] ? do_wp_page+0x3cf/0x9a0
[24490.384706]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.384711]  [<ffffffffc075595f>] zpl_putpage+0xcff/0xd70 [zfs]
[24490.384713]  [<ffffffff811ff682>] vfs_write+0xb2/0x1f0
[24490.384715]  [<ffffffff81200300>] SyS_write+0x50/0xc0
[24490.384717]  [<ffffffff81041aec>] ? do_page_fault+0xc/0x10
[24490.384719]  [<ffffffff81b1cf56>] system_call_fastpath+0x16/0x1b
[24490.384721] INFO: task Chrome_DBThread:4236 blocked for more than 180 seconds.
[24490.384722]       Tainted: P        W  O   3.19.0-plus-v8-r4 #1
[24490.384722] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24490.384723] Chrome_DBThread D ffff8807757cb5f8     0  4236   4218 0x00000000
[24490.384725]  ffff8807757cb5f8 0000000000000000 0000000000013040 ffff880757d02970
[24490.384726]  ffff8801deeac410 000000000000d090 000000000000d088 000015fe3675e367
[24490.384728]  0000000000000005 ffff8807fa808790 0000000000000001 ffff8801deeac410
[24490.384729] Call Trace:
[24490.384731]  [<ffffffff811068f4>] ? mutex_optimistic_spin+0x54/0x1f0
[24490.384733]  [<ffffffff81b18b6e>] schedule_preempt_disabled+0x2e/0x80
[24490.384735]  [<ffffffff81b1aa65>] __mutex_lock_slowpath+0xa5/0x140
[24490.384737]  [<ffffffff81b1ab16>] mutex_lock+0x16/0x30
[24490.384740]  [<ffffffffc06a25c4>] arc_space_return+0x384/0x3e60 [zfs]
[24490.384744]  [<ffffffffc063dab8>] ? spl_kmem_cache_alloc+0x88/0x840 [spl]
[24490.384748]  [<ffffffffc06a2e28>] arc_space_return+0xbe8/0x3e60 [zfs]
[24490.384751]  [<ffffffffc06a61aa>] arc_buf_alloc+0x10a/0x140 [zfs]
[24490.384755]  [<ffffffffc06a6b28>] arc_read+0x3d8/0xa30 [zfs]
[24490.384756]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.384760]  [<ffffffffc06acd10>] ? dbuf_rele_and_unlock+0x3a0/0x4b0 [zfs]
[24490.384764]  [<ffffffffc06ae035>] dbuf_read+0x315/0xe90 [zfs]
[24490.384767]  [<ffffffffc063b900>] ? kmem_asprintf+0x60/0xa0 [spl]
[24490.384772]  [<ffffffffc06c3d3b>] dmu_tx_assign+0x54b/0xca0 [zfs]
[24490.384778]  [<ffffffffc06c3f8f>] dmu_tx_assign+0x79f/0xca0 [zfs]
[24490.384780]  [<ffffffff815a6977>] ? debug_smp_processor_id+0x17/0x20
[24490.384781]  [<ffffffff811ed922>] ? __kmalloc+0x1e2/0x1f0
[24490.384783]  [<ffffffffc063bc59>] ? spl_kmem_zalloc+0x99/0x1d0 [spl]
[24490.384789]  [<ffffffffc06c44c5>] dmu_tx_hold_write+0x35/0x50 [zfs]
[24490.384794]  [<ffffffffc073e9db>] zfs_write+0x39b/0xc70 [zfs]
[24490.384795]  [<ffffffff811ec745>] ? __slab_free+0xb5/0x350
[24490.384797]  [<ffffffff8112719a>] ? hrtimer_cancel+0x1a/0x30
[24490.384799]  [<ffffffff81138cf1>] ? futex_wait+0x201/0x280
[24490.384801]  [<ffffffff811bf6ff>] ? do_wp_page+0x3cf/0x9a0
[24490.384802]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.384806]  [<ffffffffc075595f>] zpl_putpage+0xcff/0xd70 [zfs]
[24490.384808]  [<ffffffff811ff682>] vfs_write+0xb2/0x1f0
[24490.384809]  [<ffffffff81200300>] SyS_write+0x50/0xc0
[24490.384811]  [<ffffffff811ff2ca>] ? SyS_lseek+0x4a/0xb0
[24490.384813]  [<ffffffff81b1cf56>] system_call_fastpath+0x16/0x1b
[24490.384814] INFO: task Chrome_FileThre:4237 blocked for more than 180 seconds.
[24490.384815]       Tainted: P        W  O   3.19.0-plus-v8-r4 #1
[24490.384815] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24490.384816] Chrome_FileThre D ffff88070adc7418     0  4237   4218 0x00000000
[24490.384817]  ffff88070adc7418 ffff88070adc7428 0000000000013040 ffff8807fa9412c0
[24490.384819]  ffff8800d2ac4ba0 000000000000d090 000000000000d088 000015fb9a5f1a58
[24490.384820]  0000000000000002 ffff8807fb2869e0 0000000c00000001 ffff8800d2ac4ba0
[24490.384822] Call Trace:
[24490.384824]  [<ffffffff811068f4>] ? mutex_optimistic_spin+0x54/0x1f0
[24490.384826]  [<ffffffff81b18b6e>] schedule_preempt_disabled+0x2e/0x80
[24490.384827]  [<ffffffff81b1aa65>] __mutex_lock_slowpath+0xa5/0x140
[24490.384829]  [<ffffffff81b1ab16>] mutex_lock+0x16/0x30
[24490.384833]  [<ffffffffc06a25c4>] arc_space_return+0x384/0x3e60 [zfs]
[24490.384836]  [<ffffffffc063dab8>] ? spl_kmem_cache_alloc+0x88/0x840 [spl]
[24490.384840]  [<ffffffffc06a2f7f>] arc_space_return+0xd3f/0x3e60 [zfs]
[24490.384843]  [<ffffffffc06a61aa>] arc_buf_alloc+0x10a/0x140 [zfs]
[24490.384847]  [<ffffffffc06a6b28>] arc_read+0x3d8/0xa30 [zfs]
[24490.384848]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.384852]  [<ffffffffc06acd10>] ? dbuf_rele_and_unlock+0x3a0/0x4b0 [zfs]
[24490.384856]  [<ffffffffc06ae035>] dbuf_read+0x315/0xe90 [zfs]
[24490.384862]  [<ffffffffc06c819a>] ? dnode_rele+0x5a/0x80 [zfs]
[24490.384868]  [<ffffffffc06b7410>] dmu_buf_hold+0x50/0x80 [zfs]
[24490.384875]  [<ffffffffc0719d8c>] zap_lockdir+0x5c/0x960 [zfs]
[24490.384876]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.384878]  [<ffffffff815a6977>] ? debug_smp_processor_id+0x17/0x20
[24490.384880]  [<ffffffff811eea51>] ? kmem_cache_alloc+0x51/0x190
[24490.384886]  [<ffffffffc071adc6>] zap_lookup_norm+0x56/0x1c0 [zfs]
[24490.384893]  [<ffffffffc071af5e>] zap_lookup+0x2e/0x30 [zfs]
[24490.384899]  [<ffffffffc07237b8>] zfs_dirent_lock+0x578/0x6e0 [zfs]
[24490.384905]  [<ffffffffc07239ad>] zfs_dirlook+0x8d/0x370 [zfs]
[24490.384911]  [<ffffffffc071ffe1>] ? zfs_zaccess+0xa1/0x490 [zfs]
[24490.384912]  [<ffffffff81102715>] ? preempt_count_add+0x55/0xb0
[24490.384918]  [<ffffffffc07394f9>] zfs_lookup+0x2f9/0x350 [zfs]
[24490.384922]  [<ffffffffc075622b>] zpl_fallocate_common+0x6db/0x750 [zfs]
[24490.384924]  [<ffffffff812090b8>] lookup_real+0x18/0x70
[24490.384926]  [<ffffffff8120f3c6>] do_last+0x7b6/0x11f0
[24490.384928]  [<ffffffff8120fe92>] path_openat+0x92/0x650
[24490.384929]  [<ffffffff81208380>] ? pipe_read+0x300/0x340
[24490.384931]  [<ffffffff81211654>] do_filp_open+0x44/0xc0
[24490.384933]  [<ffffffff81b1cbc6>] ? _raw_spin_lock+0x16/0x60
[24490.384934]  [<ffffffff81b1c551>] ? _raw_spin_unlock+0x11/0x30
[24490.384936]  [<ffffffff8121e3df>] ? __alloc_fd+0x9f/0x130
[24490.384938]  [<ffffffff811fe796>] do_sys_open+0x136/0x250
[24490.384939]  [<ffffffff811fe8c9>] SyS_open+0x19/0x20
[24490.384941]  [<ffffffff81b1cf56>] system_call_fastpath+0x16/0x1b
[24490.384943] INFO: task BrowserBlocking:4246 blocked for more than 180 seconds.
[24490.384944]       Tainted: P        W  O   3.19.0-plus-v8-r4 #1
[24490.384944] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24490.384945] BrowserBlocking D ffff88070b5f38a8     0  4246   4218 0x00000000
[24490.384946]  ffff88070b5f38a8 ffff88070b5f3838 0000000000013040 ffff8807fa944020
[24490.384948]  ffff88042503cba0 000000000000d090 000000000000d088 000015fb50e85ad3
[24490.384949]  0000000000000007 ffff8807fa8096b0 0000000000000001 ffff88042503cba0
[24490.384951] Call Trace:
[24490.384953]  [<ffffffff811068f4>] ? mutex_optimistic_spin+0x54/0x1f0
[24490.384955]  [<ffffffff81b18b6e>] schedule_preempt_disabled+0x2e/0x80
[24490.384957]  [<ffffffff81b1aa65>] __mutex_lock_slowpath+0xa5/0x140
[24490.384959]  [<ffffffff81b1ab16>] mutex_lock+0x16/0x30
[24490.384962]  [<ffffffffc06a1b68>] arc_write+0x758/0xb50 [zfs]
[24490.384966]  [<ffffffffc06a6367>] arc_buf_add_ref+0xc7/0x1a0 [zfs]
[24490.384970]  [<ffffffffc06ae6e6>] dbuf_read+0x9c6/0xe90 [zfs]
[24490.384972]  [<ffffffffc063bc59>] ? spl_kmem_zalloc+0x99/0x1d0 [spl]
[24490.384977]  [<ffffffffc06aec1d>] dbuf_hold_impl+0x6d/0x90 [zfs]
[24490.384981]  [<ffffffffc06aef79>] dbuf_hold_level+0x29/0x60 [zfs]
[24490.384986]  [<ffffffffc06c3cda>] dmu_tx_assign+0x4ea/0xca0 [zfs]
[24490.384991]  [<ffffffffc06c41b6>] dmu_tx_assign+0x9c6/0xca0 [zfs]
[24490.384993]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.384995]  [<ffffffff815a6977>] ? debug_smp_processor_id+0x17/0x20
[24490.384996]  [<ffffffff811ed922>] ? __kmalloc+0x1e2/0x1f0
[24490.384998]  [<ffffffffc063bc59>] ? spl_kmem_zalloc+0x99/0x1d0 [spl]
[24490.385004]  [<ffffffffc06c44c5>] dmu_tx_hold_write+0x35/0x50 [zfs]
[24490.385009]  [<ffffffffc073e9db>] zfs_write+0x39b/0xc70 [zfs]
[24490.385011]  [<ffffffff8112719a>] ? hrtimer_cancel+0x1a/0x30
[24490.385012]  [<ffffffff81138cf1>] ? futex_wait+0x201/0x280
[24490.385015]  [<ffffffff810fded5>] ? resched_curr+0x35/0x50
[24490.385016]  [<ffffffff81100c5c>] ? try_to_wake_up+0x7c/0x150
[24490.385018]  [<ffffffff81137b1f>] ? wake_futex+0x5f/0x80
[24490.385019]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.385023]  [<ffffffffc075595f>] zpl_putpage+0xcff/0xd70 [zfs]
[24490.385025]  [<ffffffff811ff682>] vfs_write+0xb2/0x1f0
[24490.385026]  [<ffffffff81200300>] SyS_write+0x50/0xc0
[24490.385028]  [<ffffffff81b1cf56>] system_call_fastpath+0x16/0x1b
[24490.385029] INFO: task Chrome_HistoryT:4260 blocked for more than 180 seconds.
[24490.385030]       Tainted: P        W  O   3.19.0-plus-v8-r4 #1
[24490.385031] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24490.385031] Chrome_HistoryT D ffff8807992ff4d8     0  4260   4218 0x00000000
[24490.385033]  ffff8807992ff4d8 0000000000000003 0000000000013040 ffff8807cca45e60
[24490.385034]  0000000000000000 000000000000d090 000000000000d088 ffffffffffffffff
[24490.385036]  0000000000000001 ffff8807fb286250 ffffffff81b1c501 ffff8807fb286250
[24490.385037] Call Trace:
[24490.385039]  [<ffffffff81b1c501>] ? _raw_spin_trylock+0x41/0x80
[24490.385041]  [<ffffffff811068f4>] ? mutex_optimistic_spin+0x54/0x1f0
[24490.385043]  [<ffffffff81b18b6e>] schedule_preempt_disabled+0x2e/0x80
[24490.385044]  [<ffffffff81b1aa65>] __mutex_lock_slowpath+0xa5/0x140
[24490.385046]  [<ffffffff81b1ab16>] mutex_lock+0x16/0x30
[24490.385050]  [<ffffffffc06a25c4>] arc_space_return+0x384/0x3e60 [zfs]
[24490.385053]  [<ffffffffc063dab8>] ? spl_kmem_cache_alloc+0x88/0x840 [spl]
[24490.385057]  [<ffffffffc06a2f7f>] arc_space_return+0xd3f/0x3e60 [zfs]
[24490.385061]  [<ffffffffc06a61aa>] arc_buf_alloc+0x10a/0x140 [zfs]
[24490.385064]  [<ffffffffc06a6b28>] arc_read+0x3d8/0xa30 [zfs]
[24490.385066]  [<ffffffff811eccb7>] ? kfree+0xa7/0x1d0
[24490.385068]  [<ffffffffc063b9cd>] ? spl_kmem_free+0x2d/0x40 [spl]
[24490.385072]  [<ffffffffc06aedb1>] dbuf_prefetch+0x171/0x2b0 [zfs]
[24490.385078]  [<ffffffffc06c5819>] dmu_tx_fini+0x129/0x1c0 [zfs]
[24490.385084]  [<ffffffffc06c616a>] dmu_zfetch+0x5da/0x1c90 [zfs]
[24490.385088]  [<ffffffffc06ae660>] dbuf_read+0x940/0xe90 [zfs]
[24490.385090]  [<ffffffffc063b901>] ? kmem_asprintf+0x61/0xa0 [spl]
[24490.385092]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.385097]  [<ffffffffc06c7c7d>] dnode_hold_impl+0x1dd/0x5c0 [zfs]
[24490.385103]  [<ffffffffc06c8074>] dnode_hold+0x14/0x20 [zfs]
[24490.385108]  [<ffffffffc06c32eb>] dmu_tx_callback_register+0x9b/0x180 [zfs]
[24490.385113]  [<ffffffffc06c33e0>] dmu_tx_hold_bonus+0x10/0x20 [zfs]
[24490.385118]  [<ffffffffc06c487b>] dmu_tx_hold_sa+0x3b/0x180 [zfs]
[24490.385124]  [<ffffffffc073e9ad>] zfs_write+0x36d/0xc70 [zfs]
[24490.385125]  [<ffffffff8112719a>] ? hrtimer_cancel+0x1a/0x30
[24490.385127]  [<ffffffff81138cf1>] ? futex_wait+0x201/0x280
[24490.385128]  [<ffffffff81126600>] ? hrtimer_get_res+0x50/0x50
[24490.385130]  [<ffffffff81137bbb>] ? futex_wake+0x7b/0x160
[24490.385132]  [<ffffffff811bf6ff>] ? do_wp_page+0x3cf/0x9a0
[24490.385133]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.385137]  [<ffffffffc075595f>] zpl_putpage+0xcff/0xd70 [zfs]
[24490.385139]  [<ffffffff811ff682>] vfs_write+0xb2/0x1f0
[24490.385140]  [<ffffffff81200300>] SyS_write+0x50/0xc0
[24490.385142]  [<ffffffff811ff2ca>] ? SyS_lseek+0x4a/0xb0
[24490.385144]  [<ffffffff81b1cf56>] system_call_fastpath+0x16/0x1b
[24490.385145] INFO: task BrowserBlocking:4265 blocked for more than 180 seconds.
[24490.385146]       Tainted: P        W  O   3.19.0-plus-v8-r4 #1
[24490.385146] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24490.385147] BrowserBlocking D ffff880798d4b418     0  4265   4218 0x00000000
[24490.385149]  ffff880798d4b418 ffff880798d4b3a8 0000000000013040 ffff8800d2ac7510
[24490.385150]  ffff8807ccf67170 000000000000d090 000000000000d088 000015fc332947a7
[24490.385152]  0000000000000006 ffff8807fa808f20 ffff8800d2ac7101 ffff8807ccf67170
[24490.385153] Call Trace:
[24490.385155]  [<ffffffff811068f4>] ? mutex_optimistic_spin+0x54/0x1f0
[24490.385157]  [<ffffffff81b18b6e>] schedule_preempt_disabled+0x2e/0x80
[24490.385158]  [<ffffffff81b1aa65>] __mutex_lock_slowpath+0xa5/0x140
[24490.385160]  [<ffffffff81b1ab16>] mutex_lock+0x16/0x30
[24490.385164]  [<ffffffffc06a25c4>] arc_space_return+0x384/0x3e60 [zfs]
[24490.385167]  [<ffffffffc063dab8>] ? spl_kmem_cache_alloc+0x88/0x840 [spl]
[24490.385171]  [<ffffffffc06a2f7f>] arc_space_return+0xd3f/0x3e60 [zfs]
[24490.385175]  [<ffffffffc06a61aa>] arc_buf_alloc+0x10a/0x140 [zfs]
[24490.385178]  [<ffffffffc06a6b28>] arc_read+0x3d8/0xa30 [zfs]
[24490.385180]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.385184]  [<ffffffffc06acd10>] ? dbuf_rele_and_unlock+0x3a0/0x4b0 [zfs]
[24490.385188]  [<ffffffffc06ae035>] dbuf_read+0x315/0xe90 [zfs]
[24490.385193]  [<ffffffffc06c819a>] ? dnode_rele+0x5a/0x80 [zfs]
[24490.385199]  [<ffffffffc06b7410>] dmu_buf_hold+0x50/0x80 [zfs]
[24490.385206]  [<ffffffffc0719d8c>] zap_lockdir+0x5c/0x960 [zfs]
[24490.385207]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24490.385209]  [<ffffffff815a6977>] ? debug_smp_processor_id+0x17/0x20
[24490.385210]  [<ffffffff811eea51>] ? kmem_cache_alloc+0x51/0x190
[24490.385217]  [<ffffffffc071adc6>] zap_lookup_norm+0x56/0x1c0 [zfs]
[24490.385223]  [<ffffffffc071af5e>] zap_lookup+0x2e/0x30 [zfs]
[24490.385229]  [<ffffffffc07237b8>] zfs_dirent_lock+0x578/0x6e0 [zfs]
[24490.385235]  [<ffffffffc07239ad>] zfs_dirlook+0x8d/0x370 [zfs]
[24490.385241]  [<ffffffffc071ffe1>] ? zfs_zaccess+0xa1/0x490 [zfs]
[24490.385243]  [<ffffffff81102715>] ? preempt_count_add+0x55/0xb0
[24490.385248]  [<ffffffffc07394f9>] zfs_lookup+0x2f9/0x350 [zfs]
[24490.385252]  [<ffffffffc075622b>] zpl_fallocate_common+0x6db/0x750 [zfs]
[24490.385254]  [<ffffffff812090b8>] lookup_real+0x18/0x70
[24490.385255]  [<ffffffff8120f3c6>] do_last+0x7b6/0x11f0
[24490.385257]  [<ffffffff8120fe92>] path_openat+0x92/0x650
[24490.385259]  [<ffffffff81b1c583>] ? _raw_spin_unlock_irqrestore+0x13/0x30
[24490.385260]  [<ffffffff81100c5c>] ? try_to_wake_up+0x7c/0x150
[24490.385261]  [<ffffffff811014ab>] ? wake_up_state+0xb/0x10
[24490.385263]  [<ffffffff81211654>] do_filp_open+0x44/0xc0
[24490.385265]  [<ffffffff81b1cbc6>] ? _raw_spin_lock+0x16/0x60
[24490.385266]  [<ffffffff81b1c551>] ? _raw_spin_unlock+0x11/0x30
[24490.385268]  [<ffffffff8121e3df>] ? __alloc_fd+0x9f/0x130
[24490.385269]  [<ffffffff811fe796>] do_sys_open+0x136/0x250
[24490.385271]  [<ffffffff811fe8c9>] SyS_open+0x19/0x20
[24490.385273]  [<ffffffff81b1cf56>] system_call_fastpath+0x16/0x1b
[24490.385281] INFO: task mozStorage #1:4665 blocked for more than 180 seconds.
[24490.385282]       Tainted: P        W  O   3.19.0-plus-v8-r4 #1
[24490.385282] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24490.385283] mozStorage #1   D ffff8807545ff6f8     0  4665  31256 0x00000000
[24490.385285]  ffff8807545ff6f8 ffff8807d0789000 0000000000013040 ffff8807c64fb890
[24490.385286]  ffff8801deeadac0 000000000000d090 000000000000d088 000015fe5a4c4690
[24490.385288]  0000000000000005 ffff8807fa808790 00000000ffffff01 ffff8801deeadac0
[24490.385289] Call Trace:
[24490.385291]  [<ffffffff811068f4>] ? mutex_optimistic_spin+0x54/0x1f0
[24490.385294]  [<ffffffff81b18b6e>] schedule_preempt_disabled+0x2e/0x80
[24490.385295]  [<ffffffff81b1aa65>] __mutex_lock_slowpath+0xa5/0x140
[24490.385297]  [<ffffffff81b1ab16>] mutex_lock+0x16/0x30
[24490.385301]  [<ffffffffc06a25c4>] arc_space_return+0x384/0x3e60 [zfs]
[24490.385309]  [<ffffffffc063dab8>] ? spl_kmem_cache_alloc+0x88/0x840 [spl]
[24490.385312]  [<ffffffffc063dab8>] ? spl_kmem_cache_alloc+0x88/0x840 [spl]
[24490.385316]  [<ffffffffc06a2f7f>] arc_space_return+0xd3f/0x3e60 [zfs]
[24490.385319]  [<ffffffffc06a61aa>] arc_buf_alloc+0x10a/0x140 [zfs]
[24490.385323]  [<ffffffffc06a6b28>] arc_read+0x3d8/0xa30 [zfs]
[24490.385327]  [<ffffffffc06acd10>] ? dbuf_rele_and_unlock+0x3a0/0x4b0 [zfs]
[24490.385331]  [<ffffffffc06ae035>] dbuf_read+0x315/0xe90 [zfs]
[24490.385333]  [<ffffffff81102715>] ? preempt_count_add+0x55/0xb0
[24490.385337]  [<ffffffffc06aeb22>] dbuf_read+0xe02/0xe90 [zfs]
[24490.385341]  [<ffffffffc06aec1d>] dbuf_hold_impl+0x6d/0x90 [zfs]
[24490.385345]  [<ffffffffc06aef1a>] dbuf_hold+0x2a/0x60 [zfs]
[24490.385350]  [<ffffffffc06b5eb6>] dmu_return_arcbuf+0x166/0x5b0 [zfs]
[24490.385355]  [<ffffffffc06b63ee>] dmu_buf_hold_array_by_bonus+0xee/0x2d0 [zfs]
[24490.385360]  [<ffffffffc06b806b>] dmu_read_uio+0x4b/0x100 [zfs]
[24490.385366]  [<ffffffffc0738bac>] zfs_read+0x13c/0x460 [zfs]
[24490.385370]  [<ffffffffc0755866>] zpl_putpage+0xc06/0xd70 [zfs]
[24490.385372]  [<ffffffff81200073>] __vfs_read+0x13/0x50
[24490.385373]  [<ffffffff81200135>] vfs_read+0x85/0x140
[24490.385375]  [<ffffffff81200240>] SyS_read+0x50/0xc0
[24490.385376]  [<ffffffff811ff2ca>] ? SyS_lseek+0x4a/0xb0
[24490.385378]  [<ffffffff81b1cf56>] system_call_fastpath+0x16/0x1b
[24670.460495] INFO: task kswapd0:252 blocked for more than 180 seconds.
[24670.460498]       Tainted: P        W  O   3.19.0-plus-v8-r4 #1
[24670.460499] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[24670.460500] kswapd0         D ffff8800dc333788     0   252      2 0x00000000
[24670.460503]  ffff8800dc333788 0000000000000000 0000000000013040 ffff8807f78c8b30
[24670.460505]  ffff88077d550790 000000000000d090 000000000000d088 0000161cb7011ba9
[24670.460507]  0000000000000004 ffff8807fa808000 ffffffff8158bd01 ffff88077d550790
[24670.460508] Call Trace:
[24670.460515]  [<ffffffff8158bd01>] ? parse_option_str+0x91/0xa0
[24670.460520]  [<ffffffff811068f4>] ? mutex_optimistic_spin+0x54/0x1f0
[24670.460528]  [<ffffffff81b18b6e>] schedule_preempt_disabled+0x2e/0x80
[24670.460530]  [<ffffffff81b1aa65>] __mutex_lock_slowpath+0xa5/0x140
[24670.460533]  [<ffffffff81b1ab16>] mutex_lock+0x16/0x30
[24670.460540]  [<ffffffffc06a1c84>] arc_write+0x874/0xb50 [zfs]
[24670.460545]  [<ffffffffc06a6665>] arc_buf_remove_ref+0xb5/0x130 [zfs]
[24670.460550]  [<ffffffffc06acabf>] dbuf_rele_and_unlock+0x14f/0x4b0 [zfs]
[24670.460553]  [<ffffffff815a6993>] ? __this_cpu_preempt_check+0x13/0x20
[24670.460557]  [<ffffffff811ad982>] ? __mod_zone_page_state+0x72/0xb0
[24670.460559]  [<ffffffff815a6993>] ? __this_cpu_preempt_check+0x13/0x20
[24670.460561]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24670.460566]  [<ffffffffc06ace41>] dbuf_rele+0x21/0x30 [zfs]
[24670.460573]  [<ffffffffc06c81b0>] dnode_rele+0x70/0x80 [zfs]
[24670.460577]  [<ffffffffc06acc9d>] dbuf_rele_and_unlock+0x32d/0x4b0 [zfs]
[24670.460579]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24670.460580]  [<ffffffff81102715>] ? preempt_count_add+0x55/0xb0
[24670.460581]  [<ffffffff81102681>] ? get_parent_ip+0x11/0x50
[24670.460583]  [<ffffffff81102715>] ? preempt_count_add+0x55/0xb0
[24670.460588]  [<ffffffffc06ad0b1>] dmu_buf_rele+0x21/0x570 [zfs]
[24670.460597]  [<ffffffffc06ebb41>] sa_handle_destroy+0x61/0xb0 [zfs]
[24670.460602]  [<ffffffffc0745ec0>] zfs_zinactive+0x100/0x1d0 [zfs]
[24670.460608]  [<ffffffffc073f61f>] zfs_inactive+0x5f/0x1f0 [zfs]
[24670.460610]  [<ffffffff81b1c927>] ? _raw_spin_lock_irq+0x17/0x60
[24670.460615]  [<ffffffffc0756aa3>] zpl_vap_init+0x803/0x9c0 [zfs]
[24670.460617]  [<ffffffff8121bd13>] evict+0xb3/0x1b0
[24670.460619]  [<ffffffff8121be49>] dispose_list+0x39/0x50
[24670.460620]  [<ffffffff8121ce81>] prune_icache_sb+0x51/0x80
[24670.460623]  [<ffffffff81202f25>] super_cache_scan+0x105/0x170
[24670.460625]  [<ffffffff811a40e1>] shrink_node_slabs+0x1c1/0x3b0
[24670.460627]  [<ffffffff811a6ab3>] shrink_zone+0x153/0x1b0
[24670.460629]  [<ffffffff811a76a2>] kswapd+0x582/0xa00
[24670.460631]  [<ffffffff811a7120>] ? shrink_all_memory+0xa0/0xa0
[24670.460632]  [<ffffffff810f7a85>] kthread+0xe5/0x100
[24670.460634]  [<ffffffff810f79a0>] ? kthread_create_on_node+0x1b0/0x1b0
[24670.460636]  [<ffffffff81b1ceac>] ret_from_fork+0x7c/0xb0
[24670.460637]  [<ffffffff810f79a0>] ? kthread_create_on_node+0x1b0/0x1b0
[24816.112382] reiserfs: enabling write barrier flush mode

perhaps related entries on the issue-tracker:

#641 [closed]

#1301 [open]

#1415 [closed]

http://bison-patches-gnu.git.net/zfs-discuss/msg07891.html [mailing list]

The kernel running is a heavily patched one based on 3.19 with BFS 460 cpu scheduler, a desktop-tailored slim low-latency scheduler

which has been known to be demanding to tasks, apps and hardware alike and helping to uncover inherent bugs & issues :)
@kernelOfTruth
Copy link
Contributor Author

The output actually looks somewhat related to #3132 , what @ryao wrote in #3050 (comment)

and the call trace of the suggested patch, ryao@916e29a

I also am running with an l2arc partition attached to /home

@kernelOfTruth
Copy link
Contributor Author

The used patchset on top of latest master (as of March 1st 2015) was:

@kernelOfTruth kernelOfTruth mentioned this issue Mar 2, 2015
Closed
@behlendorf
Copy link
Contributor

@kernelOfTruth this is the same issue #3132 was designed to address.

@behlendorf behlendorf added this to the 0.6.4 milestone Mar 2, 2015
@kernelOfTruth kernelOfTruth mentioned this issue Mar 3, 2015
Closed
@kernelOfTruth
Copy link
Contributor Author

@behlendorf thank you, running the pool(s) now with the fix from #3132 & openzfs/spl#435

@kernelOfTruth kernelOfTruth mentioned this issue Mar 7, 2015
Closed
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
0.6.4
Development

No branches or pull requests
2 participants
@behlendorf @kernelOfTruth