Skip to main content
Question

The virtual machine collect file could not be uploaded

  • August 26, 2024
  • 5 replies
  • 949 views

Forum|alt.badge.img+15

Hello community, 

After we replaced the media agents in our test environment and the storage policies were redirected to the new media agents, I get the following error message.

 

Description: The virtual machine collect file could not be uploaded to MediaAgent [cvmatapp06]. Unable to initialize connection to remote file cache.

I've been dealing with this problem for half a day but can't find a solution. Maybe someone here can give me a hint. I had already replaced the media agents in production but didn't have this problem then.

Regards

Thomas

5 replies

Aplynx
Vaulter
Forum|alt.badge.img+13
  • Vaulter
  • 291 replies
  • August 27, 2024

The full error should tell you which machine is reporting the error and in what log to start with. Usually this is communication between one or more media agents. 


Damian Andre
Vaulter
Forum|alt.badge.img+23
  • Vaulter
  • 1288 replies
  • August 27, 2024

I think @Aplynx is right, but given the context I think the client is still associated with the old MA (which is offline).

Specific Media Agents ‘own’ the index of clients and virtual machines by extension. The index database can only be one one media agent, but will automatically move around in certain situations. Here it looks like the software still has the old MA associated with the location of the index for this client. You could try following these instructions one of the clients to move its index server to your new Media Agent and see if it resolves the issue you are facing.

https://documentation.commvault.com/2023e/expert/changing_indexing_mediaagent_using_change_index_server_workflow.html

 

I also want to say that there is a threshhold that will occur where it will abandon the old index location when it has been offline for a while and rebuild it on a new media agent - I can’t quite remember the timeframe though.


Forum|alt.badge.img+15
  • Author
  • Byte
  • 169 replies
  • August 28, 2024

Hello, 

I couldn't find the workflow.
The new and old media agents are still online and I couldn't see any difference in the configuration. Communication between the components is also possible. I must be missing something here.

Regards
Thomas


Aplynx
Vaulter
Forum|alt.badge.img+13
  • Vaulter
  • 291 replies
  • August 28, 2024

Some more information from the error and timeframe the error code is pointing to in the log\machine would be helpful. Otherwise, I’d suggest opening a support incident. 


Forum|alt.badge.img+15
  • Author
  • Byte
  • 169 replies
  • August 29, 2024

I have an excerpt from the log here and can only confirm that I could not detect any problems with communication.

 

Error Code: [91:462] Description: The virtual machine collect file could not be uploaded to MediaAgent [cvmatapp06]. Unable to initialize connection to remote file cache Source: cvmatapp02, Process: vsbkp

10540 1ac4  08/27 11:08:23 651484 ================================================================
10540 1ac4  08/27 11:08:23 651484 = vsbkp [BACKUP PHASE] has started vsbkp.exe -j 651484 -a 2:318 -t 1 -ref 0 -i 2 -d cvmatapp06.eos.lcl*cvmatapp06*8400 -io 1 -jt 651484:4:11:0:0:21927 -idxma cvmatapp06.eos.lcl*cvmatapp06*8400 -numstreams 1 -lastAttempt -cn cvmatapp06 -vm Instance001
10540 1ac4  08/27 11:08:23 651484 ================================================================
10540 1ac4  08/27 11:08:23 651484 VSBkpApp::PreInitialize() - This is the last attempt of the job
10540 1ac4  08/27 11:08:23 651484 CVMDiskInfo::GetVDDKInstallPath() - Using vStorage VDDK from [C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK702] version [7.0.2 build-17696664]
10540 1ac4  08/27 11:08:23 651484 CVMDiskInfo::LoadVDDKLibrary() - Successfully loaded VDDK Lib (libeay32.dll) from C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK702\bin\libeay32.dll
10540 1ac4  08/27 11:08:23 651484 CVMDiskInfo::LoadVDDKLibrary() - Successfully loaded VDDK Lib (ssleay32.dll) from C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK702\bin\ssleay32.dll
10540 1ac4  08/27 11:08:23 651484 CVMDiskInfo::LoadVDDKLibrary() - Successfully loaded VDDK Lib (libldap_r.dll) from C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK702\bin\libldap_r.dll
10540 1ac4  08/27 11:08:23 651484 CVMDiskInfo::LoadVDDKLibrary() - Successfully loaded VDDK Lib (libcurl.dll) from C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK702\bin\libcurl.dll
10540 1ac4  08/27 11:08:23 651484 CVMDiskInfo::Startup() - Performing early VDDK initialization for version 702
10540 1ac4  08/27 11:08:23 651484 CVMDiskInfo::LoadVDDKLibrary() - Successfully loaded VDDK Lib (vixDiskLib.dll) from C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK702\bin\vixDiskLib.dll
10540 1ac4  08/27 11:08:23 651484 CVMDiskInfo::LoadVDDKLibrary() - Successfully loaded VDDK Lib (vixMntApi.dll) from C:\Program Files\Commvault\ContentStore\Base\VMware\VDDK\VDDK702\bin\vixMntApi.dll
10540 1ac4  08/27 11:08:23 651484 CVMDiskInfo::PopulateVDDKTmpDirectoryPath() - Using [C:\Program Files\Commvault\ContentStore\Base\Temp\vmware-SYSTEM] for VDDK temp directory
10540 1924  08/27 11:08:23 651484 CVMDiskInfo::_VixDiskLibThread() - VixDiskLib thread running
10540 1ac4  08/27 11:08:23 651484 CVMDiskInfo::InitVDDK() - Available Transport modes: file:san:hotadd:nbdssl:nbd
10540 28cc  08/27 11:08:23 651484 CVDTerminationHandler::_WaitForCVDTermination() - Waiting for CVD Termination
10540 1ac4  08/27 11:08:23 651484 VSBkpApp::Initialize() - Initializing Job manager object
10540 1ac4  08/27 11:08:23 651484 vsJobMgr::_initBackup() - Backup Level  [Full]
10540 1ac4  08/27 11:08:23 651484 CvNetworkPool::initNetworkPool() - Creating the control thread
10540 1ac4  08/27 11:08:23 651484 Cvcl::init() - CVCL: Running in FIPS Mode
10540 1ac4  08/27 11:08:23 651484 vsJobMgr::LoadJobOptions() - Job Options: <?xml version='1.0' encoding='utf-8' ?><TMMsg_JobOption><backupOpts truncateLogsOnSource="0" sybaseSkipFullafterLogBkp="0" notSynthesizeFullFromPrevBackup="0" collectMetaInfo="0" backupLevel="1" 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="1"/><mediaOpt><storagePolicy storagePolicyName="SP_60days_akq"/></mediaOpt><dbBackupOptions maxDbBackupType="0"/></backupOpts><adminOpts><contentIndexingOption subClientBasedAnalytics="0"/></adminOpts><restoreOptions><virtualServerRstOption isBlockLevelReplication="0"/></restoreOptions><commonOpts notifyUserOnJobCompletion="0"><perfJobOpts/></commonOpts></TMMsg_JobOption>
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::querySettings() - CommCell Id [2]  Application Id [318]  CommCell Number [72268393]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryAppMgrIds() - Subclient id = [318] [60days]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryAppMgrIds() - Client Id = [229] [vcenter-test_dummy.dfd-hamburg.de]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryPhysicalClientDetails() - Physical Client Id = [256] [cvmatapp06]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryAppMgrIds() - Instance id = [52] [VMware]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryAppMgrIds() - Backup set id [254] [defaultBackupSet] [8B0C53D6-F89A-4A81-9DFA-6DC30D0B14EA]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::querySettings() - IndexingV2 is Enabled
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::querySettingsForInstance() - Instance type (101) 'VMware vCenter'  [VMware]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryPhysicalClientDetails() - Physical Client Id = [256] [cvmatapp06]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryLocalHostName() - Name of the local machine: [cvmatapp06.eos.lcl]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::updateMemberServersList() - Member servers [cvmatapp06, cvmatapp07] at level [7-SUBCLIENT_ENTITY]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryDynamicContent() - VM Content: [<?xml version="1.0" encoding="UTF-8" standalone="no" ?><VirtualServer_VMSubClientEntity><children allOrAnyChildren="1" description="" equalsOrNotEquals="1" path=""><children allOrAnyChildren="1" displayName="commvault-retention_60days" equalsOrNotEquals="1" name="urn:vmomi:InventoryServiceTag:297518dc-b5b8-4e6d-853e-d9c4b9428d46:GLOBAL" type="34"/></children></VirtualServer_VMSubClientEntity>]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::GetSubClientFilters() - VM Filter: [<?xml version="1.0" encoding="UTF-8" standalone="no" ?><VirtualServer_VMSubClientEntity allOrAnyChildren="0"/>]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::GetSubClientFilters() - VM Disk Filter: [<?xml version="1.0" encoding="UTF-8" standalone="no" ?><EVGui_VMSubclientDiskFilterList/>]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryAppMgrProperties() - Max number of streams to used is [5]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryAppMgrProperties() - Transport Mode is [0] [auto]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryAppMgrProperties() - Proxy mount host for instance: [hv601.ews-test-vm.dfd-hamburg.de]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryAppMgrProperties() - Quiesce File system [ON]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryAppMgrProperties() - Use Changed Block Tracking [ON]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryAppMgrProperties() - Datastore space values from App Manager:[10]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryAppMgrProperties() - Skip VM page file or Linux swap partition [ON]
10540 1ac4  08/27 11:08:23 651484 vsAppMgr::queryAppMgrProperties() - Use Backupset Disk Filters [true]
10540 1ac4  08/27 11:08:23 651484 vsJobMgr::initBackupMetadaCollectionDefault() - IndexingV2 is enabled. Metadata collection is not supported.
10540 1ac4  08/27 11:08:23 651484 VSBkpController::Initialize() - Replication ID from DB : [0]
10540 1ac4  08/27 11:08:23 651484 VSBkpDatastoreMonitor::Initialize() - Monitoring datastore for less than [1,073,741,824] bytes of freespace
10540 2ef0  08/27 11:08:23 651484 VSBkpController::MonitorProgress() - [0] VMs are being processed
10540 1ac4  08/27 11:08:23 651484 VSBkpCoordinator::Initialize() - VM collect file = [C:\Program Files\Commvault\ContentStore\iDataAgent\JobResults\CV_JobResults\iDataAgent\VirtualServerAgent\2\318\vmcollect_651484.cvf]; restart context file = [C:\Program Files\Commvault\ContentStore\iDataAgent\JobResults\CV_JobResults\iDataAgent\VirtualServerAgent\2\318\restartContextList_651484.xml]
10540 1ac4  08/27 11:08:23 651484 JOBRESCACHEDIR: job results impersonation user is 'eos\Adminser'
10540 1ac4  08/27 11:08:23 651484 CVImpersonateLoggedOnUser() - caching user sid [S-1-5-21-1298115169-1524694424-3996512350-46089] for optimizing subsequent impersonate operations for this user
10540 1ac4  08/27 11:08:23 651484 JOBRESCACHEDIR: opened index cache [C:\Program Files\Commvault\ContentStore\iDataAgent\JobResults\CV_JobResults\2\0\651484]
10540 1ac4  08/27 11:08:23 651484 VSBkpCoordinator::InitBackupResults() - Backup.out file created
10540 1ac4  08/27 11:08:23 651484 vsJobMgr::CheckForRestart() - Empty restart string
10540 1ac4  08/27 11:08:23 651484 VSBkpCoordinator::UpdateJobManagerVMList_Restart() - Received status of [1] Virtual machines from Job Manager
10540 1ac4  08/27 11:08:23 651484 VSBkpCoordinator::UpdateJobManagerVMList_Restart() - VM [test-cv-02.ews.eos.lcl][501d40e0-4c15-d43d-78d8-0f742c3c2ea3] - [Waiting]
10540 1ac4  08/27 11:08:23 651484 VSBkpCoordinator::UpdateJobManagerVMList_Restart() - Setting VM Name [test-cv-02.ews.eos.lcl] Guid[501d40e0-4c15-d43d-78d8-0f742c3c2ea3] VMAppId [315] in JM VMUpdateInfoRequest
10540 1ac4  08/27 11:08:23 651484 VSBkpCoordinator::UpdateJobManagerVMList_Restart() - 0 of 1 VMs were processed in previous attempts
10540 1ac4  08/27 11:08:23 651484 vsJobMgr::updateVMBkpJobStatus() - Sending VM status for [1] virtual machines
10540 1ac4  08/27 11:08:23 651484 VSBkpCoordinator::JobRestarted() - Checking for Job Restarted before VM list is initialized
10540 1ac4  08/27 11:08:23 651484 VSBkpCoordinator::calculateRequiredStreams() - There are [1] VMs and [2] Disks to be processed by a max of [5] streams
10540 1ac4  08/27 11:08:23 651484 VSBkpCoordinator::calculateRequiredStreams() - [1] streams have been allocated, [2] streams are allowed, [1] additional streams will be requested
10540 1ac4  08/27 11:08:23 651484 VSBkpCoordinator::InitStreams() - Streams will be distributed by agent resource percentage
10540 1ac4  08/27 11:08:24 651484 vsAppMgr::queryDataPathMediaAgents() - Found DataPath MediaAgents [cvmatapp07, cvmatapp06]
10540 1ac4  08/27 11:08:24 651484 VSBkpCoordinator::AddAgent() - Adding [cvmatapp06] as a local agent
10540 1ac4  08/27 11:08:24 651484 CVRemoteAgentServer::AddAgent() - Added Agent [cvmatapp06]
10540 1ac4  08/27 11:08:24 651484 VSBkpCoordinator::AddAgent() - Adding [cvmatapp07] as a remote agent
10540 1ac4  08/27 11:08:24 651484 CVRemoteAgentServer::AddAgent() - Added Agent [cvmatapp07]
10540 1ac4  08/27 11:08:24 651484 CvRemoteFileCacheClient::ConnectToRFCServer() - Removing RFC Server selection in Job options on connect error to MA [cvmatapp07.eos.lcl*cvmatapp07*8400]
10540 1ac4  08/27 11:08:24 651484 CvRemoteFileCacheClient::RemoveMASelectionInJMJobJoboptions() - Removing RFC Server selection in Job options
10540 1ac4  08/27 11:08:24 651484 vsIndexClient::InitRemoteFileCacheConnection() - Failed to initialize CvRemoteFileCacheClient, [0xECCC0016:{CvRemoteFileCacheClient::Initialize(213)} + {CvRemoteFileCacheClient::ConnectToRFCServer(295)/ErrNo.22.(Invalid argument)-Failed to submit task to CVD to lock the server [cvmatapp07.eos.lcl*cvmatapp07*8400]:[0x80070306:{CVOnDemandSvcClient::SubmitTask(126)} + {CVOnDemandSvcClient::SubmitTask(118)/W32.774.(One or more errors occurred while processing the request. (ERROR_ERRORS_ENCOUNTERED.774))-Failed to launch On Demand Service on host [cvmatapp07.eos.lcl*cvmatapp07*8400]. Status is [ERROR]}]}]
10540 1ac4  08/27 11:08:24 651484 CvRemoteFileCacheClient::RemoveMASelectionInJMJobJoboptions() - Removing RFC Server selection in Job options
10540 1ac4  08/27 11:08:24 651484 CvRemoteFileCacheClient::ConnectToRFCServer() - Removing RFC Server selection in Job options on connect error to MA [cvmatapp07.eos.lcl*cvmatapp07*8400]
10540 1ac4  08/27 11:08:24 651484 CvRemoteFileCacheClient::RemoveMASelectionInJMJobJoboptions() - Removing RFC Server selection in Job options
10540 1ac4  08/27 11:08:24 651484 vsIndexClient::InitRemoteFileCacheConnection() - Failed to initialize CvRemoteFileCacheClient, [0xECCC0016:{CvRemoteFileCacheClient::Initialize(213)} + {CvRemoteFileCacheClient::ConnectToRFCServer(295)/ErrNo.22.(Invalid argument)-Failed to submit task to CVD to lock the server [cvmatapp07.eos.lcl*cvmatapp07*8400]:[0x80070306:{CVOnDemandSvcClient::SubmitTask(126)} + {CVOnDemandSvcClient::SubmitTask(118)/W32.774.(One or more errors occurred while processing the request. (ERROR_ERRORS_ENCOUNTERED.774))-Failed to launch On Demand Service on host [cvmatapp07.eos.lcl*cvmatapp07*8400]. Status is [ERROR]}]}]
10540 1ac4  08/27 11:08:24 651484 VSBkpCoordinator::UploadCollectToIndexCache() - Failed to upload collect file to index cache - Unable to initialize connection to remote file cache
10540 1ac4  08/27 11:08:24 651484 VSBkpCoordinator::UploadCollectFileToIndex() - Failed to upload VM Collect File [C:\Program Files\Commvault\ContentStore\iDataAgent\JobResults\CV_JobResults\iDataAgent\VirtualServerAgent\2\318\vmcollect_651484.cvf] to the index cache.
10540 1ac4  08/27 11:08:24 651484 JOBRESULTSTABLE(C:\Program Files\Commvault\ContentStore\iDataAgent\JobResults\CV_JobResults\2\0\6514 removing copy 'C:\Program Files\Commvault\ContentStore\iDataAgent\JobResults\CV_JobResults\2\0\651484'
10540 2ef0  08/27 11:08:24 651484 VSBkpController::ControllerThread() - All [0] VMs have been processed
10540 1ac4  08/27 11:08:24 651484 BKP CALLED COMPLETE (PHASE Status::FAIL), 651484. Token [651484:4:11:0:0:21927]
10540 28cc  08/27 11:08:26 651484 CVDTerminationHandler::_WaitForCVDAliveMutex() - CVD Alive Check Quit Event Signaled
10540 1ac4  08/27 11:08:26 651484 = [vsbkp] has exited [BACKUP PHASE]

 


Reply


Cookie policy

We use cookies to enhance and personalize your experience. If you accept you agree to our full cookie policy. Learn more about our cookies.

 
Cookie settings