Virtual server backups are failing - no CV Support any longer for this commcell

Last post 05-09-2019, 12:01 PM by Liam. 2 replies.
Sort Posts: Previous Next
  • Virtual server backups are failing - no CV Support any longer for this commcell
    Posted: 04-29-2019, 2:31 PM

    I have very limited experience with virtual server backups, and this particular commcell is no longer supported by CV... so I'm hoping someone here on the Forum might be able to help with this problem.

    It looks like a lot of the process is working, but then there a a lot of messages like this:

     

    10820 1fb4 04/28 20:06:48 413947 CVMDiskInfo::Dispatch_VixDiskLib_Open() - VixDiskLib_Open failed Err=36b9 The server refused connection
    10820 1fb4 04/28 20:06:48 413947 CVMWareInfo::_MountVM_VCB4() - Failed to Open Disk [[rsan1fc103] REBSAPP4/REBSAPP4_2.vmdk]
    10820 2d14 04/28 20:06:48 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Open for thread 3508
    10820 1fb4 04/28 20:06:48 413947 CVMWareInfo::_MountVM_VCB4() - Unable to open any disks on VM REBSAPP4 2 attempted

     

    Here's the vsbkp.log:

     

    @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@
    Machine : rbackup1
    File    : vsbkp.log
    @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@

    10820 1e84 04/28 20:04:36 413947 EvDebug::refreshDebugLevel() - Changing Debug level from 1 to 0
    10820 1e84 04/28 20:04:36 413947 EvDebug::getNewLogFileSize() - Changing log file size from 5 MB to 10 MB
    10820 1e84 04/28 20:04:36 413947 EvDebug::getNewMaxVersion() - Changing log file count from 1 to 5
    10820 1e84 04/28 20:04:36 413947 vsbkp::initJobMgr() - ================================================================
    10820 1e84 04/28 20:04:36 413947 vsbkp::initJobMgr() - ================ VSBKP JOB STARTED =============================
    10820 1e84 04/28 20:04:36 413947 vsbkp::initJobMgr() - ================================================================
    10820 1e84 04/28 20:04:36 413947 vsbkp::logCmdLineArgs() - Received command option [-j], value [413947]
    10820 1e84 04/28 20:04:36 413947 vsbkp::logCmdLineArgs() - Received command option [-a], value [2:182]
    10820 1e84 04/28 20:04:36 413947 vsbkp::logCmdLineArgs() - Received command option [-t], value [2]
    10820 1e84 04/28 20:04:36 413947 vsbkp::logCmdLineArgs() - Received command option [-ref], value [1551402144]
    10820 1e84 04/28 20:04:36 413947 vsbkp::logCmdLineArgs() - Received command option [-i], value [3]
    10820 1e84 04/28 20:04:36 413947 vsbkp::logCmdLineArgs() - Received command option [-d], value [rbackup1.corp.awiweb.com*rbackup1*8400*8402]
    10820 1e84 04/28 20:04:36 413947 vsbkp::logCmdLineArgs() - Received command option [-io], value [1]
    10820 1e84 04/28 20:04:36 413947 vsbkp::logCmdLineArgs() - Received command option [-jt], value [413947:4:1]
    10820 1e84 04/28 20:04:36 413947 vsbkp::logCmdLineArgs() - Received command option [-numstreams], value [2]
    10820 1e84 04/28 20:04:36 413947 vsbkp::logCmdLineArgs() - Received command option [-cn], value [rbackup1]
    10820 1e84 04/28 20:04:36 413947 vsbkp::logCmdLineArgs() - Received command option [-vm], value [Instance001]
    10820 1e84 04/28 20:04:36 413947 vsbkp::initJobMgr() - Found, commserver name [ybackup1.corp.awiweb.com], Initializing job manager object
    10820 1e84 04/28 20:04:36 413947 JM Client  CVBkpJobClient::init(): Initializing job object with token [413947:4:1].
    10820 1e84 04/28 20:04:36 413947 Init() - Initializing job control [token=413947:4:1,cn=rbackup1], serverName [ybackup1.corp.awiweb.com], ControlFlag [1], Job Id [413947]
    10820 1e84 04/28 20:04:36 413947 CVJobCtrlLog::registerProcess(): successfuly created file [C:\Program Files\CommVault\Simpana\Base\JobControl\10.820]
    10820 1e84 04/28 20:04:36 413947 vsJobMgr::init() - As per backup options, metadata collection will be performed
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::querySettings() - Found CommCell Id    = [2]
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::querySettings() - Found Application Id = [182]
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::queryAppMgrIds() - Found subclient id = [182]
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::queryAppMgrIds() - Found Client Id = [9]
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::queryAppMgrIds() - Found Instance id = [37]
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::queryAppMgrIds() - Found backup set id [118]
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::queryAppMgrProperties() - Found instance type (101) 'Virtual Center Discovery'
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::queryAppMgrProperties() - Found auto discovery status [ON]
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::queryAppMgrProperties() - Found,  add unassigned VM's to default subclient is [ON]
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::queryAppMgrProperties() - Found virtual server backup type [0]
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::queryAutoDiscoveryProperties() - Found discovery type: Data Store Affinity
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::queryAppMgrProperties() - Subclient backup level: [Disk Level]
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::queryFilterList() - No filters because this is not a file nor a volume level backup
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::queryAppMgrProperties() - Max number of streams to used for the subclient [182] is [2]
    10820 1e84 04/28 20:04:36 413947 vsAppMgr::queryAppMgrProperties() - Transport Mode for the subclient [182] is [1]
    10820 1e84 04/28 20:04:36 413947 ::GetSubclientDir() - The Subclient directory is [C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\iDataAgent\VirtualServerAgent]
    10820 1e84 04/28 20:04:36 413947 vsbkp::initAppMgr() - Restart file = [C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\iDataAgent\VirtualServerAgent\2\182\restartFile.cvf]
    10820 1e84 04/28 20:04:36 413947 vsbkp::initAppMgr() - vm collect file = [C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\iDataAgent\VirtualServerAgent\2\182\vmcollect.cvf]
    10820 1e84 04/28 20:04:36 413947 JRCACHEDIR: job 413947 creating 'C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\413947'
    10820 1e84 04/28 20:04:36 413947 vsbkp::initAppMgr() - Backup.out file created
    10820 1e84 04/28 20:04:37 413947 vsJobMgr::CheckForRestart() - Empty restart string
    10820 1e84 04/28 20:04:37 413947 vsbkp::GetVMListFromAppMgr() - List of VM's:
    10820 1e84 04/28 20:04:37 413947 vsbkp::GetVMListFromAppMgr() - VMName:[REBSAPP4] VmGuid:[421c5364-4d9b-4203-b5b6-1e7a51f47293] ServerName:[optvmvc01apr.cswg.com] HostName:[rvmware6.corp.awiweb.com]
    10820 1e84 04/28 20:04:37 413947 vsbkp::GetVMListFromAppMgr() - VMName:[REBSDB4] VmGuid:[421c73c6-74eb-f61e-2c24-ad255f1bb82e] ServerName:[optvmvc01apr.cswg.com] HostName:[rvmware6.corp.awiweb.com]
    10820 1e84 04/28 20:04:37 413947 vsbkp::GetVMListFromAppMgr() - VMName:[REBSAPP7] VmGuid:[423b28b6-9695-670f-7884-c92b4827fee3] ServerName:[optvmvc01apr.cswg.com] HostName:[rvmware3.corp.awiweb.com]
    10820 1e84 04/28 20:04:37 413947 vsbkp::GetVMList() - VM Count to backup:[3]
    10820 1e84 04/28 20:04:37 413947 vsbkp::GetVMList() - This is a new backup
    10820 1e84 04/28 20:04:37 413947 CVcb2P2VXml::_Init() - _Init...
    10820 1e84 04/28 20:04:37 413947 CVMDiskInfo::GetVDDKInstallPath() - Using vStorage VDDK from [C:\Program Files\CommVault\Simpana\Base\VMware\VDDK]
    10820 2d14 04/28 20:04:37 413947 CVMDiskInfo::_VixDiskLibThread() - VixDiskLib thread running
    10820 2d14 04/28 20:04:37 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Init for thread 1e84
    10820 2d14 04/28 20:04:38 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Init for thread 1e84
    10820 1e84 04/28 20:04:38 413947 CVMDiskInfo::Init() - Avaiable Transport modes: file:san:hotadd:nbdssl:nbd
    10820 1e84 04/28 20:04:38 413947 CVMDiskInfo::DetectLocalVMGuid() - Bios Serial Number [C1X8WV1]
    10820 1e84 04/28 20:04:39 413947 CVMWareInfo::CVMWareInfo() - VMInfo Focus:[Instance001] App:[vsbkp] JobId:[413947]
    10820   1 04/28 20:04:39 ### ### ### --- Log Number from registry HKEY_LOCAL_MACHINE\SOFTWARE\CommVault Systems\Galaxy\Instance001\EventManager is 1
    10820   1 04/28 20:04:39 ### ### ### --- Log Size   from registry HKEY_LOCAL_MACHINE\SOFTWARE\CommVault Systems\Galaxy\Instance001\EventManager is 5
    10820   1 04/28 20:04:39 ### ### ### --- Log Level  from registry HKEY_LOCAL_MACHINE\SOFTWARE\CommVault Systems\Galaxy\Instance001\EventManager is 1
    10820 1e84 04/28 20:04:39 413947 CVMWareInfo::Connect() - Connecting to Url=[https://optvmvc01apr.cswg.com/sdk] User=[cswg\cvadmin]
    10820   1 04/28 20:04:49 413947 ### CVIWrapper::Connect --- Connection successful with [https://optvmvc01apr.cswg.com/sdk] [VMware vCenter Server 6.5.0 build-7119157]
    10820 1e84 04/28 20:04:49 413947 CVMWareInfo::Connect() - VCBMounter is not available
    10820 1e84 04/28 20:04:49 413947 CVMWareInfo::Connect() - VCB4 is available
    10820 1e84 04/28 20:05:28 413947 VirtualDiscoveredClientCreation::Initialize() -  commcell Id is zero, using 2
    10820 1e84 04/28 20:05:28 413947 VirtualDiscoveredClientCreation::Initialize() - client group [optvmvc01apr.cswg.com] commcellId [2]
    10820 1e84 04/28 20:05:28 413947 NetMessage::verifyResponseHeader() - Error Code [50209] returned - [Data already exists].
    10820 1e84 04/28 20:05:28 413947 ClientGroupInterfaceNet::create() - Data already exists
    10820 1e84 04/28 20:05:28 413947 VirtualDiscoveredClientCreation::Initialize() - We will be issuing request to CommServ, as it is the first time VirtualDiscoveredClientCreation API is called
    10820 1e84 04/28 20:05:28 413947 vsSim::createVMClient100() - Calling VirtualDiscoveredClientCreation::Execute()...
    10820 1e84 04/28 20:05:31 413947 VirtualDiscoveredClientCreation::postOperation() - VMGUID [421c5364-4d9b-4203-b5b6-1e7a51f47293] -> Name[REBSAPP4], Client Id[588]
    10820 1e84 04/28 20:05:31 413947 VirtualDiscoveredClientCreation::postOperation() - VMGUID [421c73c6-74eb-f61e-2c24-ad255f1bb82e] -> Name[REBSDB4], Client Id[589]
    10820 1e84 04/28 20:05:31 413947 VirtualDiscoveredClientCreation::postOperation() - VMGUID [423b28b6-9695-670f-7884-c92b4827fee3] -> Name[REBSAPP7_1], Client Id[592]
    10820 1e84 04/28 20:05:31 413947 vsSim::createVMClient100() - Done with VirtualDiscoveredClientCreation::Execute()...
    10820 1e84 04/28 20:05:31 413947 JM Client  CVJobClient::processXmlReq(), got response.
    10820 1e84 04/28 20:05:32 413947 vsbkp::BackupAllVM() - Number of virtual machines to be backed up: AppMgr:[3]  vmList:[3]
    10820 1e84 04/28 20:05:32 413947 vsJobMgr::setNumberOfVMsForProgressBar() - Number of VMs to use as reference for the progress bar [3]
    10820 1e84 04/28 20:05:32 413947 vsJobMgr::setNumberOfVMsAlreadyBackedUp() - Number of VMs already processed [0]
    10820 1e84 04/28 20:05:32 413947 vsbkp::BackupAllVM() - Max possible snaps is 50
    10820 1e84 04/28 20:05:32 413947 vsbkp::BackupAllVM() - Max possible streams is 2
    10820 1e84 04/28 20:05:32 413947 vsbkp::BackupAllVM() - Max threads in thread pool is 2
    10820 1e84 04/28 20:05:32 413947 vsbkp::calculateRequiredStreams() - All the streams that are required have been allocated
    10820 1e84 04/28 20:05:32 413947 vsbkp::BackupAllVM() - Number of available backup objects: 2
    10820 1e84 04/28 20:05:32 413947 vsbkp::createIndex() - Job options for virtual IDA Backup
    10820 1e84 04/28 20:05:33 413947 Overriding MediaAgent Interface name rbackup1.corp.awiweb.com*rbackup1*8400*8402 with rbackup1.corp.awiweb.com*rbackup1*8400*8402, my name rbackup1.corp.awiweb.com with rbackup1.corp.awiweb.com
    10820 1e84 04/28 20:05:33 413947 CreateIndex would be started with following parameters
    10820 1e84 04/28 20:05:33 413947 Commcell Id = [2]
    10820 1e84 04/28 20:05:34 413947 Subclient Id/App Id = [182]
    10820 1e84 04/28 20:05:34 413947 Backup type = [2]
    10820 1e84 04/28 20:05:34 413947 Start time = [1556496332]
    10820 1e84 04/28 20:05:34 413947 Job token = [413947:4:1]
    10820 1e84 04/28 20:05:34 413947 Snap job id = [0]
    10820 1e84 04/28 20:05:34 413947 Client network host name = [rbackup1.corp.awiweb.com]
    10820 1e84 04/28 20:05:34 413947 Gui override = [1]
    10820 1e84 04/28 20:05:34 413947 Pruning time = [0]
    10820 1e84 04/28 20:05:34 413947 Options = [1]
    10820 2a30 04/28 20:05:34 413947 Cvcl::init() - CVCL: Running in FIPS Mode
    10820 2a30 04/28 20:05:35 413947 CreateIndex Process has been launched on MediaAgent rbackup1.corp.awiweb.com*rbackup1*8400*8402
    10820 2a30 04/28 20:05:35 413947 [::SpawnThread]: cmdBuf = _handshake_90_
    10820 2a30 04/28 20:05:35 413947 [::SpawnThread]: accept successful
    10820 1e84 04/28 20:06:01 413947 [SendDirChange::wait]: ALL systems GO from CreateIndex
    10820 1e84 04/28 20:06:01 413947 [::sendFile]: Finished sending file [C:\Program Files\CommVault\Simpana\Base\Temp\413947_COMPDCHANGE\COMPDCHANGE]
    10820 1e84 04/28 20:06:01 413947 [::sendFile]: Finished sending file [C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\iDataAgent\VirtualServerAgent\2\182\DCTot.cvf]
    10820 1e84 04/28 20:06:01 413947 [SendDirChange::sendFiles]: file transfer to createIndex completed successfully
    10820 1e84 04/28 20:06:02 413947 [SendDirChange::wait]: CreateIndex completed
    10820 1e84 04/28 20:06:02 413947 [::sendDirChange]: Index Creation completed Successfully
    10820 1e84 04/28 20:06:02 413947 SENDCOMPDCHANGE: sendDirChange: send component dirchange successful
    10820 1e84 04/28 20:06:02 413947 vsbkp::createIndex() - Done...
    10820 1e84 04/28 20:06:03 413947 CVArchive::Construct() - Constructing CVArchive Object
    10820 1e84 04/28 20:06:03 413947 CVArchive::Construct() - Enable CVArchive Big Buffer [true]
    10820 1e84 04/28 20:06:03 413947 CVArchive::SetupPipeline() - Enter setupPipeline
    10820 1e84 04/28 20:06:03 413947 CVArchive::LookupPipelineInfo() - Enter LookupPipelineInfo
    10820 1e84 04/28 20:06:04 413947 isCVSingleInstanceTarget[1] singleInstanceLevel[2] signatureModuleWhere[3] signatureScheme[4] singleInstMinObjSizeKB[50] compressWhere[0] encryptionType[0] rsaKeysPresent[0]
    10820 1e84 04/28 20:06:04 413947 Configuring Compression for DataType 1
    10820 1e84 04/28 20:06:04 413947 CVArchive::ConfigureBlockAlignment() - Block alignment is not supported for this iDA (m_appType=106)
    10820 1e84 04/28 20:06:04 413947 Configuring Encryption for DataType 1
    10820 1e84 04/28 20:06:04 413947 Network agents configured before firewall check = 2
    10820 1e84 04/28 20:06:04 413947 Network agents configured after firewall check = 2
    10820 1e84 04/28 20:06:04 413947 CVArchive::StartPipeline() - StartPipeline SI configuration -[srcClientName - rbackup1] Block Level [true], Block Size [128], File Level [false], Min Signature Size [128]
    10820 1e84 04/28 20:06:04 413947 CVArchive::StartPipeline() - Starting pipeline
    10820 1e84 04/28 20:06:04 413947 CCVAPipelayer::StartPipeline() - * Turning off SingleThreadedSDTHead flag to true for apptype [106]
    10820 1e84 04/28 20:06:04 413947 CCVAPipelayer::StartPipeline() - Forcing single tag buffers to true
    10820 1e84 04/28 20:06:04 413947 Ignoring call to enable/disable multi-tag buffers. parameter [false].
    10820 1e84 04/28 20:06:04 413947 CPipelayer::InitiatePipeline Initiating SDT connection from rbackup1.corp.awiweb.com:8400(rbackup1) to rbackup1.corp.awiweb.com:8400(rbackup1)
    10820 1e84 04/28 20:06:04 413947 CPipelayer::InitiatePipeline compressionType [0], compressWhere [0]
    10820 1e84 04/28 20:06:04 413947 CPipelayer::InitiatePipeline encryptionType [0], encryptionWhere [0]
    10820 1e84 04/28 20:06:04 413947 CPipelayer::InitiatePipeline signatureType [4], signatureWhere [3]
    10820 1e84 04/28 20:06:04 413947 CPipelayer::InitiatePipeline Setting buffer size [65536]
    10820 1e84 04/28 20:06:04 413947 CPipelayer::connectToDest Connecting pipeline to (rbackup1)rbackup1.corp.awiweb.com:8400/8400
    10820 1e84 04/28 20:06:04 413947 CPipelayer::InitiatePipeline SDT Pipeline ID is [SDTPipe_rbackup1_rbackup1_413947_1556496364_10820_7812]
    10820 1e84 04/28 20:06:04 413947 SdtNetLink() - WAN Padding is OFF
    10820 1e84 04/28 20:06:04 413947 SdtNetLink::setSocket() - Switching socket 2452 to non-blocking mode.
    10820 1e84 04/28 20:06:04 413947 SdtNetLink::authenticate() - Authenticating socket connection. Timeout 30 seconds.
    10820 1e84 04/28 20:06:04 413947 SdtNetLink::authenticate() - Connection authenticated successfully
    10820 1e84 04/28 20:06:04 413947 Adding compression at index [1]
    10820 1e84 04/28 20:06:04 413947 Adding signature at index [2]
    10820 1e84 04/28 20:06:04 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 136 to MediaAgent, Waiting for Response...
    10820 1e84 04/28 20:06:07 ###### [PIPELAYER  ] Tail response = dsBackup initialization success Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 136 EventError = 0
    10820 1e84 04/28 20:06:07 413947 CCVAPipelayer::InitializeBackupPipeline() - Enable Client-Side-Deduplication [by SP - Yes]
    10820 1e84 04/28 20:06:07 413947 CCVAPipelayer::InitializeBackupPipeline() - Enabling Client-Side-Deduplication
    10820 1e84 04/28 20:06:07 413947 CCVAPipelayer::InitializeBackupPipeline() - Sent Command PL_INIT_SIGNATURE to MediaAgent [Client name - rbackup1][isClientSideDedupEnabled - yes] [CacheDBSize - 0 MB] [Cache-buffer-size - 4096 KB] [isVSAEnabled - No] [isCompressEbnabled - No]...
    10820 1e84 04/28 20:06:07 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 319 to MediaAgent, Waiting for Response...
    10820 36dc 04/28 20:06:07 413947 CDeDupCache::Initialize: Performance counter update interval seconds. setting to 1800 seconds
    10820 36dc 04/28 20:06:07 413947 CDeDupCache::Initialize:DedupCache sig-data caching size 9043968 (64 x 141312)
    10820 1e84 04/28 20:06:07 ###### [PIPELAYER  ] Tail response = signature initialization success Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 319 EventError = 0
    10820 1e84 04/28 20:06:07 413947 JM Client  CVBkpJobClient::init(): Initializing job object with token [413947:4:1].
    10820 1e84 04/28 20:06:07 413947 Ignoring call to enable/disable multi-tag buffers. parameter [true].
    10820 1e84 04/28 20:06:07 413947 Multiple Tag Headers per Pipeline Buffer is Supported
    10820 1e84 04/28 20:06:07 413947 CVArchive::AllocateArchiveFileId() - Sending allocate afileId request with copy = 20 ***
    10820 1e84 04/28 20:06:08 413947 CCVAPipelayer::SetEncryptProps() - Entered
    10820 1e84 04/28 20:06:08 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 156 to MediaAgent, Waiting for Response...
    10820 1e84 04/28 20:06:08 ###### [PIPELAYER  ] Tail response = Get PL_SET_ENC_PROPS Message Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 156 EventError = 0
    10820 1e84 04/28 20:06:08 413947 CVArchive::CreateArchiveFile() - Archive file name 773409 afilenum = 773409
    10820 1e84 04/28 20:06:08 413947 CCVAPipelayer::CreateArchiveFile() - Entered
    10820 1e84 04/28 20:06:08 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 131 to MediaAgent, Waiting for Response...
    10820 1e84 04/28 20:06:11 ###### [PIPELAYER  ] Tail response = Archive File creation succeeded Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 131 EventError = 0
    10820 1e84 04/28 20:06:11 413947 vsbkp::BackupAllVM() - Processing vmName [REBSAPP4]; vmGuid [421c5364-4d9b-4203-b5b6-1e7a51f47293]
    10820 1e84 04/28 20:06:11 413947 vsbkp::BackupAllVM() - Invoking the thread operation
    10820 1e84 04/28 20:06:11 413947 vsbkp::BackupAllVM() - Thread id is 1
    10820 1fb4 04/28 20:06:11 413947 CVcb2P2VXml::_Init() - _Init...
    10820 1e84 04/28 20:06:11 413947 CVArchive::Construct() - Constructing CVArchive Object
    10820 1fb4 04/28 20:06:11 413947 CVMWareInfo::CVMWareInfo() - VMInfo Focus:[Instance001] App:[vsbkp] JobId:[413947]
    10820 1e84 04/28 20:06:11 413947 CVArchive::Construct() - Enable CVArchive Big Buffer [true]
    10820 1e84 04/28 20:06:11 413947 CVArchive::SetupPipeline() - Enter setupPipeline
    10820 1e84 04/28 20:06:11 413947 CVArchive::LookupPipelineInfo() - Enter LookupPipelineInfo
    10820 1fb4 04/28 20:06:11 413947 CVMWareInfo::Connect() - Connecting to Url=[https://optvmvc01apr.cswg.com/sdk] User=[cswg\cvadmin]
    10820   5 04/28 20:06:11 413947 ### CVIWrapper::Connect --- Connection successful with [https://optvmvc01apr.cswg.com/sdk] [VMware vCenter Server 6.5.0 build-7119157]
    10820 1fb4 04/28 20:06:11 413947 CVMWareInfo::Connect() - VCBMounter is not available
    10820 1fb4 04/28 20:06:11 413947 CVMWareInfo::Connect() - VCB4 is available
    10820 1fb4 04/28 20:06:11 413947 CCVAPipelayer::SetRestartContext() - Setting restart context to 1
    10820 1fb4 04/28 20:06:11 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 291 to MediaAgent, Waiting for Response...
    10820 1fb4 04/28 20:06:11 ###### [PIPELAYER  ] Tail response = Current Restart Context has been set to 1 Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 291 EventError = 0
    10820 1fb4 04/28 20:06:12 413947 CVMWareInfo::_MountVM_VCB4() - Mounting VM:[REBSAPP4] with GUID:[421c5364-4d9b-4203-b5b6-1e7a51f47293]
    10820 1e84 04/28 20:06:12 413947 isCVSingleInstanceTarget[1] singleInstanceLevel[2] signatureModuleWhere[3] signatureScheme[4] singleInstMinObjSizeKB[50] compressWhere[0] encryptionType[0] rsaKeysPresent[0]
    10820 1e84 04/28 20:06:12 413947 Configuring Compression for DataType 1
    10820 1e84 04/28 20:06:12 413947 CVArchive::ConfigureBlockAlignment() - Block alignment is not supported for this iDA (m_appType=106)
    10820 1e84 04/28 20:06:12 413947 Configuring Encryption for DataType 1
    10820 1e84 04/28 20:06:12 413947 Network agents configured before firewall check = 2
    10820 1e84 04/28 20:06:12 413947 Network agents configured after firewall check = 2
    10820 1e84 04/28 20:06:12 413947 CVArchive::StartPipeline() - StartPipeline SI configuration -[srcClientName - rbackup1] Block Level [true], Block Size [128], File Level [false], Min Signature Size [128]
    10820 1e84 04/28 20:06:12 413947 CVArchive::StartPipeline() - Starting pipeline
    10820 1e84 04/28 20:06:12 413947 CCVAPipelayer::StartPipeline() - * Turning off SingleThreadedSDTHead flag to true for apptype [106]
    10820 1e84 04/28 20:06:12 413947 CCVAPipelayer::StartPipeline() - Forcing single tag buffers to true
    10820 1e84 04/28 20:06:12 413947 Ignoring call to enable/disable multi-tag buffers. parameter [false].
    10820 1e84 04/28 20:06:12 413947 CPipelayer::InitiatePipeline Initiating SDT connection from rbackup1.corp.awiweb.com:8400(rbackup1) to rbackup1.corp.awiweb.com:8400(rbackup1)
    10820 1e84 04/28 20:06:12 413947 CPipelayer::InitiatePipeline compressionType [0], compressWhere [0]
    10820 1e84 04/28 20:06:12 413947 CPipelayer::InitiatePipeline encryptionType [0], encryptionWhere [0]
    10820 1e84 04/28 20:06:12 413947 CPipelayer::InitiatePipeline signatureType [4], signatureWhere [3]
    10820 1e84 04/28 20:06:12 413947 CPipelayer::InitiatePipeline Setting buffer size [65536]
    10820 1e84 04/28 20:06:12 413947 CPipelayer::connectToDest Connecting pipeline to (rbackup1)rbackup1.corp.awiweb.com:8400/8400
    10820 1e84 04/28 20:06:12 413947 CPipelayer::InitiatePipeline SDT Pipeline ID is [SDTPipe_rbackup1_rbackup1_413947_1556496372_10820_7812]
    10820 1e84 04/28 20:06:12 413947 SdtNetLink() - WAN Padding is OFF
    10820 1e84 04/28 20:06:12 413947 SdtNetLink::setSocket() - Switching socket 2812 to non-blocking mode.
    10820 1e84 04/28 20:06:12 413947 SdtNetLink::authenticate() - Authenticating socket connection. Timeout 30 seconds.
    10820 1e84 04/28 20:06:12 413947 SdtNetLink::authenticate() - Connection authenticated successfully
    10820 1e84 04/28 20:06:12 413947 Adding compression at index [1]
    10820 1e84 04/28 20:06:12 413947 Adding signature at index [2]
    10820 1e84 04/28 20:06:12 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 136 to MediaAgent, Waiting for Response...
    10820 1e84 04/28 20:06:13 ###### [PIPELAYER  ] Tail response = dsBackup initialization success Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 136 EventError = 0
    10820 1e84 04/28 20:06:13 413947 CCVAPipelayer::InitializeBackupPipeline() - Enable Client-Side-Deduplication [by SP - Yes]
    10820 1e84 04/28 20:06:13 413947 CCVAPipelayer::InitializeBackupPipeline() - Enabling Client-Side-Deduplication
    10820 1e84 04/28 20:06:13 413947 CCVAPipelayer::InitializeBackupPipeline() - Sent Command PL_INIT_SIGNATURE to MediaAgent [Client name - rbackup1][isClientSideDedupEnabled - yes] [CacheDBSize - 0 MB] [Cache-buffer-size - 4096 KB] [isVSAEnabled - No] [isCompressEbnabled - No]...
    10820 1e84 04/28 20:06:13 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 319 to MediaAgent, Waiting for Response...
    10820 25f4 04/28 20:06:13 413947 CDeDupCache::Initialize: Performance counter update interval seconds. setting to 1800 seconds
    10820 25f4 04/28 20:06:13 413947 CDeDupCache::Initialize:DedupCache sig-data caching size 9043968 (64 x 141312)
    10820 1e84 04/28 20:06:13 ###### [PIPELAYER  ] Tail response = signature initialization success Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 319 EventError = 0
    10820 1e84 04/28 20:06:13 413947 JM Client  CVBkpJobClient::init(): Initializing job object with token [413947:4:1].
    10820 1e84 04/28 20:06:13 413947 Ignoring call to enable/disable multi-tag buffers. parameter [true].
    10820 1e84 04/28 20:06:13 413947 Multiple Tag Headers per Pipeline Buffer is Supported
    10820 1e84 04/28 20:06:13 413947 CVArchive::AllocateArchiveFileId() - Sending allocate afileId request with copy = 20 ***
    10820 1e84 04/28 20:06:13 413947 CCVAPipelayer::SetEncryptProps() - Entered
    10820 1e84 04/28 20:06:13 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 156 to MediaAgent, Waiting for Response...
    10820 1e84 04/28 20:06:13 ###### [PIPELAYER  ] Tail response = Get PL_SET_ENC_PROPS Message Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 156 EventError = 0
    10820 1e84 04/28 20:06:13 413947 CVArchive::CreateArchiveFile() - Archive file name 773410 afilenum = 773410
    10820 1e84 04/28 20:06:13 413947 CCVAPipelayer::CreateArchiveFile() - Entered
    10820 1e84 04/28 20:06:13 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 131 to MediaAgent, Waiting for Response...
    10820 1e84 04/28 20:06:15 ###### [PIPELAYER  ] Tail response = Archive File creation succeeded Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 131 EventError = 0
    10820 1e84 04/28 20:06:15 413947 vsbkp::BackupAllVM() - Processing vmName [REBSDB4]; vmGuid [421c73c6-74eb-f61e-2c24-ad255f1bb82e]
    10820 1e84 04/28 20:06:15 413947 vsbkp::BackupAllVM() - Invoking the thread operation
    10820 1e84 04/28 20:06:15 413947 vsbkp::BackupAllVM() - Thread id is 2
    10820 3508 04/28 20:06:15 413947 CVcb2P2VXml::_Init() - _Init...
    10820 3508 04/28 20:06:15 413947 CVMWareInfo::CVMWareInfo() - VMInfo Focus:[Instance001] App:[vsbkp] JobId:[413947]
    10820 3508 04/28 20:06:15 413947 CVMWareInfo::Connect() - Connecting to Url=[https://optvmvc01apr.cswg.com/sdk] User=[cswg\cvadmin]
    10820   6 04/28 20:06:16 413947 ### CVIWrapper::Connect --- Connection successful with [https://optvmvc01apr.cswg.com/sdk] [VMware vCenter Server 6.5.0 build-7119157]
    10820 3508 04/28 20:06:16 413947 CVMWareInfo::Connect() - VCBMounter is not available
    10820 3508 04/28 20:06:16 413947 CVMWareInfo::Connect() - VCB4 is available
    10820 3508 04/28 20:06:16 413947 CCVAPipelayer::SetRestartContext() - Setting restart context to 2
    10820 3508 04/28 20:06:16 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 291 to MediaAgent, Waiting for Response...
    10820 3508 04/28 20:06:16 ###### [PIPELAYER  ] Tail response = Current Restart Context has been set to 2 Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 291 EventError = 0
    10820 3508 04/28 20:06:16 413947 CVMWareInfo::_MountVM_VCB4() - Mounting VM:[REBSDB4] with GUID:[421c73c6-74eb-f61e-2c24-ad255f1bb82e]
    10820 1fb4 04/28 20:06:25 413947 CVMWareInfo::_MountVM_VCB4() - Mounting VM [REBSAPP4] config [[rsan1fc103] REBSAPP4/REBSAPP4.vmx] Moref [vm-6067] hosted by server[robesx07pr.cswg.com] version[VMware ESXi 6.5.0 build-10719125] and HW version[vmx-08]
    10820 1fb4 04/28 20:06:25 413947 CVMWareInfo::_MountVM_VCB4() - Change tracking is already enabled on VM [REBSAPP4]
    10820 1fb4 04/28 20:06:25 413947 CVMWareInfo::_MountVM_VCB4() - Datacenter [Robesonia] Datastore [rsan1fc103] VM Config Dir[REBSAPP4]
    10820 1fb4 04/28 20:06:25 413947 CVMWareInfo::_DownloadConfigFile() - DOWNLOADING VM Config File https://optvmvc01apr.cswg.com/folder/REBSAPP4/REBSAPP4.vmx?dcPath=Robesonia&dsName=rsan1fc103 to C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\iDataAgent\VirtualServerAgent\2\182\(421c5364-4d9b-4203-b5b6-1e7a51f47293)\REBSAPP4.vmx
    10820 1fb4 04/28 20:06:28 413947 CVMWareInfo::_CreateVMSnapshot() - Creating Snapshot of VM [REBSAPP4] Guid [421c5364-4d9b-4203-b5b6-1e7a51f47293]
    10820   5 04/28 20:06:28 413947 ### CreateSnapshot_Task --- Started Create Snapshot task task-57972 for VM REBSAPP4
    10820 3508 04/28 20:06:29 413947 CVMWareInfo::_MountVM_VCB4() - Mounting VM [REBSDB4] config [[rsan1fc103] REBSDB4/REBSDB4.vmx] Moref [vm-6076] hosted by server[robesx07pr.cswg.com] version[VMware ESXi 6.5.0 build-10719125] and HW version[vmx-08]
    10820 3508 04/28 20:06:29 413947 CVMWareInfo::_MountVM_VCB4() - Change tracking is already enabled on VM [REBSDB4]
    10820 3508 04/28 20:06:29 413947 CVMWareInfo::_MountVM_VCB4() - Datacenter [Robesonia] Datastore [rsan1fc103] VM Config Dir[REBSDB4]
    10820 3508 04/28 20:06:29 413947 CVMWareInfo::_DownloadConfigFile() - DOWNLOADING VM Config File https://optvmvc01apr.cswg.com/folder/REBSDB4/REBSDB4.vmx?dcPath=Robesonia&dsName=rsan1fc103 to C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\iDataAgent\VirtualServerAgent\2\182\(421c73c6-74eb-f61e-2c24-ad255f1bb82e)\REBSDB4.vmx
    10820 3508 04/28 20:06:31 413947 CVMWareInfo::_CreateVMSnapshot() - Creating Snapshot of VM [REBSDB4] Guid [421c73c6-74eb-f61e-2c24-ad255f1bb82e]
    10820   6 04/28 20:06:31 413947 ### CreateSnapshot_Task --- Started Create Snapshot task task-57973 for VM REBSDB4
    10820   5 04/28 20:06:34 413947 ### _WaitForTask --- Task [task-57972] status [success] waited for [00:00:05.6472724] task took [00:00:05.3119040]   Wait [4/28/2019 8:06:28 PM to 4/28/2019 8:06:34 PM]   Task [4/28/2019 8:06:29 PM to 4/28/2019 8:06:34 PM]
    10820   5 04/28 20:06:34 413947 ### Createsnapshot --- Successfully created Snapshot __GX_BACKUP__ snapshot-8698 from VM REBSAPP4
    10820 1fb4 04/28 20:06:34 413947 CVMWareInfo::_CreateVMSnapshot() - Successfuly created Snapshot [snapshot-8698] of VM [REBSAPP4] Guid [421c5364-4d9b-4203-b5b6-1e7a51f47293]
    10820   5 04/28 20:06:34 413947 ### _GetVMInfoFromVMSnapshotMoref --- in
    10820   5 04/28 20:06:34 413947 ### _GetVMInfoFromVMSnapshotMoref --- Input snapMoref:snapshot-8698
    10820   5 04/28 20:06:34 413947 ### _GetVMInfoFromVMSnapshotMoref --- snapMoref:snapshot-8698
    10820   5 04/28 20:06:37 413947 ### GetVMInfoForVMSnapshot --- Name:REBSAPP4 uuid:421c5364-4d9b-4203-b5b6-1e7a51f47293
    10820 1fb4 04/28 20:06:37 413947 CVMWareInfo::_MountVM_VCB4() - Connecting to VM [REBSAPP4] config [[rsan1fc103] REBSAPP4/REBSAPP4.vmx] MoRef [vm-6067] snapshot [snapshot-8698] for disk access
    10820 1fb4 04/28 20:06:37 413947 CVMDiskInfo::Connect() - Selecting transport mode: san
    10820 2d14 04/28 20:06:37 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Connect for thread 1fb4
    10820 2d14 04/28 20:06:37 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Connect for thread 1fb4
    10820 1fb4 04/28 20:06:37 413947 CVMDiskInfo::Connect() - Connected to VM [REBSAPP4] Guid [421c5364-4d9b-4203-b5b6-1e7a51f47293]
    10820 1fb4 04/28 20:06:37 413947 CVMWareInfo::_VerifyChangeTrackingForDisk() - Verifying Change tracking on Disk [REBSAPP4_1.vmdk]
    10820 1fb4 04/28 20:06:39 413947 CVMWareInfo::_MountVM_VCB4() - Opening Disk [[rsan1fc103] REBSAPP4/REBSAPP4_1.vmdk] as [REBSAPP4_1.vmdk]
    10820 1fb4 04/28 20:06:39 413947 CVMDiskInfo::OpenDisk() - Opening disk [REBSAPP4_1.vmdk] on VM [REBSAPP4] flags [ Readonly ]
    10820 2d14 04/28 20:06:39 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Open for thread 1fb4
    10820   6 04/28 20:06:40 413947 ### _WaitForTask --- Task [task-57973] status [success] waited for [00:00:08.8297132] task took [00:00:08.6165410]   Wait [4/28/2019 8:06:31 PM to 4/28/2019 8:06:40 PM]   Task [4/28/2019 8:06:31 PM to 4/28/2019 8:06:40 PM]
    10820   6 04/28 20:06:40 413947 ### Createsnapshot --- Successfully created Snapshot __GX_BACKUP__ snapshot-8699 from VM REBSDB4
    10820 3508 04/28 20:06:40 413947 CVMWareInfo::_CreateVMSnapshot() - Successfuly created Snapshot [snapshot-8699] of VM [REBSDB4] Guid [421c73c6-74eb-f61e-2c24-ad255f1bb82e]
    10820   6 04/28 20:06:40 413947 ### _GetVMInfoFromVMSnapshotMoref --- in
    10820   6 04/28 20:06:40 413947 ### _GetVMInfoFromVMSnapshotMoref --- Input snapMoref:snapshot-8699
    10820   6 04/28 20:06:40 413947 ### _GetVMInfoFromVMSnapshotMoref --- snapMoref:snapshot-8699
    10820 2d14 04/28 20:06:42 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Open for thread 1fb4
    10820 1fb4 04/28 20:06:42 413947 CVMDiskInfo::Dispatch_VixDiskLib_Open() - VixDiskLib_Open failed Err=36b9 The server refused connection
    10820 1fb4 04/28 20:06:42 413947 CVMWareInfo::_MountVM_VCB4() - Failed to Open Disk [[rsan1fc103] REBSAPP4/REBSAPP4_1.vmdk]
    10820 1fb4 04/28 20:06:42 413947 CVMWareInfo::_VerifyChangeTrackingForDisk() - Verifying Change tracking on Disk [REBSAPP4_2.vmdk]
    10820   6 04/28 20:06:43 413947 ### GetVMInfoForVMSnapshot --- Name:REBSDB4 uuid:421c73c6-74eb-f61e-2c24-ad255f1bb82e
    10820 3508 04/28 20:06:43 413947 CVMWareInfo::_MountVM_VCB4() - Connecting to VM [REBSDB4] config [[rsan1fc103] REBSDB4/REBSDB4.vmx] MoRef [vm-6076] snapshot [snapshot-8699] for disk access
    10820 3508 04/28 20:06:43 413947 CVMDiskInfo::Connect() - Selecting transport mode: san
    10820 2d14 04/28 20:06:43 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Connect for thread 3508
    10820 2d14 04/28 20:06:43 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Connect for thread 3508
    10820 3508 04/28 20:06:43 413947 CVMDiskInfo::Connect() - Connected to VM [REBSDB4] Guid [421c73c6-74eb-f61e-2c24-ad255f1bb82e]
    10820 3508 04/28 20:06:43 413947 CVMWareInfo::_VerifyChangeTrackingForDisk() - Verifying Change tracking on Disk [REBSDB4.vmdk]
    10820 1fb4 04/28 20:06:45 413947 CVMWareInfo::_MountVM_VCB4() - Opening Disk [[rsan1fc103] REBSAPP4/REBSAPP4_2.vmdk] as [REBSAPP4_2.vmdk]
    10820 1fb4 04/28 20:06:45 413947 CVMDiskInfo::OpenDisk() - Opening disk [REBSAPP4_2.vmdk] on VM [REBSAPP4] flags [ Readonly ]
    10820 2d14 04/28 20:06:45 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Open for thread 1fb4
    10820 3508 04/28 20:06:47 413947 CVMWareInfo::_MountVM_VCB4() - Opening Disk [[rsan1fc103] REBSDB4/REBSDB4.vmdk] as [REBSDB4.vmdk]
    10820 3508 04/28 20:06:47 413947 CVMDiskInfo::OpenDisk() - Opening disk [REBSDB4.vmdk] on VM [REBSDB4] flags [ Readonly ]
    10820 2d14 04/28 20:06:48 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Open for thread 1fb4
    10820 1fb4 04/28 20:06:48 413947 CVMDiskInfo::Dispatch_VixDiskLib_Open() - VixDiskLib_Open failed Err=36b9 The server refused connection
    10820 1fb4 04/28 20:06:48 413947 CVMWareInfo::_MountVM_VCB4() - Failed to Open Disk [[rsan1fc103] REBSAPP4/REBSAPP4_2.vmdk]
    10820 2d14 04/28 20:06:48 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Open for thread 3508
    10820 1fb4 04/28 20:06:48 413947 CVMWareInfo::_MountVM_VCB4() - Unable to open any disks on VM REBSAPP4 2 attempted
    10820 1fb4 04/28 20:06:48 413947 CVMWareInfo::MountVM() - MountVM_VCB4() failed!!
    10820 1fb4 04/28 20:06:48 413947 CVMWareInfo::_UnmountVM_VCB4() - Unmounting Disks for VM [REBSAPP4]
    10820 2d14 04/28 20:06:51 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Open for thread 3508
    10820 3508 04/28 20:06:51 413947 CVMDiskInfo::Dispatch_VixDiskLib_Open() - VixDiskLib_Open failed Err=36b9 The server refused connection
    10820 3508 04/28 20:06:51 413947 CVMWareInfo::_MountVM_VCB4() - Failed to Open Disk [[rsan1fc103] REBSDB4/REBSDB4.vmdk]
    10820 2d14 04/28 20:06:51 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Disconnect for thread 1fb4
    10820 2d14 04/28 20:06:51 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Disconnect for thread 1fb4
    10820 3508 04/28 20:06:51 413947 CVMWareInfo::_VerifyChangeTrackingForDisk() - Verifying Change tracking on Disk [REBSDB4_1.vmdk]
    10820 2d14 04/28 20:06:51 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Cleanup for thread 1fb4
    10820 2d14 04/28 20:06:51 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Cleanup for thread 1fb4
    10820 1fb4 04/28 20:06:51 413947 CVMWareInfo::_RemoveVMSnapshot() - Removing Snapshot [snapshot-8698] of VM [REBSAPP4] Guid [421c5364-4d9b-4203-b5b6-1e7a51f47293]
    10820   5 04/28 20:06:51 413947 ### RemoveSnapshot --- Removing Snapshot __GX_BACKUP__ snapshot-8698 from VM REBSAPP4
    10820   5 04/28 20:06:51 413947 ### RemoveSnapshot --- Started remove Snapshot task task-57976 for VM REBSAPP4 Snapshot snapshot-8698
    10820   5 04/28 20:06:55 413947 ### _WaitForTask --- Task [task-57976] status [success] waited for [00:00:04.1808536] task took [00:00:03.5218020]   Wait [4/28/2019 8:06:51 PM to 4/28/2019 8:06:55 PM]   Task [4/28/2019 8:06:51 PM to 4/28/2019 8:06:55 PM]
    10820   5 04/28 20:06:55 413947 ### RemoveSnapshot --- Successfully removed Snapshot __GX_BACKUP__ snapshot-8698 from VM REBSAPP4
    10820 1fb4 04/28 20:06:55 413947 CVMWareInfo::_RemoveVMSnapshot() - Successfuly removed Snapshot of VM [REBSAPP4] Guid [421c5364-4d9b-4203-b5b6-1e7a51f47293]
    10820 1fb4 04/28 20:06:55 413947 vsbkp::CheckVMInfoError() - VM [REBSAPP4] Error opening Virtual Machine disk(s).  Please ensure that the proxy is able to communicate with the ESX host and resolve the ESX host address.  Also verify that the disks types configured to the virtual machine are supported.
    10820 1fb4 04/28 20:06:55 413947 CVMWareInfo::_UnmountVM_VCB4() - Unmounting Disks for VM [REBSAPP4]
    10820 1fb4 04/28 20:06:55 413947 vsbkp::HandleVMComplete() - Skipped VM [REBSAPP4]
    10820 1fb4 04/28 20:06:55 413947 JM Client  CVJobClient::processXmlReq(), got response.
    10820 1e84 04/28 20:06:55 413947 vsbkp::Wait() - Done processing VM REBSAPP4 - SKIPPED
    10820 1e84 04/28 20:06:55 413947 vsbkp::BackupAllVM() - Processing vmName [REBSAPP7]; vmGuid [423b28b6-9695-670f-7884-c92b4827fee3]
    10820 1e84 04/28 20:06:55 413947 vsbkp::BackupAllVM() - Invoking the thread operation
    10820 1e84 04/28 20:06:55 413947 vsbkp::BackupAllVM() - Thread id is 3
    10820 1fb4 04/28 20:06:55 413947 CCVAPipelayer::SetRestartContext() - Setting restart context to 3
    10820 1fb4 04/28 20:06:55 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 291 to MediaAgent, Waiting for Response...
    10820 1e84 04/28 20:06:55 413947 vsbkp::BackupAllVM() - Waiting for other threads to complete..
    10820 1fb4 04/28 20:06:55 ###### [PIPELAYER  ] Tail response = Current Restart Context has been set to 3 Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 291 EventError = 0
    10820 1fb4 04/28 20:06:56 413947 CVMWareInfo::_MountVM_VCB4() - Mounting VM:[REBSAPP7] with GUID:[423b28b6-9695-670f-7884-c92b4827fee3]
    10820 3508 04/28 20:06:58 413947 CVMWareInfo::_MountVM_VCB4() - Opening Disk [[rsan1fc103] REBSDB4/REBSDB4_1.vmdk] as [REBSDB4_1.vmdk]
    10820 3508 04/28 20:06:58 413947 CVMDiskInfo::OpenDisk() - Opening disk [REBSDB4_1.vmdk] on VM [REBSDB4] flags [ Readonly ]
    10820 2d14 04/28 20:06:58 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Open for thread 3508
    10820 2d14 04/28 20:07:03 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Open for thread 3508
    10820 3508 04/28 20:07:03 413947 CVMDiskInfo::Dispatch_VixDiskLib_Open() - VixDiskLib_Open failed Err=36b9 The server refused connection
    10820 3508 04/28 20:07:03 413947 CVMWareInfo::_MountVM_VCB4() - Failed to Open Disk [[rsan1fc103] REBSDB4/REBSDB4_1.vmdk]
    10820 3508 04/28 20:07:03 413947 CVMWareInfo::_VerifyChangeTrackingForDisk() - Verifying Change tracking on Disk [REBSDB4_2.vmdk]
    10820 3508 04/28 20:07:08 413947 CVMWareInfo::_MountVM_VCB4() - Opening Disk [[rsan1fc103] REBSDB4/REBSDB4_2.vmdk] as [REBSDB4_2.vmdk]
    10820 3508 04/28 20:07:08 413947 CVMDiskInfo::OpenDisk() - Opening disk [REBSDB4_2.vmdk] on VM [REBSDB4] flags [ Readonly ]
    10820 2d14 04/28 20:07:08 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Open for thread 3508
    10820 1fb4 04/28 20:07:09 413947 CVMWareInfo::_MountVM_VCB4() - Mounting VM [REBSAPP7] config [[ROB_VMS] REBSAPP7/REBSAPP7.vmx] Moref [vm-6078] hosted by server[robesx02pr.cswg.com] version[VMware ESXi 6.5.0 build-10719125] and HW version[vmx-08]
    10820 1fb4 04/28 20:07:09 413947 CVMWareInfo::_MountVM_VCB4() - Change tracking is already enabled on VM [REBSAPP7]
    10820 1fb4 04/28 20:07:09 413947 CVMWareInfo::_MountVM_VCB4() - Datacenter [Robesonia] Datastore [ROB_VMS] VM Config Dir[REBSAPP7]
    10820 1fb4 04/28 20:07:09 413947 CVMWareInfo::_DownloadConfigFile() - DOWNLOADING VM Config File https://optvmvc01apr.cswg.com/folder/REBSAPP7/REBSAPP7.vmx?dcPath=Robesonia&dsName=ROB_VMS to C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\iDataAgent\VirtualServerAgent\2\182\(423b28b6-9695-670f-7884-c92b4827fee3)\REBSAPP7.vmx
    10820 1fb4 04/28 20:07:12 413947 CVMWareInfo::_CreateVMSnapshot() - Creating Snapshot of VM [REBSAPP7] Guid [423b28b6-9695-670f-7884-c92b4827fee3]
    10820 2d14 04/28 20:07:12 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Open for thread 3508
    10820 3508 04/28 20:07:12 413947 CVMDiskInfo::Dispatch_VixDiskLib_Open() - VixDiskLib_Open failed Err=36b9 The server refused connection
    10820 3508 04/28 20:07:12 413947 CVMWareInfo::_MountVM_VCB4() - Failed to Open Disk [[rsan1fc103] REBSDB4/REBSDB4_2.vmdk]
    10820 3508 04/28 20:07:12 413947 CVMWareInfo::_VerifyChangeTrackingForDisk() - Verifying Change tracking on Disk [REBSDB4_3.vmdk]
    10820   5 04/28 20:07:12 413947 ### CreateSnapshot_Task --- Started Create Snapshot task task-57978 for VM REBSAPP7
    10820   5 04/28 20:07:17 413947 ### _WaitForTask --- Task [task-57978] status [success] waited for [00:00:05.3976692] task took [00:00:05.0090970]   Wait [4/28/2019 8:07:12 PM to 4/28/2019 8:07:17 PM]   Task [4/28/2019 8:07:12 PM to 4/28/2019 8:07:17 PM]
    10820   5 04/28 20:07:17 413947 ### Createsnapshot --- Successfully created Snapshot __GX_BACKUP__ snapshot-8700 from VM REBSAPP7
    10820 1fb4 04/28 20:07:17 413947 CVMWareInfo::_CreateVMSnapshot() - Successfuly created Snapshot [snapshot-8700] of VM [REBSAPP7] Guid [423b28b6-9695-670f-7884-c92b4827fee3]
    10820   5 04/28 20:07:17 413947 ### _GetVMInfoFromVMSnapshotMoref --- in
    10820   5 04/28 20:07:18 413947 ### _GetVMInfoFromVMSnapshotMoref --- Input snapMoref:snapshot-8700
    10820   5 04/28 20:07:18 413947 ### _GetVMInfoFromVMSnapshotMoref --- snapMoref:snapshot-8700
    10820 3508 04/28 20:07:18 413947 CVMWareInfo::_MountVM_VCB4() - Opening Disk [[rsan1fc103] REBSDB4/REBSDB4_3.vmdk] as [REBSDB4_3.vmdk]
    10820 3508 04/28 20:07:18 413947 CVMDiskInfo::OpenDisk() - Opening disk [REBSDB4_3.vmdk] on VM [REBSDB4] flags [ Readonly ]
    10820 2d14 04/28 20:07:18 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Open for thread 3508
    10820   5 04/28 20:07:21 413947 ### GetVMInfoForVMSnapshot --- Name:REBSAPP7 uuid:423b28b6-9695-670f-7884-c92b4827fee3
    10820 1fb4 04/28 20:07:21 413947 CVMWareInfo::_MountVM_VCB4() - Connecting to VM [REBSAPP7] config [[ROB_VMS] REBSAPP7/REBSAPP7.vmx] MoRef [vm-6078] snapshot [snapshot-8700] for disk access
    10820 1fb4 04/28 20:07:21 413947 CVMDiskInfo::Connect() - Selecting transport mode: san
    10820 2d14 04/28 20:07:22 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Open for thread 3508
    10820 3508 04/28 20:07:22 413947 CVMDiskInfo::Dispatch_VixDiskLib_Open() - VixDiskLib_Open failed Err=36b9 The server refused connection
    10820 3508 04/28 20:07:22 413947 CVMWareInfo::_MountVM_VCB4() - Failed to Open Disk [[rsan1fc103] REBSDB4/REBSDB4_3.vmdk]
    10820 2d14 04/28 20:07:22 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Connect for thread 1fb4
    10820 3508 04/28 20:07:22 413947 CVMWareInfo::_VerifyChangeTrackingForDisk() - Verifying Change tracking on Disk [REBSDB4_4.vmdk]
    10820 2d14 04/28 20:07:22 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Connect for thread 1fb4
    10820 1fb4 04/28 20:07:22 413947 CVMDiskInfo::Connect() - Connected to VM [REBSAPP7] Guid [423b28b6-9695-670f-7884-c92b4827fee3]
    10820 1fb4 04/28 20:07:22 413947 CVMWareInfo::_VerifyChangeTrackingForDisk() - Verifying Change tracking on Disk [REBSAPP7_2.vmdk]
    10820 1fb4 04/28 20:07:27 413947 CVMWareInfo::_MountVM_VCB4() - Opening Disk [[ROB_VMS] REBSAPP7/REBSAPP7_2.vmdk] as [REBSAPP7_2.vmdk]
    10820 1fb4 04/28 20:07:27 413947 CVMDiskInfo::OpenDisk() - Opening disk [REBSAPP7_2.vmdk] on VM [REBSAPP7] flags [ Readonly ]
    10820 2d14 04/28 20:07:27 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Open for thread 1fb4
    10820 3508 04/28 20:07:29 413947 CVMWareInfo::_MountVM_VCB4() - Opening Disk [[rsan1fc103] REBSDB4/REBSDB4_4.vmdk] as [REBSDB4_4.vmdk]
    10820 3508 04/28 20:07:29 413947 CVMDiskInfo::OpenDisk() - Opening disk [REBSDB4_4.vmdk] on VM [REBSDB4] flags [ Readonly ]
    10820 2d14 04/28 20:07:32 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Open for thread 1fb4
    10820 1fb4 04/28 20:07:32 413947 CVMDiskInfo::Dispatch_VixDiskLib_Open() - VixDiskLib_Open failed Err=36b9 The server refused connection
    10820 1fb4 04/28 20:07:32 413947 CVMWareInfo::_MountVM_VCB4() - Failed to Open Disk [[ROB_VMS] REBSAPP7/REBSAPP7_2.vmdk]
    10820 2d14 04/28 20:07:32 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Open for thread 3508
    10820 1fb4 04/28 20:07:32 413947 CVMWareInfo::_VerifyChangeTrackingForDisk() - Verifying Change tracking on Disk [REBSAPP7_3.vmdk]
    10820 2d14 04/28 20:07:35 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Open for thread 3508
    10820 3508 04/28 20:07:35 413947 CVMDiskInfo::Dispatch_VixDiskLib_Open() - VixDiskLib_Open failed Err=36b9 The server refused connection
    10820 3508 04/28 20:07:35 413947 CVMWareInfo::_MountVM_VCB4() - Failed to Open Disk [[rsan1fc103] REBSDB4/REBSDB4_4.vmdk]
    10820 3508 04/28 20:07:35 413947 CVMWareInfo::_MountVM_VCB4() - Unable to open any disks on VM REBSDB4 5 attempted
    10820 3508 04/28 20:07:35 413947 CVMWareInfo::MountVM() - MountVM_VCB4() failed!!
    10820 3508 04/28 20:07:35 413947 CVMWareInfo::_UnmountVM_VCB4() - Unmounting Disks for VM [REBSDB4]
    10820 2d14 04/28 20:07:35 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Disconnect for thread 3508
    10820 2d14 04/28 20:07:35 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Disconnect for thread 3508
    10820 2d14 04/28 20:07:35 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Cleanup for thread 3508
    10820 2d14 04/28 20:07:35 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Cleanup for thread 3508
    10820 3508 04/28 20:07:35 413947 CVMWareInfo::_RemoveVMSnapshot() - Removing Snapshot [snapshot-8699] of VM [REBSDB4] Guid [421c73c6-74eb-f61e-2c24-ad255f1bb82e]
    10820   6 04/28 20:07:35 413947 ### RemoveSnapshot --- Removing Snapshot __GX_BACKUP__ snapshot-8699 from VM REBSDB4
    10820   6 04/28 20:07:35 413947 ### RemoveSnapshot --- Started remove Snapshot task task-57979 for VM REBSDB4 Snapshot snapshot-8699
    10820 1fb4 04/28 20:07:36 413947 CVMWareInfo::_MountVM_VCB4() - Opening Disk [[ROB_VMS] REBSAPP7/REBSAPP7_3.vmdk] as [REBSAPP7_3.vmdk]
    10820 1fb4 04/28 20:07:36 413947 CVMDiskInfo::OpenDisk() - Opening disk [REBSAPP7_3.vmdk] on VM [REBSAPP7] flags [ Readonly ]
    10820 2d14 04/28 20:07:36 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Open for thread 1fb4
    10820 2d14 04/28 20:07:38 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Open for thread 1fb4
    10820 1fb4 04/28 20:07:38 413947 CVMDiskInfo::Dispatch_VixDiskLib_Open() - VixDiskLib_Open failed Err=36b9 The server refused connection
    10820 1fb4 04/28 20:07:38 413947 CVMWareInfo::_MountVM_VCB4() - Failed to Open Disk [[ROB_VMS] REBSAPP7/REBSAPP7_3.vmdk]
    10820 1fb4 04/28 20:07:38 413947 CVMWareInfo::_MountVM_VCB4() - Unable to open any disks on VM REBSAPP7 2 attempted
    10820 1fb4 04/28 20:07:38 413947 CVMWareInfo::MountVM() - MountVM_VCB4() failed!!
    10820 1fb4 04/28 20:07:38 413947 CVMWareInfo::_UnmountVM_VCB4() - Unmounting Disks for VM [REBSAPP7]
    10820 2d14 04/28 20:07:38 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Disconnect for thread 1fb4
    10820 2d14 04/28 20:07:38 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Disconnect for thread 1fb4
    10820 2d14 04/28 20:07:38 413947 CVMDiskInfo::_VixDiskLibThread() - Calling VixDiskLib_Cleanup for thread 1fb4
    10820 2d14 04/28 20:07:38 413947 CVMDiskInfo::_VixDiskLibThread() - Completed VixDiskLib_Cleanup for thread 1fb4
    10820 1fb4 04/28 20:07:38 413947 CVMWareInfo::_RemoveVMSnapshot() - Removing Snapshot [snapshot-8700] of VM [REBSAPP7] Guid [423b28b6-9695-670f-7884-c92b4827fee3]
    10820   5 04/28 20:07:38 413947 ### RemoveSnapshot --- Removing Snapshot __GX_BACKUP__ snapshot-8700 from VM REBSAPP7
    10820   5 04/28 20:07:38 413947 ### RemoveSnapshot --- Started remove Snapshot task task-57981 for VM REBSAPP7 Snapshot snapshot-8700
    10820   5 04/28 20:07:41 413947 ### _WaitForTask --- Task [task-57981] status [success] waited for [00:00:02.9016372] task took [00:00:02.7311900]   Wait [4/28/2019 8:07:38 PM to 4/28/2019 8:07:41 PM]   Task [4/28/2019 8:07:38 PM to 4/28/2019 8:07:41 PM]
    10820   5 04/28 20:07:41 413947 ### RemoveSnapshot --- Successfully removed Snapshot __GX_BACKUP__ snapshot-8700 from VM REBSAPP7
    10820 1fb4 04/28 20:07:41 413947 CVMWareInfo::_RemoveVMSnapshot() - Successfuly removed Snapshot of VM [REBSAPP7] Guid [423b28b6-9695-670f-7884-c92b4827fee3]
    10820 1fb4 04/28 20:07:41 413947 vsbkp::CheckVMInfoError() - VM [REBSAPP7] Error opening Virtual Machine disk(s).  Please ensure that the proxy is able to communicate with the ESX host and resolve the ESX host address.  Also verify that the disks types configured to the virtual machine are supported.
    10820 1fb4 04/28 20:07:41 413947 CVMWareInfo::_UnmountVM_VCB4() - Unmounting Disks for VM [REBSAPP7]
    10820 1fb4 04/28 20:07:41 413947 vsbkp::HandleVMComplete() - Skipped VM [REBSAPP7]
    10820 1fb4 04/28 20:07:41 413947 JM Client  CVJobClient::processXmlReq(), got response.
    10820 1e84 04/28 20:07:41 413947 vsbkp::Wait() - Done processing VM REBSAPP7 - SKIPPED
    10820 1e84 04/28 20:07:41 413947 vsbkp::BackupAllVM() - Closing archive file for backup object 2
    10820 1e84 04/28 20:07:41 413947 vsArchive::close() - Closing archive file...
    10820 1e84 04/28 20:07:41 413947 CCVAPipelayer::CloseArchiveFile() - Closing archive file[afilenum=773409] in BACKUP
    10820 1e84 04/28 20:07:41 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 132 to MediaAgent, Waiting for Response...
    10820 1e84 04/28 20:07:42 ###### [PIPELAYER  ] Tail response = Close archive file succeeded Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 132 EventError = 0
    10820 1e84 04/28 20:07:42 413947 CVArchive::ClosePipeline() - Closing Pipeline
    10820 1e84 04/28 20:07:42 413947 CVArchive::ClosePipeline() - Reseting allocated stream
    10820 1e84 04/28 20:07:42 413947 CCVAPipelayer::ClosePipeline() - About to destroy Data Mover
    10820 1e84 04/28 20:07:42 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 133 to MediaAgent, Waiting for Response...
    10820 1e84 04/28 20:07:43 ###### [PIPELAYER  ] Tail response = DataMover destroyed Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 133 EventError = 0
    10820 1e84 04/28 20:07:43 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 2 to MediaAgent, Waiting for Response...
    10820 36dc 04/28 20:07:43 413947 CDeDupCache::Uninitialize():..==== DedupCache statistics ====..
    10820 36dc 04/28 20:07:43 413947 Stat- Dedupe. duration        - [28,April,19 08:06:07  ~  28,April,19 08:07:43] 00:01:36 (96)
    10820 36dc 04/28 20:07:43 413947 Stat- [Sig. Processed - 0][Inserted - 0] [Found Local - 0] [Found remote - 0] [Found sealed-store - 0]
    10820 36dc 04/28 20:07:43 413947 Stat- [Total Application Data - 0 (0.00 GB) ] [Total Data Sent on Network - 0 (0.00 GB) ] [NonDeduplicatable Data  - 0 (0.00 GB) ] [Reduced - 0.00 percent]
    10820 36dc 04/28 20:07:43 413947 [Number of signatures processed - 0]
    10820 36dc 04/28 20:07:43 413947 [New signatures encountered and inserted to primary - 0]
    10820 36dc 04/28 20:07:43 413947 Stat- [Total DedupCache time - 0.00 ][Cache time - 0.00 ][SIDB Lookup time - 0.00][Send time - 0.000000][CLDB Query - 0.00 ][CLDB Insert time - 0.00 ]
    10820 36dc 04/28 20:07:43 413947 CDeDupCache::Uninitialize():==== DedupCache Completed ====
    10820 1e84 04/28 20:07:43 ###### [PIPELAYER  ] Tail response = Tail Generated STOP_PL and ready to Terminate Status = 0 dwCode = 0 MsgType = 4 MsgSubType = 2 EventError = 0
    10820 1e84 04/28 20:07:43 413947 SdtNetLink::shutdown() - Performing graceful connection termination
    10820 1e84 04/28 20:07:43 413947 SdtNetLink::closeSocket() - Closing socket connection 2452
    10820 1e84 04/28 20:07:44 413947 vsbkp::BackupAllVM() - Releasing stream reservation 1 threads remaining
    10820 1e84 04/28 20:07:44 413947 JM Client  Freeing [1] stream(s)
    10820   6 04/28 20:07:53 413947 ### _WaitForTask --- Task [task-57979] status [success] waited for [00:00:17.9090296] task took [00:00:17.7108440]   Wait [4/28/2019 8:07:35 PM to 4/28/2019 8:07:53 PM]   Task [4/28/2019 8:07:35 PM to 4/28/2019 8:07:53 PM]
    10820   6 04/28 20:07:53 413947 ### RemoveSnapshot --- Successfully removed Snapshot __GX_BACKUP__ snapshot-8699 from VM REBSDB4
    10820 3508 04/28 20:07:53 413947 CVMWareInfo::_RemoveVMSnapshot() - Successfuly removed Snapshot of VM [REBSDB4] Guid [421c73c6-74eb-f61e-2c24-ad255f1bb82e]
    10820 3508 04/28 20:07:53 413947 vsbkp::CheckVMInfoError() - VM [REBSDB4] Error opening Virtual Machine disk(s).  Please ensure that the proxy is able to communicate with the ESX host and resolve the ESX host address.  Also verify that the disks types configured to the virtual machine are supported.
    10820 3508 04/28 20:07:53 413947 CVMWareInfo::_UnmountVM_VCB4() - Unmounting Disks for VM [REBSDB4]
    10820 3508 04/28 20:07:53 413947 vsbkp::HandleVMComplete() - Skipped VM [REBSDB4]
    10820 3508 04/28 20:07:53 413947 JM Client  CVJobClient::processXmlReq(), got response.
    10820 1e84 04/28 20:07:53 413947 vsbkp::Wait() - Done processing VM REBSDB4 - SKIPPED
    10820 1e84 04/28 20:07:53 413947 vsbkp::BackupAllVM() - Closing archive file for backup object 1
    10820 1e84 04/28 20:07:53 413947 vsArchive::close() - Closing archive file...
    10820 1e84 04/28 20:07:53 413947 CCVAPipelayer::CloseArchiveFile() - Closing archive file[afilenum=773410] in BACKUP
    10820 1e84 04/28 20:07:53 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 132 to MediaAgent, Waiting for Response...
    10820 1e84 04/28 20:07:54 ###### [PIPELAYER  ] Tail response = Close archive file succeeded Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 132 EventError = 0
    10820 1e84 04/28 20:07:54 413947 CVArchive::ClosePipeline() - Closing Pipeline
    10820 1e84 04/28 20:07:54 413947 CVArchive::ClosePipeline() - Reseting allocated stream
    10820 1e84 04/28 20:07:55 413947 CCVAPipelayer::ClosePipeline() - About to destroy Data Mover
    10820 1e84 04/28 20:07:55 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 133 to MediaAgent, Waiting for Response...
    10820 1e84 04/28 20:07:55 ###### [PIPELAYER  ] Tail response = DataMover destroyed Status = 0 dwCode = 0 MsgType = 16 MsgSubType = 133 EventError = 0
    10820 1e84 04/28 20:07:55 413947 CCVAPipelayer::SendCommandToDSBackup() - Sent Command 2 to MediaAgent, Waiting for Response...
    10820 36dc 04/28 20:07:55 413947 CDeDupCache::Uninitialize():..==== DedupCache statistics ====..
    10820 36dc 04/28 20:07:55 413947 Stat- Dedupe. duration        - [28,April,19 08:06:13  ~  28,April,19 08:07:55] 00:01:42 (102)
    10820 36dc 04/28 20:07:55 413947 Stat- [Sig. Processed - 0][Inserted - 0] [Found Local - 0] [Found remote - 0] [Found sealed-store - 0]
    10820 36dc 04/28 20:07:55 413947 Stat- [Total Application Data - 0 (0.00 GB) ] [Total Data Sent on Network - 0 (0.00 GB) ] [NonDeduplicatable Data  - 0 (0.00 GB) ] [Reduced - 0.00 percent]
    10820 36dc 04/28 20:07:55 413947 [Number of signatures processed - 0]
    10820 36dc 04/28 20:07:55 413947 [New signatures encountered and inserted to primary - 0]
    10820 36dc 04/28 20:07:55 413947 Stat- [Total DedupCache time - 0.00 ][Cache time - 0.00 ][SIDB Lookup time - 0.00][Send time - 0.000000][CLDB Query - 0.00 ][CLDB Insert time - 0.00 ]
    10820 36dc 04/28 20:07:55 413947 CDeDupCache::Uninitialize():==== DedupCache Completed ====
    10820 1e84 04/28 20:07:56 ###### [PIPELAYER  ] Tail response = Tail Generated STOP_PL and ready to Terminate Status = 0 dwCode = 0 MsgType = 4 MsgSubType = 2 EventError = 0
    10820 1e84 04/28 20:07:56 413947 SdtNetLink::shutdown() - Performing graceful connection termination
    10820 1e84 04/28 20:07:56 413947 SdtNetLink::closeSocket() - Closing socket connection 2812
    10820 1e84 04/28 20:07:57 413947 vsbkp::BackupAllVM() - Holding reservation on last stream
    10820 1e84 04/28 20:07:57 413947 vsbkp::BackupAllVM() - No VM was backed up
    10820 1e84 04/28 20:07:57 413947 vsbkp::deinit() - Phase success: [false]
    10820 1e84 04/28 20:07:57 413947 JOBRESULTSTABLE(C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\413947\JobResults): removing copy 'C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\413947'
    10820 1e84 04/28 20:07:57 413947 BKP CALLED COMPLETE (JOB Status::FAIL), 413947. Token [413947:4:1]
    10820 24f4 04/28 20:07:59 413947 CVJobCtrlLog::unregisterProcess(): successfuly removed file [C:\Program Files\CommVault\Simpana\Base\JobControl\10.820]
    10820 1e84 04/28 20:07:59 413947 vsbkp::deinit() - Phase success: [true]





  • Re: Virtual server backups are failing - no CV Support any longer for this commcell
    Posted: 04-29-2019, 4:23 PM

    I found a old post with similar error, try it it may help

    http://sso.forum.commvault.com/forums/thread/30028.aspx

    Also i saw an error

    10820 1fb4 04/28 20:07:41 413947 vsbkp::CheckVMInfoError() - VM [REBSAPP7] Error opening Virtual Machine disk(s).  Please ensure that the proxy is able to communicate with the ESX host and resolve the ESX host address.  Also verify that the disks types configured to the virtual machine are supported.

     

    It can be due to proxy media agent does not have access to the data store/LUN . if the backup is configured over SAN , try changing the transport mode to Auto or NBD in the properties of the subclient 

     

  • Re: Virtual server backups are failing - no CV Support any longer for this commcell
    Posted: 05-09-2019, 12:01 PM
    • Aplynx is not online. Last active: 09-19-2019, 11:14 AM Liam
    • Top 10 Contributor
    • Joined on 05-04-2010
    • New Jersey
    • Master
    • Points 1,707

    Need the vixdisklib.log for the same time frame. It's an echo of the VDDK so we'll see what VMware is reporting at that time. 

The content of the forums, threads and posts reflects the thoughts and opinions of each author, and does not represent the thoughts, opinions, plans or strategies of Commvault Systems, Inc. ("Commvault") and Commvault undertakes no obligation to update, correct or modify any statements made in this forum. Any and all third party links, statements, comments, or feedback posted to, or otherwise provided by this forum, thread or post are not affiliated with, nor endorsed by, Commvault.
Commvault, Commvault and logo, the “CV” logo, Commvault Systems, Solving Forward, SIM, Singular Information Management, Simpana, Commvault Galaxy, Unified Data Management, QiNetix, Quick Recovery, QR, CommNet, GridStor, Vault Tracker, InnerVault, QuickSnap, QSnap, Recovery Director, CommServe, CommCell, SnapProtect, ROMS, and CommValue, are trademarks or registered trademarks of Commvault Systems, Inc. All other third party brands, products, service names, trademarks, or registered service marks are the property of and used to identify the products or services of their respective owners. All specifications are subject to change without notice.
Close
Copyright © 2019 Commvault | All Rights Reserved. | Legal | Privacy Policy