stream不能实时传送standby redo log问题的解决

刚刚酒窖开发人员过来跟我反映了一个情况，说测试库的数据没有实时传送到开发库，让我这里看看是什么情况，检查开发库告警日志发现，即使在测试库进行日志切换，也只是传送了归档日志过来，具体信息如下：

RFS LogMiner: Registered logfile [/arch/arch1_9012_716985918.arc] to LogMiner session id [1]
Mon Feb 13 14:29:30 CST 2012
LOGMINER: Begin mining logfile for session 1 thread 1 sequence 9012, /arch/arch1_9012_716985918.arc
Mon Feb 13 14:29:31 CST 2012
RFS[24]: No standby redo logfiles of size 102400 blocks available
Mon Feb 13 14:29:32 CST 2012
LOGMINER: End mining logfile: /arch/arch1_9012_716985918.arc
Mon Feb 13 14:29:57 CST 2012
RFS[24]: Archived Log: '/arch/arch1_9013_716985918.arc'
Mon Feb 13 14:29:57 CST 2012
RFS LogMiner: Registered logfile [/arch/arch1_9013_716985918.arc] to LogMiner session id [1]
Mon Feb 13 14:29:57 CST 2012
LOGMINER: Begin mining logfile for session 1 thread 1 sequence 9013, /arch/arch1_9013_716985918.arc
Mon Feb 13 14:29:57 CST 2012
LOGMINER: End mining logfile: /arch/arch1_9013_716985918.arc
Mon Feb 13 14:29:57 CST 2012
RFS[24]: No standby redo logfiles of size 102400 blocks available

由上面的红色部分可以看出，测试库的在线日志没有实时传送到开发库的standby redo log，只是应用了归档日志，并没有进行实时的redo log应用，查看对应的standby log情况，5组redo log都是active，都有数据，不正常，回想一下，上周曾在测试库上配置过schema级别的stream，修改过相应的参数，之后对开发库的对应参数也做过调整，然后把开发库上的propagation、capture和apply进程停掉再起来，测试库尝试切换redo log还是不行，查看对应的DOWNSTREAM_REAL_TIME_MINE参数也是实时应用的，最后把该参数调整为非实时应用，再开启实时应用，然后在测试库切换redo log，对应的redo log终于传送到开发库了，这时候再查询standby redo log的状态，已经变成：

5 2741503931 1 9028 52428800 6851072 YES ACTIVE 70580907784 2012-2-13 15:16:53 70580908816 2012-2-13 15:21:31
6 UNASSIGNED 1 0 52428800 512 NO UNASSIGNED 0  0 
7 UNASSIGNED 1 0 52428800 512 YES UNASSIGNED 0  0 
8 UNASSIGNED 1 0 52428800 512 YES UNASSIGNED 0  0 
9 UNASSIGNED 1 0 52428800 512 YES UNASSIGNED 0  0 
10 UNASSIGNED 1 0 52428800 512 YES UNASSIGNED 0  0 

具体alert 日志如下：

RFS[4]: Assigned to RFS process 2520
RFS[4]: Identified database type as 'streams capture'
Mon Feb 13 14:45:40 CST 2012
RFS LogMiner: Client enabled and ready for notification
RFS[4]: Successfully opened standby log 6: '/oracle/oradata/mydev/stdbyredo02.log'
Mon Feb 13 14:45:40 CST 2012
RFS LogMiner: Client enabled and ready for notification
Mon Feb 13 14:45:40 CST 2012
RFS LogMiner: Registered logfile [/arch/arch1_9019_716985918.arc] to LogMiner session id [1]
Mon Feb 13 14:45:40 CST 2012
LOGMINER: Begin mining logfile for session 1 thread 1 sequence 9019, /oracle/oradata/mydev/stdbyredo02.log
Mon Feb 13 14:45:40 CST 2012
LOGMINER: End mining logfile: /oracle/oradata/mydev/stdbyredo02.log
Mon Feb 13 14:45:40 CST 2012
LOGMINER: Begin mining logfile for session 1 thread 1 sequence 9020, /oracle/oradata/mydev/stdbyredo01.log
Mon Feb 13 14:45:42 CST 2012
Errors in file /oracle/admin/mydev/bdump/mydev_q003_2279.trc:
ORA-00600: internal error code, arguments: [kwqbdrcp101], [], [], [], [], [], [], []
Mon Feb 13 14:45:43 CST 2012
Errors in file /oracle/admin/mydev/bdump/mydev_q003_2279.trc:
ORA-00600: internal error code, arguments: [kwqbdrcp101], [], [], [], [], [], [], []
Mon Feb 13 14:45:45 CST 2012
Errors in file /oracle/admin/mydev/bdump/mydev_q003_2279.trc:
ORA-00600: internal error code, arguments: [kgqmdeq788], [], [], [], [], [], [], []

不幸的是报600错了，查询相应的trace文件，信息如下：

[oracle@devdb ~]$ more /oracle/admin/mydev/bdump/mydev_q000_2477.trc
/oracle/admin/mydev/bdump/mydev_q000_2477.trc
Oracle Database 10g Enterprise Edition Release 10.2.0.5.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /oracle/product/10.2.0/db_1
System name:    Linux
Node name:      devdb
Release:        2.6.18-194.el5
Version:        #1 SMP Fri Apr 2 14:58:14 EDT 2010
Machine:        x86_64
Instance name: mydev
Redo thread mounted by this instance: 1
Oracle process number: 67
Unix process pid: 2477, image: oracle@devdb (q000)

*** SERVICE NAME:(SYS$BACKGROUND) 2012-02-13 14:45:58.426
*** SESSION ID:(466.19) 2012-02-13 14:45:58.426
*** 2012-02-13 14:45:58.426
ksedmp: internal or fatal error
ORA-00600: internal error code, arguments: [kwqbdrcp101], [], [], [], [], [], [], []
----- Call Stack Trace -----
calling              call     entry                argument values in hex     
location             type     point                (? means dubious value)    
-------------------- -------- -------------------- ----------------------------
ssd_unwind_bp: unhandled instruction at 0x3d12d0e instr=f

原来是oracle 的一个并行服务器进程，具体执行的语句也没查到，考虑到不是什么后台关键性进程，直接在操作系统层kill掉，之后就恢复正常了：

Mon Feb 13 14:49:51 CST 2012
RFS LogMiner: Client enabled and ready for notification
Mon Feb 13 14:49:51 CST 2012
RFS LogMiner: Registered logfile [/arch/arch1_9020_716985918.arc] to LogMiner session id [1]
Mon Feb 13 14:49:51 CST 2012
RFS[3]: Successfully opened standby log 6: '/oracle/oradata/mydev/stdbyredo02.log'

准备收工了，却发现stream的capture进程报错ORA-01280，异常abort掉了：

LogMiner process death detected
Mon Feb 13 14:50:06 CST 2012
Streams CAPTURE C001 with pid=124, OS id=2365 stopped
Mon Feb 13 14:50:06 CST 2012
Errors in file /oracle/admin/mydev/bdump/mydev_c001_2365.trc:
ORA-01280: Fatal LogMiner Error.
Mon Feb 13 14:50:30 CST 2012
Streams CAPTURE C001 started with pid=40, OS id=2642
Mon Feb 13 14:50:30 CST 2012
LOGMINER: Parameters summary for session# = 1
LOGMINER: Number of processes = 3, Transaction Chunk Size = 1
LOGMINER: Memory Size = 10M, Checkpoint interval = 1000M
Mon Feb 13 14:50:30 CST 2012
LOGMINER: krvxpsr summary for session# = 1
LOGMINER: StartScn: 70580902840 (0x0010.6ef31bb8)
LOGMINER: EndScn: 0
LOGMINER: HighConsumedScn: 70580902840 (0x0010.6ef31bb8)
LOGMINER: session_flag 0x1
LOGMINER: LowCkptScn: 70580381120 (0x0010.6eeb25c0)
LOGMINER: HighCkptScn: 70580392656 (0x0010.6eeb52d0)
LOGMINER: SkipScn: 70580381120 (0x0010.6eeb25c0)

尝试重新启动capture进程，之后就没有再报错了，如下：

LOGMINER: Archived logfile found, transition to mining logfile: /arch/arch1_9021_716985918.arc
Mon Feb 13 15:07:28 CST 2012
LOGMINER: End mining logfile: /arch/arch1_9021_716985918.arc
Mon Feb 13 15:07:28 CST 2012
LOGMINER: Begin mining logfile for session 1 thread 1 sequence 9022, /oracle/oradata/mydev/stdbyredo01.log
Mon Feb 13 15:15:25 CST 2012
RFS LogMiner: Client enabled and ready for notification
Mon Feb 13 15:15:25 CST 2012
LOGMINER: End mining logfile: /oracle/oradata/mydev/stdbyredo01.log
Mon Feb 13 15:15:25 CST 2012
RFS LogMiner: Registered logfile [/arch/arch1_9022_716985918.arc] to LogMiner session id [1]
Mon Feb 13 15:15:25 CST 2012
RFS[3]: Successfully opened standby log 6: '/oracle/oradata/mydev/stdbyredo02.log'
Mon Feb 13 15:15:26 CST 2012
LOGMINER: Begin mining logfile for session 1 thread 1 sequence 9023, /oracle/oradata/mydev/stdbyredo02.log
Mon Feb 13 15:15:26 CST 2012
RFS LogMiner: Client enabled and ready for notification
Mon Feb 13 15:15:27 CST 2012
RFS LogMiner: Registered logfile [/arch/arch1_9023_716985918.arc] to LogMiner session id [1]
Mon Feb 13 15:15:27 CST 2012
RFS[3]: Successfully opened standby log 5: '/oracle/oradata/mydev/stdbyredo01.log'
Mon Feb 13 15:15:27 CST 2012
LOGMINER: Archived logfile found, transition to mining logfile: /arch/arch1_9023_716985918.arc
Mon Feb 13 15:15:27 CST 2012
LOGMINER: End mining logfile: /arch/arch1_9023_716985918.arc
Mon Feb 13 15:15:27 CST 2012
LOGMINER: Begin mining logfile for session 1 thread 1 sequence 9024, /oracle/oradata/mydev/stdbyredo01.log

 

来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/25618347/viewspace-716157/，如需转载，请注明出处，否则将追究法律责任。

转载于:http://blog.itpub.net/25618347/viewspace-716157/