task z_zvol blocked for more than 120 seconds during ZFS send/ZFS recv

[ronnyegner]

System information

Distribution Name	Ubuntu
Distribution Version	17.04
Linux Kernel	4.10.0-24-generic
Architecture	x86_64
ZFS Version	v0.7.0-50_g1ea8942fa
SPL Version	v0.7.0-12_g9df9692

I have now noticed several times that while some zfs send/zfs recv operations are running i get the following errors related to ZVOLs. Interesting here is that i don´t ave any ZVOL configured:

Oct  8 10:06:53 homenas kernel: [83374.561093] INFO: task z_zvol:5609 blocked for more than 120 seconds.
Oct  8 10:06:53 homenas kernel: [83374.562910]       Tainted: P        W  OE   4.10.0-24-generic #28-Ubuntu
Oct  8 10:06:53 homenas kernel: [83374.564463] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Oct  8 10:06:53 homenas kernel: [83374.566143] z_zvol          D    0  5609      2 0x00000000
Oct  8 10:06:53 homenas kernel: [83374.566148] Call Trace:
Oct  8 10:06:53 homenas kernel: [83374.566161]  __schedule+0x233/0x6f0
Oct  8 10:06:53 homenas kernel: [83374.566165]  schedule+0x36/0x80
Oct  8 10:06:53 homenas kernel: [83374.566194]  taskq_wait_outstanding+0x8c/0xd0 [spl]
Oct  8 10:06:53 homenas kernel: [83374.566199]  ? wake_atomic_t_function+0x60/0x60
Oct  8 10:06:53 homenas kernel: [83374.566268]  zvol_task_cb+0x1f9/0x5b0 [zfs]
Oct  8 10:06:53 homenas kernel: [83374.566275]  ? __schedule+0x23b/0x6f0
Oct  8 10:06:53 homenas kernel: [83374.566284]  taskq_thread+0x2b5/0x4e0 [spl]
Oct  8 10:06:53 homenas kernel: [83374.566287]  ? wake_up_q+0x80/0x80
Oct  8 10:06:53 homenas kernel: [83374.566297]  kthread+0x109/0x140
Oct  8 10:06:53 homenas kernel: [83374.566302]  ? task_done+0xb0/0xb0 [spl]
Oct  8 10:06:53 homenas kernel: [83374.566305]  ? kthread_create_on_node+0x60/0x60
Oct  8 10:06:53 homenas kernel: [83374.566308]  ret_from_fork+0x2c/0x40

[error10]

I am seeing similar messages appearing on ZFS 0.7.3 on CentOS 7 with kernel 3.10.0-693.5.2.el7.x86_64 . This also occurs during ZFS send/receive. In particular the zfs recv process hangs.

[34441.109270] INFO: task z_zvol:4809 blocked for more than 120 seconds.
[34441.109919] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
message.
[34441.110584] z_zvol D 0000000000000000 0 4809 2 0x00000000
[34441.110592] ffff881fd5f4fd10 0000000000000046 ffff881fd9ac3f40 ffff881fd5f4f
fd8
[34441.110598] ffff881fd5f4ffd8 ffff881fd5f4ffd8 ffff881fd9ac3f40 ffff881ffb2b3
900
[34441.110603] 0000000000000077 0000000000000077 ffff881ffb2b39d8 0000000000000
000
[34441.110608] Call Trace:
[34441.110623] [] schedule+0x29/0x70
[34441.110655] [] taskq_wait_outstanding+0x95/0xf0 [spl]
[34441.110663] [] ? wake_up_atomic_t+0x30/0x30
[34441.110748] [] zvol_task_cb+0x216/0x5a0 [zfs]
[34441.110756] [] ? __schedule+0x39d/0x8b0
[34441.110779] [] taskq_thread+0x246/0x470 [spl]
[34441.110789] [] ? wake_up_state+0x20/0x20
[34441.110809] [] ? taskq_thread_spawn+0x60/0x60 [spl]
[34441.110817] [] kthread+0xcf/0xe0
[34441.110824] [] ? insert_kthread_work+0x40/0x40
[34441.110832] [] ret_from_fork+0x58/0x90
[34441.110839] [] ? insert_kthread_work+0x40/0x40

[johnramsden]

Same error on Arch, what's weird is I don't even have any ZVOLs on my system.

$ zfs list -t volume
no datasets available

ZFS version:

local/zfs-linux 0.7.4.4.14.6.1-2 (archzfs-linux)

System:

Linux wooly 4.14.6-1-ARCH #1 SMP PREEMPT Thu Dec 14 21:26:16 UTC 2017 x86_64 GNU/Linux

Dec 18 18:06:36 wooly kernel: INFO: task z_zvol:365 blocked for more than 120 seconds.
Dec 18 18:06:36 wooly kernel:       Tainted: P           O    4.14.6-1-ARCH #1
Dec 18 18:06:36 wooly kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
Dec 18 18:06:36 wooly kernel: z_zvol          D    0   365      2 0x80000000
Dec 18 18:06:36 wooly kernel: Call Trace:
Dec 18 18:06:36 wooly kernel:  ? __schedule+0x290/0x890
Dec 18 18:06:36 wooly kernel:  schedule+0x2f/0x90
Dec 18 18:06:36 wooly kernel:  taskq_wait_outstanding+0x81/0xc0 [spl]
Dec 18 18:06:36 wooly kernel:  ? wait_woken+0x80/0x80
Dec 18 18:06:36 wooly kernel:  zvol_task_cb+0x1f8/0x5a0 [zfs]
Dec 18 18:06:36 wooly kernel:  ? __schedule+0x298/0x890
Dec 18 18:06:36 wooly kernel:  ? __wake_up_common_lock+0x89/0xc0
Dec 18 18:06:36 wooly kernel:  taskq_thread+0x290/0x4a0 [spl]
Dec 18 18:06:36 wooly kernel:  ? wake_up_q+0x70/0x70
Dec 18 18:06:36 wooly kernel:  ? taskq_thread_should_stop+0x70/0x70 [spl]
Dec 18 18:06:36 wooly kernel:  kthread+0x118/0x130
Dec 18 18:06:36 wooly kernel:  ? kthread_create_on_node+0x70/0x70
Dec 18 18:06:36 wooly kernel:  ret_from_fork+0x25/0x30

[ronnyegner]

I know these are just warnings, but they happen on a completely idle system (16 cores, 128 GB memory) with no ZVOL at all.

[loli10K]

@ronnyegner by the looks of it is a bug. It has been reported multiple (at least 3) times, so it's also a duplicate.

Would you mind if we close this since #6330 contains a clean reproducer?

[ronnyegner]

@loli10K: of course not. I missed that obviously and will close.