exp dmp文件损坏(坏块/corruption)恢复—跳过dmp坏块

在有些情况下,大家都知道通过dul可以恢复损坏的dmp文件的表的数据,但是该方法有很多问题,特别是对很多数据类型的支持不够完美,比如lob,long raw类型等,而且还有可能恢复出来数据大量丢失,本人通过对dmp结构的分析,使用使用一些特殊的技巧方法,可以实现对于损坏的dmp文件,通过跳过异常坏块所在表,继续恢复后续表,从而最大程度减少损坏
创建测试表

SQL> conn xifenfei/"www.xifenfei.com"
Connected.
SQL> create table t_xifenfei1 as select * from dba_objects;
Table created.
SQL> create table t_xifenfei2 as select * from v$sql;
Table created.
SQL> create table t_xifenfei3 as select * from dba_tables;
Table created.
SQL> select * from tab;
TNAME                          TABTYPE  CLUSTERID
------------------------------ ------- ----------
T_XIFENFEI1                    TABLE
T_XIFENFEI2                    TABLE
T_XIFENFEI3                    TABLE
SQL> select count(*) from t_xifenfei1;
  COUNT(*)
----------
     86275
SQL>  select count(*) from t_xifenfei2;
  COUNT(*)
----------
      3387
SQL>  select count(*) from t_xifenfei3;
  COUNT(*)
----------
      2800

导出来dmp文件

[oracle@web103 ~]$ exp "'/ as sysdba'" owner=xifenfei file=/data/temp/t_xifenfei.dmp log=/data/temp/exp_t_xifenfei.log
Export: Release 11.2.0.4.0 - Production on Tue Aug 18 22:08:30 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.
Connected to: Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
Export done in ZHS16GBK character set and AL16UTF16 NCHAR character set
About to export specified users ...
. exporting pre-schema procedural objects and actions
. exporting foreign function library names for user XIFENFEI
. exporting PUBLIC type synonyms
. exporting private type synonyms
. exporting object type definitions for user XIFENFEI
About to export XIFENFEI's objects ...
. exporting database links
. exporting sequence numbers
. exporting cluster definitions
. about to export XIFENFEI's tables via Conventional Path ...
. . exporting table                    T_XIFENFEI1      86275 rows exported
. . exporting table                    T_XIFENFEI2       3387 rows exported
. . exporting table                    T_XIFENFEI3       2800 rows exported
. exporting synonyms
. exporting views
. exporting stored procedures
. exporting operators
. exporting referential integrity constraints
. exporting triggers
. exporting indextypes
. exporting bitmap, functional and extensible indexes
. exporting posttables actions
. exporting materialized views
. exporting snapshot logs
. exporting job queues
. exporting refresh groups and children
. exporting dimensions
. exporting post-schema procedural objects and actions
. exporting statistics
Export terminated successfully without warnings.

获取dmp file中的T_XIFENFEI2所在位置
计划在该表上通过dd进行破坏,因此需要事先知道该表所在的dmp文件位置范围

CPFL> SEARCH TABLE T_XIFENFEI2 FROM EXPFILE  /tmp/t_xifenfei.dmp
9980561: TABLE "T_XIFENFEI2"
9980581: CREATE TABLE "T_XIFENFEI2" (表定义忽略)
9985356: BIND information for 87 columns
 col[  1] type 1 max length 1000 cset 852 (ZHS16GBK) form 1
 col[  2] type 112 max length 86 cset 852 (ZHS16GBK) form 1
 col[  3] type 1 max length 13 cset 852 (ZHS16GBK) form 1
 col[  4] type 2 max length 22
 col[  5] type 2 max length 22
 col[  6] type 2 max length 22
 col[  7] type 2 max length 22
 col[  8] type 2 max length 22
 col[  9] type 2 max length 22
 col[ 10] type 2 max length 22
 col[ 11] type 2 max length 22
 col[ 12] type 2 max length 22
 col[ 13] type 2 max length 22
 col[ 14] type 2 max length 22
 col[ 15] type 2 max length 22
 col[ 16] type 2 max length 22
 col[ 17] type 1 max length 38 cset 852 (ZHS16GBK) form 1
 col[ 18] type 2 max length 22
 col[ 19] type 2 max length 22
 col[ 20] type 2 max length 22
 col[ 21] type 2 max length 22
 col[ 22] type 2 max length 22
 col[ 23] type 2 max length 22
 col[ 24] type 2 max length 22
 col[ 25] type 2 max length 22
 col[ 26] type 2 max length 22
 col[ 27] type 2 max length 22
 col[ 28] type 2 max length 22
 col[ 29] type 2 max length 22
 col[ 30] type 2 max length 22
 col[ 31] type 1 max length 10 cset 852 (ZHS16GBK) form 1
 col[ 32] type 2 max length 22
 col[ 33] type 23 max length 2000
 col[ 34] type 2 max length 22
 col[ 35] type 2 max length 22
 col[ 36] type 2 max length 22
 col[ 37] type 1 max length 30 cset 852 (ZHS16GBK) form 1
 col[ 38] type 2 max length 22
 col[ 39] type 23 max length 8
 col[ 40] type 23 max length 8
 col[ 41] type 2 max length 22
 col[ 42] type 2 max length 22
 col[ 43] type 2 max length 22
 col[ 44] type 2 max length 22
 col[ 45] type 1 max length 64 cset 852 (ZHS16GBK) form 1
 col[ 46] type 2 max length 22
 col[ 47] type 1 max length 64 cset 852 (ZHS16GBK) form 1
 col[ 48] type 2 max length 22
 col[ 49] type 1 max length 64 cset 852 (ZHS16GBK) form 1
 col[ 50] type 2 max length 22
 col[ 51] type 2 max length 22
 col[ 52] type 1 max length 64 cset 852 (ZHS16GBK) form 1
 col[ 53] type 2 max length 22
 col[ 54] type 2 max length 22
 col[ 55] type 2 max length 22
 col[ 56] type 23 max length 8
 col[ 57] type 2 max length 22
 col[ 58] type 1 max length 1 cset 852 (ZHS16GBK) form 1
 col[ 59] type 1 max length 19 cset 852 (ZHS16GBK) form 1
 col[ 60] type 2 max length 22
 col[ 61] type 1 max length 38 cset 852 (ZHS16GBK) form 1
 col[ 62] type 1 max length 1 cset 852 (ZHS16GBK) form 1
 col[ 63] type 1 max length 1 cset 852 (ZHS16GBK) form 1
 col[ 64] type 1 max length 1 cset 852 (ZHS16GBK) form 1
 col[ 65] type 1 max length 1 cset 852 (ZHS16GBK) form 1
 col[ 66] type 2 max length 22
 col[ 67] type 1 max length 64 cset 852 (ZHS16GBK) form 1
 col[ 68] type 1 max length 30 cset 852 (ZHS16GBK) form 1
 col[ 69] type 1 max length 30 cset 852 (ZHS16GBK) form 1
 col[ 70] type 2 max length 22
 col[ 71] type 2 max length 22
 col[ 72] type 2 max length 22
 col[ 73] type 2 max length 22
 col[ 74] type 12 max length 7
 col[ 75] type 23 max length 2000
 col[ 76] type 2 max length 22
 col[ 77] type 2 max length 22
 col[ 78] type 2 max length 22
 col[ 79] type 2 max length 22
 col[ 80] type 2 max length 22
 col[ 81] type 2 max length 22
 col[ 82] type 2 max length 22
 col[ 83] type 2 max length 22
 col[ 84] type 2 max length 22
 col[ 85] type 2 max length 22
 col[ 86] type 2 max length 22
 col[ 87] type 2 max length 22
Conventional export
9986063: start of table data
19675141: TABLE "T_XIFENFEI3"

使用dd命令破坏T_XIFENFEI2所在位置的dmp文件

[oracle@web103 ~]$ dd if=/dev/zero of=/data/temp/t_xifenfei.dmp bs=1024 count=2 conv=notrunc seek=9747
2+0 records in
2+0 records out
2048 bytes (2.0 kB) copied, 1.6e-05 seconds, 128 MB/s

尝试imp导入被破坏的dmp文件数据

[oracle@web103 ~]$ imp "'/ as sysdba'" fromuser=xifenfei touser=xifenfeinew
>file=/data/temp/t_xifenfei.dmp log=/data/temp/imp_t_xifenfei.log
Import: Release 11.2.0.4.0 - Production on Tue Aug 18 22:35:09 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.
Connected to: Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
Export file created by EXPORT:V11.02.00 via conventional path
import done in ZHS16GBK character set and AL16UTF16 NCHAR character set
. importing XIFENFEI's objects into XIFENFEINEW
. . importing table                  "T_XIFENFEI1"      86275 rows imported
IMP-00017: following statement failed with ORACLE error 1740:
 "CREATE TABLE "T_XIFENFEI2" ("SQL_TEXT" VARCHAR2(1000), "SQL_FULLTEXT" CLOB,"
 " "SQL_ID" VARCHAR2(13), "SHARABLE_MEM" NUMBER, "PERSISTENT_MEM" NUMBER, "RU"
 "NTIME_MEM" NUMBER, "SORTS" NUMBER, "LOADED_VERSIONS" NUMBER, "OPEN_VERSIONS"
 "" NUMBER, "USERS_OPENING" NUMBER, "FETCHES" NUMBER, "EXECUTIONS" NUMBER, "P"
 "X_SERVERS_EXECUTIONS" NUMBER, "END_OF_FETCH_COU"
IMP-00003: ORACLE error 1740 encountered
ORA-01740: missing double quote in identifier
IMP-00008: unrecognized statement in the export file:
IMP-00008: unrecognized statement in the export file:

导入报IMP-00003 ORA-01740 IMP-00008,由于dmp文件被dd破坏(而且破坏位置是T_XIFENFEI2所在之处),因此imp导入到T_XIFENFEI2之时,抛出大量异常,imp终止

检查导入表情况

SQL> conn xifenfeinew/"www.xifenfei.com"
Connected.
SQL> select * from tab;
TNAME                          TABTYPE  CLUSTERID
------------------------------ ------- ----------
T_XIFENFEI1                    TABLE
SQL> select count(*) from t_xifenfei1;
  COUNT(*)
----------
     86275

和预期相符,表t_xifenfei1导入进去,但是t_xifenfei2由于坏块原因未导入,由于t_xifenfei3在t_xifenfei2之后,因此也未导入

使用CPFL程序抽取正常dmp文件

CPFL>getdmp '/data/temp/t_xifenfei.dmp' skip table 'T_XIFENFEI2'
>/data/temp/t_xifenfeinew.dmp

重新导入dmp文件

[oracle@web103 ~]$ imp "'/ as sysdba'" fromuser=xifenfei touser=xifenfeinew
>file=/data/temp/t_xifenfeinew.dmp log=/data/temp/imp_t_xifenfeinew.log
Import: Release 11.2.0.4.0 - Production on Tue Aug 18 22:41:04 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.
Connected to: Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
Export file created by EXPORT:V11.02.00 via conventional path
import done in ZHS16GBK character set and AL16UTF16 NCHAR character set
. importing XIFENFEI's objects into XIFENFEINEW
. . importing table                  "T_XIFENFEI1"      86275 rows imported
. . importing table                  "T_XIFENFEI3"       2800 rows imported
Import terminated successfully no warnings.

导入了t_xifenfei1,t_xifenfei3,果然t_xifenfei2被跳过

验证导入数据

[oracle@web103 ~]$ sqlplus xifenfeinew/"www.xifenfei.com"
SQL*Plus: Release 11.2.0.4.0 Production on Tue Aug 18 22:41:32 2015
Copyright (c) 1982, 2013, Oracle.  All rights reserved.
Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
SQL> select * from tab;
TNAME                          TABTYPE  CLUSTERID
------------------------------ ------- ----------
T_XIFENFEI1                    TABLE
T_XIFENFEI3                    TABLE
SQL> select count(*) from t_xifenfei1;
  COUNT(*)
----------
     86275
SQL> select count(*) from t_xifenfei3;
  COUNT(*)
----------
      2800
SQL>

通过验证数据证明,通过CPFL完美跳过了坏块所在表,实现后续数据完美恢复

使用dml语句删除index测试(取代ddl)

在有些极端情况下,数据库由于某种原因无法执行ddl操作,但是可以执行dml语句,我们可以通过dml语句来替代ddl操作(非官方支持,纯属个人闲着无聊中的测试,请勿模仿,否则后果自负)
创建测试用户xifenfei

[oracle@web103 ~]$ sqlplus / as sysdba
SQL*Plus: Release 11.2.0.4.0 Production on Sun Aug 16 23:04:25 2015
Copyright (c) 1982, 2013, Oracle.  All rights reserved.
Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
SQL> create user xifenfei identified by "www.xifenfei.com";
User created.
SQL> grant dba to xifenfei;
Grant succeeded.

创建测试index,并使用10046跟踪

SQL> conn xifenfei/"www.xifenfei.com"
Connected.
SQL> create table t_xifenfei as select * from dba_objects;
Table created.
SQL>  alter session set events '10046 trace name context forever, level 12';
Session altered.
SQL>  select value from v$diag_info where name='Default Trace File';
VALUE
--------------------------------------------------------------------------------
/u01/app/oracle/diag/rdbms/test/test/trace/test_ora_18838.trc
SQL> create index ind_xifenfei_1 on t_xifenfei(object_id,data_object_id);
Index created.
SQL> exit
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

分析trace文件,找出来核心操作步骤

--插入创建index的记录到obj$中
insert into obj$(owner#,name,namespace,obj#,type#,ctime,mtime,stime,status,
  remoteowner,linkname,subname,dataobj#,flags,oid$,spare1,spare2,spare3)
values
(:1,:2,:3,:4,:5,:6,:7,:8,:9,:10,:11,:12,:13,:14,:15,:16,:17,:18)
--插入index的信息到seg$中
insert into seg$ (file#,block#,type#,ts#,blocks,extents,minexts,maxexts,
  extsize,extpct,user#,iniexts,lists,groups,cachehint,hwmincr, spare1,
  scanhint, bitmapranges)
values
 (:1,:2,:3,:4,:5,:6,:7,:8,:9,:10,:11,:12,:13,:14,:15,:16,DECODE(:17,0,NULL,
  :17),:18,:19)
--继续分配index的空间
update seg$ set type#=:4,blocks=:5,extents=:6,minexts=:7,maxexts=:8,extsize=
  :9,extpct=:10,user#=:11,iniexts=:12,lists=decode(:13, 65535, NULL, :13),
  groups=decode(:14, 65535, NULL, :14), cachehint=:15, hwmincr=:16, spare1=
  DECODE(:17,0,NULL,:17),scanhint=:18, bitmapranges=:19
where
 ts#=:1 and file#=:2 and block#=:3
--插入index对应的列信息到icol$中
insert into icol$(obj#,bo#,intcol#,pos#,segcol#,segcollength,offset,col#,
  spare1,spare2,spare3)
values
(:1,:2,:3,:4,0,0,0,:5,:6,:7,:8)
--插入index信息到ind$中
insert into ind$(bo#,obj#,ts#,file#,block#,intcols,type#,flags,property,
  pctfree$,initrans,maxtrans,blevel,leafcnt,distkey,lblkkey,dblkkey,clufac,
  cols,analyzetime,samplesize,dataobj#,degree,instances,rowcnt,pctthres$,
  indmethod#,trunccnt,spare1,spare4,spare2,spare6)
values
(:1,:2,:3,:4,:5,:6,:7,:8,:9,:10,:11,:12,:13,:14,:15,:16,:17,:18,:19,:20,:21,
  :22,decode(:23,1,null,:23),decode(:24,1,null,:24),:25, :32*256+:26,:27,:28,
  :29,:30,:31,:33)

通过这里我们基本上可以整体概况出来创建index主要操作了obj$,seg$,icol$,ind$几张基表,那么如果我们想通过dml语句删除index,那可以尝试人工删除这些新增记录

分析人工dml语句删除index

[oracle@web103 ~]$ sqlplus / as sysdba
SQL*Plus: Release 11.2.0.4.0 Production on Sun Aug 16 23:31:49 2015
Copyright (c) 1982, 2013, Oracle.  All rights reserved.
Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
SQL> conn xifenfei/"www.xifenfei.com"
Connected.
SQL> select object_id,data_object_id from user_objects where object_name='IND_XIFENFEI_1';
 OBJECT_ID DATA_OBJECT_ID
---------- --------------
    114642         114642
SQL> select object_id,data_object_id from user_objects where object_name='T_XIFENFEI';
 OBJECT_ID DATA_OBJECT_ID
---------- --------------
    114641         114641
SQL>  SELECT OBJ#,DATAOBJ# FROM SYS.OBJ$ WHERE NAME='IND_XIFENFEI_1';
      OBJ#   DATAOBJ#
---------- ----------
    114642     114642
--通过上面语句我们可以确定,IND_XIFENFEI_1 index的obj#和dataobj#都是为114642,而且可以直接查询obj$基表获得
SQL> SELECT OBJ#,DATAOBJ#,TS#,FILE#,BLOCK# FROM SYS.IND$ WHERE OBJ#=114642;
      OBJ#   DATAOBJ#        TS#      FILE#     BLOCK#
---------- ---------- ---------- ---------- ----------
    114642     114642          4          4     323994
--ind$结合obj$.obj#的信息,可以获得ts#,file#,block#
SQL> SELECT TABLESPACE_NAME,HEADER_FILE,HEADER_BLOCK FROM DBA_SEGMENTS WHERE SEGMENT_NAME='IND_XIFENFEI_1';
TABLESPACE_NAME                HEADER_FILE HEADER_BLOCK
------------------------------ ----------- ------------
USERS                                    4       323994
SQL> SELECT TS# FROM V$TABLESPACE WHERE NAME='USERS';
       TS#
----------
         4
--这里证明ind$中的相关ts#,file#,block#和seg#中存储一致
SQL>  SELECT COL#,POS# FROM  SYS.icol$ WHERE  OBJ#=114642;
      COL#       POS#
---------- ----------
         4          1
         5          2
SQL> SELECT COL#,NAME from SYS.COL$ where OBJ# =114641;
      COL# NAME
---------- ------------------------------
         1 OWNER
         2 OBJECT_NAME
         3 SUBOBJECT_NAME
         4 OBJECT_ID
         5 DATA_OBJECT_ID
         6 OBJECT_TYPE
         7 CREATED
         8 LAST_DDL_TIME
         9 TIMESTAMP
        10 STATUS
        11 TEMPORARY
        12 GENERATED
        13 SECONDARY
        14 NAMESPACE
        15 EDITION_NAME
15 rows selected.
--这里证明icol$中存储的列,正好和我们创建index指定列一致

人工dml删除index

SQL> conn  / as sysdba
Connected.
SQL> delete from obj$ where obj#=114642 and dataobj#=114642;
1 row deleted.
SQL> delete from sys.seg$ where file#=4 and ts#=4 and block#=323994;
1 row deleted.
SQL> delete from icol$ where obj#=114642;
2 rows deleted.
SQL> delete from ind$ where obj#=114642 and file#=4 and ts#=4 and block#=323994;
1 row deleted.
SQL> commit;
Commit complete.

检查dml语句删除index效果

SQL>  select object_id,data_object_id from user_objects where object_name='IND_XIFENFEI_1';
no rows selected
SQL>  SELECT TABLESPACE_NAME,HEADER_FILE,HEADER_BLOCK FROM DBA_SEGMENTS WHERE SEGMENT_NAME='IND_XIFENFEI_1';
no rows selected
SQL> select * from dba_indexes where index_name='IND_XIFENFEI_1';
no rows selected

从数据字典层面看,index IND_XIFENFEI_1确实已经被删除

尝试重建同名index
从数据字典层面查询,该index已经被删除,但是创建报ORA-00955: name is already used by an existing object错误

SQL> create index xifenfei.ind_xifenfei_1 on xifenfei.t_xifenfei(object_id,data_object_id);
create index xifenfei.ind_xifenfei_1 on xifenfei.t_xifenfei(object_id,data_object_id)
                      *
ERROR at line 1:
ORA-00955: name is already used by an existing object

解决重建同名index报ORA-00955错误

SQL> ALTER SESSION SET EVENTS '955 trace name errorstack level 3';
Session altered.
SQL> create index xifenfei.ind_xifenfei_1 on xifenfei.t_xifenfei(object_id,data_object_id);
create index xifenfei.ind_xifenfei_1 on xifenfei.t_xifenfei(object_id,data_object_id)
                      *
ERROR at line 1:
ORA-00955: name is already used by an existing object
SQL>  select value from v$diag_info where name='Default Trace File';
VALUE
--------------------------------------------------------------------------------
/u01/app/oracle/diag/rdbms/test/test/trace/test_ora_20277.trc
--分析trace文件发现创建index执行计划部分
============
Plan Table
============
------------------------------------------------+-----------------------------------+
| Id  | Operation               | Name          | Rows  | Bytes | Cost  | Time      |
------------------------------------------------+-----------------------------------+
| 0   | CREATE INDEX STATEMENT  |               |       |       |   548 |           |
| 1   |  INDEX BUILD NON UNIQUE | IND_XIFENFEI_1|       |       |       |           |
| 2   |   SORT CREATE INDEX     |               |  127K | 3302K |       |           |
| 3   |    INDEX FAST FULL SCAN | IND_XIFENFEI_1|       |       |       |           |
------------------------------------------------+-----------------------------------+
--从这里大概知道原因了,创建index之时,由于shared pool里面依旧记录了老的index信息,因此再次创建index之时,
--直接从老index读取信息,而且明确也依旧是在shared pool里面检查未通过,从而出现了ORA-00955错误
SQL> alter system flush shared_pool;
System altered.
SQL> create index xifenfei.ind_xifenfei_1 on xifenfei.t_xifenfei(object_id,data_object_id);
Index created.
SQL> select obj#,dataobj# from SYS.obj$ where name='IND_XIFENFEI_1';
      OBJ#   DATAOBJ#
---------- ----------
    114643     114643
SQL> select object_type,object_name from dba_objects where object_id=114643;
OBJECT_TYPE
-------------------
OBJECT_NAME
--------------------------------------------------------------------------------
INDEX
IND_XIFENFEI_1
SQL> select index_name from dba_indexes where table_name='T_XIFENFEI' AND OWNER='XIFENFEI';
INDEX_NAME
------------------------------
IND_XIFENFEI_1

补充说明
1.在不同的数据库版本,不同的平台可能操作语句以后一定的出入,依据你测试为准
2.在dml删除index操作中,可能还涉及到一些其他外围表处理,比如统计信息等
3.切勿在生产库中测试,否则可能导致数据库数据字典混乱,后果非常严重

在win 64位平台上运行bbed(支持ORACLE 10g 11g 12c)

很多朋友反馈在win 64位操作系统之上无法使用bbed(包括9i,10g,11g,12c数据库版本),以前写过一篇文章,完美实现了在win平台的各个版本的数据库版本之上实现使用bbed(在win中运行bbed程序),可惜很遗憾没有注明平台信息,留下了不少疑问,今天在自己的电脑上再次实现此功能,用来证明win 64位的平台之上也可以运行bbed程序(数据库版本包括10g,11g,12c,在10g之前x86架构中无win 64位版本数据库,因此我也无能为力).

操作系统版本64位
本机测试为win 7 64位操作系统
win-64


win-64-2


数据库版本64位
本机测试数据库版本为12.1.0.2 64位版本(因为12c都支持,那对于10g/11g更是不在话下)
db-64


bbed运行情况
这里的bbed只是运行起来,并未加载数据文件,因此这里看到的FILENAME为空,但是不妨碍证明bbed可以在win平台,64位的数据库中运行
bbed-win64


整体证明win 64位平台,64位数据库运行bbed
一图抵上千言万语,让我们使用一幅完整截图来说明,bbed是可以运行在win 64位平台的64位版本的数据库之上(而且这里使用了目前最新的12.1.0.2版本)
oracle-64-bbed-10g-11g-12c

记录一次存储异常数据库恢复后遗症ORA-600[kafspa:columnBuffer1]错误处理

先说下前提,这个库以前是由于存储异常,找硬件厂商做了raid重组,然后我进行数据恢复的,恢复出来数据之后,应用厂商通过验证和补数据,然后迁移到另外一台机器做生产用的,这个库一直没有怎么看,最近检查数据库发现ORA-600[kafspa:columnBuffer1]错误,通过删除异常记录的方式解决.
数据库alert日志

Mon Aug 10 00:00:21 2015
LNS: Standby redo logfile selected for thread 1 sequence 617 for destination LOG_ARCHIVE_DEST_2
Mon Aug 10 00:00:33 2015
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\xff\xff\trace\xff_j002_6900.trc  (incident=146517):
ORA-00600: internal error code, arguments: [kafspa:columnBuffer1], [2883], [1], [], [], [], [], [], [], [], [], []
Incident details in: D:\APP\ADMINISTRATOR\diag\rdbms\xff\xff\incident\incdir_146517\xff_j002_6900_i146517.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 D:\APP\ADMINISTRATOR\diag\rdbms\xff\xff\trace\xff_j002_6900.trc:
ORA-12012: error on auto execute of job "SYS"."ORA$AT_OS_OPT_SY_280"
ORA-20011: Approximate NDV failed:
ORA-00600: internal error code, arguments: [kafspa:columnBuffer1], [2883], [1], [], [], [], [], [], [], [], [], []
ORA-06512: at "SYS.DBMS_STATS", line 31228

分析日志发现

*** 2015-07-19 06:00:30.231
*** SESSION ID:(578.751) 2015-07-19 06:00:30.231
*** CLIENT ID:() 2015-07-19 06:00:30.231
*** SERVICE NAME:(SYS$USERS) 2015-07-19 06:00:30.231
*** MODULE NAME:(DBMS_SCHEDULER) 2015-07-19 06:00:30.231
*** ACTION NAME:(ORA$AT_OS_OPT_SY_220) 2015-07-19 06:00:30.231
Dump continued from file: D:\APP\ADMINISTRATOR\diag\rdbms\xff\xff\trace\xff_j001_4444.trc
ORA-00600: internal error code, arguments: [kafspa:columnBuffer1], [2883], [1], [], [], [], [], [], [], [], [], []
========= Dump for incident 146142 (ORA 600 [kafspa:columnBuffer1]) ========
*** 2015-07-19 06:00:30.231
dbkedDefDump(): Starting incident default dumps (flags=0x2, level=3, mask=0x0)
----- Current SQL Statement for this session (sql_id=g0q33k8qtbcpd) -----
/* SQL Analyze(1) */ select /*+  full(t)    no_parallel(t) no_parallel_index(t)
 dbms_stats cursor_sharing_exact use_weak_name_resl
dynamic_sampling(0) no_monitoring no_substrb_pad
…………
to_char(substrb(dump(max("LIST_NO"),16,0,32),1,120)) from "CHF"."T_XIFENFEI" t
…………

对表进行收集统计信息

SQL> EXEC DBMS_STATS.gather_table_stats('CHF','T_XIFENFEI',CASCADE=>TRUE)
;
BEGIN DBMS_STATS.gather_table_stats('CHF','T_XIFENFEI',CASCADE=>TRUE); EN
D;
*
第 1 行出现错误:
ORA-20011: Approximate NDV failed: ORA-00600: 内部错误代码, 参数:
[kafspa:columnBuffer1], [2883], [1], [], [], [], [], [], [], [], [], []
ORA-06512: 在 "SYS.DBMS_STATS", line 24232
ORA-06512: 在 "SYS.DBMS_STATS", line 24332
ORA-06512: 在 line 1
SQL> desc "CHF"."T_XIFENFEI"
 名称                                      是否为空? 类型
 ----------------------------------------- -------- -----------------
 VISIT_DATE                                         DATE
…………
 GETDRUG_FLAG                                       VARCHAR2(2)
…………

通过上面的alert日志和trace文件以及人工收集统计信息,基本上可以定位是由于数据库自动收集统计信息进程在进行统计信息收集之时,对于”CHF”.”T_XIFENFEI”表进行收集统计信息由于某种错误,从而出现该错误.查询mos,发现此类问题主要是由于varchar2类型存储的数据长度超过了表定义长度.

通过验证官方所说

C:\Users\Administrator>exp "'/ as sysdba'" tables="CHF"."T_XIFENFEI" file
=y:/1.dmp log=y:/1.log
Export: Release 11.2.0.4.0 - Production on 星期四 8月 13 11:03:22 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.
连接到: Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Produc
tion
With the Partitioning, OLAP, Data Mining and Real Application Testing options
已导出 ZHS16GBK 字符集和 AL16UTF16 NCHAR 字符集
即将导出指定的表通过常规路径...
当前的用户已更改为 CHF
. . 正在导出表                    T_XIFENFEI
EXP-00015: 错误出现在行 1339552 (表 T_XIFENFEI, 列 GETDRUG_FLAG), 数据类型 1
EXP-00001: 数据字段截断 - 列长度 =2, 缓冲区大小 =2 实际大小 =17Errors in file :
OCI-21500: 内部错误代码, 参数: [kghfrempty:ds], [0x00652FCC8], [], [], [], [], [
], []
----- Call Stack Trace -----
calling              call     entry                argument values in hex
location             type     point                (? means dubious value)
-------------------- -------- -------------------- ----------------------------
kgerinv_internal()+  CALL???  skgudmp()            000000000 006447680 000000000
139                                                006447680
kgerinv()+49         CALL???  kgerinv_internal()   000000001 000676B4D 0064985B0
                                                   000000000
kgerin()+49          CALL???  kgerinv()            000000018 000799612 000072000
                                                   000000000
kghnerror()+294      CALL???  kgerin()             006447680 00645092C 006447680
                                                   000000001
kghfrempty()+639     CALL???  kghnerror()          0000001F0 000000000
                                                   BE019800000000 7E01960000
kghgex()+1433        CALL???  kghfrempty()+368     000000000 00652CAD8 000000000
                                                   000000000
kghfnd()+808         CALL???  kghgex()             001004000 000000000 001BEDD10
                                                   001A7131C
kghalo()+610         CALL???  kghfnd()             00012C450 00012C4A0 000000000
                                                   006446FD0
kghgex()+445         CALL???  kghalo()             006494848 000000000 001BEDD10
                                                   00190A575
kghfnd()+808         CALL???  kghgex()             000000001 0000001A0 000000000
                                                   006493D68
kghalo()+610         CALL???  kghfnd()             000000000 006447680 0FFFFFFFF
                                                   006447680
kpuhhalo()+358       CALL???  kghalo()             000000000 000000178 07FFFFFFF
                                                   000000001
kpuertb_reallocTemp  CALL???  kpuhhalo()           00652C498 000003E84 001C0EA44
Buf()+192                                          000000000
kpuex_reallocTempBu  CALL???  kpuertb_reallocTemp  000004007 0018BA3BF 00012CAB0
f()+67                        Buf()                001AB296F
kpudefn()+347        CALL???  kpuex_reallocTempBu  00012CC38 001004000 001BEDD44
                              f()                  000000004
kpudfn()+1506        CALL???  kpudefn()            00012F3D0 000000004 006520044
                                                   000000000
OCIDefineByPos()+10  CALL???  kpudfn()             004327570 000000000 00012F3D0
2                                                  000000004
00000001400116E5     CALL???  OCIDefineByPos()     1043B9300 0043B92C0 0044002B8
                                                   004401394
000000014004AFC7     CALL???  00000001400113BA     00012F380 00012F0E0 000000068
                                                   14004B2B6
000000014001E784     CALL???  000000014004A37E     000013F30 140095A71 140097520
                                                   14009F540
00000001400027A7     CALL???  000000014001E39F     14009F838 00012FB5C 140097520
                                                   14009F540
000000014000102C     CALL???  0000000140001E2C     000000005 004327570
                                                   1D0D5749D21764D 000000000
000000014006BEF0     CALL???  000000014000100E     000130000 1AFBFE2D0D8
                                                   000000000 000000000
000000007748652D     CALL???  000000014006BDD0     000000000 000000000 000000000
                                                   000000000
00000000775BC521     CALL???  0000000077486520     000000000 000000000 000000000
                                                   000000000
call stack performance statistics:
total                  : 0.778000 sec
setup                  : 0.350000 sec
stack unwind           : 0.099000 sec
symbol translation     : 0.021000 sec
printing the call stack: 0.304000 sec
printing frame data    : 0.000000 sec
printing argument data : 0.000000 sec
----- End of Call Stack Trace -----

这里通过exp验证到数据在GETDRUG_FLAG列上有异常,本来定义列长度为2,可是实际数据长度为17,明显不符

通过plsql定位具体错误rowid

SQL> set serveroutput on
SQL> DECLARE
  2   TYPE RowIDTab IS TABLE OF ROWID INDEX BY BINARY_INTEGER;
  3   CURSOR c1 IS  select /*+index(t PK_T_XIFENFEI_BAK_NEW)*/ rowid from CHF.T_XIFENFEI t;
  4   r RowIDTab;
  5   rows  NATURAL := 20000;
  6   bad_rows number := 0 ;
  7   errors number;
  8   error_code number;
  9   myrowid rowid;
 10  BEGIN
 11   OPEN c1;
 12   LOOP
 13     FETCH  c1 BULK COLLECT INTO r LIMIT rows;
 14     EXIT WHEN r.count=0;
 15     BEGIN
 16      FORALL i IN r.FIRST..r.LAST SAVE EXCEPTIONS
 17       insert into CHF.T_XIFENFEI_new
 18       select /*+ ROWID(A) */ *
 19       from CHF.T_XIFENFEI A where rowid = r(i);
 20     EXCEPTION
 21     when OTHERS then
 22      BEGIN
 23       errors := SQL%BULK_EXCEPTIONS.COUNT;
 24       FOR err1 IN 1..errors LOOP
 25           error_code := SQL%BULK_EXCEPTIONS(err1).ERROR_CODE;
 26           myrowid := r(SQL%BULK_EXCEPTIONS(err1).ERROR_INDEX);
 27           bad_rows := bad_rows + 1;
 28           insert into system.had_rows values('CHF.T_XIFENFEI',myrowid, error_code);
 29       END LOOP;
 30       END;
 31     END;
 32    commit;
 33   END LOOP;
 34   commit;
 35   CLOSE c1;
 36   dbms_output.put_line('Total Bad Rows: '||bad_rows);
 37  END;
 38  /
Total Bad Rows: 1
PL/SQL 过程已成功完成。
SQL> SELECT row_id FROM  system.had_rows ;
 ROW_ID
 ------------------
 AAAT8wAAEAAAM29AAX
SQL> select * from  CHF.T_XIFENFEI WHERE ROWID='AAAT8wAAEAAAM29AAX';
select * from  CHF.T_XIFENFEI WHERE ROWID='AAAT8wAAEAAAM29AAX'
                        *
第 1 行出现错误:
ORA-00600: 内部错误代码, 参数: [kafspa:columnBuffer1], [2883], [1], [], [], [],
[], [], [], [], [], []

通过这里基本上可以定位到是该条rowid记录有问题,和业务进行沟通,确定该条记录可以删除(也不能访问,其实不删除也没用)

删除异常记录

SQL> delete from CHF.T_XIFENFEI WHERE ROWID='AAAT8wAAEAAAM29AAX';
已删除 1 行。
SQL> commit;
提交完成。

收集统计信息

SQL> EXEC DBMS_STATS.gather_table_stats('CHF','T_XIFENFEI',CASCADE=>TRUE)
;
PL/SQL 过程已成功完成。

通过清理异常记录,数据库可以正常收集统计信息,未再报ORA-00600[kafspa:columnBuffer1]错误,故障较完美解决

补充几个现象
1. analyze table “CHF”.”T_XIFENFEI” estimate statistics; 分析表统计信息正常,但是dbms_stats收集报错(因为dbms_stats相当对于每个列进行了扫描,而analyze应该不是)
2. 在报ORA-00600[kafspa:columnBuffer1]的情况下,ctas依旧可以成功,但是普通插入不行(因为ctas相当加油append操作),因此在有些情况下,需要慎重append(特别是有逻辑坏块的时候)

aix平台 ORA-01115 ORA-01110 ORA-27067 故障恢复

接到朋友恢复请求,aix 5.3,Oracle 10.2.0.1平台,数据库启动报ORA-01115 ORA-01110 ORA-27067错误,数据库无法正常打开,通过分析,是由于10201在aix上面的bug导致,通过技巧规避,完美解决给问题,数据0丢失
数据库报错alert日志

Mon Aug 10 13:25:22 2015
ALTER DATABASE   MOUNT
Mon Aug 10 13:25:29 2015
Setting recovery target incarnation to 1
Mon Aug 10 13:25:29 2015
Successful mount of redo thread 1, with mount id 432339141
Mon Aug 10 13:25:29 2015
Database mounted in Exclusive Mode
Completed: ALTER DATABASE   MOUNT
Mon Aug 10 13:25:36 2015
alter database open
Mon Aug 10 13:25:36 2015
Beginning crash recovery of 1 threads
 parallel recovery started with 15 processes
Mon Aug 10 13:25:37 2015
Started redo scan
Mon Aug 10 13:25:52 2015
Completed redo scan
 7889582 redo blocks read, 75305 data blocks need recovery
Mon Aug 10 13:25:53 2015
Errors in file /dc/admin/datacent/bdump/datacent_p002_144124.trc:
ORA-01115: IO error reading block from file 2 (block # 40704)
ORA-01110: data file 2: '/dc/oradata/datacent/undotbs01.dbf'
ORA-27067: size of I/O buffer is invalid
Additional information: 2
Additional information: 1572864
Mon Aug 10 13:25:53 2015
Aborting crash recovery due to slave death, attempting serial crash recovery
Mon Aug 10 13:25:53 2015
Beginning crash recovery of 1 threads
Mon Aug 10 13:25:53 2015
Started redo scan
Mon Aug 10 13:26:09 2015
Completed redo scan
 7889582 redo blocks read, 75305 data blocks need recovery
Mon Aug 10 13:26:12 2015
Aborting crash recovery due to error 1115
Mon Aug 10 13:26:12 2015
Errors in file /dc/admin/datacent/udump/datacent_ora_123384.trc:
ORA-01115: IO error reading block from file 2 (block # 39077)
ORA-01110: data file 2: '/dc/oradata/datacent/undotbs01.dbf'
ORA-27067: size of I/O buffer is invalid
Additional information: 2
Additional information: 1310720
ORA-1115 signalled during: alter database open...

这里报的前面两个错误ORA-01115 ORA-01110我们都非常熟悉,类似数据库启动遇到坏块或者io错误之时可能就会报如此错误。但是ORA-27067确实不多见,从mos上看,很多是由于rman备份之时的bug可能导致该错误。

dbv检测undo坏块文件

DBVERIFY: Release 10.2.0.1.0 - Production on Mon Aug 10 23:18:15 2015
Copyright (c) 1982, 2003, Oracle and/or its affiliates.  All rights reserved.
DBVERIFY - Verification starting : FILE = /dc/oradata/datacent/undotbs01.dbf
DBVERIFY - Verification complete
Total Pages Examined         : 329600
Total Pages Processed (Data) : 0
Total Pages Failing   (Data) : 0
Total Pages Processed (Index): 0
Total Pages Failing   (Index): 0
Total Pages Processed (Other): 327504
Total Pages Processed (Seg)  : 17
Total Pages Failing   (Seg)  : 0
Total Pages Empty            : 2096
Total Pages Marked Corrupt   : 0
Total Pages Influx           : 0
Total Pages Encrypted        : 0
Highest block SCN            : 1887888 (0.1887888)

这里可以看到,undo文件本身并没有逻辑和物理的坏块,证明因为数据库异常的原因,可能是由于ORA-27067: size of I/O buffer is invalid导致。根据官方文档ORA-01115 ORA-27067 DURING PARALLEL INSTANCE RECOVERY AFTER INSTANCE CRASH中的解释,我们基本上可以确定很可能是由于10.2.0.1在aix平台的jfs2系统中,由于大量事务操作,突然abort掉数据库(也可能断电),从而数据库在启动的时候进行实例恢复,而由于内部的bug,导致实例恢复无法成功。通过我们处理后的,数据库完美启动,数据0丢失

数据库启动日志

Mon Aug 10 16:34:14 2015
alter database open
Mon Aug 10 16:34:14 2015
Beginning crash recovery of 1 threads
 parallel recovery started with 15 processes
Mon Aug 10 16:34:14 2015
Started redo scan
Mon Aug 10 16:34:27 2015
Completed redo scan
 7889582 redo blocks read, 0 data blocks need recovery
Mon Aug 10 16:34:27 2015
Started redo application at
 Thread 1: logseq 664704, block 1286922
Mon Aug 10 16:34:27 2015
Recovery of Online Redo Log: Thread 1 Group 4 Seq 664704 Reading mem 0
  Mem# 0 errs 0: /dev/rredo04
Mon Aug 10 16:34:32 2015
Recovery of Online Redo Log: Thread 1 Group 5 Seq 664705 Reading mem 0
  Mem# 0 errs 0: /dev/rredo05
Mon Aug 10 16:34:38 2015
Recovery of Online Redo Log: Thread 1 Group 6 Seq 664706 Reading mem 0
  Mem# 0 errs 0: /dev/rredo06
Mon Aug 10 16:34:40 2015
Completed redo application
Mon Aug 10 16:34:40 2015
Completed crash recovery at
 Thread 1: logseq 664706, block 1017805, scn 8554793334
 0 data blocks read, 0 data blocks written, 7889582 redo blocks read
Mon Aug 10 16:34:40 2015
Thread 1 advanced to log sequence 664707
Thread 1 opened at log sequence 664707
  Current log# 1 seq# 664707 mem# 0: /dev/rredo01
Successful open of redo thread 1
Mon Aug 10 16:34:40 2015
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Mon Aug 10 16:34:40 2015
SMON: enabling cache recovery
Mon Aug 10 16:34:40 2015
Successfully onlined Undo Tablespace 1.
Mon Aug 10 16:34:40 2015
SMON: enabling tx recovery
Mon Aug 10 16:34:41 2015
Database Characterset is ZHS32GB18030
replication_dependency_tracking turned off (no async multimaster replication found)
WARNING: AQ_TM_PROCESSES is set to 0. System operation might be adversely affected.
Mon Aug 10 16:34:41 2015
SMON: Parallel transaction recovery tried
Mon Aug 10 16:34:42 2015
db_recovery_file_dest_size of 2048 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.
Mon Aug 10 16:34:42 2015
Completed: alter database open

分享oracleasm createdisk重新创建asm disk后数据0丢失恢复案例

有客户反馈他们重启系统之后,发现asmlib创建的asmdisk丢失了,然后又使用oracleasm deletedisk和createdisk重新创建的asm disk,最后发现asm diskgroup无法mount。让客户通过dd 备份5m数据,然后使用kfed分析
kefd分析结果

E:\OneDrive\ORACLE\recover\no_backup\asm\kfedwin>kfed read H:\temp\asmlib\xx.img
kfbh.endian:                          0 ; 0x000: 0x00
kfbh.hard:                            0 ; 0x001: 0x00
kfbh.type:                            0 ; 0x002: KFBTYP_INVALID
kfbh.datfmt:                          0 ; 0x003: 0x00
kfbh.block.blk:                       0 ; 0x004: T=0 NUMB=0x0
kfbh.block.obj:                       0 ; 0x008: TYPE=0x0 NUMB=0x0
kfbh.check:                  3760689243 ; 0x00c: 0xe027905b
kfbh.fcn.base:                        0 ; 0x010: 0x00000000
kfbh.fcn.wrap:                        0 ; 0x014: 0x00000000
kfbh.spare1:                          0 ; 0x018: 0x00000000
kfbh.spare2:                          0 ; 0x01c: 0x00000000
E:\OneDrive\ORACLE\recover\no_backup\asm\kfedwin>kfed read H:\temp\asmlib\xx.img blkn=1
kfbh.endian:                          0 ; 0x000: 0x00
kfbh.hard:                            0 ; 0x001: 0x00
kfbh.type:                            0 ; 0x002: KFBTYP_INVALID
kfbh.datfmt:                          0 ; 0x003: 0x00
kfbh.block.blk:                       0 ; 0x004: T=0 NUMB=0x0
kfbh.block.obj:                       0 ; 0x008: TYPE=0x0 NUMB=0x0
kfbh.check:                           0 ; 0x00c: 0x00000000
kfbh.fcn.base:                        0 ; 0x010: 0x00000000
kfbh.fcn.wrap:                        0 ; 0x014: 0x00000000
kfbh.spare1:                          0 ; 0x018: 0x00000000
kfbh.spare2:                          0 ; 0x01c: 0x00000000
E:\OneDrive\ORACLE\recover\no_backup\asm\kfedwin>kfed read H:\temp\asmlib\xx.img blkn=10
kfbh.endian:                          0 ; 0x000: 0x00
kfbh.hard:                            0 ; 0x001: 0x00
kfbh.type:                            0 ; 0x002: KFBTYP_INVALID
kfbh.datfmt:                          0 ; 0x003: 0x00
kfbh.block.blk:                       0 ; 0x004: T=0 NUMB=0x0
kfbh.block.obj:                       0 ; 0x008: TYPE=0x0 NUMB=0x0
kfbh.check:                           0 ; 0x00c: 0x00000000
kfbh.fcn.base:                        0 ; 0x010: 0x00000000
kfbh.fcn.wrap:                        0 ; 0x014: 0x00000000
kfbh.spare1:                          0 ; 0x018: 0x00000000
kfbh.spare2:                          0 ; 0x01c: 0x00000000
E:\OneDrive\ORACLE\recover\no_backup\asm\kfedwin>kfed read H:\temp\asmlib\xx.img blkn=255
kfbh.endian:                          0 ; 0x000: 0x00
kfbh.hard:                            0 ; 0x001: 0x00
kfbh.type:                            0 ; 0x002: KFBTYP_INVALID
kfbh.datfmt:                          0 ; 0x003: 0x00
kfbh.block.blk:                       0 ; 0x004: T=0 NUMB=0x0
kfbh.block.obj:                       0 ; 0x008: TYPE=0x0 NUMB=0x0
kfbh.check:                           0 ; 0x00c: 0x00000000
kfbh.fcn.base:                        0 ; 0x010: 0x00000000
kfbh.fcn.wrap:                        0 ; 0x014: 0x00000000
kfbh.spare1:                          0 ; 0x018: 0x00000000
kfbh.spare2:                          0 ; 0x01c: 0x00000000
E:\OneDrive\ORACLE\recover\no_backup\asm\kfedwin>kfed read H:\temp\asmlib\xx.img blkn=256|more
kfbh.endian:                          1 ; 0x000: 0x01
kfbh.hard:                          130 ; 0x001: 0x82
kfbh.type:                           17 ; 0x002: KFBTYP_PST_META
kfbh.datfmt:                          2 ; 0x003: 0x02
kfbh.block.blk:                     256 ; 0x004: T=0 NUMB=0x100
kfbh.block.obj:              2147483648 ; 0x008: TYPE=0x8 NUMB=0x0
kfbh.check:                  3925268785 ; 0x00c: 0xe9f6d931
kfbh.fcn.base:                        0 ; 0x010: 0x00000000
kfbh.fcn.wrap:                        0 ; 0x014: 0x00000000
kfbh.spare1:                          0 ; 0x018: 0x00000000
kfbh.spare2:                          0 ; 0x01c: 0x00000000
kfdpHdrPairBv1.first.super.time.hi:32994098 ; 0x000: HOUR=0x12 DAYS=0x19 MNTH=0x
c YEAR=0x7dd
kfdpHdrPairBv1.first.super.time.lo:1614030848 ; 0x004: USEC=0x0 MSEC=0x10a SECS=
0x3 MINS=0x18
kfdpHdrPairBv1.first.super.last:      2 ; 0x008: 0x00000002
kfdpHdrPairBv1.first.super.next:      2 ; 0x00c: 0x00000002
kfdpHdrPairBv1.first.super.copyCnt:   1 ; 0x010: 0x01
kfdpHdrPairBv1.first.super.version:   1 ; 0x011: 0x01
kfdpHdrPairBv1.first.super.ub2spare:  0 ; 0x012: 0x0000
kfdpHdrPairBv1.first.super.incarn:    1 ; 0x014: 0x00000001
kfdpHdrPairBv1.first.super.copy[0]:   0 ; 0x018: 0x0000
kfdpHdrPairBv1.first.super.copy[1]:   0 ; 0x01a: 0x0000
kfdpHdrPairBv1.first.super.copy[2]:   0 ; 0x01c: 0x0000
……

因为kfed默认每个block为4k,这里提示256是ok的,255是损坏的,从而推测出来,很可能oracleasm createdisk损坏了1M的数据。由于默认au是1m,而且数据库版本是11.2.0.3,而且第256个blkn开始没有损坏,因此初步判断可以考虑使用备份asm disk header来恢复磁盘头
检查还原磁盘头的asm disk

[grid@xifenfei1 disks]$ kfed read DATA1
kfbh.endian:                          1 ; 0x000: 0x01
kfbh.hard:                          130 ; 0x001: 0x82
kfbh.type:                            1 ; 0x002: KFBTYP_DISKHEAD
kfbh.datfmt:                          1 ; 0x003: 0x01
kfbh.block.blk:                       0 ; 0x004: blk=0
kfbh.block.obj:              2147483648 ; 0x008: disk=0
kfbh.check:                  2776451033 ; 0x00c: 0xa57d47d9
kfbh.fcn.base:                        0 ; 0x010: 0x00000000
kfbh.fcn.wrap:                        0 ; 0x014: 0x00000000
kfbh.spare1:                          0 ; 0x018: 0x00000000
kfbh.spare2:                          0 ; 0x01c: 0x00000000
kfdhdb.driver.provstr:    ORCLDISKDATA1 ; 0x000: length=13
kfdhdb.driver.reserved[0]:   1096040772 ; 0x008: 0x41544144
kfdhdb.driver.reserved[1]:           49 ; 0x00c: 0x00000031
kfdhdb.driver.reserved[2]:            0 ; 0x010: 0x00000000
kfdhdb.driver.reserved[3]:            0 ; 0x014: 0x00000000
kfdhdb.driver.reserved[4]:            0 ; 0x018: 0x00000000
kfdhdb.driver.reserved[5]:            0 ; 0x01c: 0x00000000
kfdhdb.compat:                186646528 ; 0x020: 0x0b200000
kfdhdb.dsknum:                        0 ; 0x024: 0x0000
kfdhdb.grptyp:                        1 ; 0x026: KFDGTP_EXTERNAL
kfdhdb.hdrsts:                        3 ; 0x027: KFDHDR_MEMBER
kfdhdb.dskname:               DATA_0000 ; 0x028: length=9
kfdhdb.grpname:                    DATA ; 0x048: length=4
kfdhdb.fgname:                DATA_0000 ; 0x068: length=9
kfdhdb.capname:                         ; 0x088: length=0
kfdhdb.crestmp.hi:             32994099 ; 0x0a8: HOUR=0x13 DAYS=0x19 MNTH=0xc YEAR=0x7dd
kfdhdb.crestmp.lo:           2797442048 ; 0x0ac: USEC=0x0 MSEC=0x365 SECS=0x2b MINS=0x29
kfdhdb.mntstmp.hi:             33022061 ; 0x0b0: HOUR=0xd DAYS=0x3 MNTH=0x8 YEAR=0x7df
kfdhdb.mntstmp.lo:            816879616 ; 0x0b4: USEC=0x0 MSEC=0x26 SECS=0xb MINS=0xc
kfdhdb.secsize:                     512 ; 0x0b8: 0x0200
kfdhdb.blksize:                    4096 ; 0x0ba: 0x1000
…………

证明磁盘头确实被比较完美的修复了,现在的任务是尝试mount磁盘组
mount磁盘组

[grid@xifenfei1 ~]$ sqlplus / as sysasm
SQL*Plus: Release 11.2.0.3.0 Production on Thu Aug 6 20:54:53 2015
Copyright (c) 1982, 2011, Oracle.  All rights reserved.
Connected to:
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Real Application Clusters and Automatic Storage Management options
SQL> alter diskgroup data mount;
Diskgroup altered.
SQL> exit
Disconnected from Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Real Application Clusters and Automatic Storage Management options

asm diskgroup已经正常mount,使用asmcmd命令检查文件是否正常
分析磁盘组数据是否正常

[grid@xifenfei1 ~]$ asmcmd
ASMCMD> lsdg
State    Type    Rebal  Sector  Block       AU  Total_MB  Free_MB  Req_mir_free_MB  Usable_file_MB  Offline_disks  Voting_files  Name
MOUNTED  EXTERN  N         512   4096  1048576   1622060   636493                0          636493              0             N  DATA/
ASMCMD> cd data
ASMCMD> ls
ORCL/
ASMCMD> cd orcl
ASMCMD> ls
CONTROLFILE/
DATAFILE/
ONLINELOG/
PARAMETERFILE/
TEMPFILE/
spfileorcl.ora
ASMCMD> cd datafile
ASMCMD> ls
XIFENFEI20130801.314.835191517
XIFENFEI20140101.321.835191571
XIFENFEI20140201.322.835191573
XIFENFEI20140301.323.835191573
…………
SYSAUX.270.835182535
SYSAUX.838.874669369
SYSTEM.271.835182533
SYSTEM.823.873555791
SYSTEM.945.883146947
…………

这里看到磁盘组里面的数据文件都正常,使用同样的方法,继续mount其他磁盘组。
尝试启动数据库

SQL> startup
ORACLE 例程已经启动。
Total System Global Area 5010685952 bytes
Fixed Size                  2236968 bytes
Variable Size            2013269464 bytes
Database Buffers         2986344448 bytes
Redo Buffers                8835072 bytes
数据库装载完毕。
ORA-16038: 日志 14 sequence# 21145 无法归档
ORA-19504: 无法创建文件""
ORA-00312: 联机日志 14 线程 2: '+DATA/orcl/onlinelog/group_14.284.835184569'
ORA-00312: 联机日志 14 线程 2: '+ARCH/orcl/onlinelog/group_14.287.835184569'

查看数据库alert日志

ARC1: Archival started
ARC2: Archival started
ARC2: Becoming the 'no FAL' ARCH
ARC2: Becoming the 'no SRL' ARCH
ARC1: Becoming the heartbeat ARCH
ARC3: Archival started
ARC0: STARTING ARCH PROCESSES COMPLETE
Thu Aug 06 21:04:06 2015
Thread 2 advanced to log sequence 21146 (thread recovery)
Picked broadcast on commit scheme to generate SCNs
Thread 2 advanced to log sequence 21147 (before internal thread enable)
Errors in file /u01/app/oracle/diag/rdbms/orcl/orcl1/trace/orcl1_ora_27402.trc:
ORA-19816: 警告: 文件可能存在于数据库未知的 db_recovery_file_dest 中。
ORA-17502: ksfdcre: 4 未能创建文件 +ARCH
ORA-15196: invalid ASM block header [kfc.c:19572] [check_kfbh] [1] [47962] [1344818371 != 630731762]
ORA-15130: diskgroup "ARCH" is being dismounted
ORA-15066: offlining disk "ARCH_0000" in group "ARCH" may result in a data loss
ORA-15196: invalid ASM block header [kfc.c:26076] [endian_kfbh] [2147483648] [1] [0 != 1]
ORA-15196: invalid ASM block header [kfc.c:26076] [endian_kfbh] [2147483648] [1] [0 != 1]
ARCH: Error 19504 Creating archive log file to '+ARCH'
NOTE: Deferred communication with ASM instance
Errors in file /u01/app/oracle/diag/rdbms/orcl/orcl1/trace/orcl1_ora_27402.trc:
ORA-15130: diskgroup "ARCH" is being dismounted
NOTE: deferred map free for map id 754
Errors in file /u01/app/oracle/diag/rdbms/orcl/orcl1/trace/orcl1_ora_27402.trc:
ORA-16038: 日志 14 sequence# 21145 无法归档
ORA-19504: 无法创建文件""
ORA-00312: 联机日志 14 线程 2: '+DATA/orcl/onlinelog/group_14.284.835184569'
ORA-00312: 联机日志 14 线程 2: '+ARCH/orcl/onlinelog/group_14.287.835184569'
ORA-16038 signalled during: ALTER DATABASE OPEN...
Thu Aug 06 21:04:10 2015
SUCCESS: diskgroup ARCH was dismounted
SUCCESS: diskgroup ARCH was dismounted
Thu Aug 06 21:04:10 2015
Errors in file /u01/app/oracle/diag/rdbms/orcl/orcl1/trace/orcl1_ckpt_27353.trc:
ORA-00206: error in writing (block 3, # blocks 1) of control file
ORA-00202: control file: '+ARCH/orcl/controlfile/current.256.835182531'
ORA-15078: ASM diskgroup was forcibly dismounted
ORA-15078: ASM diskgroup was forcibly dismounted
Errors in file /u01/app/oracle/diag/rdbms/orcl/orcl1/trace/orcl1_ckpt_27353.trc:
ORA-00221: error on write to control file
ORA-00206: error in writing (block 3, # blocks 1) of control file
ORA-00202: control file: '+ARCH/orcl/controlfile/current.256.835182531'
ORA-15078: ASM diskgroup was forcibly dismounted
ORA-15078: ASM diskgroup was forcibly dismounted
Thu Aug 06 21:04:10 2015
System state dump requested by (instance=1, osid=27353 (CKPT)), summary=[abnormal instance termination].
System State dumped to trace file /u01/app/oracle/diag/rdbms/orcl/orcl1/trace/orcl1_diag_27318.trc
CKPT (ospid: 27353): terminating the instance due to error 221
Instance terminated by CKPT, pid = 27353

查看asm alert日志

Thu Aug 06 21:04:07 2015
WARNING: cache read  a corrupt block: group=2(ARCH) dsk=0 blk=1 disk=0 (ARCH_0000) incarn=3942486752 au=0 blk=1 count=1
Errors in file /u01/app/11.2.0/grid/log/diag/asm/+asm/+ASM1/trace/+ASM1_ora_27462.trc:
ORA-15196: invalid ASM block header [kfc.c:26076] [endian_kfbh] [2147483648] [1] [0 != 1]
NOTE: a corrupted block from group ARCH was dumped to /u01/app/11.2.0/grid/log/diag/asm/+asm/+ASM1/trace/+ASM1_ora_27462.trc
WARNING: cache read (retry) a corrupt block: group=2(ARCH) dsk=0 blk=1 disk=0 (ARCH_0000) incarn=3942486752 au=0 blk=1 count=1
Errors in file /u01/app/11.2.0/grid/log/diag/asm/+asm/+ASM1/trace/+ASM1_ora_27462.trc:
ORA-15196: invalid ASM block header [kfc.c:26076] [endian_kfbh] [2147483648] [1] [0 != 1]
ORA-15196: invalid ASM block header [kfc.c:26076] [endian_kfbh] [2147483648] [1] [0 != 1]
ERROR: cache failed to read group=2(ARCH) dsk=0 blk=1 from disk(s): 0(ARCH_0000)
ORA-15196: invalid ASM block header [kfc.c:26076] [endian_kfbh] [2147483648] [1] [0 != 1]
ORA-15196: invalid ASM block header [kfc.c:26076] [endian_kfbh] [2147483648] [1] [0 != 1]
NOTE: cache initiating offline of disk 0 group ARCH
NOTE: process _user27462_+asm1 (27462) initiating offline of disk 0.3942486752 (ARCH_0000) with mask 0x7e in group 2
WARNING: Disk 0 (ARCH_0000) in group 2 in mode 0x7f is now being taken offline on ASM inst 1
NOTE: initiating PST update: grp = 2, dsk = 0/0xeafd92e0, mask = 0x6a, op = clear
Thu Aug 06 21:04:07 2015
GMON updating disk modes for group 2 at 17 for pid 35, osid 27462
ERROR: Disk 0 cannot be offlined, since diskgroup has external redundancy.
ERROR: too many offline disks in PST (grp 2)
Thu Aug 06 21:04:07 2015
NOTE: cache dismounting (not clean) group 2/0x723D6245 (ARCH)
NOTE: messaging CKPT to quiesce pins Unix process pid: 27089, image: oracle@xifenfei1 (B000)
WARNING: Offline of disk 0 (ARCH_0000) in group 2 and mode 0x7f failed on ASM inst 1
Thu Aug 06 21:04:07 2015
NOTE: halting all I/Os to diskgroup 2 (ARCH)
System State dumped to trace file /u01/app/11.2.0/grid/log/diag/asm/+asm/+ASM1/trace/+ASM1_ora_27462.trc
NOTE: AMDU dump of disk group ARCH created at /u01/app/11.2.0/grid/log/diag/asm/+asm/+ASM1/trace
Thu Aug 06 21:04:09 2015
NOTE: LGWR doing non-clean dismount of group 2 (ARCH)
NOTE: LGWR sync ABA=126.806 last written ABA 126.806

这里可以看出来,报错的block为arch磁盘组的第一个磁盘的第一个au的第二个block,而我们在开始的时候,已经分析了asm disk的第一个au完全损坏,并且我们使用了备份磁盘头进行来还原,勉强可以让磁盘组mount起来,但是由于数据库在启动的时候,需要对redo进行归档,而归档的过程需要写到arch磁盘组里面,这个时候需要访问到au=0 blk=1,而这个块本身是坏的,因此这个时候该块盘的disk就被offline掉了,而这个磁盘组是外部冗余的,因此磁盘组dismount了,所以数据库无法启动.

分析第一个au里面到底有哪些东西

SQL> select DISK_NUMBER,path from v$asm_disk;
DISK_NUMBER PATH
----------- --------------------------------------------------
          0 /dev/raw/raw1
          2 /dev/raw/raw3
          1 /dev/raw/raw2
[oracle@xifenfei raw]$ kfed read raw1 blkn=1|grep kfbh.type
kfbh.type:                            2 ; 0x002: KFBTYP_FREESPC
[oracle@xifenfei raw]$ kfed read raw1 blkn=2|grep kfbh.type
kfbh.type:                            3 ; 0x002: KFBTYP_ALLOCTBL
[oracle@xifenfei raw]$ kfed read raw1 blkn=3|grep kfbh.type
kfbh.type:                            3 ; 0x002: KFBTYP_ALLOCTBL
[oracle@xifenfei raw]$ kfed read raw1 blkn=255|grep kfbh.type
kfbh.type:                            3 ; 0x002: KFBTYP_ALLOCTBL
[oracle@xifenfei raw]$ kfed read raw2 blkn=1|grep kfbh.type
kfbh.type:                            2 ; 0x002: KFBTYP_FREESPC
[oracle@xifenfei raw]$ kfed read raw2 blkn=2|grep kfbh.type
kfbh.type:                            3 ; 0x002: KFBTYP_ALLOCTBL
[oracle@xifenfei raw]$ kfed read raw2 blkn=255|grep kfbh.type
kfbh.type:                            3 ; 0x002: KFBTYP_ALLOCTBL
[oracle@xifenfei raw]$ kfed read raw3 blkn=1|grep kfbh.type
kfbh.type:                            2 ; 0x002: KFBTYP_FREESPC
[oracle@xifenfei raw]$ kfed read raw3 blkn=2|grep kfbh.type
kfbh.type:                            3 ; 0x002: KFBTYP_ALLOCTBL
[oracle@xifenfei raw]$ kfed read raw3 blkn=255|grep kfbh.type
kfbh.type:                            3 ; 0x002: KFBTYP_ALLOCTBL

通过一个测试机器的一个磁盘组进行分析,我们可以基本上确定asm 第一个au除了asm disk header的KFBTYP_DISKHEAD之外,其他主要是KFBTYP_FREESPC(Free Space Table)和KFBTYP_ALLOCTBL(allocator table),主要就是记录asm中au的分配情况,也就是进一步说明,如果我不对asm里面的数据使用更多的au分配或者回收au,在缺少第一个au的1-255个block的信息情况下,asm的磁盘组也不会dismount。根据这个思路,让数据库归档到本地,然后继续测试

继续open数据库

SQL> startup
ORACLE 例程已经启动。
Total System Global Area 5010685952 bytes
Fixed Size                  2236968 bytes
Variable Size            2013269464 bytes
Database Buffers         2986344448 bytes
Redo Buffers                8835072 bytes
数据库装载完毕。
SQL> alter database open;
数据库已更改。
LGWR: STARTING ARCH PROCESSES COMPLETE
ARC0: STARTING ARCH PROCESSES
Fri Aug 07 02:43:13 2015
ARC1 started with pid=34, OS id=22778
Fri Aug 07 02:43:13 2015
ARC2 started with pid=35, OS id=22780
Fri Aug 07 02:43:13 2015
ARC3 started with pid=36, OS id=22782
ARC1: Archival started
ARC2: Archival started
ARC2: Becoming the 'no FAL' ARCH
ARC2: Becoming the 'no SRL' ARCH
ARC1: Becoming the heartbeat ARCH
ARC3: Archival started
ARC0: STARTING ARCH PROCESSES COMPLETE
Fri Aug 07 02:43:24 2015
Thread 1 opened at log sequence 18604
  Current log# 10 seq# 18604 mem# 0: /tmp/xifenfei/otherfile/group_10.273.835182533
  Current log# 10 seq# 18604 mem# 1: /tmp/xifenfei/otherfile/group_10.263.835182533
Successful open of redo thread 1
Fri Aug 07 02:43:24 2015
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
Fri Aug 07 02:43:25 2015
SMON: enabling cache recovery
Instance recovery: looking for dead threads
Instance recovery: lock domain invalid but no dead threads
Fri Aug 07 02:43:26 2015
minact-scn: Inst 1 is now the master inc#:2 mmon proc-id:21328 status:0x7
minact-scn status: grec-scn:0x0000.00000000 gmin-scn:0x0000.00000000 gcalc-scn:0x0000.00000000
Fri Aug 07 02:43:26 2015
Redo thread 2 internally disabled at seq 21147 (CKPT)
[21341] Successfully onlined Undo Tablespace 2.
Undo initialization finished serial:0 start:96999124 end:97000624 diff:1500 (15 seconds)
Verifying file header compatibility for 11g tablespace encryption..
Verifying 11g file header compatibility for tablespace encryption completed
SMON: enabling tx recovery
Database Characterset is ZHS16GBK
No Resource Manager plan active
Starting background process GTX0
Fri Aug 07 02:43:31 2015
GTX0 started with pid=37, OS id=22803
Starting background process RCBG
Fri Aug 07 02:43:31 2015
RCBG started with pid=38, OS id=22805
replication_dependency_tracking turned off (no async multimaster replication found)
Fri Aug 07 02:43:34 2015
Archived Log entry 73876 added for thread 2 sequence 21145 ID 0x513c613f dest 1: <---果然有归档操作发生
Starting background process QMNC
Fri Aug 07 02:43:34 2015
QMNC started with pid=39, OS id=22812
Fri Aug 07 02:43:35 2015
Archived Log entry 73877 added for thread 2 sequence 21146 ID 0x513c613f dest 1:
Fri Aug 07 02:43:35 2015
ARC0: Archiving disabled thread 2 sequence 21147
Archived Log entry 73878 added for thread 2 sequence 21147 ID 0x513c613f dest 1:
Fri Aug 07 02:43:37 2015
Completed: alter database open

现在到了这一步,基本上可以确定,数据库是零丢失恢复。由于asm 第一个au丢失数据严重,想要彻底修复比较难,考虑把数据库启动到mount/read only状态然后使用rman备份数据,然后进行重建asm 磁盘组,再迁移回来。至此完美恢复asmlib的磁盘被oracleasm重写的故障恢复,实现数据0丢失.当然在整个恢复过程没有于此的简单,涉及到在votedisk损坏的情况下,如何mount磁盘组,vote diskgroup的损坏修复问题,磁盘组在10g/11.1和11.2还原磁盘头备份的问题等问题.
虽然本次的恢复案例中,由于asmlib的asm disk不可见就轻易使用oracleasm createdisk命令对磁盘进行了重建,犯了一个很大错误,但是在重建之后,发现磁盘组依旧异常,未继续操作(比如重建磁盘组等),为最后的数据完全恢复创造了必要条件,使得客户的没有任何数据损失。如果再对除磁盘组继续复写操作,可能会导致数据永久性丢失。这个教训告诉我们:遇到自己不能把握的事情,及时终止,不要让错误越走越远

ORA-600 kccpb_sanity_check_2故障恢复

今天是有人在淘宝旺旺上找我,需要oracle数据库恢复支持
wangwang


远程登录上去一看发现数据库mount的时候报ORA-600[kccpb_sanity_check_2]错误

C:\Documents and Settings\Administrator>sqlplus / as sysdba
SQL*Plus: Release 10.2.0.3.0 - Production on Wed Jul 29 16:23:18 2015
Copyright (c) 1982, 2006, Oracle.  All Rights Reserved.
Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - Production
With the Partitioning, OLAP and Data Mining options
SQL> alter database mount;
alter database mount
*
ERROR at line 1:
ORA-00600: internal error code, arguments: [kccpb_sanity_check_2], [14169],
[14160], [0x0], [], [], [], []

尝试重建控制文件

SQL> shutdown immediate;
ORA-01507: database not mounted
ORACLE instance shut down.
SQL> startup pfile='D:\database\m104\pfile\init.ora' nomount
ORACLE instance started.
Total System Global Area  444596224 bytes
Fixed Size                  1291072 bytes
Variable Size             155192512 bytes
Database Buffers          281018368 bytes
Redo Buffers                7094272 bytes
SQL> SHOW PARAMETER CONT;
NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
control_file_record_keep_time        integer     7
control_files                        string      D:\DATABASE\M104\CTRL\CONTROL0
                                                 2.CTL
global_context_pool_size             string
SQL> ALTER DATABASE MOUNT;
ALTER DATABASE MOUNT
*
ERROR at line 1:
ORA-00600: internal error code, arguments: [kccpb_sanity_check_2], [14169],
[14160], [0x0], [], [], [], []
SQL>
SQL> CREATE CONTROLFILE REUSE DATABASE "m104_db" NORESETLOGS  FORCE LOGGING NOAR
CHIVELOG
  2      MAXLOGFILES 16
  3      MAXLOGMEMBERS 3
  4      MAXDATAFILES 100
  5      MAXINSTANCES 8
  6      MAXLOGHISTORY 2921
  7  LOGFILE
  8    GROUP 1 'D:\database\m104\log\redo01.log'  SIZE 51200K,
  9    GROUP 2 'D:\database\m104\log\redo02.log'  SIZE 51200K,
 10    GROUP 3 'D:\database\m104\log\redo03.log'  SIZE 51200K
 11  DATAFILE
 12    'd:\database\m104\data\system01.dbf',
 13    'd:\database\m104\data\sysaux01.dbf',
 14    'd:\database\m104\data\USERS01.DBF',
 15    'd:\database\m104\data\UNDOTBS01.DBF',
 16    'd:\database\m104\data\INDX01.DBF'
 17  CHARACTER SET WE8ISO8859P1
 18  ;
CREATE CONTROLFILE REUSE DATABASE "m104_db" NORESETLOGS  FORCE LOGGING NOARCHIVE
LOG
*
ERROR at line 1:
ORA-01503: CREATE CONTROLFILE failed
ORA-00600: internal error code, arguments: [kccsga_update_ckpt_4], [1], [8],
[], [], [], [], []
SQL>
SQL> CREATE CONTROLFILE REUSE DATABASE "m104_db" RESETLOGS  FORCE LOGGING NOARCH
IVELOG
  2      MAXLOGFILES 16
  3      MAXLOGMEMBERS 3
  4      MAXDATAFILES 100
  5      MAXINSTANCES 8
  6      MAXLOGHISTORY 2921
  7  LOGFILE
  8    GROUP 1 'D:\database\m104\log\redo01.log'  SIZE 51200K,
  9    GROUP 2 'D:\database\m104\log\redo02.log'  SIZE 51200K,
 10    GROUP 3 'D:\database\m104\log\redo03.log'  SIZE 51200K
 11  DATAFILE
 12    'd:\database\m104\data\system01.dbf',
 13    'd:\database\m104\data\sysaux01.dbf',
 14    'd:\database\m104\data\USERS01.DBF',
 15    'd:\database\m104\data\UNDOTBS01.DBF',
 16    'd:\database\m104\data\INDX01.DBF'
 17  CHARACTER SET WE8ISO8859P1
 18  ;
CREATE CONTROLFILE REUSE DATABASE "m104_db" RESETLOGS  FORCE LOGGING NOARCHIVELO
G
*
ERROR at line 1:
ORA-01503: CREATE CONTROLFILE failed
ORA-00600: internal error code, arguments: [kccsga_update_ckpt_4], [1], [8],
[], [], [], [], []

无论是使用noresetlogs还是resetlogs,重建控制文件都报ORA-600[kccsga_update_ckpt_4]错误.比较奇怪,无解指定控制文件新名称重建试试看

修改控制文件路径

SQL> SHUTDOWN ABORT
ORACLE instance shut down.
SQL> startup pfile='D:\database\m104\pfile\init.ora' nomount
ORACLE instance started.
Total System Global Area  444596224 bytes
Fixed Size                  1291072 bytes
Variable Size             155192512 bytes
Database Buffers          281018368 bytes
Redo Buffers                7094272 bytes
SQL> SHOW PARAMETER CONT;
NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
control_file_record_keep_time        integer     7
control_files                        string      D:\DATABASE\M104\CTRL\CONTROL0
                                                 4.CTL
global_context_pool_size             string
SQL> CREATE CONTROLFILE REUSE DATABASE "m104_db" RESETLOGS  FORCE LOGGING NOARCH
IVELOG
  2      MAXLOGFILES 16
  3      MAXLOGMEMBERS 3
  4      MAXDATAFILES 100
  5      MAXINSTANCES 8
  6      MAXLOGHISTORY 2921
  7  LOGFILE
  8    GROUP 1 'D:\database\m104\log\redo01.log'  SIZE 51200K,
  9    GROUP 2 'D:\database\m104\log\redo02.log'  SIZE 51200K,
 10    GROUP 3 'D:\database\m104\log\redo03.log'  SIZE 51200K
 11  DATAFILE
 12    'd:\database\m104\data\system01.dbf',
 13    'd:\database\m104\data\sysaux01.dbf',
 14    'd:\database\m104\data\USERS01.DBF',
 15    'd:\database\m104\data\UNDOTBS01.DBF',
 16    'd:\database\m104\data\INDX01.DBF'
 17  CHARACTER SET WE8ISO8859P1
 18  ;
Control file created.

使用新的控制文件位置,这次终于数据库重建控制文件成功
尝试指定redo进行恢复,数据库正常打开

SQL> RECOVER DATABASE USING BACKUP CONTROLFILE UNTIL CANCEL;
ORA-00279: change 3643108240801 generated at 07/26/2015 20:15:22 needed for
thread 1
ORA-00289: suggestion :
D:\ORACLE\PRODUCT\10.2.0\DB_1\RDBMS\ARC00567_0866390669.001
ORA-00280: change 3643108240801 for thread 1 is in sequence #567
Specify log: {<RET>=suggested | filename | AUTO | CANCEL}
D:\database\m104\log\redo01.log
ORA-00310: archived log contains sequence 566; sequence 567 required
ORA-00334: archived log: 'D:\DATABASE\M104\LOG\REDO01.LOG'
ORA-01547: warning: RECOVER succeeded but OPEN RESETLOGS would get error below
ORA-01194: file 1 needs more recovery to be consistent
ORA-01110: data file 1: 'D:\DATABASE\M104\DATA\SYSTEM01.DBF'
SQL> RECOVER DATABASE USING BACKUP CONTROLFILE UNTIL CANCEL;
ORA-00279: change 3643108240801 generated at 07/26/2015 20:15:22 needed for
thread 1
ORA-00289: suggestion :
D:\ORACLE\PRODUCT\10.2.0\DB_1\RDBMS\ARC00567_0866390669.001
ORA-00280: change 3643108240801 for thread 1 is in sequence #567
Specify log: {<RET>=suggested | filename | AUTO | CANCEL}
D:\database\m104\log\redo02.log
Log applied.
Media recovery complete.
SQL> ALTER DATABASE OPEN RESETLOGS;
Database altered.

数据库恢复完成。整个数据库恢复比较简单,但是注意这里的ORA-600[kccsga_update_ckpt_4]通过修改控制文件路径规避,具体原因待查。

知识点补充:ORA-600 [kccpb_sanity_check_2] [a] [b] {c}

VERSIONS:
  Versions 10.2 to 11.2
DESCRIPTION:
  This internal error is raised when the sequence number (seq#) of the
  current block of the controlfile is greater than the seq# in the controlfile header.
  The header value should always be equal to, or greater than the value
  held in the control file block(s).
  This extra check was introduced in Oracle 10gR2 to detect lost writes
  or stale reads to the header.
ARGUMENTS:
  Arg [a] seq# in control block header.
  Arg [b] seq# in the control file header.
  Arg {c}

多cpu环境中运行root.sh失败,asm报ORA-04031

有朋友和我反馈,说他们在装linux 6.5上面装11.2.0.3的rac出现异常,root.sh在第一个节点执行就失败了,请求帮助
root.sh-asm-fail


根据上面记录,查看asmca日志

[main] [ 2015-07-24 12:49:35.885 CST ] [SQLEngine.reInitialize:738]  Reinitializing SQLEngine...
[main] [ 2015-07-24 12:49:35.885 CST ] [OracleHome.getVersion:889]  OracleHome.getVersion called.  Current Version: 11.2.0.3.0
[main] [ 2015-07-24 12:49:35.885 CST ] [OracleHome.getVersion:957]  Current Version From Inventory: 11.2.0.3.0
[main] [ 2015-07-24 12:49:35.885 CST ] [OracleHome.getVersion:889]  OracleHome.getVersion called.  Current Version: 11.2.0.3.0
[main] [ 2015-07-24 12:49:35.886 CST ] [OracleHome.getVersion:957]  Current Version From Inventory: 11.2.0.3.0
[main] [ 2015-07-24 12:49:35.886 CST ] [OracleHome.getVersion:889]  OracleHome.getVersion called.  Current Version: 11.2.0.3.0
[main] [ 2015-07-24 12:49:35.886 CST ] [OracleHome.getVersion:957]  Current Version From Inventory: 11.2.0.3.0
[main] [ 2015-07-24 12:49:35.886 CST ] [SQLPlusEngine.getCmmdParams:222]  m_home 11.2.0.3.0
[main] [ 2015-07-24 12:49:35.887 CST ] [SQLPlusEngine.getCmmdParams:223]  version > 112 true
[main] [ 2015-07-24 12:49:35.887 CST ] [SQLEngine.getEnvParams:555]  Default NLS_LANG: AMERICAN_AMERICA.AL32UTF8
[main] [ 2015-07-24 12:49:35.887 CST ] [SQLEngine.getEnvParams:565]  NLS_LANG: AMERICAN_AMERICA.AL32UTF8
[main] [ 2015-07-24 12:49:35.888 CST ] [SQLEngine.initialize:325]  Execing SQLPLUS/SVRMGR process...
[main] [ 2015-07-24 12:49:35.900 CST ] [SQLEngine.initialize:362]  m_bReaderStarted: false
[main] [ 2015-07-24 12:49:35.900 CST ] [SQLEngine.initialize:366]  Starting Reader Thread...
[main] [ 2015-07-24 12:49:35.901 CST ] [SQLEngine.initialize:415]  Waiting for m_bReaderStarted to be true
[main] [ 2015-07-24 12:49:35.972 CST ] [SQLEngine.done:2189]  Done called
[main] [ 2015-07-24 12:49:35.972 CST ] [UsmcaLogger.logException:173]  SEVERE:method oracle.sysman.assistants.usmca.backend.USMInstance:configureLocalASM
[main] [ 2015-07-24 12:49:35.973 CST ] [UsmcaLogger.logException:174]  ORA-01012: not logged on
[main] [ 2015-07-24 12:49:35.973 CST ] [UsmcaLogger.logException:175]  oracle.sysman.assistants.util.sqlEngine.SQLFatalErrorException: ORA-01012: not logged on
oracle.sysman.assistants.util.sqlEngine.SQLEngine.executeImpl(SQLEngine.java:1658)
oracle.sysman.assistants.util.sqlEngine.SQLEngine.executeQuery(SQLEngine.java:831)
oracle.sysman.assistants.usmca.backend.USMInstance.configureLocalASM(USMInstance.java:3036)
oracle.sysman.assistants.usmca.service.UsmcaService.configureLocalASM(UsmcaService.java:1049)
oracle.sysman.assistants.usmca.model.UsmcaModel.performConfigureLocalASM(UsmcaModel.java:944)
oracle.sysman.assistants.usmca.model.UsmcaModel.performOperation(UsmcaModel.java:797)
oracle.sysman.assistants.usmca.Usmca.execute(Usmca.java:174)
oracle.sysman.assistants.usmca.Usmca.main(Usmca.java:369)
[main] [ 2015-07-24 12:49:35.989 CST ] [UsmcaLogger.logException:173]  SEVERE:method oracle.sysman.assistants.usmca.backend.USMInstance:configureLocalASM
[main] [ 2015-07-24 12:49:35.989 CST ] [UsmcaLogger.logException:174]  ORA-03113: end-of-file on communication channel
[main] [ 2015-07-24 12:49:35.989 CST ] [UsmcaLogger.logException:175]  oracle.sysman.assistants.util.sqlEngine.SQLFatalErrorException: ORA-03113: end-of-file on communication channel

这里可以看出来,asm实例无法登陆(ORA-01012和ORA-03113),根据这样的错误,分析asm日志

Reconfiguration complete
Fri Jul 24 12:49:29 2015
LCK0 started with pid=22, OS id=46913
Errors in file /u01/app/grid/diag/asm/+asm/+ASM1/trace/+ASM1_lmd0_46887.trc  (incident=81):
ORA-04031: unable to allocate 7072 bytes of shared memory ("shared pool","unknown object","sga heap(1,1)","ges resource ")
Incident details in: /u01/app/grid/diag/asm/+asm/+ASM1/incident/incdir_81/+ASM1_lmd0_46887_i81.trc
Errors in file /u01/app/grid/diag/asm/+asm/+ASM1/trace/+ASM1_lck0_46913.trc  (incident=177):
ORA-04031: unable to allocate 760 bytes of shared memory ("shared pool","unknown object","KKSSP^1343","kglss")
Incident details in: /u01/app/grid/diag/asm/+asm/+ASM1/incident/incdir_177/+ASM1_lck0_46913_i177.trc
Errors in file /u01/app/grid/diag/asm/+asm/+ASM1/trace/+ASM1_lmon_46885.trc  (incident=73):
ORA-04031: unable to allocate 632 bytes of shared memory ("shared pool","unknown object","sga heap(1,1)","name-service ")
Incident details in: /u01/app/grid/diag/asm/+asm/+ASM1/incident/incdir_73/+ASM1_lmon_46885_i73.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/grid/diag/asm/+asm/+ASM1/trace/+ASM1_lck0_46913.trc:
ORA-04031: unable to allocate 760 bytes of shared memory ("shared pool","unknown object","KKSSP^1343","kglss")
System state dump requested by (instance=1, osid=46913 (LCK0)), summary=[abnormal instance termination].
System State dumped to trace file /u01/app/grid/diag/asm/+asm/+ASM1/trace/+ASM1_diag_46879.trc
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
LCK0 (ospid: 46913): terminating the instance due to error 4031
Fri Jul 24 12:49:35 2015
ORA-1092 : opitsk aborting process
Instance terminated by LCK0, pid = 46913

进一步分析asm日志,发现是大家熟悉的asm的ORA-4031问题,那就是说明数据库在执行root.sh的时候使用默认参数文件启动asm的时候shared pool不够大(根据ORACLE最佳实践,建议memory_target=1536M及其以上值),从而出现该问题。类似Bug 14292825 ORA-4031 in ASM as default memory parameters values for 11.2 ASM instances low,根据官方描述该问题在11.2.0.4中修复
BUG-14292825


通过asm日志发现相关默认值配置

Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Real Application Clusters and Automatic Storage Management options.
ORACLE_HOME = /u01/app/11.2.0/grid
System name:	Linux
Node name:	RAC01
Release:	2.6.32-358.el6.x86_64
Version:	#1 SMP Tue Jan 29 11:47:41 EST 2013
Machine:	x86_64
Using parameter settings in client-side pfile /u01/app/11.2.0/grid/dbs/init+ASM1.ora on machine RAC01
System parameters with non-default values:
  large_pool_size          = 16M
  instance_type            = "asm"
  remote_login_passwordfile= "EXCLUSIVE"
  asm_power_limit          = 1
  diagnostic_dest          = "/u01/app/grid"
Cluster communication is configured to use the following interface(s) for this instance
  10.10.10.31
cluster interconnect IPC version:Oracle UDP/IP (generic)
IPC Vendor 1 proto 2
Fri Jul 24 12:49:27 2015

通过查询/proc/cpuinfo,检查cpu数量

processor	: 191
vendor_id	: GenuineIntel
cpu family	: 6
model		: 62
model name	: Intel(R) Xeon(R) CPU E7-8850 v2 @ 2.30GHz
stepping	: 7
cpu MHz		: 1200.000
cache size	: 24576 KB
physical id	: 7
siblings	: 24
core id		: 13
cpu cores	: 12
apicid		: 251
initial apicid	: 251
fpu		: yes
fpu_exception	: yes
cpuid level	: 13
wp		: yes

而根据How To Determine The Default Number Of Subpools Allocated During Startup (Doc ID 455179.1)中描述
最多7个subpool(这里一共有192个cpu,因此subpool数量为7)
1


每个suppool最少512m内存,因此shared pool最小需要3.5G(而默认值几百M,远远不够)
2


由于cpu多,导致shared pool的Subpools 更加多,使得shared pool的需求量更加大。至此本次故障原因可以总结:
由于cpu较多,需要更多的shared pool,而11.2.0.3中由于asm默认内存分配较少,导致在asm启动之时出现shared pool不足(本身默认值小,而且shared pool需求大,从而出现了ORA-04031就不奇怪了),因为运行root.sh过程中asm无法正常启动,从而使得root.sh运行失败。
处理办法:临时disable部分cpu,然后重新执行root.sh,修改asm内存分配,再enable cpu.
特别说明:此故障acs的兄弟遇到过,所以这次我能够快速反应,感谢acs兄弟们的帮忙,另外有权限的朋友可以看看:3-10479952701和3-7976215751等sr描述

win平台报ORA-15055 ORA-21561错误处理—增加SharedSection值

有一套win环境的rac,不定期的异常,alert日志经常报ORA-15055 ORA-21561错误,经过分析是由于win默认的Desktop Heap Size值太小导致该问题,以此提醒各位win平台跑oracle 的朋友注意。
alert日志报错

  Current log# 6 seq# 1820 mem# 0: +DATA/rac/onlinelog/group_6.3110.876059421
Thread 2 advanced to log sequence 1821 (LGWR switch)
  Current log# 5 seq# 1821 mem# 0: +DATA/rac/onlinelog/group_5.3109.876059417
Mon Jul 06 14:11:34 2015
WARNING: ASM communication error: op 0 state 0x0 (15055)
ERROR: direct connection failure with ASM
WARNING: ASM communication error: op 0 state 0x0 (15055)
ERROR: direct connection failure with ASM
NOTE: Deferred communication with ASM instance
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\rac\rac2\trace\rac2_arc0_276.trc:
ORA-15055: 无法连接到 ASM 实例
ORA-21561: 生成 OID 失败
ORA-15055: 无法连接到 ASM 实例
ORA-21561: 生成 OID 失败
NOTE: deferred map free for map id 28882
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\rac\rac2\trace\rac2_arc0_276.trc:
ORA-00313: 无法打开日志组 6 (用于线程 2) 的成员
ORA-00312: 联机日志 6 线程 2: '+DATA/rac/onlinelog/group_6.3110.876059421'
ORA-17503: ksfdopn: 2 未能打开文件 +DATA/rac/onlinelog/group_6.3110.876059421
ORA-15055: 无法连接到 ASM 实例
ORA-21561: 生成 OID 失败
ARCH: Archival stopped, error occurred. Will continue retrying
WARNING: ASM communication error: op 0 state 0x0 (15055)
ERROR: direct connection failure with ASM
WARNING: ASM communication error: op 0 state 0x0 (15055)
ERROR: direct connection failure with ASM
NOTE: Deferred communication with ASM instance
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\rac\rac2\trace\rac2_arc0_276.trc:
ORA-15055: 无法连接到 ASM 实例
ORA-21561: 生成 OID 失败
ORA-15055: 无法连接到 ASM 实例
ORA-21561: 生成 OID 失败
NOTE: deferred map free for map id 28883
Errors in file D:\APP\ADMINISTRATOR\diag\rdbms\rac\rac2\trace\rac2_arc0_276.trc:
ORA-00313: 无法打开日志组 6 (用于线程 2) 的成员
ORA-00312: 联机日志 6 线程 2: '+DATA/rac/onlinelog/group_6.3110.876059421'
ORA-17503: ksfdopn: 2 未能打开文件 +DATA/rac/onlinelog/group_6.3110.876059421
ORA-15055: 无法连接到 ASM 实例
ORA-21561: 生成 OID 失败

数据库版本

SQL> select * from v$version;
BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
PL/SQL Release 11.2.0.3.0 - Production
CORE    11.2.0.3.0      Production
TNS for 64-bit Windows: Version 11.2.0.3.0 - Production
NLSRTL Version 11.2.0.3.0 - Production

OS版本

SQL> host systeminfo
主机名:           RAC2
OS 名称:          Microsoft Windows Server 2008 R2 Enterprise
OS 版本:          6.1.7601 Service Pack 1 Build 7601
OS 制造商:        Microsoft Corporation
OS 配置:          独立服务器
OS 构件类型:      Multiprocessor Free
注册的所有人:     Windows 用户

通过查询MOS,发现该问题主要是由于win的SharedSection设置不足导致,而此类问题可能还导致其他错误,如:TNS12531:TNS:cannot allocate memory。

建议:对于Microsoft Windows 平台数据库,数据库版本为Version 11.2.0.1 to 12.1.0.2的系统,根据实际情况适当增加SharedSection大小。

例如:修改\HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Control\Session Manager\SubSystems\: SharedSection=1024,20480,1024。
这里的第二个为交互式的Desktop Heap Size,第三个是非交互式的Desktop Heap Size,我们主要修改第三个值

分享一例由于主库逻辑坏块导致dataguard容灾失效

有朋友数据库配置了物理dataguard,但是由于触发了某种Oracle bug/或者其他原因导致block出现大量逻辑坏块,结果是主备库(主库启动后就crash,备库failover后也启动后就crash)都无法正常工作,请求给予技术支持。
数据库配置了物理dataguard,但是主库在进行了某些操作之后,主库直接crash.重启主库发现,数据库启动之后,稍后数据库继续CRASH

Wed Jul 08 16:32:22 2015
Thread 1 advanced to log sequence 401531 (LGWR switch)
  Current log# 6 seq# 401531 mem# 0: /opt/oracle/database/fast_recovery_area/xifenfei/onlinelog/o1_mf_6_b9p7qhrm_.log
Archived Log entry 605194 added for thread 1 sequence 401530 ID 0xfbe74bc9 dest 1:
ARC3: Standby redo logfile selected for thread 1 sequence 401530 for destination LOG_ARCHIVE_DEST_2
******************************************************************
LGWR: Setting 'active' archival for destination LOG_ARCHIVE_DEST_2
******************************************************************
Wed Jul 08 16:33:02 2015
Errors in file /opt/oracle/database/diag/rdbms/xifenfei/xifenfei/trace/xifenfei_p032_413611.trc  (incident=201910):
ORA-00600: internal error code, arguments: [17114], [0x7FB03BB6DBD0], [], [], [], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [17182], [0x7FB03BB6DBF8], [], [], [], [], [], [], [], [], [], []
Incident details in: /opt/oracle/database/diag/rdbms/xifenfei/xifenfei/incident/incdir_201910/xifenfei_p032_413611_i201910.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 /opt/oracle/database/diag/rdbms/xifenfei/xifenfei/trace/xifenfei_p032_413611.trc  (incident=201911):
ORA-00600: internal error code, arguments: [kghfrempty:ds], [0x7FB03BB6DBE8], [], [], [], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [17114], [0x7FB03BB6DBD0], [], [], [], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [17182], [0x7FB03BB6DBF8], [], [], [], [], [], [], [], [], [], []
Incident details in: /opt/oracle/database/diag/rdbms/xifenfei/xifenfei/incident/incdir_201911/xifenfei_p032_413611_i201911.trc
Wed Jul 08 16:34:23 2015
SMON: slave died unexpectedly, downgrading to serial recovery
Errors in file /opt/oracle/database/diag/rdbms/xifenfei/xifenfei/trace/xifenfei_smon_413207.trc  (incident=201547):
ORA-00600: internal error code, arguments: [17182], [0x7F24D680D7A0], [], [], [], [], [], [], [], [], [], []
Incident details in: /opt/oracle/database/diag/rdbms/xifenfei/xifenfei/incident/incdir_201547/xifenfei_smon_413207_i201547.trc
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
Block recovery from logseq 401530, block 119 to scn 73226510040
Recovery of Online Redo Log: Thread 1 Group 5 Seq 401530 Reading mem 0
  Mem# 0: /opt/oracle/database/fast_recovery_area/xifenfei/onlinelog/o1_mf_5_b9p7qhl0_.log
Recovery of Online Redo Log: Thread 1 Group 6 Seq 401531 Reading mem 0
  Mem# 0: /opt/oracle/database/fast_recovery_area/xifenfei/onlinelog/o1_mf_6_b9p7qhrm_.log
Block recovery completed at rba 401531.1882.16, scn 17.212066009
ORACLE Instance xifenfei (pid = 16) - Error 600 encountered while recovering transaction (13, 14) on object 135520.
Errors in file /opt/oracle/database/diag/rdbms/xifenfei/xifenfei/trace/xifenfei_smon_413207.trc:
ORA-00600: internal error code, arguments: [17182], [0x7F24D680D7A0], [], [], [], [], [], [], [], [], [], []
Wed Jul 08 16:34:24 2015
Dumping diagnostic data in directory=[cdmp_20150708163424], requested by (instance=1, osid=413207 (SMON)), summary=[incident=201547].
Errors in file /opt/oracle/database/diag/rdbms/xifenfei/xifenfei/trace/xifenfei_smon_413207.trc  (incident=201548):
ORA-00600: internal error code, arguments: [KSMFPG2], [0x7F24D680D000], [], [], [], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [17182], [0x7F24D680D7A0], [], [], [], [], [], [], [], [], [], []
Incident details in: /opt/oracle/database/diag/rdbms/xifenfei/xifenfei/incident/incdir_201548/xifenfei_smon_413207_i201548.trc
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
Fatal internal error happened while SMON was doing active transaction recovery.
Errors in file /opt/oracle/database/diag/rdbms/xifenfei/xifenfei/trace/xifenfei_smon_413207.trc:
ORA-00600: internal error code, arguments: [KSMFPG2], [0x7F24D680D000], [], [], [], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [17182], [0x7F24D680D7A0], [], [], [], [], [], [], [], [], [], []
SMON (ospid: 413207): terminating the instance due to error 474
System state dump requested by (instance=1, osid=413207 (SMON)), summary=[abnormal instance termination].
System State dumped to trace file /opt/oracle/database/diag/rdbms/xifenfei/xifenfei/trace/xifenfei_diag_413167_20150708163426.trc
Dumping diagnostic data in directory=[cdmp_20150708163426], requested by (instance=1, osid=413207 (SMON)), summary=[abnormal instance termination].
Instance terminated by SMON, pid = 413207

由于主库不能正常open,备库直接failover方式激活

Wed Jul 08 17:56:41 2015
alter database recover managed standby database finish
Terminal Recovery: request posted (xffdb)
Wed Jul 08 17:56:45 2015
Begin: Standby Redo Logfile archival
End: Standby Redo Logfile archival
Terminal Recovery timestamp is '07/08/2015 17:56:45'
Terminal Recovery: applying standby redo logs.
Terminal Recovery: thread 1 seq# 401533 redo required
Terminal Recovery:
Recovery of Online Redo Log: Thread 1 Group 7 Seq 401533 Reading mem 0
  Mem# 0: /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_7_bb7x31lk_.log
Identified End-Of-Redo (failover) for thread 1 sequence 401533 at SCN 0xffff.ffffffff
Incomplete Recovery applied until change 73226530800 time 07/08/2015 16:56:40
Terminal Recovery: successful completion
Wed Jul 08 17:56:45 2015
ARCH: Archival stopped, error occurred. Will continue retrying
Forcing ARSCN to IRSCN for TR 17:212086768
ORACLE Instance xffdb - Archival Error
Attempt to set limbo arscn 17:212086768 irscn 17:212086768 ORA-16014: log 7 sequence# 401533 not archived, no available destinations
ORA-00312: online log 7 thread 1: '/opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_7_bb7x31lk_.log'
Resetting standby activation ID 4226239433 (0xfbe74bc9)
Wed Jul 08 17:56:45 2015
MRP0: Media Recovery Complete (xffdb)
MRP0: Background Media Recovery process shutdown (xffdb)
Terminal Recovery: completion detected (xffdb)
Completed: alter database recover managed standby database finish
Wed Jul 08 17:56:58 2015
alter database commit to switchover to primary
ALTER DATABASE SWITCHOVER TO PRIMARY (xffdb)
Maximum wait for role transition is 15 minutes.
Backup controlfile written to trace file /opt/oracle/database/diag/rdbms/xffdb/xffdb/trace/xffdb_ora_485094.trc
Standby terminal recovery start SCN: 73226530482
RESETLOGS after incomplete recovery UNTIL CHANGE 73226530800
Online logfile pre-clearing operation disabled by switchover
Online log /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_1_bb7x30gw_.log: Thread 1 Group 1 was previously cleared
Online log /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_2_bb7x30js_.log: Thread 1 Group 2 was previously cleared
Online log /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_3_bb7x310q_.log: Thread 1 Group 3 was previously cleared
Online log /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_4_bb7x312r_.log: Thread 1 Group 4 was previously cleared
Online log /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_5_bb7x317f_.log: Thread 1 Group 5 was previously cleared
Online log /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_6_bb7x31cz_.log: Thread 1 Group 6 was previously cleared
Standby became primary SCN: 73226530481
Wed Jul 08 17:56:58 2015
Setting recovery target incarnation to 3
Switchover: Complete - Database mounted as primary
Completed: alter database commit to switchover to primary

数据库激活成功后,重启激活之后数据库发现和主库出现类似情况

Wed Jul 08 17:57:25 2015
ALTER DATABASE   MOUNT
Successful mount of redo thread 1, with mount id 4243462021
Database mounted in Exclusive Mode
Lost write protection disabled
Completed: ALTER DATABASE   MOUNT
Wed Jul 08 17:57:30 2015
ALTER DATABASE OPEN
Assigning activation ID 4243462021 (0xfcee1785)
LGWR: STARTING ARCH PROCESSES
Wed Jul 08 17:57:30 2015
ARC0 started with pid=23, OS id=485230
ARC0: Archival started
LGWR: STARTING ARCH PROCESSES COMPLETE
ARC0: STARTING ARCH PROCESSES
Thread 1 advanced to log sequence 2 (thread open)
Wed Jul 08 17:57:31 2015
ARC1 started with pid=24, OS id=485236
Wed Jul 08 17:57:31 2015
ARC2 started with pid=25, OS id=485240
Wed Jul 08 17:57:31 2015
ARC3 started with pid=26, OS id=485244
ARC1: Archival started
ARC2: Archival started
ARC1: Becoming the 'no FAL' ARCH
ARC1: Becoming the 'no SRL' ARCH
ARC2: Becoming the heartbeat ARCH
Thread 1 opened at log sequence 2
  Current log# 2 seq# 2 mem# 0: /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_2_bb7x30js_.log
Successful open of redo thread 1
MTTR advisory is disabled because FAST_START_MTTR_TARGET is not set
SMON: enabling cache recovery
Wed Jul 08 17:57:31 2015
NSA2 started with pid=27, OS id=485248
[485226] Successfully onlined Undo Tablespace 2.
Undo initialization finished serial:0 start:3453451748 end:3453452018 diff:270 (2 seconds)
Dictionary check beginning
Dictionary check complete
Verifying file header compatibility for 11g tablespace encryption..
Verifying 11g file header compatibility for tablespace encryption completed
SMON: enabling tx recovery
Database Characterset is AL32UTF8
No Resource Manager plan active
replication_dependency_tracking turned off (no async multimaster replication found)
Wed Jul 08 17:57:32 2015
Errors in file /opt/oracle/database/diag/rdbms/xffdb/xffdb/trace/xffdb_p032_485380.trc  (incident=64481):
ORA-00600: internal error code, arguments: [17182], [0x7FE96B50DBF8], [], [], [], [], [], [], [], [], [], []
Incident details in: /opt/oracle/database/diag/rdbms/xffdb/xffdb/incident/incdir_64481/xffdb_p032_485380_i64481.trc
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
Starting background process QMNC
Wed Jul 08 17:57:32 2015
QMNC started with pid=92, OS id=485512
LOGSTDBY: Validating controlfile with logical metadata
LOGSTDBY: Validation complete
Dumping diagnostic data in directory=[cdmp_20150708175733], requested by (instance=1, osid=485380 (P032)), summary=[incident=64481].
Thread 1 advanced to log sequence 3 (LGWR switch)
  Current log# 3 seq# 3 mem# 0: /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_3_bb7x310q_.log
ARC3: STARTING ARCH PROCESSES
Wed Jul 08 17:57:34 2015
ARC4 started with pid=93, OS id=485516
Wed Jul 08 17:57:35 2015
db_recovery_file_dest_size of 204800 MB is 0.41% 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.
ARC4: Archival started
ARC3: STARTING ARCH PROCESSES COMPLETE
krsk_srl_archive_int: Enabling archival of deferred physical standby SRLs
Archived Log entry 273963 added for thread 1 sequence 2 ID 0xfcee1785 dest 1:
Archived Log entry 273964 added for thread 1 sequence 401533 ID 0xfbe74bc9 dest 1:
Completed: ALTER DATABASE OPEN
Wed Jul 08 17:57:36 2015
Starting background process CJQ0
Wed Jul 08 17:57:36 2015
CJQ0 started with pid=95, OS id=485554
Shutting down archive processes
ARCH shutting down
ARC4: Archival stopped
Wed Jul 08 17:57:41 2015
Thread 1 advanced to log sequence 4 (LGWR switch)
  Current log# 4 seq# 4 mem# 0: /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_4_bb7x312r_.log
Wed Jul 08 17:57:41 2015
Archived Log entry 273965 added for thread 1 sequence 3 ID 0xfcee1785 dest 1:
Wed Jul 08 17:58:30 2015
Sweep [inc][64481]: completed
Sweep [inc2][64481]: completed
Wed Jul 08 17:58:31 2015
Errors in file /opt/oracle/database/diag/rdbms/xffdb/xffdb/trace/xffdb_p032_485380.trc  (incident=64482):
ORA-00600: internal error code, arguments: [17114], [0x7FE96B50DBD0], [], [], [], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [17182], [0x7FE96B50DBF8], [], [], [], [], [], [], [], [], [], []
Incident details in: /opt/oracle/database/diag/rdbms/xffdb/xffdb/incident/incdir_64482/xffdb_p032_485380_i64482.trc
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
Wed Jul 08 17:58:32 2015
Dumping diagnostic data in directory=[cdmp_20150708175832], requested by (instance=1, osid=485380 (P032)), summary=[incident=64482].
Wed Jul 08 17:58:36 2015
Thread 1 advanced to log sequence 5 (LGWR switch)
  Current log# 5 seq# 5 mem# 0: /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_5_bb7x317f_.log
Wed Jul 08 17:59:02 2015
Errors in file /opt/oracle/database/diag/rdbms/xffdb/xffdb/trace/xffdb_p032_485380.trc  (incident=64483):
ORA-00600: internal error code, arguments: [17114], [0x7FE96B50DBD0], [], [], [], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [17114], [0x7FE96B50DBD0], [], [], [], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [17182], [0x7FE96B50DBF8], [], [], [], [], [], [], [], [], [], []
Incident details in: /opt/oracle/database/diag/rdbms/xffdb/xffdb/incident/incdir_64483/xffdb_p032_485380_i64483.trc
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
Wed Jul 08 17:59:04 2015
Dumping diagnostic data in directory=[cdmp_20150708175904], requested by (instance=1, osid=485380 (P032)), summary=[incident=64483].
Wed Jul 08 17:59:29 2015
Sweep [inc][64483]: completed
Sweep [inc][64482]: completed
Sweep [inc2][64483]: completed
Sweep [inc2][64482]: completed
Wed Jul 08 17:59:30 2015
Block recovery from logseq 2, block 104 to scn 73226531646
Recovery of Online Redo Log: Thread 1 Group 2 Seq 2 Reading mem 0
  Mem# 0: /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_2_bb7x30js_.log
Recovery of Online Redo Log: Thread 1 Group 3 Seq 3 Reading mem 0
  Mem# 0: /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_3_bb7x310q_.log
Recovery of Online Redo Log: Thread 1 Group 4 Seq 4 Reading mem 0
  Mem# 0: /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_4_bb7x312r_.log
Recovery of Online Redo Log: Thread 1 Group 5 Seq 5 Reading mem 0
  Mem# 0: /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_5_bb7x317f_.log
Block recovery stopped at EOT rba 5.765.16
Block recovery completed at rba 5.765.16, scn 17.212087614
Errors in file /opt/oracle/database/diag/rdbms/xffdb/xffdb/trace/xffdb_p032_485380.trc  (incident=64484):
ORA-00600: internal error code, arguments: [KSMFPG2], [0x7FE96B50D000], [], [], [], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [17114], [0x7FE96B50DBD0], [], [], [], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [17114], [0x7FE96B50DBD0], [], [], [], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [17182], [0x7FE96B50DBF8], [], [], [], [], [], [], [], [], [], []
Incident details in: /opt/oracle/database/diag/rdbms/xffdb/xffdb/incident/incdir_64484/xffdb_p032_485380_i64484.trc
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
Dumping diagnostic data in directory=[cdmp_20150708175934], requested by (instance=1, osid=485380 (P032)), summary=[incident=64487].
Wed Jul 08 17:59:36 2015
SMON: slave died unexpectedly, downgrading to serial recovery
Errors in file /opt/oracle/database/diag/rdbms/xffdb/xffdb/trace/xffdb_smon_485190.trc  (incident=64129):
ORA-00600: internal error code, arguments: [17182], [0x7F5AED10D7A0], [], [], [], [], [], [], [], [], [], []
Incident details in: /opt/oracle/database/diag/rdbms/xffdb/xffdb/incident/incdir_64129/xffdb_smon_485190_i64129.trc
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
Block recovery from logseq 2, block 104 to scn 73226531646
Recovery of Online Redo Log: Thread 1 Group 2 Seq 2 Reading mem 0
  Mem# 0: /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_2_bb7x30js_.log
Recovery of Online Redo Log: Thread 1 Group 3 Seq 3 Reading mem 0
  Mem# 0: /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_3_bb7x310q_.log
Recovery of Online Redo Log: Thread 1 Group 4 Seq 4 Reading mem 0
  Mem# 0: /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_4_bb7x312r_.log
Recovery of Online Redo Log: Thread 1 Group 5 Seq 5 Reading mem 0
  Mem# 0: /opt/oracle/database/fast_recovery_area/DBHLDB/onlinelog/o1_mf_5_bb7x317f_.log
Block recovery completed at rba 5.765.16, scn 17.212087615
ORACLE Instance xffdb (pid = 16) - Error 600 encountered while recovering transaction (13, 14) on object 135520.
Errors in file /opt/oracle/database/diag/rdbms/xffdb/xffdb/trace/xffdb_smon_485190.trc:
ORA-00600: internal error code, arguments: [17182], [0x7F5AED10D7A0], [], [], [], [], [], [], [], [], [], []
Dumping diagnostic data in directory=[cdmp_20150708175937], requested by (instance=1, osid=485190 (SMON)), summary=[incident=64129].
Errors in file /opt/oracle/database/diag/rdbms/xffdb/xffdb/trace/xffdb_smon_485190.trc  (incident=64130):
ORA-00600: internal error code, arguments: [KSMFPG2], [0x7F5AED10D000], [], [], [], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [17182], [0x7F5AED10D7A0], [], [], [], [], [], [], [], [], [], []
Incident details in: /opt/oracle/database/diag/rdbms/xffdb/xffdb/incident/incdir_64130/xffdb_smon_485190_i64130.trc
Use ADRCI or Support Workbench to package the incident.
See Note 411.1 at My Oracle Support for error and packaging details.
Fatal internal error happened while SMON was doing active transaction recovery.
Errors in file /opt/oracle/database/diag/rdbms/xffdb/xffdb/trace/xffdb_smon_485190.trc:
ORA-00600: internal error code, arguments: [KSMFPG2], [0x7F5AED10D000], [], [], [], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [17182], [0x7F5AED10D7A0], [], [], [], [], [], [], [], [], [], []
SMON (ospid: 485190): terminating the instance due to error 474
System state dump requested by (instance=1, osid=485190 (SMON)), summary=[abnormal instance termination].
System State dumped to trace file /opt/oracle/database/diag/rdbms/xffdb/xffdb/trace/xffdb_diag_485150_20150708175939.trc
Dumping diagnostic data in directory=[cdmp_20150708175939], requested by (instance=1, osid=485190 (SMON)), summary=[abnormal instance termination].
Instance terminated by SMON, pid = 485190

通过进一步分析确定是67号文件有异常,使用dbv检查该文件发现

DBVERIFY: Release 11.2.0.4.0 - Production on Thu Jul 9 11:08:27 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.
DBVERIFY - Verification starting : FILE = /opt/oracle/database/oradata/xffdb/dk_adv_ts_main_25.dbf
Block Checking: DBA = 283035270, Block Type = KTB-managed data block
data header at 0x7f87813ea064
kdbchk: the amount of space used is not equal to block size
        used=7383 fsc=0 avsp=873 dtl=8088
Page 2016902 failed with check code 6110
Block Checking: DBA = 283035271, Block Type = KTB-managed data block
data header at 0x7f87813ec064
kdbchk: the amount of space used is not equal to block size
        used=8676 fsc=0 avsp=832 dtl=8088
Page 2016903 failed with check code 6110
Block Checking: DBA = 283035272, Block Type = KTB-managed data block
data header at 0x7f87813ee064
kdbchk: avsp(1306) > tosp(894)
Page 2016904 failed with check code 6128
Block Checking: DBA = 283035273, Block Type = KTB-managed data block
data header at 0x7f87813f0064
kdbchk: the amount of space used is not equal to block size
        used=7506 fsc=0 avsp=815 dtl=8088
Page 2016905 failed with check code 6110
Block Checking: DBA = 283035274, Block Type = KTB-managed data block
data header at 0x7f87813f2064
kdbchk: the amount of space used is not equal to block size
        used=7892 fsc=0 avsp=884 dtl=8088
Page 2016906 failed with check code 6110
…………
Block Checking: DBA = 283035368, Block Type = KTB-managed data block
data header at 0x7f87814ae064
kdbchk: the amount of space used is not equal to block size
        used=7934 fsc=0 avsp=837 dtl=8088
Page 2017000 failed with check code 6110
Block Checking: DBA = 283035369, Block Type = KTB-managed data block
data header at 0x7f87814b0064
kdbchk: the amount of space used is not equal to block size
        used=7683 fsc=0 avsp=883 dtl=8088
Page 2017001 failed with check code 6110
Block Checking: DBA = 283035370, Block Type = KTB-managed data block
data header at 0x7f87814b2064
kdbchk: the amount of space used is not equal to block size
        used=8556 fsc=0 avsp=841 dtl=8088
Page 2017002 failed with check code 6110
Block Checking: DBA = 283035371, Block Type = KTB-managed data block
data header at 0x7f87814b4064
kdbchk: the amount of space used is not equal to block size
        used=7460 fsc=0 avsp=822 dtl=8088
Page 2017003 failed with check code 6110
DBVERIFY - Verification complete
Total Pages Examined         : 4063232
Total Pages Processed (Data) : 2724435
Total Pages Failing   (Data) : 102
Total Pages Processed (Index): 1064839
Total Pages Failing   (Index): 0
Total Pages Processed (Other): 273957
Total Pages Processed (Seg)  : 0
Total Pages Failing   (Seg)  : 0
Total Pages Empty            : 1
Total Pages Marked Corrupt   : 0
Total Pages Influx           : 0
Total Pages Encrypted        : 0
Highest block SCN            : 212065913 (17.212065913)

把datafile 67给offline之后,数据库open正常,也不再crash。这里比较明显,导致主库和被动都出现异常,主库直接crash,然后重启后,一会儿就crash;备库激活后,重启后一会儿也就crash;两个库现象相同。最后通过dbv定位到是由于某个文件出现大量逻辑坏块,导致数据库open之后,进行回滚之时crash.对于此类故障,可以通过屏蔽事务回滚,并且通过alert日志和trace文件定位到异常对象,可以删除异常对象可以暂时解决该问题。而导致数据库出现类似问题。
通过这个案例,可以的出来,由于oracle某种bug或者其他原因,导致block 逻辑损坏,而且这个损坏会传输到备库,导致备库也异常,oracle的备份,容灾不能全部依赖物理dataguard容灾。因此在条件允许情况下,建议增加物理备份和逻辑容灾(类似OGG)