Proxmox 6.4 - Problem mit Backup-Job im Stop-Mode

D

Detlef Paschke

Well-Known Member
Feb 12, 2019
139
15
58
50
Cottbus
helpdesk.schabau.eu
Hallo,

ich habe nun die zweite Woche in folge mit dem Backup-Job einer VM Probleme. Diese VM wird täglich um 04:00 Uhr im Snapshot-Mode gesichert und am Sonntag im Stop-Mode. Backup-Jobs im Snapshot-Mode machen keine Probleme, das Backup im Stop-Mode ist nun aber wiederholt nicht ausgeführt worden.
In der letzten Woche lag das Problem wohl an der VM selbst, denn der Shudown wurde aus irgend welchen Gründen, die ich noch nicht gefunden habe, unterbrochen und Proxmox hat den Job nach 10 Minuten mit dieser Meldung abgebrochen.

ERROR: Backup of VM 100 failed - command 'qm shutdown 100 --skiplock --keepActive --timeout 600' failed: exit code 255

Um 04:30 Uhr wurde der Shutdown in der VM dann ausgeführt und die VM blieb aus. Vermutlich weil der Backup-Job und damit das wieder Starten der VM in Proxmox längst Geschichte war.?

Beim heutigen Backup-Job wurde die VM aber ordnungsgemäß Heruntergefahren, Proxmox hat den Job für diese VM aber trotzdem abgebrochen.

VZDUMP.LOG
Code: 
2021-08-22 04:00:03 INFO: Starting Backup of VM 100 (qemu)
2021-08-22 04:00:03 INFO: status = running
2021-08-22 04:00:03 INFO: backup mode: stop
2021-08-22 04:00:03 INFO: ionice priority: 7
2021-08-22 04:00:03 INFO: VM Name: eisfair64
2021-08-22 04:00:03 INFO: exclude disk 'scsi1' '/dev/sdb' (backup=no)
2021-08-22 04:00:03 INFO: exclude disk 'scsi2' '/dev/sdc' (backup=no)
2021-08-22 04:00:03 INFO: exclude disk 'scsi3' '/dev/sdd' (backup=no)
2021-08-22 04:00:03 INFO: exclude disk 'scsi4' '/dev/sde' (backup=no)
2021-08-22 04:00:03 INFO: exclude disk 'scsi5' '/dev/sdf' (backup=no)
2021-08-22 04:00:05 INFO: {
2021-08-22 04:00:05 INFO:    "exitcode" : 0,
2021-08-22 04:00:05 INFO:    "exited" : 1,
2021-08-22 04:00:05 INFO:    "out-data" : "/boot: 0 B (0 bytes) trimmed\n"
2021-08-22 04:00:05 INFO: }
2021-08-22 04:00:08 INFO: {
2021-08-22 04:00:08 INFO:    "exitcode" : 0,
2021-08-22 04:00:08 INFO:    "exited" : 1,
2021-08-22 04:00:08 INFO:    "out-data" : "/: 2 GiB (2124042240 bytes) trimmed\n"
2021-08-22 04:00:08 INFO: }
2021-08-22 04:00:08 INFO: stopping vm
2021-08-22 04:00:59 INFO: creating vzdump archive '/mnt/sdb//dump/vzdump-qemu-100-2021_08_22-04_00_03.vma.zst'
2021-08-22 04:00:59 INFO: starting kvm to execute backup task
2021-08-22 04:01:04 INFO: restarting vm
2021-08-22 04:01:08 INFO: guest is online again after 60 seconds
2021-08-22 04:01:08 ERROR: Backup of VM 100 failed - timeout waiting on systemd

SYSLOG PROXMOX
Code: 
Aug 22 04:00:01 proxmox CRON[28865]: (root) CMD (vzdump 100 101 102 --compress zstd --mailto detlef@home.lan --mode stop --quiet 1 --storage sdb --node Proxmox --mailnotification always)
Aug 22 04:00:03 proxmox vzdump[28868]: <root@pam> starting task UPID:Proxmox:000070CC:0D9D5608:6121AFA3:vzdump::root@pam:
Aug 22 04:00:03 proxmox vzdump[28876]: INFO: starting new backup job: vzdump 100 101 102 --storage sdb --mailto detlef@home.lan --mailnotification always --quiet 1 --compress zstd --node Proxmox --mode stop
Aug 22 04:00:03 proxmox vzdump[28876]: INFO: Starting Backup of VM 100 (qemu)
Aug 22 04:00:09 proxmox qm[28941]: <root@pam> starting task UPID:Proxmox:00007112:0D9D58A2:6121AFA9:qmshutdown:100:root@pam:
Aug 22 04:00:09 proxmox qm[28946]: shutdown VM 100: UPID:Proxmox:00007112:0D9D58A2:6121AFA9:qmshutdown:100:root@pam:
Aug 22 04:00:52 proxmox QEMU[3818]: kvm: terminating on signal 15 from pid 1048 (/usr/sbin/qmeventd)
Aug 22 04:00:57 proxmox qmeventd[1046]: cleanup failed, terminating pid '3818' with SIGKILL
Aug 22 04:00:59 proxmox kernel: [2284238.268851]  sdc: sdc1
Aug 22 04:00:59 proxmox qm[28941]: <root@pam> end task UPID:Proxmox:00007112:0D9D58A2:6121AFA9:qmshutdown:100:root@pam: OK
Aug 22 04:00:59 proxmox kernel: [2284238.352588] vmbr1: port 2(tap100i0) entered disabled state
Aug 22 04:00:59 proxmox kernel: [2284238.352924] vmbr1: port 2(tap100i0) entered disabled state
Aug 22 04:00:59 proxmox kernel: [2284238.804321]  sdf: sdf1
Aug 22 04:00:59 proxmox systemd[1]: 100.scope: Succeeded.
Aug 22 04:00:59 proxmox systemd[1]: Stopped 100.scope.
Aug 22 04:00:59 proxmox kernel: [2284238.823775]  sdc: sdc1
Aug 22 04:00:59 proxmox kernel: [2284238.839192]  sde: sde1
Aug 22 04:00:59 proxmox kernel: [2284238.847963]  sdf: sdf1
Aug 22 04:01:00 proxmox systemd[1]: Starting Proxmox VE replication runner...
Aug 22 04:01:01 proxmox systemd[1]: pvesr.service: Succeeded.
Aug 22 04:01:01 proxmox systemd[1]: Started Proxmox VE replication runner.
Aug 22 04:01:01 proxmox pvestatd[1679]: VM 100 qmp command failed - VM 100 not running
Aug 22 04:01:06 proxmox qm[29140]: <root@pam> starting task UPID:Proxmox:000071D5:0D9D6E9C:6121AFE2:qmstart:100:root@pam:
Aug 22 04:01:06 proxmox qm[29141]: start VM 100: UPID:Proxmox:000071D5:0D9D6E9C:6121AFE2:qmstart:100:root@pam:
Aug 22 04:01:06 proxmox kernel: [2284245.332998]  sdc: sdc1
Aug 22 04:01:06 proxmox kernel: [2284245.925597]  sde: sde1
Aug 22 04:01:06 proxmox kernel: [2284245.934874]  sdf: sdf1
Aug 22 04:01:07 proxmox systemd[1]: Started 100.scope.
Aug 22 04:01:07 proxmox systemd-udevd[29144]: Using default interface naming scheme 'v240'.
Aug 22 04:01:07 proxmox systemd-udevd[29144]: link_config: autonegotiation is unset or enabled, the speed and duplex are not writable.
Aug 22 04:01:07 proxmox systemd-udevd[29144]: Could not generate persistent MAC address for tap100i0: No such file or directory
Aug 22 04:01:08 proxmox kernel: [2284247.179747] device tap100i0 entered promiscuous mode
Aug 22 04:01:08 proxmox qmeventd[1046]: Starting cleanup for 100
Aug 22 04:01:08 proxmox qmeventd[1046]: trying to acquire lock...
Aug 22 04:01:08 proxmox ovs-vsctl: ovs|00001|vsctl|INFO|Called as /usr/bin/ovs-vsctl del-port tap100i0
Aug 22 04:01:08 proxmox ovs-vsctl: ovs|00002|db_ctl_base|ERR|no port named tap100i0
Aug 22 04:01:08 proxmox ovs-vsctl: ovs|00001|vsctl|INFO|Called as /usr/bin/ovs-vsctl del-port fwln100i0
Aug 22 04:01:08 proxmox ovs-vsctl: ovs|00002|db_ctl_base|ERR|no port named fwln100i0
Aug 22 04:01:08 proxmox kernel: [2284247.246952] vmbr1: port 2(tap100i0) entered blocking state
Aug 22 04:01:08 proxmox kernel: [2284247.246956] vmbr1: port 2(tap100i0) entered disabled state
Aug 22 04:01:08 proxmox kernel: [2284247.247253] vmbr1: port 2(tap100i0) entered blocking state
Aug 22 04:01:08 proxmox kernel: [2284247.247255] vmbr1: port 2(tap100i0) entered forwarding state
Aug 22 04:01:08 proxmox qmeventd[1046]:  OK
Aug 22 04:01:08 proxmox qmeventd[1046]: vm still running
Aug 22 04:01:08 proxmox qm[29140]: <root@pam> end task UPID:Proxmox:000071D5:0D9D6E9C:6121AFE2:qmstart:100:root@pam: OK
Aug 22 04:01:08 proxmox vzdump[28876]: ERROR: Backup of VM 100 failed - timeout waiting on systemd
Aug 22 04:01:08 proxmox vzdump[28876]: INFO: Starting Backup of VM 101 (qemu)

Und hier noch der Syslog-Auszug der VM, in dem man sehen kann, das der Shutdown um 04:00:32 Uhr abgeschlossen war.

Code: 
Aug 22 04:00:05 eisfair64 qemu-ga: info: guest-ping called
Aug 22 04:00:05 eisfair64 qemu-ga: info: guest-exec called: "fstrim -v /boot"
Aug 22 04:00:05 eisfair64 qemu-ga: info: guest-ping called
Aug 22 04:00:05 eisfair64 qemu-ga: info: guest-exec-status called, pid: 15064
Aug 22 04:00:07 eisfair64 qemu-ga: info: guest-ping called
Aug 22 04:00:07 eisfair64 qemu-ga: info: guest-exec called: "fstrim -v /"
Aug 22 04:00:07 eisfair64 qemu-ga: info: guest-ping called
Aug 22 04:00:07 eisfair64 qemu-ga: info: guest-exec-status called, pid: 15066
Aug 22 04:00:08 eisfair64 qemu-ga: info: guest-ping called
Aug 22 04:00:08 eisfair64 qemu-ga: info: guest-exec-status called, pid: 15066
Aug 22 04:00:10 eisfair64 qemu-ga: info: guest-shutdown called, mode: (null)
Aug 22 04:00:10 eisfair64 shutdown[15071]: shutting down for system halt
Aug 22 04:00:10 eisfair64 init: Switching to runlevel: 0
Aug 22 04:00:10 eisfair64 FaxGetty[19003]: CAUGHT SIGNAL 15
Aug 22 04:00:10 eisfair64 FaxGetty[19003]: CLOSE /dev/ttyUSBfax
Aug 22 04:00:12 eisfair64 FaxQueuer[17442]: QUIT
Aug 22 04:00:13 eisfair64 init: Re-reading inittab
Aug 22 04:00:18 eisfair64 xinetd[6626]: Starting reconfiguration
Aug 22 04:00:18 eisfair64 xinetd[6626]: Reading included configuration file: /etc/xinetd.d/imap [file=/etc/xinetd.conf] [line=7]
Aug 22 04:00:18 eisfair64 xinetd[6626]: Reading included configuration file: /etc/xinetd.d/pop3 [file=/etc/xinetd.d/pop3] [line=25]
Aug 22 04:00:18 eisfair64 xinetd[6626]: Swapping defaults
Aug 22 04:00:18 eisfair64 xinetd[6626]: service imap4 deactivated
Aug 22 04:00:18 eisfair64 xinetd[6626]: service imap4s deactivated
Aug 22 04:00:18 eisfair64 xinetd[6626]: Reconfigured: new=0 old=0 dropped=2 (services)
Aug 22 04:00:18 eisfair64 fcron[462]: Job '/etc/cron.daily/logrotate' completed
Aug 22 04:00:24 eisfair64 spamd[15876]: spamd: server killed by SIGTERM, shutting down
Aug 22 04:00:26 eisfair64 fcrontab[16974]: installing file /tmp/fcr-qTUyaM for user root
Aug 22 04:00:26 eisfair64 fcron[6654]: updating configuration from /var/spool/fcron
Aug 22 04:00:26 eisfair64 fcron[6654]: adding new file root
Aug 22 04:00:29 eisfair64 fcron[6654]: SIGTERM signal received
Aug 22 04:00:29 eisfair64 fcron[6654]: Exiting with code 0
Aug 22 04:00:30 eisfair64 sshd[6634]: Received signal 15; terminating.
Aug 22 04:00:32 eisfair64 xinetd[6626]: Exiting...
Aug 22 04:01:14 eisfair64 kernel: Linux version 5.10.55-eisfair-64-VIRT (root@basebox64) (gcc (eisfair Linux) 10.3.0, GNU ld (GNU Binutils; eisfair-64) 2.36.1.20210326-3) #1 SMP Sat Jul 31 11:09:39 CEST 2021
Aug 22 04:01:14 eisfair64 kernel: Command line: BOOT_IMAGE=../kernel root=UUID=7d1c017d-5f2b-417e-85a5-ee91712f0964 raid=noautodetect consoleblank=600 initrd=../initrd.gz

Bei anderen VMs mit dem gleichen System, lief der Backup-Job problemlos und auch ein händisches Backup im Stop-Mode der betreffenden VM 100 ist möglich.

Die Backup-Jobs laufen seit längerer Zeit unverändert so und haben bisher keine Probleme gemacht.
An welcher Stelle könnte es Haken?

Viele Grüße
Detlef Paschke
 
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