When performing the increment backup of VMware virtual machines and this message always appear.
Any ideas ?
vsbkp.log
“47004 e040 07/21 08:47:13 430196 = vsbkp [BACKUP PHASE] has started vsbkp.exe -j 430196 -a 2:15 -t 2 -ref 1591261924 -i 2 -d pbackup*pbackup*8400 -io 0 -jt 430196:4:1:0:0:44607 -idxma pbackup*pbackup*8400 -numstreams 1 -cn pbackup -vm Instance001
47004 e040 07/21 08:47:13 430196 ================================================================
47004 e040 07/21 08:47:13 430196 CVMDiskInfo::GetVDDKInstallPath() - Using vStorage VDDK from [C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK673] version [6.7.3 build-14389676]
47004 e040 07/21 08:47:13 430196 CVMDiskInfo::LoadVDDKLibrary() - Successfully loaded VDDK Lib (libeay32.dll) from C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK673\bin\libeay32.dll
47004 e040 07/21 08:47:13 430196 CVMDiskInfo::LoadVDDKLibrary() - Successfully loaded VDDK Lib (ssleay32.dll) from C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK673\bin\ssleay32.dll
47004 e040 07/21 08:47:13 430196 CVMDiskInfo::LoadVDDKLibrary() - Successfully loaded VDDK Lib (libldap_r.dll) from C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK673\bin\libldap_r.dll
47004 e040 07/21 08:47:13 430196 CVMDiskInfo::LoadVDDKLibrary() - Successfully loaded VDDK Lib (libcurl.dll) from C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK673\bin\libcurl.dll
47004 5e0c 07/21 08:47:13 430196 CVDTerminationHandler::_WaitForCVDTermination() - Waiting for CVD Termination
47004 e040 07/21 08:47:13 430196 VSBkpApp::Initialize() - Initializing Job manager object
47004 e040 07/21 08:47:13 430196 JM Client CVJobClient::initialize(): Got remote host [pbackup].
47004 e040 07/21 08:47:13 430196 JM Client CVBkpJobClient::init(): Initializing job object with token [430196:4:1:0:0:44607].
47004 e040 07/21 08:47:13 430196 vsJobMgr::_initBackup() - Backup Level [Incr]
47004 e040 07/21 08:47:13 430196 DBBase-SQL() - dbmethods.cpp:1425, DB Layer will use [Exec] access by default. Use SetAdminAccess API for on demand Admin access.
47004 e040 07/21 08:47:13 430196 Cvcl::init() - CVCL: Running in FIPS Mode
47004 e040 07/21 08:47:13 430196 DetectNativeClient() - Found reg key [SOFTWARE\Microsoft\Microsoft SQL Server\SQLNCLI11]. Using driver [SQL Server Native Client 11.0].
47004 e040 07/21 08:47:15 430196 vsJobMgr::LoadJobOptions() - Job Options: <?xml version='1.0' encoding='utf-8' ?><TMMsg_JobOption><backupOpts truncateLogsOnSource="0" sybaseSkipFullafterLogBkp="0" notSynthesizeFullFromPrevBackup="0" collectMetaInfo="0" backupLevel="2" incLevel="1" adHocBackup="0" runIncrementalBackup="0" isSpHasInLineCopy="0" runSILOBackup="0" doNotTruncateLog="0"><vsaBackupOptions backupFailedVMsOnly="0"/><dataOpt skipCatalogPhaseForSnapBackup="1" useCatalogServer="1" followMountPoints="1" enforceTransactionLogUsage="0" skipConsistencyCheck="0" granularrecovery="0" createNewIndex="0"/><mediaOpt><storagePolicy storagePolicyName="HPE_Nimble_Non"/></mediaOpt><dbBackupOptions maxDbBackupType="0"/></backupOpts><adminOpts><contentIndexingOption subClientBasedAnalytics="0"/></adminOpts><restoreOptions><virtualServerRstOption isBlockLevelReplication="0"/></restoreOptions><commonOpts notifyUserOnJobCompletion="0"><perfJobOpts/></commonOpts></TMMsg_JobOption>
47004 e040 07/21 08:47:15 430196 TaskInterfaceDB::getOptions() - Loading default options into memory
47004 e040 07/21 08:47:15 430196 Init() - Initializing job control [token=430196:4:1:0:0:44607,cn=pbackup], serverName [pbackup], ControlFlag [1], Job Id [430196]
47004 e040 07/21 08:47:16 430196 CVJobCtrlLog::registerProcess(): successfully created file [C:\Program Files\Commvault\ContentStore\Base\JobControl\47.004]
47004 e040 07/21 08:47:16 430196 isCCSDbEnabled() - Use CCSDb Enabled [0] IsCloudLaptop [0] IsFSCoreLaptop [0]
47004 e040 07/21 08:47:16 430196 vsAppMgr::querySettings() - CommCell Id [2] Number [82123797]
47004 e040 07/21 08:47:16 430196 vsAppMgr::querySettings() - Application Id [15]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrIds() - Subclient id = [15] [default]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrIds() - Client Id = [6] [vcsa.vsphere.local]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryPhysicalClientDetails() - Physical Client Id = [2] [pbackup]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrIds() - Instance id = [5] [VMware]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrIds() - Backup set id [13] [defaultBackupSet] [6F8B28AA-A1F2-40C5-99AE-51DE7718B5F5]
47004 e040 07/21 08:47:16 430196 vsAppMgr::querySettings() - IndexingV2 is Enabled
47004 e040 07/21 08:47:16 430196 vsAppMgr::querySettingsForInstance() - Instance type (101) 'VMware vCenter' [VMware]
47004 e040 07/21 08:47:16 430196 vsAppMgr::querySettingsForInstance() - Using VM Instance UUIDs
47004 e040 07/21 08:47:16 430196 vsAppMgr::LookupMangledHostName() - CVClient::getNetworkHostnameMangled() for client id [214] returned [fre*fre*8400*8402]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryFBRMA() - Found linux FBR Client Id = [214] [fre]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryPhysicalClientDetails() - Physical Client Id = [2] [pbackup]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryLocalHostName() - Name of the local machine: [pbackup]
47004 e040 07/21 08:47:16 430196 vsAppMgr::updateMemberServersList() - Member servers [pbackup] at level [5-INSTANCE_ENTITY]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - This is the DEFAULT subclient...
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - Allow Empty Subclient: [TRUE]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryDynamicContent() - VM Content: [<?xml version="1.0" encoding="UTF-8" standalone="no" ?><VirtualServer_VMSubClientEntity allOrAnyChildren="0"><children allOrAnyChildren="1" description="" displayName="catdbhanadev" equalsOrNotEquals="1" name="500d4f64-6259-f6ab-e911-cd6006b72c7e" path="catdbhanadev" type="9"/></VirtualServer_VMSubClientEntity>]
47004 e040 07/21 08:47:16 430196 vsAppMgr::GetSubClientFilters() - VM Filter: [<?xml version="1.0" encoding="UTF-8" standalone="no" ?><VirtualServer_VMSubClientEntity allOrAnyChildren="0"/>]
47004 e040 07/21 08:47:16 430196 vsAppMgr::GetSubClientFilters() - VM Disk Filter: [<?xml version="1.0" encoding="UTF-8" standalone="no" ?><EVGui_VMSubclientDiskFilterList/>]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - Max number of streams to used is [100]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - Transport Mode is [1] [san]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - Snap Info object for VMWare: [<?xml version='1.0' encoding='UTF-8'?><VirtualServer_VSSnapInfo><snapFailoverESXHosts val="10.44.4.184" /><vsInstance clientId="6" clientName="vcsa.vsphere.local" instanceName="VMware" appName="Virtual Server" instanceId="5" applicationId="106" /></VirtualServer_VSSnapInfo>]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - Proxy mount host for instance: [10.44.4.184]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - Quiesce File system [ON]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - Use Changed Block Tracking [ON]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - Datastore space values from App Manager:[10]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - Skip VM page file or Linux swap partition [ON]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - AutoDetect VM Owners [ON]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - Use Backupset Disk Filters [true]
47004 e040 07/21 08:47:16 430196 vsJobMgr::initBackupMetadaCollectionDefault() - IndexingV2 is enabled. Metadata collection is not supported.
47004 e040 07/21 08:47:16 430196 CVOnDemandSvcClient::SubmitTask() - On Demand service CVODS_vscleanup_pbackup_1 launched at host pbackup*pbackup*8400*8402. Unique ID is B7968261-9160-4977-98D8-E5200726C5BE
47004 e040 07/21 08:47:16 430196 CVOnDemandSvcClient::Attach() - Successfully attached to on Demand service CVODS_vscleanup_pbackup_1 launched at host pbackup*pbackup*8400*8402. Unique ID is B7968261-9160-4977-98D8-E5200726C5BE
47004 e040 07/21 08:47:16 430196 VSBkpDatastoreMonitor::Initialize() - Monitoring datastore for less than [1,073,741,824] bytes of freespace
47004 e040 07/21 08:47:16 430196 VSBkpCoordinator::Initialize() - vm collect file = [C:\Program Files\Commvault\ContentStore\iDataAgent\JobResults\CV_JobResults\iDataAgent\VirtualServerAgent\2\15\vmcollect_430196.cvf]
47004 e040 07/21 08:47:16 430196 JOBRESCACHEDIR: job 430196 creating 'C:\Program Files\Commvault\ContentStore\iDataAgent\JobResults\CV_JobResults\2\0\430196'
47004 e040 07/21 08:47:16 430196 VSBkpCoordinator::InitBackupResults() - Backup.out file created
47004 e040 07/21 08:47:16 430196 vsJobMgr::CheckForRestart() - Empty restart string
47004 e040 07/21 08:47:16 430196 VSBkpCoordinator::UpdateJobManagerVMList_Restart() - This is a new job
47004 e040 07/21 08:47:16 430196 vsJobMgr::updateVMBkpJobStatus() - Sending VM status for [1] virtual machines
47004 e040 07/21 08:47:20 430196 VSBkpCoordinator::UpdateJobManagerVMList_Initial() - catdbhanadev [500d4f64-6259-f6ab-e911-cd6006b72c7e] - Completed
47004 e040 07/21 08:47:20 430196 VSBkpCoordinator::calculateRequiredStreams() - There are [1] VMs and [1] Disks to be processed by a max of [100] streams
47004 e040 07/21 08:47:20 430196 VSBkpCoordinator::calculateRequiredStreams() - All the streams that are required have been allocated
47004 e040 07/21 08:47:20 430196 VSBkpCoordinator::InitStreams() - Streams will be distributed by agent resource percentage
47004 e040 07/21 08:47:20 430196 vsAppMgr::queryDataPathMediaAgents() - Found DataPath MediaAgents [pbackup]
47004 e040 07/21 08:47:20 430196 VSBkpCoordinator::AddAgent() - Adding [pbackup] as a local agent
47004 e040 07/21 08:47:20 430196 CVRemoteAgentServer::AddAgent() - Added Agent [pbackup]
47004 e040 07/21 08:47:20 430196 Thread pool monitor interval [300] seconds, Refresh interval [60] seconds
47004 e040 07/21 08:47:20 430196 CvRemoteFileCacheClient::GetDetailsFromCS() - Input of SP [<?xml version="1.0" encoding="UTF-8" standalone="no" ?><App_GetRFCDetailsReq RFCServerType="101" appGUID="858BEE7C-A5D3-4A46-A059-1899C45EB38F" archLogFileName="RFC_AFILE" commCellId="2" copyPrecedence="0" fetchUploadedFiles="0" getPrevRFCDetails="0" jobId="430196" runningJobId="0" uploadMode="1" useFailoverMA="0" useSnapJobId="1"/>]
47004 e040 07/21 08:47:20 430196 CvRemoteFileCacheClient::GetDetailsFromCS() - Result of SP [<?xml version='1.0' encoding='utf-8' ?><App_GetRFCDetailsResp jobId="0" aFileId="0" aGroupNumber="0" backupSetGUID="6F8B28AA-A1F2-40C5-99AE-51DE7718B5F5" appId="15" clientName_RFCServer="pbackup" hostName_RFCServer="pbackup" cvdPort_RFCServer="8400" evmgrcPort_RFCServer="0" commCellId="2" appGUID="858BEE7C-A5D3-4A46-A059-1899C45EB38F" isRFCServerSelectedFirstTime="1" uploadingJobId="430196"><prevRFCDetails aFileId="0" aGroupNumber="0" commCellId="0" jobId="0"/></App_GetRFCDetailsResp>]
47004 e040 07/21 08:47:20 430196 CVOnDemandSvcClient::SubmitTask() - On Demand service CVODS_remotefilecacheserver_pbackup_1 launched at host pbackup*pbackup*8400. Unique ID is FCA176F0-A5A7-4D04-896F-C7FF17C69126
47004 e040 07/21 08:47:20 430196 CVOnDemandSvcClient::Attach() - Successfully attached to on Demand service CVODS_remotefilecacheserver_pbackup_1 launched at host pbackup*pbackup*8400. Unique ID is FCA176F0-A5A7-4D04-896F-C7FF17C69126
47004 e040 07/21 08:47:20 430196 CvRemoteFileCacheClient::UploadFiles Uploaded file [C:\Program Files\Commvault\ContentStore\iDataAgent\JobResults\CV_JobResults\iDataAgent\VirtualServerAgent\2\15\vmcollect_430196.cvf.rfczip]
47004 e040 07/21 08:47:20 430196 vsJobMgr::setNumberOfVMsForProgressBar() - Number of VMs to use as reference for the progress bar [1]
47004 e040 07/21 08:47:20 430196 VSBkpCoordinator::Run() - Successfully set job's reference time [1658368040]
47004 e040 07/21 08:47:20 430196 CVMWareInfo::DetectLocalVMGuid() - Bios Serial Number [2102311XBKN0KC000186] UUID [FEF412EA-8446-AB61-EA11-C61F5E45E3AB]
47004 e040 07/21 08:47:20 430196 CVMWareInfo::CVMWareInfo() - VMInfo Focus:[Instance001] App:[vsbkp] JobId:[430196]
47004 e040 07/21 08:47:20 430196 CVMWareInfo::Connect() - Connecting to Url=[https://vcsa.vsphere.local/sdk] User=[Administrator@vsphere.local]
47004 e040 07/21 08:47:22 430196 CVIWrapper::Connect() - Connection successful with [https://vcsa.vsphere.local/sdk] [VMware vCenter Server 6.7.0 build-15129973]
47004 d1d0 07/21 08:47:22 430196 CVRemoteAgentServer::StartLocalAgent() - Starting Local Agent [pbackup]
47004 69f4 07/21 08:47:22 430196 CVRemoteAgentClient::ConnectToLocalServer() - Attaching back to local server
47004 69f4 07/21 08:47:22 430196 CVRemoteAgentClient::ConnectToLocalServer() - Attached to local server
47004 d1d0 07/21 08:47:22 430196 CVRemoteAgentServer::StartLocalAgent() - Started Agent [pbackup]
47004 69f4 07/21 08:47:22 430196 VSBkpController::OnAgentStarted() - Agent has started
47004 d1d0 07/21 08:47:22 430196 VSBkpCoordinator::OnAgentStarted() - Agent [pbackup] has started
47004 69f4 07/21 08:47:22 430196 CVMWareInfo::DetectLocalVMGuid() - Bios Serial Number [2102311XBKN0KC000186] UUID [FEF412EA-8446-AB61-EA11-C61F5E45E3AB]
47004 69f4 07/21 08:47:22 430196 CVMWareInfo::CVMWareInfo() - VMInfo Focus:[Instance001] App:[vsbkp] JobId:[430196]
47004 69f4 07/21 08:47:22 430196 CVMWareInfo::Connect() - Connecting to Url=[https://vcsa.vsphere.local/sdk] User=[Administrator@vsphere.local]
47004 69f4 07/21 08:47:22 430196 CVIWrapper::Connect() - Connection successful with [https://vcsa.vsphere.local/sdk] [VMware vCenter Server 6.7.0 build-15129973]
47004 69f4 07/21 08:47:22 430196 VMFSSanInfo::ReadVMFSInfo() - Magic # not found on VMFS partition read from 2097152, found 0x0 expected 0xc001d00d
47004 69f4 07/21 08:47:22 430196 VSController::GetLocalComputerInfo() - Detected 32 CPUs and 131072 MB of memory
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::OnMsgVMAgentStartup() - Agent [pbackup] has initialized
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::CalculateStreamLimitForAgent() - Agent [pbackup] stream limit is cpu bound to [320] streams
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::OnMsgVMAgentStartup() - Agent [pbackup] is running on a physical machine. Agent Address: [169.254.98.179, 10.44.4.180] Subnets: [169.254.0.0, 10.44.4.128]
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::OnMsgVMAgentStartup() - Agent [pbackup] has access to [38] san datastores
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::OnIdle_Starting() - All Agents have initialized
47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgReceived() - Message [VirtualServer_VMAgentInit] received from Server
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::DistributeVMsToAgents() - Adding VM [catdbhanadev] on [10.44.4.186] to Agent [pbackup] (San Datastore match)
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::DistributeVMsToAgents() - Agent [pbackup] has 1 VMs (1 static) 1 max streams
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::OrderVMPriorityList() - -= VM Priority List =-
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::DispatchVMLists() - Sending Static VM list to [pbackup] with [1] VMs
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::GiveVMsToAgent() - Sending [1] VMs to agent [pbackup]
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::GiveVMsToAgent() - Sending VM [catdbhanadev] to agent [pbackup]
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::DispatchStreams() - There are [1] streams to be dispatched
47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgReceived() - Message [VirtualServer_VMCollectList] received from Server
47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgVMCollectList() - Received [1] VMs
47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgVMCollectList() - Received VM [catdbhanadev]
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::UpdateStreamInfo() - Added StreamId = 2, RCID = 397563, ReservationId = 317490, MediaAgentId = 2, InUse = 0
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::DumpStreamInfo() - StreamId = 2, RCID = 397563, ReservationId = 317490, MediaAgent = [pbackup], Agent = [] [Available]
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::SelectAgentForStream() - Selecting agent [pbackup] for stream as it has [0] streams, [1] VMs remaining and is using 0% of its stream resources
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::GiveStreamToAgent() - Sending Stream Id [2] RCID [397563] to agent [pbackup]
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::ExchangeStreamReservationForClient() - Not Exchanging reservation on stream RCID [397563] as it is already reserved on [2][pbackup]
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::GiveStreamToAgent() - Number of streams allocated for the agent [pbackup] are [1]
47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgReceived() - Message [VirtualServer_VMBackupStream] received from Server
47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgVMBackupStream() - Received stream ID [2] RCID [397563], [1] available, [0] open
47004 b300 07/21 08:47:23 430196 VSBkpController::OpenStream() - Opening stream # [1] of [1] Stream Id [2] RCID [397563] ReservationId [317490] ClientId [2]
47004 b300 07/21 08:47:23 430196 CVArchive::Construct() - Constructing CVArchive Object. This=0000021F2FB99400
47004 b300 07/21 08:47:23 430196 CVArchive::Construct() - Enable CVArchive Big Buffer [true] [perf-update interval 600 seconds]
47004 b300 07/21 08:47:23 430196 JM Client CVJobClient::initialize(): Got remote host [pbackup].
47004 9f7c 07/21 08:47:23 430196 VSBkpWorker::WorkerThread() - Worker [0] started
47004 9f7c 07/21 08:47:23 430196 VSBkpController::_GetNextVM() - Returning VM [catdbhanadev]
47004 9f7c 07/21 08:47:23 430196 VSBkpWorker::WorkerThread() - Worker [0] Processing VM [0] [catdbhanadev]
47004 9f7c 07/21 08:47:23 430197 VSBkpWorker::ProcessVM Processing VM [catdbhanadev] AppId 158 using child job 430197 and parent job 430196
47004 9f7c 07/21 08:47:23 430196 CVMWareInfo::DetectLocalVMGuid() - Bios Serial Number [2102311XBKN0KC000186] UUID [FEF412EA-8446-AB61-EA11-C61F5E45E3AB]
47004 9f7c 07/21 08:47:23 430196 CVMWareInfo::CVMWareInfo() - VMInfo Focus:[Instance001] App:[vsbkp] JobId:[430196]
47004 9f7c 07/21 08:47:23 430196 CVMWareInfo::Connect() - Connecting to Url=[https://vcsa.vsphere.local/sdk] User=[Administrator@vsphere.local]
47004 b300 07/21 08:47:23 430196 CVArchive::LookupPipelineInfo() - Incoming SIDBStoreId: 0
47004 b300 07/21 08:47:23 430196 CVArchive::getPipelineMode() - Using default pipeline mode [SDT] for [Bkp] pipe
47004 b300 07/21 08:47:23 430196 CVArchive::LookupPipelineInfo() - New block alignment enabled for this client
47004 9f7c 07/21 08:47:23 430196 CVIWrapper::Connect() - Connection successful with [https://vcsa.vsphere.local/sdk] [VMware vCenter Server 6.7.0 build-15129973]
47004 b300 07/21 08:47:23 430196 CVSingleInstTarget[0] singleInstLvl[0] sigWhere[0] sigScheme[0] singleInstMinObjSizeKB[0] compressWhere[0] encType[0] rsaKeys[0] Flag[103] rsrcConsumerId[397563] CloudLaptopClnt[0]
47004 9f7c 07/21 08:47:23 430196 vsJobMgr::updateVMBkpJobStatus() - Sending VM status for [1] virtual machines
47004 b300 07/21 08:47:23 430196 Configuring Compression for DataType 1
47004 b300 07/21 08:47:23 430196 CVArchive::ConfigureBlockAlignment() - Block alignment is not supported for this iDA (m_appType=106)
47004 b300 07/21 08:47:23 430196 Configuring Encryption for DataType 1
47004 b300 07/21 08:47:23 430196 Current pipeline module configuration: compression [0][CV_COMPRESS_SOURCE], signature [0][CV_SIGNATURE_NOWHERE] and encryption [0][CV_ENCRYPT_NOWHERE]
47004 b300 07/21 08:47:23 430196 N/w agents configured before/after firewall check = [2/2]. Firewalled = 0
47004 b300 07/21 08:47:23 430196 CVArchive::StartPipeline() - StartPipeline SI configuration -[srcClientName - pbackup] Block Level [false], Block Size [128], File Level [false], Min Signature Size [0]
47004 b300 07/21 08:47:23 430196 CPipelayer::InitiatePipeline Initiating SDT connection [0000021F49011A10] from pbackup:8400(pbackup) to pbackup:8400(pbackup)
47004 b300 07/21 08:47:23 430196 CPipelayer::InitiatePipeline compressionType [CV_COMPRESS], compressWhere [CV_COMPRESS_SOURCE]
47004 b300 07/21 08:47:23 430196 CPipelayer::InitiatePipeline encryptionType [CV_NO_ENCRYPT], encryptionWhere [CV_ENCRYPT_NOWHERE]
47004 b300 07/21 08:47:23 430196 CPipelayer::InitiatePipeline signatureType [CV_NO_SIGNATURE], signatureWhere [CV_SIGNATURE_NOWHERE]
47004 b300 07/21 08:47:23 430196 CPipelayer::InitiatePipeline Lan-Free - 1
47004 b300 07/21 08:47:23 430196 CPipelayer::InitiatePipeline Num Buffers [90], Buffer size [65536]
47004 b300 07/21 08:47:23 430196 CvFwClient::connectDirectly(): Connected to pbackup:8400/8400 using direct system connect
47004 b300 07/21 08:47:23 430196 CPipelayer::connectToDest Connected pipeline to (pbackup)pbackup:8400/8400, ConType 1 (Direct), Proxy []
47004 b300 07/21 08:47:23 430196 CPipelayer::InitiatePipeline SDT is using socket 3280 for connection 1/2
47004 b300 07/21 08:47:23 430196 CPipelayer::InitiatePipeline SDT Pipeline ID is [SDTPipe_pbackup_pbackup_430196_1658368043_47004_45824_0000021F49011A10]
47004 b300 07/21 08:47:23 430196 SdtNetLink() - WAN Padding is OFF
47004 b300 07/21 08:47:23 ###### Single Threaded Head [false]
47004 b300 07/21 08:47:23 430196 SdtBase::cfgComp() - LZO init retVal [0]. Spill buf size [2048] bytes
47004 b300 07/21 08:47:23 430196 SdtNetLink::setSocket() - Switching socket 3280 to non-blocking mode.
47004 8e9c 07/21 08:47:23 430196 JobStatusWorker Setting proxy Connection stats for job: [<?xml version="1.0" encoding="UTF-8" standalone="no" ?><CNSession_cvsJobNetworkInfo jobId="430196" mangledHostname="pbackup*pbackup*8400"><networkInfo connectionType="1" proxy=""/></CNSession_cvsJobNetworkInfo>]
47004 b300 07/21 08:47:23 430196 SdtNetLink::authenticate() - Connection authenticated successfully
47004 b300 07/21 08:47:23 ###### Object hash type set to 0
47004 b300 07/21 08:47:23 ###### SdtBase::InitWrkPool: Initializing SDT head thread pool
47004 b300 07/21 08:47:23 ###### Max head thread count set to 32. CPU # = 32
47004 b300 07/21 08:47:23 ###### Threads per connection set to 16
47004 b300 07/21 08:47:23 ###### Initial max. threads set to 32
47004 b300 07/21 08:47:23 ###### SdtBase::InitWrkPool: Successfully initialized Head SDT thread pool
47004 b300 07/21 08:47:23 430196 MODULE_SEQUENCE Adding compression at index [1] RCId [397563]
47004 b300 07/21 08:47:23 430196 SdtBase::cfgProcs() - Total Bufs=90, allocators=1
47004 b300 07/21 08:47:23 430196 SdtBase::cfgProcs() - Free Bufs [90]
47004 b300 07/21 08:47:23 430196 SdtBase::cfgProcs() - Free Bufs [0]
47004 b300 07/21 08:47:23 430196 SdtBase::cfgProcs() - Free Bufs [0]
47004 b300 07/21 08:47:23 430196 SdtBase::cfgProcs() - Free Bufs [0]
47004 b300 07/21 08:47:23 430196 Switching socket 3280 (1/2) to non-blking mode. RCId [397563]
47004 b300 07/21 08:47:23 430196 CPipelayer::FattenSdt Fattening SDT pipe by 1 more connection(s).
47004 b300 07/21 08:47:23 430196 CvFwClient::connectDirectly(): Connected to pbackup:8400/8400 using direct system connect
47004 b300 07/21 08:47:23 430196 CPipelayer::connectToDest Connected pipeline to (pbackup)pbackup:8400/8400, ConType 1 (Direct), Proxy []
47004 b300 07/21 08:47:23 430196 CPipelayer::FattenSdt SDT is using socket 3328 for connection 2/2
47004 b300 07/21 08:47:23 430196 Switching socket 3328 (2/2) to non-blking mode. RCId [397563]
47004 b300 07/21 08:47:23 430196 InitializePerfCounters() - Initializing Perf counters message[Pipeline-ID - 397563] [Starttime - 1658368043] [Starttime UTC - 1658342843]
47004 b300 07/21 08:47:23 430196 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 158 to MediaAgent, Waiting for Response...
47004 5608 07/21 08:47:23 430196 SdtBase::SetNwCrcProps: Enabled n/w crc on SdtHead. [Using slice-by-8] RCId [397563]
47004 5608 07/21 08:47:23 ###### SdtHead::onProcDataCompleted: SDT Head Timeout is set to [-1] secs
47004 5608 07/21 08:47:23 ###### SdtBase::procBuffer: SDT Head Check CRC after network send is set to [0]
47004 8d3c 07/21 08:47:23 430196 JobStatusWorker Setting proxy Connection stats for job: [<?xml version="1.0" encoding="UTF-8" standalone="no" ?><CNSession_cvsJobNetworkInfo jobId="430196" mangledHostname="pbackup*pbackup*8400"><networkInfo connectionType="1" proxy=""/><networkInfo connectionType="1" proxy=""/></CNSession_cvsJobNetworkInfo>]
47004 b300 07/21 08:47:23 430196 [PIPELAYER ] Tail response = Get PL_SET_NETWORK_CRC_PROPS Message Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 158 EventError = 0
47004 b300 07/21 08:47:23 430196 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 136 to MediaAgent, Waiting for Response...
47004 9f7c 07/21 08:47:23 430196 VSBkpController::GetIndexClient() - Opening Indexing connection
47004 9f7c 07/21 08:47:23 430196 IDXBROWSECL Sending init request [<?xml version="1.0" encoding="UTF-8" standalone="no" ?><databrowse_BrowseRequest opType="0" pathType="0"><entity _type_="0" applicationId="106" clientId="6" commCellId="2" name="catdbhanadev" subclientId="158"/><paths path="\"/><timeRange fromTime="0" toTime="0"/><options DoNotCacheFilters="0" PreferContentServer="0" adjustPerLastDRTime="0" browseFromCSDB="0" bulkOperation="0" bypassSubclientConfig="1" caseInsensitive="0" caseManagerDataCopy="0" createRestoreVectors="0" cycleBrowse="0" disableSnapOptimizer="0" doPrediction="0" downloadSystemScan="0" downloadTrueUpStubScanOutput="0" enforceSuperBrowse="0" fetchFileProperties="0" folderDelete="0" fsExtentBrowse="0" getACLs="0" hideEmptyExtents="0" imageBrowse="0" includeAgedData="0" includeAllParents="0" includeCheckSum="0" includeEndUserErasedItems="0" includeExtentCRC="0" includeMetadata="1" includeRunningJobs="0" includeSoftCommittedJobs="0" includeVersions="0" instantSend="0" internalReq="0" isOneTouchRestore="0" machineLiveBrowse="0" nasFilerType="0" nasSynthDirRestore="2" nasSynthRestore="0" nonRecursiveNASRestore="0" onePassRedundancy="0" onePassStubQuery="0" prepareSystemScan="0" pruneFromSource="0" queryAgedArchiveFileData="0" reCreateRestoreVector="0" refCopy="0" refCopyCloudMigration="0" refCopySF="0" relationshipBrowse="0" restoreIndex="1" sendBackListOfAfiles="0" sendOutputToFile="0" sharedFolderBrowse="0" showDeletedFiles="0" showFolderSize="0" showOnlyDeleted="0" showThumbnail="0" skipDataPrediction="0" skipIndexRestore="0" skipInvalidMimeClassification="0" skipLatestVersion="0" skipMountPoints="0" skipNasRenamedDirs="0" skipProgressMessage="0" skipSynthFullJobs="0" synthFull="0" tableViewBrowse="0" translateSyncPath="0" translateToVMReq="0" useLatestCycle="0" useUptoDateIndexOnly="1" verifyArchiverQuery="0" viewBackupCopy="0" vsDiskBrowse="1" vsExtentBrowse="0" vsFileBrowse="0" vsListVMs="0" vsLiveSyncBrowse="0" vsVolumeBrowse="0" vsaFileLevelRestore="0"/><mode mode="4"/><advOptions applyStrictACL="0" copyPrecedence="0" includePsuedoItems="0" retryLimit="0" retryWaitSecs="300" skipACLChecks="0" skipUptodateCheck="0" stubAsData="0" timeoutSecs="300" validateAfiles="0" vmCentricClient="0"/><queries queryId="0" type="0"><dataParam><paging firstNode="0" pageSize="4294967295" skipNode="0"/></dataParam></queries></databrowse_BrowseRequest>] to CS
47004 b300 07/21 08:47:24 430196 [PIPELAYER ] Tail response = dsBackup initialization success Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 136 EventError = 0
47004 b300 07/21 08:47:24 430196 CCVAPipelayer::InitializeBackupPipeline() - Disabling Client-Side-Deduplication SignatureWhere:0
47004 b300 07/21 08:47:24 430196 CCVAPipelayer::InitializeBackupPipeline() - Sent Command PL_INIT_SIGNATURE to MediaAgent [Client name - pbackup] [SIDBStoreId - 0] [isClientSideDedupEnabled - No] [CacheDBSize - 0 MB] [Cache-buffer-size - 0 KB][Compress-enabled - Yes] [latencyOptimizeEnabled - No]
47004 b300 07/21 08:47:24 430196 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 319 to MediaAgent, Waiting for Response...
47004 b300 07/21 08:47:24 430196 [PIPELAYER ] Tail response = signature initialization success Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 319 EventError = 0
47004 b300 07/21 08:47:24 430196 JM Client CVJobClient::initialize(): Got remote host [pbackup].
47004 b300 07/21 08:47:24 430196 JM Client CVBkpJobClient::init(): Initializing job object with token [430196:4:1:0:0:44607].
47004 b300 07/21 08:47:24 430196 VSBkpController::OpenStream() - Opened stream id [2] rcid [397563] stream # [1] of [1]
47004 9f7c 07/21 08:47:25 430196 vsIndexClient::InitIdxBrowseClient() - Successfully initialized idxBrowse connection
47004 9f7c 07/21 08:47:25 430196 CVOnDemandSvcClient::SubmitTask() - On Demand service CVODS_indexserver_pbackup_1 launched at host pbackup*pbackup*8400. Unique ID is C8CE1D4A-414C-4DE5-9726-80B89B666944
47004 9f7c 07/21 08:47:25 430196 CVOnDemandSvcClient::Attach() - Successfully attached to on Demand service CVODS_indexserver_pbackup_1 launched at host pbackup*pbackup*8400. Unique ID is C8CE1D4A-414C-4DE5-9726-80B89B666944
47004 e040 07/21 08:47:33 430196 VSBkpCoordinator::OnIdle_Running() - Waiting for [1] VMs to be processed. [catdbhanadev]
47004 e040 07/21 08:47:33 430196 VSBkpCoordinator::DumpStreamInfo() - StreamId = 2, RCID = 397563, ReservationId = 317490, MediaAgent = [pbackup], Agent = [pbackup] [Assigned]
47004 e040 07/21 08:47:54 430196 vsJobMgr::updateRegularBkpProgressBar() - Updating the progress bar [1]
47004 da54 07/21 08:52:20 430196 TPool [CVRemoteAgentServer]. Ser# [0] Tot [1], Pend [0], Comp [1], Max Par [1], Avg Work Time [41.36 ms], Avg Wait Time [5.92 ms]
47004 da54 07/21 08:52:20 430196 TPool [SdtHeadThPool]. Tot [3], Pend [0], Comp [3], Max Par [1], Avg Work Time [2.48 ms], Avg Wait Time [33.63 us]
47004 e040 07/21 08:52:34 430196 VSBkpCoordinator::OnIdle_Running() - Waiting for [1] VMs to be processed. [catdbhanadev]
47004 e040 07/21 08:52:34 430196 VSBkpCoordinator::DumpStreamInfo() - StreamId = 2, RCID = 397563, ReservationId = 317490, MediaAgent = [pbackup], Agent = [pbackup] [Assigned]
47004 9f7c 07/21 08:53:03 430196 IDXBROWSECL Retrying Browse after [30] secs as Index is temporarily unavailable. Received response [<?xml version="1.0" encoding="UTF-8" standalone="no" ?><databrowse_BrowseResponse doClientSideSortingAndPaging="0" respType="3" workerId="645"><session sessionId="1658368044-645"/><messages errorCode="10" errorMessage="Index Reconstruction is in progress, please wait"/></databrowse_BrowseResponse>]
47004 da54 07/21 08:57:20 430196 TPool [SdtHeadThPool]. Tot [0], Pend [0], Comp [0], Max Par [0], Avg Work Time [0.00 s], Avg Wait Time [0.00 s]
47004 e040 07/21 08:57:44 430196 VSBkpCoordinator::OnIdle_Running() - Waiting for [1] VMs to be processed. [catdbhanadev]
47004 e040 07/21 08:57:44 430196 VSBkpCoordinator::DumpStreamInfo() - StreamId = 2, RCID = 397563, ReservationId = 317490, MediaAgent = [pbackup], Agent = [pbackup] [Assigned]
47004 9f7c 07/21 08:59:03 430196 vsIndexClient::ShouldRetryBrowse() - Browse encountered errors, error messages are below
47004 9f7c 07/21 08:59:03 430196 vsIndexClient::ShouldRetryBrowse() - ERROR: Browse error [10] [Index Reconstruction is in progress, please wait]
47004 9f7c 07/21 08:59:03 430196 vsIndexClient::GetVMMetadata() - Browse for VM [500d4f64-6259-f6ab-e911-cd6006b72c7e] will be retried
47004 9f7c 07/21 08:59:03 430196 VSBkpWorker::ProcessVM() - Failed to query VM [catdbhanadev] Metadata from previous index.
47004 9f7c 07/21 08:59:03 430196 VSBkpWorker::HandleVMComplete_Status() - Error while backing up VM [catdbhanadev], backup will be retried on the next attempt
47004 9f7c 07/21 08:59:03 430196 vsJobMgr::updateVMBkpJobStatus() - Sending VM status for [1] virtual machines
47004 e040 07/21 08:59:04 430196 VSBkpCoordinator::OnMsgVMBackupResult() - Received Status [0] for VM [catdbhanadev] from [pbackup]
47004 9f7c 07/21 08:59:04 430196 VSBkpController::SendGetNextVM() - Requesting Next VM from coordinator
47004 e040 07/21 08:59:04 430196 VSBkpCoordinator::OnIdle_Running() - All VMs have been processed, stopping agents
47004 69f4 07/21 08:59:04 430196 VSBkpController::OnMsgReceived() - Message [VirtualServer_VMAgentQuit] received from Server
47004 e040 07/21 08:59:04 430196 VSBkpCoordinator::OnMsgVMBackupGetNextVM() - GetNextVM Request from [pbackup]
47004 69f4 07/21 08:59:04 430196 VSBkpController::OnMsgVMAgentQuit() - Received Quit message from coordinator
47004 9f7c 07/21 08:59:14 430196 VSBkpWorker::WorkerThread() - Worker [0] exiting
47004 b300 07/21 08:59:15 430196 VSBkpController::StopAllWorkers() - All workers have stopped
47004 b300 07/21 08:59:15 430196 VSBkpController::StopAllWorkers() - Finished stopping all workers
47004 b300 07/21 08:59:15 430196 VSBkpController::ControllerThread() - All [1] VMs have been processed
47004 b300 07/21 08:59:15 430196 VSBkpController::CloseAndReturnStreams() - Returning 1 streams
47004 b300 07/21 08:59:15 430196 VSBkpController::CloseAndReturnStreams() - Closing 1 streams
47004 b300 07/21 08:59:15 430196 VSBkpController::CloseStream() - Closing stream # [1].
47004 b300 07/21 08:59:15 430196 CVArchive::ClosePipeline() - Resetting allocated stream
47004 b300 07/21 08:59:15 430196 CCVAPipelayer::ClosePipeline() - About to destroy Data Mover
47004 b300 07/21 08:59:15 430196 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 133 to MediaAgent, Waiting for Response...
47004 b300 07/21 08:59:25 430196 [PIPELAYER ] Tail response = DataMover destroyed Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 133 EventError = 0
47004 b300 07/21 08:59:25 430196 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 2 to MediaAgent, Waiting for Response...
47004 b300 07/21 08:59:25 430196 [PIPELAYER ] Tail response = Tail Generated STOP_PL and ready to Terminate Status = 0 dwCode = 0 MsgType = 4 MsgSubType = 2 EventError = 0
47004 b300 07/21 08:59:25 430196 CPipelayer::ShutdownPipeline() - stat- SDT [0000021F49011A10] [duration - 722 seconds]
47004 b300 07/21 08:59:25 430196 CPipelayer::ShutdownPipeline() - SDT [0000021F49011A10] Shutdown completed.
47004 b300 07/21 08:59:25 430196 SdtBase::relRef: Going to delete SdtBase as ref count is down to 0. RCId [397563]
47004 b300 07/21 08:59:25 430196 SdtBase is being destroyed. RCId [397563]
47004 b300 07/21 08:59:25 430196 Name [Head], Start Delay [721.93 s], Avg [120.32 s], Procsng Time [522.00 us], Avg [87.00 us], Bytes [57.46 KB], Speed [107.49 MB/s], Samples [6] RCId [397563]
47004 b300 07/21 08:59:25 430196 Name [Head Compression], Start Delay [439.30 us], Avg [73.22 us], Procsng Time [199.90 us], Avg [33.32 us], Bytes [57.46 KB], Speed [280.70 MB/s], Samples [6] RCId [397563]
47004 b300 07/21 08:59:25 430196 Name [Head CRC32], Start Delay [1.90 us], Avg [316.67 ns], Procsng Time [3.38 ms], Avg [563.73 us], Bytes [57.47 KB], Speed [16.59 MB/s], Samples [6] RCId [397563]
47004 b300 07/21 08:59:25 430196 Name [Head Network], Start Delay [40.40 us], Avg [6.73 us], Procsng Time [4.34 ms], Avg [722.60 us], Bytes [57.47 KB], Speed [12.94 MB/s], Samples [6] RCId [397563]
47004 b300 07/21 08:59:25 430196 Performing graceful connection termination RCId [397563]
47004 b300 07/21 08:59:25 430196 Closing all sockets. RCId [397563]
47004 b300 07/21 08:59:25 430196 ~CVArchive() - Destroying CVArchive. This=0000021F2FB99400
47004 b300 07/21 08:59:25 ###### SdtTailSrvPool::Rel: Resetting SrvPool as ref. count is 0.
47004 b300 07/21 08:59:25 430196 VSBkpController::CloseStream() - Closed stream id [2] rcid [397563]
47004 b300 07/21 08:59:25 430196 VSBkpController::ReturnStream() - Returning Stream Id [2] RCID [397563] ReservationId [317490] ClientId [2]
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::OnMsgVMBackupStream() - Agent [pbackup] has returned StreamId [2], RCID [397563], ReservationId[317490]
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::DispatchStreams() - There are [1] streams to be dispatched
47004 69f4 07/21 08:59:25 430196 ID [GetNextVM], Total Time [10.008538] Sec(s)
47004 69f4 07/21 08:59:25 430196 VSBkpController::OnAgentStopped() - Controller is stopping
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::DumpStreamInfo() - StreamId = 2, RCID = 397563, ReservationId = 317490, MediaAgent = [pbackup], Agent = [] [Available]
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::DispatchStreams() - No Agent selected for stream, stream will be released. [0] streams are assigned.
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::DispatchStreams() - Holding Stream Id [2] reservation on last stream
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::ExchangeStreamReservationForClient() - Not Exchanging reservation on stream RCID [397563] as it is already reserved on [2][pbackup]
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::OnAgentStopped() - Agent [pbackup] has stopped
47004 e040 07/21 08:59:25 430196 CVRemoteAgentServer::MonitorAgents() - There are no running agents
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::Run() - VM catdbhanadev --> PENDING Failed to get the index information from previous backup
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::Run() - ===== JOB SUMMARY REPORT BACKUP PHASE =====
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::Run() - Total VMs to backup [1]
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::Run() - VMs pending [1]
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::Run() - ===========================================
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::Run() - all VMs reported an error, failing the job.
47004 e040 07/21 08:59:25 430196 JOBRESULTSTABLE(C:\Program Files\Commvault\ContentStore\iDataAgent\JobResults\CV_JobResults\2\0\4301 removing copy 'C:\Program Files\Commvault\ContentStore\iDataAgent\JobResults\CV_JobResults\2\0\430196'
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::UpdateJobManagerVMList_FailPendingVMs() - Marking [1] VM as failed
47004 e040 07/21 08:59:25 430196 vsJobMgr::updateVMBkpJobStatus() - Sending VM status for [1] virtual machines
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::DeleteVMCollectFile() - Deleted VMCollect file: [C:\Program Files\Commvault\ContentStore\iDataAgent\JobResults\CV_JobResults\iDataAgent\VirtualServerAgent\2\15\vmcollect_430196.cvf]
47004 e040 07/21 08:59:25 430196 BKP CALLED COMPLETE (JOB Status::FAIL), 430196. Token [430196:4:1:0:0:44607]
47004 de40 07/21 08:59:28 430196 CVJobCtrlLog::unregisterProcess(): successfully removed file [C:\Program Files\Commvault\ContentStore\Base\JobControl\47.004]
47004 e040 07/21 08:59:28 430196 CVMWareInfo::ShutdownVMInfo() - VMDiskInfo::Shutdown complete
47004 e040 07/21 08:59:28 430196 CVMWareInfo::ShutdownVMInfo() - CVISDKCppBridge::Cleanup complete
47004 5e0c 07/21 08:59:28 430196 CVDTerminationHandler::_WaitForCVDAliveMutex() - CVD Alive Check Quit Event Signaled
47004 e040 07/21 08:59:28 430196 = [vsbkp] has exited [BACKUP PHASE]