In this Document
Symptoms
Cause
Solution
References
Applies to:
Oracle Server - Enterprise Edition - Version: 9.2.0.1 to 10.2.0.5 -Release: 9.2 to 10.2
Information in this document applies to any platform.
Symptoms
Recieved
ORA-16146 error in a standbydatabase and then it was resolved after a few minutes.
Alert log from Standby database:
Thu Nov 04 22:11:28 2010
RFS[28]: Archive log thread 1 sequence 143273 available in 179minute(s)
Thu Nov 04 22:29:52 2010
Media Recovery Log E:\BOD\ARC43268_0649868496.001
Thu Nov 04 22:33:51 2010
RFS[32]: No standby redo logfiles created
RFS[32]: Warning. Log sequence in archive filename wrapped
to fix length as indicated by %S in LOG_ARCHIVE_FORMAT.
Old log archive with same name might be overwritten.
RFS[32]: Archived Log: 'E:\BOD\ARC43274_0649868496.001'
Committing creation of archivelog'E:\BOD\ARC43274_0649868496.001'
Thu Nov 04 22:33:58 2010
RFS[32]: Archive log thread 1 sequence 143274 available in 179minute(s)
Thu Nov 04 22:34:12 2010
Media Recovery Delayed for 179 minute(s) (thread 1 sequence143269)
Thu Nov 04 23:00:13 2010
Media Recovery Log E:\BOD\ARC43269_0649868496.001
Thu Nov 04 23:04:13 2010
System State dumped to trace filed:\oracle\product\10.2.0\admin\bod\udump\bod_rfs_8396.trc
Thu Nov 04 23:04:26 2010
Errors in filed:\oracle\product\10.2.0\admin\bod\udump\bod_rfs_8396.trc:
ORA-16146: standby destination control file enqueueunavailable
Thu Nov 04 23:04:56 2010
Media Recovery Delayed for 179 minute(s) (thread 1 sequence143270)
Thu Nov 04 23:09:35 2010
Redo Shipping Client Connected as PUBLIC
-- Connected User is Valid
RFS[33]: Assigned to RFS process 7140
RFS[33]: Identified database type as 'physical standby'
Thu Nov 04 23:20:16 2010
RFS[33]: No standby redo logfiles created
RFS[33]: Warning. Log sequence in archive filename wrapped
to fix length as indicated by %S in LOG_ARCHIVE_FORMAT.
Old log archive with same name might be overwritten.
Thu Nov 04 23:20:45 2010
RFS[33]: Archived Log: 'E:\BOD\ARC43275_0649868496.001'
Committing creation of archivelog'E:\BOD\ARC43275_0649868496.001'
Thu Nov 04 23:20:51 2010
RFS[33]: Archive log thread 1 sequence 143275 available in 179minute(s)
Alert log from Primary database:
Thu Nov 04 22:31:16 2010
Thread 1 advanced to log sequence 143275 (LGWR switch)
Current log# 3 seq# 143275 mem# 0: F:\ORADATA\AX4W\REDO03.LOG
Current log# 3 seq# 143275 mem# 1:G:\ORADATA\AX4W\REDO03A.LOG
Thu Nov 04 22:31:18 2010
ARCH: Evaluating archive log 2 thread 1 sequence 143274
ARCH: Destination LOG_ARCHIVE_DEST_2 archival not expedited
ARCH: Warning. Log sequence in archive filename wrapped
to fix length as indicated by %S in LOG_ARCHIVE_FORMAT.
Old log archive with same name might be overwritten.
Thu Nov 04 22:31:22 2010
ARC2: Evaluating archive log 2 thread 1 sequence 143274
ARC2: Unable to archive thread 1 sequence 143274
Log actively being archived by another process
Thu Nov 04 22:33:01 2010
Committing creation of archivelog'E:\AX4W\ARC43274_0649868496.001'
Invoking non-expedited destination LOG_ARCHIVE_DEST_2 thread 1sequence 143274 host(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=tcp)(HOST=VIE-AXWDB002)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=BOD_XPT)(INSTANCE_NAME=bod)(SERVER=dedicated)))
Thu Nov 04 22:33:51 2010
FAL[server, ARC3]: Begin FAL noexpedite archive (dbid 0 branch649868496 thread 1 sequence 143274 dest(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=tcp)(HOST=VIE-AXWDB002)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=BOD_XPT)(INSTANCE_NAME=bod)(SERVER=dedicated))))
ARC3: Transmitting activation ID 0x375d5c10
FAL[server, ARC3]: Archive log branch 649868496 thread 1 sequence143274 available in 180 minute(s)
FAL[server, ARC3]: Complete FAL noexpedite archive (dbid 0 branch649868496 thread 1 sequence 143274 destination(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=tcp)(HOST=VIE-AXWDB002)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=BOD_XPT)(INSTANCE_NAME=bod)(SERVER=dedicated))))
Thu Nov 04 23:04:26 2010
PING[ARC1]: Error 16146 when pinging standby(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=tcp)(HOST=VIE-AXWDB002)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=BOD_XPT)(INSTANCE_NAME=bod)(SERVER=dedicated))).
Thu Nov 04 23:18:16 2010
Thread 1 advanced to log sequence 143276 (LGWR switch)
Current log# 1 seq# 143276 mem# 0: F:\ORADATA\AX4W\REDO01.LOG
Current log# 1 seq# 143276 mem# 1:G:\ORADATA\AX4W\REDO01A.LOG
Thu Nov 04 23:18:17 2010
ARC0: Evaluating archive log 3 thread 1 sequence 143275
ARC0: Destination LOG_ARCHIVE_DEST_2 archival not expedited
ARC0: Warning. Log sequence in archive filename wrapped
to fix length as indicated by %S in LOG_ARCHIVE_FORMAT.
Old log archive with same name might be overwritten.
Thu Nov 04 23:18:44 2010
Starting control autobackup
Thu Nov 04 23:20:08 2010
Committing creation of archivelog'E:\AX4W\ARC43275_0649868496.001'
Thu Nov 04 23:20:08 2010
Control autobackup written to SBT_TAPE device
comment 'API Version 2.0,MMS Version 4.5.0.0',
media 'A20836JA'
handle 'c-928837136-20101104-07'
Thu Nov 04 23:20:11 2010
Invoking non-expedited destination LOG_ARCHIVE_DEST_2 thread 1sequence 143275 host(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=tcp)(HOST=VIE-AXWDB002)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=BOD_XPT)(INSTANCE_NAME=bod)(SERVER=dedicated)))
Thu Nov 04 23:20:12 2010
FAL[server, ARC1]: Begin FAL noexpedite archive (dbid 0 branch649868496 thread 1 sequence 143275 dest(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=tcp)(HOST=VIE-AXWDB002)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=BOD_XPT)(INSTANCE_NAME=bod)(SERVER=dedicated))))
Thu Nov 04 23:20:56 2010
FAL[server, ARC1]: Archive log branch 649868496 thread 1 sequence143275 available in 180 minute(s)
FAL[server, ARC1]: Complete FAL noexpedite archive (dbid 0 branch649868496 thread 1 sequence 143275 destination(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=tcp)(HOST=VIE-AXWDB002)(PORT=1521)))(CONNECT_DATA=(SERVICE_NAME=BOD_XPT)(INSTANCE_NAME=bod)(SERVER=dedicated))))
Thu Nov 04 23:26:55 2010
Thread 1 advanced to log sequence 143277 (LGWR switch)
Current log# 4 seq# 143277 mem# 0: F:\ORADATA\AX4W\REDO04.LOG
Current log# 4 seq# 143277 mem# 1:G:\ORADATA\AX4W\REDO04A.LOG
Cause
High Utilization of the Network and/or the Database.
Solution
ORA-16146 is usually not a serious error, The ORA-16146 basicallymeans that the ARCH-Process is not able to get an exclusiveControlfile Access (Enqueue) on the Standby Controlfile. In a DataGuard Environment many processes are updating the StandbyControlfile and require an
exclusive Enqueue for that (eg. ARCn, MRP0, RFS,...).
This error does not cause any disruption to the primary or thestandby. It is possible that updates to datafiles, which are doneunder c/f enqueue, can take a long time, and as such there could beperiods where the ControlFile enqueue is under contention.
Typical causes for that are performance problems or a too slow I/Oon the Standby controlfile.
Please ensure the Standby controlfile is placed on a separate diskas the
datafiles and archived logs and those disks are the fastest on theStandby system so that I/O-Delay is as low as possible on the I/Oto the Standby Controlfile(s).
If you encounter this behavior especially during peak times whenthere is also a lot of data to be applied to the Standby, it mightalso be helpful to stop the recovery process on the Standby duringthese times and only perform log shipping. The apply can then beresumed later after the peak.
Also,you could calculate your network bandwidth if its sufficientor not by following this Best Practice white paper::
http://www.oracle.com/technetwork/database/features/availability/maa-wp-10gr2-dataguardnetworkbestpr-134557.pdf
Topic: How Much Bandwidth is Enough?References
