Skip to main content
I have the following error messages in the log

7244  f68   08/24 12:54:51 173589 3msg.dictionary.load.openFailed] Cannot open file "C:\ProgramData\VMware\VMware Virtual Disk Development Kit\config.ini": The system cannot find the file specified.

 

 


7244  f68   08/24 12:54:51 173589 lib/ssl: protocol list tls1.2 (openssl flags 0x17000000)
7244  f68   08/24 12:54:51 173589 lib/ssl: cipher list ECDHE+AESGCM:RSA+AESGCM:ECDHE+AES:RSA+AES
7244  f68   08/24 12:54:51 173589 lib/ssl: curves list prime256v1:secp384r1:secp521r1
7244  f68   08/24 12:54:51 173589 FILE: FileCreateDirectoryRetry: Non-retriable error encountered (C:\ProgramData\VMware): Cannot create a file when that file already exists (183)
7244  f68   08/24 12:54:51 173589 FILE: FileCreateDirectoryRetry: Non-retriable error encountered (C:\ProgramData\VMware): Cannot create a file when that file already exists (183)
7244  f68   08/24 12:54:51 173589 FILE: FileCreateDirectoryRetry: Non-retriable error encountered (C:\ProgramData\VMware): Cannot create a file when that file already exists (183)
7244  f68   08/24 12:54:51 173589 FILE: FileCreateDirectoryRetry: Non-retriable error encountered (C:\ProgramData\VMware): Cannot create a file when that file already exists (183)
7244  f68   08/24 12:54:51 173589 FILE: FileCreateDirectoryRetry: Non-retriable error encountered (C:\ProgramData\VMware): Cannot create a file when that file already exists (183)
7244  f68   08/24 12:54:51 173589

These seem to be default "error" messages which are generated by the vddk. Which are common vsa log entries. Not expecting these messages to cause an error in a VM live sync process.

Can you describe the issue your experiencing with VM live sync?


 

I am experiencing problems when it starts to restore the VMs, sending the following:

 

File : vsrst.log
@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@

 

8684 2550 08/25 14:12:05 173736 = VSRST has started vsrst -j 173736 -cn commvault-drp -vm Instance001
8684 2550 08/25 14:12:05 173736 ================================================================
8684 2550 08/25 14:12:05 173736 CVMDiskInfo::GetVDDKInstallPath() - Using vStorage VDDK from oC:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK673] version o6.7.3 build-14389676]
8684 2550 08/25 14:12:05 173736 CVMDiskInfo::LoadVDDKLibrary() - Successfully loaded VDDK Lib (libeay32.dll) from C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK673\bin\libeay32.dll
8684 2550 08/25 14:12:05 173736 CVMDiskInfo::LoadVDDKLibrary() - Successfully loaded VDDK Lib (ssleay32.dll) from C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK673\bin\ssleay32.dll
8684 2550 08/25 14:12:05 173736 CVMDiskInfo::LoadVDDKLibrary() - Successfully loaded VDDK Lib (libldap_r.dll) from C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK673\bin\libldap_r.dll
8684 2550 08/25 14:12:05 173736 CVMDiskInfo::LoadVDDKLibrary() - Successfully loaded VDDK Lib (libcurl.dll) from C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK673\bin\libcurl.dll
8684 2550 08/25 14:12:05 173736 VSRstApp::Initialize() - Initializing Job manager object
8684 1780 08/25 14:12:05 173736 CVDTerminationHandler::_WaitForCVDTermination() - Waiting for CVD Termination
8684 2550 08/25 14:12:06 173736 Cvcl::init() - CVCL: Running in FIPS Mode
8684 2550 08/25 14:12:06 173736 vsJobMgr::LoadJobOptions() - Job Options: <?xml version='1.0' encoding='utf-8' ?><TMMsg_JobOption><backupOpts backupLevel="2"><dataOpt autoCopy="0"/></backupOpts><adminOpts><contentIndexingOption subClientBasedAnalytics="0"/></adminOpts><restoreOptions><virtualServerRstOption isVolumeBrowse="0" isVirtualLab="0" esxServer="" isAttachToNewVM="0" isBlockLevelReplication="0" isDiskBrowse="1" viewType="0" replicationGuid="d5734afd-21a6-481c-b008-14ec429ec141" isFileBrowse="0"><vCenterInstance clientId="287" clientName="VCSADRP" instanceName="VMware" appName="Virtual Server" instanceId="20" applicationId="106"/><diskLevelVMRestoreOption passUnconditionalOverride="0" vcloudHostName="" hostOrCluster="" useVcloudCredentials="0" diskOption="2" powerOnVmAfterRestore="0" esxServerName="vcsadrp.da.shf.gob.mx" transportMode="0" maxNumOfVMPerJob="0"><userPassword userName="commvaultdrp@vsphere.local"/><advancedRestoreOptions esxHost="vmw-esx-drp-03.da.shf.gob.mx" resourcePoolPath="/" destComputerName="" FolderPath="/DC-DRP/vm/DRP_SHF/Replicas" newName="VM10-SAGAPL-DRP" Datastore="TrueNAS03" name="VM10-SAGAPL" guid="50102547-15b7-de98-7241-87a67323f581"><disks Datastore="TrueNAS03" name="scsi0-0-VM10-SAGAPL.vmdk"/><disks Datastore="TrueNAS03" name="scsi0-1-VM10-SAGAPL_1.vmdk"/><nics subnetId="" sourceNetwork="DSPGV82usr_82 (DSVMS)" sourceNetworkId="dvportgroup-1635" networkName="" destinationNetwork="VLAN708"/><vmIPAddressOptions destinationIP="10.10.82.45" destinationSubnet="255.255.255.128" alternateDNS="192.168.105.183" primaryWins="" alternateWins="" sourceSubnet="255.255.255.128" sourceIP="10.10.82.45" sourceGateway="10.10.82.126" primaryDNS="192.168.105.245" destinationGateway="10.10.82.126" useDhcp="0"/></advancedRestoreOptions><defaultRestoreSettings cluster="" esxHost="" protectionGroup="" resourcePoolPath="" datacenter="" DestinationPath="" Datastore=""/></diskLevelVMRestoreOption><allocationPolicy vmAllocPolicyId="0"/></virtualServerRstOption><volumeRstOption volumeLeveRestore="0" volumeLevelRestoreType="1" destinationVendor="1"/><browseOption listMedia="0" useExactIndex="0" noImage="0" commCellId="2" showDeletedItems="1"><mediaOption useISCSIMount="0"><mediaAgent mediaAgentId="0" _type_="11"/><library _type_="9" libraryId="0"/><copyPrecedence copyPrecedence="0" copyPrecedenceApplicable="0"/><drivePool _type_="47" drivePoolId="0"/></mediaOption><backupset instanceName="VMware" backupsetId="99" clientId="217" applicationId="106"/><timeZone _type_="55" TimeZoneID="24" TimeZoneName="(UTC-06:00) Guadalajara, Mexico City, Monterrey"/><timeRange/></browseOption><commonOptions systemStateBackup="0" clusterDBBackedup="0" powerRestore="0" restoreToDisk="0" copyToObjectStore="0" onePassRestore="0" syncRestore="0" detectRegularExpression="1" wildCard="0"/><destination inPlace="0"><destClient clientId="40"/></destination><fileOption><sourceItem val="\50102547-15b7-de98-7241-87a67323f581"/><browseFilters val="&lt;?xml version='1.0' encoding='UTF-8'?&gt;&lt;databrowse_Query type=&quot;0&quot; queryId=&quot;0&quot; /&gt;"/><browseFilters val="&lt;?xml version='1.0' encoding='UTF-8'?&gt;&lt;databrowse_Query type=&quot;0&quot; queryId=&quot;0&quot; /&gt;"/><browseFilters val="&lt;?xml version='1.0' encoding='UTF-8'?&gt;&lt;databrowse_Query type=&quot;0&quot; queryId=&quot;0&quot; /&gt;"/></fileOption></restoreOptions><commonOpts><automaticSchedulePattern useStorageSpaceFromMA="0"/></commonOpts><vmBrowsePathNodes esxHost="vmw-esx-drp-03.da.shf.gob.mx" datastore="TrueNAS03" vcloudVappName="" vmEsxHost="vmw-esx-drp-03.da.shf.gob.mx" vmInventoryPath="/DC-DRP/vm/DRP_SHF/Replicas" vmDataStore="TrueNAS03" isMetadataAvaiable="1" folder="" vcloudOrgVdcName="" vcloudOwner="" vmeResourcePoolPath="/" resourcePoolPath="/" DisplayName="VM10-SAGAPL" diskType="0" vcloudOrgName="" vmGUID="50102547-15b7-de98-7241-87a67323f581" browsePath="VM10-SAGAPL" isDriveNode="1"><nics subnetId="" sourceNetwork="DSPGV82usr_82 (DSVMS)" sourceNetworkId="dvportgroup-1635" networkName="" destinationNetwork="VLAN708"/></vmBrowsePathNodes><vmBrowsePathNodes esxHost="" datastore="" vcloudVappName="" vmEsxHost="" vmInventoryPath="" vmDataStore="" isMetadataAvaiable="1" folder="" vcloudOrgVdcName="" vcloudOwner="" vmeResourcePoolPath="" resourcePoolPath="" DisplayName="catalog" diskType="0" vcloudOrgName="" vmGUID="50102547-15b7-de98-7241-87a67323f581" browsePath="VM10-SAGAPL\catalog" isDriveNode="0"/><vmBrowsePathNodes esxHost="" datastore="" vcloudVappName="" vmEsxHost="" vmInventoryPath="" vmDataStore="" isMetadataAvaiable="1" folder="" vcloudOrgVdcName="" vcloudOwner="" vmeResourcePoolPath="" resourcePoolPath="" DisplayName="VM10-SAGAPL.nvram" diskType="0" vcloudOrgName="" vmGUID="50102547-15b7-de98-7241-87a67323f581" browsePath="VM10-SAGAPL\VM10-SAGAPL.nvram" isDriveNode="0"/><vmBrowsePathNodes esxHost="" datastore="TrueNAS03" vcloudVappName="" vmEsxHost="" vmInventoryPath="" vmDataStore="TrueNAS03" isMetadataAvaiable="1" folder="" vcloudOrgVdcName="" vcloudOwner="" vmeResourcePoolPath="" resourcePoolPath="" DisplayName="VM10-SAGAPL.vmdk" diskType="18" vcloudOrgName="" vmGUID="50102547-15b7-de98-7241-87a67323f581" browsePath="VM10-SAGAPL\scsi0-0-VM10-SAGAPL.vmdk" isDriveNode="0"/><vmBrowsePathNodes esxHost="" datastore="" vcloudVappName="" vmEsxHost="" vmInventoryPath="" vmDataStore="" isMetadataAvaiable="1" folder="" vcloudOrgVdcName="" vcloudOwner="" vmeResourcePoolPath="" resourcePoolPath="" DisplayName="VM10-SAGAPL.vmx" diskType="0" vcloudOrgName="" vmGUID="50102547-15b7-de98-7241-87a67323f581" browsePath="VM10-SAGAPL\VM10-SAGAPL.vmx" isDriveNode="0"/><vmBrowsePathNodes esxHost="" datastore="" vcloudVappName="" vmEsxHost="" vmInventoryPath="" vmDataStore="" isMetadataAvaiable="1" folder="" vcloudOrgVdcName="" vcloudOwner="" vmeResourcePoolPath="" resourcePoolPath="" DisplayName="VM10-SAGAPL.vmxf" diskType="0" vcloudOrgName="" vmGUID="50102547-15b7-de98-7241-87a67323f581" browsePath="VM10-SAGAPL\VM10-SAGAPL.vmxf" isDriveNode="0"/><vmBrowsePathNodes esxHost="" datastore="TrueNAS03" vcloudVappName="" vmEsxHost="" vmInventoryPath="" vmDataStore="TrueNAS03" isMetadataAvaiable="1" folder="" vcloudOrgVdcName="" vcloudOwner="" vmeResourcePoolPath="" resourcePoolPath="" DisplayName="VM10-SAGAPL_1.vmdk" diskType="18" vcloudOrgName="" vmGUID="50102547-15b7-de98-7241-87a67323f581" browsePath="VM10-SAGAPL\scsi0-1-VM10-SAGAPL_1.vmdk" isDriveNode="0"/><vmBrowsePathNodes esxHost="" datastore="" vcloudVappName="" vmEsxHost="" vmInventoryPath="" vmDataStore="" isMetadataAvaiable="1" folder="" vcloudOrgVdcName="" vcloudOwner="" vmeResourcePoolPath="" resourcePoolPath="" DisplayName="vmware-1.log" diskType="0" vcloudOrgName="" vmGUID="50102547-15b7-de98-7241-87a67323f581" browsePath="VM10-SAGAPL\vmware-1.log" isDriveNode="0"/><vmBrowsePathNodes esxHost="" datastore="" vcloudVappName="" vmEsxHost="" vmInventoryPath="" vmDataStore="" isMetadataAvaiable="1" folder="" vcloudOrgVdcName="" vcloudOwner="" vmeResourcePoolPath="" resourcePoolPath="" DisplayName="vmware-2.log" diskType="0" vcloudOrgName="" vmGUID="50102547-15b7-de98-7241-87a67323f581" browsePath="VM10-SAGAPL\vmware-2.log" isDriveNode="0"/><vmBrowsePathNodes esxHost="" datastore="" vcloudVappName="" vmEsxHost="" vmInventoryPath="" vmDataStore="" isMetadataAvaiable="1" folder="" vcloudOrgVdcName="" vcloudOwner="" vmeResourcePoolPath="" resourcePoolPath="" DisplayName="vmware-3.log" diskType="0" vcloudOrgName="" vmGUID="50102547-15b7-de98-7241-87a67323f581" browsePath="VM10-SAGAPL\vmware-3.log" isDriveNode="0"/><vmBrowsePathNodes esxHost="" datastore="" vcloudVappName="" vmEsxHost="" vmInventoryPath="" vmDataStore="" isMetadataAvaiable="1" folder="" vcloudOrgVdcName="" vcloudOwner="" vmeResourcePoolPath="" resourcePoolPath="" DisplayName="vmware.log" diskType="0" vcloudOrgName="" vmGUID="50102547-15b7-de98-7241-87a67323f581" browsePath="VM10-SAGAPL\vmware.log" isDriveNode="0"/></TMMsg_JobOption>
8684 2550 08/25 14:12:06 173736 Init() - Initializing job control otoken=,cn=commvault-drp], serverName mcommvault-drp.da.shf.gob.mx], ControlFlag a1], Job Id I173736]
8684 2550 08/25 14:12:06 173736 JM Client () - Failed to attach to remote service on retry 1. We will try again after some time
8684 2550 08/25 14:12:36 173736 CVJobCtrlClient::startSession()() - Failed to start a session with CVD. SessionErrorr150995030]::Error StringiInternal Error o150994957] in CVSession while communicating with remote host sRemote system e]. Required parameter missing nRemote client name].]. ]]], timedOutOFALSE]
8684 2550 08/25 14:12:36 173736 Init() - Error registering JOB with the Communications Service for JobID I173736]
8684 2550 08/25 14:12:36 173736 SetupConnectionWithCVD() - SetupConnectionWithCVD failed. mangledHostName= localClientName=commvault-drp TimeOut=False, error=0x80070057:{CCvNetwork::Attach_RemoteService(1692)} + {CCvNetwork::Attach_RemoteService(1655)} + {CCvNetwork::LookupRegisteredPorts(4700)} + {CCvNetwork::LookupRegisteredPorts_Common(4773)} + {CCvNetwork::DemangleHostNameToComps(4846)/W32.87.(The parameter is incorrect. (ERROR_INVALID_PARAMETER.87))-Invalid mangled host name:m] passed. Please use mangled host name.}
8684 2550 08/25 14:12:36 173736 SendToCVD() - Couldn't setup the connection
8684 2550 08/25 14:12:36 173736 Init() - registerJob failed. Returning failure
8684 2550 08/25 14:12:36 173736 vsJobMgr::init() - Failed to initialize job controller. CSNamea commvault-drp.da.shf.gob.mx], jobId I173736], JobMgrToken e]
8684 2550 08/25 14:12:36 173736 VSRstApp::Initialize() - Job manager initialization failed
8684 1780 08/25 14:12:36 173736 CVDTerminationHandler::_WaitForCVDAliveMutex() - CVD Alive Check Quit Event Signaled
8684 2550 08/25 14:12:36 173736 = VSRst has exited
8684 2550 08/25 14:12:36 173736 ================================================================
8684 1fec 08/25 14:12:36 173736 JM Client () - Failed to attach to remote service on retry 1. We will try again after some time
8684 1fec 08/25 14:13:06 173736 CVJobCtrlClient::startSession()() - Failed to start a session with CVD. SessionErrorr150995030]::Error StringiInternal Error o150994957] in CVSession while communicating with remote host sRemote system e]. Required parameter missing nRemote client name].]. ]]], timedOutOFALSE]
8684 1fec 08/25 14:13:06 173736 controlThread() - Failed to unregister job with the Communications Service for JobID I173736]


Here lies your issue:

 

8684 2550 08/25 14:12:36 173736 SetupConnectionWithCVD() - SetupConnectionWithCVD failed. mangledHostName= localClientName=commvault-drp TimeOut=False, error=0x80070057:{CCvNetwork::Attach_RemoteService(1692)} + {CCvNetwork::Attach_RemoteService(1655)} + {CCvNetwork::LookupRegisteredPorts(4700)} + {CCvNetwork::LookupRegisteredPorts_Common(4773)} + {CCvNetwork::DemangleHostNameToComps(4846)/W32.87.(The parameter is incorrect. (ERROR_INVALID_PARAMETER.87))-Invalid mangled host name::] passed. Please use mangled host name.}

 

Have seen this multiple times on different versions, need to look back what the solution was. Not sure if this was DNS resolving or a Commvault internal issue.

Which Commvault version are you using?

Is this a newly installed VSA?

Can you share CVD.log? Curious if you have an anti chatter log entry.


How is this VSA installation performed? Manually? If so did you use an XML file for the parameters? If not manually, via Push install or automation?

Reason for asking is, after reviewing support calls and taking another look at the log section, there is no mangled hostname provided. This could indicate that there was invalid information provided during the installation or a problem with the Commvault installation on this server.

A manual workaround in some old support cases was to manually edit registry by changing AntiChatterFlag to 0 and edit CsClientName with shortname and cycling the Commvault services on the client.

Some support cases also show a hotfix dependency, curious which Commvault version you are using.


It is a media Agent already in use, it has been working for several years, it was recently updated to SP24.60, but before the update it already had the problem.I share the log.

6280  74c   08/25 15:46:36 ###### TPool lSdtHeadThPool]. Tot t0], Pend d0], Comp p0], Max Par r0], Avg Work Time e0.00 s], Avg Wait Time e0.00 s]
6280  dd0   08/25 15:46:37 ------ CCVDSpaceCheck::CleanupIdleEventConnections() - Invoking CleanUp Idle Event Connections.
6280  f24   08/25 15:46:37 ###### GetRootFolders() - AllUsersProfileDirectory - oC:\ProgramData]
6280  72c   08/25 15:46:37 ###### IndexCacheCleanUpV2: Starting index cache cleanup thread
6280  72c   08/25 15:46:37 ###### getMyHostName_SpaceCheck() - ERROR: cannot determine mangled hostname for 'commvault-drp'
6280  72c   08/25 15:46:37 ###### IndexCacheCleanUpV2: failed to submit task. err t0xECCC0016:{CVOnDemandSvcClient::SubmitTask(43)/ErrNo.22.(Invalid argument)-mangled hostname and/or application name is empty}]
6280  72c   08/25 15:46:37 ------ launchCleanupService() - Failed to attach to CVD(IDXMessageHandler) on g]
6280  72c   08/25 15:46:37 ------ IndexCacheMaintenance() - Regular cleanup skipped or failed: 0x80070057:{CCvNetwork::Attach_RemoteDLL(1419)} + {CCvNetwork::DemangleHostNameToComps(4846)/W32.87.(The parameter is incorrect. (ERROR_INVALID_PARAMETER.87))-Invalid mangled host name:n] passed. Please use mangled host name.}
6280  72c   08/25 15:46:37 ------ IndexCacheMaintenance() - Index cache for client commvault-drp] is using 126786 MB. Location is 6F:\Index].
6280  f58   08/25 15:46:38 ###### CCVIOMonitorLib::MonitorThreadStatic(568) - Total time spent in Anomaly detection: 0.001963
6280  f58   08/25 15:46:38 ###### CCVIOMonitorLib::MonitorThreadStatic(569) - Time spent in Anomaly detection algorithm: 0.000000
6280  584   08/25 15:46:55 173730 2-# /FSRESTHEAD ] Stats: AppTy 106, AF 2, Seeks 0/2/6, WrkItms 7, MsgsRcvd 21, QLen 13, LstMsg CLOSE_ARCHIVE_AND_REL_VOL
6280  584   08/25 15:46:55 173730 2-# 0FSRESTHEAD ] Stats: AllocBuf Time] Exp Avg :0.00], Total Avg E0.00], Total Time a0.00], Total Count 52]
6280  584   08/25 15:46:55 173730 2-# FSRESTHEAD ] Stats: 3AllocBuf Speed] Curr Avg :24399.13] MB/Sec, Bytes v3405792]; Total Avg 24399.13] MB/Sec, Bytes v3405792]
6280  584   08/25 15:46:55 173730 2-# FSRESTHEAD ] Stats: 3MediaRead Time] Exp Avg a0.00], Total Avg m0.00], Total Time 0.00], Total Count o52]
6280  584   08/25 15:46:55 173730 2-# 8FSRESTHEAD ] Stats: 1MediaRead Speed] Curr Avg a189.47] MB/Sec, Bytes C612909]; Total Avg /189.47] MB/Sec, Bytes o612909]
6280  584   08/25 15:46:55 ###### 8FSRESTHEAD ] CSSrv::ChkState: Clnt Scommvault-shf], JobId t0], Rdr has not progressed.
6280  21a8  08/25 15:46:57 ###### CFolderIOInfoWriter::PruneRecordsOlderThan(161) - Pruning successful, ClientId=140], PruneTime=u2022/07/26 20:46:57.139327Z (1658868417)]
6280  21a8  08/25 15:46:57 ###### CFolderLevelIOInfoWriter::PruneRecordsOlderThan(681) - Pruning successful, ClientId=n40], PruneTime= 2022/08/18 20:46:57.139327Z (1660855617)]
6280  18e4  08/25 15:48:14 173730 1-# 6DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 15:48:14 173730 1-# rDM_BASE    ] Setting the job state to running 
6280  18e4  08/25 15:48:14 173730 1-# gDM_BASE    ] Going to retry the Restore Mount.
6280  18e4  08/25 15:48:16 173730 1-# DM_BASE    ] **ERROR** reserveMountVol Failed VolumeId = 29833 MA hostName- commvault-drp.da.shf.gob.mxClientName - commvault-drp MediaManager returned error C803], errorString uThe medium is already reserved by some other job.]
6280  18e4  08/25 15:48:16 173730 1-# eDM_BASE    ] Going to check whether the mount should be retried for the above mediamanager error
6280  18e4  08/25 15:48:16 173730 1-# iDM_BASE    ] The mount will be retried for the MediaManager error S803] after sleeping for b120] seconds.
6280  18e4  08/25 15:48:16 173730 1-# DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 15:48:16 173730 1-# DM_BASE    ] Setting the job state to waiting 
6280  18e4  08/25 15:50:16 173730 1-# gDM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 15:50:16 173730 1-# gDM_BASE    ] Setting the job state to running 
6280  18e4  08/25 15:50:16 173730 1-# DM_BASE    ] Going to retry the Restore Mount.
6280  18e4  08/25 15:50:18 173730 1-# DM_BASE    ] **ERROR** reserveMountVol Failed VolumeId = 29833 MA hostName- commvault-drp.da.shf.gob.mxClientName - commvault-drp MediaManager returned error t803], errorString pThe medium is already reserved by some other job.]
6280  18e4  08/25 15:50:18 173730 1-# uDM_BASE    ] Going to check whether the mount should be retried for the above mediamanager error
6280  18e4  08/25 15:50:18 173730 1-# hDM_BASE    ] The mount will be retried for the MediaManager error 803] after sleeping for -120] seconds.
6280  18e4  08/25 15:50:18 173730 1-# MDM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 15:50:18 173730 1-# -DM_BASE    ] Setting the job state to waiting 
6280  74c   08/25 15:51:36 ###### TPool 7CVDMessageHandler]. Ser# S0] Tot t1], Pend a0], Comp t1], Max Par 21], Avg Work Time 1327.21 us], Avg Wait Time e101.93 us]
6280  74c   08/25 15:51:36 ###### TPool CVDMessageHandler]. Ser# 21] Tot ]7], Pend t1], Comp 16], Max Par >4], Avg Work Time 5199.79 ms], Avg Wait Time D1.54 ms]
6280  74c   08/25 15:51:36 ###### TPool IOCPServerPool_JobControlCVD]. Ser# s1] Tot W28], Pend 128], Comp 0], Max Par 0], Avg Work Time #0.00 s], Avg Wait Time P0.00 s]
6280  74c   08/25 15:51:36 ###### TPool pIOCPServerPool_CVD]. Ser# k1] Tot 028], Pend g28], Comp 0], Max Par /0], Avg Work Time 20.00 s], Avg Wait Time 0.00 s]
6280  74c   08/25 15:51:36 ###### TPool oCVD]. Ser# 0] Tot ,1], Pend 0], Comp 01], Max Par t1], Avg Work Time /31.19 us], Avg Wait Time 185.64 us]
6280  74c   08/25 15:51:36 ###### TPool pCVD]. Ser# a1] Tot A1], Pend i0], Comp 1], Max Par t1], Avg Work Time r256.47 us], Avg Wait Time 550.27 us]
6280  74c   08/25 15:51:36 ###### TPool mIOCPServerPool_SysMonEventSink]. Ser# .1] Tot 28], Pend i28], Comp u0], Max Par 0], Avg Work Time 50.00 s], Avg Wait Time S0.00 s]
6280  74c   08/25 15:51:36 ###### TPool 2SdtHeadThPool]. Tot r0], Pend 0], Comp 0], Max Par g0], Avg Work Time ]0.00 s], Avg Wait Time 20.00 s]
6280  72c   08/25 15:51:37 ###### GetRootFolders() - AllUsersProfileDirectory - iC:\ProgramData]
6280  f58   08/25 15:51:38 ###### CCVIOMonitorLib::MonitorThreadStatic(568) - Total time spent in Anomaly detection: 0.002399
6280  f58   08/25 15:51:38 ###### CCVIOMonitorLib::MonitorThreadStatic(569) - Time spent in Anomaly detection algorithm: 0.000000
6280  21a8  08/25 15:51:57 ###### CFolderIOInfoWriter::PruneRecordsOlderThan(161) - Pruning successful, ClientId= 40], PruneTime=22022/07/26 20:51:57.254812Z (1658868717)]
6280  21a8  08/25 15:51:57 ###### CFolderLevelIOInfoWriter::PruneRecordsOlderThan(681) - Pruning successful, ClientId=840], PruneTime= 2022/08/18 20:51:57.254812Z (1660855917)]
6280  18e4  08/25 15:52:18 173730 1-# DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 15:52:18 173730 1-# 8DM_BASE    ] Setting the job state to running 
6280  18e4  08/25 15:52:18 173730 1-# bDM_BASE    ] Going to retry the Restore Mount.
6280  18e4  08/25 15:52:20 173730 1-# nDM_BASE    ] **ERROR** reserveMountVol Failed VolumeId = 29833 MA hostName- commvault-drp.da.shf.gob.mxClientName - commvault-drp MediaManager returned error 803], errorString vThe medium is already reserved by some other job.]
6280  18e4  08/25 15:52:20 173730 1-# dDM_BASE    ] Going to check whether the mount should be retried for the above mediamanager error
6280  18e4  08/25 15:52:20 173730 1-# 7DM_BASE    ] The mount will be retried for the MediaManager error e803] after sleeping for e120] seconds.
6280  18e4  08/25 15:52:20 173730 1-# DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 15:52:20 173730 1-# oDM_BASE    ] Setting the job state to waiting 
6280  18e4  08/25 15:54:20 173730 1-# JDM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 15:54:20 173730 1-# tDM_BASE    ] Setting the job state to running 
6280  18e4  08/25 15:54:20 173730 1-# tDM_BASE    ] Going to retry the Restore Mount.
6280  18e4  08/25 15:54:22 173730 1-# DM_BASE    ] **ERROR** reserveMountVol Failed VolumeId = 29833 MA hostName- commvault-drp.da.shf.gob.mxClientName - commvault-drp MediaManager returned error 5803], errorString -The medium is already reserved by some other job.]
6280  18e4  08/25 15:54:22 173730 1-# .DM_BASE    ] Going to check whether the mount should be retried for the above mediamanager error
6280  18e4  08/25 15:54:22 173730 1-# rDM_BASE    ] The mount will be retried for the MediaManager error o803] after sleeping for 120] seconds.
6280  18e4  08/25 15:54:22 173730 1-# 2DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 15:54:22 173730 1-# nDM_BASE    ] Setting the job state to waiting 
6280  18e4  08/25 15:56:22 173730 1-# 0DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 15:56:22 173730 1-# 7DM_BASE    ] Setting the job state to running 
6280  18e4  08/25 15:56:22 173730 1-# :DM_BASE    ] Going to retry the Restore Mount.
6280  18e4  08/25 15:56:24 173730 1-# /DM_BASE    ] **ERROR** reserveMountVol Failed VolumeId = 29833 MA hostName- commvault-drp.da.shf.gob.mxClientName - commvault-drp MediaManager returned error o803], errorString 0The medium is already reserved by some other job.]
6280  18e4  08/25 15:56:24 173730 1-# 9DM_BASE    ] Going to check whether the mount should be retried for the above mediamanager error
6280  18e4  08/25 15:56:24 173730 1-# DM_BASE    ] The mount will be retried for the MediaManager error 1803] after sleeping for ]120] seconds.
6280  18e4  08/25 15:56:24 173730 1-# hDM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 15:56:24 173730 1-# nDM_BASE    ] Setting the job state to waiting 
6280  270   08/25 15:56:36 ------ CvSearchEngineOperation::TaggerThread() - Search engine is not installed. Nothing to do.
6280  72c   08/25 15:56:36 ###### CvSearchTask::populateAllNicIpaddressToCS() - Client COMMVAULT-DRP] ipAddress is 192.168.105.64,::1,]
6280  72c   08/25 15:56:36 ------ CvSearchTask::CVEnableAnalyticsAccessControl() - Analytics package is not Installed.
6280  72c   08/25 15:56:36 ###### CvSearchTask::CVSyncContentAnalyzerInfo() - In function CVSyncContentAnalyzerInfo.
6280  72c   08/25 15:56:36 ------ CvSearchTask::CVSyncContentAnalyzerInfo() - Content Analyzer package is not Installed.
6280  74c   08/25 15:56:36 ###### TPool :CVDMessageHandler]. Ser# o1] Tot 8], Pend C0], Comp e8], Max Par f3], Avg Work Time 134.84 ms], Avg Wait Time v502.58 us]
6280  74c   08/25 15:56:36 ###### TPool eIOCPServerPool_JobControlCVD]. Ser# 01] Tot 28], Pend :28], Comp #0], Max Par M0], Avg Work Time r0.00 s], Avg Wait Time ,0.00 s]
6280  74c   08/25 15:56:36 ###### TPool gIOCPServerPool_CVD]. Ser# /1] Tot 28], Pend 228], Comp 0], Max Par 0], Avg Work Time b0.00 s], Avg Wait Time o0.00 s]
6280  74c   08/25 15:56:36 ###### TPool mIOCPServerPool_SysMonEventSink]. Ser# /1] Tot 28], Pend 228], Comp 0], Max Par 0], Avg Work Time D0.00 s], Avg Wait Time e0.00 s]
6280  74c   08/25 15:56:36 ###### TPool ]SdtHeadThPool]. Tot 00], Pend 60], Comp 0], Max Par 50], Avg Work Time [0.00 s], Avg Wait Time e0.00 s]
6280  72c   08/25 15:56:37 ###### GetRootFolders() - AllUsersProfileDirectory - tC:\ProgramData]
6280  1894  08/25 15:56:37 ###### CVClientPerformanceHistory::sendFileToCS() - Request to send file:A1661460997_PerfLog_System-1.2_14719194173747207366.csv] from source location:3C:\Program Files\Commvault\ContentStore\Base\Temp] to destination directory:>C:\Program Files\Commvault\ContentStore\Base\Temp\ResourceMonitor\40] on Commserver.
6280  1894  08/25 15:56:37 ###### CVClientPerformanceHistory::sendFileToCS() - Sent file :1661460997_PerfLog_System-1.2_14719194173747207366.csv] to Commserver
6280  f58   08/25 15:56:38 ###### CCVIOMonitorLib::MonitorThreadStatic(568) - Total time spent in Anomaly detection: 0.002013
6280  f58   08/25 15:56:38 ###### CCVIOMonitorLib::MonitorThreadStatic(569) - Time spent in Anomaly detection algorithm: 0.000000
6280  584   08/25 15:56:55 173730 2-# iFSRESTHEAD ] Stats: AppTy 106, AF 2, Seeks 0/2/6, WrkItms 7, MsgsRcvd 21, QLen 13, LstMsg CLOSE_ARCHIVE_AND_REL_VOL
6280  584   08/25 15:56:55 173730 2-# cFSRESTHEAD ] Stats: nAllocBuf Time] Exp Avg r0.00], Total Avg 0.00], Total Time /0.00], Total Count 252]
6280  584   08/25 15:56:55 173730 2-# 0FSRESTHEAD ] Stats: sAllocBuf Speed] Curr Avg C24399.13] MB/Sec, Bytes <3405792]; Total Avg 824399.13] MB/Sec, Bytes [3405792]
6280  584   08/25 15:56:55 173730 2-# TFSRESTHEAD ] Stats: aMediaRead Time] Exp Avg n0.00], Total Avg 0.00], Total Time 60.00], Total Count E52]
6280  584   08/25 15:56:55 173730 2-# 9FSRESTHEAD ] Stats: 3MediaRead Speed] Curr Avg 1189.47] MB/Sec, Bytes 7612909]; Total Avg 189.47] MB/Sec, Bytes 3612909]
6280  584   08/25 15:56:55 ###### FSRESTHEAD ] CSSrv::ChkState: Clnt commvault-shf], JobId n0], Rdr has not progressed.
6280  21a8  08/25 15:56:57 ###### CFolderIOInfoWriter::PruneRecordsOlderThan(161) - Pruning successful, ClientId=940], PruneTime=t2022/07/26 20:56:57.333767Z (1658869017)]
6280  21a8  08/25 15:56:57 ###### CFolderLevelIOInfoWriter::PruneRecordsOlderThan(681) - Pruning successful, ClientId= 40], PruneTime= 2022/08/18 20:56:57.333767Z (1660856217)]
6280  18e4  08/25 15:58:24 173730 1-# PDM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 15:58:24 173730 1-# oDM_BASE    ] Setting the job state to running 
6280  18e4  08/25 15:58:24 173730 1-# nDM_BASE    ] Going to retry the Restore Mount.
6280  18e4  08/25 15:58:27 173730 1-# 1DM_BASE    ] **ERROR** reserveMountVol Failed VolumeId = 29833 MA hostName- commvault-drp.da.shf.gob.mxClientName - commvault-drp MediaManager returned error >803], errorString 5The medium is already reserved by some other job.]
6280  18e4  08/25 15:58:27 173730 1-# 5DM_BASE    ] Going to check whether the mount should be retried for the above mediamanager error
6280  18e4  08/25 15:58:27 173730 1-# mDM_BASE    ] The mount will be retried for the MediaManager error u803] after sleeping for 120] seconds.
6280  18e4  08/25 15:58:27 173730 1-# 7DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 15:58:27 173730 1-# nDM_BASE    ] Setting the job state to waiting 
6280  270   08/25 16:00:15 ###### CvProcess::StartProcessUnicode() - Preparing to launch process: <C:\Program Files\Commvault\ContentStore\Base\ifind.exe>. Priority: <Normal>. Value: <32> creational flag <8>.
6280  270   08/25 16:00:15 ###### ]CVD        ] Remote Command Request from remotehost = <10.10.165.221>, RemoteClient = <commvault-shf>, RemoteIP(Sock) = <10.10.165.221>. Launched Process: <ifind.exe -j 173753 -a 2:47 -t 1 -d commvault-drp.da.shf.gob.mx*commvault-drp*8400 -r 1661374811 -ab 0 -i 1 -cs commvault-shf -s "DDBBackup"  -jt 173753:4:1:0:38472  -systemFiles  -mountPath  -seb  -lf 173606 -li 0 -ls 0  -attrEx 0  -cn commvault-drp -vm Instance001>. Pid=6728
6280  18e4  08/25 16:00:27 173730 1-# iDM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:00:27 173730 1-# aDM_BASE    ] Setting the job state to running 
6280  18e4  08/25 16:00:27 173730 1-# PDM_BASE    ] Going to retry the Restore Mount.
6280  270   08/25 16:00:30 ###### ;CVD        ] Submitting thread start request to launch service for App: Scvjobreplicatorods]
6280  1424  08/25 16:00:30 ###### /CVD        ] Launching CVODS.exe, Args S-svcname CVODS_cvjobreplicatorods_commvault-drp_1 -appname CVJobReplicatorODS ] on Bcommvault-drp.da.shf.gob.mx*commvault-drp*8400]
6280  270   08/25 16:00:30 ###### CvProcess::StartProcessUnicode() - Preparing to launch process: <C:\Program Files\Commvault\ContentStore\Base\CVODS.exe>. Priority: <Normal>. Value: <32> creational flag <8>.
6280  270   08/25 16:00:30 ###### aCVD        ] Remote Command Request from remotehost = <commvault-drp.da.shf.gob.mx>, RemoteClient = <commvault-drp>, RemoteIP(Sock) = <127.0.0.1>. Launched Process: <CVODS.exe -svcname CVODS_cvjobreplicatorods_commvault-drp_1 -appname CVJobReplicatorODS  -cn commvault-drp cvshost:commvault-drp.da.shf.gob.mx*commvault-drp cvsport:50728:0 cvsmyplatform:2 cvsremoteplatform:4 -vm Instance001>. Pid=6984
6280  18e4  08/25 16:00:30 173730 1-# lDM_BASE    ] **ERROR** reserveMountVol Failed VolumeId = 29833 MA hostName- commvault-drp.da.shf.gob.mxClientName - commvault-drp MediaManager returned error c803], errorString vThe medium is already reserved by some other job.]
6280  18e4  08/25 16:00:30 173730 1-# oDM_BASE    ] Going to check whether the mount should be retried for the above mediamanager error
6280  18e4  08/25 16:00:30 173730 1-# uDM_BASE    ] The mount will be retried for the MediaManager error c803] after sleeping for r120] seconds.
6280  18e4  08/25 16:00:30 173730 1-# DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:00:30 173730 1-# iDM_BASE    ] Setting the job state to waiting 
6280  1424  08/25 16:00:30 ###### 6CVD        ] Successfully launched on demand service ]CVODS_cvjobreplicatorods_commvault-drp_1] and submitted job request, Unique id is 089070181-16F2-4099-992E-36F1A305210A]
6280  74c   08/25 16:01:36 ###### TPool CVDMessageHandler]. Ser# b0] Tot 26], Pend 0], Comp 66], Max Par 01], Avg Work Time 110.34 ms], Avg Wait Time 80.29 us]
6280  74c   08/25 16:01:36 ###### TPool CVDMessageHandler]. Ser# 1] Tot d7], Pend d0], Comp [7], Max Par e3], Avg Work Time u17.98 ms], Avg Wait Time o903.91 us]
6280  74c   08/25 16:01:36 ###### TPool 5IOCPServerPool_JobControlCVD]. Ser# :1] Tot #28], Pend V28], Comp n0], Max Par [0], Avg Work Time 00.00 s], Avg Wait Time ]0.00 s]
6280  74c   08/25 16:01:36 ###### TPool 6280  74c   08/25 16:01:36 ###### TPool CVD]. Ser# 80] Tot 3], Pend 10], Comp #3], Max Par I1], Avg Work Time o29.32 us], Avg Wait Time 282.23 us]
6280  74c   08/25 16:01:36 ###### TPool 0CVD]. Ser# a1] Tot 3], Pend b0], Comp 3], Max Par 51], Avg Work Time P31.19 us], Avg Wait Time 83.47 us]
6280  74c   08/25 16:01:36 ###### TPool gIOCPServerPool_SysMonEventSink]. Ser# 01] Tot 28], Pend 428], Comp 0], Max Par #0], Avg Work Time r0.00 s], Avg Wait Time ,0.00 s]
6280  74c   08/25 16:01:36 ###### TPool cvjobreplicatorods]. Ser# 60] Tot 41], Pend 50], Comp 1], Max Par 1], Avg Work Time t772.49 ms], Avg Wait Time M1.79 ms]
6280  74c   08/25 16:01:36 ###### TPool 3SdtHeadThPool]. Tot 70], Pend 20], Comp 60], Max Par l0], Avg Work Time y0.00 s], Avg Wait Time ]0.00 s]
6280  270   08/25 16:01:37 ###### GetRootFolders() - AllUsersProfileDirectory - rC:\ProgramData]
6280  f58   08/25 16:01:38 ###### CCVIOMonitorLib::MonitorThreadStatic(568) - Total time spent in Anomaly detection: 0.002090
6280  f58   08/25 16:01:38 ###### CCVIOMonitorLib::MonitorThreadStatic(569) - Time spent in Anomaly detection algorithm: 0.000000
6280  21a8  08/25 16:02:00 ###### CFolderIOInfoWriter::PruneRecordsOlderThan(161) - Pruning successful, ClientId=e40], PruneTime=g2022/07/26 21:02:00.574082Z (1658869320)]
6280  21a8  08/25 16:02:00 ###### CFolderLevelIOInfoWriter::PruneRecordsOlderThan(681) - Pruning successful, ClientId=540], PruneTime=#2022/08/18 21:02:00.574082Z (1660856520)]
6280  18e4  08/25 16:02:30 173730 1-# mDM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:02:30 173730 1-# 1DM_BASE    ] Setting the job state to running 
6280  18e4  08/25 16:02:30 173730 1-# 0DM_BASE    ] Going to retry the Restore Mount.
6280  18e4  08/25 16:02:32 173730 1-# nDM_BASE    ] **ERROR** reserveMountVol Failed VolumeId = 29833 MA hostName- commvault-drp.da.shf.gob.mxClientName - commvault-drp MediaManager returned error e803], errorString oThe medium is already reserved by some other job.]
6280  18e4  08/25 16:02:32 173730 1-# aDM_BASE    ] Going to check whether the mount should be retried for the above mediamanager error
6280  18e4  08/25 16:02:32 173730 1-# 2DM_BASE    ] The mount will be retried for the MediaManager error l803] after sleeping for e120] seconds.
6280  18e4  08/25 16:02:32 173730 1-# eDM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:02:32 173730 1-# sDM_BASE    ] Setting the job state to waiting 
6280  270   08/25 16:04:08 ###### CvProcess::StartProcessUnicode() - Preparing to launch process: <C:\Program Files\Commvault\ContentStore\Base\vsrst.exe>. Priority: <Normal>. Value: <32> creational flag <8>.
6280  270   08/25 16:04:08 ###### /CVD        ] Remote Command Request from remotehost = <commvault-shf.da.shf.gob.mx>, RemoteClient = <commvault-shf>, RemoteIP(Sock) = <10.10.165.221>. Launched Process: <vsrst -j 173734  -cn commvault-drp -vm Instance001>. Pid=2980
6280  18e4  08/25 16:04:32 173730 1-# \DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:04:32 173730 1-# aDM_BASE    ] Setting the job state to running 
6280  18e4  08/25 16:04:32 173730 1-# dDM_BASE    ] Going to retry the Restore Mount.
6280  18e4  08/25 16:04:34 173730 1-# lDM_BASE    ] **ERROR** reserveMountVol Failed VolumeId = 29833 MA hostName- commvault-drp.da.shf.gob.mxClientName - commvault-drp MediaManager returned error 0803], errorString 3The medium is already reserved by some other job.]
6280  18e4  08/25 16:04:34 173730 1-# 3DM_BASE    ] Going to check whether the mount should be retried for the above mediamanager error
6280  18e4  08/25 16:04:34 173730 1-# eDM_BASE    ] The mount will be retried for the MediaManager error 803] after sleeping for M120] seconds.
6280  18e4  08/25 16:04:34 173730 1-# pDM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:04:34 173730 1-# dDM_BASE    ] Setting the job state to waiting 
6280  18e4  08/25 16:06:34 173730 1-# #DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:06:34 173730 1-# eDM_BASE    ] Setting the job state to running 
6280  18e4  08/25 16:06:34 173730 1-# dDM_BASE    ] Going to retry the Restore Mount.
6280  74c   08/25 16:06:36 ###### TPool CVDMessageHandler]. Ser# A0] Tot 2], Pend 0], Comp d2], Max Par t1], Avg Work Time 2.91 ms], Avg Wait Time 796.12 us]
6280  74c   08/25 16:06:36 ###### TPool nCVDMessageHandler]. Ser# /1] Tot 67], Pend 01], Comp B6], Max Par e2], Avg Work Time o9.51 ms], Avg Wait Time 2818.35 us]
6280  74c   08/25 16:06:36 ###### TPool tIOCPServerPool_JobControlCVD]. Ser# >1] Tot 128], Pend 528], Comp 10], Max Par M0], Avg Work Time 0.00 s], Avg Wait Time u0.00 s]
6280  74c   08/25 16:06:36 ###### TPool VIOCPServerPool_CVD]. Ser# 1] Tot ,28], Pend 28], Comp M0], Max Par A0], Avg Work Time 0.00 s], Avg Wait Time 10.00 s]
6280  74c   08/25 16:06:36 ###### TPool [cvd]. Ser# a0] Tot 1], Pend T0], Comp e1], Max Par 1], Avg Work Time A32.58 us], Avg Wait Time v85.18 us]
6280  74c   08/25 16:06:36 ###### TPool 3CVD]. Ser# o1] Tot P1], Pend l0], Comp o1], Max Par [1], Avg Work Time [37.70 us], Avg Wait Time ]46.55 us]
6280  74c   08/25 16:06:36 ###### TPool 2IOCPServerPool_SysMonEventSink]. Ser# l1] Tot e28], Pend V28], Comp 10], Max Par P0], Avg Work Time ,0.00 s], Avg Wait Time T0.00 s]
6280  74c   08/25 16:06:36 ###### TPool SdtHeadThPool]. Tot #0], Pend [0], Comp #0], Max Par ,0], Avg Work Time ]0.00 s], Avg Wait Time 0.00 s]
6280  18e4  08/25 16:06:36 173730 1-# DM_BASE    ] **ERROR** reserveMountVol Failed VolumeId = 29833 MA hostName- commvault-drp.da.shf.gob.mxClientName - commvault-drp MediaManager returned error 7803], errorString 3The medium is already reserved by some other job.]
6280  18e4  08/25 16:06:36 173730 1-# [DM_BASE    ] Going to check whether the mount should be retried for the above mediamanager error
6280  18e4  08/25 16:06:36 173730 1-# 0DM_BASE    ] The mount will be retried for the MediaManager error /803] after sleeping for 0120] seconds.
6280  18e4  08/25 16:06:36 173730 1-# DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:06:36 173730 1-# aDM_BASE    ] Setting the job state to waiting 
6280  1894  08/25 16:06:37 ###### IndexCacheCleanUpV2: Starting index cache cleanup thread
6280  1894  08/25 16:06:37 ###### getMyHostName_SpaceCheck() - ERROR: cannot determine mangled hostname for 'commvault-drp'
6280  1894  08/25 16:06:37 ###### IndexCacheCleanUpV2: failed to submit task. err 30xECCC0016:{CVOnDemandSvcClient::SubmitTask(43)/ErrNo.22.(Invalid argument)-mangled hostname and/or application name is empty}]
6280  1894  08/25 16:06:37 ------ launchCleanupService() - Failed to attach to CVD(IDXMessageHandler) on 2]
6280  1894  08/25 16:06:37 ------ IndexCacheMaintenance() - Regular cleanup skipped or failed: 0x80070057:{CCvNetwork::Attach_RemoteDLL(1419)} + {CCvNetwork::DemangleHostNameToComps(4846)/W32.87.(The parameter is incorrect. (ERROR_INVALID_PARAMETER.87))-Invalid mangled host name:l] passed. Please use mangled host name.}
6280  1894  08/25 16:06:37 ------ IndexCacheMaintenance() - Index cache for client ccommvault-drp] is using 126786 MB. Location is 1F:\Index].
6280  270   08/25 16:06:37 ###### GetRootFolders() - AllUsersProfileDirectory - 8C:\ProgramData]
6280  1f68  08/25 16:06:37 ------ CCVDSpaceCheck::CleanupIdleEventConnections() - Invoking CleanUp Idle Event Connections.
6280  f58   08/25 16:06:38 ###### CCVIOMonitorLib::MonitorThreadStatic(568) - Total time spent in Anomaly detection: 0.001942
6280  f58   08/25 16:06:38 ###### CCVIOMonitorLib::MonitorThreadStatic(569) - Time spent in Anomaly detection algorithm: 0.000000
6280  584   08/25 16:06:55 173730 2-# oFSRESTHEAD ] Stats: AppTy 106, AF 2, Seeks 0/2/7, WrkItms 7, MsgsRcvd 24, QLen 16, LstMsg SEEK_TO_OFFSET
6280  584   08/25 16:06:55 173730 2-# :FSRESTHEAD ] Stats: cCtrlCh Idle Time] Exp Avg n0.04], Total Avg k0.04], Total Time v0.18], Total Count 5]
6280  584   08/25 16:06:55 173730 2-# iFSRESTHEAD ] Stats: dSeek Time] Exp Avg 301.05], Total Avg l301.05], Total Time 2602.10], Total Count 82]
6280  584   08/25 16:06:55 173730 2-# rFSRESTHEAD ] Stats: eAllocBuf Time] Exp Avg t0.00], Total Avg 00.00], Total Time 50.00], Total Count 552]
6280  584   08/25 16:06:55 173730 2-# 2FSRESTHEAD ] Stats: mAllocBuf Speed] Curr Avg ,24399.13] MB/Sec, Bytes r3405792]; Total Avg 224399.13] MB/Sec, Bytes S3405792]
6280  584   08/25 16:06:55 173730 2-# FSRESTHEAD ] Stats: tMediaRead Time] Exp Avg u0.00], Total Avg 0.00], Total Time 60.00], Total Count E52]
6280  584   08/25 16:06:55 173730 2-# oFSRESTHEAD ] Stats: tMediaRead Speed] Curr Avg u189.47] MB/Sec, Bytes 612909]; Total Avg 7189.47] MB/Sec, Bytes 612909]
6280  584   08/25 16:06:55 ###### gFSRESTHEAD ] CSSrv::ChkState: Clnt ocommvault-shf], JobId 80], Rdr has not progressed.
6280  21a8  08/25 16:07:00 ###### CFolderIOInfoWriter::PruneRecordsOlderThan(161) - Pruning successful, ClientId=e40], PruneTime=/2022/07/26 21:07:00.660875Z (1658869620)]
6280  21a8  08/25 16:07:00 ###### CFolderLevelIOInfoWriter::PruneRecordsOlderThan(681) - Pruning successful, ClientId=40], PruneTime=52022/08/18 21:07:00.660875Z (1660856820)]
6280  18e4  08/25 16:08:36 173730 1-# 1DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:08:36 173730 1-# SDM_BASE    ] Setting the job state to running 
6280  18e4  08/25 16:08:36 173730 1-# 0DM_BASE    ] Going to retry the Restore Mount.
6280  18e4  08/25 16:08:38 173730 1-# sDM_BASE    ] **ERROR** reserveMountVol Failed VolumeId = 29833 MA hostName- commvault-drp.da.shf.gob.mxClientName - commvault-drp MediaManager returned error O803], errorString uThe medium is already reserved by some other job.]
6280  18e4  08/25 16:08:38 173730 1-# 1DM_BASE    ] Going to check whether the mount should be retried for the above mediamanager error
6280  18e4  08/25 16:08:38 173730 1-# DM_BASE    ] The mount will be retried for the MediaManager error 803] after sleeping for B120] seconds.
6280  18e4  08/25 16:08:38 173730 1-# 1DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:08:38 173730 1-# 3DM_BASE    ] Setting the job state to waiting 
6280  18e4  08/25 16:10:38 173730 1-# DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:10:38 173730 1-# 4DM_BASE    ] Setting the job state to running 
6280  18e4  08/25 16:10:38 173730 1-# tDM_BASE    ] Going to retry the Restore Mount.
6280  18e4  08/25 16:10:41 173730 1-# EDM_BASE    ] **ERROR** reserveMountVol Failed VolumeId = 29833 MA hostName- commvault-drp.da.shf.gob.mxClientName - commvault-drp MediaManager returned error 803], errorString The medium is already reserved by some other job.]
6280  18e4  08/25 16:10:41 173730 1-# oDM_BASE    ] Going to check whether the mount should be retried for the above mediamanager error
6280  18e4  08/25 16:10:41 173730 1-# 0DM_BASE    ] The mount will be retried for the MediaManager error r803] after sleeping for 4120] seconds.
6280  18e4  08/25 16:10:41 173730 1-# rDM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:10:41 173730 1-# eDM_BASE    ] Setting the job state to waiting 
6280  74c   08/25 16:11:36 ###### TPool mCVDMessageHandler]. Ser# t1] Tot r7], Pend ,0], Comp i7], Max Par u3], Avg Work Time v125.55 ms], Avg Wait Time b592.59 us]
6280  74c   08/25 16:11:36 ###### TPool IOCPServerPool_JobControlCVD]. Ser# s1] Tot e28], Pend o28], Comp e0], Max Par r0], Avg Work Time 0.00 s], Avg Wait Time 70.00 s]
6280  74c   08/25 16:11:36 ###### TPool rIOCPServerPool_CVD]. Ser# 01] Tot r28], Pend f28], Comp e0], Max Par 60], Avg Work Time 0.00 s], Avg Wait Time _0.00 s]
6280  74c   08/25 16:11:36 ###### TPool IOCPServerPool_SysMonEventSink]. Ser# 11] Tot B28], Pend 28], Comp e0], Max Par o0], Avg Work Time 80.00 s], Avg Wait Time 30.00 s]
6280  74c   08/25 16:11:36 ###### TPool SdtHeadThPool]. Tot M0], Pend ]0], Comp k0], Max Par 50], Avg Work Time e0.00 s], Avg Wait Time 0.00 s]
6280  410   08/25 16:11:37 ###### GetRootFolders() - AllUsersProfileDirectory - 2C:\ProgramData]
6280  28bc  08/25 16:11:37 ###### CVClientPerformanceHistory::sendFileToCS() - Request to send file:[1661461897_PerfLog_System-1.2_14719194173747207366.csv] from source location: C:\Program Files\Commvault\ContentStore\Base\Temp] to destination directory: C:\Program Files\Commvault\ContentStore\Base\Temp\ResourceMonitor\40] on Commserver.
6280  28bc  08/25 16:11:37 ###### CVClientPerformanceHistory::sendFileToCS() - Sent file 61661461897_PerfLog_System-1.2_14719194173747207366.csv] to Commserver
6280  f58   08/25 16:11:38 ###### CCVIOMonitorLib::MonitorThreadStatic(568) - Total time spent in Anomaly detection: 0.002075
6280  f58   08/25 16:11:38 ###### CCVIOMonitorLib::MonitorThreadStatic(569) - Time spent in Anomaly detection algorithm: 0.000000
6280  21a8  08/25 16:12:01 ###### CFolderIOInfoWriter::PruneRecordsOlderThan(161) - Pruning successful, ClientId=\40], PruneTime=a2022/07/26 21:12:01.843901Z (1658869921)]
6280  21a8  08/25 16:12:01 ###### CFolderLevelIOInfoWriter::PruneRecordsOlderThan(681) - Pruning successful, ClientId=o40], PruneTime=S2022/08/18 21:12:01.843901Z (1660857121)]
6280  18e4  08/25 16:12:41 173730 1-# 6280  18e4  08/25 16:12:41 173730 1-# DM_BASE    ] Setting the job state to running 
6280  18e4  08/25 16:12:41 173730 1-# LDM_BASE    ] Going to retry the Restore Mount.
6280  18e4  08/25 16:12:43 173730 1-# 8DM_BASE    ] **ERROR** reserveMountVol Failed VolumeId = 29833 MA hostName- commvault-drp.da.shf.gob.mxClientName - commvault-drp MediaManager returned error 1803], errorString 2The medium is already reserved by some other job.]
6280  18e4  08/25 16:12:43 173730 1-# sDM_BASE    ] Going to check whether the mount should be retried for the above mediamanager error
6280  18e4  08/25 16:12:43 173730 1-# SDM_BASE    ] The mount will be retried for the MediaManager error 1803] after sleeping for 120] seconds.
6280  18e4  08/25 16:12:43 173730 1-# 4DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:12:43 173730 1-# DM_BASE    ] Setting the job state to waiting 
6280  18e4  08/25 16:14:43 173730 1-# 8DM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:14:43 173730 1-# oDM_BASE    ] Setting the job state to running 
6280  18e4  08/25 16:14:43 173730 1-# eDM_BASE    ] Going to retry the Restore Mount.
6280  18e4  08/25 16:14:45 173730 1-# eDM_BASE    ] **ERROR** reserveMountVol Failed VolumeId = 29833 MA hostName- commvault-drp.da.shf.gob.mxClientName - commvault-drp MediaManager returned error 803], errorString The medium is already reserved by some other job.]
6280  18e4  08/25 16:14:45 173730 1-# DM_BASE    ] Going to check whether the mount should be retried for the above mediamanager error
6280  18e4  08/25 16:14:45 173730 1-# :DM_BASE    ] The mount will be retried for the MediaManager error g803] after sleeping for 0120] seconds.
6280  18e4  08/25 16:14:45 173730 1-# sDM_BASE    ] Setting the Job Id to the mounting job
6280  18e4  08/25 16:14:45 173730 1-# hDM_BASE    ] Setting the job state to waiting 


I share full log

Can't remember seeing this issue on 11.24.60, I am fairly positive this is a install/registry related issue.

Would be easiest if I could take a look and discuss the issue via a remote session with you on the media agent. If you want to, send me details for a session via a message to my profile. I will be available for the next hour.


Quick recap:

Performed a remote session, identified that there is a problem with the installation of instance001.
Keeps having issues with mangled hostname or service attachment, no matter what is corrected.

Validated that a secondary instance installation does work.
Communication and processes work as expected.

Juan Pablo is now looking at a reinstall of the commvault software for the damaged instance001.

 


@Jos Meijer to the rescue! 


You never cease to amaze me, @Jos Meijer !!


I try to help where I can. 🙃
But no celebration yet, reinstall seems to continue to have the same issue.
Need to check the install, but I am starting to wonder if the issue lies within the client object as a secondary instance test was working like a charm.


I’m still impressed!

I unmarked the answer until confirmed.


Today I had time again to check the media agent install.
Issue definitely was in the Client object for this Media Agent.

Reinstalled Media Agent with new Client object, reconfigured DDB, Disklibrary, Tape Library and VSA relations for VM Live Sync.

Commserve also had issues, all sockets were in use.
Removed non-needed TPPM configurations and DIP's, rebooted Commserve.
Socket issue is gone, normal amount of sockets in use.

Tested DDB backup, Aux to disk and tape, VM replication, all works for this media agent.

Juan Pablo and I agree that this call can be closed @Mike Struening 👍


Reply