search

openzfs / zfs

OpenZFS on Linux and FreeBSD
https://openzfs.github.io/openzfs-docs
Other
10.62k stars 1.75k forks source link

PANIC: zfs: removing nonexistent segment from range tree #15915

Open antst opened 8 months ago

antst commented 8 months ago

System information

Type Version/Name
Distribution Name Ubuntu
Distribution Version 22.04.03
Kernel Version 6.5.0-15-generic
Architecture x86_64
OpenZFS Version 2.2.0 (kernel) 2.1.5 (utils)

Describe the problem you're observing

On pool import I get a panic , then systems hangs. After initial panic message, systems keeps hanging, but produce regular message about blocked task. As it is root pool,I rather limited in options. But I tried: 1) import as read-only, it works. 2) set zil_replay_disable=1 and zfs_recover=1, it does not help.

HW details: Pool is on single NVME (Samsung 970 Pro). Smartctl shows good health of the NVME. System is with ECC memory. I can guess that because I had couple of hard resets (due to some other issue), I got some corruption. But I would love to find way to fix pool.

Describe how to reproduce the problem

Include any warning/errors/backtraces from the system logs

console log:

(initramfs) modprobe zfs
[ 1827.190644] ZFS: Loaded module v2.2.0-0ubuntu1~23.10, ZFS pool version 5000, ZFS filesystem version 5
(initramfs) zpool import -N -o failmode=continue  rpool
[ 1909.349875] PANIC: zfs: removing nonexistent segment from range tree (offset=f001540e812000 size=2000)
[ 1909.363713] Showing stack for process 2026
[ 1909.372262] CPU: 19 PID: 2026 Comm: z_wr_iss Tainted: P           OE      6.5.0-18-generic #18~22.04.1-Ubuntu
[ 1909.386723] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./TRX40D8-2N2T, BIOS P1.10 08/13/2020
[ 1909.401107] Call Trace:
[ 1909.408011]  <TASK>
[ 1909.414525]  dump_stack_lvl+0x48/0x70
[ 1909.422625]  dump_stack+0x10/0x20
[ 1909.430335]  spl_dumpstack+0x29/0x40 [spl]
[ 1909.438868]  vcmn_err+0xb8/0x110 [spl]
[ 1909.447146]  zfs_panic_recover+0x75/0xa0 [zfs]
[ 1909.456389]  range_tree_remove_impl+0x486/0x4f0 [zfs]
[ 1909.466269]  range_tree_remove+0x10/0x20 [zfs]
[ 1909.475499]  space_map_load_callback+0x27/0xb0 [zfs]
[ 1909.485228]  space_map_iterate+0x1bc/0x480 [zfs]
[ 1909.494560]  ? __pfx_space_map_load_callback+0x10/0x10 [zfs]
[ 1909.504953]  space_map_load_length+0x7c/0x100 [zfs]
[ 1909.514559]  metaslab_load_impl+0xcd/0x510 [zfs]
[ 1909.523884]  ? srso_return_thunk+0x5/0x10
[ 1909.532277]  ? ktime_get_raw_ts64+0x41/0xd0
[ 1909.540780]  ? srso_return_thunk+0x5/0x10
[ 1909.549076]  ? srso_return_thunk+0x5/0x10
[ 1909.557292]  ? gethrtime+0x30/0x60 [zfs]
[ 1909.565757]  ? srso_return_thunk+0x5/0x10
[ 1909.573931]  ? arc_all_memory+0xe/0x20 [zfs]
[ 1909.582681]  ? srso_return_thunk+0x5/0x10
[ 1909.590737]  metaslab_load+0x72/0xe0 [zfs]
[ 1909.599120]  metaslab_activate+0x50/0x110 [zfs]
[ 1909.607972]  ? srso_return_thunk+0x5/0x10
[ 1909.615925]  metaslab_group_alloc_normal+0x318/0x4f0 [zfs]
[ 1909.625709]  metaslab_group_alloc+0x25/0xb0 [zfs]
[ 1909.634583]  metaslab_alloc_dva+0x28f/0x590 [zfs]
[ 1909.643325]  metaslab_alloc+0xc8/0x200 [zfs]
[ 1909.651558]  zio_dva_allocate+0xb2/0x390 [zfs]
[ 1909.659845]  ? tsd_get+0x30/0x60 [spl]
[ 1909.667005]  ? srso_return_thunk+0x5/0x10
[ 1909.674288]  zio_execute+0x92/0xf0 [zfs]
[ 1909.681674]  taskq_thread+0x1f6/0x3c0 [spl]
[ 1909.688899]  ? __pfx_default_wake_function+0x10/0x10
[ 1909.696801]  ? __pfx_zio_execute+0x10/0x10 [zfs]
[ 1909.704659]  ? __pfx_taskq_thread+0x10/0x10 [spl]
[ 1909.712278]  kthread+0xf2/0x120
[ 1909.718289]  ? __pfx_kthread+0x10/0x10
[ 1909.724912]  ret_from_fork+0x47/0x70
[ 1909.731317]  ? __pfx_kthread+0x10/0x10
[ 1909.737860]  ret_from_fork_asm+0x1b/0x30
[ 1909.744570]  </TASK>
[ 2055.094755] INFO: task zpool:1649 blocked for more than 120 seconds.
[ 2055.103826]       Tainted: P           OE      6.5.0-18-generic #18~22.04.1-Ubuntu
[ 2055.114082] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2055.124596] task:zpool           state:D stack:0     pid:1649  ppid:1632   flags:0x00004002
[ 2055.135619] Call Trace:
[ 2055.140607]  <TASK>
[ 2055.145240]  __schedule+0x2cc/0x750
[ 2055.151290]  ? srso_return_thunk+0x5/0x10
[ 2055.157889]  schedule+0x63/0x110
[ 2055.163695]  io_schedule+0x46/0x80
[ 2055.169666]  cv_wait_common+0xab/0x140 [spl]
[ 2055.176534]  ? __pfx_autoremove_wake_function+0x10/0x10
[ 2055.184344]  __cv_wait_io+0x18/0x30 [spl]
[ 2055.190956]  txg_wait_synced_impl+0xd6/0x130 [zfs]
[ 2055.198533]  txg_wait_synced+0x10/0x60 [zfs]
[ 2055.205556]  spa_load_impl.constprop.0+0x280/0x3b0 [zfs]
[ 2055.213634]  spa_load+0x6b/0x130 [zfs]
[ 2055.220114]  spa_load_best+0x57/0x260 [zfs]
[ 2055.227009]  ? zpool_get_load_policy+0x19e/0x1b0 [zfs]
[ 2055.234866]  spa_import+0x22f/0x670 [zfs]
[ 2055.241604]  zfs_ioc_pool_import+0x163/0x180 [zfs]
[ 2055.249140]  zfsdev_ioctl_common+0x62d/0x750 [zfs]
[ 2055.256708]  ? srso_return_thunk+0x5/0x10
[ 2055.263337]  ? srso_return_thunk+0x5/0x10
[ 2055.269921]  zfsdev_ioctl+0x57/0xf0 [zfs]
[ 2055.276663]  __x64_sys_ioctl+0xa3/0xf0
[ 2055.282986]  do_syscall_64+0x5b/0x90
[ 2055.289131]  ? srso_return_thunk+0x5/0x10
[ 2055.295719]  ? __fput+0x1aa/0x2c0
[ 2055.301592]  ? srso_return_thunk+0x5/0x10
[ 2055.308143]  ? __rseq_handle_notify_resume+0x37/0x70
[ 2055.315682]  ? srso_return_thunk+0x5/0x10
[ 2055.322278]  ? exit_to_user_mode_loop+0xe5/0x130
[ 2055.329503]  ? srso_return_thunk+0x5/0x10
[ 2055.336112]  ? exit_to_user_mode_prepare+0x30/0xb0
[ 2055.343513]  ? srso_return_thunk+0x5/0x10
[ 2055.350133]  ? syscall_exit_to_user_mode+0x37/0x60
[ 2055.357553]  ? srso_return_thunk+0x5/0x10
[ 2055.364184]  ? do_syscall_64+0x67/0x90
[ 2055.370545]  entry_SYSCALL_64_after_hwframe+0x6e/0xd8
[ 2055.378237] RIP: 0033:0x7fd596a6294f
[ 2055.384460] RSP: 002b:00007ffc202fddb0 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 2055.394756] RAX: ffffffffffffffda RBX: 000055e19b969500 RCX: 00007fd596a6294f
[ 2055.404660] RDX: 00007ffc202fe780 RSI: 0000000000005a02 RDI: 0000000000000003
[ 2055.414596] RBP: 00007ffc20301d70 R08: 0000000000000000 R09: 000055e19b975fc0
[ 2055.424529] R10: 00007fd596b63410 R11: 0000000000000246 R12: 000055e19b952320
[ 2055.434695] R13: 00007ffc202fe780 R14: 00007fd588001a70 R15: 0000000000000000
[ 2055.444635]  </TASK>
[ 2055.449724] INFO: task z_wr_iss:1832 blocked for more than 121 seconds.
[ 2055.459120]       Tainted: P           OE      6.5.0-18-generic #18~22.04.1-Ubuntu
[ 2055.469648] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2055.480257] task:z_wr_iss        state:D stack:0     pid:1832  ppid:2      flags:0x00004000
[ 2055.491429] Call Trace:
[ 2055.496666]  <TASK>
[ 2055.501541]  __schedule+0x2cc/0x750
[ 2055.507819]  ? rs_get_start+0x11/0x40 [zfs]
[ 2055.514979]  schedule+0x63/0x110
[ 2055.521009]  cv_wait_common+0x102/0x140 [spl]
[ 2055.528192]  ? __pfx_autoremove_wake_function+0x10/0x10
[ 2055.536253]  __cv_wait+0x15/0x30 [spl]
[ 2055.542827]  metaslab_load_wait+0x28/0x50 [zfs]
[ 2055.550347]  metaslab_load+0x17/0xe0 [zfs]
[ 2055.557420]  metaslab_activate+0x50/0x110 [zfs]
[ 2055.564908]  ? srso_return_thunk+0x5/0x10
[ 2055.571698]  metaslab_group_alloc_normal+0x318/0x4f0 [zfs]
[ 2055.580189]  metaslab_group_alloc+0x25/0xb0 [zfs]
[ 2055.587858]  metaslab_alloc_dva+0x28f/0x590 [zfs]
[ 2055.595502]  metaslab_alloc+0xc8/0x200 [zfs]
[ 2055.602689]  zio_dva_allocate+0xb2/0x390 [zfs]
[ 2055.610064]  ? tsd_get+0x30/0x60 [spl]
[ 2055.616619]  ? srso_return_thunk+0x5/0x10
[ 2055.623495]  zio_execute+0x92/0xf0 [zfs]
[ 2055.630386]  taskq_thread+0x1f6/0x3c0 [spl]
[ 2055.637500]  ? __pfx_default_wake_function+0x10/0x10
[ 2055.645299]  ? __pfx_zio_execute+0x10/0x10 [zfs]
[ 2055.652965]  ? __pfx_taskq_thread+0x10/0x10 [spl]
[ 2055.660593]  kthread+0xf2/0x120
[ 2055.666619]  ? __pfx_kthread+0x10/0x10
[ 2055.673210]  ret_from_fork+0x47/0x70
[ 2055.679627]  ? __pfx_kthread+0x10/0x10
[ 2055.686187]  ret_from_fork_asm+0x1b/0x30
[ 2055.692920]  </TASK>
[ 2055.697873] INFO: task txg_sync:2019 blocked for more than 121 seconds.
[ 2055.707331]       Tainted: P           OE      6.5.0-18-generic #18~22.04.1-Ubuntu
[ 2055.717791] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2055.728572] task:txg_sync        state:D stack:0     pid:2019  ppid:2      flags:0x00004000
[ 2055.739972] Call Trace:
[ 2055.745380]  <TASK>
[ 2055.750397]  __schedule+0x2cc/0x750
[ 2055.756775]  schedule+0x63/0x110
[ 2055.762829]  schedule_timeout+0x95/0x170
[ 2055.769559]  ? __pfx_process_timeout+0x10/0x10
[ 2055.776821]  io_schedule_timeout+0x51/0x80
[ 2055.783746]  __cv_timedwait_common+0x139/0x180 [spl]
[ 2055.791562]  ? __pfx_autoremove_wake_function+0x10/0x10
[ 2055.799612]  __cv_timedwait_io+0x19/0x30 [spl]
[ 2055.806859]  zio_wait+0x116/0x230 [zfs]
[ 2055.813589]  dsl_pool_sync_mos+0x3c/0xc0 [zfs]
[ 2055.820892]  dsl_pool_sync+0x3b3/0x410 [zfs]
[ 2055.827954]  spa_sync_iterate_to_convergence+0xde/0x220 [zfs]
[ 2055.836493]  spa_sync+0x321/0x620 [zfs]
[ 2055.843132]  txg_sync_thread+0x1e2/0x250 [zfs]
[ 2055.850385]  ? __pfx_txg_sync_thread+0x10/0x10 [zfs]
[ 2055.858178]  ? __pfx_thread_generic_wrapper+0x10/0x10 [spl]
[ 2055.866449]  thread_generic_wrapper+0x5f/0x70 [spl]
[ 2055.874031]  kthread+0xf2/0x120
[ 2055.879844]  ? __pfx_kthread+0x10/0x10
[ 2055.886287]  ret_from_fork+0x47/0x70
[ 2055.892544]  ? __pfx_kthread+0x10/0x10
[ 2055.898947]  ret_from_fork_asm+0x1b/0x30
[ 2055.905671]  </TASK>
[ 2055.910474] INFO: task z_wr_iss:2021 blocked for more than 121 seconds.
[ 2055.919856]       Tainted: P           OE      6.5.0-18-generic #18~22.04.1-Ubuntu
[ 2055.930274] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2055.941026] task:z_wr_iss        state:D stack:0     pid:2021  ppid:2      flags:0x00004000
[ 2055.952359] Call Trace:
[ 2055.957739]  <TASK>
[ 2055.962696]  __schedule+0x2cc/0x750
[ 2055.969051]  ? rs_get_start+0x11/0x40 [zfs]
[ 2055.976280]  schedule+0x63/0x110
[ 2055.982375]  cv_wait_common+0x102/0x140 [spl]
[ 2055.989604]  ? __pfx_autoremove_wake_function+0x10/0x10
[ 2055.997905]  __cv_wait+0x15/0x30 [spl]
[ 2056.004550]  metaslab_load_wait+0x28/0x50 [zfs]
[ 2056.012149]  metaslab_load+0x17/0xe0 [zfs]
[ 2056.019484]  metaslab_activate+0x50/0x110 [zfs]
[ 2056.027256]  ? srso_return_thunk+0x5/0x10
[ 2056.034172]  metaslab_group_alloc_normal+0x318/0x4f0 [zfs]
[ 2056.042772]  metaslab_group_alloc+0x25/0xb0 [zfs]
[ 2056.050573]  metaslab_alloc_dva+0x28f/0x590 [zfs]
[ 2056.058325]  metaslab_alloc+0xc8/0x200 [zfs]
[ 2056.065574]  zio_dva_allocate+0xb2/0x390 [zfs]
[ 2056.072935]  ? tsd_get+0x30/0x60 [spl]
[ 2056.079378]  ? srso_return_thunk+0x5/0x10
[ 2056.086221]  zio_execute+0x92/0xf0 [zfs]
[ 2056.092968]  taskq_thread+0x1f6/0x3c0 [spl]
[ 2056.099850]  ? __pfx_default_wake_function+0x10/0x10
[ 2056.107718]  ? __pfx_zio_execute+0x10/0x10 [zfs]
[ 2056.115227]  ? __pfx_taskq_thread+0x10/0x10 [spl]
[ 2056.122667]  kthread+0xf2/0x120
[ 2056.128626]  ? __pfx_kthread+0x10/0x10
[ 2056.135074]  ret_from_fork+0x47/0x70
[ 2056.141317]  ? __pfx_kthread+0x10/0x10
[ 2056.147891]  ret_from_fork_asm+0x1b/0x30
[ 2056.154461]  </TASK>
[ 2056.159260] INFO: task z_wr_iss:2022 blocked for more than 121 seconds.
[ 2056.168600]       Tainted: P           OE      6.5.0-18-generic #18~22.04.1-Ubuntu
[ 2056.178928] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2056.189566] task:z_wr_iss        state:D stack:0     pid:2022  ppid:2      flags:0x00004000
[ 2056.200823] Call Trace:
[ 2056.206089]  <TASK>
[ 2056.211012]  __schedule+0x2cc/0x750
[ 2056.217340]  ? rs_get_start+0x11/0x40 [zfs]
[ 2056.224515]  schedule+0x63/0x110
[ 2056.230525]  cv_wait_common+0x102/0x140 [spl]
[ 2056.237738]  ? __pfx_autoremove_wake_function+0x10/0x10
[ 2056.245948]  __cv_wait+0x15/0x30 [spl]
[ 2056.252539]  metaslab_load_wait+0x28/0x50 [zfs]
[ 2056.260135]  metaslab_load+0x17/0xe0 [zfs]
[ 2056.267237]  metaslab_activate+0x50/0x110 [zfs]
[ 2056.274685]  ? srso_return_thunk+0x5/0x10
[ 2056.281429]  metaslab_group_alloc_normal+0x318/0x4f0 [zfs]
[ 2056.289782]  metaslab_group_alloc+0x25/0xb0 [zfs]
[ 2056.297250]  metaslab_alloc_dva+0x28f/0x590 [zfs]
[ 2056.304776]  metaslab_alloc+0xc8/0x200 [zfs]
[ 2056.311834]  zio_dva_allocate+0xb2/0x390 [zfs]
[ 2056.319061]  ? tsd_get+0x30/0x60 [spl]
[ 2056.325421]  ? srso_return_thunk+0x5/0x10
[ 2056.332029]  zio_execute+0x92/0xf0 [zfs]
[ 2056.338693]  taskq_thread+0x1f6/0x3c0 [spl]
[ 2056.345459]  ? __pfx_default_wake_function+0x10/0x10
[ 2056.353002]  ? __pfx_zio_execute+0x10/0x10 [zfs]
[ 2056.360377]  ? __pfx_taskq_thread+0x10/0x10 [spl]
[ 2056.367695]  kthread+0xf2/0x120
[ 2056.373420]  ? __pfx_kthread+0x10/0x10
[ 2056.379734]  ret_from_fork+0x47/0x70
[ 2056.385875]  ? __pfx_kthread+0x10/0x10
[ 2056.392195]  ret_from_fork_asm+0x1b/0x30
[ 2056.398704]  </TASK>
[ 2056.403453] INFO: task z_wr_iss:2024 blocked for more than 122 seconds.
[ 2056.412715]       Tainted: P           OE      6.5.0-18-generic #18~22.04.1-Ubuntu
[ 2056.422992] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2056.433830] task:z_wr_iss        state:D stack:0     pid:2024  ppid:2      flags:0x00004000
[ 2056.445036] Call Trace:
[ 2056.450275]  <TASK>
[ 2056.455127]  __schedule+0x2cc/0x750
[ 2056.461383]  ? rs_get_start+0x11/0x40 [zfs]
[ 2056.468506]  schedule+0x63/0x110
[ 2056.474500]  cv_wait_common+0x102/0x140 [spl]
[ 2056.481695]  ? __pfx_autoremove_wake_function+0x10/0x10
[ 2056.489742]  __cv_wait+0x15/0x30 [spl]
[ 2056.496356]  metaslab_load_wait+0x28/0x50 [zfs]
[ 2056.503900]  metaslab_load+0x17/0xe0 [zfs]
[ 2056.510958]  metaslab_activate+0x50/0x110 [zfs]
[ 2056.518396]  ? srso_return_thunk+0x5/0x10
[ 2056.525078]  metaslab_group_alloc_normal+0x318/0x4f0 [zfs]
[ 2056.533379]  metaslab_group_alloc+0x25/0xb0 [zfs]
[ 2056.540841]  metaslab_alloc_dva+0x28f/0x590 [zfs]
[ 2056.548323]  metaslab_alloc+0xc8/0x200 [zfs]
[ 2056.555371]  zio_dva_allocate+0xb2/0x390 [zfs]
[ 2056.562585]  ? tsd_get+0x30/0x60 [spl]
[ 2056.568944]  ? srso_return_thunk+0x5/0x10
[ 2056.575560]  zio_execute+0x92/0xf0 [zfs]
[ 2056.582224]  taskq_thread+0x1f6/0x3c0 [spl]
[ 2056.588984]  ? __pfx_default_wake_function+0x10/0x10
[ 2056.596540]  ? __pfx_zio_execute+0x10/0x10 [zfs]
[ 2056.603919]  ? __pfx_taskq_thread+0x10/0x10 [spl]
[ 2056.611238]  kthread+0xf2/0x120
[ 2056.616971]  ? __pfx_kthread+0x10/0x10
[ 2056.623294]  ret_from_fork+0x47/0x70
[ 2056.629439]  ? __pfx_kthread+0x10/0x10
[ 2056.635766]  ret_from_fork_asm+0x1b/0x30
[ 2056.642276]  </TASK>
[ 2056.647040] INFO: task z_wr_iss:2025 blocked for more than 122 seconds.
[ 2056.656319]       Tainted: P           OE      6.5.0-18-generic #18~22.04.1-Ubuntu
[ 2056.666609] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2056.677215] task:z_wr_iss        state:D stack:0     pid:2025  ppid:2      flags:0x00004000
[ 2056.688594] Call Trace:
[ 2056.693830]  <TASK>
[ 2056.698743]  __schedule+0x2cc/0x750
[ 2056.705009]  ? rs_get_start+0x11/0x40 [zfs]
[ 2056.712149]  schedule+0x63/0x110
[ 2056.718139]  cv_wait_common+0x102/0x140 [spl]
[ 2056.725295]  ? __pfx_autoremove_wake_function+0x10/0x10
[ 2056.733341]  __cv_wait+0x15/0x30 [spl]
[ 2056.739929]  metaslab_load_wait+0x28/0x50 [zfs]
[ 2056.747647]  metaslab_load+0x17/0xe0 [zfs]
[ 2056.754708]  metaslab_activate+0x50/0x110 [zfs]
[ 2056.762139]  ? srso_return_thunk+0x5/0x10
[ 2056.768826]  metaslab_group_alloc_normal+0x318/0x4f0 [zfs]
[ 2056.777305]  metaslab_group_alloc+0x25/0xb0 [zfs]
[ 2056.784769]  metaslab_alloc_dva+0x28f/0x590 [zfs]
[ 2056.792254]  metaslab_alloc+0xc8/0x200 [zfs]
[ 2056.799291]  zio_dva_allocate+0xb2/0x390 [zfs]
[ 2056.806682]  ? tsd_get+0x30/0x60 [spl]
[ 2056.813042]  ? srso_return_thunk+0x5/0x10
[ 2056.819654]  zio_execute+0x92/0xf0 [zfs]
[ 2056.826495]  taskq_thread+0x1f6/0x3c0 [spl]
[ 2056.833256]  ? __pfx_default_wake_function+0x10/0x10
[ 2056.840807]  ? __pfx_zio_execute+0x10/0x10 [zfs]
[ 2056.848176]  ? __pfx_taskq_thread+0x10/0x10 [spl]
[ 2056.855507]  kthread+0xf2/0x120
[ 2056.861235]  ? __pfx_kthread+0x10/0x10
[ 2056.867621]  ret_from_fork+0x47/0x70
[ 2056.873761]  ? __pfx_kthread+0x10/0x10
[ 2056.880082]  ret_from_fork_asm+0x1b/0x30
[ 2056.886585]  </TASK>
[ 2056.891312] INFO: task z_wr_iss:2026 blocked for more than 122 seconds.
[ 2056.900565]       Tainted: P           OE      6.5.0-18-generic #18~22.04.1-Ubuntu
[ 2056.910851] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2056.921452] task:z_wr_iss        state:D stack:0     pid:2026  ppid:2      flags:0x00004000
[ 2056.932653] Call Trace:
[ 2056.938070]  <TASK>
[ 2056.942928]  __schedule+0x2cc/0x750
[ 2056.949190]  schedule+0x63/0x110
[ 2056.955165]  vcmn_err+0xce/0x110 [spl]
[ 2056.961673]  zfs_panic_recover+0x75/0xa0 [zfs]
[ 2056.969048]  range_tree_remove_impl+0x486/0x4f0 [zfs]
[ 2056.977061]  range_tree_remove+0x10/0x20 [zfs]
[ 2056.984455]  space_map_load_callback+0x27/0xb0 [zfs]
[ 2056.992381]  space_map_iterate+0x1bc/0x480 [zfs]
[ 2056.999916]  ? __pfx_space_map_load_callback+0x10/0x10 [zfs]
[ 2057.008485]  space_map_load_length+0x7c/0x100 [zfs]
[ 2057.016223]  metaslab_load_impl+0xcd/0x510 [zfs]
[ 2057.023653]  ? srso_return_thunk+0x5/0x10
[ 2057.030259]  ? ktime_get_raw_ts64+0x41/0xd0
[ 2057.037058]  ? srso_return_thunk+0x5/0x10
[ 2057.043700]  ? srso_return_thunk+0x5/0x10
[ 2057.050295]  ? gethrtime+0x30/0x60 [zfs]
[ 2057.056966]  ? srso_return_thunk+0x5/0x10
[ 2057.063558]  ? arc_all_memory+0xe/0x20 [zfs]
[ 2057.070576]  ? srso_return_thunk+0x5/0x10
[ 2057.077126]  metaslab_load+0x72/0xe0 [zfs]
[ 2057.083928]  metaslab_activate+0x50/0x110 [zfs]
[ 2057.091176]  ? srso_return_thunk+0x5/0x10
[ 2057.097733]  metaslab_group_alloc_normal+0x318/0x4f0 [zfs]
[ 2057.105976]  metaslab_group_alloc+0x25/0xb0 [zfs]
[ 2057.113401]  metaslab_alloc_dva+0x28f/0x590 [zfs]
[ 2057.120823]  metaslab_alloc+0xc8/0x200 [zfs]
[ 2057.127814]  zio_dva_allocate+0xb2/0x390 [zfs]
[ 2057.134980]  ? tsd_get+0x30/0x60 [spl]
[ 2057.141285]  ? srso_return_thunk+0x5/0x10
[ 2057.147838]  zio_execute+0x92/0xf0 [zfs]
[ 2057.154465]  taskq_thread+0x1f6/0x3c0 [spl]
[ 2057.161211]  ? __pfx_default_wake_function+0x10/0x10
[ 2057.168752]  ? __pfx_zio_execute+0x10/0x10 [zfs]
[ 2057.176090]  ? __pfx_taskq_thread+0x10/0x10 [spl]
[ 2057.183359]  kthread+0xf2/0x120
[ 2057.189047]  ? __pfx_kthread+0x10/0x10
[ 2057.195336]  ret_from_fork+0x47/0x70
[ 2057.201447]  ? __pfx_kthread+0x10/0x10
[ 2057.207739]  ret_from_fork_asm+0x1b/0x30
[ 2057.214218]  </TASK>
[ 2057.218924] INFO: task z_wr_iss:2027 blocked for more than 122 seconds.
[ 2057.228161]       Tainted: P           OE      6.5.0-18-generic #18~22.04.1-Ubuntu
[ 2057.238386] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2057.248881] task:z_wr_iss        state:D stack:0     pid:2027  ppid:2      flags:0x00004000
[ 2057.259913] Call Trace:
[ 2057.264928]  <TASK>
[ 2057.269521]  __schedule+0x2cc/0x750
[ 2057.275540]  ? rs_get_start+0x11/0x40 [zfs]
[ 2057.282445]  schedule+0x63/0x110
[ 2057.288214]  cv_wait_common+0x102/0x140 [spl]
[ 2057.295162]  ? __pfx_autoremove_wake_function+0x10/0x10
[ 2057.302998]  __cv_wait+0x15/0x30 [spl]
[ 2057.309348]  metaslab_load_wait+0x28/0x50 [zfs]
[ 2057.316665]  metaslab_load+0x17/0xe0 [zfs]
[ 2057.323519]  metaslab_activate+0x50/0x110 [zfs]
[ 2057.330809]  ? srso_return_thunk+0x5/0x10
[ 2057.337382]  metaslab_group_alloc_normal+0x318/0x4f0 [zfs]
[ 2057.345617]  metaslab_group_alloc+0x25/0xb0 [zfs]
[ 2057.353035]  metaslab_alloc_dva+0x28f/0x590 [zfs]
[ 2057.360448]  metaslab_alloc+0xc8/0x200 [zfs]
[ 2057.367410]  zio_dva_allocate+0xb2/0x390 [zfs]
[ 2057.374549]  ? tsd_get+0x30/0x60 [spl]
[ 2057.380867]  ? srso_return_thunk+0x5/0x10
[ 2057.387447]  zio_execute+0x92/0xf0 [zfs]
[ 2057.394091]  taskq_thread+0x1f6/0x3c0 [spl]
[ 2057.400854]  ? __pfx_default_wake_function+0x10/0x10
[ 2057.408420]  ? __pfx_zio_execute+0x10/0x10 [zfs]
[ 2057.415794]  ? __pfx_taskq_thread+0x10/0x10 [spl]
[ 2057.423110]  kthread+0xf2/0x120
[ 2057.428838]  ? __pfx_kthread+0x10/0x10
[ 2057.435193]  ret_from_fork+0x47/0x70
[ 2057.441330]  ? __pfx_kthread+0x10/0x10
[ 2057.447650]  ret_from_fork_asm+0x1b/0x30
[ 2057.454165]  </TASK>
[ 2057.458899] INFO: task z_wr_iss:2029 blocked for more than 123 seconds.
[ 2057.468334]       Tainted: P           OE      6.5.0-18-generic #18~22.04.1-Ubuntu
[ 2057.478791] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[ 2057.489578] task:z_wr_iss        state:D stack:0     pid:2029  ppid:2      flags:0x00004000
[ 2057.500781] Call Trace:
[ 2057.506022]  <TASK>
[ 2057.510884]  __schedule+0x2cc/0x750
[ 2057.517316]  ? rs_get_start+0x11/0x40 [zfs]
[ 2057.524439]  schedule+0x63/0x110
[ 2057.530614]  cv_wait_common+0x102/0x140 [spl]
[ 2057.537844]  ? __pfx_autoremove_wake_function+0x10/0x10
[ 2057.546074]  __cv_wait+0x15/0x30 [spl]
[ 2057.552652]  metaslab_load_wait+0x28/0x50 [zfs]
[ 2057.560195]  metaslab_load+0x17/0xe0 [zfs]
[ 2057.567422]  metaslab_activate+0x50/0x110 [zfs]
[ 2057.574864]  ? srso_return_thunk+0x5/0x10
[ 2057.581543]  metaslab_group_alloc_normal+0x318/0x4f0 [zfs]
[ 2057.589846]  metaslab_group_alloc+0x25/0xb0 [zfs]
[ 2057.597317]  metaslab_alloc_dva+0x28f/0x590 [zfs]
[ 2057.604798]  metaslab_alloc+0xc8/0x200 [zfs]
[ 2057.611840]  zio_dva_allocate+0xb2/0x390 [zfs]
[ 2057.619059]  ? tsd_get+0x30/0x60 [spl]
[ 2057.625596]  ? srso_return_thunk+0x5/0x10
[ 2057.632209]  zio_execute+0x92/0xf0 [zfs]
[ 2057.638876]  taskq_thread+0x1f6/0x3c0 [spl]
[ 2057.645813]  ? __pfx_default_wake_function+0x10/0x10
[ 2057.653362]  ? __pfx_zio_execute+0x10/0x10 [zfs]
[ 2057.660728]  ? __pfx_taskq_thread+0x10/0x10 [spl]
[ 2057.668039]  kthread+0xf2/0x120
[ 2057.673767]  ? __pfx_kthread+0x10/0x10
[ 2057.680092]  ret_from_fork+0x47/0x70
[ 2057.686241]  ? __pfx_kthread+0x10/0x10
[ 2057.692564]  ret_from_fork_asm+0x1b/0x30
[ 2057.699076]  </TASK>
[ 2057.703811] Future hung task reports are suppressed, see sysctl kernel.hung_task_warnings
antst commented 8 months ago

if I set 

(initramfs) echo 1 > /sys/module/zfs/parameters/zil_replay_disable
(initramfs) echo 1 > /sys/module/zfs/parameters/zfs_recover
(initramfs) echo 0 > /sys/module/zfs/parameters/spa_load_verify_data
(initramfs) echo 0 > /sys/module/zfs/parameters/spa_load_verify_metadata

then log is:

(initramfs) zpool import -N -o failmode=continue rpool 
(initramfs) [  538.725503] WARNING: zfs: removing nonexistent segment from range tree (offset=f001540e812000 size=2000)
[  538.739337] WARNING: zfs: removing nonexistent segment from range tree (offset=1083812200000 size=8f3000)
[  538.753221] WARNING: zfs: removing nonexistent segment from range tree (offset=4d0015800008000 size=7014000)
[  538.767354] WARNING: zfs: adding existent segment to range tree (offset=85f15513100000 size=284c000)
[  538.780809] WARNING: zfs: removing nonexistent segment from range tree (offset=31001de2000a000 size=3101000)
[  538.794986] WARNING: zfs: removing nonexistent segment from range tree (offset=1464008d0000 size=1000)
[  538.808593] VERIFY3(rs_get_end(rs, rt) >= end) failed (1460340334592 >= 40146828902903808)
[  538.821181] PANIC at range_tree.c:499:range_tree_remove_impl()
[  538.831301] Showing stack for process 2023
[  538.839641] CPU: 51 PID: 2023 Comm: z_wr_iss Tainted: P           OE      6.5.0-18-generic #18~22.04.1-Ubuntu
[  538.853912] Hardware name: To Be Filled By O.E.M. To Be Filled By O.E.M./TRX40D8-2N2T, BIOS P1.10 08/13/2020
[  538.868141] Call Trace:
[  538.874953]  <TASK>
[  538.881361]  dump_stack_lvl+0x48/0x70
[  538.889253]  dump_stack+0x10/0x20
[  538.896666]  spl_dumpstack+0x29/0x40 [spl]
[  538.904909]  spl_panic+0xfc/0x120 [spl]
[  538.912855]  ? zfs_btree_find+0x17b/0x270 [zfs]
[  538.921798]  range_tree_remove_impl+0x4b0/0x4f0 [zfs]
[  538.931187]  range_tree_remove+0x10/0x20 [zfs]
[  538.939640]  space_map_load_callback+0x27/0xb0 [zfs]
[  538.948506]  space_map_iterate+0x1bc/0x480 [zfs]
[  538.956907]  ? __pfx_space_map_load_callback+0x10/0x10 [zfs]
[  538.966267]  space_map_load_length+0x7c/0x100 [zfs]
[  538.974726]  metaslab_load_impl+0xcd/0x510 [zfs]
[  538.982822]  ? srso_return_thunk+0x5/0x10
[  538.990019]  ? ktime_get_raw_ts64+0x41/0xd0
[  538.997367]  ? srso_return_thunk+0x5/0x10
[  539.004556]  ? srso_return_thunk+0x5/0x10
[  539.011709]  ? gethrtime+0x30/0x60 [zfs]
[  539.018962]  ? srso_return_thunk+0x5/0x10
[  539.026130]  ? arc_all_memory+0xe/0x20 [zfs]
[  539.033720]  ? srso_return_thunk+0x5/0x10
[  539.040864]  metaslab_load+0x72/0xe0 [zfs]
[  539.048249]  metaslab_activate+0x50/0x110 [zfs]
[  539.056051]  ? srso_return_thunk+0x5/0x10
[  539.063107]  metaslab_group_alloc_normal+0x318/0x4f0 [zfs]
[  539.071888]  metaslab_group_alloc+0x25/0xb0 [zfs]
[  539.079823]  metaslab_alloc_dva+0x28f/0x590 [zfs]
[  539.087768]  metaslab_alloc+0xc8/0x200 [zfs]
[  539.095298]  zio_dva_allocate+0xb2/0x390 [zfs]
[  539.102985]  ? tsd_get+0x30/0x60 [spl]
[  539.109802]  ? srso_return_thunk+0x5/0x10
[  539.116872]  zio_execute+0x92/0xf0 [zfs]
[  539.123972]  taskq_thread+0x1f6/0x3c0 [spl]
[  539.131154]  ? __pfx_default_wake_function+0x10/0x10
[  539.139120]  ? __pfx_zio_execute+0x10/0x10 [zfs]
[  539.146815]  ? __pfx_taskq_thread+0x10/0x10 [spl]
[  539.154366]  kthread+0xf2/0x120
[  539.160332]  ? __pfx_kthread+0x10/0x10
[  539.166911]  ret_from_fork+0x47/0x70
[  539.173249]  ? __pfx_kthread+0x10/0x10
[  539.179691]  ret_from_fork_asm+0x1b/0x30
[  539.186547]  </TASK>
antst commented 8 months ago

I also tried zdb -AAA -b rpool it results in infinite log :)

But 

(initramfs) zdb -A -b rpool

Traversing all blocks to verify nothing leaked ...

loading concrete vdev 0, metaslab 85 of 116 ...entry_offset < sm->sm_start + sm->sm_size (0xf001540e812000 < 0x15800000000)
ASSERT at ../../module/zfs/space_map.c:173:space_map_iterate()entry_offset + entry_run <= sm->sm_start + sm->sm_size (0xf001540e814000 <= 0x15800000000)
ASSERT at ../../module/zfs/space_map.c:175:space_map_iterate()start <= UINT32_MAX (0xf000000e812 <= 0xffffffff)
ASSERT at ../../include/sys/range_tree.h:199:rs_set_start_raw()end <= UINT32_MAX (0xf000000e814 <= 0xffffffff)
ASSERT at ../../include/sys/range_tree.h:219:rs_set_end_raw()error: zfs: adding existent segment to range tree (offset=f001540e812000 size=2000)
Aborted
rincebrain commented 8 months ago

In general, I would suggest upgrading to 2.2.2 - not for this, I don't recall anything fixed since 2.2.0 that might be germane immediately, but there are a number of fixes that have gone in since then that are somewhat valuable.

failmode=continue doesn't do anything useful here, that's more for disks that vanish underneath, and only in a very specific case, it's pretty unsafe otherwise, IIRC.

13963 and #13483 seem germane. Most of the cases of this I see seem to be on systems where people aren't necessarily running ECC RAM, so it might have been something bitflipping exciting, and it's hard to know for certain. That said, I believe your motherboard can take ECC or non-ECC RAM, so it's probably worth asking if you have that, to eliminate one possible cause if you do.

The error message basically means it's trying to remove an element that's not there, which shouldn't happen, ever, really. Conceivably you could patch out the panic on that happening and make it just throw out the invalid remove request, but what you might get if you did that is pretty undefined, since by definition this should never happen, so it happening means something already went wrong and we don't know what it was.

You could also try importing at older txgs readonly and seeing if they behave less badly - specifying specific txgs with zdb would probably be faster to iterate on than trying the import outside of zdb and seeing if it panics, but if your userland is 2.1.x, zdb might get upset if you used any 2.2 features on the pool.

antst commented 8 months ago

failmode=continue doesn't do anything useful here, that's more for disks that vanish underneath, and only in a very specific case, it's pretty unsafe otherwise, IIRC.

I just experimented/ I made copies of logs on last attempts, and those were with failmode. And yes, I know it is for different case. Unfortunately it takes ages to reboot after every attempt, so I left as is :)

13963 and #13483 seem germane. Most of the cases of this I see seem to be on systems where people aren't necessarily running ECC RAM, so it might have been something bitflipping exciting, and it's hard to know for certain. That said, I believe your motherboard can take ECC or non-ECC RAM, so it's probably worth asking if you have that, to eliminate one possible cause if you do.

My memory is ECC, granted.

The error message basically means it's trying to remove an element that's not there, which shouldn't happen, ever, really. Conceivably you could patch out the panic on that happening and make it just throw out the invalid remove request, but what you might get if you did that is pretty undefined, since by definition this should never happen, so it happening means something already went wrong and we don't know what it was.

Patching, if that would let me make snapshot and copy to another pool - would be sufficient :)

You could also try importing at older txgs readonly and seeing if they behave less badly - specifying specific txgs with zdb would probably be faster to iterate on than trying the import outside of zdb and seeing if it panics, but if your userland is 2.1.x, zdb might get upset if you used any 2.2 features on the pool.

I can push userland to 2.2. Readonly is no help here, as it imports without any issues in RO. Should I just use -t option with zdb, or there is more to that?

rincebrain commented 8 months ago

If it imports readonly with 0 issues, that's useful enough to let you get data out, since you can send from read-only datasets without a snapshot (though you can't, like, resume or use a number of flags like -R to do it).

zdb -t [some txg] with an older txg from zdb -lu would be an experiment, once you're sure that it fails right now without a txg specified.

zdb also grew -B I think it is in 2.2, which lets you emit a send stream from zdb from just specifying a dataset, for a pool where it wouldn't import enough to do the dance I just suggested you do. (At least, I think that made it into 2.2, it's in git...)

antst commented 8 months ago

If it imports readonly with 0 issues, that's useful enough to let you get data out, since you can send from read-only datasets without a snapshot (though you can't, like, resume or use a number of flags like -R to do it).

...but would be hell of a work, as there are a lot datasets(snap, lxd, docker) and some of them clones of another.

zdb -t [some txg] with an older txg from zdb -lu would be an experiment, once you're sure that it fails right now without a txg specified.

zdb also grew -B I think it is in 2.2, which lets you emit a send stream from zdb from just specifying a dataset, for a pool where it wouldn't import enough to do the dance I just suggested you do. (At least, I think that made it into 2.2, it's in git...)

Thanks for the tips! :)

antst commented 8 months ago

hm. zdb with all txgs, belonging to present uberblocks, ends up with the same issue

(initramfs) zdb -e -b -t 91793915  rpool

Traversing all blocks to verify nothing leaked ...

loading concrete vdev 0, metaslab 85 of 116 ...entry_offset < sm->sm_start + sm->sm_size (0xf001540e812000 < 0x15800000000)
ASSERT at ../../module/zfs/space_map.c:173:space_map_iterate()Aborted
antst commented 8 months ago

assuming I am going to send datasets from read-only mounted pool or via zdb -B, then what should be my strategy to properly backup datasets with snapshots? for example:

rpool/lxd/images/97b9236df59497b28eebeb91eee7a2bd815e428613e49e478837ffa401d39da0
rpool/lxd/images/97b9236df59497b28eebeb91eee7a2bd815e428613e49e478837ffa401d39da0@readonly
rpool/lxd/images/dc0665d2cbf69531370268c87fc707bce37cbab22298d4399a8029f65751f8aa
rpool/lxd/images/dc0665d2cbf69531370268c87fc707bce37cbab22298d4399a8029f65751f8aa@readonly

and, even more difficult case, datasets which are clones.

antst commented 8 months ago

or, maybe, after all, there is a way to manually alter metaslab(s) and make pool good enough, to mount RW, make recursive snapshots and generate replication stream?

rincebrain commented 8 months ago

I'm not aware of anyone having written one.

You could do receive with -o checksum=[something stronger than fletcher4] and then use -o origin= to re-establish clone relationships afterward, and it'll apply nopwrite liberally to save space.

Note that the first part is not optional, or it will just take up the full amount of space and be marked as a clone.

antst commented 8 months ago

hm. I am working on the script which managed backing up of such read-only pool. But have a problem. Assuming I have multiple snapshots on the dataset, for example

NAME                                               CREATION                USED  REFER
rpool/ROOT/ubuntu_6ishm7/var/snap                  Thu Mar 11 22:57 2021  3.56G  1.78G
rpool/ROOT/ubuntu_6ishm7/var/snap@autozsys_67t44x  Mon Jun  5 16:18 2023    96K  1.79G
rpool/ROOT/ubuntu_6ishm7/var/snap@autozsys_ltgnni  Mon Jun  5 16:25 2023    96K  1.79G
rpool/ROOT/ubuntu_6ishm7/var/snap@autozsys_cys0gu  Wed Jun  7  4:30 2023   442M  1.79G
rpool/ROOT/ubuntu_6ishm7/var/snap@autozsys_mjohdz  Thu Jun  8  4:29 2023  5.44M  1.79G
rpool/ROOT/ubuntu_6ishm7/var/snap@autozsys_vliktr  Tue Jun 13  4:58 2023  5.54M  1.79G
rpool/ROOT/ubuntu_6ishm7/var/snap@autozsys_zm0e2o  Fri Jun 16  4:02 2023  5.19M  1.79G
rpool/ROOT/ubuntu_6ishm7/var/snap@autozsys_dnnhut  Sat Jun 17  4:19 2023  5.19M  1.79G
rpool/ROOT/ubuntu_6ishm7/var/snap@autozsys_7s62vg  Tue Jun 20  4:32 2023  5.35M  1.79G
rpool/ROOT/ubuntu_6ishm7/var/snap@autozsys_0wu8sf  Fri Jun 23  4:19 2023  5.36M  1.79G
rpool/ROOT/ubuntu_6ishm7/var/snap@autozsys_0ce0q2  Fri Jun 30  4:17 2023  6.13M  1.79G
rpool/ROOT/ubuntu_6ishm7/var/snap@autozsys_cvwdyu  Sat Feb 17 23:11 2024  7.40M  1.78G

I either can send all existing snapshots up to the last one or head of dataset without any snapshots. But can't find way to combine them. Sending snapshots and then sending head with -o origin=xxx does not help. Anything I am missing here?

rincebrain commented 8 months ago

What do you mean "does not help"?

I think setting the checksum to a nopwrite-capable one, setting origin=, then promoting the clone should do what you'd like here, if cumbersomely.

On Tue, Feb 20, 2024, 9:31 AM Anton Starikov @.***> wrote:

hm. I am working on the script which managed backing up of such read-only pool. But have a problem. Assuming I have multiple snapshots on the dataset, for example

NAME CREATION USED REFER rpool/ROOT/ubuntu_6ishm7/var/snap Thu Mar 11 22:57 2021 3.56G 1.78G @._67t44x Mon Jun 5 16:18 2023 96K 1.79G @._ltgnni Mon Jun 5 16:25 2023 96K 1.79G @._cys0gu Wed Jun 7 4:30 2023 442M 1.79G @._mjohdz Thu Jun 8 4:29 2023 5.44M 1.79G @._vliktr Tue Jun 13 4:58 2023 5.54M 1.79G @._zm0e2o Fri Jun 16 4:02 2023 5.19M 1.79G @._dnnhut Sat Jun 17 4:19 2023 5.19M 1.79G @._7s62vg Tue Jun 20 4:32 2023 5.35M 1.79G @._0wu8sf Fri Jun 23 4:19 2023 5.36M 1.79G @._0ce0q2 Fri Jun 30 4:17 2023 6.13M 1.79G @.***_cvwdyu Sat Feb 17 23:11 2024 7.40M 1.78G

I either can send all existing snapshots up to the last one or head of dataset without any snapshots. But can't find way to combine them. Sending snapshots and then sending head with -o origin=xxx does not help. Anything I am missing here?

— Reply to this email directly, view it on GitHub https://github.com/openzfs/zfs/issues/15915#issuecomment-1954339906, or unsubscribe https://github.com/notifications/unsubscribe-auth/AABUI7NCESWHTQESEGJZGYTYUSXUXAVCNFSM6AAAAABDQDZAICVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTSNJUGMZTSOJQGY . You are receiving this because you commented.Message ID: @.***>

antst commented 8 months ago

After all, looks like I managed to backup it all in more or less consistent way. Wasted whole day though )

bastikus commented 7 months ago

Hi! I have similar error. But my system doesn't freeze. Pools are available for reading and writing. Everything is working well, except for errors in logs.

Type    Version/Name
Distribution Name   Ubuntu
Distribution Version    22.04.4
Kernel Version  6.5.0-25-generic
Architecture    x86_64
OpenZFS Version 2.2.0 (kernel) 2.1.5 (utils)

I see error at startup, but OS is loading:

Begin: Importing ZFS root pool 'rpool' ... Begin: Importing pool 'rpool' using defaults ... [     4.006236] VERIFY3(rs_get_end(rs, rt) >= end) failed (8053108736 >= 8071139328)
PANIC at range_tree.c:499:range_tree_remove_impl()

image

When OS is running:

root@Bastik:~# zpool status -v
  pool: bpool
 state: ONLINE
config:

    NAME                                    STATE     READ WRITE CKSUM
    bpool                                   ONLINE       0     0     0
     74ae56db-aa4b-5f46-8fe4-a176a5d756dd  ONLINE       0     0     0

errors: No known data errors

  pool: rpool
 state: ONLINE
  scan: scrub repaired 0B in 00:03:23 with 0 errors on Fri Mar 15 13:05:31 2024
config:

    NAME                                    STATE     READ WRITE CKSUM
    rpool                                   ONLINE       0     0     0
     b2ac8a6e-2f4d-e240-85ce-3712884b3019  ONLINE       0     0     0

errors: No known data errors

root@Bastik:~# zdb 
bpool:
    version: 5000
    name: 'bpool'
    state: 0
    txg: 342657
    pool_guid: 14285551797236171980
    errata: 0
    hostid: 1372433909
    hostname: 'Bastik-UTech'
    com.delphix:has_per_vdev_zaps
    vdev_children: 1
    vdev_tree:
        type: 'root'
        id: 0
        guid: 14285551797236171980
        create_txg: 4
        children[0]:
            type: 'disk'
            id: 0
            guid: 10628172824458441428
            path: '/dev/disk/by-partuuid/74ae56db-aa4b-5f46-8fe4-a176a5d756dd'
            whole_disk: 0
            metaslab_array: 256
            metaslab_shift: 27
            ashift: 12
            asize: 2142765056
            is_log: 0
            create_txg: 4
            com.delphix:vdev_zap_leaf: 129
            com.delphix:vdev_zap_top: 130
    features_for_read:
        com.delphix:embedded_data
        com.delphix:hole_birth
rpool:
    version: 5000
    name: 'rpool'
    state: 0
    txg: 5752086
    pool_guid: 8373325186333015073
    errata: 0
    hostid: 1372433909
    hostname: 'Bastik-UTech'
    com.delphix:has_per_vdev_zaps
    vdev_children: 1
    vdev_tree:
        type: 'root'
        id: 0
        guid: 8373325186333015073
        create_txg: 4
        children[0]:
            type: 'disk'
            id: 0
            guid: 2971497501110945703
            path: '/dev/disk/by-partuuid/b2ac8a6e-2f4d-e240-85ce-3712884b3019'
            whole_disk: 0
            metaslab_array: 69
            metaslab_shift: 29
            ashift: 12
            asize: 156223406080
            is_log: 0
            DTL: 841
            create_txg: 4
            com.delphix:vdev_zap_leaf: 67
            com.delphix:vdev_zap_top: 68
    features_for_read:
        com.delphix:hole_birth
        com.delphix:embedded_data

journalctl

 kernel: INFO: task z_metaslab:597 blocked for more than 362 seconds.
 kernel:       Tainted: P           OE      6.5.0-25-generic #25~22.04.1-Ubuntu
 kernel: "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
 kernel: task:z_metaslab      state:D stack:0     pid:597   ppid:2      flags:0x00004000
 kernel: Call Trace:
 kernel:  <TASK>
 kernel:  __schedule+0x2cb/0x750
 kernel:  schedule+0x63/0x110
 kernel:  cv_wait_common+0x102/0x140 [spl]
 kernel:  ? __pfx_autoremove_wake_function+0x10/0x10
 kernel:  __cv_wait+0x15/0x30 [spl]
 kernel:  metaslab_load_wait+0x28/0x50 [zfs]
 kernel:  metaslab_load+0x17/0xe0 [zfs]
 kernel:  metaslab_preload+0x48/0xa0 [zfs]
 kernel:  taskq_thread+0x1f6/0x3c0 [spl]
 kernel:  ? __pfx_default_wake_function+0x10/0x10
 kernel:  ? __pfx_taskq_thread+0x10/0x10 [spl]
 kernel:  kthread+0xf2/0x120
 kernel:  ? __pfx_kthread+0x10/0x10
 kernel:  ret_from_fork+0x47/0x70
 kernel:  ? __pfx_kthread+0x10/0x10
 kernel:  ret_from_fork_asm+0x1b/0x30
 kernel:  </TASK>
rincebrain commented 7 months ago

You should probably file a bug with Ubuntu, since that's something that I believe is long-since fixed here.

Could be wrong, but since they shipped a version with a lot of known issues, I'd suggest you try to reproduce with 2.2.3 first.

(Of course, I suspect at the point where your pool is trashed now, it'll fail the same way on 2.2.3 on import, and not tell us anything about the underlying bug that made it write something broken in the first place, but I could be wrong.

bastikus commented 7 months ago

I restored my VM from snapshot, at a time when there was no error. And I noticed that the error appears after automatic update of Snap Apps (canonical-livepatch, snapstore, snapd etc...).

Then I restored my virtual machine again, before this error appeared. I immediately turned off automatic Snap Apps updates.

snap refresh --hold

And the error doesn't appear anymore. I assume that the error is in Snap Apps. Since all updates via APT package manager (zfs-initramfs, zfs-zed, linux-hwe, linux-headers etc...) are installed and work without problems.

bastikus commented 6 months ago

Problem with these Snap apps:

  1. snapd
  2. core20

I restored my VM from snapshot, at a time when there was no error. Deleted these apps and problem is gone. However, I had to completely abandon SNAP. And I also lost Canonical Livepatch :(