[SOLVED] Unregelmäßige Fehler beim Backup von zwei verbundenen Nodes

[Stefan_Malte_Schumacher]

Hallo

Wir haben einen zwei miteinander verbundene Nodes, auf dem im Wesentlichen das bisschen Windows läuft, dem wir nicht entkommen sind. Das ganze wird auf einem Proxmox-Backup-Server gesichert. Dieser Server ist sehr aktiv und wird von vielen PVE-Nodes täglich und ohne Fehler benutzt. Bei den beiden Nodes bekommen wir Fehlermeldungen folgendes Typs und zwar unregelmäßig, d.h. nicht immer auf der selben Node und es sind auch nicht immer die selben VMs betroffen. Was könnte da das Problem sein?

101: 2024-10-05 00:00:05 INFO: Starting Backup of VM 101 (qemu)
101: 2024-10-05 00:00:05 INFO: status = running
101: 2024-10-05 00:00:05 INFO: VM Name: vm-paperless-ngx
101: 2024-10-05 00:00:05 INFO: include disk 'scsi0' 'local-thinpool-ssd:vm-101-disk-0' 100G
101: 2024-10-05 00:00:05 INFO: backup mode: snapshot
101: 2024-10-05 00:00:05 INFO: ionice priority: 7
101: 2024-10-05 00:00:05 INFO: creating Proxmox Backup Server archive 'vm/101/2024-10-04T22:00:05Z'
101: 2024-10-05 00:00:05 INFO: issuing guest-agent 'fs-freeze' command
101: 2024-10-05 00:00:15 INFO: issuing guest-agent 'fs-thaw' command
101: 2024-10-05 00:00:15 ERROR: VM 101 qmp command 'backup' failed - backup connect failed: command error: Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)
101: 2024-10-05 00:00:15 INFO: aborting backup job
101: 2024-10-05 00:00:15 INFO: resuming VM again
101: 2024-10-05 00:00:15 ERROR: Backup of VM 101 failed - VM 101 qmp command 'backup' failed - backup connect failed: command error: Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)

Woher kommen diese Fehler? Hardware-Probleme auf gleich zwei Nodes erscheint mir zumindest unwahrscheinlich. Angeschlossen sind die beiden über ein Bond-Interface mit LACP an zwei verschiedene Cisco-Switche.

Und hier noch ein pveversion -v:
pveversion
pve-manager/8.2.4/faa83925c9641325 (running kernel: 6.8.12-1-pve)
root@server243-116:~# pveversion -v
proxmox-ve: 8.2.0 (running kernel: 6.8.12-1-pve)
pve-manager: 8.2.4 (running version: 8.2.4/faa83925c9641325)
proxmox-kernel-helper: 8.1.0
pve-kernel-6.2: 8.0.5
proxmox-kernel-6.8: 6.8.12-1
proxmox-kernel-6.8.12-1-pve-signed: 6.8.12-1
proxmox-kernel-6.8.8-4-pve-signed: 6.8.8-4
proxmox-kernel-6.5.13-6-pve-signed: 6.5.13-6
proxmox-kernel-6.5: 6.5.13-6
proxmox-kernel-6.5.11-8-pve-signed: 6.5.11-8
proxmox-kernel-6.2.16-20-pve: 6.2.16-20
proxmox-kernel-6.2: 6.2.16-20
pve-kernel-6.2.16-3-pve: 6.2.16-3
ceph-fuse: 17.2.6-pve1+3
corosync: 3.1.7-pve3
criu: 3.17.1-2
glusterfs-client: 10.3-5
ifupdown2: 3.2.0-1+pmx9
ksm-control-daemon: 1.5-1
libjs-extjs: 7.0.0-4
libknet1: 1.28-pve1
libproxmox-acme-perl: 1.5.1
libproxmox-backup-qemu0: 1.4.1
libproxmox-rs-perl: 0.3.3
libpve-access-control: 8.1.4
libpve-apiclient-perl: 3.3.2
libpve-cluster-api-perl: 8.0.7
libpve-cluster-perl: 8.0.7
libpve-common-perl: 8.2.2
libpve-guest-common-perl: 5.1.4
libpve-http-server-perl: 5.1.0
libpve-network-perl: 0.9.8
libpve-rs-perl: 0.8.9
libpve-storage-perl: 8.2.3
libspice-server1: 0.15.1-1
lvm2: 2.03.16-2
lxc-pve: 6.0.0-1
lxcfs: 6.0.0-pve2
novnc-pve: 1.4.0-3
proxmox-backup-client: 3.2.7-1
proxmox-backup-file-restore: 3.2.7-1
proxmox-firewall: 0.5.0
proxmox-kernel-helper: 8.1.0
proxmox-mail-forward: 0.2.3
proxmox-mini-journalreader: 1.4.0
proxmox-widget-toolkit: 4.2.3
pve-cluster: 8.0.7
pve-container: 5.1.12
pve-docs: 8.2.3
pve-edk2-firmware: 4.2023.08-4
pve-esxi-import-tools: 0.7.1
pve-firewall: 5.0.7
pve-firmware: 3.13-1
pve-ha-manager: 4.0.5
pve-i18n: 3.2.2
pve-qemu-kvm: 9.0.2-2
pve-xtermjs: 5.3.0-3
qemu-server: 8.2.4
smartmontools: 7.3-pve1
spiceterm: 3.3.0
swtpm: 0.8.0+pve1
vncterm: 1.8.0
zfsutils-linux: 2.2.4-pve1

Viele Grüße
Stefan

VMID	Name	Status	Time	Size	Filename
101	vm-paperless-ngx	err	10s	0 B	null
201	deb12-Malte	err	11s	0 B	null

 

[Chris]

Unable to acquire lock "/var/log/proxmox-backup/tasks/.active.lock" - Interrupted system call (os error 4)

Hallo,

sieht so aus also ob das task list file lock in ein timeout läuft (10 Sekunden scheinen nicht zu reichen?). Ein kurzer blick in den Code zeigt, dass das lock vermutlich vom logrotate, welches ebenfalls via scheduler um Mitternacht ausgeführt wird gehalten wird. Bitte den entsprechenden task log zum log rotate auf PBS Seite posten. Dies sollte eigentlich nicht so lange benötigen.

Es reicht hier vermutlich den backup Job um ein paar Minuten nach hinten zu verlegen, sodass der log rotate job das file lock bereits wieder frei gegeben hat.

 

[Stefan_Malte_Schumacher]

sieht so aus also ob das task list file lock in ein timeout läuft (10 Sekunden scheinen nicht zu reichen?). Ein kurzer blick in den Code zeigt, dass das lock vermutlich vom logrotate, welches ebenfalls via scheduler um Mitternacht ausgeführt wird gehalten wird. Bitte den entsprechenden task log zum log rotate auf PBS Seite posten. Dies sollte eigentlich nicht so lange benötigen.

Wo auf der PBS-Seite? Ist der folgende Log-Eintrag aus Administration - Tasks - Logrotate - der, den du benötigst?

2024-10-08T00:00:00+02:00: starting task log rotation
2024-10-08T00:00:00+02:00: task log archive was not rotated
2024-10-08T00:00:05+02:00: API access log was rotated
2024-10-08T00:00:05+02:00: API authentication log was rotated
2024-10-08T00:00:05+02:00: TASK OK


Ich habe mir mal ~ 10 Einträge angeschaut und die sehen alle ziemlich gleich aus. Keine Fehler.

Es reicht hier vermutlich den backup Job um ein paar Minuten nach hinten zu verlegen, sodass der log rotate job das file lock bereits wieder frei gegeben hat.

Das habe ich gerade gemacht, ich poste das Ergebnis morgen vormittag.

Viele Grüße
Stefan

 

[Chris]

Wo auf der PBS-Seite? Ist der folgende Log-Eintrag aus Administration - Tasks - Logrotate - der, den du benötigst?

2024-10-08T00:00:00+02:00: starting task log rotation
2024-10-08T00:00:00+02:00: task log archive was not rotated
2024-10-08T00:00:05+02:00: API access log was rotated
2024-10-08T00:00:05+02:00: API authentication log was rotated
2024-10-08T00:00:05+02:00: TASK OK

Ja, genau diese tasks, aber das schaut soweit eigentlich OK aus, um 00:00:05 ist der task fertig.

Das habe ich gerade gemacht, ich poste das Ergebnis morgen vormittag.

Okay, eventuell dann auch gleich das systemd journal rund um MItternacht und die task logs der tasks welche in etwa um die selbe Zeit ausgeführt werden posten, falls das problem weiterhin besteht. Vielleicht gibt das ja Aufschluss wer das lock halten könnte.

 

[Stefan_Malte_Schumacher]

Heute nacht lief alles durch, ich habe gerade die Logs gecheckt. Ich bedanke mich für die kompetente Unterstützung.
Viele Grüße
Stefan