Hi guys,
Last saturday I've migrated a database 11.2.0.3.15 (In Oracle Database Appliance Engineered System) from using ASM disk groups to ASM Cluster File Systems.
Suddenly I see an unexpected behavior, Archived Redo Logs take too much time to be applied in the standby database.
Connection between the servers is good, redo transport is good but not the archived redo log applying.
Also I see the following wait events:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
When I DE ACTIVATE the recovery in Standby Server
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
SQL> alter database recover managed standby database cancel;
SQL> sta waits
WAIT_CLASS EVENT T0 T1 T2 T3 T4 T5 T6 T7 T8 T9
-------------------- ------------------------------ ---- ---- ---- ---- ---- ---- ---- ---- ---- ----
System I/O RFS write 1
System I/O Standby redo I/O 1 1 1
System I/O db file async I/O submit 1 1 1 1 1 1 1 1 1 1
Other MRP inactivation 1 1 1 1 1 1 1 1 1 1
Network SQL*Net message to client 1 1 1 1 1 1 1 1 1 1
Configuration checkpoint completed 5 5 5 5 5 5 5 5 5 5 <<<<<<<<<This lock everything
---- ---- ---- ---- ---- ---- ---- ---- ---- ----
sum 8 9 8 8 8 8 9 9 8 9
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Lock tree
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Username OS User SID SERIAL Program Lock Wait Waiting Time (Min) Status Machine Logon Time EVENT
-------------------- -------------------- ----- ---------- ---------------------------------------- ---------------- ------------------ ---------- ------------------------- -------------------- --------------------------------------------------
(oracle) oracle 1367 1 oracle@dbscc-qro1 (CKPT) 0 ACTIVE dbscc-qro1 16-MAY-2016 10:58:43 rdbms ipc message
..(oracle) oracle 688 5 oracle@dbscc-qro1 (PR04) 0 ACTIVE dbscc-qro1 16-MAY-2016 11:56:19 checkpoint completed
..(oracle) oracle 1370 19 oracle@dbscc-qro1 (PR08) 0 ACTIVE dbscc-qro1 16-MAY-2016 11:56:19 checkpoint completed
..(oracle) oracle 2394 5 oracle@dbscc-qro1 (PR01) 0 ACTIVE dbscc-qro1 16-MAY-2016 11:56:19 checkpoint completed
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
When I ACTIVATE the recovery in Standby Server
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
SQL> alter database recover managed standby database using current logfile disconnect;
SQL> sta waits
WAIT_CLASS EVENT T0 T1 T2 T3 T4 T5 T6 T7 T8 T9
-------------------- ------------------------------ ---- ---- ---- ---- ---- ---- ---- ---- ---- ----
Network SQL*Net message to client 1 1 1 1 1 1 1 1 1 1
Other enq: CF - contention 1 1 1 1 1 1 1 1 1 1
User I/O db file single write 1 1 1 1 1 1 1 1 1 1
System I/O db file async I/O submit 1 1 1 1 1 1 1 1 1 1
---- ---- ---- ---- ---- ---- ---- ---- ---- ----
sum 4 4 4 4 4 4 4 4 4 4
Username OS User SID SERIAL Program Lock Wait Waiting Time (Min) Status Machine Logon Time EVENT
-------------------- -------------------- ----- ---------- ---------------------------------------- ---------------- ------------------ ---------- ------------------------- -------------------- --------------------------------------------------
(oracle) oracle 1367 1 oracle@dbscc-qro1 (CKPT) 0 ACTIVE dbscc-qro1 16-MAY-2016 10:58:43 rdbms ipc message
..(oracle) oracle 6 7 oracle@dbscc-qro1 (PR02) 0 ACTIVE dbscc-qro1 16-MAY-2016 12:08:24 checkpoint completed
..(oracle) oracle 347 7 oracle@dbscc-qro1 (PR03) 0 ACTIVE dbscc-qro1 16-MAY-2016 12:08:24 checkpoint completed
..(oracle) oracle 688 7 oracle@dbscc-qro1 (PR04) 0 ACTIVE dbscc-qro1 16-MAY-2016 12:08:24 checkpoint completed
..(oracle) oracle 1029 9 oracle@dbscc-qro1 (PR07) 0 ACTIVE dbscc-qro1 16-MAY-2016 12:08:24 checkpoint completed
..(oracle) oracle 1370 25 oracle@dbscc-qro1 (PR08) 0 ACTIVE dbscc-qro1 16-MAY-2016 12:08:24 checkpoint completed
..(oracle) oracle 2394 7 oracle@dbscc-qro1 (PR01) 0 ACTIVE dbscc-qro1 16-MAY-2016 12:08:24 checkpoint completed
7 rows selected.
An also when...
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
When I perform a SWITCH LOG (alter system archive log current;) in Primary database, I see the following in standby database:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Username OS User SID SERIAL Program Lock Wait Waiting Time (Min) Status Machine Log on Time EVENT
-------------------- -------------------- ----- ---------- ---------------------------------------- ---------------- ------------------ ---------- ------------------------- --- ----------------- --------------------------------------------------
(oracle) oracle 2053 7 oracle@dbscc-qro1 (PR00) 0 ACTIVE dbscc-qro1 16- MAY-2016 12:08:00 db file single write
..PUBLIC oracle 2055 3 oracle@dbscc-sf1 (TNS V1-V3) 0000002325DAA9C0 0 ACTIVE dbscc-sf1 16- MAY-2016 11:11:53 enq: CF - contention
..(oracle) oracle 2392 1 oracle@dbscc-qro1 (ARC2) 0000002325DAD310 0 ACTIVE dbscc-qro1 16- MAY-2016 10:58:50 enq: CF - contention
..PUBLIC oracle 2396 3 oracle@dbscc-sf2 (TNS V1-V3) 0000002325D7A7D8 0 ACTIVE dbscc-sf2 16- MAY-2016 11:11:51 enq: CF - contention
4 rows selected.
I am lost in this, because ACFS is a system layer on ASM, why I am facing this delays or this waits events?
GI version 12.1.0.2
RDBMS version 11.2.0.3.15
OS version: Oracle Linux 5.11
In addition, controlfile & redo log files including the standby redo logs, are stored over a filesystem mounted on "/u01/app/oracle/oradata/datastore" using the asm volume "/dev/asm/datastore-18" created on REDO asm disk group with SSD disks.
Please guide about what to check or do in order to speed the archived redo log application.
Regards,
Juan M