Restoring Standby Database after Failover

 In the previous post, I demonstrated how the Database Incarnation changed after a Failover was issued for a Standby Database.

Let's assume that Read-Write testing of the Standby has been done and now I need to restore and revert STDBYDB to the state of being a Standby for ORCLCDB

The Primary is still at Database Incarnation#=3  and is now at Sequence#=409

SQL> show parameter db_unique_name

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
db_unique_name                       string      ORCLCDB
SQL> select incarnation#
  2  from v$database_incarnation
  3  where status = 'CURRENT'
  4  /

INCARNATION#
------------
           3

SQL> archive log list;
Database log mode              Archive Mode
Automatic archival             Enabled
Archive destination            /opt/oracle/archivelog/ORCLCDB
Oldest online log sequence     407
Next log sequence to archive   409
Current log sequence           409
SQL>

The former Standby STDBYDB has already diverged and is at Incarnation#=4 and its current Sequence#=5

SQL> show parameter db_unique_name

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
db_unique_name                       string      STDBYDB
SQL> select incarnation#
  2  from v$database_incarnation
  3  where status = 'CURRENT'
  4  /

INCARNATION#
------------
           4

SQL> archive log list
Database log mode              Archive Mode
Automatic archival             Enabled
Archive destination            /opt/oracle/archivelog/STDBYDB
Oldest online log sequence     3
Next log sequence to archive   5
Current log sequence           5
SQL>

I now delete all the datafiles STDBYDB and restore the the backup that I made before I executed the Failover (see the previous blog post)

SQL> shutdown immediate;
Database closed.
Database dismounted.
ORACLE instance shut down.
SQL> quit
Disconnected from Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.12.0.0.0
oracle19c>cd
oracle19c>sh ./to_delete_STDBYDB.SH
oracle19c>
oracle19c>echo $ORACLE_SID
STDBYDB
oracle19c>rman target /

Recovery Manager: Release 19.0.0.0.0 - Production on Sat Aug 14 17:49:50 2021
Version 19.12.0.0.0

Copyright (c) 1982, 2019, Oracle and/or its affiliates.  All rights reserved.

connected to target database (not started)

RMAN> startup nomount;

Oracle instance started

Total System Global Area    1207955544 bytes

Fixed Size                     9134168 bytes
Variable Size                486539264 bytes
Database Buffers             704643072 bytes
Redo Buffers                   7639040 bytes

RMAN> restore controlfile from '/opt/oracle/FRA/STDBYDB/STDBYDB/autobackup/2021_08_13/o1_mf_s_1080515319_jkf2tzhp_.bkp';

Starting restore at 14-AUG-21
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=245 device type=DISK

channel ORA_DISK_1: restoring control file
channel ORA_DISK_1: restore complete, elapsed time: 00:00:03
output file name=/opt/oracle/oradata/STDBYDB/control01.ctl
output file name=/opt/oracle/oradata/STDBYDB/control02.ctl
Finished restore at 14-AUG-21

RMAN> quit


Recovery Manager complete.
oracle19c>echo $ORACLE_SID
STDBYDB
oracle19c>sqlplus '/ as sysdba'

SQL*Plus: Release 19.0.0.0.0 - Production on Sat Aug 14 17:52:34 2021
Version 19.12.0.0.0

Copyright (c) 1982, 2021, Oracle.  All rights reserved.


Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.12.0.0.0

SQL> alter database mount;

Database altered.

SQL>  show parameter db_unique_name

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
db_unique_name                       string      STDBYDB
SQL> select database_role, open_mode
  2  from v$database
  3  /

DATABASE_ROLE    OPEN_MODE
---------------- --------------------
PHYSICAL STANDBY MOUNTED

SQL> select incarnation#, resetlogs_change#, to_char(resetlogs_time,'DD-MON-RR HH24:MI') resetlogs_time,
  2  status, resetlogs_id
  3  from v$database_incarnation
  4  order by 1
  5  /

INCARNATION# RESETLOGS_CHANGE# RESETLOGS_TIME           STATUS  RESETLOGS_ID
------------ ----------------- ------------------------ ------- ------------
           1                 1 17-APR-19 00:55          PARENT    1005785759
           2           1920977 04-MAY-19 23:21          PARENT    1007421686
           3           4797184 27-MAR-20 00:00          CURRENT   1036108814

SQL>

So, this restored Controlfile confirms that I have a Standby Database that is now back at Incarnation#=3.

I can now proceed to restore the database and I assume that I can reapply all the ArchiveLogs from the Primary which is also at Incarnation#=3

SQL> quit
Disconnected from Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.12.0.0.0
oracle19c>rman target /

Recovery Manager: Release 19.0.0.0.0 - Production on Sat Aug 14 17:56:06 2021
Version 19.12.0.0.0

Copyright (c) 1982, 2019, Oracle and/or its affiliates.  All rights reserved.

connected to target database: ORCLCDB (DBID=2778483057, not open)

RMAN> restore database;

Starting restore at 14-AUG-21
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=11 device type=DISK
allocated channel: ORA_DISK_2
channel ORA_DISK_2: SID=129 device type=DISK

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 00003 to /opt/oracle/oradata/STDBYDB/sysaux01.dbf
channel ORA_DISK_1: restoring datafile 00007 to /opt/oracle/oradata/STDBYDB/users01.dbf
channel ORA_DISK_1: reading from backup piece /opt/oracle/FRA/STDBYDB/STDBYDB/backupset/2021_08_13/o1_mf_nnndf_TAG20210813T230720_jkf2ob5r_.bkp
channel ORA_DISK_2: starting datafile backup set restore
channel ORA_DISK_2: specifying datafile(s) to restore from backup set
channel ORA_DISK_2: restoring datafile 00001 to /opt/oracle/oradata/STDBYDB/system01.dbf
channel ORA_DISK_2: restoring datafile 00004 to /opt/oracle/oradata/STDBYDB/undotbs01.dbf
channel ORA_DISK_2: reading from backup piece /opt/oracle/FRA/STDBYDB/STDBYDB/backupset/2021_08_13/o1_mf_nnndf_TAG20210813T230720_jkf2o9j4_.bkp
....
....
....

channel ORA_DISK_2: restored backup piece 1
channel ORA_DISK_2: restore complete, elapsed time: 00:00:36
Finished restore at 14-AUG-21

RMAN> quit


Recovery Manager complete.
oracle19c>sqlplus '/ as sysdba'

SQL*Plus: Release 19.0.0.0.0 - Production on Sat Aug 14 18:01:50 2021
Version 19.12.0.0.0

Copyright (c) 1982, 2021, Oracle.  All rights reserved.


Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.12.0.0.0

SQL> show parameter db_unique_name

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
db_unique_name                       string      STDBYDB
SQL> select database_role, open_mode
  2  from v$database
  3  /

DATABASE_ROLE    OPEN_MODE
---------------- --------------------
PHYSICAL STANDBY MOUNTED

SQL> select incarnation#, resetlogs_change#, to_char(resetlogs_time,'DD-MON-RR HH24:MI') resetlogs_time,
  2  status, resetlogs_id
  3  from v$database_incarnation
  4  order by 1
  5  /

INCARNATION# RESETLOGS_CHANGE# RESETLOGS_TIME           STATUS  RESETLOGS_ID
------------ ----------------- ------------------------ ------- ------------
           1                 1 17-APR-19 00:55          PARENT    1005785759
           2           1920977 04-MAY-19 23:21          PARENT    1007421686
           3           4797184 27-MAR-20 00:00          CURRENT   1036108814

SQL>

Let my now try to Recover this Database as a Standby using ArchiveLogs from the PrimaryR (after " alter system set log_archive_dest_state_2='enable';" at the Primary)

SQL> select l.group#, l.bytes/1048576, l.status, f.member
  2  from v$standby_log l, v$logfile f
  3  where l.group#=f.group#
  4  order by 1
  5  /

    GROUP# L.BYTES/1048576 STATUS
---------- --------------- ----------
MEMBER
------------------------------------------------------------------------------------------------------------------------------------
         4             200 ACTIVE
/opt/oracle/oradata/STDBYDB/stdbredo01.log

         5             200 ACTIVE
/opt/oracle/oradata/STDBYDB/stdbredo02.dbf


SQL> alter database clear logfile group 4;

Database altered.

SQL> alter database clear logfile group 5;

Database altered.

SQL>
SQL>  select l.group#, l.bytes/1048576, l.status, f.member
  2  from v$standby_log l, v$logfile f
  3  where l.group#=f.group#
  4  order by 1
  5  /

    GROUP# L.BYTES/1048576 STATUS
---------- --------------- ----------
MEMBER
------------------------------------------------------------------------------------------------------------------------------------
         4             200 UNASSIGNED
/opt/oracle/oradata/STDBYDB/stdbredo01.log

         5             200 UNASSIGNED
/opt/oracle/oradata/STDBYDB/stdbredo02.dbf


SQL>
SQL> alter database recover managed standby database using current logfile disconnect from session;

Database altered.

SQL>

STDBYDB takes a few minutes to get all the ArchiveLogs from Sequence#402 onwards and apply them

2021-08-14T18:16:46.242533+08:00
 rfs (PID:24643): Selected LNO:5 for T-1.S-416 dbid 2778483057 branch 1036108814
2021-08-14T18:16:46.279518+08:00
ARC1 (PID:15987): Archived Log entry 19 added for T-1.S-415 ID 0xa7521ccd LAD:1
2021-08-14T18:16:46.408474+08:00
PR00 (PID:23234): Media Recovery Waiting for T-1.S-416 (in transit)
2021-08-14T18:16:46.420169+08:00
Recovery of Online Redo Log: Thread 1 Group 5 Seq 416 Reading mem 0
  Mem# 0: /opt/oracle/oradata/STDBYDB/stdbredo02.dbf

The Primary also now shows :

SQL> l
  1  select dest_id, db_unique_name, status, type, archived_seq#, applied_seq#, synchronized, gap_status
  2  from v$archive_dest_status
  3  where dest_id in (1,2,3)
  4* order by 1
SQL> /

   DEST_ID DB_UNIQUE_NAME                 STATUS    TYPE             ARCHIVED_SEQ# APPLIED_SEQ# SYN GAP_STATUS
---------- ------------------------------ --------- ---------------- ------------- ------------ --- ------------------------
         1 NONE                           VALID     LOCAL                      415            0 NO
         2 STDBYDB                        VALID     PHYSICAL                   415          414 YES NO GAP
         3 STDB2                          VALID     PHYSICAL                   415          405 NO  NO GAP

SQL>

I can also see the ArchiveLogs that were generated from STDBYDB :

oracle19c>pwd
/opt/oracle/archivelog/STDBYDB
oracle19c>ls -latr
total 196820
drwxr-xr-x. 6 oracle oinstall       63 Aug 11 14:25 ..
-rw-r-----. 1 oracle oinstall   269824 Aug 13 22:47 1_394_1036108814.dbf
-rw-r-----. 1 oracle oinstall  4147200 Aug 13 23:02 1_399_1036108814.dbf
-rw-r-----. 1 oracle oinstall     3584 Aug 13 23:02 1_400_1036108814.dbf
-rw-r-----. 1 oracle oinstall    24064 Aug 13 23:02 1_401_1036108814.dbf
-rw-r-----. 1 oracle oinstall     3072 Aug 13 23:03 1_402_1036108814.dbf
-rw-r-----. 1 oracle oinstall     1024 Aug 13 23:13 1_1_1080515513.dbf
-rw-r-----. 1 oracle oinstall 21302784 Aug 14 17:13 1_2_1080515513.dbf
-rw-r-----. 1 oracle oinstall 96683520 Aug 14 17:41 1_3_1080515513.dbf
-rw-r-----. 1 oracle oinstall    14848 Aug 14 17:42 1_4_1080515513.dbf
-rw-r-----. 1 oracle oinstall    45568 Aug 14 18:04 1_405_1036108814.dbf
-rw-r-----. 1 oracle oinstall   703488 Aug 14 18:04 1_404_1036108814.dbf
-rw-r-----. 1 oracle oinstall   486400 Aug 14 18:04 1_403_1036108814.dbf
-rw-r-----. 1 oracle oinstall 20830208 Aug 14 18:04 1_406_1036108814.dbf
-rw-r-----. 1 oracle oinstall  5378048 Aug 14 18:04 1_407_1036108814.dbf
-rw-r-----. 1 oracle oinstall   538112 Aug 14 18:04 1_408_1036108814.dbf
-rw-r-----. 1 oracle oinstall  4228096 Aug 14 18:04 1_409_1036108814.dbf
-rw-r-----. 1 oracle oinstall     4096 Aug 14 18:04 1_410_1036108814.dbf
-rw-r-----. 1 oracle oinstall   197120 Aug 14 18:07 1_411_1036108814.dbf
-rw-r-----. 1 oracle oinstall   176128 Aug 14 18:16 1_414_1036108814.dbf
-rw-r-----. 1 oracle oinstall   489984 Aug 14 18:16 1_412_1036108814.dbf
-rw-r-----. 1 oracle oinstall    91136 Aug 14 18:16 1_413_1036108814.dbf
-rw-r-----. 1 oracle oinstall     4096 Aug 14 18:16 1_415_1036108814.dbf
drwxr-xr-x. 2 oracle oinstall     4096 Aug 14 18:25 .
-rw-r-----. 1 oracle oinstall 45876224 Aug 14 18:25 1_416_1036108814.dbf
oracle19c>

Note how Sequence#1 to Sequence#4 were generated in the new Incarnation with Resetlogs ID 1080515513.  This was the Resetlogs ID assigned when STDBYDB was opened with Failover, thus a New Incarnation and effectively a Resetlogs. Sequence#403 onwards are from the Primary with Resetlogs ID 1036108814

(You can check the Resetlogs IDs shown in the previous blog post)

Failover and Database Incarnation

In previous blog posts, I have demonstrated : 

1.  Using Flashback Database for [destructive] testing at a Standby

2.  Using Snapshot Standby Database for [destructive] testing at a Standby

3. Executing a Failover To a Standby Database

In this blog post, I will demonstrate the Database Incarnation feature when a Failover is executed.

This is the current status at the Primary :

SQL> show parameter db_unique_name

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
db_unique_name                       string      ORCLCDB
SQL> archive log list

SQL>
SQL> archive log list
Database log mode              Archive Mode
Automatic archival             Enabled
Archive destination            /opt/oracle/archivelog/ORCLCDB
Oldest online log sequence     401
Next log sequence to archive   403
Current log sequence           403
SQL>

SQL> select incarnation#, resetlogs_change#, to_char(resetlogs_time,'DD-MON-RR HH24:MI') resetlogs_time,
  2  status, resetlogs_id
  3  from v$database_incarnation
  4  order by 1
  5  /

INCARNATION# RESETLOGS_CHANGE# RESETLOGS_TIME           STATUS  RESETLOGS_ID
------------ ----------------- ------------------------ ------- ------------
           1                 1 17-APR-19 00:55          PARENT    1005785759
           2           1920977 04-MAY-19 23:21          PARENT    1007421686
           3           4797184 27-MAR-20 00:00          CURRENT   1036108814

SQL>
SQL> l
  1  select dest_id, db_unique_name, status, type, archived_seq#, applied_seq#, synchronized, gap_status
  2  from v$archive_dest_status
  3  where dest_id in (1,2,3)
  4* order by 1
SQL> /

   DEST_ID DB_UNIQUE_NAME STATUS    TYPE             ARCHIVED_SEQ# APPLIED_SEQ# SYN GAP_STATUS
---------- -------------- --------- ---------------- ------------- ------------ --- ------------------------
         1 NONE           VALID     LOCAL                      402            0 NO
         2 STDBYDB        VALID     PHYSICAL                   402          401 YES NO GAP
         3 STDB2          VALID     PHYSICAL                   402          384 NO  NO GAP

SQL>

And this is the current status at the first Standby (STDBYDB)

From the alert log :

2021-08-13T23:03:00.998407+08:00
Recovery of Online Redo Log: Thread 1 Group 4 Seq 403 Reading mem 0
  Mem# 0: /opt/oracle/oradata/STDBYDB/stdbredo01.log


SQL> show parameter db_unique_name

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
db_unique_name                       string      STDBYDB
SQL> select incarnation#, resetlogs_change#, to_char(resetlogs_time,'DD-MON-RR HH24:MI') resetlogs_time,
  2  status, resetlogs_id
  3  from v$database_incarnation
  4  order by 1
  5  /

INCARNATION# RESETLOGS_CHANGE# RESETLOGS_TIME           STATUS  RESETLOGS_ID
------------ ----------------- ------------------------ ------- ------------
           1                 1 17-APR-19 00:55          PARENT    1005785759
           2           1920977 04-MAY-19 23:21          PARENT    1007421686
           3           4797184 27-MAR-20 00:00          CURRENT   1036108814

SQL>

I now create a Backup of the Standby (STDBYDB) (for this test I will not be using Flashback Database or Snapshot Standby Database {see the first two blog posts listed at the beginning for demonstrations of both methods}) :

oracle19c>rman target /

Recovery Manager: Release 19.0.0.0.0 - Production on Fri Aug 13 23:07:04 2021
Version 19.12.0.0.0

Copyright (c) 1982, 2019, Oracle and/or its affiliates.  All rights reserved.

connected to target database: ORCLCDB (DBID=2778483057, not open)

RMAN> backup as compressed backupset database;

Starting backup at 13-AUG-21
Starting implicit crosscheck backup at 13-AUG-21
using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=128 device type=DISK
allocated channel: ORA_DISK_2
channel ORA_DISK_2: SID=252 device type=DISK
Crosschecked 10 objects
Crosschecked 11 objects
Finished implicit crosscheck backup at 13-AUG-21

Starting implicit crosscheck copy at 13-AUG-21
using channel ORA_DISK_1
using channel ORA_DISK_2
Finished implicit crosscheck copy at 13-AUG-21

searching for all files in the recovery area
cataloging files...
no files cataloged

using channel ORA_DISK_1
using channel ORA_DISK_2
channel ORA_DISK_1: starting compressed full datafile backup set
channel ORA_DISK_1: specifying datafile(s) in backup set
input datafile file number=00001 name=/opt/oracle/oradata/STDBYDB/system01.dbf
input datafile file number=00004 name=/opt/oracle/oradata/STDBYDB/undotbs01.dbf
channel ORA_DISK_1: starting piece 1 at 13-AUG-21
channel ORA_DISK_2: starting compressed full datafile backup set
channel ORA_DISK_2: specifying datafile(s) in backup set
input datafile file number=00003 name=/opt/oracle/oradata/STDBYDB/sysaux01.dbf
input datafile file number=00007 name=/opt/oracle/oradata/STDBYDB/users01.dbf
channel ORA_DISK_2: starting piece 1 at 13-AUG-21


....
....
....


Starting Control File and SPFILE Autobackup at 13-AUG-21
piece handle=/opt/oracle/FRA/STDBYDB/STDBYDB/autobackup/2021_08_13/o1_mf_s_1080515319_jkf2tzhp_.bkp comment=NONE
Finished Control File and SPFILE Autobackup at 13-AUG-21

RMAN>
RMAN> quit


Recovery Manager complete.
oracle19c>

I now execute a FAILOVER command at STDBYDB :

oracle19c>sqlplus '/ as sysdba'

SQL*Plus: Release 19.0.0.0.0 - Production on Fri Aug 13 23:11:08 2021
Version 19.12.0.0.0

Copyright (c) 1982, 2021, Oracle.  All rights reserved.


Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.12.0.0.0

SQL> alter database recover managed standby database cancel;

Database altered.

SQL> show parameter db_unique_name

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
db_unique_name                       string      STDBYDB
SQL> alter database failover to STDBYDB;

Database altered.

SQL>
SQL> shutdown immediate;
ORA-01109: database not open


Database dismounted.
ORACLE instance shut down.
SQL> startup open;
ORACLE instance started.

Total System Global Area 1207955544 bytes
Fixed Size                  9134168 bytes
Variable Size             436207616 bytes
Database Buffers          754974720 bytes
Redo Buffers                7639040 bytes
Database mounted.
Database opened.
SQL> show parameter db_unique_name

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
db_unique_name                       string      STDBYDB
SQL>
SQL> select incarnation#, resetlogs_change#, to_char(resetlogs_time,'DD-MON-RR HH24:MI') resetlogs_time,
  2  status, resetlogs_id
  3  from v$database_incarnation
  4  order by 1
  5  /

INCARNATION# RESETLOGS_CHANGE# RESETLOGS_TIME           STATUS  RESETLOGS_ID
------------ ----------------- ------------------------ ------- ------------
           1                 1 17-APR-19 00:55          PARENT    1005785759
           2           1920977 04-MAY-19 23:21          PARENT    1007421686
           3           4797184 27-MAR-20 00:00          PARENT    1036108814
           4          14030903 13-AUG-21 23:11          CURRENT   1080515513

SQL>

>

The STDYDB alert log also shows :

2021-08-13T23:11:18.443497+08:00
alter database recover managed standby database cancel
2021-08-13T23:11:18.475672+08:00
PR00 (PID:354): MRP0: Background Media Recovery cancelled with status 16037
2021-08-13T23:11:18.475814+08:00
Errors in file /opt/oracle/diag/rdbms/stdbydb/STDBYDB/trace/STDBYDB_pr00_354.trc:
ORA-16037: user requested cancel of managed recovery operation
PR00 (PID:354): Managed Standby Recovery not using Real Time Apply
Recovery interrupted!
Recovered data files to a consistent state at change 14030850
Stopping change tracking
2021-08-13T23:11:18.858990+08:00
Errors in file /opt/oracle/diag/rdbms/stdbydb/STDBYDB/trace/STDBYDB_pr00_354.trc:
ORA-16037: user requested cancel of managed recovery operation
2021-08-13T23:11:19.004299+08:00
Background Media Recovery process shutdown (STDBYDB)
2021-08-13T23:11:19.477146+08:00
Managed Standby Recovery Canceled (STDBYDB)
Completed: alter database recover managed standby database cancel

2021-08-13T23:11:40.986985+08:00
alter database failover to STDBYDB

2021-08-13T23:11:40.987075+08:00
.... (PID:4479): The Time Management Interface (TMI) is being enabled for role transition
.... (PID:4479): information.  This will result in messages beingoutput to the alert log
.... (PID:4479): file with the prefix 'TMI: '.  This is being enabled to make the timing of
.... (PID:4479): the various stages of the role transition available for diagnostic purposes.
.... (PID:4479): This output will end when the role transition is complete.
TMI: dbsdrv failover to target BEGIN 2021-08-13 23:11:40.987474
Terminal Recovery requested in process 4479
TMI: adbdrv termRecovery BEGIN 2021-08-13 23:11:40.989180
2021-08-13T23:11:41.082414+08:00
Attempt to do a Terminal Recovery (STDBYDB)
TMI: adbdrv termRecovery END 2021-08-13 23:11:41.082472
2021-08-13T23:11:41.083019+08:00
Attempt to do a Terminal Recovery (STDBYDB)
TMI: adbdrv termRecovery END 2021-08-13 23:11:41.082472
2021-08-13T23:11:41.083019+08:00
Media Recovery Start: Managed Standby Recovery (STDBYDB)
 Started logmerger process
2021-08-13T23:11:41.141008+08:00
PR00 (PID:4636): Managed Standby Recovery not using Real Time Apply
2021-08-13T23:11:42.361339+08:00
max_pdb is 5
2021-08-13T23:11:43.009492+08:00
Parallel Media Recovery started with 4 slaves
2021-08-13T23:11:44.585417+08:00
Stopping change tracking
PR00 (PID:4636): Media Recovery Waiting for T-1.S-403 (in transit)
2021-08-13T23:11:45.982280+08:00
PR00 (PID:4636): Killing 3 processes (PIDS:375,391,394) (all RFS, wait for I/O) in order to disallow current and future RFS connections. Requested by OS process 4636
2021-08-13T23:11:45.982627+08:00
Process termination requested for pid 375 [source = rdbms], [info = 2] [request issued by pid: 4636, uid: 54321]
2021-08-13T23:11:45.983224+08:00
Process termination requested for pid 391 [source = rdbms], [info = 2] [request issued by pid: 4636, uid: 54321]
2021-08-13T23:11:45.983244+08:00
Process termination requested for pid 394 [source = rdbms], [info = 2] [request issued by pid: 4636, uid: 54321]
2021-08-13T23:11:47.984399+08:00
PR00 (PID:4636): Begin: SRL archival
PR00 (PID:4636): End: SRL archival
PR00 (PID:4636): Terminal Recovery timestamp is '08/13/2021 23:11:48'
2021-08-13T23:11:49.723810+08:00
PR00 (PID:4636): Terminal Recovery: applying standby redo logs.
PR00 (PID:4636): Terminal Recovery: thread 1 seq# 403 redo required
2021-08-13T23:11:49.887210+08:00
PR00 (PID:4636): Terminal Recovery:
2021-08-13T23:11:50.007728+08:00
Recovery of Online Redo Log: Thread 1 Group 4 Seq 403 Reading mem 0
  Mem# 0: /opt/oracle/oradata/STDBYDB/stdbredo01.log
2021-08-13T23:11:50.853550+08:00

Terminal Recovery finished with No-Data-Loss
2021-08-13T23:11:51.223461+08:00
Incomplete Recovery applied until change 14030902 time 08/13/2021 23:11:45
2021-08-13T23:11:51.329028+08:00
Media Recovery Complete (STDBYDB)
2021-08-13T23:11:52.416801+08:00
Terminal Recovery: successful completion

PR00 (PID:4636): Forcing ARSCN to IRSCN for TR SCN:0x0000000000d61836
PR00 (PID:4636): Attempt to set limbo arscn SCN:0x0000000000d61836 irscn SCN:0x0000000000d61836
PR00 (PID:4636): Resetting standby activation ID 2807176397 (0xa7521ccd)
Stopping change tracking
2021-08-13T23:11:52.625495+08:00
ALTER DATABASE SWITCHOVER TO PRIMARY (STDBYDB)
2021-08-13T23:11:52.626348+08:00
Maximum wait for role transition is 15 minutes.
TMI: kcv_commit_to_so_to_primary wait for MRP to finish BEGIN 2021-08-13 23:11:52.626362
TMI: kcv_commit_to_so_to_primary wait for MRP to finish END 2021-08-13 23:11:52.626450
TMI: kcv_commit_to_so_to_primary Switchover from physical BEGIN 2021-08-13 23:11:52.626957
Backup controlfile written to trace file /opt/oracle/diag/rdbms/stdbydb/STDBYDB/trace/STDBYDB_ora_4479.trc
Standby terminal recovery start SCN: 14030850
RESETLOGS after incomplete recovery UNTIL CHANGE 14030902 time 08/13/2021 23:11:45
NET  (PID:4479): ORL pre-clearing operation disabled by switchover
Online log /opt/oracle/oradata/STDBYDB/redo01.log: Thread 1 Group 1 was previously cleared
Online log /opt/oracle/oradata/STDBYDB/redo02.log: Thread 1 Group 2 was previously cleared
Online log /opt/oracle/oradata/STDBYDB/redo03.log: Thread 1 Group 3 was previously cleared

2021-08-13T23:11:53.667669+08:00
Standby became primary SCN: 14030849
2021-08-13T23:11:53.668267+08:00
Setting recovery target incarnation to 4
2021-08-13T23:11:53.715844+08:00
NET (PID:4479): RT: Role transition work is not done
NET (PID:4479): The Time Management Interface (TMI) is being enabled for role transition
NET (PID:4479): information. This will result in messages beingoutput to the alert log
NET (PID:4479): file with the prefix 'TMI: '. This is being enabled to make the timing of
NET (PID:4479): the various stages of the role transition available for diagnostic purposes.
NET (PID:4479): This output will end when the role transition is complete.
NET (PID:4479): Redo network throttle feature is disabled at mount time
2021-08-13T23:11:53.934288+08:00
NET (PID:4479): Database role cleared from PHYSICAL STANDBY [kcvs.c:1099]
Switchover: Complete - Database mounted as primary
TMI: kcv_commit_to_so_to_primary Switchover from physical END 2021-08-13 23:11:53.935283
TMI: dbsdrv failover to target END 2021-08-13 23:11:53.935372
Failover completed with No-Data-Loss.
Completed: alter database failover to STDBYDB

2021-08-13T23:12:16.059509+08:00
ARC1 (PID:32662): Becoming the 'no SRL' ARCH
2021-08-13T23:12:26.958308+08:00
Shutting down ORACLE instance (immediate) (OS id: 4479)
....
....
....
2021-08-13T23:12:45.501291+08:00
Instance shutdown complete (OS id: 4479)
....
....
....
2021-08-13T23:12:55.538734+08:00
Starting ORACLE instance (normal) (OS id: 5005)
....
....
....
2021-08-13T23:14:09.422553+08:00
CJQ0 started with pid=64, OS id=6101
Completed: ALTER DATABASE OPEN

Meanwhile, the Primary shows that it no longer communicates with STDBYDB

SQL> l
  1  select dest_id, db_unique_name, status, type, archived_seq#, applied_seq#, synchronized, gap_status
  2  from v$archive_dest_status
  3  where dest_id in (1,2,3)
  4* order by 1
SQL> /

   DEST_ID DB_UNIQUE_NAME STATUS    TYPE             ARCHIVED_SEQ# APPLIED_SEQ# SYN GAP_STATUS
---------- -------------- --------- ---------------- ------------- ------------ --- ------------------------
         1 NONE           VALID     LOCAL                      403            0 NO
         2 STDBYDB        ERROR     PHYSICAL                   401          401 NO  RESOLVABLE GAP
         3 STDB2          VALID     PHYSICAL                   403          386 NO  NO GAP

SQL>


from the alert log :
2021-08-13T23:02:58.137970+08:00
NET  (PID:32207): Archived Log entry 956 added for T-1.S-401 ID 0xa7521ccd LAD:1
2021-08-13T23:03:00.379365+08:00
ALTER SYSTEM ARCHIVE LOG
2021-08-13T23:03:01.008064+08:00
Thread 1 advanced to log sequence 403 (LGWR switch),  current SCN: 14029372
  Current log# 1 seq# 403 mem# 0: /opt/oracle/oradata/ORCLCDB/redo01.log
2021-08-13T23:03:01.143735+08:00
NET  (PID:32207): Archived Log entry 959 added for T-1.S-402 ID 0xa7521ccd LAD:1
2021-08-13T23:11:46.487983+08:00
LGWR (PID:3724): Attempting LAD:2 network reconnect (3113)
LGWR (PID:3724): LAD:2 network reconnect abandoned
2021-08-13T23:11:46.488223+08:00
Errors in file /opt/oracle/diag/rdbms/orclcdb/ORCLCDB/trace/ORCLCDB_lgwr_3724.trc:
ORA-03113: end-of-file on communication channel
LGWR (PID:3724): Error 3113 for LNO:1 to 'STDBYDB'
2021-08-13T23:11:46.532708+08:00
LGWR (PID:3724): LAD:2 is UNSYNCHRONIZED
2021-08-13T23:11:48.149800+08:00
LGWR (PID:3724): Failed to archive LNO:1 T-1.S-403, error=3113
LGWR (PID:3724): Error 1041 disconnecting from LAD:2 standby host 'STDBYDB'
2021-08-13T23:11:48.300060+08:00
Thread 1 advanced to log sequence 404 (LGWR switch),  current SCN: 14030909
  Current log# 2 seq# 404 mem# 0: /opt/oracle/oradata/ORCLCDB/redo02.log
2021-08-13T23:11:49.005544+08:00
ARC1 (PID:3853): Archived Log entry 961 added for T-1.S-403 ID 0xa7521ccd LAD:1
2021-08-13T23:13:23.840728+08:00
 rfs (PID:5505): krsr_rfs_atc: Identified database type as 'PRIMARY': Client is Foreground (PID:5166)
 rfs (PID:5505): Database mount ID mismatch [0xa9f74b79:0xa9f7dc16] (2851556217:2851593238)
 rfs (PID:5505): Not using real application clusters

So, now the STDBYDB database has diverged from the Primary at SCN#14030903 and no longer accepts Redo from the Primary.

The STDBYDB database is now at Incarnation#4

I can stop Redo Shipping from the Primary

SQL> show parameter db_unique_name

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
db_unique_name                       string      ORCLCDB
SQL> select incarnation#, resetlogs_change#, to_char(resetlogs_time,'DD-MON-RR HH24:MI') resetlogs_time,
  2  status, resetlogs_id
  3  from v$database_incarnation
  4  order by 1
  5  /

INCARNATION# RESETLOGS_CHANGE# RESETLOGS_TIME           STATUS  RESETLOGS_ID
------------ ----------------- ------------------------ ------- ------------
           1                 1 17-APR-19 00:55          PARENT    1005785759
           2           1920977 04-MAY-19 23:21          PARENT    1007421686
           3           4797184 27-MAR-20 00:00          CURRENT   1036108814

SQL>
SQL> l
  1  select dest_id, db_unique_name, status, type, archived_seq#, applied_seq#, synchronized, gap_status
  2  from v$archive_dest_status
  3  where dest_id in (1,2,3)
  4* order by 1
SQL> /

   DEST_ID DB_UNIQUE_NAME STATUS    TYPE             ARCHIVED_SEQ# APPLIED_SEQ# SYN GAP_STATUS
---------- -------------- --------- ---------------- ------------- ------------ --- ------------------------
         1 NONE           VALID     LOCAL                      403            0 NO
         2 STDBYDB        ERROR     PHYSICAL                   401          401 NO  RESOLVABLE GAP
         3 STDB2          VALID     PHYSICAL                   403          386 NO  NO GAP

SQL> 
SQL> show parameter log_archive_dest_state_2

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
log_archive_dest_state_2             string      enable
log_archive_dest_state_20            string      enable
log_archive_dest_state_21            string      enable
log_archive_dest_state_22            string      enable
log_archive_dest_state_23            string      enable
log_archive_dest_state_24            string      enable
log_archive_dest_state_25            string      enable
log_archive_dest_state_26            string      enable
log_archive_dest_state_27            string      enable
log_archive_dest_state_28            string      enable
log_archive_dest_state_29            string      enable
SQL> alter system set log_archive_dest_state_2='DEFER';

System altered.

SQL>

from the alert log
2021-08-13T23:21:58.120088+08:00
ALTER SYSTEM SET log_archive_dest_state_2='DEFER' SCOPE=BOTH;

Notice how v$archive_dest_status at the Primary now show that Sequence#401 is the last Archived and Applied at STDBYDB. Sequence#402 and subsequent ones are no longer relevant to STDBYDB.

You might note that the STDB2 which I have configured as a Lagging Standby (DEST_ID=3) is still receiving Redo from the Primary.  So, that Standby is still active.  (See here and here as to how I configured STDB2 as a second Standby that is lagging)

In the next Blog Post, I will show what happens if I attempt to restore the backup of STDBYDB and resync with the Primary after executing multiple changes (redo) in this database want to discard it, inspite of it now running at a different Incarnation# (Incarnation=4)

Opening a Lagging Standby Database (to verify data ?)

 As shown in my previous blog post, you can create a Standby Database that lags the Primary by not applying Redo immediately but "waiting" for a specified interval.  It continues to receive and  ArchiveLogs but simply applies each only after the "wait interval".

So, first, the status at the Primary:

oracle19c>echo $ORACLE_SID
ORCLCDB
oracle19c>sqlplus '/ as sysdba'

SQL*Plus: Release 19.0.0.0.0 - Production on Sat Jul 24 18:03:12 2021
Version 19.3.0.0.0

Copyright (c) 1982, 2019, Oracle.  All rights reserved.


Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.3.0.0.0

SQL> select systimestamp, database_role, current_scn from v$database;

SYSTIMESTAMP                                                   DATABASE_ROLE    CURRENT_SCN
-------------------------------------------------------------- ---------------- -----------
24-JUL-21 06.03.32.106863 PM +08:00                            PRIMARY             13258062

SQL> alter session set container=ORCLPDB1;

Session altered.

SQL> select * from hemant.job_tracking_tbl order by 1;

JOB_END_TIME                                                       JOB_ID     DB_SCN
-------------------------------------------------------------- ---------- ----------
24-JUL-21 04.57.21.676949 PM                                            1   13239134
24-JUL-21 05.04.29.870877 PM                                            2   13241261
24-JUL-21 05.30.17.962275 PM                                            3   13246616
24-JUL-21 05.39.10.912969 PM                                            4   13247859
24-JUL-21 05.40.20.865467 PM                                            5   13248159
24-JUL-21 05.50.23.930352 PM                                            6   13252182
24-JUL-21 06.00.27.037797 PM                                            7   13257658

7 rows selected.

SQL> archive log list;
Database log mode              Archive Mode
Automatic archival             Enabled
Archive destination            /opt/oracle/archivelog/ORCLCDB
Oldest online log sequence     310
Next log sequence to archive   312
Current log sequence           312
SQL>

Now, the status at STDB2 (the Standby that is lagging with an enforced 60minutes delay

From the alert.log :
2021-07-24T17:51:15.716720+08:00
PR00 (PID:2924): Media Recovery Log /opt/oracle/archivelog/STDB21_303_1036108814.dbf
PR00 (PID:2924): Media Recovery Delayed for 59 minute(s) T-1.S-304
2021-07-24T17:57:26.299295+08:00
PR00 (PID:2924): Media Recovery Log /opt/oracle/archivelog/STDB21_304_1036108814.dbf
2021-07-24T17:57:44.580258+08:00
PR00 (PID:2924): Media Recovery Delayed for 60 minute(s) T-1.S-305
2021-07-24T18:00:32.550708+08:00
 rfs (PID:3452): Archived Log entry 52 added for B-1036108814.T-1.S-311 ID 0xa7521ccd LAD:3
2021-07-24T18:00:33.444329+08:00
 rfs (PID:3452): Selected LNO:4 for T-1.S-312 dbid 2778483057 branch 1036108814


oracle19c>sqlplus '/ as sysdba'

SQL*Plus: Release 19.0.0.0.0 - Production on Sat Jul 24 18:05:53 2021
Version 19.3.0.0.0

Copyright (c) 1982, 2019, Oracle.  All rights reserved.


Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.3.0.0.0

SQL> alter database recover managed standby database cancel;

Database altered.

SQL> alter database open read only;

Database altered.

SQL> select systimestamp, database_role, open_mode, current_scn from v$database;

SYSTIMESTAMP                                        DATABASE_ROLE    OPEN_MODE    CURRENT_SCN
--------------------------------------------------- ---------------- ------------ -----------
24-JUL-21 06.06.51.313616 PM +08:00                 PHYSICAL STANDBY READ ONLY       13239390

SQL>
SQL> alter pluggable database orclpdb1 open read only;

Pluggable database altered.

SQL> alter session set container=ORCLPDB1;

Session altered.

SQL> select * from hemant.job_tracking_tbl order by 1;

CURRENT_TIMESTAMP                                                  JOB_ID CURRENT_SCN
-------------------------------------------------------------- ---------- -----------
24-JUL-21 04.57.21.676949 PM                                            1    13239134

SQL>

The Primary database is at Log Sequence#312. This Standby has applied only Sequence#304. Let me resume Recovery for some more time and then check the Standby again.

SQL> exit
Disconnected from Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.3.0.0.0
oracle19c>echo $ORACLE_SID
STDB2
oracle19c>sqlplus '/ as sysdba'

SQL*Plus: Release 19.0.0.0.0 - Production on Sat Jul 24 18:11:12 2021
Version 19.3.0.0.0

Copyright (c) 1982, 2019, Oracle.  All rights reserved.


Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.3.0.0.0

SQL> shutdown immediate;
Database closed.
Database dismounted.
ORACLE instance shut down.
SQL> startup mount;
ORACLE instance started.

Total System Global Area 1207955552 bytes
Fixed Size                  9134176 bytes
Variable Size             318767104 bytes
Database Buffers          872415232 bytes
Redo Buffers                7639040 bytes
Database mounted.
SQL> alter database recover managed standby database using archived logfile disconnect from session;

Database altered.

SQL>
SQL> quit
Disconnected from Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.3.0.0.0
oracle19c>


Later ... from the STDB2 alert log :

2021-07-24T18:40:22.531574+08:00
PR00 (PID:29990): Media Recovery Log /opt/oracle/archivelog/STDB21_309_1036108814.dbf
PR00 (PID:29990): Media Recovery Delayed for 59 minute(s) T-1.S-310
2021-07-24T18:40:43.574486+08:00
 rfs (PID:531): No SRLs available for T-1
2021-07-24T18:40:43.743506+08:00
 rfs (PID:531): Opened log for T-1.S-317 dbid 2778483057 branch 1036108814
2021-07-24T18:40:43.762715+08:00
ARC3 (PID:29836): Archived Log entry 57 added for T-1.S-316 ID 0xa7521ccd LAD:1
2021-07-24T18:40:43.762785+08:00
ARC3 (PID:29836): Archive log for T-1.S-316 available in 60 minute(s)
2021-07-24T18:49:27.636427+08:00
PR00 (PID:29990): Media Recovery Log /opt/oracle/archivelog/STDB21_310_1036108814.dbf
PR00 (PID:29990): Media Recovery Delayed for 60 minute(s) T-1.S-311
2021-07-24T18:50:45.257290+08:00
 rfs (PID:531): Archived Log entry 58 added for B-1036108814.T-1.S-317 ID 0xa7521ccd LAD:3
2021-07-24T18:50:46.045279+08:00
 rfs (PID:531): Selected LNO:4 for T-1.S-318 dbid 2778483057 branch 1036108814


oracle19c>echo $ORACLE_SID
STDB2
oracle19c>sqlplus '/ as sysdba'

SQL*Plus: Release 19.0.0.0.0 - Production on Sat Jul 24 18:51:27 2021
Version 19.3.0.0.0

Copyright (c) 1982, 2019, Oracle.  All rights reserved.


Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.3.0.0.0

SQL> alter database recover managed standby database cancel;

Database altered.

SQL> alter database open read only;

Database altered.

SQL> alter pluggable database orclpdb1 open read only;

Pluggable database altered.

SQL> alter session set container=orclpdb1;

Session altered.

SQL>
SQL> select * from hemant.job_tracking_tbl order by 1;

JOB_END_TIME                                                       JOB_ID     DB_SCN
-------------------------------------------------------------- ---------- ----------
24-JUL-21 04.57.21.676949 PM                                            1   13239134
24-JUL-21 05.04.29.870877 PM                                            2   13241261
24-JUL-21 05.30.17.962275 PM                                            3   13246616
24-JUL-21 05.39.10.912969 PM                                            4   13247859
24-JUL-21 05.40.20.865467 PM                                            5   13248159
24-JUL-21 05.50.23.930352 PM                                            6   13252182

6 rows selected.

SQL>
SQL> select systimestamp from dual;

SYSTIMESTAMP
---------------------------------------------------------------------------
24-JUL-21 06.53.31.159094 PM +08:00

SQL>

So, now at 18:47, STDB2 has applied Sequence#310 and the database now shows data that came through that ArchiveLog. Upto JOB_ID=6, JOB_END_TIME=05:50:23pm
The Primary has already progressed further.

SQL> l
  1* select * from hemant.job_tracking_tbl order by 1
SQL> /

JOB_END_TIME                                                       JOB_ID     DB_SCN
-------------------------------------------------------------- ---------- ----------
24-JUL-21 04.57.21.676949 PM                                            1   13239134
24-JUL-21 05.04.29.870877 PM                                            2   13241261
24-JUL-21 05.30.17.962275 PM                                            3   13246616
24-JUL-21 05.39.10.912969 PM                                            4   13247859
24-JUL-21 05.40.20.865467 PM                                            5   13248159
24-JUL-21 05.50.23.930352 PM                                            6   13252182
24-JUL-21 06.00.27.037797 PM                                            7   13257658
24-JUL-21 06.10.33.163203 PM                                            8   13259223
24-JUL-21 06.20.36.839944 PM                                            9   13261275
24-JUL-21 06.22.46.972310 PM                                           10   13261560
24-JUL-21 06.30.39.787880 PM                                           11   13262799
24-JUL-21 06.37.18.623659 PM                                           12   13263658
24-JUL-21 06.40.41.713016 PM                                           13   13264263
24-JUL-21 06.50.43.755835 PM                                           14   13265798

14 rows selected.

SQL>

So, the operative methods at the Standby are :

 For Recovery :

1.  alter database recover managed standby database USING ARCHIVED LOGFILE disconnect from session

To Open and Query :

1. alter database recover managed standby database CANCEL

2. alter database OPEN READ ONLY

3. alter pluggable database <pdbname>   OPEN READ ONLY

To resume Recovery :

1. shutdown immediate

2. startup mount

3. alter database recover managed standby database USING ARCHIVED LOGFILE disconnect from session

While the Primary must specify a DELAY value in the log_archive_dest_n parameter for this destination Standby