We are getting ORA-3113 error(OEM12C Alert) for our primary database from time to time. This alert is followed by ORA-16778 then in few minutes it gets cleared with the following statement.
Message=The Data Guard status of PROD is Normal ORA-00000: normal, successful completion.
During this time we see the following:
Error in standby Alert log:
I see a "RFS[62]: Possible network disconnect with primary database" in the standby alert log
Errors in Primary alert log error:
NSA: Error 3113 archiving log 1 to 'PRODSBY'
Errors in file /orcl/adm/diag/rdbms/prodprod/PRODPROD/trace/PRODPROD_nsa2_20979.trc:
ORA-03113: end-of-file on communication channel
LNS: Failed to archive log 1 thread 1 sequence 1824370 (3113)
Thu Dec 28 13:00:08 2017
ARC1: Archive log rejected (thread 1 sequence 1824369) at host 'PRODSBY'
FAL[server, ARC1]: FAL archive failed, see trace file.
ARCH: FAL archive failed. Archiver continuing
Error in the trace file referenced above:
*** 2017-12-28 13:00:08.913
*** 2017-12-28 13:00:08.913 3322 krsb.c
krsb_iorb_reap: Error 3113 reaping buffers
krsb_bcb_get: Error 3113 performing stall for 1 BCB I/O completion check
*** 2017-12-28 13:00:08.914 4265 krsh.c
NSA: Error 3113 archiving log 1 to 'PRODSBY'
Error 1041 detaching RFS from standby instance at host 'PRODSBY'
*** 2017-12-28 13:00:08.914 2864 krsi.c
krsi_dst_fail: dest:2 err:3113 force:0 blast:1
ORA-03113: end-of-file on communication channel
Closing Redo Read Context
Time when the alert clears in trace file:
*** 2017-12-28 13:06:18.835
Destination is specified with ASYNC=30720
Redo shipping client performing standby login
*** 2017-12-28 13:06:19.068 4595 krsu.c
Logged on to standby successfully
Client logon and security negotiation successful!
when we query V$archived_log view(as shown below) the DEST_ID for the time when the issue happens until it clears changes from 1 to 2 and goes back to 1 when this issue is cleared. As of now our network team do not see any problem with the network so not sure what could be causing the break in communication between the standby/primary. Also I would highly appreciate someone explaining why the DEST_ID in v$archived_log results is changing from 1 to 2 and back to 1 what is happening during this time frame.
Seq# Dest CREATOR REGISTR TO_CHAR(FIRST_TIM TO_CHAR(NEXT_TIME APPLIED
-------- ---- ------- ------- ----------------- ----------------- ---------
1824368 1 ARCH RFS 12/28/17 12:59:18 12/28/17 12:59:24 YES
1824369 1 ARCH RFS 12/28/17 12:59:24 12/28/17 12:59:36 YES
1824370 1 ARCH RFS 12/28/17 12:59:36 12/28/17 12:59:55 YES
1824371 2 ARCH RFS 12/28/17 12:59:55 12/28/17 13:00:16 YES
1824372 2 ARCH RFS 12/28/17 13:00:16 12/28/17 13:00:34 YES
1824373 2 ARCH RFS 12/28/17 13:00:34 12/28/17 13:00:54 YES
1824374 2 ARCH RFS 12/28/17 13:00:54 12/28/17 13:01:12 YES
1824375 2 ARCH RFS 12/28/17 13:01:12 12/28/17 13:01:25 YES
1824376 2 ARCH RFS 12/28/17 13:01:25 12/28/17 13:01:47 YES
1824377 2 ARCH RFS 12/28/17 13:01:47 12/28/17 13:01:59 YES
1824378 2 ARCH RFS 12/28/17 13:01:59 12/28/17 13:02:17 YES
Seq# Dest CREATOR REGISTR TO_CHAR(FIRST_TIM TO_CHAR(NEXT_TIME APPLIED
-------- ---- ------- ------- ----------------- ----------------- ---------
1824379 2 ARCH RFS 12/28/17 13:02:17 12/28/17 13:02:36 YES
1824380 2 ARCH RFS 12/28/17 13:02:36 12/28/17 13:02:54 YES
1824381 2 ARCH RFS 12/28/17 13:02:54 12/28/17 13:03:19 YES
1824382 2 ARCH RFS 12/28/17 13:03:19 12/28/17 13:03:37 YES
1824383 2 ARCH RFS 12/28/17 13:03:37 12/28/17 13:03:54 YES
1824384 2 ARCH RFS 12/28/17 13:03:54 12/28/17 13:04:20 YES
1824385 2 ARCH RFS 12/28/17 13:04:20 12/28/17 13:05:06 YES
1824386 2 ARCH RFS 12/28/17 13:05:06 12/28/17 13:06:18 YES
1824387 1 ARCH RFS 12/28/17 13:06:18 12/28/17 13:08:48 YES
1824388 1 ARCH RFS 12/28/17 13:08:48 12/28/17 13:13:35 YES
1824389 1 ARCH RFS 12/28/17 13:13:35 12/28/17 13:18:43 YES
DB Version 11.2.0.2
Platform HP-UX