One of our machines in one of our VM policies always says 0.0% optimization. We have many other machines in the same policy that have no issue with optimization rates ranging from 99% to 65%. This one machine takes a long time to backup because it seems that the accelerator is not working and is always sending the full machine, even on differential backups. I have checked the setting for the vm to make sure it is enabled to use change tracking, with the VM parameters:ctkEnabled=True. This is a 2019 windows server backing up to MSDP on 5240 appliance. Like I said no other machine has an issue in the policy. Also this is a File server, so most of the files don't change, it should be getting much better dedup and optimization, but it's not. Any ideas on where else to investigate?
Here is the job details for that client:
Sep 25, 2023 7:02:29 PM - Info nbjm (pid=34084) starting backup job (jobid=1517544) for client DRXXX, policy GSCvCenter-EARLY, schedule Differential-Inc
Sep 25, 2023 7:02:29 PM - Info bpbrm (pid=75745) The data-in-transit encryption (DTE) is disabled for the client (nbumaster.xxx.xxxxx-xxxxx.net) as the global DTE mode is set to 'Preferred Off' and the client DTE mode is set to 'Automatic'
Sep 25, 2023 7:02:29 PM - Info bpbrm (pid=75745) DRxxx is the host to backup data from
Sep 25, 2023 7:02:29 PM - Info bpbrm (pid=75745) reading file list for client
Sep 25, 2023 7:02:29 PM - Info bpbrm (pid=75745) accelerator enabled
Sep 25, 2023 7:02:29 PM - estimated 1170930310 kbytes needed
Sep 25, 2023 7:02:29 PM - Info nbjm (pid=34084) started backup (backupid=DRxxx_1695682949) job for client DRxxx, policy GSCvCenter-EARLY, schedule Differential-Inc on storage unit stu_disk_nbumaster using backup host nbumaster.xxxx.xxxxx-xxxxx.net
Sep 25, 2023 7:02:29 PM - started process bpbrm (pid=75745)
Sep 25, 2023 7:03:02 PM - Info bpbrm (pid=75745) starting bpbkar on client
Sep 25, 2023 7:03:02 PM - connecting
Sep 25, 2023 7:03:02 PM - connected; connect time: 0:00:00
Sep 25, 2023 7:03:03 PM - Info bpbkar (pid=76769) Backup started
Sep 25, 2023 7:03:03 PM - Info bpbrm (pid=75745) bptm pid: 76790
Sep 25, 2023 7:03:03 PM - Info bptm (pid=76790) start
Sep 25, 2023 7:03:03 PM - Info bptm (pid=76790) using 262144 data buffer size
Sep 25, 2023 7:03:03 PM - Info bptm (pid=76790) using 30 data buffers
Sep 25, 2023 7:03:03 PM - Info bptm (pid=76790) start backup
Sep 25, 2023 7:03:04 PM - begin writing
Sep 25, 2023 7:03:05 PM - Info bpbkar (pid=76769) INF - Backing up vCenter server gscvcenter.xxxx.xxxxx-xxxxx.net, ESX host bcvsc11.xxxx.xxxxx-xxxxx.net, BIOS UUID 421998ce-22c3-daca-df2a-f9a55686d946, Instance UUID 5019bd6f-d2fb-52e0-8539-26487f4be1c3, Display Name DRxxx, Hostname DRxxx.xxxx.xxxx-xxxxx.net
Sep 25, 2023 7:03:34 PM - Info bpbkar (pid=76769) INF - Number of virtual volumes found : 6
Sep 25, 2023 7:03:34 PM - Info bpbkar (pid=76769) INF - Mapping supported volume : C:
Sep 25, 2023 7:03:34 PM - Info bpbkar (pid=76769) INF - Mapping supported volume : D:
Sep 25, 2023 7:03:34 PM - Info bpbkar (pid=76769) INF - Mapping supported volume : E:
Sep 25, 2023 7:03:34 PM - Info bpbkar (pid=76769) INF - Mapping supported volume : F:
Sep 25, 2023 7:03:34 PM - Info bpbkar (pid=76769) INF - Mapping supported volume : H:
Sep 25, 2023 7:03:34 PM - Info bpbkar (pid=76769) INF - Mapping supported volume : Volume{6cfa4020-7c3a-11e4-80b4-806e6f6e6963}
Sep 25, 2023 7:05:17 PM - Info bpbkar (pid=76769) INF - Transport Type = nbd
Sep 26, 2023 4:18:20 AM - Info bpbkar (pid=76769) accelerator sent 999768730624 bytes out of 999768722944 bytes to server, optimization 0.0%
Sep 26, 2023 4:18:20 AM - Info bptm (pid=76790) waited for full buffer 1161674 times, delayed 1714794 times
Sep 26, 2023 4:18:20 AM - Info bpbkar (pid=76769) bpbkar waited 458 times for empty buffer, delayed 162679 times, each delay is 1000 micro-seconds
Sep 26, 2023 4:18:31 AM - Info bptm (pid=76790) EXITING with status 0 <----------
Sep 26, 2023 4:18:31 AM - Info nbumaster.xxxx.xxxxx-xxxx.net (pid=76790) StorageServer=PureDisk:nbumaster.xxxx.xxxxxx-xxxxx.net; Report=PDDO Stats for (nbumaster.xxxxx.xxxxx-xxxxx.net): scanned: 976341081 KB, CR sent: 879548292 KB, CR sent over FC: 0 KB, dedup: 9.9%, cache disabled, where dedup space saving:5.8%, compression space saving:4.1%
Sep 26, 2023 4:18:31 AM - Info bpbrm (pid=75745) validating image for client DRxxx
Sep 26, 2023 4:18:31 AM - Info bpbkar (pid=76769) done. status: 0: the requested operation was successfully completed
Sep 26, 2023 4:18:31 AM - end writing; write time: 9:15:27
The requested operation was successfully completed. (0)
