ORA-00600,伺服器斷電導致日誌丟失

煙花丶易冷發表於2017-08-30
一套跑在Linux機器上的11gR2單例項資料庫,由於伺服器異常斷電導致的故障,遭遇到這個ORA-600的錯誤

[oracle@os5 ~]$ sqlplus / as sysdba
SQL*Plus: Release 11.2.0.1.0 Production on Wed Nov 21 10:54:16 2012
Copyright (c) 1982, 2009, Oracle.  All rights reserved.
Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options


SQL> alter database open;
alter database open
*
ERROR at line 1:
ORA-00600: internal error code, arguments: [kcratr_nab_less_than_odr], [1],
[3464], [12432], [12534], [], [], [], [], [], [], []


SQL> select open_mode from v$database;


OPEN_MODE
--------------------
MOUNTED
  從上可以看到,當前資料庫停留在MOUNT狀態,沒法OPEN,然後,就用RMAN重新做了個全備,並手工複製了聯機日誌檔案,保留現場!
         2 接下來,重新嘗試以RESETLOGS方式也打不開,嘗試RECOVER依然報錯!


SQL> alter database open resetlogs;
alter database open resetlogs
*
ERROR at line 1:
ORA-01139: RESETLOGS option only valid after an incomplete database recovery




SQL> recover database;
ORA-00283: recovery session canceled due to errors
ORA-00264: no recovery required




SQL> alter database open;
alter database open
*
ERROR at line 1:
ORA-00600: internal error code, arguments: [kcratr_nab_less_than_odr], [1], [3464], [12432], [12534], [], [], [], [], [], [], []




SQL>


        3  那麼接下來,看看ALERT日誌都記錄哪些有用的資訊:


Wed Nov 21 10:59:16 2012
alter database open
Beginning crash recovery of 1 threads
 parallel recovery started with 2 processes
Started redo scan
Completed redo scan
 read 1642 KB redo, 0 data blocks need recovery
Errors in file /oracle/ora11gR2/diag/rdbms/database/database/trace/database_ora_4848.trc  (incident=129790):
ORA-00600: internal error code, arguments: [kcratr_nab_less_than_odr], [1], [3464], [12432], [12534], [], [], [], [], [], [], []
Incident details in: /oracle/ora11gR2/diag/rdbms/database/database/incident/incdir_129790/database_ora_4848_i129790.trc
Aborting crash recovery due to error 600
Errors in file /oracle/ora11gR2/diag/rdbms/database/database/trace/database_ora_4848.trc:
ORA-00600: internal error code, arguments: [kcratr_nab_less_than_odr], [1], [3464], [12432], [12534], [], [], [], [], [], [], []
Errors in file /oracle/ora11gR2/diag/rdbms/database/database/trace/database_ora_4848.trc:
ORA-00600: internal error code, arguments: [kcratr_nab_less_than_odr], [1], [3464], [12432], [12534], [], [], [], [], [], [], []
ORA-600 signalled during: alter database open...
Wed Nov 21 10:59:17 2012
Sweep [inc][129790]: completed
Sweep [inc2][129790]: completed
Wed Nov 21 10:59:17 2012
Trace dumping is performing id=[cdmp_20121121105917]
Wed Nov 21 11:07:50 2012
db_recovery_file_dest_size of 3852 MB is 0.00% used. This is a
user-specified limit on the amount of space that will be used by this
database for recovery-related files, and does not reflect the amount of
space available in the underlying filesystem or ASM diskgroup.


        從alert裡,一直看到ORA-00600: internal error code, arguments: [kcratr_nab_less_than_odr], [1], [3464], [12432], [12534], [], [], [], [], [], [], []的錯誤,還有一些提示就是Errors in file /oracle/ora11gR2/diag/rdbms/database/database/trace/database_ora_4848.trc。
        4 就去看看上述的TRACE檔案:


*** 2012-11-21 10:59:16.123
Successfully allocated 2 recovery slaves
Using 66 overflow buffers per recovery slave
Thread 1 checkpoint: logseq 3464, block 4945, scn 203336710
  cache-low rba: logseq 3464, block 9148
    on-disk rba: logseq 3464, block 12534, scn 203340512
  start recovery at logseq 3464, block 9148, scn 0


*** 2012-11-21 10:59:16.144
Started writing zeroblks thread 1 seq 3464 blocks 12432-12439


*** 2012-11-21 10:59:16.144
Completed writing zeroblks thread 1 seq 3464
==== Redo read statistics for thread 1 ====
Total physical reads (from disk and memory): 4096Kb
-- Redo read_disk statistics --
Read rate (ASYNC): 1642Kb in 0.02s => 80.18 Mb/sec
Longest record: 14Kb, moves: 0/1953 (0%)
Change moves: 22/192 (11%), moved: 0Mb
Longest LWN: 445Kb, moves: 0/733 (0%), moved: 0Mb
Last redo scn: 0x0000.0c1eba6c (203340396)
----------------------------------------------
----- Recovery Hash Table Statistics ---------
Hash table buckets = 32768
Longest hash chain = 0
Average hash chain = 0/0 = 0.0
Max compares per lookup = 0
Avg compares per lookup = 0/0 = 0.0
----------------------------------------------
WARNING! Crash recovery of thread 1 seq 3464 is
ending at redo block 12432 but should not have ended before
redo block 12534
Incident 129790 created, dump file: /oracle/ora11gR2/diag/rdbms/database/database/incident/incdir_129790/database_ora_4848_i129790.trc
ORA-00600: internal error code, arguments: [kcratr_nab_less_than_odr], [1], [3464], [12432], [12534], [], [], [], [], [], [], []


ORA-00600: internal error code, arguments: [kcratr_nab_less_than_odr], [1], [3464], [12432], [12534], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [kcratr_nab_less_than_odr], [1], [3464], [12432], [12534], [], [], [], [], [], [], []


        5 結合ALERT裡的錯誤ORA-00600: internal error code, arguments: [kcratr_nab_less_than_odr], [1], [3464], [12432], [12534], 和TRACE裡的錯誤提示WARNING! Crash recovery of thread 1 seq 3464 is ending at redo block 12432 but should not have ended before redo block 12534 以及查詢MetaLink文件ID 1299564.1獲取的指導性資訊,應該是由於伺服器異常斷電,導致LGWR寫聯機日誌檔案時失敗,下次重新啟動資料庫時,需要做例項級恢復,而又無法從聯機日誌檔案裡獲取到這些redo資訊,因為上次斷電時,寫日誌失敗了。
          那麼ORA-00600的錯誤裡,那幾個引數 [1], [3464], [12432], [12534]又表示什麼呢? 從EYGLE的網站上查詢到類似的案例資訊,結合本故障場景分析,原來是例項需要恢復日誌序列號為3464的聯機日誌檔案,需要恢復到編號為12534的日誌塊,而實際上只能恢復到第12432個日誌塊兒,所以庫就啟不來了。不過,從當前日誌檔案資訊,可以看到,當前日誌組的確是3464:


SQL> alter session set nls_date_format='yyyy/mm/dd hh24:mi:ss';


Session altered.


SQL> select * from v$log;


    GROUP#    THREAD#  SEQUENCE#      BYTES  BLOCKSIZE    MEMBERS ARC STATUS           FIRST_CHANGE# FIRST_TIME          NEXT_CHANGE# NEXT_TIME
---------- ---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- ------------------- ------------ -------------------
         1          1       3463   52428800        512          1 YES INACTIVE             203285629 2012/11/21 03:00:32    203335249 2012/11/21 08:59:46
         3          1       3462   52428800        512          1 YES INACTIVE             203238520 2012/11/20 21:00:52    203285629 2012/11/21 03:00:32
         2          1       3464   52428800        512          1 NO  CURRENT              203335249 2012/11/21 08:59:46   2.8147E+14


SQL> 


        6 參照MetaLink文件ID 1299564.1的方案來恢復資料庫:
       


SQL> recover database until cancel using backup controlfile;
ORA-00279: change 203360397 generated at 11/21/2012 09:21:51 needed for thread 1
ORA-00289: suggestion : /home/oracle/archive_no_delete/ARC_743097220_0000003464_1.arc
ORA-00280: change 203360397 for thread 1 is in sequence #3464




Specify log: {=suggested | filename | AUTO | CANCEL}
/oracle/ora11gR2/oradata/database/redo02.log
Log applied.
Media recovery complete.
SQL> alter database open ;
alter database open
*
ERROR at line 1:
ORA-01589: must use RESETLOGS or NORESETLOGS option for database open




SQL>  alter database open resetlogs;


Database altered.


SQL> 


          至此,這個庫是成功恢復,並且啟動了。恢復之後,再次對資料庫做了備份。看到Alert日誌資訊:


Wed Nov 21 12:43:44 2012
ALTER DATABASE RECOVER    LOGFILE '/oracle/ora11gR2/oradata/database/redo02.log'  
Media Recovery Log /oracle/ora11gR2/oradata/database/redo02.log
Wed Nov 21 12:43:44 2012
Incomplete recovery applied all redo ever generated.
Recovery completed through change 203360398 time 11/21/2012 09:21:51
Media Recovery Complete (database)
Completed: ALTER DATABASE RECOVER    LOGFILE '/oracle/ora11gR2/oradata/database/redo02.log'  
Wed Nov 21 12:43:55 2012
alter database open 
Errors in file /oracle/ora11gR2/diag/rdbms/database/database/trace/database_ora_10698.trc:
ORA-01589: must use RESETLOGS or NORESETLOGS option for database open
ORA-1589 signalled during: alter database open ...
Wed Nov 21 12:44:37 2012
 alter database open resetlogs
Archived Log entry 3382 added for thread 1 sequence 3463 ID 0xd9842c95 dest 1:
Archived Log entry 3383 added for thread 1 sequence 3464 ID 0xd9842c95 dest 1:
Archived Log entry 3384 added for thread 1 sequence 3462 ID 0xd9842c95 dest 1:
RESETLOGS after complete recovery through change 203360398
Resetting resetlogs activation ID 3649318037 (0xd9842c95)
Wed Nov 21 12:44:43 2012
Setting recovery target incarnation to 4
Wed Nov 21 12:44:43 2012
Assigning activation ID 3706166088 (0xdce79b48)
LGWR: STARTING ARCH PROCESSES
Wed Nov 21 12:44:43 2012
ARC0 started with pid=24, OS id=11236 
ARC0: Archival started
LGWR: STARTING ARCH PROCESSES COMPLETE
ARC0: STARTING ARCH PROCESSES
Wed Nov 21 12:44:44 2012
ARC1 started with pid=25, OS id=11238 
Wed Nov 21 12:44:44 2012
ARC2 started with pid=26, OS id=11240 
Thread 1 opened at log sequence 1
  Current log# 1 seq# 1 mem# 0: /oracle/ora11gR2/oradata/database/redo01.log
Successful open of redo thread 1
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Wed Nov 21 12:44:44 2012
SMON: enabling cache recovery
ARC1: Archival started
ARC2: Archival started
Wed Nov 21 12:44:44 2012
ARC3 started with pid=29, OS id=11242 
ARC1: Becoming the 'no FAL' ARCH
ARC1: Becoming the 'no SRL' ARCH
ARC2: Becoming the heartbeat ARCH
Successfully onlined Undo Tablespace 2.
Dictionary check beginning
Dictionary check complete
Verifying file header compatibility for 11g tablespace encryption..
Verifying 11g file header compatibility for tablespace encryption completed


 
 從Metalink上看到,目前這個ORA-600的錯誤應該只有在Oracle 11g上才有的。



來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/29618264/viewspace-2144311/,如需轉載,請註明出處,否則將追究法律責任。

相關文章