search

psy0rz / zfs_autobackup

ZFS autobackup is used to periodicly backup ZFS filesystems to other locations. Easy to use and very reliable.
https://github.com/psy0rz/zfs_autobackup
GNU General Public License v3.0
583 stars 62 forks source link

Error: cannot receive incremental stream: most recent snapshot does not match incremental source #261

Closed derandiunddasbo closed 1 month ago

derandiunddasbo commented 1 month ago

I have a strange problem performing backups of a datasets to a locally attached external USB drive.

After running a successful backup for all datasets onto the target drive, when I'm running the next backup only seconds later, literally without touching anything on the source or the target datasets, the backup of one of the datasets is suddenly failing most of the times. In some rare cases, the next run is successful again, but most if the time the backup keeps failing for this one dataset.

For now, the only thing that I could figure out to recover from this error, is to destroy this dataset including snapshots on the target and all "backup-zfs" prefixed snapshots on the source, thus forcing a full backup again for this one dataset.

I'm not a zfs expert and have no clue, what to even look for to find the source of this problem. Why is zfs-autobackup able to perform a successful backup, but is failing with the same command executed literally seconds later, because of a mismatch of the most recent snapshots on the source and the target? 

root@Hamster:~#  zfs-autobackup -v --encrypt --set-properties readonly=on  backup-zfs backup-zfs-1/encrypted
  zfs-autobackup v3.2 - (c)2022 E.H.Eefting (edwin@datux.nl)

  NOTE: Source and target are on the same host, excluding target-path from selection.

  Selecting dataset property : autobackup:backup-zfs
  Snapshot format            : backup-zfs-%Y%m%d%H%M%S
  Timezone                   : Local
  Hold name                  : zfs_autobackup:backup-zfs

  #### Source settings
  [Source] Keep the last 10 snapshots.
  [Source] Keep every 1 day, delete after 1 week.
  [Source] Keep every 1 week, delete after 1 month.
  [Source] Keep every 1 month, delete after 1 year.

  #### Selecting
  [Source] hamster-zfs: Selected
  [Source] hamster-zfs/Austausch: Selected
  [Source] hamster-zfs/Backup: Selected
  [Source] hamster-zfs/Baugruppe: Selected
  [Source] hamster-zfs/Bilder: Selected
  [Source] hamster-zfs/Docker: Selected
  [Source] hamster-zfs/Dokumente: Selected
  [Source] hamster-zfs/Musik: Selected
  [Source] hamster-zfs/PBS: Selected
  [Source] hamster-zfs/Tausch: Selected
  [Source] hamster-zfs/Things: Selected
  [Source] hamster-zfs/Videos: Selected

  #### Snapshotting
  [Source] hamster-zfs: No changes since backup-zfs-20240730175238
  [Source] hamster-zfs/Austausch: No changes since backup-zfs-20240729195823
  [Source] hamster-zfs/Backup: No changes since backup-zfs-20240730180009
  [Source] hamster-zfs/Baugruppe: No changes since backup-zfs-20240727120013
  [Source] hamster-zfs/Bilder: No changes since backup-zfs-20240727120013
  [Source] hamster-zfs/Dokumente: No changes since backup-zfs-20240727120013
  [Source] hamster-zfs/Musik: No changes since backup-zfs-20240730175238
  [Source] hamster-zfs/PBS: No changes since backup-zfs-20240730175238
  [Source] hamster-zfs/Tausch: No changes since backup-zfs-20240730175238
  [Source] hamster-zfs/Things: No changes since backup-zfs-20240727120013
  [Source] hamster-zfs/Videos: No changes since backup-zfs-20240730175238
  [Source] Creating snapshots backup-zfs-20240730182617 in pool hamster-zfs

  #### Target settings
  [Target] Keep the last 10 snapshots.
  [Target] Keep every 1 day, delete after 1 week.
  [Target] Keep every 1 week, delete after 1 month.
  [Target] Keep every 1 month, delete after 1 year.
  [Target] Receive datasets under: backup-zfs-1/encrypted

  #### Synchronising
  [Source] hamster-zfs: sending to backup-zfs-1/encrypted/hamster-zfs
  [Source] hamster-zfs/Austausch: sending to backup-zfs-1/encrypted/hamster-zfs/Austausch
  [Source] hamster-zfs/Backup: sending to backup-zfs-1/encrypted/hamster-zfs/Backup
  [Source] hamster-zfs/Baugruppe: sending to backup-zfs-1/encrypted/hamster-zfs/Baugruppe
  [Source] hamster-zfs/Bilder: sending to backup-zfs-1/encrypted/hamster-zfs/Bilder
  [Source] hamster-zfs/Docker: sending to backup-zfs-1/encrypted/hamster-zfs/Docker
  [Target] backup-zfs-1/encrypted/hamster-zfs/Docker@backup-zfs-20240730182617: receiving full
  [Source] hamster-zfs/Dokumente: sending to backup-zfs-1/encrypted/hamster-zfs/Dokumente
  [Source] hamster-zfs/Musik: sending to backup-zfs-1/encrypted/hamster-zfs/Musik
  [Source] hamster-zfs/PBS: sending to backup-zfs-1/encrypted/hamster-zfs/PBS
  [Source] hamster-zfs/Tausch: sending to backup-zfs-1/encrypted/hamster-zfs/Tausch
  [Source] hamster-zfs/Things: sending to backup-zfs-1/encrypted/hamster-zfs/Things
  [Source] hamster-zfs/Videos: sending to backup-zfs-1/encrypted/hamster-zfs/Videos

  #### All operations completed successfully
root@Hamster:~#  zfs-autobackup -v --encrypt --set-properties readonly=on  backup-zfs backup-zfs-1/encrypted
  zfs-autobackup v3.2 - (c)2022 E.H.Eefting (edwin@datux.nl)

  NOTE: Source and target are on the same host, excluding target-path from selection.

  Selecting dataset property : autobackup:backup-zfs
  Snapshot format            : backup-zfs-%Y%m%d%H%M%S
  Timezone                   : Local
  Hold name                  : zfs_autobackup:backup-zfs

  #### Source settings
  [Source] Keep the last 10 snapshots.
  [Source] Keep every 1 day, delete after 1 week.
  [Source] Keep every 1 week, delete after 1 month.
  [Source] Keep every 1 month, delete after 1 year.

  #### Selecting
  [Source] hamster-zfs: Selected
  [Source] hamster-zfs/Austausch: Selected
  [Source] hamster-zfs/Backup: Selected
  [Source] hamster-zfs/Baugruppe: Selected
  [Source] hamster-zfs/Bilder: Selected
  [Source] hamster-zfs/Docker: Selected
  [Source] hamster-zfs/Dokumente: Selected
  [Source] hamster-zfs/Musik: Selected
  [Source] hamster-zfs/PBS: Selected
  [Source] hamster-zfs/Tausch: Selected
  [Source] hamster-zfs/Things: Selected
  [Source] hamster-zfs/Videos: Selected

  #### Snapshotting
  [Source] hamster-zfs: No changes since backup-zfs-20240730175238
  [Source] hamster-zfs/Austausch: No changes since backup-zfs-20240729195823
  [Source] hamster-zfs/Backup: No changes since backup-zfs-20240730180009
  [Source] hamster-zfs/Baugruppe: No changes since backup-zfs-20240727120013
  [Source] hamster-zfs/Bilder: No changes since backup-zfs-20240727120013
  [Source] hamster-zfs/Dokumente: No changes since backup-zfs-20240727120013
  [Source] hamster-zfs/Musik: No changes since backup-zfs-20240730175238
  [Source] hamster-zfs/PBS: No changes since backup-zfs-20240730175238
  [Source] hamster-zfs/Tausch: No changes since backup-zfs-20240730175238
  [Source] hamster-zfs/Things: No changes since backup-zfs-20240727120013
  [Source] hamster-zfs/Videos: No changes since backup-zfs-20240730175238
  [Source] Creating snapshots backup-zfs-20240730184456 in pool hamster-zfs

  #### Target settings
  [Target] Keep the last 10 snapshots.
  [Target] Keep every 1 day, delete after 1 week.
  [Target] Keep every 1 week, delete after 1 month.
  [Target] Keep every 1 month, delete after 1 year.
  [Target] Receive datasets under: backup-zfs-1/encrypted

  #### Synchronising
  [Source] hamster-zfs: sending to backup-zfs-1/encrypted/hamster-zfs
  [Source] hamster-zfs/Austausch: sending to backup-zfs-1/encrypted/hamster-zfs/Austausch
  [Source] hamster-zfs/Backup: sending to backup-zfs-1/encrypted/hamster-zfs/Backup
  [Source] hamster-zfs/Baugruppe: sending to backup-zfs-1/encrypted/hamster-zfs/Baugruppe
  [Source] hamster-zfs/Bilder: sending to backup-zfs-1/encrypted/hamster-zfs/Bilder
  [Source] hamster-zfs/Docker: sending to backup-zfs-1/encrypted/hamster-zfs/Docker
  [Target] backup-zfs-1/encrypted/hamster-zfs/Docker@backup-zfs-20240730184456: receiving incremental
! [Target] STDERR > cannot receive incremental stream: most recent snapshot of backup-zfs-1/encrypted/hamster-zfs/Docker does not
! [Target] STDERR > match incremental source
! [Source] Command "zfs send -L -v -P -p -i @zfs-auto-snap_frequent-2024-07-30-1630 hamster-zfs/Docker@backup-zfs-20240730184456" returned exit code 141 (valid codes: [0])
! [Target] Command "zfs recv -u -x keylocation -x pbkdf2iters -x keyformat -x encryption -o readonly=on -v -s backup-zfs-1/encrypted/hamster-zfs/Docker" returned exit code 1 (valid codes: [0])
! [Source] hamster-zfs/Docker: FAILED: Last command returned error
  [Source] hamster-zfs/Dokumente: sending to backup-zfs-1/encrypted/hamster-zfs/Dokumente
  [Source] hamster-zfs/Musik: sending to backup-zfs-1/encrypted/hamster-zfs/Musik
  [Source] hamster-zfs/PBS: sending to backup-zfs-1/encrypted/hamster-zfs/PBS
  [Source] hamster-zfs/Tausch: sending to backup-zfs-1/encrypted/hamster-zfs/Tausch
  [Source] hamster-zfs/Things: sending to backup-zfs-1/encrypted/hamster-zfs/Things
  [Source] hamster-zfs/Videos: sending to backup-zfs-1/encrypted/hamster-zfs/Videos
! 1 dataset(s) failed!

This is the output from a --debug run performed immediately after a failed run:

root@Hamster:~#  zfs-autobackup -v --debug --encrypt --set-properties readonly=on  backup-zfs backup-zfs-1/encrypted
  zfs-autobackup v3.2 - (c)2022 E.H.Eefting (edwin@datux.nl)

  NOTE: Source and target are on the same host, excluding target-path from selection.

  Selecting dataset property : autobackup:backup-zfs
  Snapshot format            : backup-zfs-%Y%m%d%H%M%S
  Timezone                   : Local
  Hold name                  : zfs_autobackup:backup-zfs

  #### Source settings
  [Source] Keep the last 10 snapshots.
  [Source] Keep every 1 day, delete after 1 week.
  [Source] Keep every 1 week, delete after 1 month.
  [Source] Keep every 1 month, delete after 1 year.

  #### Selecting
# [Source] Getting selected datasets
# [Source] CMD    > (zfs get -t volume,filesystem -o name,value,source -H autobackup:backup-zfs)
# [Source] backup-zfs-1/encrypted/hamster-zfs: Excluded (path in exclude list)
# [Source] backup-zfs-1/encrypted/hamster-zfs/Austausch: Excluded (path in exclude list)
# [Source] backup-zfs-1/encrypted/hamster-zfs/Backup: Excluded (path in exclude list)
# [Source] backup-zfs-1/encrypted/hamster-zfs/Baugruppe: Excluded (path in exclude list)
# [Source] backup-zfs-1/encrypted/hamster-zfs/Bilder: Excluded (path in exclude list)
# [Source] backup-zfs-1/encrypted/hamster-zfs/Docker: Excluded (path in exclude list)
# [Source] backup-zfs-1/encrypted/hamster-zfs/Dokumente: Excluded (path in exclude list)
# [Source] backup-zfs-1/encrypted/hamster-zfs/Musik: Excluded (path in exclude list)
# [Source] backup-zfs-1/encrypted/hamster-zfs/PBS: Excluded (path in exclude list)
# [Source] backup-zfs-1/encrypted/hamster-zfs/Tausch: Excluded (path in exclude list)
# [Source] backup-zfs-1/encrypted/hamster-zfs/Things: Excluded (path in exclude list)
# [Source] backup-zfs-1/encrypted/hamster-zfs/Videos: Excluded (path in exclude list)
# [Source] hamster-zfs: Checking if dataset is changed
  [Source] hamster-zfs: Selected
# [Source] hamster-zfs/Austausch: Checking if dataset is changed
  [Source] hamster-zfs/Austausch: Selected
# [Source] hamster-zfs/Backup: Checking if dataset is changed
  [Source] hamster-zfs/Backup: Selected
# [Source] hamster-zfs/Baugruppe: Checking if dataset is changed
  [Source] hamster-zfs/Baugruppe: Selected
# [Source] hamster-zfs/Bilder: Checking if dataset is changed
  [Source] hamster-zfs/Bilder: Selected
# [Source] hamster-zfs/Docker: Checking if dataset is changed
  [Source] hamster-zfs/Docker: Selected
# [Source] hamster-zfs/Dokumente: Checking if dataset is changed
  [Source] hamster-zfs/Dokumente: Selected
# [Source] hamster-zfs/Musik: Checking if dataset is changed
  [Source] hamster-zfs/Musik: Selected
# [Source] hamster-zfs/PBS: Checking if dataset is changed
  [Source] hamster-zfs/PBS: Selected
# [Source] hamster-zfs/Tausch: Checking if dataset is changed
  [Source] hamster-zfs/Tausch: Selected
# [Source] hamster-zfs/Things: Checking if dataset is changed
  [Source] hamster-zfs/Things: Selected
# [Source] hamster-zfs/Videos: Checking if dataset is changed
  [Source] hamster-zfs/Videos: Selected

  #### Snapshotting
# [Source] hamster-zfs: Checking if filesystem exists: was forced to True
# [Source] hamster-zfs: Getting snapshots
# [Source] CMD    > (zfs list -d 1 -r -t snapshot -H -o name hamster-zfs)
# [Source] hamster-zfs: Getting bytes written since our last snapshot
# [Source] CMD    > (zfs get -H -ovalue -p written@hamster-zfs@backup-zfs-20240730175238 hamster-zfs)
  [Source] hamster-zfs: No changes since backup-zfs-20240730175238
# [Source] hamster-zfs/Austausch: Checking if filesystem exists: was forced to True
# [Source] hamster-zfs/Austausch: Getting snapshots
# [Source] CMD    > (zfs list -d 1 -r -t snapshot -H -o name hamster-zfs/Austausch)
# [Source] hamster-zfs/Austausch: Getting bytes written since our last snapshot
# [Source] CMD    > (zfs get -H -ovalue -p written@hamster-zfs/Austausch@backup-zfs-20240729195823 hamster-zfs/Austausch)
  [Source] hamster-zfs/Austausch: No changes since backup-zfs-20240729195823
# [Source] hamster-zfs/Backup: Checking if filesystem exists: was forced to True
# [Source] hamster-zfs/Backup: Getting snapshots
# [Source] CMD    > (zfs list -d 1 -r -t snapshot -H -o name hamster-zfs/Backup)
# [Source] hamster-zfs/Backup: Getting bytes written since our last snapshot
# [Source] CMD    > (zfs get -H -ovalue -p written@hamster-zfs/Backup@backup-zfs-20240730180009 hamster-zfs/Backup)
  [Source] hamster-zfs/Backup: No changes since backup-zfs-20240730180009
# [Source] hamster-zfs/Baugruppe: Checking if filesystem exists: was forced to True
# [Source] hamster-zfs/Baugruppe: Getting snapshots
# [Source] CMD    > (zfs list -d 1 -r -t snapshot -H -o name hamster-zfs/Baugruppe)
# [Source] hamster-zfs/Baugruppe: Getting bytes written since our last snapshot
# [Source] CMD    > (zfs get -H -ovalue -p written@hamster-zfs/Baugruppe@backup-zfs-20240727120013 hamster-zfs/Baugruppe)
  [Source] hamster-zfs/Baugruppe: No changes since backup-zfs-20240727120013
# [Source] hamster-zfs/Bilder: Checking if filesystem exists: was forced to True
# [Source] hamster-zfs/Bilder: Getting snapshots
# [Source] CMD    > (zfs list -d 1 -r -t snapshot -H -o name hamster-zfs/Bilder)
# [Source] hamster-zfs/Bilder: Getting bytes written since our last snapshot
# [Source] CMD    > (zfs get -H -ovalue -p written@hamster-zfs/Bilder@backup-zfs-20240727120013 hamster-zfs/Bilder)
  [Source] hamster-zfs/Bilder: No changes since backup-zfs-20240727120013
# [Source] hamster-zfs/Docker: Checking if filesystem exists: was forced to True
# [Source] hamster-zfs/Docker: Getting snapshots
# [Source] CMD    > (zfs list -d 1 -r -t snapshot -H -o name hamster-zfs/Docker)
# [Source] hamster-zfs/Docker: Getting bytes written since our last snapshot
# [Source] CMD    > (zfs get -H -ovalue -p written@hamster-zfs/Docker@backup-zfs-20240730192004 hamster-zfs/Docker)
  [Source] hamster-zfs/Docker: No changes since backup-zfs-20240730192004
# [Source] hamster-zfs/Dokumente: Checking if filesystem exists: was forced to True
# [Source] hamster-zfs/Dokumente: Getting snapshots
# [Source] CMD    > (zfs list -d 1 -r -t snapshot -H -o name hamster-zfs/Dokumente)
# [Source] hamster-zfs/Dokumente: Getting bytes written since our last snapshot
# [Source] CMD    > (zfs get -H -ovalue -p written@hamster-zfs/Dokumente@backup-zfs-20240727120013 hamster-zfs/Dokumente)
  [Source] hamster-zfs/Dokumente: No changes since backup-zfs-20240727120013
# [Source] hamster-zfs/Musik: Checking if filesystem exists: was forced to True
# [Source] hamster-zfs/Musik: Getting snapshots
# [Source] CMD    > (zfs list -d 1 -r -t snapshot -H -o name hamster-zfs/Musik)
# [Source] hamster-zfs/Musik: Getting bytes written since our last snapshot
# [Source] CMD    > (zfs get -H -ovalue -p written@hamster-zfs/Musik@backup-zfs-20240730175238 hamster-zfs/Musik)
  [Source] hamster-zfs/Musik: No changes since backup-zfs-20240730175238
# [Source] hamster-zfs/PBS: Checking if filesystem exists: was forced to True
# [Source] hamster-zfs/PBS: Getting snapshots
# [Source] CMD    > (zfs list -d 1 -r -t snapshot -H -o name hamster-zfs/PBS)
# [Source] hamster-zfs/PBS: Getting bytes written since our last snapshot
# [Source] CMD    > (zfs get -H -ovalue -p written@hamster-zfs/PBS@backup-zfs-20240730175238 hamster-zfs/PBS)
  [Source] hamster-zfs/PBS: No changes since backup-zfs-20240730175238
# [Source] hamster-zfs/Tausch: Checking if filesystem exists: was forced to True
# [Source] hamster-zfs/Tausch: Getting snapshots
# [Source] CMD    > (zfs list -d 1 -r -t snapshot -H -o name hamster-zfs/Tausch)
# [Source] hamster-zfs/Tausch: Getting bytes written since our last snapshot
# [Source] CMD    > (zfs get -H -ovalue -p written@hamster-zfs/Tausch@backup-zfs-20240730175238 hamster-zfs/Tausch)
  [Source] hamster-zfs/Tausch: No changes since backup-zfs-20240730175238
# [Source] hamster-zfs/Things: Checking if filesystem exists: was forced to True
# [Source] hamster-zfs/Things: Getting snapshots
# [Source] CMD    > (zfs list -d 1 -r -t snapshot -H -o name hamster-zfs/Things)
# [Source] hamster-zfs/Things: Getting bytes written since our last snapshot
# [Source] CMD    > (zfs get -H -ovalue -p written@hamster-zfs/Things@backup-zfs-20240727120013 hamster-zfs/Things)
  [Source] hamster-zfs/Things: No changes since backup-zfs-20240727120013
# [Source] hamster-zfs/Videos: Checking if filesystem exists: was forced to True
# [Source] hamster-zfs/Videos: Getting snapshots
# [Source] CMD    > (zfs list -d 1 -r -t snapshot -H -o name hamster-zfs/Videos)
# [Source] hamster-zfs/Videos: Getting bytes written since our last snapshot
# [Source] CMD    > (zfs get -H -ovalue -p written@hamster-zfs/Videos@backup-zfs-20240730175238 hamster-zfs/Videos)
  [Source] hamster-zfs/Videos: No changes since backup-zfs-20240730175238
  [Source] No changes anywhere: not creating snapshots.

  #### Target settings
  [Target] Keep the last 10 snapshots.
  [Target] Keep every 1 day, delete after 1 week.
  [Target] Keep every 1 week, delete after 1 month.
  [Target] Keep every 1 month, delete after 1 year.
  [Target] Receive datasets under: backup-zfs-1/encrypted

  #### Synchronising
# [Target] backup-zfs-1/encrypted: Checking if filesystem exists
# [Target] CMD    > (zfs list backup-zfs-1/encrypted)
# Checking target names:
# [Source] hamster-zfs: -> backup-zfs-1/encrypted/hamster-zfs
# [Source] hamster-zfs/Austausch: -> backup-zfs-1/encrypted/hamster-zfs/Austausch
# [Source] hamster-zfs/Backup: -> backup-zfs-1/encrypted/hamster-zfs/Backup
# [Source] hamster-zfs/Baugruppe: -> backup-zfs-1/encrypted/hamster-zfs/Baugruppe
# [Source] hamster-zfs/Bilder: -> backup-zfs-1/encrypted/hamster-zfs/Bilder
# [Source] hamster-zfs/Docker: -> backup-zfs-1/encrypted/hamster-zfs/Docker
# [Source] hamster-zfs/Dokumente: -> backup-zfs-1/encrypted/hamster-zfs/Dokumente
# [Source] hamster-zfs/Musik: -> backup-zfs-1/encrypted/hamster-zfs/Musik
# [Source] hamster-zfs/PBS: -> backup-zfs-1/encrypted/hamster-zfs/PBS
# [Source] hamster-zfs/Tausch: -> backup-zfs-1/encrypted/hamster-zfs/Tausch
# [Source] hamster-zfs/Things: -> backup-zfs-1/encrypted/hamster-zfs/Things
# [Source] hamster-zfs/Videos: -> backup-zfs-1/encrypted/hamster-zfs/Videos
# [Source] zpool hamster-zfs: Getting zpool properties
# [Source] CMD    > (zpool get -H -p all hamster-zfs)
# [Target] zpool backup-zfs-1: Getting zpool properties
# [Target] CMD    > (zpool get -H -p all backup-zfs-1)
  [Source] hamster-zfs: sending to backup-zfs-1/encrypted/hamster-zfs
# [Target] backup-zfs-1/encrypted/hamster-zfs: Determining start snapshot
# [Target] backup-zfs-1/encrypted/hamster-zfs: Checking if filesystem exists
# [Target] CMD    > (zfs list backup-zfs-1/encrypted/hamster-zfs)
# [Target] backup-zfs-1/encrypted/hamster-zfs: Getting snapshots
# [Target] CMD    > (zfs list -d 1 -r -t snapshot -H -o name backup-zfs-1/encrypted/hamster-zfs)
# [Source] hamster-zfs@backup-zfs-20240730175238: common snapshot
# [Target] backup-zfs-1/encrypted/hamster-zfs: Creating virtual target snapshots
# [Target] backup-zfs-1/encrypted/hamster-zfs: Getting zfs properties
# [Target] CMD    > (zfs get -H -o property,value -p all backup-zfs-1/encrypted/hamster-zfs)
# [Source] hamster-zfs: Getting zfs properties
# [Source] CMD    > (zfs get -H -o property,value -p all hamster-zfs)
  [Source] hamster-zfs/Austausch: sending to backup-zfs-1/encrypted/hamster-zfs/Austausch
# [Target] backup-zfs-1/encrypted/hamster-zfs/Austausch: Determining start snapshot
# [Target] backup-zfs-1/encrypted/hamster-zfs/Austausch: Checking if filesystem exists
# [Target] CMD    > (zfs list backup-zfs-1/encrypted/hamster-zfs/Austausch)
# [Target] backup-zfs-1/encrypted/hamster-zfs/Austausch: Getting snapshots
# [Target] CMD    > (zfs list -d 1 -r -t snapshot -H -o name backup-zfs-1/encrypted/hamster-zfs/Austausch)
# [Source] hamster-zfs/Austausch@zfs-auto-snap_hourly-2024-07-30-1717: common snapshot
# [Target] backup-zfs-1/encrypted/hamster-zfs/Austausch: Creating virtual target snapshots
# [Target] backup-zfs-1/encrypted/hamster-zfs/Austausch: Getting zfs properties
# [Target] CMD    > (zfs get -H -o property,value -p all backup-zfs-1/encrypted/hamster-zfs/Austausch)
# [Source] hamster-zfs/Austausch: Getting zfs properties
# [Source] CMD    > (zfs get -H -o property,value -p all hamster-zfs/Austausch)
  [Source] hamster-zfs/Backup: sending to backup-zfs-1/encrypted/hamster-zfs/Backup
# [Target] backup-zfs-1/encrypted/hamster-zfs/Backup: Determining start snapshot
# [Target] backup-zfs-1/encrypted/hamster-zfs/Backup: Checking if filesystem exists
# [Target] CMD    > (zfs list backup-zfs-1/encrypted/hamster-zfs/Backup)
# [Target] backup-zfs-1/encrypted/hamster-zfs/Backup: Getting snapshots
# [Target] CMD    > (zfs list -d 1 -r -t snapshot -H -o name backup-zfs-1/encrypted/hamster-zfs/Backup)
# [Source] hamster-zfs/Backup@backup-zfs-20240730180009: common snapshot
# [Target] backup-zfs-1/encrypted/hamster-zfs/Backup: Creating virtual target snapshots
# [Target] backup-zfs-1/encrypted/hamster-zfs/Backup: Getting zfs properties
# [Target] CMD    > (zfs get -H -o property,value -p all backup-zfs-1/encrypted/hamster-zfs/Backup)
# [Source] hamster-zfs/Backup: Getting zfs properties
# [Source] CMD    > (zfs get -H -o property,value -p all hamster-zfs/Backup)
  [Source] hamster-zfs/Baugruppe: sending to backup-zfs-1/encrypted/hamster-zfs/Baugruppe
# [Target] backup-zfs-1/encrypted/hamster-zfs/Baugruppe: Determining start snapshot
# [Target] backup-zfs-1/encrypted/hamster-zfs/Baugruppe: Checking if filesystem exists
# [Target] CMD    > (zfs list backup-zfs-1/encrypted/hamster-zfs/Baugruppe)
# [Target] backup-zfs-1/encrypted/hamster-zfs/Baugruppe: Getting snapshots
# [Target] CMD    > (zfs list -d 1 -r -t snapshot -H -o name backup-zfs-1/encrypted/hamster-zfs/Baugruppe)
# [Source] hamster-zfs/Baugruppe@zfs-auto-snap_hourly-2024-07-30-1717: common snapshot
# [Target] backup-zfs-1/encrypted/hamster-zfs/Baugruppe: Creating virtual target snapshots
# [Target] backup-zfs-1/encrypted/hamster-zfs/Baugruppe: Getting zfs properties
# [Target] CMD    > (zfs get -H -o property,value -p all backup-zfs-1/encrypted/hamster-zfs/Baugruppe)
# [Source] hamster-zfs/Baugruppe: Getting zfs properties
# [Source] CMD    > (zfs get -H -o property,value -p all hamster-zfs/Baugruppe)
  [Source] hamster-zfs/Bilder: sending to backup-zfs-1/encrypted/hamster-zfs/Bilder
# [Target] backup-zfs-1/encrypted/hamster-zfs/Bilder: Determining start snapshot
# [Target] backup-zfs-1/encrypted/hamster-zfs/Bilder: Checking if filesystem exists
# [Target] CMD    > (zfs list backup-zfs-1/encrypted/hamster-zfs/Bilder)
# [Target] backup-zfs-1/encrypted/hamster-zfs/Bilder: Getting snapshots
# [Target] CMD    > (zfs list -d 1 -r -t snapshot -H -o name backup-zfs-1/encrypted/hamster-zfs/Bilder)
# [Source] hamster-zfs/Bilder@zfs-auto-snap_hourly-2024-07-30-1717: common snapshot
# [Target] backup-zfs-1/encrypted/hamster-zfs/Bilder: Creating virtual target snapshots
# [Target] backup-zfs-1/encrypted/hamster-zfs/Bilder: Getting zfs properties
# [Target] CMD    > (zfs get -H -o property,value -p all backup-zfs-1/encrypted/hamster-zfs/Bilder)
# [Source] hamster-zfs/Bilder: Getting zfs properties
# [Source] CMD    > (zfs get -H -o property,value -p all hamster-zfs/Bilder)
  [Source] hamster-zfs/Docker: sending to backup-zfs-1/encrypted/hamster-zfs/Docker
# [Target] backup-zfs-1/encrypted/hamster-zfs/Docker: Determining start snapshot
# [Target] backup-zfs-1/encrypted/hamster-zfs/Docker: Checking if filesystem exists
# [Target] CMD    > (zfs list backup-zfs-1/encrypted/hamster-zfs/Docker)
# [Target] backup-zfs-1/encrypted/hamster-zfs/Docker: Getting snapshots
# [Target] CMD    > (zfs list -d 1 -r -t snapshot -H -o name backup-zfs-1/encrypted/hamster-zfs/Docker)
# [Source] hamster-zfs/Docker@zfs-auto-snap_hourly-2024-07-30-1717: common snapshot
# [Target] backup-zfs-1/encrypted/hamster-zfs/Docker: Creating virtual target snapshots
# [Target] backup-zfs-1/encrypted/hamster-zfs/Docker: Getting zfs properties
# [Target] CMD    > (zfs get -H -o property,value -p all backup-zfs-1/encrypted/hamster-zfs/Docker)
# [Source] hamster-zfs/Docker: Getting zfs properties
# [Source] CMD    > (zfs get -H -o property,value -p all hamster-zfs/Docker)
# [Source] hamster-zfs/Docker@backup-zfs-20240730192004: Transfer snapshot to backup-zfs-1/encrypted/hamster-zfs/Docker
  [Target] backup-zfs-1/encrypted/hamster-zfs/Docker@backup-zfs-20240730192004: receiving incremental
# [Source] CMD    > (zfs send -L zfs_autobackup_option_test)
# [Source] STDERR > cannot open 'zfs_autobackup_option_test': dataset does not exist
# [Source] CMD    > (zfs send -e zfs_autobackup_option_test)
# [Source] STDERR > cannot open 'zfs_autobackup_option_test': dataset does not exist
# [Source] CMD    > (zfs send -c zfs_autobackup_option_test)
# [Source] STDERR > cannot open 'zfs_autobackup_option_test': dataset does not exist
# [Target] CMD    > (zfs recv -s zfs_autobackup_option_test)
# [Target] STDERR > cannot receive: failed to read from stream
# [Target] backup-zfs-1/encrypted/hamster-zfs/Docker@backup-zfs-20240730192004: Enabled resume support
# [Target] CMD    > (zfs send -L -v -P -p -i @zfs-auto-snap_hourly-2024-07-30-1717 hamster-zfs/Docker@backup-zfs-20240730192004) | (zfs recv -u -x keylocation -x pbkdf2iters -x keyformat -x encryption -o readonly=on -v -s backup-zfs-1/encrypted/hamster-zfs/Docker)
# [Source] STDERR > incremental hamster-zfs/Docker@zfs-auto-snap_hourly-2024-07-30-1717 hamster-zfs/Docker@backup-zfs-20240730192004    624
# [Source] STDERR > size        624
! [Target] STDERR > cannot receive incremental stream: most recent snapshot of backup-zfs-1/encrypted/hamster-zfs/Docker does not
! [Target] STDERR > match incremental source
! [Target] Command "zfs recv -u -x keylocation -x pbkdf2iters -x keyformat -x encryption -o readonly=on -v -s backup-zfs-1/encrypted/hamster-zfs/Docker" returned exit code 1 (valid codes: [0])
! [Source] hamster-zfs/Docker: FAILED: Last command returned error
  Debug mode, aborting on first error
! Exception: Last command returned error
Traceback (most recent call last):
  File "/root/.local/bin/zfs-autobackup", line 8, in <module>
    sys.exit(cli())
             ^^^^^
  File "/root/.local/pipx/venvs/zfs-autobackup/lib/python3.11/site-packages/zfs_autobackup/ZfsAutobackup.py", line 542, in cli
    failed_datasets=ZfsAutobackup(sys.argv[1:], False).run()
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/root/.local/pipx/venvs/zfs-autobackup/lib/python3.11/site-packages/zfs_autobackup/ZfsAutobackup.py", line 497, in run
    fail_count = self.sync_datasets(
                 ^^^^^^^^^^^^^^^^^^^
  File "/root/.local/pipx/venvs/zfs-autobackup/lib/python3.11/site-packages/zfs_autobackup/ZfsAutobackup.py", line 353, in sync_datasets
    source_dataset.sync_snapshots(target_dataset, show_progress=self.args.progress,
  File "/root/.local/pipx/venvs/zfs-autobackup/lib/python3.11/site-packages/zfs_autobackup/ZfsDataset.py", line 1106, in sync_snapshots
    source_snapshot.transfer_snapshot(target_snapshot, features=features,
  File "/root/.local/pipx/venvs/zfs-autobackup/lib/python3.11/site-packages/zfs_autobackup/ZfsDataset.py", line 734, in transfer_snapshot
    target_snapshot.recv_pipe(pipe, features=features, filter_properties=filter_properties,
  File "/root/.local/pipx/venvs/zfs-autobackup/lib/python3.11/site-packages/zfs_autobackup/ZfsDataset.py", line 677, in recv_pipe
    self.zfs_node.run(cmd, inp=pipe, valid_exitcodes=valid_exitcodes)
  File "/root/.local/pipx/venvs/zfs-autobackup/lib/python3.11/site-packages/zfs_autobackup/ExecuteNode.py", line 177, in run
    raise(ExecuteError("Last command returned error"))
zfs_autobackup.ExecuteNode.ExecuteError: Last command returned error

These are the snapshots created by zfs-autobackup after a couple of failed runs. Obviously, the command keeps creating snapshots on the source despite the error and then seemingly complaining about the snapshots on the target not being in sync with the source:

root@Hamster:~# zfs list -H -o name -t snapshot|grep Docker|grep @backup-zfs
backup-zfs-1/encrypted/hamster-zfs/Docker@backup-zfs-20240730182617
hamster-zfs/Docker@backup-zfs-20240730182617
hamster-zfs/Docker@backup-zfs-20240730184456
hamster-zfs/Docker@backup-zfs-20240730192004
hamster-zfs/Docker@backup-zfs-20240730193251
hamster-zfs/Docker@backup-zfs-20240730194832
derandiunddasbo commented 1 month ago

As I couldn't solve this issue and didn't find any clue, why this error even happens, I finally gave up on the tool and switched to syncoid. Because of that, I couldn't do any more testing or debugging with my setup, if this issue would be worked on. Thus, I'm closing this issue.

psy0rz commented 1 month ago

sorry for my late response.

if someone has this issue: try zfs-autobackup v3.3, it has build in guid-checking and will warn you if a common snapshot is incompatioble.

I suspect in your case, something is creating snapshots on both the source and target sides. (maybe a snapshotter cronjob?)

Then zfs-autobackup will incorrectly assume that the snapshots point to the same data, because they have the same name.