今天是2014-06-06,在进行数据库恢复的时候出现了一个久违的ora-600 [2662]错误,特整理如下:
问题描述:
system表空间误删,采用恢复数据文件的方式将数据库恢复到开始状态,数据库为非归档模式。在alter database open resetlog打开数据库的时候提示ora-600 【2662】错误。信息如下:
SQL> col member for a80SQL> select group#,status,member from v$logfile; GROUP# STATUS MEMBER---------- ------- -------------------------------------------------------------------------------- 3 /u01/app/oracle/ORAC1/onlinelog/o1_mf_3_9r1wx0r7_.log 3 /u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_3_9r1wx0tq_.log 2 /u01/app/oracle/ORAC1/onlinelog/o1_mf_2_9r1wwyrm_.log 2 /u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_2_9r1wwyvm_.log 1 /u01/app/oracle/ORAC1/onlinelog/o1_mf_1_9r1www7g_.log 1 /u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_1_9r1wwwdz_.log6 rows selected.SQL> recover database until cancel using backup controlfile ; ORA-00279: change 1104149 generated at 06/06/2014 09:50:26 needed for thread 1ORA-00289: suggestion : /u01/app/oracle/fast_recovery_area/ORAC1/archivelog/2014_06_06/o1_mf_1_23_%u_.arcORA-00280: change 1104149 for thread 1 is in sequence #23Specify log: {<RET>=suggested | filename | AUTO | CANCEL}filenameORA-00308: cannot open archived log 'filename'ORA-27037: unable to obtain file statusLinux-x86_64 Error: 2: No such file or directoryAdditional information: 3Specify log: {<RET>=suggested | filename | AUTO | CANCEL}/u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_2_9r1wwyvm_.logORA-00279: change 1106290 generated at 06/06/2014 10:25:19 needed for thread 1ORA-00289: suggestion : /u01/app/oracle/fast_recovery_area/ORAC1/archivelog/2014_06_06/o1_mf_1_24_%u_.arcORA-00280: change 1106290 for thread 1 is in sequence #24ORA-00278: log file '/u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_2_9r1wwyvm_.log' no longer needed for this recoverySpecify log: {<RET>=suggested | filename | AUTO | CANCEL}/u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_3_9r1wx0tq_.logLog applied.Media recovery complete.SQL> SQL> SQL> SQL> alter database open;alter database open*ERROR at line 1:ORA-01589: must use RESETLOGS or NORESETLOGS option for database openSQL> alter database open resetlogs;alter database open resetlogs*ERROR at line 1:ORA-00603: ORACLE server session terminated by fatal errorORA-00600: internal error code, arguments: [2662], [0], [1106971], [0], [1107731], [12583040], [], [], [], [], [], []ORA-00600: internal error code, arguments: [2662], [0], [1106970], [0], [1107731], [12583040], [], [], [], [], [], []ORA-01092: ORACLE instance terminated. Disconnection forcedORA-00600: internal error code, arguments: [2662], [0], [1106968], [0], [1107731], [12583040], [], [], [], [], [], []Process ID: 3479Session ID: 1 Serial number: 3SQL>
查看日志提示如下:
Completed: ALTER DATABASE RECOVER LOGFILE '/u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_3_9r1wx0tq_.log'alter database openErrors in file /u01/app/oracle/diag/rdbms/orac1/orac1/trace/orac1_ora_3479.trc:ORA-01589: must use RESETLOGS or NORESETLOGS option for database openORA-1589 signalled during: alter database open...Fri Jun 06 11:07:23 2014alter database open resetlogsRESETLOGS after complete recovery through change 1106961Clearing online redo logfile 1 /u01/app/oracle/ORAC1/onlinelog/o1_mf_1_9r1www7g_.logClearing online log 1 of thread 1 sequence number 22Clearing online redo logfile 1 completeClearing online redo logfile 2 /u01/app/oracle/ORAC1/onlinelog/o1_mf_2_9r1wwyrm_.logClearing online log 2 of thread 1 sequence number 23Clearing online redo logfile 2 completeClearing online redo logfile 3 /u01/app/oracle/ORAC1/onlinelog/o1_mf_3_9r1wx0r7_.logClearing online log 3 of thread 1 sequence number 24Clearing online redo logfile 3 completeResetting resetlogs activation ID 1775401946 (0x69d27bda)Online log /u01/app/oracle/ORAC1/onlinelog/o1_mf_1_9r1www7g_.log: Thread 1 Group 1 was previously clearedOnline log /u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_1_9r1wwwdz_.log: Thread 1 Group 1 was previously clearedOnline log /u01/app/oracle/ORAC1/onlinelog/o1_mf_2_9r1wwyrm_.log: Thread 1 Group 2 was previously clearedOnline log /u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_2_9r1wwyvm_.log: Thread 1 Group 2 was previously clearedOnline log /u01/app/oracle/ORAC1/onlinelog/o1_mf_3_9r1wx0r7_.log: Thread 1 Group 3 was previously clearedOnline log /u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_3_9r1wx0tq_.log: Thread 1 Group 3 was previously clearedFri Jun 06 11:07:26 2014Setting recovery target incarnation to 3Fri Jun 06 11:07:26 2014Assigning activation ID 1776465391 (0x69e2b5ef)Thread 1 opened at log sequence 1 Current log# 1 seq# 1 mem# 0: /u01/app/oracle/ORAC1/onlinelog/o1_mf_1_9r1www7g_.log Current log# 1 seq# 1 mem# 1: /u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_1_9r1wwwdz_.logSuccessful open of redo thread 1MTTR advisory is disabled because FAST_START_MTTR_TARGET is not setFri Jun 06 11:07:26 2014SMON: enabling cache recoveryErrors in file /u01/app/oracle/diag/rdbms/orac1/orac1/trace/orac1_ora_3479.trc (incident=16953):ORA-00600: internal error code, arguments: [2662], [0], [1106968], [0], [1107731], [12583040], [], [], [], [], [], []Incident details in: /u01/app/oracle/diag/rdbms/orac1/orac1/incident/incdir_16953/orac1_ora_3479_i16953.trcUse ADRCI or Support Workbench to package the incident.See Note 411.1 at My Oracle Support for error and packaging details.Errors in file /u01/app/oracle/diag/rdbms/orac1/orac1/trace/orac1_ora_3479.trc:ORA-00600: internal error code, arguments: [2662], [0], [1106968], [0], [1107731], [12583040], [], [], [], [], [], []Errors in file /u01/app/oracle/diag/rdbms/orac1/orac1/trace/orac1_ora_3479.trc:ORA-00600: internal error code, arguments: [2662], [0], [1106968], [0], [1107731], [12583040], [], [], [], [], [], []Error 600 happened during db open, shutting down database
查看trace日志如下:
*** 2014-06-06 11:07:09.937Media Recovery drop redo thread 1File 1 (stop scn 1106961) completed recovery at checkpoint scn 1106961File 2 (stop scn 1106961) completed recovery at checkpoint scn 1106961File 3 (stop scn 1106961) completed recovery at checkpoint scn 1106961File 4 (stop scn 1106961) completed recovery at checkpoint scn 1106961File 5 (stop scn 1106961) completed recovery at checkpoint scn 1106961KCBR: Number of read descriptors = 1024KCBR: Media recovery blocks read (SYNC) = 50*** 2014-06-06 11:07:09.865Media Recovery Log /u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_3_9r1wx0tq_.logLog read is SYNCHRONOUS though disk_asynch_io is enabled!----- Redo read statistics for thread 1 -----Read rate (SYNC): 3029Kb in 21.95s => 0.13 Mb/secTotal redo bytes: 4042Kb Longest record: 22Kb, moves: 1/7102 moved: 0Mb (0%)Longest LWN: 678Kb, reads: 421Last redo scn: 0x0000.0010e18f (1106319)Change vector header moves = 1060/17429 (6%)----------------------------------------------*** 2014-06-06 11:07:09.937Media Recovery drop redo thread 1File 1 (stop scn 1106961) completed recovery at checkpoint scn 1106961File 2 (stop scn 1106961) completed recovery at checkpoint scn 1106961File 3 (stop scn 1106961) completed recovery at checkpoint scn 1106961File 4 (stop scn 1106961) completed recovery at checkpoint scn 1106961File 5 (stop scn 1106961) completed recovery at checkpoint scn 1106961KCBR: Number of read descriptors = 1024KCBR: Media recovery blocks read (SYNC) = 50KCBR: Influx buffers flushed = 4 timesKCBR: Redo cache copies/changes = 815/815*** 2014-06-06 11:07:10.164Completed Media Recovery*** 2014-06-06 11:07:15.938ORA-01589: must use RESETLOGS or NORESETLOGS option for database open*** 2014-06-06 11:07:23.097Prior to RESETLOGS processing...ALTER SYSTEM ARCHIVE LOG ALL USING BACKUP CONTROLFILE startDatabase is not in archivelog modeALTER SYSTEM ARCHIVE LOG ALL USING BACKUP CONTROLFILE complete*** 2014-06-06 11:07:23.097 4329 krsh.cClearing online redo logfile 1 /u01/app/oracle/ORAC1/onlinelog/o1_mf_1_9r1www7g_.log*** 2014-06-06 11:07:24.492*** 2014-06-06 11:07:24.492 4329 krsh.cClearing online redo logfile 1 complete*** 2014-06-06 11:07:24.493 4329 krsh.cClearing online redo logfile 2 /u01/app/oracle/ORAC1/onlinelog/o1_mf_2_9r1wwyrm_.log*** 2014-06-06 11:07:25.669*** 2014-06-06 11:07:25.669 4329 krsh.cClearing online redo logfile 2 complete*** 2014-06-06 11:07:25.669 4329 krsh.cClearing online redo logfile 3 /u01/app/oracle/ORAC1/onlinelog/o1_mf_3_9r1wx0r7_.log*** 2014-06-06 11:07:26.837*** 2014-06-06 11:07:26.837 4329 krsh.cClearing online redo logfile 3 complete*** 2014-06-06 11:07:26.837Incident 16953 created, dump file: /u01/app/oracle/diag/rdbms/orac1/orac1/incident/incdir_16953/orac1_ora_3479_i16953.trcORA-00600: internal error code, arguments: [2662], [0], [1106968], [0], [1107731], [12583040], [], [], [], [], [], []ORA-00600: internal error code, arguments: [2662], [0], [1106968], [0], [1107731], [12583040], [], [], [], [], [], []ORA-00600: internal error code, arguments: [2662], [0], [1106968], [0], [1107731], [12583040], [], [], [], [], [], []*** 2014-06-06 11:07:29.650USER (ospid: 3479): terminating the instance due to error 600ksupop : Instance termination detected*** 2014-06-06 11:07:29.722dbkedDefDump(): Starting a non-incident diagnostic dump (flags=0x0, level=3, mask=0x0)----- Error Stack Dump -----ORA-00600: internal error code, arguments: [2662], [0], [1106971], [0], [1107731], [12583040], [], [], [], [], [], []ORA-00600: internal error code, arguments: [2662], [0], [1106970], [0], [1107731], [12583040], [], [], [], [], [], []ORA-01092: ORACLE instance terminated. Disconnection forcedORA-00600: internal error code, arguments: [2662], [0], [1106968], [0], [1107731], [12583040], [], [], [], [], [], []----- Current SQL Statement for this session (sql_id=7j16t46cacjt9) -----alter database open resetlogs----- Call Stack Trace -----calling call entry argument values in hexlocation type point (? means dubious value)-------------------- -------- -------------------- ----------------------------skdstdst()+41 call kgdsdst() 000000000 ? 000000000 ? 7FFFC73D3A60 ? 7FFFC73D3B38 ? 7FFFC73D85E0 ? 000000002 ?ksedst1()+103 call skdstdst() 000000000 ? 000000000 ? 7FFFC73D3A60 ? 7FFFC73D3B38 ? 7FFFC73D85E0 ? 000000002 ?ksedst()+39 call ksedst1() 000000000 ? 000000001 ? 7FFFC73D3A60 ? 7FFFC73D3B38 ? 7FFFC73D85E0 ? 000000002 ?dbkedDefDump()+2746 call ksedst() 000000000 ? 000000001 ? 7FFFC73D3A60 ? 7FFFC73D3B38 ? 7FFFC73D85E0 ? 000000002 ?ksedmp()+41 call dbkedDefDump() 000000003 ? 000000000 ? 7FFFC73D3A60 ? 7FFFC73D3B38 ? 7FFFC73D85E0 ? 000000002 ?ksupop()+4099 call ksedmp() 000000003 ? 000000000 ? 7FFFC73D3A60 ? 7FFFC73D3B38 ? 7FFFC73D85E0 ? 000000002 ?
问题分析:
出现该问题说明:一个数据块的scn大于当前的scn,对于scn号做一些说明:scn分为高位和地位。高位为wrap占用2bytes,低位为base占用4bytes,对于scn的介绍见如下整理:
http://blog.csdn.net/rhys_oracle/article/details/9052599
那这次报错来看:
ORA-00600: internal error code, arguments: [2662], [0], [1106968], [0], [1107731], [12583040], [], [], [], [], [], []
1106968 为base,1107731为current base,12583040代表:where present this is the DBA where the dependent scn came from。
知道了这些信息之后那么我们就需要采用不同办法去让它增长scn了。
问题解决办法:
重启多次重启数据库,自动增长scn解决问题。
SQL> exitDisconnected from Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit ProductionWith the Partitioning, OLAP, Data Mining and Real Application Testing options[[email protected] ~]$ sqlplus / as sysdbaSQL*Plus: Release 11.2.0.4.0 Production on Fri Jun 6 11:26:28 2014Copyright (c) 1982, 2013, Oracle. All rights reserved.Connected to an idle instance.SQL> startup mount;ORACLE instance started.Total System Global Area 839282688 bytesFixed Size 2257880 bytesVariable Size 545262632 bytesDatabase Buffers 289406976 bytesRedo Buffers 2355200 bytesDatabase mounted.
SQL> alter database open;Database altered.SQL> shutdown immediate;Database closed.Database dismounted.ORACLE instance shut down.SQL> startupORACLE instance started.Total System Global Area 839282688 bytesFixed Size 2257880 bytesVariable Size 545262632 bytesDatabase Buffers 289406976 bytesRedo Buffers 2355200 bytesDatabase mounted.Database opened.SQL> SQL> col name for a80SQL> r 1* select CHECKPOINT_CHANGE#,file#,name from v$datafileCHECKPOINT_CHANGE# FILE# NAME------------------ ---------- -------------------------------------------------------------------------------- 1127546 1 /u01/app/oracle/ORAC1/datafile/o1_mf_system_9r1wqt9c_.dbf 1127546 2 /u01/app/oracle/ORAC1/datafile/o1_mf_sysaux_9r1wqtfd_.dbf 1127546 3 /u01/app/oracle/ORAC1/datafile/o1_mf_undotbs1_9r1wqtks_.dbf 1127546 4 /u01/app/oracle/ORAC1/datafile/o1_mf_users_9r1wqtmc_.dbf 1127546 5 /u01/app/oracle/ORAC1/datafile/o1_mf_example_9r1wxq5m_.dbfSQL> select current_scn from v$database;CURRENT_SCN----------- 1127967SQL> SQL> select * from v$log; GROUP# THREAD# SEQUENCE# BYTES BLOCKSIZE MEMBERS ARC STATUS FIRST_CHANGE# FIRST_TIM NEXT_CHANGE# NEXT_TIME---------- ---------- ---------- ---------- ---------- ---------- --- ---------------- ------------- --------- ------------ --------- 1 1 1 52428800 512 2 NO INACTIVE 1106962 06-JUN-14 1126971 06-JUN-14 2 1 2 52428800 512 2 NO CURRENT 1126971 06-JUN-14 2.8147E+14 3 1 0 52428800 512 2 YES UNUSED 0 0SQL>
查看日志可以发现数据库依然在进行了一次异常恢复,正是刚刚自动关闭后的结果。
Completed: ALTER DATABASE MOUNTFri Jun 06 11:35:20 2014alter database openBeginning crash recovery of 1 threadsStarted redo scanCompleted redo scan read 1 KB redo, 3 data blocks need recoveryStarted redo application at Thread 1: logseq 1, block 3, scn 1106967Recovery of Online Redo Log: Thread 1 Group 1 Seq 1 Reading mem 0 Mem# 0: /u01/app/oracle/ORAC1/onlinelog/o1_mf_1_9r1www7g_.log Mem# 1: /u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_1_9r1wwwdz_.logCompleted redo application of 0.00MBCompleted crash recovery at Thread 1: logseq 1, block 5, scn 1126969 3 data blocks read, 3 data blocks written, 1 redo k-bytes readFri Jun 06 11:35:20 2014Thread 1 advanced to log sequence 2 (thread open)Thread 1 opened at log sequence 2 Current log# 2 seq# 2 mem# 0: /u01/app/oracle/ORAC1/onlinelog/o1_mf_2_9r1wwyrm_.log Current log# 2 seq# 2 mem# 1: /u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_2_9r1wwyvm_.logSuccessful open of redo thread 1MTTR advisory is disabled because FAST_START_MTTR_TARGET is not setFri Jun 06 11:35:20 2014SMON: enabling cache recovery[3735] Successfully onlined Undo Tablespace 2.Undo initialization finished serial:0 start:5887334 end:5887494 diff:160 (1 seconds)Dictionary check beginningDictionary check completeVerifying file header compatibility for 11g tablespace encryption..Verifying 11g file header compatibility for tablespace encryption completed
可以看到数据文件的scn已经低于数据的current_scn.
这是一种办法,另还有两种办法:
一种需要数据库open:通过alter session set events 'immediate trace name adjust_scn level *';
一种是数据库必须mount:设置10015事件来完成
alter session set events ‘10015 trace name adjust_scn level *';
注意* 代表n,每个n为1那么就是1024*1024*1024
注:对于dblink引起的scn自动大幅度跳跃问题,特别繁琐,之前在运营商处理过这个问题,为避免这些繁琐的问题,最好的办法是关注oracle mos了解安全警戒和打补丁。
That's all!