dataguard 错误分析之RESOLVABLE GAP

查询主库GAP_STATUSRESOLVABLE GAP

select STATUS, GAP_STATUS from V$ARCHIVE_DEST_STATUS where DEST_ID = 2;

检查从库日志应用情况：

select SEQUENCE#, FIRST_TIME, NEXT_TIME, APPLIED, ARCHIVED from V$ARCHIVED_LOG where name = 'srvdbhz1' order by FIRST_TIME desc; 

从几天前起，applied字段都为NO，说明主库的日志没有应用到从库；

检查alert日志：

Fatal NI connect error 12170.


  VERSION INFORMATION:
        TNS for Linux: Version 11.2.0.4.0 - Production
        Oracle Bequeath NT Protocol Adapter for Linux: Version 11.2.0.4.0 - Production
        TCP/IP NT Protocol Adapter for Linux: Version 11.2.0.4.0 - Production
  Time: 29-72014 19:06:56
  Tracing not turned on.
  Tns error struct:
    ns main err code: 12535
    
TNS-12535: TNS: 


                     ns secondary err code: 12560
    nt main err code: 505
    
TNS-00505: 


                nt secondary err code: 110
    nt OS err code: 0
  Client address: (ADDRESS=(PROTOCOL=tcp)(HOST=10.18.220.144)(PORT=4607))
Tue Jul 29 19:06:57 2014
Error 1041 received logging on to the standby
FAL[server, ARC5]: Error 1041 creating remote archivelog file 'srvdbhz1'
FAL[server, ARC5]: FAL archive failed, see trace file.
ARCH: FAL archive failed. Archiver continuing
ORACLE Instance serverdbnj1 - Archival Error. Archiver continuing.
Tue Jul 29 19:06:57 2014
Error 1041 received logging on to the standby
FAL[server, ARC3]: Error 1041 creating remote archivelog file 'srvdbhz1'
FAL[server, ARC3]: FAL archive failed, see trace file.
ARCH: FAL archive failed. Archiver continuing
ORACLE Instance serverdbnj1 - Archival Error. Archiver continuing.
nullTue Jul 29 19:07:54 2014
WARN: ARC1: Terminating pid 2596 hung on an I/O operation
Killing 1 processes with pids 2596 (Process by index) in order to remove hung processes. Requested by OS process 24785
ARC1: Detected ARCH process failure
ARC1: STARTING ARCH PROCESSES
Tue Jul 29 19:07:57 2014
ARC4 started with pid=56, OS id=5567 
ARC4: Archival started
ARC1: STARTING ARCH PROCESSES COMPLETE
Reclaiming FAL entry from dead process [pid 2596]
Tue Jul 29 19:08:19 2014
Error 1041 received logging on to the standby
FAL[server, ARC0]: Error 1041 creating remote archivelog file 'srvdbhz1'
FAL[server, ARC0]: FAL archive failed, see trace file.
ARCH: FAL archive failed. Archiver continuing
ORACLE Instance serverdbnj1 - Archival Error. Archiver continuing.
Tue Jul 29 19:08:19 2014
NSA:  Error 3113 archiving log 3 to 'srvdbhz1'
Errors in file /bee/app/oracle/diag/rdbms/serverdbnj1/serverdbnj1/trace/serverdbnj1_nsa2_1158.trc:
ORA-03113: end-of-file on communication channel
LNS: Failed to archive log 3 thread 1 sequence 38110 (3113)
nullTue Jul 29 19:12:58 2014
WARN: ARC1: Terminating pid 21874 hung on an I/O operation
Killing 1 processes with pids 21874 (Process by index) in order to remove hung processes. Requested by OS process 24785
ARC1: Error 16198 due to hung I/O operation to LOG_ARCHIVE_DEST_2
ARC1: Detected ARCH process failure
ARC1: STARTING ARCH PROCESSES
Tue Jul 29 19:13:00 2014
ARC7 started with pid=90, OS id=6024 
ARC7: Archival started
ARC1: STARTING ARCH PROCESSES COMPLETE
Reclaiming FAL entry from dead process [pid 21874]
Tue Jul 29 19:14:01 2014

检查trac日志

[root@serverdbnj01 serverdbnj1]# cat /bee/app/oracle/diag/rdbms/serverdbnj1/serverdbnj1/trace/serverdbnj1_nsa2_16703.trc
Trace file /bee/app/oracle/diag/rdbms/serverdbnj1/serverdbnj1/trace/serverdbnj1_nsa2_16703.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /bee/app/oracle/product/11.2.0/db_1
System name:    Linux
Node name:      serverdbnj01
Release:        2.6.32-358.el6.x86_64
Version:        #1 SMP Tue Jan 29 11:47:41 EST 2013
Machine:        x86_64
Instance name: serverdbnj1
Redo thread mounted by this instance: 1
Oracle process number: 148
Unix process pid: 16703, image: oracle@serverdbnj01 (NSA2)




*** 2014-07-29 12:57:26.463
*** SESSION ID:(1532.34463) 2014-07-29 12:57:26.463
*** CLIENT ID:() 2014-07-29 12:57:26.463
*** SERVICE NAME:(SYS$BACKGROUND) 2014-07-29 12:57:26.463
*** MODULE NAME:() 2014-07-29 12:57:26.463
*** ACTION NAME:() 2014-07-29 12:57:26.463
 
*** 2014-07-29 12:57:26.457 1279 krsw.c
NSA2: initializing for LGWR communication
NSA2: connecting to KSR channel
Success
NSA2: subscribing to KSR channel
Success
*** 2014-07-29 12:57:26.463 1324 krsw.c
NSA2: initialized successfully ASYNC=1


*** 2014-07-29 13:03:21.974
Destination is specified with ASYNC=61440


*** 2014-07-29 13:03:23.752
Log file opened [logno 1]


*** 2014-07-29 13:10:57.916
*** 2014-07-29 13:10:57.916 3328 krsb.c
krsb_iorb_reap: Error 3113 reaping buffers
krsb_bcb_get: Error 3113 performing stall for 1 BCB I/O completion check
*** 2014-07-29 13:10:57.916 4329 krsh.c
NSA:  Error 3113 archiving log 1 to 'srvdbhz1'
Error 1041 detaching RFS from standby instance at host 'srvdbhz1'
*** 2014-07-29 13:10:57.917 2917 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 
Destination is specified with ASYNC=61440


*** 2014-07-29 13:14:59.630
Log file opened [logno 2]


*** 2014-07-29 13:26:13.847
*** 2014-07-29 13:26:13.847 3328 krsb.c
krsb_iorb_reap: Error 3140 reaping buffers
krsb_bcb_get: Error 3113 performing stall for 1 BCB I/O completion check
*** 2014-07-29 13:26:13.848 4329 krsh.c
NSA:  Error 3113 archiving log 2 to 'srvdbhz1'
Error 1041 detaching RFS from standby instance at host 'srvdbhz1'
*** 2014-07-29 13:26:13.848 2917 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 
Destination is specified with ASYNC=61440


*** 2014-07-29 13:30:06.044
Log file opened [logno 4]


*** 2014-07-29 13:51:55.704
*** 2014-07-29 13:51:55.704 3328 krsb.c
krsb_iorb_reap: Error 3113 reaping buffers
krsb_bcb_get: Error 3113 performing stall for 1 BCB I/O completion check
*** 2014-07-29 13:51:55.705 4329 krsh.c
NSA:  Error 3113 archiving log 4 to 'srvdbhz1'
Error 1041 detaching RFS from standby instance at host 'srvdbhz1'
*** 2014-07-29 13:51:55.705 2917 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 


*** 2014-07-29 14:00:36.776
Destination is specified with ASYNC=61440


*** 2014-07-29 14:00:37.625
Log file opened [logno 1]


*** 2014-07-29 14:10:10.957
*** 2014-07-29 14:10:10.957 3328 krsb.c
krsb_iorb_reap: Error 3113 reaping buffers
krsb_bcb_get: Error 3113 performing stall for 1 BCB I/O completion check
*** 2014-07-29 14:10:10.958 4329 krsh.c
NSA:  Error 3113 archiving log 1 to 'srvdbhz1'
Error 1041 detaching RFS from standby instance at host 'srvdbhz1'
*** 2014-07-29 14:10:10.958 2917 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 

重启了从库，虽然顺利重启，但还是一样：日志未应用，仔细观察，发现未应用的日志少了个，就是说主库传过来的日志还是在应用，只是非常慢；

各种定位和分析，怀疑是网络问题，主库在南京，从库在杭州，因为带宽不够，网络上对带宽进行了策略限制。

修改策略后，果然应用日志的速度快了很多，等明天再来看情况；