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/，如需轉載，請註明出處，否則將追究法律責任。