Snapshot failed to rollback

[MoreDakka]

Windows VM
Wanted to test snapshot rollbacks, this is what happened:



Task viewer: VM 101 - Rollback

OutputStatus

Stop
Rolling back to snapshot: 1% complete...
Rolling back to snapshot: 2% complete...
Rolling back to snapshot: 3% complete...
Rolling back to snapshot: 4% complete...
Rolling back to snapshot: 5% complete...
Rolling back to snapshot: 6% complete...
Rolling back to snapshot: 7% complete...
Rolling back to snapshot: 8% complete...
Rolling back to snapshot: 9% complete...
Rolling back to snapshot: 10% complete...
Rolling back to snapshot: 11% complete...
Rolling back to snapshot: 12% complete...
Rolling back to snapshot: 13% complete...
Rolling back to snapshot: 14% complete...
Rolling back to snapshot: 15% complete...
Rolling back to snapshot: 16% complete...
Rolling back to snapshot: 17% complete...
Rolling back to snapshot: 18% complete...
Rolling back to snapshot: 19% complete...
Rolling back to snapshot: 20% complete...
Rolling back to snapshot: 21% complete...
Rolling back to snapshot: 22% complete...
Rolling back to snapshot: 23% complete...
Rolling back to snapshot: 24% complete...
Rolling back to snapshot: 25% complete...
Rolling back to snapshot: 26% complete...
Rolling back to snapshot: 27% complete...
Rolling back to snapshot: 28% complete...
Rolling back to snapshot: 29% complete...
Rolling back to snapshot: 30% complete...
Rolling back to snapshot: 31% complete...
Rolling back to snapshot: 32% complete...
Rolling back to snapshot: 33% complete...
Rolling back to snapshot: 34% complete...
Rolling back to snapshot: 35% complete...
Rolling back to snapshot: 36% complete...
Rolling back to snapshot: 37% complete...
Rolling back to snapshot: 38% complete...
Rolling back to snapshot: 39% complete...
Rolling back to snapshot: 40% complete...
Rolling back to snapshot: 41% complete...
Rolling back to snapshot: 42% complete...
Rolling back to snapshot: 43% complete...
Rolling back to snapshot: 44% complete...
Rolling back to snapshot: 45% complete...
Rolling back to snapshot: 46% complete...
Rolling back to snapshot: 47% complete...
Rolling back to snapshot: 48% complete...
Rolling back to snapshot: 49% complete...
Rolling back to snapshot: 50% complete...
Rolling back to snapshot: 51% complete...
Rolling back to snapshot: 52% complete...
Rolling back to snapshot: 53% complete...
Rolling back to snapshot: 54% complete...
Rolling back to snapshot: 55% complete...
Rolling back to snapshot: 56% complete...
Rolling back to snapshot: 57% complete...
Rolling back to snapshot: 58% complete...
Rolling back to snapshot: 59% complete...
Rolling back to snapshot: 60% complete...
Rolling back to snapshot: 61% complete...
Rolling back to snapshot: 62% complete...
Rolling back to snapshot: 63% complete...
Rolling back to snapshot: 64% complete...
Rolling back to snapshot: 65% complete...
Rolling back to snapshot: 66% complete...
Rolling back to snapshot: 67% complete...
Rolling back to snapshot: 68% complete...
Rolling back to snapshot: 69% complete...
Rolling back to snapshot: 70% complete...
Rolling back to snapshot: 71% complete...
Rolling back to snapshot: 72% complete...
Rolling back to snapshot: 73% complete...
Rolling back to snapshot: 74% complete...
Rolling back to snapshot: 75% complete...
Rolling back to snapshot: 76% complete...
Rolling back to snapshot: 77% complete...
Rolling back to snapshot: 78% complete...
Rolling back to snapshot: 79% complete...
Rolling back to snapshot: 80% complete...
Rolling back to snapshot: 81% complete...
Rolling back to snapshot: 82% complete...
Rolling back to snapshot: 83% complete...
Rolling back to snapshot: 84% complete...
Rolling back to snapshot: 85% complete...
Rolling back to snapshot: 86% complete...
Rolling back to snapshot: 87% complete...
Rolling back to snapshot: 88% complete...
Rolling back to snapshot: 89% complete...
Rolling back to snapshot: 90% complete...
Rolling back to snapshot: 91% complete...
Rolling back to snapshot: 92% complete...
Rolling back to snapshot: 93% complete...
Rolling back to snapshot: 94% complete...
Rolling back to snapshot: 95% complete...
Rolling back to snapshot: 96% complete...
Rolling back to snapshot: 97% complete...
Rolling back to snapshot: 98% complete...
Rolling back to snapshot: 99% complete...
Rolling back to snapshot: 100% complete...done.
Rolling back to snapshot: 100% complete...done.
Rolling back to snapshot: 100% complete...done.
/dev/rbd0
/dev/rbd1
/dev/rbd2
/dev/rbd4
swtpm_setup: Not overwriting existing state file.
kvm: tpm-emulator: TPM result for CMD_INIT: 0x101 operation failed
stopping swtpm instance (pid 2696354) due to QEMU startup error
TASK ERROR: start failed: QEMU exited with code 1

root@pve1-cpu1:~# 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-5.15: 7.2-14
pve-kernel-helper: 7.2-14
pve-kernel-5.13: 7.1-9
pve-kernel-5.11: 7.0-10
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-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-2-pve: 5.13.19-4
pve-kernel-5.13.19-1-pve: 5.13.19-3
pve-kernel-5.11.22-7-pve: 5.11.22-12
pve-kernel-5.11.22-5-pve: 5.11.22-10
pve-kernel-5.11.22-4-pve: 5.11.22-9
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.2
libproxmox-backup-qemu0: 1.3.1-1
libpve-access-control: 7.2-5
libpve-apiclient-perl: 3.2-1
libpve-common-perl: 7.2-8
libpve-guest-common-perl: 4.2-3
libpve-http-server-perl: 4.1-5
libpve-storage-perl: 7.2-12
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.7-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.5-6
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
root@pve1-cpu1:~#



Any ideas?

 

[fiona]

Hi,
was the VM running at the time of the rollback? Please share cat /etc/pve/qemu-server/101.conf and tell us which snapshot you wanted to roll back to.

 

[MoreDakka]

Hey,

Yes the VM was running during that time.


root@pve1-cpu1:~# cat /etc/pve/qemu-server/101.conf
agent: 0
bios: ovmf
boot: order=scsi0;ide2;net0;ide0
cores: 8
cpu: host
efidisk0: Ceph-RBDStor:vm-101-disk-0,efitype=4m,pre-enrolled-keys=1,size=528K
ide0: FreeNAS-ProxBackup:iso/virtio-win-0.1.215.iso,media=cdrom,size=528322K
ide2: FreeNAS-ProxBackup:iso/SW_DVD9_Win_Server_STD_CORE_2022__64Bit_English_DC_STD_MLF_X22-74290__1_.ISO,media=cdrom,size=5420564K
machine: pc-q35-6.2
memory: 16384
meta: creation-qemu=6.2.0,ctime=1653059759
name: www21.domain.com
net0: e1000=BE:B5:6F:62:67:41,bridge=vmbr0,firewall=1,tag=VLAN
numa: 1
onboot: 1
ostype: win11
parent: TestSnapshot
scsi0: Ceph-RBDStor:vm-101-disk-1,discard=on,size=250G,ssd=1
scsihw: virtio-scsi-pci
smbios1: uuid=5a2f24b2-ddd4-4c37-b018-0cb13170307e
sockets: 2
tpmstate0: Ceph-RBDStor:vm-101-disk-2,size=4M,version=v2.0
vmgenid: 6a87bbce-14fc-469c-976f-fe983fb2a7ee

[TestSnapshot]
agent: 0
bios: ovmf
boot: order=scsi0;ide2;net0;ide0
cores: 8
cpu: host
efidisk0: Ceph-RBDStor:vm-101-disk-0,efitype=4m,pre-enrolled-keys=1,size=528K
ide0: FreeNAS-ProxBackup:iso/virtio-win-0.1.215.iso,media=cdrom,size=528322K
ide2: FreeNAS-ProxBackup:iso/SW_DVD9_Win_Server_STD_CORE_2022__64Bit_English_DC_STD_MLF_X22-74290__1_.ISO,media=cdrom,size=5420564K
machine: pc-q35-6.2
memory: 16384
meta: creation-qemu=6.2.0,ctime=1653059759
name: www21.domain.com
net0: e1000=BE:B5:6F:62:67:41,bridge=vmbr0,firewall=1,tag=VLAN
numa: 1
onboot: 1
ostype: win11
runningcpu: host,hv_ipi,hv_relaxed,hv_reset,hv_runtime,hv_spinlocks=0x1fff,hv_stimer,hv_synic,hv_time,hv_vapic,hv_vpindex,+kvm_pv_eoi,+kvm_pv_unhalt
runningmachine: pc-q35-6.2+pve0
scsi0: Ceph-RBDStor:vm-101-disk-1,discard=on,size=250G,ssd=1
scsihw: virtio-scsi-pci
smbios1: uuid=5a2f24b2-ddd4-4c37-b018-0cb13170307e
snaptime: 1669756751
sockets: 2
tpmstate0: Ceph-RBDStor:vm-101-disk-2,size=4M,version=v2.0
vmgenid: 078d7213-86a1-4617-91f9-847e7450d62c
vmstate: Ceph-RBDStor:vm-101-state-TestSnapshot
root@pve1-cpu1:~#

 

[MoreDakka]

PS. When this snapshot rollback failed, the VM became non-responsive. There was the option to try to rollback again but same results as above.

 

[fiona]

kvm: tpm-emulator: TPM result for CMD_INIT: 0x101 operation failed
stopping swtpm instance (pid 2696354) due to QEMU startup error
TASK ERROR: start failed: QEMU exited with code 1

Unfortunately, I'm not able to reproduce the issue here. Did you already try to rollback while the VM is stopped? If that doesn't work, maybe you need to re-create the TPM drive and start the VM afterwards.

 

[MoreDakka]

I recreated the TPM State disk as per your suggestion and it booted no problem. Any ideas on why the snapshot rollback broke the TPM disk?

 

[fiona]

I recreated the TPM State disk as per your suggestion and it booted no problem. Any ideas on why the snapshot rollback broke the TPM disk?

No, I couldn't reproduce the issue. The error only tells us that the initialization of TPM from QEMU failed, but not why. To learn more one would've needed to debug swtpm and/or analyze the image.

How long was the VM running before the snapshot was taken? Could you check in /var/log/apt/history.log (and maybe older logs) when swtpm and pve-qemu-kvm updates were installed?