David Marcos' Blog

Testing your Oracle Standby configuration using Oracle Broker. 4 April 2011

Several weeks ago I wrote a post regarding testing your standby database ( https://davidalejomarcos.wordpress.com/2011/03/01/how-to-test-your-dataguard-configuration-standby-database/ ). The database I tested did not have Oracle Broker configured.

Today I will show you how I did perform a switchover with Oracle Broker configured.

The problem:

Perform a switchover using Oracle Broker.

The solution:

It proved to be quite simple and trouble-free.

Below are the steps I followed:

Note.- Primary is my production primary database during all the exercise, independently of the role the database is running. PRMRY relates to the commands to be run on the current production database.

Note.- Standby is my production standby database during all the exercise, independently of the role the database is running. STNDBY relates to the commands to be run on the current standby database.

1.- Check primary and standby database are in sync:

PRMRY> select sequence# seq,thread# thread  from v$log where status = 'CURRENT' order by thread#;

SEQ     THREAD
---------- ----------
33388        1

PRMRY> alter system switch logfile;

System altered.

PRMRY> /

System altered.

PRMRY> /

System altered.

PRMRY> select sequence# seq,thread# thread  from v$log where status = 'CURRENT' order by thread#;

SEQ     THREAD
---------- ----------
33391        1

PRMRY> exit

STNDBY> select distinct max( sequence#) over (partition by thread# order by thread#) seq, thread# thread from gv$log_history;

SEQ     THREAD
---------- ----------
33390        1

STNDBY> exit

2.- Connect to Oracle Broker from the server where PRMRY is running and:

[oracle@sssss ~]$ dgmgrl
DGMGRL for Linux: Version 11.2.0.1.0 - 64bit Production

Copyright (c) 2000, 2009, Oracle. All rights reserved.

Welcome to DGMGRL, type "help" for information.
DGMGRL> connect /
Connected.

2.1.- Check the configuration for errors:

DGMGRL> show configuration

Configuration - ssss_DG

Protection Mode: MaxPerformance
Databases:
PRIMARY    - Primary database
STANDBY    - Physical standby database

Fast-Start Failover: DISABLED

Configuration Status:
SUCCESS

2.2.- Check primary is in “TRANSPORT-ON” state

DGMGRL> show database primary

Database - primary

Enterprise Manager Name: sss_primary
Role:                    PRIMARY
Intended State:          TRANSPORT-ON
Instance(s):
sss

Database Status:
SUCCESS

2.3.- standby database is in “APPLY-ON” state:

DGMGRL> show database standby

Database - standby

Enterprise Manager Name: sss_standby
Role:                    PHYSICAL STANDBY
Intended State:          APPLY-ON
Transport Lag:           0 seconds
Apply Lag:               0 seconds
Real Time Query:         OFF
Instance(s):
sss

Database Status:
SUCCESS

3.- Perform the switchover using Oracle Broker:

DGMGRL> switchover to standby
Performing switchover NOW, please wait...
New primary database "standby" is opening...
Operation requires shutdown of instance "sss" on database "primary"
Shutting down instance "sss"...
ORA-01031: insufficient privileges

Warning: You are no longer connected to ORACLE.

Please complete the following steps to finish switchover:
shut down instance "sss" of database "primary"
start up and mount instance "sss" of database "primary"

DGMGRL>

4.- Restart the new standby database and register it with the listener:

[oracle@ssss ~]$ sqlplus '/as sysdba'

SQL*Plus: Release 11.2.0.1.0 Production on Sat Apr 2 09:02:20 2011

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

Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning option

SQL> select open_mode from v$database;

OPEN_MODE
--------------------
MOUNTED

SQL> shutdown immediate

ORA-01109: database not open
Database dismounted.
ORACLE instance shut down.

SQL> startup mount

Total System Global Area 1.2827E+10 bytes
Fixed Size            2225336 bytes
Variable Size         1207962440 bytes
Database Buffers     1.1610E+10 bytes
Redo Buffers            7348224 bytes
Database mounted.

SQL> alter system register;

System altered.

SQL> exit

5.- Check log files are being sent and applied on the new standby database.

As always, comments are welcome.

————————-

Appendix:

Below is the section of the primary database while switching over to standby:

Sat Apr 02 08:58:37 2011
ALTER DATABASE COMMIT TO SWITCHOVER TO PHYSICAL STANDBY WITH SESSION SHUTDOWN
ALTER DATABASE COMMIT TO SWITCHOVER TO PHYSICAL STANDBY  [Process Id: 8432] (sss)
Sat Apr 02 08:58:37 2011
Thread 1 cannot allocate new log, sequence 33392
Private strand flush not complete
Current log# 3 seq# 33391 mem# 0: /u03/oradata/sss/redo03.rdo
Thread 1 advanced to log sequence 33392 (LGWR switch)
Current log# 1 seq# 33392 mem# 0: /u03/oradata/sss/redo01.rdo
Waiting for all non-current ORLs to be archived...
Waiting for the ORL for thread 1 sequence 33391 to be archived...
Sat Apr 02 08:58:44 2011
Archived Log entry 68782 added for thread 1 sequence 33391 ID 0x2a7ee921 dest 1:
Sat Apr 02 08:58:51 2011
ORL for thread 1 sequence 33391 has been archived...
All non-current ORLs have been archived.
Waiting for all FAL entries to be archived...
All FAL entries have been archived.
Waiting for dest_id 2 to become synchronized...
Sat Apr 02 08:59:01 2011
Active, synchronized Physical Standby  switchover target has been identified
Sat Apr 02 08:59:01 2011
Thread 1 cannot allocate new log, sequence 33393
Private strand flush not complete
Current log# 1 seq# 33392 mem# 0: /u03/oradata/sss/redo01.rdo
Thread 1 advanced to log sequence 33393 (LGWR switch)
Current log# 2 seq# 33393 mem# 0: /u03/oradata/sss/redo02.rdo
ARCH: Standby redo logfile selected for thread 1 sequence 33392 for destination LOG_ARCHIVE_DEST_2
Archived Log entry 68783 added for thread 1 sequence 33392 ID 0x2a7ee921 dest 1:
Sat Apr 02 08:59:01 2011
Stopping background process CJQ0
Sat Apr 02 08:59:01 2011
SMON: disabling tx recovery
Stopping background process QMNC
CLOSE: killing server sessions.
Sat Apr 02 08:59:14 2011
CLOSE: all sessions shutdown successfully.
Sat Apr 02 08:59:14 2011
SMON: disabling cache recovery
Sat Apr 02 08:59:15 2011
Shutting down archive processes
Archiving is disabled
Sat Apr 02 08:59:15 2011
ARCH shutting down
Sat Apr 02 08:59:15 2011
ARCH shutting down
ARC9: Archival stopped
ARC7: Archival stopped
Sat Apr 02 08:59:15 2011
ARCH shutting down
ARC5: Archival stopped
Sat Apr 02 08:59:15 2011
ARCH shutting down
Sat Apr 02 08:59:15 2011
ARCH shutting down
ARC3: Archival stopped
ARC0: Archival stopped
Sat Apr 02 08:59:15 2011
ARCH shutting down
Sat Apr 02 08:59:15 2011
ARCH shutting down
ARC4: Archival stopped
ARC6: Archival stopped
Sat Apr 02 08:59:15 2011
ARCH shutting down
ARC2: Archival stopped
Sat Apr 02 08:59:15 2011
ARCH shutting down
ARC8: Archival stopped
Sat Apr 02 08:59:15 2011
ARCH shutting down
ARC1: Archival stopped
Thread 1 closed at log sequence 33393
Successful close of redo thread 1
ARCH: Noswitch archival of thread 1, sequence 33393
ARCH: End-Of-Redo Branch archival of thread 1 sequence 33393
Archived Log entry 68785 added for thread 1 sequence 33393 ID 0x2a7ee921 dest 1:
ARCH: Archiving is disabled due to current logfile archival
Primary will check for some target standby to have received all redo
Final check for a synchronized target standby. Check will be made once.
LOG_ARCHIVE_DEST_2 is a potential Physical Standby  switchover target
Active, synchronized target has been identified
Target has also applied all redo
Backup controlfile written to trace file /opt/oracle/diag/rdbms/primary/sss/trace/sss_rsm0_8432.trc
Clearing standby activation ID 712960289 (0x2a7ee921)
The primary database controlfile was created using the
'MAXLOGFILES 12' clause.
There is space for up to 9 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 262144000;
ALTER DATABASE ADD STANDBY LOGFILE 'srl2.f' SIZE 262144000;
ALTER DATABASE ADD STANDBY LOGFILE 'srl3.f' SIZE 262144000;
ALTER DATABASE ADD STANDBY LOGFILE 'srl4.f' SIZE 262144000;
Archivelog for thread 1 sequence 33393 required for standby recovery
Switchover: Primary controlfile converted to standby controlfile succesfully.
Sat Apr 02 08:59:19 2011
MRP0 started with pid=18, OS id=10456
MRP0: Background Managed Standby Recovery process started (sss)
Serial Media Recovery started
Managed Standby Recovery not using Real Time Apply
Online logfile pre-clearing operation disabled by switchover
Media Recovery Log /u01/oradata/sss/arch/log1_33393_708427666.arc
Identified End-Of-Redo for thread 1 sequence 33393
Resetting standby activation ID 0 (0x0)
Media Recovery End-Of-Redo indicator encountered
Media Recovery Applied until change 241462639865
MRP0: Media Recovery Complete: End-Of-REDO (sss)
MRP0: Background Media Recovery process shutdown (sss)
Sat Apr 02 08:59:25 2011
Switchover: Complete - Database shutdown required (sss)
Completed: ALTER DATABASE COMMIT TO SWITCHOVER TO PHYSICAL STANDBY WITH SESSION SHUTDOWN
Using STANDBY_ARCHIVE_DEST parameter default value as /u01/oradata/sss/arch
ALTER SYSTEM SET log_archive_dest_2='' SCOPE=BOTH;
Using STANDBY_ARCHIVE_DEST parameter default value as /u01/oradata/sss/arch
ALTER SYSTEM SET log_archive_dest_state_2='ENABLE' SCOPE=BOTH;
Sat Apr 02 08:59:29 2011
RFS[1]: Assigned to RFS process 11886
RFS[1]: Identified database type as 'physical standby': Client is ARCH pid 5025
RFS[1]: Opened log for thread 1 sequence 33394 dbid 666702615 branch 708427666
Sat Apr 02 08:59:29 2011
RFS[2]: Assigned to RFS process 11894
RFS[2]: Identified database type as 'physical standby': Client is ARCH pid 5021
Sat Apr 02 08:59:29 2011
RFS[3]: Assigned to RFS process 11898
RFS[3]: Identified database type as 'physical standby': Client is ARCH pid 5029
RFS[3]: Opened log for thread 1 sequence 33395 dbid 666702615 branch 708427666
Archived Log entry 68787 added for thread 1 sequence 33394 rlc 708427666 ID 0x2cbe3767 dest 2:
Archived Log entry 68788 added for thread 1 sequence 33395 rlc 708427666 ID 0x2cbe3767 dest 2:
Sat Apr 02 08:59:33 2011
RFS[4]: Assigned to RFS process 12348
RFS[4]: Identified database type as 'physical standby': Client is ARCH pid 5037
RFS[4]: Opened log for thread 1 sequence 33396 dbid 666702615 branch 708427666
Archived Log entry 68789 added for thread 1 sequence 33396 rlc 708427666 ID 0x2cbe3767 dest 2:
Sat Apr 02 08:59:33 2011
RFS[5]: Assigned to RFS process 12342
RFS[5]: Identified database type as 'physical standby': Client is LGWR ASYNC pid 24051
Primary database is in MAXIMUM PERFORMANCE mode
RFS[5]: Opened log for thread 1 sequence 33397 dbid 666702615 branch 708427666
Archived Log entry 68790 added for thread 1 sequence 33397 rlc 708427666 ID 0x2cbe3767 dest 2:
RFS[5]: Opened log for thread 1 sequence 33398 dbid 666702615 branch 708427666
Sat Apr 02 09:00:17 2011
RFS[6]: Assigned to RFS process 18674
RFS[6]: Identified database type as 'physical standby': Client is ARCH pid 5021
Sat Apr 02 09:00:23 2011
Archived Log entry 68791 added for thread 1 sequence 33398 rlc 708427666 ID 0x2cbe3767 dest 2:
RFS[5]: Opened log for thread 1 sequence 33399 dbid 666702615 branch 708427666

and here is the section of the alert.log file of the production standby database during the switchover:

Sat Apr 02 08:58:41 2011
Media Recovery Waiting for thread 1 sequence 33392
Sat Apr 02 08:58:41 2011
Archived Log entry 34084 added for thread 1 sequence 33391 ID 0x2a7ee921 dest 1:
Sat Apr 02 08:58:51 2011
RFS[6]: Assigned to RFS process 23317
RFS[6]: Identified database type as 'physical standby': Client is ARCH pid 8452
Sat Apr 02 08:59:01 2011
RFS[7]: Assigned to RFS process 23326
RFS[7]: Identified database type as 'physical standby': Client is Foreground pid 8432
RFS[7]: Selected log 6 for thread 1 sequence 33392 dbid 666702615 branch 708427666
Sat Apr 02 08:59:01 2011
Archived Log entry 34085 added for thread 1 sequence 33392 ID 0x2a7ee921 dest 1:
Sat Apr 02 08:59:02 2011
Media Recovery Log /u01/oradata/sss/arch/log1_33392_708427666.arc
Media Recovery Waiting for thread 1 sequence 33393
Sat Apr 02 08:59:11 2011
RFS[8]: Assigned to RFS process 23340
RFS[8]: Identified database type as 'physical standby': Client is ARCH pid 8452
Sat Apr 02 08:59:18 2011
RFS[9]: Assigned to RFS process 24039
RFS[9]: Identified database type as 'physical standby': Client is Foreground pid 8432
RFS[9]: Opened log for thread 1 sequence 33393 dbid 666702615 branch 708427666
Archived Log entry 34086 added for thread 1 sequence 33393 rlc 708427666 ID 0x2a7ee921 dest 2:
Sat Apr 02 08:59:18 2011
Media Recovery Log /u01/oradata/sss/arch/log1_33393_708427666.arc
Identified End-Of-Redo for thread 1 sequence 33393
Resetting standby activation ID 712960289 (0x2a7ee921)
Media Recovery End-Of-Redo indicator encountered
Media Recovery Continuing
Resetting standby activation ID 712960289 (0x2a7ee921)
Media Recovery Waiting for thread 1 sequence 33394
Sat Apr 02 08:59:19 2011
RFS[10]: Assigned to RFS process 24045
RFS[10]: Identified database type as 'physical standby': Client is Foreground pid 8432
Sat Apr 02 08:59:25 2011
ALTER DATABASE RECOVER MANAGED STANDBY DATABASE CANCEL
MRP0: Background Media Recovery cancelled with status 16037
Errors in file /opt/oracle/diag/rdbms/standby/sss/trace/sss_pr00_6126.trc:
ORA-16037: user requested cancel of managed recovery operation
Managed Standby Recovery not using Real Time Apply
Recovery interrupted!
Waiting for MRP0 pid 6122 to terminate
Errors in file /opt/oracle/diag/rdbms/standby/sss/trace/sss_pr00_6126.trc:
ORA-16037: user requested cancel of managed recovery operation
Sat Apr 02 08:59:26 2011
MRP0: Background Media Recovery process shutdown (sss)
Managed Standby Recovery Canceled (sss)
Completed: ALTER DATABASE RECOVER MANAGED STANDBY DATABASE CANCEL
ALTER DATABASE COMMIT TO SWITCHOVER TO PRIMARY WAIT WITH SESSION SHUTDOWN
ALTER DATABASE SWITCHOVER TO PRIMARY (sss)
Maximum wait for role transition is 15 minutes.
Backup controlfile written to trace file /opt/oracle/diag/rdbms/standby/sss/trace/sss_rsm0_5074.trc
SwitchOver after complete recovery through change 241462639865
Online log /u03/oradata/sss/redo01.rdo: Thread 1 Group 1 was previously cleared
Online log /u03/oradata/sss/redo02.rdo: Thread 1 Group 2 was previously cleared
Online log /u03/oradata/sss/redo03.rdo: Thread 1 Group 3 was previously cleared
Standby became primary SCN: 241462639863
Switchover: Complete - Database mounted as primary
Completed: ALTER DATABASE COMMIT TO SWITCHOVER TO PRIMARY WAIT WITH SESSION SHUTDOWN
Sat Apr 02 08:59:26 2011
ARC7: Becoming the 'no SRL' ARCH
Sat Apr 02 08:59:29 2011
ARC8: Becoming the 'no SRL' ARCH
ALTER SYSTEM SET log_archive_dest_2='service="horvitz"','LGWR ASYNC NOAFFIRM delay=0 optional compression=disable max_failure=0 max_connections=1 reopen=300 db_unique_name="horvitz" net_timeout=30','valid_for=(all_logfiles,primary_role)' SCOPE=BOTH;
ALTER DATABASE OPEN
Data Guard Broker initializing...
Switching redo format version from 11.1.0.0.0 to 11.2.0.0.0 at change 241462639868
Thread 1 advanced to log sequence 33395 (COMPATIBLE advance)
Sat Apr 02 08:59:29 2011
Assigning activation ID 750663527 (0x2cbe3767)
Thread 1 advanced to log sequence 33396 (thread open)
Sat Apr 02 08:59:29 2011
ARC9: Becoming the 'no SRL' ARCH
Thread 1 opened at log sequence 33396
Current log# 3 seq# 33396 mem# 0: /u03/oradata/sss/redo03.rdo
Successful open of redo thread 1
Sat Apr 02 08:59:29 2011
ARC0: Becoming the 'no SRL' ARCH
Archived Log entry 34087 added for thread 1 sequence 33394 ID 0x2cbe3767 dest 1:
Sat Apr 02 08:59:29 2011
NSA2 started with pid=32, OS id=24051
Sat Apr 02 08:59:29 2011
ARC1: Becoming the 'no SRL' ARCH
Archived Log entry 34088 added for thread 1 sequence 33395 ID 0x2cbe3767 dest 1:
Sat Apr 02 08:59:29 2011
SMON: enabling cache recovery
Thread 1 advanced to log sequence 33397 (LGWR switch)
Current log# 1 seq# 33397 mem# 0: /u03/oradata/sss/redo01.rdo
******************************************************************
LGWR: Setting 'active' archival for destination LOG_ARCHIVE_DEST_2
******************************************************************
Sat Apr 02 08:59:32 2011
Archived Log entry 34091 added for thread 1 sequence 33396 ID 0x2cbe3767 dest 1:
Successfully onlined Undo Tablespace 1.
Dictionary check beginning
Dictionary check complete
Verifying file header compatibility for 11g tablespace encryption..
Verifying 11g file header compatibility for tablespace encryption completed
SMON: enabling tx recovery
Database Characterset is AL32UTF8
No Resource Manager plan active
replication_dependency_tracking turned off (no async multimaster replication found)
Sat Apr 02 08:59:36 2011
Starting background process QMNC
Sat Apr 02 08:59:36 2011
QMNC started with pid=33, OS id=24060
LOGSTDBY: Validating controlfile with logical metadata
LOGSTDBY: Validation complete
Completed: ALTER DATABASE OPEN
ALTER SYSTEM SET log_archive_trace=0 SCOPE=BOTH SID='sss';
ALTER SYSTEM SET log_archive_format='log%t_%s_%r.arc' SCOPE=SPFILE SID='sss';
ALTER SYSTEM SET standby_file_management='AUTO' SCOPE=BOTH SID='*';
ALTER SYSTEM SET archive_lag_target=1800 SCOPE=BOTH SID='*';
ALTER SYSTEM SET log_archive_max_processes=10 SCOPE=BOTH SID='*';
ALTER SYSTEM SET log_archive_min_succeed_dest=1 SCOPE=BOTH SID='*';
ALTER SYSTEM ARCHIVE LOG
Thread 1 advanced to log sequence 33398 (LGWR switch)
Current log# 2 seq# 33398 mem# 0: /u03/oradata/sss/redo02.rdo
Sat Apr 02 08:59:37 2011
ARC7: STARTING ARCH PROCESSES
Archived Log entry 34094 added for thread 1 sequence 33397 ID 0x2cbe3767 dest 1:
Sat Apr 02 08:59:37 2011
ARCa started with pid=34, OS id=24064
ARCa: Archival started
ARC7: STARTING ARCH PROCESSES COMPLETE
Sat Apr 02 08:59:43 2011
Starting background process CJQ0
Sat Apr 02 08:59:43 2011
CJQ0 started with pid=39, OS id=24099
Setting Resource Manager plan SCHEDULER[0xFD16]:DEFAULT_MAINTENANCE_PLAN via scheduler window
Setting Resource Manager plan DEFAULT_MAINTENANCE_PLAN via parameter
Sat Apr 02 08:59:47 2011
Starting background process VKRM
Sat Apr 02 08:59:47 2011
VKRM started with pid=38, OS id=24118
Sat Apr 02 09:00:17 2011
Shutting down archive processes
Sat Apr 02 09:00:17 2011
ARCH shutting down
ARCa: Archival stopped
Sat Apr 02 09:00:20 2011
ALTER SYSTEM ARCHIVE LOG
Sat Apr 02 09:00:20 2011
Thread 1 cannot allocate new log, sequence 33399
Checkpoint not complete
Current log# 2 seq# 33398 mem# 0: /u03/oradata/sss/redo02.rdo
Thread 1 advanced to log sequence 33399 (LGWR switch)
Current log# 3 seq# 33399 mem# 0: /u03/oradata/sss/redo03.rdo
Archived Log entry 34096 added for thread 1 sequence 33398 ID 0x2cbe3767 dest 1:

ORA-16765 + ORA-16826: apply service state is inconsistent with the DelayMins property with Dataguard Broker 28 October 2010

Last Saturday I had to start-up our DR Database as the server went down 3 days before due to maintenance.

It should have been an easy task as the DR database was lagging “only” 400 files behind and all archivelogs were on the primary database.

The problem:

I had the following errors on the Dataguard Broker:

ORA-16765: Redo Apply is running

and

ORA-16826: apply service state is inconsistent with the DelayMins property

I first thought it was related to how much time we allow the standby database to be behind the primary, but it is not the case.

The solution:

I did copy all necessary archivelogs from the primary server to the standby server using SCP.

Once I had the necessary archivelogs, I registered using the following script:


spool /tmp/register.sql
begin
for i in 38010 .. 38060 loop
dbms_output.put_line ('alter database register logfile ''/u01/oradata/dbname/arch/1_'||i||'_697561259.arc'';');
end loop;
end;
/
@/tmp/register.sql


where:
1.- 38010 is the first archivelog file the standby was waiting for.
2.- 38060 is the last archivelog being generated by the primary database.

Once archivelogs were registered, the database started to apply them.

With only two logfiles behind, I decided to enable dataguard broker but the same error happened.

The only way I could get around was:

1.- To remove the standby database from the configuration:
DGMGRL> remove database 'dr_database';
Removed database "dr_database" from the configuration

2.- Add the database back to the configuration:
DGMGRL> add database 'dr_database' as connect identifier is 'dr_database';
Database "dr_database" added

3.- And then enable it again:
DGMGRL> enable database 'dr_database';
Enabled.

And voila, it started to work again.

As always, comments are welcome.