IT33655: ORACLE ON-DEMAND RESTORE FAILS WITH CTGGF0156 AND MESSAGE 'FAILED TO START INSTANCE'

APAR status

• Closed as program error.

Error description

• The Spectrum Protect Plus On-Demand Oracle restore process
  might stop with the message : 'CTGGF0156' and 'Failed to start
  instance'
  
  The job log will display
  :
  
  SUMMARY,,<timestamp>,,CTGGA2398,Starting job for policy
  onDemandRestore_<ID> (ID:xxxx). id -> <JobID>. IBM Spectrum
  Protect Plus version 10.1.6-1974.
  ...
  
  DETAIL,,<timestamp>,2,CTGGF0175,[<OracleHostIP>]
  <OracleInstance>: Running command: alter database open
  resetlogs;
   DETAIL,,<timestamp>,2,,[<OracleHostIP>]
  <OracleInstance>: Retrying because error ORA-65088 was
  received
   DETAIL,,<timestamp>,2,CTGGF0175,[<OracleHostIP>]
  <OracleInstance>: Running command: startup mount
  pfile='/srv/oracle/product/19_a/dbs/init<OracleInstance>.ora';
  
  ERROR,,<timestamp>,2,CTGGF0156,[<OracleHostIP>] Databas
  <OracleInstance>: Restore failed: Failed to start instance
  
  The
  command log found in the job log export will give a bit more
  detail :
  
  [<timestamp>] JOBLOG pid:xxxx Thread-yy
  writeInputFile: <CTGGF0175> <OracleInstance>: Running command:
  recover database using backup controlfile until
  cancel;
  [<timestamp>] INFO pid:xxxx Thread-yy processOutput:
  <OracleInstance>: ORA-00279: change aaaa generated at <Day>
  <Time_1> needed for thread 1
  [<timestamp>] INFO pid:xxxx
  Thread-yy processOutput: <OracleInstance>: ORA-00289:
  suggestion : /mnt/spp/vsnap/vpool2/fs69/<OracleHostIP>/<DBName>/
  arch/1_<SEQ1>_1042719871.dbf
  [<timestamp>] INFO pid:xxxx
  Thread-yy processOutput: <OracleInstance>: ORA-00280: change
  aaaa for thread 1 is in sequence #<SEQ1>
  [<timestamp>] INFO
  pid:xxxx Thread-yy processOutput: <OracleInstance>: ORA-00279:
  change bbbb generated at <Day> <Time_2> needed for thread
  1
  [<timestamp>] INFO pid:xxxx Thread-yy processOutput:
  <OracleInstance>: ORA-00289: suggestion : /mnt/spp/vsnap/vpool2/
  fs69/<OracleHostIP>/<DBName>/arch/1_<SEQ2>_1042719871.dbf
  [<time
  stamp>] INFO pid:xxxx Thread-yy processOutput:
  <OracleInstance>: ORA-00280: change bbbb for thread 1 is in
  sequence #<SEQ2>
  [<timestamp>] INFO pid:xxxx Thread-yy
  processOutput: <OracleInstance>: ORA-00308: cannot open
  archived log '/mnt/spp/vsnap/vpool2/fs69/<OracleHostIP>/<DBName>
  /arch/1_<SEQ2>_1042719871.dbf'
  [<timestamp>] INFO pid:xxxx
  Thread-yy processOutput: <OracleInstance>: ORA-17503: ksfdopn:4
  Failed to open file /mnt/spp/vsnap/vpool2/fs69/<OracleHostIP>/<D
  BName>/arch/1_<SEQ2>_1042719871.dbf
  [<timestamp>] INFO pid:xxxx
  Thread-yy processOutput: <OracleInstance>: ORA-17500: ODM
  err:File does not exist
  [<timestamp>] JOBLOG pid:xxxx Thread-yy
  writeInputFile: <CTGGF0175> <OracleInstance>: Running command:
  alter database archivelog;
  [<timestamp>] JOBLOG pid:xxxx
  Thread-yy worker_restore: <CTGGF0149> <OracleInstance>: Opening
  database.
  [<timestamp>] JOBLOG pid:xxxx Thread-yy
  writeInputFile: <CTGGF0175> <OracleInstance>: Running command:
  alter database open resetlogs;
  [<timestamp>] INFO pid:xxxx
  Thread-yy openDatabase: Traceback (most recent call last):
  
  File "/opt/IBM/SPP/agents_bkp_ispp/oracleagent/runner.py", line
  1021, in openDatabase
  Exception: Unexpected messages in command
  output
  [<timestamp>] INFO pid:xxxx Thread-yy openDatabase:
  <OracleInstance>: ORA-65088: database open should be
  retried
  [<timestamp>] JOBLOG pid:xxxx Thread-yy worker_restore:
  <OracleInstance>: Retrying because error ORA-65088 was
  received
  [<timestamp>] JOBLOG pid:xxxx Thread-yy
  writeInputFile: <CTGGF0175> <OracleInstance>: Running command:
  startup mount pfile='/srv/oracle/product/19_a/dbs/init<OracleIns
  tance>.ora';
  [<timestamp>] INFO pid:xxxx Thread-yy
  run_shell_command: Return code 1: ps -ef | grep
  _[p]mon_<OracleInstance>
  [<timestamp>] INFO pid:xxxx Thread-yy
  startupInstancewithPmonCheck: The startup instance process has
  encountered some issue: ['ORA-01012: not logged on', 'Process
  ID: 0', 'Session ID: 0 Serial number: 0', '', '']
  
  ORA-01012 is
  basically telling the restore process did not find the instance
  up and running.
  
  This can happen when the memory allocated to
  the Oracle system is set too low and therefore slowing down the
  instance startup sequence.
  If the startup takes too much time,
  the restore process stops after a few seconds waiting.
  The
  restore process should allow more time to wait the Oracle
  instance to come up.
  
  IBM Spectrum Protect Plus Versions
  Affected:
  IBM Spectrum Protect Plus 10.1.5, 10.1.6
  
  Initial
  Impact: Medium
  
  Additional Keywords: SPP, SPPLUS, TS003872080,
  oracle, restore, 19c, CDB, container
  

Local fix

• Increase memory for the Oracle system to allow for sufficient
  resources so the instance can start within a few seconds.
  

Problem summary

• ****************************************************************
  * USERS AFFECTED:                                              *
  * IBM Spectrum Protect Plus level 10.15. and 10.1.6            *
  ****************************************************************
  * PROBLEM DESCRIPTION:                                         *
  * See ERROR DESCRIPTION                                        *
  ****************************************************************
  * RECOMMENDATION:                                              *
  * Apply fixing level when available. This problem is currently *
  * projected to be fixed in IBM Spectrum Protect Plus level     *
  * 10.1.7. Note that this is subject to change at the           *
  * discretion of IBM.                                           *
  ****************************************************************
  

Problem conclusion

• Database start logic is enhanced to wait for a minute after
  encountering ORA-65088 when starting the database.
  

Temporary fix

Comments

APAR Information

• APAR is sysrouted FROM one or more of the following:

• APAR is sysrouted TO one or more of the following:

Fix information

• Fixed component name

  SP PLUS

• Fixed component ID

  5737SPLUS

Applicable component levels