none
0x809909FB DPM 2010 RRS feed

  • Question

  • Hello,

    i have the following problem. When i want to backup System State with DPM2010 on Windows Server 2008 i get the failure 0x809909FB. There is enough Space on the backed up server. A normal System state backup with wbadmin works. VSS writes are all ok.  Can somebody help me?

     

    Thanks Felix

     

    • Moved by Praveen D [MSFT] Monday, July 19, 2010 7:27 AM Moving to DPM SS and BMR Protection Forum (From:Data Protection Manager)
    Friday, May 14, 2010 12:21 PM

Answers

  • The disk is a 4K sector drive, Windows and DPM don't control the sector size.  You may want to check with the manufacturer and see if you can enable emulation mode for 512 bytes / sector.  If it can be done, you will need to delete all volumes from the disk, and start over.

     

    Alternative would be to add a new 512 bytes/ sector drive and use custom volumes to host the BMR backup replica and recovery point volumes.


    Regards, Mike J [MSFT] This posting is provided "AS IS" with no warranties, and confers no rights.
    Thursday, August 26, 2010 6:07 PM
    Moderator

All replies

  • Hi,

    System state backup using wbadmin could be working for you may be because you have selected backup target which has lot of free space. In the DPM case this drive may not be the one that is being used. To find out which drive DPM is using to stage the system state backup, can you open "C:\Program Files\Microsoft Data Protection Manager\DPM\Datasources\PSDataSourceConfig.xml" and check the free space on the drive that is present in <FilesToProtect> tag.

    You can change the drive location as appropriate and re-configure protection for system state.

    Thanks

    Shyama

    Friday, May 14, 2010 12:41 PM
  • Hello,

     

    thanks for your answer. The drive is <FilesToProtect>C:\WindowsImageBackup\*</FilesToProtect>

    There are 215 GB of 250 GB free. I think this is enough. I have the Problem on all my Windows 2008 and 2008 R2 Servers.

    Thanks

    Felix

    Friday, May 14, 2010 12:51 PM
  • Hi,

    Can you post the DPM alert corresponding to the failure? Also does the job fail immediately or fails after some time.

    One possibility is that the replica space creatd by DPM is not enough to hold the system state backup. DPM 2010 by default assumes 10 GB system state size since there is no way to predict how much the space will be needed. In you case if the system state size is more than 10 GB modify the protection group to increase the disk allocation.

    If the above happens typically after about 30-40 mins when windows server backup has dumped the system state backup to local volume and then DPM tries to transfer the data.

    Since C: is also your staging location please verify whether "AllowSSBToAnyVolume" regkey is set, so that DPM can use the C: as the staging location. This is also documented as part of the following support article.

    http://support.microsoft.com/kb/944530

    Thanks

    Shyama Hembram

     

    Friday, May 14, 2010 4:30 PM
  • Felix,

    if you open up the properties of C:\ and you look at the shadowcopies properties, it is more than likely not enabled, but is there a size limit set?


    Walt W [MSFT] This posting is provided "AS IS" with no warranties, and confers no rights.
    Friday, May 14, 2010 4:46 PM
  • Hello,

    thanks for the answers. Here is DPM Alert:

    Affected area: Computer\System Protection
    Occurred since: 14.05.2010 19:33:09
    Description: The replica of System Protection Computer\System Protection on VP-DC-02.highway.vp-tecmedia.com is inconsistent with the protected data source. All protection activities for data source will fail until the replica is synchronized with consistency check. You can recover data from existing recovery points, but new recovery points cannot be created until the replica is consistent.

    For SharePoint farm, recovery points will continue getting created with the databases that are consistent. To backup inconsistent databases, run a consistency check on the farm. (ID 3106)
     DPM cannot create a backup because Windows Server Backup (WSB) on the protected computer encountered an error (WSB Event ID: 517, WSB Error Code:  0x8078002A). (ID 30229 Details: Internal error code: 0x809909FB)
     More information
    Recommended action: For resolution actions and more information on the WSB error, go to http://technet.microsoft.com/en-us/library/cc734488(WS.10).aspx.
     Synchronize with consistency check.
     Run a synchronization job with consistency check...
    Resolution: To dismiss the alert, click below
     Inactivate alert

    Shadow copies are diabled and no limit is set. The manual system state backup is about 11 GB. On c: there are. 210 GB are free on the c: volume.

    Disk allocation is set zo 40 GB.

    The reg key is set to 1. Manual backup with wbadmin works.

    Thanks

    FElix

     

     

     

     

     

    Friday, May 14, 2010 5:42 PM
  • Hi,

    Can you review the resolution steps for this event as described at http://technet.microsoft.com/en-us/library/cc734395(WS.10).aspx.

    Thanks

    Shyama


    Thanks Shyama Hembram[MSFT] This posting is provided "AS IS" with no warranties, and confers no rights.
    Monday, May 17, 2010 7:33 PM
  • Hi Felix,

    That error code 0x8078002A from the dpm alerts = "One of the backup files could not be created."

    This is being returned by the Windows Server backup engine.

    Look in the Event log under "Application and Services Logs" - Microsoft - Windows - backup: and see if you find any failed backup events, then look at the details.

    DPM simply runs the Windows Server backup by executing a .cmd file and passing the drive letter telling backup what drive to store the backup on.
    You can mimick what DPM does by running the following commands from an elevated command prompt on the protected server in question.

       CD C:\Program Files\Microsoft Data Protection Manager\DPM\bin
       LHSystemStateBackup.cmd C:


    If this also fails, then you should seek help from the Windows Server Backup newsgroup.

    Regards
    Mike


    Regards, Mike J [MSFT] This posting is provided "AS IS" with no warranties, and confers no rights.
    Monday, May 17, 2010 11:08 PM
    Moderator
  • Hi,

    the   LHSystemStateBackup.cmd C: works perfectly. Any other suggestions?

    Thanks

    Felix

     

    Wednesday, May 19, 2010 12:15 PM
  • Hi,

    i tried the following:

    C:\>%SystemRoot%\system32\wbadmin.exe start backup -allcritical -quiet -backuptarget:c:

    the message is the volume is a critical volume. But the AllowSSBToAnyVolume Key is correctly set. I don´t understand it.

    Thanks Felix

     

    Wednesday, May 19, 2010 3:50 PM
  • Hi Felix,

     

    Are you selecting SystemState, or Bare Metal Restore for DPM to backup that seems to be failing ?

    LHSystemStateBackup.cmd is used for systemstate backups and uses local storage for the backup files that DPM then protects.

    BMRBackup.cmd is used for bare metal restore, and DPM writes directly to the DPM server via a network share and doesn't use local storage for BMR backups.  

    Try BMRBackup.cmd \\server_name\Share_name and see if that works.  Select a test server, not the DPM server.

    Regards

    Mike J.


    Regards, Mike J [MSFT] This posting is provided "AS IS" with no warranties, and confers no rights.
    Wednesday, May 19, 2010 4:58 PM
    Moderator
  • Hi Mike,

     

    thanks for the feedback BMRBackup.cmd \\server_name\Share_name works. Only System State over DPM works too. Butt Bare Metal over DPM generates Error 517.

     

    Thanks

     

    Felix

     

    Thursday, May 20, 2010 1:24 PM
  • Still the same problem. Any Ideas?

     

    Felix

    Thursday, May 27, 2010 9:08 AM
  • Hi,

    i found the problem. Each time when i added Bare metal to the protection group. Dpm createes a folder in C:\Program Files\Microsoft DPM\DPM\Volumes\Replica\Non VSS Datasource Writer.

    The security settings on the subfolder vol_308110ac-f9c9-43b7-89a4-01fa1d73c06d\efb6a823-cc85-4654-bb02-5fc46aee7683\Full\C-Vol\WindowsImageBackup where wrong. The proteced server was missing. I added it manually with full access and it works.

    The settings are always wrong. On new protection groups, too.

    Thank you

     

    Felix

     

     

    Thursday, May 27, 2010 11:09 AM
  • Hello,

    still the same Problem. The solution above was wrong.

    With my solution above DPM makes the Bare Metal Backup to the folder C:\Program Files\Microsoft DPM\DPM\Volumes\Replica\Non VSS Datasource Writer\vol_a6de4a4f-9e41-4807-a3c2-8371a89e0e46\cdc0618d-6697-4e22-85df-31502f3556f0\Full\D-Vol\WindowsImageBackup\servername

    an not to the attached ISCSI Storage. 0x809909FB only happens when bare metal backup is activated. I think it is a rights problem on the DPM created volumes or an language specific Problem. DPM is english the servers are german.

    Any suggestions?

    Thanks

    Felix

    Tuesday, June 8, 2010 8:57 AM
  • Anybody an idea?
    Wednesday, June 30, 2010 11:06 AM
  • Hello everybody,

    i reinstalled the complete server (os and dpm 2010). After the first backup of a windows 2008 r2 the same problem happend. Only on bmr Backup here are the details:

    on dpm:

    DPM kann keine Sicherung erstellen, da Windows Server Backup (WSB) auf dem geschützten Computer einen Fehler festgestellt hat (WSB-Ereignis-ID: 517, WSB-Fehlercode:  0x8078002A). (ID 30229 Details: Interner Fehlercode: 0x809909FB)

    on the protected server in dpm log:

    120C 132C 07/05 18:00:31.005 31 createsnapshotsubtask.cpp(977) [00000000046DA0B0] A64C66F2-C32D-49AC-891E-C92261B47A9A NORMAL Executing PreSnap step ""c:\Program Files\Microsoft Data Protection Manager\DPM\bin\BMRBackup.cmd" \\vp-backup-svr.highway.vp-tecmedia.com\01f01da13d974dddaf7585d0965a6eef"

    120C 0FE4 07/05 18:00:34.239 18 fsutils.cpp(2944) 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD WARNING Failed: Hr: = [0x80070057] : GetFileHandleById failed to open file, frn:0x0335000000010480

    120C 0FE4 07/05 18:00:34.239 18 fsutils.cpp(2944) 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD WARNING Failed: Hr: = [0x80070057] : GetFileHandleById failed to open file, frn:0x0335000000010480

    120C 0FAC 07/05 18:00:35.755 20 session.cpp(1693) [00000000046BFE40] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL Hr: = [0x00000000] DM: Will attempt to post DM_SESSION_CLOSED, pSes=00000000046BFE40 rcv=0000000000000000 snd=0000000000000000 sesop=0000000004656460 seserr=0000000000000000

    120C 132C 07/05 18:00:35.755 18 dsmsendersubtaskbase.cpp(325) [00000000046562B0] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CDsmSubTaskBase received session closed completion in CLOSE state [00000000046562B0]

    120C 132C 07/05 18:00:35.755 31 readdatasetdeltasubtask.cpp(498) [0000000000365F50] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CReadDatasetDeltaSubTask::SubTaskDone [0000000000365F50]

    120C 132C 07/05 18:00:35.755 31 datasetfixupsubtaskbase.cpp(383) [0000000000365F50] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CDatasetFixupSubTaskBase::SubTaskDone [0000000000365F50] [00000000046562B0]

    120C 132C 07/05 18:00:35.755 31 datasetfixupsubtaskbase.cpp(393) [0000000000365F50] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CDatasetFixupSubTaskBase::SubTaskDone - LWV

    120C 0FE4 07/05 18:00:35.755 31 readdatasetdeltasubtask.cpp(498) [0000000000365F50] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CReadDatasetDeltaSubTask::SubTaskDone [0000000000365F50]

    120C 0FE4 07/05 18:00:35.755 31 datasetfixupsubtaskbase.cpp(383) [0000000000365F50] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CDatasetFixupSubTaskBase::SubTaskDone [0000000000365F50] [00000000046BEDA0]

    120C 0FE4 07/05 18:00:35.755 31 datasetfixupsubtaskbase.cpp(401) [0000000000365F50] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CDatasetFixupSubTaskBase::SubTaskDone - HWV

    120C 0FAC 07/05 18:00:35.755 20 session.cpp(1693) [00000000046C0440] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL Hr: = [0x00000000] DM: Will attempt to post DM_SESSION_CLOSED, pSes=00000000046C0440 rcv=0000000000000000 snd=0000000000000000 sesop=00000000046BEF50 seserr=0000000000000000

    120C 0940 07/05 18:00:35.755 18 dsmreceiversubtaskbase.cpp(324) [00000000046BEDA0] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CDsmReceiverSubTaskBase received completion for session closed in CLEANUP state

    120C 0FAC 07/05 18:00:35.755 20 session.cpp(1693) [00000000046CA200] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL Hr: = [0x00000000] DM: Will attempt to post DM_SESSION_CLOSED, pSes=00000000046CA200 rcv=0000000000000000 snd=0000000000000000 sesop=00000000046BF480 seserr=0000000000000000

    120C 132C 07/05 18:00:35.755 18 dsmsendersubtaskbase.cpp(325) [00000000046BF2D0] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CDsmSubTaskBase received session closed completion in CLOSE state [00000000046BF2D0]

    120C 132C 07/05 18:00:35.755 31 readdatasetdeltasubtask.cpp(498) [0000000000365F50] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CReadDatasetDeltaSubTask::SubTaskDone [0000000000365F50]

    120C 132C 07/05 18:00:35.755 31 datasetfixupsubtaskbase.cpp(383) [0000000000365F50] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CDatasetFixupSubTaskBase::SubTaskDone [0000000000365F50] [00000000046BF2D0]

    120C 132C 07/05 18:00:35.755 31 datasetfixupsubtaskbase.cpp(409) [0000000000365F50] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CDatasetFixupSubTaskBase::SubTaskDone - Fixup

    120C 132C 07/05 18:00:35.755 31 readdatasetdeltasubtask.cpp(541) [0000000000365F50] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CReadDatasetDeltaSubTask::CleanUp [0000000000365F50]

    120C 132C 07/05 18:00:35.755 31 datasetfixupsubtaskbase.cpp(361) [0000000000365F50] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CDatasetFixupSubTaskBase::CleanUp [0000000000365F50]

    120C 132C 07/05 18:00:35.755 18 dsmsubtaskbase.cpp(88) [00000000046562B0] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CDsmSubTaskBase: destructor [00000000046562B0]

    120C 132C 07/05 18:00:35.755 18 dsmsubtaskbase.cpp(88) [00000000046BEDA0] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CDsmSubTaskBase: destructor [00000000046BEDA0]

    120C 132C 07/05 18:00:35.755 18 dsmsubtaskbase.cpp(88) [00000000046BF2D0] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CDsmSubTaskBase: destructor [00000000046BF2D0]

    120C 132C 07/05 18:00:40.989 31 freesnapshotsubtask.cpp(46) [00000000046CA200] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CFreeSnapshotSubTask: constructor [00000000046CA200]

    120C 132C 07/05 18:00:40.989 31 freesnapshotsubtask.cpp(123) [00000000046CA200] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CFreeSnapshotSubTask::TriggerDone [00000000046CA200]

    120C 132C 07/05 18:00:41.005 31 vastatemachineutils.cpp(843) [00000000046D8AD0] WARNING Failed: Hr: = [0x809909fb] : F: lVal : m_pScriptExecutor->GetFailureHR()

    120C 132C 07/05 18:00:41.005 05 fsmstate.cpp(167) [00000000046BB440] WARNING Failed: Hr: = [0x809909fb] : F: lVal : pTransition->Execute(pEvent)

    120C 132C 07/05 18:00:41.005 05 genericfsm.cpp(225) [00000000046D2E20] WARNING Failed: Hr: = [0x809909fb] : F: lVal : m_pCurrentState->SendEvent(pEvent, pNextState)

    120C 132C 07/05 18:00:41.005 05 fsmtransition.cpp(111) [00000000046DDCE0] WARNING Failed: Hr: = [0x809909fb] HasEventErrorCode: completion: 0x27, signature: 0xaabbcc00

    120C 132C 07/05 18:00:41.005 31 aasubtask.cpp(1373) [00000000046DA0B0] WARNING Updating task status with hr: 809909ff8x, dls error code:2023

    120C 132C 07/05 18:00:41.005 31 aasubtask.cpp(913) [00000000046DA0B0] WARNING <?xml version="1.0"?>

    120C 132C 07/05 18:00:41.005 31 aasubtask.cpp(913) [00000000046DA0B0] WARNING <Status xmlns="http://schemas.microsoft.com/2003/dls/StatusMessages.xsd" StatusCode="-2137454081" Reason="Error" CommandID="RAPreBackup" CommandInstanceID="639f59b3-9fd2-47c1-aa47-f72fe111ce72" GuidWorkItem="e807477f-0356-493d-9968-b9117f430cae" TETaskInstanceID="a64c66f2-c32d-49ac-891e-c92261b47a9a"><ErrorInfo xmlns="http://schemas.microsoft.com/2003/dls/GenericAgentStatus.xsd" ErrorCode="998" DetailedCode="-2137454081" DetailedSource="2"/><RAStatus><RAPreBackup xmlns="http://schemas.microsoft.com/2003/dls/ArchiveAgent/StatusMessages.xsd"><BackupTime>129228264410050000</BackupTime><DSStatus><ComponentName>System Protection</ComponentName><LogicalPath>Computer</LogicalPath><BackupStamp></BackupStamp><Metadata></Metadata></DSStatus></RAPreBackup></RAStatus></Status>

    120C 132C 07/05 18:00:41.005 03 runtime.cpp(1599) [00000000002A9140] FATAL Subtask failure, sending status response XML=[<?xml version="1.0"?>

    120C 132C 07/05 18:00:41.005 03 runtime.cpp(1599) [00000000002A9140] FATAL <Status xmlns="http://schemas.microsoft.com/2003/dls/StatusMessages.xsd" StatusCode="-2137454081" Reason="Error" CommandID="RAPreBackup" CommandInstanceID="639f59b3-9fd2-47c1-aa47-f72fe111ce72" GuidWorkItem="e807477f-0356-493d-9968-b9117f430cae" TETaskInstanceID="a64c66f2-c32d-49ac-891e-c92261b47a9a"><ErrorInfo xmlns="http://schemas.microsoft.com/2003/dls/GenericAgentStatus.xsd" ErrorCode="2023" DetailedCode="-2137454081" DetailedSource="2"><Parameter Name="AgentTargetServer" Value="VP-DC-02.highway.vp-tecmedia.com"/></ErrorInfo><RAStatus><RAPreBackup xmlns="http://schemas.microsoft.com/2003/dls/ArchiveAgent/StatusMessages.xsd"><BackupTime>129228264410050000</BackupTime><DSStatus><ComponentName>System Protection</ComponentName><LogicalPath>Computer</LogicalPath><BackupStamp></BackupStamp><Metadata></Metadata></DSStatus></RAPreBackup></RAStatus></Status>

    120C 132C 07/05 18:00:41.005 03 runtime.cpp(1599) [00000000002A9140] FATAL ]

    120C 132C 07/05 18:00:41.036 31 freesnapshotsubtask.cpp(559) [00000000046CA200] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CFreeSnapshotSubTask: StartBackupComplete [00000000046CA200]

    120C 132C 07/05 18:00:41.036 31 vssbaserequestor.cpp(1070) [0000000004653730] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CVssBaseRequestor::StartGatherWriterStatus [0000000004653730]

    120C 0940 07/05 18:00:41.302 31 freesnapshotsubtask.cpp(46) [00000000046CFAF0] A64C66F2-C32D-49AC-891E-C92261B47A9A NORMAL CFreeSnapshotSubTask: constructor [00000000046CFAF0]

    120C 0940 07/05 18:00:41.302 31 freesnapshotsubtask.cpp(123) [00000000046CFAF0] A64C66F2-C32D-49AC-891E-C92261B47A9A NORMAL CFreeSnapshotSubTask::TriggerDone [00000000046CFAF0]

    120C 0940 07/05 18:00:41.349 31 freesnapshotsubtask.cpp(559) [00000000046CFAF0] A64C66F2-C32D-49AC-891E-C92261B47A9A NORMAL CFreeSnapshotSubTask: StartBackupComplete [00000000046CFAF0]

    120C 0940 07/05 18:00:41.349 31 freesnapshotsubtask.cpp(671) [00000000046CFAF0] A64C66F2-C32D-49AC-891E-C92261B47A9A NORMAL CFreeSnapshotSubTask: ReleaseSnapshot [00000000046CFAF0]

    120C 132C 07/05 18:00:41.349 31 freesnapshotsubtask.cpp(181) [00000000046CFAF0] A64C66F2-C32D-49AC-891E-C92261B47A9A NORMAL CFreeSnapshotSubTask::GetFinalStatus [00000000046CFAF0]

    120C 132C 07/05 18:00:41.380 31 freesnapshotsubtask.cpp(63) [00000000046CFAF0] A64C66F2-C32D-49AC-891E-C92261B47A9A NORMAL CFreeSnapshotSubTask: destructor [00000000046CFAF0]

    120C 0940 07/05 18:00:42.036 31 vssbaserequestor.cpp(946) [0000000004653730] NORMAL QueryStatus returned 0x4230a, Releasing VssAsync [00000000001CFE80]

    120C 0940 07/05 18:00:42.036 31 freesnapshotsubtask.cpp(671) [00000000046CA200] NORMAL CFreeSnapshotSubTask: ReleaseSnapshot [00000000046CA200]

    120C 0940 07/05 18:00:42.036 31 vssbaserequestor.cpp(1103) [0000000004653730] NORMAL CVssBaseRequestor::CheckWriterStatus [0000000004653730]

    120C 0940 07/05 18:00:42.036 31 vsssnapshotrequestor.cpp(1141) [0000000004653730] NORMAL CVssSnapshotRequestor::ReleaseSnaphot [0000000004653730]

    120C 0940 07/05 18:00:42.036 31 vsssnapshotrequestor.cpp(1763) [0000000004653730] NORMAL CVssSnapshotRequestor::CleanUp [0000000004653730]

    120C 132C 07/05 18:00:42.052 03 workitem.cpp(272) [00000000000FFEF0] A64C66F2-C32D-49AC-891E-C92261B47A9A ACTIVITY WorkItem stopping

    120C 132C 07/05 18:00:42.208 31 freesnapshotsubtask.cpp(181) [00000000046CA200] NORMAL CFreeSnapshotSubTask::GetFinalStatus [00000000046CA200]

    120C 132C 07/05 18:00:42.239 31 freesnapshotsubtask.cpp(63) [00000000046CA200] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CFreeSnapshotSubTask: destructor [00000000046CA200]

    120C 132C 07/05 18:00:42.396 31 filterwrapper.cpp(398) [0000000004F4F810] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL DeleteBitmap: {C3EC0A03-FA56-42BC-8DEA-A63975CD4DFB}

    120C 132C 07/05 18:00:42.614 31 vsssnapshotrequestor.cpp(94) [0000000004653730] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CVssSnapshotRequestor::~CVssSnapshotRequestor [0000000004653730]

    120C 132C 07/05 18:00:42.614 31 vsssnapshotrequestor.cpp(1763) [0000000004653730] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CVssSnapshotRequestor::CleanUp [0000000004653730]

    120C 132C 07/05 18:00:42.614 31 vssbaserequestor.cpp(80) [0000000004653730] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL CVssBaseRequestor: destructor [0000000004653730]

    120C 132C 07/05 18:00:42.614 03 workitem.cpp(272) [0000000000362A80] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD ACTIVITY WorkItem stopping

    120C 0820 07/05 18:05:36.489 20 destination.cpp(1283) [00000000046C0150] NORMAL DM: Doing Connection TimeOut for Destination 00000000046C0150: connection 00000000046C2B30 m_dwLastCompletionTime: 23, m_bUseLongDMConnectionTimeOut: 0, Diff: 301

    120C 0820 07/05 18:05:36.489 20 cc_base.cpp(388) [00000000046C2B30] NORMAL DM: Going to timeout connection

    120C 0FAC 07/05 18:05:36.489 20 cc_extcalls.cpp(517) [00000000046C2B30] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD WARNING DM: TempErr: err=0x4d4 read=1 write=0

    120C 0FAC 07/05 18:05:36.489 20 cc_base.cpp(1226) [00000000046C2B30] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL DM: Aborting http state machine for reason 0

    120C 0820 07/05 18:05:36.489 20 destination.cpp(1283) [00000000046C0750] NORMAL DM: Doing Connection TimeOut for Destination 00000000046C0750: connection 00000000046C7F10 m_dwLastCompletionTime: 23, m_bUseLongDMConnectionTimeOut: 0, Diff: 301

    120C 0820 07/05 18:05:36.489 20 cc_base.cpp(388) [00000000046C7F10] NORMAL DM: Going to timeout connection

    120C 0820 07/05 18:05:36.489 20 destination.cpp(1283) [00000000046CA510] NORMAL DM: Doing Connection TimeOut for Destination 00000000046CA510: connection 00000000046CB800 m_dwLastCompletionTime: 23, m_bUseLongDMConnectionTimeOut: 0, Diff: 301

    120C 0820 07/05 18:05:36.489 20 cc_base.cpp(388) [00000000046CB800] NORMAL DM: Going to timeout connection

    120C 0C64 07/05 18:05:36.489 20 cc_extcalls.cpp(517) [00000000046C7F10] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD WARNING DM: TempErr: err=0x4d4 read=1 write=0

    120C 0C64 07/05 18:05:36.489 20 cc_base.cpp(1226) [00000000046C7F10] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL DM: Aborting http state machine for reason 0

    120C 0BC0 07/05 18:05:36.489 20 cc_extcalls.cpp(517) [00000000046CB800] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD WARNING DM: TempErr: err=0x4d4 read=1 write=0

    120C 0BC0 07/05 18:05:36.489 20 cc_base.cpp(1226) [00000000046CB800] 68AD85F0-DB2A-4E4C-9108-482DABF5DBCD NORMAL DM: Aborting http state machine for reason 0

    120C 0A74 07/05 18:05:42.614 03 runtime.cpp(1652) [00000000002A9140] NORMAL CDLSRuntime::ProcessIdleTimeout

    120C 0A74 07/05 18:05:42.614 03 runtime.cpp(646) [00000000002A9140] NORMAL CDLSRuntime::Uninitialize, bForce: 0

    120C 0A74 07/05 18:05:42.614 05 genericagent.cpp(264) [00000000002A9EA0] NORMAL Agent Can Shutdown if there is only default wokitem active[1]

    120C 0A74 07/05 18:05:42.614 29 dpmra.cpp(360) [00000000002A9EA0] NORMAL CDPMRA::Shutting down dpmra, force-shutdown :yes

    120C 0A74 07/05 18:05:42.614 03 workitem.cpp(391) NORMAL Timing out WI [00000000002E09F0], WI GUID = {B71B4544-7067-4A30-B5FB-BA320B10D82A}, ..last DM activity happened 980238843msec back, WI Idle Timeout = 390000msec

    120C 0A74 07/05 18:05:42.614 22 genericthreadpool.cpp(664) [00000000000FF2A0] NORMAL CGenericThreadPool: Waiting for threads to exit

    120C 0BC0 07/05 18:05:44.614 20 cc_base.cpp(1226) [000000000032F630] NORMAL DM: Aborting http state machine for reason 0

    120C 0FAC 07/05 18:05:44.614 20 cc_base.cpp(1226) [000000000032AFD0] NORMAL DM: Aborting http state machine for reason 0

    120C 0C64 07/05 18:05:44.614 20 cc_base.cpp(1226) [000000000032D340] NORMAL DM: Aborting http state machine for reason 0

    120C 0A74 07/05 18:05:44.614 20 cc_base.cpp(388) [00000000003269F0] NORMAL DM: Going to timeout connection

    120C 0A74 07/05 18:05:44.614 20 cc_base.cpp(388) [0000000000328CE0] NORMAL DM: Going to timeout connection

    120C 0C08 07/05 18:05:44.614 20 cc_base.cpp(1226) [0000000000328CE0] NORMAL DM: Aborting http state machine for reason 0

    120C 0A74 07/05 18:05:44.614 20 cc_base.cpp(388) [000000000032AFD0] NORMAL DM: Going to timeout connection

    120C 0A74 07/05 18:05:44.614 20 cc_base.cpp(388) [000000000032D340] NORMAL DM: Going to timeout connection

    120C 0A74 07/05 18:05:44.614 20 cc_base.cpp(388) [000000000032F630] NORMAL DM: Going to timeout connection

    120C 0A74 07/05 18:05:44.614 20 cc_base.cpp(388) [0000000000331920] NORMAL DM: Going to timeout connection

    120C 0A74 07/05 18:05:44.614 20 cc_base.cpp(388) [0000000000333C10] NORMAL DM: Going to timeout connection

    120C 0A74 07/05 18:05:44.614 20 cc_base.cpp(388) [0000000000335F00] NORMAL DM: Going to timeout connection

    120C 0A74 07/05 18:05:44.614 20 cc_base.cpp(388) [00000000003381F0] NORMAL DM: Going to timeout connection

    120C 0A74 07/05 18:05:44.614 20 cc_base.cpp(388) [00000000000F6FD0] NORMAL DM: Going to timeout connection

    120C 0FAC 07/05 18:05:44.614 20 cc_base.cpp(1226) [00000000003269F0] NORMAL DM: Aborting http state machine for reason 0

    120C 0BC0 07/05 18:05:44.614 20 cc_base.cpp(1226) [00000000003381F0] NORMAL DM: Aborting http state machine for reason 0

    120C 0C64 07/05 18:05:44.614 20 cc_base.cpp(1226) [00000000000F6FD0] NORMAL DM: Aborting http state machine for reason 0

    120C 0C08 07/05 18:05:44.614 20 cc_base.cpp(1226) [0000000000335F00] NORMAL DM: Aborting http state machine for reason 0

    120C 0BC0 07/05 18:05:44.614 20 cc_base.cpp(1226) [0000000000331920] NORMAL DM: Aborting http state machine for reason 0

    120C 0FAC 07/05 18:05:44.614 20 cc_base.cpp(1226) [0000000000333C10] NORMAL DM: Aborting http state machine for reason 0

    120C 0A74 07/05 18:05:44.614 22 genericthreadpool.cpp(664) [00000000002A9140] NORMAL CGenericThreadPool: Waiting for threads to exit

    120C 0D14 07/05 18:05:46.630 03 timer.cpp(513) [00000000000F9478] ACTIVITY Shutting down timer thread.

    120C 0A74 07/05 18:05:46.630 03 service.cpp(81) ACTIVITY CService::StopThisService

    120C 0A74 07/05 18:05:46.630 03 service.cpp(281) [000000000026F690] ACTIVITY CService::StopService()

    120C 0F34 07/05 18:05:46.630 03 service.cpp(298) [000000000026F690] ACTIVITY CService::AnnounceServiceStatus

    01F4 0C98 07/05 18:15:03.552 03 runtime.cpp(818) [00000000002B9140] ACTIVITY InitializeSecurity found 3 authorized entities

    01F4 0C98 07/05 18:15:03.552 03 runtime.cpp(836) [00000000002B9140] ACTIVITY InitializeSecurity added COM perm for highway.vp-tecmedia.com\VP-BACKUP-SVR

    01F4 0C98 07/05 18:15:03.552 03 runtime.cpp(854) [00000000002B9140] ACTIVITY InitializeSecurity added COM perm for DPMRADCOMTrustedMachines$VP-DC-02

    01F4 0C98 07/05 18:15:03.552 03 runtime.cpp(857) [00000000002B9140] ACTIVITY Detected as Domain Controller, InitializeSecurity adding to the members of group [DPMRADCOMTrustedMachines$VP-DC-02]

    01F4 0C98 07/05 18:15:03.552 03 runtime.cpp(891) [00000000002B9140] ACTIVITY InitializeSecurity added DM perm for DPMRADmTrustedMachines$VP-DC-02

    01F4 0C98 07/05 18:15:03.552 03 runtime.cpp(894) [00000000002B9140] ACTIVITY Detected as Domain Controller, InitializeSecurity adding to the members of group [DPMRADmTrustedMachines$VP-DC-02]

    01F4 0C98 07/05 18:15:03.552 03 runtime.cpp(94) NORMAL Found 1 writer account(s) under VSS access control.

    01F4 0C98 07/05 18:15:03.552 03 runtime.cpp(161) NORMAL Added writer account [0] 'NT Authority\NetworkService' to the DACL.

    01F4 0C98 07/05 18:15:03.568 22 genericthreadpool.cpp(804) [00000000002B9140] NORMAL Hr: = [0x80070002] CGenericThreadPool::m_dwMaximumNumberOfThreads[20]

    01F4 0C98 07/05 18:15:03.568 22 agentutils.cpp(2624) WARNING Failed: Hr: = [0x80070645] : U: lVal : hr

    01F4 130C 07/05 18:15:03.568 03 timer.cpp(490) ACTIVITY CTimerMgr::TimerThread

    01F4 130C 07/05 18:15:03.568 03 timer.cpp(503) [0000000000311DD0] ACTIVITY CTimerMgr::TimerThreadInternal

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(913) NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(908) NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(1036) NORMAL Created Socket with Family: 2, QoS Index: 5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(913) NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(908) NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(1036) NORMAL Created Socket with Family: 23, QoS Index: 4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(913) NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(908) NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(1036) NORMAL Created Socket with Family: 2, QoS Index: 5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(761) [00000000003369F0] NORMAL DM: - EndPoint:0000000000336850, Family: 2, Indx:5, Port:0

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(913) NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(908) NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(1036) NORMAL Created Socket with Family: 2, QoS Index: 5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(761) [0000000000338CE0] NORMAL DM: - EndPoint:0000000000336850, Family: 2, Indx:5, Port:0

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(913) NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(908) NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(1036) NORMAL Created Socket with Family: 2, QoS Index: 5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(761) [000000000033AFD0] NORMAL DM: - EndPoint:0000000000336850, Family: 2, Indx:5, Port:0

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(913) NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(908) NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(1036) NORMAL Created Socket with Family: 2, QoS Index: 5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(761) [000000000033D340] NORMAL DM: - EndPoint:0000000000336850, Family: 2, Indx:5, Port:0

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(913) NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(908) NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(1036) NORMAL Created Socket with Family: 2, QoS Index: 5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(761) [000000000033F630] NORMAL DM: - EndPoint:0000000000336850, Family: 2, Indx:5, Port:0

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(913) NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(908) NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(1036) NORMAL Created Socket with Family: 23, QoS Index: 4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(761) [0000000000341920] NORMAL DM: - EndPoint:0000000000336920, Family: 23, Indx:4, Port:0

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(913) NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(908) NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(1036) NORMAL Created Socket with Family: 23, QoS Index: 4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(761) [0000000000343C10] NORMAL DM: - EndPoint:0000000000336920, Family: 23, Indx:4, Port:0

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(913) NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(908) NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(1036) NORMAL Created Socket with Family: 23, QoS Index: 4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(761) [0000000000345F00] NORMAL DM: - EndPoint:0000000000336920, Family: 23, Indx:4, Port:0

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(913) NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(908) NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(1036) NORMAL Created Socket with Family: 23, QoS Index: 4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(761) [00000000003481F0] NORMAL DM: - EndPoint:0000000000336920, Family: 23, Indx:4, Port:0

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(913) NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(908) NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(1036) NORMAL Created Socket with Family: 23, QoS Index: 4

    01F4 0C98 07/05 18:15:03.568 20 cc_base.cpp(761) [0000000000106FD0] NORMAL DM: - EndPoint:0000000000336920, Family: 23, Indx:4, Port:0

    01F4 0C98 07/05 18:15:03.568 20 commengine.cpp(350) [0000000000313600] ACTIVITY Hr: = [0x80070002] ConnectionNoActivityTimeout: 300

    01F4 0C98 07/05 18:15:03.568 20 commengine.cpp(364) [0000000000313600] ACTIVITY Hr: = [0x80070002] m_dwConnectionNoActivityTimeoutForSlowReceiver: 3600

    01F4 0F2C 07/05 18:15:03.583 03 timer.cpp(490) ACTIVITY CTimerMgr::TimerThread

    01F4 0F2C 07/05 18:15:03.583 03 timer.cpp(503) [0000000000109478] ACTIVITY CTimerMgr::TimerThreadInternal

    01F4 0C98 07/05 18:15:03.583 29 dpmra.cpp(162) [00000000002B9EA0] NORMAL CDPMRA::Initialize [00000000002B9EA0]

    01F4 0C98 07/05 18:15:03.583 31 vaagent.cpp(226) NORMAL CVAAgent: Initialize globals

    01F4 0C98 07/05 18:15:03.599 29 mta.cpp(126) ACTIVITY CMTA::AddSchemasToSchemaCache => Initialize loaded schemas

    01F4 0C98 07/05 18:15:03.614 29 dpmra.cpp(184) [00000000002B9EA0] NORMAL CDPMRA::Initialize loaded schemas

    01F4 0C98 07/05 18:15:03.614 22 genericthreadpool.cpp(75) [000000000010F2A0] NORMAL CGenericThreadPool: constructor

    01F4 0C98 07/05 18:15:03.614 22 genericthreadpool.cpp(804) [000000000010F2A0] NORMAL Hr: = [0x80070002] CGenericThreadPool::m_dwMaximumNumberOfThreads[256]

    01F4 0C98 07/05 18:15:03.614 29 dpmra.cpp(271) [00000000002B9EA0] NORMAL CreateDefaultSubTask [00000000002B9EA0]

    01F4 0C98 07/05 18:15:03.614 29 dpmra.cpp(194) [00000000002B9EA0] NORMAL Temporary storage path reg key found

    01F4 0C98 07/05 18:15:03.614 29 dpmra.cpp(210) [00000000002B9EA0] NORMAL MTA Temp location Path = [c:\Program Files\Microsoft Data Protection Manager\DPM\temp\MTA\]

    01F4 0C98 07/05 18:15:03.614 29 mtamethrottlehelper.cpp(114) [000000000010FD60] NORMAL Hr: = [0x80070002] Number of encryption threads = [2]

    01F4 0C98 07/05 18:15:03.614 03 service.cpp(298) [000000000027FA30] ACTIVITY CService::AnnounceServiceStatus

    01F4 0C20 07/05 18:15:03.661 29 radefaultsubtask.cpp(337) [000000000010F7A0] 060095E0-5954-4E0A-A382-0393153996E7 ACTIVITY CRADefaultSubTask::CommandReceivedSpecific => Command SetActiveOwner Received

    01F4 0C20 07/05 18:15:03.927 03 workitem.cpp(86) [000000000010FF60] 060095E0-5954-4E0A-A382-0393153996E7 ACTIVITY Idle Timer created with timeout = 390000

    01F4 0C20 07/05 18:15:04.255 31 aaxmlprocessingutils.cpp(49) 060095E0-5954-4E0A-A382-0393153996E7 WARNING Failed: Hr: = [0x80070057] : F: lVal : E_INVALIDARG

    01F4 0C20 07/05 18:15:04.255 31 vadatasourcestate.cpp(729) 060095E0-5954-4E0A-A382-0393153996E7 WARNING Failed: Hr: = [0x8007007e] GetModuleHandle failed for Library [FileWriterHelperPlugin], will try LoadLibrary

    01F4 0C20 07/05 18:15:04.255 18 agentutils.hpp(68) 060095E0-5954-4E0A-A382-0393153996E7 WARNING Failed: Hr: = [0x80070002] : F: lVal : r.GetValue(pszKey, pT)

    01F4 0C20 07/05 18:15:04.255 18 fsutils.cpp(4426) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CClientReadThrottler::InitializeWaitForClientRead Failed to read sleep time from registry [hr = 0x80070002]. Setting default [50 ms].

    01F4 0C20 07/05 18:15:04.255 31 dllmain.cpp(36) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL FileWriterHelperPlugin: DLL_PROCESS_ATTACH

    01F4 0C20 07/05 18:15:04.302 31 basewriterhelperplugin.cpp(155) [00000000002F0B50] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL SetOperationType(2)

    01F4 0C20 07/05 18:15:04.302 31 vssbaserequestor.cpp(62) [0000000004663730] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CVssBaseRequestor: constructor [0000000004663730]

    01F4 0C20 07/05 18:15:04.302 31 vsssnapshotrequestor.cpp(76) [0000000004663730] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CVssSnapshotRequestor::CVssSnapshotRequestor [0000000004663730]

    01F4 0C20 07/05 18:15:04.302 31 vssbaserequestor.cpp(99) [0000000004663730] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CVssBaseRequestor::Initialize [0000000004663730]

    01F4 0C20 07/05 18:15:04.302 31 vsssnapshotrequestor.cpp(170) [0000000004663730] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CVssSnapshotRequestor::InitializeSnapshotCreation [0000000004663730]

    01F4 0C20 07/05 18:15:04.364 22 agentutils.cpp(2373) 060095E0-5954-4E0A-A382-0393153996E7 WARNING Failed: Hr: = [0x80070002] Could not open HKEY_LOCAL_MACHINE\Software\Microsoft\Microsoft Data Protection Manager\Agent\2.0

    01F4 0C20 07/05 18:15:04.364 18 usnjournalhelper.cpp(525) [0000000004D0F6D8] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnJournal::GetVolumeHandle Volume Path = \\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}

    01F4 0C20 07/05 18:15:04.364 18 usnjournalhelper.cpp(543) [0000000004D0F6D8] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnJournal::GetVolumeHandle Volume Path = \\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}, Volume Handle = afc

    01F4 0C20 07/05 18:15:04.364 18 usnjournalhelper.cpp(465) [0000000004D0F6D8] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnJournalHelper::GetNextUsnInternal(vol:afc)

    01F4 0C20 07/05 18:15:04.364 18 usnjournalhelper.cpp(487) [0000000004D0F6D8] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL UsnJournalID = 0x01CA95D98BBE767C

    01F4 0C20 07/05 18:15:04.364 18 usnjournalhelper.cpp(488) [0000000004D0F6D8] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL FirstUsn = 0x0000000004300000

    01F4 0C20 07/05 18:15:04.364 18 usnjournalhelper.cpp(489) [0000000004D0F6D8] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL NextUsn = 0x0000000020B158A0

    01F4 0C20 07/05 18:15:04.364 18 usnjournalhelper.cpp(490) [0000000004D0F6D8] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL LowestValidUsn = 0x0000000000000000

    01F4 0C20 07/05 18:15:04.364 18 usnjournalhelper.cpp(491) [0000000004D0F6D8] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL MaxUsn = 0x00000FFFFFFF0000

    01F4 0C20 07/05 18:15:04.364 18 usnjournalhelper.cpp(492) [0000000004D0F6D8] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL MaximumSize = 0x0000000100000000

    01F4 0C20 07/05 18:15:04.364 18 usnjournalhelper.cpp(493) [0000000004D0F6D8] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL AllocationDelta = 0x0000000040000000

    01F4 0C20 07/05 18:15:04.364 31 vsssnapshotrequestor.cpp(347) [0000000004663730] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CVssSnapshotRequestor::AddVolumeForSnapshot [0000000004663730]

    01F4 0C20 07/05 18:15:04.364 31 vsssnapshotrequestor.cpp(379) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL ssLocalVolumeGuid = [\\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}\], ssClusterVolGuid=[\\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}\]

    01F4 0C20 07/05 18:15:04.364 31 vsssnapshotrequestor.cpp(390) [0000000004663730] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CVssSnapshotRequestor: AddVolumeForSnapshot - Marked volume \\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}\ to be snapshot

    01F4 0C20 07/05 18:15:04.364 31 vsssnapshotrequestor.cpp(424) [0000000004663730] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CVssSnapshotRequestor::StartPrepareForBackup [0000000004663730]

    01F4 0C20 07/05 18:15:04.443 31 vssbaserequestor.cpp(1070) [0000000004663730] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CVssBaseRequestor::StartGatherWriterStatus [0000000004663730]

    01F4 0C20 07/05 18:15:05.443 31 vssbaserequestor.cpp(946) [0000000004663730] NORMAL QueryStatus returned 0x4230a, Releasing VssAsync [0000000000D7FE80]

    01F4 0C20 07/05 18:15:05.443 31 vssbaserequestor.cpp(1103) [0000000004663730] NORMAL CVssBaseRequestor::CheckWriterStatus [0000000004663730]

    01F4 0C20 07/05 18:15:05.443 31 filterwrapper.cpp(68) [0000000004D0F600] NORMAL CreateBitmap: {C373314F-FA7C-494C-809A-6EC6C03C1CBB}

    01F4 0C20 07/05 18:15:05.458 31 vsssnapshotrequestor.cpp(529) [0000000004663730] NORMAL CVssSnapshotRequestor::StartDoSnapshot [0000000004663730]

    01F4 0C20 07/05 18:15:16.458 31 vssbaserequestor.cpp(946) [0000000004663730] NORMAL QueryStatus returned 0x4230a, Releasing VssAsync [0000000000D7FE80]

    01F4 0C20 07/05 18:15:16.458 31 vssbaserequestor.cpp(1070) [0000000004663730] NORMAL CVssBaseRequestor::StartGatherWriterStatus [0000000004663730]

    01F4 0C20 07/05 18:15:17.458 31 vssbaserequestor.cpp(946) [0000000004663730] NORMAL QueryStatus returned 0x4230a, Releasing VssAsync [0000000000D7FE80]

    01F4 0C20 07/05 18:15:17.458 31 vsssnapshotrequestor.cpp(564) [0000000004663730] NORMAL CVssSnapshotRequestor::MapVolumesToSnapshotPaths [0000000004663730]

    01F4 0C20 07/05 18:15:17.458 31 vsssnapshotrequestor.cpp(585) [0000000004663730] NORMAL CVssSnapshotRequestor:: ProviderId:[{B5946137-7B9F-4925-AF80-51ABD60B20D5}], h/w provider:[0], volume:[\\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}\]

    01F4 0C20 07/05 18:15:17.677 31 vssbaserequestor.cpp(1103) [0000000004663730] NORMAL CVssBaseRequestor::CheckWriterStatus [0000000004663730]

    01F4 0DFC 07/05 18:15:18.021 22 incompatiblefiltersfinder.cpp(170) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL No Incompatible Service Groups. Hence no incompatible filters

    01F4 0DFC 07/05 18:15:18.021 31 basewriterhelperplugin.cpp(174) [00000000002F0B50] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL SetSystemFlags(0)

    01F4 0DFC 07/05 18:15:18.021 18 dsmsendersubtaskbase.cpp(47) [0000000004666050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CDsmSenderSubTaskBase: constructor [0000000004666050] openovl[00000000046661B8] msgovl[00000000046662A8] closeovl[0000000004666200]

    01F4 0DFC 07/05 18:15:18.021 31 vsssnapshotrequestor.cpp(1071) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL ssLocalVolumeGuid = [\\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}\], ssClusterVolGuid=[\\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}\]

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(381) [0000000004C1F050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnJournalHelper::GetFirstUsnOnSnapshot(vol:\\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}\, jrnl:0x01CA95D98BBE767C, nextUsnBeforeSnapshot:0x0000000020B158A0, snapshotTm:0x01CB1C6E0271C125)

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(525) [0000000004C1F050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnJournal::GetVolumeHandle Volume Path = \\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(543) [0000000004C1F050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnJournal::GetVolumeHandle Volume Path = \\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}, Volume Handle = 6bc

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(465) [0000000004C1F050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnJournalHelper::GetNextUsnInternal(vol:6bc)

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(487) [0000000004C1F050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL UsnJournalID = 0x01CA95D98BBE767C

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(488) [0000000004C1F050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL FirstUsn = 0x0000000004300000

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(489) [0000000004C1F050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL NextUsn = 0x0000000020B16AB0

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(490) [0000000004C1F050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL LowestValidUsn = 0x0000000000000000

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(491) [0000000004C1F050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL MaxUsn = 0x00000FFFFFFF0000

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(492) [0000000004C1F050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL MaximumSize = 0x0000000100000000

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(493) [0000000004C1F050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL AllocationDelta = 0x0000000040000000

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(442) [0000000004C1F050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnJournalHelper::GetFirstUsnOnSnapshot(deltaUsn: 0x0000000020B16628)

    01F4 0DFC 07/05 18:15:18.021 18 usnchangeiterator.cpp(106) [0000000004666360] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnChangeIterator::Init(vol:\\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}\, snap:\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy1088, jrnl:0x01CA95D98BBE767C, start bs:0x0000000020B11768, start:0x0000000020B127D8, last bs:0x0000000020B158A0, last:0x0000000020B16628, checkpoint:0x0000000020B113D0)

    01F4 0DFC 07/05 18:15:18.021 18 usnchangeiterator.cpp(217) [0000000004666360] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnChangeIterator::SetFileSystemFlags (0x1) called

    01F4 0DFC 07/05 18:15:18.021 18 iteratorutils.cpp(637) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CaseSensitivity NOT enabled on the machine

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(525) [0000000004666958] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnJournal::GetVolumeHandle Volume Path = \\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(543) [0000000004666958] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnJournal::GetVolumeHandle Volume Path = \\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}, Volume Handle = 6bc

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(465) [0000000004666958] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnJournalHelper::GetNextUsnInternal(vol:6bc)

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(487) [0000000004666958] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL UsnJournalID = 0x01CA95D98BBE767C

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(488) [0000000004666958] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL FirstUsn = 0x0000000004300000

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(489) [0000000004666958] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL NextUsn = 0x0000000020B16AB0

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(490) [0000000004666958] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL LowestValidUsn = 0x0000000000000000

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(491) [0000000004666958] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL MaxUsn = 0x00000FFFFFFF0000

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(492) [0000000004666958] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL MaximumSize = 0x0000000100000000

    01F4 0DFC 07/05 18:15:18.021 18 usnjournalhelper.cpp(493) [0000000004666958] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL AllocationDelta = 0x0000000040000000

    01F4 0DFC 07/05 18:15:18.021 18 fsutils.cpp(1729) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL GetVolumeHandle Volume Path = \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy1088

    01F4 0DFC 07/05 18:15:18.021 18 filehandlecache.cpp(47) [0000000000373FC0] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnChangeIterator::Init(snap:\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy1088\)

    01F4 0DFC 07/05 18:15:18.052 31 vsssnapshotrequestor.cpp(1071) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL ssLocalVolumeGuid = [\\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}\], ssClusterVolGuid=[\\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}\]

    01F4 0DFC 07/05 18:15:18.052 31 filewriterhelperplugin.cpp(455) [00000000002F0B50] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CFileWriterBackupHelper::GetIterator Adding read path \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy1088\ [00000000002F0B50]

    01F4 0DFC 07/05 18:15:18.052 31 filewriterhelperplugin.cpp(460) [00000000002F0B50] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CFileWriterBackupHelper::GetIterator Adding read path \\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy1088\ [00000000002F0B50]

    01F4 0DFC 07/05 18:15:18.052 18 usnchangeiterator.cpp(264) [0000000004666360] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CUsnChangeIterator:AddIncludeFiles(filepath:\\?\Volume{6b28aa2d-01cc-11df-b6a3-806e6f6e6963}\, filespec:*, snapshotpath:\\?\GLOBALROOT\Device\HarddiskVolumeShadowCopy1088\, Recursive:true, ReaderOptions:0x0) called

    01F4 0DFC 07/05 18:15:18.052 18 dsmsendersubtaskbase.cpp(625) [0000000004666050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL Page size to be used: 4096

    01F4 0DFC 07/05 18:15:18.052 18 dsmsendersubtaskbase.cpp(644) [0000000004666050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL Failed to read MaxBufferSize from registry. Using default size: 262144

    01F4 0DFC 07/05 18:15:18.052 18 dsmreceiversubtaskbase.cpp(45) [00000000046CEA60] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CDsmReceiverSubTaskBase: constructor [00000000046CEA60] openovl[00000000046CEBC8] msgovl[00000000046CECB0] closeovl[00000000046CEC10]

    01F4 0DFC 07/05 18:15:18.052 18 dsmsendersubtaskbase.cpp(47) [00000000046CEF90] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CDsmSenderSubTaskBase: constructor [00000000046CEF90] openovl[00000000046CF0F8] msgovl[00000000046CF1E8] closeovl[00000000046CF140]

    01F4 0DFC 07/05 18:15:18.052 18 dsmsendersubtaskbase.cpp(625) [00000000046CEF90] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL Page size to be used: 4096

    01F4 0DFC 07/05 18:15:18.052 18 dsmsendersubtaskbase.cpp(644) [00000000046CEF90] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL Failed to read MaxBufferSize from registry. Using default size: 262144

    01F4 0DFC 07/05 18:15:18.052 18 fixupreaderiterator.cpp(173) [00000000046CF2B0] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CFixupReaderIterator::SetFileSystemFlags (0x0) called

    01F4 0DFC 07/05 18:15:18.099 31 datasetfixupsubtaskbase.cpp(227) [0000000000375E50] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CDatasetFixupSubTaskBase::BeginDataMove [0000000000375E50]

    01F4 0DFC 07/05 18:15:18.099 20 agentutils.hpp(68) 060095E0-5954-4E0A-A382-0393153996E7 WARNING Failed: Hr: = [0x80070002] : F: lVal : r.GetValue(pszKey, pT)

    01F4 0DFC 07/05 18:15:18.099 20 destination.cpp(1442) [00000000046CFE10] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL DM: GetPreferredProtocolFamilyToConnect for VP-BACKUP-SVR : 0, PingBeforeConnect : 0

    01F4 0DFC 07/05 18:15:18.099 20 cc_base.cpp(913) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0DFC 07/05 18:15:18.099 20 cc_base.cpp(908) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0DFC 07/05 18:15:18.099 20 cc_base.cpp(1036) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL Created Socket with Family: 2, QoS Index: 5

    01F4 0DFC 07/05 18:15:18.099 20 cc_base.cpp(761) [00000000046D27F0] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL DM: - EndPoint:0000000000000000, Family: 2, Indx:5, Port:58890

    01F4 03D8 07/05 18:15:18.099 20 cc_extcalls.cpp(272) [00000000046D27F0] NORMAL Doing DNS Lookup for host:vp-backup-svr.highway.vp-tecmedia.com, Port: 5718, Address Family: 2

    01F4 03D8 07/05 18:15:18.099 20 cc_extcalls.cpp(292) [00000000046D27F0] NORMAL DM: - Name lookup without DNS failed

    01F4 03D8 07/05 18:15:18.099 20 cc_extcalls.cpp(307) [00000000046D27F0] NORMAL DM: - DNS Lookup SUCCESS

    01F4 03D8 07/05 18:15:18.099 20 cc_extcalls.cpp(316) [00000000046D27F0] NORMAL BackupLan Count:0

    01F4 0DFC 07/05 18:15:18.099 20 agentutils.hpp(68) 060095E0-5954-4E0A-A382-0393153996E7 WARNING Failed: Hr: = [0x80070002] : F: lVal : r.GetValue(pszKey, pT)

    01F4 0DFC 07/05 18:15:18.099 20 destination.cpp(1442) [00000000046D0410] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL DM: GetPreferredProtocolFamilyToConnect for VP-BACKUP-SVR : 0, PingBeforeConnect : 0

    01F4 0DFC 07/05 18:15:18.099 20 cc_base.cpp(913) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0DFC 07/05 18:15:18.099 20 cc_base.cpp(908) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0DFC 07/05 18:15:18.099 20 cc_base.cpp(1036) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL Created Socket with Family: 2, QoS Index: 5

    01F4 0DFC 07/05 18:15:18.099 20 cc_base.cpp(761) [00000000046D7BD0] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL DM: - EndPoint:0000000000000000, Family: 2, Indx:5, Port:58891

    01F4 0DFC 07/05 18:15:18.161 20 protocolhandshakehelper.cpp(320) [00000000046642F0] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL Protocol selected for host [HOST/vp-backup-svr.highway.vp-tecmedia.com@highway.vp-tecmedia.com] is [KERBEROS]

    01F4 03D8 07/05 18:15:18.161 20 protocolhandshakehelper.cpp(320) [0000000004664350] NORMAL Protocol selected for host [HOST/vp-backup-svr.highway.vp-tecmedia.com@highway.vp-tecmedia.com] is [KERBEROS]

    01F4 0DFC 07/05 18:15:18.161 20 agentutils.hpp(68) 060095E0-5954-4E0A-A382-0393153996E7 WARNING Failed: Hr: = [0x80070002] : F: lVal : r.GetValue(pszKey, pT)

    01F4 0DFC 07/05 18:15:18.161 20 destination.cpp(1442) [00000000046DA1D0] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL DM: GetPreferredProtocolFamilyToConnect for VP-BACKUP-SVR : 0, PingBeforeConnect : 0

    01F4 0944 07/05 18:15:18.161 20 cc_session.cpp(161) [00000000046D7BD0] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL Hr: = [0x80070002] DM: SetTcpSendWindow failed for connection 00000000046D7BD0, Ignoring the failure

    01F4 0DFC 07/05 18:15:18.161 20 cc_base.cpp(913) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL DM: - Spotted QoS IPv6, Index:4

    01F4 0DFC 07/05 18:15:18.161 20 cc_base.cpp(908) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL DM: - Spotted QoS IPv4, Index:5

    01F4 0DFC 07/05 18:15:18.161 20 cc_base.cpp(1036) 060095E0-5954-4E0A-A382-0393153996E7 NORMAL Created Socket with Family: 2, QoS Index: 5

    01F4 0DFC 07/05 18:15:18.161 20 cc_base.cpp(761) [00000000046DB4C0] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL DM: - EndPoint:0000000000000000, Family: 2, Indx:5, Port:58893

    01F4 0944 07/05 18:15:18.161 20 cc_session.cpp(161) [00000000046D27F0] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL Hr: = [0x80070002] DM: SetTcpSendWindow failed for connection 00000000046D27F0, Ignoring the failure

    01F4 0DFC 07/05 18:15:18.161 20 protocolhandshakehelper.cpp(320) [00000000046643B0] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL Protocol selected for host [HOST/vp-backup-svr.highway.vp-tecmedia.com@highway.vp-tecmedia.com] is [KERBEROS]

    01F4 0DFC 07/05 18:15:18.161 18 dsmreceiversubtaskbase.cpp(243) [00000000046CEA60] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CDsmReceiverSubTaskBase received session opened completion in WAIT state

    01F4 0944 07/05 18:15:18.161 20 cc_session.cpp(161) [00000000046DB4C0] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL Hr: = [0x80070002] DM: SetTcpSendWindow failed for connection 00000000046DB4C0, Ignoring the failure

    01F4 0DFC 07/05 18:15:18.161 18 dsmsendersubtaskbase.cpp(141) [0000000004666050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CDsmSenderSubTaskBase received session opened completion in WAIT state

    01F4 0DFC 07/05 18:15:18.161 18 usnjournal.cpp(94) [0000000004666428] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL DoFirstPass firstUsn: 0x0061006D00200022

    01F4 0C20 07/05 18:15:18.161 18 dsmsendersubtaskbase.cpp(141) [00000000046CEF90] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CDsmSenderSubTaskBase received session opened completion in WAIT state

    01F4 0524 07/05 18:15:19.661 20 session.cpp(1693) [00000000046CFB00] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL Hr: = [0x00000000] DM: Will attempt to post DM_SESSION_CLOSED, pSes=00000000046CFB00 rcv=0000000000000000 snd=0000000000000000 sesop=0000000004666200 seserr=0000000000000000

    01F4 0DFC 07/05 18:15:19.661 18 dsmsendersubtaskbase.cpp(325) [0000000004666050] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CDsmSubTaskBase received session closed completion in CLOSE state [0000000004666050]

    01F4 0DFC 07/05 18:15:19.661 31 readdatasetdeltasubtask.cpp(498) [0000000000375E50] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CReadDatasetDeltaSubTask::SubTaskDone [0000000000375E50]

    01F4 0DFC 07/05 18:15:19.661 31 datasetfixupsubtaskbase.cpp(383) [0000000000375E50] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CDatasetFixupSubTaskBase::SubTaskDone [0000000000375E50] [0000000004666050]

    01F4 0DFC 07/05 18:15:19.661 31 datasetfixupsubtaskbase.cpp(393) [0000000000375E50] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CDatasetFixupSubTaskBase::SubTaskDone - LWV

    01F4 124C 07/05 18:15:20.974 31 readdatasetdeltasubtask.cpp(498) [0000000000375E50] 060095E0-5954-4E0A-A382-0393153996E7 NORMAL CReadDatasetDeltaSubTask::SubTaskDone

     

    Thursday, July 8, 2010 11:39 AM
  • Hi,

     

    some news. The Problem above only happens when i backup to the attached ISCSI Storage. When i backup to a local Volume (custom Volume) it works.

     

    ???

    Felix

     

    Friday, July 9, 2010 2:02 PM
  • Is the iSCSI attached storage on a dedicated NIC, or using the same NIC as agent communications and production ?  If on a dedicated NIC already, you may want to work with the iSCSI san vendor to see if there is something that can be done to fix the issue.

     

     

     


    Regards, Mike J [MSFT] This posting is provided "AS IS" with no warranties, and confers no rights.
    Friday, July 9, 2010 3:23 PM
    Moderator
  • No it is not on an dedicated Nic . I will try ist with a dedicated.

     

    Thanks Felix

     

    Monday, July 12, 2010 8:12 AM
  • Ok. Now i have a dedicated connection between the dpm server and the iscsi storage. Still the same Problem. 0x809909FB

     

    Monday, July 12, 2010 10:38 AM
  • Check if the disk in storage pool has 4k sector. If yes change the sector size to 512 and see if BMR works.


    Thanks, Anjani Kumar. This posting is provided "AS IS" with no warranties, and confers no rights.
    Tuesday, August 10, 2010 5:26 PM
  • Ok thank you. how can i do that? It´s a dynamic disk which was formated by dpm? It is not a custom volume.

     

    Thanks

     

    Felix

     

    Tuesday, August 24, 2010 9:01 AM
  • MSInfo32 will identify the 4k native drive in Components/Storage/Disks with a Bytes/Sector = 4096

     

    Use MSinfo32 to check to see if the any of the disks have a Bytes/Sector greater than 512


    Regards, Mike J [MSFT] This posting is provided "AS IS" with no warranties, and confers no rights.
    Tuesday, August 24, 2010 8:40 PM
    Moderator
  • Msinfo say 4096 bytes pro sector. i will try to change ist but i have to format my whole iscsi drive.
    Thursday, August 26, 2010 2:07 PM
  • The storage was formatted by DPM. How can i force DPM to use 512 sectors?
    Thursday, August 26, 2010 2:32 PM
  • The disk is a 4K sector drive, Windows and DPM don't control the sector size.  You may want to check with the manufacturer and see if you can enable emulation mode for 512 bytes / sector.  If it can be done, you will need to delete all volumes from the disk, and start over.

     

    Alternative would be to add a new 512 bytes/ sector drive and use custom volumes to host the BMR backup replica and recovery point volumes.


    Regards, Mike J [MSFT] This posting is provided "AS IS" with no warranties, and confers no rights.
    Thursday, August 26, 2010 6:07 PM
    Moderator
  • It works! Thank you all for your help!. I changed the sector size on the Iscsci Storage to 512 and it runs.

    Problem solved

    Thank you.

    Friday, August 27, 2010 8:21 AM