30 June, 2021

Using a Snapshot Standby Database for [destructive] D.R. Testing

 In a previous blog post I have demonstrated how to use the Flashback Database feature to allow you to open a Standby Database for "destructive" testing (whereby you make changes that you want discarded later) and then revert all the changes with the FLASHBACK DATABASE command.

Another method is to open the existing Standby Database as a Snapshot Standby.

Essentially, the steps are :

1. Ensure that an FRA (instance parameters "db_recovery_file_dest" and "db_recovery_file_dest_size") is configured

2. If the Standby is in Recovery mode, stop recovery and confirm that it is only in MOUNT mode

3. Convert the Standby to a Snapshot Standby with "alter database convert to snapshot standby"

4. Open the Standby as a Read/Write database with "alter database open read write"

5. Begin Read/Write operations (i.e. what I call "destructive" testing which consists of updates to the database that you need discarded later so that it can resync with the Primary)

6. Continue using the Primary while the Standby is being tested.  The Standby will continue receiving Archive Logs from the Primary but will hold them and not apply them to the database

7. At the end of testing, revert to the MOUNT state and convert the Standby back to a [normal] Physical Standby with "alter database convert to physical standby"

8. Resume Recovery of the Standby database. You will see the Standby rollback all changes made at Step 5 and then apply all the Primary Archive Logs from Step 6 till it does a "catch-up" and is in sync with the Primary

Snapshot Standby actually uses the Flashback Database feature but you do *not* have to configure Flashback Database in either the Primary or Standby  -- note that any database change that prevents usage of Flashback Database will prevent you from converting the Snapshot Standby to a Physical Standby at Step 7.



Currently, the Standby is receiving and applying Redo :

PR00 (PID:25362): Media Recovery Waiting for T-1.S-24 (in transit)
2021-06-29T23:15:22.056684+08:00
Recovery of Online Redo Log: Thread 1 Group 4 Seq 24 Reading mem 0
  Mem# 0: /opt/oracle/oradata/STDBYDB/stdredo04.log
2021-06-29T23:15:51.519366+08:00
ARC2 (PID:25135): Archived Log entry 6 added for T-1.S-24 ID 0xa998aceb LAD:1
2021-06-29T23:15:51.614140+08:00
 rfs (PID:28617): Primary database is in MAXIMUM PERFORMANCE mode
2021-06-29T23:15:51.625100+08:00
PR00 (PID:25362): Media Recovery Waiting for T-1.S-25
2021-06-29T23:15:51.674786+08:00
 rfs (PID:28617): Selected LNO:4 for T-1.S-25 dbid 2778483057 branch 1074297871
2021-06-29T23:15:52.671617+08:00
Recovery of Online Redo Log: Thread 1 Group 4 Seq 25 Reading mem 0
  Mem# 0: /opt/oracle/oradata/STDBYDB/stdredo04.log


So, now, I chose to convert it to a Snapshot Standby.

SQL> alter database recover managed standby database cancel;

Database altered.

SQL> show parameter db_recovery_file_dest

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
db_recovery_file_dest                string      /opt/oracle/FRA/STDBYDB
db_recovery_file_dest_size           big integer 10G
SQL> alter database convert to snapshot standby;

Database altered.

SQL> alter database open read write;

Database altered.

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


This is what I see in the Standby alert log now ...

2021-06-29T23:18:07.359020+08:00
alter database recover managed standby database cancel
2021-06-29T23:18:07.360109+08:00
PR00 (PID:25362): MRP0: Background Media Recovery cancelled with status 16037
2021-06-29T23:18:07.360231+08:00
Errors in file /opt/oracle/diag/rdbms/stdbydb/STDBYDB/trace/STDBYDB_pr00_25362.trc:
ORA-16037: user requested cancel of managed recovery operation
PR00 (PID:25362): Managed Standby Recovery not using Real Time Apply
Recovery interrupted!
2021-06-29T23:18:08.769438+08:00
Recovered data files to a consistent state at change 13251952
stopping change tracking
2021-06-29T23:18:08.770983+08:00
Errors in file /opt/oracle/diag/rdbms/stdbydb/STDBYDB/trace/STDBYDB_pr00_25362.trc:
ORA-16037: user requested cancel of managed recovery operation
2021-06-29T23:18:08.887583+08:00
Background Media Recovery process shutdown (STDBYDB)
2021-06-29T23:18:09.362417+08:00
Managed Standby Recovery Canceled (STDBYDB)
Completed: alter database recover managed standby database cancel
2021-06-29T23:18:21.398899+08:00alter database convert to snapshot standby
Starting background process RVWR
2021-06-29T23:18:21.820131+08:00
RVWR started with pid=45, OS id=29682
2021-06-29T23:18:24.330193+08:00
Allocating 8388608 bytes in shared pool for flashback generation buffer.
Allocated 4664520 bytes in shared pool for flashback generation buffer
Created guaranteed restore point SNAPSHOT_STANDBY_REQUIRED_06/29/2021 23:18:21
.... (PID:29031): Killing 5 processes (PIDS:28412,28617,28424,28422,28426) (all RFS) in order to disallow current and future RFS connections. Requested by OS process 29031
2021-06-29T23:18:25.156848+08:00
Process termination requested for pid 28617 [source = rdbms], [info = 2] [request issued by pid: 29031, uid: 54321]
2021-06-29T23:18:25.156966+08:00
Process termination requested for pid 28412 [source = rdbms], [info = 2] [request issued by pid: 29031, uid: 54321]
2021-06-29T23:18:25.156976+08:00
Process termination requested for pid 28424 [source = rdbms], [info = 2] [request issued by pid: 29031, uid: 54321]
2021-06-29T23:18:25.157075+08:00
Process termination requested for pid 28422 [source = rdbms], [info = 2] [request issued by pid: 29031, uid: 54321]
2021-06-29T23:18:25.157085+08:00
Process termination requested for pid 28426 [source = rdbms], [info = 2] [request issued by pid: 29031, uid: 54321]
2021-06-29T23:18:27.449097+08:00
.... (PID:29031): Database role changed from PHYSICAL STANDBY to SNAPSHOT STANDBY [kcvs.c:3111]
.... (PID:29031): Begin: SRL archival
.... (PID:29031): End: SRL archival
2021-06-29T23:18:28.867461+08:00
RESETLOGS after incomplete recovery UNTIL CHANGE 13251952 time 06/29/2021 23:18:06
Resetting resetlogs activation ID 2845355243 (0xa998aceb)
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-06-29T23:18:30.336562+08:00
Standby became primary SCN: 13251950
2021-06-29T23:18:30.337002+08:00
Setting recovery target incarnation to 5
2021-06-29T23:18:31.503592+08:00
**********************************************************************
WARNING: The LOG_ARCHIVE_CONFIG parameter has NOT been defined but
remote Data Guard destinations have been configured.  Oracle strongly
recommends that this parameter is set when using Data Guard as
described in the Data Guard manuals.
**********************************************************************
.... (PID:29031): Redo network throttle feature is disabled at mount time
CONVERT TO SNAPSHOT STANDBY: Complete - Database mounted as snapshot standby
Completed: alter database convert to snapshot standby
2021-06-29T23:18:37.046934+08:00
alter database open read write
2021-06-29T23:18:37.175569+08:00
Ping without log force is disabled:
  instance mounted in exclusive mode.
2021-06-29T23:18:37.305328+08:00
Crash Recovery excluding pdb 2 which was cleanly closed.
2021-06-29T23:18:37.305440+08:00
Crash Recovery excluding pdb 4 which was cleanly closed.
Endian type of dictionary set to little
2021-06-29T23:18:37.380920+08:00
Assigning activation ID 2847610391 (0xa9bb1617)
Redo log for group 1, sequence 1 is not located on DAX storage
Thread 1 opened at log sequence 1
  Current log# 1 seq# 1 mem# 0: /opt/oracle/oradata/STDBYDB/redo01.log
Successful open of redo thread 1
2021-06-29T23:18:37.409372+08:00
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
stopping change tracking
2021-06-29T23:18:37.410681+08:00
ARC2 (PID:25135): Becoming the 'no SRL' ARCH
2021-06-29T23:18:38.408371+08:00
Undo initialization recovery: err:0 start: 3634303 end: 3634511 diff: 208 ms (0.2 seconds)
[29031] Successfully onlined Undo Tablespace 2.
Undo initialization online undo segments: err:0 start: 3634511 end: 3635110 diff: 599 ms (0.6 seconds)
Undo initialization finished serial:0 start:3634303 end:3635201 diff:898 ms (0.9 seconds)
Dictionary check beginning
2021-06-29T23:18:39.390552+08:00
Errors in file /opt/oracle/diag/rdbms/stdbydb/STDBYDB/trace/STDBYDB_dbw0_24923.trc:
ORA-01186: file 201 failed verification tests
ORA-01157: cannot identify/lock data file 201 - see DBWR trace file
ORA-01110: data file 201: '/opt/oracle/oradata/STDBYDB/temp01.dbf'
2021-06-29T23:18:39.390607+08:00
File 201 not verified due to error ORA-01157
2021-06-29T23:18:39.457218+08:00
Dictionary check complete
Verifying minimum file header compatibility for tablespace encryption for pdb 1..
Verifying file header compatibility for tablespace encryption completed for pdb 1
2021-06-29T23:18:39.548199+08:00
Errors in file /opt/oracle/diag/rdbms/stdbydb/STDBYDB/trace/STDBYDB_dbw0_24923.trc:
ORA-01157: cannot identify/lock data file 201 - see DBWR trace file
ORA-01110: data file 201: '/opt/oracle/oradata/STDBYDB/temp01.dbf'
ORA-27037: unable to obtain file status
Linux-x86_64 Error: 2: No such file or directory
Additional information: 7
2021-06-29T23:18:39.549816+08:00
Errors in file /opt/oracle/diag/rdbms/stdbydb/STDBYDB/trace/STDBYDB_dbw0_24923.trc:
ORA-01186: file 201 failed verification tests
ORA-01157: cannot identify/lock data file 201 - see DBWR trace file
ORA-01110: data file 201: '/opt/oracle/oradata/STDBYDB/temp01.dbf'
2021-06-29T23:18:39.550371+08:00
File 201 not verified due to error ORA-01157
2021-06-29T23:18:39.587875+08:00
Re-creating tempfile /opt/oracle/oradata/STDBYDB/temp01.dbf
Database Characterset is AL32UTF8
2021-06-29T23:18:40.528004+08:00
No Resource Manager plan active
2021-06-29T23:18:41.713001+08:00
**********************************************************
WARNING: Files may exists in db_recovery_file_dest
that are not known to the database. Use the RMAN command
CATALOG RECOVERY AREA to re-catalog any such files.
If files cannot be cataloged, then manually delete them
using OS command.
One of the following events caused this:
1. A backup controlfile was restored.
2. A standby controlfile was restored.
3. The controlfile was re-created.
4. db_recovery_file_dest had previously been enabled and
   then disabled.
**********************************************************
2021-06-29T23:18:42.808166+08:00
joxcsys_required_dirobj_exists: directory object exists with required path /opt/oracle/product/19c/dbhome_1/javavm/admin/, pid 29031 cid 1
replication_dependency_tracking turned off (no async multimaster replication found)
2021-06-29T23:18:45.099661+08:00
LOGSTDBY: Validating controlfile with logical metadata
LOGSTDBY: Validation complete
Starting background process AQPC
2021-06-29T23:18:45.252140+08:00
AQPC started with pid=44, OS id=29833
PDB$SEED(2):Autotune of undo retention is turned on.
2021-06-29T23:18:46.281751+08:00
Errors in file /opt/oracle/diag/rdbms/stdbydb/STDBYDB/trace/STDBYDB_dbw0_24923.trc:
ORA-01157: cannot identify/lock data file 202 - see DBWR trace file
ORA-01110: data file 202: '/opt/oracle/oradata/STDBYDB/pdbseed/temp012019-05-04_23-32-15-038-PM.dbf'
ORA-27037: unable to obtain file status
Linux-x86_64 Error: 2: No such file or directory
Additional information: 7
2021-06-29T23:18:46.283068+08:00
Errors in file /opt/oracle/diag/rdbms/stdbydb/STDBYDB/trace/STDBYDB_dbw0_24923.trc:
ORA-01186: file 202 failed verification tests
ORA-01157: cannot identify/lock data file 202 - see DBWR trace file
ORA-01110: data file 202: '/opt/oracle/oradata/STDBYDB/pdbseed/temp012019-05-04_23-32-15-038-PM.dbf'
2021-06-29T23:18:46.283122+08:00
File 202 not verified due to error ORA-01157
2021-06-29T23:18:46.299502+08:00
PDB$SEED(2):Endian type of dictionary set to little
PDB$SEED(2):Undo initialization finished serial:0 start:3642756 end:3642756 diff:0 ms (0.0 seconds)
PDB$SEED(2):Pluggable database PDB$SEED dictionary check beginning
PDB$SEED(2):Pluggable Database PDB$SEED Dictionary check complete
PDB$SEED(2):Database Characterset for PDB$SEED is AL32UTF8
2021-06-29T23:18:47.274699+08:00
Errors in file /opt/oracle/diag/rdbms/stdbydb/STDBYDB/trace/STDBYDB_dbw0_24923.trc:
ORA-01157: cannot identify/lock data file 202 - see DBWR trace file
ORA-01110: data file 202: '/opt/oracle/oradata/STDBYDB/pdbseed/temp012019-05-04_23-32-15-038-PM.dbf'
ORA-27037: unable to obtain file status
Linux-x86_64 Error: 2: No such file or directory
Additional information: 7
2021-06-29T23:18:47.275063+08:00
Errors in file /opt/oracle/diag/rdbms/stdbydb/STDBYDB/trace/STDBYDB_dbw0_24923.trc:
ORA-01186: file 202 failed verification tests
ORA-01157: cannot identify/lock data file 202 - see DBWR trace file
ORA-01110: data file 202: '/opt/oracle/oradata/STDBYDB/pdbseed/temp012019-05-04_23-32-15-038-PM.dbf'
2021-06-29T23:18:47.275116+08:00
File 202 not verified due to error ORA-01157
2021-06-29T23:18:47.278375+08:00
PDB$SEED(2):Re-creating tempfile /opt/oracle/oradata/STDBYDB/pdbseed/temp012019-05-04_23-32-15-038-PM.dbf
2021-06-29T23:18:53.913930+08:00
PDB$SEED(2):Opening pdb with no Resource Manager plan active
2021-06-29T23:18:56.010088+08:00
QPI: opatch file present, opatch
QPI: qopiprep.bat file present
2021-06-29T23:18:56.556712+08:00
Starting background process CJQ0
2021-06-29T23:18:56.567311+08:00
CJQ0 started with pid=61, OS id=29890
Completed: alter database open read write
2021-06-29T23:18:56.718602+08:00
Errors in file /opt/oracle/diag/rdbms/stdbydb/STDBYDB/trace/STDBYDB_dbw0_24923.trc:
ORA-01157: cannot identify/lock data file 203 - see DBWR trace file
ORA-01110: data file 203: '/opt/oracle/oradata/STDBYDB/ORCLPDB1/temp01.dbf'
ORA-27037: unable to obtain file status
Linux-x86_64 Error: 2: No such file or directory
Additional information: 7
2021-06-29T23:19:00.397276+08:00
Setting Resource Manager plan SCHEDULER[0x4D53]:DEFAULT_MAINTENANCE_PLAN via scheduler window
Setting Resource Manager CDB plan DEFAULT_MAINTENANCE_PLAN via parameter
2021-06-29T23:19:01.355946+08:00


Ignore the error messages relating to the tempfile for pdbseed. For the Pluggable Database "ORCLPDB1", I have to actually OPEN it and then add the TEMPFILE

SQL> alter pluggable database orclpdb1 open;

Pluggable database altered.

SQL>
SQL> alter session set container=ORCLPDB1;

Session altered.

SQL> alter tablespace temp add tempfile '/opt/oracle/oradata/STDBYDB/ORCLPDB1/temp01.dbf' size 100M;

Tablespace altered.

SQL>


2021-06-29T23:31:16.350347+08:00
ORCLPDB1(3):alter pluggable database orclpdb1 open
ORCLPDB1(3):Autotune of undo retention is turned on.
2021-06-29T23:31:16.983648+08:00
ORCLPDB1(3):Endian type of dictionary set to little
2021-06-29T23:31:17.656064+08:00
ORCLPDB1(3):Undo initialization recovery: err:0 start: 4393577 end: 4393759 diff: 182 ms (0.2 seconds)
2021-06-29T23:31:18.148370+08:00
ORCLPDB1(3):[1962] Successfully onlined Undo Tablespace 2.
ORCLPDB1(3):Undo initialization online undo segments: err:0 start: 4393759 end: 4394252 diff: 493 ms (0.5 seconds)
ORCLPDB1(3):Undo initialization finished serial:0 start:4393577 end:4394295 diff:718 ms (0.7 seconds)
ORCLPDB1(3):Pluggable database ORCLPDB1 dictionary check beginning
ORCLPDB1(3):Dropping offline tempfile '/opt/oracle/oradata/STDBYDB/ORCLPDB1/temp01.dbf'
ORCLPDB1(3):Pluggable Database ORCLPDB1 Dictionary check complete
ORCLPDB1(3):Database Characterset for ORCLPDB1 is AL32UTF8
ORCLPDB1(3):*********************************************************************
ORCLPDB1(3):WARNING: The following temporary tablespaces in container(ORCLPDB1)
ORCLPDB1(3):         contain no files.
ORCLPDB1(3):         This condition can occur when a backup controlfile has
ORCLPDB1(3):         been restored.  It may be necessary to add files to these
ORCLPDB1(3):         tablespaces.  That can be done using the SQL statement:
ORCLPDB1(3):
ORCLPDB1(3):         ALTER TABLESPACE tablespace_name ADD TEMPFILE
ORCLPDB1(3):
ORCLPDB1(3):         Alternatively, if these temporary tablespaces are no longer
ORCLPDB1(3):         needed, then they can be dropped.
ORCLPDB1(3):           Empty temporary tablespace: TEMP
ORCLPDB1(3):*********************************************************************
2021-06-29T23:31:23.694969+08:00
ORCLPDB1(3):Opening pdb with no Resource Manager plan active
ORCLPDB1(3):joxcsys_required_dirobj_exists: directory object exists with required path /opt/oracle/product/19c/dbhome_1/javavm/admin/, pid 1962 cid 3
2021-06-29T23:31:24.744735+08:00
Pluggable database ORCLPDB1 opened read write
ORCLPDB1(3):Completed: alter pluggable database orclpdb1 open
2021-06-29T23:36:08.893763+08:00
ORCLPDB1(3):alter tablespace temp add tempfile '/opt/oracle/oradata/STDBYDB/ORCLPDB1/temp01.dbf' size 100M
ORCLPDB1(3):Completed: alter tablespace temp add tempfile '/opt/oracle/oradata/STDBYDB/ORCLPDB1/temp01.dbf' size 100M


Now, my database with ORACLE_SID=STDBYDB is actually open in Read Write mode and I can execute transactions in it.

STDBYDB>sqlplus hemant/hemant@STDBYPDB1

SQL*Plus: Release 19.0.0.0.0 - Production on Tue Jun 29 23:39:25 2021
Version 19.3.0.0.0

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

Last Successful login time: Fri Jun 25 2021 16:44:27 +08:00

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

SQL> create table my_dummy_table as select * from dba_objects;

Table created.

SQL> insert into my_dummy_table select * from dba_objects;

72825 rows created.

SQL> commit;

Commit complete.

SQL>


Meanwhile, this Standby has been receiving Archive Logs from Sequence#26 onwards from the Primary but not applying them (not that the last one being applied before I converted this to a Snapshot Standby was Sequence#25 (if you scroll up this post and see the alert log entries):

2021-06-29T23:40:05.613462+08:00
 rfs (PID:6610): Selected LNO:5 for T-1.S-26 dbid 2778483057 branch 1074297871
2021-06-29T23:40:06.191335+08:00
ARC3 (PID:25137): Archived Log entry 7 added for T-1.S-25 ID 0xa998aceb LAD:1
2021-06-29T23:41:31.588385+08:00
 rfs (PID:6610): Selected LNO:4 for T-1.S-27 dbid 2778483057 branch 1074297871
2021-06-29T23:41:32.457688+08:00
ARC1 (PID:25133): Archived Log entry 8 added for T-1.S-26 ID 0xa998aceb LAD:1
2021-06-29T23:41:34.786546+08:00
 rfs (PID:6610): Selected LNO:5 for T-1.S-28 dbid 2778483057 branch 1074297871
2021-06-29T23:41:34.972948+08:00
ARC2 (PID:25135): Archived Log entry 9 added for T-1.S-27 ID 0xa998aceb LAD:1
2021-06-29T23:41:38.291575+08:00
 rfs (PID:6610): Selected LNO:4 for T-1.S-29 dbid 2778483057 branch 1074297871
2021-06-29T23:41:38.359875+08:00
ARC3 (PID:25137): Archived Log entry 10 added for T-1.S-28 ID 0xa998aceb LAD:1


After I am done with my testing (the "my_dummy_table" creation and insert statement simulate multiple transactions), I can revert this to a Physical Standby

STDBYDB>echo $ORACLE_SID
STDBYDB
STDBYDB>sqlplus '/ as sysdba'

SQL*Plus: Release 19.0.0.0.0 - Production on Tue Jun 29 23:48:50 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 database_role, open_mode from v$database;

DATABASE_ROLE    OPEN_MODE
---------------- --------------------
SNAPSHOT STANDBY READ WRITE

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             436207616 bytes
Database Buffers          754974720 bytes
Redo Buffers                7639040 bytes
Database mounted.
SQL> alter database convert to physical standby;

Database altered.

SQL> alter database recover managed standby database disconnect from session;

Database altered.

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

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

SQL>


And if I check the alert log

2021-06-29T23:49:00.581987+08:00
Shutting down ORACLE instance (immediate) (OS id: 10178)
2021-06-29T23:49:02.106249+08:00
Stopping background process SMCO
2021-06-29T23:49:03.176041+08:00
Shutting down instance: further logons disabled
2021-06-29T23:49:03.419275+08:00
Stopping background process CJQ0
Stopping background process MMNL
2021-06-29T23:49:04.473142+08:00
Stopping background process MMON
2021-06-29T23:49:06.521607+08:00
alter pluggable database all close immediate
2021-06-29T23:49:06.659467+08:00
ORCLPDB1(3):JIT: pid 10178 requesting stop
ORCLPDB1(3):Buffer Cache flush deferred for PDB 3
2021-06-29T23:49:08.769129+08:00
Pluggable database ORCLPDB1 closed
Completed: alter pluggable database all close immediate
PDB$SEED(2):JIT: pid 10178 requesting stop
PDB$SEED(2):Buffer Cache flush deferred for PDB 2
License high water mark = 9
2021-06-29T23:49:09.947301+08:00
Dispatchers and shared servers shutdown

Data Pump shutdown on PDB: 1 in progress
2021-06-29T23:49:09.947665+08:00
Process termination requested for pid 6610 [source = rdbms], [info = 2] [request issued by pid: 10178, uid: 54321]
2021-06-29T23:49:09.947758+08:00
2021-06-29T23:49:09.947758+08:00
Process termination requested for pid 32278 [source = rdbms], [info = 2] [request issued by pid: 10178, uid: 54321]
2021-06-29T23:49:12.026734+08:00
ALTER DATABASE CLOSE NORMAL
2021-06-29T23:49:12.053755+08:00
Stopping Emon pool
alter pluggable database all close immediate
Completed: alter pluggable database all close immediate
2021-06-29T23:49:13.207695+08:00

IM on ADG: Start of Empty Journal

IM on ADG: End of Empty Journal
Stopping Emon pool
stopping change tracking
2021-06-29T23:49:14.508126+08:00
Shutting down archive processes
2021-06-29T23:49:14.508360+08:00
TT00 (PID:25129): Gap Manager exiting
2021-06-29T23:49:15.508649+08:00
Archiving is disabled
2021-06-29T23:49:15.509020+08:00
ARC3 (PID:25137): ARCH shutting down
ARC3 (PID:25137): Archival stopped
2021-06-29T23:49:15.509302+08:00
ARC2 (PID:25135): ARCH shutting down
ARC2 (PID:25135): Archival stopped
2021-06-29T23:49:15.509646+08:00
ARC1 (PID:25133): ARCH shutting down
ARC1 (PID:25133): Archival stopped
2021-06-29T23:49:15.509894+08:00
ARC0 (PID:25127): ARCH shutting down
ARC0 (PID:25127): Archival stopped
2021-06-29T23:49:16.509551+08:00
Thread 1 closed at log sequence 1
Successful close of redo thread 1
2021-06-29T23:49:16.512464+08:00
Buffer Cache invalidation for all PDBs started
Buffer Cache invalidation for all PDBs complete
Completed: ALTER DATABASE CLOSE NORMAL
ALTER DATABASE DISMOUNT
Shutting down archive processes
Archiving is disabled
Completed: ALTER DATABASE DISMOUNT
2021-06-29T23:49:17.721725+08:00
.... (PID:10178): Archival disabled due to shutdown: 1089
Shutting down archive processes
Archiving is disabled
2021-06-29T23:49:18.723216+08:00
JIT: pid 10178 requesting stop
.... (PID:10178): Archival disabled due to shutdown: 1089
Shutting down archive processes
Archiving is disabled
JIT: pid 10178 requesting stop
2021-06-29T23:49:18.753899+08:00
Stopping background process VKTM
2021-06-29T23:49:31.362905+08:00
Instance shutdown complete (OS id: 10178)
2021-06-29T23:49:40.001253+08:00
Starting ORACLE instance (normal) (OS id: 10479)
2021-06-29T23:49:40.008425+08:00
****************************************************
 Sys-V shared memory will be used for creating SGA
 ****************************************************
2021-06-29T23:49:40.009279+08:00
**********************************************************************
2021-06-29T23:49:40.009331+08:00
Dump of system resources acquired for SHARED GLOBAL AREA (SGA)

2021-06-29T23:49:40.009453+08:00
 Per process system memlock (soft) limit = 128G
2021-06-29T23:49:40.009507+08:00
.... 
.... removed normal alert log messages for instance startup
....
2021-06-29T23:49:42.110291+08:00
ALTER DATABASE   MOUNT
2021-06-29T23:49:44.864639+08:00
Using default pga_aggregate_limit of 2048 MB
2021-06-29T23:49:46.335191+08:00
.... (PID:10659): Database role set to SNAPSHOT STANDBY [kcvfdb.c:8281]
**********************************************************************
WARNING: The LOG_ARCHIVE_CONFIG parameter has NOT been defined but
remote Data Guard destinations have been configured.  Oracle strongly
recommends that this parameter is set when using Data Guard as
described in the Data Guard manuals.
**********************************************************************
.... (PID:10659): Redo network throttle feature is disabled at mount time
2021-06-29T23:49:46.670017+08:00
Successful mount of redo thread 1, with mount id 2847556374
2021-06-29T23:49:46.671968+08:00
Allocating 8388608 bytes in shared pool for flashback generation buffer.
Allocated 8086776 bytes in shared pool for flashback generation buffer
Starting background process RVWR
2021-06-29T23:49:46.682551+08:00
RVWR started with pid=38, OS id=10680
2021-06-29T23:49:46.973026+08:00
Database mounted in Exclusive Mode
Lost write protection disabled
.... (PID:10659): Using STANDBY_ARCHIVE_DEST parameter default value as /opt/oracle/archivelog/STDBYDB [krsd.c:18141]
.... (PID:10659): STARTING ARCH PROCESSES
Starting background process ARC0
2021-06-29T23:49:47.204833+08:00
TT00 (PID:10683): Gap Manager starting
2021-06-29T23:49:47.212662+08:00
ARC0 started with pid=40, OS id=10685
2021-06-29T23:49:47.223092+08:00
.... (PID:10659): ARC0: Archival started
.... (PID:10659): STARTING ARCH PROCESSES COMPLETE
2021-06-29T23:49:47.223272+08:00
ARC0 (PID:10685): Becoming a 'no FAL' ARCH
Completed: ALTER DATABASE   MOUNT
ARC0 (PID:10685): Becoming the 'no SRL' ARCH
2021-06-29T23:49:48.204507+08:00
TMON (PID:10658): STARTING ARCH PROCESSES
Starting background process ARC1
Starting background process ARC2
2021-06-29T23:49:48.213579+08:00
ARC1 started with pid=41, OS id=10688
Starting background process ARC3
2021-06-29T23:49:48.223493+08:00
ARC2 started with pid=42, OS id=10690
TMON (PID:10658): ARC1: Archival started
TMON (PID:10658): ARC2: Archival started
2021-06-29T23:49:48.233487+08:00
ARC3 started with pid=43, OS id=10692
TMON (PID:10658): ARC3: Archival started
TMON (PID:10658): STARTING ARCH PROCESSES COMPLETE
2021-06-29T23:49:50.907722+08:00
 rfs (PID:10708): Selected LNO:4 for T-1.S-29 dbid 2778483057 branch 1074297871
2021-06-29T23:49:56.957932+08:00
alter database convert to physical standby
2021-06-29T23:49:56.958049+08:00
ALTER DATABASE CONVERT TO PHYSICAL STANDBY (STDBYDB)
2021-06-29T23:49:56.977719+08:00
.... (PID:10686): Killing 2 processes (PIDS:10706,10708) (all RFS) in order to disallow current and future RFS connections. Requested by OS process 10686
2021-06-29T23:49:56.977988+08:00
Process termination requested for pid 10708 [source = rdbms], [info = 2] [request issued by pid: 10686, uid: 54321]
2021-06-29T23:49:56.978145+08:00
Process termination requested for pid 10706 [source = rdbms], [info = 2] [request issued by pid: 10686, uid: 54321]
2021-06-29T23:49:59.623973+08:00
Flashback Restore Start
2021-06-29T23:50:06.211660+08:00
Flashback Restore Complete
Drop guaranteed restore point
Stopping background process RVWR
2021-06-29T23:50:08.169218+08:00
Deleted Oracle managed file /opt/oracle/FRA/STDBYDB/STDBYDB/flashback/o1_mf_jfpgfxwn_.flb
Deleted Oracle managed file /opt/oracle/FRA/STDBYDB/STDBYDB/flashback/o1_mf_jfpgg215_.flb
Guaranteed restore point  dropped
2021-06-29T23:50:08.204353+08:00
.... (PID:10686): Database role cleared from SNAPSHOT STANDBY [kcvs.c:8837]
Clearing standby activation ID 2847610391 (0xa9bb1617)
The primary database controlfile was created using the
'MAXLOGFILES 16' clause.
There is space for up to 13 standby redo logfiles
Use the following SQL commands on the standby database to create
standby redo logfiles that match the primary database:
ALTER DATABASE ADD STANDBY LOGFILE 'srl1.f' SIZE 209715200;
ALTER DATABASE ADD STANDBY LOGFILE 'srl2.f' SIZE 209715200;
ALTER DATABASE ADD STANDBY LOGFILE 'srl3.f' SIZE 209715200;
ALTER DATABASE ADD STANDBY LOGFILE 'srl4.f' SIZE 209715200;
Offline data file 5 marked as online during convert to standby or switchover to standby.
Restore of backup may be required if the file is not physically accessible.
Offline data file 6 marked as online during convert to standby or switchover to standby.
Restore of backup may be required if the file is not physically accessible.
Offline data file 8 marked as online during convert to standby or switchover to standby.
Restore of backup may be required if the file is not physically accessible.
Offline data file 27 marked as online during convert to standby or switchover to standby.
Restore of backup may be required if the file is not physically accessible.
Offline data file 28 marked as online during convert to standby or switchover to standby.
Restore of backup may be required if the file is not physically accessible.
Offline data file 29 marked as online during convert to standby or switchover to standby.
Restore of backup may be required if the file is not physically accessible.
Offline data file 30 marked as online during convert to standby or switchover to standby.
Restore of backup may be required if the file is not physically accessible.
.... (PID:10686): Database role changed from PRIMARY to PHYSICAL STANDBY [kcvs.c:8842]
.... (PID:10686): RT: Role transition work is not done
**********************************************************************
WARNING: The LOG_ARCHIVE_CONFIG parameter has NOT been defined but
remote Data Guard destinations have been configured.  Oracle strongly
recommends that this parameter is set when using Data Guard as
described in the Data Guard manuals.
**********************************************************************
.... (PID:10686): Redo network throttle feature is disabled at mount time
Physical Standby Database mounted.
2021-06-29T23:50:08.445082+08:00
In-memory operation on ADG is currently only supported on Engineered systems and PaaS.
inmemory_adg_enabled is turned off automatically.
Please contact our support team for EXADATA solutions
CONVERT TO PHYSICAL STANDBY: Complete - Database mounted as physical standby
Completed: alter database convert to physical standby
2021-06-29T23:50:08.945385+08:00
 rfs (PID:11113): Primary database is in MAXIMUM PERFORMANCE mode
2021-06-29T23:50:09.052749+08:00
 rfs (PID:11113): Selected LNO:4 for T-1.S-29 dbid 2778483057 branch 1074297871
2021-06-29T23:50:28.597419+08:00
alter database recover managed standby database disconnect from session
2021-06-29T23:50:28.602993+08:00
Attempt to start background Managed Standby Recovery process (STDBYDB)
Starting background process MRP0
2021-06-29T23:50:28.613186+08:00
MRP0 started with pid=46, OS id=11197
2021-06-29T23:50:28.614021+08:00
Background Managed Standby Recovery process started (STDBYDB)
2021-06-29T23:50:33.639389+08:00
 Started logmerger process
2021-06-29T23:50:33.675757+08:00
PR00 (PID:11203): Managed Standby Recovery starting Real Time Apply
max_pdb is 5
2021-06-29T23:50:33.879309+08:00
Parallel Media Recovery started with 2 slaves
2021-06-29T23:50:34.023681+08:00
stopping change tracking
2021-06-29T23:50:34.043787+08:00
TT02 (PID:11209): Waiting for all non-current ORLs to be archived
2021-06-29T23:50:34.043942+08:00
TT02 (PID:11209): All non-current ORLs have been archived
TT02 (PID:11209): Clearing ORL LNO:1 /opt/oracle/oradata/STDBYDB/redo01.log
Clearing online log 1 of thread 1 sequence number 1
2021-06-29T23:50:34.621214+08:00
Completed: alter database recover managed standby database disconnect from session
2021-06-29T23:50:35.522538+08:00
PR00 (PID:11203): Media Recovery Log /opt/oracle/archivelog/STDBYDB/1_25_1074297871.dbf
2021-06-29T23:50:43.531488+08:00
PR00 (PID:11203): Media Recovery Log /opt/oracle/archivelog/STDBYDB/1_26_1074297871.dbf
2021-06-29T23:50:45.201867+08:00
TT02 (PID:11209): Clearing ORL LNO:1 complete
2021-06-29T23:50:45.330739+08:00
PR00 (PID:11203): Media Recovery Log /opt/oracle/archivelog/STDBYDB/1_27_1074297871.dbf
2021-06-29T23:50:45.523635+08:00
PR00 (PID:11203): Media Recovery Log /opt/oracle/archivelog/STDBYDB/1_28_1074297871.dbf
PR00 (PID:11203): Media Recovery Waiting for T-1.S-29 (in transit)
2021-06-29T23:50:45.747920+08:00
Recovery of Online Redo Log: Thread 1 Group 4 Seq 29 Reading mem 0
  Mem# 0: /opt/oracle/oradata/STDBYDB/stdredo04.log
2021-06-29T23:50:50.908827+08:00
TT02 (PID:11209): Waiting for all non-current ORLs to be archived
2021-06-29T23:50:50.908947+08:00
TT02 (PID:11209): All non-current ORLs have been archived
2021-06-29T23:57:47.333206+08:00
PR00 (PID:11203): Media Recovery Waiting for T-1.S-30
2021-06-29T23:57:47.338144+08:00
ARC3 (PID:10692): Archived Log entry 11 added for T-1.S-29 ID 0xa998aceb LAD:1
2021-06-29T23:57:47.351366+08:00
 rfs (PID:14591): Primary database is in MAXIMUM PERFORMANCE mode
2021-06-29T23:57:47.397285+08:00
 rfs (PID:14591): Selected LNO:4 for T-1.S-30 dbid 2778483057 branch 1074297871
2021-06-29T23:57:48.392151+08:00
Recovery of Online Redo Log: Thread 1 Group 4 Seq 30 Reading mem 0
  Mem# 0: /opt/oracle/oradata/STDBYDB/stdredo04.log


We can see that it actually did a FLASHBACK DATABASE and DROP GUARANTEED RESTORE POINT(including deletion of Flashback Logs) between 2021-06-29T23:49:59.623973+08:00  and   2021-06-29T23:50:08.169218+08:00.
(This is, effectively, the same method that I demonstrated in the earlier blog post).  After converting to a Physical Standby it applied Archive Logs from Sequence#25 (which was incompletely applied as it was only in Real Time Apply mode at the first conversion to a Snapshot Standby) to Sequence#29 and even the new Sequence#30 being applied in Real Time Apply mode.

But what are the messages relating to datafiles 5, 6, 8, 27,28, 29, 30 ?  The first few are for PDBSEED -- which we know does not get updated and the last 4 are for a PDB called "RMANCAT" which I did *not* OPEN.  


SQL> l
  1  select f.con_id, f.file#, p.name as pdb_name, f.name
  2  from v$datafile f, v$pdbs p
  3  where f.con_id=p.con_id
  4  and f.file# in (5,6,8, 27, 28, 29, 30)
  5* order by 1,2
SQL> /

    CON_ID      FILE# PDB_NAME NAME
---------- ---------- -------- --------------------------------------------------------------------------------
         2          5 PDB$SEED /opt/oracle/oradata/STDBYDB/pdbseed/system01.dbf
         2          6 PDB$SEED /opt/oracle/oradata/STDBYDB/pdbseed/sysaux01.dbf
         2          8 PDB$SEED /opt/oracle/oradata/STDBYDB/pdbseed/undotbs01.dbf
         4         27 RMANCAT  /opt/oracle/oradata/STDBYDB/C07D1F2BA98C23D0E0530100007F7D34/datafile/o1_mf_syst
                               em_jckz3qym_.dbf

         4         28 RMANCAT  /opt/oracle/oradata/STDBYDB/C07D1F2BA98C23D0E0530100007F7D34/datafile/o1_mf_sysa
                               ux_jckz3qy8_.dbf

         4         29 RMANCAT  /opt/oracle/oradata/STDBYDB/C07D1F2BA98C23D0E0530100007F7D34/datafile/o1_mf_undo
                               tbs1_jckz3r04_.dbf

         4         30 RMANCAT  /opt/oracle/oradata/STDBYDB/C07D1F2BA98C23D0E0530100007F7D34/datafile/o1_mf_rman
                               _tbs_jckz3r09_.dbf


7 rows selected.

SQL>


Since these PDBs were *NOT* opened when the database was operating as a Snaphot Standby, they did not get updated.  I can actually ignore the message.  The datafiles are present but were simply not updated.  I do know that the datafiles are present and the RMANCAT PDB is being updated by operations on the Primary.

STDBYDB>cd /opt/oracle/oradata/STDBYDB/C07D1F2BA98C23D0E0530100007F7D34/datafile
STDBYDB>ls -l
total 860192
-rw-r-----. 1 oracle oinstall 104865792 Jun 30 00:14 o1_mf_rman_tbs_jckz3r09_.dbf
-rw-r-----. 1 oracle oinstall 377495552 Jun 30 00:14 o1_mf_sysaux_jckz3qy8_.dbf
-rw-r-----. 1 oracle oinstall 293609472 Jun 30 00:14 o1_mf_system_jckz3qym_.dbf
-rw-r-----. 1 oracle oinstall 104865792 Jun 30 00:14 o1_mf_undotbs1_jckz3r04_.dbf
STDBYDB>


Also, I can ignore the messages relating to creation of Standby Redo Logs as I already have 3 Standby Redo Logs in the database.

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

    GROUP# STATUS     MEMBER                                           L.BYTES/1048576
---------- ---------- ------------------------------------------------ ---------------
         4 UNASSIGNED /opt/oracle/oradata/STDBYDB/stdredo04.log                    200
         5 ACTIVE     /opt/oracle/oradata/STDBYDB/stdredo05.log                    200
         6 UNASSIGNED /opt/oracle/oradata/STDBYDB/stdredo06.log                    200

SQL> !ls -l /opt/oracle/oradata/STDBYDB/stdred*
-rw-r-----. 1 oracle oinstall 209715712 Jun 30 00:16 /opt/oracle/oradata/STDBYDB/stdredo04.log
-rw-r-----. 1 oracle oinstall 209715712 Jun 30 00:22 /opt/oracle/oradata/STDBYDB/stdredo05.log
-rw-r-----. 1 oracle oinstall 209715712 Jun 29 23:06 /opt/oracle/oradata/STDBYDB/stdredo06.log

SQL>



Finally : This was a demonstration of opening a Standby of a MultiTenant Database as a Snapshot, opening a selected PDB (ORCLPDB1) without having to open all the PDBs, executing transactions and then reverting the whole CDB back to a Physical Standby.


No comments: