Incremental backup chain broken after Alma Linux 9 OS update in the VM

[asitemade4u]

Version used
2.17

Describe the bug

• I created a backup chain on an Alma Linux 9.4 VM: first a full backup then incremental ones. All worked perfectly.
• The VMs I am using were all converted to qcow3 format.
• Then there was a kernel update on Alma Linux 9.5 (5.14.0-503.14.1.el9_5.x86_64) and the backup chain now fails with this error message :

�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root job - start [main]:  Starting backup job.�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m fs fs - freeze [main]:  Freezed [2] filesystems.�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m fs fs - thaw [main]:  Thawed [2] filesystems.�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m �[31mERROR�[0m root job - start [main]: �[31m Failed to start backup: [checkpoint inconsistent: missing or broken bitmap 'virtnbdbackup.22' for disk 'vda']�[0m

Expected behavior
One would expect that a relatively minor OS update in the VM would not break down the incremental backup chain.
Instead, that virtnbdbackup would be able to cope with minor changes at the OS level.

Hypervisor information:

• OS: AlmaLinux 9.5
• HV type: cockpit-machines with libvirt-10.5.0-7.el9_5.alma.1.src.rpminstalled

Logfiles:

�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m lib common - printVersion [main]:  Version: 2.17 Arguments: /usr/local/bin/virtnbdbackup -d al9cdr -l inc -o /zfs212/vms-bkp/al9cdr�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Backup level: [inc]�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Libvirt library version: [10005000]�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  NBD library version: [1.20.2]�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root disktype - Optical [main]:  Skipping attached [cdrom] device: [sda].�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Backup will save [1] attached disks.�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Concurrent backup processes: [1]�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root checkpoint - create [main]:  Loading checkpoints from: [/zfs212/vms-bkp/al9cdr/al9cdr.cpt]�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root checkpoint - redefine [main]:  Loading checkpoint list from: [/zfs212/vms-bkp/al9cdr/checkpoints]�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root checkpoint - create [main]:  Checkpoint handling.�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root checkpoint - create [main]:  Next checkpoint id: [23].�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root checkpoint - create [main]:  Parent checkpoint name [virtnbdbackup.22].�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root checkpoint - create [main]:  Using checkpoint name: [virtnbdbackup.23].�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Local NBD Endpoint socket: [/var/tmp/virtnbdbackup.142995]�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Temporary scratch file target directory: [/var/tmp]�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m root job - start [main]:  Starting backup job.�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m fs fs - freeze [main]:  Freezed [2] filesystems.�[0m
�[32m[2024-11-24 05:59:54]�[0m�[34m INFO�[0m fs fs - thaw [main]:  Thawed [2] filesystems.�[0m

Workaround:

1. delete the backup folder
2. remove all virtual image checkpoints one by one
3. recreate the full backup
4. check an incremental backu
5. = 10 mn work for 10 machines = an hour and a half of avoidable chores!

[abbbi]

I dont see how virtnbdbackup is at fault here, did the alma update do changes on the qcow images?

Have the qcow images been converted during said update? There is an option to keep bitmaps during conversion, with the bitmaps missing there is no way the Backup until can continue a chain. You should investigate the reason why the bitmaps are missing now. Most probably they have been converted without the option to keep existing bitmaps.

handling these edge situations is non trivial and it’s better to error out instead of risking data loss.

[asitemade4u]

@abbbi , thanks for your answer.

• No, qcow2 images were NOT converted during OS update. I manually converted them before backing them up in order to take full advantage of the capabilities of virtnbdbackup. Which proved true as I enjoyed it working before the OS update.
• Here is an example of the checkpoints within the above mentioned VM, after the OS update:

virsh checkpoint-list al9cdr
 Name               Creation Time
-----------------------------------------------
 virtnbdbackup.0    2024-11-22 13:56:07 -0500
 virtnbdbackup.1    2024-11-22 13:56:25 -0500
 virtnbdbackup.10   2024-11-22 22:14:06 -0500
 virtnbdbackup.11   2024-11-22 22:58:26 -0500
 virtnbdbackup.12   2024-11-22 23:07:56 -0500
 virtnbdbackup.13   2024-11-22 23:34:50 -0500
 virtnbdbackup.14   2024-11-23 00:10:19 -0500
 virtnbdbackup.15   2024-11-23 00:16:48 -0500
 virtnbdbackup.16   2024-11-23 07:47:03 -0500
 virtnbdbackup.17   2024-11-23 10:34:18 -0500
 virtnbdbackup.18   2024-11-23 10:42:35 -0500
 virtnbdbackup.19   2024-11-23 10:57:15 -0500
 virtnbdbackup.2    2024-11-22 14:32:08 -0500
 virtnbdbackup.20   2024-11-23 11:13:35 -0500
 virtnbdbackup.21   2024-11-23 11:59:53 -0500
 virtnbdbackup.22   2024-11-23 14:59:53 -0500
 virtnbdbackup.3    2024-11-22 15:15:33 -0500
 virtnbdbackup.4    2024-11-22 15:25:19 -0500
 virtnbdbackup.5    2024-11-22 15:37:00 -0500
 virtnbdbackup.6    2024-11-22 16:04:40 -0500
 virtnbdbackup.7    2024-11-22 16:38:02 -0500
 virtnbdbackup.8    2024-11-22 16:52:16 -0500
 virtnbdbackup.9    2024-11-22 21:49:22 -0500

As you can see, ALL checkpoints are still present in the VM.

[abbbi]

The checkpoints are not the bitmaps, the bitmaps for a checkpoint are saved in the qcow images directly

in your case the checkpoints are existing bit the bitmaps are missing

[asitemade4u]

As you can also see, it would be a lot of work to delete the checkpoints one by one in all machines.
I found out you had developed a tool for that purpose, vircpt. Unfortunately I was unable to install it and just created a bug report about it.

[asitemade4u]

in your case the checkpoints are existing bit the bitmaps are missing

How would that even happen??
The backup destination is a ZFS pool, and as such super-secure.

[abbbi]

In a situation where the checkpoints exist but the bitmaps are missing there is something seriously wrong, I could remove the checkpoints forcefully in this case ( during full backup ) but diring inc or diff backups there is no way to recover gracefully and continue the backup chain

[abbbi]

in your case the checkpoints are existing bit the bitmaps are missing

How would that even happen?? The backup destination is a ZFS pool, and as such super-secure.

Something must have altered the qcow images

[asitemade4u]

To help you figure it out, here is the log of the last successful incremental backup on the aforementioned VM, al9cdr:

# Job ID: jm3ulgu9x06
# Event Title: al9cdr
# Hostname: g10
# Date/Time: 2024/11/23 14:59:53 (GMT-5)

�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m lib common - printVersion [main]:  Version: 2.17 Arguments: /usr/local/bin/virtnbdbackup -d al9cdr -l inc -o /zfs212/vms-bkp/al9cdr�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Backup level: [inc]�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Libvirt library version: [10005000]�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  NBD library version: [1.20.2]�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root disktype - Optical [main]:  Skipping attached [cdrom] device: [sda].�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Backup will save [1] attached disks.�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Concurrent backup processes: [1]�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root checkpoint - create [main]:  Loading checkpoints from: [/zfs212/vms-bkp/al9cdr/al9cdr.cpt]�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root checkpoint - redefine [main]:  Loading checkpoint list from: [/zfs212/vms-bkp/al9cdr/checkpoints]�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root checkpoint - create [main]:  Checkpoint handling.�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root checkpoint - create [main]:  Next checkpoint id: [22].�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root checkpoint - create [main]:  Parent checkpoint name [virtnbdbackup.21].�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root checkpoint - create [main]:  Using checkpoint name: [virtnbdbackup.22].�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Local NBD Endpoint socket: [/var/tmp/virtnbdbackup.728236]�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Temporary scratch file target directory: [/var/tmp]�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root job - start [main]:  Starting backup job.�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m fs fs - freeze [main]:  Freezed [2] filesystems.�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m fs fs - thaw [main]:  Thawed [2] filesystems.�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Started backup job with checkpoint, saving information.�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m root checkpoint - backup [main]:  Saving checkpoint config to: [/zfs212/vms-bkp/al9cdr/checkpoints/virtnbdbackup.22.xml]�[0m
�[32m[2024-11-23 14:59:53]�[0m�[34m INFO�[0m nbd client - connect [vda]:  Waiting until NBD server at [nbd+unix:///vda?socket=/var/tmp/virtnbdbackup.728236] is up.�[0m
�[32m[2024-11-23 14:59:54]�[0m�[34m INFO�[0m nbd client - connect [vda]:  Connection to NBD backend succeeded.�[0m
�[32m[2024-11-23 14:59:54]�[0m�[34m INFO�[0m root disk - backup [vda]:  Got 595 extents to backup.�[0m
�[32m[2024-11-23 14:59:54]�[0m�[34m INFO�[0m root disk - backup [vda]:  53687091200 bytes disk size�[0m
�[32m[2024-11-23 14:59:54]�[0m�[34m INFO�[0m root disk - backup [vda]:  48365568 bytes of data extents to backup�[0m
�[32m[2024-11-23 14:59:54]�[0m�[34m INFO�[0m root target - get [vda]:  Write data to target file: [/zfs212/vms-bkp/al9cdr/vda.inc.virtnbdbackup.22.data.partial].�[0m
�[32m[2024-11-23 14:59:54]�[0m�[34m INFO�[0m root disk - backup [vda]:  Creating thin provisioned stream backup image�[0m

saving disk vda:   0%|          | 0.00/48.4M [00:00<?, ?B/s]
saving disk vda:  64%|██████▍   | 31.1M/48.4M [00:00<00:00, 279MB/s]
                                                                    
�[32m[2024-11-23 14:59:54]�[0m�[34m INFO�[0m root metadata - backupChecksum [vda]:  Checksum for file: [/zfs212/vms-bkp/al9cdr/vda.inc.virtnbdbackup.22.data]:[3483389754]�[0m
�[32m[2024-11-23 14:59:54]�[0m�[34m INFO�[0m root metadata - backupChecksum [vda]:  Saving checksum to: [/zfs212/vms-bkp/al9cdr/vda.inc.virtnbdbackup.22.data.chksum]�[0m
�[32m[2024-11-23 14:59:54]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Backup jobs finished, stopping backup task.�[0m
�[32m[2024-11-23 14:59:54]�[0m�[34m INFO�[0m root metadata - backupConfig [main]:  Saving VM config to: [/zfs212/vms-bkp/al9cdr/vmconfig.virtnbdbackup.22.xml]�[0m
�[32m[2024-11-23 14:59:54]�[0m�[34m INFO�[0m root metadata - backupDiskInfo [main]:  Saved qcow image config to: [/zfs212/vms-bkp/al9cdr/vda.virtnbdbackup.22.qcow.json]�[0m
�[32m[2024-11-23 14:59:54]�[0m�[34m INFO�[0m root metadata - backupAutoStart [main]:  Autostart setting configured for virtual machine.�[0m
�[32m[2024-11-23 14:59:54]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Total saved disk data: [46.1MB]�[0m
�[32m[2024-11-23 14:59:54]�[0m�[34m INFO�[0m root virtnbdbackup - main [main]:  Finished successfully�[0m

# Job completed successfully at 2024/11/23 14:59:54 (GMT-5).
# End of log.

[asitemade4u]

Something must have altered the qcow images

I can emphatically tell you that is NOT the case.
Except, of course, for the OS update I performed on them.

[abbbi]

Something must have altered the qcow images

I can emphatically tell you that is NOT the case. Except, of course, for the OS update I performed on them.

The Backup util does not touch the qcow images for the bitmaps in any way it all goes through the libvirt api.

If libvirt is removing a checkpoint it also deletes the bitmap. This usually only happens during a full backup.

[asitemade4u]

I agree but there was NO full backup in between.
I am using a script automating tool (Cronicle) to launch the backup scripts. The whole point is precisely NOT to manually interfere in incremental backups once the full (manual) backup has been performed.

For reference, here is the incremental script for the al9cdr VM:

vm=al9cdr && virtnbdbackup -d $vm -l inc -o /zfs212/vms-bkp/$vm

[abbbi]

Like said, you should check what has reset bitmap information in the qcow images, check with qemu-img info util if they are all gone or just some of them. I still don’t see how this issue is caused by the backup util

Maybe also check alma upgrade and/or libvirt logs

[asitemade4u]

Thank you for the suggestion.
So I turned off the VM, cd to the image folder and did qemu-img info al9cdr.qcow2.
Here is the result:

image: al9cdr.qcow2
file format: qcow2
virtual size: 50 GiB (53687091200 bytes)
disk size: 24.5 GiB
cluster_size: 65536
Format specific information:
    compat: 1.1
    compression type: zlib
    lazy refcounts: false
    bitmaps:
        [0]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.13
            granularity: 65536
        [1]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.12
            granularity: 65536
        [2]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.11
            granularity: 65536
        [3]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.10
            granularity: 65536
        [4]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.9
            granularity: 65536
        [5]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.8
            granularity: 65536
        [6]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.7
            granularity: 65536
        [7]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.6
            granularity: 65536
        [8]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.5
            granularity: 65536
        [9]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.4
            granularity: 65536
        [10]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.3
            granularity: 65536
        [11]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.2
            granularity: 65536
        [12]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.1
            granularity: 65536
        [13]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.0
            granularity: 65536
        [14]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.14
            granularity: 65536
        [15]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.18
            granularity: 65536
        [16]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.17
            granularity: 65536
        [17]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.16
            granularity: 65536
        [18]:
            flags:
                [0]: in-use
                [1]: auto
            name: virtnbdbackup.15
            granularity: 65536
    refcount bits: 16
    corrupt: false
    extended l2: false
Child node '/file':
    filename: al9cdr.qcow2
    protocol type: file
    file length: 24.5 GiB (26292322304 bytes)
    disk size: 24.5 GiB
    Format specific information:
        extent size hint: 1048576

[asitemade4u]

At one point of the discussion, you mentioned a 22 bitmap.
As you can see, the highest bitmap saved in the image is 18.

[abbbi]

Yes that’s the reason for the issue
How that can Happen: I don’t know

the bitmaps must have existed at some point

Check libvirtd logs (on the hypervisor) for what happened during backup 22