zfs
zfs copied to clipboard
Published
20 hours ago •
openzfs
openzfs
Hung zed and l2arc_feed tasks during pool import on 2.0.3
System information
| Type | Version/Name |
|---|---|
| Distribution Name | Debian (derivative) |
| Distribution Version | 10 |
| Kernel Version | 4.19.0-21-amd64 |
| Architecture | x86_64 |
| OpenZFS Version | zfs-2.0.3-12 / zfs-kmod-2.0.3-12 |
Describe the problem you're observing
During pool import, on some systems the import will take more than 10 minutes and when the pool does eventually import, filesystems are not automatically mounted as usual. It seems to me like this is some kind of deadlock, but due to the number of tasks involved, I've not been able to track down how it might be happening.
zpool status shows no irregularities.
Describe how to reproduce the problem
Unfortunately I cannot easily reproduce the issue. This has only happened on a single system which can't be interrupted to do more testing without a good bit of trouble. However, if anyone has ideas for how I might trigger this condition, I can potentially arrange a test (and of course I can test on other systems).
Include any warning/errors/backtraces from the system logs
dmesg output follows:
[Wed Aug 3 09:50:06 2022] INFO: task l2arc_feed:482 blocked for more than 120 seconds.
[Wed Aug 3 09:50:06 2022] Tainted: P W O 4.19.0-21-amd64 #1 Debian 4.19.208-3
[Wed Aug 3 09:50:06 2022] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Wed Aug 3 09:50:06 2022] l2arc_feed D 0 482 2 0x80000000
[Wed Aug 3 09:50:06 2022] Call Trace:
[Wed Aug 3 09:50:06 2022] __schedule+0x29f/0x840
[Wed Aug 3 09:50:06 2022] schedule+0x28/0x80
[Wed Aug 3 09:50:06 2022] schedule_preempt_disabled+0xa/0x10
[Wed Aug 3 09:50:06 2022] __mutex_lock.isra.8+0x286/0x470
[Wed Aug 3 09:50:06 2022] ? sigprocmask+0x72/0xa0
[Wed Aug 3 09:50:06 2022] ? __cv_timedwait_idle+0x67/0x90 [spl]
[Wed Aug 3 09:50:06 2022] l2arc_feed_thread+0x101/0x1a90 [zfs]
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to+0x8c/0x440
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:50:06 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:50:06 2022] ? __wake_up_common+0x7a/0x190
[Wed Aug 3 09:50:06 2022] ? l2arc_remove_vdev+0x240/0x240 [zfs]
[Wed Aug 3 09:50:06 2022] ? __thread_exit+0x20/0x20 [spl]
[Wed Aug 3 09:50:06 2022] thread_generic_wrapper+0x6f/0x80 [spl]
[Wed Aug 3 09:50:06 2022] kthread+0x112/0x130
[Wed Aug 3 09:50:06 2022] ? kthread_bind+0x30/0x30
[Wed Aug 3 09:50:06 2022] ret_from_fork+0x1f/0x40
[Wed Aug 3 09:52:07 2022] INFO: task l2arc_feed:482 blocked for more than 120 seconds.
[Wed Aug 3 09:52:07 2022] Tainted: P W O 4.19.0-21-amd64 #1 Debian 4.19.208-3
[Wed Aug 3 09:52:07 2022] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Wed Aug 3 09:52:07 2022] l2arc_feed D 0 482 2 0x80000000
[Wed Aug 3 09:52:07 2022] Call Trace:
[Wed Aug 3 09:52:07 2022] __schedule+0x29f/0x840
[Wed Aug 3 09:52:07 2022] schedule+0x28/0x80
[Wed Aug 3 09:52:07 2022] schedule_preempt_disabled+0xa/0x10
[Wed Aug 3 09:52:07 2022] __mutex_lock.isra.8+0x286/0x470
[Wed Aug 3 09:52:07 2022] ? sigprocmask+0x72/0xa0
[Wed Aug 3 09:52:07 2022] ? __cv_timedwait_idle+0x67/0x90 [spl]
[Wed Aug 3 09:52:07 2022] l2arc_feed_thread+0x101/0x1a90 [zfs]
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to+0x8c/0x440
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x41/0x70
[Wed Aug 3 09:52:07 2022] ? __switch_to_asm+0x35/0x70
[Wed Aug 3 09:52:07 2022] ? __wake_up_common+0x7a/0x190
[Wed Aug 3 09:52:07 2022] ? l2arc_remove_vdev+0x240/0x240 [zfs]
[Wed Aug 3 09:52:07 2022] ? __thread_exit+0x20/0x20 [spl]
[Wed Aug 3 09:52:07 2022] thread_generic_wrapper+0x6f/0x80 [spl]
[Wed Aug 3 09:52:07 2022] kthread+0x112/0x130
[Wed Aug 3 09:52:07 2022] ? kthread_bind+0x30/0x30
[Wed Aug 3 09:52:07 2022] ret_from_fork+0x1f/0x40
[Wed Aug 3 09:52:07 2022] INFO: task zed:3747 blocked for more than 120 seconds.
[Wed Aug 3 09:52:07 2022] Tainted: P W O 4.19.0-21-amd64 #1 Debian 4.19.208-3
[Wed Aug 3 09:52:07 2022] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Wed Aug 3 09:52:07 2022] zed D 0 3747 1 0x00000000
[Wed Aug 3 09:52:07 2022] Call Trace:
[Wed Aug 3 09:52:07 2022] __schedule+0x29f/0x840
[Wed Aug 3 09:52:07 2022] schedule+0x28/0x80
[Wed Aug 3 09:52:07 2022] schedule_preempt_disabled+0xa/0x10
[Wed Aug 3 09:52:07 2022] __mutex_lock.isra.8+0x286/0x470
[Wed Aug 3 09:52:07 2022] ? call_function_single_interrupt+0xa/0x20
[Wed Aug 3 09:52:07 2022] spa_open_common+0x5f/0x4c0 [zfs]
[Wed Aug 3 09:52:07 2022] spa_get_stats+0x4d/0x520 [zfs]
[Wed Aug 3 09:52:07 2022] ? _cond_resched+0x15/0x30
[Wed Aug 3 09:52:07 2022] ? __kmalloc_node+0x1ea/0x2c0
[Wed Aug 3 09:52:07 2022] zfs_ioc_pool_stats+0x34/0x80 [zfs]
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl_common+0x5b5/0x830 [zfs]
[Wed Aug 3 09:52:07 2022] ? kmalloc_large_node+0x37/0x60
[Wed Aug 3 09:52:07 2022] ? __kmalloc_node+0x213/0x2c0
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl+0x4f/0xe0 [zfs]
[Wed Aug 3 09:52:07 2022] do_vfs_ioctl+0xa4/0x630
[Wed Aug 3 09:52:07 2022] ? handle_mm_fault+0xd6/0x200
[Wed Aug 3 09:52:07 2022] ksys_ioctl+0x60/0x90
[Wed Aug 3 09:52:07 2022] __x64_sys_ioctl+0x16/0x20
[Wed Aug 3 09:52:07 2022] do_syscall_64+0x53/0x110
[Wed Aug 3 09:52:07 2022] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Wed Aug 3 09:52:07 2022] RIP: 0033:0x7f0c1c48e427
[Wed Aug 3 09:52:07 2022] Code: Bad RIP value.
[Wed Aug 3 09:52:07 2022] RSP: 002b:00007f0c1b4a95c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[Wed Aug 3 09:52:07 2022] RAX: ffffffffffffffda RBX: 00007f0c1b4a95f0 RCX: 00007f0c1c48e427
[Wed Aug 3 09:52:07 2022] RDX: 00007f0c1b4a95f0 RSI: 0000000000005a05 RDI: 000000000000000b
[Wed Aug 3 09:52:07 2022] RBP: 00007f0c1b4acbe0 R08: 00007f0c0c01b1f0 R09: 0000000000000079
[Wed Aug 3 09:52:07 2022] R10: 00007f0c0c0008d0 R11: 0000000000000246 R12: 00007f0c0c040f70
[Wed Aug 3 09:52:07 2022] R13: 00005611db1cd300 R14: 0000000000000000 R15: 00007f0c1b4acc04
[Wed Aug 3 09:52:07 2022] INFO: task node:5105 blocked for more than 120 seconds.
[Wed Aug 3 09:52:07 2022] Tainted: P W O 4.19.0-21-amd64 #1 Debian 4.19.208-3
[Wed Aug 3 09:52:07 2022] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Wed Aug 3 09:52:07 2022] node D 0 5105 5017 0x00000000
[Wed Aug 3 09:52:07 2022] Call Trace:
[Wed Aug 3 09:52:07 2022] __schedule+0x29f/0x840
[Wed Aug 3 09:52:07 2022] schedule+0x28/0x80
[Wed Aug 3 09:52:07 2022] schedule_preempt_disabled+0xa/0x10
[Wed Aug 3 09:52:07 2022] __mutex_lock.isra.8+0x286/0x470
[Wed Aug 3 09:52:07 2022] spa_open_common+0x5f/0x4c0 [zfs]
[Wed Aug 3 09:52:07 2022] spa_get_stats+0x4d/0x520 [zfs]
[Wed Aug 3 09:52:07 2022] ? _cond_resched+0x15/0x30
[Wed Aug 3 09:52:07 2022] ? __kmalloc_node+0x1ea/0x2c0
[Wed Aug 3 09:52:07 2022] zfs_ioc_pool_stats+0x34/0x80 [zfs]
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl_common+0x5b5/0x830 [zfs]
[Wed Aug 3 09:52:07 2022] ? kmalloc_large_node+0x37/0x60
[Wed Aug 3 09:52:07 2022] ? __kmalloc_node+0x213/0x2c0
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl+0x4f/0xe0 [zfs]
[Wed Aug 3 09:52:07 2022] do_vfs_ioctl+0xa4/0x630
[Wed Aug 3 09:52:07 2022] ? handle_mm_fault+0xd6/0x200
[Wed Aug 3 09:52:07 2022] ksys_ioctl+0x60/0x90
[Wed Aug 3 09:52:07 2022] __x64_sys_ioctl+0x16/0x20
[Wed Aug 3 09:52:07 2022] do_syscall_64+0x53/0x110
[Wed Aug 3 09:52:07 2022] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Wed Aug 3 09:52:07 2022] RIP: 0033:0x7f035a8be427
[Wed Aug 3 09:52:07 2022] Code: Bad RIP value.
[Wed Aug 3 09:52:07 2022] RSP: 002b:00007ffc350ea7c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[Wed Aug 3 09:52:07 2022] RAX: ffffffffffffffda RBX: 00007ffc350ea7f0 RCX: 00007f035a8be427
[Wed Aug 3 09:52:07 2022] RDX: 00007ffc350ea7f0 RSI: 0000000000005a05 RDI: 0000000000000014
[Wed Aug 3 09:52:07 2022] RBP: 00007ffc350edde0 R08: 000000000336f8d0 R09: 00007f035a989d10
[Wed Aug 3 09:52:07 2022] R10: 0000000002e5a010 R11: 0000000000000246 R12: 0000000002f4b6e0
[Wed Aug 3 09:52:07 2022] R13: 00000000031c2880 R14: 0000000000000000 R15: 00007ffc350eddf4
[Wed Aug 3 09:52:07 2022] INFO: task zfs:8280 blocked for more than 120 seconds.
[Wed Aug 3 09:52:07 2022] Tainted: P W O 4.19.0-21-amd64 #1 Debian 4.19.208-3
[Wed Aug 3 09:52:07 2022] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Wed Aug 3 09:52:07 2022] zfs D 0 8280 1 0x00000000
[Wed Aug 3 09:52:07 2022] Call Trace:
[Wed Aug 3 09:52:07 2022] __schedule+0x29f/0x840
[Wed Aug 3 09:52:07 2022] ? rrw_exit+0xfb/0x150 [zfs]
[Wed Aug 3 09:52:07 2022] schedule+0x28/0x80
[Wed Aug 3 09:52:07 2022] schedule_preempt_disabled+0xa/0x10
[Wed Aug 3 09:52:07 2022] __mutex_lock.isra.8+0x286/0x470
[Wed Aug 3 09:52:07 2022] spa_open_common+0x5f/0x4c0 [zfs]
[Wed Aug 3 09:52:07 2022] ? dbuf_rele_and_unlock+0x30f/0x660 [zfs]
[Wed Aug 3 09:52:07 2022] dsl_pool_hold+0x2e/0x80 [zfs]
[Wed Aug 3 09:52:07 2022] dmu_objset_hold_flags+0x38/0xd0 [zfs]
[Wed Aug 3 09:52:07 2022] zfs_ioc_objset_stats+0x2f/0xa0 [zfs]
[Wed Aug 3 09:52:07 2022] zfs_ioc_dataset_list_next+0x145/0x1a0 [zfs]
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl_common+0x5b5/0x830 [zfs]
[Wed Aug 3 09:52:07 2022] ? kmalloc_large_node+0x37/0x60
[Wed Aug 3 09:52:07 2022] ? __kmalloc_node+0x213/0x2c0
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl+0x4f/0xe0 [zfs]
[Wed Aug 3 09:52:07 2022] do_vfs_ioctl+0xa4/0x630
[Wed Aug 3 09:52:07 2022] ? handle_mm_fault+0xd6/0x200
[Wed Aug 3 09:52:07 2022] ksys_ioctl+0x60/0x90
[Wed Aug 3 09:52:07 2022] __x64_sys_ioctl+0x16/0x20
[Wed Aug 3 09:52:07 2022] do_syscall_64+0x53/0x110
[Wed Aug 3 09:52:07 2022] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Wed Aug 3 09:52:07 2022] RIP: 0033:0x7fb3a2a42427
[Wed Aug 3 09:52:07 2022] Code: Bad RIP value.
[Wed Aug 3 09:52:07 2022] RSP: 002b:00007ffd7b026fd8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[Wed Aug 3 09:52:07 2022] RAX: ffffffffffffffda RBX: 00007ffd7b027040 RCX: 00007fb3a2a42427
[Wed Aug 3 09:52:07 2022] RDX: 00007ffd7b027040 RSI: 0000000000005a14 RDI: 0000000000000003
[Wed Aug 3 09:52:07 2022] RBP: 00007ffd7b027020 R08: 000000000003ffff R09: 000000000000007f
[Wed Aug 3 09:52:07 2022] R10: 00005618a032e010 R11: 0000000000000246 R12: 00005618a037d670
[Wed Aug 3 09:52:07 2022] R13: 000056189f174f50 R14: 00005618a037d680 R15: 0000000000005a14
[Wed Aug 3 09:52:07 2022] INFO: task zfs:8350 blocked for more than 120 seconds.
[Wed Aug 3 09:52:07 2022] Tainted: P W O 4.19.0-21-amd64 #1 Debian 4.19.208-3
[Wed Aug 3 09:52:07 2022] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Wed Aug 3 09:52:07 2022] zfs D 0 8350 8328 0x00000000
[Wed Aug 3 09:52:07 2022] Call Trace:
[Wed Aug 3 09:52:07 2022] __schedule+0x29f/0x840
[Wed Aug 3 09:52:07 2022] schedule+0x28/0x80
[Wed Aug 3 09:52:07 2022] schedule_preempt_disabled+0xa/0x10
[Wed Aug 3 09:52:07 2022] __mutex_lock.isra.8+0x286/0x470
[Wed Aug 3 09:52:07 2022] spa_open_common+0x5f/0x4c0 [zfs]
[Wed Aug 3 09:52:07 2022] ? entity_namecheck+0xc8/0x380 [zcommon]
[Wed Aug 3 09:52:07 2022] pool_status_check.isra.24.part.25+0x2c/0xe0 [zfs]
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl_common+0x588/0x830 [zfs]
[Wed Aug 3 09:52:07 2022] ? kmalloc_large_node+0x37/0x60
[Wed Aug 3 09:52:07 2022] ? __kmalloc_node+0x213/0x2c0
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl+0x4f/0xe0 [zfs]
[Wed Aug 3 09:52:07 2022] do_vfs_ioctl+0xa4/0x630
[Wed Aug 3 09:52:07 2022] ? handle_mm_fault+0xd6/0x200
[Wed Aug 3 09:52:07 2022] ksys_ioctl+0x60/0x90
[Wed Aug 3 09:52:07 2022] __x64_sys_ioctl+0x16/0x20
[Wed Aug 3 09:52:07 2022] do_syscall_64+0x53/0x110
[Wed Aug 3 09:52:07 2022] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Wed Aug 3 09:52:07 2022] RIP: 0033:0x7fa0333fc427
[Wed Aug 3 09:52:07 2022] Code: Bad RIP value.
[Wed Aug 3 09:52:07 2022] RSP: 002b:00007ffe4aee2308 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[Wed Aug 3 09:52:07 2022] RAX: ffffffffffffffda RBX: 00007ffe4aee2370 RCX: 00007fa0333fc427
[Wed Aug 3 09:52:07 2022] RDX: 00007ffe4aee2370 RSI: 0000000000005a14 RDI: 0000000000000003
[Wed Aug 3 09:52:07 2022] RBP: 00007ffe4aee2350 R08: 000055cae89dd640 R09: 00007fa0334c7d30
[Wed Aug 3 09:52:07 2022] R10: 000055cae89b6010 R11: 0000000000000246 R12: 000055cae89cf6b0
[Wed Aug 3 09:52:07 2022] R13: 000055cae6af9a50 R14: 000055cae89cf6c0 R15: 0000000000005a14
[Wed Aug 3 09:52:07 2022] INFO: task zfs:12649 blocked for more than 120 seconds.
[Wed Aug 3 09:52:07 2022] Tainted: P W O 4.19.0-21-amd64 #1 Debian 4.19.208-3
[Wed Aug 3 09:52:07 2022] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Wed Aug 3 09:52:07 2022] zfs D 0 12649 5040 0x00000000
[Wed Aug 3 09:52:07 2022] Call Trace:
[Wed Aug 3 09:52:07 2022] __schedule+0x29f/0x840
[Wed Aug 3 09:52:07 2022] schedule+0x28/0x80
[Wed Aug 3 09:52:07 2022] schedule_preempt_disabled+0xa/0x10
[Wed Aug 3 09:52:07 2022] __mutex_lock.isra.8+0x286/0x470
[Wed Aug 3 09:52:07 2022] spa_open_common+0x5f/0x4c0 [zfs]
[Wed Aug 3 09:52:07 2022] ? entity_namecheck+0xc8/0x380 [zcommon]
[Wed Aug 3 09:52:07 2022] pool_status_check.isra.24.part.25+0x2c/0xe0 [zfs]
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl_common+0x588/0x830 [zfs]
[Wed Aug 3 09:52:07 2022] ? kmalloc_large_node+0x37/0x60
[Wed Aug 3 09:52:07 2022] ? __kmalloc_node+0x213/0x2c0
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl+0x4f/0xe0 [zfs]
[Wed Aug 3 09:52:07 2022] do_vfs_ioctl+0xa4/0x630
[Wed Aug 3 09:52:07 2022] ? handle_mm_fault+0xd6/0x200
[Wed Aug 3 09:52:07 2022] ksys_ioctl+0x60/0x90
[Wed Aug 3 09:52:07 2022] __x64_sys_ioctl+0x16/0x20
[Wed Aug 3 09:52:07 2022] do_syscall_64+0x53/0x110
[Wed Aug 3 09:52:07 2022] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Wed Aug 3 09:52:07 2022] RIP: 0033:0x7f55959c0427
[Wed Aug 3 09:52:07 2022] Code: Bad RIP value.
[Wed Aug 3 09:52:07 2022] RSP: 002b:00007ffde216ae08 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[Wed Aug 3 09:52:07 2022] RAX: ffffffffffffffda RBX: 00007ffde216ae70 RCX: 00007f55959c0427
[Wed Aug 3 09:52:07 2022] RDX: 00007ffde216ae70 RSI: 0000000000005a14 RDI: 0000000000000003
[Wed Aug 3 09:52:07 2022] RBP: 00007ffde216ae50 R08: 000000000003ffff R09: 00007f5595a8c0a0
[Wed Aug 3 09:52:07 2022] R10: 000056040ab91010 R11: 0000000000000246 R12: 000056040abdde90
[Wed Aug 3 09:52:07 2022] R13: 000056040a7efa50 R14: 000056040abddea0 R15: 0000000000005a14
[Wed Aug 3 09:52:07 2022] INFO: task zpool:18691 blocked for more than 120 seconds.
[Wed Aug 3 09:52:07 2022] Tainted: P W O 4.19.0-21-amd64 #1 Debian 4.19.208-3
[Wed Aug 3 09:52:07 2022] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Wed Aug 3 09:52:07 2022] zpool D 0 18691 1 0x00000000
[Wed Aug 3 09:52:07 2022] Call Trace:
[Wed Aug 3 09:52:07 2022] __schedule+0x29f/0x840
[Wed Aug 3 09:52:07 2022] schedule+0x28/0x80
[Wed Aug 3 09:52:07 2022] schedule_preempt_disabled+0xa/0x10
[Wed Aug 3 09:52:07 2022] __mutex_lock.isra.8+0x286/0x470
[Wed Aug 3 09:52:07 2022] spa_open_common+0x5f/0x4c0 [zfs]
[Wed Aug 3 09:52:07 2022] spa_get_stats+0x4d/0x520 [zfs]
[Wed Aug 3 09:52:07 2022] ? _cond_resched+0x15/0x30
[Wed Aug 3 09:52:07 2022] ? __kmalloc_node+0x1ea/0x2c0
[Wed Aug 3 09:52:07 2022] zfs_ioc_pool_stats+0x34/0x80 [zfs]
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl_common+0x5b5/0x830 [zfs]
[Wed Aug 3 09:52:07 2022] ? kmalloc_large_node+0x37/0x60
[Wed Aug 3 09:52:07 2022] ? __kmalloc_node+0x213/0x2c0
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl+0x4f/0xe0 [zfs]
[Wed Aug 3 09:52:07 2022] do_vfs_ioctl+0xa4/0x630
[Wed Aug 3 09:52:07 2022] ? handle_mm_fault+0xd6/0x200
[Wed Aug 3 09:52:07 2022] ksys_ioctl+0x60/0x90
[Wed Aug 3 09:52:07 2022] __x64_sys_ioctl+0x16/0x20
[Wed Aug 3 09:52:07 2022] do_syscall_64+0x53/0x110
[Wed Aug 3 09:52:07 2022] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Wed Aug 3 09:52:07 2022] RIP: 0033:0x7fdb5bd94427
[Wed Aug 3 09:52:07 2022] Code: Bad RIP value.
[Wed Aug 3 09:52:07 2022] RSP: 002b:00007ffc7aaf3ae8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[Wed Aug 3 09:52:07 2022] RAX: ffffffffffffffda RBX: 00007ffc7aaf3b10 RCX: 00007fdb5bd94427
[Wed Aug 3 09:52:07 2022] RDX: 00007ffc7aaf3b10 RSI: 0000000000005a05 RDI: 0000000000000004
[Wed Aug 3 09:52:07 2022] RBP: 00007ffc7aaf7100 R08: 000056194b840fa0 R09: 00007fdb5be5fea0
[Wed Aug 3 09:52:07 2022] R10: 000056194b83d010 R11: 0000000000000246 R12: 000056194b840e50
[Wed Aug 3 09:52:07 2022] R13: 000056194b83d2e0 R14: 0000000000000000 R15: 00007ffc7aaf7114
[Wed Aug 3 09:52:07 2022] INFO: task zpool:19003 blocked for more than 120 seconds.
[Wed Aug 3 09:52:07 2022] Tainted: P W O 4.19.0-21-amd64 #1 Debian 4.19.208-3
[Wed Aug 3 09:52:07 2022] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Wed Aug 3 09:52:07 2022] zpool D 0 19003 1 0x00000000
[Wed Aug 3 09:52:07 2022] Call Trace:
[Wed Aug 3 09:52:07 2022] __schedule+0x29f/0x840
[Wed Aug 3 09:52:07 2022] schedule+0x28/0x80
[Wed Aug 3 09:52:07 2022] schedule_preempt_disabled+0xa/0x10
[Wed Aug 3 09:52:07 2022] __mutex_lock.isra.8+0x286/0x470
[Wed Aug 3 09:52:07 2022] spa_open_common+0x5f/0x4c0 [zfs]
[Wed Aug 3 09:52:07 2022] spa_get_stats+0x4d/0x520 [zfs]
[Wed Aug 3 09:52:07 2022] ? _cond_resched+0x15/0x30
[Wed Aug 3 09:52:07 2022] ? __kmalloc_node+0x1ea/0x2c0
[Wed Aug 3 09:52:07 2022] zfs_ioc_pool_stats+0x34/0x80 [zfs]
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl_common+0x5b5/0x830 [zfs]
[Wed Aug 3 09:52:07 2022] ? kmalloc_large_node+0x37/0x60
[Wed Aug 3 09:52:07 2022] ? __kmalloc_node+0x213/0x2c0
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl+0x4f/0xe0 [zfs]
[Wed Aug 3 09:52:07 2022] do_vfs_ioctl+0xa4/0x630
[Wed Aug 3 09:52:07 2022] ? handle_mm_fault+0xd6/0x200
[Wed Aug 3 09:52:07 2022] ksys_ioctl+0x60/0x90
[Wed Aug 3 09:52:07 2022] __x64_sys_ioctl+0x16/0x20
[Wed Aug 3 09:52:07 2022] do_syscall_64+0x53/0x110
[Wed Aug 3 09:52:07 2022] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Wed Aug 3 09:52:07 2022] RIP: 0033:0x7efc09320427
[Wed Aug 3 09:52:07 2022] Code: Bad RIP value.
[Wed Aug 3 09:52:07 2022] RSP: 002b:00007ffcf1d594c8 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[Wed Aug 3 09:52:07 2022] RAX: ffffffffffffffda RBX: 00007ffcf1d594f0 RCX: 00007efc09320427
[Wed Aug 3 09:52:07 2022] RDX: 00007ffcf1d594f0 RSI: 0000000000005a05 RDI: 0000000000000004
[Wed Aug 3 09:52:07 2022] RBP: 00007ffcf1d5cae0 R08: 0000563ad85cefa0 R09: 00007efc093ebea0
[Wed Aug 3 09:52:07 2022] R10: 0000563ad85cb010 R11: 0000000000000246 R12: 0000563ad85cee50
[Wed Aug 3 09:52:07 2022] R13: 0000563ad85cb2e0 R14: 0000000000000000 R15: 00007ffcf1d5caf4
[Wed Aug 3 09:52:07 2022] INFO: task zpool:19632 blocked for more than 120 seconds.
[Wed Aug 3 09:52:07 2022] Tainted: P W O 4.19.0-21-amd64 #1 Debian 4.19.208-3
[Wed Aug 3 09:52:07 2022] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[Wed Aug 3 09:52:07 2022] zpool D 0 19632 1 0x00000000
[Wed Aug 3 09:52:07 2022] Call Trace:
[Wed Aug 3 09:52:07 2022] __schedule+0x29f/0x840
[Wed Aug 3 09:52:07 2022] schedule+0x28/0x80
[Wed Aug 3 09:52:07 2022] schedule_preempt_disabled+0xa/0x10
[Wed Aug 3 09:52:07 2022] __mutex_lock.isra.8+0x286/0x470
[Wed Aug 3 09:52:07 2022] spa_open_common+0x5f/0x4c0 [zfs]
[Wed Aug 3 09:52:07 2022] spa_get_stats+0x4d/0x520 [zfs]
[Wed Aug 3 09:52:07 2022] ? _cond_resched+0x15/0x30
[Wed Aug 3 09:52:07 2022] ? __kmalloc_node+0x1ea/0x2c0
[Wed Aug 3 09:52:07 2022] zfs_ioc_pool_stats+0x34/0x80 [zfs]
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl_common+0x5b5/0x830 [zfs]
[Wed Aug 3 09:52:07 2022] ? kmalloc_large_node+0x37/0x60
[Wed Aug 3 09:52:07 2022] ? __kmalloc_node+0x213/0x2c0
[Wed Aug 3 09:52:07 2022] zfsdev_ioctl+0x4f/0xe0 [zfs]
[Wed Aug 3 09:52:07 2022] do_vfs_ioctl+0xa4/0x630
[Wed Aug 3 09:52:07 2022] ? handle_mm_fault+0xd6/0x200
[Wed Aug 3 09:52:07 2022] ksys_ioctl+0x60/0x90
[Wed Aug 3 09:52:07 2022] __x64_sys_ioctl+0x16/0x20
[Wed Aug 3 09:52:07 2022] do_syscall_64+0x53/0x110
[Wed Aug 3 09:52:07 2022] entry_SYSCALL_64_after_hwframe+0x44/0xa9
[Wed Aug 3 09:52:07 2022] RIP: 0033:0x7ff55303f427
[Wed Aug 3 09:52:07 2022] Code: Bad RIP value.
[Wed Aug 3 09:52:07 2022] RSP: 002b:00007ffc99345b98 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[Wed Aug 3 09:52:07 2022] RAX: ffffffffffffffda RBX: 00007ffc99345bc0 RCX: 00007ff55303f427
[Wed Aug 3 09:52:07 2022] RDX: 00007ffc99345bc0 RSI: 0000000000005a05 RDI: 0000000000000004
[Wed Aug 3 09:52:07 2022] RBP: 00007ffc993491b0 R08: 000055e51079bfa0 R09: 00007ff55310aea0
[Wed Aug 3 09:52:07 2022] R10: 000055e510798010 R11: 0000000000000246 R12: 000055e51079be50
[Wed Aug 3 09:52:07 2022] R13: 000055e5107982e0 R14: 0000000000000000 R15: 00007ffc993491c4
I've also attached the contents of /proc/spl/kstat/zfs/dbgmsg: dbgmsg.txt
