VM Restore schlägt fehl?!

Skankhunt42

Member
May 25, 2021
27
0
6
Münster - NRW, Germany
Guten Tag,

ich hatte gehofft nicht in diese Lage zu kommen doch nun ist es leider so weit. Eine VM ist gestorben (warum auch immer - Proxmox hatte auf der Systemfestplatte kein Bootable OS mehr gefunden?!).
Nun hatte ich versucht eines meiner Backups wiederherzustellen. Da es eine sehr große VM ist, dauert dies leider relativ lange. Nach ca. 4 Stunden ist das Restore abgebrochen, dies ist bereits der zweite versuch gewesen, der erste restore job schlug mit dem selben Fehler fehl.


Code:
restore-drive-sata1: transferred 256.5 GiB of 810.0 GiB (31.67%) in 3h 40m 49s
restore-drive-sata1: stream-job finished
restore-drive jobs finished successfully, removing all tracking block devices to disconnect from Proxmox Backup Server
An error occurred during live-restore: VM 101 qmp command 'blockdev-del' failed - Node 'drive-sata0-pbs' is busy: node is used as backing hd of '#block057'

error before or during data restore, some or all disks were not completely restored. VM 101 state is NOT cleaned up.
TASK ERROR: live-restore failed


Woran könnte dies liegen? Ich hoffe die VM irgendwie wieder zu bekommen.

Vielen Dank schonmal.
 
kannst du es mal als "regulaeren" restore statt live-restore probieren? und fuer den abgebrochenen restore den ganzen log posten und am PBS auch nach dem korrespondierenden task log suchen und den log posten (eventuelle auffaellige messages im system log auf beiden seiten zum abbruch zeitpunkt waeren natuerlich auch interessant).
 
Hi,
bitte auch die Ausgabe von pveversion -v und die im Backup enthaltene VM-Konfiguration posten.
 
Es sieht mir so aus als würde es am Storage liegen. Dies ist aktuell ein QNAP NAS, welches über NFS am PBS gemountet ist.
Der QNAP scheint mit den ca. 65000 Subdirectories des .chunk folders Probleme zu haben. Ich bin gerade dabei zu versuchen alle Daten vom NAS auf eine Externe HDD zu verschieben (ich hoffe das klappt) und diese dann direkt am PBS zu Mounten und zu schauen, ob dies eine Lösung bringt.



Hier noch einmal ein Log Ausschnitt eines regulären Restores:


Code:
new volume ID is 'local-lvm:vm-101-disk-0'
Formatting '/mnt/pve/CD_Storage/images/101/vm-101-disk-0.raw', fmt=raw size=869730877440 preallocation=off
new volume ID is 'CD_Storage:101/vm-101-disk-0.raw'
restore proxmox backup image: /usr/bin/pbs-restore --repository root@pam@10.10.102.9:MADLEN-QNAP02 vm/101/2022-12-16T11:00:05Z drive-sata0.img.fidx /dev/pve/vm-101-disk-0 --verbose --format raw --keyfile /etc/pve/priv/storage/MADLEN-BAK01.enc --skip-zero
connecting to repository 'root@pam@10.10.102.9:MADLEN-QNAP02'
open block backend for target '/dev/pve/vm-101-disk-0'
starting to restore snapshot 'vm/101/2022-12-16T11:00:05Z'
download and verify backup index
progress 1% (read 1396703232 bytes, zeroes = 2% (29360128 bytes), duration 62 sec)
progress 2% (read 2793406464 bytes, zeroes = 2% (71303168 bytes), duration 107 sec)
progress 3% (read 4190109696 bytes, zeroes = 23% (973078528 bytes), duration 116 sec)
progress 4% (read 5586812928 bytes, zeroes = 28% (1614807040 bytes), duration 155 sec)
progress 5% (read 6979321856 bytes, zeroes = 23% (1656750080 bytes), duration 215 sec)
progress 6% (read 8376025088 bytes, zeroes = 19% (1656750080 bytes), duration 268 sec)
progress 7% (read 9772728320 bytes, zeroes = 17% (1707081728 bytes), duration 325 sec)
progress 8% (read 11169431552 bytes, zeroes = 15% (1786773504 bytes), duration 377 sec)
progress 9% (read 12566134784 bytes, zeroes = 14% (1786773504 bytes), duration 434 sec)
progress 10% (read 13958643712 bytes, zeroes = 13% (1895825408 bytes), duration 482 sec)
progress 11% (read 15355346944 bytes, zeroes = 12% (1929379840 bytes), duration 535 sec)
progress 12% (read 16752050176 bytes, zeroes = 11% (1929379840 bytes), duration 579 sec)
progress 13% (read 18148753408 bytes, zeroes = 11% (2051014656 bytes), duration 623 sec)
progress 14% (read 19545456640 bytes, zeroes = 11% (2176843776 bytes), duration 680 sec)
progress 15% (read 20937965568 bytes, zeroes = 10% (2181038080 bytes), duration 748 sec)
progress 16% (read 22334668800 bytes, zeroes = 10% (2315255808 bytes), duration 814 sec)
progress 17% (read 23731372032 bytes, zeroes = 10% (2420113408 bytes), duration 881 sec)
progress 18% (read 25128075264 bytes, zeroes = 9% (2453667840 bytes), duration 922 sec)
progress 19% (read 26524778496 bytes, zeroes = 9% (2575302656 bytes), duration 971 sec)
progress 20% (read 27917287424 bytes, zeroes = 9% (2575302656 bytes), duration 1025 sec)
progress 21% (read 29313990656 bytes, zeroes = 9% (2696937472 bytes), duration 1075 sec)
progress 22% (read 30710693888 bytes, zeroes = 10% (3133145088 bytes), duration 1114 sec)
progress 23% (read 32107397120 bytes, zeroes = 13% (4475322368 bytes), duration 1116 sec)
progress 24% (read 33504100352 bytes, zeroes = 17% (5851054080 bytes), duration 1116 sec)
progress 25% (read 34896609280 bytes, zeroes = 20% (7184842752 bytes), duration 1117 sec)
progress 26% (read 36293312512 bytes, zeroes = 23% (8581545984 bytes), duration 1117 sec)
progress 27% (read 37690015744 bytes, zeroes = 23% (8904507392 bytes), duration 1149 sec)
restore failed: reading file "/mnt/QNAP_Datastore/.chunks/9720/9720568f86be4451724a42eaa5d7def2c2fa543185edcde9b95cf0e3ae0ddae3" failed: No such file or directory (os error 2)
temporary volume 'CD_Storage:101/vm-101-disk-0.raw' sucessfuly removed
  Logical volume "vm-101-disk-0" successfully removed
temporary volume 'local-lvm:vm-101-disk-0' sucessfuly removed
error before or during data restore, some or all disks were not completely restored. VM 101 state is NOT cleaned up.
TASK ERROR: command '/usr/bin/pbs-restore --repository root@pam@10.10.102.9:MADLEN-QNAP02 vm/101/2022-12-16T11:00:05Z drive-sata0.img.fidx /dev/pve/vm-101-disk-0 --verbose --format raw --keyfile /etc/pve/priv/storage/MADLEN-BAK01.enc --skip-zero' failed: exit code 255

PBS Task Log:



Code:
Dec 19 00:44:23 MADLEN-BAK01 proxmox-backup-proxy[689]: download chunk "/mnt/QNAP_Datastore/.chunks/60b7/60b728944d6ef11d81bf3378bd254d5ce2e34446f1eb2e792e70b9400d3b3f5a"
Dec 19 00:44:23 MADLEN-BAK01 proxmox-backup-proxy[689]: unable to parse worker status 'UPID:MADLENUPID:MADLEN-BAK01:000002C9:00000AEB:00000026:63167163:backup:MADLEN\x2dQNAP02\x3avm-101:root@pam: 63168805 OK' - unable to parse UPID 'UPID:MADLENUPID:MADLEN-BAK01:000002C9:00000AEB:00000026:63167163:backup:MADLEN\x2dQNAP02\x3avm-101:root@pam:'
 "/mnt/QNAP_Datastore/.chunks/9720/9720568f86be4451724a42eaa5d7def2c2fa543185edcde9b95cf0e3ae0ddae3"
Dec 19 00:44:27 MADLEN-BAK01 proxmox-backup-proxy[689]: GET /chunk: 400 Bad Request: reading file "/mnt/QNAP_Datastore/.chunks/9720/9720568f86be4451724a42eaa5d7def2c2fa543185edcde9b95cf0e3ae0ddae3" failed: No such file or directory (os error 2)
Dec 19 00:44:27 MADLEN-BAK01 proxmox-backup-proxy[689]: reader finished successfully
Dec 19 00:44:27 MADLEN-BAK01 proxmox-backup-proxy[689]: TASK OK
Dec 19 00:44:39 MADLEN-BAK01 proxmox-backup-proxy[689]: unable to parse worker status 'UPID:MADLENUPID:MADLEN-BAK01:000002C9:00000AEB:00000026:63167163:backup:MADLEN\x2dQNAP02\x3avm-101:root@pam: 63168805 OK' - unable to parse UPID 'UPID:MADLENUPID:MADLEN-BAK01:000002C9:00000AEB:00000026:63167163:backup:MADLEN\x2dQNAP02\x3avm-101:root@pam:'
Dec 19 00:44:49 MADLEN-BAK01 proxmox-backup-proxy[689]: starting new backup reader datastore 'MADLEN-QNAP02': "/mnt/QNAP_Datastore"
Dec 19 00:44:49 MADLEN-BAK01 proxmox-backup-proxy[689]: protocol upgrade done
Dec 19 00:44:49 MADLEN-BAK01 proxmox-backup-proxy[689]: GET /download
Dec 19 00:44:49 MADLEN-BAK01 proxmox-backup-proxy[689]: download "/mnt/QNAP_Datastore/vm/101/2022-12-16T11:00:05Z/index.json.blob"
Dec 19 00:44:49 MADLEN-BAK01 proxmox-backup-proxy[689]: GET /download
Dec 19 00:44:49 MADLEN-BAK01 proxmox-backup-proxy[689]: download "/mnt/QNAP_Datastore/vm/101/2022-12-16T11:00:05Z/qemu-server.conf.blob"
Dec 19 00:44:49 MADLEN-BAK01 proxmox-backup-proxy[689]: reader finished successfully
Dec 19 00:44:49 MADLEN-BAK01 proxmox-backup-proxy[689]: TASK OK
Dec 19 00:44:55 MADLEN-BAK01 proxmox-backup-proxy[689]: error during snapshot file listing: 'unable to load blob '"/mnt/QNAP_Datastore/vm/100/2022-09-04T02:30:00Z/index.json.blob"' - No such file or directory (os error 2)'
Dec 19 00:44:55 MADLEN-BAK01 proxmox-backup-proxy[689]: unable to parse worker status 'UPID:MADLENUPID:MADLEN-BAK01:000002C9:00000AEB:00000026:63167163:backup:MADLEN\x2dQNAP02\x3avm-101:root@pam: 63168805 OK' - unable to parse UPID 'UPID:MADLENUPID:MADLEN-BAK01:000002C9:00000AEB:00000026:63167163:backup:MADLEN\x2dQNAP02\x3avm-101:root@pam:'
Dec 19 00:44:56 MADLEN-BAK01 proxmox-backup-proxy[689]: error during snapshot file listing: 'unable to load blob '"/mnt/QNAP_Datastore/vm/101/2022-12-18T11:00:04Z/index.json.blob"' - No such file or directory (os error 2)'


PVE Version:


Code:
~# pveversion -v
proxmox-ve: 7.3-1 (running kernel: 5.15.74-1-pve)
pve-manager: 7.3-3 (running version: 7.3-3/c3928077)
pve-kernel-helper: 7.3-1
pve-kernel-5.15: 7.2-14
pve-kernel-5.13: 7.1-9
pve-kernel-5.15.74-1-pve: 5.15.74-1
pve-kernel-5.15.64-1-pve: 5.15.64-1
pve-kernel-5.15.60-2-pve: 5.15.60-2
pve-kernel-5.15.60-1-pve: 5.15.60-1
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.15.39-3-pve: 5.15.39-3
pve-kernel-5.15.39-2-pve: 5.15.39-2
pve-kernel-5.15.39-1-pve: 5.15.39-1
pve-kernel-5.15.35-3-pve: 5.15.35-6
pve-kernel-5.15.35-2-pve: 5.15.35-5
pve-kernel-5.15.35-1-pve: 5.15.35-3
pve-kernel-5.13.19-6-pve: 5.13.19-15
pve-kernel-5.13.19-4-pve: 5.13.19-9
pve-kernel-5.13.19-3-pve: 5.13.19-7
pve-kernel-5.13.19-2-pve: 5.13.19-4
ceph: 16.2.9-pve1
ceph-fuse: 16.2.9-pve1
corosync: 3.1.7-pve1
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-pve2
libproxmox-acme-perl: 1.4.3
libproxmox-backup-qemu0: 1.3.1-1
libpve-access-control: 7.2-5
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
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.3.1-1
proxmox-backup-file-restore: 2.3.1-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-1
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-1
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-1
smartmontools: 7.2-pve3
spiceterm: 3.2-2
swtpm: 0.8.0~bpo11+2
vncterm: 1.7-1
zfsutils-linux: 2.1.6-pve1


VM Config:

Code:
agent: 1
balloon: 6140
bootdisk: sata0
cores: 4
cpu: Broadwell
cpuunits: 1050
memory: 10240
name: MADLEN-CloudDrive
net0: e1000=0A:0C:51:AF:72:CE,bridge=vmbr0,tag=102
numa: 0
onboot: 1
ostype: l26
sata0: local-lvm:vm-101-disk-0,size=130G
sata1: CD_Storage:101/vm-101-disk-0.raw,size=870G
scsihw: virtio-scsi-pci
smbios1: uuid=8527197d-ffd1-49e9-ae72-7c23d7a352fd
sockets: 1
startup: order=3,up=400,down=20
tags: linux;ubuntu
vcpus: 4
vga: std,memory=16
vmgenid: 6fa0ed76-ac02-45a6-b09f-a10ab4aace23
#qmdump#map:sata0:drive-sata0:local-lvm:raw:
#qmdump#map:sata1:drive-sata1:CD_Storage:raw:
 
Last edited:
Könnte sein, ich kann es nur vermuten.
Ich muss jetzt erstmal zusehen, dass ich die VM wieder ans Laufen bekomme. Über das File Restore scheine ich zumindest noch an alle Daten zu gelangen...

Mal sehen wie es ausgeht...
Nachdem die VM Läuft werde ich auf Ursachenprüfung des fehlerhaften Backups gehen, evtl. den PBS neu aufsetzen und den Datastore als iSCSI Block in PBS bereitstellen.
 

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!

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!