Input/output error in recent snapshot; three times on same host now

System information

Type	Version/Name
Distribution Name	Ubuntu/Linux
Distribution Version	Jammy
Kernel Version	5.15.0-86-generic
Architecture	x86_64
OpenZFS Version	2.1.5-1ubuntu6~22.04.1 + ossomacfix (see lp#1987190#14)

Problem observation

Input/output error

(Times below without a Z are in CET, i.e. 06:00 is 05:00Z.)

I have snapshots:

# ls -l /var/lib/mysql/redacted/.zfs/snapshot/
total 8
drwxr-xr-x 7 mysql mysql 21 okt 17 10:26 planb-20231101T0200Z
drwxr-xr-x 7 mysql mysql 21 okt 17 10:26 planb-20231101T0300Z
drwxr-xr-x 7 mysql mysql 21 okt 17 10:26 planb-20231101T0400Z
drwxr-xr-x 7 mysql mysql 21 okt 17 10:26 planb-20231101T0500Z
drwxr-xr-x 7 mysql mysql 21 okt 17 10:26 planb-20231101T0700Z

But the (now) second to last one, I cannot access.

# ls -l /var/lib/mysql/redacted/.zfs/snapshot/planb-20231101T0500Z
ls: cannot access '/var/lib/mysql/redacted/.zfs/snapshot/planb-20231101T0500Z/aria_log.00000001': Input/output error
ls: cannot access '/var/lib/mysql/redacted/.zfs/snapshot/planb-20231101T0500Z/aria_log_control': Input/output error
total 10129
-????????? ? ?     ?               ?            ? aria_log.00000001
-????????? ? ?     ?               ?            ? aria_log_control
-rw-rw---- 1 mysql mysql           0 nov  1 02:55 ddl.log
-rw-rw---- 1 mysql mysql       16384 okt 17 10:26 ddl_recovery.log
-rw-rw---- 1 mysql mysql 10737419544 nov  1 02:55 galera.cache
-rw-rw---- 1 mysql mysql           8 okt 17 10:26 galera.pid
...

Some files have stat issues (see the ? above). None of the files can be read except for the empty file:

# cat /var/lib/mysql/redacted/.zfs/snapshot/planb-20231101T0500Z/mysql_upgrade_info 
cat: /var/lib/mysql/redacted/.zfs/snapshot/planb-20231101T0500Z/mysql_upgrade_info: Input/output error

# cat /var/lib/mysql/redacted/.zfs/snapshot/planb-20231101T0500Z/galera.pid
cat: /var/lib/mysql/redacted/.zfs/snapshot/planb-20231101T0500Z/galera.pid: Input/output error

# cat /var/lib/mysql/redacted/.zfs/snapshot/planb-20231101T0500Z/ddl.log

(Reading the 0 byte file went fine.)

Checking zpool status:

# zpool status
...
errors: 941 data errors, use '-v' for a list

Most of those 941 data errors were from the battle I had with the previous snapshot that went bad. I deleted that bad snapshot yesterday, in the hope that it was just a fluke. That snapshot concerned a different fileset by the way: tank/mysql/redacted2/data

# zpool status -v
...
        <0x11ba1>:<0x3ff>  <-- the other (redacted2) snapshot
        <0x11ba1>:<0x6ff>
        tank/mysql/redacted/data@planb-20231101T0500Z:<0x0>
        tank/mysql/redacted/data@planb-20231101T0500Z:<0x201>
        tank/mysql/redacted/data@planb-20231101T0500Z:<0x6>
        tank/mysql/redacted/data@planb-20231101T0500Z:<0x20>
        tank/mysql/redacted/data@planb-20231101T0500Z:<0x21>
        tank/mysql/redacted/data@planb-20231101T0500Z:<0x181>

How to reproduce the problem

I don't know yet. This is the first such issue I have encountered:

there is encryption enabled:

# zfs get all tank/mysql/redacted/data | grep encr
tank/mysql/redacted/data  encryption            aes-256-gcm           -
tank/mysql/redacted/data  encryptionroot        tank/mysql            -

we do hourly-ish snapshots and sync those to another location that does not hold the encryption keys;
creating a new snapshot succeeds, but doing the incremental sync fails, so that's why I have planb-20231101T0500Z and planb-20231101T0700Z; the 0700Z one appears to be readable.
(not sure yet why the attempt at 0600Z was not done, but that's irrelevant for the discussion);
right now, auto-backups have stopped. otherwise I would have a bunch more snapshots after @planb-20231101T0500Z, but none that can be synced, because every sync starting from 0400Z tries to include 0500Z as well, and that fails.
the other broken snapshot was planb-20231030T0500Z, so also at 05:00, but an even earlier failure was in tank/mysql/redacted3/data@planb-20231027T1800Z.
these failures started appearing after this machine was upgraded from Focal (zfs 0.8.3) to Jammy (zfs 2.1.5) on Oct 11.

Include any warning/errors/backtraces from the system logs

dmesg

Empty. Nothing after boot (Oct 17).

/proc/spl/kstat/zfs/dbgmsg

I got this from the debug log, which isn't much:

# cat /proc/spl/kstat/zfs/dbgmsg | wtimedecode
timestamp    message 
2023-11-01T09:29:13+0100 (1698827353)   zfs_ctldir.c:1106:zfsctl_snapshot_mount(): Unable to automount /var/lib/mysql/redacted2/.zfs/snapshot/planb-20231030T0500Z error=256

This is strange, because at 2023-11-01 that (redacted2) snapshot should've been gone already. I was now debugging the redacted one.

After clearing the log (echo 0 > /proc/spl/kstat/zfs/dbgmsg) and enabling (random) extra stuff (echo 1 > /sys/module/zfs/parameters/spa_load_print_vdev_tree) I now have this:

# cat /proc/spl/kstat/zfs/dbgmsg | wtimedecode 
timestamp    message 
2023-11-01T09:40:28+0100 (1698828028)   metaslab.c:3650:metaslab_condense(): condensing: txg 14928129, msp[128] ffff9bbc683ba000, vdev id 0, spa tank, smp size 1619424, segments 100180, forcing condense=FALSE
2023-11-01T09:49:05+0100 (1698828545)   metaslab.c:3650:metaslab_condense(): condensing: txg 14928230, msp[195] ffff9bbc685e4000, vdev id 0, spa tank, smp size 727776, segments 45449, forcing condense=FALSE
2023-11-01T09:49:10+0100 (1698828550)   metaslab.c:3650:metaslab_condense(): condensing: txg 14928231, msp[172] ffff9bbc684f8000, vdev id 0, spa tank, smp size 993776, segments 61730, forcing condense=FALSE
2023-11-01T10:04:27+0100 (1698829467)   metaslab.c:3650:metaslab_condense(): condensing: txg 14928410, msp[63] ffff9bbc6819c000, vdev id 0, spa tank, smp size 1430544, segments 87916, forcing condense=FALSE
2023-11-01T10:11:21+0100 (1698829881)   metaslab.c:3650:metaslab_condense(): condensing: txg 14928491, msp[172] ffff9bbc684f8000, vdev id 0, spa tank, smp size 951408, segments 59411, forcing condense=FALSE

This means nothing to me, and could just be debug info from the extra spa_load_print_vdev_tree I enabled.

zed

# journalctl -S '00:00' -t zed | sed -e 's/^nov 01 //;s/ [^ ]* / /'
06:01:00 zed[2572813]: eid=31087 class=authentication pool='tank' bookmark=107766:0:0:42
08:00:53 zed[3154622]: eid=31131 class=data pool='tank' priority=2 err=5 flags=0x180 bookmark=107766:0:0:42
08:00:53 zed[3154626]: eid=31133 class=data pool='tank' priority=2 err=5 flags=0x80 bookmark=107766:0:0:42
08:00:53 zed[3154625]: eid=31132 class=authentication pool='tank' priority=2 err=5 flags=0x80 bookmark=107766:0:0:42
09:24:13 zed[3514527]: eid=31137 class=authentication pool='tank' priority=0 err=5 flags=0x80 bookmark=107766:32:0:0
09:24:13 zed[3514529]: eid=31138 class=data pool='tank' priority=0 err=5 flags=0x80 bookmark=107766:32:0:0
09:29:06 zed[3534332]: eid=31139 class=authentication pool='tank' priority=0 err=5 flags=0x80 bookmark=107766:32:0:0
09:29:06 zed[3534334]: eid=31140 class=data pool='tank' priority=0 err=5 flags=0x80 bookmark=107766:32:0:0
09:29:06 zed[3534337]: eid=31141 class=authentication pool='tank' priority=0 err=5 flags=0x80 bookmark=107766:32:0:0
09:29:06 zed[3534338]: eid=31142 class=data pool='tank' priority=0 err=5 flags=0x80 bookmark=107766:32:0:0
09:30:52 zed[3541004]: eid=31143 class=authentication pool='tank' bookmark=107766:0:0:42
09:30:52 zed[3541005]: eid=31144 class=authentication pool='tank' bookmark=107766:0:0:42
09:32:06 zed[3546489]: eid=31145 class=authentication pool='tank' bookmark=107766:0:0:42
09:32:06 zed[3546490]: eid=31146 class=authentication pool='tank' bookmark=107766:0:0:42
09:32:08 zed[3546592]: eid=31147 class=authentication pool='tank' bookmark=107766:0:0:42
09:32:08 zed[3546593]: eid=31148 class=authentication pool='tank' bookmark=107766:0:0:42
09:42:15 zed[3587704]: eid=31149 class=authentication pool='tank' bookmark=107766:0:0:42
09:42:15 zed[3587705]: eid=31150 class=authentication pool='tank' bookmark=107766:0:0:42
09:42:28 zed[3588614]: eid=31151 class=authentication pool='tank' bookmark=107766:0:0:42
09:42:28 zed[3588615]: eid=31152 class=authentication pool='tank' bookmark=107766:0:0:42
09:42:33 zed[3589470]: eid=31153 class=authentication pool='tank' bookmark=107766:0:0:42
09:42:33 zed[3589471]: eid=31154 class=authentication pool='tank' bookmark=107766:0:0:42
09:42:53 zed[3590398]: eid=31155 class=authentication pool='tank' priority=0 err=5 flags=0x880 bookmark=107766:513:0:0
09:42:53 zed[3590400]: eid=31156 class=data pool='tank' priority=0 err=5 flags=0x880 bookmark=107766:513:0:0
09:49:38 zed[3615957]: eid=31157 class=authentication pool='tank' priority=0 err=5 flags=0x880 bookmark=107766:513:0:0
09:49:38 zed[3615959]: eid=31158 class=data pool='tank' priority=0 err=5 flags=0x880 bookmark=107766:513:0:0
09:50:44 zed[3620982]: eid=31159 class=authentication pool='tank' bookmark=107766:0:0:42
09:50:44 zed[3620983]: eid=31160 class=authentication pool='tank' bookmark=107766:0:0:42
09:50:54 zed[3621521]: eid=31161 class=authentication pool='tank' bookmark=107766:0:0:42
09:50:54 zed[3621522]: eid=31162 class=authentication pool='tank' bookmark=107766:0:0:42
09:50:55 zed[3621526]: eid=31164 class=authentication pool='tank' bookmark=107766:0:0:42
09:50:55 zed[3621527]: eid=31163 class=authentication pool='tank' bookmark=107766:0:0:42
09:51:09 zed[3622291]: eid=31165 class=authentication pool='tank' priority=0 err=5 flags=0x800880 bookmark=107766:6:0:0

"When"

# zfs list -oname,creation -t snapshot -r tank/mysql/redacted/data
NAME                                       CREATION
tank/mysql/redacted/data@planb-20231101T0200Z  wo nov  1  3:01 2023
tank/mysql/redacted/data@planb-20231101T0300Z  wo nov  1  4:00 2023
tank/mysql/redacted/data@planb-20231101T0400Z  wo nov  1  5:00 2023
tank/mysql/redacted/data@planb-20231101T0500Z  wo nov  1  6:01 2023  <-- 05:01Z
tank/mysql/redacted/data@planb-20231101T0700Z  wo nov  1  8:00 2023  <-- 07:00Z

First failure (at 05:01:04Z), seen on the receiving end:

warning: cannot send 'tank/mysql/redacted/data@planb-20231101T0500Z': Input/output error
cannot receive incremental stream: checksum mismatch

Second failure (at 07:00:56Z), seen on the receiving end:

warning: cannot send 'tank/mysql/redacted/data@planb-20231101T0500Z': Input/output error
cannot receive incremental stream: invalid backup stream

The other side?

The other side has no snapshots after tank/mysql/redacted/data@planb-20231101T0400Z. The snapshots that do exist are likely fine (including 0400Z).

How to fix?

As I mentioned, I yesterday had the same issue with a bigger snapshot (redacted2). There I destroyed the snapshot, and resumed with a snapshot which I still had on both sides (the 0400Z one).

I started a scrub then too, which finished before the new issues started:

  scan: scrub repaired 0B in 01:51:52 with 0 errors on Tue Oct 31 19:17:19 2023

Interestingly, the mentioned problems in zpool status -v were still there.

Questions

What other debugging can I do/enable/run/check?

I can probably leave this in this state for a short while, hopefully not too long, while I break out the debugging tools.

Can you help with with some zfs/zdb debugging foo so we can get to the bottom of this?

Thanks! Walter Doekes OSSO B.V.

Per your suggestion in https://github.com/openzfs/zfs/issues/14911#issuecomment-1570013030 I compiled zdb from git and ran it here.

If I look at the diff between the zdb -K <key> -dbdbdbdbdbdb of the 0400Z and 0500Z (broken) snapshot, nothing obvious stands out:

zdb-K-db6-0400-0500.diff.gz

Same with the diff between 0500Z (broken) and 0700Z:

zdb-K-db6-0500-0700.diff.gz

Nor with a diff between two good snapshots 0400Z and 0700Z:

zdb-K-db6-0400-0700.diff.gz

And the difference between the dataset and the snapshot (sans inherit=lz4 -> inherit=inherit):

# diff -pu <(sed -e 's/inherit=lz4/inherit=inherit/' tank-mysql-redacted-data.zdb-db6-K.log) \
    tank-mysql-redacted-data-AT-planb-20231101T0500Z.zdb-db6-K.log

zdb-K-db6-dataset-vs-0500.diff.gz

I'd provide the full files, if you think there is useful info in there. I just have to know I'm not leaking anything, so I'd have to do some more redacting.

I'd try running a version that's current like 2.1.13 or 2.2.0 and seeing if still produces EIOIO, rather than hoping whatever Ubuntu is shipping isn't on fire.

Okay. I've spent some time getting proper deb packages which I can manage in an apt repository. (This meant getting reproducible builds right, because repository managers mandate that two identically named files must be identical.)

https://github.com/ossobv/zfs-kmod-build-deb

This appears to be sufficient to get things up and running.

I loaded the new module and rebooted.
I ran a scrub: only the errors of the still existing snapshot remained.

errors: 943 data errors, use '-v' for a list -> errors: 6 data errors, use '-v' for a list

I read the files: I could now read all the files in the (previously corrupted) snapshot. Error refs in zpool status -v changed from:

errors: Permanent errors have been detected in the following files:

    tank/mysql/redacted/data@planb-20231101T0500Z:<0x0>
    tank/mysql/redacted/data@planb-20231101T0500Z:/mysql_upgrade_info
    tank/mysql/redacted/data@planb-20231101T0500Z:/ddl_recovery.log
    tank/mysql/redacted/data@planb-20231101T0500Z:<0x20>
    tank/mysql/redacted/data@planb-20231101T0500Z:<0x21>
    tank/mysql/redacted/data@planb-20231101T0500Z:/galera.pid

to:

errors: Permanent errors have been detected in the following files:

    tank/mysql/redacted/data@planb-20231101T0500Z:<0x0>
    /var/lib/mysql/redacted/.zfs/snapshot/planb-20231101T0500Z/mysql_upgrade_info
    /var/lib/mysql/redacted/.zfs/snapshot/planb-20231101T0500Z/ddl_recovery.log
    tank/mysql/redacted/data@planb-20231101T0500Z:<0x20>
    tank/mysql/redacted/data@planb-20231101T0500Z:<0x21>
    /var/lib/mysql/redacted/.zfs/snapshot/planb-20231101T0500Z/galera.pid

I ran the zfs send: this now worked. (I did not check the received data, but got no complaints from the remote zfs recv.)
I ran a second scrub: now the last of the data errors disappeared.

errors: No known data errors

That makes me a happy camper.

With regards to self-compiled builds. There are a few items that would be nice to get fixed here:

alien now strips custom (extra) version info when it should not (--bump0 -> --keep-version)
rpmbuild creates builds with differing NT_GNU_BUILD_ID because of a lack of -ffile-prefix-map= and the use of "random" mktemp paths
rpmbuild uses the build hostname and build timestamps

See https://github.com/ossobv/zfs-kmod-build-deb/blob/3ddbe5fb2f09fda9724b232e6f90903d524abed8/Dockerfile#L60-L81 and https://github.com/ossobv/zfs-kmod-build-deb/blob/3ddbe5fb2f09fda9724b232e6f90903d524abed8/dpkg-repackage-reproducible .

Best would probably be to create proper debian packaging infra. Then I could also ensure that e.g. libzpool5 conflicts with libzpool5linux, which is likely going to be my next hurdle.

Thinking out loud...

In any case: this particular issue is fixed with 2.1.13. Thanks!

Walter Doekes OSSO B.V.

Bad news.

The error reappeared in snapshot 2013-11-13 22:00 Z. Same system, 2.1.13 ZFS module now.

Versions

# zfs version
zfs-2.1.5-1ubuntu6~22.04.1
zfs-kmod-2.1.13-1osso1

# uptime
 09:16:14 up 10 days, 19:29,  2 users,  load average: 1.31, 1.42, 1.53

# cat /sys/module/zfs/version 
2.1.13-1osso1

We're still running the Ubuntu provided userspace tools (2.1.5), but we run the 2.1.13 kernel module kmod-zfs-5.15.0-88-generic_2.1.13-1osso1_amd64.deb:

https://github.com/ossobv/zfs-kmod-build-deb/releases/tag/zfs-2.1.13-1osso1 (built by ./buildone.sh jammy 5.15.0-88-generic osso1)

Errors

Error seen in zpool status:

# zpool status -v
  pool: tank
 state: ONLINE
...
  scan: scrub repaired 0B in 01:01:44 with 0 errors on Fri Nov  3 13:27:42 2023
config:

    NAME                                           STATE     READ WRITE CKSUM
    tank                                           ONLINE       0     0     0
      nvme-XXX                                     ONLINE       0     0     0

errors: Permanent errors have been detected in the following files:

        tank/mysql/redacted3/data@planb-20231113T2200Z:<0x0>
        tank/mysql/redacted3/data@planb-20231113T2200Z:<0x20>

# zfs list -oname,creation -t snapshot -r tank/mysql/redacted3
NAME                                                    CREATION
tank/mysql/redacted3/data@planb-20231113T1900Z  ma nov 13 20:00 2023
tank/mysql/redacted3/data@planb-20231113T2000Z  ma nov 13 21:00 2023
tank/mysql/redacted3/data@planb-20231113T2100Z  ma nov 13 22:00 2023
tank/mysql/redacted3/data@planb-20231113T2200Z  ma nov 13 23:00 2023
tank/mysql/redacted3/data@planb-20231114T0124Z  di nov 14  2:24 2023
tank/mysql/redacted3/data@planb-20231114T0300Z  di nov 14  4:00 2023
tank/mysql/redacted3/data@planb-20231114T0500Z  di nov 14  6:00 2023
tank/mysql/redacted3/data@planb-20231114T0700Z  di nov 14  8:00 2023
tank/mysql/redacted3/log@planb-20231113T1900Z   ma nov 13 20:01 2023
tank/mysql/redacted3/log@planb-20231113T2000Z   ma nov 13 21:00 2023
tank/mysql/redacted3/log@planb-20231113T2100Z   ma nov 13 22:00 2023

Followup

I'll try and replace the userland tools with the 2.1.13 builds and see if anything changes.

@rincebrain: if you have other (zdb?) tips for debugging in the mean time, I'm interested.

But the files were readable in the snapshot -- at least the ones I tried.

Error state:

errors: Permanent errors have been detected in the following files:

        tank/mysql/redacted3/data@planb-20231113T2200Z:<0x0>
        tank/mysql/redacted3/data@planb-20231113T2200Z:<0x20>

Removing the snapshot:

errors: Permanent errors have been detected in the following files:

        <0x8416>:<0x0>
        <0x8416>:<0x20>

Doing a scrub:

errors: No known data errors

... running 2.1.13 userland tools now. We'll see if the error reappears.

And now, with userland at 2.1.13 and module 2.1.13, after a reboot, there is a new data error.

# zfs version
zfs-2.1.13-1osso1
zfs-kmod-2.1.13-1osso1

# uname -r
5.15.0-88-generic

errors: Permanent errors have been detected in the following files:

        tank/mysql/redacted/data@planb-20231126T1900Z:<0x0>

Interestingly, just after checking (cause?) with zpool status -v, a second error appeared:

errors: Permanent errors have been detected in the following files:

        tank/mysql/redacted/data@planb-20231126T1900Z:<0x0>
        tank/mysql/redacted/data@planb-20231126T1900Z:<0x20>

dmesg has nothing (no disk/IO errors or anything). The storage seems fine too:

# nvme smart-log /dev/nvme0n1
Smart Log for NVME device:nvme0n1 namespace-id:ffffffff
critical_warning            : 0
temperature             : 33 C (306 Kelvin)
available_spare             : 99%
available_spare_threshold       : 10%
percentage_used             : 8%
endurance group critical warning summary: 0
data_units_read             : 2.743.533.883
data_units_written          : 1.743.454.820
host_read_commands          : 251.349.221.948
host_write_commands         : 46.896.760.515
controller_busy_time            : 18.088
power_cycles                : 47
power_on_hours              : 26.930
unsafe_shutdowns            : 43
media_errors                : 0
num_err_log_entries         : 0
Warning Temperature Time        : 0
Critical Composite Temperature Time : 0
Thermal Management T1 Trans Count   : 0
Thermal Management T2 Trans Count   : 0
Thermal Management T1 Total Time    : 0
Thermal Management T2 Total Time    : 0

(I do notice that ashift is 9 and the sector size is 512, which is not optimal for this device.)

(edit: added uname -r)

(SSDs usually hide the performance impact of actual size of IOs to them well enough that you should weigh the observed performance against the space efficiency that results, IMO.)

So, I would guess this is decryption errors, not actual r/w/c errors, since they're not showing up there.

My guess would be there's some additional stupid caveat around the MAC caveats that said patch you originally were applying to Ubuntu's tree is a workaround for - the caveat is, that patch just works around it when it encounters it, a different change is what stops it from screwing up in the first place. (cc #11294 #13709 #14161 63a26454ba43ca3af5020f25d2e59c7ee15bf13d e257bd481bb77181e475bf35292c1a4b0cb2c57a for prior art.) Of course, those are all just for "I cannot unlock the dataset at all because of that error", not files within it erroring...

If it's giving stat errors, I would guess that there could be a similar issue with not just the objset accounting data? I'm not really sure what we can do about that, though, because the reason we can just ignore it in the objset accounting data case is that we can just regenerate it.

If this is a backup target, what's the source running, in terms of ZFS version? What's the automation that's doing the send/recv?

2.1.x has useful counters you can see in grep . /proc/spl/kstat/kcf/*provider* for when decryption things failed - of course, they were dropped in 2.2.x for some reason, I don't really understand why, but for now at least, you can confirm that's decryption errors.

I would suggest that you look at the zpool events output for those errors, and see what they have to say - in particular, you might also find it useful to look at the (git, so it can look at encrypted objects) zdb output for objects 0 and 0x20 (so 32) on that dataset that's erroring, and see if it reports anything interesting. (0 could actually mean 0 or somewhere in the metadata without more precision; 0x20 appears to be the system attribute node on most of the more recent datasets I've made and a normal directory object on some others, so it'd be good to find out what it is here)

It also, thinking about it, wouldn't completely astonish me if those decryption errors were transient and went away after it decided to regenerate the accounting information, but that's just wild speculation, so if you scrub and they go away, and it doesn't come back, great, that's a nice cleanup that should probably be applied to how that's reported, but that's better than getting "???" for files.

If you're still seeing the ??? for some files, though, then we should probably dig even more into it.

Thanks for the replies :)

If this is a backup target, what's the source running, in terms of ZFS version? What's the automation that's doing the send/recv?

This is a backup source. The target is running 2.1.5, but we're not actually getting any data there (when it fails), so I don't think that can be an issue. The automation consists of: zfs snapshot, zfs set planb:owner=..., zfs send -I. The data is sent unencrypted (not --raw, it's encrypted with a different key on the target).

so if you scrub and they go away, and it doesn't come back, great

So far this only went away by removing the snapshot and doing a scrub afterwards.

If you're still seeing the ??? for some files, though, then we should probably dig even more into it.

# cd /var/lib/mysql/redacted/.zfs/snapshot/planb-20231126T1900Z/

# ls -a
.  ..

# cd ..

# ls -l
total 8
drwxr-xr-x 7 mysql mysql 21 nov 14 13:56 planb-20231126T0800Z
drwxr-xr-x 7 mysql mysql 21 nov 14 13:56 planb-20231126T1700Z
drwxr-xr-x 7 mysql mysql 21 nov 14 13:56 planb-20231126T1800Z
drwxr-xr-x 7 mysql mysql 21 nov 14 13:56 planb-20231126T1900Z
drwxr-xr-x 7 mysql mysql 21 nov 14 13:56 planb-20231126T2100Z

# ls planb-20231126T1800Z
aria_log.00000001  ddl.log           galera.cache
...

# ls planb-20231126T2100Z
aria_log.00000001  ddl.log           galera.cache
...

# ls planb-20231126T1900Z/
ls: cannot access 'planb-20231126T1900Z/aria_log.00000001': Input/output error
ls: cannot access 'planb-20231126T1900Z/aria_log_control': Input/output error
aria_log.00000001  ddl.log           galera.cache
...

Weird. The files weren't there. And then they were, but were unreadable.

Still exactly 2 errors at this point.

# cat planb-20231126T1900Z/galera.cache >/dev/null 
cat: planb-20231126T1900Z/galera.cache: Input/output error

But this caused a third error to appear. (And later a fourth.)

errors: Permanent errors have been detected in the following files:

        tank/mysql/redacted/data@planb-20231126T1900Z:<0x0>   # 1
        tank/mysql/redacted/data@planb-20231126T1900Z:<0x20>  # 2
        tank/mysql/redacted/data@planb-20231126T1900Z:<0x21>  # 4
        tank/mysql/redacted/data@planb-20231126T1900Z:<0x382> # 3

Here are the counters:

# grep . /proc/spl/kstat/kcf/*provider*
2 1 0x01 4 1088 3737526914 1069440114633433
name                            type data
kcf_ops_total                   4    5954800672
kcf_ops_passed                  4    5954800635
kcf_ops_failed                  4    37
kcf_ops_returned_busy           4    0

Not sure if these say they are decryption errors or not.

I'll see if I can get some zdb info tomorrow...

kcf_ops_failed is pronounced "I failed to decrypt something".

# ls -l good-0x* bad-0x*
-rw-r--r-- 1 root root  14568 nov 27 13:22 bad-0x0
-rw-r--r-- 1 root root   1131 nov 27 13:22 bad-0x20
-rw-r--r-- 1 root root   1118 nov 27 13:22 bad-0x21
-rw-r--r-- 1 root root 553316 nov 27 13:22 bad-0x382
-rw-r--r-- 1 root root  14568 nov 27 13:22 good-0x0
-rw-r--r-- 1 root root   1131 nov 27 13:22 good-0x20
-rw-r--r-- 1 root root   1118 nov 27 13:22 good-0x21
-rw-r--r-- 1 root root 553316 nov 27 13:22 good-0x382

Types of the aforementioned objects:

# grep Object bad-0x* -A1
bad-0x0:    Object  lvl   iblk   dblk  dsize  dnsize  lsize   %full  type
bad-0x0-         0    6   128K    16K   910K     512   784K   15.05  DMU dnode (K=inherit) (Z=inherit=inherit)
--
bad-0x20:    Object  lvl   iblk   dblk  dsize  dnsize  lsize   %full  type
bad-0x20-        32    1   128K    512     1K     512    512  100.00  SA master node (K=inherit) (Z=inherit=inherit)
--
bad-0x21:    Object  lvl   iblk   dblk  dsize  dnsize  lsize   %full  type
bad-0x21-        33    1   128K    512     1K     512    512  100.00  ZFS delete queue (K=inherit) (Z=inherit=inherit)
--
bad-0x382:    Object  lvl   iblk   dblk  dsize  dnsize  lsize   %full  type
bad-0x382-       898    4   128K    16K  10.5M     512  1.00G    2.83  ZFS plain file (K=inherit) (Z=inherit=inherit)

So, DMU dnode (if 0x0 really is 0x0), SA master node, ZFS delete queue and ZFS plain file respectively.

Very few differences between a good and a bad snapshot:

diff -U10 <(cat good-0x*) <(cat bad-0x*)

--- /dev/fd/63 2023-11-27 13:31:07.049708006 +0100 +++ /dev/fd/62 2023-11-27 13:31:07.049708006 +0100 @@ -1,23 +1,23 @@ Unlocked encryption root: tank/mysql -Dataset tank/mysql/redacted/data@planb-20231126T1800Z [ZPL], ID 67719, cr_txg 15383768, 32.7M, 236 objects, rootbp DVA[0]=<0:2c5a0f94200:1000> DVA[1]=<0:1a4abdd8200:1000> [L0 DMU objset] fletcher4 uncompressed authenticated LE contiguous unique double size=1000L/1000P birth=15383310L/15383310P fill=236 cksum=000000272218b544:0000703a9a4e8e4a:00a9c470070c10f1:b2d3805de20d379e +Dataset tank/mysql/redacted/data@planb-20231126T1900Z [ZPL], ID 67919, cr_txg 15384510, 32.7M, 236 objects, rootbp DVA[0]=<0:2c5a1906800:1000> DVA[1]=<0:1a4ac5f4200:1000> [L0 DMU objset] fletcher4 uncompressed authenticated LE contiguous unique double size=1000L/1000P birth=15384359L/15384359P fill=236 cksum=0000002477cce424:000067457efc5aaa:009aa63ca1cb117d:a1bc5cd4e7913680 Object lvl iblk dblk dsize dnsize lsize %full type 0 6 128K 16K 910K 512 784K 15.05 DMU dnode (K=inherit) (Z=inherit=inherit) dnode flags: USED_BYTES dnode maxblkid: 48 Indirect blocks: - 0 L5 DVA[0]=<0:37cf5cf2800:400> DVA[1]=<0:32ee7c13200:400> [L5 DMU dnode] fletcher4 lz4 indirect-MAC LE contiguous unique double size=20000L/400P birth=15383310L/15383310P fill=236 cksum=0021883aba978620:08746ad2de7f84c8:27c9e69634657ef1:6c3cb47841c67153 - 0 L4 DVA[0]=<0:37cf5cf1c00:400> DVA[1]=<0:32ee7c12600:400> [L4 DMU dnode] fletcher4 lz4 indirect-MAC LE contiguous unique double size=20000L/400P birth=15383310L/15383310P fill=236 cksum=001fcc0ff14c63d7:07e71bba680fe649:c7072401c80680a7:a3d26ac26c905e81 - 0 L3 DVA[0]=<0:c0f6ac5c00:400> DVA[1]=<0:18e43275200:400> [L3 DMU dnode] fletcher4 lz4 indirect-MAC LE contiguous unique double size=20000L/400P birth=15383310L/15383310P fill=236 cksum=00207528df08d374:081c2e5858bea482:51ecef02902b8a1b:ae0266f02e9cb0ba - 0 L2 DVA[0]=<0:c0f6ab6400:400> DVA[1]=<0:18e43265a00:400> [L2 DMU dnode] fletcher4 lz4 indirect-MAC LE contiguous unique double size=20000L/400P birth=15383310L/15383310P fill=236 cksum=0021580e1bc7ddf0:0864a97316f80a0d:97de067f8b082f74:dca97f8ddf677295 - 0 L1 DVA[0]=<0:37cf5ce5000:c00> DVA[1]=<0:32ee7c07e00:c00> [L1 DMU dnode] fletcher4 lz4 indirect-MAC LE contiguous unique double size=20000L/c00P birth=15383310L/15383310P fill=236 cksum=01e34853fecd8757:66806faa16ffadb5:49e66e57db640d6b:15825b09a3f5705f + 0 L5 DVA[0]=<0:37cf9665800:400> DVA[1]=<0:32eeab5ce00:400> [L5 DMU dnode] fletcher4 lz4 indirect-MAC LE contiguous unique double size=20000L/400P birth=15384359L/15384359P fill=236 cksum=002228352ca04564:08a5d17947b85597:0ccabe7d819edce6:95d5c21fc13dc12b + 0 L4 DVA[0]=<0:37cf9665000:400> DVA[1]=<0:32eeab5c600:400> [L4 DMU dnode] fletcher4 lz4 indirect-MAC LE contiguous unique double size=20000L/400P birth=15384359L/15384359P fill=236 cksum=001ff784e827a90f:07f4e1a60cbb427e:2a6ec58bb7496359:6a43c2255d8d9d1e + 0 L3 DVA[0]=<0:c0fce17c00:400> DVA[1]=<0:18e4802c800:400> [L3 DMU dnode] fletcher4 lz4 indirect-MAC LE contiguous unique double size=20000L/400P birth=15384359L/15384359P fill=236 cksum=002040bb5053a2f7:080c690334c5282d:d01d415fb012f8c6:59cc9c9b32be5868 + 0 L2 DVA[0]=<0:c0fce17400:400> DVA[1]=<0:18e4802c000:400> [L2 DMU dnode] fletcher4 lz4 indirect-MAC LE contiguous unique double size=20000L/400P birth=15384359L/15384359P fill=236 cksum=00219cc1f99fa0a4:0879382731e5452e:1f4e8e1f7d7b8f0a:350412897ab2a388 + 0 L1 DVA[0]=<0:37cf9663400:c00> DVA[1]=<0:32eeab5aa00:c00> [L1 DMU dnode] fletcher4 lz4 indirect-MAC LE contiguous unique double size=20000L/c00P birth=15384359L/15384359P fill=236 cksum=01e653ccbdfb3279:67848cf16194940f:cb6ec92779c9e6b9:b848528869df635b 0 L0 DVA[0]=<0:bad7832000:4000> DVA[1]=<0:32db11e8200:4000> salt=eb7c19fbb31a2896 iv=2f87cb9113bab786:6af1f83e [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=15372102L/15372102P fill=2 cksum=10a4b3a6b26d3f82:2fb64beaa71a7a76:410ee197fce45d3d:980172ad786a4bc0 4000 L0 DVA[0]=<0:27801d56000:4000> DVA[1]=<0:32c58286800:4000> salt=eb7c19fbb31a2896 iv=d6ddfd1c9e77e68e:efa270c7 [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=15162731L/15162731P fill=5 cksum=1fd388db45559956:30146d5cd13e9d0a:2baf18f02849834d:32c82535f5cd7400 8000 L0 HOLE [L0 DMU dnode] size=4000L birth=3119973L c000 L0 HOLE [L0 DMU dnode] size=4000L birth=3119973L 10000 L0 DVA[0]=<0:27801d62200:4000> DVA[1]=<0:32c5ec2a000:4000> salt=eb7c19fbb31a2896 iv=10071c96d02a316f:b4258f21 [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=15162731L/15162731P fill=5 cksum=33b9bb555a2db2ea:034046a801e4c5a7:4f17e8987bdbb629:1bbcff71af7ab2a0 14000 L0 HOLE [L0 DMU dnode] size=4000L birth=11808645L 20000 L0 HOLE [L0 DMU dnode] size=4000L birth=15162730L 24000 L0 HOLE [L0 DMU dnode] size=4000L birth=12297274L 30000 L0 DVA[0]=<0:27801d5a000:4000> DVA[1]=<0:32c5ec22000:4000> salt=eb7c19fbb31a2896 iv=410cb0cb1980d636:fe97b940 [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=15162731L/15162731P fill=4 cksum=2d3a255cd9a8482c:c86e8448ddab9058:8f7f99229932921f:64ab33cc0b5f17b1 40000 L0 DVA[0]=<0:27801d6a200:4000> DVA[1]=<0:32c5ec32000:4000> salt=eb7c19fbb31a2896 iv=d591da11453a1bc5:ad40fa7f [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=15162731L/15162731P fill=6 cksum=74d4b0e567899c06:7c45f30e8fdbb7ab:0ab0494041483a4c:fc522d3e91bed75c @@ -36,21 +36,21 @@ 78000 L0 DVA[0]=<0:2ba1bd8f200:4000> DVA[1]=<0:3100b807200:4000> salt=e167adc1ca149ab1 iv=1b9ffcf72e79e38d:d14e642b [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=11810236L/11810236P fill=32 cksum=f6d80dd85118aec9:ab26df98d1f55f1b:76172cf67f8d08c1:14fbab103a4e05f8 7c000 L0 DVA[0]=<0:2ba1bd87200:4000> DVA[1]=<0:3100b7ede00:4000> salt=e167adc1ca149ab1 iv=d8f2a0ee9b90c397:3b2ff543 [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=11810236L/11810236P fill=32 cksum=f9293bc5f89a9c23:ce265c050ec77d32:7f92a701d169fb1e:1e544b185533d117 80000 L0 DVA[0]=<0:27801d95200:4000> DVA[1]=<0:32c6bd61000:4000> salt=eb7c19fbb31a2896 iv=2b9b2281220542ad:972dff7d [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=15162731L/15162731P fill=3 cksum=14449b508874abb7:41ebe129aacd0215:63f756d34543a249:5c0febe7d2a6d8fb 84000 L0 DVA[0]=<0:2ba1bd4f200:4000> DVA[1]=<0:3100b792e00:4000> salt=e167adc1ca149ab1 iv=3ef76e969849bc50:f323e49f [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=11810236L/11810236P fill=2 cksum=000cfae50a150c70:02ff8a844c971b68:7c7264f5fc09adf3:ef72083eb658e3cb 88000 L0 DVA[0]=<0:2ba1bd53200:4000> DVA[1]=<0:3100b796e00:4000> salt=e167adc1ca149ab1 iv=33385b1d4634dac8:36f1548f [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=11810236L/11810236P fill=1 cksum=145bd1260c2aac57:74b453df36aaa4d5:02044e7780267598:89f54c5a2213f6b7 90000 L0 HOLE [L0 DMU dnode] size=4000L birth=15162392L 98000 L0 HOLE [L0 DMU dnode] size=4000L birth=11810236L 9c000 L0 DVA[0]=<0:bad783a000:4000> DVA[1]=<0:32db11f0200:4000> salt=eb7c19fbb31a2896 iv=43a4e510a8d6031:d3bba4cd [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=15372102L/15372102P fill=6 cksum=0cd48fbe419155fb:30d1a9a051604b3b:8500cc17f5f66f43:b437ee146c0f5f1d a0000 L0 DVA[0]=<0:31807f26400:4000> DVA[1]=<0:32ff4e12c00:4000> salt=eb7c19fbb31a2896 iv=c827d4d598c3867c:cedf771c [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=15290191L/15290191P fill=11 cksum=6185877ea2418bd5:222c929592d9eb00:92f939cd2a1b806b:7b3e6f157b2d4a92 a4000 L0 DVA[0]=<0:3480012ba00:4000> DVA[1]=<0:3100fc7bc00:4000> salt=e167adc1ca149ab1 iv=3a22658a1f4621b6:e8d06d08 [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=11821747L/11821747P fill=3 cksum=006fadbed3c91583:36fd432725977eae:1c0cc6a22bf83b8f:3b5eb89fe45e8377 - a8000 L0 DVA[0]=<0:37c74ab0000:4000> DVA[1]=<0:32dfd1e8c00:4000> salt=eb7c19fbb31a2896 iv=a24d26b5cf82ef5d:9bf7287e [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=15383310L/15383310P fill=4 cksum=0a33d7910401ebe8:1e4554f1ae028764:da75461794c13e87:fc0b65372d24be4f + a8000 L0 DVA[0]=<0:37c76dca400:4000> DVA[1]=<0:32e00101000:4000> salt=eb7c19fbb31a2896 iv=6773bb9233db20ee:a0fb63fd [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=15384359L/15384359P fill=4 cksum=0a72e97ee13adb57:eb572499fb52536b:c70e94cfc2af90f1:cb4154dbe903389e ac000 L0 DVA[0]=<0:2ba146a8200:4000> DVA[1]=<0:31003a98c00:4000> salt=a16006a52ff4bcb3 iv=e4fb70423efcf77d:cd7ef7cd [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=11808929L/11808929P fill=1 cksum=0fc32f2a802f5a89:aa52acd4626fdd16:f13d225c237c09da:b1bd66bad85a01cb b0000 L0 DVA[0]=<0:2ba1bd43200:4000> DVA[1]=<0:3100b784c00:4000> salt=e167adc1ca149ab1 iv=faff6510978c06e3:8718e667 [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=11810236L/11810236P fill=8 cksum=7697269badb4ad19:4f1b154bae0f134c:3215c021e33654e3:e35095d168275459 b4000 L0 HOLE [L0 DMU dnode] size=4000L birth=12297059L c0000 L0 DVA[0]=<0:2ba1bd83200:4000> DVA[1]=<0:3100b7e9e00:4000> salt=e167adc1ca149ab1 iv=fb6d2b4d0adaeb99:64cac0a8 [L0 DMU dnode] fletcher4 uncompressed encrypted LE contiguous unique double size=4000L/4000P birth=11810236L/11810236P fill=17 cksum=e0c180a28ac75f62:64da2fdc10b0ff74:72e85a0c499ed3b0:5cd03397a5666fe6 segment [0000000000000200, 0000000000000400) size 512 segment [0000000000000a00, 0000000000000c00) size 512 segment [0000000000004000, 0000000000004a00) size 2.50K segment [0000000000011000, 0000000000011a00) size 2.50K segment [0000000000030000, 0000000000030200) size 512 @@ -89,51 +89,51 @@ segment [00000000000a7800, 00000000000a7e00) size 1.50K segment [00000000000a9800, 00000000000a9a00) size 512 segment [00000000000ab000, 00000000000ab200) size 512 segment [00000000000aba00, 00000000000abe00) size 1K segment [00000000000acc00, 00000000000ace00) size 512 segment [00000000000b0400, 00000000000b1200) size 3.50K segment [00000000000b2600, 00000000000b2800) size 512 segment [00000000000c0000, 00000000000c2200) size 8.50K Unlocked encryption root: tank/mysql -Dataset tank/mysql/redacted/data@planb-20231126T1800Z [ZPL], ID 67719, cr_txg 15383768, 32.7M, 236 objects, rootbp DVA[0]=<0:2c5a0f94200:1000> DVA[1]=<0:1a4abdd8200:1000> [L0 DMU objset] fletcher4 uncompressed authenticated LE contiguous unique double size=1000L/1000P birth=15383310L/15383310P fill=236 cksum=000000272218b544:0000703a9a4e8e4a:00a9c470070c10f1:b2d3805de20d379e +Dataset tank/mysql/redacted/data@planb-20231126T1900Z [ZPL], ID 67919, cr_txg 15384510, 32.7M, 236 objects, rootbp DVA[0]=<0:2c5a1906800:1000> DVA[1]=<0:1a4ac5f4200:1000> [L0 DMU objset] fletcher4 uncompressed authenticated LE contiguous unique double size=1000L/1000P birth=15384359L/15384359P fill=236 cksum=0000002477cce424:000067457efc5aaa:009aa63ca1cb117d:a1bc5cd4e7913680 Object lvl iblk dblk dsize dnsize lsize %full type 32 1 128K 512 1K 512 512 100.00 SA master node (K=inherit) (Z=inherit=inherit) dnode flags: USED_BYTES USERUSED_ACCOUNTED USEROBJUSED_ACCOUNTED dnode maxblkid: 0 microzap: 512 bytes, 2 entries REGISTRY = 35 LAYOUTS = 36 Indirect blocks: 0 L0 DVA[0]=<0:100009a600:200> DVA[1]=<0:140009a600:200> salt=cea7d00cc51104d3 iv=7b5d5ca08bc9b078:b22797 [L0 SA master node] fletcher4 uncompressed encrypted LE contiguous unique double size=200L/200P birth=69L/69P fill=1 cksum=0002d8a2050b18ee:005e8c5c4267f84c:4d78b9600dfa1e49:5e4a20d97b02bb7d segment [0000000000000000, 0000000000000200) size 512 Unlocked encryption root: tank/mysql -Dataset tank/mysql/redacted/data@planb-20231126T1800Z [ZPL], ID 67719, cr_txg 15383768, 32.7M, 236 objects, rootbp DVA[0]=<0:2c5a0f94200:1000> DVA[1]=<0:1a4abdd8200:1000> [L0 DMU objset] fletcher4 uncompressed authenticated LE contiguous unique double size=1000L/1000P birth=15383310L/15383310P fill=236 cksum=000000272218b544:0000703a9a4e8e4a:00a9c470070c10f1:b2d3805de20d379e +Dataset tank/mysql/redacted/data@planb-20231126T1900Z [ZPL], ID 67919, cr_txg 15384510, 32.7M, 236 objects, rootbp DVA[0]=<0:2c5a1906800:1000> DVA[1]=<0:1a4ac5f4200:1000> [L0 DMU objset] fletcher4 uncompressed authenticated LE contiguous unique double size=1000L/1000P birth=15384359L/15384359P fill=236 cksum=0000002477cce424:000067457efc5aaa:009aa63ca1cb117d:a1bc5cd4e7913680 Object lvl iblk dblk dsize dnsize lsize %full type 33 1 128K 512 1K 512 512 100.00 ZFS delete queue (K=inherit) (Z=inherit=inherit) dnode flags: USED_BYTES USERUSED_ACCOUNTED USEROBJUSED_ACCOUNTED dnode maxblkid: 0 microzap: 512 bytes, 0 entries Indirect blocks: 0 L0 DVA[0]=<0:14802d99200:200> DVA[1]=<0:1a400aa6400:200> salt=eb7c19fbb31a2896 iv=de39e0c5ca8190b8:42588b57 [L0 ZFS delete queue] fletcher4 uncompressed encrypted LE contiguous unique double size=200L/200P birth=15162731L/15162731P fill=1 cksum=0003130907e2f727:0063bc01482517f9:8d6472e84320d255:ddb20b4bdf312488 segment [0000000000000000, 0000000000000200) size 512 Unlocked encryption root: tank/mysql -Dataset tank/mysql/redacted/data@planb-20231126T1800Z [ZPL], ID 67719, cr_txg 15383768, 32.7M, 236 objects, rootbp DVA[0]=<0:2c5a0f94200:1000> DVA[1]=<0:1a4abdd8200:1000> [L0 DMU objset] fletcher4 uncompressed authenticated LE contiguous unique double size=1000L/1000P birth=15383310L/15383310P fill=236 cksum=000000272218b544:0000703a9a4e8e4a:00a9c470070c10f1:b2d3805de20d379e +Dataset tank/mysql/redacted/data@planb-20231126T1900Z [ZPL], ID 67919, cr_txg 15384510, 32.7M, 236 objects, rootbp DVA[0]=<0:2c5a1906800:1000> DVA[1]=<0:1a4ac5f4200:1000> [L0 DMU objset] fletcher4 uncompressed authenticated LE contiguous unique double size=1000L/1000P birth=15384359L/15384359P fill=236 cksum=0000002477cce424:000067457efc5aaa:009aa63ca1cb117d:a1bc5cd4e7913680 Object lvl iblk dblk dsize dnsize lsize %full type 898 4 128K 16K 10.5M 512 1.00G 2.83 ZFS plain file (K=inherit) (Z=inherit=inherit) 176 bonus System attributes dnode flags: USED_BYTES USERUSED_ACCOUNTED USEROBJUSED_ACCOUNTED dnode maxblkid: 65536 path /galera.cache uid 111 gid 120 atime Thu May 11 15:52:34 2023

I did find the following line in /proc/spl/kstat/zfs/dbgmsg:

2023-11-26T22:35:19+0100 (1701034519)   zfs_ctldir.c:1139:zfsctl_snapshot_mount(): Unable to automount /var/lib/mysql/redacted/.zfs/snapshot/planb-20231126T1900Z error=256

That was when doing the ls -a yesterday, which turned up nothing.

The aria_log.00000001 and aria_log_control which showed ??? look like this in zdb:

    Object  lvl   iblk   dblk  dsize  dnsize  lsize   %full  type
        34    1   128K  1.50K     1K     512  1.50K  100.00  ZFS directory (K=inherit) (Z=inherit=inherit)
                                               176   bonus  System attributes
        dnode flags: USED_BYTES USERUSED_ACCOUNTED USEROBJUSED_ACCOUNTED 
        dnode maxblkid: 0
        path    /
        uid     111
        gid     120
        atime   Tue Jul 20 23:05:23 2021
        mtime   Tue Nov 14 13:56:56 2023
        ctime   Tue Nov 14 13:56:56 2023
        crtime  Tue Jul 20 23:05:23 2021
        gen     69
        mode    40755
        size    21
        parent  34
        links   7
        pflags  840800000144
        microzap: 1536 bytes, 19 entries

                ddl.log = 1273 (type: Regular File)
                ibtmp1 = 512 (type: Regular File)
                ib_buffer_pool = 896 (type: Regular File)
                aria_log.00000001 = 1373 (type: Regular File)
                redacted = 1038 (type: Directory)
                galera.cache = 898 (type: Regular File)
                performance_schema = 934 (type: Directory)
                mysql = 1040 (type: Directory)
                test = 1037 (type: Directory)
                galera.pid = 514 (type: Regular File)
                multi-master.info = 660 (type: Regular File)
                sys = 936 (type: Directory)
                gvwstate.dat = 384 (type: Regular File)
                aria_log_control = 1374 (type: Regular File)
                ddl_recovery.log = 640 (type: Regular File)
                xtrabackup_info = 1382 (type: Regular File)
                mysql_upgrade_info = 513 (type: Regular File)
                grastate.dat = 5 (type: Regular File)
                ibdata1 = 1294 (type: Regular File)
Indirect blocks:
               0 L0 DVA[0]=<0:14802d99400:200> DVA[1]=<0:1a400aa6600:200> salt=eb7c19fbb31a2896 iv=91ea3e5bc650043f:146ab2be [L0 ZFS directory] fletcher4 lz4 encrypted LE contiguous unique double size=600L/200P birth=15162731L/15162731P fill=1 cksum=0002c75bc4814940:005986c858f339f9:d63621ecb3d69fed:557039941fa509af

                segment [0000000000000000, 0000000000000600) size 1.50K

    Object  lvl   iblk   dblk  dsize  dnsize  lsize   %full  type
      1373    2   128K    16K   312K     512  1.45M  100.00  ZFS plain file (K=inherit) (Z=inherit=inherit)
                                               176   bonus  System attributes
        dnode flags: USED_BYTES USERUSED_ACCOUNTED USEROBJUSED_ACCOUNTED 
        dnode maxblkid: 92
        path    /aria_log.00000001
        uid     111
        gid     120
        atime   Thu May 11 15:55:12 2023
        mtime   Sun Nov 26 19:49:34 2023
        ctime   Sun Nov 26 19:49:34 2023
        crtime  Thu May 11 15:55:12 2023
        gen     11808755
        mode    100660
        size    1515520
        parent  34
        links   1
        pflags  840800000004
Indirect blocks:
               0 L1  DVA[0]=<0:37d39d9f600:1a00> DVA[1]=<0:32fcf924400:1a00> [L1 ZFS plain file] fletcher4 lz4 indirect-MAC LE contiguous unique double size=20000L/1a00P birth=15384359L/15384359P fill=93 cksum=133591c4d8e18cd7:08819389ec10b94c:46255c22acab03b7:243bd9c3b057da1f
               0  L0 DVA[0]=<0:2b9ee7f8800:600> salt=a16006a52ff4bcb3 iv=d60f57e4331171fb:39c57726 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/600P birth=11808755L/11808755P fill=1 cksum=00480df48ce2376f:1b36ffdb1bbc8173:24b90b64cde4f631:5f58e161356986f0
            4000  L0 DVA[0]=<0:2ba25bfb800:800> salt=a16006a52ff4bcb3 iv=ba410c2136c80647:1ad3fe9c [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/800P birth=11808755L/11808755P fill=1 cksum=00ae75b70020849a:580a60172c11fdc6:eb3fb2b50a981203:a740c033085fe422
            8000  L0 DVA[0]=<0:2ba25bfc000:800> salt=a16006a52ff4bcb3 iv=43ac0f67162fc3c3:6df46420 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/800P birth=11808755L/11808755P fill=1 cksum=00b16fcf35454983:59a76676ec6c67f4:326ef34f738dfd38:ab2ab61815713ebc
... truncated ...

    Object  lvl   iblk   dblk  dsize  dnsize  lsize   %full  type
      1374    1   128K    512    512     512    512  100.00  ZFS plain file (K=inherit) (Z=inherit=inherit)
                                               176   bonus  System attributes
        dnode flags: USED_BYTES USERUSED_ACCOUNTED USEROBJUSED_ACCOUNTED 
        dnode maxblkid: 0
        path    /aria_log_control
        uid     111
        gid     120
        atime   Thu May 11 15:55:12 2023
        mtime   Sun Nov 26 19:49:34 2023
        ctime   Sun Nov 26 19:49:34 2023
        crtime  Thu May 11 15:55:12 2023
        gen     11808755
        mode    100660
        size    52
        parent  34
        links   1
        pflags  840800000004
Indirect blocks:
               0 L0 DVA[0]=<0:234e715dc00:200> salt=eb7c19fbb31a2896 iv=7d98a4386a558b60:fd266813 [L0 ZFS plain file] fletcher4 uncompressed encrypted LE contiguous unique single size=200L/200P birth=15384359L/15384359P fill=1 cksum=0002c2484e02f9e1:005a1eeabbf1c802:0e2f9fce11c32d51:0f35cf920387c23c

                segment [0000000000000000, 0000000000000200) size   512

Objects 34, 1373 and 1374 diff between the previous snapshot and the failing one:

diff -U10 good-34-1373-1374 bad-34-1373-1374

--- good-34-1373-1374 2023-11-27 13:42:57.408596765 +0100 +++ bad-34-1373-1374 2023-11-27 13:43:05.480674224 +0100 @@ -1,12 +1,12 @@ Unlocked encryption root: tank/mysql -Dataset tank/mysql/redacted/data@planb-20231126T1800Z [ZPL], ID 67719, cr_txg 15383768, 32.7M, 236 objects, rootbp DVA[0]=<0:2c5a0f94200:1000> DVA[1]=<0:1a4abdd8200:1000> [L0 DMU objset] fletcher4 uncompressed authenticated LE contiguous unique double size=1000L/1000P birth=15383310L/15383310P fill=236 cksum=000000272218b544:0000703a9a4e8e4a:00a9c470070c10f1:b2d3805de20d379e +Dataset tank/mysql/redacted/data@planb-20231126T1900Z [ZPL], ID 67919, cr_txg 15384510, 32.7M, 236 objects, rootbp DVA[0]=<0:2c5a1906800:1000> DVA[1]=<0:1a4ac5f4200:1000> [L0 DMU objset] fletcher4 uncompressed authenticated LE contiguous unique double size=1000L/1000P birth=15384359L/15384359P fill=236 cksum=0000002477cce424:000067457efc5aaa:009aa63ca1cb117d:a1bc5cd4e7913680 Object lvl iblk dblk dsize dnsize lsize %full type 34 1 128K 1.50K 1K 512 1.50K 100.00 ZFS directory (K=inherit) (Z=inherit=inherit) 176 bonus System attributes dnode flags: USED_BYTES USERUSED_ACCOUNTED USEROBJUSED_ACCOUNTED dnode maxblkid: 0 path / uid 111 gid 120 atime Tue Jul 20 23:05:23 2021 @@ -47,31 +47,31 @@ Object lvl iblk dblk dsize dnsize lsize %full type 1373 2 128K 16K 312K 512 1.45M 100.00 ZFS plain file (K=inherit) (Z=inherit=inherit) 176 bonus System attributes dnode flags: USED_BYTES USERUSED_ACCOUNTED USEROBJUSED_ACCOUNTED dnode maxblkid: 92 path /aria_log.00000001 uid 111 gid 120 atime Thu May 11 15:55:12 2023 - mtime Sun Nov 26 18:23:34 2023 - ctime Sun Nov 26 18:23:34 2023 + mtime Sun Nov 26 19:49:34 2023 + ctime Sun Nov 26 19:49:34 2023 crtime Thu May 11 15:55:12 2023 gen 11808755 mode 100660 size 1515520 parent 34 links 1 pflags 840800000004 Indirect blocks: - 0 L1 DVA[0]=<0:37d31f40c00:1a00> DVA[1]=<0:32fc83dc800:1a00> [L1 ZFS plain file] fletcher4 lz4 indirect-MAC LE contiguous unique double size=20000L/1a00P birth=15383310L/15383310P fill=93 cksum=133607619cd6fdff:08a161c5edcbeefd:4c07da2c5dca0bef:35f35ecb744ba729 + 0 L1 DVA[0]=<0:37d39d9f600:1a00> DVA[1]=<0:32fcf924400:1a00> [L1 ZFS plain file] fletcher4 lz4 indirect-MAC LE contiguous unique double size=20000L/1a00P birth=15384359L/15384359P fill=93 cksum=133591c4d8e18cd7:08819389ec10b94c:46255c22acab03b7:243bd9c3b057da1f 0 L0 DVA[0]=<0:2b9ee7f8800:600> salt=a16006a52ff4bcb3 iv=d60f57e4331171fb:39c57726 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/600P birth=11808755L/11808755P fill=1 cksum=00480df48ce2376f:1b36ffdb1bbc8173:24b90b64cde4f631:5f58e161356986f0 4000 L0 DVA[0]=<0:2ba25bfb800:800> salt=a16006a52ff4bcb3 iv=ba410c2136c80647:1ad3fe9c [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/800P birth=11808755L/11808755P fill=1 cksum=00ae75b70020849a:580a60172c11fdc6:eb3fb2b50a981203:a740c033085fe422 8000 L0 DVA[0]=<0:2ba25bfc000:800> salt=a16006a52ff4bcb3 iv=43ac0f67162fc3c3:6df46420 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/800P birth=11808755L/11808755P fill=1 cksum=00b16fcf35454983:59a76676ec6c67f4:326ef34f738dfd38:ab2ab61815713ebc c000 L0 DVA[0]=<0:2ba25bfc800:800> salt=a16006a52ff4bcb3 iv=a4027b64af32edc1:a7515d1d [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/800P birth=11808755L/11808755P fill=1 cksum=009ed1f0d7172e8f:4e64d1fd08f36d39:57d2811b6c4a0210:a85a4819cfa90bb0 10000 L0 DVA[0]=<0:2ba25bfd000:800> salt=a16006a52ff4bcb3 iv=2edbdfa21cec0373:9f7a0520 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/800P birth=11808755L/11808755P fill=1 cksum=00a64ee21be65790:5444901bfad56f2c:4879b5fdff176ed9:c4fe1e178293eb9b 14000 L0 DVA[0]=<0:2ba25bfd800:800> salt=a16006a52ff4bcb3 iv=b0fb7c2f54c7b99c:35b4774c [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/800P birth=11808755L/11808755P fill=1 cksum=00b24533eda62b71:59d82b47fd32f89d:716d6124ac70325d:5501b55854791282 18000 L0 DVA[0]=<0:2ba25bfe000:800> salt=a16006a52ff4bcb3 iv=17649f0cfdc368c:94d62662 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/800P birth=11808755L/11808755P fill=1 cksum=00aeff4bb9d45b59:5816188f23601001:5de8b76cdebc271c:697be53dd091db8f 1c000 L0 DVA[0]=<0:2ba25bfe800:800> salt=a16006a52ff4bcb3 iv=2eca68132f3dd2e6:6fc27721 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/800P birth=11808755L/11808755P fill=1 cksum=00ad84ac5a814deb:575b14d5f326d816:1fed7df226dd783f:2cd06b2f61696c41 20000 L0 DVA[0]=<0:2ba25bff000:800> salt=a16006a52ff4bcb3 iv=fb961cb6649ed0b6:42131580 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/800P birth=11808755L/11808755P fill=1 cksum=00b345ca6892ac7a:5af9626884c6549e:825576dfaaa646ff:c0e7d5d2c0acd8b0 24000 L0 DVA[0]=<0:2ba25bff800:800> salt=a16006a52ff4bcb3 iv=330e80414cec721a:97c0dd92 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/800P birth=11808755L/11808755P fill=1 cksum=00b02eb060f04c1c:586116933ea7c981:2782951e3b9a9eeb:ea843e208a9fa808 @@ -150,37 +150,37 @@ 148000 L0 DVA[0]=<0:231bb75e600:1000> salt=607938b3d7d2a46b iv=a62d7b915f5583c2:3ef02b83 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/1000P birth=13544554L/13544554P fill=1 cksum=054e8f8750812113:4cc93994b2e6fecb:07a2038218962aef:f6651dd7d3ddde3c 14c000 L0 DVA[0]=<0:19d04de3a00:1000> salt=607938b3d7d2a46b iv=edca6375aceb2365:fd291a2 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/1000P birth=13742433L/13742433P fill=1 cksum=058ff61cbfc36e0e:993a454f2e3d1bfc:775688ddb2aec077:f8469b9ef0e0ef9e 150000 L0 DVA[0]=<0:150aebde200:1000> salt=607938b3d7d2a46b iv=f5590f43345cfe7d:9ddceb20 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/1000P birth=13943785L/13943785P fill=1 cksum=0550feef027bf5b7:564ab218ff6d02b7:f38e697cb6f6f9d1:34ddbc74c64f6995 154000 L0 DVA[0]=<0:324961ade00:1000> salt=4eb17d7d320f80a6 iv=fc8bf219a60534e3:a70af3f4 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/1000P birth=14143325L/14143325P fill=1 cksum=05346adaa24fb29c:26178dac597fc763:ee4d7ef4fb09179e:d5e5f0a601d78350 158000 L0 DVA[0]=<0:10766cd8400:1000> salt=f29c9e6b56b8e079 iv=59dc7c914b856505:5911697a [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/1000P birth=14340298L/14340298P fill=1 cksum=056e876ca4608d24:7f9bcdd539aaeca9:d095464796d349b7:550323666cf0c738 15c000 L0 DVA[0]=<0:ba10339a00:1000> salt=d582100159ee9f0c iv=419e2797b51ba352:53746861 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/1000P birth=14539888L/14539888P fill=1 cksum=05642a5a65c17e3b:6782f249bbfe55e4:78a2096ff4f65099:34268817543d4e51 160000 L0 DVA[0]=<0:2f057e9c400:1000> salt=c71d1cf36b9e52e6 iv=d386310c37b1abc8:cbf260ba [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/1000P birth=14734863L/14734863P fill=1 cksum=05761de15549f904:71ee2a11c84534a5:648c434f4c55c12b:89c1418f99d3f488 164000 L0 DVA[0]=<0:203813b8000:1000> salt=c71d1cf36b9e52e6 iv=5b1f342fe3052d26:fff300b6 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/1000P birth=14930857L/14930857P fill=1 cksum=0562d507d6ec98a0:5fbee88d2f4670f6:71dfaf54a377baff:65d86468ac351f04 168000 L0 DVA[0]=<0:3617507cc00:1000> salt=4c76819ef0bdfda5 iv=8c88ff91baf9f46a:13538638 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/1000P birth=15131803L/15131803P fill=1 cksum=052c81ab79eea7f6:220a7d16fa3fa704:93daf99b08399ca3:ca86683634a585c6 16c000 L0 DVA[0]=<0:229e2486600:1000> salt=eb7c19fbb31a2896 iv=39bfc684e4fa962e:1bce27f [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/1000P birth=15328972L/15328972P fill=1 cksum=0549743d53716b13:466a76fb9c6d638b:77a654cbcd50cfb8:050f0c328bd54410 - 170000 L0 DVA[0]=<0:234e4479e00:600> salt=eb7c19fbb31a2896 iv=bdbcb75cb602c68b:ffbc7dee [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/600P birth=15383310L/15383310P fill=1 cksum=0046d27c23bc84de:1ac97de673eac332:c85e8e83663efed9:f6d658c6697cdf9d + 170000 L0 DVA[0]=<0:234e715d600:600> salt=eb7c19fbb31a2896 iv=1615aa2a2d5564ad:d8aec9a2 [L0 ZFS plain file] fletcher4 lz4 encrypted LE contiguous unique single size=4000L/600P birth=15384359L/15384359P fill=1 cksum=00472c143a8a15ea:1a8d27931c546a6c:341e967cc061f060:21da747cf9e82cb7 segment [0000000000000000, 0000000000174000) size 1.45M Object lvl iblk dblk dsize dnsize lsize %full type 1374 1 128K 512 512 512 512 100.00 ZFS plain file (K=inherit) (Z=inherit=inherit) 176 bonus System attributes dnode flags: USED_BYTES USERUSED_ACCOUNTED USEROBJUSED_ACCOUNTED dnode maxblkid: 0 path /aria_log_control uid 111 gid 120 atime Thu May 11 15:55:12 2023 - mtime Sun Nov 26 18:23:34 2023 - ctime Sun Nov 26 18:23:34 2023 + mtime Sun Nov 26 19:49:34 2023 + ctime Sun Nov 26 19:49:34 2023 crtime Thu May 11 15:55:12 2023 gen 11808755 mode 100660 size 52 parent 34 links 1 pflags 840800000004 Indirect blocks: - 0 L0 DVA[0]=<0:234e447a400:200> salt=eb7c19fbb31a2896 iv=501f8bf6a9a38b03:84da206a [L0 ZFS plain file] fletcher4 uncompressed encrypted LE contiguous unique single size=200L/200P birth=15383310L/15383310P fill=1 cksum=0002a4e371958b27:0057772bed0ab651:f66ca0c460379c96:e91fe27cbaf1fbe4 + 0 L0 DVA[0]=<0:234e715dc00:200> salt=eb7c19fbb31a2896 iv=7d98a4386a558b60:fd266813 [L0 ZFS plain file] fletcher4 uncompressed encrypted LE contiguous unique single size=200L/200P birth=15384359L/15384359P fill=1 cksum=0002c2484e02f9e1:005a1eeabbf1c802:0e2f9fce11c32d51:0f35cf920387c23c segment [0000000000000000, 0000000000000200) size 512

Today I have more question marks/immediately failing files:

# ls -l
ls: cannot access 'ddl.log': Input/output error
ls: cannot access 'ib_buffer_pool': Input/output error
ls: cannot access 'aria_log.00000001': Input/output error
ls: cannot access 'galera.cache': Input/output error
ls: cannot access 'aria_log_control': Input/output error
total 2286
-????????? ? ?     ?            ?            ? aria_log.00000001
-????????? ? ?     ?            ?            ? aria_log_control
-????????? ? ?     ?            ?            ? ddl.log
-rw-rw---- 1 mysql mysql    16384 nov 14 13:56 ddl_recovery.log
-????????? ? ?     ?            ?            ? galera.cache
-rw-rw---- 1 mysql mysql        7 nov 14 13:56 galera.pid
...

# ls -l galera.*
ls: cannot access 'galera.cache': Input/output error
-rw-rw---- 1 mysql mysql 7 nov 14 13:56 galera.pid

# cat galera.pid
cat: galera.pid: Input/output error

    Object  lvl   iblk   dblk  dsize  dnsize  lsize   %full  type
       514    1   128K    512    512     512    512  100.00  ZFS plain file (K=inherit) (Z=inherit=inherit)
                                               176   bonus  System attributes
        dnode flags: USED_BYTES USERUSED_ACCOUNTED USEROBJUSED_ACCOUNTED 
        dnode maxblkid: 0
        path    /galera.pid
        uid     111
        gid     120
        atime   Tue Nov 14 13:56:56 2023
        mtime   Tue Nov 14 13:56:56 2023
        ctime   Tue Nov 14 13:56:56 2023
        crtime  Tue Nov 14 13:56:56 2023
        gen     15162731
        mode    100660
        size    7
        parent  34
        links   1
        pflags  840800000004
Indirect blocks:
               0 L0 DVA[0]=<0:14802d99600:200> salt=eb7c19fbb31a2896 iv=cc4fd4a49efb67fa:28fa32e6 [L0 ZFS plain file] fletcher4 uncompressed encrypted LE contiguous unique single size=200L/200P birth=15162731L/15162731P fill=1 cksum=0002abee1ae25470:0058d8bdb904c79e:a1cd2474ef3ddaba:9846bf62da08af08

                segment [0000000000000000, 0000000000000200) size   512

Reading with zdb -r does seem to work:

# ~osso/openzfs-zfs.git/zdb -K $KEY -dbdbdbdbdbdb tank/mysql/redacted/data@planb-20231126T1900Z -r galera.pid /root/galera.pid
Unlocked encryption root: tank/mysql
Unlocked encryption root: tank/mysql
Copying object 514 to file /root/galera.pid
Object 514 is 7 bytes

# hd /root/galera.pid 
00000000  31 35 34 31 35 33 0a                              |154153.|
00000007

In fact, also the aria_log_control which was modified between the good (1800Z) and bad (1900Z) snapshot is readable with zdb -r.

That's about all I can gather from this right now. Let me know if you'd like to see anything else.

My guess remains that it's failing to decrypt the SA and thus refusing you access to the information on the object, but it's not obvious to me why it would be doing that. (zdb, of course, doesn't care about that anyway.)

What's the server hardware that this is in?

I don't immediately recall any bugs with a race in the native encryption code, but, who knows.

What's the server hardware that this is in?

Supermicro X11SCE-F, Intel(R) Xeon(R) E-2236 CPU @ 3.40GHz (6 cores), 4x32GB Micron DDR4 (18ADF4G72AZ-2G6B2), INTEL SSDPE2KX040T8 4TB nvme.

If you have suggestions on debug/tracing code to add to 2.1.13, I can certainly add patches.

There was a second dataset snapshot broken today. I removed both snapshots so the backups are running again. So there's nothing to poke at until the next error pops up.

Checking in.

In November I've had corrupt snapshots on:

2023-11-01 (zfs-2.1.5)
2023-11-13 (zfs-2.1.13)
2023-11-26
2023-11-28
2023-11-29
2023-11-30 (2 corrupt snapshots)

In December (2023-12-01 10:03:02), I updated to ZFS 2.1.14-1osso0:

no corrupt snapshots yet

No idea if it could be related to the fixes in 2.1.14. I do hope it is and that the snapshots remain working from now on.

I would naively expect it to be unrelated, as I don't immediately see how the fix for #15526 would have impacted this, and if it were #15395 I wouldn't expect the snapshots to have data readable from zdb, but I could be wrong.

Okay. Well, that theory was fun while it lasted :)

errors: Permanent errors have been detected in the following files:

        tank/mysql/redacted/log@planb-20231219T0600Z:<0x0>

For different reasons I'll be disabling hourly snapshots on this host. Let me know if you have anything I can work with, then I'll gladly restart something to try and reproduce.

(/proc/spl/kstat/zfs/dbgmsg kept)

Maybe relevant: when no snapshots were made in between, I (still) had to scrub twice to get rid of the error after deleting the failing snapshot.

That's expected - the way the error list in zpool status works, it keeps the previous list after a scrub and only removes things after they don't crop up for two scrubs, I think the original idea being that if you have something flaky, it's useful to remember where it was wrong before even if it read fine this time.

Today I saw https://www.phoronix.com/news/OpenZFS-Encrypt-Corrupt and this looks very similar to #12014 :

the source snapshots gets corrupt, but the receiving end never gets (the) corrupt snapshots
removing the corrupt snapshots and doing a bunch of scrubbing removes the errors
problems started with zfs 2.1.4 (ubuntu jammy)
problems are only observed where a relatively high send/recv frequency is done (in our case, an hourly script that did a handful of datasets in sequence)

openzfs / zfs