Failovers with Oracle Dataguard
In the last month, we have been hit with two clients’ large-scale failures. The first involved network issues; the second, disk failures. Fun fun.
We have one production and two standby environments. In the case of the first failure we went into our trusty dataguard config and performed what can only be described as a minor miracle.
First we connected to the standby that was to become the primary.
Welcome to DGMGRL, type "help" for information. DGMGRL> connect sys/xxxxx@rcatstdby2 Connected. DGMGRL> show configuration; Configuration Name: rcat Enabled: YES Protection Mode: MaxPerformance Fast-Start Failover: DISABLED Databases: rcat_aussw10_db - Physical standby database rcat_nflsw01_db - Primary database rcat_aussw20_db - Physical standby database Current status for "rcat": ^C
We had to control-c out because it hung: it could not connect to nflsw01 and we knew that at least dataguard thought there was a problem. Then we took the steps that separate the men from the boys.
oracle@aussw10-->(ORACLE_SID = rcat) ** prodstdby2, rcatstdby2, limtest, COREprod, ** /home/oracle> dgmgrl DGMGRL for Solaris: Version 10.2.0.2.0 - 64bit Production Copyright (c) 2000, 2005, Oracle. All rights reserved. Welcome to DGMGRL, type "help" for information. DGMGRL> connect sys/xxxxxxx@rcatstdby2 Connected. DGMGRL> remove site rcat_nflsw01_db you cannot remove the primary site DGMGRL> failover to rcat_aussw10_db graceful; Performing failover NOW, please wait... Failover succeeded, new primary is "rcat_aussw10_db" DGMGRL> show configuration Configuration Name: rcat Enabled: YES Protection Mode: MaxPerformance Fast-Start Failover: DISABLED Databases: rcat_aussw10_db - Primary database rcat_nflsw01_db - Physical standby database (disabled) rcat_aussw20_db - Physical standby database Current status for "rcat": SUCCESS DGMGRL>
That was it. What a let down! No magical status updates, no little “dots” going across the screen. Just one line and 15 seconds. Oracle, get your act together! I even had to use bold text to make it stand out.
What happened, you may ask. We took one of the standbys and turned it into a primary. The other standby then automagically started recovering from the new primary! Wow! Maybe you don’t know, but this used to be a huge, complicated process once upon a time. I remember doing — ugh! — manual failovers in the past and now it just feels so… 2005. It’s really amazing what dataguard can do isn’t it?
Sadly, it can’t take care of everything. The second disk failure managed to fubar dataguard enough that we had to do our trusty 2005 version of a manual failover. We were using standby redo logs, and when the failure hit, some of our actual archive logs hadn’t made it over because we weren’t using ASYNC. I’m still not sure how this happened, but when dataguard tried to failover, it found that we were missing archive logs and redo, and wouldn’t do a graceful failover.
Here’s this attempt with the accompanying alert log from the standby that we tried to activate.
DGMGRL> show configuration
Configuration
Name: prod
Enabled: YES
Protection Mode: MaxPerformance
Databases:
prod_aussw20_db - Primary database
prod_nflsw01_db - Physical standby database
prod_aussw10_db - Physical standby database
Current status for "prod":
Error: ORA-16625: cannot reach the primary
DGMGRL> failover to prod_nflsw01_db graceful;
Performing failover NOW. Please wait...
Error: ORA-16771: Converting physical standby to primary failed in the failover operation.
Failed.
Can not proceed to failover.
DGMGRL>
And here is the output from the alert log:
ARCH: Connecting to console port... Mon Oct 30 07:15:30 2006 Terminal Recovery: completion detected (prod) Mon Oct 30 07:15:30 2006 ARCH: Connecting to console port... Completed: ALTER DATABASE RECOVER MANAGED STANDBY DATABASE DI Mon Oct 30 07:15:30 2006 ALTER DATABASE COMMIT TO SWITCHOVER TO PRIMARY WAIT WITH SESSION SHUTDOWN Mon Oct 30 07:15:30 2006 ALTER DATABASE SWITCHOVER TO PRIMARY (prod) ARCH: Connecting to console port... If media recovery active, switchover will wait 900 seconds Database not available for switchover End-Of-REDO archived log file has not been recovered Database not available for switchover End-Of-REDO archived log file has not been recovered Switchover: Media recovery required - standby not in limbo ORA-16139 signalled during: ALTER DATABASE COMMIT TO SWITCHOVER TO PRIMARY WAI...
It unfortunate that it wasn’t smart enough to know that it had missing archive logs. I think it should have asked to perform a resetlogs or something. In the end, we found two of the three archive logs on the other standby. The third must be in ora-0600 purgatory.
For reference, I’ve added the alert log from the successful dataguard failover that I described in the first part of the article. It’s neat-o. When it works, it works incredibly well.
MRP0: Background Media Recovery cancelled with status 16037 Thu Oct 19 15:07:28 2006 Errors in file /home/oracle/app/oracle/admin/rcat/bdump/rcat_mrp0_6688.trc: ORA-16037: user requested cancel of managed recovery operation Managed Standby Recovery not using Real Time Apply Recovery interrupted! Recovered data files to a consistent state at change 68214212 Thu Oct 19 15:07:29 2006 Errors in file /home/oracle/app/oracle/admin/rcat/bdump/rcat_mrp0_6688.trc: ORA-16037: user requested cancel of managed recovery operation Thu Oct 19 15:07:29 2006 MRP0: Background Media Recovery process shutdown (rcat) Thu Oct 19 15:07:29 2006 Terminal Recovery: Stopped real time apply Thu Oct 19 15:07:29 2006 Attempt to do a Terminal Recovery (rcat) Thu Oct 19 15:07:29 2006 Media Recovery Start: Managed Standby Recovery (rcat) Managed Standby Recovery not using Real Time Apply parallel recovery started with 5 processes Terminal Recovery timestamp is '10/19/2006 15:07:31' Terminal Recovery: applying standby redo logs. Terminal Recovery: thread 1 seq# 98673 redo required Terminal Recovery: /home/oracle/oradata/rcat/sbylog1_g6.dbf Identified End-Of-Redo for thread 1 sequence 98673 Thu Oct 19 15:07:31 2006 Incomplete recovery applied all redo ever generated. Recovery completed through change 68214224 Thu Oct 19 15:07:31 2006 Media Recovery Complete (rcat) Terminal Recovery: successful completion Begin: Standby Redo Logfile archival End: Standby Redo Logfile archival Resetting standby activation ID 375195464 (0x165d0748) Completed: ALTER DATABASE RECOVER MANAGED STANDBY DATABASE FINISH FORCE Thu Oct 19 15:07:35 2006 ALTER DATABASE COMMIT TO SWITCHOVER TO PRIMARY WAIT WITH SESSION SHUTDOWN Thu Oct 19 15:07:35 2006 ALTER DATABASE SWITCHOVER TO PRIMARY (rcat) If media recovery active, switchover will wait 900 seconds Standby terminal recovery start SCN: 68214212 SwitchOver after complete recovery through change 68214224 Online log /home/oracle/oradata/rcat/log1_g1.dbf: Thread 1 Group 1 was previously cleared Online log /home/oracle/oradata/rcat/log2_g1.dbf: Thread 1 Group 1 was previously cleared Online log /home/oracle/oradata/rcat/log1_g2.dbf: Thread 1 Group 2 was previously cleared Online log /home/oracle/oradata/rcat/log2_g2.dbf: Thread 1 Group 2 was previously cleared Online log /home/oracle/oradata/rcat/log1_g3.dbf: Thread 1 Group 3 was previously cleared Online log /home/oracle/oradata/rcat/log2_g3.dbf: Thread 1 Group 3 was previously cleared Standby became primary SCN: 68214211 Converting standby mount to primary mount. Thu Oct 19 15:07:36 2006 Switchover: Complete - Database mounted as primary (rcat) Thu Oct 19 15:07:36 2006 ARC0: STARTING ARCH PROCESSES Thu Oct 19 15:07:36 2006 Completed: ALTER DATABASE COMMIT TO SWITCHOVER TO PRIMARY WAIT WITH SESSION SHUTDOWN Thu Oct 19 15:07:36 2006 ARC2: Archival started ARC0: STARTING ARCH PROCESSES COMPLETE ARC0: Becoming the 'no SRL' ARCH ARC2 started with pid=13, OS id=14326 Thu Oct 19 15:07:37 2006 ALTER SYSTEM SET standby_archive_dest='' SCOPE=BOTH SID='rcat'; Thu Oct 19 15:07:37 2006 ALTER SYSTEM SET log_archive_dest_1='location="/export/backup/arch/rcat"', 'valid_for=(ONLINE_LOGFILE,ALL_ROLES)' SCOPE=BOTH SID='rcat'; Thu Oct 19 15:07:37 2006 ALTER SYSTEM SET log_archive_dest_state_1='ENABLE' SCOPE=BOTH SID='rcat'; Thu Oct 19 15:07:37 2006 ALTER SYSTEM SET log_archive_dest_2='service="(DESCRIPTION=(ADDRESS_LIST= (ADDRESS=(PROTOCOL=tcp)(HOST=aussw20)(PORT=1521))) (CONNECT_DATA=(SERVICE_NAME=rcat_aussw20_db_XPT.aussw20.lim.com) (INSTANCE_NAME=rcat)(SERVER=dedicated)))"',' ARCH SYNC NOAFFIRM delay=0 OPTIONAL max_failure=0 max_connections=1 reopen=300 db_unique_name="rcat_aussw20_db" register net_timeout=180 valid_for=(online_logfile,primary_role)' SCOPE=BOTH; Thu Oct 19 15:07:37 2006 ALTER SYSTEM SET log_archive_dest_state_2='ENABLE' SCOPE=BOTH; Thu Oct 19 15:07:37 2006 ALTER DATABASE OPEN Thu Oct 19 15:07:38 2006 Assigning activation ID 374183684 (0x164d9704) Thread 1 opened at log sequence 98674 Current log# 2 seq# 98674 mem# 0: /home/oracle/oradata/rcat/log1_g2.dbf Current log# 2 seq# 98674 mem# 1: /home/oracle/oradata/rcat/log2_g2.dbf Successful open of redo thread 1
