[SOLVED] "Job error" bei Backup einer VM auf einen PBS

[Inworks IT]

Hallo,

wir haben gerade ein Problem, eine VM auf einen PBS zu sichern.

Wenn der Backup-Job losläuft, sichert er die VM auf den PBS und startet anschließend den Verification-Job auf dem PBS.
Seltsamerweise läuft aber nicht mal eine halbe Minute später wieder ein Backup-Job los, der dann wegen des Locks auf das Verzeichnis auf dem PBS einen Fehler wirft.

00:00:07

VM 100 qmp command 'backup' failed - backup connect failed: command error: unable to acquire lock on snapshot directory "/mnt/datastore/zbackup/vm/100/2022-10-21T12:48:01Z" - base snapshot is already locked by another operation

Woher kommt dieses Verhalten?
Der "Repeat missed"-Schalter ist aus. Eine weitere Option ist uns jetzt nicht aufgefallen.

 

[fiona]

Hi,
sollte normalerweise nicht vorkommen. Was ist die Ausgabe von folgenden Kommandos?

ps aux | grep pvescheduler
pveversion -v
cat /etc/pve/jobs.cfg
cat /var/lib/pve-manager/jobs/vzdump-<ID vom problematischen Job>.json

Ein Auszug von /var/log/syslog rund um die Zeit des Problems wäre auch hilfreich.

EDIT: Gibts in /etc/pve/vzdump.cron (wurde benutzt bevor jobs.cfg kam) noch alte Einträge?

 

[Inworks IT]

Hi,
sollte normalerweise nicht vorkommen. Was ist die Ausgabe von folgenden Kommandos?

ps aux | grep pvescheduler
pveversion -v
cat /etc/pve/jobs.cfg
cat /var/lib/pve-manager/jobs/vzdump-<ID vom problematischen Job>.json

Ein Auszug von /var/log/syslog rund um die Zeit des Problems wäre auch hilfreich.

EDIT: Gibts in /etc/pve/vzdump.cron (wurde benutzt bevor jobs.cfg kam) noch alte Einträge?

# ps aux | grep pvescheduler
root        5324  0.0  0.1 327072 114192 ?       Ss   Sep16   2:06 pvescheduler
root     2464918  0.0  0.0   6244   712 pts/1    S+   11:55   0:00 grep pvescheduler

# pveversion -v
proxmox-ve: 7.2-1 (running kernel: 5.15.53-1-pve)
pve-manager: 7.2-11 (running version: 7.2-11/b76d3178)
pve-kernel-helper: 7.2-12
pve-kernel-5.15: 7.2-10
pve-kernel-5.13: 7.1-9
pve-kernel-5.15.53-1-pve: 5.15.53-1
pve-kernel-5.15.39-4-pve: 5.15.39-4
pve-kernel-5.13.19-6-pve: 5.13.19-15
pve-kernel-5.13.19-2-pve: 5.13.19-4
ceph-fuse: 15.2.15-pve1
corosync: 3.1.5-pve2
criu: 3.15-1+pve-1
glusterfs-client: 9.2-1
ifupdown2: 3.1.0-1+pmx3
ksm-control-daemon: 1.4-1
libjs-extjs: 7.0.0-1
libknet1: 1.24-pve1
libproxmox-acme-perl: 1.4.2
libproxmox-backup-qemu0: 1.3.1-1
libpve-access-control: 7.2-4
libpve-apiclient-perl: 3.2-1
libpve-common-perl: 7.2-2
libpve-guest-common-perl: 4.1-2
libpve-http-server-perl: 4.1-3
libpve-storage-perl: 7.2-10
libspice-server1: 0.14.3-2.1
lvm2: 2.03.11-2.1
lxc-pve: 5.0.0-3
lxcfs: 4.0.12-pve1
novnc-pve: 1.3.0-3
proxmox-backup-client: 2.2.7-1
proxmox-backup-file-restore: 2.2.5-1
proxmox-mini-journalreader: 1.3-1
proxmox-widget-toolkit: 3.5.1
pve-cluster: 7.2-2
pve-container: 4.2-2
pve-docs: 7.2-2
pve-edk2-firmware: 3.20220526-1
pve-firewall: 4.2-5
pve-firmware: 3.5-1
pve-ha-manager: 3.4.0
pve-i18n: 2.7-2
pve-qemu-kvm: 7.0.0-3
pve-xtermjs: 4.16.0-1
qemu-server: 7.2-4
smartmontools: 7.2-pve3
spiceterm: 3.2-2
swtpm: 0.7.1~bpo11+1
vncterm: 1.7-1
zfsutils-linux: 2.1.5-pve1

# cat /etc/pve/jobs.cfg
vzdump: backup-01986f61-b55b
        schedule sun,mon..fri */3
        enabled 0
        mailnotification failure
        mailto xxxxxx@inworks.de
        mode snapshot
        storage javin
        vmid 100

vzdump: backup-8a4a078b-bc26
        schedule sat 00:00..17:00
        enabled 0
        mailnotification failure
        mailto xxxxxx@inworks.de
        mode snapshot
        notes-template {{guestname}}
        storage javin
        vmid 100

# cat /var/lib/pve-manager/jobs/vzdump-backup-01986f61-b55b.json
{"config":{"enabled":"0","schedule":"sun,mon..fri */3"},"msg":"job errors","updated":1666616375,"state":"stopped","upid":"UPID:anaxes:0030BDCC:13A3A81B:63568C14:vzdump:100:root@pam:"}

Ausschnitt aus /var/log/syslog:

Oct 24 14:39:00 anaxes pvescheduler[78896]: <root@pam> starting task UPID:anaxes:00013431:13A1D347:63568764:vzdump:100:root@pam:
Oct 24 14:39:00 anaxes pvescheduler[78897]: INFO: starting new backup job: vzdump 100 --mailnotification failure --mailto xxxxxx@inworks.de --storage javin --mode snapshot --quiet 1
Oct 24 14:39:00 anaxes pvescheduler[78897]: INFO: Starting Backup of VM 100 (qemu)
Oct 24 14:43:54 anaxes pmxcfs[4901]: [dcdb] notice: data verification successful
Oct 24 14:58:47 anaxes pvescheduler[78897]: INFO: Finished Backup of VM 100 (00:19:47)
Oct 24 14:58:47 anaxes pvescheduler[78897]: INFO: Backup job finished successfully
Oct 24 14:59:00 anaxes pvescheduler[3194315]: <root@pam> starting task UPID:anaxes:0030BDCC:13A3A81B:63568C14:vzdump:100:root@pam:
Oct 24 14:59:00 anaxes pvescheduler[3194316]: INFO: starting new backup job: vzdump 100 --quiet 1 --storage javin --mode snapshot --mailto xxxxxx@inworks.de --mailnotification failure
Oct 24 14:59:00 anaxes pvescheduler[3194316]: INFO: Starting Backup of VM 100 (qemu)
Oct 24 14:59:06 anaxes pvescheduler[3194316]: VM 100 qmp command failed - VM 100 qmp command 'backup' failed - backup connect failed: command error: unable to acquire lock on snapshot directory "/mnt/datastore/zbackup/vm/100/2022-10-24T12:39:00Z" - base snapshot is already locked by another operation
Oct 24 14:59:06 anaxes pvescheduler[3194316]: ERROR: Backup of VM 100 failed - VM 100 qmp command 'backup' failed - backup connect failed: command error: unable to acquire lock on snapshot directory "/mnt/datastore/zbackup/vm/100/2022-10-24T12:39:00Z" - base snapshot is already locked by another operation
Oct 24 14:59:06 anaxes pvescheduler[3194316]: INFO: Backup job finished with errors
Oct 24 14:59:06 anaxes pvescheduler[3194316]: job errors

In der /etc/pve/vzdump.cron steht außer einer PATH-Variable nichts drin.

 

[fiona]

# cat /etc/pve/jobs.cfg
vzdump: backup-01986f61-b55b
        schedule sun,mon..fri */3
        enabled 0
        mailnotification failure
        mailto xxxxxx@inworks.de
        mode snapshot
        storage javin
        vmid 100

Dieser Schedule ist alle 3 Minuten. Also wenn ein Backup länger braucht startet das nächste sofort danach.

vzdump: backup-8a4a078b-bc26
        schedule sat 00:00..17:00
        enabled 0
        mailnotification failure
        mailto xxxxxx@inworks.de
        mode snapshot
        notes-template {{guestname}}
        storage javin
        vmid 100

Dieser Schedule führt den Job jede Minute zwischen 00:00 und 00:17 aus. Wahrscheinlich meintest Du 00..17:00:00, weil .. stärker bindet als :. Es gibt einen Schedule Simulator-Knopf in der GUI, mit dem Du testen kannst und hier ist die Dokumentation.