cancel
Turn on suggestions
Auto-suggest helps you quickly narrow down your search results by suggesting possible matches as you type.
Showing results for 
Search instead for 
Did you mean: 

SAP BR*TOOL execution failed

Former Member

on ‎08-25-2014 7:53 AM

0 Kudos

Hi, last week due to migration our server was crashed. We built a new SAP server and when trying to restore the CONTROL FILE  from last successful  back up using the commvault tool, we are ending up with a error "SAP BR*TOOL execution failed"

Request help on this immediately.

The error log generated in commvault is as below.

@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@

Machine : abtmsasbkp01

File    : JobManager.log

@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@

12996 1154 08/25 12:03:23 47259 Servant    [---- IMMEDIATE RESTORE REQUEST ----] Task id [47259] Clnt[abtmssdq01] AppType[SAP for Oracle][61]

12996 cf0  08/25 12:03:24 47259 Scheduler  Phase [2-Restore] (0,0) started on [10.24.42.4] - ClSapAgent.exe SAPRESTORE 47259 47259 -p 2

12996 1e7c 08/25 12:03:24 47259 Servant    Reg [Control] received. Host [10.24.42.4] plattype = 4

12996 1e7c 08/25 12:03:28 47259 Scheduler  Set pending cause [sap BRRESTORE execution failed. Please, check the log file for details.]::Client [abtmssdq01] Application [ClSapAgent] Message Id [301989982] RCID [0] ReservationId [0].  Level [0] flags [0] id [0] overwrite [0] append [0] CustId[0].

12996 1e7c 08/25 12:03:29 47259 Scheduler  Phase [Failed] message received from [10.24.42.4] Module [ClSapAgent] Token [] restartPhase [0]

12996 1e7c 08/25 12:03:29 47259 JobSvr Obj Phase [2-Restore] for Restore Job Failed and cannot be restarted.

12996 1e7c 08/25 12:03:29 47259 Scheduler   -> FAILED <-

12996 25ac 08/25 12:03:29 47259 Scheduler  Got delayed pending cause [318768440] for RCID [0], Reservation Id [0] from client [abtmssdq01] and application [ClSapAgent]::[Oracle Restore [sap BR*TOOL execution failed.

@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@

Machine : abtmssdq01

File    : ClSapAgent.log

@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@

1156 150 08/25 12:03:24 47259 OraAgentBase::Initialize1() - m_totalBytesDiff=[104857600].

1156 150 08/25 12:03:24 47259 OraAgentBase::Initialize1() - secondsToWait=30 mode=0 m_backup=2.

1156 150 08/25 12:03:24 47259 OraAgentBase::JobObjectInitialize() - [47259] getting the new m_jobObject for CommServer=<abtmsasbkp01>

1156 150 08/25 12:03:24 47259 ::Initialize2() - Initialize2: jobMode=2 SAP Oracle Restores...

1156 150 08/25 12:03:24 47259 ::Initialize2() - Initialize2: ClientHostName=10.24.42.4 ServerHostName=abtmsasbkp01

1156 150 08/25 12:03:24 47259 ClSapAgent::Initialize3() - job id at enter [47259]

1156 150 08/25 12:03:24 47259 ClSapAgent::Initialize3() - m_clientName=abtmssdq01

1156 150 08/25 12:03:24 47259 ClSapAgent::Initialize3() - CVClient::getCommCellId=2

1156 150 08/25 12:03:24 47259 ::JobControlInitialize() - [47259] getting the new m_jobControl for CommServer=<abtmsasbkp01>...

1156 150 08/25 12:03:24 47259 ::JobControlInitialize() - m_jobControl.init(CONTROL) ...

1156 150 08/25 12:03:24 47259 Init() - Initializing job control [token=,cn=abtmssdq01], serverName [abtmsasbkp01], ControlFlag [1], Job Id [47259]

1156 150 08/25 12:03:24 47259 CVJobCtrlLog::registerProcess(): successfuly created file [C:\Program Files\CommVault\Simpana\Base\JobControl\1.156]

1156 150 08/25 12:03:24 47259 JRCACHEDIR: job 47259 creating 'C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\47259'

1156 150 08/25 12:03:24 47259 ::ExecuteBrRestore() - enter

1156 150 08/25 12:03:24 47259 ::ExecuteBrRestore() - After EvRstTask getAppTypeId=61 retCode=0

1156 150 08/25 12:03:24 47259 ::ExecuteBrRestore() - SAP RESTORE instId=13 clientId=9

1156 150 08/25 12:03:24 47259 ClOraAgent::InitializeOraParams() - oraUser[chqadm]

1156 150 08/25 12:03:24 47259 ::ExecuteBrRestore() - oraSID

1156 150 08/25 12:03:24 47259 ::ExecuteBrRestore() - oraUser

1156 150 08/25 12:03:24 47259 ::ExecuteBrRestore() - oraHome

1156 150 08/25 12:03:24 47259 ::ExecuteBrRestore() - getDestinationClientId returned [9] destination client id

1156 150 08/25 12:03:24 47259 ::ExecuteBrRestore() -  [13]  E m_initArgs.instanceId.

1156 150 08/25 12:03:24 47259 ClOraAgent::InitializeOraParams() - oraUser[chqadm]

1156 150 08/25 12:03:24 47259 ::ExecuteBrRestore() -  [13]  F m_initArgs.instanceId.

1156 150 08/25 12:03:24 47259 ::ExecuteBrRestore() - Success in init with JM

1156 150 08/25 12:03:24 47259 CVArchive::Construct() - Constructing CVArchive Object

1156 150 08/25 12:03:24 47259 CVArchive::Construct() - Enable CVArchive Big Buffer [true]

1156 150 08/25 12:03:24 47259 ::ExecuteBrRestore() - Before amgr.getArchFileListByTime(), clientId=9, instanceId=13, appType=61, before=2147483647

1156 150 08/25 12:03:25 47259 ::ExecuteBrRestore() - No of recs=75 snapRestore=0

1156 150 08/25 12:03:25 47259 ::ExecuteBrRestore() - Job=46327 CommCellId=2

1156 150 08/25 12:03:25 ##### JM Client  CVJobClient::initialize(): Invalid job id passed as parameter.

1156 150 08/25 12:03:25 47259 ::ExecuteBrRestore() - Job Init ok

1156 150 08/25 12:03:25 47259 getXmlBlob() call received xml [<?xml version="1.0" encoding="UTF-8" standalone="no" ?><JobManager_BkpJobDetailsXml appType="61" compType="2" jobType="1"><sapOracleJob attribType="0"><dataAttributes backupMode="0" backupType="1" backupdevice="0" clockSkew="-1" detailFileName="G:\oracle\CHQ\sapbackup\beomwekx.aff" endTime="2014-08-13 02.46.03" startTime="2014-08-13 02.05.39" summaryFileName="G:\oracle\CHQ\sapbackup\backCHQ.log"/></sapOracleJob></JobManager_BkpJobDetailsXml>] for job 46327

1156 150 08/25 12:03:25 47259 ::ExecuteBrRestore() - Job=46327 CommCellId=2 [<?xml version="1.0" encoding="UTF-8" standalone="no" ?><JobManager_BkpJobDetailsXml appType="61" compType="2" jobType="1"><sapOracleJob attribType="0"><dataAttributes backupMode="0" backupType="1" backupdevice="0" clockSkew="-1" detailFileName="G:\oracle\CHQ\sapbackup\beomwekx.aff" endTime="2014-08-13 02.46.03" startTime="2014-08-13 02.05.39" summaryFileName="G:\oracle\CHQ\sapbackup\backCHQ.log"/></sapOracleJob></JobManager_BkpJobDetailsXml>]

1156 150 08/25 12:03:25 47259 ::ExecuteBrRestore() - retCode from unserialize=0

1156 150 08/25 12:03:25 47259 ::ExecuteBrRestore() - FULL util_file beomwekx.aff 2014-08-13 02.05.39 2014-08-13 02.46.03

1156 150 08/25 12:03:25 47259 ::ExecuteBrRestore() - logRangeRman=<> logRangeUtil=<> logEndTime=<>

1156 150 08/25 12:03:25 47259 ::ExecuteBrRestore() - checking ....restoreData=0 restoreArchiveLog=0 recoverDb=0 restoreTime=0 recoverTime=0 restoreControlFile=1 openDatabase=0 resetLogs=0 restorePartial=0 revert=0 copyPrec=0 archLogBy=0 resetDatabase=0 logFromTime=0 logToTime=0 logStart=0 logEnd=0 numStreams=1 useRmanFull=0 rmanDetail=

1156 150 08/25 12:03:25 47259 SapJobProgress() - Constructor

1156 150 08/25 12:03:25 47259 ::ExecuteBrRestore() - Neighter Tablespace or ArchiveLogs are being restored...

1156 150 08/25 12:03:25 47259 ::GetNlsLang() - fetching registry key NLS_LANG

1156 150 08/25 12:03:25 47259 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII

1156 150 08/25 12:03:25 47259 OraChildProcess::Initialize() - enter

1156 150 08/25 12:03:25 47259 OraChildProcess::ReadBuf() - ReadFile: LastError=109

1156 150 08/25 12:03:25 47259 OraChildProcess::Wait() - Child OK

1156 150 08/25 12:03:25 47259 OraChildProcess::~OraChildProcess() - enter

1156 150 08/25 12:03:25 47259 OraChildProcess::~OraChildProcess() - exit

1156 150 08/25 12:03:25 47259 ::ExecuteBrRestore() - Database is in no mount mode.

1156 150 08/25 12:03:25 47259 ::ExecuteBrRestore() - restore_config: data summary file [G:\oracle\CHQ\sapbackup\backCHQ.log]

1156 150 08/25 12:03:25 47259 ::ExecuteBrRestore() - Invoking: [brrestore -d util_file -b2 \#NULL -m G:\oracle\CHQ\sapbackup\backCHQ.log -c force -u / ]

1156 150 08/25 12:03:25 47259 ::GetNlsLang() - fetching registry key NLS_LANG

1156 150 08/25 12:03:25 47259 ::GetNlsLang() - registry key NLS_LANG not set therefore setting NLS_LANG to American_America.US7ASCII

1156 150 08/25 12:03:25 47259 ClSapAgent::SetSapEnv() - SETENVIRONMENTVARIABLE(DIR_LIBRARY=D:\usr\sap\CHQ\SYS\exe\uc\NTAMD64)

1156 150 08/25 12:03:25 47259 ClSapAgent::FillNTEnv() - SETENVIRONMENTVARIABLE(CvClientName=abtmssdq01) set successfully

1156 150 08/25 12:03:25 47259 ClSapAgent::FillNTEnv() - SETENVIRONMENTVARIABLE(CvInstanceName=Instance001) set successfully

1156 150 08/25 12:03:25 47259 OraChildProcess::Initialize() - enter

1156 150 08/25 12:03:25 47259 OraChildProcess::BeginWait() - Rman thread with HNDL=314 TID=2840 EC=259 was created

1156 b18 08/25 12:03:25 47259 OraChildProcess::WaitThread() - start: thread Id=2840

1156 b18 08/25 12:03:25 47259 OraChildProcess::Wait() - Child process: dwExitCode=3

1156 b18 08/25 12:03:25 47259 OraChildProcess::WaitThread() - Wait failed; lastErr=3

1156 150 08/25 12:03:28 47259 ::ExecuteBrRestore() - After Begin wait...

1156 150 08/25 12:03:28 47259 ::ExecuteBrRestore() - wait failed...

1156 150 08/25 12:03:28 47259 OraChildProcess::ReadBuf() - Rman thread with HNDL=304 TID=2912 EC=259 was created

1156 b60 08/25 12:03:28 47259 OraChildProcess::ReadThread() - start: thread Id=2912

1156 b60 08/25 12:03:29 47259 OraChildProcess::ReadThread() - GETLASTERROR returned=109 (ret=0)

1156 150 08/25 12:03:29 47259 ::CloseJobResultsFile() - [47259] going to m_buResults.closeFile...

1156 150 08/25 12:03:29 47259 STORERESULTS: cleanUp: skipping jobResults cleanup. Another cleanup process is running

1156 150 08/25 12:03:29 47259 JOBRESULTSTABLE(C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\47259\JobResults): removing copy 'C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\47259'

1156 150 08/25 12:03:29 47259 ::CloseJobResultsFile() - [47259] m_buResults.closeFile() & cleanUp() succeeded.

1156 150 08/25 12:03:29 47259 OraChildProcess::Finalize() - start

1156 150 08/25 12:03:29 47259 OraChildProcess::~OraChildProcess() - enter

1156 150 08/25 12:03:29 47259 OraChildProcess::~OraChildProcess() - exit

1156 150 08/25 12:03:29 47259 ::ProcessComplete() - Sending ORA_MSG_RMAN_COMPLETE

1156 150 08/25 12:03:29 47259 Sending FAILED complete message to JM, 47259

1156 150 08/25 12:03:29 47259 ::ExecuteBrRestore() - sap BR*TOOL execution failed.

1156 150 08/25 12:03:29 47259 ::ExecuteBrRestore() - sap BR*TOOL execution failed.

1156 150 08/25 12:03:29 47259 ::ExecuteBrRestore() - m_jobObject->setPendingCause(sap BR*TOOL execution failed.

1156 150 08/25 12:03:29 47259 GetChannelParamFileName() - Channel Parameter File : C:\Program Files\CommVault\Simpana\Base\Temp\cv_channel_info47259

1156 150 08/25 12:03:29 47259 DeleteChannelParamFile() - Cleaned up channel parameter file

1156 150 08/25 12:03:29 47259 ::Close() - ClOraAgent Closed.

1156 150 08/25 12:03:29 47259 ::Finalize() - enter Parent=true

1156 150 08/25 12:03:29 47259 ::Finalize() - m_jobControl->finishedWorkWithoutExit() ...

1156 180 08/25 12:03:29 47259 CVJobCtrlLog::unregisterProcess(): successfuly removed file [C:\Program Files\CommVault\Simpana\Base\JobControl\1.156]

1156 150 08/25 12:03:29 47259 ::Finalize() - delete m_jobControl ...

1156 150 08/25 12:03:29 47259 ::CloseJobResultsFile() - [47259] going to m_buResults.closeFile...

1156 150 08/25 12:03:29 47259 STORERESULTS: cleanUp: skipping jobResults cleanup. Another cleanup process is running

1156 150 08/25 12:03:29 47259 JOBRESULTSTABLE(C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\47259\JobResults): removing copy 'C:\Program Files\CommVault\Simpana\iDataAgent\JobResults\CV_JobResults\2\0\47259'

1156 150 08/25 12:03:29 47259 ::CloseJobResultsFile() - [47259] m_buResults.closeFile() & cleanUp() succeeded.

Show replies
Show replies
Answer

Accepted Solutions (0)

Answers (2)

Answers (2)

Former Member
‎08-28-2014 7:10 AM
0 Kudos

Hi

Backup has been restored

now try to recover using

Sql> recover database using backup controlfile ;

but if you have archive log files till some time

then please use

Sql> recover database using backup controlfile until time '' ;

and then open database using

sql > alter database open resetlogs;

because after database restore it will not allow you to open with no reset logs.

all the best

Regards

Dishant .

Show replies
Show replies
Former Member
‎08-28-2014 10:22 AM
0 Kudos

Saying:



sql > alter database open resetlogs;




because after database restore it will not allow you to open with no reset logs.

is misleading. You must reset logs only when you:

- lost ALL control files

- do incomplete recovery (recover database until....)

But in this particular case yes, RESETLOGS is necessary.

Former Member
‎08-28-2014 11:00 AM
0 Kudos

HI michal

i have replied considering this case only.

and yes i agree this is dangerous doing Resetlogs.

any way thanks you to mention the same .

Regards

Dishant

Former Member
‎10-02-2014 10:47 PM
0 Kudos

Hello ,

You can make resetlogs, without problems !!! If all files be restored and all archivelogs apolied, do this "alter database open resetlogs"

will be generate new database incarnation for this database. And you need to make a new database full bakcup.

regards

Sandro Lobo

former_member188883
Active Contributor
‎08-25-2014 8:22 AM
0 Kudos

Hi Suman,

I Assume that backup has been restored successfully. In such a case you may recreate the controlfile and then proceed with recovery as applicable.

Regards,

Deepak Kori

Show replies
Show replies
Ask a Question