none
DPM Client wont sync RRS feed

  • Question

  • I have DPM protection agent v5.0.361.0 installed on Windows 7 workstation, and have protection policy configured on DPM 2016 server with synchronization set for every 24 hours and recovery point created at 12PM every day:

    But for some reason my workstation will never sync automatically:

    On the workstation I can click "Sync now" and it will sync, but never by itself automatically every 24 hours like it's supposed to. 

    Because it never syncs, recovery points are never created on the server:

    There is no firewall between the server and client, what am I missing? 


    Shaun

    Wednesday, August 22, 2018 5:31 PM

All replies

  • Hello!

    Could you give us an extract of your DPM log from your Windows 7 workstation?

    You can find the log here:
    C:\Program Files\Microsoft Data Protection Manager\DPM\Temp\DPMRACurr.errlog

    Best regards,
    Leon


    Blog: https://thesystemcenterblog.com LinkedIn:

    Wednesday, August 22, 2018 6:47 PM
  • There's no activity in the DPMRACurr.errlog file since my last manual sync (by clicking "Sync now" in DPM client). That log ends with this info:

    2F08 11F8 08/20 19:22:54.011 20 session.cpp(1560) [00000000036954B0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL Hr: = [0x00000000] DM: Will attempt to post DM_SESSION_CLOSED, pSes=00000000036954B0 rcv=0000000000000000 snd=0000000000000000 sesop=0000000003612998 seserr=0000000000000000
    2F08 1694 08/20 19:22:54.011 18 dsmsendersubtaskbase.cpp(325) [00000000036127B0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CDsmSubTaskBase received session closed completion in CLOSE state [00000000036127B0]
    2F08 1694 08/20 19:22:54.011 03 readdatasetdeltasubtask.cpp(547) [000000000360D7C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CReadDatasetDeltaSubTask::SubTaskDone [000000000360D7C0]
    2F08 1694 08/20 19:22:54.011 03 datasetfixupsubtaskbase.cpp(379) [000000000360D7C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CDatasetFixupSubTaskBase::SubTaskDone [000000000360D7C0] [00000000036127B0]
    2F08 1694 08/20 19:22:54.011 03 datasetfixupsubtaskbase.cpp(389) [000000000360D7C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CDatasetFixupSubTaskBase::SubTaskDone - LWV
    2F08 3300 08/20 19:22:57.778 03 service.cpp(147) [000000000024FA30] ACTIVITY CService::ServiceHandlerExInternal
    2F08 3300 08/20 19:23:57.891 03 service.cpp(147) [000000000024FA30] ACTIVITY CService::ServiceHandlerExInternal
    2F08 3300 08/20 19:24:58.011 03 service.cpp(147) [000000000024FA30] ACTIVITY CService::ServiceHandlerExInternal
    2F08 29C4 08/20 19:25:20.145 03 readdatasetdeltasubtask.cpp(547) [000000000360D7C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CReadDatasetDeltaSubTask::SubTaskDone [000000000360D7C0]
    2F08 29C4 08/20 19:25:20.145 03 datasetfixupsubtaskbase.cpp(379) [000000000360D7C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CDatasetFixupSubTaskBase::SubTaskDone [000000000360D7C0] [00000000035D2590]
    2F08 29C4 08/20 19:25:20.145 03 datasetfixupsubtaskbase.cpp(397) [000000000360D7C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CDatasetFixupSubTaskBase::SubTaskDone - HWV
    2F08 2B54 08/20 19:25:20.145 18 dsmreceiversubtaskbase.cpp(318) [00000000035D2590] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CDsmReceiverSubTaskBase received completion for session closed in CLEANUP state
    2F08 3300 08/20 19:25:58.102 03 service.cpp(147) [000000000024FA30] ACTIVITY CService::ServiceHandlerExInternal
    2F08 2DB4 08/20 19:26:04.807 18 fixupsendersubtask.cpp(368) [0000000003606410] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CFixupSenderSubTask::GetBuffer End of data
    2F08 3248 08/20 19:26:04.807 20 session.cpp(1560) [000000000369BAE0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL Hr: = [0x00000000] DM: Will attempt to post DM_SESSION_CLOSED, pSes=000000000369BAE0 rcv=0000000000000000 snd=0000000000000000 sesop=00000000036065F8 seserr=0000000000000000
    2F08 2B54 08/20 19:26:04.807 18 dsmsendersubtaskbase.cpp(325) [0000000003606410] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CDsmSubTaskBase received session closed completion in CLOSE state [0000000003606410]
    2F08 2B54 08/20 19:26:04.807 03 readdatasetdeltasubtask.cpp(547) [000000000360D7C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CReadDatasetDeltaSubTask::SubTaskDone [000000000360D7C0]
    2F08 2B54 08/20 19:26:04.807 03 datasetfixupsubtaskbase.cpp(379) [000000000360D7C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CDatasetFixupSubTaskBase::SubTaskDone [000000000360D7C0] [0000000003606410]
    2F08 2B54 08/20 19:26:04.807 03 datasetfixupsubtaskbase.cpp(405) [000000000360D7C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CDatasetFixupSubTaskBase::SubTaskDone - Fixup
    2F08 2B54 08/20 19:26:04.807 03 readdatasetdeltasubtask.cpp(590) [000000000360D7C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CReadDatasetDeltaSubTask::CleanUp [000000000360D7C0]
    2F08 2B54 08/20 19:26:04.807 03 datasetfixupsubtaskbase.cpp(357) [000000000360D7C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CDatasetFixupSubTaskBase::CleanUp [000000000360D7C0]
    2F08 2B54 08/20 19:26:04.807 18 dsmsubtaskbase.cpp(85) [00000000036127B0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CDsmSubTaskBase: destructor [00000000036127B0]
    2F08 2B54 08/20 19:26:04.807 18 dsmsubtaskbase.cpp(85) [00000000035D2590] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CDsmSubTaskBase: destructor [00000000035D2590]
    2F08 2B54 08/20 19:26:04.807 18 perftimer.cpp(288) [00000000035D0E10] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CCInstr: Lifetime for Subtask: FixupSenderSubTask =         202 sec, Trustable: TRUE         Time for Proc: 201 sec, trustable: TRUE         Time for Proc_Specific: 2 sec, trustable: TRUE         Time for IO: 1 sec, Trustable: TRUE         Time for IO_Specific: 0 sec, Trustable: TRUE         Time for Network: 0 sec, Trustable: TRUE
    2F08 2B54 08/20 19:26:04.808 18 dsmsubtaskbase.cpp(85) [0000000003606410] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CDsmSubTaskBase: destructor [0000000003606410]
    2F08 2B54 08/20 19:26:13.050 03 cfreesnapshotsubtask.cpp(119) [000000000369E1E0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CFreeSnapshotSubTask::TriggerDone [000000000369E1E0]
    2F08 2B54 08/20 19:26:13.064 03 cfreesnapshotsubtask.cpp(560) [000000000369E1E0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CFreeSnapshotSubTask: StartBackupComplete [000000000369E1E0]
    2F08 2B54 08/20 19:26:13.064 31 vssbaserequestor.cpp(1067) [0000000002F0A0C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CVssBaseRequestor::StartGatherWriterStatus [0000000002F0A0C0]
    2F08 2B54 08/20 19:26:14.064 31 vssbaserequestor.cpp(943) [0000000002F0A0C0] NORMAL QueryStatus returned 0x4230a, Releasing VssAsync [000000000064FE30]
    2F08 2B54 08/20 19:26:14.064 03 cfreesnapshotsubtask.cpp(673) [000000000369E1E0] NORMAL CFreeSnapshotSubTask: ReleaseSnapshot [000000000369E1E0]
    2F08 2B54 08/20 19:26:14.064 31 vssbaserequestor.cpp(1100) [0000000002F0A0C0] NORMAL CVssBaseRequestor::CheckWriterStatus [0000000002F0A0C0]
    2F08 2B54 08/20 19:26:14.064 31 vsssnapshotrequestor.cpp(1506) [0000000002F0A0C0] NORMAL CVssSnapshotRequestor::ReleaseSnaphot [0000000002F0A0C0]
    2F08 2B54 08/20 19:26:14.064 31 vsssnapshotrequestor.cpp(2182) [0000000002F0A0C0] NORMAL CVssSnapshotRequestor::CleanUp [0000000002F0A0C0]
    2F08 2B54 08/20 19:26:14.064 31 vsssnapshotrequestor.cpp(1768) [0000000002F0A0C0] NORMAL CVssSnapshotRequestor::ReleaseVolumesForSnapshot [0000000002F0A0C0]
    2F08 2DB4 08/20 19:26:14.139 03 cfreesnapshotsubtask.cpp(177) [000000000369E1E0] NORMAL CFreeSnapshotSubTask::GetFinalStatus [000000000369E1E0]
    2F08 2DB4 08/20 19:26:14.260 31 vsssnapshotrequestor.cpp(122) [0000000002F0A0C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CVssSnapshotRequestor::~CVssSnapshotRequestor [0000000002F0A0C0]
    2F08 2DB4 08/20 19:26:14.260 31 vsssnapshotrequestor.cpp(2182) [0000000002F0A0C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CVssSnapshotRequestor::CleanUp [0000000002F0A0C0]
    2F08 2DB4 08/20 19:26:14.260 31 vsssnapshotrequestor.cpp(1768) [0000000002F0A0C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CVssSnapshotRequestor::ReleaseVolumesForSnapshot [0000000002F0A0C0]
    2F08 2DB4 08/20 19:26:14.260 31 vssbaserequestor.cpp(69) [0000000002F0A0C0] 32F3268F-8918-4176-B605-6D1817E6B8BF NORMAL CVssBaseRequestor: destructor [0000000002F0A0C0]
    2F08 2DB4 08/20 19:26:14.260 03 cworkitem.cpp(23) [0000000001648BA0] 32F3268F-8918-4176-B605-6D1817E6B8BF ACTIVITY WorkItem stopping
    2F08 3300 08/20 19:26:58.213 03 service.cpp(147) [000000000024FA30] ACTIVITY CService::ServiceHandlerExInternal
    2F08 3248 08/20 19:27:57.857 20 cc_extcalls.cpp(517) [00000000036AB150] 32F3268F-8918-4176-B605-6D1817E6B8BF WARNING DM: TempErr: err=0x40 read=1 write=0
    2F08 3300 08/20 19:27:58.315 03 service.cpp(147) [000000000024FA30] ACTIVITY CService::ServiceHandlerExInternal
    2F08 3300 08/20 19:28:58.401 03 service.cpp(147) [000000000024FA30] ACTIVITY CService::ServiceHandlerExInternal
    2F08 3248 08/20 19:29:25.769 20 cc_extcalls.cpp(517) [0000000003712240] 32F3268F-8918-4176-B605-6D1817E6B8BF WARNING DM: TempErr: err=0x40 read=1 write=0
    2F08 3300 08/20 19:29:58.479 03 service.cpp(147) [000000000024FA30] ACTIVITY CService::ServiceHandlerExInternal
    2F08 3300 08/20 19:30:58.629 03 service.cpp(147) [000000000024FA30] ACTIVITY CService::ServiceHandlerExInternal
    2F08 18DC 08/20 19:31:05.241 20 destination.cpp(1283) [0000000003754740] NORMAL DM: Doing Connection TimeOut for  Destination 0000000003754740: connection 0000000003759770 m_dwLastCompletionTime: 206, m_bUseLongDMConnectionTimeOut: 0, Diff: 301
    2F08 3248 08/20 19:31:05.241 20 cc_extcalls.cpp(517) [0000000003759770] 32F3268F-8918-4176-B605-6D1817E6B8BF WARNING DM: TempErr: err=0x4d4 read=1 write=0
    2F08 2ED8 08/20 19:31:14.274 03 runtime.cpp(1426) [0000000000419BE0] NORMAL CDLSRuntime::ProcessIdleTimeout
    2F08 2ED8 08/20 19:31:14.274 03 runtime.cpp(602) [0000000000419BE0] NORMAL CDLSRuntime::Uninitialize, bForce: 0
    2F08 2ED8 08/20 19:31:14.274 05 genericagent.cpp(273) [000000000041AC30] NORMAL Agent Can Shutdown if there is only default wokitem active[1]
    2F08 2ED8 08/20 19:31:14.274 29 dpmra.cpp(356) [000000000041AC30] NORMAL CDPMRA::Shutting down dpmra, force-shutdown :yes
    2F08 2ED8 08/20 19:31:14.274 03 cworkitem.cpp(328) [0000000001647880] NORMAL Timing out WI [0000000001647880], WI GUID = {B71B4544-7067-4A30-B5FB-BA320B10D82A}, ..last DM activity happened 116424123msec back, WI Idle Timeout = 390000msec
    2F08 2ED8 08/20 19:31:14.274 22 genericthreadpool.cpp(684) [00000000016484A0] NORMAL CGenericThreadPool: Waiting for threads to exit
    2F08 2ED8 08/20 19:31:16.274 22 genericthreadpool.cpp(684) [0000000000419BE0] NORMAL CGenericThreadPool: Waiting for threads to exit
    2F08 23EC 08/20 19:31:18.299 03 timer.cpp(513) [000000000163D678] ACTIVITY Shutting down timer thread.
    2F08 2ED8 08/20 19:31:18.299 03 service.cpp(81) ACTIVITY CService::StopThisService
    2F08 2ED8 08/20 19:31:18.299 03 service.cpp(281) [000000000024FA30] ACTIVITY CService::StopService()

    There is a DPMRACurr.errlog file that is mostly this:

    2C70 2568 08/21 23:57:50.508 03 service.cpp(147) [000000000018FAE0] ACTIVITY CService::ServiceHandlerExInternal

    With some occasional other activity as follows (ive taken out host name and server name):

    2B40 19AC 08/21 20:55:03.385 33 dlsclientprotection.cpp(1919) NORMAL CClientProtectionTimer:: Client Service idle timeout timer fired -  TimerOrWaitFired:True, Timer State: 0
    2B40 19AC 08/21 20:55:03.385 03 service.cpp(81) ACTIVITY CService::StopThisService
    2B40 19AC 08/21 20:55:03.385 03 service.cpp(281) [000000000015F840] ACTIVITY CService::StopService()
    2D60 1F04 08/21 22:25:05.388 33 dpmclientservice.cpp(98) [00000000000BFE00] NORMAL Enabled Low Fragmentation heap on CRT heap
    2D60 1F04 08/21 22:25:05.388 33 dpmclientservice.cpp(109) [00000000000BFE00] NORMAL Enabled Low Fragmentation heap on process heap
    2D60 1F04 08/21 22:25:05.388 03 service.cpp(334) [00000000000BFE00] ACTIVITY CService::RunAsService
    2D60 277C 08/21 22:25:05.388 03 service.cpp(92) [00000000000BFE00] ACTIVITY CService::ServiceMainInternal
    2D60 277C 08/21 22:25:05.388 03 service.cpp(298) [00000000000BFE00] ACTIVITY CService::AnnounceServiceStatus
    2D60 277C 08/21 22:25:05.404 33 dlsclientprotectionfactory.cpp(247) [00000000003124C0] ACTIVITY Principal name HOST/hostname@domainname
    2D60 277C 08/21 22:25:05.451 03 service.cpp(298) [00000000000BFE00] ACTIVITY CService::AnnounceServiceStatus
    2D60 0E28 08/21 22:25:05.607 33 dlsclientprotection.cpp(778) [0000000000329460] NORMAL Connecting to DPM Server: (servername)
    2D60 1F04 08/21 22:25:41.291 03 service.cpp(147) [00000000000BFE00] ACTIVITY CService::ServiceHandlerExInternal
    2D60 1F04 08/21 22:26:41.380 03 service.cpp(147) [00000000000BFE00] ACTIVITY CService::ServiceHandlerExInternal
    2D60 1F04 08/21 22:27:41.471 03 service.cpp(147) [00000000000BFE00] ACTIVITY CService::ServiceHandlerExInternal
    2D60 1F04 08/21 22:28:41.610 03 service.cpp(147) [00000000000BFE00] ACTIVITY CService::ServiceHandlerExInternal
    2D60 1F04 08/21 22:29:41.717 03 service.cpp(147) [00000000000BFE00] ACTIVITY CService::ServiceHandlerExInternal
    2D60 1F04 08/21 22:30:41.824 03 service.cpp(147) [00000000000BFE00] ACTIVITY CService::ServiceHandlerExInternal
    2D60 0F44 08/21 22:31:05.817 33 dlsclientprotection.cpp(1919) NORMAL CClientProtectionTimer:: Client Service idle timeout timer fired -  TimerOrWaitFired:True, Timer State: 0
    2D60 0F44 08/21 22:31:05.817 03 service.cpp(81) ACTIVITY CService::StopThisService
    2D60 0F44 08/21 22:31:05.817 03 service.cpp(281) [00000000000BFE00] ACTIVITY CService::StopService()
    2C70 2568 08/21 23:26:16.501 33 dpmclientservice.cpp(98) [000000000018FAE0] NORMAL Enabled Low Fragmentation heap on CRT heap
    2C70 2568 08/21 23:26:16.501 33 dpmclientservice.cpp(109) [000000000018FAE0] NORMAL Enabled Low Fragmentation heap on process heap
    2C70 2568 08/21 23:26:16.501 03 service.cpp(334) [000000000018FAE0] ACTIVITY CService::RunAsService
    2C70 112C 08/21 23:26:16.501 03 service.cpp(92) [000000000018FAE0] ACTIVITY CService::ServiceMainInternal
    2C70 112C 08/21 23:26:16.501 03 service.cpp(298) [000000000018FAE0] ACTIVITY CService::AnnounceServiceStatus
    2C70 112C 08/21 23:26:16.517 33 dlsclientprotectionfactory.cpp(247) [00000000004424C0] ACTIVITY Principal name HOST/hostname@domainname
    2C70 112C 08/21 23:26:16.517 03 service.cpp(298) [000000000018FAE0] ACTIVITY CService::AnnounceServiceStatus
    2C70 2690 08/21 23:26:16.626 33 dlsclientprotection.cpp(778) [0000000000459460] NORMAL Connecting to DPM Server: (servername)


    Shaun

    Wednesday, August 22, 2018 7:42 PM
  • Thanks, not seeing anything out of the ordinary.

    Does this happen to all your clients in DPM? Or is it just this Windows 7 workstation?

    You could try, removing it from the protection group and then re-adding it.

    If that won't work, try reinstalling the DPM protection agent on the Windows 7 workstation.


    Blog: https://thesystemcenterblog.com LinkedIn:


    • Edited by Leon Laude Wednesday, August 22, 2018 8:03 PM
    Wednesday, August 22, 2018 8:03 PM