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?

 

[ThomasGlanzmann]

Hello,
we're able to reproduce the issue three times by migrating the windows VM from ceph to zfs and than back to ceph. Once we did that we're unable to rollback the snapshots with the above error message. Deleting the tpm disk and recreating it, resolved the issue for us.

Cheers,
Thomas