一次ora-00600 [4194]的错误分析

前不久东区某客户的一个核心数据库出现故障;由于异常宕机之后,数据库无法正常打开;虽然数据库有完整的备份和归档,然而考虑到数据量较大,超过5TB,客户想通过其他手段能够尽快将数据库拉起来,恢复业务。预算我尝试了如下一些列操作。

这里我们首先来看一下数据库的报错信息是什么样的:

ORA-00600: internal error code, arguments: [4194], [], [], [], [], [], [], [], [], [], [], []
ORA-00600: internal error code, arguments: [4194], [], [], [], [], [], [], [], [], [], [], []

 

我们可以看到,这是大家非常熟悉的经典错误,ora-00600 4194;其次报错的SQL语句如下:

update /*+ rule */ undo$ set name=:2,file#=:3,block#=:4,status$=:5,user#=:6,undosqn=:7,xactsqn=:8,scnbas=:9,scnwrp=:10,inst#=:11,ts#=:12,spare1=:13 where us#=:1
END OF STMT
PARSE #46912533790200:c=17997,e=89897,p=12,cr=59,cu=0,mis=1,r=0,dep=1,og=3,plh=0,tim=1460688192385667
BINDS #46912533790200:
 Bind#0
  oacdty=01 mxl=32(20) mxlc=00 mal=00 scl=00 pre=00
  oacflg=18 fl2=0001 frm=01 csi=873 siz=32 off=0
  kxsbbbfp=1feea695d2  bln=32  avl=20  flg=09
  value="_SYSSMU1_3724004606$"
 Bind#1
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=2aaaad1746e0  bln=24  avl=02  flg=05
  value=3
 .......
........
 Bind#12
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=2aaaad174710  bln=22  avl=02  flg=05
  value=1
WAIT #46912533790200: nam='db file sequential read' ela= 12451 file#=1 block#=103328 blocks=1 obj#=0 tim=1460688192400006
Incident 504337 created, dump file: /oracle/app/oraclebase/diag/rdbms/arsys/arsys1/incident/incdir_504337/arsys1_ora_3815_i504337.trc
ORA-00600: internal error code, arguments: [4194], [], [], [], [], [], [], [], [], [], [], []

 

不难发现,这是针对oracle数据字典表undo$的操作。实际上我们可以看到,这里Oracle在对第1号回滚段进行操作时,出现了异常;所以最开始我通过teamviewer远程诊断时,发现之后就立刻编译了bbed,然后修改undo$数据字典基表,将1号回滚段的状态改成offline,这样可以绕过Oracle对该回滚段的操作。经过操作之后,我open数据库时,发现可以打开数据库,不过很快就挂掉了。

然而此时我却并没有注意,时间比较急,赶着去客户现场;因此后续的工作由东区工程师接手了。等东区的同事接手之后,检查日志发现数据库已经挂掉了,也就是说数据库虽然open了,但是很快就crash掉了。

后面我建议同事利用rman备份进行了恢复,通过恢复system文件,然后结合数据库归档进行恢复即可。当同事将当时的相关trace文件发给我之后,我进行了进一步研究,发现该问题如果要手工修复,还是比较复杂的,这里进行简单的分析说明。

首先我们来看当时报错的日志信息:

Dump continued from file: /oracle/app/oraclebase/diag/rdbms/arsys/arsys1/trace/arsys1_ora_5304.trc
ORA-00600: internal error code, arguments: [4194], [ry_file_dest
========= Dump for incident 288337 (ORA 600 [4194]) ========
----- Beginning of Customized Incident Dump(s) -----
*** ktuc_diag_dmp: dump of current change vector
ktudb redo: siz: 308 spc: 3682 flg: 0x0012 seq: 0x006e rec: 0x1b
            xid:  0x0000.050.00000046  
ktubl redo: slt: 80 rci: 0 opc: 11.1 [objn: 15 objd: 15 tsn: 0]
Undo type:  Regular undo        Begin trans    Last buffer split:  No 
Temp Object:  No 
Tablespace Undo:  No 
             0x00000000  prev ctl uba: 0x004193a0.006e.1a 
prev ctl max cmt scn:  0x0020.97e1eba3  prev tx cmt scn:  0x0020.97e1eba6 
txn start scn:  0xffff.ffffffff  logon user: 0  prev brb: 4297624  prev bcl: 0 BuExt idx: 0 flg2: 0
KDO undo record:
KTB Redo 
op: 0x04  ver: 0x01  
compat bit: 4 (post-11) padding: 1
op: L  itl: xid:  0x0000.037.00000045 uba: 0x0041939a.006d.1a
                      flg: C---    lkc:  0     scn: 0x0020.97e1b044
KDO Op code: URP row dependencies Disabled
  xtype: XA flags: 0x00000000  bdba: 0x004000e1  hdba: 0x004000e0
itli: 3  ispac: 0  maxfr: 4863
tabn: 0 slot: 1(0x1) flag: 0x2c lock: 0 ckix: 150
ncol: 17 nnew: 12 size: 0
col  1: [20]  5f 53 59 53 53 4d 55 31 5f 33 37 32 34 30 30 34 36 30 36 24
col  2: [ 2]  c1 02
col  3: [ 2]  c1 04
col  4: [ 3]  c2 02 1d
col  5: [ 6]  c5 11 3b 63 46 0b
col  6: [ 2]  c1 21
col  7: [ 4]  c3 02 20 2b
col  8: [ 3]  c2 19 3a
col  9: [ 2]  c1 03
col 10: [ 2]  c1 04
col 11: [ 2]  c1 03
col 16: [ 2]  c1 03

 

从上述信息可以看出,oracle的提示也较为明确,已经可以进行大致的判断。或许有人还不理解4194错误的含义,这里允许我进行简单说明,该错误的含义表示oracle在对数据块进行recover时发现redo记录与undo record不匹配,则会抛出该错误。

很明显,上述redo dump中,提到的事务(xid)为:xid:  0x0000.050.00000046;且该事务对于的undo block地址为:uba: 0x004193a0.006e.1a;其中004193a0 表示undo block 地址。

上述的dump还要一层隐藏的含义表示,该redo record对应的undo record记录为undo block(004193a0)中的第1a(转换为10进制为26)个undo record记录。既然如此,那么我们来看一下该undo block的dump情况:

UNDO BLK:  
xid: 0x0000.056.00000046  seq: 0x6e  cnt: 0xe   irb: 0xe   icl: 0x0   flg: 0x0000
 
 Rec Offset      Rec Offset      Rec Offset      Rec Offset      Rec Offset
---------------------------------------------------------------------------
0x01 0x1f48     0x02 0x1ee4     0x03 0x1e94     0x04 0x1e60     0x05 0x1e00     
0x06 0x1c9c     0x07 0x1c30     0x08 0x1bd4     0x09 0x1b5c     0x0a 0x19f8     
0x0b 0x18f8     0x0c 0x17c4     0x0d 0x175c     0x0e 0x16cc     
......
......
*-----------------------------
* Rec #0xd  slt: 0x56  objn: 2(0x00000002)  objd: 4294967295  tblspc: 2(0x00000002)
*       Layer:  22 (Tablespace Bitmapped file)   opc: 3   rci 0x00   
Undo type:  Regular undo    Begin trans    Last buffer split:  No 
Temp Object:  No 
Tablespace Undo:  Yes 
rdba: 0x00000000Ext idx: 0
flg2: 0
*-----------------------------
uba: 0x004193a0.006e.0c ctl max scn: 0x0020.97e1b1ae prv tx scn: 0x0020.97e1b1b1
txn start scn: scn: 0x0020.97e1f99f logon user: 93
 prev brb: 4297624 prev bcl: 0
ktfbhundo - File Space Header Undo:
Space Header DBA:0xc00002, File:0x3 
Header Opcode: 
Save: Free Extent: 
Begin: 36432, Length: 8, Instance: 0 
 
*-----------------------------
* Rec #0xe  slt: 0x56  objn: 14(0x0000000e)  objd: 8  tblspc: 0(0x00000000)
*       Layer:  11 (Row)   opc: 1   rci 0x0d   
Undo type:  Regular undo   Last buffer split:  No 
Temp Object:  No 
Tablespace Undo:  No 
rdba: 0x00000000
*-----------------------------
KDO undo record:
KTB Redo 
op: 0x04  ver: 0x01  
compat bit: 4 (post-11) padding: 1
op: L  itl: xid:  0x0000.03b.00000046 uba: 0x004193a0.006e.0a
                      flg: C---    lkc:  0     scn: 0x0020.97e1f953
KDO Op code: DRP row dependencies Disabled
  xtype: XA flags: 0x00000000  bdba: 0x00417cf2  hdba: 0x004000c0
itli: 2  ispac: 0  maxfr: 4863
tabn: 2 slot: 13(0xd)

 

到这里很明白了,该undo block中,undo record的记录一共只有0e(转换为10进制为14)个,怎么会有26个呢?很明显,这是不匹配的。这也就不难理解,为什么Oracle 会抛出这样的错误了。

那最后我们会想,如果要通过bbed 来修复该错误,是否可以呢? 答案是肯定的。

我们进一步看下该数据块的dump:

  -----------------------------------------------------------------
  Extent Header:: spare1: 0      spare2: 0      #extents: 13     #blocks: 103   
                  last map  0x00000000  #maps: 0      offset: 4128  
      Highwater::  0x004193a1  ext#: 3      blk#: 1      ext size: 8     
  #blocks in seg. hdr's freelists: 0     
  #blocks below: 0     
  mapblk  0x00000000  offset: 3     
                   Unlocked
     Map Header:: next  0x00000000  #extents: 13   obj#: 0      flag: 0x40000000
  Extent Map
  -----------------------------------------------------------------
   0x00400081  length: 7     
   ......    
  
  TRN CTL:: seq: 0x006e chd: 0x001d ctl: 0x003f inc: 0x00000000 nfb: 0x0001
            mgc: 0x8002 xts: 0x0068 flg: 0x0001 opt: 2147483646 (0x7ffffffe)
            uba: 0x004193a0.006e.1b scn: 0x0020.97e1eba6
Version: 0x01
  FREE BLOCK POOL::
    uba: 0x00000000.006e.1a ext: 0x3  spc: 0xe62   
    uba: 0x004193a1.006e.0e ext: 0x3  spc: 0x169e  
    uba: 0x00000000.005f.14 ext: 0x1  spc: 0x138e  
    uba: 0x00000000.005d.04 ext: 0xc  spc: 0x1e56  
    uba: 0x00000000.005d.02 ext: 0xc  spc: 0x1f16  
  TRN TBL::
 
  index  state cflags  wrap#    uel         scn            dba            parent-xid    nub     stmt_num
  ------------------------------------------------------------------------------------------------
   0x00    9    0x00  0x0046  0x0002  0x0020.97e1f305  0x0041939c  0x0000.000.00000000  0x00000001   0x00000000
   0x01    9    0x00  0x0046  0x0011  0x0020.97e1f47d  0x0041939e  0x0000.000.00000000  0x00000001   0x00000000
   0x02    9    0x00  0x0045  0x002d  0x0020.97e1f309  0x0041939c  0x0000.000.00000000  0x00000001   0x00000000
   0x03    9    0x00  0x0046  0x0030  0x0020.97e1f575  0x0041939d  0x0000.000.00000000  0x00000001   0x00000000
   ......
   0x4d    9    0x00  0x0045  0x0009  0x0020.97e1f585  0x0041939d  0x0000.000.00000000  0x00000001   0x00000000
   0x4e    9    0x00  0x0046  0x0060  0x0020.97e1f76c  0x0041939e  0x0000.000.00000000  0x00000001   0x00000000
   0x4f    9    0x00  0x0045  0x0010  0x0020.97e1f356  0x0041939c  0x0000.000.00000000  0x00000001   0x00000000
   0x50   10    0x00  0x0046  0x0003  0x0020.97ea7865  0x004193a0  0x0000.000.00000000  0x00000001   0x00000000
   0x51    9    0x00  0x0045  0x0048  0x0020.97e1ed08  0x0041939c  0x0000.000.00000000  0x00000001   0x00000000
   0x52    9    0x00  0x0046  0x0056  0x0020.97e1f9a2  0x004193a1  0x0000.000.00000000  0x00000001   0x00000000
   0x53    9    0x00  0x0045  0x005c  0x0020.97e1f478  0x0041939d  0x0000.000.00000000  0x00000001   0x00000000
   0x54    9    0x00  0x0046  0x0045  0x0020.97e1f70a  0x0041939d  0x0000.000.00000000  0x00000001   0x00000000
   0x55    9    0x00  0x0045  0x0035  0x0020.97e1ed5f  0x0041939b  0x0000.000.00000000  0x00000001   0x00000000
   0x56    9    0x00  0x0046  0x002f  0x0020.97e1f9a4  0x004193a0  0x0000.000.00000000  0x00000001   0x00000000
   0x57    9    0x00  0x0045  0x0005  0x0020.97e1f351  0x0041939c  0x0000.000.00000000  0x00000001   0x00000000
   0x58    9    0x00  0x0046  0x001b  0x0020.97e837c9  0x004193a0  0x0000.000.00000000  0x00000001   0x00000000
   0x59    9    0x00  0x0045  0x0049  0x0020.97e1f765  0x0041939e  0x0000.000.00000000  0x00000001   0x00000000
   0x5a    9    0x00  0x0045  0x005f  0x0020.97e1f5cd  0x0041939e  0x0000.000.00000000  0x00000001   0x00000000
   0x5b    9    0x00  0x0045  0x0036  0x0020.97e1edaf  0x0041939b  0x0000.000.00000000  0x00000001   0x00000000
   0x5c    9    0x00  0x0045  0x0001  0x0020.97e1f47a  0x0041939e  0x0000.000.00000000  0x00000001   0x00000000
   0x5d    9    0x00  0x0045  0x0054  0x0020.97e1f707  0x0041939e  0x0000.000.00000000  0x00000001   0x00000000
   0x5e    9    0x00  0x0045  0x0023  0x0020.97e1f57e  0x0041939d  0x0000.000.00000000  0x00000001   0x00000000
   0x5f    9    0x00  0x0045  0x0061  0x0020.97e1f5d0  0x0041939e  0x0000.000.00000000  0x00000001   0x00000000
   0x60    9    0x00  0x0045  0x0020  0x0020.97e1f76f  0x0041939e  0x0000.000.00000000  0x00000001   0x00000000
   0x61    9    0x00  0x0045  0x0004  0x0020.97e1f5d5  0x0041939e  0x0000.000.00000000  0x00000001   0x00000000

 

从上面的dump 可以看出,上述回滚段为system回滚段,而且存在一个活动事务,即第0x56号事务槽。同时我们从10046 trace 也可以看到,该操作是在对file 1 block 128进行recover操作:

Doing block recovery for file 1 block 128
WAIT #46912533790200: nam='db file sequential read' ela= 303 file#=1 block#=128 blocks=1 obj#=0 tim=1460688221882291
Block header before block recovery:
buffer tsn: 0 rdba: 0x00400080 (1/128)
scn: 0x0020.97e837d6 seq: 0x01 flg: 0x04 tail: 0x37d60e01
frmt: 0x02 chkval: 0x74b9 type: 0x0e=KTU UNDO HEADER W/UNLIMITED EXTENTS

 

既然如此,那么我们就可以通过bbed来修改file 1 block 128。那么到底怎么修改呢?

第一种方式是:我们修改将第0x56号事务槽的状态从10改成9;因为10是active,9表示inactive;同时修改ctl中的nbf 信息,该信息表示free block 个数(undo block);目前是1。

第二种方式是:我们还需要修改system 回滚段头的ctl 指针信息,将ctl 中的uba: 0x004193a0.006e.1b 改成uba: 0x004193a0.006e.0e;同时修改free block pool中的相关信息即可。为什么这里要修改指针呢,因为我分析该前面的undo block dump发现,其中包含了14个undo record记录,而且前面的12个record都是bootstrap 核心数据字典表的操作,因此如果屏蔽整个事务,那么可以会导致数据字典出现异常,可能产生更麻烦的事情。

发表评论

电子邮件地址不会被公开。 必填项已用*标注