"zpool import" hangs

[BenEstrabaud]

System setup:

• Custom Linux distribution with ZFS 0.6.5-1 from the "master" branch (zfs commit 0743485 and spl commit 2a55273)
• 4 zpools on a RAID5 device each (single device and vdev per pool).
• 1 zvol on each zpool
• Deduplication enabled on each zpool.
• Clustered system: The zpools are imported on one node or the other, depending on which is alive at the time, and can be exported and moved to the other node when needed (e.g. node failure).

After a system failure (both nodes failed, ZFS filesystem was running and not cleanly unmounted), one of the node restarted and attempted to "import" all 4 RAID backed zpools. All 4 "zpool command" then hang forever (still hung after hours).

Here is an extract from dmesg:

<7>[ 126.872975] RAID conf printout:
<7>[ 126.872976] --- level:6 rd:5 wd:5
<7>[ 126.872977] disk 0, o:1, dev:sdah3
<7>[ 126.872978] disk 1, o:1, dev:sdad3
<7>[ 126.872979] disk 2, o:1, dev:sdy3
<7>[ 126.872980] disk 3, o:1, dev:sdab3
<7>[ 126.872981] disk 4, o:1, dev:sdac3
<6>[ 126.872988] md/raid456: discard support disabled due to uncertainty.
<6>[ 126.880196] Set raid456.devices_handle_discard_safely=Y to override.
<6>[ 126.887515] created bitmap (1 pages) for device md_d1
<4>[ 126.893297] broadcasting MP EVENT 174 0:0:1
<6>[ 126.893327] md_d1: bitmap initialized from disk: read 1 pages, set 0 of 895 bits
<6>[ 126.893457] md_d1: detected capacity change from 0 to 5759937282048
<6>[ 126.913853] md_d1: p1 p2
<5>[ 128.579752] SPL: using hostid 0x00000000
<4>[ 138.713320] WARNING: Pool 'z0x1d2de4d79220088e' has encountered an uncorrectable I/O failure and has been suspended.
<4>[ 138.713320]
<6>[ 182.483156] nbd: registered device at major 43
<3>[ 188.552160] NFSD: Unable to end grace period: -110
<3>[ 361.131405] INFO: task zpool:3032 blocked for more than 120 seconds.
<3>[ 361.138580] Tainted: P O 4.1.5 #6
<3>[ 361.144198] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 361.153053] zpool D ffff880f3bde7b78 0 3032 2331 0x00000002
<4>[ 361.161159] ffff880f3bde7b78 ffff880f93d3e200 ffff8810384a0000 ffff880f45a8e200
<4>[ 361.169813] ffff880f3bde4008 ffff880f93d3e200 ffffffffa08b04a4 00000000ffffffff
<4>[ 361.178474] ffffffffa08b04a8 ffff880f3bde7b98 ffffffff816b50ae ffff880f93d3e200
<4>[ 361.187132] Call Trace:
<4>[ 361.189960] [] schedule+0x3e/0x90
<4>[ 361.195604] [] schedule_preempt_disabled+0xe/0x10
<4>[ 361.202808] [] __mutex_lock_slowpath+0x93/0x100
<4>[ 361.209813] [] ? spl_kmem_free+0x2b/0x40 [spl]
<4>[ 361.216722] [] mutex_lock+0x23/0x40
<4>[ 361.222575] [] spa_prop_get+0x2493/0x2850 [zfs]
<4>[ 361.229582] [] ? T.2226+0x4a/0x60
<4>[ 361.235237] [] ? zvol_create_minor+0x70/0x1050 [zfs]
<4>[ 361.242729] [] spa_open+0x13/0x20 [zfs]
<4>[ 361.248962] [] dmu_objset_find+0x39/0x440 [zfs]
<4>[ 361.255980] [] zvol_create_minors+0x33/0x6f0 [zfs]
<4>[ 361.263288] [] spa_import+0x49d/0x720 [zfs]
<4>[ 361.269905] [] ? nvlist_exists+0xe4/0x130 [znvpair]
<4>[ 361.277311] [] dataset_name_hidden+0x2454/0x4770 [zfs]
<4>[ 361.285012] [] pool_status_check+0x537/0x580 [zfs]
<4>[ 361.292342] [] do_vfs_ioctl+0x93/0x540
<4>[ 361.298470] [] SyS_ioctl+0xa1/0xb0
<4>[ 361.304211] [] system_call_fastpath+0x12/0x6a
<3>[ 361.311024] INFO: task zpool:3071 blocked for more than 120 seconds.

Any idea what is causing this problem? Any subsequent "zpool" command (like "zpool list") also hangs forever.

Thanks in advance.

[behlendorf]

WARNING: Pool 'z0x1d2de4d79220088e' has encountered an uncorrectable I/O failure and has been suspended.

This indicates ZFS suspended the pool due to I/O errors from the disk. In this case it looks like it was still working on importing the pool which is why all the commands are blocked. You'll want to investigate why there were disk errors.

[BenEstrabaud]

Thanks for your response. I'll investigate but it's odd since the backend device was a RAID device and it was taking read and writes fine. Each time we run the import (after reboot) the same thing happened. Ultimately we ended up deleting the pool and recreating it and the issue cleared. I'll update this issue if the problem occurs again.

[ryao]

@BenEstrabaud That is not odd at all. RAID is almost entirely incapable of recognizing when the data it reads from the disks is wrong. The only exception occurs on a degraded array, when parity might catch it, but parity is not guaranteed to catch it. In all other cases, it will happily return wrong data. ZFS on the other hand, is designed to detect this and when it has sufficient redundancy, it will correct it.

ZFS has redundant metadata such that it would normally be able to recover from this issue even without mirror / raidz vdevs. A failure despite that means that the storage under ZFS damaged multiple IOs. ZFS with raidz and/or mirror vdevs would have been able to recover from this and tell you which device caused it, assuming that it was just one.

That said, your dmesg output suggests that you are using MD RAID 6. I suggest that you switch to raidz2. There are numerous problems with the design of RAID that are unfixable. Some of them are documented on the Open ZFS wiki in a discussion of Hardware RAID. Any point that does not describe some physical hardware component also applies to software RAID:

http://open-zfs.org/wiki/Hardware#Hardware_RAID_controllers

[BenEstrabaud]

Thanks for your answer,

We are aware of the issue using a RAID as a backend storage (especially with regards to data integrity) is a less than optimal solution. It is possible that this RAID had been damaged during test before hand, I know understand that the issue could have stemmed from ZFS failing to start/hanging as metadata would be damaged.

I suppose I'm going to close that issue as the hang happened because of a use case that's not a recommended one.

Thanks both for those clarifications.

[ryao]

@BenEstrabaud Someone pointed out to me that we really should have returned an error to userspace in this instance and he is right. This does not contradict the idea that data was clobbered in a way from which we couldn't recover, but it does suggest that there is some sort race that can occur when this happens.

Upon examining the stack trace in more detail, I see that we are blocked trying to grab spa->spa_props_lock, but that lock should be free. We likely need all of the stack traces between 361.131405 and 120 seconds later to get an idea of why the zpool command hung instead of returning an error.

With that in mind, we probably should reopen this. The only stupid thing hardware is presently allowed to do that could hang import is fail to respond to IOs (this would irrecoverably hang anything non-FUSE at the moment). Everything else should cause import to terminate with an error code.

[BenEstrabaud]

Thanks for your answer. In our case having an error instead of a hang would help getting out of a situation where a reboot is the only alternative with heavy manual intervention to prevent further import.

Here is the rest of the trace:

<3>[ 361.131405] INFO: task zpool:3032 blocked for more than 120 seconds.
<3>[ 361.138580] Tainted: P O 4.1.5 #6
<3>[ 361.144198] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 361.153053] zpool D ffff880f3bde7b78 0 3032 2331 0x00000002
<4>[ 361.161159] ffff880f3bde7b78 ffff880f93d3e200 ffff8810384a0000 ffff880f45a8e200
<4>[ 361.169813] ffff880f3bde4008 ffff880f93d3e200 ffffffffa08b04a4 00000000ffffffff
<4>[ 361.178474] ffffffffa08b04a8 ffff880f3bde7b98 ffffffff816b50ae ffff880f93d3e200
<4>[ 361.187132] Call Trace:
<4>[ 361.189960] [] schedule+0x3e/0x90
<4>[ 361.195604] [] schedule_preempt_disabled+0xe/0x10
<4>[ 361.202808] [] __mutex_lock_slowpath+0x93/0x100
<4>[ 361.209813] [] ? spl_kmem_free+0x2b/0x40 [spl]
<4>[ 361.216722] [] mutex_lock+0x23/0x40
<4>[ 361.222575] [] spa_prop_get+0x2493/0x2850 [zfs]
<4>[ 361.229582] [] ? T.2226+0x4a/0x60
<4>[ 361.235237] [] ? zvol_create_minor+0x70/0x1050 [zfs]
<4>[ 361.242729] [] spa_open+0x13/0x20 [zfs]
<4>[ 361.248962] [] dmu_objset_find+0x39/0x440 [zfs]
<4>[ 361.255980] [] zvol_create_minors+0x33/0x6f0 [zfs]
<4>[ 361.263288] [] spa_import+0x49d/0x720 [zfs]
<4>[ 361.269905] [] ? nvlist_exists+0xe4/0x130 [znvpair]
<4>[ 361.277311] [] dataset_name_hidden+0x2454/0x4770 [zfs]
<4>[ 361.285012] [] pool_status_check+0x537/0x580 [zfs]
<4>[ 361.292342] [] do_vfs_ioctl+0x93/0x540
<4>[ 361.298470] [] SyS_ioctl+0xa1/0xb0
<4>[ 361.304211] [] system_call_fastpath+0x12/0x6a
<3>[ 361.311024] INFO: task zpool:3071 blocked for more than 120 seconds.
<3>[ 361.318263] Tainted: P O 4.1.5 #6
<3>[ 361.323897] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 361.332778] zpool D ffff880f3b41fbd8 0 3071 2328 0x00000000
<4>[ 361.332779] ffff880f3b41fbd8 ffff880f45a8e200 ffff8810384a3100 ffff880f3b41fbc8
<4>[ 361.332780] ffff880f3b41c008 ffff880f46e76220 ffff880f3b41fc08 ffff880f46e762e0
<4>[ 361.332781] 0000000000000000 ffff880f3b41fbf8 ffffffff816b50ae ffff880f46e76220
<4>[ 361.332781] Call Trace:
<4>[ 361.332783] [] schedule+0x3e/0x90
<4>[ 361.332787] [] __cv_timedwait+0x13d/0x150 [spl]
<4>[ 361.332789] [] ? woken_wake_function+0x20/0x20
<4>[ 361.332792] [] __cv_wait+0x15/0x20 [spl]
<4>[ 361.332805] [] txg_wait_synced+0xef/0x140 [zfs]
<4>[ 361.332816] [] spa_config_update+0xcc/0x120 [zfs]
<4>[ 361.332825] [] spa_import+0x558/0x720 [zfs]
<4>[ 361.332828] [] ? nvlist_exists+0xe4/0x130 [znvpair]
<4>[ 361.332842] [] dataset_name_hidden+0x2454/0x4770 [zfs]
<4>[ 361.332853] [] pool_status_check+0x537/0x580 [zfs]
<4>[ 361.332854] [] do_vfs_ioctl+0x93/0x540
<4>[ 361.332856] [] SyS_ioctl+0xa1/0xb0
<4>[ 361.332857] [] system_call_fastpath+0x12/0x6a
<3>[ 361.332858] INFO: task zpool:3116 blocked for more than 120 seconds.
<3>[ 361.332858] Tainted: P O 4.1.5 #6
<3>[ 361.332859] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 361.332860] zpool D ffff880f3afcbc68 0 3116 2333 0x00000000
<4>[ 361.332861] ffff880f3afcbc68 ffff880f45a66200 ffff8810384a6200 ffff880f93d3e200
<4>[ 361.332862] ffff880f3afc8008 ffff880f45a66200 ffffffffa08b04a4 00000000ffffffff
<4>[ 361.332863] ffffffffa08b04a8 ffff880f3afcbc88 ffffffff816b50ae ffff880f45a66200
<4>[ 361.332863] Call Trace:
<4>[ 361.332865] [] schedule+0x3e/0x90
<4>[ 361.332867] [] schedule_preempt_disabled+0xe/0x10
<4>[ 361.332868] [] __mutex_lock_slowpath+0x93/0x100
<4>[ 361.332870] [] mutex_lock+0x23/0x40
<4>[ 361.332880] [] spa_import+0x53/0x720 [zfs]
<4>[ 361.332883] [] ? nvlist_alloc+0xa29/0xa70 [znvpair]
<4>[ 361.332886] [] ? nvlist_exists+0xe4/0x130 [znvpair]
<4>[ 361.332897] [] dataset_name_hidden+0x2454/0x4770 [zfs]
<4>[ 361.332907] [] pool_status_check+0x537/0x580 [zfs]
<4>[ 361.332908] [] do_vfs_ioctl+0x93/0x540
<4>[ 361.332910] [] SyS_ioctl+0xa1/0xb0
<4>[ 361.332911] [] system_call_fastpath+0x12/0x6a
<3>[ 361.332912] INFO: task zpool:3280 blocked for more than 120 seconds.
<3>[ 361.332913] Tainted: P O 4.1.5 #6
<3>[ 361.332913] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 361.332914] zpool D ffff880f3b9c3c68 0 3280 2340 0x00000000
<4>[ 361.332915] ffff880f3b9c3c68 ffff880f5ed58000 ffff8810384a3100 ffff880f45a8e200
<4>[ 361.332916] ffff880f3b9c0008 ffff880f5ed58000 ffffffffa08b04a4 00000000ffffffff
<4>[ 361.332917] ffffffffa08b04a8 ffff880f3b9c3c88 ffffffff816b50ae ffff880f5ed58000
<4>[ 361.332917] Call Trace:
<4>[ 361.332919] [] schedule+0x3e/0x90
<4>[ 361.332921] [] schedule_preempt_disabled+0xe/0x10
<4>[ 361.332922] [] __mutex_lock_slowpath+0x93/0x100
<4>[ 361.332923] [] mutex_lock+0x23/0x40
<4>[ 361.332933] [] spa_import+0x53/0x720 [zfs]
<4>[ 361.332936] [] ? nvlist_alloc+0xa29/0xa70 [znvpair]
<4>[ 361.332939] [] ? nvlist_exists+0xe4/0x130 [znvpair]
<4>[ 361.332949] [] dataset_name_hidden+0x2454/0x4770 [zfs]
<4>[ 361.332959] [] pool_status_check+0x537/0x580 [zfs]
<4>[ 361.332960] [] do_vfs_ioctl+0x93/0x540
<4>[ 361.332962] [] SyS_ioctl+0xa1/0xb0
<4>[ 361.332963] [] system_call_fastpath+0x12/0x6a
<3>[ 361.332968] INFO: task spa_async:3448 blocked for more than 120 seconds.
<3>[ 361.332968] Tainted: P O 4.1.5 #6
<3>[ 361.332968] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 361.332970] spa_async D ffff880f39b2bd68 0 3448 2 0x00000000
<4>[ 361.332971] ffff880f39b2bd68 ffff880f3a2ee200 ffff8810384a1880 ffff88107f396068
<4>[ 361.332972] ffff880f39b28008 ffff880f3a2ee200 ffffffffa08b04a4 00000000ffffffff
<4>[ 361.332973] ffffffffa08b04a8 ffff880f39b2bd88 ffffffff816b50ae ffff880f3a2ee200
<4>[ 361.332973] Call Trace:
<4>[ 361.332975] [] schedule+0x3e/0x90
<4>[ 361.332976] [] schedule_preempt_disabled+0xe/0x10
<4>[ 361.332977] [] __mutex_lock_slowpath+0x93/0x100
<4>[ 361.332979] [] ? sched_clock_cpu+0xad/0xc0
<4>[ 361.332981] [] mutex_lock+0x23/0x40
<4>[ 361.332991] [] spa_vdev_detach+0x96c/0xa20 [zfs]
<4>[ 361.332994] [] ? __thread_create+0x160/0x1f0 [spl]
<4>[ 361.332997] [] ? kfree+0x108/0x140
<4>[ 361.333006] [] ? spa_vdev_detach+0x710/0xa20 [zfs]
<4>[ 361.333008] [] ? __thread_create+0x160/0x1f0 [spl]
<4>[ 361.333010] [] __thread_create+0x1d8/0x1f0 [spl]
<4>[ 361.333013] [] ? __thread_create+0x160/0x1f0 [spl]
<4>[ 361.333015] [] kthread+0xce/0x100
<4>[ 361.333017] [] ? kthread_freezable_should_stop+0x70/0x70
<4>[ 361.333018] [] ret_from_fork+0x42/0x70
<4>[ 361.333020] [] ? kthread_freezable_should_stop+0x70/0x70
<3>[ 361.333025] INFO: task txg_sync:3547 blocked for more than 120 seconds.
<3>[ 361.333026] Tainted: P O 4.1.5 #6
<3>[ 361.333026] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 361.333027] txg_sync D ffff880f37f537b8 0 3547 2 0x00000000
<4>[ 361.333028] ffff880f37f537b8 ffff880f45890000 ffff8810384c3100 ffff880f381b8d20
<4>[ 361.333029] ffff880f37f50008 ffff88107f696000 7fffffffffffffff ffff880f381be808
<4>[ 361.333030] 0000000000000001 ffff880f37f537d8 ffffffff816b50ae ffff880f00000000
<4>[ 361.333030] Call Trace:
<4>[ 361.333032] [] schedule+0x3e/0x90
<4>[ 361.333033] [] schedule_timeout+0x13d/0x1d0
<4>[ 361.333036] [] ? ktime_get+0x52/0xc0
<4>[ 361.333037] [] io_schedule_timeout+0xa4/0x110
<4>[ 361.333041] [] __cv_timedwait+0xcf/0x150 [spl]
<4>[ 361.333042] [] ? woken_wake_function+0x20/0x20
<4>[ 361.333045] [] __cv_wait_io+0x18/0x20 [spl]
<4>[ 361.333058] [] zio_wait+0xd3/0x150 [zfs]
<4>[ 361.333065] [] dbuf_read+0x469/0x7f0 [zfs]
<4>[ 361.333071] [] dmu_buf_will_dirty+0x61/0x80 [zfs]
<4>[ 361.333078] [] dmu_write+0x90/0x190 [zfs]
<4>[ 361.333089] [] spa_get_errlog+0x2f6/0x330 [zfs]
<4>[ 361.333099] [] spa_history_create_obj+0x328/0x760 [zfs]
<4>[ 361.333100] [] ? __wake_up+0x53/0x70
<4>[ 361.333110] [] dsl_sync_task_sync+0x10a/0x120 [zfs]
<4>[ 361.333119] [] dsl_pool_sync+0x30b/0x650 [zfs]
<4>[ 361.333130] [] ? spa_sync_allpools+0x2ed/0x660 [zfs]
<4>[ 361.333138] [] spa_sync+0x35e/0xe80 [zfs]
<4>[ 361.333139] [] ? __wake_up_common+0x59/0x90
<4>[ 361.333141] [] ? getrawmonotonic64+0x3f/0xd0
<4>[ 361.333153] [] txg_init+0x614/0x890 [zfs]
<4>[ 361.333155] [] ? kfree+0x108/0x140
<4>[ 361.333165] [] ? txg_init+0x240/0x890 [zfs]
<4>[ 361.333168] [] ? __thread_create+0x160/0x1f0 [spl]
<4>[ 361.333170] [] __thread_create+0x1d8/0x1f0 [spl]
<4>[ 361.333172] [] ? __thread_create+0x160/0x1f0 [spl]
<4>[ 361.333174] [] kthread+0xce/0x100
<4>[ 361.333176] [] ? kthread_freezable_should_stop+0x70/0x70
<4>[ 361.333177] [] ret_from_fork+0x42/0x70
<4>[ 361.333178] [] ? kthread_freezable_should_stop+0x70/0x70
<3>[ 481.449359] INFO: task zpool:3032 blocked for more than 120 seconds.
<3>[ 481.456535] Tainted: P O 4.1.5 #6
<3>[ 481.462153] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 481.471008] zpool D ffff880f3bde7b78 0 3032 2331 0x00000002
<4>[ 481.479112] ffff880f3bde7b78 ffff880f93d3e200 ffff8810384a0000 ffff880f45a8e200
<4>[ 481.487763] ffff880f3bde4008 ffff880f93d3e200 ffffffffa08b04a4 00000000ffffffff
<4>[ 481.496419] ffffffffa08b04a8 ffff880f3bde7b98 ffffffff816b50ae ffff880f93d3e200
<4>[ 481.505076] Call Trace:
<4>[ 481.507902] [] schedule+0x3e/0x90
<4>[ 481.513547] [] schedule_preempt_disabled+0xe/0x10
<4>[ 481.520750] [] __mutex_lock_slowpath+0x93/0x100
<4>[ 481.527755] [] ? spl_kmem_free+0x2b/0x40 [spl]
<4>[ 481.534661] [] mutex_lock+0x23/0x40
<4>[ 481.540513] [] spa_prop_get+0x2493/0x2850 [zfs]
<4>[ 481.547522] [] ? T.2226+0x4a/0x60
<4>[ 481.553174] [] ? zvol_create_minor+0x70/0x1050 [zfs]
<4>[ 481.560677] [] spa_open+0x13/0x20 [zfs]
<4>[ 481.566910] [] dmu_objset_find+0x39/0x440 [zfs]
<4>[ 481.573925] [] zvol_create_minors+0x33/0x6f0 [zfs]
<4>[ 481.581231] [] spa_import+0x49d/0x720 [zfs]
<4>[ 481.587850] [] ? nvlist_exists+0xe4/0x130 [znvpair]
<4>[ 481.595262] [] dataset_name_hidden+0x2454/0x4770 [zfs]
<4>[ 481.602963] [] pool_status_check+0x537/0x580 [zfs]
<4>[ 481.610263] [] do_vfs_ioctl+0x93/0x540
<4>[ 481.616393] [] SyS_ioctl+0xa1/0xb0
<4>[ 481.622134] [] system_call_fastpath+0x12/0x6a
<3>[ 481.628943] INFO: task zpool:3071 blocked for more than 120 seconds.
<3>[ 481.636142] Tainted: P O 4.1.5 #6
<3>[ 481.641774] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 481.650655] zpool D ffff880f3b41fbd8 0 3071 2328 0x00000000
<4>[ 481.658763] ffff880f3b41fbd8 ffff880f45a8e200 ffff8810384a3100 ffff880f3b41fbc8
<4>[ 481.667419] ffff880f3b41c008 ffff880f46e76220 ffff880f3b41fc08 ffff880f46e762e0
<4>[ 481.676078] 0000000000000000 ffff880f3b41fbf8 ffffffff816b50ae ffff880f46e76220
<4>[ 481.684734] Call Trace:
<4>[ 481.687552] [] schedule+0x3e/0x90
<4>[ 481.693195] [] __cv_timedwait+0x13d/0x150 [spl]
<4>[ 481.700199] [] ? woken_wake_function+0x20/0x20
<4>[ 481.707106] [] __cv_wait+0x15/0x20 [spl]
<4>[ 481.713440] [] txg_wait_synced+0xef/0x140 [zfs]
<4>[ 481.720457] [] spa_config_update+0xcc/0x120 [zfs]
<4>[ 481.727668] [] spa_import+0x558/0x720 [zfs]
<4>[ 481.734287] [] ? nvlist_exists+0xe4/0x130 [znvpair]
<4>[ 481.741694] [] dataset_name_hidden+0x2454/0x4770 [zfs]
<4>[ 481.749391] [] pool_status_check+0x537/0x580 [zfs]
<4>[ 481.756688] [] do_vfs_ioctl+0x93/0x540
<4>[ 481.762816] [] SyS_ioctl+0xa1/0xb0
<4>[ 481.768553] [] system_call_fastpath+0x12/0x6a
<3>[ 481.775366] INFO: task zpool:3116 blocked for more than 120 seconds.
<3>[ 481.782565] Tainted: P O 4.1.5 #6
<3>[ 481.788204] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 481.797089] zpool D ffff880f3afcbc68 0 3116 2333 0x00000000
<4>[ 481.805195] ffff880f3afcbc68 ffff880f45a66200 ffff8810384a6200 ffff880f93d3e200
<4>[ 481.813851] ffff880f3afc8008 ffff880f45a66200 ffffffffa08b04a4 00000000ffffffff
<4>[ 481.822508] ffffffffa08b04a8 ffff880f3afcbc88 ffffffff816b50ae ffff880f45a66200
<4>[ 481.831153] Call Trace:
<4>[ 481.833972] [] schedule+0x3e/0x90
<4>[ 481.839613] [] schedule_preempt_disabled+0xe/0x10
<4>[ 481.846816] [] __mutex_lock_slowpath+0x93/0x100
<4>[ 481.853821] [] mutex_lock+0x23/0x40
<4>[ 481.859657] [] spa_import+0x53/0x720 [zfs]
<4>[ 481.866177] [] ? nvlist_alloc+0xa29/0xa70 [znvpair]
<4>[ 481.873574] [] ? nvlist_exists+0xe4/0x130 [znvpair]
<4>[ 481.880979] [] dataset_name_hidden+0x2454/0x4770 [zfs]
<4>[ 481.888670] [] pool_status_check+0x537/0x580 [zfs]
<4>[ 481.895970] [] do_vfs_ioctl+0x93/0x540
<4>[ 481.902101] [] SyS_ioctl+0xa1/0xb0
<4>[ 481.907838] [] system_call_fastpath+0x12/0x6a
<3>[ 481.914648] INFO: task zpool:3280 blocked for more than 120 seconds.
<3>[ 481.921848] Tainted: P O 4.1.5 #6
<3>[ 481.927487] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
<6>[ 481.936368] zpool D ffff880f3b9c3c68 0 3280 2340 0x00000000
<4>[ 481.944484] ffff880f3b9c3c68 ffff880f5ed58000 ffff8810384a3100 ffff880f45a8e200
<4>[ 481.953142] ffff880f3b9c0008 ffff880f5ed58000 ffffffffa08b04a4 00000000ffffffff
<4>[ 481.961795] ffffffffa08b04a8 ffff880f3b9c3c88 ffffffff816b50ae ffff880f5ed58000
<4>[ 481.970452] Call Trace:
<4>[ 481.973272] [] schedule+0x3e/0x90
<4>[ 481.978905] [] schedule_preempt_disabled+0xe/0x10
<4>[ 481.986102] [] __mutex_lock_slowpath+0x93/0x100
<4>[ 481.993108] [] mutex_lock+0x23/0x40
<4>[ 481.998956] [] spa_import+0x53/0x720 [zfs]
<4>[ 482.005476] [] ? nvlist_alloc+0xa29/0xa70 [znvpair]
<4>[ 482.012876] [] ? nvlist_exists+0xe4/0x130 [znvpair]
<4>[ 482.020283] [] dataset_name_hidden+0x2454/0x4770 [zfs]
<4>[ 482.027982] [] pool_status_check+0x537/0x580 [zfs]
<4>[ 482.035281] [] do_vfs_ioctl+0x93/0x540
<4>[ 482.041413] [] SyS_ioctl+0xa1/0xb0
<4>[ 482.047142] [] system_call_fastpath+0x12/0x6a

Thanks a lot for your help!

[stale]

This issue has been automatically marked as "stale" because it has not had any activity for a while. It will be closed in 90 days if no further activity occurs. Thank you for your contributions.