@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ Machine : 701-nfcommserve01 File : Licensing_1.log @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 8820 31f8 05/25 15:00:09 1836347 Check license: appType [22] Name [Oracle Database] on client/library [781]- Valid @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ Machine : 701-nfcommserve01 File : SrvOraAgent.log @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 2288 4d64 05/25 15:00:17 1836347 ::Initialize2() - m_jobControl.init(NONCONTROLMONITOR) <1836347:4:1> 2288 4d64 05/25 15:00:17 1836347 Init() - Initializing job control [token=1836347:4:1,cn=701-nfcommserve01], serverName [701-nfcommserve01.custcbb.local], ControlFlag [7], Job Id [1836347] 2288 4d64 05/25 15:00:17 1836347 CVJobCtrlLog::registerProcess(): successfully created file [D:\Program Files\CommVault\Simpana\Base\JobControl\2.288] 2288 4d64 05/25 15:00:17 1836347 OraAgentBase::JobObjectInitialize() - [1836347] getting the new m_jobObject for CommServer=<701-nfcommserve01.custcbb.local> 2288 4d64 05/25 15:00:17 1836347 OraJobObject::OraJobObject() - new m_jobObjectB 2288 4d64 05/25 15:00:17 1836347 JM Client CVBkpJobClient::init(): Initializing job object with token [1836347:4:1]. 2288 4d64 05/25 15:00:17 1836347 SrvOraAgent::AppMgrInit() - m_bMergeIncremental=[0] 2288 4d64 05/25 15:00:17 1836347 ::GetArchiveMgrInfo() - change m_initArgs.streamNumber value from old [100] to new one [2] for DATA 2288 4d64 05/25 15:00:17 1836347 ::CheckIfNothingToBackup() - m_logsBackup=0 m_dataBackup=1 2288 4d64 05/25 15:00:18 1836347 ::RecvOraParams() - m_oraObjNameList : B F A F 2288 4d64 05/25 15:00:18 1836347 ::RecvOraParams() - m_initArgs.jobID : 1836347 2288 4d64 05/25 15:00:18 1836347 ::RecvOraParams() - appType = 22|m_ctrlRestore=0|m_dataRestore = 0, useInstanceId=110 2288 4d64 05/25 15:00:18 1836347 ::RecvOraParams() - m_task=NULL|m_task->getDestinationInstanceId=-1|m_initArgs.instanceId=110 2288 4d64 05/25 15:00:18 1836347 SrvOraAgent::LoadRmanCatalog() - rmanName=[rdsk] rmanService=[RCAT] rmanNoCatalog=0. 2288 4d64 05/25 15:00:18 1836347 ::PreBrowse() - m_bCustomizedScript = 0 2288 4d64 05/25 15:00:18 1836347 SrvSingleInstanceAgent::DoClientBrowse() - dataAgentAttach-> HostName=172.16.4.218*proddb01*8400*8402 start... 2288 4d64 05/25 15:00:18 1836347 SrvSingleInstanceAgent::DoClientBrowse() - after dataAgentAttach-> HostName=172.16.4.218*proddb01*8400*8402. 2288 4d64 05/25 15:00:18 1836347 ::GetCvsProtocolVersion() - Protocol version=4097 clientVersionIsLessThan3_7_1=0 clientVersionIsBiggerThan5_0=1. 2288 4d64 05/25 15:00:18 1836347 SrvSingleInstanceAgent::DoClientBrowse() - extended options : 2288 4d64 05/25 15:00:19 1836347 SrvSingleInstanceAgent::DoClientBrowse() - Client Browse Start 2288 4d64 05/25 15:00:24 1836347 SrvOraAgent::ProcessClientBrowseMsg() - Galaxy install Instance: Instance001 2288 4d64 05/25 15:00:24 1836347 ::UpdateRepository() - CreateMutex(SrvOraAgentBrowseInst110) 2288 4d64 05/25 15:00:25 1836347 ::RmanBuildBackupCommandScript() - m_bPreview : 0 2288 4d64 05/25 15:00:25 1836347 ::RmanBuildBackupCommandScript() - m_bCustomizedScript = 0 2288 4d64 05/25 15:00:25 1836347 OraAgentBase::BackupPieceFormat() - Using default backup piece format [f7686_1836347_%d_%U] 2288 4d64 05/25 15:00:25 1836347 ::RmanBuildBackupCommandScript() - Enter ... 2288 4d64 05/25 15:00:25 1836347 ::RmanBuildBackupCommandScript() - sRMANOPTPERFFIX = 1 2288 4d64 05/25 15:00:25 1836347 ::RmanBuildBackupCommandScript() - DISKRATIO = -1 2288 4d64 05/25 15:00:25 1836347 ::RmanBuildBackupCommandScript() - TableSpace List : (null) Datafile List : (null) 2288 4d64 05/25 15:00:25 1836347 ::RmanBuildBackupCommandScript() - Backup Mode is 0, MAXCORRUPT is 0 2288 4d64 05/25 15:00:25 1836347 SrvOraAgent::CreateMergeIncrementalScript() - m_bMergeIncremental=[0] m_logsBackup[0] m_initArgs.appType [22] 2288 4d64 05/25 15:00:25 1836347 ::RmanBuildBackupCommandScript() - disableSwitchLogFile=0 2288 4d64 05/25 15:00:25 1836347 ::RmanBuildBackupCommandScript() - EvBkpTask.getOptionULong() for BACKUPARCHLOGOPTIONS_BACKUP_ARCHIVE_LOG_CRITERIA returned typeId: 7 2288 4d64 05/25 15:00:25 1836347 ::RmanBuildBackupCommandScript() - EvBkpTask.getOptionULong() for DELETEARCHLOGOPTIONS_BACKUP_ARCHIVE_LOG_CRITERIA returned typeId: 0 2288 4d64 05/25 15:00:25 1836347 ::RmanBuildBackupCommandScript() - Resync catalog = [false], backupArchiveLog=0 2288 4d64 05/25 15:00:25 1836347 ::AddChannelArgs() - block size=262144 returned from getBlockSize(). 2288 4d64 05/25 15:00:25 1836347 ::AddChannelArgs() - Galaxy install name: Instance001, clientName=proddb01, Oracle sbt library= 2288 4d64 05/25 15:00:25 1836347 ::AddChannelArgs() - Galaxy install name: [Instance001], clientName=[proddb01], Oracle sbt library=[], Client CSHostName=[701-nfcommserve01.custcbb.local], Oracle Version [11.2.0.3.0] 2288 4d64 05/25 15:00:25 1836347 ::AddChannelArgs() - block size=262144 returned from getBlockSize(). 2288 4d64 05/25 15:00:25 1836347 ::AddChannelArgs() - Galaxy install name: Instance001, clientName=proddb01, Oracle sbt library= 2288 4d64 05/25 15:00:25 1836347 ::AddChannelArgs() - Galaxy install name: [Instance001], clientName=[proddb01], Oracle sbt library=[], Client CSHostName=[701-nfcommserve01.custcbb.local], Oracle Version [11.2.0.3.0] 2288 4d64 05/25 15:00:25 1836347 ::RmanBuildBackupCommandScript() - maxBackupSetSize = 0 2288 4d64 05/25 15:00:25 1836347 ::RmanBuildBackupCommandScript() - Section size 0K 2288 4d64 05/25 15:00:25 1836347 OraAgentBase::ParseRmanTagFormat() - user specified tag : 2288 4d64 05/25 15:00:25 1836347 ::RmanBuildBackupCommandScript() - Resync catalog = [false], backupArchiveLog=0 2288 4d64 05/25 15:00:25 1836347 ::SetDataSize() - TblObj.getBackupSize(1147,true)... 2288 4d64 05/25 15:00:25 1836347 ::SetDataSize() - TblObj.getBackupSize() returned maxSize=117612756992,dataSize=70673907712. 2288 4d64 05/25 15:00:25 1836347 ::SetDataSize() - backupLevel=1 setUncompBytesToXfer(0)... 2288 4d64 05/25 15:00:25 1836347 ::SetDataSize() - After m_jobObject->updateInfo(70673907712); 2288 4d64 05/25 15:00:25 1836347 ::WaitClOraAgent() - Client Rman Start 2288 4d64 05/25 15:00:28 1836347 ::WaitClOraAgent() - Rman-Complete:Client Returned to RmanLog=[(null)] 2288 4d64 05/25 15:00:28 1836347 ::WaitClOraAgent() - reply disconnect to Client Ora Agent 2288 4d64 05/25 15:00:28 1836347 ::Close() - SrvOraAgent Closed. 2288 48c0 05/25 15:00:28 1836347 CVJobCtrlLog::unregisterProcess(): successfully removed file [D:\Program Files\CommVault\Simpana\Base\JobControl\2.288] 2288 4d64 05/25 15:00:28 1836347 ::Finalize() - delete m_jobControl ... 2288 4d64 05/25 15:00:28 1836347 OraAgentBase::Finalize() - [1836347] delete m_jobObject. 2288 4d64 05/25 15:00:28 1836347 OraJobObject::~OraJobObject() - After m_jobObject deletion. 2288 4d64 05/25 15:00:28 1836347 ::Finalize() - delete m_event ... 19092 48e0 05/25 15:20:46 1836347 ::Initialize2() - m_jobControl.init(NONCONTROLMONITOR) <1836347:4:2> 19092 48e0 05/25 15:20:46 1836347 Init() - Initializing job control [token=1836347:4:2,cn=701-nfcommserve01], serverName [701-nfcommserve01.custcbb.local], ControlFlag [7], Job Id [1836347] 19092 48e0 05/25 15:20:46 1836347 CVJobCtrlLog::registerProcess(): successfully created file [D:\Program Files\CommVault\Simpana\Base\JobControl\19.092] 19092 48e0 05/25 15:20:46 1836347 OraAgentBase::JobObjectInitialize() - [1836347] getting the new m_jobObject for CommServer=<701-nfcommserve01.custcbb.local> 19092 48e0 05/25 15:20:46 1836347 OraJobObject::OraJobObject() - new m_jobObjectB 19092 48e0 05/25 15:20:46 1836347 JM Client CVBkpJobClient::init(): Initializing job object with token [1836347:4:2]. 19092 48e0 05/25 15:20:46 1836347 SrvOraAgent::AppMgrInit() - m_bMergeIncremental=[0] 19092 48e0 05/25 15:20:46 1836347 ::GetArchiveMgrInfo() - change m_initArgs.streamNumber value from old [100] to new one [2] for DATA 19092 48e0 05/25 15:20:46 1836347 ::CheckIfNothingToBackup() - m_logsBackup=0 m_dataBackup=1 19092 48e0 05/25 15:20:46 1836347 ::RecvOraParams() - m_oraObjNameList : B F A F 19092 48e0 05/25 15:20:46 1836347 ::RecvOraParams() - m_initArgs.jobID : 1836347 19092 48e0 05/25 15:20:46 1836347 ::RecvOraParams() - appType = 22|m_ctrlRestore=0|m_dataRestore = 0, useInstanceId=110 19092 48e0 05/25 15:20:46 1836347 ::RecvOraParams() - m_task=NULL|m_task->getDestinationInstanceId=-1|m_initArgs.instanceId=110 19092 48e0 05/25 15:20:46 1836347 SrvOraAgent::LoadRmanCatalog() - rmanName=[rdsk] rmanService=[RCAT] rmanNoCatalog=0. 19092 48e0 05/25 15:20:46 1836347 ::PreBrowse() - m_bCustomizedScript = 0 19092 48e0 05/25 15:20:46 1836347 SrvSingleInstanceAgent::DoClientBrowse() - dataAgentAttach-> HostName=172.16.4.218*proddb01*8400*8402 start... 19092 48e0 05/25 15:20:48 1836347 SrvSingleInstanceAgent::DoClientBrowse() - after dataAgentAttach-> HostName=172.16.4.218*proddb01*8400*8402. 19092 48e0 05/25 15:20:48 1836347 ::GetCvsProtocolVersion() - Protocol version=4097 clientVersionIsLessThan3_7_1=0 clientVersionIsBiggerThan5_0=1. 19092 48e0 05/25 15:20:48 1836347 SrvSingleInstanceAgent::DoClientBrowse() - extended options : 19092 48e0 05/25 15:20:50 1836347 SrvSingleInstanceAgent::DoClientBrowse() - Client Browse Start 19092 48e0 05/25 15:20:57 1836347 SrvOraAgent::ProcessClientBrowseMsg() - Galaxy install Instance: Instance001 19092 48e0 05/25 15:20:57 1836347 ::UpdateRepository() - CreateMutex(SrvOraAgentBrowseInst110) 19092 48e0 05/25 15:20:58 1836347 ::RmanBuildBackupCommandScript() - m_bPreview : 0 19092 48e0 05/25 15:20:58 1836347 ::RmanBuildBackupCommandScript() - m_bCustomizedScript = 0 19092 48e0 05/25 15:20:58 1836347 OraAgentBase::BackupPieceFormat() - Using default backup piece format [f7686_1836347_%d_%U] 19092 48e0 05/25 15:20:58 1836347 ::RmanBuildBackupCommandScript() - Enter ... 19092 48e0 05/25 15:20:58 1836347 ::RmanBuildBackupCommandScript() - sRMANOPTPERFFIX = 1 19092 48e0 05/25 15:20:58 1836347 ::RmanBuildBackupCommandScript() - DISKRATIO = -1 19092 48e0 05/25 15:20:58 1836347 ::RmanBuildBackupCommandScript() - TableSpace List : (null) Datafile List : (null) 19092 48e0 05/25 15:20:58 1836347 ::RmanBuildBackupCommandScript() - Backup Mode is 0, MAXCORRUPT is 0 19092 48e0 05/25 15:20:58 1836347 SrvOraAgent::CreateMergeIncrementalScript() - m_bMergeIncremental=[0] m_logsBackup[0] m_initArgs.appType [22] 19092 48e0 05/25 15:20:58 1836347 ::RmanBuildBackupCommandScript() - disableSwitchLogFile=0 19092 48e0 05/25 15:20:58 1836347 ::RmanBuildBackupCommandScript() - EvBkpTask.getOptionULong() for BACKUPARCHLOGOPTIONS_BACKUP_ARCHIVE_LOG_CRITERIA returned typeId: 7 19092 48e0 05/25 15:20:58 1836347 ::RmanBuildBackupCommandScript() - EvBkpTask.getOptionULong() for DELETEARCHLOGOPTIONS_BACKUP_ARCHIVE_LOG_CRITERIA returned typeId: 0 19092 48e0 05/25 15:20:58 1836347 ::RmanBuildBackupCommandScript() - Resync catalog = [false], backupArchiveLog=0 19092 48e0 05/25 15:20:58 1836347 ::AddChannelArgs() - block size=262144 returned from getBlockSize(). 19092 48e0 05/25 15:20:58 1836347 ::AddChannelArgs() - Galaxy install name: Instance001, clientName=proddb01, Oracle sbt library= 19092 48e0 05/25 15:20:58 1836347 ::AddChannelArgs() - Galaxy install name: [Instance001], clientName=[proddb01], Oracle sbt library=[], Client CSHostName=[701-nfcommserve01.custcbb.local], Oracle Version [11.2.0.3.0] 19092 48e0 05/25 15:20:58 1836347 ::AddChannelArgs() - block size=262144 returned from getBlockSize(). 19092 48e0 05/25 15:20:58 1836347 ::AddChannelArgs() - Galaxy install name: Instance001, clientName=proddb01, Oracle sbt library= 19092 48e0 05/25 15:20:58 1836347 ::AddChannelArgs() - Galaxy install name: [Instance001], clientName=[proddb01], Oracle sbt library=[], Client CSHostName=[701-nfcommserve01.custcbb.local], Oracle Version [11.2.0.3.0] 19092 48e0 05/25 15:20:58 1836347 ::RmanBuildBackupCommandScript() - maxBackupSetSize = 0 19092 48e0 05/25 15:20:58 1836347 ::RmanBuildBackupCommandScript() - Section size 0K 19092 48e0 05/25 15:20:58 1836347 OraAgentBase::ParseRmanTagFormat() - user specified tag : 19092 48e0 05/25 15:20:58 1836347 ::RmanBuildBackupCommandScript() - Resync catalog = [false], backupArchiveLog=0 19092 48e0 05/25 15:20:58 1836347 ::SetDataSize() - TblObj.getBackupSize(1147,true)... 19092 48e0 05/25 15:20:58 1836347 ::SetDataSize() - TblObj.getBackupSize() returned maxSize=117612756992,dataSize=70809567232. 19092 48e0 05/25 15:20:58 1836347 ::SetDataSize() - backupLevel=1 setUncompBytesToXfer(0)... 19092 48e0 05/25 15:20:58 1836347 ::SetDataSize() - After m_jobObject->updateInfo(70809567232); 19092 48e0 05/25 15:20:59 1836347 ::WaitClOraAgent() - Client Rman Start 19092 48e0 05/25 15:21:02 1836347 ::WaitClOraAgent() - Rman-Complete:Client Returned to RmanLog=[(null)] 19092 48e0 05/25 15:21:02 1836347 ::WaitClOraAgent() - reply disconnect to Client Ora Agent 19092 48e0 05/25 15:21:02 1836347 ::Close() - SrvOraAgent Closed. 19092 3738 05/25 15:21:02 1836347 CVJobCtrlLog::unregisterProcess(): successfully removed file [D:\Program Files\CommVault\Simpana\Base\JobControl\19.092] 19092 48e0 05/25 15:21:02 1836347 ::Finalize() - delete m_jobControl ... 19092 48e0 05/25 15:21:02 1836347 OraAgentBase::Finalize() - [1836347] delete m_jobObject. 19092 48e0 05/25 15:21:02 1836347 OraJobObject::~OraJobObject() - After m_jobObject deletion. 19092 48e0 05/25 15:21:02 1836347 ::Finalize() - delete m_event ... 17384 1b90 05/25 15:41:52 1836347 ::Initialize2() - m_jobControl.init(NONCONTROLMONITOR) <1836347:4:3> 17384 1b90 05/25 15:41:52 1836347 Init() - Initializing job control [token=1836347:4:3,cn=701-nfcommserve01], serverName [701-nfcommserve01.custcbb.local], ControlFlag [7], Job Id [1836347] 17384 1b90 05/25 15:41:52 1836347 CVJobCtrlLog::registerProcess(): successfully created file [D:\Program Files\CommVault\Simpana\Base\JobControl\17.384] 17384 1b90 05/25 15:41:52 1836347 OraAgentBase::JobObjectInitialize() - [1836347] getting the new m_jobObject for CommServer=<701-nfcommserve01.custcbb.local> 17384 1b90 05/25 15:41:52 1836347 OraJobObject::OraJobObject() - new m_jobObjectB 17384 1b90 05/25 15:41:52 1836347 JM Client CVBkpJobClient::init(): Initializing job object with token [1836347:4:3]. 17384 1b90 05/25 15:41:52 1836347 SrvOraAgent::AppMgrInit() - m_bMergeIncremental=[0] 17384 1b90 05/25 15:41:52 1836347 ::GetArchiveMgrInfo() - change m_initArgs.streamNumber value from old [100] to new one [2] for DATA 17384 1b90 05/25 15:41:52 1836347 ::CheckIfNothingToBackup() - m_logsBackup=0 m_dataBackup=1 17384 1b90 05/25 15:41:52 1836347 ::RecvOraParams() - m_oraObjNameList : B F A F 17384 1b90 05/25 15:41:52 1836347 ::RecvOraParams() - m_initArgs.jobID : 1836347 17384 1b90 05/25 15:41:52 1836347 ::RecvOraParams() - appType = 22|m_ctrlRestore=0|m_dataRestore = 0, useInstanceId=110 17384 1b90 05/25 15:41:52 1836347 ::RecvOraParams() - m_task=NULL|m_task->getDestinationInstanceId=-1|m_initArgs.instanceId=110 17384 1b90 05/25 15:41:52 1836347 SrvOraAgent::LoadRmanCatalog() - rmanName=[rdsk] rmanService=[RCAT] rmanNoCatalog=0. 17384 1b90 05/25 15:41:52 1836347 ::PreBrowse() - m_bCustomizedScript = 0 17384 1b90 05/25 15:41:52 1836347 SrvSingleInstanceAgent::DoClientBrowse() - dataAgentAttach-> HostName=172.16.4.218*proddb01*8400*8402 start... 17384 1b90 05/25 15:41:52 1836347 SrvSingleInstanceAgent::DoClientBrowse() - after dataAgentAttach-> HostName=172.16.4.218*proddb01*8400*8402. 17384 1b90 05/25 15:41:52 1836347 ::GetCvsProtocolVersion() - Protocol version=4097 clientVersionIsLessThan3_7_1=0 clientVersionIsBiggerThan5_0=1. 17384 1b90 05/25 15:41:52 1836347 SrvSingleInstanceAgent::DoClientBrowse() - extended options : 17384 1b90 05/25 15:41:54 1836347 SrvSingleInstanceAgent::DoClientBrowse() - Client Browse Start 17384 1b90 05/25 15:42:01 1836347 SrvOraAgent::ProcessClientBrowseMsg() - Galaxy install Instance: Instance001 17384 1b90 05/25 15:42:01 1836347 ::UpdateRepository() - CreateMutex(SrvOraAgentBrowseInst110) 17384 1b90 05/25 15:42:02 1836347 ::RmanBuildBackupCommandScript() - m_bPreview : 0 17384 1b90 05/25 15:42:02 1836347 ::RmanBuildBackupCommandScript() - m_bCustomizedScript = 0 17384 1b90 05/25 15:42:02 1836347 OraAgentBase::BackupPieceFormat() - Using default backup piece format [f7686_1836347_%d_%U] 17384 1b90 05/25 15:42:02 1836347 ::RmanBuildBackupCommandScript() - Enter ... 17384 1b90 05/25 15:42:02 1836347 ::RmanBuildBackupCommandScript() - sRMANOPTPERFFIX = 1 17384 1b90 05/25 15:42:02 1836347 ::RmanBuildBackupCommandScript() - DISKRATIO = -1 17384 1b90 05/25 15:42:02 1836347 ::RmanBuildBackupCommandScript() - TableSpace List : (null) Datafile List : (null) 17384 1b90 05/25 15:42:02 1836347 ::RmanBuildBackupCommandScript() - Backup Mode is 0, MAXCORRUPT is 0 17384 1b90 05/25 15:42:02 1836347 SrvOraAgent::CreateMergeIncrementalScript() - m_bMergeIncremental=[0] m_logsBackup[0] m_initArgs.appType [22] 17384 1b90 05/25 15:42:02 1836347 ::RmanBuildBackupCommandScript() - disableSwitchLogFile=0 17384 1b90 05/25 15:42:02 1836347 ::RmanBuildBackupCommandScript() - EvBkpTask.getOptionULong() for BACKUPARCHLOGOPTIONS_BACKUP_ARCHIVE_LOG_CRITERIA returned typeId: 7 17384 1b90 05/25 15:42:02 1836347 ::RmanBuildBackupCommandScript() - EvBkpTask.getOptionULong() for DELETEARCHLOGOPTIONS_BACKUP_ARCHIVE_LOG_CRITERIA returned typeId: 0 17384 1b90 05/25 15:42:02 1836347 ::RmanBuildBackupCommandScript() - Resync catalog = [false], backupArchiveLog=0 17384 1b90 05/25 15:42:02 1836347 ::AddChannelArgs() - block size=262144 returned from getBlockSize(). 17384 1b90 05/25 15:42:02 1836347 ::AddChannelArgs() - Galaxy install name: Instance001, clientName=proddb01, Oracle sbt library= 17384 1b90 05/25 15:42:02 1836347 ::AddChannelArgs() - Galaxy install name: [Instance001], clientName=[proddb01], Oracle sbt library=[], Client CSHostName=[701-nfcommserve01.custcbb.local], Oracle Version [11.2.0.3.0] 17384 1b90 05/25 15:42:02 1836347 ::AddChannelArgs() - block size=262144 returned from getBlockSize(). 17384 1b90 05/25 15:42:02 1836347 ::AddChannelArgs() - Galaxy install name: Instance001, clientName=proddb01, Oracle sbt library= 17384 1b90 05/25 15:42:02 1836347 ::AddChannelArgs() - Galaxy install name: [Instance001], clientName=[proddb01], Oracle sbt library=[], Client CSHostName=[701-nfcommserve01.custcbb.local], Oracle Version [11.2.0.3.0] 17384 1b90 05/25 15:42:02 1836347 ::RmanBuildBackupCommandScript() - maxBackupSetSize = 0 17384 1b90 05/25 15:42:02 1836347 ::RmanBuildBackupCommandScript() - Section size 0K 17384 1b90 05/25 15:42:02 1836347 OraAgentBase::ParseRmanTagFormat() - user specified tag : 17384 1b90 05/25 15:42:02 1836347 ::RmanBuildBackupCommandScript() - Resync catalog = [false], backupArchiveLog=0 17384 1b90 05/25 15:42:02 1836347 ::SetDataSize() - TblObj.getBackupSize(1147,true)... 17384 1b90 05/25 15:42:02 1836347 ::SetDataSize() - TblObj.getBackupSize() returned maxSize=117612756992,dataSize=70866190336. 17384 1b90 05/25 15:42:02 1836347 ::SetDataSize() - backupLevel=1 setUncompBytesToXfer(0)... 17384 1b90 05/25 15:42:02 1836347 ::SetDataSize() - After m_jobObject->updateInfo(70866190336); 17384 1b90 05/25 15:42:02 1836347 ::WaitClOraAgent() - Client Rman Start 17384 1b90 05/25 15:42:05 1836347 ::WaitClOraAgent() - Rman-Complete:Client Returned to RmanLog=[(null)] 17384 1b90 05/25 15:42:05 1836347 ::WaitClOraAgent() - reply disconnect to Client Ora Agent 17384 1b90 05/25 15:42:05 1836347 ::Close() - SrvOraAgent Closed. 17384 46f4 05/25 15:42:06 1836347 CVJobCtrlLog::unregisterProcess(): successfully removed file [D:\Program Files\CommVault\Simpana\Base\JobControl\17.384] 17384 1b90 05/25 15:42:06 1836347 ::Finalize() - delete m_jobControl ... 17384 1b90 05/25 15:42:06 1836347 OraAgentBase::Finalize() - [1836347] delete m_jobObject. 17384 1b90 05/25 15:42:06 1836347 OraJobObject::~OraJobObject() - After m_jobObject deletion. 17384 1b90 05/25 15:42:06 1836347 ::Finalize() - delete m_event ... 18412 55e4 05/25 16:02:52 1836347 ::Initialize2() - m_jobControl.init(NONCONTROLMONITOR) <1836347:4:4> 18412 55e4 05/25 16:02:52 1836347 Init() - Initializing job control [token=1836347:4:4,cn=701-nfcommserve01], serverName [701-nfcommserve01.custcbb.local], ControlFlag [7], Job Id [1836347] 18412 55e4 05/25 16:02:52 1836347 CVJobCtrlLog::registerProcess(): successfully created file [D:\Program Files\CommVault\Simpana\Base\JobControl\18.412] 18412 55e4 05/25 16:02:52 1836347 OraAgentBase::JobObjectInitialize() - [1836347] getting the new m_jobObject for CommServer=<701-nfcommserve01.custcbb.local> 18412 55e4 05/25 16:02:52 1836347 OraJobObject::OraJobObject() - new m_jobObjectB 18412 55e4 05/25 16:02:52 1836347 JM Client CVBkpJobClient::init(): Initializing job object with token [1836347:4:4]. 18412 55e4 05/25 16:02:52 1836347 SrvOraAgent::AppMgrInit() - m_bMergeIncremental=[0] 18412 55e4 05/25 16:02:52 1836347 ::GetArchiveMgrInfo() - change m_initArgs.streamNumber value from old [100] to new one [2] for DATA 18412 55e4 05/25 16:02:52 1836347 ::CheckIfNothingToBackup() - m_logsBackup=0 m_dataBackup=1 18412 55e4 05/25 16:02:52 1836347 ::RecvOraParams() - m_oraObjNameList : B F A F 18412 55e4 05/25 16:02:52 1836347 ::RecvOraParams() - m_initArgs.jobID : 1836347 18412 55e4 05/25 16:02:52 1836347 ::RecvOraParams() - appType = 22|m_ctrlRestore=0|m_dataRestore = 0, useInstanceId=110 18412 55e4 05/25 16:02:52 1836347 ::RecvOraParams() - m_task=NULL|m_task->getDestinationInstanceId=-1|m_initArgs.instanceId=110 18412 55e4 05/25 16:02:52 1836347 SrvOraAgent::LoadRmanCatalog() - rmanName=[rdsk] rmanService=[RCAT] rmanNoCatalog=0. 18412 55e4 05/25 16:02:52 1836347 ::PreBrowse() - m_bCustomizedScript = 0 18412 55e4 05/25 16:02:52 1836347 SrvSingleInstanceAgent::DoClientBrowse() - dataAgentAttach-> HostName=172.16.4.218*proddb01*8400*8402 start... 18412 55e4 05/25 16:02:52 1836347 SrvSingleInstanceAgent::DoClientBrowse() - after dataAgentAttach-> HostName=172.16.4.218*proddb01*8400*8402. 18412 55e4 05/25 16:02:52 1836347 ::GetCvsProtocolVersion() - Protocol version=4097 clientVersionIsLessThan3_7_1=0 clientVersionIsBiggerThan5_0=1. 18412 55e4 05/25 16:02:52 1836347 SrvSingleInstanceAgent::DoClientBrowse() - extended options : 18412 55e4 05/25 16:02:54 1836347 SrvSingleInstanceAgent::DoClientBrowse() - Client Browse Start 18412 55e4 05/25 16:03:00 1836347 SrvOraAgent::ProcessClientBrowseMsg() - Galaxy install Instance: Instance001 18412 55e4 05/25 16:03:00 1836347 ::UpdateRepository() - CreateMutex(SrvOraAgentBrowseInst110) 18412 55e4 05/25 16:03:01 1836347 ::RmanBuildBackupCommandScript() - m_bPreview : 0 18412 55e4 05/25 16:03:01 1836347 ::RmanBuildBackupCommandScript() - m_bCustomizedScript = 0 18412 55e4 05/25 16:03:01 1836347 OraAgentBase::BackupPieceFormat() - Using default backup piece format [f7686_1836347_%d_%U] 18412 55e4 05/25 16:03:01 1836347 ::RmanBuildBackupCommandScript() - Enter ... 18412 55e4 05/25 16:03:01 1836347 ::RmanBuildBackupCommandScript() - sRMANOPTPERFFIX = 1 18412 55e4 05/25 16:03:01 1836347 ::RmanBuildBackupCommandScript() - DISKRATIO = -1 18412 55e4 05/25 16:03:01 1836347 ::RmanBuildBackupCommandScript() - TableSpace List : (null) Datafile List : (null) 18412 55e4 05/25 16:03:01 1836347 ::RmanBuildBackupCommandScript() - Backup Mode is 0, MAXCORRUPT is 0 18412 55e4 05/25 16:03:01 1836347 SrvOraAgent::CreateMergeIncrementalScript() - m_bMergeIncremental=[0] m_logsBackup[0] m_initArgs.appType [22] 18412 55e4 05/25 16:03:01 1836347 ::RmanBuildBackupCommandScript() - disableSwitchLogFile=0 18412 55e4 05/25 16:03:01 1836347 ::RmanBuildBackupCommandScript() - EvBkpTask.getOptionULong() for BACKUPARCHLOGOPTIONS_BACKUP_ARCHIVE_LOG_CRITERIA returned typeId: 7 18412 55e4 05/25 16:03:01 1836347 ::RmanBuildBackupCommandScript() - EvBkpTask.getOptionULong() for DELETEARCHLOGOPTIONS_BACKUP_ARCHIVE_LOG_CRITERIA returned typeId: 0 18412 55e4 05/25 16:03:01 1836347 ::RmanBuildBackupCommandScript() - Resync catalog = [false], backupArchiveLog=0 18412 55e4 05/25 16:03:01 1836347 ::AddChannelArgs() - block size=262144 returned from getBlockSize(). 18412 55e4 05/25 16:03:01 1836347 ::AddChannelArgs() - Galaxy install name: Instance001, clientName=proddb01, Oracle sbt library= 18412 55e4 05/25 16:03:01 1836347 ::AddChannelArgs() - Galaxy install name: [Instance001], clientName=[proddb01], Oracle sbt library=[], Client CSHostName=[701-nfcommserve01.custcbb.local], Oracle Version [11.2.0.3.0] 18412 55e4 05/25 16:03:01 1836347 ::AddChannelArgs() - block size=262144 returned from getBlockSize(). 18412 55e4 05/25 16:03:01 1836347 ::AddChannelArgs() - Galaxy install name: Instance001, clientName=proddb01, Oracle sbt library= 18412 55e4 05/25 16:03:01 1836347 ::AddChannelArgs() - Galaxy install name: [Instance001], clientName=[proddb01], Oracle sbt library=[], Client CSHostName=[701-nfcommserve01.custcbb.local], Oracle Version [11.2.0.3.0] 18412 55e4 05/25 16:03:01 1836347 ::RmanBuildBackupCommandScript() - maxBackupSetSize = 0 18412 55e4 05/25 16:03:01 1836347 ::RmanBuildBackupCommandScript() - Section size 0K 18412 55e4 05/25 16:03:01 1836347 OraAgentBase::ParseRmanTagFormat() - user specified tag : 18412 55e4 05/25 16:03:01 1836347 ::RmanBuildBackupCommandScript() - Resync catalog = [false], backupArchiveLog=0 18412 55e4 05/25 16:03:01 1836347 ::SetDataSize() - TblObj.getBackupSize(1147,true)... 18412 55e4 05/25 16:03:01 1836347 ::SetDataSize() - TblObj.getBackupSize() returned maxSize=117612756992,dataSize=70937755648. 18412 55e4 05/25 16:03:01 1836347 ::SetDataSize() - backupLevel=1 setUncompBytesToXfer(0)... 18412 55e4 05/25 16:03:02 1836347 ::SetDataSize() - After m_jobObject->updateInfo(70937755648); 18412 55e4 05/25 16:03:02 1836347 ::WaitClOraAgent() - Client Rman Start 18412 55e4 05/25 16:03:05 1836347 ::WaitClOraAgent() - Rman-Complete:Client Returned to RmanLog=[(null)] 18412 55e4 05/25 16:03:05 1836347 ::WaitClOraAgent() - reply disconnect to Client Ora Agent 18412 55e4 05/25 16:03:05 1836347 ::Close() - SrvOraAgent Closed. 18412 3060 05/25 16:03:05 1836347 CVJobCtrlLog::unregisterProcess(): successfully removed file [D:\Program Files\CommVault\Simpana\Base\JobControl\18.412] 18412 55e4 05/25 16:03:05 1836347 ::Finalize() - delete m_jobControl ... 18412 55e4 05/25 16:03:05 1836347 OraAgentBase::Finalize() - [1836347] delete m_jobObject. 18412 55e4 05/25 16:03:05 1836347 OraJobObject::~OraJobObject() - After m_jobObject deletion. 18412 55e4 05/25 16:03:05 1836347 ::Finalize() - delete m_event ... 20168 83c 05/25 16:23:54 1836347 ::Initialize2() - m_jobControl.init(NONCONTROLMONITOR) <1836347:4:5> 20168 83c 05/25 16:23:54 1836347 Init() - Initializing job control [token=1836347:4:5,cn=701-nfcommserve01], serverName [701-nfcommserve01.custcbb.local], ControlFlag [7], Job Id [1836347] 20168 83c 05/25 16:23:54 1836347 CVJobCtrlLog::registerProcess(): successfully created file [D:\Program Files\CommVault\Simpana\Base\JobControl\20.168] 20168 83c 05/25 16:23:54 1836347 OraAgentBase::JobObjectInitialize() - [1836347] getting the new m_jobObject for CommServer=<701-nfcommserve01.custcbb.local> 20168 83c 05/25 16:23:54 1836347 OraJobObject::OraJobObject() - new m_jobObjectB 20168 83c 05/25 16:23:54 1836347 JM Client CVBkpJobClient::init(): Initializing job object with token [1836347:4:5]. 20168 83c 05/25 16:23:54 1836347 SrvOraAgent::AppMgrInit() - m_bMergeIncremental=[0] 20168 83c 05/25 16:23:54 1836347 ::GetArchiveMgrInfo() - change m_initArgs.streamNumber value from old [100] to new one [2] for DATA 20168 83c 05/25 16:23:54 1836347 ::CheckIfNothingToBackup() - m_logsBackup=0 m_dataBackup=1 20168 83c 05/25 16:23:54 1836347 ::RecvOraParams() - m_oraObjNameList : B F A F 20168 83c 05/25 16:23:54 1836347 ::RecvOraParams() - m_initArgs.jobID : 1836347 20168 83c 05/25 16:23:54 1836347 ::RecvOraParams() - appType = 22|m_ctrlRestore=0|m_dataRestore = 0, useInstanceId=110 20168 83c 05/25 16:23:54 1836347 ::RecvOraParams() - m_task=NULL|m_task->getDestinationInstanceId=-1|m_initArgs.instanceId=110 20168 83c 05/25 16:23:54 1836347 SrvOraAgent::LoadRmanCatalog() - rmanName=[rdsk] rmanService=[RCAT] rmanNoCatalog=0. 20168 83c 05/25 16:23:54 1836347 ::PreBrowse() - m_bCustomizedScript = 0 20168 83c 05/25 16:23:54 1836347 SrvSingleInstanceAgent::DoClientBrowse() - dataAgentAttach-> HostName=172.16.4.218*proddb01*8400*8402 start... 20168 83c 05/25 16:23:55 1836347 SrvSingleInstanceAgent::DoClientBrowse() - after dataAgentAttach-> HostName=172.16.4.218*proddb01*8400*8402. 20168 83c 05/25 16:23:55 1836347 ::GetCvsProtocolVersion() - Protocol version=4097 clientVersionIsLessThan3_7_1=0 clientVersionIsBiggerThan5_0=1. 20168 83c 05/25 16:23:55 1836347 SrvSingleInstanceAgent::DoClientBrowse() - extended options : 20168 83c 05/25 16:23:57 1836347 SrvSingleInstanceAgent::DoClientBrowse() - Client Browse Start 20168 83c 05/25 16:24:03 1836347 SrvOraAgent::ProcessClientBrowseMsg() - Galaxy install Instance: Instance001 20168 83c 05/25 16:24:03 1836347 ::UpdateRepository() - CreateMutex(SrvOraAgentBrowseInst110) 20168 83c 05/25 16:24:04 1836347 ::RmanBuildBackupCommandScript() - m_bPreview : 0 20168 83c 05/25 16:24:04 1836347 ::RmanBuildBackupCommandScript() - m_bCustomizedScript = 0 20168 83c 05/25 16:24:04 1836347 OraAgentBase::BackupPieceFormat() - Using default backup piece format [f7686_1836347_%d_%U] 20168 83c 05/25 16:24:04 1836347 ::RmanBuildBackupCommandScript() - Enter ... 20168 83c 05/25 16:24:04 1836347 ::RmanBuildBackupCommandScript() - sRMANOPTPERFFIX = 1 20168 83c 05/25 16:24:04 1836347 ::RmanBuildBackupCommandScript() - DISKRATIO = -1 20168 83c 05/25 16:24:04 1836347 ::RmanBuildBackupCommandScript() - TableSpace List : (null) Datafile List : (null) 20168 83c 05/25 16:24:04 1836347 ::RmanBuildBackupCommandScript() - Backup Mode is 0, MAXCORRUPT is 0 20168 83c 05/25 16:24:04 1836347 SrvOraAgent::CreateMergeIncrementalScript() - m_bMergeIncremental=[0] m_logsBackup[0] m_initArgs.appType [22] 20168 83c 05/25 16:24:04 1836347 ::RmanBuildBackupCommandScript() - disableSwitchLogFile=0 20168 83c 05/25 16:24:04 1836347 ::RmanBuildBackupCommandScript() - EvBkpTask.getOptionULong() for BACKUPARCHLOGOPTIONS_BACKUP_ARCHIVE_LOG_CRITERIA returned typeId: 7 20168 83c 05/25 16:24:04 1836347 ::RmanBuildBackupCommandScript() - EvBkpTask.getOptionULong() for DELETEARCHLOGOPTIONS_BACKUP_ARCHIVE_LOG_CRITERIA returned typeId: 0 20168 83c 05/25 16:24:04 1836347 ::RmanBuildBackupCommandScript() - Resync catalog = [false], backupArchiveLog=0 20168 83c 05/25 16:24:04 1836347 ::AddChannelArgs() - block size=262144 returned from getBlockSize(). 20168 83c 05/25 16:24:04 1836347 ::AddChannelArgs() - Galaxy install name: Instance001, clientName=proddb01, Oracle sbt library= 20168 83c 05/25 16:24:04 1836347 ::AddChannelArgs() - Galaxy install name: [Instance001], clientName=[proddb01], Oracle sbt library=[], Client CSHostName=[701-nfcommserve01.custcbb.local], Oracle Version [11.2.0.3.0] 20168 83c 05/25 16:24:04 1836347 ::AddChannelArgs() - block size=262144 returned from getBlockSize(). 20168 83c 05/25 16:24:04 1836347 ::AddChannelArgs() - Galaxy install name: Instance001, clientName=proddb01, Oracle sbt library= 20168 83c 05/25 16:24:04 1836347 ::AddChannelArgs() - Galaxy install name: [Instance001], clientName=[proddb01], Oracle sbt library=[], Client CSHostName=[701-nfcommserve01.custcbb.local], Oracle Version [11.2.0.3.0] 20168 83c 05/25 16:24:04 1836347 ::RmanBuildBackupCommandScript() - maxBackupSetSize = 0 20168 83c 05/25 16:24:04 1836347 ::RmanBuildBackupCommandScript() - Section size 0K 20168 83c 05/25 16:24:04 1836347 OraAgentBase::ParseRmanTagFormat() - user specified tag : 20168 83c 05/25 16:24:04 1836347 ::RmanBuildBackupCommandScript() - Resync catalog = [false], backupArchiveLog=0 20168 83c 05/25 16:24:04 1836347 ::SetDataSize() - TblObj.getBackupSize(1147,true)... 20168 83c 05/25 16:24:04 1836347 ::SetDataSize() - TblObj.getBackupSize() returned maxSize=117612756992,dataSize=71126499328. 20168 83c 05/25 16:24:04 1836347 ::SetDataSize() - backupLevel=1 setUncompBytesToXfer(0)... 20168 83c 05/25 16:24:04 1836347 ::SetDataSize() - After m_jobObject->updateInfo(71126499328); 20168 83c 05/25 16:24:04 1836347 ::WaitClOraAgent() - Client Rman Start 20168 83c 05/25 16:24:07 1836347 ::WaitClOraAgent() - Rman-Complete:Client Returned to RmanLog=[(null)] 20168 83c 05/25 16:24:07 1836347 ::WaitClOraAgent() - reply disconnect to Client Ora Agent 20168 83c 05/25 16:24:07 1836347 ::Close() - SrvOraAgent Closed. 20168 37cc 05/25 16:24:07 1836347 CVJobCtrlLog::unregisterProcess(): successfully removed file [D:\Program Files\CommVault\Simpana\Base\JobControl\20.168] 20168 83c 05/25 16:24:07 1836347 ::Finalize() - delete m_jobControl ... 20168 83c 05/25 16:24:07 1836347 OraAgentBase::Finalize() - [1836347] delete m_jobObject. 20168 83c 05/25 16:24:07 1836347 OraJobObject::~OraJobObject() - After m_jobObject deletion. 20168 83c 05/25 16:24:07 1836347 ::Finalize() - delete m_event ... 9040 2dbc 05/25 16:44:55 1836347 ::Initialize2() - m_jobControl.init(NONCONTROLMONITOR) <1836347:4:6> 9040 2dbc 05/25 16:44:55 1836347 Init() - Initializing job control [token=1836347:4:6,cn=701-nfcommserve01], serverName [701-nfcommserve01.custcbb.local], ControlFlag [7], Job Id [1836347] 9040 2dbc 05/25 16:44:56 1836347 CVJobCtrlLog::registerProcess(): successfully created file [D:\Program Files\CommVault\Simpana\Base\JobControl\9.040] 9040 2dbc 05/25 16:44:56 1836347 OraAgentBase::JobObjectInitialize() - [1836347] getting the new m_jobObject for CommServer=<701-nfcommserve01.custcbb.local> 9040 2dbc 05/25 16:44:56 1836347 OraJobObject::OraJobObject() - new m_jobObjectB 9040 2dbc 05/25 16:44:56 1836347 JM Client CVBkpJobClient::init(): Initializing job object with token [1836347:4:6]. 9040 2dbc 05/25 16:44:56 1836347 SrvOraAgent::AppMgrInit() - m_bMergeIncremental=[0] 9040 2dbc 05/25 16:44:56 1836347 ::GetArchiveMgrInfo() - change m_initArgs.streamNumber value from old [100] to new one [2] for DATA 9040 2dbc 05/25 16:44:56 1836347 ::CheckIfNothingToBackup() - m_logsBackup=0 m_dataBackup=1 9040 2dbc 05/25 16:44:56 1836347 ::RecvOraParams() - m_oraObjNameList : B F A F 9040 2dbc 05/25 16:44:56 1836347 ::RecvOraParams() - m_initArgs.jobID : 1836347 9040 2dbc 05/25 16:44:56 1836347 ::RecvOraParams() - appType = 22|m_ctrlRestore=0|m_dataRestore = 0, useInstanceId=110 9040 2dbc 05/25 16:44:56 1836347 ::RecvOraParams() - m_task=NULL|m_task->getDestinationInstanceId=-1|m_initArgs.instanceId=110 9040 2dbc 05/25 16:44:56 1836347 SrvOraAgent::LoadRmanCatalog() - rmanName=[rdsk] rmanService=[RCAT] rmanNoCatalog=0. 9040 2dbc 05/25 16:44:56 1836347 ::PreBrowse() - m_bCustomizedScript = 0 9040 2dbc 05/25 16:44:56 1836347 SrvSingleInstanceAgent::DoClientBrowse() - dataAgentAttach-> HostName=172.16.4.218*proddb01*8400*8402 start... 9040 2dbc 05/25 16:44:56 1836347 SrvSingleInstanceAgent::DoClientBrowse() - after dataAgentAttach-> HostName=172.16.4.218*proddb01*8400*8402. 9040 2dbc 05/25 16:44:56 1836347 ::GetCvsProtocolVersion() - Protocol version=4097 clientVersionIsLessThan3_7_1=0 clientVersionIsBiggerThan5_0=1. 9040 2dbc 05/25 16:44:56 1836347 SrvSingleInstanceAgent::DoClientBrowse() - extended options : 9040 2dbc 05/25 16:44:58 1836347 SrvSingleInstanceAgent::DoClientBrowse() - Client Browse Start 9040 2dbc 05/25 16:45:05 1836347 SrvOraAgent::ProcessClientBrowseMsg() - Galaxy install Instance: Instance001 9040 2dbc 05/25 16:45:05 1836347 ::UpdateRepository() - CreateMutex(SrvOraAgentBrowseInst110) 9040 2dbc 05/25 16:45:06 1836347 ::RmanBuildBackupCommandScript() - m_bPreview : 0 9040 2dbc 05/25 16:45:06 1836347 ::RmanBuildBackupCommandScript() - m_bCustomizedScript = 0 9040 2dbc 05/25 16:45:06 1836347 OraAgentBase::BackupPieceFormat() - Using default backup piece format [f7686_1836347_%d_%U] 9040 2dbc 05/25 16:45:06 1836347 ::RmanBuildBackupCommandScript() - Enter ... 9040 2dbc 05/25 16:45:06 1836347 ::RmanBuildBackupCommandScript() - sRMANOPTPERFFIX = 1 9040 2dbc 05/25 16:45:06 1836347 ::RmanBuildBackupCommandScript() - DISKRATIO = -1 9040 2dbc 05/25 16:45:06 1836347 ::RmanBuildBackupCommandScript() - TableSpace List : (null) Datafile List : (null) 9040 2dbc 05/25 16:45:06 1836347 ::RmanBuildBackupCommandScript() - Backup Mode is 0, MAXCORRUPT is 0 9040 2dbc 05/25 16:45:06 1836347 SrvOraAgent::CreateMergeIncrementalScript() - m_bMergeIncremental=[0] m_logsBackup[0] m_initArgs.appType [22] 9040 2dbc 05/25 16:45:06 1836347 ::RmanBuildBackupCommandScript() - disableSwitchLogFile=0 9040 2dbc 05/25 16:45:06 1836347 ::RmanBuildBackupCommandScript() - EvBkpTask.getOptionULong() for BACKUPARCHLOGOPTIONS_BACKUP_ARCHIVE_LOG_CRITERIA returned typeId: 7 9040 2dbc 05/25 16:45:06 1836347 ::RmanBuildBackupCommandScript() - EvBkpTask.getOptionULong() for DELETEARCHLOGOPTIONS_BACKUP_ARCHIVE_LOG_CRITERIA returned typeId: 0 9040 2dbc 05/25 16:45:06 1836347 ::RmanBuildBackupCommandScript() - Resync catalog = [false], backupArchiveLog=0 9040 2dbc 05/25 16:45:06 1836347 ::AddChannelArgs() - block size=262144 returned from getBlockSize(). 9040 2dbc 05/25 16:45:06 1836347 ::AddChannelArgs() - Galaxy install name: Instance001, clientName=proddb01, Oracle sbt library= 9040 2dbc 05/25 16:45:06 1836347 ::AddChannelArgs() - Galaxy install name: [Instance001], clientName=[proddb01], Oracle sbt library=[], Client CSHostName=[701-nfcommserve01.custcbb.local], Oracle Version [11.2.0.3.0] 9040 2dbc 05/25 16:45:06 1836347 ::AddChannelArgs() - block size=262144 returned from getBlockSize(). 9040 2dbc 05/25 16:45:06 1836347 ::AddChannelArgs() - Galaxy install name: Instance001, clientName=proddb01, Oracle sbt library= 9040 2dbc 05/25 16:45:06 1836347 ::AddChannelArgs() - Galaxy install name: [Instance001], clientName=[proddb01], Oracle sbt library=[], Client CSHostName=[701-nfcommserve01.custcbb.local], Oracle Version [11.2.0.3.0] 9040 2dbc 05/25 16:45:06 1836347 ::RmanBuildBackupCommandScript() - maxBackupSetSize = 0 9040 2dbc 05/25 16:45:06 1836347 ::RmanBuildBackupCommandScript() - Section size 0K 9040 2dbc 05/25 16:45:06 1836347 OraAgentBase::ParseRmanTagFormat() - user specified tag : 9040 2dbc 05/25 16:45:06 1836347 ::RmanBuildBackupCommandScript() - Resync catalog = [false], backupArchiveLog=0 9040 2dbc 05/25 16:45:06 1836347 ::SetDataSize() - TblObj.getBackupSize(1147,true)... 9040 2dbc 05/25 16:45:06 1836347 ::SetDataSize() - TblObj.getBackupSize() returned maxSize=117612756992,dataSize=71187316736. 9040 2dbc 05/25 16:45:06 1836347 ::SetDataSize() - backupLevel=1 setUncompBytesToXfer(0)... 9040 2dbc 05/25 16:45:06 1836347 ::SetDataSize() - After m_jobObject->updateInfo(71187316736); 9040 2dbc 05/25 16:45:07 1836347 ::WaitClOraAgent() - Client Rman Start 9040 2dbc 05/25 16:45:10 1836347 ::WaitClOraAgent() - Rman-Complete:Client Returned to RmanLog=[(null)] 9040 2dbc 05/25 16:45:10 1836347 ::WaitClOraAgent() - reply disconnect to Client Ora Agent 9040 2dbc 05/25 16:45:10 1836347 ::Close() - SrvOraAgent Closed. 9040 2334 05/25 16:45:10 1836347 CVJobCtrlLog::unregisterProcess(): successfully removed file [D:\Program Files\CommVault\Simpana\Base\JobControl\9.040] 9040 2dbc 05/25 16:45:10 1836347 ::Finalize() - delete m_jobControl ... 9040 2dbc 05/25 16:45:10 1836347 OraAgentBase::Finalize() - [1836347] delete m_jobObject. 9040 2dbc 05/25 16:45:10 1836347 OraJobObject::~OraJobObject() - After m_jobObject deletion. 9040 2dbc 05/25 16:45:10 1836347 ::Finalize() - delete m_event ... @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ Machine : proddb01 File : ClOraAgent_1.log @@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 6772 1674 05/25 15:00:18 1836347 OraAgentBase::Initialize1() - m_totalBytesDiff=[104857600]. 6772 1674 05/25 15:00:18 1836347 OraAgentBase::Initialize1() - secondsToWait=30 mode=0 m_backup=1. 6772 1674 05/25 15:00:18 1836347 OraAgentBase::JobObjectInitialize() - [1836347] getting the new m_jobObject for CommServer=<172.16.4.2> 6772 1674 05/25 15:00:18 1836347 OraJobObject::OraJobObject() - new m_jobObjectB 6772 1674 05/25 15:00:18 1836347 JM Client CVBkpJobClient::init(): Initializing job object with token [1836347:4:1]. 6772 1674 05/25 15:00:18 1836347 ::Initialize2() - dataAgentAttach-> ClientHostName=172.16.4.218 ServerHostName=172.16.4.2 6772 1674 05/25 15:00:18 1836347 ::JobControlInitialize() - [1836347] getting the new m_jobControl for CommServer=<172.16.4.2>... 6772 1674 05/25 15:00:18 1836347 ::JobControlInitialize() - m_jobControl.init(CONTROL) 1836347:4:1... 6772 1674 05/25 15:00:18 1836347 Init() - Initializing job control [token=1836347:4:1,cn=proddb01], serverName [172.16.4.2], ControlFlag [1], Job Id [1836347] 6772 1674 05/25 15:00:18 1836347 CVJobCtrlLog::registerProcess(): successfuly created file [C:\Program Files\CommVault\Simpana\Base\JobControl\6.772] 6772 1674 05/25 15:00:19 1836347 ::RecvOraParams() - set JM JMBKP_ORACLE_RMAN_CUSTOMSCRIPT_BKP 0 6772 1674 05/25 15:00:19 1836347 ::BrowseInit() - Initialize0(oraUser[noc_ora] oraHome=[c:\apps\product\oracle\oracle11gr23\] oraSID=[HRDB]) 6772 1674 05/25 15:00:19 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 6772 1674 05/25 15:00:19 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 6772 1674 05/25 15:00:19 1836347 ::RunBrowse() - GetInfo(oraObjNameList=[B F A F]) 6772 1674 05/25 15:00:19 1836347 OraObject::GetOraMode() - strictSID = 0 6772 1674 05/25 15:00:19 1836347 OraChildProcess::Initialize() - enter 6772 1674 05/25 15:00:22 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6772 1674 05/25 15:00:22 1836347 OraChildProcess::Wait() - Child OK 6772 1674 05/25 15:00:22 1836347 OraChildProcess::Finalize() - start 6772 1674 05/25 15:00:22 1836347 OraChildProcess::~OraChildProcess() - enter 6772 1674 05/25 15:00:22 1836347 OraChildProcess::~OraChildProcess() - exit 6772 1674 05/25 15:00:22 1836347 OraObject::GetOraMode() - oraMode = READ WRITE. 6772 1674 05/25 15:00:22 1836347 OraChildProcess::Initialize() - enter 6772 1674 05/25 15:00:22 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6772 1674 05/25 15:00:22 1836347 OraChildProcess::Wait() - Child OK 6772 1674 05/25 15:00:22 1836347 OraChildProcess::Finalize() - start 6772 1674 05/25 15:00:22 1836347 OraChildProcess::~OraChildProcess() - enter 6772 1674 05/25 15:00:22 1836347 OraChildProcess::~OraChildProcess() - exit 6772 1674 05/25 15:00:22 1836347 OraObject::CheckSid() - Galaxy Oracle SID[HRDB] equals Oracle SID [HRDB]. 6772 1674 05/25 15:00:22 1836347 OraChildProcess::Initialize() - enter 6772 1674 05/25 15:00:22 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6772 1674 05/25 15:00:22 1836347 OraChildProcess::Wait() - Child OK 6772 1674 05/25 15:00:22 1836347 OraChildProcess::Finalize() - start 6772 1674 05/25 15:00:22 1836347 OraChildProcess::~OraChildProcess() - enter 6772 1674 05/25 15:00:22 1836347 OraChildProcess::~OraChildProcess() - exit 6772 1674 05/25 15:00:22 1836347 OraObject::GetVersion() - Oracle Instance Version is [11.2.0.3.0] 6772 1674 05/25 15:00:22 1836347 OraChildProcess::Initialize() - enter 6772 1674 05/25 15:00:22 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6772 1674 05/25 15:00:22 1836347 OraChildProcess::Wait() - Child OK 6772 1674 05/25 15:00:22 1836347 OraChildProcess::Finalize() - start 6772 1674 05/25 15:00:22 1836347 OraObject::ParseReturn() - m_oraDbRole : [PRIMARY] 6772 1674 05/25 15:00:22 1836347 OraChildProcess::~OraChildProcess() - enter 6772 1674 05/25 15:00:22 1836347 OraChildProcess::~OraChildProcess() - exit 6772 1674 05/25 15:00:22 1836347 OraObject::GetDbRole() - Oracle Instance Role is [PRIMARY] 6772 1674 05/25 15:00:22 1836347 OraObject::GetOraMode() - 64bit oracle 1 6772 1674 05/25 15:00:22 1836347 OraChildProcess::Initialize() - enter 6772 1674 05/25 15:00:23 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6772 1674 05/25 15:00:23 1836347 OraChildProcess::Wait() - Child OK 6772 1674 05/25 15:00:23 1836347 OraChildProcess::Finalize() - start 6772 1674 05/25 15:00:23 1836347 OraChildProcess::~OraChildProcess() - enter 6772 1674 05/25 15:00:23 1836347 OraChildProcess::~OraChildProcess() - exit 6772 1674 05/25 15:00:23 1836347 OraChildProcess::Initialize() - enter 6772 1674 05/25 15:00:24 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6772 1674 05/25 15:00:24 1836347 OraChildProcess::Wait() - Child OK 6772 1674 05/25 15:00:24 1836347 OraChildProcess::Finalize() - start 6772 1674 05/25 15:00:24 1836347 OraChildProcess::~OraChildProcess() - enter 6772 1674 05/25 15:00:24 1836347 OraChildProcess::~OraChildProcess() - exit 6772 1674 05/25 15:00:24 1836347 ClOraAgent::GetInfoFromDB () - Trying Browse with B X 6772 1674 05/25 15:00:24 1836347 ::BrowseInit() - Initialize0(oraUser[noc_ora] oraHome=[c:\apps\product\oracle\oracle11gr23\] oraSID=[HRDB]) 6772 1674 05/25 15:00:24 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 6772 1674 05/25 15:00:24 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 6772 1674 05/25 15:00:24 1836347 ClOraAgent::GetInfoFromDB () - GetInfo(oraObjNameList=[B X]) 6772 1674 05/25 15:00:24 1836347 OraObject::GetOraMode() - strictSID = 0 6772 1674 05/25 15:00:24 1836347 OraChildProcess::Initialize() - enter 6772 1674 05/25 15:00:24 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6772 1674 05/25 15:00:24 1836347 OraChildProcess::Wait() - Child OK 6772 1674 05/25 15:00:24 1836347 OraChildProcess::Finalize() - start 6772 1674 05/25 15:00:24 1836347 OraChildProcess::~OraChildProcess() - enter 6772 1674 05/25 15:00:24 1836347 OraChildProcess::~OraChildProcess() - exit 6772 1674 05/25 15:00:24 1836347 OraObject::GetOraMode() - oraMode = READ WRITE. 6772 1674 05/25 15:00:24 1836347 OraChildProcess::Initialize() - enter 6772 1674 05/25 15:00:24 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6772 1674 05/25 15:00:24 1836347 OraChildProcess::Wait() - Child OK 6772 1674 05/25 15:00:24 1836347 OraChildProcess::Finalize() - start 6772 1674 05/25 15:00:24 1836347 OraChildProcess::~OraChildProcess() - enter 6772 1674 05/25 15:00:24 1836347 OraChildProcess::~OraChildProcess() - exit 6772 1674 05/25 15:00:24 1836347 ::ReadjustStreamsForSBTCopyParam() - oraReturn = 6772 1674 05/25 15:00:24 1836347 JRCACHEDIR: job 1836347 creating 'C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\1836347' 6772 1674 05/25 15:00:24 1836347 ::RecvRmanScript() - receiving:OraRmanScript... 6772 1674 05/25 15:00:25 1836347 ::RecvRmanScript() - RmanName=[rdsk] RmanService=[RCAT] 6772 1674 05/25 15:00:25 1836347 ExecuteAction() - Total rman block to execute : 1 6772 1674 05/25 15:00:25 1836347 ExecuteAction() - jobToken [1836347:4:1] Previous Phase Num [0] Rman Block Num [0]. 6772 1674 05/25 15:00:25 1836347 ExecuteAction() - Executing rman block no :1 from rman script. 6772 1674 05/25 15:00:25 1836347 ::RunRman() - enter 6772 1674 05/25 15:00:25 1836347 ::VerifyOraVersion() - Loading DLL = C:\Program Files\CommVault\Simpana\Base\ORASBT.dll 6772 1674 05/25 15:00:25 1836347 ::VerifyOraVersion() - Running Version = 9.0.0(BUILD84) 6772 1674 05/25 15:00:25 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 6772 1674 05/25 15:00:25 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 6772 1674 05/25 15:00:25 1836347 OraChildProcess::Initialize() - enter 6772 1674 05/25 15:00:25 1836347 OraChildProcess::BeginWait() - Rman thread with HNDL=31c TID=7420 EC=259 was created 6772 1cfc 05/25 15:00:25 1836347 OraChildProcess::WaitThread() - start: thread Id=7420 6772 1674 05/25 15:00:25 1836347 ::RunRman() - SendMsgToOA msgType=ORA_MSG_RMAN_START 6772 1674 05/25 15:00:28 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - disconnect from Srv Ora Agent 6772 1cfc 05/25 15:00:28 1836347 OraChildProcess::Wait() - Child process: dwExitCode=1 6772 1cfc 05/25 15:00:28 1836347 OraChildProcess::WaitThread() - Wait failed; lastErr=1 6772 1674 05/25 15:00:30 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - delete m_cvsOA... 6772 1674 05/25 15:00:30 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - after delete m_cvsOA. 6772 1674 05/25 15:00:30 1836347 OraChildProcess::ReadBuf() - Rman thread with HNDL=290 TID=7768 EC=259 was created 6772 1e58 05/25 15:00:30 1836347 OraChildProcess::ReadThread() - start: thread Id=7768 6772 1e58 05/25 15:00:30 1836347 OraChildProcess::ReadThread() - GETLASTERROR returned=109 (ret=0) 6772 1674 05/25 15:00:30 1836347 ::CloseJobResultsFile() - [1836347] going to m_buResults.closeFile... 6772 1674 05/25 15:00:30 1836347 STORERESULTS: cleanUp: skipping jobResults cleanup. Another cleanup process is running 6772 1674 05/25 15:00:30 1836347 JOBRESULTSTABLE(C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\1836347\JobResults): removing copy 'C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\1836347' 6772 1674 05/25 15:00:30 1836347 ::CloseJobResultsFile() - [1836347] m_buResults.closeFile() & cleanUp() succeeded. 6772 1674 05/25 15:00:30 1836347 OraChildProcess::Finalize() - start 6772 1674 05/25 15:00:30 1836347 OraChildProcess::~OraChildProcess() - enter 6772 1674 05/25 15:00:30 1836347 OraChildProcess::~OraChildProcess() - exit 6772 1674 05/25 15:00:30 1836347 ::ProcessComplete() - Sending ORA_MSG_RMAN_COMPLETE 6772 1674 05/25 15:00:30 1836347 ::RunRman() - m_rmanProcess->Failed(). 6772 1674 05/25 15:00:30 1836347 ::ExitHere() - enter: phase=10 6772 1674 05/25 15:00:30 1836347 ::ParseAndIgnoreErrors() - dir [0] temp_pos[1427] ignore_start_pos[1427] 6772 1674 05/25 15:00:30 1836347 ::SetErrorString() - m_ErrorStr [ORA-19554: error allocating device, device type: SBT_TAPE, device name: ], 1427, 1499 6772 1674 05/25 15:00:30 1836347 getRmanErrors() - Rman returned error [ORA-19554: error allocating device, device type: SBT_TAPE, device name: ] during backup operation.. 6772 1674 05/25 15:00:30 1836347 OraAgentBase::NotifyCommServeJobComplete() - Notify CommServe: jobObject.complete(FAIL,PHASE) 6772 1674 05/25 15:00:30 1836347 BKP CALLED COMPLETE (PHASE Status::FAIL), 1836347. Token [1836347:4:1] 6772 1674 05/25 15:00:31 1836347 ::Finalize() - enter Parent=true 6772 1674 05/25 15:00:31 1836347 ::Finalize() - m_jobControl->finishedWorkWithoutExit() ... 6772 1144 05/25 15:00:31 1836347 CVJobCtrlLog::unregisterProcess(): successfuly removed file [C:\Program Files\CommVault\Simpana\Base\JobControl\6.772] 6772 1674 05/25 15:00:31 1836347 ::Finalize() - delete m_jobControl ... 6772 1674 05/25 15:00:31 1836347 OraAgentBase::Finalize() - [1836347] delete m_jobObject. 6772 1674 05/25 15:00:31 1836347 OraJobObject::~OraJobObject() - After m_jobObject deletion. 6772 1674 05/25 15:00:31 1836347 ::Finalize() - delete m_event ... 8156 1d44 05/25 15:20:48 1836347 OraAgentBase::Initialize1() - m_totalBytesDiff=[104857600]. 8156 1d44 05/25 15:20:48 1836347 OraAgentBase::Initialize1() - secondsToWait=30 mode=0 m_backup=1. 8156 1d44 05/25 15:20:48 1836347 OraAgentBase::JobObjectInitialize() - [1836347] getting the new m_jobObject for CommServer=<172.16.4.2> 8156 1d44 05/25 15:20:48 1836347 OraJobObject::OraJobObject() - new m_jobObjectB 8156 1d44 05/25 15:20:48 1836347 JM Client CVBkpJobClient::init(): Initializing job object with token [1836347:4:2]. 8156 1d44 05/25 15:20:48 1836347 ::Initialize2() - dataAgentAttach-> ClientHostName=172.16.4.218 ServerHostName=172.16.4.2 8156 1d44 05/25 15:20:48 1836347 ::JobControlInitialize() - [1836347] getting the new m_jobControl for CommServer=<172.16.4.2>... 8156 1d44 05/25 15:20:48 1836347 ::JobControlInitialize() - m_jobControl.init(CONTROL) 1836347:4:2... 8156 1d44 05/25 15:20:48 1836347 Init() - Initializing job control [token=1836347:4:2,cn=proddb01], serverName [172.16.4.2], ControlFlag [1], Job Id [1836347] 8156 1d44 05/25 15:20:48 1836347 CVJobCtrlLog::registerProcess(): successfuly created file [C:\Program Files\CommVault\Simpana\Base\JobControl\8.156] 8156 1d44 05/25 15:20:50 1836347 ::RecvOraParams() - set JM JMBKP_ORACLE_RMAN_CUSTOMSCRIPT_BKP 0 8156 1d44 05/25 15:20:50 1836347 ::BrowseInit() - Initialize0(oraUser[noc_ora] oraHome=[c:\apps\product\oracle\oracle11gr23\] oraSID=[HRDB]) 8156 1d44 05/25 15:20:50 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 8156 1d44 05/25 15:20:50 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 8156 1d44 05/25 15:20:50 1836347 ::RunBrowse() - GetInfo(oraObjNameList=[B F A F]) 8156 1d44 05/25 15:20:50 1836347 OraObject::GetOraMode() - strictSID = 0 8156 1d44 05/25 15:20:50 1836347 OraChildProcess::Initialize() - enter 8156 1d44 05/25 15:20:52 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8156 1d44 05/25 15:20:52 1836347 OraChildProcess::Wait() - Child OK 8156 1d44 05/25 15:20:52 1836347 OraChildProcess::Finalize() - start 8156 1d44 05/25 15:20:52 1836347 OraChildProcess::~OraChildProcess() - enter 8156 1d44 05/25 15:20:52 1836347 OraChildProcess::~OraChildProcess() - exit 8156 1d44 05/25 15:20:52 1836347 OraObject::GetOraMode() - oraMode = READ WRITE. 8156 1d44 05/25 15:20:52 1836347 OraChildProcess::Initialize() - enter 8156 1d44 05/25 15:20:52 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8156 1d44 05/25 15:20:52 1836347 OraChildProcess::Wait() - Child OK 8156 1d44 05/25 15:20:52 1836347 OraChildProcess::Finalize() - start 8156 1d44 05/25 15:20:52 1836347 OraChildProcess::~OraChildProcess() - enter 8156 1d44 05/25 15:20:52 1836347 OraChildProcess::~OraChildProcess() - exit 8156 1d44 05/25 15:20:52 1836347 OraObject::CheckSid() - Galaxy Oracle SID[HRDB] equals Oracle SID [HRDB]. 8156 1d44 05/25 15:20:52 1836347 OraChildProcess::Initialize() - enter 8156 1d44 05/25 15:20:53 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8156 1d44 05/25 15:20:53 1836347 OraChildProcess::Wait() - Child OK 8156 1d44 05/25 15:20:53 1836347 OraChildProcess::Finalize() - start 8156 1d44 05/25 15:20:53 1836347 OraChildProcess::~OraChildProcess() - enter 8156 1d44 05/25 15:20:53 1836347 OraChildProcess::~OraChildProcess() - exit 8156 1d44 05/25 15:20:53 1836347 OraObject::GetVersion() - Oracle Instance Version is [11.2.0.3.0] 8156 1d44 05/25 15:20:53 1836347 OraChildProcess::Initialize() - enter 8156 1d44 05/25 15:20:53 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8156 1d44 05/25 15:20:53 1836347 OraChildProcess::Wait() - Child OK 8156 1d44 05/25 15:20:53 1836347 OraChildProcess::Finalize() - start 8156 1d44 05/25 15:20:53 1836347 OraObject::ParseReturn() - m_oraDbRole : [PRIMARY] 8156 1d44 05/25 15:20:53 1836347 OraChildProcess::~OraChildProcess() - enter 8156 1d44 05/25 15:20:53 1836347 OraChildProcess::~OraChildProcess() - exit 8156 1d44 05/25 15:20:53 1836347 OraObject::GetDbRole() - Oracle Instance Role is [PRIMARY] 8156 1d44 05/25 15:20:53 1836347 OraObject::GetOraMode() - 64bit oracle 1 8156 1d44 05/25 15:20:53 1836347 OraChildProcess::Initialize() - enter 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::Wait() - Child OK 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::Finalize() - start 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::~OraChildProcess() - enter 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::~OraChildProcess() - exit 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::Initialize() - enter 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::Wait() - Child OK 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::Finalize() - start 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::~OraChildProcess() - enter 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::~OraChildProcess() - exit 8156 1d44 05/25 15:20:57 1836347 ClOraAgent::GetInfoFromDB () - Trying Browse with B X 8156 1d44 05/25 15:20:57 1836347 ::BrowseInit() - Initialize0(oraUser[noc_ora] oraHome=[c:\apps\product\oracle\oracle11gr23\] oraSID=[HRDB]) 8156 1d44 05/25 15:20:57 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 8156 1d44 05/25 15:20:57 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 8156 1d44 05/25 15:20:57 1836347 ClOraAgent::GetInfoFromDB () - GetInfo(oraObjNameList=[B X]) 8156 1d44 05/25 15:20:57 1836347 OraObject::GetOraMode() - strictSID = 0 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::Initialize() - enter 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::Wait() - Child OK 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::Finalize() - start 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::~OraChildProcess() - enter 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::~OraChildProcess() - exit 8156 1d44 05/25 15:20:57 1836347 OraObject::GetOraMode() - oraMode = READ WRITE. 8156 1d44 05/25 15:20:57 1836347 OraChildProcess::Initialize() - enter 8156 1d44 05/25 15:20:58 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8156 1d44 05/25 15:20:58 1836347 OraChildProcess::Wait() - Child OK 8156 1d44 05/25 15:20:58 1836347 OraChildProcess::Finalize() - start 8156 1d44 05/25 15:20:58 1836347 OraChildProcess::~OraChildProcess() - enter 8156 1d44 05/25 15:20:58 1836347 OraChildProcess::~OraChildProcess() - exit 8156 1d44 05/25 15:20:58 1836347 ::ReadjustStreamsForSBTCopyParam() - oraReturn = 8156 1d44 05/25 15:20:58 1836347 ::RecvRmanScript() - receiving:OraRmanScript... 8156 1d44 05/25 15:20:58 1836347 ::RecvRmanScript() - RmanName=[rdsk] RmanService=[RCAT] 8156 1d44 05/25 15:20:59 1836347 ExecuteAction() - Total rman block to execute : 1 8156 1d44 05/25 15:20:59 1836347 ExecuteAction() - jobToken [1836347:4:2] Previous Phase Num [0] Rman Block Num [0]. 8156 1d44 05/25 15:20:59 1836347 ExecuteAction() - Executing rman block no :1 from rman script. 8156 1d44 05/25 15:20:59 1836347 ::RunRman() - enter 8156 1d44 05/25 15:20:59 1836347 ::VerifyOraVersion() - Loading DLL = C:\Program Files\CommVault\Simpana\Base\ORASBT.dll 8156 1d44 05/25 15:20:59 1836347 ::VerifyOraVersion() - Running Version = 9.0.0(BUILD84) 8156 1d44 05/25 15:20:59 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 8156 1d44 05/25 15:20:59 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 8156 1d44 05/25 15:20:59 1836347 OraChildProcess::Initialize() - enter 8156 1d44 05/25 15:20:59 1836347 OraChildProcess::BeginWait() - Rman thread with HNDL=31c TID=6788 EC=259 was created 8156 1a84 05/25 15:20:59 1836347 OraChildProcess::WaitThread() - start: thread Id=6788 8156 1d44 05/25 15:20:59 1836347 ::RunRman() - SendMsgToOA msgType=ORA_MSG_RMAN_START 8156 1a84 05/25 15:21:01 1836347 OraChildProcess::Wait() - Child process: dwExitCode=1 8156 1a84 05/25 15:21:01 1836347 OraChildProcess::WaitThread() - Wait failed; lastErr=1 8156 1d44 05/25 15:21:02 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - disconnect from Srv Ora Agent 8156 1d44 05/25 15:21:03 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - delete m_cvsOA... 8156 1d44 05/25 15:21:03 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - after delete m_cvsOA. 8156 1d44 05/25 15:21:04 1836347 OraChildProcess::ReadBuf() - Rman thread with HNDL=288 TID=7464 EC=259 was created 8156 1d28 05/25 15:21:04 1836347 OraChildProcess::ReadThread() - start: thread Id=7464 8156 1d28 05/25 15:21:04 1836347 OraChildProcess::ReadThread() - GETLASTERROR returned=109 (ret=0) 8156 1d44 05/25 15:21:04 1836347 ::CloseJobResultsFile() - [1836347] going to m_buResults.closeFile... 8156 1d44 05/25 15:21:04 1836347 STORERESULTS: cleanUp: skipping jobResults cleanup. Another cleanup process is running 8156 1d44 05/25 15:21:04 1836347 JOBRESULTSTABLE(C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\1836347\JobResults): removing copy 'C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\1836347' 8156 1d44 05/25 15:21:04 1836347 ::CloseJobResultsFile() - [1836347] m_buResults.closeFile() & cleanUp() succeeded. 8156 1d44 05/25 15:21:04 1836347 OraChildProcess::Finalize() - start 8156 1d44 05/25 15:21:04 1836347 OraChildProcess::~OraChildProcess() - enter 8156 1d44 05/25 15:21:04 1836347 OraChildProcess::~OraChildProcess() - exit 8156 1d44 05/25 15:21:04 1836347 ::ProcessComplete() - Sending ORA_MSG_RMAN_COMPLETE 8156 1d44 05/25 15:21:04 1836347 ::RunRman() - m_rmanProcess->Failed(). 8156 1d44 05/25 15:21:04 1836347 ::ExitHere() - enter: phase=10 8156 1d44 05/25 15:21:04 1836347 ::ParseAndIgnoreErrors() - dir [0] temp_pos[1427] ignore_start_pos[1427] 8156 1d44 05/25 15:21:04 1836347 ::SetErrorString() - m_ErrorStr [ORA-19554: error allocating device, device type: SBT_TAPE, device name: ], 1427, 1499 8156 1d44 05/25 15:21:04 1836347 getRmanErrors() - Rman returned error [ORA-19554: error allocating device, device type: SBT_TAPE, device name: ] during backup operation.. 8156 1d44 05/25 15:21:04 1836347 OraAgentBase::NotifyCommServeJobComplete() - Notify CommServe: jobObject.complete(FAIL,PHASE) 8156 1d44 05/25 15:21:04 1836347 BKP CALLED COMPLETE (PHASE Status::FAIL), 1836347. Token [1836347:4:2] 8156 1d44 05/25 15:21:04 1836347 ::Finalize() - enter Parent=true 8156 1d44 05/25 15:21:04 1836347 ::Finalize() - m_jobControl->finishedWorkWithoutExit() ... 8156 1c08 05/25 15:21:04 1836347 CVJobCtrlLog::unregisterProcess(): successfuly removed file [C:\Program Files\CommVault\Simpana\Base\JobControl\8.156] 8156 1d44 05/25 15:21:04 1836347 ::Finalize() - delete m_jobControl ... 8156 1d44 05/25 15:21:04 1836347 OraAgentBase::Finalize() - [1836347] delete m_jobObject. 8156 1d44 05/25 15:21:04 1836347 OraJobObject::~OraJobObject() - After m_jobObject deletion. 8156 1d44 05/25 15:21:04 1836347 ::Finalize() - delete m_event ... 7708 1a74 05/25 15:41:52 1836347 OraAgentBase::Initialize1() - m_totalBytesDiff=[104857600]. 7708 1a74 05/25 15:41:52 1836347 OraAgentBase::Initialize1() - secondsToWait=30 mode=0 m_backup=1. 7708 1a74 05/25 15:41:52 1836347 OraAgentBase::JobObjectInitialize() - [1836347] getting the new m_jobObject for CommServer=<172.16.4.2> 7708 1a74 05/25 15:41:52 1836347 OraJobObject::OraJobObject() - new m_jobObjectB 7708 1a74 05/25 15:41:52 1836347 JM Client CVBkpJobClient::init(): Initializing job object with token [1836347:4:3]. 7708 1a74 05/25 15:41:52 1836347 ::Initialize2() - dataAgentAttach-> ClientHostName=172.16.4.218 ServerHostName=172.16.4.2 7708 1a74 05/25 15:41:52 1836347 ::JobControlInitialize() - [1836347] getting the new m_jobControl for CommServer=<172.16.4.2>... 7708 1a74 05/25 15:41:52 1836347 ::JobControlInitialize() - m_jobControl.init(CONTROL) 1836347:4:3... 7708 1a74 05/25 15:41:52 1836347 Init() - Initializing job control [token=1836347:4:3,cn=proddb01], serverName [172.16.4.2], ControlFlag [1], Job Id [1836347] 7708 1a74 05/25 15:41:52 1836347 CVJobCtrlLog::registerProcess(): successfuly created file [C:\Program Files\CommVault\Simpana\Base\JobControl\7.708] 7708 1a74 05/25 15:41:54 1836347 ::RecvOraParams() - set JM JMBKP_ORACLE_RMAN_CUSTOMSCRIPT_BKP 0 7708 1a74 05/25 15:41:54 1836347 ::BrowseInit() - Initialize0(oraUser[noc_ora] oraHome=[c:\apps\product\oracle\oracle11gr23\] oraSID=[HRDB]) 7708 1a74 05/25 15:41:54 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 7708 1a74 05/25 15:41:54 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 7708 1a74 05/25 15:41:54 1836347 ::RunBrowse() - GetInfo(oraObjNameList=[B F A F]) 7708 1a74 05/25 15:41:54 1836347 OraObject::GetOraMode() - strictSID = 0 7708 1a74 05/25 15:41:54 1836347 OraChildProcess::Initialize() - enter 7708 1a74 05/25 15:41:54 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 7708 1a74 05/25 15:41:54 1836347 OraChildProcess::Wait() - Child OK 7708 1a74 05/25 15:41:54 1836347 OraChildProcess::Finalize() - start 7708 1a74 05/25 15:41:54 1836347 OraChildProcess::~OraChildProcess() - enter 7708 1a74 05/25 15:41:54 1836347 OraChildProcess::~OraChildProcess() - exit 7708 1a74 05/25 15:41:54 1836347 OraObject::GetOraMode() - oraMode = READ WRITE. 7708 1a74 05/25 15:41:54 1836347 OraChildProcess::Initialize() - enter 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::Wait() - Child OK 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::Finalize() - start 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::~OraChildProcess() - enter 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::~OraChildProcess() - exit 7708 1a74 05/25 15:41:55 1836347 OraObject::CheckSid() - Galaxy Oracle SID[HRDB] equals Oracle SID [HRDB]. 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::Initialize() - enter 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::Wait() - Child OK 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::Finalize() - start 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::~OraChildProcess() - enter 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::~OraChildProcess() - exit 7708 1a74 05/25 15:41:55 1836347 OraObject::GetVersion() - Oracle Instance Version is [11.2.0.3.0] 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::Initialize() - enter 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::Wait() - Child OK 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::Finalize() - start 7708 1a74 05/25 15:41:55 1836347 OraObject::ParseReturn() - m_oraDbRole : [PRIMARY] 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::~OraChildProcess() - enter 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::~OraChildProcess() - exit 7708 1a74 05/25 15:41:55 1836347 OraObject::GetDbRole() - Oracle Instance Role is [PRIMARY] 7708 1a74 05/25 15:41:55 1836347 OraObject::GetOraMode() - 64bit oracle 1 7708 1a74 05/25 15:41:55 1836347 OraChildProcess::Initialize() - enter 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::Wait() - Child OK 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::Finalize() - start 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::~OraChildProcess() - enter 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::~OraChildProcess() - exit 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::Initialize() - enter 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::Wait() - Child OK 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::Finalize() - start 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::~OraChildProcess() - enter 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::~OraChildProcess() - exit 7708 1a74 05/25 15:42:01 1836347 ClOraAgent::GetInfoFromDB () - Trying Browse with B X 7708 1a74 05/25 15:42:01 1836347 ::BrowseInit() - Initialize0(oraUser[noc_ora] oraHome=[c:\apps\product\oracle\oracle11gr23\] oraSID=[HRDB]) 7708 1a74 05/25 15:42:01 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 7708 1a74 05/25 15:42:01 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 7708 1a74 05/25 15:42:01 1836347 ClOraAgent::GetInfoFromDB () - GetInfo(oraObjNameList=[B X]) 7708 1a74 05/25 15:42:01 1836347 OraObject::GetOraMode() - strictSID = 0 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::Initialize() - enter 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::Wait() - Child OK 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::Finalize() - start 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::~OraChildProcess() - enter 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::~OraChildProcess() - exit 7708 1a74 05/25 15:42:01 1836347 OraObject::GetOraMode() - oraMode = READ WRITE. 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::Initialize() - enter 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::Wait() - Child OK 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::Finalize() - start 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::~OraChildProcess() - enter 7708 1a74 05/25 15:42:01 1836347 OraChildProcess::~OraChildProcess() - exit 7708 1a74 05/25 15:42:01 1836347 ::ReadjustStreamsForSBTCopyParam() - oraReturn = 7708 1a74 05/25 15:42:01 1836347 ::RecvRmanScript() - receiving:OraRmanScript... 7708 1a74 05/25 15:42:02 1836347 ::RecvRmanScript() - RmanName=[rdsk] RmanService=[RCAT] 7708 1a74 05/25 15:42:02 1836347 ExecuteAction() - Total rman block to execute : 1 7708 1a74 05/25 15:42:02 1836347 ExecuteAction() - jobToken [1836347:4:3] Previous Phase Num [0] Rman Block Num [0]. 7708 1a74 05/25 15:42:02 1836347 ExecuteAction() - Executing rman block no :1 from rman script. 7708 1a74 05/25 15:42:02 1836347 ::RunRman() - enter 7708 1a74 05/25 15:42:02 1836347 ::VerifyOraVersion() - Loading DLL = C:\Program Files\CommVault\Simpana\Base\ORASBT.dll 7708 1a74 05/25 15:42:02 1836347 ::VerifyOraVersion() - Running Version = 9.0.0(BUILD84) 7708 1a74 05/25 15:42:02 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 7708 1a74 05/25 15:42:02 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 7708 1a74 05/25 15:42:02 1836347 OraChildProcess::Initialize() - enter 7708 1a74 05/25 15:42:02 1836347 OraChildProcess::BeginWait() - Rman thread with HNDL=320 TID=6344 EC=259 was created 7708 1a74 05/25 15:42:02 1836347 ::RunRman() - SendMsgToOA msgType=ORA_MSG_RMAN_START 7708 18c8 05/25 15:42:02 1836347 OraChildProcess::WaitThread() - start: thread Id=6344 7708 18c8 05/25 15:42:04 1836347 OraChildProcess::Wait() - Child process: dwExitCode=1 7708 18c8 05/25 15:42:04 1836347 OraChildProcess::WaitThread() - Wait failed; lastErr=1 7708 1a74 05/25 15:42:05 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - disconnect from Srv Ora Agent 7708 1a74 05/25 15:42:07 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - delete m_cvsOA... 7708 1a74 05/25 15:42:07 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - after delete m_cvsOA. 7708 1a74 05/25 15:42:07 1836347 OraChildProcess::ReadBuf() - Rman thread with HNDL=294 TID=8008 EC=259 was created 7708 1f48 05/25 15:42:07 1836347 OraChildProcess::ReadThread() - start: thread Id=8008 7708 1f48 05/25 15:42:08 1836347 OraChildProcess::ReadThread() - GETLASTERROR returned=109 (ret=0) 7708 1a74 05/25 15:42:08 1836347 ::CloseJobResultsFile() - [1836347] going to m_buResults.closeFile... 7708 1a74 05/25 15:42:08 1836347 STORERESULTS: cleanUp: skipping jobResults cleanup. Another cleanup process is running 7708 1a74 05/25 15:42:08 1836347 JOBRESULTSTABLE(C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\1836347\JobResults): removing copy 'C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\1836347' 7708 1a74 05/25 15:42:08 1836347 ::CloseJobResultsFile() - [1836347] m_buResults.closeFile() & cleanUp() succeeded. 7708 1a74 05/25 15:42:08 1836347 OraChildProcess::Finalize() - start 7708 1a74 05/25 15:42:08 1836347 OraChildProcess::~OraChildProcess() - enter 7708 1a74 05/25 15:42:08 1836347 OraChildProcess::~OraChildProcess() - exit 7708 1a74 05/25 15:42:08 1836347 ::ProcessComplete() - Sending ORA_MSG_RMAN_COMPLETE 7708 1a74 05/25 15:42:08 1836347 ::RunRman() - m_rmanProcess->Failed(). 7708 1a74 05/25 15:42:08 1836347 ::ExitHere() - enter: phase=10 7708 1a74 05/25 15:42:08 1836347 ::ParseAndIgnoreErrors() - dir [0] temp_pos[1427] ignore_start_pos[1427] 7708 1a74 05/25 15:42:08 1836347 ::SetErrorString() - m_ErrorStr [ORA-19554: error allocating device, device type: SBT_TAPE, device name: ], 1427, 1499 7708 1a74 05/25 15:42:08 1836347 getRmanErrors() - Rman returned error [ORA-19554: error allocating device, device type: SBT_TAPE, device name: ] during backup operation.. 7708 1a74 05/25 15:42:08 1836347 OraAgentBase::NotifyCommServeJobComplete() - Notify CommServe: jobObject.complete(FAIL,PHASE) 7708 1a74 05/25 15:42:08 1836347 BKP CALLED COMPLETE (PHASE Status::FAIL), 1836347. Token [1836347:4:3] 7708 1a74 05/25 15:42:08 1836347 ::Finalize() - enter Parent=true 7708 1a74 05/25 15:42:08 1836347 ::Finalize() - m_jobControl->finishedWorkWithoutExit() ... 7708 1fa8 05/25 15:42:08 1836347 CVJobCtrlLog::unregisterProcess(): successfuly removed file [C:\Program Files\CommVault\Simpana\Base\JobControl\7.708] 7708 1a74 05/25 15:42:08 1836347 ::Finalize() - delete m_jobControl ... 7708 1a74 05/25 15:42:08 1836347 OraAgentBase::Finalize() - [1836347] delete m_jobObject. 7708 1a74 05/25 15:42:08 1836347 OraJobObject::~OraJobObject() - After m_jobObject deletion. 7708 1a74 05/25 15:42:08 1836347 ::Finalize() - delete m_event ... 6796 1428 05/25 16:02:52 1836347 OraAgentBase::Initialize1() - m_totalBytesDiff=[104857600]. 6796 1428 05/25 16:02:52 1836347 OraAgentBase::Initialize1() - secondsToWait=30 mode=0 m_backup=1. 6796 1428 05/25 16:02:52 1836347 OraAgentBase::JobObjectInitialize() - [1836347] getting the new m_jobObject for CommServer=<172.16.4.2> 6796 1428 05/25 16:02:52 1836347 OraJobObject::OraJobObject() - new m_jobObjectB 6796 1428 05/25 16:02:52 1836347 JM Client CVBkpJobClient::init(): Initializing job object with token [1836347:4:4]. 6796 1428 05/25 16:02:53 1836347 ::Initialize2() - dataAgentAttach-> ClientHostName=172.16.4.218 ServerHostName=172.16.4.2 6796 1428 05/25 16:02:53 1836347 ::JobControlInitialize() - [1836347] getting the new m_jobControl for CommServer=<172.16.4.2>... 6796 1428 05/25 16:02:53 1836347 ::JobControlInitialize() - m_jobControl.init(CONTROL) 1836347:4:4... 6796 1428 05/25 16:02:53 1836347 Init() - Initializing job control [token=1836347:4:4,cn=proddb01], serverName [172.16.4.2], ControlFlag [1], Job Id [1836347] 6796 1428 05/25 16:02:53 1836347 CVJobCtrlLog::registerProcess(): successfuly created file [C:\Program Files\CommVault\Simpana\Base\JobControl\6.796] 6796 1428 05/25 16:02:54 1836347 ::RecvOraParams() - set JM JMBKP_ORACLE_RMAN_CUSTOMSCRIPT_BKP 0 6796 1428 05/25 16:02:54 1836347 ::BrowseInit() - Initialize0(oraUser[noc_ora] oraHome=[c:\apps\product\oracle\oracle11gr23\] oraSID=[HRDB]) 6796 1428 05/25 16:02:54 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 6796 1428 05/25 16:02:54 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 6796 1428 05/25 16:02:54 1836347 ::RunBrowse() - GetInfo(oraObjNameList=[B F A F]) 6796 1428 05/25 16:02:54 1836347 OraObject::GetOraMode() - strictSID = 0 6796 1428 05/25 16:02:54 1836347 OraChildProcess::Initialize() - enter 6796 1428 05/25 16:02:54 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6796 1428 05/25 16:02:54 1836347 OraChildProcess::Wait() - Child OK 6796 1428 05/25 16:02:54 1836347 OraChildProcess::Finalize() - start 6796 1428 05/25 16:02:54 1836347 OraChildProcess::~OraChildProcess() - enter 6796 1428 05/25 16:02:54 1836347 OraChildProcess::~OraChildProcess() - exit 6796 1428 05/25 16:02:54 1836347 OraObject::GetOraMode() - oraMode = READ WRITE. 6796 1428 05/25 16:02:54 1836347 OraChildProcess::Initialize() - enter 6796 1428 05/25 16:02:54 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6796 1428 05/25 16:02:54 1836347 OraChildProcess::Wait() - Child OK 6796 1428 05/25 16:02:54 1836347 OraChildProcess::Finalize() - start 6796 1428 05/25 16:02:54 1836347 OraChildProcess::~OraChildProcess() - enter 6796 1428 05/25 16:02:54 1836347 OraChildProcess::~OraChildProcess() - exit 6796 1428 05/25 16:02:54 1836347 OraObject::CheckSid() - Galaxy Oracle SID[HRDB] equals Oracle SID [HRDB]. 6796 1428 05/25 16:02:54 1836347 OraChildProcess::Initialize() - enter 6796 1428 05/25 16:02:54 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6796 1428 05/25 16:02:54 1836347 OraChildProcess::Wait() - Child OK 6796 1428 05/25 16:02:54 1836347 OraChildProcess::Finalize() - start 6796 1428 05/25 16:02:54 1836347 OraChildProcess::~OraChildProcess() - enter 6796 1428 05/25 16:02:54 1836347 OraChildProcess::~OraChildProcess() - exit 6796 1428 05/25 16:02:54 1836347 OraObject::GetVersion() - Oracle Instance Version is [11.2.0.3.0] 6796 1428 05/25 16:02:54 1836347 OraChildProcess::Initialize() - enter 6796 1428 05/25 16:02:54 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6796 1428 05/25 16:02:54 1836347 OraChildProcess::Wait() - Child OK 6796 1428 05/25 16:02:54 1836347 OraChildProcess::Finalize() - start 6796 1428 05/25 16:02:54 1836347 OraObject::ParseReturn() - m_oraDbRole : [PRIMARY] 6796 1428 05/25 16:02:54 1836347 OraChildProcess::~OraChildProcess() - enter 6796 1428 05/25 16:02:54 1836347 OraChildProcess::~OraChildProcess() - exit 6796 1428 05/25 16:02:54 1836347 OraObject::GetDbRole() - Oracle Instance Role is [PRIMARY] 6796 1428 05/25 16:02:54 1836347 OraObject::GetOraMode() - 64bit oracle 1 6796 1428 05/25 16:02:54 1836347 OraChildProcess::Initialize() - enter 6796 1428 05/25 16:03:00 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6796 1428 05/25 16:03:00 1836347 OraChildProcess::Wait() - Child OK 6796 1428 05/25 16:03:00 1836347 OraChildProcess::Finalize() - start 6796 1428 05/25 16:03:00 1836347 OraChildProcess::~OraChildProcess() - enter 6796 1428 05/25 16:03:00 1836347 OraChildProcess::~OraChildProcess() - exit 6796 1428 05/25 16:03:00 1836347 OraChildProcess::Initialize() - enter 6796 1428 05/25 16:03:00 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6796 1428 05/25 16:03:00 1836347 OraChildProcess::Wait() - Child OK 6796 1428 05/25 16:03:00 1836347 OraChildProcess::Finalize() - start 6796 1428 05/25 16:03:00 1836347 OraChildProcess::~OraChildProcess() - enter 6796 1428 05/25 16:03:00 1836347 OraChildProcess::~OraChildProcess() - exit 6796 1428 05/25 16:03:00 1836347 ClOraAgent::GetInfoFromDB () - Trying Browse with B X 6796 1428 05/25 16:03:00 1836347 ::BrowseInit() - Initialize0(oraUser[noc_ora] oraHome=[c:\apps\product\oracle\oracle11gr23\] oraSID=[HRDB]) 6796 1428 05/25 16:03:00 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 6796 1428 05/25 16:03:00 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 6796 1428 05/25 16:03:00 1836347 ClOraAgent::GetInfoFromDB () - GetInfo(oraObjNameList=[B X]) 6796 1428 05/25 16:03:00 1836347 OraObject::GetOraMode() - strictSID = 0 6796 1428 05/25 16:03:00 1836347 OraChildProcess::Initialize() - enter 6796 1428 05/25 16:03:00 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6796 1428 05/25 16:03:00 1836347 OraChildProcess::Wait() - Child OK 6796 1428 05/25 16:03:00 1836347 OraChildProcess::Finalize() - start 6796 1428 05/25 16:03:00 1836347 OraChildProcess::~OraChildProcess() - enter 6796 1428 05/25 16:03:00 1836347 OraChildProcess::~OraChildProcess() - exit 6796 1428 05/25 16:03:00 1836347 OraObject::GetOraMode() - oraMode = READ WRITE. 6796 1428 05/25 16:03:00 1836347 OraChildProcess::Initialize() - enter 6796 1428 05/25 16:03:01 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 6796 1428 05/25 16:03:01 1836347 OraChildProcess::Wait() - Child OK 6796 1428 05/25 16:03:01 1836347 OraChildProcess::Finalize() - start 6796 1428 05/25 16:03:01 1836347 OraChildProcess::~OraChildProcess() - enter 6796 1428 05/25 16:03:01 1836347 OraChildProcess::~OraChildProcess() - exit 6796 1428 05/25 16:03:01 1836347 ::ReadjustStreamsForSBTCopyParam() - oraReturn = 6796 1428 05/25 16:03:01 1836347 ::RecvRmanScript() - receiving:OraRmanScript... 6796 1428 05/25 16:03:01 1836347 ::RecvRmanScript() - RmanName=[rdsk] RmanService=[RCAT] 6796 1428 05/25 16:03:02 1836347 ExecuteAction() - Total rman block to execute : 1 6796 1428 05/25 16:03:02 1836347 ExecuteAction() - jobToken [1836347:4:4] Previous Phase Num [0] Rman Block Num [0]. 6796 1428 05/25 16:03:02 1836347 ExecuteAction() - Executing rman block no :1 from rman script. 6796 1428 05/25 16:03:02 1836347 ::RunRman() - enter 6796 1428 05/25 16:03:02 1836347 ::VerifyOraVersion() - Loading DLL = C:\Program Files\CommVault\Simpana\Base\ORASBT.dll 6796 1428 05/25 16:03:02 1836347 ::VerifyOraVersion() - Running Version = 9.0.0(BUILD84) 6796 1428 05/25 16:03:02 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 6796 1428 05/25 16:03:02 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 6796 1428 05/25 16:03:02 1836347 OraChildProcess::Initialize() - enter 6796 1428 05/25 16:03:02 1836347 OraChildProcess::BeginWait() - Rman thread with HNDL=31c TID=5108 EC=259 was created 6796 1428 05/25 16:03:02 1836347 ::RunRman() - SendMsgToOA msgType=ORA_MSG_RMAN_START 6796 13f4 05/25 16:03:02 1836347 OraChildProcess::WaitThread() - start: thread Id=5108 6796 13f4 05/25 16:03:04 1836347 OraChildProcess::Wait() - Child process: dwExitCode=1 6796 13f4 05/25 16:03:04 1836347 OraChildProcess::WaitThread() - Wait failed; lastErr=1 6796 1428 05/25 16:03:05 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - disconnect from Srv Ora Agent 6796 1428 05/25 16:03:07 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - delete m_cvsOA... 6796 1428 05/25 16:03:07 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - after delete m_cvsOA. 6796 1428 05/25 16:03:07 1836347 OraChildProcess::ReadBuf() - Rman thread with HNDL=290 TID=4420 EC=259 was created 6796 1144 05/25 16:03:07 1836347 OraChildProcess::ReadThread() - start: thread Id=4420 6796 1144 05/25 16:03:07 1836347 OraChildProcess::ReadThread() - GETLASTERROR returned=109 (ret=0) 6796 1428 05/25 16:03:07 1836347 ::CloseJobResultsFile() - [1836347] going to m_buResults.closeFile... 6796 1428 05/25 16:03:07 1836347 STORERESULTS: cleanUp: skipping jobResults cleanup. Another cleanup process is running 6796 1428 05/25 16:03:07 1836347 JOBRESULTSTABLE(C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\1836347\JobResults): removing copy 'C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\1836347' 6796 1428 05/25 16:03:07 1836347 ::CloseJobResultsFile() - [1836347] m_buResults.closeFile() & cleanUp() succeeded. 6796 1428 05/25 16:03:07 1836347 OraChildProcess::Finalize() - start 6796 1428 05/25 16:03:07 1836347 OraChildProcess::~OraChildProcess() - enter 6796 1428 05/25 16:03:07 1836347 OraChildProcess::~OraChildProcess() - exit 6796 1428 05/25 16:03:07 1836347 ::ProcessComplete() - Sending ORA_MSG_RMAN_COMPLETE 6796 1428 05/25 16:03:07 1836347 ::RunRman() - m_rmanProcess->Failed(). 6796 1428 05/25 16:03:07 1836347 ::ExitHere() - enter: phase=10 6796 1428 05/25 16:03:07 1836347 ::ParseAndIgnoreErrors() - dir [0] temp_pos[1427] ignore_start_pos[1427] 6796 1428 05/25 16:03:07 1836347 ::SetErrorString() - m_ErrorStr [ORA-19554: error allocating device, device type: SBT_TAPE, device name: ], 1427, 1499 6796 1428 05/25 16:03:07 1836347 getRmanErrors() - Rman returned error [ORA-19554: error allocating device, device type: SBT_TAPE, device name: ] during backup operation.. 6796 1428 05/25 16:03:07 1836347 OraAgentBase::NotifyCommServeJobComplete() - Notify CommServe: jobObject.complete(FAIL,PHASE) 6796 1428 05/25 16:03:07 1836347 BKP CALLED COMPLETE (PHASE Status::FAIL), 1836347. Token [1836347:4:4] 6796 1428 05/25 16:03:07 1836347 ::Finalize() - enter Parent=true 6796 1428 05/25 16:03:07 1836347 ::Finalize() - m_jobControl->finishedWorkWithoutExit() ... 6796 16b8 05/25 16:03:07 1836347 CVJobCtrlLog::unregisterProcess(): successfuly removed file [C:\Program Files\CommVault\Simpana\Base\JobControl\6.796] 6796 1428 05/25 16:03:07 1836347 ::Finalize() - delete m_jobControl ... 6796 1428 05/25 16:03:07 1836347 OraAgentBase::Finalize() - [1836347] delete m_jobObject. 6796 1428 05/25 16:03:07 1836347 OraJobObject::~OraJobObject() - After m_jobObject deletion. 6796 1428 05/25 16:03:07 1836347 ::Finalize() - delete m_event ... 4568 1e1c 05/25 16:23:55 1836347 OraAgentBase::Initialize1() - m_totalBytesDiff=[104857600]. 4568 1e1c 05/25 16:23:55 1836347 OraAgentBase::Initialize1() - secondsToWait=30 mode=0 m_backup=1. 4568 1e1c 05/25 16:23:55 1836347 OraAgentBase::JobObjectInitialize() - [1836347] getting the new m_jobObject for CommServer=<172.16.4.2> 4568 1e1c 05/25 16:23:55 1836347 OraJobObject::OraJobObject() - new m_jobObjectB 4568 1e1c 05/25 16:23:55 1836347 JM Client CVBkpJobClient::init(): Initializing job object with token [1836347:4:5]. 4568 1e1c 05/25 16:23:55 1836347 ::Initialize2() - dataAgentAttach-> ClientHostName=172.16.4.218 ServerHostName=172.16.4.2 4568 1e1c 05/25 16:23:55 1836347 ::JobControlInitialize() - [1836347] getting the new m_jobControl for CommServer=<172.16.4.2>... 4568 1e1c 05/25 16:23:55 1836347 ::JobControlInitialize() - m_jobControl.init(CONTROL) 1836347:4:5... 4568 1e1c 05/25 16:23:55 1836347 Init() - Initializing job control [token=1836347:4:5,cn=proddb01], serverName [172.16.4.2], ControlFlag [1], Job Id [1836347] 4568 1e1c 05/25 16:23:55 1836347 CVJobCtrlLog::registerProcess(): successfuly created file [C:\Program Files\CommVault\Simpana\Base\JobControl\4.568] 4568 1e1c 05/25 16:23:57 1836347 ::RecvOraParams() - set JM JMBKP_ORACLE_RMAN_CUSTOMSCRIPT_BKP 0 4568 1e1c 05/25 16:23:57 1836347 ::BrowseInit() - Initialize0(oraUser[noc_ora] oraHome=[c:\apps\product\oracle\oracle11gr23\] oraSID=[HRDB]) 4568 1e1c 05/25 16:23:57 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 4568 1e1c 05/25 16:23:57 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 4568 1e1c 05/25 16:23:57 1836347 ::RunBrowse() - GetInfo(oraObjNameList=[B F A F]) 4568 1e1c 05/25 16:23:57 1836347 OraObject::GetOraMode() - strictSID = 0 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::Initialize() - enter 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::Wait() - Child OK 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::Finalize() - start 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::~OraChildProcess() - enter 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::~OraChildProcess() - exit 4568 1e1c 05/25 16:23:57 1836347 OraObject::GetOraMode() - oraMode = READ WRITE. 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::Initialize() - enter 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::Wait() - Child OK 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::Finalize() - start 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::~OraChildProcess() - enter 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::~OraChildProcess() - exit 4568 1e1c 05/25 16:23:57 1836347 OraObject::CheckSid() - Galaxy Oracle SID[HRDB] equals Oracle SID [HRDB]. 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::Initialize() - enter 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::Wait() - Child OK 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::Finalize() - start 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::~OraChildProcess() - enter 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::~OraChildProcess() - exit 4568 1e1c 05/25 16:23:57 1836347 OraObject::GetVersion() - Oracle Instance Version is [11.2.0.3.0] 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::Initialize() - enter 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::Wait() - Child OK 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::Finalize() - start 4568 1e1c 05/25 16:23:57 1836347 OraObject::ParseReturn() - m_oraDbRole : [PRIMARY] 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::~OraChildProcess() - enter 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::~OraChildProcess() - exit 4568 1e1c 05/25 16:23:57 1836347 OraObject::GetDbRole() - Oracle Instance Role is [PRIMARY] 4568 1e1c 05/25 16:23:57 1836347 OraObject::GetOraMode() - 64bit oracle 1 4568 1e1c 05/25 16:23:57 1836347 OraChildProcess::Initialize() - enter 4568 1e1c 05/25 16:24:02 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 4568 1e1c 05/25 16:24:02 1836347 OraChildProcess::Wait() - Child OK 4568 1e1c 05/25 16:24:02 1836347 OraChildProcess::Finalize() - start 4568 1e1c 05/25 16:24:02 1836347 OraChildProcess::~OraChildProcess() - enter 4568 1e1c 05/25 16:24:02 1836347 OraChildProcess::~OraChildProcess() - exit 4568 1e1c 05/25 16:24:02 1836347 OraChildProcess::Initialize() - enter 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::Wait() - Child OK 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::Finalize() - start 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::~OraChildProcess() - enter 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::~OraChildProcess() - exit 4568 1e1c 05/25 16:24:03 1836347 ClOraAgent::GetInfoFromDB () - Trying Browse with B X 4568 1e1c 05/25 16:24:03 1836347 ::BrowseInit() - Initialize0(oraUser[noc_ora] oraHome=[c:\apps\product\oracle\oracle11gr23\] oraSID=[HRDB]) 4568 1e1c 05/25 16:24:03 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 4568 1e1c 05/25 16:24:03 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 4568 1e1c 05/25 16:24:03 1836347 ClOraAgent::GetInfoFromDB () - GetInfo(oraObjNameList=[B X]) 4568 1e1c 05/25 16:24:03 1836347 OraObject::GetOraMode() - strictSID = 0 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::Initialize() - enter 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::Wait() - Child OK 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::Finalize() - start 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::~OraChildProcess() - enter 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::~OraChildProcess() - exit 4568 1e1c 05/25 16:24:03 1836347 OraObject::GetOraMode() - oraMode = READ WRITE. 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::Initialize() - enter 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::Wait() - Child OK 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::Finalize() - start 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::~OraChildProcess() - enter 4568 1e1c 05/25 16:24:03 1836347 OraChildProcess::~OraChildProcess() - exit 4568 1e1c 05/25 16:24:03 1836347 ::ReadjustStreamsForSBTCopyParam() - oraReturn = 4568 1e1c 05/25 16:24:03 1836347 ::RecvRmanScript() - receiving:OraRmanScript... 4568 1e1c 05/25 16:24:04 1836347 ::RecvRmanScript() - RmanName=[rdsk] RmanService=[RCAT] 4568 1e1c 05/25 16:24:04 1836347 ExecuteAction() - Total rman block to execute : 1 4568 1e1c 05/25 16:24:04 1836347 ExecuteAction() - jobToken [1836347:4:5] Previous Phase Num [0] Rman Block Num [0]. 4568 1e1c 05/25 16:24:04 1836347 ExecuteAction() - Executing rman block no :1 from rman script. 4568 1e1c 05/25 16:24:04 1836347 ::RunRman() - enter 4568 1e1c 05/25 16:24:04 1836347 ::VerifyOraVersion() - Loading DLL = C:\Program Files\CommVault\Simpana\Base\ORASBT.dll 4568 1e1c 05/25 16:24:04 1836347 ::VerifyOraVersion() - Running Version = 9.0.0(BUILD84) 4568 1e1c 05/25 16:24:04 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 4568 1e1c 05/25 16:24:04 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 4568 1e1c 05/25 16:24:04 1836347 OraChildProcess::Initialize() - enter 4568 1e1c 05/25 16:24:04 1836347 OraChildProcess::BeginWait() - Rman thread with HNDL=31c TID=7172 EC=259 was created 4568 1c04 05/25 16:24:04 1836347 OraChildProcess::WaitThread() - start: thread Id=7172 4568 1e1c 05/25 16:24:04 1836347 ::RunRman() - SendMsgToOA msgType=ORA_MSG_RMAN_START 4568 1c04 05/25 16:24:06 1836347 OraChildProcess::Wait() - Child process: dwExitCode=1 4568 1c04 05/25 16:24:06 1836347 OraChildProcess::WaitThread() - Wait failed; lastErr=1 4568 1e1c 05/25 16:24:07 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - disconnect from Srv Ora Agent 4568 1e1c 05/25 16:24:09 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - delete m_cvsOA... 4568 1e1c 05/25 16:24:09 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - after delete m_cvsOA. 4568 1e1c 05/25 16:24:09 1836347 OraChildProcess::ReadBuf() - Rman thread with HNDL=290 TID=7808 EC=259 was created 4568 1e80 05/25 16:24:09 1836347 OraChildProcess::ReadThread() - start: thread Id=7808 4568 1e80 05/25 16:24:09 1836347 OraChildProcess::ReadThread() - GETLASTERROR returned=109 (ret=0) 4568 1e1c 05/25 16:24:09 1836347 ::CloseJobResultsFile() - [1836347] going to m_buResults.closeFile... 4568 1e1c 05/25 16:24:09 1836347 STORERESULTS: cleanUp: skipping jobResults cleanup. Another cleanup process is running 4568 1e1c 05/25 16:24:09 1836347 JOBRESULTSTABLE(C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\1836347\JobResults): removing copy 'C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\1836347' 4568 1e1c 05/25 16:24:09 1836347 ::CloseJobResultsFile() - [1836347] m_buResults.closeFile() & cleanUp() succeeded. 4568 1e1c 05/25 16:24:09 1836347 OraChildProcess::Finalize() - start 4568 1e1c 05/25 16:24:09 1836347 OraChildProcess::~OraChildProcess() - enter 4568 1e1c 05/25 16:24:09 1836347 OraChildProcess::~OraChildProcess() - exit 4568 1e1c 05/25 16:24:09 1836347 ::ProcessComplete() - Sending ORA_MSG_RMAN_COMPLETE 4568 1e1c 05/25 16:24:09 1836347 ::RunRman() - m_rmanProcess->Failed(). 4568 1e1c 05/25 16:24:09 1836347 ::ExitHere() - enter: phase=10 4568 1e1c 05/25 16:24:09 1836347 ::ParseAndIgnoreErrors() - dir [0] temp_pos[1427] ignore_start_pos[1427] 4568 1e1c 05/25 16:24:09 1836347 ::SetErrorString() - m_ErrorStr [ORA-19554: error allocating device, device type: SBT_TAPE, device name: ], 1427, 1499 4568 1e1c 05/25 16:24:09 1836347 getRmanErrors() - Rman returned error [ORA-19554: error allocating device, device type: SBT_TAPE, device name: ] during backup operation.. 4568 1e1c 05/25 16:24:09 1836347 OraAgentBase::NotifyCommServeJobComplete() - Notify CommServe: jobObject.complete(FAIL,PHASE) 4568 1e1c 05/25 16:24:09 1836347 BKP CALLED COMPLETE (PHASE Status::FAIL), 1836347. Token [1836347:4:5] 4568 1e1c 05/25 16:24:10 1836347 ::Finalize() - enter Parent=true 4568 1e1c 05/25 16:24:10 1836347 ::Finalize() - m_jobControl->finishedWorkWithoutExit() ... 4568 1f2c 05/25 16:24:10 1836347 CVJobCtrlLog::unregisterProcess(): successfuly removed file [C:\Program Files\CommVault\Simpana\Base\JobControl\4.568] 4568 1e1c 05/25 16:24:10 1836347 ::Finalize() - delete m_jobControl ... 4568 1e1c 05/25 16:24:10 1836347 OraAgentBase::Finalize() - [1836347] delete m_jobObject. 4568 1e1c 05/25 16:24:10 1836347 OraJobObject::~OraJobObject() - After m_jobObject deletion. 4568 1e1c 05/25 16:24:10 1836347 ::Finalize() - delete m_event ... 8008 1c14 05/25 16:44:56 1836347 OraAgentBase::Initialize1() - m_totalBytesDiff=[104857600]. 8008 1c14 05/25 16:44:56 1836347 OraAgentBase::Initialize1() - secondsToWait=30 mode=0 m_backup=1. 8008 1c14 05/25 16:44:56 1836347 OraAgentBase::JobObjectInitialize() - [1836347] getting the new m_jobObject for CommServer=<172.16.4.2> 8008 1c14 05/25 16:44:56 1836347 OraJobObject::OraJobObject() - new m_jobObjectB 8008 1c14 05/25 16:44:56 1836347 JM Client CVBkpJobClient::init(): Initializing job object with token [1836347:4:6]. 8008 1c14 05/25 16:44:56 1836347 ::Initialize2() - dataAgentAttach-> ClientHostName=172.16.4.218 ServerHostName=172.16.4.2 8008 1c14 05/25 16:44:56 1836347 ::JobControlInitialize() - [1836347] getting the new m_jobControl for CommServer=<172.16.4.2>... 8008 1c14 05/25 16:44:56 1836347 ::JobControlInitialize() - m_jobControl.init(CONTROL) 1836347:4:6... 8008 1c14 05/25 16:44:56 1836347 Init() - Initializing job control [token=1836347:4:6,cn=proddb01], serverName [172.16.4.2], ControlFlag [1], Job Id [1836347] 8008 1c14 05/25 16:44:56 1836347 CVJobCtrlLog::registerProcess(): successfuly created file [C:\Program Files\CommVault\Simpana\Base\JobControl\8.008] 8008 1c14 05/25 16:44:58 1836347 ::RecvOraParams() - set JM JMBKP_ORACLE_RMAN_CUSTOMSCRIPT_BKP 0 8008 1c14 05/25 16:44:58 1836347 ::BrowseInit() - Initialize0(oraUser[noc_ora] oraHome=[c:\apps\product\oracle\oracle11gr23\] oraSID=[HRDB]) 8008 1c14 05/25 16:44:58 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 8008 1c14 05/25 16:44:58 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 8008 1c14 05/25 16:44:58 1836347 ::RunBrowse() - GetInfo(oraObjNameList=[B F A F]) 8008 1c14 05/25 16:44:58 1836347 OraObject::GetOraMode() - strictSID = 0 8008 1c14 05/25 16:44:58 1836347 OraChildProcess::Initialize() - enter 8008 1c14 05/25 16:44:58 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::Wait() - Child OK 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::Finalize() - start 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::~OraChildProcess() - enter 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::~OraChildProcess() - exit 8008 1c14 05/25 16:44:59 1836347 OraObject::GetOraMode() - oraMode = READ WRITE. 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::Initialize() - enter 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::Wait() - Child OK 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::Finalize() - start 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::~OraChildProcess() - enter 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::~OraChildProcess() - exit 8008 1c14 05/25 16:44:59 1836347 OraObject::CheckSid() - Galaxy Oracle SID[HRDB] equals Oracle SID [HRDB]. 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::Initialize() - enter 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::Wait() - Child OK 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::Finalize() - start 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::~OraChildProcess() - enter 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::~OraChildProcess() - exit 8008 1c14 05/25 16:44:59 1836347 OraObject::GetVersion() - Oracle Instance Version is [11.2.0.3.0] 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::Initialize() - enter 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::Wait() - Child OK 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::Finalize() - start 8008 1c14 05/25 16:44:59 1836347 OraObject::ParseReturn() - m_oraDbRole : [PRIMARY] 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::~OraChildProcess() - enter 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::~OraChildProcess() - exit 8008 1c14 05/25 16:44:59 1836347 OraObject::GetDbRole() - Oracle Instance Role is [PRIMARY] 8008 1c14 05/25 16:44:59 1836347 OraObject::GetOraMode() - 64bit oracle 1 8008 1c14 05/25 16:44:59 1836347 OraChildProcess::Initialize() - enter 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::Wait() - Child OK 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::Finalize() - start 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::~OraChildProcess() - enter 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::~OraChildProcess() - exit 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::Initialize() - enter 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::Wait() - Child OK 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::Finalize() - start 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::~OraChildProcess() - enter 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::~OraChildProcess() - exit 8008 1c14 05/25 16:45:05 1836347 ClOraAgent::GetInfoFromDB () - Trying Browse with B X 8008 1c14 05/25 16:45:05 1836347 ::BrowseInit() - Initialize0(oraUser[noc_ora] oraHome=[c:\apps\product\oracle\oracle11gr23\] oraSID=[HRDB]) 8008 1c14 05/25 16:45:05 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 8008 1c14 05/25 16:45:05 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 8008 1c14 05/25 16:45:05 1836347 ClOraAgent::GetInfoFromDB () - GetInfo(oraObjNameList=[B X]) 8008 1c14 05/25 16:45:05 1836347 OraObject::GetOraMode() - strictSID = 0 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::Initialize() - enter 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::Wait() - Child OK 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::Finalize() - start 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::~OraChildProcess() - enter 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::~OraChildProcess() - exit 8008 1c14 05/25 16:45:05 1836347 OraObject::GetOraMode() - oraMode = READ WRITE. 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::Initialize() - enter 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::ReadBuf() - ReadFile: LastError=109 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::Wait() - Child OK 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::Finalize() - start 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::~OraChildProcess() - enter 8008 1c14 05/25 16:45:05 1836347 OraChildProcess::~OraChildProcess() - exit 8008 1c14 05/25 16:45:05 1836347 ::ReadjustStreamsForSBTCopyParam() - oraReturn = 8008 1c14 05/25 16:45:05 1836347 ::RecvRmanScript() - receiving:OraRmanScript... 8008 1c14 05/25 16:45:06 1836347 ::RecvRmanScript() - RmanName=[rdsk] RmanService=[RCAT] 8008 1c14 05/25 16:45:07 1836347 ExecuteAction() - Total rman block to execute : 1 8008 1c14 05/25 16:45:07 1836347 ExecuteAction() - jobToken [1836347:4:6] Previous Phase Num [0] Rman Block Num [0]. 8008 1c14 05/25 16:45:07 1836347 ExecuteAction() - Executing rman block no :1 from rman script. 8008 1c14 05/25 16:45:07 1836347 ::RunRman() - enter 8008 1c14 05/25 16:45:07 1836347 ::VerifyOraVersion() - Loading DLL = C:\Program Files\CommVault\Simpana\Base\ORASBT.dll 8008 1c14 05/25 16:45:07 1836347 ::VerifyOraVersion() - Running Version = 9.0.0(BUILD84) 8008 1c14 05/25 16:45:07 1836347 ::GetNlsLang() - fetching registry key NLS_LANG 8008 1c14 05/25 16:45:07 1836347 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII 8008 1c14 05/25 16:45:07 1836347 OraChildProcess::Initialize() - enter 8008 1c14 05/25 16:45:07 1836347 OraChildProcess::BeginWait() - Rman thread with HNDL=31c TID=5556 EC=259 was created 8008 1c14 05/25 16:45:07 1836347 ::RunRman() - SendMsgToOA msgType=ORA_MSG_RMAN_START 8008 15b4 05/25 16:45:07 1836347 OraChildProcess::WaitThread() - start: thread Id=5556 8008 15b4 05/25 16:45:09 1836347 OraChildProcess::Wait() - Child process: dwExitCode=1 8008 15b4 05/25 16:45:09 1836347 OraChildProcess::WaitThread() - Wait failed; lastErr=1 8008 1c14 05/25 16:45:10 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - disconnect from Srv Ora Agent 8008 1c14 05/25 16:45:11 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - delete m_cvsOA... 8008 1c14 05/25 16:45:11 1836347 OraAgentBase::DisconnectFromSrvOraAgent() - after delete m_cvsOA. 8008 1c14 05/25 16:45:12 1836347 OraChildProcess::ReadBuf() - Rman thread with HNDL=290 TID=1480 EC=259 was created 8008 5c8 05/25 16:45:12 1836347 OraChildProcess::ReadThread() - start: thread Id=1480 8008 5c8 05/25 16:45:12 1836347 OraChildProcess::ReadThread() - GETLASTERROR returned=109 (ret=0) 8008 1c14 05/25 16:45:12 1836347 ::CloseJobResultsFile() - [1836347] going to m_buResults.closeFile... 8008 1c14 05/25 16:45:12 1836347 STORERESULTS: cleanUp: skipping jobResults cleanup. Another cleanup process is running 8008 1c14 05/25 16:45:12 1836347 JOBRESULTSTABLE(C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\1836347\JobResults): removing copy 'C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\1836347' 8008 1c14 05/25 16:45:12 1836347 ::CloseJobResultsFile() - [1836347] m_buResults.closeFile() & cleanUp() succeeded. 8008 1c14 05/25 16:45:12 1836347 OraChildProcess::Finalize() - start 8008 1c14 05/25 16:45:12 1836347 OraChildProcess::~OraChildProcess() - enter 8008 1c14 05/25 16:45:12 1836347 OraChildProcess::~OraChildProcess() - exit 8008 1c14 05/25 16:45:12 1836347 ::ProcessComplete() - Sending ORA_MSG_RMAN_COMPLETE 8008 1c14 05/25 16:45:12 1836347 ::RunRman() - m_rmanProcess->Failed(). 8008 1c14 05/25 16:45:12 1836347 ::ExitHere() - enter: phase=10 8008 1c14 05/25 16:45:12 1836347 ::ParseAndIgnoreErrors() - dir [0] temp_pos[1427] ignore_start_pos[1427] 8008 1c14 05/25 16:45:12 1836347 ::SetErrorString() - m_ErrorStr [ORA-19554: error allocating device, device type: SBT_TAPE, device name: ], 1427, 1499 8008 1c14 05/25 16:45:12 1836347 getRmanErrors() - Rman returned error [ORA-19554: error allocating device, device type: SBT_TAPE, device name: ] during backup operation.. 8008 1c14 05/25 16:45:12 1836347 OraAgentBase::NotifyCommServeJobComplete() - Notify CommServe: jobObject.complete(FAIL,PHASE) 8008 1c14 05/25 16:45:12 1836347 BKP CALLED COMPLETE (PHASE Status::FAIL), 1836347. Token [1836347:4:6] 8008 1c14 05/25 16:45:12 1836347 ::Finalize() - enter Parent=true 8008 1c14 05/25 16:45:12 1836347 ::Finalize() - m_jobControl->finishedWorkWithoutExit() ... 8008 1c64 05/25 16:45:12 1836347 CVJobCtrlLog::unregisterProcess(): successfuly removed file [C:\Program Files\CommVault\Simpana\Base\JobControl\8.008] 8008 1c14 05/25 16:45:12 1836347 ::Finalize() - delete m_jobControl ... 8008 1c14 05/25 16:45:12 1836347 OraAgentBase::Finalize() - [1836347] delete m_jobObject. 8008 1c14 05/25 16:45:12 1836347 OraJobObject::~OraJobObject() - After m_jobObject deletion. 8008 1c14 05/25 16:45:12 1836347 ::Finalize() - delete m_event ...