This blog post is on what happens when you ask RMAN to restore and recover your database or a portion of your database (like a datafile).
This came up with a colleague who asked about the order of recovery. The question was "If my archive logs are on disk for 48 hours, I performed a full backup 36 hours ago (to SBT_TAPE) and an incremental backup 12 hours ago (to SBT_TAPE), after restoring from SBT_TAPE, will it recover from the archive logs on disk, or will it go to tape for the incremental backup first ?
Well the answer is in the manual
here.
Incremental Backups and Archived Redo Log Files
Except for RECOVER BLOCK
, RMAN can use both incremental backups and archived redo log files for recovery. RMAN uses the following search order:
Incremental backup sets on disk or tape
Archived redo log files on disk
Archived redo log backups on disk
Archived redo log backup sets on tape
Now let's see this in action.
In my scenario, I am using the "USERS" tablespace. The datafile I'm going to drop is datafile 7.
Let's walk down what happens at each SCN interval.
3435417 Full backup of datafile 7
BS Key Type LV Size Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
1 Incr 0 1.64G DISK 00:01:30 14-MAY-18
BP Key: 1 Status: AVAILABLE Compressed: NO Tag: TAG20180514T065607
Piece Name: D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\01T2ROOB_1_1
List of Datafiles in backup set 1
File LV Type Ckp SCN Ckp Time Abs Fuz SCN Sparse Name
---- -- ---- ---------- --------- ----------- ------ ----
7 0 Incr 3435417 14-MAY-18 NO D:\APP\BGRENN\VIRTUAL\ORADATA\ORCL\USERS01.DBF
Backup of Archive logs to defuzzy full backup
BS Key Size Device Type Elapsed Time Completion Time
------- ---------- ----------- ------------ ---------------
5 143.22M DISK 00:00:05 14-MAY-18
BP Key: 5 Status: AVAILABLE Compressed: NO Tag: TAG20180514T065904
Piece Name: D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\05T2ROTO_1_1
List of Archived Logs in backup set 5
Thrd Seq Low SCN Low Time Next SCN Next Time
---- ------- ---------- --------- ---------- ---------
1 38 3394580 13-MAY-18 3435493 14-MAY-18
Backup of archive logs prior to incremental backup
BS Key Size Device Type Elapsed Time Completion Time
------- ---------- ----------- ------------ ---------------
9 952.50K DISK 00:00:00 14-MAY-18
BP Key: 9 Status: AVAILABLE Compressed: NO Tag: TAG20180514T070224
Piece Name: D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\0BT2RP41_1_1
List of Archived Logs in backup set 9
Thrd Seq Low SCN Low Time Next SCN Next Time
---- ------- ---------- --------- ---------- ---------
1 39 3435493 14-MAY-18 3435597 14-MAY-18
1 40 3435597 14-MAY-18 3435668 14-MAY-18
h3 style="text-align: left;">
3435627 Incremental backup of datafile 7
BS Key Type LV Size Device Type Elapsed Time Completion Time
------- ---- -- ---------- ----------- ------------ ---------------
7 Incr 1 1.24M DISK 00:00:37 14-MAY-18
BP Key: 7 Status: AVAILABLE Compressed: NO Tag: TAG20180514T070122
Piece Name: D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\07T2RP23_1_1
List of Datafiles in backup set 7
File LV Type Ckp SCN Ckp Time Abs Fuz SCN Sparse Name
---- -- ---- ---------- --------- ----------- ------ ----
7 1 Incr 3435627 14-MAY-18 NO D:\APP\BGRENN\VIRTUAL\ORADATA\ORCL\USERS01.DBF
Backup of archive logs
BS Key Size Device Type Elapsed Time Completion Time
------- ---------- ----------- ------------ ---------------
9 952.50K DISK 00:00:00 14-MAY-18
BP Key: 9 Status: AVAILABLE Compressed: NO Tag: TAG20180514T070224
Piece Name: D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\0BT2RP41_1_1
List of Archived Logs in backup set 9
Thrd Seq Low SCN Low Time Next SCN Next Time
---- ------- ---------- --------- ---------- ---------
1 39 3435493 14-MAY-18 3435597 14-MAY-18
1 40 3435597 14-MAY-18 3435668 14-MAY-18
BS Key Size Device Type Elapsed Time Completion Time
------- ---------- ----------- ------------ ---------------
11 3.11M DISK 00:00:00 14-MAY-18
BP Key: 11 Status: AVAILABLE Compressed: NO Tag: TAG20180514T085551
Piece Name: D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\0DT2RVOO_1_1
List of Archived Logs in backup set 11
Thrd Seq Low SCN Low Time Next SCN Next Time
---- ------- ---------- --------- ---------- ---------
1 41 3435668 14-MAY-18 3435770 14-MAY-18
1 42 3435770 14-MAY-18 3437175 14-MAY-18
1 43 3437175 14-MAY-18 3437200 14-MAY-18
1 44 3437200 14-MAY-18 3437210 14-MAY-18
1 45 3437210 14-MAY-18 3437216 14-MAY-18
OK.. Now we have backups on disk (full and level 1) to restore and recover from.
First let's do the restore of datafile 7
RMAN>
Starting restore at 14-MAY-18
using channel ORA_DISK_1
channel ORA_DISK_1: starting datafile backup set restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
channel ORA_DISK_1: restoring datafile 00007 to D:\APP\BGRENN\VIRTUAL\ORADATA\ORCL\USERS01.DBF
channel ORA_DISK_1: reading from backup piece D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\01T2ROOB_1_1
channel ORA_DISK_1: piece handle=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\01T2ROOB_1_1 tag=TAG20180514T065607
channel ORA_DISK_1: restored backup piece 1
channel ORA_DISK_1: restore complete, elapsed time: 00:00:01
Finished restore at 14-MAY-18
Now let's do the recovery of datafile 7 and watch what happens.
RMAN>
Starting recover at 14-MAY-18
using channel ORA_DISK_1
channel ORA_DISK_1: starting incremental datafile backup set restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
destination for restore of datafile 00007: D:\APP\BGRENN\VIRTUAL\ORADATA\ORCL\USERS01.DBF
channel ORA_DISK_1: reading from backup piece D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\07T2RP23_1_1
channel ORA_DISK_1: piece handle=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\07T2RP23_1_1 tag=TAG20180514T070122
channel ORA_DISK_1: restored backup piece 1
channel ORA_DISK_1: restore complete, elapsed time: 00:00:02
starting media recovery
archived log for thread 1 with sequence 40 is already on disk as file D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000040_0974378014.0001
archived log for thread 1 with sequence 41 is already on disk as file D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000041_0974378014.0001
archived log for thread 1 with sequence 42 is already on disk as file D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000042_0974378014.0001
archived log for thread 1 with sequence 43 is already on disk as file D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000043_0974378014.0001
archived log for thread 1 with sequence 44 is already on disk as file D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000044_0974378014.0001
archived log for thread 1 with sequence 45 is already on disk as file D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000045_0974378014.0001
archived log file name=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000040_0974378014.0001 thread=1 sequence=40
archived log file name=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000041_0974378014.0001 thread=1 sequence=41
archived log file name=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000042_0974378014.0001 thread=1 sequence=42
archived log file name=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000043_0974378014.0001 thread=1 sequence=43
media recovery complete, elapsed time: 00:00:03
Finished recover at 14-MAY-18
You can see in the recovery, there are 2 steps performed, but this isn't whole picture.
Step 1 Restore all incremental backups.
using channel ORA_DISK_1
channel ORA_DISK_1: starting incremental datafile backup set restore
channel ORA_DISK_1: specifying datafile(s) to restore from backup set
destination for restore of datafile 00007: D:\APP\BGRENN\VIRTUAL\ORADATA\ORCL\USERS01.DBF
channel ORA_DISK_1: reading from backup piece D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\07T2RP23_1_1
channel ORA_DISK_1: piece handle=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\07T2RP23_1_1 tag=TAG20180514T070122
channel ORA_DISK_1: restored backup piece 1
channel ORA_DISK_1: restore complete, elapsed time: 00:00:02
Step 2 Recover using archive logs on disk
starting media recovery
archived log for thread 1 with sequence 40 is already on disk as file D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000040_0974378014.0001
archived log for thread 1 with sequence 41 is already on disk as file D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000041_0974378014.0001
archived log for thread 1 with sequence 42 is already on disk as file D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000042_0974378014.0001
archived log for thread 1 with sequence 43 is already on disk as file D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000043_0974378014.0001
archived log for thread 1 with sequence 44 is already on disk as file D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000044_0974378014.0001
archived log for thread 1 with sequence 45 is already on disk as file D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000045_0974378014.0001
archived log file name=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000040_0974378014.0001 thread=1 sequence=40
archived log file name=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000041_0974378014.0001 thread=1 sequence=41
archived log file name=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000042_0974378014.0001 thread=1 sequence=42
archived log file name=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000043_0974378014.0001 thread=1 sequence=43
media recovery complete, elapsed time: 00:00:03
Finished recover at 14-MAY-18
Now I reran with trace on and let's look at the pieces
Rman determines the current checkpoint SCN of the datafile I'm recovering (3435417)
DBGSQL: TARGET> select fhscn, to_date(fhtim,'MM/DD/RR HH24:MI:SS', 'NLS_CALENDAR=Gregorian'), fhcrs, fhrls, to_date(fhrlc,'MM/DD/RR HH24:MI:SS', 'NLS_CALENDAR=Gregorian'), fhafs, fhrfs, fhrft, hxerr, fhfsz, fhsta, fhdbi, fhfdbi, fhplus, fhtyp into :ckpscn, :ckptime, :crescn, :rlgscn, :rlgtime, :afzscn, :rfzscn, :rfztime, :hxerr, :blocks, :fhsta, :fhdbi, :fhfdbi, :fhplus, :fhtyp from x$kcvfhall where hxfil = :fno
DBGSQL: sqlcode = 0
DBGSQL: D :ckpscn = 3435417
DBGSQL: D :ckptime = "14-MAY-18"
DBGSQL: D :crescn = 29665
DBGSQL: D :rlgscn = 1490582
DBGSQL: D :rlgtime = "25-APR-18"
DBGSQL: D :afzscn = 0
DBGSQL: D :rfzscn = 0
DBGSQL: D :rfztime = NULL
DBGSQL: D :hxerr = 0
DBGSQL: D :blocks = 640
DBGSQL: D :fhsta = 0
DBGSQL: D :fhdbi = 1502158741
DBGSQL: D :fhfdbi = 0
DBGSQL: D :fhplus = 0
DBGSQL: D :fhtyp = 3
DBGSQL: B :fno = 7
DBGMISC: krmkrfh: [10:07:46.470]
DBGMISC: DF fno=7 pplfno=0 pdbid=1 pdbname= crescn=29665
DBGMISC: blksize=8192 blocks=640 rfno=7 pdbForeignDbid=0
DBGMISC: fn=D:\APP\BGRENN\VIRTUAL\ORADATA\ORCL\USERS01.DBF
DBGMISC: ts=USERS, flags=KRMKDF_INBACKUP
DBGMISC: fedata: sta=0x0e crescn=29665
DBGMISC: fhdata: ckpscn=3435417 rlgscn=1490582
DBGMISC: EXITED krmkrfh [10:07:46.779] elapsed time [00:00:00:01.074]
RMAN finds any incremental backups that can applied. Then restores and applies as much incremental backups as it can.
TARGET> declare allCopies boolean; begin dbms_rcvman.resetthisBackupAge; if (:allCopies > 0) then allCopies := TRUE; else allCopies := FALSE; end if; :rc := dbms_rcvman.computeRecoveryActions( fno => :fno, crescn => :crescn, df_rlgscn => :rlgscn, df_rlgtime => :rlgtime, df_ckpscn => :ckpscn, offlscn => :offlscn, onlscn => :onlscn, onltime => :onltime, cleanscn => :cleanscn, clean2scn => :clean2scn, clean2time => :clean2time, allowfuzzy => FALSE, partial_rcv => FALSE, cf_scn => :cfscn, cf_cretime => :cfcretime, cf_offrrid => :cfoffrrid, allCopies => allCopies, df_cretime => :cretime, rmanCmd => :rmanCmd, foreignDbid => :foreignDbid, pluggedRonly => :pluggedRonly, pluginSCN => :pluginSCN, pluginRlgSCN => :pluginRlgSCN, pluginRlgTime => :pluginRlgTime, creation_thread => :creation_thread, creation_size => :creation_size, pdbId => :pdbId, pdbForeignDbid => :pdbForeignDbid ); if (:maxact > 0) then dbms_rcvman.trimRecoveryActions( maxActions => :maxact, containerMask => dbms_rcvman.proxyCopy_con_t + dbms_rcvman.imageCopy_con_t + dbms_rcvman.backupSet_con_t, actionMask => dbms_rcvman.full_act_t); end if; end;
DBGSQL: sqlcode = 0
DBGSQL: B :rc = 0
DBGSQL: B :allCopies = 2
DBGSQL: B :fno = 7
DBGSQL: B :crescn = 29665
DBGSQL: B :rlgscn = 1490582
DBGSQL: B :rlgtime = "25-APR-18"
DBGSQL: B :ckpscn = 3435417
DBGSQL: B :offlscn = 1490581
DBGSQL: B :onlscn = 1490582
DBGSQL: B :onltime = "25-APR-18"
DBGSQL: B :cleanscn = 0
DBGSQL: B :clean2scn = 0
DBGSQL: B :clean2time = "01-JAN-88"
DBGSQL: B :cfscn = 3440786
DBGSQL: B :cfcretime = "25-APR-18"
DBGSQL: B :cfoffrrid = 1
DBGSQL: B :cretime = "08-MAR-17"
DBGSQL: B :rmanCmd = 1
DBGSQL: B :maxact = 0
DBGSQL: B :foreignDbid = 0
DBGSQL: B :pluggedRonly = 0
DBGSQL: B :pluginSCN = 0
DBGSQL: B :pluginRlgSCN = 0
DBGSQL: B :pluginRlgTime = NULL
DBGSQL: B :creation_thread = 0
DBGSQL: B :creation_size = 0
DBGSQL: B :pdbId = 1
DBGSQL: B :pdbForeignDbid = 0
DBGRCVMAN: thisBackupAge= 0
DBGRCVMAN: ENTERING computeRecoveryActions
DBGRCVMAN: computeRecoveryActions fno: 7
DBGRCVMAN: computeRecoveryActions crescn: 29665
DBGRCVMAN: computeRecoveryActions df_rlgscn: 1490582
DBGRCVMAN: computeRecoveryActions df_ckpscn: 3435417
DBGRCVMAN: computeRecoveryActions offlscn: 1490581
DBGRCVMAN: computeRecoveryActions onlscn: 1490582
DBGRCVMAN: computeRecoveryActions cleanscn: 0
DBGRCVMAN: computeRecoveryActions clean2scn: 0
DBGRCVMAN: computeRecoveryActions cf_scn: 3440786
DBGRCVMAN: computeRecoveryActions cf_offrrid: 1
DBGRCVMAN: computeRecoveryActions foreignDbid: 0
DBGRCVMAN: computeRecoveryActions pluggedRonly: 0
DBGRCVMAN: computeRecoveryActions pluginSCN: 0
DBGRCVMAN: computeRecoveryActions pluinRlgSCN: 0
DBGRCVMAN: computeRecoveryActions creation_thread: 0
DBGRCVMAN: computeRecoveryActions creation_size: 0
DBGRCVMAN: computeRecoveryActions pdbid: 1
DBGRCVMAN: computeRecoveryActions pdbForeignDbid: 0
DBGRCVMAN: allCopies is TRUE
DBGRCVMAN: doing recover
DBGRCVMAN: ENTERING computeRecoveryActions2
DBGRCVMAN: computeRecoveryActions2 doing recovery.
DBGRCVMAN: computeRecoveryActions2 This is ancestor.
DBGRCVMAN: ENTERING openRecoveryActionCursor
DBGRCVMAN: openRecoveryActionCursor target scn is NULL,creSCN=29665,dfCkpSCN=3435417,dbincRlgSCN=1490582,offlSCN=1490581,onlSCN=1490582,cleanSCN=0,clean2SCN=0,fno=7,pluginSCN=0,rmanCmd=1
DBGRCVMAN: openRecoveryActionCursor currc1.type_con=NULL currc1.fno=7 currc1.crescn=29665
DBGRCVMAN: openRecoveryActionCursor restoreSource=, restoreSparse=0
DBGRCVMAN: openRecoveryActionCursor cursor1 not open yet
DBGRCVMAN: OPENING cursor rcvRecCursor1_c in openRecoveryActionCursor
DBGRCVMAN: ENTERING fetchCursor1RecoveryAction
DBGRCVMAN: fetchCursor1RecoveryAction opcode=1
DBGRCVMAN: fetchCursor1RecoveryAction seekNext
DBGRCVMAN: fetchCursor1RecoveryAction rcvRecCursor1_c record
DBGRCVMAN: DUMPING RECOVERY CONTAINER
DBGRCVMAN: Incremental Backup Set
DBGRCVMAN: bsKey=7 bsRecid=7 bsStamp=976086120 setStamp=976086083 setCount=7 site_key=0
DBGRCVMAN: bsLevel=1 bsType=I pieceCount=1
DBGRCVMAN: multi_section=N
DBGRCVMAN: key=17 recid=17 stamp=976086085 sparse_backup_con =NO
DBGRCVMAN: compTime=14-MAY-18
DBGRCVMAN: blocks=1 blockSize=8192
DBGRCVMAN: fromSCN=3435417 toSCN=3435627 toTime=14-MAY-18 level=1 section_size=0
DBGRCVMAN: rlgSCN=1490582 rlgTime=25-APR-18 dbincKey=
DBGRCVMAN: afzSCN=0
DBGRCVMAN: pdbKey=1
DBGRCVMAN: dfNumber=7 creationSCN=29665 pluginSCN=0 foreignDbid=0 pluggedRonly=0
DBGRCVMAN: cfType=B
DBGRCVMAN: keep_options=0 keep_until=NULL
DBGRCVMAN: EXITING fetchCursor1RecoveryAction filter accepted
DBGRCVMAN: EXITING openRecoveryActionCursor
DBGRCVMAN: ENTERING fetchRecoveryAction
DBGRCVMAN: ENTERING fetchCursor1RecoveryAction
DBGRCVMAN: fetchCursor1RecoveryAction opcode=1
DBGRCVMAN: fetchCursor1RecoveryAction seekNext
DBGRCVMAN: fetchCursor1RecoveryAction no more records
DBGRCVMAN: EXITING fetchCursor1RecoveryAction seekCurrent - beyond current fno, creSCN
DBGRCVMAN: EXITING fetchRecoveryAction with TRUE
DBGRCVMAN: fetched recovery action
DBGRCVMAN: DUMPING RECOVERY CONTAINER
DBGRCVMAN: Incremental Backup Set
DBGRCVMAN: bsKey=7 bsRecid=7 bsStamp=976086120 setStamp=976086083 setCount=7 site_key=0
DBGRCVMAN: bsLevel=1 bsType=I pieceCount=1
DBGRCVMAN: multi_section=N
DBGRCVMAN: key=17 recid=17 stamp=976086085 sparse_backup_con =NO
DBGRCVMAN: compTime=14-MAY-18
DBGRCVMAN: blocks=1 blockSize=8192
DBGRCVMAN: fromSCN=3435417 toSCN=3435627 toTime=14-MAY-18 level=1 section_size=0
DBGRCVMAN: rlgSCN=1490582 rlgTime=25-APR-18 dbincKey=
DBGRCVMAN: afzSCN=0
DBGRCVMAN: pdbKey=1
DBGRCVMAN: dfNumber=7 creationSCN=29665 pluginSCN=0 foreignDbid=0 pluggedRonly=0
DBGRCVMAN: cfType=B
DBGRCVMAN: keep_options=0 keep_until=NULL
DBGRCVMAN: found an incremental backup set
DBGRCVMAN: ENTERING addAction
DBGRCVMAN: addAction action.type_con=
DBGRCVMAN: ENTERING redoNeeded
DBGRCVMAN: EXITING redoNeeded with: FALSE
DBGRCVMAN: CheckRecAction called 04/25/18 12:33:34; rlgscn=1490582; pdbId=1; cleanscn=0
DBGRCVMAN: CheckRecAction:matches inc=0,fromscn=3435417,toscn=3435627,afzSCN=0
DBGRCVMAN: cacheFindValidBackupSet: setStamp=976086083 setCount=7 tag=NULL deviceType=NULL mask=1
DBGRCVMAN: ENTERING loadBsRecCache
DBGRCVMAN: loadBsRecCache mixcopy=0
DBGRCVMAN: *****BsRecCache Statistics*****
DBGRCVMAN: Cache size=0 hit=0
DBGRCVMAN: loadBsRecCache loadRedundDf_c
DBGRCVMAN: loadBsRecCache tag=NULL deviceType=NULL mask=1
DBGRCVMAN: loadBsRecCache Cache contains 12 records
DBGRCVMAN: loadBsRecCache Minimum SetCount=1
DBGRCVMAN: EXITING loadBsRecCache
DBGRCVMAN: ENTERING validateBackupSet0
DBGRCVMAN: cacheGetValidBackupSet: returning valid rec deviceType=DISK tag=TAG20180514T070122 copyNumber=1
DBGRCVMAN: validateBackupSet0 exiting loop with rc: SUCCESS
DBGRCVMAN: EXITING validateBackupSet0 with rc:0
DBGRCVMAN: DUMPING RECOVERY CONTAINER
DBGRCVMAN: Incremental Backup Set
DBGRCVMAN: bsKey=7 bsRecid=7 bsStamp=976086120 setStamp=976086083 setCount=7 site_key=0
DBGRCVMAN: bsLevel=1 bsType=I pieceCount=1
DBGRCVMAN: multi_section=N
DBGRCVMAN: key=17 recid=17 stamp=976086085 sparse_backup_con =NO
DBGRCVMAN: tag=TAG20180514T070122 compTime=14-MAY-18
DBGRCVMAN: deviceType=DISK blocks=1 blockSize=8192
DBGRCVMAN: fromSCN=3435417 toSCN=3435627 toTime=14-MAY-18 level=1 section_size=0
DBGRCVMAN: rlgSCN=1490582 rlgTime=25-APR-18 dbincKey=
DBGRCVMAN: afzSCN=0
DBGRCVMAN: pdbKey=1
DBGRCVMAN: dfNumber=7 creationSCN=29665 pluginSCN=0 foreignDbid=0 pluggedRonly=0
DBGRCVMAN: cfType=B
DBGRCVMAN: keep_options=0 keep_until=NULL
DBGRCVMAN: rcvRecPush:from_scn=3435417,to_scn=3435627,rcvRecStackCount=1
DBGRCVMAN: addAction Added action:
DBGRCVMAN: addAction allCopies is TRUE, trying to add other copies
DBGRCVMAN: ENTERING validateBackupSet0
DBGRCVMAN: validateBackupSet0 rc is null, setting to unavailable
DBGRCVMAN: EXITING validateBackupSet0 with rc:1
DBGRCVMAN: EXITING addAction with: action_OK
DBGRCVMAN: addAction returned code 0
DBGRCVMAN: done set to true - 3
DBGRCVMAN: EXITING computeRecoveryActions2 - 3
DBGRCVMAN: computeRecoveryActions: Top of stack=1
DBGRCVMAN: EXITING computeRecoveryActions with: SUCCESS
DBGMISC: EXITED krmkcra with status 0 [10:07:52.484] elapsed time [00:00:00:06.814]
DBGRCV: ENTERED krmkgrr
DBGRCV: krmkgrr(funcode=10) (krmkgrr)
DBGRCVMAN: ENTERING getRcvRec
DBGRCVMAN: getRcvRec funCode=10
DBGRCVMAN: ENTERING getRecoveryAction
DBGRCVMAN: rcvRecPop:from_scn=3435417,to_scn=3435627,rcvRecStackCount=1
DBGRCVMAN: EXITING getRecoveryAction with: FALSE#
DBGRCVMAN: DUMPING RECOVERY CONTAINER
DBGRCVMAN: Incremental Backup Set
DBGRCVMAN: bsKey=7 bsRecid=7 bsStamp=976086120 setStamp=976086083 setCount=7 site_key=0
DBGRCVMAN: bsLevel=1 bsType=I pieceCount=1
DBGRCVMAN: multi_section=N
DBGRCVMAN: key=17 recid=17 stamp=976086085 sparse_backup_con =NO
DBGRCVMAN: tag=TAG20180514T070122 compTime=14-MAY-18
DBGRCVMAN: deviceType=DISK blocks=1 blockSize=8192
DBGRCVMAN: fromSCN=3435417 toSCN=3435627 toTime=14-MAY-18 level=1 section_size=0
DBGRCVMAN: rlgSCN=1490582 rlgTime=25-APR-18 dbincKey=
DBGRCVMAN: afzSCN=0
DBGRCVMAN: pdbKey=1
DBGRCVMAN: dfNumber=7 creationSCN=29665 pluginSCN=0 foreignDbid=0 pluggedRonly=0
DBGRCVMAN: cfType=B
DBGRCVMAN: keep_options=0 keep_until=NULL
DBGRCVMAN: EXITING getRcvRec with rc:0
DBGRCV: ENTERED krmrrcvc
DBGRCV: EXITED krmrrcvc
DBGRCV: EXITED krmkgrr with status 0
DBGMISC: EXITED krmkfbs [10:07:54.256] elapsed time [00:00:00:08.618]
DBGRESTORE: EXITED krmrrcv_dfile
DBGRCV: ENTERED krmkbbsbp
DBGSQL: TARGET> begin dbms_rcvman.translateBackupPieceBsKey( startBskey => :bsKey, tag => :tag, statusMask => :statusMask); end;
DBGSQL: sqlcode = 0
DBGSQL: B :bsKey = 7
DBGSQL: B :tag = NULL
DBGSQL: B :statusMask = 1
DBGRCVMAN: ENTERING computeAvailableMask
DBGRCVMAN: EXITING computeAvailableMask with rc:1
DBGSQL: TARGET> begin dbms_rcvman.translateSeekBpBsKey( bsKey => :bsKey, pieceCount => :pieceCount, duplicates => :duplicates, deviceType => :deviceType, copyNumber => :copyNumber); end;
DBGSQL: sqlcode = 0
DBGSQL: B :bsKey = 7
DBGSQL: B :pieceCount = 1
DBGSQL: B :duplicates = 0
DBGSQL: B :deviceType = DISK
DBGSQL: B :copyNumber = 1
DBGRCVMAN: ENTERING translateSeekBpBsKey
DBGRCVMAN: translateSeekBpBsKey bskey=7
DBGRCVMAN: EXITING translateSeekBpBsKey got key=7
DBGRCV: ENTERED krmkgtbp
DBGRCVMAN: ENTERING getBackupPiece
DBGRCVMAN: bskey = 7
DBGRCVMAN: next bskey=8
DBGRCVMAN: EXITING getBackupPiece
DBGSQL: ocirc = 0 (krmkgtbp)
DBGRCVMAN: ENTERING getBackupPiece
DBGRCVMAN: bskey = 8
DBGRCVMAN: end of backupset
DBGRCVMAN: EXITING getBackupPiece no more records
DBGRCV: EXITED krmkgtbp
DBGSQL: TARGET> begin dbms_rcvman.translateBpBsKeyCancel; end;
DBGSQL: sqlcode = 0
DBGRCV: EXITED krmkbbsbp
DBGRCV: EXITED krmrrcv with address 53622976
DBGMISC: krmkibap: the incremental backup source tree is: [10:07:55.852]
DBGMISC: 1 BS (incremental datafile) key=7 recid=7 stamp=976086120 setstamp=976086083 setcount=7
DBGMISC: level=1 level_i=0 piececount=1 keepopts=0, site_key=0 [10:07:55.918]
DBGMISC: site_key=0 [10:07:55.941]
DBGMISC: chid=NIL parm=NIL [10:07:55.976]
DBGMISC: flags=<has site key> [10:07:56.001]
DBGMISC: valid backup set list is [10:07:56.034]
DBGMISC: 1 VBS copy#=1 tag=TAG20180514T070122 deviceType=DISK status=A
DBGMISC: 1 BPIECEX key=7 recid=7 stamp=976086084
DBGMISC: bskey=7 vbkey=0 set_stamp=976086083 set_count=7 site_key=0
DBGMISC: pieceno=1 handle=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\07T2RP23_1_1 ba_access=U
DBGMISC: device=DISK krmkch { count=0 found=FALSE }
DBGMISC: restore target list is [10:07:56.217]
DBGMISC: 1 ACT type=incremental fromSCN=3435417 toSCN=3435627 fno=7
DBGMISC: DF fno=7 pplfno=0 pdbid=1 pdbname= crescn=29665
DBGMISC: blksize=8192 blocks=640 rfno=7 pdbForeignDbid=0
DBGMISC: fn=D:\APP\BGRENN\VIRTUAL\ORADATA\ORCL\USERS01.DBF
DBGMISC: ts=USERS, flags=KRMKDF_INBACKUP
DBGMISC: fedata: sta=0x0e crescn=29665
DBGMISC: fhdata: ckpscn=3435627 rlgscn=1490582
DBGRESTORE: ENTERED krmkrstp
DBGRESTORE: ENTERED krmkgdn
DBGRESTORE: Looking up newname for 7 (krmkgdn)
DBGRCV: ENTERED krmklknn
DBGRCV: Looking for newname for datafile: 7, Translate: 1, dosearch=1 (krmklknn)
DBGRCV: Looking up in unprocessed newname list, need_dfinfo=0 (krmklknn)
DBGRCV: ENTERED krmksearchnewname
DBGRCV: EXITED krmksearchnewname with address 0
DBGRCV: No newname found for datafile 7 (krmklknn)
DBGRCV: EXITED krmklknn with address 0
DBGRESTORE: Restoring datafile 7 to filename in controlfile: D:\APP\BGRENN\VIRTUAL\ORADATA\ORCL\USERS01.DBF (krmkgdn)
DBGRESTORE: EXITED krmkgdn with status D:\APP\BGRENN\VIRTUAL\ORADATA\ORCL\USERS01.DBF
DBGRESTORE: ENTERED krmkgbp
DBGRESTORE: EXITED krmkgbp
DBGRESTORE: EXITED krmkrstp
DBGRCV: EXITED krmkibap with address 53624008
DBGMISC: EXITED krmkomp [10:07:57.652] elapsed time [00:00:00:14.968]
DBGPLSQL: the compiled command tree is: [10:07:57.689] (krmicomp)
DBGPLSQL: 1 CMD type=incremental backup restore cmdid=1 status=NOT STARTED
DBGPLSQL: 1 STEPstepid=1 cmdid=1 status=NOT STARTED devtype=DISK bs.stamp=976086120 step_size=0 Bytes
DBGPLSQL: 1 TEXTNOD = --
DBGPLSQL: 2 TEXTNOD = declare
DBGPLSQL: 3 TEXTNOD = /* restoreStatus */
DBGPLSQL: 4 TEXTNOD = state binary_integer;
DBGPLSQL: 5 TEXTNOD = pieces_done binary_integer;
DBGPLSQL: 6 TEXTNOD = files binary_integer;
DBGPLSQL: 7 TEXTNOD = datafiles boolean;
DBGPLSQL: 8 TEXTNOD = incremental boolean;
DBGPLSQL: 9 TEXTNOD = device boolean;
DBGPLSQL: 10 TEXTNOD = /* restorebackuppiece */
DBGPLSQL: 11 TEXTNOD = done boolean;
DBGPLSQL: 12 TEXTNOD = currcf boolean;
DBGPLSQL: 13 TEXTNOD = fhandle varchar2(512);
DBGPLSQL: 14 TEXTNOD = handle varchar2(512);
DBGPLSQL: 15 TEXTNOD = outhandle varchar2(512);
DBGPLSQL: 16 TEXTNOD = params varchar2(512);
DBGPLSQL: 17 TEXTNOD = fromdisk boolean; -- TRUE => backupset on disk
DBGPLSQL: 18 TEXTNOD = /* Miscellaneous */
DBGPLSQL: 19 TEXTNOD = memnum number;
DBGPLSQL: 20 TEXTNOD = piecenum number;
DBGPLSQL: 21 TEXTNOD = dfnumber number;
DBGPLSQL: 22 TEXTNOD = thread number := null;
DBGPLSQL: 23 TEXTNOD = sequence number := null;
DBGPLSQL: 24 TEXTNOD = toname varchar2(512);
DBGPLSQL: 25 TEXTNOD = cfname varchar2(512);
DBGPLSQL: 26 TEXTNOD = fuzzy_hint number;
DBGPLSQL: 27 TEXTNOD = set_count number;
DBGPLSQL: 28 TEXTNOD = set_stamp number;
DBGPLSQL: 29 TEXTNOD = first_time boolean := TRUE;
DBGPLSQL: 30 TEXTNOD = validate boolean := FALSE;
DBGPLSQL: 31 TEXTNOD = val_bs_only boolean := FALSE; -- TRUE => only bs validation
DBGPLSQL: 32 TEXTNOD = --
DBGPLSQL: 33 TEXTNOD = max_corrupt binary_integer := 0;
DBGPLSQL: 34 TEXTNOD = check_logical boolean := FALSE;
DBGPLSQL: 35 TEXTNOD = tag varchar2(31);
DBGPLSQL: 36 TEXTNOD = outtag varchar2(31);
DBGPLSQL: 37 TEXTNOD = bmr boolean := FALSE;
DBGPLSQL: 38 TEXTNOD = blocks number;
DBGPLSQL: 39 TEXTNOD = blksize number;
DBGPLSQL: 40 TEXTNOD = failover boolean := FALSE;
DBGPLSQL: 41 TEXTNOD = devtype varchar2(512);
DBGPLSQL: 42 TEXTNOD = rcvcopy boolean := FALSE;
DBGPLSQL: 43 TEXTNOD = islevel0 binary_integer := 0;
DBGPLSQL: 44 TEXTNOD = rsid number;
DBGPLSQL: 45 TEXTNOD = rsts number;
DBGPLSQL: 46 TEXTNOD = err_msg varchar2(2048);
DBGPLSQL: 47 TEXTNOD = start_time date;
DBGPLSQL: 48 TEXTNOD = recid number;
DBGPLSQL: 49 TEXTNOD = stamp number;
DBGPLSQL: 50 TEXTNOD = preview boolean := FALSE;
DBGPLSQL: 51 TEXTNOD = recall boolean := FALSE;
DBGPLSQL: 52 TEXTNOD = isstby boolean := FALSE;
DBGPLSQL: 53 TEXTNOD = nocfconv boolean := FALSE;
DBGPLSQL: 54 TEXTNOD = msrpno number := 0;
DBGPLSQL: 55 TEXTNOD = msrpct number := 0;
DBGPLSQL: 56 TEXTNOD = isfarsync boolean := FALSE;
DBGPLSQL: 57 TEXTNOD = preplugin boolean := FALSE;
DBGPLSQL: 58 TEXTNOD = pdbid number := 0;
DBGPLSQL: 59 TEXTNOD = pplcdbdbid number := 0;
DBGPLSQL: 60 TEXTNOD = ppltrans number;
DBGPLSQL: 61 TEXTNOD = old_dfnumber number;
DBGPLSQL: 62 TEXTNOD = restore_not_complete exception;
DBGPLSQL: 63 TEXTNOD =
DBGPLSQL: 64 TEXTNOD = begin
DBGPLSQL: 65 TEXTNOD =
DBGPLSQL: 66 PRMVAL = set_count := 7; set_stamp := 976086083; rsid := 53; rsts := 976097261; params := null; isstby := false; isfarsync := false; nocfconv := true;
DBGPLSQL: 67 TEXTNOD =
DBGPLSQL: 68 TEXTNOD = --
DBGPLSQL: 69 TEXTNOD = if preview then
DBGPLSQL: 70 TEXTNOD = deb('ridf_start', 'preview');
DBGPLSQL: 71 TEXTNOD = return;
DBGPLSQL: 72 TEXTNOD = end if;
DBGPLSQL: 73 TEXTNOD =
DBGPLSQL: 74 TEXTNOD = sys.dbms_backup_restore.restoreStatus(state, pieces_done, files, datafiles,
DBGPLSQL: 75 TEXTNOD = incremental, device);
DBGPLSQL: 76 TEXTNOD = if (msrpno > 1) then
DBGPLSQL: 77 TEXTNOD = --
DBGPLSQL: 78 TEXTNOD = --
DBGPLSQL: 79 TEXTNOD = --
DBGPLSQL: 80 TEXTNOD = --
DBGPLSQL: 81 TEXTNOD = pieces_done := msrpno - 1;
DBGPLSQL: 82 TEXTNOD = end if;
DBGPLSQL: 83 TEXTNOD =
DBGPLSQL: 84 TEXTNOD = select sysdate into start_time from x$dual;
DBGPLSQL: 85 TEXTNOD = if state = sys.dbms_backup_restore.restore_no_conversation then
DBGPLSQL: 86 TEXTNOD = goto start_convo;
DBGPLSQL: 87 TEXTNOD = elsif state = sys.dbms_backup_restore.restore_naming_files then
DBGPLSQL: 88 TEXTNOD = goto name_files;
DBGPLSQL: 89 TEXTNOD = else
DBGPLSQL: 90 TEXTNOD = goto restore_piece;
DBGPLSQL: 91 TEXTNOD = end if;
DBGPLSQL: 92 TEXTNOD =
DBGPLSQL: 93 TEXTNOD = <<start_convo>>
DBGPLSQL: 94 TEXTNOD = sys.dbms_backup_restore.setRmanStatusRowId(rsid=>rsid, rsts=>rsts);
DBGPLSQL: 95 TEXTNOD = sys.dbms_backup_restore.applySetDatafile(
DBGPLSQL: 96 TEXTNOD = check_logical => check_logical
DBGPLSQL: 97 TEXTNOD = ,cleanup => FALSE
DBGPLSQL: 98 TEXTNOD = ,service => NULL
DBGPLSQL: 99 TEXTNOD = ,chunksize => 0
DBGPLSQL: 100 TEXTNOD = ,rs_flags => 0
DBGPLSQL: 101 TEXTNOD = ,preplugin => preplugin);
DBGPLSQL: 102 TEXTNOD = incremental := TRUE;
DBGPLSQL: 103 TEXTNOD = krmicd.writeMsg(8039, krmicd.getChid);
DBGPLSQL: 104 TEXTNOD =
DBGPLSQL: 105 TEXTNOD = setRestoreParams;
DBGPLSQL: 106 TEXTNOD = <<name_files>>
DBGPLSQL: 107 TEXTNOD = deb('ridf_start', 'set_stamp=' || set_stamp || ' set_count=' || set_count,
DBGPLSQL: 108 TEXTNOD = rman_constant.DEBUG_IO, rman_constant.LEVEL_MIN);
DBGPLSQL: 109 TEXTNOD = --
DBGPLSQL: 110 TEXTNOD = toname := null;
DBGPLSQL: 111 TEXTNOD = max_corrupt := 0;
DBGPLSQL: 112 TEXTNOD =
DBGPLSQL: 113 PRMVAL = memnum := 1;
DBGPLSQL: 114 TEXTNOD =
DBGPLSQL: 115 PRMVAL = fuzzy_hint := 0; islevel0 := 0; recid := 0; stamp := 0; dfnumber := 7; old_dfnumber := 7; toname := 'D:\APP\BGRENN\VIRTUAL\ORADATA\ORCL\USERS01.DBF'; blocks := 640; blksize := 8192;
DBGPLSQL: 116 TEXTNOD = if msrpno > 1 and not bmr then
DBGPLSQL: 117 TEXTNOD = declare
DBGPLSQL: 118 TEXTNOD = tempfno number;
DBGPLSQL: 119 TEXTNOD = begin
DBGPLSQL: 120 TEXTNOD = krmicd.getMSR(tempfno, toname);
DBGPLSQL: 121 TEXTNOD = end;
DBGPLSQL: 122 TEXTNOD = end if;
DBGPLSQL: 123 TEXTNOD = if files < memnum then
DBGPLSQL: 124 TEXTNOD = sys.dbms_backup_restore.applyDataFileTo(
DBGPLSQL: 125 TEXTNOD = dfnumber => dfnumber,
DBGPLSQL: 126 TEXTNOD = toname => toname,
DBGPLSQL: 127 TEXTNOD = fuzziness_hint => fuzzy_hint,
DBGPLSQL: 128 TEXTNOD = max_corrupt => max_corrupt,
DBGPLSQL: 129 TEXTNOD = islevel0 => islevel0,
DBGPLSQL: 130 TEXTNOD = recid => recid,
DBGPLSQL: 131 TEXTNOD = stamp => stamp,
DBGPLSQL: 132 TEXTNOD = old_dfnumber => old_dfnumber);
DBGPLSQL: 133 TEXTNOD =
DBGPLSQL: 134 TEXTNOD = if msrpno = 1 and not bmr then
DBGPLSQL: 135 TEXTNOD = sys.dbms_backup_restore.initMSR(dfnumber, toname);
DBGPLSQL: 136 TEXTNOD = end if;
DBGPLSQL: 137 TEXTNOD =
DBGPLSQL: 138 TEXTNOD = if msrpno > 0 then
DBGPLSQL: 139 TEXTNOD = krmicd.setMSR(dfnumber, toname);
DBGPLSQL: 140 TEXTNOD = end if;
DBGPLSQL: 141 TEXTNOD =
DBGPLSQL: 142 TEXTNOD = if first_time then
DBGPLSQL: 143 TEXTNOD = if bmr then
DBGPLSQL: 144 TEXTNOD = krmicd.writeMsg(8108, krmicd.getChid);
DBGPLSQL: 145 TEXTNOD = elsif rcvcopy then
DBGPLSQL: 146 TEXTNOD = krmicd.writeMsg(8131, krmicd.getChid);
DBGPLSQL: 147 TEXTNOD = else
DBGPLSQL: 148 TEXTNOD = krmicd.writeMsg(8089, krmicd.getChid);
DBGPLSQL: 149 TEXTNOD = end if;
DBGPLSQL: 150 TEXTNOD = first_time := FALSE;
DBGPLSQL: 151 TEXTNOD = end if;
DBGPLSQL: 152 TEXTNOD =
DBGPLSQL: 153 TEXTNOD = if bmr then
DBGPLSQL: 154 TEXTNOD = krmicd.writeMsg(8533, to_char(dfnumber, 'FM09999'));
DBGPLSQL: 155 TEXTNOD = elsif toname is not null then
DBGPLSQL: 156 TEXTNOD = if rcvcopy then
DBGPLSQL: 157 TEXTNOD = krmicd.writeMsg(8551, to_char(dfnumber, 'FM09999'), toname);
DBGPLSQL: 158 TEXTNOD = else
DBGPLSQL: 159 TEXTNOD = krmicd.writeMsg(8509, to_char(dfnumber, 'FM09999'), toname);
DBGPLSQL: 160 TEXTNOD = end if;
DBGPLSQL: 161 TEXTNOD = deb('ridf_name', 'blocks=' || blocks || ' block_size=' || blksize,
DBGPLSQL: 162 TEXTNOD = rman_constant.DEBUG_IO, rman_constant.LEVEL_MIN);
DBGPLSQL: 163 TEXTNOD = end if;
DBGPLSQL: 164 TEXTNOD = if (msrpno > 0) then
DBGPLSQL: 165 TEXTNOD = krmicd.writeMsg(8555, krmicd.getChid, to_char(msrpno), to_char(msrpct));
DBGPLSQL: 166 TEXTNOD = end if;
DBGPLSQL: 167 TEXTNOD = end if;
DBGPLSQL: 168 TEXTNOD = --
DBGPLSQL: 169 TEXTNOD = <<restore_piece>>
DBGPLSQL: 170 TEXTNOD = --
DBGPLSQL: 171 TEXTNOD = fhandle := NULL;
DBGPLSQL: 172 TEXTNOD =
DBGPLSQL: 173 PRMVAL = piecenum := 1;
DBGPLSQL: 174 TEXTNOD = --
DBGPLSQL: 175 TEXTNOD =
DBGPLSQL: 176 PRMVAL = handle := 'D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\07T2RP23_1_1'; fromdisk := true; recid := 7; stamp := 976086084; tag := 'TAG20180514T070122';
DBGPLSQL: 177 TEXTNOD = -- handle, tag, fromdisk, recid, stamp
DBGPLSQL: 178 TEXTNOD = if (pieces_done+1) = piecenum then
DBGPLSQL: 179 TEXTNOD = sys.dbms_backup_restore.restoreSetPiece(handle => handle,
DBGPLSQL: 180 TEXTNOD = tag => tag,
DBGPLSQL: 181 TEXTNOD = fromdisk => fromdisk,
DBGPLSQL: 182 TEXTNOD = recid => recid,
DBGPLSQL: 183 TEXTNOD = stamp => stamp);
DBGPLSQL: 184 TEXTNOD = if fhandle is NULL then
DBGPLSQL: 185 TEXTNOD = fhandle := handle;
DBGPLSQL: 186 TEXTNOD = end if;
DBGPLSQL: 187 TEXTNOD = end if;
DBGPLSQL: 188 TEXTNOD = if (restore_piece_int(pieces_done, piecenum, fhandle, done, params,
DBGPLSQL: 189 TEXTNOD = outhandle, outtag, failover, err_msg, val_bs_only, validate,
DBGPLSQL: 190 TEXTNOD = devtype, bmr, set_stamp, set_count, start_time, incremental,
DBGPLSQL: 191 TEXTNOD = currcf, ppltrans)) then
DBGPLSQL: 192 TEXTNOD = goto restore_failover;
DBGPLSQL: 193 TEXTNOD = end if;
DBGPLSQL: 194 TEXTNOD =
DBGPLSQL: 195 TEXTNOD = if done then
DBGPLSQL: 196 TEXTNOD = return;
DBGPLSQL: 197 TEXTNOD = end if;
DBGPLSQL: 198 TEXTNOD = --
DBGPLSQL: 199 TEXTNOD = krmicd.writeMsg(8001);
DBGPLSQL: 200 TEXTNOD =
DBGPLSQL: 201 TEXTNOD = if not krmicd.doRestoreFailover(rman_constant.BACKUPPIECE) then
DBGPLSQL: 202 TEXTNOD = begin
DBGPLSQL: 203 TEXTNOD = sys.dbms_backup_restore.restoreCancel(FALSE);
DBGPLSQL: 204 TEXTNOD = exception
DBGPLSQL: 205 TEXTNOD = when others then
DBGPLSQL: 206 TEXTNOD = krmicd.writeMsg(1005,
DBGPLSQL: 207 TEXTNOD = 'a. dbms_backup_restore.restoreCancel() failed');
DBGPLSQL: 208 TEXTNOD = end;
DBGPLSQL: 209 TEXTNOD =
DBGPLSQL: 210 TEXTNOD = if (ppltrans > 0) then
DBGPLSQL: 211 TEXTNOD = sys.dbms_backup_restore.endPrePluginTranslation;
DBGPLSQL: 212 TEXTNOD = end if;
DBGPLSQL: 213 TEXTNOD = raise restore_not_complete;
DBGPLSQL: 214 TEXTNOD = end if;
DBGPLSQL: 215 TEXTNOD =
DBGPLSQL: 216 TEXTNOD = --
DBGPLSQL: 217 TEXTNOD = --
DBGPLSQL: 218 TEXTNOD = --
DBGPLSQL: 219 TEXTNOD = --
DBGPLSQL: 220 TEXTNOD = if (not validate) then
DBGPLSQL: 221 TEXTNOD = getFileRestored(FALSE);
DBGPLSQL: 222 TEXTNOD = end if;
DBGPLSQL: 223 TEXTNOD =
DBGPLSQL: 224 TEXTNOD = devtype := krmicd.checkBsFailover;
DBGPLSQL: 225 TEXTNOD =
DBGPLSQL: 226 TEXTNOD = if (incremental and devtype is null) then
DBGPLSQL: 227 TEXTNOD = begin
DBGPLSQL: 228 TEXTNOD = sys.dbms_backup_restore.restoreCancel(TRUE);
DBGPLSQL: 229 TEXTNOD = exception
DBGPLSQL: 230 TEXTNOD = when others then
DBGPLSQL: 231 TEXTNOD = krmicd.writeMsg(1005,
DBGPLSQL: 232 TEXTNOD = 'b. dbms_backup_restore.restoreCancel() failed');
DBGPLSQL: 233 TEXTNOD = end;
DBGPLSQL: 234 TEXTNOD =
DBGPLSQL: 235 TEXTNOD = if (ppltrans > 0) then
DBGPLSQL: 236 TEXTNOD = sys.dbms_backup_restore.endPrePluginTranslation;
DBGPLSQL: 237 TEXTNOD = end if;
DBGPLSQL: 238 TEXTNOD = end if;
DBGPLSQL: 239 TEXTNOD =
DBGPLSQL: 240 TEXTNOD = if (dfnumber is not null) then
DBGPLSQL: 241 TEXTNOD = krmicd.writeMsg(1005, 'Restore did not complete for some' ||
DBGPLSQL: 242 TEXTNOD = ' files from backup piece ' ||
DBGPLSQL: 243 TEXTNOD = outhandle || ' (piecenum=' || to_char(piecenum) ||
DBGPLSQL: 244 TEXTNOD = ', pieces_done=' || to_char(pieces_done) ||
DBGPLSQL: 245 TEXTNOD = ', done=' || bool2char(done) ||
DBGPLSQL: 246 TEXTNOD = ', failover=' || bool2char(failover) || ')');
DBGPLSQL: 247 TEXTNOD = else
DBGPLSQL: 248 TEXTNOD = krmicd.writeMsg(1005, 'Restore did not complete for some' ||
DBGPLSQL: 249 TEXTNOD = ' archived logs from backup piece ' || outhandle ||
DBGPLSQL: 250 TEXTNOD = ' (piecenum=' || to_char(piecenum) ||
DBGPLSQL: 251 TEXTNOD = ', pieces_done=' || to_char(pieces_done) ||
DBGPLSQL: 252 TEXTNOD = ', done=' || bool2char(done) ||
DBGPLSQL: 253 TEXTNOD = ', failover=' || bool2char(failover) || ')');
DBGPLSQL: 254 TEXTNOD = end if;
DBGPLSQL: 255 TEXTNOD =
DBGPLSQL: 256 TEXTNOD = krmicd.writeMsg(1005, 'Please check alert log for ' ||
DBGPLSQL: 257 TEXTNOD = 'additional information.');
DBGPLSQL: 258 TEXTNOD =
DBGPLSQL: 259 TEXTNOD = if (devtype is not null) then
DBGPLSQL: 260 TEXTNOD = krmicd.writeMsg(8612, krmicd.getChid, devtype);
DBGPLSQL: 261 TEXTNOD = end if;
DBGPLSQL: 262 TEXTNOD =
DBGPLSQL: 263 TEXTNOD = --
DBGPLSQL: 264 TEXTNOD = <<restore_failover>>
DBGPLSQL: 265 TEXTNOD = begin
DBGPLSQL: 266 TEXTNOD = sys.dbms_backup_restore.restoreCancel(FALSE);
DBGPLSQL: 267 TEXTNOD = exception
DBGPLSQL: 268 TEXTNOD = when others then
DBGPLSQL: 269 TEXTNOD = krmicd.writeMsg(1005,
DBGPLSQL: 270 TEXTNOD = 'c. dbms_backup_restore.restoreCancel() failed');
DBGPLSQL: 271 TEXTNOD = end;
DBGPLSQL: 272 TEXTNOD =
DBGPLSQL: 273 TEXTNOD = if (ppltrans > 0) then
DBGPLSQL: 274 TEXTNOD = sys.dbms_backup_restore.endPrePluginTranslation;
DBGPLSQL: 275 TEXTNOD = end if;
DBGPLSQL: 276 TEXTNOD =
DBGPLSQL: 277 TEXTNOD = sys.dbms_backup_restore.setRmanStatusRowId(rsid=>0, rsts=>0);
DBGPLSQL: 278 TEXTNOD = end;
DBGMISC: EXITED krmicomp with address 53624008 [10:08:11.848] elapsed time [00:00:00:29.192]
DBGMISC: ENTERED krmiexe [10:08:11.876]
DBGMISC: Executing command incremental backup restore [10:08:11.995] (krmiexe)
DBGRPC: krmxr - entering
DBGRPC: krmxpoq - returning rpc_number: 14 with status: FINISHED129 for channel default
DBGRPC: krmxr - channel default has rpc_count: 14
DBGRPC: krmxpoq - returning rpc_number: 27 with status: FINISHED129 for channel ORA_DISK_1
DBGRPC: krmxr - channel ORA_DISK_1 has rpc_count: 27
DBGRPC: ENTERED krmqgns
DBGRPC: krmqgns: looking for work for channel default (krmqgns)
DBGRPC: krmqgns: commands remaining to be executed: (krmqgns)
DBGRPC: CMD type=incremental backup restore cmdid=1 status=NOT STARTED
DBGRPC: 1 STEPstepid=1 cmdid=1 status=NOT STARTED devtype=DISK bs.stamp=976086120 step_size=0 Bytes
DBGRPC: krmqgns: no work found for channel default (krmqgns)
DBGRPC: (krmqgns)
DBGRPC: EXITED krmqgns with status 1
DBGRPC: ENTERED krmqgns
DBGRPC: krmqgns: looking for work for channel ORA_DISK_1 (krmqgns)
DBGRPC: krmqgns: commands remaining to be executed: (krmqgns)
DBGRPC: CMD type=incremental backup restore cmdid=1 status=NOT STARTED
DBGRPC: 1 STEPstepid=1 cmdid=1 status=NOT STARTED devtype=DISK bs.stamp=976086120 step_size=0 Bytes
DBGRPC: krmqgns: channel ORA_DISK_1 assigned step 1 (krmqgns)
DBGRPC: (krmqgns)
DBGRPC: EXITED krmqgns with status 0
DBGRPC: krmxcis - channel ORA_DISK_1, calling pcicmp
DBGRPC: krmxr - channel ORA_DISK_1 calling peicnt
DBGRPC: krmxrpc - channel ORA_DISK_1 kpurpc2 err=0 db=target proc=SYS.DBMS_BACKUP_RESTORE.RESTORESTATUS excl: 0
DBGRPC: krmxrpc - channel ORA_DISK_1 kpurpc2 err=0 db=target proc=SYS.DBMS_BACKUP_RESTORE.SETRMANSTATUSROWID excl: 0
DBGRPC: krmxrpc - channel ORA_DISK_1 kpurpc2 err=0 db=target proc=SYS.DBMS_BACKUP_RESTORE.APPLYSETDATAFILE excl: 0
DBGMISC: ENTERED krmzlog [10:08:12.863]
RMAN-08039: channel ORA_DISK_1: starting incremental datafile backup set restore
DBGMISC: EXITED krmzlog [10:08:12.957] elapsed time [00:00:00:00.094]
DBGMISC: ENTERED krmzgparms [10:08:12.979]
DBGMISC: Step id = 1; Code = 2 [10:08:13.102] (krmzgparms)
DBGMISC: EXITED krmzgparms with status 0 (FALSE) [10:08:13.145] elapsed time [00:00:00:00.166]
DBGIO: channel ORA_DISK_1: set_stamp=976086083 set_count=7 [10:08:13.181] (ridf_start)
DBGRPC: krmxrpc - channel ORA_DISK_1 kpurpc2 err=0 db=target proc=SYS.DBMS_BACKUP_RESTORE.APPLYDATAFILETO excl: 0
DBGMISC: ENTERED krmzlog [10:08:13.270]
RMAN-08089: channel ORA_DISK_1: specifying datafile(s) to restore from backup set
DBGMISC: EXITED krmzlog [10:08:13.356] elapsed time [00:00:00:00.086]
DBGMISC: ENTERED krmzlog [10:08:13.378]
RMAN-08509: destination for restore of datafile 00007: D:\APP\BGRENN\VIRTUAL\ORADATA\ORCL\USERS01.DBF
DBGMISC: EXITED krmzlog [10:08:13.456] elapsed time [00:00:00:00.078]
DBGIO: channel ORA_DISK_1: blocks=640 block_size=8192 [10:08:13.477] (ridf_name)
DBGRPC: krmxrpc - channel ORA_DISK_1 kpurpc2 err=0 db=target proc=SYS.DBMS_BACKUP_RESTORE.RESTORESETPIECE excl: 0
DBGMISC: ENTERED krmzlog [10:08:13.571]
RMAN-08003: channel ORA_DISK_1: reading from backup piece D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\07T2RP23_1_1
DBGMISC: EXITED krmzlog [10:08:13.680] elapsed time [00:00:00:00.109]
DBGRPC: krmxrpc - channel ORA_DISK_1 kpurpc2 err=3123 db=target proc=SYS.DBMS_BACKUP_RESTORE.RESTOREBACKUPPIECE excl: 0
DBGRPC: krmxr - channel ORA_DISK_1 returned from peicnt
DBGRPC: krmxpoq - returning rpc_number: 33 with status: STARTED40 for channel ORA_DISK_1
DBGRPC: ENTERED krmqgns
DBGRPC: krmqgns: looking for work for channel default (krmqgns)
DBGRPC: krmqgns: commands remaining to be executed: (krmqgns)
DBGRPC: CMD type=incremental backup restore cmdid=1 status=STARTED
DBGRPC: 1 STEPstepid=1 cmdid=1 status=STARTED devtype=DISK bs.stamp=976086120 step_size=0 Bytes
DBGRPC: krmqgns: no work found for channel default (krmqgns)
DBGRPC: (krmqgns)
DBGRPC: EXITED krmqgns with status 1
DBGRPC: krmxpoq - returning rpc_number: 33 with status: FINISHED40 for channel ORA_DISK_1
DBGRPC: krmxr - channel ORA_DISK_1 calling peicnt
DBGRPC: krmxrpc - channel ORA_DISK_1 kpurpc2 err=0 db=target proc=SYS.DBMS_BACKUP_RESTORE.RESTOREBACKUPPIECE excl: 0
DBGMISC: ENTERED krmzlog [10:08:14.452]
RMAN-08611: channel ORA_DISK_1: piece handle=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\07T2RP23_1_1 tag=TAG20180514T070122
DBGMISC: EXITED krmzlog [10:08:14.527] elapsed time [00:00:00:00.075]
DBGMISC: ENTERED krmzlog [10:08:14.560]
RMAN-08023: channel ORA_DISK_1: restored backup piece 1
DBGMISC: EXITED krmzlog [10:08:14.677] elapsed time [00:00:00:00.117]
DBGIO: Type %Comp Blocks Tot Blocks Blksize ElpTime(s) IO Rt(b/s) Name [10:08:14.710] (krmkqio)
DBGIO: ---- ----- ---------- ---------- ---------- ---------- ---------- ----- [10:08:14.732] (krmkqio)
DBGIO: IN 127 8192 0 0 D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\DATABASE\07T2RP23_1_1 [10:08:14.759] (krmkqio)
DBGIO: AGG 0 8192 0 0 [10:08:14.790] (krmkqio)
DBGMISC: ENTERED krmzlog [10:08:14.818]
RMAN-08180: channel ORA_DISK_1: restore complete, elapsed time: 00:00:02
DBGMISC: EXITED krmzlog [10:08:14.893] elapsed time [00:00:00:00.075]
DBGRPC: krmxrpc - channel ORA_DISK_1 kpurpc2 err=0 db=target proc=SYS.DBMS_BACKUP_RESTORE.FETCHFILERESTORED excl: 0
DBGRPC: krmxrpc - channel ORA_DISK_1 kpurpc2 err=0 db=target proc=SYS.DBMS_BACKUP_RESTORE.FETCHFILERESTORED excl: 0
DBGRPC: krmxrpc - channel ORA_DISK_1 kpurpc2 err=0 db=target proc=SYS.DBMS_BACKUP_RESTORE.RESTORECANCEL excl: 0
DBGRPC: krmxr - channel ORA_DISK_1 returned from peicnt
DBGRPC: krmxr - channel ORA_DISK_1 finished step
DBGRPC: ENTERED krmqgns
krmqgns: looking for work for channel default (krmqgns)
DBGRPC: krmqgns: commands remaining to be executed: (krmqgns)
DBGRPC: CMD type=incremental backup restore cmdid=1 status=STARTED
DBGRPC: 1 STEPstepid=1 cmdid=1 status=FINISHED devtype=DISK bs.stamp=976086120 step_size=0 Bytes
DBGRPC: krmqgns: no work found for channel default (krmqgns)
DBGRPC: (krmqgns)
DBGRPC: EXITED krmqgns with status 1
DBGRPC: ENTERED krmqgns
DBGRPC: krmqgns: channel ORA_DISK_1 finished step 1 (krmqgns)
DBGRPC: krmqgns: looking for work for channel ORA_DISK_1 (krmqgns)
DBGRPC: krmqgns: commands remaining to be executed: (krmqgns)
DBGRPC: krmqgns: no work found for channel ORA_DISK_1 (krmqgns)
DBGRPC: (krmqgns)
DBGRPC: EXITED krmqgns with status 1
DBGRPC: ENTERED krmqgns
DBGRPC: krmqgns: looking for work for channel default (krmqgns)
DBGRPC: krmqgns: commands remaining to be executed: (krmqgns)
DBGRPC: krmqgns: no work found for channel default (krmqgns)
DBGRPC: (krmqgns)
DBGRPC: EXITED krmqgns with status 1
DBGRPC: ENTERED krmqgns
DBGRPC: krmqgns: looking for work for channel ORA_DISK_1 (krmqgns)
DBGRPC: krmqgns: commands remaining to be executed: (krmqgns)
DBGRPC: krmqgns: no work found for channel ORA_DISK_1 (krmqgns)
DBGRPC: (krmqgns)
DBGRPC: EXITED krmqgns with status 1
DBGRPC: krmxr - all done
DBGRPC: krmxr - exiting with 0
DBGMISC: EXITED krmiexe with status 0 [10:08:16.147] elapsed time [00:00:00:04.271]
DBGMISC: Finished incremental backup restore at 14-MAY-18 [10:08:16.169]
DBGMISC: ENTERED krmkmrsr [10:08:16.196]
DBGSQL: ENTERED krmkosqlerr
DBGSQL: TARGET> select /*+ rule */ round(sum(MBYTES_PROCESSED)), round(sum(INPUT_BYTES)), round(sum(OUTPUT_BYTES)) from V$RMAN_STATUS START WITH RECID = :row_id and STAMP = :row_stamp CONNECT BY PRIOR RECID = parent_recid
DBGSQL: sqlcode = 24347
DBGSQL: B :row_id = 53
DBGSQL: B :row_stamp = 976097261
DBGSQL: success: ORA-24347: Warning of a NULL column in an aggregate function (krmkosqlerr)
DBGSQL: (krmkosqlerr)
DBGSQL: EXITED krmkosqlerr
DBGSQL: ENTERED krmkgodevtype
DBGMISC: krmkgodevtype: return device type [10:08:16.641]
DBGSQL: EXITED krmkgodevtype
DBGSQL: TARGET> begin sys.dbms_backup_restore.commitRmanStatusRow( row_id => :row_id, row_stamp => :row_stamp, mbytes => :mb, status => :status, ibytes => :ib, obytes => :ob, odevtype => :odevtype); end;
DBGSQL: sqlcode = 0
DBGSQL: B :row_id = 53
DBGSQL: B :row_stamp = 976097261
DBGSQL: B :mb = 0
DBGSQL: B :status = 2
DBGSQL: B :ib = 1040384
DBGSQL: B :ob = 0
DBGSQL: B :odevtype =
DBGMISC: EXITED krmkmrsr [10:08:17.225] elapsed time [00:00:00:01.029]
DBGMISC: EXITED krmice [10:08:17.251] elapsed time [00:00:00:36.481]
DBGMISC: ENTERED krmice [10:08:17.343]
DBGMISC: command to be compiled and executed is: starting media recovery [10:08:17.368] (krmice)
DBGMISC: command after this command is: restoring and applying logs [10:08:17.390] (krmice)
DBGMISC: current incarnation must match for starting media recovery [10:08:17.417] (krmice)
DBGMISC: ENTERED krmkcrsr [10:08:17.456]
DBGSQL: TARGET> begin sys.dbms_backup_restore.createRmanStatusRow( level => :level, parent_id => :pid, parent_stamp => :pts, status => :status, command_id => :command_id, operation => :operation, row_id => :row_id, row_stamp => :row_stamp, flags => :flags); end;
DBGSQL: sqlcode = 0
DBGSQL: B :row_id = 54
DBGSQL: B :row_stamp = 976097297
DBGSQL: B :level = 2
DBGSQL: B :pid = 51
DBGSQL: B :pts = 976097246
DBGSQL: B :status = 1
DBGSQL: B :command_id = 2018-05-14T10:05:22
DBGSQL: B :operation = starting media recovery
DBGSQL: B :flags = 2
DBGMISC: EXITED krmkcrsr [10:08:18.371] elapsed time [00:00:00:00.915]
DBGMISC: ENTERED krmicomp [10:08:18.398]
DBGMISC: ENTERED krmkomp [10:08:18.420]
DBGRCV: ENTERED krmkucls
DBGRCV: EXITED krmkucls with address 0
DBGMISC: krmkcomp - Name translation defaults
RMAN gets the list of archive logs that are needed.
DBGSQL: TARGET> declare thread number; sequence number; recid number; alRec dbms_rcvman.alRec_t; begin dbms_rcvman.getArchivedLog(alRec => alRec); if (:rlscn = alRec.rlgSCN and :stopthr = alRec.thread and ((alRec.sequence >= :stopseq and :toclause = 0) or (alRec.sequence > :stopseq and :toclause = 1))) then :flag := 1; else :flag := 0; :al_key:al_key_i := alRec.key; :recid:recid_i := alRec.recid; :stamp:stamp_i := alRec.stamp; :thread := alRec.thread; :sequence := alRec.sequence; :fileName:fileName_i := alRec.fileName; :lowSCN := alRec.lowSCN; :lowTime := alRec.lowTime; :nextSCN := alRec.nextSCN; :nextTime := nvl(alRec.nextTime, to_date('12/31/9999', 'MM/DD/YYYY')); :rlgSCN := alRec.rlgSCN; :rlgTime := alRec.rlgTime; :blocks := alRec.blocks; :blockSize := alRec.blockSize; :status := alRec.status; :compTime:compTime_i := alRec.compTime; :duplicate := alRec.duplicate; :compressed:compressed_i := alRec.compressed; :isrdf:isrdf_i := alRec.isrdf; :stby := alRec.stby; :terminal := alRec.terminal; :site_key:site_key_i := alRec.site_key; :source_dbid := alRec.source_dbid; end if; end;
DBGSQL: sqlcode = 0
DBGSQL: B :flag = 0
DBGSQL: B :al_key = NULL
DBGSQL: B :recid = NULL
DBGSQL: B :stamp = NULL
DBGSQL: B :thread = 1
DBGSQL: B :sequence = 44
DBGSQL: B :fileName = NULL
DBGSQL: B :lowSCN = 3437200
DBGSQL: B :lowTime = "14-MAY-18"
DBGSQL: B :nextSCN = 3437210
DBGSQL: B :nextTime = "14-MAY-18"
DBGSQL: B :rlgSCN = 1490582
DBGSQL: B :rlgTime = "25-APR-18"
DBGSQL: B :blocks = 25
DBGSQL: B :blockSize = 512
DBGSQL: B :status = D
DBGSQL: B :compTime = NULL
DBGSQL: B :duplicate = 1
DBGSQL: B :compressed = NO
DBGSQL: B :isrdf = NO
DBGSQL: B :stby = N
DBGSQL: B :terminal = NO
DBGSQL: B :site_key = 0
DBGSQL: B :source_dbid = 0
DBGSQL: B :rlscn = 1490582
DBGSQL: B :stopthr = 0
DBGSQL: B :stopseq = 0
DBGSQL: B :toclause = 0
DBGRCVMAN: ENTERING getArchivedLog
DBGRCVMAN: getArchivedLog - resetscn=1490582 thread=1 seq=44 lowscn=3437200 nextscn=3437210 terminal=NO site_key_order_col=0 isrdf=NO stamp=-1
DBGRCVMAN: getArchivedLog - currInc =0
DBGRCVMAN: getArchivedLogLast(translateArcLogSCNRange2) := local
DBGRCVMAN: getArchivedLogLast := local
DBGRCVMAN: EXITING getArchivedLog
DBGMISC: EXITED krmkgal with status Done [10:08:57.766] elapsed time [00:00:00:01.696]
DBGMISC: ENTERED krmkgal [10:08:57.792]
BGMISC: krmrfalb: archive log list: [10:09:02.627]
DBGRESTORE: 1 ALSPEC
DBGRESTORE: 1 RAL key=3 recid=3 stamp=976086144 thread=1 seq=40 site_key=0
DBGRESTORE: lowscn=3435597 nxtscn=3435668 rstscn=1490582
DBGRESTORE: lowtime=2018-05-14 07:00:45 nexttime=2018-05-14 07:02:24 rlgtime=2018-04-25 12:33:34
DBGRESTORE: status=A blocks=9 krmkch { count=0 found=FALSE }
DBGRESTORE: name=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000040_0974378014.0001
DBGRESTORE: 2 RAL key=0 recid=0 stamp=0 thread=1 seq=40 site_key=0
DBGRESTORE: lowscn=3435597 nxtscn=3435668 rstscn=1490582
DBGRESTORE: lowtime=2018-05-14 07:00:45 nexttime=2018-05-14 07:02:24 rlgtime=2018-04-25 12:33:34
DBGRESTORE: status=D blocks=9 krmkch { count=0 found=FALSE }
DBGRESTORE: name=
DBGRESTORE: 3 RAL key=4 recid=4 stamp=976086175 thread=1 seq=41 site_key=0
DBGRESTORE: lowscn=3435668 nxtscn=3435770 rstscn=1490582
DBGRESTORE: lowtime=2018-05-14 07:02:24 nexttime=2018-05-14 07:02:55 rlgtime=2018-04-25 12:33:34
DBGRESTORE: status=A blocks=1970 krmkch { count=0 found=FALSE }
DBGRESTORE: name=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000041_0974378014.0001
DBGRESTORE: 4 RAL key=0 recid=0 stamp=0 thread=1 seq=41 site_key=0
DBGRESTORE: lowscn=3435668 nxtscn=3435770 rstscn=1490582
DBGRESTORE: lowtime=2018-05-14 07:02:24 nexttime=2018-05-14 07:02:55 rlgtime=2018-04-25 12:33:34
DBGRESTORE: status=D blocks=1970 krmkch { count=0 found=FALSE }
DBGRESTORE: name=
DBGRESTORE: 5 RAL key=5 recid=5 stamp=976092346 thread=1 seq=42 site_key=0
DBGRESTORE: lowscn=3435770 nxtscn=3437175 rstscn=1490582
DBGRESTORE: lowtime=2018-05-14 07:02:55 nexttime=2018-05-14 08:45:45 rlgtime=2018-04-25 12:33:34
DBGRESTORE: status=A blocks=4349 krmkch { count=0 found=FALSE }
DBGRESTORE: name=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000042_0974378014.0001
DBGRESTORE: 6 RAL key=0 recid=0 stamp=0 thread=1 seq=42 site_key=0
DBGRESTORE: lowscn=3435770 nxtscn=3437175 rstscn=1490582
DBGRESTORE: lowtime=2018-05-14 07:02:55 nexttime=2018-05-14 08:45:45 rlgtime=2018-04-25 12:33:34
DBGRESTORE: status=D blocks=4349 krmkch { count=0 found=FALSE }
DBGRESTORE: name=
DBGRESTORE: 7 RAL key=6 recid=6 stamp=976092358 thread=1 seq=43 site_key=0
DBGRESTORE: lowscn=3437175 nxtscn=3437200 rstscn=1490582
DBGRESTORE: lowtime=2018-05-14 08:45:45 nexttime=2018-05-14 08:45:58 rlgtime=2018-04-25 12:33:34
DBGRESTORE: status=A blocks=16 krmkch { count=0 found=FALSE }
DBGRESTORE: name=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000043_0974378014.0001
DBGRESTORE: 8 RAL key=0 recid=0 stamp=0 thread=1 seq=43 site_key=0
DBGRESTORE: lowscn=3437175 nxtscn=3437200 rstscn=1490582
DBGRESTORE: lowtime=2018-05-14 08:45:45 nexttime=2018-05-14 08:45:58 rlgtime=2018-04-25 12:33:34
DBGRESTORE: status=D blocks=16 krmkch { count=0 found=FALSE }
DBGRESTORE: name=
DBGRESTORE: 9 RAL key=7 recid=7 stamp=976092375 thread=1 seq=44 site_key=0
DBGRESTORE: lowscn=3437200 nxtscn=3437210 rstscn=1490582
DBGRESTORE: lowtime=2018-05-14 08:45:58 nexttime=2018-05-14 08:46:14 rlgtime=2018-04-25 12:33:34
DBGRESTORE: status=A blocks=25 krmkch { count=0 found=FALSE }
DBGRESTORE: name=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000044_0974378014.0001
DBGRESTORE: 10 RAL key=0 recid=0 stamp=0 thread=1 seq=44 site_key=0
DBGRESTORE: lowscn=3437200 nxtscn=3437210 rstscn=1490582
DBGRESTORE: lowtime=2018-05-14 08:45:58 nexttime=2018-05-14 08:46:14 rlgtime=2018-04-25 12:33:34
DBGRESTORE: status=D blocks=25 krmkch { count=0 found=FALSE }
DBGRESTORE: name=
DBGRESTORE: 11 RAL key=8 recid=8 stamp=976092381 thread=1 seq=45 site_key=0
DBGRESTORE: lowscn=3437210 nxtscn=3437216 rstscn=1490582
DBGRESTORE: lowtime=2018-05-14 08:46:14 nexttime=2018-05-14 08:46:21 rlgtime=2018-04-25 12:33:34
DBGRESTORE: status=A blocks=1 krmkch { count=0 found=FALSE }
DBGRESTORE: name=D:\APP\BGRENN\VIRTUAL\PRODUCT\12.2.0\DBHOME_1\RDBMS\ARC0000000045_0974378014.0001
DBGRESTORE: 12 RAL key=0 recid=0 stamp=0 thread=1 seq=45 site_key=0
DBGRESTORE: lowscn=3437210 nxtscn=3437216 rstscn=1490582
DBGRESTORE: lowtime=2018-05-14 08:46:14 nexttime=2018-05-14 08:46:21 rlgtime=2018-04-25 12:33:34
DBGRESTORE: status=D blocks=1 krmkch { count=0 found=FALSE }
DBGRESTORE: name=