Backups are failing (sometimes)

[vanlueckn]

Hello all,

I create a backup of a VM every 30 minutes. Since a few hours the backups fail from time to time (but not always either).

There is enough disk space available. This is the task log:

INFO: starting new backup job: vzdump 100 --mode snapshot --mailto censored@censored.de --node prox1 --mailnotification failure --compress zstd --storage storagebox --quiet 1
INFO: Starting Backup of VM 100 (qemu)
INFO: Backup started at 2022-05-06 15:30:02
INFO: status = running
INFO: VM Name: cp.k8s.stoffi.xyz
INFO: include disk 'scsi0' 'local-zfs:vm-100-disk-0' 30G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating vzdump archive '/mnt/pve/storagebox/dump/vzdump-qemu-100-2022_05_06-15_30_02.vma.zst'
INFO: issuing guest-agent 'fs-freeze' command
INFO: issuing guest-agent 'fs-thaw' command
INFO: started backup task '5e82d5eb-88d7-4ece-8de4-33530342b07e'
INFO: resuming VM again
INFO:   4% (1.3 GiB of 30.0 GiB) in 3s, read: 450.7 MiB/s, write: 239.3 MiB/s
INFO:   9% (2.8 GiB of 30.0 GiB) in 6s, read: 495.4 MiB/s, write: 229.6 MiB/s
INFO:  11% (3.5 GiB of 30.0 GiB) in 9s, read: 261.0 MiB/s, write: 242.3 MiB/s
INFO:  14% (4.3 GiB of 30.0 GiB) in 12s, read: 271.9 MiB/s, write: 243.0 MiB/s
INFO:  16% (5.1 GiB of 30.0 GiB) in 15s, read: 246.5 MiB/s, write: 243.7 MiB/s
INFO:  19% (5.9 GiB of 30.0 GiB) in 18s, read: 292.4 MiB/s, write: 268.5 MiB/s
INFO:  22% (6.9 GiB of 30.0 GiB) in 21s, read: 321.4 MiB/s, write: 256.3 MiB/s
INFO:  34% (10.4 GiB of 30.0 GiB) in 24s, read: 1.2 GiB/s, write: 184.7 MiB/s
INFO:  62% (18.8 GiB of 30.0 GiB) in 27s, read: 2.8 GiB/s, write: 44.2 MiB/s
INFO:  85% (25.5 GiB of 30.0 GiB) in 30s, read: 2.3 GiB/s, write: 4.0 KiB/s
zstd: /*stdout*\: Input/output error
INFO: 100% (30.0 GiB of 30.0 GiB) in 32s, read: 2.2 GiB/s, write: 12.0 KiB/s
INFO: backup is sparse: 24.28 GiB (80%) total zero data
INFO: transferred 30.00 GiB in 32 seconds (960.0 MiB/s)
ERROR: Backup of VM 100 failed - zstd --rsyncable --threads=1 failed - wrong exit status 1
INFO: Failed at 2022-05-06 15:30:35
INFO: Backup job finished with errors
TASK ERROR: job errors

 

[nosoop4u]

Did you find a resolution to this issue?

I am getting the exact same Backup of VM ### failed - zstd --resyncable --threads=1 failed - wrong exit status 1 error...

This is Proxmox 7.4-3 backing up a Windows 11 VM (offline/shut down) from LVM storage to a CIFS share. Gets all the way to the end and then fails.

2023-07-15 01:59:48 INFO: Starting Backup of VM 101 (qemu)
2023-07-15 01:59:48 INFO: status = stopped
2023-07-15 01:59:48 INFO: backup mode: stop
2023-07-15 01:59:48 INFO: ionice priority: 7
2023-07-15 01:59:48 INFO: VM Name: XXXXX
2023-07-15 01:59:48 INFO: include disk 'virtio0' 'vgdata1:vm-101-disk-1' 64G
2023-07-15 01:59:48 INFO: include disk 'efidisk0' 'vgdata1:vm-101-disk-0' 4M
2023-07-15 01:59:48 INFO: include disk 'tpmstate0' 'vgdata1:vm-101-disk-2' 4M
2023-07-15 01:59:51 INFO: creating vzdump archive '/mnt/pve/synobkp/dump/vzdump-qemu-101-2023_07_15-01_59_48.vma.zst'
2023-07-15 01:59:51 INFO: starting kvm to execute backup task
2023-07-15 01:59:55 INFO: attaching TPM drive to QEMU for backup
2023-07-15 01:59:55 INFO: started backup task '5af3f020-274a-4395-a923-1a8ffd3bfeaf'
2023-07-15 01:59:58 INFO:   0% (0.0 B of 64.0 GiB) in 3s, read: 0 B/s, write: 0 B/s
2023-07-15 02:06:04 INFO:   1% (658.0 MiB of 64.0 GiB) in 6m 9s, read: 1.8 MiB/s, write: 1.6 MiB/s
2023-07-15 02:12:07 INFO:   2% (1.3 GiB of 64.0 GiB) in 12m 12s, read: 1.8 MiB/s, write: 1.8 MiB/s
2023-07-15 02:18:08 INFO:   3% (1.9 GiB of 64.0 GiB) in 18m 13s, read: 1.8 MiB/s, write: 1.8 MiB/s
. . .

2023-07-15 11:47:22 INFO:  97% (62.1 GiB of 64.0 GiB) in 9h 47m 27s, read: 1.8 MiB/s, write: 11.0 B/s
2023-07-15 11:53:23 INFO:  98% (62.7 GiB of 64.0 GiB) in 9h 53m 28s, read: 1.8 MiB/s, write: 280.8 KiB/s
2023-07-15 11:59:30 INFO:  99% (63.4 GiB of 64.0 GiB) in 9h 59m 35s, read: 1.8 MiB/s, write: 1.6 MiB/s
2023-07-15 12:05:34 INFO: 100% (64.0 GiB of 64.0 GiB) in 10h 5m 39s, read: 1.8 MiB/s, write: 1.5 MiB/s
2023-07-15 12:05:34 INFO: backup is sparse: 18.09 GiB (28%) total zero data
2023-07-15 12:05:34 INFO: transferred 64.00 GiB in 36339 seconds (1.8 MiB/s)
2023-07-15 12:05:51 INFO: stopping kvm after backup task
2023-07-15 12:05:56 ERROR: Backup of VM 101 failed - zstd --rsyncable --threads=1 failed - wrong exit status 1

I can rename the resulting backup file that gets deleted so it looks like a valid backup, but the restore fails as well:

restore vma archive: zstd -q -d -c /mnt/pve/synobkp/dump/vzdump-qemu-101-2023_07_15-01_59_48.vma.zst | vma extract -v -r /var/tmp/vzdumptmp28413.fifo - /var/tmp/vzdumptmp28413
CFG: size: 830 name: qemu-server.conf
DEV: dev_id=1 size: 540672 devname: drive-efidisk0
DEV: dev_id=2 size: 4194304 devname: drive-tpmstate0-backup
DEV: dev_id=3 size: 68719476736 devname: drive-virtio0
CTIME: Sat Jul 15 02:00:02 2023
  Rounding up size to full physical extent 4.00 MiB
  Logical volume "vm-101-disk-0" created.
new volume ID is 'nvme1:vm-101-disk-0'
  Logical volume "vm-101-disk-1" created.
new volume ID is 'nvme1:vm-101-disk-1'
  Logical volume "vm-101-disk-2" created.
new volume ID is 'nvme1:vm-101-disk-2'
map 'drive-efidisk0' to '/dev/nvme1/vm-101-disk-0' (write zeros = 0)
map 'drive-tpmstate0-backup' to '/dev/nvme1/vm-101-disk-1' (write zeros = 0)
map 'drive-virtio0' to '/dev/nvme1/vm-101-disk-2' (write zeros = 0)
progress 1% (read 687276032 bytes, duration 4 sec)
progress 2% (read 1374486528 bytes, duration 7 sec)
progress 3% (read 2061762560 bytes, duration 11 sec)
. . .
progress 92% (read 63226314752 bytes, duration 316 sec)
progress 93% (read 63913525248 bytes, duration 316 sec)
progress 94% (read 64600801280 bytes, duration 318 sec)
_15-01_59_48.vma.zst : Decoding error (36) : Data corruption detected 
vma: restore failed - short vma extent (3635896 < 3801600)
/bin/bash: line 1: 28424 Exit 1                  zstd -q -d -c /mnt/pve/synobkp/dump/vzdump-qemu-101-2023_07_15-01_59_48.vma.zst
     28425 Trace/breakpoint trap   | vma extract -v -r /var/tmp/vzdumptmp28413.fifo - /var/tmp/vzdumptmp28413
  Logical volume "vm-101-disk-0" successfully removed.
temporary volume 'nvme1:vm-101-disk-0' sucessfuly removed
  Logical volume "vm-101-disk-1" successfully removed.
temporary volume 'nvme1:vm-101-disk-1' sucessfuly removed
  Logical volume "vm-101-disk-2" successfully removed.
temporary volume 'nvme1:vm-101-disk-2' sucessfuly removed
no lock found trying to remove 'create'  lock
error before or during data restore, some or all disks were not completely restored. VM 101 state is NOT cleaned up.
TASK ERROR: command 'set -o pipefail && zstd -q -d -c /mnt/pve/synobkp/dump/vzdump-qemu-101-2023_07_15-01_59_48.vma.zst | vma extract -v -r /var/tmp/vzdumptmp28413.fifo - /var/tmp/vzdumptmp28413' failed: exit code 133