none
DPM 2010 BMR not working for newly added servers RRS feed

  • Question

  • Hi,

    I have following setup:

    1. DPM2010 setup with System State and Bare Metal recovery protection enabled for all the servers and that is working fine.

    2. recently added 2 new Windows 2008 R2 servers that are part of same domian.

    3. Changed the default backup location on PSDataSourceConfig.xml file from C:\ (50GB) to D:\windowsImageBackup that has around 200 GB of free space. system and backup operators have full control of this folder

    4. I am able to take a local system state backup using wbadmin.exe and console both.

    5. Registry key for AllowSSBToAnyVolume is set to 1.

    6. checked DNS, the name resolution has no issues.

    7. all are physical servers & no virtualization involved.

    Still the consistency check for system state and bare metal recovery fails.

    Logs from DPM Agent:

    1E8C 1F68 10/20 03:33:26.256 29 radefaultsubtask.cpp(337) [000000000165D790] 6E9ED180-4550-4089-A718-19FF7A2C7A55 ACTIVITY CRADefaultSubTask::CommandReceivedSpecific => Command SetActiveOwner Received
    1E8C 1F68 10/20 03:33:26.417 03 workitem.cpp(86) [0000000000468AF0] 6E9ED180-4550-4089-A718-19FF7A2C7A55 ACTIVITY Idle Timer created with timeout = 390000
    1E8C 1F68 10/20 03:33:26.610 31 vadatasourcestate.cpp(729)  6E9ED180-4550-4089-A718-19FF7A2C7A55 WARNING Failed: Hr: = [0x8007007e] GetModuleHandle failed for Library [GenericNonVssDatasourceHelperPlugin], will try LoadLibrary
    1E8C 1F68 10/20 03:33:26.691 18 agentutils.hpp(68)  6E9ED180-4550-4089-A718-19FF7A2C7A55 WARNING Failed: Hr: = [0x80070002] : F: lVal : r.GetValue(pszKey, pT)
    1E8C 1F68 10/20 03:33:26.691 18 fsutils.cpp(4426)  6E9ED180-4550-4089-A718-19FF7A2C7A55 NORMAL CClientReadThrottler::InitializeWaitForClientRead Failed to read sleep time from registry [hr = 0x80070002]. Setting default [50 ms].
    1E8C 1F68 10/20 03:33:26.691 31 dllmain.cpp(36)  6E9ED180-4550-4089-A718-19FF7A2C7A55 NORMAL GenericNonVssDatasourceHelperPlugin: DLL_PROCESS_ATTACH
    1E8C 1638 10/20 03:33:26.691 31 vssbaserequestor.cpp(62) [0000000001660590] 6E9ED180-4550-4089-A718-19FF7A2C7A55 NORMAL CVssBaseRequestor: constructor [0000000001660590]
    1E8C 1638 10/20 03:33:26.691 31 vsssnapshotrequestor.cpp(76) [0000000001660590] 6E9ED180-4550-4089-A718-19FF7A2C7A55 NORMAL CVssSnapshotRequestor::CVssSnapshotRequestor [0000000001660590]
    1E8C 1638 10/20 03:33:26.691 31 vssbaserequestor.cpp(99) [0000000001660590] 6E9ED180-4550-4089-A718-19FF7A2C7A55 NORMAL CVssBaseRequestor::Initialize [0000000001660590]
    1E8C 1638 10/20 03:33:26.707 31 vsssnapshotrequestor.cpp(170) [0000000001660590] 6E9ED180-4550-4089-A718-19FF7A2C7A55 NORMAL CVssSnapshotRequestor::InitializeSnapshotCreation [0000000001660590]
    1E8C 1638 10/20 03:33:26.964 22 agentutils.cpp(2373)  6E9ED180-4550-4089-A718-19FF7A2C7A55 WARNING Failed: Hr: = [0x80070002] Could not open HKEY_LOCAL_MACHINE\Software\Microsoft\Microsoft Data Protection Manager\Agent\2.0
    1E8C 1638 10/20 03:33:27.109 31 vsssnapshotrequestor.cpp(94) [0000000001660590] 6E9ED180-4550-4089-A718-19FF7A2C7A55 NORMAL CVssSnapshotRequestor::~CVssSnapshotRequestor [0000000001660590]
    1E8C 1638 10/20 03:33:27.109 31 vsssnapshotrequestor.cpp(1763) [0000000001660590] 6E9ED180-4550-4089-A718-19FF7A2C7A55 NORMAL CVssSnapshotRequestor::CleanUp [0000000001660590]
    1E8C 1638 10/20 03:33:27.109 31 vssbaserequestor.cpp(80) [0000000001660590] 6E9ED180-4550-4089-A718-19FF7A2C7A55 NORMAL CVssBaseRequestor: destructor [0000000001660590]
    1E8C 1638 10/20 03:33:27.109 03 workitem.cpp(272) [0000000000468A80] 6E9ED180-4550-4089-A718-19FF7A2C7A55 ACTIVITY WorkItem stopping
    1E8C 1638 10/20 03:33:27.399 29 radefaultsubtask.cpp(337) [000000000165D790] A1186049-977E-4BB4-ABAE-517041D00444 ACTIVITY CRADefaultSubTask::CommandReceivedSpecific => Command SetActiveOwner Received
    1E8C 1638 10/20 03:33:27.544 03 workitem.cpp(86) [0000000000468AF0] A1186049-977E-4BB4-ABAE-517041D00444 ACTIVITY Idle Timer created with timeout = 390000
    1E8C 1638 10/20 03:33:27.834 31 aaxmlprocessingutils.cpp(49)  A1186049-977E-4BB4-ABAE-517041D00444 WARNING Failed: Hr: = [0x80070057] : F: lVal : E_INVALIDARG
    1E8C 1638 10/20 03:33:27.898 31 basewriterhelperplugin.cpp(155) [0000000001667B50] A1186049-977E-4BB4-ABAE-517041D00444 NORMAL SetOperationType(1)
    1E8C 1638 10/20 03:33:27.914 31 createsnapshotsubtask.cpp(1003) [0000000001663740] A1186049-977E-4BB4-ABAE-517041D00444 NORMAL Executing PreSnap step ""C:\Program Files\Microsoft Data Protection Manager\DPM\bin\BMRBackup.cmd"  \\asmsgdpm02.asm.com\78b7fb37bc94465bb667f249950360fe"
    1E8C 1F68 10/20 03:38:45.706 31 vastatemachineutils.cpp(843) [0000000000468C50]  WARNING Failed: Hr: = [0x809909fb] : F: lVal : m_pScriptExecutor->GetFailureHR()
    1E8C 1F68 10/20 03:38:45.706 05 fsmstate.cpp(167) [0000000001660E00]  WARNING Failed: Hr: = [0x809909fb] : F: lVal : pTransition->Execute(pEvent)
    1E8C 1F68 10/20 03:38:45.706 05 genericfsm.cpp(225) [00000000016623B0]  WARNING Failed: Hr: = [0x809909fb] : F: lVal : m_pCurrentState->SendEvent(pEvent, pNextState)
    1E8C 1F68 10/20 03:38:45.706 05 fsmtransition.cpp(111) [0000000000483E80]  WARNING Failed: Hr: = [0x809909fb] HasEventErrorCode: completion: 0x27, signature: 0xaabbcc00
    1E8C 1F68 10/20 03:38:45.800 22 eventsutil.cpp(88) [00000000047CF6F0]  WARNING Failed: Hr: = [0x80070103] : F: lVal : m_pfnEvtNext(m_hQueryResult, 1, &m_hEvent, -1, 0, &dwEventsReturned)
    1E8C 1F68 10/20 03:38:45.800 31 aasubtask.cpp(1373) [0000000001663740]  WARNING Updating task status with hr: 809909fb8x, dls error code:30072
    1E8C 1F68 10/20 03:38:45.800 31 aasubtask.cpp(913) [0000000001663740]  WARNING <?xml version="1.0"?>
    1E8C 1F68 10/20 03:38:45.800 31 aasubtask.cpp(913) [0000000001663740]  WARNING <Status xmlns="http://schemas.microsoft.com/2003/dls/StatusMessages.xsd" StatusCode="-2137454085" Reason="Error" CommandID="RAPreBackup" CommandInstanceID="4d764856-9cbc-4a89-af87-9f9bac90fe8f" GuidWorkItem="be0807b8-fda2-4734-a8b5-14ff89fcc359" TETaskInstanceID="a1186049-977e-4bb4-abae-517041d00444"><ErrorInfo xmlns="http://schemas.microsoft.com/2003/dls/GenericAgentStatus.xsd" ErrorCode="998" DetailedCode="-2137454085" DetailedSource="2"/><RAStatus><RAPreBackup xmlns="http://schemas.microsoft.com/2003/dls/ArchiveAgent/StatusMessages.xsd"><BackupTime>129635555258000000</BackupTime><DSStatus><ComponentName>System Protection</ComponentName><LogicalPath>Computer</LogicalPath><BackupStamp></BackupStamp><Metadata></Metadata></DSStatus></RAPreBackup></RAStatus></Status>
    1E8C 1F68 10/20 03:38:45.800 03 runtime.cpp(1599) [000000000046C4D0]  FATAL Subtask failure, sending status response XML=[<?xml version="1.0"?>
    1E8C 1F68 10/20 03:38:45.800 03 runtime.cpp(1599) [000000000046C4D0]  FATAL <Status xmlns="http://schemas.microsoft.com/2003/dls/StatusMessages.xsd" StatusCode="-2137454085" Reason="Error" CommandID="RAPreBackup" CommandInstanceID="4d764856-9cbc-4a89-af87-9f9bac90fe8f" GuidWorkItem="be0807b8-fda2-4734-a8b5-14ff89fcc359" TETaskInstanceID="a1186049-977e-4bb4-abae-517041d00444"><ErrorInfo xmlns="http://schemas.microsoft.com/2003/dls/GenericAgentStatus.xsd" ErrorCode="30072" DetailedCode="-2137454085" DetailedSource="2"><Parameter Name="WindowsBackupErrorCode" Value="0x80070040"/><Parameter Name="WindowsBackupEventID" Value="517"/><Parameter Name="AgentTargetServer" Value="ASMSGMSM01.asm.com"/></ErrorInfo><RAStatus><RAPreBackup xmlns="http://schemas.microsoft.com/2003/dls/ArchiveAgent/StatusMessages.xsd"><BackupTime>129635555258000000</BackupTime><DSStatus><ComponentName>System Protection</ComponentName><LogicalPath>Computer</LogicalPath><BackupStamp></BackupStamp><Metadata></Metadata></DSStatus></RAPreBackup></RAStatus></Status>
    1E8C 1F68 10/20 03:38:45.800 03 runtime.cpp(1599) [000000000046C4D0]  FATAL ]
    1E8C 1578 10/20 03:38:46.147 31 freesnapshotsubtask.cpp(46) [000000000166A450] A1186049-977E-4BB4-ABAE-517041D00444 NORMAL CFreeSnapshotSubTask: constructor [000000000166A450]
    1E8C 1578 10/20 03:38:46.147 31 freesnapshotsubtask.cpp(123) [000000000166A450] A1186049-977E-4BB4-ABAE-517041D00444 NORMAL CFreeSnapshotSubTask::TriggerDone [000000000166A450]
    1E8C 1578 10/20 03:38:46.210 31 freesnapshotsubtask.cpp(559) [000000000166A450] A1186049-977E-4BB4-ABAE-517041D00444 NORMAL CFreeSnapshotSubTask: StartBackupComplete [000000000166A450]
    1E8C 1578 10/20 03:38:46.210 31 freesnapshotsubtask.cpp(671) [000000000166A450] A1186049-977E-4BB4-ABAE-517041D00444 NORMAL CFreeSnapshotSubTask: ReleaseSnapshot [000000000166A450]
    1E8C 1F68 10/20 03:38:46.210 31 freesnapshotsubtask.cpp(181) [000000000166A450] A1186049-977E-4BB4-ABAE-517041D00444 NORMAL CFreeSnapshotSubTask::GetFinalStatus [000000000166A450]
    1E8C 1F68 10/20 03:38:46.274 31 freesnapshotsubtask.cpp(63) [000000000166A450] A1186049-977E-4BB4-ABAE-517041D00444 NORMAL CFreeSnapshotSubTask: destructor [000000000166A450]
    1E8C 1578 10/20 03:38:46.573 03 workitem.cpp(272) [0000000000468A80] A1186049-977E-4BB4-ABAE-517041D00444 ACTIVITY WorkItem stopping
    1E8C 0590 10/20 03:41:41.867 03 service.cpp(147) [000000000013FAA0]  ACTIVITY CService::ServiceHandlerExInternal
    1E8C 1848 10/20 03:43:49.119 03 runtime.cpp(1652) [000000000046C4D0]  NORMAL CDLSRuntime::ProcessIdleTimeout
    1E8C 1848 10/20 03:43:49.119 03 runtime.cpp(646) [000000000046C4D0]  NORMAL CDLSRuntime::Uninitialize, bForce: 0
    1E8C 1848 10/20 03:43:49.119 05 genericagent.cpp(264) [0000000000469E30]  NORMAL Agent Can Shutdown if there is only default wokitem active[1]
    1E8C 1848 10/20 03:43:49.119 29 dpmra.cpp(360) [0000000000469E30]  NORMAL CDPMRA::Shutting down dpmra, force-shutdown :yes
    1E8C 1848 10/20 03:43:49.119 03 workitem.cpp(391)   NORMAL Timing out WI [000000000163A030], WI GUID = {B71B4544-7067-4A30-B5FB-BA320B10D82A}, ..last DM activity happened 1113613msec back, WI Idle Timeout = 390000msec
    1E8C 1848 10/20 03:43:49.119 22 genericthreadpool.cpp(664) [000000000021FA80]  NORMAL CGenericThreadPool: Waiting for threads to exit
    1E8C 1DCC 10/20 03:43:51.136 20 cc_base.cpp(1226) [0000000000498170]  NORMAL DM: Aborting  http state machine for reason 0
    1E8C 1DCC 10/20 03:43:51.136 20 cc_base.cpp(1226) [000000000048E5B0]  NORMAL DM: Aborting  http state machine for reason 0
    1E8C 1848 10/20 03:43:51.136 20 cc_base.cpp(388) [000000000048E5B0]  NORMAL DM: Going to timeout connection
    1E8C 1848 10/20 03:43:51.136 20 cc_base.cpp(388) [00000000004918A0]  NORMAL DM: Going to timeout connection
    1E8C 1DD8 10/20 03:43:51.136 20 cc_base.cpp(1226) [0000000000495E80]  NORMAL DM: Aborting  http state machine for reason 0
    1E8C 1184 10/20 03:43:51.136 20 cc_base.cpp(1226) [0000000000493B90]  NORMAL DM: Aborting  http state machine for reason 0
    1E8C 1914 10/20 03:43:51.136 20 cc_base.cpp(1226) [00000000004918A0]  NORMAL DM: Aborting  http state machine for reason 0
    1E8C 1848 10/20 03:43:51.136 20 cc_base.cpp(388) [0000000000493B90]  NORMAL DM: Going to timeout connection
    1E8C 1848 10/20 03:43:51.136 20 cc_base.cpp(388) [0000000000495E80]  NORMAL DM: Going to timeout connection
    1E8C 1848 10/20 03:43:51.136 20 cc_base.cpp(388) [000000000049A460]  NORMAL DM: Going to timeout connection
    1E8C 1848 10/20 03:43:51.136 20 cc_base.cpp(388) [000000000049C750]  NORMAL DM: Going to timeout connection
    1E8C 1848 10/20 03:43:51.136 20 cc_base.cpp(388) [0000000000217FD0]  NORMAL DM: Going to timeout connection
    1E8C 1848 10/20 03:43:51.136 20 cc_base.cpp(388) [000000000021A2C0]  NORMAL DM: Going to timeout connection
    1E8C 1848 10/20 03:43:51.136 20 cc_base.cpp(388) [000000000021C5B0]  NORMAL DM: Going to timeout connection
    1E8C 1DCC 10/20 03:43:51.136 20 cc_base.cpp(1226) [000000000021C5B0]  NORMAL DM: Aborting  http state machine for reason 0
    1E8C 1DD8 10/20 03:43:51.136 20 cc_base.cpp(1226) [000000000021A2C0]  NORMAL DM: Aborting  http state machine for reason 0
    1E8C 1DCC 10/20 03:43:51.136 20 cc_base.cpp(1226) [0000000000217FD0]  NORMAL DM: Aborting  http state machine for reason 0
    1E8C 1DD8 10/20 03:43:51.136 20 cc_base.cpp(1226) [000000000049C750]  NORMAL DM: Aborting  http state machine for reason 0
    1E8C 1184 10/20 03:43:51.136 20 cc_base.cpp(1226) [000000000049A460]  NORMAL DM: Aborting  http state machine for reason 0
    1E8C 1848 10/20 03:43:51.136 22 genericthreadpool.cpp(664) [000000000046C4D0]  NORMAL CGenericThreadPool: Waiting for threads to exit
    1E8C 12C4 10/20 03:43:53.168 03 timer.cpp(513) [000000000049F568]  ACTIVITY Shutting down timer thread.
    1E8C 1848 10/20 03:43:53.168 03 service.cpp(81)   ACTIVITY CService::StopThisService
    1E8C 1848 10/20 03:43:53.168 03 service.cpp(281) [000000000013FAA0]  ACTIVITY CService::StopService()

    Thursday, October 20, 2011 7:48 AM

Answers

  • Hi All,

    Sorry for the delay in response to this thread.

    We were finally able to resolve the call by opening a support case with DELL and Microsoft. 

    Dell requested to upgrade firmware & drivers software of LTO drive

    Updated Microsoft DPM with latest patches available.

    Most of the features started working fine as expected.

    Thanks for all your support.

    Regards,

    Amit Raja

    • Marked as answer by Amit Raja Friday, July 13, 2012 9:05 AM
    Friday, July 13, 2012 9:05 AM

All replies

  • Hello,

    I assume that the target server in question is ASMSGMSM01.asm.com, correct? 


    1E8C 1F68 10/20 03:38:45.800 03 runtime.cpp(1599) [000000000046C4D0] FATAL <Status xmlns="http://schemas.microsoft.com/2003/dls/StatusMessages.xsd" StatusCode="-2137454085" Reason="Error" CommandID="RAPreBackup" CommandInstanceID="4d764856-9cbc-4a89-af87-9f9bac90fe8f" GuidWorkItem="be0807b8-fda2-4734-a8b5-14ff89fcc359" TETaskInstanceID="a1186049-977e-4bb4-abae-517041d00444"><ErrorInfo xmlns="http://schemas.microsoft.com/2003/dls/GenericAgentStatus.xsd" ErrorCode="30072" DetailedCode="-2137454085" DetailedSource="2"><Parameter Name="WindowsBackupErrorCode" Value="0x80070040"/><Parameter Name="WindowsBackupEventID" Value="517"/><Parameter Name="AgentTargetServer" Value="ASMSGMSM01.asm.com"/></ErrorInfo><RAStatus><RAPreBackup

    err 80070040
    # as an HRESULT: Severity: FAILURE (1), FACILITY_WIN32 (0x7), Code 0x40
    # for hex 0x40 / decimal 64
      ERROR_NETNAME_DELETED
    # The specified network name is no longer available.
    # 1 matches found for "80070040"

     

    The 80070040 can be, but not always, caused by:
    a.) Server in shadow copy protected mode
    b.) Aggressive filtering 3rd party apps.  (Antivirus, firewalls both software and hardware)

    Quesitons

    1.) Do you see any errors on the DPM or protected server like:

    Event Type: Error
    Event Source: VolSnap
    Event Category: None
    Event ID: 93
    User: N/A
    Computer: Server1
    Description: Volume C:\...System\E-GUID is offline for shadow copy protection. The shadow copy storage was made inaccessible or removed from the system.
    Ensure that the shadow copy storage is present. Try clearing the protection fault or rsestart the computer. If it still fails, revert out of shadow copy protection
    mode to reclaim the use of the volume while losing the shadow copies.

    2.) Do you have any filtering apps on the target server that you can temp remove?  Unfortunately disabling such things does not remove the filters from both the registry and protocol stack.  Only a removal can do that.  Of course you could test via disabling first for testing.

    3.) I know that a system state works by using wbadmin but does a BMR by wbadmin work as well?
          wbadmin start backup -allcritical -backupTarget:<any existing drive name>:

     

    4.) Are you adding them to a existing PG or their own PG? 


    Thanks
    Shane

     

     

    Friday, October 21, 2011 2:20 PM
  • Hi Shane,

    Thanks for the response.

    Here are the details you requested:

    The 80070040 can be, but not always, caused by:
    a.) Server in shadow copy protected mode - I dont see any errors related to this in eventvwr.

    b.) Aggressive filtering 3rd party apps. (Antivirus, firewalls both software and hardware)

    - windows Firewall is disabled, no other firewall in between dpm and target server as they are on LAN

    - Antivirus is McAfee Virus Scan Enterprise, that is consistent on all servers.

    1.) Do you see any errors on the DPM or protected server like: I dont see this error

    Event Type: Error
    Event Source: VolSnap
    Event Category: None
    Event ID: 93
    User: N/A
    Computer: Server1
    Description: Volume C:\...System\E-GUID is offline for shadow copy protection. Theshadow copy storage was made inaccessible or removed from the system.
    Ensure that the shadow copy storage is present. Try clearing the protection fault or rsestart the computer. If it still fails, revert out ofshadow copy protection
    mode to reclaim the use of the volume while losing the shadow copies.

    2.) Do you have any filtering apps on the target server that you can temp remove? Unfortunately disabling such things does not remove the filters from both the registry and protocol stack. Only a removal can do that. Of course you could test via disabling first for testing. - No apps installed on this server other than SystemCenterServiceManager

    3.) I know that a system state works by using wbadmin but does a BMR by wbadmin work as well?
    wbadmin start backup -allcritical -backupTarget:<any existing drive name>: - Yes the BMR backup works

     

    4.) Are you adding them to a existing PG or their own PG? - I am adding it to the existing Protection Group, this group is created only for System state and BMR backup of all the servers.

    Regards,

    Amit Raja

    Monday, October 24, 2011 3:30 AM
  • Hello Amit,

    I'd try the following:

    1.) Setup the antivirus as per: http://technet.microsoft.com/en-us/library/ff399439.aspx
    I personally elect to NOT scan the entire DPM directory on both the DPM server and the client server.

    2.) Remove the target server from the PG altogether.  Create a new PG just for this server BMR with plenty of space.

    Once this is done, is a successful replica created?


    Shane

    Monday, October 24, 2011 12:21 PM
  • Hello,

    Is this still a problem?
    Please reference this article in your efforts to resolve this issue:
    http://blogs.technet.com/b/dpm/archive/2011/10/31/troubleshooting-data-protection-manager-system-state-and-bare-metal-backup.aspx

     

    Thanks,
    Shane

    • Proposed as answer by ShaneB. _ Tuesday, December 20, 2011 3:20 PM
    Wednesday, November 16, 2011 9:23 PM
  • Hi Shane,

    Thanks for the effort....

    This was for my client, they are yet to implement the suggestions that you provided, i am waiting for them to do the changes and respond back to me.

    As a workaround, we have taken the manual backup.

    Would keep you posted if the scenario changes.

    Regards,

    Amit Raja

    Tuesday, November 22, 2011 7:41 AM
  • Hello,

    Are you still having the issue?


    Thanks
    Shane
    • Proposed as answer by ShaneB. _ Tuesday, December 20, 2011 3:18 PM
    Friday, December 2, 2011 7:40 PM
  • Hi All,

    Sorry for the delay in response to this thread.

    We were finally able to resolve the call by opening a support case with DELL and Microsoft. 

    Dell requested to upgrade firmware & drivers software of LTO drive

    Updated Microsoft DPM with latest patches available.

    Most of the features started working fine as expected.

    Thanks for all your support.

    Regards,

    Amit Raja

    • Marked as answer by Amit Raja Friday, July 13, 2012 9:05 AM
    Friday, July 13, 2012 9:05 AM