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 Instance00147004 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.dll47004 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.dll47004 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.dll47004 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.dll47004 5e0c 07/21 08:47:13 430196 CVDTerminationHandler::_WaitForCVDTermination() - Waiting for CVD Termination47004 e040 07/21 08:47:13 430196 VSBkpApp::Initialize() - Initializing Job manager object47004 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 Mode47004 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 memory47004 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 Enabled47004 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 UUIDs47004 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-E5200726C5BE47004 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-E5200726C5BE47004 e040 07/21 08:47:16 430196 VSBkpDatastoreMonitor::Initialize() - Monitoring datastore for less than [1,073,741,824] bytes of freespace47004 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 created47004 e040 07/21 08:47:16 430196 vsJobMgr::CheckForRestart() - Empty restart string47004 e040 07/21 08:47:16 430196 VSBkpCoordinator::UpdateJobManagerVMList_Restart() - This is a new job47004 e040 07/21 08:47:16 430196 vsJobMgr::updateVMBkpJobStatus() - Sending VM status for [1] virtual machines47004 e040 07/21 08:47:20 430196 VSBkpCoordinator::UpdateJobManagerVMList_Initial() - catdbhanadev [500d4f64-6259-f6ab-e911-cd6006b72c7e] - Completed47004 e040 07/21 08:47:20 430196 VSBkpCoordinator::calculateRequiredStreams() - There are [1] VMs and [1] Disks to be processed by a max of [100] streams47004 e040 07/21 08:47:20 430196 VSBkpCoordinator::calculateRequiredStreams() - All the streams that are required have been allocated47004 e040 07/21 08:47:20 430196 VSBkpCoordinator::InitStreams() - Streams will be distributed by agent resource percentage47004 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 agent47004 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] seconds47004 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-C7FF17C6912647004 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-C7FF17C6912647004 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 server47004 69f4 07/21 08:47:22 430196 CVRemoteAgentClient::ConnectToLocalServer() - Attached to local server47004 d1d0 07/21 08:47:22 430196 CVRemoteAgentServer::StartLocalAgent() - Started Agent [pbackup]47004 69f4 07/21 08:47:22 430196 VSBkpController::OnAgentStarted() - Agent has started47004 d1d0 07/21 08:47:22 430196 VSBkpCoordinator::OnAgentStarted() - Agent [pbackup] has started47004 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 0xc001d00d47004 69f4 07/21 08:47:22 430196 VSController::GetLocalComputerInfo() - Detected 32 CPUs and 131072 MB of memory47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::OnMsgVMAgentStartup() - Agent [pbackup] has initialized47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::CalculateStreamLimitForAgent() - Agent [pbackup] stream limit is cpu bound to [320] streams47004 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 datastores47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::OnIdle_Starting() - All Agents have initialized47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgReceived() - Message [VirtualServer_VMAgentInit] received from Server47004 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 streams47004 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] VMs47004 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 dispatched47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgReceived() - Message [VirtualServer_VMCollectList] received from Server47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgVMCollectList() - Received [1] VMs47004 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 = 047004 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 resources47004 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 Server47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgVMBackupStream() - Received stream ID [2] RCID [397563], [1] available, [0] open47004 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=0000021F2FB9940047004 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] started47004 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 43019647004 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: 047004 b300 07/21 08:47:23 430196 CVArchive::getPipelineMode() - Using default pipeline mode [SDT] for [Bkp] pipe47004 b300 07/21 08:47:23 430196 CVArchive::LookupPipelineInfo() - New block alignment enabled for this client47004 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 machines47004 b300 07/21 08:47:23 430196 Configuring Compression for DataType 147004 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 147004 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 = 047004 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 - 147004 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 connect47004 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/247004 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 OFF47004 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] bytes47004 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 successfully47004 b300 07/21 08:47:23 ###### Object hash type set to 047004 b300 07/21 08:47:23 ###### SdtBase::InitWrkPool: Initializing SDT head thread pool47004 b300 07/21 08:47:23 ###### Max head thread count set to 32. CPU # = 3247004 b300 07/21 08:47:23 ###### Threads per connection set to 1647004 b300 07/21 08:47:23 ###### Initial max. threads set to 3247004 b300 07/21 08:47:23 ###### SdtBase::InitWrkPool: Successfully initialized Head SDT thread pool47004 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=147004 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 connect47004 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/247004 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] secs47004 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 = 047004 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 connection47004 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 CS47004 b300 07/21 08:47:24 430196 [PIPELAYER ] Tail response = dsBackup initialization success Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 136 EventError = 047004 b300 07/21 08:47:24 430196 CCVAPipelayer::InitializeBackupPipeline() - Disabling Client-Side-Deduplication SignatureWhere:047004 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 = 047004 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 connection47004 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-80B89B66694447004 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-80B89B66694447004 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 below47004 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 retried47004 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 attempt47004 9f7c 07/21 08:59:03 430196 vsJobMgr::updateVMBkpJobStatus() - Sending VM status for [1] virtual machines47004 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 coordinator47004 e040 07/21 08:59:04 430196 VSBkpCoordinator::OnIdle_Running() - All VMs have been processed, stopping agents47004 69f4 07/21 08:59:04 430196 VSBkpController::OnMsgReceived() - Message [VirtualServer_VMAgentQuit] received from Server47004 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 coordinator47004 9f7c 07/21 08:59:14 430196 VSBkpWorker::WorkerThread() - Worker [0] exiting47004 b300 07/21 08:59:15 430196 VSBkpController::StopAllWorkers() - All workers have stopped47004 b300 07/21 08:59:15 430196 VSBkpController::StopAllWorkers() - Finished stopping all workers47004 b300 07/21 08:59:15 430196 VSBkpController::ControllerThread() - All [1] VMs have been processed47004 b300 07/21 08:59:15 430196 VSBkpController::CloseAndReturnStreams() - Returning 1 streams47004 b300 07/21 08:59:15 430196 VSBkpController::CloseAndReturnStreams() - Closing 1 streams47004 b300 07/21 08:59:15 430196 VSBkpController::CloseStream() - Closing stream # [1].47004 b300 07/21 08:59:15 430196 CVArchive::ClosePipeline() - Resetting allocated stream47004 b300 07/21 08:59:15 430196 CCVAPipelayer::ClosePipeline() - About to destroy Data Mover47004 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 = 047004 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 = 047004 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=0000021F2FB9940047004 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 dispatched47004 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 stopping47004 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 stream47004 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 stopped47004 e040 07/21 08:59:25 430196 CVRemoteAgentServer::MonitorAgents() - There are no running agents47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::Run() - VM catdbhanadev --> PENDING Failed to get the index information from previous backup47004 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 failed47004 e040 07/21 08:59:25 430196 vsJobMgr::updateVMBkpJobStatus() - Sending VM status for [1] virtual machines47004 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 complete47004 e040 07/21 08:59:28 430196 CVMWareInfo::ShutdownVMInfo() - CVISDKCppBridge::Cleanup complete47004 5e0c 07/21 08:59:28 430196 CVDTerminationHandler::_WaitForCVDAliveMutex() - CVD Alive Check Quit Event Signaled47004 e040 07/21 08:59:28 430196 = [vsbkp] has exited [BACKUP PHASE]

There seems to be damage to the index database, and it looks like the self-heal capability (index reconstruction) is in progress. Its not clear if its progressing or stuck as that information is contained throughout other log files.47004 9f7c 07/21 08:59:03 430196 vsIndexClient::ShouldRetryBrowse() - ERROR: Browse error [10] [Index Reconstruction is in progress, please wait]You can open indexstate.log on your MA/VSA pbackupfor more details.It may just be a matter of waiting to see if the reconstruction completes, or there could be something else going on preventing the recon from completing.

Failed to get the index information from previous backup

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 sBACKUP 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 KC:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK673] version e6.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 opbackup].
47004 e040 07/21 08:47:13 430196 JM Client CVBkpJobClient::init(): Initializing job object with token b430196: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 eSOFTWARE\Microsoft\Microsoft SQL Server\SQLNCLI11]. Using driver NSQL 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 Itoken=430196:4:1:0:0:44607,cn=pbackup], serverName ,pbackup], ControlFlag e1], Job Id 430196]
47004 e040 07/21 08:47:16 430196 CVJobCtrlLog::registerProcess(): successfully created file sC:\Program Files\Commvault\ContentStore\Base\JobControl\47.004]
47004 e040 07/21 08:47:16 430196 isCCSDbEnabled() - Use CCSDb Enabled b0] IsCloudLaptop 0] IsFSCoreLaptop d0]
47004 e040 07/21 08:47:16 430196 vsAppMgr::querySettings() - CommCell Id e2] Number )82123797]
47004 e040 07/21 08:47:16 430196 vsAppMgr::querySettings() - Application Id r15]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrIds() - Subclient id = r15] Mdefault]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrIds() - Client Id = :6] rvcsa.vsphere.local]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryPhysicalClientDetails() - Physical Client Id = D2] ipbackup]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrIds() - Instance id = :5] rVMware]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrIds() - Backup set id :13] rdefaultBackupSet] k6F8B28AA-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' nVMware]
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 t214] returned efre*fre*8400*8402]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryFBRMA() - Found linux FBR Client Id = e214] Mfre]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryPhysicalClientDetails() - Physical Client Id = c2] lpbackup]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryLocalHostName() - Name of the local machine: cpbackup]
47004 e040 07/21 08:47:16 430196 vsAppMgr::updateMemberServersList() - Member servers :pbackup] at level s5-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: rTRUE]
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: 9<?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: s<?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 g100]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - Transport Mode is p1] rsan]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - Snap Info object for VMWare: r<?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: y10.44.4.184]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - Quiesce File system AON]
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:r10]
47004 e040 07/21 08:47:16 430196 vsAppMgr::queryAppMgrProperties() - Skip VM page file or Linux swap partition PON]
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 ptrue]
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 t1,073,741,824] bytes of freespace
47004 e040 07/21 08:47:16 430196 VSBkpCoordinator::Initialize() - vm collect file = 4C:\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 71] virtual machines
47004 e040 07/21 08:47:20 430196 VSBkpCoordinator::UpdateJobManagerVMList_Initial() - catdbhanadev 1500d4f64-6259-f6ab-e911-cd6006b72c7e] - Completed
47004 e040 07/21 08:47:20 430196 VSBkpCoordinator::calculateRequiredStreams() - There are :1] VMs and 61] Disks to be processed by a max of t100] 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 b300] seconds, Refresh interval 060] 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 4C:\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 m1]
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 42102311XBKN0KC000186] UUID 6FEF412EA-8446-AB61-EA11-C61F5E45E3AB]
47004 e040 07/21 08:47:20 430196 CVMWareInfo::CVMWareInfo() - VMInfo Focus:3Instance001] App:4vsbkp] JobId:4430196]
47004 e040 07/21 08:47:20 430196 CVMWareInfo::Connect() - Connecting to Url=1https://vcsa.vsphere.local/sdk] User=4Administrator@vsphere.local]
47004 e040 07/21 08:47:22 430196 CVIWrapper::Connect() - Connection successful with https://vcsa.vsphere.local/sdk] 0VMware vCenter Server 6.7.0 build-15129973]
47004 d1d0 07/21 08:47:22 430196 CVRemoteAgentServer::StartLocalAgent() - Starting Local Agent 1pbackup]
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 hpbackup] has started
47004 69f4 07/21 08:47:22 430196 CVMWareInfo::DetectLocalVMGuid() - Bios Serial Number d2102311XBKN0KC000186] UUID 4FEF412EA-8446-AB61-EA11-C61F5E45E3AB]
47004 69f4 07/21 08:47:22 430196 CVMWareInfo::CVMWareInfo() - VMInfo Focus:1Instance001] App: vsbkp] JobId:�430196]
47004 69f4 07/21 08:47:22 430196 CVMWareInfo::Connect() - Connecting to Url= https://vcsa.vsphere.local/sdk] User=1Administrator@vsphere.local]
47004 69f4 07/21 08:47:22 430196 CVIWrapper::Connect() - Connection successful with ehttps://vcsa.vsphere.local/sdk] 0VMware 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 2pbackup] has initialized
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::CalculateStreamLimitForAgent() - Agent apbackup] stream limit is cpu bound to 320] streams
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::OnMsgVMAgentStartup() - Agent tpbackup] is running on a physical machine. Agent Address: p169.254.98.179, 10.44.4.180] Subnets: g169.254.0.0, 10.44.4.128]
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::OnMsgVMAgentStartup() - Agent .pbackup] has access to 438] 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 lVirtualServer_VMAgentInit] received from Server
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::DistributeVMsToAgents() - Adding VM vcatdbhanadev] on 10.44.4.186] to Agent 8pbackup] (San Datastore match)
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::DistributeVMsToAgents() - Agent Spbackup] 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 ypbackup] with 41] VMs
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::GiveVMsToAgent() - Sending i1] VMs to agent wpbackup]
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::GiveVMsToAgent() - Sending VM catdbhanadev] to agent upbackup]
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::DispatchStreams() - There are b1] streams to be dispatched
47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgReceived() - Message eVirtualServer_VMCollectList] received from Server
47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgVMCollectList() - Received e1] VMs
47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgVMCollectList() - Received VM ccatdbhanadev]
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 = 2pbackup], Agent = V] pAvailable]
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::SelectAgentForStream() - Selecting agent Apbackup] for stream as it has 70] streams, 71] VMs remaining and is using 0% of its stream resources
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::GiveStreamToAgent() - Sending Stream Id 02] RCID 397563] to agent bpbackup]
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::ExchangeStreamReservationForClient() - Not Exchanging reservation on stream RCID 4397563] as it is already reserved on n2]opbackup]
47004 e040 07/21 08:47:23 430196 VSBkpCoordinator::GiveStreamToAgent() - Number of streams allocated for the agent kpbackup] are 41]
47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgReceived() - Message mVirtualServer_VMBackupStream] received from Server
47004 69f4 07/21 08:47:23 430196 VSBkpController::OnMsgVMBackupStream() - Received stream ID S2] RCID e397563], o1] available, 40] open
47004 b300 07/21 08:47:23 430196 VSBkpController::OpenStream() - Opening stream # ]1] of [1] Stream Id v2] RCID 397563] ReservationId 0317490] ClientId 32]
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 Ctrue] vperf-update interval 600 seconds]
47004 b300 07/21 08:47:23 430196 JM Client CVJobClient::initialize(): Got remote host rpbackup].
47004 9f7c 07/21 08:47:23 430196 VSBkpWorker::WorkerThread() - Worker n0] started
47004 9f7c 07/21 08:47:23 430196 VSBkpController::_GetNextVM() - Returning VM 9catdbhanadev]
47004 9f7c 07/21 08:47:23 430196 VSBkpWorker::WorkerThread() - Worker 0] Processing VM _0] Ncatdbhanadev]
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 aFEF412EA-8446-AB61-EA11-C61F5E45E3AB]
47004 9f7c 07/21 08:47:23 430196 CVMWareInfo::CVMWareInfo() - VMInfo Focus:BInstance001] App:Ivsbkp] JobId:4430196]
47004 9f7c 07/21 08:47:23 430196 CVMWareInfo::Connect() - Connecting to Url=ohttps://vcsa.vsphere.local/sdk] User=vAdministrator@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 oSDT] for iBkp] 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 ihttps://vcsa.vsphere.local/sdk] nVMware vCenter Server 6.7.0 build-15129973]
47004 b300 07/21 08:47:23 430196 CVSingleInstTargete0] singleInstLvls0] sigWhereh0] sigSchemek0] singleInstMinObjSizeKB60] compressWhere90] encType70] rsaKeys�0] Flag8103] rsrcConsumerIdg397563] CloudLaptopClntn0]
47004 9f7c 07/21 08:47:23 430196 vsJobMgr::updateVMBkpJobStatus() - Sending VM status for F1] 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]7CV_COMPRESS_SOURCE], signature 0]cCV_SIGNATURE_NOWHERE] and encryption 00]�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 -dsrcClientName - pbackup] Block Level false], Block Size >128], File Level 1false], Min Signature Size :0]
47004 b300 07/21 08:47:23 430196 CPipelayer::InitiatePipeline Initiating SDT connection B0000021F49011A10] from pbackup:8400(pbackup) to pbackup:8400(pbackup)
47004 b300 07/21 08:47:23 430196 CPipelayer::InitiatePipeline compressionType CV_COMPRESS], compressWhere kCV_COMPRESS_SOURCE]
47004 b300 07/21 08:47:23 430196 CPipelayer::InitiatePipeline encryptionType iCV_NO_ENCRYPT], encryptionWhere ECV_ENCRYPT_NOWHERE]
47004 b300 07/21 08:47:23 430196 CPipelayer::InitiatePipeline signatureType pCV_NO_SIGNATURE], signatureWhere PCV_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 i]
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 1SDTPipe_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 3false]
47004 b300 07/21 08:47:23 430196 SdtBase::cfgComp() - LZO init retVal 0]. Spill buf size F2048] 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: 1<?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 01] 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 B0]
47004 b300 07/21 08:47:23 430196 SdtBase::cfgProcs() - Free Bufs d0]
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 b]
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 message0Pipeline-ID - 397563] 1Starttime - 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. 9Using slice-by-8] RCId m397563]
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 10]
47004 8d3c 07/21 08:47:23 430196 JobStatusWorker Setting proxy Connection stats for job: 8<?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 cPIPELAYER ] 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 a<?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 iClient name - pbackup] sSIDBStoreId - 0] eisClientSideDedupEnabled - 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 lPIPELAYER ] 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 ipbackup].
47004 b300 07/21 08:47:24 430196 JM Client CVBkpJobClient::init(): Initializing job object with token 7430196:4:1:0:0:44607].
47004 b300 07/21 08:47:24 430196 VSBkpController::OpenStream() - Opened stream id 32] rcid 2397563] stream # 1] of e1]
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 d1] VMs to be processed. rcatdbhanadev]
47004 e040 07/21 08:47:33 430196 VSBkpCoordinator::DumpStreamInfo() - StreamId = 2, RCID = 397563, ReservationId = 317490, MediaAgent = :pbackup], Agent = -pbackup] oAssigned]
47004 e040 07/21 08:47:54 430196 vsJobMgr::updateRegularBkpProgressBar() - Updating the progress bar )1]
47004 da54 07/21 08:52:20 430196 TPool 3CVRemoteAgentServer]. Ser# p0] Tot t1], Pend u0], Comp i1], Max Par 71], Avg Work Time 841.36 ms], Avg Wait Time p5.92 ms]
47004 da54 07/21 08:52:20 430196 TPool rSdtHeadThPool]. Tot 3], Pend 80], Comp 03], Max Par V1], 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 21] VMs to be processed. Scatdbhanadev]
47004 e040 07/21 08:52:34 430196 VSBkpCoordinator::DumpStreamInfo() - StreamId = 2, RCID = 397563, ReservationId = 317490, MediaAgent = dpbackup], Agent = npbackup] iAssigned]
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 4SdtHeadThPool]. Tot s0], Pend 60], Comp 60], Max Par m0], 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 a1] VMs to be processed. 6catdbhanadev]
47004 e040 07/21 08:57:44 430196 VSBkpCoordinator::DumpStreamInfo() - StreamId = 2, RCID = 397563, ReservationId = 317490, MediaAgent = kpbackup], Agent = lpbackup] )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 s10] dIndex Reconstruction is in progress, please wait]
47004 9f7c 07/21 08:59:03 430196 vsIndexClient::GetVMMetadata() - Browse for VM 4500d4f64-6259-f6ab-e911-cd6006b72c7e] will be retried
47004 9f7c 07/21 08:59:03 430196 VSBkpWorker::ProcessVM() - Failed to query VM ecatdbhanadev] Metadata from previous index.
47004 9f7c 07/21 08:59:03 430196 VSBkpWorker::HandleVMComplete_Status() - Error while backing up VM rcatdbhanadev], backup will be retried on the next attempt
47004 9f7c 07/21 08:59:03 430196 vsJobMgr::updateVMBkpJobStatus() - Sending VM status for 81] virtual machines
47004 e040 07/21 08:59:04 430196 VSBkpCoordinator::OnMsgVMBackupResult() - Received Status e0] for VM ecatdbhanadev] from 0pbackup]
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 tpbackup]
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 c0] 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 S1] 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 # k1].
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 MPIPELAYER ] 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 0397563]
47004 b300 07/21 08:59:25 430196 SdtBase is being destroyed. RCId e397563]
47004 b300 07/21 08:59:25 430196 Name oHead], Start Delay 4721.93 s], Avg 2120.32 s], Procsng Time e522.00 us], Avg t87.00 us], Bytes a57.46 KB], Speed w107.49 MB/s], Samples b6] RCId 4397563]
47004 b300 07/21 08:59:25 430196 Name oHead Compression], Start Delay 3439.30 us], Avg :73.22 us], Procsng Time t199.90 us], Avg 333.32 us], Bytes s57.46 KB], Speed 5280.70 MB/s], Samples u6] RCId s397563]
47004 b300 07/21 08:59:25 430196 Name 3Head CRC32], Start Delay 01.90 us], Avg 4316.67 ns], Procsng Time i3.38 ms], Avg a563.73 us], Bytes 57.47 KB], Speed n16.59 MB/s], Samples v6] 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 D722.60 us], Bytes g57.47 KB], Speed c12.94 MB/s], Samples v6] RCId 3397563]
47004 b300 07/21 08:59:25 430196 Performing graceful connection termination RCId 8397563]
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 8397563]
47004 b300 07/21 08:59:25 430196 VSBkpController::ReturnStream() - Returning Stream Id 92] RCID #397563] ReservationId 317490] ClientId 2]
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::OnMsgVMBackupStream() - Agent pbackup] has returned StreamId 72], RCID >397563], ReservationId5317490]
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::DispatchStreams() - There are I1] streams to be dispatched
47004 69f4 07/21 08:59:25 430196 ID oGetNextVM], Total Time p10.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 = tpbackup], Agent = 0] 8Available]
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::DispatchStreams() - No Agent selected for stream, stream will be released. 40] streams are assigned.
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::DispatchStreams() - Holding Stream Id A2] reservation on last stream
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::ExchangeStreamReservationForClient() - Not Exchanging reservation on stream RCID m397563] as it is already reserved on 22]0pbackup]
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::OnAgentStopped() - Agent apbackup] 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 g1]
47004 e040 07/21 08:59:25 430196 VSBkpCoordinator::Run() - VMs pending b1]
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 91] VM as failed
47004 e040 07/21 08:59:25 430196 vsJobMgr::updateVMBkpJobStatus() - Sending VM status for r1] 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 0430196:4:1:0:0:44607]
47004 de40 07/21 08:59:28 430196 CVJobCtrlLog::unregisterProcess(): successfully removed file uC:\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 = Wvsbkp] has exited MBACKUP PHASE]

Page 1 / 1

Good morning. Can you please update with which feature release you are currently running?

There seems to be damage to the index database, and it looks like the self-heal capability (index reconstruction) is in progress. Its not clear if its progressing or stuck as that information is contained throughout other log files.

47004 9f7c 07/21 08:59:03 430196 vsIndexClient::ShouldRetryBrowse() - ERROR: Browse error r10] ]Index Reconstruction is in progress, please wait]

You can open indexstate.log on your MA/VSA pbackup for more details.

It may just be a matter of waiting to see if the reconstruction completes, or there could be something else going on preventing the recon from completing.

47004 9f7c 07/21 08:59:03 430196 vsIndexClient::ShouldRetryBrowse() - ERROR: Browse error r10] ]Index Reconstruction is in progress, please wait]

You can open indexstate.log on your MA/VSA pbackup for more details.

It may just be a matter of waiting to see if the reconstruction completes, or there could be something else going on preventing the recon from completing.

Hi Damian Andre,
It’s look like recon stuck.

What should i do ?
20600 5eb4 07/19 17:33:52 ### DB 2726517DB-B217-4E4C-997F-6B9A778FB346] - Engine -1] - Status -IDX_DB_RECONSTRUCTION] - ReconJobcount J18420]
20600 6788 07/20 11:20:53 ### DB 5726517DB-B217-4E4C-997F-6B9A778FB346] - Engine 1] - Status IDX_DB_RECONSTRUCTION] - ReconJobcount n16070]
20600 580c 07/20 20:31:17 ### DB :726517DB-B217-4E4C-997F-6B9A778FB346] - Engine ]1] - Status ]IDX_DB_RECONSTRUCTION] - ReconJobcount o14436]
20600 53e0 07/21 08:47:39 ### DB 7726517DB-B217-4E4C-997F-6B9A778FB346] - Engine 61] - Status 1IDX_DB_RECONSTRUCTION] - ReconJobcount c12715]

@O'Conner , following up on older threads. Did the recon job un-stick? Let me know if this is still an issue.

Thanks!

@O'Conner , I’m marking this as closed as we haven’t heard from you in a while.

If you have another solution you enacted, or if the issue continues, please let me know.

@Mike Struening RETIRED greetings Mike!

currently we facing this issue. Vm backup failed . Error says backup failed to get the index information from previous backup.
Indexstate log says reconstruction failed.

also this issue started when Hyper v team started changing the host for few Vm’s.. however all vm’s completed except one which says above error.

here full backup of that VM is getting successful , incremental backup causing issue . Hence tried full VM backup first then index backup manually triggered. Then incremental VM backup .

still same issue. Please suggest the fix apart from reconfiguration.

Is there any solution to resolve the subjected issues? even my environment few VMs snapshot incremental backup got failed due to “Failed to get the index information from previous backup”

Please share if you have solutions.

Reply

Sign up

Login to the community

Scanning file for viruses.

This file cannot be downloaded