blocked for more than 120 seconds

[lr1980]

Dec 18 16:42:41 server kernel: [  242.179115] INFO: task l2arc_feed:805 blocked for more than 120 seconds.
Dec 18 16:42:41 server kernel: [  242.186214] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 18 16:42:41 server kernel: [  242.194517] l2arc_feed      D ffff88087fc54580     0   805      2 0x00000000
Dec 18 16:42:41 server kernel: [  242.194533]  ffff880842981d40 0000000000000046 ffff880842981fd8 0000000000014580
Dec 18 16:42:41 server kernel: [  242.194545]  ffff880842981fd8 0000000000014580 ffff88084fa9ddc0 ffffffffa08d4f20
Dec 18 16:42:41 server kernel: [  242.194555]  ffffffffa08d4f24 ffff88084fa9ddc0 00000000ffffffff ffffffffa08d4f28
Dec 18 16:42:41 server kernel: [  242.194566] Call Trace:
Dec 18 16:42:41 server kernel: [  242.194592]  [<ffffffff816eb9d9>] schedule_preempt_disabled+0x29/0x70
Dec 18 16:42:41 server kernel: [  242.194604]  [<ffffffff816e9a1f>] __mutex_lock_slowpath+0x13f/0x1c0
Dec 18 16:42:41 server kernel: [  242.194616]  [<ffffffff81085580>] ? wake_up_atomic_t+0x30/0x30
Dec 18 16:42:41 server kernel: [  242.194675]  [<ffffffffa07f9670>] ? l2arc_evict+0x320/0x320 [zfs]
Dec 18 16:42:41 server kernel: [  242.194685]  [<ffffffff816e8e0f>] mutex_lock+0x1f/0x2f
Dec 18 16:42:41 server kernel: [  242.194731]  [<ffffffffa07f9714>] l2arc_feed_thread+0xa4/0xa70 [zfs]
Dec 18 16:42:41 server kernel: [  242.194741]  [<ffffffff8109e514>] ? enqueue_task_fair+0x424/0x670
Dec 18 16:42:41 server kernel: [  242.194763]  [<ffffffffa054b34b>] ? kmem_free_debug+0x4b/0x150 [spl]
Dec 18 16:42:41 server kernel: [  242.194774]  [<ffffffff8118e4dd>] ? kfree+0xfd/0x130
Dec 18 16:42:41 server kernel: [  242.194793]  [<ffffffffa054b34b>] ? kmem_free_debug+0x4b/0x150 [spl]
Dec 18 16:42:41 server kernel: [  242.194803]  [<ffffffff81091c55>] ? set_user_nice+0xd5/0x180
Dec 18 16:42:41 server kernel: [  242.194848]  [<ffffffffa07f9670>] ? l2arc_evict+0x320/0x320 [zfs]
Dec 18 16:42:41 server kernel: [  242.194868]  [<ffffffffa054f71a>] thread_generic_wrapper+0x7a/0x90 [spl]
Dec 18 16:42:41 server kernel: [  242.194887]  [<ffffffffa054f6a0>] ? __thread_exit+0xa0/0xa0 [spl]
Dec 18 16:42:41 server kernel: [  242.194897]  [<ffffffff810847b0>] kthread+0xc0/0xd0
Dec 18 16:42:41 server kernel: [  242.194907]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Dec 18 16:42:41 server kernel: [  242.194917]  [<ffffffff816f566c>] ret_from_fork+0x7c/0xb0
Dec 18 16:42:41 server kernel: [  242.194926]  [<ffffffff810846f0>] ? kthread_create_on_node+0x120/0x120
Dec 18 16:42:41 server kernel: [  242.194976] INFO: task zpool:3516 blocked for more than 120 seconds.
Dec 18 16:42:41 server kernel: [  242.201699] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 18 16:42:41 server kernel: [  242.209988] zpool           D ffff88087fc54580     0  3516   3424 0x00000000
Dec 18 16:42:41 server kernel: [  242.210003]  ffff88076907ddb0 0000000000000046 ffff88076907dfd8 0000000000014580
Dec 18 16:42:41 server kernel: [  242.210015]  ffff88076907dfd8 0000000000014580 ffff88084ee8aee0 ffffffffa08d4f20
Dec 18 16:42:41 server kernel: [  242.210025]  ffffffffa08d4f24 ffff88084ee8aee0 00000000ffffffff ffffffffa08d4f28
Dec 18 16:42:41 server kernel: [  242.210036] Call Trace:
Dec 18 16:42:41 server kernel: [  242.210059]  [<ffffffff816eb9d9>] schedule_preempt_disabled+0x29/0x70
Dec 18 16:42:41 server kernel: [  242.210070]  [<ffffffff816e9a1f>] __mutex_lock_slowpath+0x13f/0x1c0
Dec 18 16:42:41 server kernel: [  242.210083]  [<ffffffff816e8e0f>] mutex_lock+0x1f/0x2f
Dec 18 16:42:41 server kernel: [  242.210158]  [<ffffffffa084bd50>] spa_all_configs+0x50/0x130 [zfs]
Dec 18 16:42:41 server kernel: [  242.210226]  [<ffffffffa0876a0b>] zfs_ioc_pool_configs+0x1b/0x50 [zfs]
Dec 18 16:42:41 server kernel: [  242.210292]  [<ffffffffa0877f6a>] zfsdev_ioctl+0xfa/0x1a0 [zfs]
Dec 18 16:42:41 server kernel: [  242.210304]  [<ffffffff811b8c55>] do_vfs_ioctl+0x2e5/0x4d0
Dec 18 16:42:41 server kernel: [  242.210314]  [<ffffffff8116da67>] ? do_munmap+0x297/0x3b0
Dec 18 16:42:41 server kernel: [  242.210324]  [<ffffffff811b8ec1>] SyS_ioctl+0x81/0xa0
Dec 18 16:42:41 server kernel: [  242.210334]  [<ffffffff816f571d>] system_call_fastpath+0x1a/0x1f
Dec 18 16:42:41 server kernel: [  242.210343] INFO: task zpool:3721 blocked for more than 120 seconds.
Dec 18 16:42:41 server kernel: [  242.217049] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 18 16:42:41 server kernel: [  242.225295] zpool           D ffff88087fc54580     0  3721   3720 0x00000004
Dec 18 16:42:41 server kernel: [  242.225309]  ffff880852723db0 0000000000000046 ffff880852723fd8 0000000000014580
Dec 18 16:42:41 server kernel: [  242.225320]  ffff880852723fd8 0000000000014580 ffff88084ee8c650 ffffffffa08d4f20
Dec 18 16:42:41 server kernel: [  242.225330]  ffffffffa08d4f24 ffff88084ee8c650 00000000ffffffff ffffffffa08d4f28
Dec 18 16:42:41 server kernel: [  242.225341] Call Trace:
Dec 18 16:42:41 server kernel: [  242.225360]  [<ffffffff816eb9d9>] schedule_preempt_disabled+0x29/0x70
Dec 18 16:42:41 server kernel: [  242.225371]  [<ffffffff816e9a1f>] __mutex_lock_slowpath+0x13f/0x1c0
Dec 18 16:42:41 server kernel: [  242.225383]  [<ffffffff816e8e0f>] mutex_lock+0x1f/0x2f
Dec 18 16:42:41 server kernel: [  242.225457]  [<ffffffffa084bd50>] spa_all_configs+0x50/0x130 [zfs]
Dec 18 16:42:41 server kernel: [  242.225526]  [<ffffffffa0876a0b>] zfs_ioc_pool_configs+0x1b/0x50 [zfs]
Dec 18 16:42:41 server kernel: [  242.225593]  [<ffffffffa0877f6a>] zfsdev_ioctl+0xfa/0x1a0 [zfs]
Dec 18 16:42:41 server kernel: [  242.225604]  [<ffffffff811b8c55>] do_vfs_ioctl+0x2e5/0x4d0
Dec 18 16:42:41 server kernel: [  242.225614]  [<ffffffff8116da67>] ? do_munmap+0x297/0x3b0
Dec 18 16:42:41 server kernel: [  242.225624]  [<ffffffff811b8ec1>] SyS_ioctl+0x81/0xa0
Dec 18 16:42:41 server kernel: [  242.225634]  [<ffffffff816f571d>] system_call_fastpath+0x1a/0x1f

i have regularly blocks... the above block comes after reboot and a first command: zpool status

system:
zfs-dkms 0.6.2-1~saucy

Linux server 3.11.0-14-generic #21-Ubuntu SMP Tue Nov 12 17:04:55 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux

4 1 0x01 84 4032 18237167894 567266514802
name                            type data
hits                            4    85233
misses                          4    618984
demand_data_hits                4    0
demand_data_misses              4    0
demand_metadata_hits            4    59110
demand_metadata_misses          4    136
prefetch_data_hits              4    0
prefetch_data_misses            4    1
prefetch_metadata_hits          4    26123
prefetch_metadata_misses        4    618847
mru_hits                        4    51625
mru_ghost_hits                  4    0
mfu_hits                        4    7485
mfu_ghost_hits                  4    0
deleted                         4    10
recycle_miss                    4    0
mutex_miss                      4    0
evict_skip                      4    0
evict_l2_cached                 4    0
evict_l2_eligible               4    0
evict_l2_ineligible             4    2048
hash_elements                   4    620162
hash_elements_max               4    620162
hash_collisions                 4    233113
hash_chains                     4    176201
hash_chain_max                  4    5
p                               4    5368709120
c                               4    10737418240
c_min                           4    2684354560
c_max                           4    10737418240
size                            4    2730938800
hdr_size                        4    218031152
data_size                       4    2512300032
other_size                      4    567264
anon_size                       4    16384
anon_evict_data                 4    0
anon_evict_metadata             4    0
mru_size                        4    2512193024
mru_evict_data                  4    131072
mru_evict_metadata              4    2510355968
mru_ghost_size                  4    6197248
mru_ghost_evict_data            4    0
mru_ghost_evict_metadata        4    6197248
mfu_size                        4    90624
mfu_evict_data                  4    0
mfu_evict_metadata              4    57856
mfu_ghost_size                  4    76722176
mfu_ghost_evict_data            4    0
mfu_ghost_evict_metadata        4    76722176
l2_hits                         4    0
l2_misses                       4    618963
l2_feeds                        4    270
l2_rw_clash                     4    0
l2_read_bytes                   4    0
l2_write_bytes                  4    3505664
l2_writes_sent                  4    2
l2_writes_done                  4    2
l2_writes_error                 4    0
l2_writes_hdr_miss              4    0
l2_evict_lock_retry             4    0
l2_evict_reading                4    0
l2_free_on_write                4    0
l2_abort_lowmem                 4    0
l2_cksum_bad                    4    0
l2_io_error                     4    0
l2_size                         4    5190656
l2_asize                        4    3505664
l2_hdr_size                     4    40352
l2_compress_successes           4    1255
l2_compress_zeros               4    0
l2_compress_failures            4    0
memory_throttle_count           4    0
duplicate_buffers               4    0
duplicate_buffers_size          4    0
duplicate_reads                 4    0
memory_direct_count             4    0
memory_indirect_count           4    0
arc_no_grow                     4    0
arc_tempreserve                 4    0
arc_loaned_bytes                4    0
arc_prune                       4    0
arc_meta_used                   4    2730807728
arc_meta_limit                  4    5368709120
arc_meta_max                    4    2795253632

[GregorKopka]

Do you have PREEMPT_NONE in your kernel? #1909

[lr1980]

dont know... i use the default ubuntu kernel... but... after i connect more drives and reconnect/reorganize all cable it works without any blocks!?...

[behlendorf]

Closing. After the hardware was reorganized the issue was not reproducible.