timeout error while backing up VM with stop mode

T

Thatoo

Member
Jun 11, 2021
53
0
11
38
Hello,

I set up a backup of a VM with stop mode. It used to work nicely before the day before yesterday.
Now, I get the following error :
INFO: starting new backup job: vzdump 100 --notes-template '{{guestname}}' --mailnotification failure --quiet 1 --mode stop --prune-backups 'keep-daily=10,keep-monthly=3,keep-weekly=4,keep-yearly=1' --mailto root@xxx.in,root@xxx.fr --node pve --storage PBS_H
Code: 
INFO: Starting Backup of VM 100 (qemu)
INFO: Backup started at 2024-09-19 02:00:03
INFO: status = running
INFO: backup mode: stop
INFO: ionice priority: 7
INFO: VM Name: xxx.in
INFO: include disk 'scsi0' 'local-lvm:vm-100-disk-0' 500G
INFO: include disk 'scsi1' 'local-lvm:vm-100-disk-1' 300G
INFO: stopping virtual guest
INFO: creating Proxmox Backup Server archive 'vm/100/2024-09-19T00:00:03Z'
INFO: enabling encryption
INFO: starting kvm to execute backup task
INFO: guest is online again after 149 seconds
ERROR: Backup of VM 100 failed - start failed: command '/usr/bin/kvm -id 100 -name 'xxx.in,debug-threads=on' -no-shutdown -chardev 'socket,id=qmp,path=/var/run/qemu-server/100.qmp,server=on,wait=off' -mon 'chardev=qmp,mode=control' -chardev 'socket,id=qmp-event,path=/var/run/qmeventd.sock,reconnect=5' -mon 'chardev=qmp-event,mode=control' -pidfile /var/run/qemu-server/100.pid -daemonize -smbios 'type=1,uuid=15ae1c18-8964-4824-9c26-5442f669b54e' -smp '3,sockets=1,cores=3,maxcpus=3' -nodefaults -boot 'menu=on,strict=on,reboot-timeout=1000,splash=/usr/share/qemu-server/bootsplash.jpg' -vnc 'unix:/var/run/qemu-server/100.vnc,password=on' -cpu qemu64,+aes,enforce,+kvm_pv_eoi,+kvm_pv_unhalt,+pni,+popcnt,+sse4.1,+sse4.2,+ssse3 -m 8192 -object 'iothread,id=iothread-virtioscsi0' -object 'iothread,id=iothread-virtioscsi1' -device 'pci-bridge,id=pci.1,chassis_nr=1,bus=pci.0,addr=0x1e' -device 'pci-bridge,id=pci.2,chassis_nr=2,bus=pci.0,addr=0x1f' -device 'pci-bridge,id=pci.3,chassis_nr=3,bus=pci.0,addr=0x5' -device 'vmgenid,guid=07fb610a-a824-4655-a698-ef1e404b80fe' -device 'piix3-usb-uhci,id=uhci,bus=pci.0,addr=0x1.0x2' -device 'qemu-xhci,p2=15,p3=15,id=xhci,bus=pci.1,addr=0x1b' -device 'usb-tablet,id=tablet,bus=uhci.0,port=1' -device 'usb-host,bus=xhci.0,port=1,vendorid=0x0cf3,productid=0x7015,id=usb0' -device 'VGA,id=vga,bus=pci.0,addr=0x2' -chardev 'socket,path=/var/run/qemu-server/100.qga,server=on,wait=off,id=qga0' -device 'virtio-serial,id=qga0,bus=pci.0,addr=0x8' -device 'virtserialport,chardev=qga0,name=org.qemu.guest_agent.0' -device 'virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x3,free-page-reporting=on' -iscsi 'initiator-name=iqn.1993-08.org.debian:01:e193297b7c1' -drive 'if=none,id=drive-ide2,media=cdrom,aio=io_uring' -device 'ide-cd,bus=ide.1,unit=0,drive=drive-ide2,id=ide2,bootindex=100' -device 'virtio-scsi-pci,id=virtioscsi0,bus=pci.3,addr=0x1,iothread=iothread-virtioscsi0' -drive 'file=/dev/pve/vm-100-disk-0,if=none,id=drive-scsi0,discard=on,format=raw,cache=none,aio=io_uring,detect-zeroes=unmap' -device 'scsi-hd,bus=virtioscsi0.0,channel=0,scsi-id=0,lun=0,drive=drive-scsi0,id=scsi0,rotation_rate=1,bootindex=101' -device 'virtio-scsi-pci,id=virtioscsi1,bus=pci.3,addr=0x2,iothread=iothread-virtioscsi1' -drive 'file=/dev/pve/vm-100-disk-1,if=none,id=drive-scsi1,discard=on,format=raw,cache=none,aio=io_uring,detect-zeroes=unmap' -device 'scsi-hd,bus=virtioscsi1.0,channel=0,scsi-id=0,lun=1,drive=drive-scsi1,id=scsi1,rotation_rate=1' -netdev 'type=tap,id=net0,ifname=tap100i0,script=/var/lib/qemu-server/pve-bridge,downscript=/var/lib/qemu-server/pve-bridgedown,vhost=on' -device 'virtio-net-pci,mac=BC:24:11:E0:2B:82,netdev=net0,bus=pci.0,addr=0x12,id=net0,rx_queue_size=1024,tx_queue_size=256,bootindex=102' -machine 'type=pc+pve0' -S' failed: got timeout
INFO: Failed at 2024-09-19 02:02:32
INFO: Backup job finished with errors
INFO: notified via target `<root@xxx.in,root@xxx.fr>`
TASK ERROR: job errors

So it looks like the VM didn't stop within the 149 seconds and thus, the backup failed.
However, the VM was indeed switched off when I wake up and if I look at /var/log/syslog in the VM, here is what I found :

Code: 
Sep 18 02:00:01 xxx CRON[28796]: (nextcloud) CMD (/usr/bin/php8.3 --define apc.enable_cli=1 -f /var/www/nextcloud/cron.php)
Sep 18 02:00:04 xxx qemu-ga: info: guest-shutdown called, mode: (null)
Sep 18 02:00:04 xxx systemd[1]: unattended-upgrades.service: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Removed slice system-modprobe.slice.
Sep 18 02:00:04 xxx systemd[1]: Stopped target Graphical Interface.
Sep 18 02:00:04 xxx systemd[1]: Stopped target Multi-User System.
Sep 18 02:00:04 xxx systemd[1]: Stopped target Login Prompts.
Sep 18 02:00:04 xxx systemd[1]: Stopped target Timers.
Sep 18 02:00:04 xxx systemd[1]: anacron.timer: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Stopped Trigger anacron every hour.
Sep 18 02:00:04 xxx systemd[1]: apt-daily-upgrade.timer: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Stopped Daily apt upgrade and clean activities.
Sep 18 02:00:04 xxx systemd[1]: apt-daily.timer: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Stopped Daily apt download activities.
Sep 18 02:00:04 xxx systemd[1]: e2scrub_all.timer: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Stopped Periodic ext4 Online Metadata Check for All Filesystems.
Sep 18 02:00:04 xxx systemd[1]: fstrim.timer: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Stopped Discard unused blocks once a week.
Sep 18 02:00:04 xxx systemd[1]: logrotate.timer: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Stopped Daily rotation of log files.
Sep 18 02:00:04 xxx systemd[1]: man-db.timer: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Stopped Daily man-db regeneration.
Sep 18 02:00:04 xxx systemd[1]: phpsessionclean.timer: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Stopped Clean PHP session files every 30 mins.
Sep 18 02:00:04 xxx systemd[1]: systemd-tmpfiles-clean.timer: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Stopped Clean PHP session files every 30 mins.
Sep 18 02:00:04 xxx systemd[1]: systemd-tmpfiles-clean.timer: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Stopped Daily Cleanup of Temporary Directories.
Sep 18 02:00:04 xxx systemd[1]: systemd-rfkill.socket: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Closed Load/Save RF Kill Switch Status /dev/rfkill Watch.
Sep 18 02:00:04 xxx systemd[1]: Unmounting /media/stockage...
Sep 18 02:00:04 xxx systemd[1]: Stopping Deferred execution scheduler...
Sep 18 02:00:04 xxx systemd[1]: Stopping coTURN STUN/TURN Server...
Sep 18 02:00:04 xxx systemd[1]: Stopping Regular background program processing daemon...
Sep 18 02:00:04 xxx systemd[1]: Stopping Dovecot IMAP/POP3 email server...
Sep 18 02:00:04 xxx systemd[1]: Stopping Fail2Ban Service...
Sep 18 02:00:04 xxx systemd[1]: Stopping Getty on tty1...
Sep 18 02:00:04 xxx systemd[1]: Stopping LSB: disk temperature monitoring daemon...
Sep 18 02:00:04 xxx systemd[1]: Stopping LSB: Advanced IEEE 802.11 management daemon...
Sep 18 02:00:04 xxx systemd[1]: lm-sensors.service: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Stopped Initialize hardware monitoring sensors.
Sep 18 02:00:04 xxx systemd[1]: Stopping MariaDB 10.5.23 database server...
Sep 18 02:00:04 xxx systemd[1]: Stopping Matrix Signal Bridge...
Sep 18 02:00:04 xxx systemd[1]: Stopping Matrix Telegram Bridge...
Sep 18 02:00:04 xxx mariadbd[977]: 2024-09-18  2:00:04 0 [Note] InnoDB: Starting shutdown...
Sep 18 02:00:04 xxx mariadbd[977]: 2024-09-18  2:00:04 0 [Note] InnoDB: Dumping buffer pool(s) to /var/lib/mysql/ib_buffer_pool
Sep 18 02:00:04 xxx mariadbd[977]: 2024-09-18  2:00:04 0 [Note] InnoDB: Buffer pool(s) dump completed at 240918  2:00:04
Sep 18 02:00:04 xxx ntpd[654]: ntpd exiting on signal 15 (Terminated)
Sep 18 02:00:04 xxx systemd[1]: Stopping Matrix Whatsapp Bridge...
Sep 18 02:00:04 xxx systemd[1]: Stopped OpenVPN service.
Sep 18 02:00:04 xxx systemd[1]: Stopping The PHP 7.4 FastCGI Process Manager...
Sep 18 02:00:04 xxx dovecot: master: Warning: Killed with signal 15 (by pid=28815 uid=0 code=kill)
Sep 18 02:00:04 xxx systemd[1]: Stopping The PHP 8.0 FastCGI Process Manager...
Sep 18 02:00:04 xxx systemd[1]: Stopping The PHP 8.2 FastCGI Process Manager...
Sep 18 02:00:04 xxx python3[578]: [2024-09-18 02:00:04,292] [#033[36mINFO#033[0m@#033[32mmau.init#033[0m] Everything stopped, shutting down
Sep 18 02:00:04 xxx systemd[1]: Stopping The PHP 8.3 FastCGI Process Manager...
Sep 18 02:00:04 xxx systemd[1]: postfix.service: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Stopped Postfix Mail Transport Agent.
Sep 18 02:00:04 xxx systemd[1]: Stopping Postfix Mail Transport Agent (instance -)...
Sep 18 02:00:04 xxx systemd[1]: postgresql.service: Succeeded.
Sep 18 02:00:04 xxx systemd[1]: Stopped PostgreSQL RDBMS.
Sep 18 02:00:04 xxx systemd[1]: Stopping PostgreSQL Cluster 13-main...
Sep 18 02:00:04 xxx systemd[1]: Stopping PostSRSd Daemon...
Sep 18 07:35:11 xxx kernel: [    0.000000] Linux version 5.10.0-32-amd64 (debian-kernel@lists.debian.org) (gcc-10 (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2) #1 SMP Debian 5.10.223-1 (2024->
Sep 18 07:35:11 xxx kernel: [    0.000000] Command line: BOOT_IMAGE=/vmlinuz-5.10.0-32-amd64 root=UUID=de565b6a-9830-49c0-8c17-7c2cf81f747a ro quiet
Sep 18 07:35:11 xxx kernel: [    0.000000] BIOS-provided physical RAM map:

So it looks like the VM stop at Sep 18 02:00:04 and wake up at Sep 18 07:35:11 when I indeed woke it up.
So from what I found in /var/log/syslog of the VM, the VM took about 4 seconds to switch off, not 149 seconds.

The question is then, why PVE thought the VM was not switched off after 149 seconds? And how can I solve this issue to get nightly working backup again?
 
Last edited:
Hi!

Did you already have a look in the logs on the PBS-side? Maybe there is something that could help explaining the issue.
 
No, there is no trace of anything.
Code: 
Sep 16 01:49:20 pve proxmox-backup-proxy[997]: rrd journal successfully committed (25 files in 0.012 seconds)
Sep 16 02:01:00 pve proxmox-backup-proxy[997]: starting new backup on datastore 'PBS_Hamdel' from ::ffff:82.67.83.201: "vm/100/2024-09-16T00:00:05Z"
Sep 16 02:01:00 pve proxmox-backup-proxy[997]: download 'index.json.blob' from previous backup.
Sep 16 02:01:00 pve proxmox-backup-proxy[997]: register chunks in 'drive-scsi0.img.fidx' from previous backup.
Sep 16 02:01:00 pve proxmox-backup-proxy[997]: download 'drive-scsi0.img.fidx' from previous backup.
Sep 16 02:01:00 pve proxmox-backup-proxy[997]: created new fixed index 1 ("vm/100/2024-09-16T00:00:05Z/drive-scsi0.img.fidx")
Sep 16 02:01:00 pve proxmox-backup-proxy[997]: register chunks in 'drive-scsi1.img.fidx' from previous backup.
Sep 16 02:01:00 pve proxmox-backup-proxy[997]: download 'drive-scsi1.img.fidx' from previous backup.
Sep 16 02:01:01 pve proxmox-backup-proxy[997]: created new fixed index 2 ("vm/100/2024-09-16T00:00:05Z/drive-scsi1.img.fidx")
Sep 16 02:01:01 pve proxmox-backup-proxy[997]: add blob "/mnt/datastore/PBS_Hamdel/vm/100/2024-09-16T00:00:05Z/qemu-server.conf.blob" (435 bytes, comp: 435)
Sep 16 02:14:02 pve systemd[1]: Starting proxmox-backup-daily-update.service - Daily Proxmox Backup Server update and maintenance activities...

here is the last time it has worked. But last night and previous night, I can't find it.

Code: 
Sep 18 01:49:40 pve proxmox-backup-proxy[997]: rrd journal successfully committed (25 files in 0.012 seconds)
Sep 18 02:06:17 pve systemd[1]: Starting pve-daily-update.service - Daily PVE download activities...
 
Do you still have access to the last successful backup task-log from you PVE host? Do you have the qemu-guest-agent running in your VM?
Could you also post the actual config of the vm?
 
Last edited:
Yes :

Code: 
INFO: starting new backup job: vzdump 100 --quiet 1 --prune-backups 'keep-daily=10,keep-monthly=3,keep-weekly=4,keep-yearly=1' --notes-template '{{guestname}}' --mailto root@xxx.in,root@xxx.fr --node pve --mailnotification failure --storage PBS_H --mode stop
INFO: Starting Backup of VM 100 (qemu)
INFO: Backup started at 2024-09-17 02:00:00
INFO: status = running
INFO: backup mode: stop
INFO: ionice priority: 7
INFO: VM Name: xxx.in
INFO: include disk 'scsi0' 'local-lvm:vm-100-disk-0' 500G
INFO: include disk 'scsi1' 'local-lvm:vm-100-disk-1' 300G
INFO: stopping virtual guest
INFO: creating Proxmox Backup Server archive 'vm/100/2024-09-17T00:00:00Z'
INFO: enabling encryption
INFO: starting kvm to execute backup task
INFO: started backup task '00cd107b-27d3-4306-9902-b9ae4f84d336'
INFO: resuming VM again after 59 seconds
INFO: scsi0: dirty-bitmap status: created new
INFO: scsi1: dirty-bitmap status: created new
INFO:   0% (1.4 GiB of 800.0 GiB) in 3s, read: 493.3 MiB/s, write: 1.3 MiB/s
INFO:   1% (8.2 GiB of 800.0 GiB) in 33s, read: 228.9 MiB/s, write: 11.2 MiB/s
INFO:   2% (16.1 GiB of 800.0 GiB) in 59s, read: 313.8 MiB/s, write: 6.6 MiB/s
INFO:   3% (24.5 GiB of 800.0 GiB) in 1m 27s, read: 306.0 MiB/s, write: 1.9 MiB/s
INFO:   4% (32.1 GiB of 800.0 GiB) in 1m 41s, read: 558.9 MiB/s, write: 292.6 KiB/s
INFO:   5% (40.9 GiB of 800.0 GiB) in 1m 55s, read: 642.9 MiB/s, write: 0 B/s
INFO:   6% (48.0 GiB of 800.0 GiB) in 2m 19s, read: 303.5 MiB/s, write: 341.3 KiB/s
INFO:   7% (56.0 GiB of 800.0 GiB) in 2m 44s, read: 327.7 MiB/s, write: 0 B/s
INFO:   8% (64.2 GiB of 800.0 GiB) in 3m 11s, read: 309.8 MiB/s, write: 303.4 KiB/s
INFO:   9% (72.4 GiB of 800.0 GiB) in 3m 36s, read: 335.5 MiB/s, write: 163.8 KiB/s
INFO:  10% (80.3 GiB of 800.0 GiB) in 3m 54s, read: 447.3 MiB/s, write: 0 B/s
INFO:  11% (88.0 GiB of 800.0 GiB) in 4m 22s, read: 284.4 MiB/s, write: 0 B/s
INFO:  12% (96.3 GiB of 800.0 GiB) in 4m 40s, read: 471.1 MiB/s, write: 0 B/s
INFO:  13% (104.3 GiB of 800.0 GiB) in 4m 55s, read: 542.9 MiB/s, write: 0 B/s
INFO:  14% (112.1 GiB of 800.0 GiB) in 5m 17s, read: 364.5 MiB/s, write: 0 B/s
INFO:  15% (120.2 GiB of 800.0 GiB) in 5m 43s, read: 320.9 MiB/s, write: 5.8 MiB/s
INFO:  16% (128.2 GiB of 800.0 GiB) in 6m 8s, read: 327.5 MiB/s, write: 0 B/s
INFO:  17% (136.3 GiB of 800.0 GiB) in 6m 30s, read: 373.5 MiB/s, write: 0 B/s
INFO:  18% (144.2 GiB of 800.0 GiB) in 6m 55s, read: 325.8 MiB/s, write: 0 B/s
INFO:  19% (152.2 GiB of 800.0 GiB) in 7m 22s, read: 304.6 MiB/s, write: 151.7 KiB/s
INFO:  20% (160.2 GiB of 800.0 GiB) in 7m 50s, read: 289.4 MiB/s, write: 0 B/s
INFO:  21% (168.1 GiB of 800.0 GiB) in 8m 17s, read: 300.7 MiB/s, write: 0 B/s
INFO:  22% (176.2 GiB of 800.0 GiB) in 8m 37s, read: 415.2 MiB/s, write: 0 B/s
INFO:  23% (184.1 GiB of 800.0 GiB) in 8m 53s, read: 502.2 MiB/s, write: 0 B/s
INFO:  24% (192.2 GiB of 800.0 GiB) in 9m 13s, read: 418.8 MiB/s, write: 0 B/s
INFO:  25% (200.2 GiB of 800.0 GiB) in 9m 29s, read: 510.0 MiB/s, write: 0 B/s
INFO:  26% (208.2 GiB of 800.0 GiB) in 9m 55s, read: 313.8 MiB/s, write: 0 B/s
INFO:  27% (216.1 GiB of 800.0 GiB) in 10m 23s, read: 290.6 MiB/s, write: 146.3 KiB/s
INFO:  28% (224.1 GiB of 800.0 GiB) in 10m 46s, read: 356.7 MiB/s, write: 0 B/s
INFO:  29% (232.7 GiB of 800.0 GiB) in 11m 2s, read: 550.5 MiB/s, write: 0 B/s
INFO:  30% (240.0 GiB of 800.0 GiB) in 11m 14s, read: 621.3 MiB/s, write: 0 B/s
INFO:  31% (248.8 GiB of 800.0 GiB) in 11m 23s, read: 999.6 MiB/s, write: 0 B/s
INFO:  33% (264.4 GiB of 800.0 GiB) in 11m 26s, read: 5.2 GiB/s, write: 0 B/s
INFO:  34% (279.3 GiB of 800.0 GiB) in 11m 29s, read: 5.0 GiB/s, write: 0 B/s
INFO:  36% (294.9 GiB of 800.0 GiB) in 11m 32s, read: 5.2 GiB/s, write: 0 B/s
INFO:  37% (302.2 GiB of 800.0 GiB) in 11m 35s, read: 2.4 GiB/s, write: 0 B/s
INFO:  38% (304.2 GiB of 800.0 GiB) in 11m 41s, read: 353.3 MiB/s, write: 5.3 MiB/s
INFO:  39% (312.3 GiB of 800.0 GiB) in 12m 2s, read: 390.9 MiB/s, write: 3.8 MiB/s
INFO:  40% (320.2 GiB of 800.0 GiB) in 12m 22s, read: 406.8 MiB/s, write: 2.8 MiB/s
INFO:  41% (328.2 GiB of 800.0 GiB) in 12m 41s, read: 431.4 MiB/s, write: 3.4 MiB/s
INFO:  42% (337.4 GiB of 800.0 GiB) in 12m 47s, read: 1.5 GiB/s, write: 45.3 MiB/s
INFO:  43% (344.2 GiB of 800.0 GiB) in 12m 58s, read: 628.4 MiB/s, write: 9.5 MiB/s
INFO:  44% (352.0 GiB of 800.0 GiB) in 13m 33s, read: 229.8 MiB/s, write: 3.9 MiB/s
INFO:  45% (361.5 GiB of 800.0 GiB) in 13m 56s, read: 421.9 MiB/s, write: 12.2 MiB/s
INFO:  46% (368.2 GiB of 800.0 GiB) in 14m 19s, read: 296.5 MiB/s, write: 890.4 KiB/s
INFO:  47% (379.4 GiB of 800.0 GiB) in 14m 44s, read: 460.0 MiB/s, write: 5.3 MiB/s
INFO:  49% (395.1 GiB of 800.0 GiB) in 14m 47s, read: 5.2 GiB/s, write: 0 B/s
INFO:  51% (410.8 GiB of 800.0 GiB) in 14m 50s, read: 5.2 GiB/s, write: 0 B/s
INFO:  53% (426.2 GiB of 800.0 GiB) in 14m 53s, read: 5.2 GiB/s, write: 0 B/s
INFO:  55% (441.9 GiB of 800.0 GiB) in 14m 56s, read: 5.2 GiB/s, write: 0 B/s
INFO:  57% (457.7 GiB of 800.0 GiB) in 14m 59s, read: 5.2 GiB/s, write: 0 B/s
INFO:  59% (473.3 GiB of 800.0 GiB) in 15m 2s, read: 5.2 GiB/s, write: 0 B/s
INFO:  61% (488.7 GiB of 800.0 GiB) in 15m 5s, read: 5.1 GiB/s, write: 0 B/s
INFO:  63% (504.2 GiB of 800.0 GiB) in 15m 8s, read: 5.2 GiB/s, write: 0 B/s
INFO:  64% (519.7 GiB of 800.0 GiB) in 15m 11s, read: 5.2 GiB/s, write: 0 B/s
INFO:  66% (535.1 GiB of 800.0 GiB) in 15m 14s, read: 5.1 GiB/s, write: 0 B/s
INFO:  68% (550.6 GiB of 800.0 GiB) in 15m 17s, read: 5.2 GiB/s, write: 0 B/s
INFO:  70% (566.9 GiB of 800.0 GiB) in 15m 20s, read: 5.4 GiB/s, write: 0 B/s
INFO:  72% (582.1 GiB of 800.0 GiB) in 15m 23s, read: 5.1 GiB/s, write: 0 B/s
INFO:  74% (597.6 GiB of 800.0 GiB) in 15m 26s, read: 5.2 GiB/s, write: 0 B/s
INFO:  76% (613.0 GiB of 800.0 GiB) in 15m 29s, read: 5.1 GiB/s, write: 0 B/s
INFO:  78% (628.7 GiB of 800.0 GiB) in 15m 32s, read: 5.3 GiB/s, write: 0 B/s
INFO:  80% (644.3 GiB of 800.0 GiB) in 15m 35s, read: 5.2 GiB/s, write: 0 B/s
INFO:  82% (659.4 GiB of 800.0 GiB) in 15m 38s, read: 5.0 GiB/s, write: 0 B/s
INFO:  84% (675.2 GiB of 800.0 GiB) in 15m 41s, read: 5.3 GiB/s, write: 0 B/s
INFO:  86% (691.1 GiB of 800.0 GiB) in 15m 44s, read: 5.3 GiB/s, write: 0 B/s
INFO:  88% (707.2 GiB of 800.0 GiB) in 15m 47s, read: 5.4 GiB/s, write: 0 B/s
INFO:  90% (722.9 GiB of 800.0 GiB) in 15m 50s, read: 5.2 GiB/s, write: 0 B/s
INFO:  92% (738.3 GiB of 800.0 GiB) in 15m 53s, read: 5.2 GiB/s, write: 0 B/s
INFO:  94% (753.8 GiB of 800.0 GiB) in 15m 56s, read: 5.2 GiB/s, write: 0 B/s
INFO:  96% (769.7 GiB of 800.0 GiB) in 15m 59s, read: 5.3 GiB/s, write: 0 B/s
INFO:  98% (785.6 GiB of 800.0 GiB) in 16m 2s, read: 5.3 GiB/s, write: 0 B/s
INFO: 100% (800.0 GiB of 800.0 GiB) in 16m 5s, read: 4.8 GiB/s, write: 0 B/s
INFO: Waiting for server to finish backup validation...
INFO: backup is sparse: 579.02 GiB (72%) total zero data
INFO: backup was done incrementally, reused 798.12 GiB (99%)
INFO: transferred 800.00 GiB in 967 seconds (847.2 MiB/s)
INFO: adding notes to backup
INFO: prune older backups with retention: keep-daily=10, keep-monthly=3, keep-weekly=4, keep-yearly=1
INFO: running 'proxmox-backup-client prune' for 'vm/100'
INFO: pruned 1 backup(s) not covered by keep-retention policy
INFO: Finished Backup of VM 100 (00:17:07)
INFO: Backup finished at 2024-09-17 02:17:07
INFO: Backup job finished successfully
TASK OK

and yes :
Code: 
:~ $ sudo service qemu-guest-agent status
● qemu-guest-agent.service - QEMU Guest Agent
     Loaded: loaded (/lib/systemd/system/qemu-guest-agent.service; static)
     Active: active (running) since Thu 2024-09-19 11:05:55 CEST; 1h 22min ago
   Main PID: 470 (qemu-ga)
      Tasks: 2 (limit: 9482)
     Memory: 2.5M
        CPU: 4.742s
     CGroup: /system.slice/qemu-guest-agent.service
             └─470 /usr/sbin/qemu-ga

sept. 19 12:19:42 hamdel.in qemu-ga[470]: info: guest-ping called
sept. 19 12:19:53 hamdel.in qemu-ga[470]: info: guest-ping called
sept. 19 12:20:04 hamdel.in qemu-ga[470]: info: guest-ping called
sept. 19 12:20:15 hamdel.in qemu-ga[470]: info: guest-ping called
sept. 19 12:20:26 hamdel.in qemu-ga[470]: info: guest-ping called
sept. 19 12:20:37 hamdel.in qemu-ga[470]: info: guest-ping called
sept. 19 12:20:48 hamdel.in qemu-ga[470]: info: guest-ping called
sept. 19 12:20:59 hamdel.in qemu-ga[470]: info: guest-ping called
sept. 19 12:21:10 hamdel.in qemu-ga[470]: info: guest-ping called
sept. 19 12:21:21 hamdel.in qemu-ga[470]: info: guest-ping called
 
I'm trying to backup manually. Shutdown took about 1 min and the backup is now running (around 3%). It has already pass where it was failing previous nights.

[edit] : manual backup shutting down the VM did work!
 
Last edited:
Glad to hear that the manual trigger works for you!

Could you also post the vm's config from '/etc/pve/qemu-server/100.conf', to gain further insights?

And possibly also the contents of '/etc/pve/jobs.cfg'?
 
Last edited:
Code: 
# cat /etc/pve/qemu-server/100.conf
agent: 1
boot: order=ide2;scsi0;net0
cores: 3
cpu: x86-64-v2-AES
ide2: none,media=cdrom
memory: 8192
meta: creation-qemu=8.1.5,ctime=1712567534
name: xxx.in
net0: virtio=BC:24:11:E0:2B:82,bridge=vmbr0
numa: 0
onboot: 1
ostype: l26
scsi0: local-lvm:vm-100-disk-0,discard=on,iothread=1,size=500G,ssd=1
scsi1: local-lvm:vm-100-disk-1,discard=on,iothread=1,size=300G,ssd=1
scsihw: virtio-scsi-single
smbios1: uuid=15ae1c18-8964-4824-9c26-5442f669b54e
sockets: 1
usb0: host=0cf3:7015
vmgenid: 07fb610a-a824-4655-a698-ef1e404b80fe
root@pve:~# cat /etc/pve/qemu-server/100.conf
agent: 1
boot: order=ide2;scsi0;net0
cores: 3
cpu: x86-64-v2-AES
ide2: none,media=cdrom
memory: 8192
meta: creation-qemu=8.1.5,ctime=1712567534
name: hamdel.in
net0: virtio=BC:24:11:E0:2B:82,bridge=vmbr0
numa: 0
onboot: 1
ostype: l26
scsi0: local-lvm:vm-100-disk-0,discard=on,iothread=1,size=500G,ssd=1
scsi1: local-lvm:vm-100-disk-1,discard=on,iothread=1,size=300G,ssd=1
scsihw: virtio-scsi-single
smbios1: uuid=15ae1c18-8964-4824-9c26-5442f669b54e
sockets: 1
usb0: host=0cf3:7015
vmgenid: 07fb610a-a824-4655-a698-ef1e404b80fe
root@pve:~# cat /etc/pve/jobs.cfg
vzdump: backup-b0c5602b-4899
        schedule 2:00
        enabled 1
        mailnotification failure
        mailto root@xxx.in,root@xxx.fr
        mode stop
        node pve
        notes-template {{guestname}}
        prune-backups keep-daily=10,keep-monthly=3,keep-weekly=4,keep-yearly=1
        storage PBS_Hamdel
        vmid 100
 
I don't know, I read it's stop mode is providing the highest consistency of the backup.
I didn't get what you recommend. You seem to say that having guest-agent enabled, I should choose an other mode but I didn't get which one and why guest-agent change something about the choice. Would you mind explain me a bit?
 
Sorry for not being clear -- I totally missed verbalizing the word 'snapshot' for the mode! The running guest-agent is needed to make use of QEMU's 'guest-fsfreeze-freeze' [0] and 'guest-fsfreeze-thaw' [1] commands for enhanced consistency and speedy backups.

Clearly, you still have to check the integrity of the backups periodically, but this has to be done in any mode ('Snapshot' however seems to be the default mode currently).

[0] https://www.qemu.org/docs/master/interop/qemu-ga-ref.html#qapidoc-78
[1] https://www.qemu.org/docs/master/interop/qemu-ga-ref.html#qapidoc-87
 
  • Like
Reactions: Thatoo
You must log in or register to reply here.

About

The Proxmox community has been around for many years and offers help and support for Proxmox VE, Proxmox Backup Server, and Proxmox Mail Gateway.
We think our community is one of the best thanks to people like you!

Quick Navigation

Home Get Subscription Wiki Downloads Proxmox Customer Portal About

Get your subscription!

The Proxmox team works very hard to make sure you are running the best software and getting stable updates and security enhancements, as well as quick enterprise support. Tens of thousands of happy customers have a Proxmox subscription. Get yours easily in our online shop.

Buy now!
Community platform by XenForo® © 2010-2024 XenForo Ltd.
Top Bottom
Back