zpool import fail with :spa_log_summary_dirty_flushed_metaslab+0x58/0x70 [zfs]

openzfs / zfs

OpenZFS on Linux and FreeBSD

https://openzfs.github.io/openzfs-docs

Other

10.6k stars 1.75k forks source link

zpool import fail with :spa_log_summary_dirty_flushed_metaslab+0x58/0x70 [zfs] #15935

Closed afberendsen closed 7 months ago

afberendsen commented 8 months ago

System information

Type	Version/Name
Distribution Name	Fedora
Distribution Version	39
Kernel Version	6.4.13-200.fc38.x86_64
Architecture	x86_64
OpenZFS Version	zfs-2.2.3-1 zfs-kmod-2.2.3-1

Describe the problem you're observing

zpool import fail with spa_log_summary_dirty_flushed_metaslab+0x58/0x70 [zfs]

Describe how to reproduce the problem

$ lsblk --scsi
NAME HCTL       TYPE VENDOR   MODEL                 REV SERIAL                               TRAN
sda  0:0:0:0    disk TOSHIBA  TOSHIBA MG09ACA18TE  0105 41AC00000819                         usb
sdb  1:0:0:0    disk ST8000AS ST8000AS0002-1NA17Z  RT17 71AC00000819                         usb
sdc  2:0:0:0    disk TOSHIBA  TOSHIBA MG09ACA18TE  0104 51AC00000819                         usb
sdd  3:0:0:0    disk ST16000N ST16000NM001G-2KK103 SN02 81AC00000819                         usb
sde  4:0:0:0    disk ST16000N ST16000NM001G-2KK103 SN03 91AC00000819                         usb
sdf  5:0:0:0    disk ST16000N ST16000NM001G-2KK103 SB30 01AC00000819                         usb
sdg  6:0:0:0    disk ST16000N ST16000NM001G-2KK103 SN04 11AC00000819                         usb
sdh  7:0:0:0    disk TOSHIBA  TOSHIBA MG09ACA18TE  0104 21AC00000819                         usb
sdi  8:0:0:0    disk ST16000N ST16000NM001G-2KK103 SN02 31AC00000819                         usb
sdj  9:0:0:0    disk LIO-ORG  t16-A-disk0           4.0 b7a24920-56e4-44fa-879a-b4d3183242d0 iscsi
sdk  10:0:0:0   disk LIO-ORG  t15-A-disk1           4.0 2c0dbded-a792-47dc-9b34-5bb4915a945c iscsi
sdl  9:0:0:9    disk LIO-ORG  t16-B-disk4           4.0 de2d1422-70b1-4dd5-8185-623042b314ce iscsi
sdm  10:0:0:1   disk LIO-ORG  t15-A-disk2           4.0 be4f58cd-b41a-40b6-84d5-e128a6566d60 iscsi
sdn  9:0:0:8    disk LIO-ORG  t16-B-disk3           4.0 3ef443e7-eeaa-450f-8351-b66ad08a73c8 iscsi
sdo  10:0:0:2   disk LIO-ORG  t15-A-disk3           4.0 fa7bfaa5-62f3-4d8b-a4ab-a786e7e91245 iscsi
sdp  9:0:0:7    disk LIO-ORG  t16-B-disk2           4.0 1fd1db56-46e4-4332-9659-93269b9082dd iscsi
sdq  9:0:0:6    disk LIO-ORG  t16-B-disk1           4.0 bf954519-91ec-424f-aa36-899ef7a192e3 iscsi
sdr  10:0:0:3   disk LIO-ORG  t15-A-disk4           4.0 263f33ef-3dab-479c-9ae9-6138ffbbee53 iscsi
sds  9:0:0:5    disk LIO-ORG  t16-B-disk0           4.0 d844efb5-3e4d-479b-b8ff-47f11bfcc27a iscsi
sdt  10:0:0:4   disk LIO-ORG  t15-A-disk0           4.0 a5af33b8-5d79-47c4-8d06-7697a4038002 iscsi
sdu  9:0:0:4    disk LIO-ORG  t16-A-disk4           4.0 56f8255f-080d-4ece-9c4f-0dca05baf9fc iscsi
sdv  9:0:0:3    disk LIO-ORG  t16-A-disk3           4.0 a27bf30e-b5fc-443d-80d4-7ece58aa6d82 iscsi
sdw  9:0:0:2    disk LIO-ORG  t16-A-disk2           4.0 7f596910-a53a-45ae-931e-fa4ded37822e iscsi
sdx  9:0:0:1    disk LIO-ORG  t16-A-disk1           4.0 5ddcb318-26ca-439e-905c-398d769a80af iscsi
sdy  11:0:0:0   disk LIO-ORG  t14-A-disk0           4.0 ff587101-5785-4d09-beb5-e966f7f0b95c iscsi
sdz  11:0:0:4   disk LIO-ORG  t14-A-disk4           4.0 e0a57b83-0cf2-4fb8-959f-75277fc9d707 iscsi
sdaa 11:0:0:3   disk LIO-ORG  t14-A-disk3           4.0 8051fa8c-9bfe-463c-bcc9-678bcd229600 iscsi
sdab 11:0:0:2   disk LIO-ORG  t14-A-disk2           4.0 998806bf-f05f-429f-b7ba-1244036fdfef iscsi
sdac 11:0:0:1   disk LIO-ORG  t14-A-disk1           4.0 c1e8b208-de02-46ff-87db-6210c0f2f591 iscsi

$ sudo zpool import
[sudo] password for ********:
   pool: pool_videos
     id: 214206722705514979
  state: DEGRADED
status: One or more devices contains corrupted data.
 action: The pool can be imported despite missing or damaged devices.  The
        fault tolerance of the pool may be compromised if imported.
   see: https://openzfs.github.io/openzfs-docs/msg/ZFS-8000-4J
 config:

        pool_videos                              DEGRADED
          27e9e2a8-bdcd-624f-a401-c38ad60c3f27   ONLINE
          d0d55084-4c97-d443-9302-6acf18f61f33   ONLINE
          f886c743-b0d7-7449-b298-f01f3e4e5649   ONLINE
          indirect-3                             ONLINE
          c18e34c1-9dca-054a-9586-983e369404b1   ONLINE
          a703990a-eec4-8941-babe-e24592e3f4b9   ONLINE
          c3fee1c9-dc96-f54b-8aeb-482b9b53fd28   ONLINE
          /8fee2172-2286-9a4a-8f1e-0bb245299523  ONLINE
          e75375b0-1f63-ee48-999c-60cebb46b1c0   ONLINE
          eb99577c-3cfc-324c-983b-72f89ea913bf   ONLINE
          c8fd8101-c78b-7c42-9d28-2bebf6f36473   ONLINE
          c9d34e8b-fd5a-1e43-80e6-b53a1952e806   ONLINE
          73758373-96ff-1745-8ea0-daa8a84db7a9   ONLINE
          5c588b7c-3f09-c04b-baa6-4b55d5e19c6e   ONLINE
          10b4e398-69c0-6e4c-985b-d65d4801d916   ONLINE
          b2aba5ee-fa29-0c44-9197-7bac96e3fe5e   ONLINE
          9fc9d66e-0868-354c-b868-ec18b83aeae6   ONLINE
          e371b4b9-1e2f-694d-b5a3-79abcf5f5e12   ONLINE
          849d2ea4-a845-ec4a-8c79-95f42c17f480   ONLINE
          indirect-21                            ONLINE
          73d95a8a-d7ec-3e4b-b4df-82ebeeb4a646   ONLINE
          930ac0cf-83b9-8848-bcef-b3048a351c08   ONLINE
          84f08447-1712-444c-b040-710132d2fd14   ONLINE
          7f11c82a-b815-7e4b-9b6c-a89268f96e06   ONLINE
          02a7298a-527e-6e45-8413-2af22cc465c6   ONLINE
          d6386513-bdca-0b43-aee0-a864ba0c68c0   ONLINE
          25e685f1-8efb-6141-94af-20cd69b562e7   ONLINE
          57afd5ac-41ca-fb41-ba0a-b501ca26b6f9   ONLINE
          e9afd6cf-dcd0-cd45-811f-73b33ebcec7e   ONLINE
          fc31ef96-22e5-e946-953b-820ac4eb8026   ONLINE
          77c5a28a-c107-43fc-8f0b-bce8b7382565   ONLINE
        cache
          sdb2
        logs
          c0fd6232-8548-f546-b2cb-b0b29103cf9f   UNAVAIL
          b903fe71-2060-cb44-9484-c3bbfff48a8c   UNAVAIL

$ sudo zpool import -f -FXn -N pool_videos
[sudo] password for ********:

$ sudo zpool import -f -FX -N pool_videos
[sudo] password for ********:
cannot import 'pool_videos': one or more devices is currently unavailable

$ sudo zpool import -f -FX -N -m pool_videos
[sudo] password for *********:
Killed

After this point, any new requst with zpool or zfs will hang. Only option is to reset the host and try again.

Include any warning/errors/backtraces from the system logs

$ sudo dmesg 
[ 5824.178643] perf: interrupt took too long (2631 > 2500), lowering kernel.perf_event_max_sample_rate to 76000
[ 8092.534920] BUG: kernel NULL pointer dereference, address: 0000000000000020
[ 8092.534928] #PF: supervisor write access in kernel mode
[ 8092.534931] #PF: error_code(0x0002) - not-present page
[ 8092.534933] PGD 0 P4D 0
[ 8092.534936] Oops: 0002 [#1] PREEMPT SMP PTI
[ 8092.534939] CPU: 4 PID: 3496212 Comm: zpool Tainted: P S      W  OE      6.4.13-200.fc38.x86_64 #1
[ 8092.534942] Hardware name: Apple Inc. MacPro6,1/Mac-F60DEB81FF30ACF6, BIOS 430.140.2.0.0 04/18/2022
[ 8092.534945] RIP: 0010:spa_log_summary_dirty_flushed_metaslab+0x58/0x70 [zfs]
[ 8092.535221] Code: f7 d9 4c 29 c2 74 23 31 ff 48 3b 32 72 19 4a 8b 04 02 49 39 c1 74 13 48 89 d7 48 01 c8 74 0b 48 89 c2 48 3b 32 73 e7 48 89 fa <48> 83 42 20 01 c3 cc cc cc cc 31 d2 eb f2 66 2e 0f 1f 84 00 00 00
[ 8092.535226] RSP: 0018:ffffb169ec443ac0 EFLAGS: 00010297
[ 8092.535230] RAX: ffff9d0a78431570 RBX: ffffb169ec443b50 RCX: ffffffffffffffd0
[ 8092.535233] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[ 8092.535236] RBP: ffff9d028c858000 R08: 0000000000000030 R09: ffff9d0a6d524c70
[ 8092.535238] R10: 000000000003ae80 R11: ffff9d117ffd5000 R12: 0000000000000000
[ 8092.535241] R13: ffff9d0a6d524000 R14: 0000000000b20000 R15: 0000000006ff6833
[ 8092.535244] FS:  00007f5b3caf3900(0000) GS:ffff9d113f900000(0000) knlGS:0000000000000000
[ 8092.535248] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 8092.535251] CR2: 0000000000000020 CR3: 00000006ee8fe005 CR4: 00000000001706e0
[ 8092.535254] Call Trace:
[ 8092.535260]  <TASK>
[ 8092.535265]  ? __die+0x23/0x70
[ 8092.535272]  ? page_fault_oops+0x171/0x4e0
[ 8092.535281]  ? exc_page_fault+0x7f/0x180
[ 8092.535288]  ? asm_exc_page_fault+0x26/0x30
[ 8092.535294]  ? spa_log_summary_dirty_flushed_metaslab+0x58/0x70 [zfs]
[ 8092.535520]  spa_ld_log_sm_cb+0xc9/0x110 [zfs]
[ 8092.535745]  space_map_iterate+0x198/0x410 [zfs]
[ 8092.536023]  ? __pfx_spa_ld_log_sm_cb+0x10/0x10 [zfs]
[ 8092.536272]  ? dnode_rele_and_unlock+0x58/0xf0 [zfs]
[ 8092.536493]  spa_ld_log_spacemaps+0x5c4/0x760 [zfs]
[ 8092.536747]  spa_load+0xbd5/0x1890 [zfs]
[ 8092.536990]  ? __dprintf+0x12a/0x1b0 [zfs]
[ 8092.537190]  spa_load_best+0x54/0x2c0 [zfs]
[ 8092.537414]  spa_import+0x235/0x6d0 [zfs]
[ 8092.537637]  zfs_ioc_pool_import+0x15b/0x180 [zfs]
[ 8092.537848]  zfsdev_ioctl_common+0x869/0x9a0 [zfs]
[ 8092.538062]  ? kvmalloc_node+0x43/0xd0
[ 8092.538068]  zfsdev_ioctl+0x53/0xe0 [zfs]
[ 8092.538448]  __x64_sys_ioctl+0x94/0xd0
[ 8092.538458]  do_syscall_64+0x60/0x90
[ 8092.538466]  ? exc_page_fault+0x7f/0x180
[ 8092.538473]  entry_SYSCALL_64_after_hwframe+0x72/0xdc
[ 8092.538479] RIP: 0033:0x7f5b3d3ae19d
[ 8092.538511] Code: 04 25 28 00 00 00 48 89 45 c8 31 c0 48 8d 45 10 c7 45 b0 10 00 00 00 48 89 45 b8 48 8d 45 d0 48 89 45 c0 b8 10 00 00 00 0f 05 <89> c2 3d 00 f0 ff ff 77 1a 48 8b 45 c8 64 48 2b 04 25 28 00 00 00
[ 8092.538516] RSP: 002b:00007ffeafbcb880 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[ 8092.538522] RAX: ffffffffffffffda RBX: 00007f5b3ca51010 RCX: 00007f5b3d3ae19d
[ 8092.538525] RDX: 00007ffeafbcc240 RSI: 0000000000005a02 RDI: 0000000000000003
[ 8092.538528] RBP: 00007ffeafbcb8d0 R08: 00000000ffffffff R09: 0000000000000000
[ 8092.538531] R10: 0000000000000022 R11: 0000000000000246 R12: 0000557353597bd0
[ 8092.538534] R13: 00007ffeafbcc240 R14: 000055735359f1d8 R15: 0000000000000000
[ 8092.538539]  </TASK>
[ 8092.538542] Modules linked in: rfcomm xt_mark xt_connmark nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 xt_comment nft_compat wireguard curve25519_x86_64 libcurve25519_generic ip6_udp_tunnel udp_tunnel rpcrdma rdma_cm iw_cm ib_cm ib_core nf_tables nfnetlink iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi bonding tls qrtr bnep binfmt_misc btusb btrtl btbcm btintel btmtk bluetooth apple_mfi_fastcharge zfs(POE) spl(OE) intel_rapl_msr intel_rapl_common sb_edac x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass rapl wl(POE) joydev cfg80211 snd_hda_codec_cirrus snd_hda_codec_generic ledtrig_audio snd_hda_codec_hdmi snd_hda_intel snd_intel_dspcfg snd_intel_sdw_acpi at24 snd_hda_codec iTCO_wdt intel_pmc_bxt iTCO_vendor_support snd_seq snd_hda_core snd_seq_device intel_cstate snd_hwdep applesmc intel_uncore snd_pcm pcspkr snd_timer i2c_i801 rfkill snd lpc_ich mei_me i2c_smbus mei thunderbolt ioatdma soundcore dca nls_utf8 hfsplus apple_gmux nfsd auth_rpcgss nfs_acl lockd grace sunrpc i2c_dev loop amdgpu
[ 8092.538648]  iommu_v2 drm_buddy gpu_sched uas usb_storage radeon crct10dif_pclmul drm_ttm_helper crc32_pclmul ttm crc32c_intel polyval_clmulni video polyval_generic wmi nvme i2c_algo_bit drm_suballoc_helper ghash_clmulni_intel nvme_core drm_display_helper tg3 sha512_ssse3 cec nvme_common scsi_dh_rdac scsi_dh_emc scsi_dh_alua ip6_tables ip_tables dm_multipath fuse
[ 8092.538687] CR2: 0000000000000020
[ 8092.538730] ---[ end trace 0000000000000000 ]---
[ 8092.538736] RIP: 0010:spa_log_summary_dirty_flushed_metaslab+0x58/0x70 [zfs]
[ 8092.539229] Code: f7 d9 4c 29 c2 74 23 31 ff 48 3b 32 72 19 4a 8b 04 02 49 39 c1 74 13 48 89 d7 48 01 c8 74 0b 48 89 c2 48 3b 32 73 e7 48 89 fa <48> 83 42 20 01 c3 cc cc cc cc 31 d2 eb f2 66 2e 0f 1f 84 00 00 00
[ 8092.539234] RSP: 0018:ffffb169ec443ac0 EFLAGS: 00010297
[ 8092.539238] RAX: ffff9d0a78431570 RBX: ffffb169ec443b50 RCX: ffffffffffffffd0
[ 8092.539241] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[ 8092.539257] RBP: ffff9d028c858000 R08: 0000000000000030 R09: ffff9d0a6d524c70
[ 8092.539260] R10: 000000000003ae80 R11: ffff9d117ffd5000 R12: 0000000000000000
[ 8092.539263] R13: ffff9d0a6d524000 R14: 0000000000b20000 R15: 0000000006ff6833
[ 8092.539266] FS:  00007f5b3caf3900(0000) GS:ffff9d113f900000(0000) knlGS:0000000000000000
[ 8092.539270] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 8092.539273] CR2: 0000000000000020 CR3: 00000006ee8fe005 CR4: 00000000001706e0

afberendsen commented 8 months ago

Another try. This time the cache device is on. It faile don the dry-run. Any suggestions?

$ sudo zpool import
[sudo] password for ********:
   pool: pool_videos
     id: 214206722705514979
  state: ONLINE
status: Some supported features are not enabled on the pool.
        (Note that they may be intentionally disabled if the
        'compatibility' property is set.)
 action: The pool can be imported using its name or numeric identifier, though
        some features will not be available without an explicit 'zpool upgrade'.
 config:

        pool_videos                              ONLINE
          27e9e2a8-bdcd-624f-a401-c38ad60c3f27   ONLINE
          d0d55084-4c97-d443-9302-6acf18f61f33   ONLINE
          f886c743-b0d7-7449-b298-f01f3e4e5649   ONLINE
          indirect-3                             ONLINE
          c18e34c1-9dca-054a-9586-983e369404b1   ONLINE
          a703990a-eec4-8941-babe-e24592e3f4b9   ONLINE
          c3fee1c9-dc96-f54b-8aeb-482b9b53fd28   ONLINE
          /8fee2172-2286-9a4a-8f1e-0bb245299523  ONLINE
          e75375b0-1f63-ee48-999c-60cebb46b1c0   ONLINE
          eb99577c-3cfc-324c-983b-72f89ea913bf   ONLINE
          c8fd8101-c78b-7c42-9d28-2bebf6f36473   ONLINE
          c9d34e8b-fd5a-1e43-80e6-b53a1952e806   ONLINE
          73758373-96ff-1745-8ea0-daa8a84db7a9   ONLINE
          5c588b7c-3f09-c04b-baa6-4b55d5e19c6e   ONLINE
          10b4e398-69c0-6e4c-985b-d65d4801d916   ONLINE
          b2aba5ee-fa29-0c44-9197-7bac96e3fe5e   ONLINE
          9fc9d66e-0868-354c-b868-ec18b83aeae6   ONLINE
          e371b4b9-1e2f-694d-b5a3-79abcf5f5e12   ONLINE
          849d2ea4-a845-ec4a-8c79-95f42c17f480   ONLINE
          indirect-21                            ONLINE
          73d95a8a-d7ec-3e4b-b4df-82ebeeb4a646   ONLINE
          930ac0cf-83b9-8848-bcef-b3048a351c08   ONLINE
          84f08447-1712-444c-b040-710132d2fd14   ONLINE
          7f11c82a-b815-7e4b-9b6c-a89268f96e06   ONLINE
          02a7298a-527e-6e45-8413-2af22cc465c6   ONLINE
          d6386513-bdca-0b43-aee0-a864ba0c68c0   ONLINE
          25e685f1-8efb-6141-94af-20cd69b562e7   ONLINE
          57afd5ac-41ca-fb41-ba0a-b501ca26b6f9   ONLINE
          e9afd6cf-dcd0-cd45-811f-73b33ebcec7e   ONLINE
          fc31ef96-22e5-e946-953b-820ac4eb8026   ONLINE
          77c5a28a-c107-43fc-8f0b-bce8b7382565   ONLINE
        cache
          sdb2
        logs
          c0fd6232-8548-f546-b2cb-b0b29103cf9f   ONLINE
          b903fe71-2060-cb44-9484-c3bbfff48a8c   ONLINE
$ sudo zpool import -m -f -FXn -N pool_videos
Killed
$

$ sudo dmesg
.
.
.
[  600.138079] BUG: kernel NULL pointer dereference, address: 0000000000000020
[  600.138093] #PF: supervisor write access in kernel mode
[  600.138097] #PF: error_code(0x0002) - not-present page
[  600.138100] PGD 0 P4D 0
[  600.138106] Oops: 0002 [#1] PREEMPT SMP PTI
[  600.138111] CPU: 5 PID: 105290 Comm: zpool Tainted: P S      W  OE      6.4.13-200.fc38.x86_64 #1
[  600.138116] Hardware name: Apple Inc. MacPro6,1/Mac-F60DEB81FF30ACF6, BIOS 430.140.2.0.0 04/18/2022
[  600.138119] RIP: 0010:spa_log_summary_dirty_flushed_metaslab+0x58/0x70 [zfs]
[  600.138536] Code: f7 d9 4c 29 c2 74 23 31 ff 48 3b 32 72 19 4a 8b 04 02 49 39 c1 74 13 48 89 d7 48 01 c8 74 0b 48 89 c2 48 3b 32 73 e7 48 89 fa <48> 83 42 20 01 c3 cc cc cc cc 31 d2 eb f2 66 2e 0f 1f 84 00 00 00
[  600.138540] RSP: 0018:ffff98347171bad8 EFLAGS: 00010297
[  600.138545] RAX: ffff8a7a4adefe30 RBX: ffff98347171bb68 RCX: ffffffffffffffd0
[  600.138548] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[  600.138550] RBP: ffff8a73fcd0a000 R08: 0000000000000030 R09: ffff8a7a39544c70
[  600.138553] R10: 000000000003ae80 R11: ffff8a80bffd5000 R12: 0000000000000000
[  600.138556] R13: ffff8a7a39544000 R14: 0000000000b20000 R15: 0000000006ff6833
[  600.138559] FS:  00007f0e23714900(0000) GS:ffff8a807f940000(0000) knlGS:0000000000000000
[  600.138563] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  600.138566] CR2: 0000000000000020 CR3: 00000009d2d32004 CR4: 00000000001706e0
[  600.138569] Call Trace:
[  600.138574]  <TASK>
[  600.138578]  ? __die+0x23/0x70
[  600.138586]  ? page_fault_oops+0x171/0x4e0
[  600.138596]  ? exc_page_fault+0x7f/0x180
[  600.138604]  ? asm_exc_page_fault+0x26/0x30
[  600.138612]  ? spa_log_summary_dirty_flushed_metaslab+0x58/0x70 [zfs]
[  600.138986]  spa_ld_log_sm_cb+0xc9/0x110 [zfs]
[  600.139359]  space_map_iterate+0x198/0x410 [zfs]
[  600.139723]  ? __pfx_spa_ld_log_sm_cb+0x10/0x10 [zfs]
[  600.140093]  ? dnode_rele_and_unlock+0x58/0xf0 [zfs]
[  600.140461]  spa_ld_log_spacemaps+0x5c4/0x760 [zfs]
[  600.140831]  spa_load+0xbd5/0x1890 [zfs]
[  600.141203]  ? __dprintf+0x12a/0x1b0 [zfs]
[  600.141536]  spa_load_best+0x54/0x2c0 [zfs]
[  600.141908]  spa_import+0x235/0x6d0 [zfs]
[  600.142280]  zfs_ioc_pool_import+0x15b/0x180 [zfs]
[  600.142632]  zfsdev_ioctl_common+0x869/0x9a0 [zfs]
[  600.142985]  ? kvmalloc_node+0x43/0xd0
[  600.142994]  zfsdev_ioctl+0x53/0xe0 [zfs]
[  600.143285]  __x64_sys_ioctl+0x94/0xd0
[  600.143291]  do_syscall_64+0x60/0x90
[  600.143296]  ? exc_page_fault+0x7f/0x180
[  600.143300]  entry_SYSCALL_64_after_hwframe+0x72/0xdc
[  600.143303] RIP: 0033:0x7f0e23fd119d
[  600.143327] Code: 04 25 28 00 00 00 48 89 45 c8 31 c0 48 8d 45 10 c7 45 b0 10 00 00 00 48 89 45 b8 48 8d 45 d0 48 89 45 c0 b8 10 00 00 00 0f 05 <89> c2 3d 00 f0 ff ff 77 1a 48 8b 45 c8 64 48 2b 04 25 28 00 00 00
[  600.143329] RSP: 002b:00007ffff935abc0 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  600.143332] RAX: ffffffffffffffda RBX: 00007f0e23672010 RCX: 00007f0e23fd119d
[  600.143334] RDX: 00007ffff935b580 RSI: 0000000000005a02 RDI: 0000000000000003
[  600.143336] RBP: 00007ffff935ac10 R08: 00000000ffffffff R09: 0000000000000000
[  600.143337] R10: 0000000000000022 R11: 0000000000000246 R12: 00005622b9568bd0
[  600.143339] R13: 00007ffff935b580 R14: 00005622b9571388 R15: 0000000000000000
[  600.143342]  </TASK>
[  600.143343] Modules linked in: rfcomm xt_mark xt_connmark nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 xt_comment nft_compat wireguard curve25519_x86_64 libcurve25519_generic ip6_udp_tunnel udp_tunnel rpcrdma rdma_cm iw_cm ib_cm ib_core nf_tables nfnetlink iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi bonding tls qrtr bnep binfmt_misc btusb btrtl btbcm btintel btmtk bluetooth apple_mfi_fastcharge zfs(POE) spl(OE) intel_rapl_msr intel_rapl_common sb_edac x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel kvm irqbypass wl(POE) rapl joydev snd_hda_codec_cirrus snd_hda_codec_generic ledtrig_audio snd_hda_codec_hdmi at24 snd_hda_intel snd_intel_dspcfg snd_intel_sdw_acpi snd_hda_codec iTCO_wdt intel_pmc_bxt iTCO_vendor_support snd_hda_core intel_cstate snd_hwdep applesmc snd_seq cfg80211 snd_seq_device intel_uncore snd_pcm pcspkr i2c_i801 snd_timer mei_me rfkill lpc_ich i2c_smbus snd mei thunderbolt soundcore ioatdma dca nls_utf8 hfsplus apple_gmux nfsd auth_rpcgss nfs_acl lockd grace sunrpc i2c_dev loop amdgpu
[  600.143409]  iommu_v2 drm_buddy gpu_sched radeon uas usb_storage drm_ttm_helper ttm crct10dif_pclmul crc32_pclmul crc32c_intel video polyval_clmulni polyval_generic wmi nvme i2c_algo_bit drm_suballoc_helper ghash_clmulni_intel nvme_core drm_display_helper sha512_ssse3 tg3 nvme_common cec scsi_dh_rdac scsi_dh_emc scsi_dh_alua ip6_tables ip_tables dm_multipath fuse
[  600.143434] CR2: 0000000000000020
[  600.143451] ---[ end trace 0000000000000000 ]---
[  600.143454] RIP: 0010:spa_log_summary_dirty_flushed_metaslab+0x58/0x70 [zfs]
[  600.143687] Code: f7 d9 4c 29 c2 74 23 31 ff 48 3b 32 72 19 4a 8b 04 02 49 39 c1 74 13 48 89 d7 48 01 c8 74 0b 48 89 c2 48 3b 32 73 e7 48 89 fa <48> 83 42 20 01 c3 cc cc cc cc 31 d2 eb f2 66 2e 0f 1f 84 00 00 00
[  600.143689] RSP: 0018:ffff98347171bad8 EFLAGS: 00010297
[  600.143692] RAX: ffff8a7a4adefe30 RBX: ffff98347171bb68 RCX: ffffffffffffffd0
[  600.143694] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[  600.143695] RBP: ffff8a73fcd0a000 R08: 0000000000000030 R09: ffff8a7a39544c70
[  600.143697] R10: 000000000003ae80 R11: ffff8a80bffd5000 R12: 0000000000000000
[  600.143698] R13: ffff8a7a39544000 R14: 0000000000b20000 R15: 0000000006ff6833
[  600.143700] FS:  00007f0e23714900(0000) GS:ffff8a807f940000(0000) knlGS:0000000000000000
[  600.143702] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  600.143704] CR2: 0000000000000020 CR3: 00000009d2d32004 CR4: 00000000001706e0
$

afberendsen commented 8 months ago

Under my limit knowldege, eveyrhting I tried failed and I cannot import/use the pool anymore.

Also, after a failed zpool import, the entire ZFS stack becomes unresponsive. I need to restart the host to be able to try any other zpool command.

afberendsen commented 8 months ago

Installed latest version following https://github.com/openzfs/zfs/issues/15483

Log device turned off

$ sudo zpool import
pool: pool_videos
 id: 214206722705514979
state: DEGRADED
status: One or more devices contains corrupted data.
action: The pool can be imported despite missing or damaged devices.  The
    fault tolerance of the pool may be compromised if imported.
see: https://openzfs.github.io/openzfs-docs/msg/ZFS-8000-4J
config:

    pool_videos                              DEGRADED
      27e9e2a8-bdcd-624f-a401-c38ad60c3f27   ONLINE
      d0d55084-4c97-d443-9302-6acf18f61f33   ONLINE
      f886c743-b0d7-7449-b298-f01f3e4e5649   ONLINE
      indirect-3                             ONLINE
      c18e34c1-9dca-054a-9586-983e369404b1   ONLINE
      a703990a-eec4-8941-babe-e24592e3f4b9   ONLINE
      c3fee1c9-dc96-f54b-8aeb-482b9b53fd28   ONLINE
      /8fee2172-2286-9a4a-8f1e-0bb245299523  ONLINE
      e75375b0-1f63-ee48-999c-60cebb46b1c0   ONLINE
      eb99577c-3cfc-324c-983b-72f89ea913bf   ONLINE
      c8fd8101-c78b-7c42-9d28-2bebf6f36473   ONLINE
      c9d34e8b-fd5a-1e43-80e6-b53a1952e806   ONLINE
      73758373-96ff-1745-8ea0-daa8a84db7a9   ONLINE
      5c588b7c-3f09-c04b-baa6-4b55d5e19c6e   ONLINE
      10b4e398-69c0-6e4c-985b-d65d4801d916   ONLINE
      b2aba5ee-fa29-0c44-9197-7bac96e3fe5e   ONLINE
      9fc9d66e-0868-354c-b868-ec18b83aeae6   ONLINE
      e371b4b9-1e2f-694d-b5a3-79abcf5f5e12   ONLINE
      849d2ea4-a845-ec4a-8c79-95f42c17f480   ONLINE
      indirect-21                            ONLINE
      73d95a8a-d7ec-3e4b-b4df-82ebeeb4a646   ONLINE
      930ac0cf-83b9-8848-bcef-b3048a351c08   ONLINE
      84f08447-1712-444c-b040-710132d2fd14   ONLINE
      7f11c82a-b815-7e4b-9b6c-a89268f96e06   ONLINE
      02a7298a-527e-6e45-8413-2af22cc465c6   ONLINE
      d6386513-bdca-0b43-aee0-a864ba0c68c0   ONLINE
      25e685f1-8efb-6141-94af-20cd69b562e7   ONLINE
      57afd5ac-41ca-fb41-ba0a-b501ca26b6f9   ONLINE
      e9afd6cf-dcd0-cd45-811f-73b33ebcec7e   ONLINE
      fc31ef96-22e5-e946-953b-820ac4eb8026   ONLINE
      77c5a28a-c107-43fc-8f0b-bce8b7382565   ONLINE
    cache
      sdb2
    logs
      c0fd6232-8548-f546-b2cb-b0b29103cf9f   UNAVAIL
      b903fe71-2060-cb44-9484-c3bbfff48a8c   UNAVAIL
$
$ lsblk /dev/sdb
NAME   MAJ:MIN RM  SIZE RO TYPE MOUNTPOINTS
sdb      8:16   0  7.3T  0 disk
└─sdb1   8:17   0  7.3T  0 part

Reboot server

new try

$ zfs version
zfs-2.2.99-365_g8f2f6cd2a
zfs-kmod-2.2.99-365_g8f2f6cd2a
$ sudo zpool import -m -f -N pool_videos
[sudo] password for ********:
Killed

=================

Reboot server

New try

$ zpool version
zfs-2.2.99-365_g8f2f6cd2a
zfs-kmod-2.2.99-365_g8f2f6cd2a
$
$ sudo zpool import -m -f -FXn -N pool_videos
[sudo] password for ********:
Killed
$

[  474.336770] BUG: kernel NULL pointer dereference, address: 0000000000000020
[  474.336786] #PF: supervisor write access in kernel mode
[  474.336791] #PF: error_code(0x0002) - not-present page
[  474.336796] PGD 0 P4D 0
[  474.336803] Oops: 0002 [#1] PREEMPT SMP PTI
[  474.336810] CPU: 11 PID: 28677 Comm: zpool Tainted: P S      W  OE      6.4.13-200.fc38.x86_64 #1
[  474.336817] Hardware name: Apple Inc. MacPro6,1/Mac-F60DEB81FF30ACF6, BIOS 430.140.2.0.0 04/18/2022
[  474.336822] RIP: 0010:spa_log_summary_dirty_flushed_metaslab+0x58/0x70 [zfs]
[  474.337441] Code: f7 d9 4c 29 c2 74 23 31 ff 48 3b 32 72 19 4a 8b 04 02 49 39 c1 74 13 48 89 d7 48 01 c8 74 0b 48 89 c2 48 3b 32 73 e7 48 89 fa <48> 83 42 20 01 c3 cc cc cc cc 31 d2 eb f2 66 2e 0f 1f 84 00 00 00
[  474.337446] RSP: 0018:ffffb7d0a23efa60 EFLAGS: 00010297
[  474.337451] RAX: ffff9f94b554cd30 RBX: ffffb7d0a23efaf0 RCX: ffffffffffffffd0
[  474.337455] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[  474.337459] RBP: ffff9f95f5c7c000 R08: 0000000000000030 R09: ffff9f9395e64c60
[  474.337462] R10: 000000000003ae80 R11: ffff9fa1bffd5000 R12: 0000000000000000
[  474.337466] R13: ffff9f9395e64000 R14: 0000000000b20000 R15: 0000000006ff6833
[  474.337470] FS:  00007fc0c44f6140(0000) GS:ffff9fa17fac0000(0000) knlGS:0000000000000000
[  474.337475] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  474.337478] CR2: 0000000000000020 CR3: 00000002415ee005 CR4: 00000000001706e0
[  474.337483] Call Trace:
[  474.337490]  <TASK>
[  474.337497]  ? __die+0x23/0x70
[  474.337507]  ? page_fault_oops+0x171/0x4e0
[  474.337519]  ? exc_page_fault+0x7f/0x180
[  474.337529]  ? asm_exc_page_fault+0x26/0x30
[  474.337539]  ? spa_log_summary_dirty_flushed_metaslab+0x58/0x70 [zfs]
[  474.338009]  spa_ld_log_sm_cb+0xc9/0x110 [zfs]
[  474.338428]  space_map_iterate+0x198/0x410 [zfs]
[  474.339127]  ? __pfx_spa_ld_log_sm_cb+0x10/0x10 [zfs]
[  474.339580]  spa_ld_log_spacemaps+0x5ea/0x790 [zfs]
[  474.339997]  spa_load+0xc4d/0x1a10 [zfs]
[  474.340478]  ? __dprintf+0x13a/0x1c0 [zfs]
[  474.340972]  spa_load_best+0x54/0x2c0 [zfs]
[  474.341579]  spa_import+0x235/0x6d0 [zfs]
[  474.342150]  zfs_ioc_pool_import+0x15b/0x180 [zfs]
[  474.342580]  zfsdev_ioctl_common+0x869/0x9a0 [zfs]
[  474.343052]  ? kvmalloc_node+0x43/0xd0
[  474.343067]  zfsdev_ioctl+0x53/0xe0 [zfs]
[  474.343523]  __x64_sys_ioctl+0x94/0xd0
[  474.343534]  do_syscall_64+0x60/0x90
[  474.343542]  ? count_memcg_events.constprop.0+0x1a/0x30
[  474.343550]  ? handle_mm_fault+0x9e/0x350
[  474.343556]  ? do_user_addr_fault+0x23a/0x600
[  474.343562]  ? exc_page_fault+0x7f/0x180
[  474.343570]  entry_SYSCALL_64_after_hwframe+0x72/0xdc
[  474.343577] RIP: 0033:0x7fc0c473619d
[  474.343613] Code: 04 25 28 00 00 00 48 89 45 c8 31 c0 48 8d 45 10 c7 45 b0 10 00 00 00 48 89 45 b8 48 8d 45 d0 48 89 45 c0 b8 10 00 00 00 0f 05 <89> c2 3d 00 f0 ff ff 77 1a 48 8b 45 c8 64 48 2b 04 25 28 00 00 00
[  474.343618] RSP: 002b:00007ffc6dd2c930 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
[  474.343624] RAX: ffffffffffffffda RBX: 00007fc0b6761010 RCX: 00007fc0c473619d
[  474.343628] RDX: 00007ffc6dd2d2f0 RSI: 0000000000005a02 RDI: 0000000000000003
[  474.343631] RBP: 00007ffc6dd2c980 R08: 00000000ffffffff R09: 0000000000000000
[  474.343634] R10: 0000000000000022 R11: 0000000000000246 R12: 000055f3a64b0bd0
[  474.343637] R13: 00007ffc6dd2d2f0 R14: 000055f3a650cbc8 R15: 0000000000000000
[  474.343643]  </TASK>
[  474.343645] Modules linked in: rfcomm xt_mark xt_connmark nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 xt_comment nft_compat wireguard curve25519_x86_64 libcurve25519_generic ip6_udp_tunnel udp_tunnel rpcrdma rdma_cm iw_cm ib_cm ib_core nf_tables iscsi_tcp libiscsi_tcp nfnetlink libiscsi scsi_transport_iscsi bonding tls qrtr bnep binfmt_misc btusb btrtl btbcm btintel btmtk bluetooth apple_mfi_fastcharge zfs(POE) spl(OE) intel_rapl_msr intel_rapl_common sb_edac x86_pkg_temp_thermal intel_powerclamp coretemp kvm_intel joydev kvm snd_hda_codec_cirrus snd_hda_codec_generic irqbypass snd_hda_codec_hdmi ledtrig_audio snd_hda_intel snd_intel_dspcfg iTCO_wdt rapl snd_intel_sdw_acpi intel_pmc_bxt wl(POE) intel_cstate at24 iTCO_vendor_support applesmc snd_hda_codec snd_hda_core intel_uncore cfg80211 pcspkr snd_hwdep i2c_i801 snd_seq snd_seq_device i2c_smbus lpc_ich snd_pcm rfkill snd_timer mei_me snd nls_utf8 soundcore mei ioatdma dca thunderbolt hfsplus apple_gmux nfsd auth_rpcgss nfs_acl lockd grace sunrpc i2c_dev loop amdgpu
[  474.343755]  iommu_v2 drm_buddy gpu_sched radeon drm_ttm_helper crct10dif_pclmul ttm crc32_pclmul crc32c_intel video polyval_clmulni nvme polyval_generic wmi i2c_algo_bit drm_suballoc_helper nvme_core ghash_clmulni_intel drm_display_helper sha512_ssse3 tg3 cec nvme_common uas usb_storage scsi_dh_rdac scsi_dh_emc scsi_dh_alua ip6_tables ip_tables dm_multipath fuse
[  474.343797] CR2: 0000000000000020
[  474.343826] ---[ end trace 0000000000000000 ]---
[  474.343831] RIP: 0010:spa_log_summary_dirty_flushed_metaslab+0x58/0x70 [zfs]
[  474.344409] Code: f7 d9 4c 29 c2 74 23 31 ff 48 3b 32 72 19 4a 8b 04 02 49 39 c1 74 13 48 89 d7 48 01 c8 74 0b 48 89 c2 48 3b 32 73 e7 48 89 fa <48> 83 42 20 01 c3 cc cc cc cc 31 d2 eb f2 66 2e 0f 1f 84 00 00 00
[  474.344413] RSP: 0018:ffffb7d0a23efa60 EFLAGS: 00010297
[  474.344416] RAX: ffff9f94b554cd30 RBX: ffffb7d0a23efaf0 RCX: ffffffffffffffd0
[  474.344419] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000000
[  474.344421] RBP: ffff9f95f5c7c000 R08: 0000000000000030 R09: ffff9f9395e64c60
[  474.344423] R10: 000000000003ae80 R11: ffff9fa1bffd5000 R12: 0000000000000000
[  474.344425] R13: ffff9f9395e64000 R14: 0000000000b20000 R15: 0000000006ff6833
[  474.344428] FS:  00007fc0c44f6140(0000) GS:ffff9fa17fac0000(0000) knlGS:0000000000000000
[  474.344430] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[  474.344433] CR2: 0000000000000020 CR3: 00000002415ee005 CR4: 00000000001706e0
$

Now I need to try to find a way to ignore the cache device from the import....

afberendsen commented 8 months ago

/dev/sdb2 is not the cache device. I added the caceh device (SSD) with the WWN but it was changed to SD device name. After a reboot, the SD name changed. I did not noticed that the cache device was using the SD name instead of the WWN name, as per every other device.,

$ lsblk /dev/sdb
NAME   MAJ:MIN RM  SIZE RO TYPE MOUNTPOINTS
sdb      8:16   0  7.3T  0 disk
└─sdb1   8:17   0  7.3T  0 part
$ sudo touch /dev/sdb2
[sudo] password for ********:
$ ls -la /dev/sdb*
brw-rw---- 1 root disk 8, 16 Feb 28 14:41 /dev/sdb
brw-rw---- 1 root disk 8, 17 Feb 28 14:41 /dev/sdb1
-rw-r--r-- 1 root root     0 Feb 28 14:53 /dev/sdb2
$ sudo zpool import -m -f -N pool_videos
Killed
$

afberendsen commented 8 months ago

Any ideas? I still could not find a way to recover the pool....

afberendsen commented 8 months ago

After few days leaving all devices tunrned off, another try today.....

$ sudo zpool import -m -N -F -X
   pool: pool_videos
     id: 214206722705514979
  state: ONLINE
status: One or more devices contains corrupted data.
 action: The pool can be imported using its name or numeric identifier.
   see: https://openzfs.github.io/openzfs-docs/msg/ZFS-8000-4J
 config:

        pool_videos                              ONLINE
          27e9e2a8-bdcd-624f-a401-c38ad60c3f27   ONLINE
          d0d55084-4c97-d443-9302-6acf18f61f33   ONLINE
          f886c743-b0d7-7449-b298-f01f3e4e5649   ONLINE
          indirect-3                             ONLINE
          c18e34c1-9dca-054a-9586-983e369404b1   ONLINE
          a703990a-eec4-8941-babe-e24592e3f4b9   ONLINE
          c3fee1c9-dc96-f54b-8aeb-482b9b53fd28   ONLINE
          /8fee2172-2286-9a4a-8f1e-0bb245299523  ONLINE
          e75375b0-1f63-ee48-999c-60cebb46b1c0   ONLINE
          eb99577c-3cfc-324c-983b-72f89ea913bf   ONLINE
          c8fd8101-c78b-7c42-9d28-2bebf6f36473   ONLINE
          c9d34e8b-fd5a-1e43-80e6-b53a1952e806   ONLINE
          73758373-96ff-1745-8ea0-daa8a84db7a9   ONLINE
          5c588b7c-3f09-c04b-baa6-4b55d5e19c6e   ONLINE
          10b4e398-69c0-6e4c-985b-d65d4801d916   ONLINE
          b2aba5ee-fa29-0c44-9197-7bac96e3fe5e   ONLINE
          9fc9d66e-0868-354c-b868-ec18b83aeae6   ONLINE
          e371b4b9-1e2f-694d-b5a3-79abcf5f5e12   ONLINE
          849d2ea4-a845-ec4a-8c79-95f42c17f480   ONLINE
          indirect-21                            ONLINE
          73d95a8a-d7ec-3e4b-b4df-82ebeeb4a646   ONLINE
          930ac0cf-83b9-8848-bcef-b3048a351c08   ONLINE
          84f08447-1712-444c-b040-710132d2fd14   ONLINE
          7f11c82a-b815-7e4b-9b6c-a89268f96e06   ONLINE
          02a7298a-527e-6e45-8413-2af22cc465c6   ONLINE
          d6386513-bdca-0b43-aee0-a864ba0c68c0   ONLINE
          25e685f1-8efb-6141-94af-20cd69b562e7   ONLINE
          57afd5ac-41ca-fb41-ba0a-b501ca26b6f9   ONLINE
          e9afd6cf-dcd0-cd45-811f-73b33ebcec7e   ONLINE
          fc31ef96-22e5-e946-953b-820ac4eb8026   ONLINE
          77c5a28a-c107-43fc-8f0b-bce8b7382565   ONLINE
        cache
          sdad2
        logs
          c0fd6232-8548-f546-b2cb-b0b29103cf9f   ONLINE
          b903fe71-2060-cb44-9484-c3bbfff48a8c   ONLINE

$ df -h
Filesystem                      Size  Used Avail Use% Mounted on
devtmpfs                        4.0M     0  4.0M   0% /dev
tmpfs                            32G  206M   32G   1% /dev/shm
tmpfs                            13G  2.9M   13G   1% /run
/dev/mapper/fedora_fedora-root   69G   43G   23G  65% /
/dev/nvme0n1p3                  974M  345M  562M  38% /boot
/dev/nvme0n1p2                  600M   22M  579M   4% /boot/efi
/dev/mapper/fedora_fedora-home  846G  100G  703G  13% /home
tmpfs                            32G   17M   32G   1% /tmp
tmpfs                           6.3G  196K  6.3G   1% /run/user/1000

$ sudo zpool list
no pools available

This time the cache device was turned on after all devices were on. It now points to sdad2, which is better. The import executed without crashing this time....Still the pool is not imported....

afberendsen commented 8 months ago

....it crashed again

$ sudo zpool import -m -N -F -X 214206722705514979
Killed
$

After this crash, zppol and zfs hang when called . The only viable solution is to reset the host...Clearly there is something very wrong if one of the control data but I cannot find what and how to fix it. The available tools are not enough.

afberendsen commented 8 months ago

I just realised something. One of the devcies shows with a '/': /8fee2172-2286-9a4a-8f1e-0bb245299523 ONLINE However, from the host is:

$ ls -lF /dev/disk/by-partuuid/|grep -i 0bb245299523
lrwxrwxrwx 1 root root 11 Mar  6 12:31 8fee2172-2286-9a4a-8f1e-0bb245299523 -> ../../sdac1

Not sure how to interpret the '/'....

afberendsen commented 8 months ago

I am not sure it this is relevant. vdev_tree id#8 is missing

$ for x in /dev/sd*1; do sudo zdb -l $x|grep ' id:'; done|sort -t: -k2 -n
        id: 0
        id: 1
        id: 2
        id: 4
        id: 5
        id: 6
        id: 7
        id: 9
        id: 10
        id: 11
        id: 12
        id: 13
        id: 14
        id: 15
        id: 16
        id: 17
        id: 18
        id: 19
        id: 20
        id: 22
        id: 23
        id: 24
        id: 25
        id: 26
        id: 27
        id: 28
        id: 29
        id: 30
        id: 31
        id: 32

vdev_children is 33. device 3 and 21 where removed in fact. Thy shows as indirect-. howber, device 8 ws not removed.

afberendsen commented 8 months ago

dev labels and L2ARC header attached

$ for x in /dev/sd*1; do sudo zdb -lll $x -uuuuuuuuuuuuuuuu; done | grep checkpoint_txg | uniq
        checkpoint_txg = 0

$ for x in /dev/sd*1; do sudo zdb -lll $x -uuuuuuuuuuuuuuuu; done | grep ' txg'|sort -t: -k2 -n|uniq
    txg: 117398503

device_conf.txt

afberendsen commented 8 months ago

Some invalid uberblocks in the cache device. Not sure if this is a problem or somwething acceptable


$ sudo zdb -lll /dev/sdb2 -uuuuuuuuuuuuuuuuuuuu|head -100
------------------------------------
LABEL 0
------------------------------------
    version: 5000
    state: 4
    guid: 4415563566865631289
    labels = 0 1 2 3

ZFS Label NVList Config Stats:
  124 bytes used, 114524 bytes free (using  0.1%)

   integers:    3    104 bytes (83.87%)
    strings:    0      0 bytes ( 0.00%)
   booleans:    0      0 bytes ( 0.00%)
    nvlists:    1     20 bytes (16.13%)

    Uberblock[0]
        magic = 0000000000bab10c
        version = 5000
        txg = 0
        guid_sum = 7066779138072329375
        timestamp = 1675607943 UTC = Sun Feb  5 15:39:03 2023
        mmp_magic = 00000000a11cea11
        mmp_delay = 0
        mmp_valid = 0
        rootbp = DVA[0]=<11:f348bfb9000:1000> DVA[1]=<10:40637487000:1000> DVA[2]=<12:5d7769000:1000> [L0 DMU objset] fletcher4 uncompressed unencrypted LE contiguous unique triple size=1000L/1000P birth=237203L/237203P fill=10786 cksum=00000004c6b72f50:000012770364e07f:0023bbb2190c8c5f:2e2720b268c9ede7
        checkpoint_txg = 0
        raidz_reflow state=0 off=0
        labels = 0 1 2 3
    Uberblock[1] invalid
    Uberblock[2] invalid
    Uberblock[3] invalid
    Uberblock[4] invalid
    Uberblock[5] invalid
    Uberblock[6] invalid
    Uberblock[7] invalid
    Uberblock[8] invalid
    Uberblock[9] invalid
    Uberblock[10] invalid
    Uberblock[11] invalid
    Uberblock[12] invalid
    Uberblock[13] invalid
    Uberblock[14] invalid
    Uberblock[15] invalid
    Uberblock[16] invalid
    Uberblock[17] invalid
    Uberblock[18] invalid
    Uberblock[19] invalid
    Uberblock[20] invalid
    Uberblock[21] invalid
    Uberblock[22] invalid
    Uberblock[23] invalid
    Uberblock[24] invalid
    Uberblock[25] invalid
    Uberblock[26] invalid
    Uberblock[27] invalid
    Uberblock[28] invalid
    Uberblock[29] invalid
    Uberblock[30] invalid
    Uberblock[31] invalid
    Uberblock[32] invalid
    Uberblock[33] invalid
    Uberblock[34] invalid
    Uberblock[35] invalid
    Uberblock[36] invalid
    Uberblock[37] invalid
    Uberblock[38] invalid
    Uberblock[39] invalid
    Uberblock[40] invalid
    Uberblock[41] invalid
    Uberblock[42] invalid
    Uberblock[43] invalid
    Uberblock[44] invalid
    Uberblock[45] invalid
    Uberblock[46] invalid
    Uberblock[47] invalid
    Uberblock[48] invalid
    Uberblock[49] invalid
    Uberblock[50] invalid
    Uberblock[51] invalid
    Uberblock[52] invalid
    Uberblock[53] invalid
    Uberblock[54] invalid
    Uberblock[55] invalid
    Uberblock[56] invalid
    Uberblock[57] invalid
    Uberblock[58] invalid
    Uberblock[59] invalid
    Uberblock[60] invalid
    Uberblock[61] invalid
    Uberblock[62] invalid
    Uberblock[63] invalid
    Uberblock[64] invalid
    Uberblock[65] invalid
    Uberblock[66] invalid
    Uberblock[67] invalid
    Uberblock[68] invalid
    Uberblock[69] invalid
``

afberendsen commented 8 months ago

Cache contents seems to be ok

$ sudo zdb -lll /dev/sdb2 -uuuuuuuuuuuuuuuuuuuu
.
.
.
log_blk_count:   26724 with valid cksum
     0 with invalid cksum
log_blk_asize:   422096896

afberendsen commented 8 months ago

Checking source for module/zfs/zfs_ioctl.c, it seems that there is no protection for zc as null pointer. Maybe this is causing the kernel trap?

static int
zfs_ioc_pool_import(zfs_cmd_t *zc)
{
  nvlist_t *config, *props = NULL;
  uint64_t guid;
  int error;

  if ((error = get_nvlist(zc->zc_nvlist_conf, zc->zc_nvlist_conf_size,
      zc->zc_iflags, &config)) != 0)
    return (error);

afberendsen commented 8 months ago

zfs-import.strace.gz dmesg show the trap as

[Mar 6 14:25] BUG: kernel NULL pointer dereference, address: 0000000000000020
[  +0.000012] #PF: supervisor write access in kernel mode
[  +0.000003] #PF: error_code(0x0002) - not-present page
[  +0.000004] PGD 0 P4D 0

Running the zpool import with strace, I got this snip

.
.
.
14:20:13 openat(AT_FDCWD, "/sys/devices/platform/host11/session2/target11:0:0/11:0:0:4/block/sdt/sdt1/uevent", O_RDONLY|O_NOCTTY|O_CLOEXEC) = 5
14:20:13 newfstatat(5, "", {st_mode=S_IFREG|0644, st_size=4096, ...}, AT_EMPTY_PATH) = 0
14:20:13 read(5, "MAJOR=65\nMINOR=49\nDEVNAME=sdt1\nD"..., 4104) = 68
14:20:13 close(5)                       = 0
14:20:13 getrandom("\xe3\x6c\xd7\x90\x4e\x73\xb0\xd0\x41\x6e\x6b\xcc\x33\x1f\x95\xe8", 16, GRND_INSECURE) = 16
14:20:13 readlinkat(AT_FDCWD, "/sys/devices/platform/host11/session2/target11:0:0/11:0:0:4/block/sdt/sdt1/subsystem", "../../../../../../../../../class"..., 4096) = 38
14:20:13 openat(AT_FDCWD, "/run/udev/data/b65:49", O_RDONLY|O_CLOEXEC) = 5
14:20:13 newfstatat(5, "", {st_mode=S_IFREG|0644, st_size=2452, ...}, AT_EMPTY_PATH) = 0
14:20:13 newfstatat(5, "", {st_mode=S_IFREG|0644, st_size=2452, ...}, AT_EMPTY_PATH) = 0
14:20:13 read(5, "S:disk/by-id/wwn-0x6001405a5af33"..., 4096) = 2452
14:20:13 read(5, "", 4096)              = 0
14:20:13 close(5)                       = 0
.
.
.
14:23:01 readlink("/dev", 0x7ffc62c81050, 1023) = -1 EINVAL (Invalid argument)
14:23:01 readlink("/dev/sdb2", 0x7ffc62c81050, 1023) = -1 EINVAL (Invalid argument)
14:23:01 access("/sys/bus/block/devices/sdb2", F_OK) = -1 ENOENT (No such file or directory)
14:23:01 access("/sys/class/block/sdb2", F_OK) = 0
14:23:01 openat(AT_FDCWD, "/", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = 5
14:23:01 statx(5, ".", AT_STATX_SYNC_AS_STAT, STATX_TYPE|STATX_INO|STATX_MNT_ID, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=STATX_ATTR_MOUNT_ROOT, stx_mode=S_IFDIR|0555, stx_size=4096, ...}) = 0
14:23:01 statx(5, "..", AT_STATX_SYNC_AS_STAT, STATX_TYPE|STATX_INO|STATX_MNT_ID, {stx_mask=STATX_BASIC_STATS|STATX_MNT_ID, stx_attributes=STATX_ATTR_MOUNT_ROOT, stx_mode=S_IFDIR|0555, stx_size=4096, ...}) = 0
14:23:01 openat(5, "/", O_RDONLY|O_CLOEXEC|O_PATH|O_DIRECTORY) = 6
14:23:01 newfstatat(6, "", {st_mode=S_IFDIR|0555, st_size=4096, ...}, AT_EMPTY_PATH) = 0
.
.
.
14:23:01 getrandom("\x42\xac\x99\xb6\xd4\x6f\xe4\x5a\x1f\x8c\xc9\x81\x84\x41\x3d\xf9", 16, GRND_INSECURE) = 16
14:23:01 readlinkat(AT_FDCWD, "/sys/devices/pci0000:00/0000:00:01.0/0000:10:00.0/0000:11:01.0/0000:12:00.0/usb3/3-4/3-4.1/3-4.1.1/3-4.1.1:1.0/host1/target1:0:0/1:0:0:0/block/sdb/sdb2/subsystem", "../../../../../../../../../../.."..., 4096) = 62
14:23:01 openat(AT_FDCWD, "/run/udev/data/b8:18", O_RDONLY|O_CLOEXEC) = 5
14:23:01 newfstatat(5, "", {st_mode=S_IFREG|0644, st_size=2854, ...}, AT_EMPTY_PATH) = 0
14:23:01 newfstatat(5, "", {st_mode=S_IFREG|0644, st_size=2854, ...}, AT_EMPTY_PATH) = 0
14:23:01 read(5, "S:disk/by-id/ata-Fanxiang_S101_2"..., 4096) = 2854
14:23:01 read(5, "", 4096)              = 0
14:23:01 close(5)                       = 0
14:23:01 getrandom("\x1d\xaa\xf3\x23\x83\xdd\x40\x91\xa5\x79\x7f\x59\xe3\x85\x31\x26", 16, GRND_INSECURE) = 16
14:23:01 getrandom("\xb5\xec\x89\x04\x57\xd4\xd3\xdb\xf3\xac\x2c\x21\x17\xaa\xb0\x0f", 16, GRND_INSECURE) = 16
14:23:01 getrandom("\x68\x13\x71\x14\x77\x8d\xe5\xe8\x81\x05\xf5\x4d\x5f\xb4\xa9\xf3", 16, GRND_INSECURE) = 16
14:23:01 getrandom("\x1b\xab\x7e\x8c\xbd\x16\x98\x7f\xce\x7a\xbc\xf4\xd8\x89\x46\x86", 16, GRND_INSECURE) = 16
14:23:01 getrandom("\x78\xe8\xfc\x35\xab\xaa\xea\x54\x1e\x7a\x78\xfa\xa0\xa2\x2d\x4e", 16, GRND_INSECURE) = 16
14:23:01 getrandom("\xc5\x71\x1b\x4b\xda\x0e\x22\x95\xc0\x92\xff\xf2\x89\xbc\xa4\x6f", 16, GRND_INSECURE) = 16
14:23:01 getrandom("\x55\x9a\x87\x58\x88\x27\xef\x11\x22\xb0\x83\x3a\x2a\x7e\x61\x78", 16, GRND_INSECURE) = 16
14:23:01 getrandom("\xe8\x06\x80\xf0\x12\x3a\xdf\xbd\x21\x71\x13\x51\x75\x20\xa6\x4a", 16, GRND_INSECURE) = 16
14:23:01 getrandom("\x3b\xfc\xce\xc3\x31\xc3\x12\xde\x47\x79\xd9\xfc\x4e\xc8\x3d\x33", 16, GRND_INSECURE) = 16
14:23:01 brk(0x55f114bda000)            = 0x55f114bda000
14:23:01 brk(0x55f114bfb000)            = 0x55f114bfb000
14:23:01 brk(0x55f114c1c000)            = 0x55f114c1c000
14:23:01 openat(AT_FDCWD, "/proc/sys/kernel/spl/hostid", O_RDONLY|O_CLOEXEC) = 5
14:23:01 newfstatat(5, "", {st_mode=S_IFREG|0644, st_size=0, ...}, AT_EMPTY_PATH) = 0
14:23:01 read(5, "0\n", 1024)           = 2
14:23:01 close(5)                       = 0
14:23:01 openat(AT_FDCWD, "/etc/hostid", O_RDONLY|O_CLOEXEC) = -1 ENOENT (No such file or directory)
14:23:01 openat(AT_FDCWD, "/usr/share/locale/locale.alias", O_RDONLY|O_CLOEXEC) = 5
14:23:01 newfstatat(5, "", {st_mode=S_IFREG|0644, st_size=2998, ...}, AT_EMPTY_PATH) = 0
14:23:01 read(5, "# Locale name alias data base.\n#"..., 4096) = 2998
14:23:01 read(5, "", 4096)              = 0
14:23:01 close(5)                       = 0
14:23:01 openat(AT_FDCWD, "/usr/share/locale/en_GB.UTF-8/LC_MESSAGES/zfs-linux-user.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
14:23:01 openat(AT_FDCWD, "/usr/share/locale/en_GB.utf8/LC_MESSAGES/zfs-linux-user.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
14:23:01 openat(AT_FDCWD, "/usr/share/locale/en_GB/LC_MESSAGES/zfs-linux-user.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
14:23:01 openat(AT_FDCWD, "/usr/share/locale/en.UTF-8/LC_MESSAGES/zfs-linux-user.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
14:23:01 openat(AT_FDCWD, "/usr/share/locale/en.utf8/LC_MESSAGES/zfs-linux-user.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
14:23:01 openat(AT_FDCWD, "/usr/share/locale/en/LC_MESSAGES/zfs-linux-user.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
14:23:01 brk(0x55f114c6b000)            = 0x55f114c6b000
14:23:02 mmap(NULL, 651264, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f6cdb561000
14:23:02 ioctl(3, ZFS_IOC_POOL_IMPORT <unfinished ...>) = ?
14:25:55 +++ killed by SIGKILL +++

afberendsen commented 8 months ago

One more run. It seems that the zpool import fails on the last device of the pool.

$ sudo ./bc1.sh
[sudo] password for ********:
27e9e2a8-bdcd-624f-a401-c38ad60c3f27 : sdm1    :   18000205840384 bytes :  32 :
.
.
.
77c5a28a-c107-43fc-8f0b-bce8b7382565 : sdaa1   :   18000205840384 bytes :  32 :
c0fd6232-8548-f546-b2cb-b0b29103cf9f : sdb3    :      68719476736 bytes :   1 :
b903fe71-2060-cb44-9484-c3bbfff48a8c : sdb1    :      68719476736 bytes : 107 :

The output from strace shows that the last device accessed is sdaa:

16878 1709734738.778122 (+     0.000053) openat(AT_FDCWD, "/sys/devices/platform/host12/session3/target12:0:0/12:0:0:4/block/sdaa/sdaa1/uevent", O_RDONLY|O_NOCTTY|O_CLOEXEC) = 5 <0.000028>
16878 1709734738.778192 (+     0.000070) newfstatat(5, "", {st_mode=S_IFREG|0644, st_size=4096, ...}, AT_EMPTY_PATH) = 0 <0.000013>
16878 1709734738.778254 (+     0.000062) read(5, "MAJOR=65\nMINOR=161\nDEVNAME=sdaa1"..., 4104) = 70 <0.000021>
16878 1709734738.778319 (+     0.000063) close(5) = 0 <0.000013>
16878 1709734738.778378 (+     0.000059) getrandom("\xca\x14\xa4\x1d\x60\x44\xe1\xac\xd2\x0d\x02\x58\xc7\x6d\x8e\xb8", 16, GRND_INSECURE) = 16 <0.000012>
16878 1709734738.778450 (+     0.000072) readlinkat(AT_FDCWD, "/sys/devices/platform/host12/session3/target12:0:0/12:0:0:4/block/sdaa/sdaa1/subsystem", "../../../../../../../../../class"..., 4096) = 38 <0.000021>
16878 1709734738.778528 (+     0.000078) openat(AT_FDCWD, "/run/udev/data/b65:161", O_RDONLY|O_CLOEXEC) = 5 <0.000018>
16878 1709734738.778596 (+     0.000067) newfstatat(5, "", {st_mode=S_IFREG|0644, st_size=2453, ...}, AT_EMPTY_PATH) = 0 <0.000014>
16878 1709734738.778659 (+     0.000063) newfstatat(5, "", {st_mode=S_IFREG|0644, st_size=2453, ...}, AT_EMPTY_PATH) = 0 <0.000011>

afberendsen commented 8 months ago

Turning off the cache device and ezecuting a new import

$ sudo strace -o zfs-import.strace --follow-forks -tttt -r -T -C zpool import -m -N -fF 214206722705514979
[sudo] password for **********:
Killed

$ grep 'access("/sys/class/block/' zfs-import.strace
275710 1709737031.806900 (+     0.000018) access("/sys/class/block/sda1", F_OK <unfinished ...>
275733 1709737031.818963 (+     0.000020) access("/sys/class/block/sdd1", F_OK <unfinished ...>
.
.
.
273252 1709737032.761226 (+     0.000080) access("/sys/class/block/sdh1", F_OK) = 0 <0.000037>
273252 1709737032.776224 (+     0.000080) access("/sys/class/block/sdu1", F_OK) = 0 <0.000034>
$

Checking the devices, the last device in the pool is sdu.

$ sudo ./bc1.sh
[sudo] password for *********:
27e9e2a8-bdcd-624f-a401-c38ad60c3f27 : sdk1    :   18000205840384 bytes :  32 :
c18e34c1-9dca-054a-9586-983e369404b1 : sdad1   :   12000136527872 bytes :  32 :
a703990a-eec4-8941-babe-e24592e3f4b9 : sdab1   :   16000898564096 bytes :  32 :
c3fee1c9-dc96-f54b-8aeb-482b9b53fd28 : sdaa1   :   18000205840384 bytes :  32 :
8fee2172-2286-9a4a-8f1e-0bb245299523 : sds1    :   16000898564096 bytes :  32 :
e75375b0-1f63-ee48-999c-60cebb46b1c0 : sdz1    :   18000205840384 bytes :  32 :
eb99577c-3cfc-324c-983b-72f89ea913bf : sdq1    :   18000205840384 bytes :  32 :
c8fd8101-c78b-7c42-9d28-2bebf6f36473 : sdx1    :   18000205840384 bytes :  32 :
c9d34e8b-fd5a-1e43-80e6-b53a1952e806 : sdo1    :   12000136527872 bytes :  32 :
73758373-96ff-1745-8ea0-daa8a84db7a9 : sdy1    :   16000898564096 bytes :  32 :
5c588b7c-3f09-c04b-baa6-4b55d5e19c6e : sdr1    :   12000136527872 bytes :  32 :
10b4e398-69c0-6e4c-985b-d65d4801d916 : sdv1    :   16000898564096 bytes :  32 :
b2aba5ee-fa29-0c44-9197-7bac96e3fe5e : sdt1    :   12000136527872 bytes :  32 :
9fc9d66e-0868-354c-b868-ec18b83aeae6 : sdg1    :   16000898564096 bytes :  32 :
e371b4b9-1e2f-694d-b5a3-79abcf5f5e12 : sdd1    :    8001561821184 bytes :  32 :
849d2ea4-a845-ec4a-8c79-95f42c17f480 : sde1    :   16000898564096 bytes :  32 :
73d95a8a-d7ec-3e4b-b4df-82ebeeb4a646 : sda1    :   18000205840384 bytes :  32 :
930ac0cf-83b9-8848-bcef-b3048a351c08 : sdc1    :   18000205840384 bytes :  32 :
84f08447-1712-444c-b040-710132d2fd14 : sdf1    :   16000898564096 bytes :  32 :
7f11c82a-b815-7e4b-9b6c-a89268f96e06 : sdi1    :   18000205840384 bytes :  32 :
02a7298a-527e-6e45-8413-2af22cc465c6 : sdj1    :   16000898564096 bytes :  32 :
d6386513-bdca-0b43-aee0-a864ba0c68c0 : sdm1    :   12000136527872 bytes :  32 :
25e685f1-8efb-6141-94af-20cd69b562e7 : sdp1    :   12000136527872 bytes :  32 :
57afd5ac-41ca-fb41-ba0a-b501ca26b6f9 : sdn1    :    4000751550464 bytes :  32 : [removing]
e9afd6cf-dcd0-cd45-811f-73b33ebcec7e : sdl1    :   12000136527872 bytes :  32 :
fc31ef96-22e5-e946-953b-820ac4eb8026 : sdh1    :   16000898564096 bytes :  32 :
77c5a28a-c107-43fc-8f0b-bce8b7382565 : sdu1    :   18000205840384 bytes :  32 :
fdisk: cannot open /dev/: Is a directory
c0fd6232-8548-f546-b2cb-b0b29103cf9f :         :                        :   0 :
fdisk: cannot open /dev/: Is a directory
b903fe71-2060-cb44-9484-c3bbfff48a8c :         :                        :   0 :

This time the cache and log devices are off. Calling zpol list it nevers returns...

futex(0x7f01e3e6872c, FUTEX_WAKE_PRIVATE, 2147483647) = 0
openat(AT_FDCWD, "/dev/zfs", O_RDWR|O_EXCL|O_CLOEXEC) = 3
openat(AT_FDCWD, "/dev/zfs", O_RDWR|O_CLOEXEC) = 4
openat(AT_FDCWD, "/sys/module/zfs/properties.dataset", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0755, st_size=0, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x55ae57280680 /* 100 entries */, 32768) = 3312
getdents64(5, 0x55ae57280680 /* 0 entries */, 32768) = 0
close(5)                                = 0
openat(AT_FDCWD, "/sys/module/zfs/properties.pool", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0755, st_size=0, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x55ae57280680 /* 38 entries */, 32768) = 1192
getdents64(5, 0x55ae57280680 /* 0 entries */, 32768) = 0
close(5)                                = 0
openat(AT_FDCWD, "/sys/module/zfs/features.pool", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0755, st_size=0, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x55ae57280680 /* 43 entries */, 32768) = 2040
getdents64(5, 0x55ae57280680 /* 0 entries */, 32768) = 0
close(5)                                = 0
openat(AT_FDCWD, "/sys/module/zfs/properties.vdev", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 5
newfstatat(5, "", {st_mode=S_IFDIR|0755, st_size=0, ...}, AT_EMPTY_PATH) = 0
getdents64(5, 0x55ae57280680 /* 51 entries */, 32768) = 1584
getdents64(5, 0x55ae57280680 /* 0 entries */, 32768) = 0
close(5)                                = 0
mmap(NULL, 266240, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7f01e3aee000
ioctl(3, ZFS_IOC_POOL_CONFIGS

Found similar (not the same) problem at https://github.com/openzfs/zfs/issues/10223 and https://github.com/openzfs/zfs/issues/12980.

I will try to import R/O now. (after system restart, of course).

afberendsen commented 8 months ago

~$ sudo strace -o zfs-import.strace --follow-forks -tttt -r -T -C zpool import -m -N -f -o readonly=on 214206722705514979
[sudo] password for *************:

It worked

$ sudo zpool list
[sudo] password for ****************:
NAME          SIZE  ALLOC   FREE  CKPOINT  EXPANDSZ   FRAG    CAP  DEDUP    HEALTH  ALTROOT
pool_videos   398T      0   398T        -         -     0%     0%  1.00x  DEGRADED  -
$

Now, try the next step from the link of previous post

$ sudo su -
# echo 1 > /sys/module/zfs/parameters/zfs_recover
# zdb -e -bcsvL pool_videos

Traversing all blocks to verify checksums ...

34.0G completed (  26MB/s) estimated time remaining: 4094hr 10min 48sec        ^C

This is going to take half year. Better to run a scrub in background after the pool is back to life

# zdb -e -bsvL pool_videos

Traversing all blocks ...

4.23T completed (14352MB/s) estimated time remaining: 7hr 28min 04sec

Still goin gto take a lot of time....I will update this thread when is finished

Update 1: 22:00 ... still 4 hours to go Update 2: 07:35 ... still 3 hours to go Update 3: 12:00 .. (5174MB/s) estimated time remaining: 3hr 20min 16sec Update 4: 15:30 .. (4412MB/s) estimated time remaining: 3hr 27min 53sec Update 5: 20:40 .. (3655MB/s) estimated time remaining: 3hr 30min 19sec Update 6: 08:20 .. (2746MB/s) estimated time remaining: 1hr 55min 42sec Update 7: 12:40 .. (2531MB/s) estimated time remaining: 1hr 04min 38sec Update 8: 16:40 .. (2341MB/s) estimated time remaining: 0hr 31min 40sec Update 9: 18:00 .. DONE Took about 40 hours to process the pool. Clearly the code for "time left" requires a review...

        bp count:           37461747822
        ganged count:        7176021065
        bp logical:      371214323670528      avg:   9909
        bp physical:     359734390696448      avg:   9602     compression:   1.03
        bp allocated:    406204656513024      avg:  10843     compression:   0.91
        bp deduped:                   0    ref>1:      0   deduplication:   1.00
        bp cloned:                    0    count:      0
        Normal class:    409247172419584     used: 93.60%
        Embedded log class              0     used:  0.00%

        additional, non-pointer bps of type 0:   58613882
        Dittoed blocks on same vdev: 8759374
        Dittoed blocks in same metaslab: 42
        indirect vdev id 3 has 766227869 segments (731M in memory)
        indirect vdev id 21 has 71158814 segments (67.9M in memory)
        indirect vdev id 29 has 608159 segments (594K in memory)

Blocks  LSIZE   PSIZE   ASIZE     avg    comp   %Total  Type
     -      -       -       -       -       -        -  unallocated
     2    32K      8K     24K     12K    4.00     0.00  object directory
   431  3.82M    303K   5.03M   11.9K   12.91     0.00  object array
     3    48K     12K     36K     12K    4.00     0.00  packed nvlist
     -      -       -       -       -       -        -  packed nvlist size
     -      -       -       -       -       -        -  bpobj
     -      -       -       -       -       -        -  bpobj header
     -      -       -       -       -       -        -  SPA space map header
 87.5K  8.54G   4.58G   13.8G    161K    1.87     0.00  SPA space map
     -      -       -       -       -       -        -  ZIL intent log
 3.39M  54.6G   14.5G   30.1G   8.88K    3.76     0.01  DMU dnode
     8    32K     32K     68K   8.50K    1.00     0.00  DMU objset
     -      -       -       -       -       -        -  DSL directory
    10  5.50K      1K     12K   1.20K    5.50     0.00  DSL directory child map
     -      -       -       -       -       -        -  DSL dataset snap map
    17   226K   42.5K    168K   9.88K    5.31     0.00  DSL props
     -      -       -       -       -       -        -  DSL dataset
     -      -       -       -       -       -        -  ZFS znode
     -      -       -       -       -       -        -  ZFS V0 ACL
 34.9G   337T    327T    369T   10.6K    1.03    99.98  ZFS plain file
 15.2M  60.1G   7.76G   27.3G   1.80K    7.74     0.01  ZFS directory
     7  3.50K   3.50K     56K      8K    1.00     0.00  ZFS master node
    24   474K     76K    152K   6.33K    6.24     0.00  ZFS delete queue
     -      -       -       -       -       -        -  zvol object
     -      -       -       -       -       -        -  zvol prop
     -      -       -       -       -       -        -  other uint8[]
     -      -       -       -       -       -        -  other uint64[]
     -      -       -       -       -       -        -  other ZAP
     -      -       -       -       -       -        -  persistent error log
     2   256K     20K     60K     30K   12.80     0.00  SPA history
     -      -       -       -       -       -        -  SPA history offsets
     -      -       -       -       -       -        -  Pool properties
     -      -       -       -       -       -        -  DSL permissions
     -      -       -       -       -       -        -  ZFS ACL
     -      -       -       -       -       -        -  ZFS SYSACL
     -      -       -       -       -       -        -  FUID table
     -      -       -       -       -       -        -  FUID table size
     1     1K      1K     12K     12K    1.00     0.00  DSL dataset next clones
     -      -       -       -       -       -        -  scan work queue
    21  10.5K      1K     16K     780   10.50     0.00  ZFS user/group/project used
     -      -       -       -       -       -        -  ZFS user/group/project quota
     -      -       -       -       -       -        -  snapshot refcount tags
     -      -       -       -       -       -        -  DDT ZAP algorithm
     -      -       -       -       -       -        -  DDT statistics
 3.55K  1.77M   1.77M   28.4M      8K    1.00     0.00  System attributes
     -      -       -       -       -       -        -  SA master node
     7  10.5K   10.5K     56K      8K    1.00     0.00  SA attr registration
    14   224K     56K    112K      8K    4.00     0.00  SA attr layouts
     -      -       -       -       -       -        -  scan translations
     -      -       -       -       -       -        -  deduplicated block
     -      -       -       -       -       -        -  DSL deadlist map
     -      -       -       -       -       -        -  DSL deadlist map hdr
     1     1K      1K     12K     12K    1.00     0.00  DSL dir clones
     -      -       -       -       -       -        -  bpobj subobj
     -      -       -       -       -       -        -  deferred free
     -      -       -       -       -       -        -  dedup ditto
  158K  19.7G   6.53G   19.6G    127K    3.02     0.01  other
 34.9G   338T    327T    369T   10.6K    1.03   100.00  Total
 96.8M  9.89T   1.66T   3.42T   36.2K    5.98     0.93  Metadata Total

Block Size Histogram

  block   psize                lsize                asize
   size   Count   Size   Cum.  Count   Size   Cum.  Count   Size   Cum.
    512:  10.1M  5.03G  5.03G  5.85M  2.92G  2.92G      0      0      0
     1K:  23.3M  29.1G  34.1G  8.27M  9.93G  12.9G      0      0      0
     2K:  73.2M   208G   242G  8.66M  23.5G  36.3G      0      0      0
     4K:  13.8G  55.5T  55.7T  13.5G  53.9T  53.9T  13.9G  55.5T  55.5T
     8K:  20.4G   163T   219T  20.8G   166T   220T  17.2G   137T   193T
    16K:  39.7M   655G   219T  53.7M   862G   221T  3.33G  66.5T   259T
    32K:  32.8M  1.41T   221T   288K  12.4G   221T  7.10M   280G   260T
    64K:   855K  71.5G   221T   176K  14.9G   221T  32.7M  2.85T   262T
   128K:  19.9M  2.54T   223T  99.0M  12.4T   233T  20.2M  2.59T   265T
   256K:   415M   104T   327T   416M   104T   337T   415M   104T   369T
   512K:      0      0   327T      0      0   337T      0      0   369T
     1M:      0      0   327T      0      0   337T      0      0   369T
     2M:      0      0   327T      0      0   337T      0      0   369T
     4M:      0      0   327T      0      0   337T      0      0   369T
     8M:      0      0   327T      0      0   337T      0      0   369T
    16M:      0      0   327T      0      0   337T      0      0   369T

                            capacity   operations   bandwidth  ---- errors ----
description                used avail  read write  read write  read write cksum
pool_videos                372T 25.9T   551     0 10.3M     0     0     0     0
  /dev/disk/by-partuuid/27e9e2a8-bdcd-624f-a401-c38ad60c3f27                                    16.2T  165G    11     0  208K     0     0     0     0
  /dev/disk/by-partuuid/d0d55084-4c97-d443-9302-6acf18f61f33                                    16.2T  166G     9     0  149K     0     0     0     0
  /dev/disk/by-partuuid/f886c743-b0d7-7449-b298-f01f3e4e5649                                    16.2T  139G     4     0 79.9K     0     0     0     0
  indirect                                0     0     0     0     0     0     0
  /dev/disk/by-partuuid/c18e34c1-9dca-054a-9586-983e369404b1                                    10.8T  113G     4     0 75.3K     0     0     0     0
  /dev/disk/by-partuuid/a703990a-eec4-8941-babe-e24592e3f4b9                                    14.4T  158G     4     0 81.2K     0     0     0     0
  /dev/disk/by-partuuid/c3fee1c9-dc96-f54b-8aeb-482b9b53fd28                                    16.2T  183G     4     0 76.6K     0     0     0     0
  /dev/disk/by-partuuid//8fee2172-2286-9a4a-8f1e-0bb245299523                                     14.4T  148G     4     0 56.8K     0     0     0     0
  /dev/disk/by-partuuid/c0fd6232-8548-f546-b2cb-b0b29103cf9f                              (log)     0 63.5G     0     0     0     0     0     0     0
  /dev/disk/by-partuuid/e75375b0-1f63-ee48-999c-60cebb46b1c0                                    16.2T  165G    17     0  359K     0     0     0     0
  /dev/disk/by-partuuid/eb99577c-3cfc-324c-983b-72f89ea913bf                                    16.2T  165G    18     0  333K     0     0     0     0
  /dev/disk/by-partuuid/c8fd8101-c78b-7c42-9d28-2bebf6f36473                                    16.2T  152G    13     0  266K     0     0     0     0
  /dev/disk/by-partuuid/c9d34e8b-fd5a-1e43-80e6-b53a1952e806                                    10.8T 99.8G    23     0  480K     0     0     0     0
  /dev/disk/by-partuuid/b903fe71-2060-cb44-9484-c3bbfff48a8c                              (log)  128K 63.5G     0     0     0     0     0     0     0
  /dev/disk/by-partuuid/73758373-96ff-1745-8ea0-daa8a84db7a9                                    14.4T  125G    24     0  393K     0     0     0     0
  /dev/disk/by-partuuid/5c588b7c-3f09-c04b-baa6-4b55d5e19c6e                                    10.8T 93.6G    31     0  524K     0     0     0     0
  /dev/disk/by-partuuid/10b4e398-69c0-6e4c-985b-d65d4801d916                                    14.4T  123G    33     0  640K     0     0     0     0
  /dev/disk/by-partuuid/b2aba5ee-fa29-0c44-9197-7bac96e3fe5e                                    10.8T 99.3G    10     0  306K     0     4     0     0
  /dev/disk/by-partuuid/9fc9d66e-0868-354c-b868-ec18b83aeae6                                    14.4T  129G    18     0  365K     0     0     0     0
  /dev/disk/by-partuuid/e371b4b9-1e2f-694d-b5a3-79abcf5f5e12                                    7.20T 68.9G    17     0  266K     0     0     0     0
  /dev/disk/by-partuuid/849d2ea4-a845-ec4a-8c79-95f42c17f480                                    14.4T  138G    33     0  635K     0     0     0     0
  indirect                                0     0     0     0     0     0     0
  /dev/disk/by-partuuid/73d95a8a-d7ec-3e4b-b4df-82ebeeb4a646                                    16.2T  165G    34     0  694K     0     0     0     0
  /dev/disk/by-partuuid/930ac0cf-83b9-8848-bcef-b3048a351c08                                    16.2T  155G    36     0  711K     0     0     0     0
  /dev/disk/by-partuuid/84f08447-1712-444c-b040-710132d2fd14                                    14.4T  124G    34     0  665K     0     0     0     0
  /dev/disk/by-partuuid/7f11c82a-b815-7e4b-9b6c-a89268f96e06                                    16.2T  150G    40     0  820K     0     0     0     0
  /dev/disk/by-partuuid/02a7298a-527e-6e45-8413-2af22cc465c6                                    14.4T  127G    31     0  620K     0     0     0     0
  /dev/disk/by-partuuid/d6386513-bdca-0b43-aee0-a864ba0c68c0                                    10.8T  107G    29     0  559K     0     0     0     0
  /dev/disk/by-partuuid/25e685f1-8efb-6141-94af-20cd69b562e7                                    6.42T 4.48T    11     0  219K     0     0     0     0
  /dev/disk/by-partuuid/57afd5ac-41ca-fb41-ba0a-b501ca26b6f9                                    3.49T  141G    13     0  268K     0     0     0     0
  /dev/disk/by-partuuid/e9afd6cf-dcd0-cd45-811f-73b33ebcec7e                                    8.01T 2.89T    16     0  327K     0     0     0     0
  /dev/disk/by-partuuid/fc31ef96-22e5-e946-953b-820ac4eb8026                                    14.4T  147G    17     0  358K     0     0     0     0
  /dev/disk/by-partuuid/77c5a28a-c107-43fc-8f0b-bce8b7382565                                    1.30T 15.1T     0     0 10.7K     0     0     0     0

Next step is try to make this pool R/W...

Restarting the system
New import in R/W mode: sudo strace -o zfs-import.strace --follow-forks -tttt -r -T -C zpool import -m -N -f 214206722705514979 (-m to ignore the logs, -N to not mount any data set). --> Failed again
Restarting the system

New import in R/O mode: sudo strace -o zfs-import.strace --follow-forks -tttt -r -T -C zpool import -f -o readonly=on 214206722705514979 (no -m, no '-N') --> Worked

$ sudo zpool list
NAME          SIZE  ALLOC   FREE  CKPOINT  EXPANDSZ   FRAG    CAP  DEDUP    HEALTH  ALTROOT
pool_videos   398T      0   398T        -         -     0%     0%  1.00x    ONLINE  -
$ sudo zfs list
NAME                             USED  AVAIL  REFER  MOUNTPOINT
pool_videos                      369T  24.5T    96K  legacy
pool_videos/vol000               140K  24.5T   140K  /Volumes/vol000
pool_videos/vol001              7.96T  24.5T  7.96T  /Volumes/vol001
pool_videos/vol003_Development   399G  24.5T   399G  /Volumes/vol003
pool_videos/vol007               290T  24.5T   290T  /Volumes/vol007
pool_videos/vol013              12.1T  24.5T  12.1T  /Volumes/vol013
pool_videos/vol014              58.7T  24.5T  58.7T  /Volumes/vol014
$ sudo zfs get all | grep readonly
pool_videos                     readonly              off                    default
pool_videos/vol000              readonly              on                     temporary
pool_videos/vol001              readonly              on                     temporary
pool_videos/vol003_Development  readonly              on                     temporary
pool_videos/vol007              readonly              on                     temporary
pool_videos/vol013              readonly              on                     temporary
pool_videos/vol014              readonly              on                     temporary
$ df -h
Filesystem                      Size  Used Avail Use% Mounted on
.
.
.
pool_videos/vol000               25T  144K   25T   1% /Volumes/vol000
pool_videos/vol007              315T  291T   25T  93% /Volumes/vol007
pool_videos/vol001               33T  8.0T   25T  25% /Volumes/vol001
pool_videos/vol003_Development   25T  400G   25T   2% /Volumes/vol003
pool_videos/vol014               84T   59T   25T  71% /Volumes/vol014
pool_videos/vol013               37T   13T   25T  34% /Volumes/vol013

Srill cannot make it R/W

afberendsen commented 7 months ago

Option now is to run a zdb -e -bcsvL pool_videos .... This is going to take forever.....

# echo 1 > /sys/module/zfs/parameters/zfs_recover
# zdb -e -bcsvL pool_videos

Traversing all blocks to verify checksums ...

5.82G completed (  28MB/s) estimated time remaining: 3870hr 13min 51sec

Too slow. It is going to take more than one year to finish it...

afberendsen commented 7 months ago

New import, monitoring /proc/spl/kstat/zfs/dbgmsg

$ sudo tail -f /proc/spl/kstat/zfs/dbgmsg
.
.
.
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/10b4e398-69c0-6e4c-985b-d65d4801d916': probe done, cant_read=0 cant_write=1
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/c9d34e8b-fd5a-1e43-80e6-b53a1952e806': probe done, cant_read=0 cant_write=1
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/b2aba5ee-fa29-0c44-9197-7bac96e3fe5e': probe done, cant_read=0 cant_write=1
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/5c588b7c-3f09-c04b-baa6-4b55d5e19c6e': probe done, cant_read=0 cant_write=1
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/eb99577c-3cfc-324c-983b-72f89ea913bf': probe done, cant_read=0 cant_write=1
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/c3fee1c9-dc96-f54b-8aeb-482b9b53fd28': probe done, cant_read=0 cant_write=1
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/c18e34c1-9dca-054a-9586-983e369404b1': probe done, cant_read=0 cant_write=1
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/d6386513-bdca-0b43-aee0-a864ba0c68c0': probe done, cant_read=0 cant_write=1
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/f886c743-b0d7-7449-b298-f01f3e4e5649': probe done, cant_read=0 cant_write=1
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/e75375b0-1f63-ee48-999c-60cebb46b1c0': probe done, cant_read=0 cant_write=1
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/57afd5ac-41ca-fb41-ba0a-b501ca26b6f9': probe done, cant_read=0 cant_write=1
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/25e685f1-8efb-6141-94af-20cd69b562e7': probe done, cant_read=0 cant_write=1
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/e9afd6cf-dcd0-cd45-811f-73b33ebcec7e': probe done, cant_read=0 cant_write=1
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/a703990a-eec4-8941-babe-e24592e3f4b9': probe done, cant_read=0 cant_write=1
1710145474   ffff93a9b131a8c0 vdev.c:162:vdev_dbgmsg(): disk vdev '/dev/disk/by-partuuid/77c5a28a-c107-43fc-8f0b-bce8b7382565': probe done, cant_read=0 cant_write=1
1710145474   ffff93a8dd85a8c0 spa_misc.c:2324:spa_import_progress_set_notes_impl(): 'pool_videos' Loading checkpoint txg
1710145474   ffff93a8dd85a8c0 spa_misc.c:2324:spa_import_progress_set_notes_impl(): 'pool_videos' Loading indirect vdev metadata

Import failed again....

afberendsen commented 7 months ago

System restart...

# echo 1 > /sys/module/zfs/parameters/zfs_recover
$ sudo zpool import 214206722705514979 ...and it failed...

afberendsen commented 7 months ago

I ried to force import with some disk devices disabled, but the import failed. Only option now is to import R/O, save the most important files, and destroy and revuild the pool....

afberendsen commented 7 months ago

Not possible to reover. I had to destroy and re-create the pool.

AllKind commented 7 months ago

The question still remains how this happened in the first place. I've seen reports here where, if the log device was missing people had problems importing the pool. In your initial post, the log devices were UNAVAIL. This what happened here? Also the device name of the cache disk changing is something that should not happen. Sadly no developer responded (in time).

afberendsen commented 7 months ago

When using zfs import, the -m switch can be used to ignore the log device. If you check the following post, the log device was always available. I just turned it off/on to check potential solutions.
Using -o readonly=on I was ablae to import the pool. Thisimplies that when importing the pool if R/W mode, someactions are taken by the driver which landed on a null pointer. Trackign the program execution, I noticed that the ZFS driver code is not guarded by null pointer assignments. There are no corrective actions taken or control messages issued.
Evidently is an issue with some of the internal strucutures. I could not find any tool which alllowed me to import part of the pool, even in DEGRADED mode.
The change in device name is caused by the fact that the cache code shows the partition name ad not the assigned device name. When the cache was added, I used the part-id entry. However, the zpool list -v shows the device name. It is very confusing indeed.