commvault.com commvault.com
Solved

Throughput Issue with VMware snapshot backups

  • 14 September 2021
  • 11 replies
  • 1251 views
Mohit Chordia
Rank
Userlevel 3
Badge +11

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

icon

Best answer by Mike Struening RETIRED 27 September 2021, 23:04

View original

11 replies

Mohit Chordia
Rank
Userlevel 3
Badge +11
DDB Prune Status

 

Mike Struening RETIRED
Rank
Userlevel 7
Badge +23

@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?

https://www.linkedin.com/in/michael-struening
Mohit Chordia
Rank
Userlevel 3
Badge +11

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] 

 

Mohit Chordia
Rank
Userlevel 3
Badge +11

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) 

1 Attachment
Mike Struening RETIRED
Rank
Userlevel 7
Badge +23

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).

https://www.linkedin.com/in/michael-struening
Mohit Chordia
Rank
Userlevel 3
Badge +11

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.

Mike Struening RETIRED
Rank
Userlevel 7
Badge +23

@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.

https://www.linkedin.com/in/michael-struening
Onno van den Berg
Rank
Userlevel 7
Badge +19

Following this one. Curious to hear the outcome! 

Mohit Chordia
Rank
Userlevel 3
Badge +11

Case # 210914-310 opened with support 

Mike Struening RETIRED
Rank
Userlevel 7
Badge +23

Updating with case solution:

-VM VSA backup running with poor throughput when dedupe is enabled
-The VM backup runs with Average throughput of 30GB\Hr when dedupe is enabled.
-For the same client when dedupe is disabled we get a throughput of 1.4 TB\Hr.


-Checked the DDB and noticed the Q&I is fine but the Pending deletes are high, 42 TB to be freed
-Since pruning is running in the background, the backup performance could be affected.
-We temporarily disabled pruning and initiated new job  and noticed the Avg throughput was increasing gradually and the current throughput was 1.2 TB\hr
-So this confirms pruning is the bottleneck.


-The disklibrary  is 91% full hence we cannot disable pruning. At this point, our goal is to bring down the pending deletes to 0.
-We enabled the pruning and increased the volume size updates to 9000 and update time interval to 15 Minutes.
-checked the SIDBPrune logs and noticed Pruning works fine for its local path, and it tries to prune from the Shared MP and reports ReadOnly. This behaviour is seen from all MA's
-So we provided "Read\Write" permissions to all MA's, so that any MA can prune the data.
-Also added the additional key DedupPrunerThreadPoolSizeDisk with the value of 10.

Solution:

The pending deletes for reduced to 0 after implementing the changes.
Backups are running with expected throughput

https://www.linkedin.com/in/michael-struening
Mohit Chordia
Rank
Userlevel 3
Badge +11

Thanks Everyone . This one was resolved after long troubleshooting with support .

Reply


Terms & ConditionsCookie settings