今天是2014-06-06,在进行数据库恢复的时候出现了一个久违的ora-600 [2662]错误。特整理例如以下:

问题描写叙述:

  system及数据文件误删,採用恢复数据文件的方式将数据库恢复到開始状态,数据库为非归档模式。

在alter database open resetlog打开数据库的时候提示ora-600 【2662】错误。信息例如以下:

SQL> col member for a80
SQL> 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_.log

6 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 1
ORA-00289: suggestion : /u01/app/oracle/fast_recovery_area/ORAC1/archivelog/2014_06_06/o1_mf_1_23_%u_.arc
ORA-00280: change 1104149 for thread 1 is in sequence #23


Specify log: {<RET>=suggested | filename | AUTO | CANCEL}
filename
ORA-00308: cannot open archived log 'filename'
ORA-27037: unable to obtain file status
Linux-x86_64 Error: 2: No such file or directory
Additional information: 3


Specify log: {<RET>=suggested | filename | AUTO | CANCEL}
/u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_2_9r1wwyvm_.log
ORA-00279: change 1106290 generated at 06/06/2014 10:25:19 needed for thread 1
ORA-00289: suggestion : /u01/app/oracle/fast_recovery_area/ORAC1/archivelog/2014_06_06/o1_mf_1_24_%u_.arc
ORA-00280: change 1106290 for thread 1 is in sequence #24
ORA-00278: log file '/u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_2_9r1wwyvm_.log' no longer needed for this recovery


Specify log: {<RET>=suggested | filename | AUTO | CANCEL}
/u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_3_9r1wx0tq_.log
Log 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 open


SQL> alter database open resetlogs;
alter database open resetlogs
*
ERROR at line 1:
ORA-00603: ORACLE server session terminated by fatal error
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 forced
ORA-00600: internal error code, arguments: [2662], [0], [1106968], [0], [1107731], [12583040], [], [], [], [], [], []
Process ID: 3479
Session ID: 1 Serial number: 3


SQL> 


查看日志提演示样例如以下:

Completed: ALTER DATABASE RECOVER    LOGFILE '/u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_3_9r1wx0tq_.log'
alter database open
Errors in file /u01/app/oracle/diag/rdbms/orac1/orac1/trace/orac1_ora_3479.trc:
ORA-01589: must use RESETLOGS or NORESETLOGS option for database open
ORA-1589 signalled during: alter database open...
Fri Jun 06 11:07:23 2014
alter database open resetlogs
RESETLOGS after complete recovery through change 1106961
Clearing online redo logfile 1 /u01/app/oracle/ORAC1/onlinelog/o1_mf_1_9r1www7g_.log
Clearing online log 1 of thread 1 sequence number 22
Clearing online redo logfile 1 complete
Clearing online redo logfile 2 /u01/app/oracle/ORAC1/onlinelog/o1_mf_2_9r1wwyrm_.log
Clearing online log 2 of thread 1 sequence number 23
Clearing online redo logfile 2 complete
Clearing online redo logfile 3 /u01/app/oracle/ORAC1/onlinelog/o1_mf_3_9r1wx0r7_.log
Clearing online log 3 of thread 1 sequence number 24
Clearing online redo logfile 3 complete
Resetting resetlogs activation ID 1775401946 (0x69d27bda)
Online log /u01/app/oracle/ORAC1/onlinelog/o1_mf_1_9r1www7g_.log: Thread 1 Group 1 was previously cleared
Online log /u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_1_9r1wwwdz_.log: Thread 1 Group 1 was previously cleared
Online log /u01/app/oracle/ORAC1/onlinelog/o1_mf_2_9r1wwyrm_.log: Thread 1 Group 2 was previously cleared
Online log /u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_2_9r1wwyvm_.log: Thread 1 Group 2 was previously cleared
Online log /u01/app/oracle/ORAC1/onlinelog/o1_mf_3_9r1wx0r7_.log: Thread 1 Group 3 was previously cleared
Online log /u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_3_9r1wx0tq_.log: Thread 1 Group 3 was previously cleared
Fri Jun 06 11:07:26 2014
Setting recovery target incarnation to 3
Fri Jun 06 11:07:26 2014
Assigning 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_.log
Successful open of redo thread 1
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Fri Jun 06 11:07:26 2014
SMON: enabling cache recovery
Errors 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.trc
Use 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.937
Media Recovery drop redo thread 1
File 1 (stop scn 1106961) completed recovery at checkpoint scn 1106961
File 2 (stop scn 1106961) completed recovery at checkpoint scn 1106961
File 3 (stop scn 1106961) completed recovery at checkpoint scn 1106961
File 4 (stop scn 1106961) completed recovery at checkpoint scn 1106961
File 5 (stop scn 1106961) completed recovery at checkpoint scn 1106961
KCBR: Number of read descriptors = 1024
KCBR: Media recovery blocks read (SYNC) = 50
*** 2014-06-06 11:07:09.865
Media Recovery Log /u01/app/oracle/fast_recovery_area/ORAC1/onlinelog/o1_mf_3_9r1wx0tq_.log
Log 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/sec
Total redo bytes: 4042Kb Longest record: 22Kb, moves: 1/7102 moved: 0Mb (0%)
Longest LWN: 678Kb, reads: 421
Last redo scn: 0x0000.0010e18f (1106319)
Change vector header moves = 1060/17429 (6%)
----------------------------------------------

*** 2014-06-06 11:07:09.937
Media Recovery drop redo thread 1
File 1 (stop scn 1106961) completed recovery at checkpoint scn 1106961
File 2 (stop scn 1106961) completed recovery at checkpoint scn 1106961
File 3 (stop scn 1106961) completed recovery at checkpoint scn 1106961
File 4 (stop scn 1106961) completed recovery at checkpoint scn 1106961
File 5 (stop scn 1106961) completed recovery at checkpoint scn 1106961
KCBR: Number of read descriptors = 1024
KCBR: Media recovery blocks read (SYNC) = 50
KCBR: Influx buffers flushed = 4 times
KCBR: Redo cache copies/changes = 815/815

*** 2014-06-06 11:07:10.164
Completed Media Recovery

*** 2014-06-06 11:07:15.938
ORA-01589: must use RESETLOGS or NORESETLOGS option for database open

*** 2014-06-06 11:07:23.097
Prior to RESETLOGS processing...
ALTER SYSTEM ARCHIVE LOG ALL USING BACKUP CONTROLFILE start
Database is not in archivelog mode
ALTER SYSTEM ARCHIVE LOG ALL USING BACKUP CONTROLFILE complete
*** 2014-06-06 11:07:23.097 4329 krsh.c
Clearing 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.c
Clearing online redo logfile 1 complete
*** 2014-06-06 11:07:24.493 4329 krsh.c
Clearing 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.c
Clearing online redo logfile 2 complete
*** 2014-06-06 11:07:25.669 4329 krsh.c
Clearing 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.c
Clearing online redo logfile 3 complete

*** 2014-06-06 11:07:26.837
Incident 16953 created, dump file: /u01/app/oracle/diag/rdbms/orac1/orac1/incident/incdir_16953/orac1_ora_3479_i16953.trc
ORA-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.650
USER (ospid: 3479): terminating the instance due to error 600
ksupop : Instance termination detected

*** 2014-06-06 11:07:29.722
dbkedDefDump(): 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 forced
ORA-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 hex
location             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> exit
Disconnected from 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@oracle11g ~]$ sqlplus / as sysdba

SQL*Plus: Release 11.2.0.4.0 Production on Fri Jun 6 11:26:28 2014

Copyright (c) 1982, 2013, Oracle.  All rights reserved.

Connected to an idle instance.

SQL> startup mount;
ORACLE instance started.

Total System Global Area  839282688 bytes
Fixed Size                  2257880 bytes
Variable Size             545262632 bytes
Database Buffers          289406976 bytes
Redo Buffers                2355200 bytes
Database mounted.

 

SQL> alter database open;

Database altered.

SQL> shutdown immediate;
Database closed.
Database dismounted.
ORACLE instance shut down.
SQL> startup
ORACLE instance started.

Total System Global Area  839282688 bytes
Fixed Size                  2257880 bytes
Variable Size             545262632 bytes
Database Buffers          289406976 bytes
Redo Buffers                2355200 bytes
Database mounted.
Database opened.
SQL> 
SQL> col name for a80
SQL> r
  1* select  CHECKPOINT_CHANGE#,file#,name from v$datafile

CHECKPOINT_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_.dbf

SQL> select current_scn from v$database;

CURRENT_SCN
-----------
    1127967

SQL> 
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                      0

SQL> 

查看日志能够发现数据库依旧在进行了一次异常恢复,正是刚刚自己主动关闭后的结果。

Completed: ALTER DATABASE   MOUNT
Fri Jun 06 11:35:20 2014
alter database open
Beginning crash recovery of 1 threads
Started redo scan
Completed redo scan
 read 1 KB redo, 3 data blocks need recovery
Started redo application at
 Thread 1: logseq 1, block 3, scn 1106967
Recovery 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_.log
Completed redo application of 0.00MB
Completed crash recovery at
 Thread 1: logseq 1, block 5, scn 1126969
 3 data blocks read, 3 data blocks written, 1 redo k-bytes read
Fri Jun 06 11:35:20 2014
Thread 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_.log
Successful open of redo thread 1
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Fri Jun 06 11:35:20 2014
SMON: enabling cache recovery
[3735] Successfully onlined Undo Tablespace 2.
Undo initialization finished serial:0 start:5887334 end:5887494 diff:160 (1 seconds)
Dictionary check beginning
Dictionary check complete
Verifying 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!