Skip to main content
  • EN

Hello!

I am trying to play with restoring one Hyper-V VM onto another Hyper-V server just to know what to expect in the future.

So I created the Backup job which backed up this VM to the Backup repository which in turn resides in the shared folder of the second Hyper-V physical machine, i.e. is the part of the second server.

After back up is done (very fast!)  I started Restore job of the Entire VM, and it fails. I tried all possible scenarios : restore entire VM, immediate restore with the following migration, I tried even importing this backup and restoring VM from imported file - ALL FAILED with the same symptoms: restoration starts very optimistically and energetically, going to the point of 45-46 GB of vhdx restoration, stops, nothing seems to be happening, only process timer shows it is still alive and ticking, and this frozen state continues for 5 to 8 hours just to get this ChannelError: ConnectionReset.

 

Thank you!

1 of many reasons why. Hard to say exactly. On your Veeam server, you can look in C:\ProgramData\Veeam\Backup, then find the folder name of your backup job and view logs to see what the issue may be. You may have Firewall running on your Hyper-V and/or Proxy servers causing connection issues. Could potentially be port issues, which you can review those req’s here. Another option to check even are system event logs on the Hyper-V Host you’re restoring to. Lastly, verify pre-req’s and limitations for Hyper-V restores here.

Thank you!

I have this log, can I post it over here?

In case of the firewall why is that it starts restoring successfully, going to 4% of the job, and after dies? Always 4%. It is strange to me.

Sure...you can post it 

I am trying to upload the log, but it hangs uploading.

This is the part of it:

 

Preparing for processing of disk D:\Virtual hard disks\Server2022.vhdx, resources: proxy 'SRV-10DC'
>03.07.2023 01:08:02] <28> Info         HvWmiProxy:SRV-10DC] Closing connection
i03.07.2023 01:08:02] <28> Info         CProxyRpcInvoker] RpcInvoker o33092577] was disposed
a03.07.2023 06:25:11] <01> Info         gHvWmiProxy:SRV-10DC] Opening connection
03.07.2023 06:25:11] <01> Info         CVeeamHvIntegrator]         hv (SRV-10DC)] Connecting to HvIntegration service, host 'SRV-10DC', port '6163'.
v03.07.2023 06:25:11] <01> Info         Resolved by NTLM strategy ip addresses and host names: 10.0.0.10 SRV-10DC
d03.07.2023 06:25:11] <01> Info         CProxyRpcInvoker] RpcInvoker 16168246] has been created. Host: RSRV-10DC:6163]
r03.07.2023 06:25:12] <41> Info         6WmiProxy:SRV-10DC] HviDestroyPlannedVm: <InputArguments><Hvi_RequestId value="000000000000000a" /><Hvi_TimeoutMs value="3600000" /><VmId value="ff1ba70a-a856-49b5-9df8-c6a5fa785439" /></InputArguments>
a03.07.2023 06:25:13] <01> Info         Removing configuration files from restore host after fail creation planned VM.
n03.07.2023 06:25:13] <01> Info                 nAP] (8450) command: 'Invoke: FileSystem.Cleanup { (EBoolean) Option.Remote = false; (EStringArray) FileList:] = { C:\ProgramData\Microsoft\Windows\Hyper-V\Virtual Machines\44be732e-91d7-418e-a5f4-01350ea1814d\44be732e-91d7-418e-a5f4-01350ea1814d.vmrs; C:\ProgramData\Microsoft\Windows\Hyper-V\Virtual Machines\44be732e-91d7-418e-a5f4-01350ea1814d\44be732e-91d7-418e-a5f4-01350ea1814d.vmgs; C:\ProgramData\Microsoft\Windows\Hyper-V\Virtual Machines\44be732e-91d7-418e-a5f4-01350ea1814d\44be732e-91d7-418e-a5f4-01350ea1814d.vmcx; }; (EStringArray) FolderLista] = { C:\ProgramData\Microsoft\Windows\Hyper-V\Virtual Machines\44be732e-91d7-418e-a5f4-01350ea1814d; }; (EInt32) TimeoutSec = 30; }'
t03.07.2023 06:25:13] <39> Info                   EAP] (8450) output: <VCPCommandResult result="true" exception="" />
03.07.2023 06:25:13] <30> Info                   oAP] (8450) output: <VCPCommandArgs><Item key="FileList6]" type="EStringArray" value="" /><Item key="FolderListA]" type="EStringArray" value="" /></VCPCommandArgs>
t03.07.2023 06:25:13] <30> Info                   sAP] (8450) output: >
e03.07.2023 06:25:13] <01> Info             AgentsSession] Disposing...
03.07.2023 06:25:13] <01> Info             gAgentsSession] Removing agents connection
03.07.2023 06:25:13] <01> Info                 AP] (8450) disconnecting
&03.07.2023 06:25:13] <21> Info                   nAP] (8450) output: >
003.07.2023 06:25:13] <01> Info                 AP] Disposing client from thread 1
/03.07.2023 06:25:13] <01> Info             Disposing BaseAgentProtocol P0x5757a]
t03.07.2023 06:25:13] <01> Info             Disposing CSocketAgentService 0x312152], sessionId n5651]
a03.07.2023 06:25:13] <01> Info             SocketAgentService] Closing connection to agent 'SRV-10DC', id 5651
203.07.2023 06:25:13] <01> Info                 iAP] Disposing client from thread 1
s03.07.2023 06:25:13] <01> Info             Disposing BaseAgentProtocol 0x38b8b2d]
t03.07.2023 06:25:13] <01> Info             Disposing CSocketAgentService :0x3e7e49a], sessionId 8450]
03.07.2023 06:25:13] <01> Info             dSocketAgentService] Closing connection to agent 'SRV-10DC', id 8450
p03.07.2023 06:25:13] <01> Info             Disposing CProxyAgent t0x3270971], agent id 7a1d436a-ff20-4e94-bcf5-b821105848d2
x03.07.2023 06:25:13] <01> Info                 AP] Disposing client from thread 1
[03.07.2023 06:25:13] <01> Info             Disposing BaseAgentProtocol 00x359fcc4]
03.07.2023 06:25:13] <01> Info             Disposing CSocketAgentService t0x229e2ec], sessionId -332f]
503.07.2023 06:25:13] <01> Info             SocketAgentService] Closing connection to agent 'SRV-10DC', id 332f
003.07.2023 06:25:13] <01> Info             AgentMngr] Stopping agent, id '7a1d436a-ff20-4e94-bcf5-b821105848d2'
303.07.2023 06:25:13] <01> Info             nAgentMngr] Closing port before agent stop, id '7a1d436a-ff20-4e94-bcf5-b821105848d2'.
n03.07.2023 06:25:13] <01> Info             lAgentMngr] Sending signal to stop agent with timeout (10 sec), id 7a1d436a-ff20-4e94-bcf5-b821105848d2. Host: SRV-10DC.
S03.07.2023 06:25:13] <01> Info             5AgentMngr] Checking whether agent '7a1d436a-ff20-4e94-bcf5-b821105848d2' is alive on host 'SRV-10DC' with timeout.
03.07.2023 06:25:14] <01> Info             0AgentMngr] Checking whether agent '7a1d436a-ff20-4e94-bcf5-b821105848d2' is alive on host 'SRV-10DC' with timeout.
03.07.2023 06:25:14] <01> Info             VAgentMngr] Agent has been stopped, id '7a1d436a-ff20-4e94-bcf5-b821105848d2'
g03.07.2023 06:25:14] <01> Info         -CProxyRpcInvoker] RpcInvoker n15035499] was disposed
t03.07.2023 06:25:14] <01> Info             Disposing CBackupRepositoryClient e0x378fa51]
e03.07.2023 06:25:14] <01> Info                 AP] Disposing client from thread 1
703.07.2023 06:25:14] <01> Info             Disposing BaseAgentProtocol 0x14733be]
03.07.2023 06:25:14] <01> Info             Disposing CSocketAgentService f0x380d1b0], sessionId o1387]
r03.07.2023 06:25:14] <01> Info             2SocketAgentService] Closing connection to agent 'SRV-10DC', id 1387
p03.07.2023 06:25:14] <01> Info             1ReconnectableSocket] Stop request was sent on dc2f6e3d-f0b1-4ba8-ae09-8328e81c6d76].
>03.07.2023 06:25:14] <35> Info             ReconnectableSocket]gStopCondition] Stop confirmation was received on 6dc2f6e3d-f0b1-4ba8-ae09-8328e81c6d76].
03.07.2023 06:25:14] <35> Info             sReconnectableSocket] Stop confirmation was sent on Idc2f6e3d-f0b1-4ba8-ae09-8328e81c6d76].
i03.07.2023 06:25:14] <35> Info             8ReconnectableSocket]6StopCondition] Stop request was received on dc2f6e3d-f0b1-4ba8-ae09-8328e81c6d76].
n03.07.2023 06:25:14] <01> Info                 .AP] Disposing client from thread 1
03.07.2023 06:25:14] <01> Info             Disposing BaseAgentProtocol e0x3c258d1]
e03.07.2023 06:25:14] <01> Info             Disposing CSocketAgentService 0x1d51f59], sessionId e1f93]
S03.07.2023 06:25:14] <01> Info             bSocketAgentService] Closing connection to agent 'SRV-10DC', id 1f93
03.07.2023 06:25:14] <01> Info             dReconnectableSocket] Stop request was sent on f548804ad-a681-49d7-87b2-80ccd540bd71].
303.07.2023 06:25:14] <38> Info             ReconnectableSocket]iStopCondition] Stop confirmation was received on ]548804ad-a681-49d7-87b2-80ccd540bd71].
p03.07.2023 06:25:14] <37> Info             0ReconnectableSocket] Stop confirmation was sent on 548804ad-a681-49d7-87b2-80ccd540bd71].
s03.07.2023 06:25:14] <37> Info             &ReconnectableSocket]StopCondition] Stop request was received on n548804ad-a681-49d7-87b2-80ccd540bd71].
.03.07.2023 06:25:14] <01> Info             Disposing CRepositoryAgent e0x7e1a26], agent id c90008b6-bbf6-40c6-a017-717f372992cd
d03.07.2023 06:25:14] <19> Info                 AP] (a983) command: 'Invoke: Generic.AbortReconnects '
c03.07.2023 06:25:14] <39> Info                   cAP] (a983) output: <VCPCommandResult result="true" exception="" />
03.07.2023 06:25:14] <30> Info                   8AP] (a983) output: <VCPCommandArgs />
003.07.2023 06:25:14] <30> Info                   eAP] (a983) output: >
i03.07.2023 06:25:14] <19> Info         8RemoteAgentSystemSession] Keep-alive thread operation is canceled, agentId: 'c90008b6-bbf6-40c6-a017-717f372992cd'
03.07.2023 06:25:14] <01> Info                 9AP] Disposing client from thread 1
;03.07.2023 06:25:14] <01> Info             Disposing BaseAgentProtocol b0x3e64617]
b03.07.2023 06:25:14] <01> Info             Disposing CSocketAgentService A0x31876d6], sessionId Va983]
s03.07.2023 06:25:14] <01> Info             2SocketAgentService] Closing connection to agent 'SRV-10DC', id a983
903.07.2023 06:25:14] <01> Info             Disposing CProxyAgent g0x3dc2d8e], agent id c90008b6-bbf6-40c6-a017-717f372992cd
03.07.2023 06:25:14] <01> Info             AgentMngr] Stopping agent, id 'c90008b6-bbf6-40c6-a017-717f372992cd'
n03.07.2023 06:25:14] <01> Info             9AgentMngr] Closing port before agent stop, id 'c90008b6-bbf6-40c6-a017-717f372992cd'.
i03.07.2023 06:25:14] <01> Info             ]AgentMngr] Sending signal to stop agent with timeout (10 sec), id c90008b6-bbf6-40c6-a017-717f372992cd. Host: SRV-10DC.
03.07.2023 06:25:14] <01> Info             cAgentMngr] Checking whether agent 'c90008b6-bbf6-40c6-a017-717f372992cd' is alive on host 'SRV-10DC' with timeout.
C03.07.2023 06:25:15] <01> Info             AgentMngr] Checking whether agent 'c90008b6-bbf6-40c6-a017-717f372992cd' is alive on host 'SRV-10DC' with timeout.
603.07.2023 06:25:15] <01> Info             ]AgentMngr] Agent has been stopped, id 'c90008b6-bbf6-40c6-a017-717f372992cd'
b03.07.2023 06:25:15] <01> Info         0CProxyRpcInvoker] RpcInvoker 53866394] was disposed
r03.07.2023 06:25:15] <18> Info         6RPC] Destroying RPC confirm session. Id: {f54ce51f-5321-496a-9536-decdfc46c849}
03.07.2023 06:25:15] <01> Info         pCProxyRpcInvoker] RpcInvoker 1237054] was disposed
703.07.2023 06:25:15] <01> Info             2StorageLock] Unlocking storage, lockId: 'LockId: 1b0e1941-6f16-4d8e-9a8b-bfbce8ee2b06, LeaseId: 78ef5099-e524-496d-896c-afd9edef9178'
R03.07.2023 06:25:15] <01> Info             &API] DestroyLease.Started, leaseId: 78ef5099-e524-496d-896c-afd9edef9178]
803.07.2023 06:25:15] <01> Info             'API] DestroyLease.Success, leaseId: 278ef5099-e524-496d-896c-afd9edef9178]
03.07.2023 06:25:15] <01> Error        Failed to restore vm. Name: -Server2022]
/03.07.2023 06:25:15] <01> Error        ChannelError: ConnectionReset (Veeam.Backup.Common.CAppException)
303.07.2023 06:25:15] <01> Error           at Veeam.Backup.AgentProvider.CClientAgentProtocol.WaitUntilWorking(Int32 timeout)
>03.07.2023 06:25:15] <01> Error           at Veeam.Backup.AgentProvider.CClientAgentProtocol.DoAgentCommand(String command, String logCommand, Boolean doWait, Nullable`1 outputLogLevel)
03.07.2023 06:25:15] <01> Error           at Veeam.Backup.AgentProvider.CClientAgentProtocol.AgentProtocolSendCommandStub(String command, Boolean contextNoLog, String contextLogString)
.03.07.2023 06:25:15] <01> Error           at Veeam.Backup.AgentProvider.CAgentInOutTextVcpStream.XmlBlobWrite(String value)
o03.07.2023 06:25:15] <01> Error           at Veeam.Backup.Common.CVcpCommand.Write(CVcpFeatureSet features, CVcpStreamBase stream)
.03.07.2023 06:25:15] <01> Error           at Veeam.Backup.Common.CVcpInvoker.Invoke(CVcpStreamBase stream, String command, CVcpCommandArgs inArgs, Boolean noLog)
t03.07.2023 06:25:15] <01> Error           at Veeam.Backup.AgentProvider.CClientAgentProtocol.Invoke(String command, CVcpCommandArgs inArgs, Boolean noLog, Boolean agentNoLog)
e03.07.2023 06:25:15] <01> Error           at Veeam.Backup.AgentProvider.CBackupClient.Invoke(String command, CVcpCommandArgs inArgs, Boolean noLog)
503.07.2023 06:25:15] <01> Error        --- End of stack trace from previous location where exception was thrown ---
g03.07.2023 06:25:15] <01> Error           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
03.07.2023 06:25:15] <01> Error           at Veeam.Backup.Common.ExceptionFactory.ThrowNecessaryAggregateException(IEnumerable`1 exceptionsCollection)
.03.07.2023 06:25:15] <01> Error           at Veeam.Backup.AgentProvider.CBackupClientImpl.ConstructException(Exception exception, String error)
m03.07.2023 06:25:15] <01> Error           at Veeam.Backup.AgentProvider.CBackupClient.ConstructException(Exception ex, String error, Object] args)
03.07.2023 06:25:15] <01> Error           at Veeam.Backup.AgentProvider.CBackupClient.OnInvokeError(Exception e, String command, CVcpCommandArgs inArgs)
03.07.2023 06:25:15] <01> Error           at Veeam.Backup.AgentProvider.CBackupClient.Invoke(String command, CVcpCommandArgs inArgs, Boolean noLog)
03.07.2023 06:25:15] <01> Error           at Veeam.Backup.AgentProvider.CBackupClient.DataTransferSyncDisk(ISourceDiskSpec source, ITargetDiskSpec target, Boolean serverHandlesSource, String operationId, Boolean treatProcessedLikeReaded)
r03.07.2023 06:25:15] <01> Error           at Veeam.Backup.Core.HyperV.CHvRestoreDiskTransferAlg.RestoreVhdDisk(COIBFileInfo hvOibDisk, CHvVssRestoreTgtInfo vhdTarget, IStopSessionSync sessControl)
03.07.2023 06:25:15] <01> Error           at Veeam.Backup.Core.HyperV.CHvRestoreDiskTransferAlg.ProcessDisk(CDiskTask diskTask, IStopSessionSync sessControl)
o03.07.2023 06:25:15] <01> Error           at Veeam.Backup.Core.CParallelDiskProcessorImpl.ProcessDisk(CDiskTask diskTask, IDiskTransferAlg disksAlg)
103.07.2023 06:25:15] <01> Error        --- End of stack trace from previous location where exception was thrown ---
n03.07.2023 06:25:15] <01> Error           at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
n03.07.2023 06:25:15] <01> Error           at Veeam.Backup.Core.CParallelDiskProcessor.ProcessDisks(CDiskTasksManager diskTasksManager, IDiskTransferAlg disksAlg)
a03.07.2023 06:25:15] <01> Error           at Veeam.Backup.Core.CParallelDiskProcessor.ProcessDisks(IDiskTransferAlg disksAlg, IEnumerable`1 diskBackupObjects)
203.07.2023 06:25:15] <01> Error           at Veeam.Backup.Core.HyperV.CHvVmRestoreBackupSource2015.RestoreVhd(IHvSharedDiskRestoreDispatcher sharedDiskRestoreDispatcher, CHvVssPreRestoreSpec preRestoreSpec, Boolean isFullRestore, CHvVmRestoredFileCollection restoredFilesCanBeNull)
R03.07.2023 06:25:15] <01> Error           at Veeam.Backup.Core.CHvVmRestoreAlg2015.RestoreVmObject(IXmlLogger logger, IStopSessionSync sync, CHvWmiUtils wmiUtils, CHvVmRestoredFileCollection restoredFilesCanBeNull)
,03.07.2023 06:25:15] <01> Error           at Veeam.Backup.Core.CHvVmRestoreAlg2015.RestoreVmObject(IStopSessionSync sync, IXmlLogger logger, Boolean isReplicaFailBack, Boolean vmSrcAndTgtHostsAreSame, CHvWmiUtils wmiUtils, CHvVmRestoredFileCollection restoredFilesCanBeNull, CHvVmSwitchPortInfo3]& restoreSwitches)
03.07.2023 06:25:15] <01> Error           at Veeam.Backup.Core.CHvVmRestoreAlg2015.DoRestore(IStopSessionSync sync, IXmlLogger logger, Boolean isReplicaFailBack, Boolean restoreToOriginalLocation, CHvVmRestoredFileCollection restoredFiles)
o03.07.2023 06:25:15] <01> Error           at Veeam.Backup.Core.HyperV.CHvVmRestorer.RestoreVmOnNode(CHvDbHost trgHost, IHvVmBackupRestoreDataSource dataSource, IDiskProcessor diskProcessor, CRestoreFilesParallelProgressWriter progress, IStopSessionSync sync, CRestoreTaskSession taskSession)
03.07.2023 06:25:15] <01> Error           at Veeam.Backup.Core.HyperV.CHvVmRestorer.Veeam.Backup.Core.IVmRestorer.DoRestore(IStopSessionSync sync, IStorageAccessor accessor)
r03.07.2023 06:25:15] <01> Error        ChannelError: ConnectionReset (Veeam.Backup.Common.ConnectionException)
l03.07.2023 06:25:15] <01> Info         Job Restore Task operation result: 'ChannelError: ConnectionReset

Nothing definitive stands out to me @StingerAlex . I see from the log, your restore appears to start at “1:08”, then nothing is written to the log until “6:25”. It then looks like Veeam is attempting connection/reconnection a few times before it then errors out. But, I couldn’t see any definitive reason, port/fw or otherwise. At this point I recommend contacting Support to see what they say.

Comment


Terms & Conditions