none
File Server Online Recovery point Appears hung RRS feed

  • Question

  • we are using DPM2012R2 to protect a number of servers running on a Hyper-V CSV Cluster. Some are full Hyper-V backups, some Exchange and some Agent-based File servers. We are using Disk short termp protection and Azure Recovery Services for Long-Term.

    A couple of weeks ago We had some corruption on one of the target disks and ultimately had to mark the disk offline , add a new replacement disk and reallocate all affected replicas. This worked successfully and after an initial resync all protected servers are now performing disk-based recovery points as they should.

    All are also performing online recovery points as they should apart from 1 large file server Data Volume (approx 2.8TB).

    I have tried restarting DPM but essentially get the same issue with this job each time - it starts and runs fine and I can see in resource monitor that the target VHDs are being actively accessed for the first few hours, but thereafter the job seems to hang and no further data is transmitted

    So the job above has not written any data since about 4 hours into the job - it's now at 48 Hours 41 Minutes.

    the CBENGINECURR.ERRLOG is not offering a great deal of information  but is littered with :

    [000000001A9C7510] C163BB3E-C720-4FC0-987A-7F5959714A09  ACTIVITY Last completed state for Ds Id (17594024357756) is 5

    events followed typically with a block of events like :

    0CD4 12FC 07/26 10:20:28.767 79 WcfClient.cs(986)  C163BB3E-C720-4FC0-987A-7F5959714A09  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 = None/None, Message =
    0CD4 12FC 07/26 10:20:28.767 79 WcfClient.cs(986)  C163BB3E-C720-4FC0-987A-7F5959714A09  WARNING ).}
    0CD4 12FC 07/26 10:20:28.767 79 WcfClient.cs(725)  C163BB3E-C720-4FC0-987A-7F5959714A09  NORMAL Request submitted for async processing
    0CD4 12FC 07/26 10:20:28.767 79 WcfClient.cs(948)  C163BB3E-C720-4FC0-987A-7F5959714A09  NORMAL Executing web service call | Params: {ServiceInterface = Microsoft.Internal.CloudBackup.Common.FileCatalog.Interface.IFileCatalogExternalChannel}{Description = GetStatus}{TargetEndpoint = https://pod01-fc1.ne.backup.windowsazure.com/FileCatalogExternalService.svc}
    0CD4 12FC 07/26 10:20:28.767 69 CBEngineWcfClientHelper.cs(379)  C163BB3E-C720-4FC0-987A-7F5959714A09  NORMAL Setting RequestId header for outgoing request | Params: {RequestId = 99b423de-cff1-46db-83a1-4313f71876c5}{WorkitemId = eb88cd96-f0e3-4cc8-83c9-c808117fb00f}{TaskId = c163bb3e-c720-4fc0-987a-7f5959714a09}{AgentVersion = 2.0.9077.0}
    0CD4 12FC 07/26 10:20:28.917 79 WcfClient.cs(969)  C163BB3E-C720-4FC0-987A-7F5959714A09  NORMAL Finished web service call | Params: {ServiceInterface = Microsoft.Internal.CloudBackup.Common.FileCatalog.Interface.IFileCatalogExternalChannel}{Description = GetStatus}{TargetEndpoint = https://pod01-fc1.ne.backup.windowsazure.com/FileCatalogExternalService.svc}
    0CD4 12FC 07/26 10:20:28.917 79 WcfClient.cs(816)  C163BB3E-C720-4FC0-987A-7F5959714A09  WARNING FMBlock: Executing retry policy | Params: {CurrentAttempt = 1}{MaxAttempts = 18000}{BackOffIntervalInSec = 3.6}{OperationCode = WcfProxyGenericAsyncOperationPollingCall}{Retry policy id = 7}
    0CD4 03E4 07/26 10:20:29.348 71 dscontext.cpp(183) [000000001A9C7510] C163BB3E-C720-4FC0-987A-7F5959714A09  ACTIVITY Last completed state for Ds Id (17594024357756) is 5
    0CD4 03E4 07/26 10:20:31.351 71 dscontext.cpp(183) [000000001A9C7510] C163BB3E-C720-4FC0-987A-7F5959714A09  ACTIVITY Last completed state for Ds Id (17594024357756) is 5
    0CD4 12FC 07/26 10:20:31.710 79 WcfClient.cs(948)  C163BB3E-C720-4FC0-987A-7F5959714A09  NORMAL Executing web service call | Params: {ServiceInterface = Microsoft.Internal.CloudBackup.Common.FileCatalog.Interface.IFileCatalogExternalChannel}{Description = GetStatus}{TargetEndpoint = https://pod01-fc1.ne.backup.windowsazure.com/FileCatalogExternalService.svc}
    0CD4 12FC 07/26 10:20:31.710 69 CBEngineWcfClientHelper.cs(379)  C163BB3E-C720-4FC0-987A-7F5959714A09  NORMAL Setting RequestId header for outgoing request | Params: {RequestId = 33e0db8b-1e78-4406-ab10-d41417526dcf}{WorkitemId = de4e14e4-1552-46fc-b03e-3a1c5971c9ab}{TaskId = c163bb3e-c720-4fc0-987a-7f5959714a09}{AgentVersion = 2.0.9077.0}
    0CD4 12FC 07/26 10:20:31.901 79 WcfClient.cs(969)  C163BB3E-C720-4FC0-987A-7F5959714A09  NORMAL Finished web service call | Params: {ServiceInterface = Microsoft.Internal.CloudBackup.Common.FileCatalog.Interface.IFileCatalogExternalChannel}{Description = GetStatus}{TargetEndpoint = https://pod01-fc1.ne.backup.windowsazure.com/FileCatalogExternalService.svc}
    0CD4 12FC 07/26 10:20:31.901 79 WcfClient.cs(816)  C163BB3E-C720-4FC0-987A-7F5959714A09  WARNING FMBlock: Executing retry policy | Params: {CurrentAttempt = 2}{MaxAttempts = 18000}{BackOffIntervalInSec = 4.8}{OperationCode = WcfProxyGenericAsyncOperationPollingCall}{Retry policy id = 7}
    0CD4 03E4 07/26 10:20:33.354 71 dscontext.cpp(183) [000000001A9C7510] C163BB3E-C720-4FC0-987A-7F5959714A09  ACTIVITY Last completed state for Ds Id (17594024357756) is 5
    0CD4 12FC 07/26 10:20:35.199 79 WcfClient.cs(948)  C163BB3E-C720-4FC0-987A-7F5959714A09  NORMAL Executing web service call | Params: {ServiceInterface = Microsoft.Internal.CloudBackup.Common.FileCatalog.Interface.IFileCatalogExternalChannel}{Description = GetStatus}{TargetEndpoint = https://pod01-fc1.ne.backup.windowsazure.com/FileCatalogExternalService.svc}
    0CD4 12FC 07/26 10:20:35.199 69 CBEngineWcfClientHelper.cs(379)  C163BB3E-C720-4FC0-987A-7F5959714A09  NORMAL Setting RequestId header for outgoing request | Params: {RequestId = 5c264d7a-3d9a-4480-b533-9de512b31a9f}{WorkitemId = d438bde0-d05b-48c8-9da2-51edd92f737b}{TaskId = c163bb3e-c720-4fc0-987a-7f5959714a09}{AgentVersion = 2.0.9077.0}
    0CD4 03E4 07/26 10:20:35.355 71 dscontext.cpp(183) [000000001A9C7510] C163BB3E-C720-4FC0-987A-7F5959714A09  ACTIVITY Last completed state for Ds Id (17594024357756) is 5
    0CD4 12FC 07/26 10:20:35.417 79 WcfClient.cs(969)  C163BB3E-C720-4FC0-987A-7F5959714A09  NORMAL Finished web service call | Params: {ServiceInterface = Microsoft.Internal.CloudBackup.Common.FileCatalog.Interface.IFileCatalogExternalChannel}{Description = GetStatus}{TargetEndpoint = https://pod01-fc1.ne.backup.windowsazure.com/FileCatalogExternalService.svc}
    0CD4 12FC 07/26 10:20:35.417 79 WcfClient.cs(816)  C163BB3E-C720-4FC0-987A-7F5959714A09  WARNING FMBlock: Executing retry policy | Params: {CurrentAttempt = 3}{MaxAttempts = 18000}{BackOffIntervalInSec = 7.2}{OperationCode = WcfProxyGenericAsyncOperationPollingCall}{Retry policy id = 7}

    I have seen some suggestion that deleting VHDS under the AzureRecoveryServicesAgent\Scratch folder might resolve but equally ahve read it's really not a good Idea to tinker in here so I'mloathe to do that.

    Any suggestions?  I really need to get this file server backing up properly as it's now 3 weeks with out a long-term Azure backup.

    All other Online Recovery Points are completing succesfuly I might add - it's just this one data volume that is 'failing'

    Wednesday, July 26, 2017 10:47 AM