incorrect error "unsupported btrfs-progs" reported after failed send

[ian-kelling]

A send failed, probably due to a network failure, and btrbk reports ERROR: Failed to parse subvolume detail (unsupported btrfs-progs). But as far as I can tell, the error had nothing to do with that. The next run of btrbk, it says "Target subvolume xxx exists , but is not a receive target of yyy." and "Please delete stray subvolumes", that made more sense. Here is a bigger excerpt from the logs:

Mar 01 22:00:26 kd sysd-mail-once[1851213]: Checking for missing backups of subvolume "/mnt/o/o" in "x3wg.b8.nz:/mnt/o/btrbk/"
Mar 01 22:00:26 kd sysd-mail-once[1851213]: Creating incremental backup...
Mar 01 22:00:26 kd sysd-mail-once[1851213]: [send/receive] target: x3wg.b8.nz:/mnt/o/btrbk/o.20230301T210018-0500
Mar 01 22:00:26 kd sysd-mail-once[1851213]: [send/receive] source: /mnt/o/btrbk/o.20230301T210018-0500
Mar 01 22:00:26 kd sysd-mail-once[1851213]: [send/receive] parent: /mnt/o/btrbk/o.20230301T190008-0500
Mar 01 22:00:26 kd btrbk[1851213]: send-receive starting ssh://x3wg.b8.nz/mnt/o/btrbk/o.20230301T210018-0500 /mnt/o/btrbk/o.20230301T210018-0500 /mnt/o/btrbk/o.20230301T190008-0500 -
Mar 01 22:01:02 kd sysd-mail-once[1851213]: [send/receive] checking target metadata: x3wg.b8.nz:/mnt/o/btrbk/o.20230301T210018-0500
Mar 01 22:01:05 kd sysd-mail-once[1851213]: ERROR: Failed to parse subvolume detail (unsupported btrfs-progs)s for: x3wg.b8.nz:/mnt/o/btrbk/o.20230301T210018-0500
Mar 01 22:01:05 kd sysd-mail-once[1851213]: ERROR: Failed to send/receive subvolume: /mnt/o/btrbk/o.20230301T210018-0500 [/mnt/o/btrbk/o.20230301T190008-0500] -> x3wg.b8.nz:/mnt/o/btrbk/o.20230301T210018-0500
Mar 01 22:01:05 kd sysd-mail-once[1851213]: ERROR: ... SSH command failed (exitcode=255)
Mar 01 22:01:05 kd sysd-mail-once[1851213]: ERROR: ... sh: btrfs send -p '/mnt/o/btrbk/o.20230301T190008-0500' '/mnt/o/btrbk/o.20230301T210018-0500' | ssh -i '/q/root/h' root@x3wg.b8.nz 'btrfs receive '\''/mnt/o/btrbk/'\'''
Mar 01 22:01:05 kd sysd-mail-once[1851213]: ERROR: ... client_loop: send disconnect: Broken pipe
Mar 01 22:01:05 kd sysd-mail-once[1851213]: ERROR: ... failed to read stream from kernel: Broken pipe
Mar 01 22:01:05 kd sysd-mail-once[1851213]: ERROR: ... failed to check target subvolume: x3wg.b8.nz:/mnt/o/btrbk/o.20230301T210018-0500
Mar 01 22:01:05 kd sysd-mail-once[1851213]: ERROR: ... cannot find real path for '/mnt/o/btrbk/o.20230301T210018-0500': No such file or directory
Mar 01 22:01:05 kd btrbk[1851213]: send-receive ERROR ssh://x3wg.b8.nz/mnt/o/btrbk/o.20230301T210018-0500 /mnt/o/btrbk/o.20230301T210018-0500 /mnt/o/btrbk/o.20230301T190008-0500 -
Mar 01 22:01:05 kd sysd-mail-once[1851213]: ERROR: Error while resuming backups, aborting
Mar 01 22:01:05 kd sysd-mail-once[1851213]: Created 0/2 missing backups

btrbk run again an hour later

Mar 01 23:00:23 kd sysd-mail-once[1930563]: Checking for missing backups of subvolume "/mnt/o/o" in "x3wg.b8.nz:/mnt/o/btrbk/
"
Mar 01 23:00:23 kd sysd-mail-once[1930563]: WARNING: Target subvolume "x3wg.b8.nz:/mnt/o/btrbk/o.20230301T210018-0500" exists
, but is not a receive target of "/mnt/o/btrbk/o.20230301T210018-0500"
Mar 01 23:00:23 kd sysd-mail-once[1930563]: WARNING: Please delete stray subvolumes: "btrbk clean x3wg.b8.nz:/mnt/o/btrbk"
Mar 01 23:00:23 kd sysd-mail-once[1930563]: WARNING: Skipping backup of: /mnt/o/btrbk/o.20230301T210018-0500

[ian-kelling]

And a little more relevant info:

btrfs sub show /mnt/o/btrbk/o.20230301T120009-0500
btrbk/o.20230301T120009-0500
        Name:                   o.20230301T120009-0500
        UUID:                   1c350400-8b8e-f74a-afc6-589305650155
        Parent UUID:            7e286cac-9c4a-6349-9825-8541e71937f9
        Received UUID:          39e38f2c-3155-cd4d-b684-61e052a80c5b
        Creation time:          2023-03-01 21:03:11 -0500
        Subvolume ID:           2274
        Generation:             14127
        Gen at creation:        14124
        Parent ID:              5
        Top level ID:           5
        Flags:                  readonly
        Send transid:           160142
        Send time:              2023-03-01 21:03:11 -0500
        Receive transid:        14125
        Receive time:           2023-03-01 21:03:25 -0500
        Snapshot(s):
                                btrbk/o.20230301T130009-0500

[ian-kelling]

version info

btrbk: commit af2d7b2c99bac7c5af2f9b2c5f0b1947be525597 Date: Sat Nov 12 05:21:50 2022 +0100

btrfs-progs v6.1.3

kernel: Linux version 6.2.1-gnu (rms@mit-oz) (x86_64-linux-gcc (GCC) 12.2.0, GNU ld (GNU Binutils) 2.40) #1.0 SMP PREEMPT_DYNAMIC Tue Sep 27 12:35:59 EST 1983

I've just updated my btrbk to the latest master, I checked commits inbetween and they didn't look to have anything that would be relevant to the unsupported version error message.

[ian-kelling]

For completeness, above was the btrfs-progs and kernel on the receiving machine. They were slightly different on the sending machine.

[digint]

A send failed, probably due to a network failure, and btrbk reports ERROR: Failed to parse subvolume detail (unsupported btrfs-progs). But as far as I can tell, the error had nothing to do with that. The next run of btrbk, it says "Target subvolume xxx exists , but is not a receive target of yyy." and "Please delete stray subvolumes", that made more sense.

I beleive that's "functions as designed". btrfs-progs leaves incomplete subvolumes behind, and btrbk does not delete those (by design), resulting in message: "Please delete stray subvolumes"

If there were some parsing errors, btrbk would have said so, I thinke the "(unsupported btrfs-progs)" part is a bit misleasing in some cases.

In case you can reproduce the ERROR: Failed to parse subvolume detail (unsupported btrfs-progs), please re-run with -l debug . The parser will give some more detailed info.