Open abbbi opened 1 year ago
This is the error message when the virtual machine stops unexpectedly when starting the backup
virtnbdbackup -S /tmp/ -d svrServicios --noprogress -q --compress -l auto -o /srv/backup/svrServicios/2023-50 --checkpointdir /srv/backup/.checkpoint/svrServicios -v [2023-12-13 13:01:57] INFO lib common - printVersion [MainThread]: Version: 1.9.51 Arguments: /usr/lib/python-exec/python3.11/virtnbdbackup -S /tmp/ -d svrServicios --noprogress -q --compress -l auto -o /srv/backup/svrServicios/2023-50 --checkpointdir /srv/backup/.checkpoint/svrServicios -v [2023-12-13 13:01:57] INFO root virtnbdbackup - main [MainThread]: Backup level: [auto] [2023-12-13 13:01:57] INFO root virtnbdbackup - main [MainThread]: Compression enabled, level [2] [2023-12-13 13:01:57] INFO root virtnbdbackup - main [MainThread]: Backup mode auto: executing incremental backup. [2023-12-13 13:01:57] INFO root virtnbdbackup - main [MainThread]: Store checkpoints in: [/srv/backup/.checkpoint/svrServicios] [2023-12-13 13:01:57] DEBUG output target - create [MainThread]: Create: /srv/backup/.checkpoint/svrServicios [2023-12-13 13:01:57] DEBUG virt client - _connect [MainThread]: Libvirt URI: [qemu:///system] [2023-12-13 13:01:57] DEBUG virt client - _connect [MainThread]: Hostname: [raptor.chumitar.local] [2023-12-13 13:01:57] DEBUG virt client - _connect [MainThread]: Connect libvirt using open function. [2023-12-13 13:01:57] INFO root virtnbdbackup - main [MainThread]: Libvirt library version: [9004000] [2023-12-13 13:01:57] DEBUG root checkpoint - _hasForeign [MainThread]: Found foreign checkpoint: [virtnbdbackup.0] [2023-12-13 13:01:57] INFO root disktype - Optical [MainThread]: Skipping attached [cdrom] device: [sda]. [2023-12-13 13:01:57] DEBUG virt client - getDomainDisks [MainThread]: Disk [vda]: file notation [2023-12-13 13:01:57] DEBUG virt client - getDomainDisks [MainThread]: Device list: [DomainDisk(target='vda', format='qcow2', filename='svrservicios.qcow2', path='/var/lib/libvirt/images/svrservicios.qcow2', backingstores=[])] [2023-12-13 13:01:57] DEBUG virt client - getDomainInfo [MainThread]: No setting [kernel] found: 'NoneType' object has no attribute 'text' [2023-12-13 13:01:57] DEBUG virt client - getDomainInfo [MainThread]: No setting [initrd] found: 'NoneType' object has no attribute 'text' [2023-12-13 13:01:57] DEBUG virt client - getDomainInfo [MainThread]: Domain Info: [{'loader': '/usr/share/qemu/edk2-x86_64-secure-code.fd', 'nvram': '/var/lib/libvirt/qemu/nvram/plantilla-windows-uefi-clone_VARS.fd'}] [2023-12-13 13:01:57] INFO root virtnbdbackup - main [MainThread]: Backup will save [1] attached disks. [2023-12-13 13:01:57] INFO root virtnbdbackup - main [MainThread]: Concurrent backup processes: [1] [2023-12-13 13:01:57] INFO root checkpoint - create [MainThread]: Loading checkpoints from: [/srv/backup/svrServicios/2023-50/svrServicios.cpt] [2023-12-13 13:01:57] INFO root checkpoint - redefine [MainThread]: Loading checkpoint list from: [/srv/backup/.checkpoint/svrServicios] [2023-12-13 13:01:57] DEBUG root checkpoint - redefine [MainThread]: Loading checkpoint config from: [/srv/backup/.checkpoint/svrServicios/virtnbdbackup.0.xml] [2023-12-13 13:01:57] DEBUG root checkpoint - redefine [MainThread]: Checkpoint [virtnbdbackup.0] found [2023-12-13 13:01:57] INFO root checkpoint - create [MainThread]: Checkpoint handling. [2023-12-13 13:01:57] INFO root checkpoint - create [MainThread]: Next checkpoint id: [1]. [2023-12-13 13:01:57] INFO root checkpoint - create [MainThread]: Parent checkpoint name [virtnbdbackup.0]. [2023-12-13 13:01:57] INFO root checkpoint - create [MainThread]: Using checkpoint name: [virtnbdbackup.1]. [2023-12-13 13:01:57] DEBUG root checkpoint - create [MainThread]: Checkpoint info: [{'name': 'virtnbdbackup.1', 'parent': 'virtnbdbackup.0', 'file': '/srv/backup/svrServicios/2023-50/svrServicios.cpt'}]. [2023-12-13 13:01:57] INFO root virtnbdbackup - main [MainThread]: Local NBD Endpoint socket: [/var/tmp/virtnbdbackup.2245674] [2023-12-13 13:01:57] INFO root virtnbdbackup - main [MainThread]: Temporary scratch file target directory: [/tmp/] [2023-12-13 13:01:57] DEBUG output target - create [MainThread]: Create: /tmp/ [2023-12-13 13:01:57] INFO root virtnbdbackup - startBackupJob [MainThread]: Starting backup job. [2023-12-13 13:01:57] DEBUG virt client - _createBackupXml [MainThread]: Using scratch file: /tmp//backup.2LGXD.vda [2023-12-13 13:01:57] DEBUG root xml - indent [MainThread]:[2023-12-13 13:01:57] DEBUG root xml - indent [MainThread]: virtnbdbackup.0 [2023-12-13 13:01:57] DEBUG fs fs - freeze [MainThread]: Attempting to freeze filesystems. [2023-12-13 13:02:04] INFO fs fs - freeze [MainThread]: Freezed [2] filesystems. [2023-12-13 13:02:04] DEBUG virt client - startBackup [MainThread]: Starting backup job via libvirt API. [2023-12-13 13:02:04] DEBUG virt client - startBackup [MainThread]: Started backup job via libvirt API. [2023-12-13 13:02:04] DEBUG fs fs - thaw [MainThread]: Attempting to thaw filesystems. [2023-12-13 13:02:05] WARNING fs fs - thaw [MainThread]: error interno: End of file from agent socket [2023-12-13 13:02:05] DEBUG root virtnbdbackup - startBackupJob [MainThread]: Backup job started. [2023-12-13 13:02:05] INFO root virtnbdbackup - main [MainThread]: Started backup job with checkpoint, saving information. [2023-12-13 13:02:05] INFO root checkpoint - backup [MainThread]: Saving checkpoint config to: [/srv/backup/.checkpoint/svrServicios/virtnbdbackup.1.xml] [2023-12-13 13:02:06] WARNING root checkpoint - getXml [MainThread]: Failed to get checkpoint info with size information: [No se pudo leer desde el monitor: Conexión reinicializada por la máquina remota] [2023-12-13 13:02:07] INFO root context - get [vda]: Using NBD meta context [qemu:dirty-bitmap:backup-vda] [2023-12-13 13:02:07] INFO nbd client - printVersion [vda]: libnbd version: 1.18.1 [2023-12-13 13:02:07] INFO nbd client - connect [vda]: Waiting until NBD server at [nbd+unix:///vda?socket=/var/tmp/virtnbdbackup.2245674] is up. [2023-12-13 13:02:08] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 0 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:09] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 1 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:10] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 2 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:11] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 3 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:12] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 4 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:13] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 5 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:14] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 6 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:15] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 7 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:16] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 8 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:17] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 9 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:18] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 10 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:19] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 11 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:20] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 12 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:21] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 13 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:22] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 14 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:23] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 15 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:24] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 16 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:25] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 17 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:26] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 18 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:27] INFO nbd client - connect [vda]: Waiting for NBD Server, Retry: 19 [Unable to connect nbd server: nbd_connect_uri: connect: Connection refused (ECONNREFUSED)] [2023-12-13 13:02:28] ERROR root virtnbdbackup - main [MainThread]: Disk backup failed: [NBD endpoint: [Unix(exportName='vda', metaContext='qemu:dirty-bitmap:backup-vda', backupSocket='/var/tmp/virtnbdbackup.2245674', tls=False)]: connection failed: [Timeout during connection to NBD server backend.]] [2023-12-13 13:02:28] INFO root virtnbdbackup - main [MainThread]: Backup jobs finished, stopping backup task. [2023-12-13 13:02:28] WARNING virt client - stopBackup [MainThread]: Failed to stop backup job: [La información solicitada no es válida: El dominio no está ejecutándose] [2023-12-13 13:02:28] INFO root metadata - backupConfig [MainThread]: Saving VM config to: [/srv/backup/svrServicios/2023-50/vmconfig.virtnbdbackup.1.xml] [2023-12-13 13:02:28] INFO root metadata - backupBootConfig [MainThread]: Save additional boot config [loader] to: [/srv/backup/svrServicios/2023-50/edk2-x86_64-secure-code.fd.virtnbdbackup.1] [2023-12-13 13:02:28] INFO root metadata - backupBootConfig [MainThread]: Save additional boot config [nvram] to: [/srv/backup/svrServicios/2023-50/plantilla-windows-uefi-clone_VARS.fd.virtnbdbackup.1] [2023-12-13 13:02:28] DEBUG libvirtnbdbackup.qemu.command command - run [MainThread]: CMD: qemu-img info /var/lib/libvirt/images/svrservicios.qcow2 --output json --force-share [2023-12-13 13:02:28] DEBUG libvirtnbdbackup.qemu.command command - run [MainThread]: Return code: 0 [2023-12-13 13:02:28] DEBUG libvirtnbdbackup.qemu.command command - run [MainThread]: Started [qemu-img] process: [processInfo(pid=2245894, logFile='', err='', out='{\n "children": [\n {\n "name": "file",\n "info": {\n "children": [\n ],\n "virtual-size": 119546511360,\n "filename": "/var/lib/libvirt/images/svrservicios.qcow2",\n "format": "file",\n "actual-size": 119894630400,\n "format-specific": {\n "type": "file",\n "data": {\n }\n },\n "dirty-flag": false\n }\n }\n ],\n "virtual-size": 161061273600,\n "filename": "/var/lib/libvirt/images/svrservicios.qcow2",\n "cluster-size": 65536,\n "format": "qcow2",\n "actual-size": 119894630400,\n "format-specific": {\n "type": "qcow2",\n "data": {\n "compat": "1.1",\n "compression-type": "zlib",\n "lazy-refcounts": false,\n "refcount-bits": 16,\n "corrupt": false,\n "extended-l2": false\n }\n },\n "dirty-flag": false\n}', pidFile='')] [2023-12-13 13:02:28] INFO root metadata - backupDiskInfo [MainThread]: Saved qcow image config to: [/srv/backup/svrServicios/2023-50/vda.virtnbdbackup.1.qcow.json] [2023-12-13 13:02:28] ERROR root virtnbdbackup - main [MainThread]: Error during backup Backup checkpoint virtnbdbackup.1 virtnbdbackup.0
If you want, we can close this task, since the unexpected interruptions (#206 and #207) that happened to me when an error is generated in Python and the job is not canceled have been solved.
Another thing is that in case of error the work is always canceled preventively.
If the Backup fails a new full backup is required which removes all existing checkpoints anyway
Discussion: https://github.com/abbbi/virtnbdbackup/discussions/146
In some cases backup operation might fail even if a checkpoint has been created. In this case, virtnbdbackup could attempt to remove the checkpoint.
If it makes sense to remove the checkpoint depend at which state the backup has failed:
startBackup opertion fails: its safe to remove the checkpoint because no data will be transferred