Error during backup of the virtual machine and it stops

[inode64]

Version used 2.13

Describe the bug I encountered an issue while running a backup on a virtual machine using virtnbdbackup. During the backup process, the virtual machine unexpectedly stops with this error.

Hypervisor information:

• OS: Gentoo
• HV type libvirtd 10.3.0

Logfiles:

[2024-08-22 10:09:41] INFO lib common - printVersion [main]: Version: 2.13 Arguments: ./virtnbdbackup -d test --nocolor --noprogress -q --raw --compress -l copy -o /tmp/virt/9/
[2024-08-22 10:09:41] INFO root virtnbdbackup - main [main]: Backup level: [copy]
[2024-08-22 10:09:41] INFO root virtnbdbackup - main [main]: Compression enabled, level [2]
[2024-08-22 10:09:41] INFO root virtnbdbackup - main [main]: Libvirt library version: [10003000]
[2024-08-22 10:09:41] INFO root virtnbdbackup - main [main]: NBD library version: [1.18.1]
[2024-08-22 10:09:41] INFO root disktype - Optical [main]: Skipping attached [cdrom] device: [sda].
[2024-08-22 10:09:41] INFO root virtnbdbackup - main [main]: Backup will save [1] attached disks.
[2024-08-22 10:09:41] INFO root virtnbdbackup - main [main]: Concurrent backup processes: [1]
[2024-08-22 10:09:41] INFO root checkpoint - create [main]: Loading checkpoints from: [/tmp/virt/9//test.cpt]
[2024-08-22 10:09:41] INFO root checkpoint - redefine [main]: Loading checkpoint list from: [/tmp/virt/9//checkpoints]
[2024-08-22 10:09:41] INFO root checkpoint - create [main]: Checkpoint handling.
[2024-08-22 10:09:41] INFO root virtnbdbackup - main [main]: Local NBD Endpoint socket: [/var/tmp/virtnbdbackup.2588453]
[2024-08-22 10:09:41] INFO root virtnbdbackup - main [main]: Temporary scratch file target directory: [/var/tmp]
[2024-08-22 10:09:41] INFO root job - start [main]: Starting backup job.
[2024-08-22 10:09:41] WARNING fs fs - freeze [main]: Agente de huésped no responde: QEMU guest agent is not connected
[2024-08-22 10:09:41] INFO nbd client - connect [vda]: Waiting until NBD server at [nbd+unix:///vda?socket=/var/tmp/virtnbdbackup.2588453] is up.
[2024-08-22 10:09:42] INFO nbd client - connect [vda]: Connection to NBD backend succeeded.
[2024-08-22 10:09:42] INFO root disk - _getExtentHandler [vda]: Using qemu tools to query extents
[2024-08-22 10:09:42] INFO root disk - backup [vda]: Got 2 extents to backup.
[2024-08-22 10:09:42] INFO root disk - backup [vda]: 4294967296 bytes disk size
[2024-08-22 10:09:42] INFO root disk - backup [vda]: 2147614720 bytes of data extents to backup
[2024-08-22 10:09:42] INFO root target - get [vda]: Write data to target file: [/tmp/virt/9//vda.copy.data.partial].
[2024-08-22 10:09:42] INFO root disk - backup [vda]: Creating thin provisioned stream backup image
[2024-08-22 10:09:43] CRITICAL root virtnbdbackup - main [main]: Unknown Exception during backup: nbd_pread: read: command failed: Transport endpoint is not connected (ENOTCONN)
[2024-08-22 10:09:43] ERROR root virtnbdbackup - main [main]: nbd_pread: read: command failed: Transport endpoint is not connected (ENOTCONN)
Traceback (most recent call last):
  File "/usr/src/virtnbdbackup/./virtnbdbackup", line 499, in main
    size, state = future.result()
                  ^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/concurrent/futures/_base.py", line 449, in result
    return self.__get_result()
           ^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/concurrent/futures/_base.py", line 401, in __get_result
    raise self._exception
  File "/usr/lib/python3.12/concurrent/futures/thread.py", line 58, in run
    result = self.fn(*self.args, **self.kwargs)
             ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/src/virtnbdbackup/libvirtnbdbackup/backup/disk.py", line 159, in backup
    size, cSizes = chunk.write(
                   ^^^^^^^^^^^^
  File "/usr/src/virtnbdbackup/libvirtnbdbackup/chunk.py", line 48, in write
    data = nbdCon.nbd.pread(blocklen, blockOffset)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/usr/lib/python3.12/site-packages/nbd.py", line 2363, in pread
    return libnbdmod.pread(self._o, count, offset, flags)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
nbd.Error: nbd_pread: read: command failed: Transport endpoint is not connected (ENOTCONN)
[2024-08-22 10:09:43] INFO root virtnbdbackup - main [main]: Backup jobs finished, stopping backup task.
[2024-08-22 10:09:44] WARNING virt client - stopBackup [main]: Failed to stop backup job: [La información solicitada no es válida: El dominio no está ejecutándose]
[2024-08-22 10:09:44] INFO root metadata - backupConfig [main]: Saving VM config to: [/tmp/virt/9//vmconfig.copy.xml]
[2024-08-22 10:09:44] INFO root metadata - backupBootConfig [main]: Save additional boot config [loader] to: [/tmp/virt/9//edk2-x86_64-code.fd]
[2024-08-22 10:09:44] INFO root metadata - backupBootConfig [main]: Save additional boot config [nvram] to: [/tmp/virt/9//test_VARS.fd]
[2024-08-22 10:09:44] INFO root metadata - backupDiskInfo [main]: Saved qcow image config to: [/tmp/virt/9//vda.copy.qcow.json]
[2024-08-22 10:09:44] ERROR root virtnbdbackup - main [main]: Error during backup

[abbbi]

i guess VM shutdown during backup, i cant translate:

Failed to stop backup job: [La información solicitada no es válida: El dominio no está ejecutándose]

You should check the qemu/libvirt logs for the error cause.

[abbbi]

added fix to catch exceptions a little bit better, other than that, i dont see there is much to do.