ora-600 2037 ORA-7445 kcbs_dump_adv_state解决

联系:手机/微信(+86 17813235971) QQ(107644445)

标题:ora-600 2037 ORA-7445 kcbs_dump_adv_state解决

作者:惜分飞©版权所有[未经本人同意,不得以任何形式转载,否则有进一步追究法律责任的权利.]

有客户系统断电,导致数据库无法启动,让我们帮忙解决,通过分析主要是ORA-600 2037和ORA-7445 _kcbs_dump_adv_state等错误,通过人工recover解决.
数据库报ORA-03113,无法启动成功

C:\Documents and Settings\Administrator>sqlplus / as sysdba
SQL*Plus: Release 10.2.0.1.0 - Production on 星期五 5月 12 09:50:36 2017
Copyright (c) 1982, 2005, Oracle.  All rights reserved.
已连接到空闲例程。
SQL> startup
ORACLE 例程已经启动。
Total System Global Area 1258291200 bytes
Fixed Size                  1250548 bytes
Variable Size             218106636 bytes
Database Buffers         1031798784 bytes
Redo Buffers                7135232 bytes
数据库装载完毕。
ORA-03113: 通信通道的文件结束

分析alert日志

Fri May 12 09:50:43 2017
ALTER DATABASE OPEN
Fri May 12 09:50:43 2017
Beginning crash recovery of 1 threads
 parallel recovery started with 15 processes
Fri May 12 09:50:43 2017
Started redo scan
Fri May 12 09:50:43 2017
Completed redo scan
 1240 redo blocks read, 277 data blocks need recovery
Fri May 12 09:50:44 2017
Started redo application at
 Thread 1: logseq 5881, block 41179
Fri May 12 09:50:44 2017
Recovery of Online Redo Log: Thread 1 Group 1 Seq 5881 Reading mem 0
  Mem# 0 errs 0: E:\ORACLE\PRODUCT\10.2.0\ORADATA\xff\REDO01.LOG
Fri May 12 09:50:44 2017
Completed redo application
Fri May 12 09:50:44 2017
Errors in file e:\oracle\product\10.2.0\admin\xff\bdump\xff_p006_6072.trc:
ORA-00600: internal error code, arguments: [6110], [193], [3], [], [], [], [], []
Fri May 12 09:50:44 2017
Hex dump of (file 3, block 14004) in trace file e:\oracle\product\10.2.0\admin\xff\bdump\xff_p000_6024.trc
Corrupt block relative dba: 0x00c036b4 (file 3, block 14004)
Bad header found during crash/instance recovery
Data in bad block:
 type: 255 format: 7 rdba: 0x06010601
 last change scn: 0xa206.a2060601 seq: 0xb4 flg: 0x36
 spare1: 0x1 spare2: 0x6 spare3: 0x673
 consistency value in tail: 0x1b0a0708
 check value in block header: 0x36b4
 computed block checksum: 0xe4f5
Fri May 12 09:50:44 2017
Hex dump of (file 9, block 65507) in trace file e:\oracle\product\10.2.0\admin\xff\bdump\xff_p003_6056.trc
Corrupt block relative dba: 0x0240ffe3 (file 9, block 65507)
Bad header found during crash/instance recovery
Data in bad block:
 type: 3 format: 6 rdba: 0x06020601
 last change scn: 0xa206.a2060602 seq: 0xe3 flg: 0xff
 spare1: 0x1 spare2: 0x6 spare3: 0x6dc
 consistency value in tail: 0xc1028001
 check value in block header: 0xffe3
 computed block checksum: 0xff01
Fri May 12 09:50:44 2017
Reread of rdba: 0x00c036b4 (file 3, block 14004) found different data
Fri May 12 09:50:44 2017
Reread of rdba: 0x0240ffe3 (file 9, block 65507) found different data
Fri May 12 09:50:44 2017
Errors in file e:\oracle\product\10.2.0\admin\xff\bdump\xff_p005_6060.trc:
ORA-00600: internal error code,arguments:[2037],[17442602],[2718302723],[255],[9],[203],[657105414],[2147549568]
Fri May 12 09:50:44 2017
Errors in file e:\oracle\product\10.2.0\admin\xff\bdump\xff_p000_6024.trc:
ORA-07445:exception encountered:core dump[ACCESS_VIOLATION][_kclcomplete+79][PC:0x72B0C7][ADDR:0x220][UNABLE_TO_READ][]
Fri May 12 09:50:44 2017
Errors in file e:\oracle\product\10.2.0\admin\xff\bdump\xff_p006_6072.trc:
ORA-07445: exception encountered:core dump[ACCESS_VIOLATION][_kcbzdh+2496][PC:0x4A4928][ADDR:0xB][UNABLE_TO_READ][]
ORA-00600: internal error code, arguments: [6110], [193], [3], [], [], [], [], []
Errors in file e:\oracle\product\10.2.0\admin\xff\bdump\xff_p012_6128.trc:
ORA-07445: exception encountered: core dump [ACCESS_VIOLATION] [_kcbs_dump_adv_state+723]
                                 [PC:0x5975A3] [ADDR:0xCBC0CBB2] [UNABLE_TO_READ] []
ORA-00600:internal error code,arguments:[2037],[17430318],[2718303745],[128],[1],[203],[4147028486],[2147549568]

错误比较明显由于坏块导致应用日志恢复异常,主要错误集中在ORA-600 2037,ORA-7445 _kcbs_dump_adv_state,ORA-7445_kcbzdh,ORA-7445 _kclcomplete等

dbv检查数据文件

E:\>dbv file=E:\ORACLE\PRODUCT\10.2.0\ORADATA\xff\SYSAUX01.DBF
DBVERIFY: Release 10.2.0.1.0 - Production on 星期五 5月 12 09:57:39 2017
Copyright (c) 1982, 2005, Oracle.  All rights reserved.
DBVERIFY - 开始验证: FILE = E:\ORACLE\PRODUCT\10.2.0\ORADATA\xff\SYSAUX01.DBF
页 13353 标记为损坏
Corrupt block relative dba: 0x00c03429 (file 3, block 13353)
Bad header found during dbv:
Data in bad block:
 type: 1 format: 6 rdba: 0x3429a206
 last change scn: 0x066f.066f3429 seq: 0x0 flg: 0x00
 spare1: 0x6 spare2: 0xa2 spare3: 0x8c96
 consistency value in tail: 0x06018001
 check value in block header: 0x0
 block checksum disabled
页 14004 标记为损坏
Corrupt block relative dba: 0x00c036b4 (file 3, block 14004)
Bad header found during dbv:
Data in bad block:
 type: 1 format: 6 rdba: 0x36b4a206
 last change scn: 0x0673.067336b4 seq: 0x0 flg: 0x00
 spare1: 0x6 spare2: 0xa2 spare3: 0xfb97
 consistency value in tail: 0x06010210
 check value in block header: 0x0
 block checksum disabled
页 15261 标记为损坏
Corrupt block relative dba: 0x00c03b9d (file 3, block 15261)
Bad header found during dbv:
Data in bad block:
 type: 2 format: 6 rdba: 0x3b9da206
 last change scn: 0x0673.06733b9d seq: 0x0 flg: 0x00
 spare1: 0x6 spare2: 0xa2 spare3: 0x0
 consistency value in tail: 0x06018001
 check value in block header: 0x5549
 block checksum disabled
DBVERIFY - 验证完成
检查的页总数: 58880
处理的页总数 (数据): 19318
失败的页总数 (数据): 0
处理的页总数 (索引): 18610
失败的页总数 (索引): 0
处理的页总数 (其它): 13747
处理的总页数 (段)  : 0
失败的总页数 (段)  : 0
空的页总数: 7202
标记为损坏的总页数: 3
流入的页总数: 0
最高块 SCN            : 178325323 (0.178325323)
E:\>dbv file=E:\ORACLE\PRODUCT\10.2.0\ORADATA\xff\xff_BSE02
DBVERIFY: Release 10.2.0.1.0 - Production on 星期五 5月 12 10:10:24 2017
Copyright (c) 1982, 2005, Oracle.  All rights reserved.
DBVERIFY - 开始验证: FILE = E:\ORACLE\PRODUCT\10.2.0\ORADATA\xff\xff_BSE02
页 65507 标记为损坏
Corrupt block relative dba: 0x0240ffe3 (file 9, block 65507)
Bad header found during dbv:
Data in bad block:
 type: 2 format: 6 rdba: 0xffe3a206
 last change scn: 0x06dc.06dcffe3 seq: 0x0 flg: 0x00
 spare1: 0x6 spare2: 0xa2 spare3: 0xb32
 consistency value in tail: 0x060102ff
 check value in block header: 0x0
 block checksum disabled
DBVERIFY - 验证完成
检查的页总数: 1310720
处理的页总数 (数据): 34102
失败的页总数 (数据): 0
处理的页总数 (索引): 30270
失败的页总数 (索引): 0
处理的页总数 (其它): 10850
处理的总页数 (段)  : 0
失败的总页数 (段)  : 0
空的页总数: 1235497
标记为损坏的总页数: 1
流入的页总数: 0
最高块 SCN            : 178325221 (0.178325221)

确实如alert日志报错,file 3和9 都出现坏块导致实例恢复无法进行。根据错误ORA-600 2037和ORA-7445 _kcbs_dump_adv_state,初步判断和During Startup (Open Database) Alert Log Shows ORA-600[2037] and ORA-7445[kcbs_dump_adv_state] (Doc ID 551993.1)文章描述相符(而且版本也相符)

尝试recover datafile部分file

E:\>sqlplus / as sysdba
SQL*Plus: Release 10.2.0.1.0 - Production on 星期五 5月 12 10:16:00 2017
Copyright (c) 1982, 2005, Oracle.  All rights reserved.
连接到:
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - Production
With the Partitioning, OLAP and Data Mining options
SQL> recover datafile 1;
完成介质恢复。
SQL> recover datafile 2;
完成介质恢复。
SQL> recover datafile 3;
完成介质恢复。
SQL> recover datafile 4;
完成介质恢复。
SQL> recover datafile 9;
完成介质恢复。
SQL> alter database open;
alter database open
*
第 1 行出现错误:
ORA-00600: 内部错误代码, 参数: [kcratr1_lastbwr], [], [], [], [], [], [], []

ORA-00600 kcratr1_lastbwr错误比较明显,见ORA-00600:[Kcratr1_lastbwr] During Database Startup after a Crash (Doc ID 393984.1)

通过recover database处理

SQL> recover database;
完成介质恢复。
SQL> alter database open;
数据库已更改。

然后通过查询dba_extents 处理坏块对象

补充ORA-600 2037错误

Format: ORA-600 [2037] [a] [b]  [d] [e] [f] [g]
VERSIONS:
  versions 8.0 and above
DESCRIPTION:
  During recovery we are examining a block to ensure that it is not
  corrupt prior to applying any change vectors.
  The block has failed this check and this exception is raised.
ARGUMENTS:
  Arg [a] Relative Data Block Address (RDBA) that the redo vector is for
  Arg [b] The Block format
  Arg {c} RDBA in the block itself
  Arg [d] The block type
  Arg [e] The sequence number
  Arg [f] Flags, if set
  Arg [g] The return value from the block head/tail checker.

ORA-27300 ORA-27301 ORA-27302

联系:手机/微信(+86 17813235971) QQ(107644445)

标题:ORA-27300 ORA-27301 ORA-27302

作者:惜分飞©版权所有[未经本人同意,不得以任何形式转载,否则有进一步追究法律责任的权利.]

有朋友库中alert日志报ORA-27300 ORA-27301 ORA-27302错误,让帮忙分析原因
ORA-27300 ORA-27301 ORA-27302

Fri Oct 28 22:15:33 2016
Process startup failed, error stack:
Errors in file d:\app\diag\rdbms\xifenfei\xifenfei\trace\xifenfei_psp0_4856.trc:
ORA-27300: OS system dependent operation:CreateThread failed with status: 8
ORA-27301: OS failure message: 存储空间不足,无法处理此命令。
ORA-27302: failure occurred at: ssthrddcr
Fri Oct 28 22:15:34 2016
Process J001 died, see its trace file
kkjcre1p: unable to spawn jobq slave process
Errors in file d:\app\diag\rdbms\xifenfei\xifenfei\trace\xifenfei_cjq0_5664.trc:
Fri Oct 28 22:16:35 2016
Process startup failed, error stack:
Errors in file d:\app\diag\rdbms\xifenfei\xifenfei\trace\xifenfei_psp0_4856.trc:
ORA-27300: OS system dependent operation:CreateThread failed with status: 8
ORA-27301: OS failure message: 存储空间不足,无法处理此命令。
ORA-27302: failure occurred at: ssthrddcr
Fri Oct 28 22:16:36 2016
Process J001 died, see its trace file
kkjcre1p: unable to spawn jobq slave process
Errors in file d:\app\diag\rdbms\xifenfei\xifenfei\trace\xifenfei_cjq0_5664.trc:
Fri Oct 28 22:17:36 2016
Process startup failed, error stack:
Errors in file d:\app\diag\rdbms\xifenfei\xifenfei\trace\xifenfei_psp0_4856.trc:
ORA-27300: OS system dependent operation:CreateThread failed with status: 8
ORA-27301: OS failure message: 存储空间不足,无法处理此命令。
ORA-27302: failure occurred at: ssthrddcr

系统版本win 2008 32位
os


系统状态
os2


数据库版本
version


数据库内存配置
db-memory


新会话无法连接

28-10月-2016 22:46:59 * (CONNECT_DATA=(SID=xifenfei)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=Administrator))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.16.91.5)(PORT=54383)) * establish * xifenfei * 12518
TNS-12518: TNS: 监听程序无法分发客户机连接
 TNS-12560: TNS: 协议适配器错误
28-10月-2016 22:46:59 * (CONNECT_DATA=(SID=xifenfei)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=Administrator))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.16.91.5)(PORT=54384)) * establish * xifenfei * 12518
TNS-12518: TNS: 监听程序无法分发客户机连接
 TNS-12560: TNS: 协议适配器错误
28-10月-2016 22:46:59 * (CONNECT_DATA=(SID=xifenfei)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=Administrator))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.16.91.5)(PORT=54385)) * establish * xifenfei * 12518
TNS-12518: TNS: 监听程序无法分发客户机连接
 TNS-12560: TNS: 协议适配器错误
28-10月-2016 22:46:59 * (CONNECT_DATA=(SID=xifenfei)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=Administrator))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.16.91.5)(PORT=54386)) * establish * xifenfei * 12518
TNS-12518: TNS: 监听程序无法分发客户机连接
 TNS-12560: TNS: 协议适配器错误
28-10月-2016 22:46:59 * (CONNECT_DATA=(SID=xifenfei)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=Administrator))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.16.91.5)(PORT=54388)) * establish * xifenfei * 12518
TNS-12518: TNS: 监听程序无法分发客户机连接
 TNS-12560: TNS: 协议适配器错误
28-10月-2016 22:46:59 * (CONNECT_DATA=(SID=xifenfei)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=Administrator))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.16.91.5)(PORT=54389)) * establish * xifenfei * 12518
TNS-12518: TNS: 监听程序无法分发客户机连接
 TNS-12560: TNS: 协议适配器错误
28-10月-2016 22:46:59 * (CONNECT_DATA=(SID=xifenfei)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=Administrator))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.16.91.5)(PORT=54390)) * establish * xifenfei * 12518
TNS-12518: TNS: 监听程序无法分发客户机连接
 TNS-12560: TNS: 协议适配器错误
28-10月-2016 22:47:00 * (CONNECT_DATA=(SID=xifenfei)(CID=(PROGRAM=)(HOST=__jdbc__)(USER=Administrator))) * (ADDRESS=(PROTOCOL=tcp)(HOST=172.16.91.5)(PORT=54391)) * establish * xifenfei * 12518
TNS-12518: TNS: 监听程序无法分发客户机连接
 TNS-12560: TNS: 协议适配器错误

20161028224020


故障处理

HKEY_LOCAL_MACHINE SYSTEM\CurrentControlSet\Services\LanmanServer\Parameters
Value Name: IRPStackSize
Data Type: DWORD
The default value of the IRPStackSize parameter is 15. The range is from 11 (0xb hexadecimal) through 50 (0x32 hexadecimal).

register


参考:Ora-27300: OS System Dependent Operation:Createthread Failed With Status: 8 (Doc ID 1310453.1)

ORA-600 kcrfr_update_nab_2 故障恢复

联系:手机/微信(+86 17813235971) QQ(107644445)

标题:ORA-600 kcrfr_update_nab_2 故障恢复

作者:惜分飞©版权所有[未经本人同意,不得以任何形式转载,否则有进一步追究法律责任的权利.]

由于控制器掉线导致数据库启动报ORA-600 kcrfr_update_nab_2错误,导致无法正常open
数据库版本信息

ORACLE V10.2.0.4.0 - 64bit Production vsnsta=0
vsnsql=14 vsnxtr=3
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
Windows Server 2003 Version V5.2 Service Pack 2
CPU                 : 12 - type 8664, 2 Physical Cores
Process Affinity    : 0x0000000000000000
Memory (Avail/Total): Ph:22579M/32754M, Ph+PgF:24594M/33845M

ORA-600 kcrfr_update_nab_2报错

Mon Oct 24 17:42:57 2016
Database mounted in Exclusive Mode
Completed: ALTER DATABASE   MOUNT
Mon Oct 24 17:42:58 2016
ALTER DATABASE OPEN
Mon Oct 24 17:43:14 2016
Beginning crash recovery of 1 threads
 parallel recovery started with 11 processes
Mon Oct 24 17:43:14 2016
Started redo scan
Mon Oct 24 17:43:16 2016
Errors in file d:\oracle\product\10.2.0\admin\spcsjkdb\udump\spcsjkdb_ora_10108.trc:
ORA-00600: internal error code, arguments: [kcrfr_update_nab_2], [0x7FFC22A2150], [2], [], [], [], [], []
Mon Oct 24 17:43:18 2016
Aborting crash recovery due to error 600
Mon Oct 24 17:43:18 2016
Errors in file d:\oracle\product\10.2.0\admin\spcsjkdb\udump\spcsjkdb_ora_10108.trc:
ORA-00600: internal error code, arguments: [kcrfr_update_nab_2], [0x7FFC22A2150], [2], [], [], [], [], []
ORA-600 signalled during: ALTER DATABASE OPEN...

trace文件信息

*** 2016-10-24 17:43:14.515
*** ACTION NAME:() 2016-10-24 17:43:14.515
*** MODULE NAME:(sqlplus.exe) 2016-10-24 17:43:14.515
*** SERVICE NAME:() 2016-10-24 17:43:14.515
*** SESSION ID:(356.3) 2016-10-24 17:43:14.515
Successfully allocated 11 recovery slaves
Using 101 overflow buffers per recovery slave
Thread 1 checkpoint: logseq 33251, block 2, scn 14624215134369
  cache-low rba: logseq 33251, block 2463324
    on-disk rba: logseq 33251, block 2803965, scn 14624216078841
  start recovery at logseq 33251, block 2463324, scn 0
*** 2016-10-24 17:43:16.406
ksedmp: internal or fatal error
ORA-00600: internal error code, arguments: [kcrfr_update_nab_2], [0x7FFC22A2150], [2], [], [], [], [], []
Current SQL statement for this session:
ALTER DATABASE OPEN
----- Call Stack Trace -----
calling              call     entry                argument values in hex
location             type     point                (? means dubious value)
-------------------- -------- -------------------- ----------------------------
ksedmp+663           CALL???  ksedst+55            003C878B8 000000000 012B863E8
                                                   000000000
ksfdmp+19            CALL???  ksedmp+663           000000003 015572A70 007222698
                                                   003CACC80
kgerinv+158          CALL???  ksfdmp+19            015572430 000000000 0FFFFFFFF
                                                   000000000
kgeasnmierr+62       CALL???  kgerinv+158          000000000 000000000 000000000
                                                   004FD788F
kcrfr_update_nab+18  CALL???  kgeasnmierr+62       00BDA1170 000000000 000000000
6                                                  000000002
kcrfr_read+1078      CALL???  kcrfr_update_nab+18  007222698 00001E650 015572430
                              6                    0072229B8
kcrfrgv+8134         CALL???  kcrfr_read+1078      000000000 0051525D7 000000000
                                                   0051525D7
kcratr1+488          CALL???  kcrfrgv+8134         007222698 000000000 000000000
                                                   000000000
kcratr+412           CALL???  kcratr1+488          012B891C8 012B890A4 00727FFB8
                                                   00BEA7FF0
kctrec+1910          CALL???  kcratr+412           012B891C8 012B91E18 000000000
                                                   012B91E48
kcvcrv+3585          CALL???  kctrec+1910          012B92C58 000000000 00726DF00
                                                   00726BDB0
kcfopd+1007          CALL???  kcvcrv+3585          012B93350 000000000 000000000
                                                   000000000
adbdrv+55820         CALL???  kcfopd+1007          000000000 000000000 000000000
                                                   000000000
opiexe+13897         CALL???  adbdrv+55820         000000023 000000003 000000102
                                                   000000000
opiosq0+3558         CALL???  opiexe+13897         000000004 000000000 012B9B238
                                                   4155474E414C5F45
kpooprx+339          CALL???  opiosq0+3558         000000003 00000000E 012B9B3C8
                                                   0000000A4
kpoal8+894           CALL???  kpooprx+339          015587550 000000018 0041AE700
                                                   000000001
opiodr+1136          CALL???  kpoal8+894           00000005E 000000017 012B9E868
                                                   0072F5100
ttcpip+5146          CALL???  opiodr+1136          00000005E 000000017 012B9E868
                                                   2D8C00000000
opitsk+1818          CALL???  ttcpip+5146          015587550 000000000 000000000
                                                   000000000
opiino+1129          CALL???  opitsk+1818          00000001E 000000000 000000000
                                                   000000000
opiodr+1136          CALL???  opiino+1129          00000003C 000000004 012B9FB20
                                                   000000000
opidrv+815           CALL???  opiodr+1136          00000003C 000000004 012B9FB20
                                                   000000000
sou2o+52             CALL???  opidrv+815           00000003C 000000004 012B9FB20
                                                   7FF7FC48580
opimai_real+131      CALL???  sou2o+52             000000000 012B9FC40
                                                   7FFFFF7F258 077EF4D1C
opimai+96            CALL???  opimai_real+131      7FF7FC48580 7FFFFF7E000
                                                   0001F0003 000000000
OracleThreadStart+6  CALL???  opimai+96            012B9FEF0 01289FF3C 012B9FCC0
40                                                 7FF7FC48580
0000000077D6B6DA     CALL???  OracleThreadStart+6  01289FF3C 000000000 000000000
                              40                   012B9FFA8

官方描述
The assert ORA-600: [kcrfr_update_nab_2] is a direct result of a lost write in the current on line log that we are attempting to resolve.So, this confirms the theory that this is a OS/hardware lost write issue not an internal oracle bug. In fact the assert ORA-600: [kcrfr_update_nab_2] is how we detect a lost log write.
Bug 5692594
Hdr: 5692594 10.2.0.1 RDBMS 10.2.0.1 RECOVERY PRODID-5 PORTID-226 ORA-600
Abstract: AFTER DATABASE CRASHED DOESN’T OPEN ORA-600 [KCRFR_UPDATE_NAB_2]
Status: 95,Closed, Vendor OS Problem
Bug 6655116
Hdr: 6655116 10.2.0.3 RDBMS 10.2.0.3 RECOVERY PRODID-5 PORTID-23
Abstract: INSTANCES CRASH WITH ORA-600 [KCRFR_UPDATE_NAB_2] AFTER DISK FAILURE
根据官方的描述,结合故障情况,基本上可以确定是由于硬件异常导致Oracle写丢失,从而除非oracle相关bug导致数据库无法正常启动

ORA-600 [kcrfr_update_nab_2] [a] [b]
VERSIONS:
versions 10.2 to 11.1
DESCRIPTION:
Failure of upgrade of recovery node (RN) enqueue to SSX mode
ARGUMENTS:
Arg [a] State Object for redo nab enqueue for resilvering
Arg [b] Redo nab enqueue mode
FUNCTIONALITY:
Kernel Cache Redo File Read
IMPACT:
INSTANCE FAILURE

处理方法
1.如果有备份,利用备份进行不完全恢复,跳过最后异常的redo,数据库resetlogs打开
2.如果没有备份,尝试使用历史的控制文件进行不完全恢复,或者直接跳过数据库一致性打开库.
3.互联网有人解决删除redo第二组成员数据库open成功(http://blog.itpub.net/16976507/viewspace-1266952/)
redo


ORA-20011 KUP-11024错误分析

联系:手机/微信(+86 17813235971) QQ(107644445)

标题:ORA-20011 KUP-11024错误分析

作者:惜分飞©版权所有[未经本人同意,不得以任何形式转载,否则有进一步追究法律责任的权利.]

数据库alert日志出现ORA-20011 KUP-11024等错误

Thu Sep 22 18:00:31 2016
DBMS_STATS: GATHER_STATS_JOB encountered errors.  Check the trace file.
Errors in file /u1/oracle/diag/rdbms/xifenfei/xifenfei/trace/xifenfei_j002_2686.trc:
ORA-20011: Approximate NDV failed: ORA-29913: error in executing ODCIEXTTABLEOPEN callout
KUP-11024: This external table can only be accessed from within a Data Pump job.

从报错的信息看应该是数据库收集统计信息报错(GATHER_STATS_JOB),但是报错原因是由于访问外部表导致,而该外部表很可能和data pump有关系.

查看trace日志

[oracle@xifenfei]$ more /u1/oracle/diag/rdbms/xifenfei/xifenfei/trace/xifenfei_j002_2686.trc
Trace file /u1/oracle/diag/rdbms/xifenfei/xifenfei/trace/xifenfei_j002_2686.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /u1/oracle/pruduct/11.2.0.3
System name:    Linux
Node name:      xifenfei
Release:        2.6.32-220.el6.x86_64
Version:        #1 SMP Wed Nov 9 08:03:13 EST 2011
Machine:        x86_64
Instance name: xifenfei
Redo thread mounted by this instance: 1
Oracle process number: 356
Unix process pid: 2686, image: oracle@xifenfei (J002)
*** 2016-09-22 18:00:31.939
*** SESSION ID:(835.16363) 2016-09-22 18:00:31.939
*** CLIENT ID:() 2016-09-22 18:00:31.939
*** SERVICE NAME:(SYS$USERS) 2016-09-22 18:00:31.939
*** MODULE NAME:(DBMS_SCHEDULER) 2016-09-22 18:00:31.939
*** ACTION NAME:(ORA$AT_OS_OPT_SY_10669) 2016-09-22 18:00:31.939
ORA-20011: Approximate NDV failed: ORA-29913: error in executing ODCIEXTTABLEOPEN callout
KUP-11024: This external table can only be accessed from within a Data Pump job.
*** 2016-09-22 18:00:31.939
DBMS_STATS: GATHER_STATS_JOB: GATHER_TABLE_STATS('"DWDBA"','"ET$012D00070001"','""', ...)
DBMS_STATS: ORA-20011: Approximate NDV failed: ORA-29913: error in executing ODCIEXTTABLEOPEN callout
KUP-11024: This external table can only be accessed from within a Data Pump job.
*** 2016-09-22 18:00:31.960
DBMS_STATS: GATHER_STATS_JOB: GATHER_TABLE_STATS('"DWDBA"','"ET$01D10D4F0001"','""', ...)
DBMS_STATS: ORA-20011: Approximate NDV failed: ORA-29913: error in executing ODCIEXTTABLEOPEN callout
KUP-11024: This external table can only be accessed from within a Data Pump job.

通过trace文件,我们已经可以明确是由于数据库对DWDBA.ET$012D00070001和DWDBA.ET$01D10D4F0001这两个表收集统计信息时候报的上述alert日志中看到的错误.

查询数据库记录

SYS@xifenfei>select OWNER,OBJECT_NAME,OBJECT_TYPE, status,
  2  to_char(CREATED,'dd-mon-yyyy hh24:mi:ss') created
  3  ,to_char(LAST_DDL_TIME , 'dd-mon-yyyy hh24:mi:ss') last_ddl_time
  4  from dba_objects
  5  where object_name like 'ET$%'
  6  /
OWNER     OBJECT_NAME      OBJECT_TYPE  STATUS  CREATED               LAST_DDL_TIME
--------- ---------------- ------------ ------- ------------------------- ----------------
DWDBA     ET$012D00070001  TABLE        VALID   10-mar-2016 16:32:25  10-mar-2016 16:32:25
DWDBA     ET$01D10D4F0001  TABLE        VALID   10-mar-2016 17:29:29  10-mar-2016 17:29:29
SYS@xifenfei> select owner, TABLE_NAME, DEFAULT_DIRECTORY_NAME, ACCESS_TYPE
  2  from dba_external_tables
  3  order by 1,2
  4  /
OWNER       TABLE_NAME                     DEFAULT_DIRECTORY_NAME         ACCESS_
----------- ------------------------------ ------------------------------ -------
DWDBA       ET$012D00070001                EXP_FILE_DIR                   CLOB
DWDBA       ET$01D10D4F0001                EXP_FILE_DIR                   CLOB

到这一步,我们已经完全清楚,ET$012D00070001和ET$01D10D4F0001是两个外部表,由于他们的存在使得收集统计信息异常。

分析ET$012D00070001表

SYS@xifenfei>desc DWDBA.ET$012D00070001
 Name                                                  Null?    Type
 ----------------------------------------------------- -------- ------------------------------------
 STORE_NO                                                       NUMBER(3)
 ITEM_NO                                                        NUMBER(6)
 WORK_DATE                                                      DATE
 DIVISION_NO                                                    NUMBER(2)
 SECTION_NO                                                     NUMBER(3)
 SUP_NO                                                         NUMBER(6)
 GRP_NO                                                         NUMBER(3)
 SUBGRP_NO                                                      NUMBER(3)
 USR                                                            VARCHAR2(30)
 TYPE                                                           NUMBER(1)
 ACTIVE_SELL_PRICE                                              NUMBER(8,2)
 SELL_PRICE                                                     NUMBER(8,2)
 SELL_VAT                                                       NUMBER(1)
 BUY_PRICE                                                      NUMBER(10,4)
 BUY_VAT                                                        NUMBER(1)
 PROMOTION_NO                                                   NUMBER(10)
 PROM_CLASS                                                     VARCHAR2(1)
 PROM_LEVEL                                                     NUMBER(1)
 STOCK                                                          NUMBER(10,3)
 STOCK_ADJ                                                      NUMBER(10,3)
 RECPT                                                          NUMBER(10,3)
 SALES                                                          NUMBER(10,3)
 STOCK_ADJ_AMNT                                                 NUMBER(10,2)
 RECPT_AMNT                                                     NUMBER(10,2)
 SALES_AMNT                                                     NUMBER(10,2)
 PROF_AMNT                                                      NUMBER(10,2)
 COST_CHANGE                                                    NUMBER(10,2)
 DISC                                                           NUMBER(10,3)
 RTN_QTY                                                        NUMBER(9,3)
 DISC_AMNT                                                      NUMBER(10,2)
 RTN_AMNT                                                       NUMBER(10,2)
 LOSS_AMNT                                                      NUMBER(10,2)
 CREATED_DATE                                                   DATE
 COST                                                           NUMBER(10,4)
 NBR_PK                                                         NUMBER(5)
 NBR_VISIT                                                      NUMBER(5)
 NBR_PK_LINE                                                    NUMBER(5)
 N_N_PROF_AMNT                                                  NUMBER(9,2)
 CON_FORE                                                       NUMBER(10,2)
 CON_FORE_OTH                                                   NUMBER(10,2)
 SALES_B                                                        NUMBER(10,3)
 SALES_AMNT_B                                                   NUMBER(10,2)
SYS@xifenfei>select count(*) from DWDBA.ET$012D00070001;
select count(*) from DWDBA.ET$012D00070001
*
ERROR at line 1:
ORA-29913: error in executing ODCIEXTTABLEOPEN callout
KUP-11024: This external table can only be accessed from within a Data Pump job.

通过对ET$012D00070001表查询重新了alert日志一样的错误,可以明确定位问题就是由于该外部表异常导致.通过查询mos,确定Bug 10327346 DBMS_WORKLOAD_CAPTURE does not drop external tables (causing ORA-20011 from DBMS_STATS)可能导致DBMS_WORKLOAD_CAPTURE无法正常清理掉Data pump的外部表导致出现Datapump出现孤立的外部表对象,从而出现该问题.解决方案就是直接drop 相关外部表.也就是这里的(ET$012D00070001和ET$01D10D4F0001)

ORA-600 kcbz_check_objd_typ_1 处理

联系:手机/微信(+86 17813235971) QQ(107644445)

标题:ORA-600 kcbz_check_objd_typ_1 处理

作者:惜分飞©版权所有[未经本人同意,不得以任何形式转载,否则有进一步追究法律责任的权利.]

客户数据库异常(ORA-600 kcbz_check_objd_typ_1),让我们远程给分析处理
ORA-600 kcbz_check_objd_typ_1异常

Mon Aug  8 12:19:28 2016
Completed: ALTER DATABASE OPEN
Mon Aug  8 12:19:29 2016
db_recovery_file_dest_size of 20480 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  8 12:19:33 2016
Errors in file /home/oracle/admin/RT/bdump/rt_smon_1514.trc:
ORA-00600: internal error code, arguments: [kcbz_check_objd_typ_1], [0], [0], [1], [], [], [], []
Mon Aug  8 12:20:21 2016
Shutting down archive processes
Mon Aug  8 12:20:26 2016
ARCH shutting down
ARC3: Archival stopped
Mon Aug  8 13:12:25 2016
Thread 1 advanced to log sequence 13804
  Current log# 3 seq# 13804 mem# 0: /home/oracle/product/10.2.0/oradata/RT/redo03a.log
Mon Aug  8 14:01:37 2016
Thread 1 advanced to log sequence 13805
  Current log# 2 seq# 13805 mem# 0: /home/oracle/product/10.2.0/oradata/RT/redo02a.log
Mon Aug  8 14:20:51 2016
Errors in file /home/oracle/admin/RT/bdump/rt_smon_1514.trc:
ORA-00600: internal error code, arguments: [kcbz_check_objd_typ_1], [0], [0], [1], [], [], [], []
Mon Aug  8 15:54:47 2016
Thread 1 advanced to log sequence 13808
  Current log# 2 seq# 13808 mem# 0: /home/oracle/product/10.2.0/oradata/RT/redo02a.log
Mon Aug  8 16:21:48 2016
Errors in file /home/oracle/admin/RT/bdump/rt_smon_1514.trc:
ORA-00600: internal error code, arguments: [kcbz_check_objd_typ_1], [0], [0], [1], [], [], [], []
Mon Aug  8 16:22:05 2016
Errors in file /home/oracle/admin/RT/bdump/rt_pmon_1500.trc:
ORA-00474: SMON process terminated with error

这里比较明显,数据库报大量ORA-600 kcbz_check_objd_typ_1错误之后,然后smon进程终止,实例crash.

smon trace文件

Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - Production
With the Partitioning, OLAP and Data Mining options
ORACLE_HOME = /home/oracle/product/10.2.0/db_1
System name:	SunOS
Node name:	st104
Release:	5.10
Version:	Generic_141445-09
Machine:	i86pc
Instance name: RT
Redo thread mounted by this instance: 1
Oracle process number: 12
Unix process pid: 1514, image: oracle@st104 (SMON)
*** 2016-08-08 12:19:26.868
*** SERVICE NAME:() 2016-08-08 12:19:26.868
*** SESSION ID:(383.1) 2016-08-08 12:19:26.868
Dead transaction 0x003d.002.0000f964 recovered by SMON
Dead transaction 0x0041.017.00004d55 recovered by SMON
Dead transaction 0x0047.002.0000180c recovered by SMON
Dead transaction 0x004c.01c.00001b57 recovered by SMON
*** SESSION ID:(383.1) 2016-08-08 12:19:27.470
DATA seg.obj=0, on-disk obj=925949, dsflg=0, dsobj=923715, cls=4
Formatted dump of block:
buffer tsn: 4 rdba: 0x0100336b (4/13163)
scn: 0x09c6.b2c7f7a2 seq: 0x02 flg: 0x04 tail: 0xf7a20602
frmt: 0x02 chkval: 0x649b type: 0x06=trans data
Hex dump of block: st=0, typ_found=1
*** SESSION ID:(383.1) 2016-08-08 12:19:34.244
DATA seg.obj=0, on-disk obj=925950, dsflg=0, dsobj=923671, cls=4
Formatted dump of block:
buffer tsn: 4 rdba: 0x01003343 (4/13123)
scn: 0x09c6.b2c7f7dc seq: 0x02 flg: 0x04 tail: 0xf7dc0602
frmt: 0x02 chkval: 0x8013 type: 0x06=trans data
Hex dump of block: st=0, typ_found=1
*** SESSION ID:(383.1) 2016-08-08 12:19:35.197
DATA seg.obj=0, on-disk obj=925941, dsflg=0, dsobj=923657, cls=4
Formatted dump of block:
buffer tsn: 7 rdba: 0x01c03d53 (7/15699)
scn: 0x09c6.b2c7f570 seq: 0x02 flg: 0x04 tail: 0xf5700602
frmt: 0x02 chkval: 0xe5c5 type: 0x06=trans data
Hex dump of block: st=0, typ_found=1
*** SESSION ID:(383.1) 2016-08-08 12:19:38.965
DATA seg.obj=0, on-disk obj=925948, dsflg=0, dsobj=923656, cls=4
Formatted dump of block:
buffer tsn: 7 rdba: 0x01c03a6b (7/14955)
scn: 0x09c6.b2c7f745 seq: 0x02 flg: 0x04 tail: 0xf7450602
frmt: 0x02 chkval: 0x58c5 type: 0x06=trans data
Hex dump of block: st=0, typ_found=1

这里可以看出来有block中的obj和dataobj不匹配.

查询seg$.type=3
type=3为临时对象,由于异常原因导致smon在清理temp对象无法正常完成,从而使得smon终止,实例crash.

SQL> select file#, block#, ts# from seg$ where type# = 3;
     FILE#     BLOCK#        TS#
---------- ---------- ----------
         4      13163          4
         4      13123          4
         7      15699          7
         7      14955          7

ORA-600 kcbz_check_objd_typ_1处理方法

1) Check tablespace bitmap
SQL> oradebug setmypid
SQL> exec dbms_space_admin.tablespace_verify('&TBSP_NAME')
SQL> oradebug tracefile_name
or if the tablespace involved is an ASSM tablespace:
SQL> oradebug setmypid
SQL> exec dbms_space_admin.assm_tablespace_verify ('&TBSP_NAME',dbms_space_admin.TS_VERIFY_BITMAPS)
SQL> oradebug tracefile_name
I am expecting to fail
2) Corrupt these temp segments
SQL> exec dbms_space_admin.segment_corrupt('&TBSP_NAME', &FILE#, &BLOCK#)
3) Drop them
SQL> exec dbms_space_admin.segment_drop_corrupt('&TBSP_NAME', &FILE#, &BLOCK#)
4) Rebuild tablespace bitmap
exec DBMS_SPACE_ADMIN.TABLESPACE_REBUILD_BITMAPS('&TBSP_NAME')
5) Verify the tablespace again
SQL> oradebug setmypid
SQL> exec dbms_space_admin.tablespace_verify('&TBSP_NAME')
SQL> oradebug tracefile_name
or if the tablespace involved is an ASSM tablespace:
SQL> oradebug setmypid
SQL> exec dbms_space_admin.assm_tablespace_verify('&TBSP_NAME',dbms_space_admin.TS_VERIFY_BITMAPS)
SQL> oradebug tracefile_name

ORA-600 999 异常恢复

联系:手机/微信(+86 17813235971) QQ(107644445)

标题:ORA-600 999 异常恢复

作者:惜分飞©版权所有[未经本人同意,不得以任何形式转载,否则有进一步追究法律责任的权利.]

有网友数据库启动报ORA-600 999错误,无法正常open,让我们介入分析,帮忙恢复其中部分数据
数据库启动报ORA-600 999

Sun Jul 31 23:09:36 2016
SMON: enabling cache recovery
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
Errors in file d:\app\administrator\diag\rdbms\orcl\orcl\trace\orcl_smon_3356.trc  (incident=179779):
ORA-00600: internal error code, arguments: [999], [0x7FFAE748013], [], [], [], [], [], [], [], [], [], []
Incident details in: d:\app\administrator\diag\rdbms\orcl\orcl\incident\incdir_179779\orcl_smon_3356_i179779.trc
No Resource Manager plan active
Starting background process QMNC
Sun Jul 31 23:09:37 2016
QMNC started with pid=20, OS id=5068
ORACLE Instance orcl (pid = 13) - Error 600 encountered while recovering transaction (7, 1).
Errors in file d:\app\administrator\diag\rdbms\orcl\orcl\trace\orcl_smon_3356.trc:
ORA-00600: internal error code, arguments: [999], [0x7FFAE748013], [], [], [], [], [], [], [], [], [], []
Completed: alter database open
Sun Jul 31 23:09:38 2016
db_recovery_file_dest_size of 8680 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.
Trace dumping is performing id=[cdmp_20160731230939]
Errors in file d:\app\administrator\diag\rdbms\orcl\orcl\trace\orcl_smon_3356.trc  (incident=179785):
ORA-00600: internal error code, arguments: [999], [0x7FFAE748013], [], [], [], [], [], [], [], [], [], []
ORACLE Instance orcl (pid = 13) - Error 600 encountered while recovering transaction (7, 1).
Errors in file d:\app\administrator\diag\rdbms\orcl\orcl\trace\orcl_smon_3356.trc:
ORA-00600: internal error code, arguments: [999], [0x7FFAE748013], [], [], [], [], [], [], [], [], [], []
Sun Jul 31 23:09:41 2016
Starting background process CJQ0
Sun Jul 31 23:09:41 2016
CJQ0 started with pid=25, OS id=2572
Process debug not enabled via parameter _debug_enable
Trace dumping is performing id=[cdmp_20160731230942]
PMON (ospid: 3948): terminating the instance due to error 474
Sun Jul 31 23:09:48 2016
opiodr aborting process unknown ospid (2592) as a result of ORA-1092
Sun Jul 31 23:09:48 2016
ORA-1092 : opitsk aborting process
Sun Jul 31 23:09:52 2016
Instance terminated by PMON, pid = 3948

设置_offline_rollback_segments数据库启动正常

Sun Jul 31 23:18:13 2016
ALTER DATABASE OPEN
Thread 1 opened at log sequence 16
  Current log# 1 seq# 16 mem# 0: D:\APP\ADMINISTRATOR\ORADATA\ORCL\REDO01.LOG
Successful open of redo thread 1
SMON: enabling cache recovery
Successfully onlined Undo Tablespace 5.
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
Errors in file d:\app\administrator\diag\rdbms\orcl\orcl\trace\orcl_smon_4372.trc  (incident=182188):
ORA-00600: internal error code, arguments: [kdBlkCheckError], [3], [224], [38508], [], [], [], [], [], [], [], []
Incident details in: d:\app\administrator\diag\rdbms\orcl\orcl\incident\incdir_182188\orcl_smon_4372_i182188.trc
Doing block recovery for file 3 block 224
Resuming block recovery (PMON) for file 3 block 224
Block recovery from logseq 16, block 2945 to scn 15431544
Recovery of Online Redo Log: Thread 1 Group 1 Seq 16 Reading mem 0
  Mem# 0: D:\APP\ADMINISTRATOR\ORADATA\ORCL\REDO01.LOG
Trace dumping is performing id=[cdmp_20160731231815]
Block recovery stopped at EOT rba 16.2952.16
Block recovery completed at rba 16.2952.16, scn 0.15431543
Errors in file d:\app\administrator\diag\rdbms\orcl\orcl\trace\orcl_smon_4372.trc:
ORA-00607: Internal error occurred while making a change to a data block
ORA-00600: internal error code, arguments: [kdBlkCheckError], [3], [224], [38508], [], [], [], [], [], [], [], []
Sun Jul 31 23:18:19 2016
Errors in file d:\app\administrator\diag\rdbms\orcl\orcl\trace\orcl_smon_4372.trc  (incident=182189):
ORA-00600: internal error code, arguments: [kdBlkCheckError], [3], [224], [38508], [], [], [], [], [], [], [], []
Incident details in: d:\app\administrator\diag\rdbms\orcl\orcl\incident\incdir_182189\orcl_smon_4372_i182189.trc
Starting background process QMNC
Sun Jul 31 23:18:19 2016
QMNC started with pid=20, OS id=4920
Doing block recovery for file 3 block 224
Resuming block recovery (PMON) for file 3 block 224
Block recovery from logseq 16, block 2945 to scn 15431544
Recovery of Online Redo Log: Thread 1 Group 1 Seq 16 Reading mem 0
  Mem# 0: D:\APP\ADMINISTRATOR\ORADATA\ORCL\REDO01.LOG
Block recovery completed at rba 16.2952.16, scn 0.15431545
Errors in file d:\app\administrator\diag\rdbms\orcl\orcl\trace\orcl_smon_4372.trc:
ORA-00607: Internal error occurred while making a change to a data block
ORA-00600: internal error code, arguments: [kdBlkCheckError], [3], [224], [38508], [], [], [], [], [], [], [], []
Starting background process SMCO
Sun Jul 31 23:18:19 2016
SMCO started with pid=21, OS id=3176
Sun Jul 31 23:18:20 2016
Trace dumping is performing id=[cdmp_20160731231820]
Completed: ALTER DATABASE OPEN

尝试删除异常回滚段

Sun Jul 31 23:15:07 2016
drop rollback segment "_SYSSMU7_1101470402$"
Sun Jul 31 23:15:07 2016
Corrupt Block Found
         TSN = 2, TSNAME = UNDOTBS1
         RFN = 3, BLK = 224, RDBA = 12583136
         OBJN = -1, OBJD = -1, OBJECT = , SUBOBJECT =
         SEGMENT OWNER = , SEGMENT TYPE =
Errors in file d:\app\administrator\diag\rdbms\orcl\orcl\trace\orcl_ora_5300.trc  (incident=181035):
ORA-00600: 内部错误代码, 参数: [kdBlkCheckError], [3], [224], [38508], [], [], [], [], [], [], [], []
Incident details in: d:\app\administrator\diag\rdbms\orcl\orcl\incident\incdir_181035\orcl_ora_5300_i181035.trc
Doing block recovery for file 3 block 224
Resuming block recovery (PMON) for file 3 block 224
Block recovery from logseq 14, block 8682 to scn 15397854
Recovery of Online Redo Log: Thread 1 Group 2 Seq 14 Reading mem 0
  Mem# 0: D:\APP\ADMINISTRATOR\ORADATA\ORCL\REDO02.LOG
Block recovery completed at rba 14.8688.16, scn 0.15397855
ORA-607 signalled during: drop rollback segment "_SYSSMU7_1101470402$"...
Corrupt Block Found
         TSN = 2, TSNAME = UNDOTBS1
         RFN = 3, BLK = 224, RDBA = 12583136
         OBJN = -1, OBJD = -1, OBJECT = , SUBOBJECT =
         SEGMENT OWNER = , SEGMENT TYPE =

从这里看,我们可以确定file 3 block 224异常,导致删除回滚段异常.和mos官方给出来的案例类似,由于undo坏块导致数据库报ORA-600 999错误

mos中ORA-600 999报错信息
官方的益处ORA-600[999]报错,也是由于undo坏块引起和本文的报错基本上一致
ORA-600-999


因为只要部分数据,直接屏蔽回滚段,数据库不再crash,导出需要对象即可

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

联系:手机/微信(+86 17813235971) QQ(107644445)

标题:记录一次存储异常数据库恢复后遗症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 故障恢复

联系:手机/微信(+86 17813235971) QQ(107644445)

标题: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

ORA-600 kccpb_sanity_check_2故障恢复

联系:手机/微信(+86 17813235971) QQ(107644445)

标题: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

联系:手机/微信(+86 17813235971) QQ(107644445)

标题:多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描述