Question

Throughput Issue with VMware snapshot backups

  • 14 September 2021
  • 9 replies
  • 37 views

Badge +5

Team,

From last 2 weeks we are observing performance issues with Vmware snapshot backup over SAN mode.

vMware backup jobs are taking 2-3 days to complete , throughput has declined from 1 TB/hr to 50 GB/hr.

The underlying backup library is healthy with no disk failures .

I see in command center health report that disk pruning status as critical for global vmware deduplication policy . data aging is running on daily basis .

How can i manually run pruning of DDB ? Is there any impact on running backup while pruning DDB manually. There is an option to validate and 

Also , what does Read, write and network % means in Average throughout which is very low .

Average throughput 64.27 GB/hr
(Read: 14.19%, Write: 0.83%, Network: 84.96%)

Regards, Mohit


9 replies

Badge +5
DDB Prune Status

 

Userlevel 7
Badge +19

@Mohit Chordia , appreciate all of the detail!

Can you copy and paste the excerpts from the PerformanceMetrics.log file at this time?  It will give us a better breakdown.

Regarding the Dedupe concerns, jobs can run while pruning occurs, but the backup will take priority.  More threads will apply towards the backups themselves compared to the pruning side.

Do you have time frames where backups won’t be running?

Badge +5

excerpts from the PerformanceMetrics.log file :


22160 cf1c  09/14 08:08:00 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
22160 cf1c  09/14 08:08:00 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
22160 cf1c  09/14 08:08:00 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
22160 cf1c  09/14 08:08:00 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[18084] TaskDone:[18084] 
5392  6e18  09/14 08:08:02 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
5392  6e18  09/14 08:08:02 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
5392  6e18  09/14 08:08:02 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[5] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
5392  6e18  09/14 08:08:02 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[26313] TaskDone:[26313] 
60992 d2e8  09/14 08:08:03 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
60992 d2e8  09/14 08:08:03 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
60992 d2e8  09/14 08:08:03 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
60992 d2e8  09/14 08:08:03 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[4052] TaskDone:[4052] 
45696 5be0  09/14 08:08:05 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
45696 5be0  09/14 08:08:05 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
45696 5be0  09/14 08:08:05 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
45696 5be0  09/14 08:08:05 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[15620] TaskDone:[15620] 
24496 8980  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
24496 8980  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
24496 8980  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
24496 8980  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[7031] TaskDone:[7031] 
25096 4868  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
25096 4868  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
25096 4868  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[5] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
25096 4868  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[13297] TaskDone:[13297] 
1260  3ef0  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
1260  3ef0  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
1260  3ef0  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[5] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
1260  3ef0  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[12176] TaskDone:[12176] 
22300 b48   09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
22300 b48   09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
22300 b48   09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[5] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
22300 b48   09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[9362] TaskDone:[9362] 
20980 70c4  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
20980 70c4  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
20980 70c4  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[1] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
20980 70c4  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[2488] TaskDone:[2488] 
30676 7810  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
30676 7810  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
30676 7810  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
30676 7810  09/14 08:08:07 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[2118] TaskDone:[2118] 
12460 8618  09/14 08:08:09 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
12460 8618  09/14 08:08:09 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
36512 8b08  09/14 08:08:09 ### Context:[IndexingService.exe] Module:[NetworkServer] Instance:[IndexingService_2] Type:[SnapShot] ConnectionCount:[1] 
36512 8b08  09/14 08:08:09 ### Context:[IndexingService.exe] Module:[NetworkServer] Instance:[IndexingService_2] Type:[Delta] ConnectionAdded:[0] ConnectionRemoved:[0] 
36512 8b08  09/14 08:08:09 ### Context:[IndexingService.exe] Module:[ThreadPool] Instance:[IOCPServerPool_IndexingService_2] Type:[SnapShot] BusyThreads:[40] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
36512 8b08  09/14 08:08:09 ### Context:[IndexingService.exe] Module:[ThreadPool] Instance:[IOCPServerPool_IndexingService_2] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
36512 8b08  09/14 08:08:09 ### Context:[IndexingService.exe] Module:[ThreadPool] Instance:[IndexingService] Type:[SnapShot] BusyThreads:[1] MaxThreads:[100] ReadyTask:[0] TaskList:[0] WorkerThreads:[3] 
36512 8b08  09/14 08:08:09 ### Context:[IndexingService.exe] Module:[ThreadPool] Instance:[IndexingService] Type:[Delta] TaskAdded:[10] TaskDone:[10] 
36512 8b08  09/14 08:08:09 ### Context:[IndexingService.exe] Module:[ThreadPool] Instance:[IndexingService_2] Type:[SnapShot] BusyThreads:[0] MaxThreads:[100] ReadyTask:[0] TaskList:[0] WorkerThreads:[2] 
36512 8b08  09/14 08:08:09 ### Context:[IndexingService.exe] Module:[ThreadPool] Instance:[IndexingService_2] Type:[Delta] TaskAdded:[10] TaskDone:[10] 
18696 5f80  09/14 08:08:10 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
18696 5f80  09/14 08:08:10 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
18696 5f80  09/14 08:08:10 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
18696 5f80  09/14 08:08:10 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[10562] TaskDone:[10562] 
53252 f724  09/14 08:08:10 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
53252 f724  09/14 08:08:10 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
53252 f724  09/14 08:08:10 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[1] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
53252 f724  09/14 08:08:10 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[3313] TaskDone:[3313] 
38600 d9b0  09/14 08:08:12 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
38600 d9b0  09/14 08:08:12 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
38600 d9b0  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[1] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[30] 
38600 d9b0  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[7427] TaskDone:[7427] 
46720 a43c  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
46720 a43c  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
46720 a43c  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
46720 a43c  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[13852] TaskDone:[13852] 
38056 a1b0  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
38056 a1b0  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
38056 a1b0  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[1] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[20] 
38056 a1b0  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[3897] TaskDone:[3897] 
41280 9f04  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
41280 9f04  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
41280 9f04  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[1] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[20] 
41280 9f04  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[1477] TaskDone:[1477] 
25352 408   09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
25352 408   09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
25352 408   09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
25352 408   09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[2476] TaskDone:[2476] 
36236 a1c   09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
36236 a1c   09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
36236 a1c   09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[1] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[20] 
36236 a1c   09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[2515] TaskDone:[2515] 
37304 b978  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
37304 b978  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
37304 b978  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
37304 b978  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[1255] TaskDone:[1255] 
36612 416c  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
36612 416c  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
36612 416c  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[1] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[20] 
36612 416c  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
47080 5a44  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
47080 5a44  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
47080 5a44  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[1] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[20] 
47080 5a44  09/14 08:08:13 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[1282] TaskDone:[1282] 
32856 db2c  09/14 08:08:14 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
32856 db2c  09/14 08:08:14 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
32856 db2c  09/14 08:08:14 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[24] 
32856 db2c  09/14 08:08:14 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
55332 7194  09/14 08:08:15 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
20508 2d70  09/14 08:08:15 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
55332 7194  09/14 08:08:15 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
20508 2d70  09/14 08:08:15 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
55332 7194  09/14 08:08:15 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[1] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[20] 
55332 7194  09/14 08:08:15 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[4442] TaskDone:[4442] 
63060 cdc8  09/14 08:08:15 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
63060 cdc8  09/14 08:08:15 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
63060 cdc8  09/14 08:08:15 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[1] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[20] 
63060 cdc8  09/14 08:08:15 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
36016 5a2c  09/14 08:08:15 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
36016 5a2c  09/14 08:08:15 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
36016 5a2c  09/14 08:08:15 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
36016 5a2c  09/14 08:08:15 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[1737] TaskDone:[1737] 
49624 5068  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
49624 5068  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
49624 5068  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
49624 5068  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
52192 755c  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
52192 755c  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
52192 755c  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[1] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[20] 
52192 755c  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[1245] TaskDone:[1245] 
57468 a13c  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
57468 a13c  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
57468 a13c  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
57468 a13c  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[1705] TaskDone:[1705] 
19680 a9c0  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
19680 a9c0  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
19680 a9c0  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[1] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[20] 
19680 a9c0  09/14 08:08:16 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
56496 bd00  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
56496 bd00  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
56496 bd00  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[3] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
56496 bd00  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[2108] TaskDone:[2108] 
61228 6b6c  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
39628 cb58  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
61228 6b6c  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
39628 cb58  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
61228 6b6c  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[5] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
39628 cb58  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[5] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
61228 6b6c  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[2857] TaskDone:[2857] 
39628 cb58  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[962] TaskDone:[962] 
49848 ed34  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
49848 ed34  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
49848 ed34  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
49848 ed34  09/14 08:08:17 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
51276 28f4  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
51276 28f4  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
51276 28f4  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
51276 28f4  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[838] TaskDone:[838] 
24328 d92c  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
24328 d92c  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
24328 d92c  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
24328 d92c  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[5509] TaskDone:[5509] 
27832 7b6c  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
27832 7b6c  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
27832 7b6c  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
27832 7b6c  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[1010] TaskDone:[1010] 
30564 8794  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
30564 8794  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
30564 8794  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[1] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[20] 
30564 8794  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
17776 87a8  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
17776 87a8  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
17776 87a8  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
17776 87a8  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[1594] TaskDone:[1594] 
34000 5b9c  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
34000 5b9c  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
34000 5b9c  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[2] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[40] 
34000 5b9c  09/14 08:08:18 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
58208 8a14  09/14 08:08:19 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[SnapShot] BusyThreads:[0] MaxThreads:[4] ReadyTask:[0] TaskList:[0] WorkerThreads:[0] 
58208 8a14  09/14 08:08:19 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[CVRemoteAgentServer] Type:[Delta] TaskAdded:[0] TaskDone:[0] 
58208 8a14  09/14 08:08:19 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[SnapShot] BusyThreads:[1] MaxThreads:[40] ReadyTask:[0] TaskList:[0] WorkerThreads:[20] 
58208 8a14  09/14 08:08:19 ### Context:[vsbkp.exe] Module:[ThreadPool] Instance:[SdtHeadThPool] Type:[Delta] TaskAdded:[0] TaskDone:[0] 

 

Badge +5

We don't have any time frame when backups are not running .

I ran 2 on-demand VM backup jobs with same MA and proxy ,  one with dedupe disable and other one with dedupe enabled and can see significant difference in backup throughput.

with dedupe disabled  – received backup throughput close to 2 TB/hr

with dedupe enabled  - received backup throughput of 80 GB/hr.

So definitely something is wrong with DDB store  , Q&I time is fine ( 136 us)

there are 6 DDB partition for global dedupe policy .

How can i check when last DDB pruning happened and can i run DDB pruning manually and monitor it?

What action needs to be taken when DDB pruning status is Critical ? ( Attached screenshot) 

Userlevel 7
Badge +19

Appreciate the logs and the context.  Definitely dedupe related.

Open GxTail.exe and then open the SIDBPrune.log file and the SIDBPhysicalDeletes.log file to see when pruning occurs (logically and physically).  SIDBEngine.log will help get further details on the store itself (check for the exact Store ID).

Badge +5

i checked these files and but not able to find the root cause why backups are running slow using dedupe.

 

See these SIDBPrunelogs :

9536  8184  09/14 09:18:15 ### 31-3 SetMountPath:330 Got path [E:\xxxxxxx\Local\VM\V3YWOW_Folder1\CV_MAGNETIC] for id [170]. User []
9536  8184  09/14 09:18:15 ### 31-3 OpenIdx:3169 Cannot lock chunk [107288200].
9536  8184  09/14 09:18:15 ### 31-3 OnChunkStart:1914 Cannot initialize SI Chunk pruner. iRet [-1]

 

SetMountPath:330 Got path [\\xxxxxx\xxxxxxx\Local\VM\Folder1\CV_MAGNETIC] for id [171]. User [xxxxxxxxxxxxx]
9536  7820  09/14 09:18:15 ### 31-3 PruneZRRecInt:2334 Got [1] primary records. Start ChunkId [106557690], Start Id [3458764514847122184], End Chunk Id [106557690], End Id [3458764514847122184]
9536  4114  09/14 09:18:15 ### 31-3 SetMountPath:359 Mountpath [171] is read only.

Userlevel 7
Badge +19

@Mohit Chordia , I would recommend opening a support case to have an engineer do a deeper dive of the DDB and its activity.

Share the case number with me once you do so I can track it accordingly.

Userlevel 5
Badge +10

Following this one. Curious to hear the outcome! 

Badge +5

Case # 210914-310 opened with support 

Reply