Automatisches VM Backup schlägt fehl

[LuiMen]

Hallo,

in unregelmäßigen Abständen habe ich das Problem, dass das automatische nächtliche Backup bei immer der selben VM fehlschlägt.

Nachdem das Backup fehlgeschlagen ist, hängt sich bei dieser VM auch immer die Konsole kompklett auf. Ich muss die VM dann hart stoppen.

Im Backup Log tauchen dann auch Fehler auf:

INFO: starting new backup job: vzdump 101 103 --prune-backups 'keep-last=4' --quiet 1 --node ex-DUS4-1A2013 --mode stop --storage sdbRyzen --mailto mail@lmengel.de --compress zstd --mailnotification always
INFO: Starting Backup of VM 101 (qemu)
INFO: Backup started at 2022-06-29 00:30:01
INFO: status = running
INFO: backup mode: stop
INFO: ionice priority: 7
INFO: VM Name: Gitlab
INFO: include disk 'sata0' 'local:101/vm-101-disk-0.qcow2' 150G
INFO: stopping virtual guest
INFO: creating vzdump archive '/mnt/sdb/dump/vzdump-qemu-101-2022_06_29-00_30_01.vma.zst'
INFO: starting kvm to execute backup task
INFO: started backup task 'd704b2b4-3c6b-4d1b-bab3-8b2a87f75a93'
INFO: resuming VM again after 35 seconds
INFO:   1% (2.5 GiB of 150.0 GiB) in 3s, read: 844.6 MiB/s, write: 244.4 MiB/s
INFO:   2% (3.6 GiB of 150.0 GiB) in 6s, read: 392.5 MiB/s, write: 279.5 MiB/s
INFO:   3% (4.8 GiB of 150.0 GiB) in 9s, read: 390.5 MiB/s, write: 303.6 MiB/s
INFO:   4% (6.4 GiB of 150.0 GiB) in 13s, read: 417.8 MiB/s, write: 313.3 MiB/s
INFO:   5% (7.8 GiB of 150.0 GiB) in 17s, read: 368.8 MiB/s, write: 311.7 MiB/s
INFO:   6% (9.2 GiB of 150.0 GiB) in 21s, read: 336.2 MiB/s, write: 293.0 MiB/s
INFO:   7% (10.6 GiB of 150.0 GiB) in 25s, read: 361.6 MiB/s, write: 331.0 MiB/s
INFO:   8% (12.3 GiB of 150.0 GiB) in 30s, read: 345.1 MiB/s, write: 296.4 MiB/s
INFO:   9% (13.6 GiB of 150.0 GiB) in 34s, read: 345.3 MiB/s, write: 338.5 MiB/s
INFO:  10% (15.2 GiB of 150.0 GiB) in 39s, read: 325.5 MiB/s, write: 287.7 MiB/s
INFO:  11% (16.8 GiB of 150.0 GiB) in 44s, read: 337.1 MiB/s, write: 303.2 MiB/s
INFO:  12% (18.4 GiB of 150.0 GiB) in 47s, read: 531.7 MiB/s, write: 389.9 MiB/s
INFO:  13% (19.5 GiB of 150.0 GiB) in 50s, read: 377.8 MiB/s, write: 326.5 MiB/s
INFO:  14% (21.2 GiB of 150.0 GiB) in 53s, read: 569.5 MiB/s, write: 346.9 MiB/s
INFO:  15% (22.7 GiB of 150.0 GiB) in 57s, read: 382.4 MiB/s, write: 304.2 MiB/s
INFO:  16% (24.0 GiB of 150.0 GiB) in 1m 1s, read: 343.5 MiB/s, write: 300.4 MiB/s
INFO:  17% (25.7 GiB of 150.0 GiB) in 1m 7s, read: 294.8 MiB/s, write: 253.4 MiB/s
INFO:  18% (27.1 GiB of 150.0 GiB) in 1m 12s, read: 282.0 MiB/s, write: 237.3 MiB/s
INFO:  19% (28.6 GiB of 150.0 GiB) in 1m 17s, read: 311.0 MiB/s, write: 279.4 MiB/s
INFO:  20% (30.3 GiB of 150.0 GiB) in 1m 23s, read: 285.8 MiB/s, write: 256.4 MiB/s
INFO:  21% (31.7 GiB of 150.0 GiB) in 1m 27s, read: 348.0 MiB/s, write: 323.8 MiB/s
INFO:  22% (33.2 GiB of 150.0 GiB) in 1m 30s, read: 531.7 MiB/s, write: 349.4 MiB/s
INFO:  23% (34.6 GiB of 150.0 GiB) in 1m 34s, read: 358.9 MiB/s, write: 308.9 MiB/s
INFO:  24% (36.3 GiB of 150.0 GiB) in 1m 38s, read: 428.7 MiB/s, write: 323.5 MiB/s
INFO:  25% (37.7 GiB of 150.0 GiB) in 1m 43s, read: 292.9 MiB/s, write: 282.3 MiB/s
INFO:  26% (40.1 GiB of 150.0 GiB) in 1m 46s, read: 823.4 MiB/s, write: 346.4 MiB/s
INFO:  28% (42.3 GiB of 150.0 GiB) in 1m 49s, read: 747.5 MiB/s, write: 222.0 MiB/s
INFO:  29% (43.8 GiB of 150.0 GiB) in 1m 54s, read: 300.9 MiB/s, write: 298.2 MiB/s
INFO:  31% (47.5 GiB of 150.0 GiB) in 1m 58s, read: 949.1 MiB/s, write: 218.9 MiB/s
INFO:  36% (54.2 GiB of 150.0 GiB) in 2m 1s, read: 2.2 GiB/s, write: 145.0 MiB/s
INFO:  41% (62.2 GiB of 150.0 GiB) in 2m 4s, read: 2.7 GiB/s, write: 143.0 MiB/s
INFO:  48% (72.0 GiB of 150.0 GiB) in 2m 8s, read: 2.5 GiB/s, write: 73.2 MiB/s
INFO:  57% (86.0 GiB of 150.0 GiB) in 2m 11s, read: 4.7 GiB/s, write: 12.2 MiB/s
INFO:  66% (100.0 GiB of 150.0 GiB) in 2m 14s, read: 4.7 GiB/s, write: 0 B/s
INFO:  76% (114.3 GiB of 150.0 GiB) in 2m 17s, read: 4.8 GiB/s, write: 0 B/s
INFO:  85% (128.5 GiB of 150.0 GiB) in 2m 21s, read: 3.6 GiB/s, write: 0 B/s
INFO:  95% (143.0 GiB of 150.0 GiB) in 2m 24s, read: 4.8 GiB/s, write: 0 B/s
ERROR: VM 101 qmp command 'query-backup' failed - got timeout
INFO: aborting backup job
ERROR: VM 101 qmp command 'backup-cancel' failed - unable to connect to VM 101 qmp socket - timeout after 5993 retries
INFO: resuming VM again
ERROR: Backup of VM 101 failed - VM 101 qmp command 'cont' failed - unable to connect to VM 101 qmp socket - timeout after 451 retries
INFO: Failed at 2022-06-29 00:53:47

 

[LuiMen]

Auch ein normales stoppen war nicht erfolgreich:

VM quit/powerdown failed - terminating now with SIGTERM
VM still running - terminating now with SIGKILL
TASK OK

 

[itNGO]

In Verbindung mit PBS 2.2x ist das auch schon aufgetaucht.
Vielleicht ein Problem im aktuellen PVE 7.2? Kann deine Version leider nicht sehen....

 

[LuiMen]

In Verbindung mit PBS 2.2x ist das auch schon aufgetaucht.
Vielleicht ein Problem im aktuellen PVE 7.2? Kann deine Version leider nicht sehen....

Hi,

ich nutze: Virtual Environment 7.2-5

 

[mira]

Wie sieht denn der Output von pveversion -v aus?
Bitte auch den Output von qm config 101 dazu.

Da es sich um einen Directory Storage handelt, worauf ist dieser aufgesetzt? HDDs/SSDs/NVMes?
Hardware RAID, Software RAID, Single Disk?

Um welches Diskmodell handelt es sich?

Wie sieht die CPU/Speicher/Disk Auslastung zu dem Zeitpunkt aus?
I/O Wait sehr hoch?

 

[LuiMen]

Wie sieht denn der Output von pveversion -v aus?
Bitte auch den Output von qm config 101 dazu.

Da es sich um einen Directory Storage handelt, worauf ist dieser aufgesetzt? HDDs/SSDs/NVMes?
Hardware RAID, Software RAID, Single Disk?

Um welches Diskmodell handelt es sich?

Wie sieht die CPU/Speicher/Disk Auslastung zu dem Zeitpunkt aus?
I/O Wait sehr hoch?

Hi,

pveversion -v:

proxmox-ve: 7.2-1 (running kernel: 5.15.35-3-pve)
pve-manager: 7.2-5 (running version: 7.2-5/12f1e639)
pve-kernel-5.15: 7.2-5
pve-kernel-helper: 7.2-5
pve-kernel-5.15.35-3-pve: 5.15.35-6
pve-kernel-5.15.35-2-pve: 5.15.35-5
ceph-fuse: 14.2.21-1
corosync: 3.1.5-pve2
criu: 3.15-1+pve-1
glusterfs-client: 9.2-1
ifupdown: residual config
ifupdown2: 3.1.0-1+pmx3
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-2
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-2
libpve-storage-perl: 7.2-5
libspice-server1: 0.14.3-2.1
lvm2: 2.03.11-2.1
lxc-pve: 4.0.12-1
lxcfs: 4.0.12-pve1
novnc-pve: 1.3.0-3
proxmox-backup-client: 2.2.3-1
proxmox-backup-file-restore: 2.2.3-1
proxmox-mini-journalreader: 1.3-1
proxmox-widget-toolkit: 3.5.1
pve-cluster: 7.2-1
pve-container: 4.2-1
pve-docs: 7.2-2
pve-edk2-firmware: 3.20210831-2
pve-firewall: 4.2-5
pve-firmware: 3.4-2
pve-ha-manager: 3.3-4
pve-i18n: 2.7-2
pve-qemu-kvm: 6.2.0-10
pve-xtermjs: 4.16.0-1
qemu-server: 7.2-3
smartmontools: 7.2-pve3
spiceterm: 3.2-2
swtpm: 0.7.1~bpo11+1
vncterm: 1.7-1
zfsutils-linux: 2.1.4-pve1

qm config 101:

boot: order=sata0;ide2;net0
cores: 2
ide2: none,media=cdrom
memory: 4096
meta: creation-qemu=6.2.0,ctime=1655155446
name: Gitlab
net0: virtio=C6:F7:63:85:5E:79,bridge=vmbr0,firewall=1
numa: 0
onboot: 1
ostype: l26
sata0: local:101/vm-101-disk-0.qcow2,size=150G,ssd=1
scsihw: virtio-scsi-pci
smbios1: uuid=abd45cf0-ca42-4bd0-996c-2c0cc89b67c5
sockets: 1
vmgenid: 3197d430-ca3f-4eda-8f2a-a631a39b79ef

Bei dem Host sind 2 1TB SSDs eingebaut, die unter keinem RAID betrieben werden.
CPU ist zu ca. 10% ausgelastet, RAM: ca. 20 %, DISK space: ca. 30%
I/O Delay liegt bei ca. 0.00 bis 0.10%

 

[mira]

Vielen Dank für die Infos!

Wenn die VM erneut hängen bleibt, wäre es möglich den Output von ps aux zu holen?
Hier wäre interessant ob der/ein Prozess eventuell im D State hängt. Dies wäre ein `Uninterruptible Sleep` in dem der Prozess auf I/O wartet.
Dies kann endlos hängen in manchen Fällen, z.B. weil ein NFS Storage nicht mehr erreichbar ist.

Sollte zwar bei local SSD Storage nicht der Fall sein, aber wäre dennoch gut zu wissen.

 

[Moonlander]

Ich hänge mich hier mal mit an - ich habe nämlich genau das selbe Problem. In einem 3-Knoten-Cluster fährt sich das Backup für eine VM (id:100) immer fest. Die letzte Zeile lautet:

INFO:   0% (1.3 GiB of 720.0 GiB) in 3s, read: 444.0 MiB/s, write: 1.3 MiB/s

, danach tut sich dann nichts mehr, bis eben der qmp timeout kommt.

Wenn ich dann (natürlich per "qm unlock 100") das Backup manuell starte, steht dort nur noch:

INFO: stopping virtual guest
INFO: VM 100 qmp command 'query-status' failed - unable to connect to VM 100 qmp socket - timeout after 31 retries
INFO: VM quit/powerdown failed
ERROR: Backup of VM 100 failed - command 'qm shutdown 100 --skiplock --keepActive --timeout 600' failed: exit code 255

Die VM hat 3 Platten, von denen die ersten beiden in einem Ceph-Pool liegen, der per Crush-Rule auf NVMe-Platten festgelegt ist (je Knoten 2x Samsung PM9A3 4TB-Platten), und die dritte in einem relativ langsamen HDD-Pool.

Es gibt in meinem Fall in der Liste von `ps aux` übrigens keinen Prozess im Zustand "D".

EDIT: Und eine Migration auf einen anderen Knoten bringt auch nichts - obige Zeile "INFO: 0% ..." ist die letzte, die ich sehe.

Ideen? Vielen Dank von meiner Seite!

 

[mira]

Was läuft denn in der VM?
Ist der Guest Agent aktiv?

 

[Moonlander]

Hi Mira, die VM beherbergt eine minimale Installation von Ubuntu 20.04 LTS mit Gitea. Guest-Agent ist nicht aktiv. Dazu sagen sollte ich aber, dass ich es im "Stop"-Mode versucht habe (und nicht im Snapshot-Mode).

Nach einem Neustart des gesamten Clusters ist das Problem jetzt übrigens (aktuell?) weg, das Backup auf den PBS hat funktioniert; dafür hat mich der Cluster heute Nacht benachrichtigt, dass das Backup einer weitern VM nicht durchgeführt werden konnte, weil die gesperrt (locked) ist. Anscheinend hat der Backup-Lauf in der vorigen Nacht (der laut Benachrichtigungsmail des Clusters aber erfolgreich war) das Lock nicht aufgehoben.

Dieser Cluster ist aktuell in der Evaluationsphase, und eigentlich wollte ich diese Woche Enterprise-Lizenzen für die Nodes und den Backup-Server kaufen, aber offen gestanden zögere ich jetzt doch wieder; die Backups sollten schon absolut reibungslos laufen. Deshalb wäre ich schon dankbar, wenn wir dem Problem weiter auf den Grund gehen könnten, obwohl es im Moment nicht mehr besteht.

 

[mira]

Wie ist denn der Output von pveversion -v?
Findet sich etwas im Journal um die Zeit des Backups herum?

 

[BoehserWolf]

Auch ich reihe mich hier mit ein:

vzdump[363079]: INFO: starting new backup job: vzdump 228 --compress gzip --mode snapshot --mailto root --prune-backups 'keep-last=5' --dumpdir /blablabla/proxmox --pigz 1
vzdump[363079]: INFO: Starting Backup of VM 228 (qemu)
pvestatd[1706]: VM 228 qmp command failed - VM 228 qmp command 'query-proxmox-support' failed - got timeout
pvestatd[1706]: status update time (8.321 seconds)
pvestatd[1706]: VM 228 qmp command failed - VM 228 qmp command 'query-proxmox-support' failed - unable to connect to VM 228 qmp socket - timeout after 51 retries

Der Output von pveversion -v ist wie folgt:

proxmox-ve: 7.3-1 (running kernel: 5.15.83-1-pve)
pve-manager: 7.3-4 (running version: 7.3-4/d69b70d4)
pve-kernel-helper: 7.3-2
pve-kernel-5.15: 7.3-1
pve-kernel-5.15.83-1-pve: 5.15.83-1
pve-kernel-5.15.60-1-pve: 5.15.60-1
ceph-fuse: 15.2.17-pve1
corosync: 3.1.7-pve1
criu: 3.15-1+pve-1
glusterfs-client: 9.2-1
ifupdown: residual config
ifupdown2: 3.1.0-1+pmx3
ksm-control-daemon: 1.4-1
libjs-extjs: 7.0.0-1
libknet1: 1.24-pve2
libproxmox-acme-perl: 1.4.3
libproxmox-backup-qemu0: 1.3.1-1
libpve-access-control: 7.3-1
libpve-apiclient-perl: 3.2-1
libpve-common-perl: 7.3-1
libpve-guest-common-perl: 4.2-3
libpve-http-server-perl: 4.1-5
libpve-storage-perl: 7.3-1
libqb0: 1.0.5-1
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
openvswitch-switch: 2.15.0+ds1-2+deb11u2
proxmox-backup-client: 2.3.2-1
proxmox-backup-file-restore: 2.3.2-1
proxmox-mini-journalreader: 1.3-1
proxmox-offline-mirror-helper: 0.5.0-1
proxmox-widget-toolkit: 3.5.3
pve-cluster: 7.3-2
pve-container: 4.4-2
pve-docs: 7.3-1
pve-edk2-firmware: 3.20220526-1
pve-firewall: 4.2-7
pve-firmware: 3.6-2
pve-ha-manager: 3.5.1
pve-i18n: 2.8-1
pve-qemu-kvm: 7.1.0-4
pve-xtermjs: 4.16.0-1
qemu-server: 7.3-2
smartmontools: 7.2-pve3
spiceterm: 3.2-2
swtpm: 0.8.0~bpo11+2
vncterm: 1.7-1
zfsutils-linux: 2.1.7-pve3

Einen Restart habe ich bereits durch. Danach kam das Problem leider wieder mit obigen Meldungen.

EDIT: EIn qm shutdown läuft ewig ins Timeout. Nur per qm stop lässt sich die VM beenden. Bei der VM handelt es sich um Windows 10. Danach kann sie neu gestartet werden, beim nächsten Backup tritt das Problem dann wieder auf.

 

[Falk R.]

Nach einem Neustart des gesamten Clusters ist das Problem jetzt übrigens (aktuell?) weg, das Backup auf den PBS hat funktioniert; dafür hat mich der Cluster heute Nacht benachrichtigt, dass das Backup einer weitern VM nicht durchgeführt werden konnte, weil die gesperrt (locked) ist. Anscheinend hat der Backup-Lauf in der vorigen Nacht (der laut Benachrichtigungsmail des Clusters aber erfolgreich war) das Lock nicht aufgehoben.

Das hatte ich auch schon einmal. Da hat ein qm unlock #vmid# geholfen. Danach lief wieder alles bestens.

 

[Falk R.]

Dieser Cluster ist aktuell in der Evaluationsphase, und eigentlich wollte ich diese Woche Enterprise-Lizenzen für die Nodes und den Backup-Server kaufen, aber offen gestanden zögere ich jetzt doch wieder; die Backups sollten schon absolut reibungslos laufen. Deshalb wäre ich schon dankbar, wenn wir dem Problem weiter auf den Grund gehen könnten, obwohl es im Moment nicht mehr besteht.

Ich habe schon einige Cluster Produktiv installiert und gar keine Probleme.
- ich habe immer die guest tools drauf, macht es auf jeden fall angenehmer
- Ceph mache ich nur noch all Flash, kostet ja nicht mehr so viel und läuft super performant, wenn das Netzwerk passt.
- PBS Backups mache ich immer im Snapshot mode und hatte mit diesem Setup nie Probleme.

Die einzigen Probleme beim Backup hatte ich in meiner Spielumgebung wenn ich auf sehr langsamen HDDs oder auf dem Mini Rechner mit 1,1 GHz Celeron rumgespielt habe. In der Regel war vor den Problemen immer ein hoher io delay.