Failed: command error: no previous backup found, cannot do incremental backup

[vnngoanhtuan]

Dear All,

I have the issues on PBS, can you help?

proxmox-backup-manager versions
proxmox-backup-server 2.1.5-1 running version: 2.1.5


pveversion -v
proxmox-ve: 7.1-1 (running kernel: 5.11.22-4-pve)
pve-manager: 7.1-10 (running version: 7.1-10/6ddebafe)
pve-kernel-helper: 7.1-12
pve-kernel-5.13: 7.1-7
pve-kernel-5.11: 7.0-10
pve-kernel-5.13.19-4-pve: 5.13.19-9
pve-kernel-5.11.22-7-pve: 5.11.22-12
pve-kernel-5.11.22-5-pve: 5.11.22-10
pve-kernel-5.11.22-4-pve: 5.11.22-9
ceph-fuse: 15.2.14-pve1
corosync: 3.1.5-pve2
criu: 3.15-1+pve-1
glusterfs-client: 9.2-1
ifupdown2: 3.1.0-1+pmx3
ksm-control-daemon: 1.4-1
libjs-extjs: 7.0.0-1
libknet1: 1.22-pve2
libproxmox-acme-perl: 1.4.1
libproxmox-backup-qemu0: 1.2.0-1
libpve-access-control: 7.1-6
libpve-apiclient-perl: 3.2-1
libpve-common-perl: 7.1-3
libpve-guest-common-perl: 4.1-1
libpve-http-server-perl: 4.1-1
libpve-storage-perl: 7.1-1
libspice-server1: 0.14.3-2.1
lvm2: 2.03.11-2.1
lxc-pve: 4.0.11-1
lxcfs: 4.0.11-pve1
novnc-pve: 1.3.0-2
proxmox-backup-client: 2.1.5-1
proxmox-backup-file-restore: 2.1.5-1
proxmox-mini-journalreader: 1.3-1
proxmox-widget-toolkit: 3.4-6
pve-cluster: 7.1-3
pve-container: 4.1-4
pve-docs: 7.1-2
pve-edk2-firmware: 3.20210831-2
pve-firewall: 4.2-5
pve-firmware: 3.3-5
pve-ha-manager: 3.3-3
pve-i18n: 2.6-2
pve-qemu-kvm: 6.1.1-2
pve-xtermjs: 4.16.0-1
qemu-server: 7.1-4
smartmontools: 7.2-1
spiceterm: 3.2-2
swtpm: 0.7.0~rc1+2
vncterm: 1.7-1
zfsutils-linux: 2.1.2-pve1

On PBS:

2022-02-22T14:11:24+07:00: starting new backup on datastore 'PBS-xxx-xxx': "vm/xxx/2022-02-22T07:11:24Z"
2022-02-22T14:11:24+07:00: download 'index.json.blob' from previous backup.
2022-02-22T14:11:24+07:00: backup ended and finish failed: backup ended but finished flag is not set.
2022-02-22T14:11:24+07:00: removing unfinished backup
2022-02-22T14:11:24+07:00: TASK ERROR: backup ended but finished flag is not set.

On ProxmoxVE:

()
INFO: starting new backup job: vzdump xxx --node ProxmoxXXX --storage PBS-xxx-xxx --mode snapshot --all 0 --mailto xxx@xxx.xxx.yyy --mailnotification always
INFO: Starting Backup of VM xxx (qemu)
INFO: Backup started at 2022-02-22 14:11:24
INFO: status = running
INFO: VM Name: XXX.xxx.xxx.yyy
INFO: include disk 'sata0' 'local-lvm:vm-xxx-disk-0' 80G
INFO: backup mode: snapshot
INFO: ionice priority: 7
INFO: creating Proxmox Backup Server archive 'vm/xxx/2022-02-22T07:11:24Z'
ERROR: VM xxx qmp command 'backup' failed - backup register image failed: command error: no previous backup found, cannot do incremental backup
INFO: aborting backup job
INFO: resuming VM again
ERROR: Backup of VM xxx failed - VM xxx qmp command 'backup' failed - backup register image failed: command error: no previous backup found, cannot do incremental backup
INFO: Failed at 2022-02-22 14:11:24
INFO: Backup job finished with errors
TASK ERROR: job errors

Thanks,
Tuan Ngo

 

[dcsapak]

was that a one time issue or does it happen everytime you try a backup? was a prune job running at the same time? (or did someone manually delete the backup group on the source?)

 

[vnngoanhtuan]

Dear dcsapak,

Thank for your reply.

- was that a one time issue or does it happen everytime you try a backup? : This happened for everytime I try a backup include manual backup.
- was a prune job running at the same time? (or did someone manually delete the backup group on the source?) : The issues was happen when we upgarded Proxmox VE from 7.0.13 to 7.1.10, all backup were failed.

- Just deleted a group and try backup again. The first backup works like a charm, the second one break with the same error.

- Shutdown and start VM, it work for first time others are still issues.

Do you any suggest to fix the issues?

Thanks,
Tuan Ngo

 

[dcsapak]

ok,

what does

qm status ID --verbose

say?

 

[vnngoanhtuan]

Dear dcsapak,

Thanks for your reply.

Please see as below:

- I saw the : running-qemu: 6.1.1, this is reason of issues?

qm status xxx --verbose
balloon: 4294967296
ballooninfo:
        actual: 4294967296
        free_mem: 3345244160
        last_update: 1645519388
        major_page_faults: 762
        max_mem: 4294967296
        mem_swapped_in: 0
        mem_swapped_out: 0
        minor_page_faults: 371458
        total_mem: 3917701120
blockstat:
        ide2:
                account_failed: 0
                account_invalid: 0
                failed_flush_operations: 0
                failed_rd_operations: 0
                failed_unmap_operations: 0
                failed_wr_operations: 0
                flush_operations: 0
                flush_total_time_ns: 0
                idle_time_ns: 1541791288588
                invalid_flush_operations: 0
                invalid_rd_operations: 0
                invalid_unmap_operations: 0
                invalid_wr_operations: 0
                rd_bytes: 158
                rd_merged: 0
                rd_operations: 5
                rd_total_time_ns: 80905
                timed_stats:
                unmap_bytes: 0
                unmap_merged: 0
                unmap_operations: 0
                unmap_total_time_ns: 0
                wr_bytes: 0
                wr_highest_offset: 0
                wr_merged: 0
                wr_operations: 0
                wr_total_time_ns: 0
        scsi0:
                account_failed: 1
                account_invalid: 1
                failed_flush_operations: 0
                failed_rd_operations: 0
                failed_unmap_operations: 0
                failed_wr_operations: 0
                flush_operations: 233
                flush_total_time_ns: 27084405
                idle_time_ns: 2092360660
                invalid_flush_operations: 0
                invalid_rd_operations: 0
                invalid_unmap_operations: 0
                invalid_wr_operations: 0
                rd_bytes: 220550144
                rd_merged: 0
                rd_operations: 6555
                rd_total_time_ns: 1093353616
                timed_stats:
                unmap_bytes: 0
                unmap_merged: 0
                unmap_operations: 0
                unmap_total_time_ns: 0
                wr_bytes: 39806976
                wr_highest_offset: 35523608576
                wr_merged: 0
                wr_operations: 906
                wr_total_time_ns: 25189102011
cpus: 4
disk: 0
diskread: 220550302
diskwrite: 39806976
freemem: 3345244160
maxdisk: 42949672960
maxmem: 4294967296
mem: 572456960
name: xxx.xxx.xxx.yyy
netin: 12155248
netout: 783781
nics:
        tap6140i0:
                netin: 12155248
                netout: 783781
pid: 3256197
proxmox-support:
        pbs-dirty-bitmap: 1
        pbs-dirty-bitmap-migration: 1
        pbs-dirty-bitmap-savevm: 1
        pbs-library-version: 1.2.0 (6e555bc73a7dcfb4d0b47355b958afd101ad27b5)
        pbs-masterkey: 1
        query-bitmap-info: 1
qmpstatus: running
running-machine: pc-i440fx-6.1+pve0
running-qemu: 6.1.1
status: running
uptime: 1557
vmid: xxx

Thanks,
Tuan Ngo

 

[dcsapak]

ok can you post the vm config,
the syslog/journal of the pbs while trying to backup
and the output of

ls -l /path/to/datastore/vm/<ID>/<Last-snapshot>/

?

i only could reproduce that when some '.fidx' file was missing in the datastore, but that should never happen (i had to manually delete one to trigger the same error)

 

[vnngoanhtuan]

Dear dcsapak,

Thanks for your reply.

- I think stop the ProxmoxVE and start again, this backup will work well but not good solution as many important services are running on this.

VM Configure:

bootdisk: scsi0
cores: 2
ide2: none,media=cdrom
memory: 4096
name: xxx.xxx.xxx.yyy
net0: e1000=xx:xx:xx:yy:yy:yy,bridge=xxyy,firewall=1
numa: 0
ostype: l26
scsi0: zzz-xxx:vm-xxx-disk-0,size=40G
scsihw: virtio-scsi-pci
smbios1: uuid=69e34f71-0026-44d6-9409-ce61225f5d96
sockets: 2
vmgenid: 9136feac-7b88-40cd-b84e-041c90da5b4d

---
ls -lha /xxyyzz/vm/xxx/
total 56K
drwxr-xr-x 13 backup backup 4.0K Feb 22 15:34 .
drwxr-xr-x 93 backup backup 4.0K Feb 22 14:42 ..
drwxr-xr-x  2 backup backup 4.0K Feb 21 23:57 2021-10-23T07:00:28Z
drwxr-xr-x  2 backup backup 4.0K Feb 16 17:25 2021-11-27T07:00:19Z
drwxr-xr-x  2 backup backup 4.0K Feb 19 23:32 2021-12-25T07:00:24Z
drwxr-xr-x  2 backup backup 4.0K Feb 19 00:09 2022-01-01T07:00:21Z
drwxr-xr-x  2 backup backup 4.0K Feb 19 00:09 2022-01-08T07:00:19Z
drwxr-xr-x  2 backup backup 4.0K Feb 16 23:30 2022-01-15T09:00:23Z
drwxr-xr-x  2 backup backup 4.0K Feb 15 23:55 2022-01-22T07:00:19Z
drwxr-xr-x  2 backup backup 4.0K Feb 14 23:55 2022-01-29T07:00:18Z
drwxr-xr-x  2 backup backup 4.0K Feb 22 11:12 2022-02-05T07:00:25Z
drwxr-xr-x  2 backup backup 4.0K Feb 20 22:29 2022-02-12T07:00:21Z
drwxr-xr-x  2 backup backup 4.0K Feb 22 15:19 2022-02-22T08:18:16Z
-rw-r--r--  1 backup backup    9 Mar 27  2021 owner

ls -lha /xxyyzz/vm/xxx/2022-02-22T08:18:16Z/
total 344K
drwxr-xr-x  2 backup backup 4.0K Feb 22 15:19 .
drwxr-xr-x 13 backup backup 4.0K Feb 22 15:34 ..
-rw-r--r--  1 backup backup  933 Feb 22 15:19 client.log.blob
-rw-r--r--  1 backup backup 324K Feb 22 15:19 drive-scsi0.img.fidx
-rw-r--r--  1 backup backup  401 Feb 22 15:19 index.json.blob
-rw-r--r--  1 backup backup  499 Feb 22 15:18 qemu-server.conf.blob

ls -lha /xxyyzz/vm/xxx/2022-02-12T07:00:21Z/
total 344K
drwxr-xr-x  2 backup backup 4.0K Feb 20 22:29 .
drwxr-xr-x 13 backup backup 4.0K Feb 22 15:34 ..
-rw-r--r--  1 backup backup  570 Feb 12 14:00 client.log.blob
-rw-r--r--  1 backup backup 324K Feb 12 14:00 drive-scsi0.img.fidx
-rw-r--r--  1 backup backup  517 Feb 20 22:29 index.json.blob
-rw-r--r--  1 backup backup  499 Feb 12 14:00 qemu-server.conf.blob

=====
log error from syslog:

Feb 22 16:22:44 xxyyzz proxmox-backup-proxy[941715]: starting new backup on datastore 'xxyyzz/': "vm/xxx/2022-02-22T09:22:43Z"
Feb 22 16:22:44 xxyyzz proxmox-backup-proxy[941715]: download 'index.json.blob' from previous backup.
Feb 22 16:22:44 xxyyzz proxmox-backup-proxy[941715]: backup ended and finish failed: backup ended but finished flag is not set.
Feb 22 16:22:44 xxyyzz proxmox-backup-proxy[941715]: removing unfinished backup
Feb 22 16:22:44 xxyyzz proxmox-backup-proxy[941715]: removing backup snapshot "/xxyyzz//vm/xxx/2022-02-22T09:22:43Z"
Feb 22 16:22:44 xxyyzz proxmox-backup-proxy[941715]: TASK ERROR: backup ended but finished flag is not set.

Thanks,
Tuan Ngo

 

[dcsapak]

hmm... does

proxmox-backup-debug inspect file /path/to/datastore/vm/<TIME>/drive-scsi0.img.fidx

work? (this might print a lot !)
does it exit with an error?

 

[vnngoanhtuan]

Dear dcspak,

Thanks for your reply.

The status of this command is ok and no issues ;( with: does it exit with an error? -- no error anymore.

- I think do not any issues on PBS, can you give your idea on PVE? clean cache issues?

proxmox-backup-debug inspect file 2022-02-22T10:49:17Z/drive-scsi0.img.fidx
size: 42949672960
creation time: Tue Feb 22 17:49:18 2022
chunks:
  "3b5c38ce33fa0995136ef11a6c878d4ac2a322189e1dfcf64806c62ae7797273"
  "07cf8097f29d3cab296eb384967eb7066551ce7ff1839b8fb78ef919ee0ca87a"
  "72c7d5f084c5f65a7558bb8d1b431bdd6ca79a0eada3d920369d7335fb1030ba"
  "8b1d36febb019156d9d1bbe425f3f1c1fece48c6e648bd6788f0058526b0428c"
  "617354ce0f6be1e63cb5d31b41817a11c5a457e124bf72edad68599d4449d8c7"
  "52468087931f4e8d6b4cd67ca9b48c2bc9a854f8eb6e4c2223f0033ff98f3860"
  ....
  ....
  ....
  ....

Thanks,
Tuan Ngo

 

[dcsapak]

- I think do not any issues on PBS, can you give your idea on PVE? clean cache issues?

no there is no cache for that. the issue seems to be that the pve wants to do an incremental backup (because there is a previous backup) but cannot download the '.fidx' file for the disk which contains the chunklist.
as i said i only could reproduce the error if i manually deleted one of the .fidx files (which is obviously not happening in your case since they are still there and readable)

does it exit with an error? -- no error anymore

what do you mean anymore? does the backup work now?

 

[vnngoanhtuan]

Dear dcsapak,

Thank your very much for your support. I have analysis the log on PVE and found issue on /tmp folder did not write anything, other folders are still Ok. I will schedule to reboot PVE and hope that the issue will be solved.

Thank your very much again.

Thanks,
Tuan Ngo