Proxmox 8.3 and Veeam 12.3 restore issue

AdrianC

New Member
Jan 25, 2024
1
0
1
Hi,

I'm trying to restore some VMs to a Proxmox 8.3 new deployment. They were backed up using VBR 12.3 on a vSphere 8 hypervisor and restoring with the same version of VBR to PVE. I'm having some errors with the entire VM restores to PVE though. There's no pattern as such that I can find, although larger VMs (~6TB) seems to be failing after 1:14 to 1:15 minutes give or take a minute. Veeam support suggest it's something within Proxmox which it may well be, however I'm wondering if anyone else has come across this? It's getting quite important that I crack this and get the restores back to the new PVE server. Parts of the Veeam log files Veeam support have highlighted are as follows:

While reviewing the logs I could see the following behavior during the restore process:
• 6 disks are mapped on the Proxmox Cluster

2025-02-02 22:25:30.5471 00026 [1530] INFO | [NbdEngine]: Mapping the disk "D1286FBCB6A7721A0023EC7BED0B40AB" to block devices...
2025-02-02 22:25:30.5482 00026 [1530] INFO | [NbdEngine]: The disk "D1286FBCB6A7721A0023EC7BED0B40AB" has been mapped to the block device "drive-sata0" using files "/dev/zvol/Data/vm-113-disk-4":""
2025-02-02 22:25:30.5482 00026 [1530] INFO | [NbdEngine]: Mapping the disk "E089D29C6DA891DCF5A7C23EAC89BD38" to block devices...
2025-02-02 22:25:30.5482 00026 [1530] INFO | [NbdEngine]: The disk "E089D29C6DA891DCF5A7C23EAC89BD38" has been mapped to the block device "drive-sata1" using files "/dev/zvol/Data/vm-113-disk-5":""
2025-02-02 22:25:30.5482 00026 [1530] INFO | [NbdEngine]: Mapping the disk "DD614D7C8193556B20A686E1965B2CC9" to block devices...
2025-02-02 22:25:30.5482 00026 [1530] INFO | [NbdEngine]: The disk "DD614D7C8193556B20A686E1965B2CC9" has been mapped to the block device "drive-sata2" using files "/dev/zvol/Data/vm-113-disk-6":""
2025-02-02 22:25:30.5482 00026 [1530] INFO | [NbdEngine]: Mapping the disk "2E7044557627B7E400B8BBEF13A77837" to block devices...
2025-02-02 22:25:30.5482 00026 [1530] INFO | [NbdEngine]: The disk "2E7044557627B7E400B8BBEF13A77837" has been mapped to the block device "drive-sata3" using files "/dev/zvol/Data/vm-113-disk-7":""
2025-02-02 22:25:30.5487 00026 [1530] INFO | [NbdEngine]: Mapping the disk "58153C9711826370336D28D5315C3E62" to block devices...
2025-02-02 22:25:30.5487 00026 [1530] INFO | [NbdEngine]: The disk "58153C9711826370336D28D5315C3E62" has been mapped to the block device "drive-sata4" using files "/dev/zvol/Data/vm-113-disk-8":""
2025-02-02 22:25:30.5487 00026 [1530] INFO | [NbdEngine]: Mapping the disk "3A1B4E736A51948D6262FB323ADB0960" to block devices...
2025-02-02 22:25:30.5487 00026 [1530] INFO | [NbdEngine]: The disk "3A1B4E736A51948D6262FB323ADB0960" has been mapped to the block device "drive-sata5" using files "/dev/zvol/Data/vm-113-disk-9":""
2025-02-02 22:25:30.5504 00026 [1530] INFO | [NbdEngine]: Performing export "VeeamTmp_exported_drive-sata0" of the device "#block178":"drive-sata0"
2025-02-02 22:25:30.5516 00026 [1530] INFO | [QmpCommands]: Exporting the device "#block178" with the export name "VeeamTmp_exported_drive-sata0"...
• then the restore process is started

2025-02-02 22:25:30.5712 00026 [1530] INFO | [VbrRestoreProgressReporter]: OnStartDiskRestore
2025-02-02 22:25:30.5712 00026 [1530] INFO | [NbdEngine]: Restoring the disk "D1286FBCB6A7721A0023EC7BED0B40AB" (key "XXXXXXXX_12-flat.vmdk")
2025-02-02 22:25:30.5712 00026 [1530] INFO | [NbdEngine]: Zeroed regions will NOT be written on the disk ["XXXXXXXX_12-flat.vmdk"] on ["zfspool"]
2025-02-02 22:25:30.5737 00026 [1530] INFO | [SshClientUtils]: Start executing ssh command "comm -23 <(seq 49152 65535 | sort) <(ss -Htan | awk '{{print $4}}' | cut -d':' -f2 | sort -u) | shuf | head -n 1"
• then the Worker is failing to communicate with SshQmpSocket on the Proxmox Cluster side:

2025-02-02 22:35:12.2928 00031 [1530] INFO | [MemoryLoggerWorkflow][MemoryLogger]: GC mem: 26209608, Process mem: 506036224
2025-02-02 22:39:41.4380 00024 [1530] INFO | [ForwardedSocket]: Renci.SshNet.Common.ExceptionEventArgs
2025-02-02 22:39:41.4408 00004 [1530] INFO | [SshQmpSocket]: An error occurred while executing the socat command on "/var/run/qemu-server/113.qmp":55294: Renci.SshNet.Common.SshConnectionException: An established connection was aborted by the server.
2025-02-02 22:55:52.4607 00027 [1530] INFO | [VbrVmDiskRestore]: Successfully completed writer tasks
2025-02-02 22:55:55.0978 00027 [1530] ERROR | [SshQmpSocket]: Failed to connect to the QMP device using SSH: Veeam.Vbf.Common.Exceptions.ExceptionWithDetail: Failed to connect to the QMP socket: SSH connection is inactive.
2025-02-02 22:55:55.0978 00027 [1530] ERROR | [SshQmpSocket]: at Veeam.Vbf.BackupAgent.BackupProxmox.Qmp.SshQmpSocket.ConnectAsync(String path, CancellationToken cancellationToken)
2025-02-02 22:55:55.0978 00027 [1530] ERROR | [HotAddConfigurator]: Failed to connect to the worker QMP socket: Veeam.Vbf.Common.Exceptions.ExceptionWithDetail: Failed to connect to the QMP socket: SSH connection is inactive.
2025-02-02 22:55:55.0978 00027 [1530] ERROR | [HotAddConfigurator]: at Veeam.Vbf.BackupAgent.BackupProxmox.Qmp.SshQmpSocket.ConnectAsync(String path, CancellationToken cancellationToken)

If anyone has any suggestions I'd really appreciate it.

Thank you!
 
Last edited: