Data recovery failure from Azure Data Recovery Vault using MARS Agent with on-premises computer

Despite trying several times since last night, the recovery of a volume from an Azure Data Recovery Vault to a new location on the original source computer fails after approximately (but not exactly) the same amount of data transfer (~3.7GB of ~7.5GB). If the recovery is attempted over the previously transferred data (with overwrite off) the recovery fails after just a few MB.

The computer is an ordinary Windows 10 Pro laptop on which a test recovery was previously performed successfully 6 months ago. The MARS Agent has been updated. The backups show no errors and have all been completed successfully as defined in the plan.

The volume can be mounted successfully using the MARS agent but this method is not usable since the files are encrypted (NTFS EFS encryption), the data needs to be recovered as a volume with file attributes etc intact.

Needless to say, this is extremely disturbing - does anyone have any suggestions? I have reached the other side of the internet without finding any actionable information and the error log (excerpts below) is cryptic, suggesting some sort of corruption but whether this is in the original backup or in the transfer process/cache I can't tell.

Any help deeply appreciated, Thanks

2:36:56 PM  3   dynamicloadedmodule.cpp(86) WARNING Failed: Hr: = [0x80070057] : Encountered Failure: : lVal : E_INVALIDARG
2:36:57 PM  75  OMUtils.cs(309) WARNING cbpVersion 2.0.9167.0 , latestVersion 2.0.9167.0 
2:36:57 PM  3   registryutils.cpp(249)  WARNING Failed: Hr: = [0x80070002] : Encountered Failure: : lVal : (UINT)RegDeleteValue(hReg, pwstrValueName)
2:38:24 PM  75  OMUtils.cs(309) WARNING cbpVersion 2.0.9167.0 , latestVersion 2.0.9127.0 
2:39:28 PM  3   miscellaneousutils.cpp(292) WARNING Failed: Hr: = [0x8007007e] GetModuleHandle failed for Library [RefCountedVhdManager], will try LoadLibrary
2:39:28 PM  3   miscellaneousutils.cpp(292) WARNING Failed: Hr: = [0x8007007e] GetModuleHandle failed for Library [HypervVhdHelper], will try LoadLibrary
2:39:28 PM  3   miscellaneousutils.cpp(292) WARNING Failed: Hr: = [0x8007007e] GetModuleHandle failed for Library [NativeVHDProvider], will try LoadLibrary
2:39:28 PM  18  fsutils.cpp(1962)   WARNING Failed: Hr: = [0x80990a57] : Failed to open volume:\\?\{90600554-265E-453E-9C8E-6BB78588BAB2}
2:39:28 PM  18  metadatawriteriterator.cpp(791) WARNING Failed: Hr: = [0x80990a57] : Failed to get handle for volume {90600554-265E-453E-9C8E-6BB78588BAB2}\
2:39:39 PM  79  WcfClient.cs(998)   WARNING Unable to make web service call | Params: {Exception:  = System.ServiceModel.FaultException`1[Microsoft.Internal.CloudBackup.Common.FailureModeling.CloudServiceFault]: Internal Service Error (Fault Detail is equal to ErrorCode = CloudAsyncWorkSubmitted, DetailedErrorCode = 0, DetailedErrorSource = Service/None/None/None, Message = 
2:39:39 PM  79  WcfClient.cs(998)   WARNING ).}
2:39:40 PM  79  WcfClient.cs(815)   WARNING FMBlock: Executing retry policy | Params: {CurrentAttempt = 1}{MaxAttempts = 28800}{BackOffIntervalInSec = 3.6}{OperationCode = WcfProxyGenericAsyncOperationPollingCall}{Retry policy id = 7}
2:43:47 PM  79  WcfClient.cs(815)   WARNING FMBlock: Executing retry policy | Params: {CurrentAttempt = 20}{MaxAttempts = 28800}{BackOffIntervalInSec = 18}{OperationCode = WcfProxyGenericAsyncOperationPollingCall}{Retry policy id = 7}
2:45:58 PM  3   workitem.cpp(233)   WARNING Idle Timer FIRED But WorkItem 000000001A395C80 Doesnt Exist! TimerOrWaitFired: True
2:45:58 PM  3   workitem.cpp(233)   WARNING Idle Timer FIRED But WorkItem 000000001C567D00 Doesnt Exist! TimerOrWaitFired: True
2:48:02 PM  75  CBJob.cs(1387)  WARNING [TriggerJobFailed#2]The Job of type Recovery is already running.
2:48:02 PM  69  CBEngineHelper.cs(403)  WARNING FMBlock: FM exception caught | Params: {OperationCode = GenericOMCall}{OperationStartTime = 6/19/2019 2:48:00 PM}{FMExceptionDetail = FMException: [ErrorCode:CBPBackupOrRestoreInProgress, DetailedCode:0, Source:None, Message:This operation cannot be performed now because a backup or restore operation is currently in progress.]
2:48:02 PM  69  CBEngineHelper.cs(403)  WARNING }
2:48:02 PM  71  CBEngineHelper.cs(412)  WARNING Caught CloudFMException with error detailsFMException: [ErrorCode:CBPBackupOrRestoreInProgress, DetailedCode:0, Source:None, Message:This operation cannot be performed now because a backup or restore operation is currently in progress.]
2:48:02 PM  71  CBEngineHelper.cs(412)  WARNING Stack trace:   at Microsoft.Internal.CloudBackup.ObjectModel.OMCommon.CBJob.CheckAndFailIfAnotherJobAlreadyInProgress()
2:48:02 PM  71  CBEngineHelper.cs(412)  WARNING    at Microsoft.Internal.CloudBackup.ObjectModel.OMCommon.CBAutoRetry.RetryFailedJobs(CBPolicy policy)
2:48:02 PM  71  CBEngineHelper.cs(412)  WARNING    at Microsoft.Internal.CloudBackup.ObjectModel.OMCommon.CBBackupServer.RetryFailedJobs()
2:48:02 PM  71  CBEngineHelper.cs(412)  WARNING    at Microsoft.Internal.Common.FailureModeling.FMComponent`3._FMBlock(String fileName, Int32 lineNumber, FMBlockArgs args, Action fmPrecheckBlock, Action fmUserBlock)
2:48:02 PM  71  CBEngineHelper.cs(412)  WARNING    at Microsoft.Internal.CloudBackup.Engine.CBEngineHelper.CallOMFunction(Action omFunction)
2:48:02 PM  71  CBEngineHelper.cs(258)  WARNING Caught CloudFMException with ErrorCode CBPBackupOrRestoreInProgress, DetailedErrorCode 0
2:48:05 PM  18  fswrapper.cpp(933)  WARNING Hr: = [0x1c4e4b10] Unable to CreateFile C:\Temp\C_vol\Project\Company\Website\ReCaptcha.docx error :5
2:48:28 PM  18  fswrapper.cpp(933)  WARNING Hr: = [0x2328c670] Unable to CreateFile C:\Temp\C_vol\Project\Product\Working\ error :3
2:48:28 PM  18  fswrapper.cpp(933)  WARNING Hr: = [0x201d62d0] Unable to CreateFile C:\Temp\C_vol\Project\Product\Working\ProductVisualizerPC\Product.Licensing\obj\x86\Release\build.force error :3
2:48:28 PM  32  transformer.cpp(1288)   WARNING Failed: Hr: = [0x80990feb] Unexpected block version                     Block number inside buffer - [0],                    Block Major version - [28515],                    Block Minor version - [25966]
2:48:28 PM  18  fswrapper.cpp(933)  WARNING Hr: = [0x201d61e0] Unable to CreateFile C:\Temp\C_vol\Project\Product\Working\ProductVisualizerPC\Product.Licensing\obj\x86\Release\DesignTimeResolveAssemblyReferencesInput.cache error :3
2:48:28 PM  32  transformer.cpp(574)    WARNING Failed: Hr: = [0x80990feb] Detected problem in Block Header IntegrityTRANSFORMATION Message - [000000001A3608B0],Offset before transformation - [4252402176],Length before transformation - [16896],Ovl - [000000001C4EB140],Offset after transformation - [0],Length after transformation - [512],Block number inside buffer - [0],Block Major version - [0],Block Minor version - [0]
2:48:28 PM  18  fswrapper.cpp(933)  WARNING Hr: = [0x231b07b0] Unable to CreateFile C:\Temp\C_vol\Project\Product\Working\ProductVisualizerPC\Product.Licensing\obj\x86\Release\GenerateResource.read.1.tlog error :3
2:48:28 PM  32  addressindex.cpp(1498)  WARNING Failed: Hr: = [0x80990feb] Received read error from transformation layer
2:48:28 PM  18  fswrapper.cpp(933)  WARNING Hr: = [0x231b0da0] Unable to CreateFile C:\Temp\C_vol\Project\Product\Working\ProductVisualizerPC\Product.Licensing\obj\x86\Release\GenerateResource.write.1.tlog error :3
2:48:28 PM  18  mtfdirectory.cpp(1672)  WARNING Failed: Hr: = [0x80990feb] BackupRead failed on file(C:\Project\Product\Working2013\)
2:48:28 PM  18  fswrapper.cpp(933)  WARNING Hr: = [0x201d62d0] Unable to CreateFile C:\Temp\C_vol\Project\Product\Working\ProductVisualizerPC\Product.Licensing\obj\x86\Release\Product.Licensing.Client.dll error :3
2:48:28 PM  18  fsutils.cpp(4751)   WARNING Failed: Hr: = [0x80070057] Failed: QueryVolumeAccessPath of [C:\] with error
2:48:28 PM  18  fswrapper.cpp(933)  WARNING Hr: = [0x201d5e20] Unable to CreateFile C:\Temp\C_vol\Project\Product\Working\ProductVisualizerPC\Product.Licensing\obj\x86\Release\Product.Licensing.Client.pdb error :3
2:48:28 PM  18  fsutils.cpp(4730)   WARNING Failed: Hr: = [0x80070057] : GetVolumePathNamesForVolumeName failed for volume name volume name [C:\]
2:48:28 PM  18  fswrapper.cpp(933)  WARNING Hr: = [0x201d6230] Unable to CreateFile C:\Temp\C_vol\Project\Product\Working\ProductVisualizerPC\Product.Licensing\obj\x86\Release\Product.Licensing.Client.Resources.resources error :3
2:48:28 PM  18  validationsubtaskbase.cpp(155)  WARNING Failed: Hr: = [0x80070057] : Encountered Failure: : lVal : QueryVolumeAccessPath(ssVolumePath, ssMountPointPath)
2:48:28 PM  18  fswrapper.cpp(933)  WARNING Hr: = [0x201d63c0] Unable to CreateFile C:\Temp\C_vol\Project\Product\Working\ProductVisualizerPC\Product.Licensing\obj\x86\Release\Product.Licensing.Client.vbproj.FileListAbsolute.txt error :3
2:48:28 PM  18  dsmsendersubtaskbase.cpp(582)   WARNING Failed: Hr: = [0x80990feb] SendData() failed
2:48:28 PM  18  fswrapper.cpp(933)  WARNING Hr: = [0x201d60f0] Unable to CreateFile C:\Temp\C_vol\Project\Product\Working\ProductVisualizerPC\Product.Licensing\obj\x86\Release\Product.Licensing.Client.xml error :3
2:48:28 PM  18  dsmreceiversubtaskbase.cpp(251) WARNING CDsmReceiverSubTaskBase received completion for session closed in WAIT state
2:48:28 PM  18  dsmsubtaskbase.cpp(227) WARNING Session closed before data move completed
2:48:28 PM  18  fswrapper.cpp(933)  WARNING Hr: = [0x2010fbc0] Unable to CreateFile C:\Temp\C_vol\Project\Product\Working\ProductVisualizerPC\Product.Licensing\obj\x86\Debug\Product.Licensing.Client.pdb error :3
2:48:28 PM  32  salbuffer.cpp(304)  WARNING Failed: Hr: = [0x80990fe5] Encountered pending error on queue 000000001A122570
2:48:28 PM  18  fswrapper.cpp(933)  WARNING Hr: = [0x2010ff30] Unable to CreateFile C:\Temp\C_vol\Project\Product\Working\ProductVisualizerPC\Product.Licensing\obj\x86\Debug\Product.Licensing.Client.vbprojResolveAssemblyReference.cache error :3
2:48:28 PM  32  salreaderqueue.cpp(343) WARNING Failed: Hr: = [0x80990fe5] Error hit in SalReaderqueue. Aborting .... 
2:48:28 PM  18  fswrapper.cpp(933)  WARNING Hr: = [0x2010fb20] Unable to CreateFile C:\Temp\C_vol\Project\Product\Working\ProductVisualizerPC\Product.Licensing\obj\x86\Debug\Product.Licensing.Client.xml error :3
2:48:28 PM  18  writeriterator.cpp(613) WARNING CFileWriterIterator failed at checkpoint 0000000000000000
2:48:28 PM  32  salbuffer.cpp(304)  WARNING Failed: Hr: = [0x80990fe5] Encountered pending error on queue 000000001A122570
2:48:28 PM  18  iteratorutils.cpp(616)  WARNING Create(usn:0x0000000000000000, frn:0x0000000000000000, path:C:\Project\Product\Working\ProductVisualizerPC\Product.Licensing\obj\x86\Debug\Product.Licensing.Client.xml, ChangeTime: {0x20362a3a,0x1d49c9a}, BackupTime: {0x0,0x0}, ParentModifiedTime: {0x3e7b0ea4,0x324aa4f5})
2:48:28 PM  18  iteratorutils.cpp(624)  WARNING File properties sent by sender (Attributes: 0x4020, CreationTime: {0x3b6514d4,0x1d48e55}, LastAccessTime: {0x3b6514d4,0x1d48e55}, LastWriteTime: {0x401acd00,0x1cf31df}, FileSize: 9220 bytes, ReparseTag:0x0)
2:48:28 PM  32  salbuffer.cpp(304)  WARNING Failed: Hr: = [0x80990fe5] Encountered pending error on queue 000000001A122570
2:48:28 PM  18  mtfparser.cpp(232)  WARNING CMtfParser::Parse - Error parsing dblk at offset 23965696 after reading 0 bytes.
2:48:28 PM  32  salbuffer.cpp(304)  WARNING Failed: Hr: = [0x80990fe5] Encountered pending error on queue 000000001A122570
2:48:30 PM  32  metadatastream.cpp(630) WARNING Failed: Hr: = [0x80070002] Failed to delete metadata file [C:\Program Files\Microsoft Azure Recovery Services Agent\Scratch\MicrosoftBackupProvider\SAL\MetadataStreams\{E340ADF7-13E0-48A6-BE69-CCB1695FC670}.dat]
2:48:30 PM  71  restoreasync.cpp(548)   WARNING Failed: Hr: = [0x80990feb] Recovery Progress: Failed
2:48:30 PM  71  restoreasync.cpp(601)   RECOVERY_FAIL   Saving failed recovery logs.

In the interests of anyone who stumbles on this question hoping to find an answer, the root cause turned out to be a bug on the server side. Identifying the exact problem took months working with a very professional tech support person as well as the Microsoft dev team in India (because I had to run remote tests for them and they were working blind).

So this kind of thing can happen but at least in this instance a patch was created and applied and all is well.

The other important thing to know (I did not) is that there is a script-based method available through Powershell that allows you to recover selected files and/or folders without working through the MARS gui. This is essential if you don't want to download an entire archive which is the only option available (at this time) through the gui for EFS encrypted content - you can't mount the volume remotely because any files recovered will be encrypted and unusable even on the original source computer.

It is beyond the scope of this answer to describe all the available options but I'm appending a generic script that I was sent to give some sense of the approach. The part up to "$sources" is not required if recovering to the original machine. Documentation here: https://docs.microsoft.com/en-us/powershell/module/msonlinebackup/?view=msonlinebackup-ps

Sample script:

import-Module MSOnlineBackup 

$AltServer = Get-OBAlternateBackupServer -VaultCredentials "C:\Users\...\xyz_Mon Sep 09 2019.VaultCredentials" 

$AltServer.ServerName[2]  #This will print the server name, in this case it should print the original win 10 machine, if not, then change the index till we find the right machine

$obj = New-object Microsoft.Internal.CloudBackup.ObjectModel.OMCommon.CBBackupServer

$obj.ServerName = $AltServer.ServerName[2] 

$sources = Get-OBRecoverableSource -Server $obj #$sources variable will basically contain the backed up drives, $sources[0] should show up the first drive in the list, lets ensure that we select the right drive

$rps = Get-OBRecoverableItem $sources[0] 

$ro = new-obrecoveryoption -DestinationPath "c:\temp"  #The folder must exists so please create it manually at this point and add it here, no letter required, just to path

$ri = New-OBRecoverableItem $rps[81] "Project\Test" $TRUE #add backed up folder name

$key = ConvertTo-SecureString -string "passphraseplease" -AsPlainText -Force #provide the correct passphrase for the restore to work properly

start-obrecovery @($ri) -RecoveryOption $ro -EncryptionPassphrase $key