oracle数据库重启之后无法open的恢复案例

作者:袖梨 2022-06-29

这是某网友的维护的一套数据库,据说是正常重启之后就无法启动数据库了。那么我们先来看看日志是什么样的:

Errors in file /u01/app/oracle/admin/orcl/bdump/orcl1_p012_18165.trc:
ORA-27090: Message 27090 not found;  product=RDBMS; facility=ORA
Linux-x86_64 Error: 4: Interrupted system call
Additional information: 3
Additional information: 128
Additional information: 65536
.....
Errors in file /u01/app/oracle/admin/orcl/bdump/orcl1_p007_18153.trc:
ORA-27090: Message 27090 not found;  product=RDBMS; facility=ORA
Linux-x86_64 Error: 4: Interrupted system call
Additional information: 3
Additional information: 128
Additional information: 65536
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
.....
SMON: enabling cache recovery
Errors in file /u01/app/oracle/admin/orcl/udump/orcl1_ora_8858.trc:
ORA-00600: internal error code, arguments: [16703], [1403], [20], [], [], [], [], []
.....
Errors in file /u01/app/oracle/admin/orcl/udump/orcl1_ora_8858.trc:
ORA-00704: bootstrap process failure
ORA-00704: bootstrap process failure
ORA-00600: internal error code, arguments: [16703], [1403], [20], [], [], [], [], []
.....
Error 704 happened during db open, shutting down database
USER: terminating instance due to error 704

我们可以看到,节点1在9:48:52秒被强行终止重启了实例。而且我们还可以看出该节点从9:42开始就出现ORA-27090 错误。而该错误通常跟操作系统有关系,通过后面的Linux-x86_64 Error: 4: Interrupted system call 错误也验证了这一点。

Thread 2 advanced to log sequence 334685 (LGWR switch)
  Current log# 4 seq# 334685 mem# 0: +DATA/orcl/onlinelog/group_4.log
.....
Starting ORACLE instance (normal)
LICENSE_MAX_SESSION = 0
.....
Errors in file /u01/app/oracle/admin/orcl/bdump/orcl2_mmon_9401.trc:
ORA-07445: Message 7445 not found; No message file for product=RDBMS, facility=ORA; arguments: [kgghteFindCB()+188] [SIGSEGV] [Address not mapped to object] [0x00000010B]
.....
Errors in file /u01/app/oracle/admin/orcl/udump/orcl2_ora_9475.trc:
ORA-07445: exception encountered: core dump [kglsget()+490] [SIGSEGV] [Address not mapped to object] [0x000000008] [] []
.....
Error 0 in kwqmnpartition(), aborting txn
.....
Errors in file /u01/app/oracle/admin/orcl/udump/orcl2_ora_9943.trc:
ORA-00600: internal error code, arguments: [kggfaAllocFunc1], [], [], [], [], [], [], []
.....
ORA-00600: internal error code, arguments: [kggfaAllocFunc1], [], [], [], [], [], [], []
.....
ORA-65535 encountered when generating server alert SMG-4131
.....
Errors in file /u01/app/oracle/admin/orcl/udump/orcl2_ora_9943.trc:
ORA-00600: internal error code, arguments: [kggfaAllocFunc1], [], [], [], [], [], [], []
.....
Reconfiguration started (old inc 2, new inc 4)
List of nodes:
 0 1
 Global Resource Directory frozen
 Communication channels reestablished
 * domain 0 valid = 1 according to instance 0
......
Completed redo application
.....
Errors in file /u01/app/oracle/admin/orcl/udump/orcl2_ora_10551.trc:
ORA-00600: internal error code, arguments: [kggfaAllocFunc1], [], [], [], [], [], [], []
.....
Errors in file /u01/app/oracle/admin/orcl/bdump/orcl2_smon_9395.trc:
ORA-00600: Message 600 not found; No message file for product=RDBMS, facility=ORA; arguments: [16659] [kqldtu] [D] [0] [65]
.....
Redo Shipping Client Connected as PUBLIC
-- Connected User is Valid
......
Non-fatal internal error happenned while SMON was doing cursor transient type cleanup.
SMON encountered 1 out of maximum 100 non-fatal internal errors.
.....
Trace dumping is performing id=[cdmp_20160802094934]
.....
Errors in file /u01/app/oracle/admin/orcl/bdump/orcl2_smon_9395.trc:
ORA-00600: Message 600 not found; No message file for product=RDBMS, facility=ORA; arguments: [16659] [kqldtu] [D] [0] [195]
.....
Non-fatal internal error happenned while SMON was doing cursor transient type cleanup.
SMON encountered 2 out of maximum 100 non-fatal internal errors.
......
Errors in file /u01/app/oracle/admin/orcl/bdump/orcl2_pmon_9349.trc:
ORA-00474: Message 474 not found; No message file for product=RDBMS, facility=ORA
......
PMON: terminating instance due to error 474
......
Errors in file /u01/app/oracle/admin/orcl/bdump/orcl2_lmon_9355.trc:
ORA-00474: Message 474 not found; No message file for product=RDBMS, facility=ORA
.....
System state dump is made for local instance
System State dumped to trace file /u01/app/oracle/admin/orcl/bdump/orcl2_diag_9351.trc
......
Shutting down instance (abort)
License high water mark = 72
......
Trace dumping is performing id=[cdmp_20160802095002]
.....
Instance terminated by PMON, pid = 9349
.....
Instance terminated by USER, pid = 11027
.....
Starting ORACLE instance (normal)

这里我们无论是看节点1还是节点2的alert log日志都会发现,由于smon进程在进程事务恢复时失败之后,导致数据库实例最终宕掉。宕掉之后就再也无法正常启动了。很明显这是强行关库之后带来的蝴蝶效应。
这里我们来看看其中节点2的这个ORA-00600 [16559]是什么含义?

ERROR: ORA-600 [16659] [a] [b] [c] [d] [e]
VERSIONS: versions 8.0 to 8.1
DESCRIPTION: We are attempting to update a tab$ row and fail to update the dictionary information correctly.
FUNCTIONALITY: DATA DICTIONARY IMPACT: PROCESS FAILURE POSSIBLE DATA DICTIONARY INCONSISTENCY

从解释来看,这是Oracle 数据字典表tab$出现了不一致的情况。比较郁闷的是,客户的dataguard也坏掉了,也是一样的错误。
那么看来只能进行恢复了。这里首先要明白,节点1的ora-00600 [16703]本质上来讲跟ora-00600 [16559]是一回事。
从具体的错误来看,Oracle在open时,进行bootstrap初始化的过程就失败了,因此报错ORA-00704: bootstrap process failure.

处理思路也很简单,我们首先通过10046 trace跟踪open的过程,来看看Oracle 在bootstrap初始化的时候在进行什么操作时报错的?

PARSING IN CURSOR #2 len=106 dep=1 uid=0 oct=3 lid=0 tim=1435661277781458 hv=3628073639 ad='cfd74588'
select rowcnt,blkcnt,empcnt,avgspc,chncnt,avgrln,nvl(degree,1), nvl(instances,1) from tab$ where obj# = :1
END OF STMT
PARSE #2:c=999,e=676,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,tim=1435661277781453
=====================
.....
BINDS #2:
kkscoacd
 Bind#0
  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=2b5f7bae1b00  bln=22  avl=02  flg=05
  value=20
EXEC #2:c=999,e=1015,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,tim=1435661277798049
WAIT #2: nam='db file sequential read' ela= 1086 file#=1 block#=50 blocks=1 obj#=-1 tim=1435661277799253
WAIT #2: nam='db file sequential read' ela= 568 file#=1 block#=51 blocks=1 obj#=-1 tim=1435661277799931
WAIT #2: nam='db file sequential read' ela= 1804 file#=1 block#=26 blocks=1 obj#=-1 tim=1435661277801863
FETCH #2:c=0,e=3833,p=3,cr=3,cu=0,mis=0,r=0,dep=1,og=4,tim=1435661277801922
*** 2016-08-02 13:52:28.469
ksedmp: internal or fatal error
ORA-00600: internal error code, arguments: [16703], [1403], [20], [], [], [], [], []
Current SQL statement for this session:
alter database open

从上面的错误不难看出就是在访问tab$ 的时候报错的,而且是访问的obj#=20的这个对象。那么这个对象是什么呢?

SQL> select owner,object_name,object_type from dba_objects where object_id=20;
 
OWNER                          OBJECT_NAME                    OBJECT_TYPE
------------------------------ ------------------------------ -------------------
SYS                            ICOL$                          TABLE
 
SQL> !oerr ora 1403
01403, 00000, "no data found"
// *Cause:
// *Action:

根据我们的查询以及对ORA-00600 [16703],[1403],[20] 这个错误的理解,那么我这里可以大致判断这个错误后的几个数字的含义:
16703: 错误代码,表示数据字典基表存在不一致1403: 表示数据没找到或者不匹配,即not data found.20: 表示访问的对象号,即object_id.
同时我们从前面的10046 trace跟踪来看,报错的SQL语句访问了3个block,然后报错,分别是file 1 block 50,51,26。
这我们分别dump 上面的3个block发现其中block 51,26 的dump 内容如下:

---block 51
Object id on Block? Y
 seg/obj: 0x3  csc: 0x00.64205  itc: 2  flg: -  typ: 2 - INDEX
     fsl: 0  fnx: 0x0 ver: 0x01
 
 Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x0001.008.0000000d  0x0080118a.0010.01  CB--    0  scn 0x0000.000105c7
0x02   0x000a.01e.000005e0  0x008074fc.007a.36  --U-    1  fsc 0x0000.00064208
 
Leaf block dump
===============
header address 185777756=0xb12be5c
kdxcolev 0
KDXCOLEV Flags = - - -
kdxcolok 0
kdxcoopc 0x80: opcode=0: iot flags=--- is converted=Y
kdxconco 1
kdxcosdc 2
kdxconro 258
kdxcofbo 552=0x228
kdxcofeo 4484=0x1184
kdxcoavs 3932
kdxlespl 0
kdxlende 0
kdxlenxt 4194360=0x400038
kdxleprv 0=0x0
kdxledsz 8
kdxlebksz 8032
...
row#93[5724] flag: ------, lock: 2, len=14, data:(8):  00 40 38 8e 00 06 02 00
col 0; len 3; (3):  c2 03 03
......
 
---block 26
Block header dump:  0x0040001a
 Object id on Block? Y
 seg/obj: 0x2  csc: 0x05.e0568950  itc: 2  flg: -  typ: 1 - DATA
     fsl: 0  fnx: 0x0 ver: 0x01
 
 Itl           Xid                  Uba         Flag  Lck        Scn/Fsc
0x01   0x0000.05f.00000002  0x00400012.0001.16  C---    0  scn 0x0000.000000fd
0x02   0x000b.00d.00048164  0x0100982b.b8bd.4d  --U-    7  fsc 0x039f.e0568c3e
 
data_block_dump,data header at 0xb12be5c
===============
tsiz: 0x1fa0
hsiz: 0x140
pbl: 0x0b12be5c
bdba: 0x0040001a
     76543210
flag=--------
ntab=6
nrow=141
frre=-1
fsbo=0x140
fseo=0x160
avsp=0x20
tosp=0x3db
0xe:pti[0]      nrow=8  offs=0
0x12:pti[1]     nrow=7  offs=8
0x16:pti[2]     nrow=1  offs=15
0x1a:pti[3]     nrow=10 offs=16
0x1e:pti[4]     nrow=15 offs=26
0x22:pti[5]     nrow=100        offs=41
.....
col  0: [ 2]  c1 14
tab 1, row 0, @0x1e65
tl: 4 fb: -CHDFL-- lb: 0x2  cc: 0 cki: 0
tab 1, row 1, @0x1ddb
tl: 4 fb: -CHDFL-- lb: 0x2  cc: 0 cki: 1
tab 1, row 2, @0x1d51
tl: 4 fb: -CHDFL-- lb: 0x2  cc: 0 cki: 2
tab 1, row 3, @0x1ccd
tl: 4 fb: -CHDFL-- lb: 0x2  cc: 0 cki: 4
tab 1, row 4, @0x1c45
tl: 4 fb: -CHDFL-- lb: 0x2  cc: 0 cki: 5
tab 1, row 5, @0x1bc0
tl: 4 fb: -CHDFL-- lb: 0x2  cc: 0 cki: 6
tab 1, row 6, @0x1b35
tl: 4 fb: -CHDFL-- lb: 0x2  cc: 0 cki: 7
tab 2, row 0, @0x160
tl: 48 fb: -CH-FL-- lb: 0x0  cc: 19 cki: 3
col  0: [ 2]  c1 1e
col  1: [ 1]  80
.....
col 17: *NULL*
col 18: [ 1]  80
tab 3, row 0, @0x1ad0
.....

看到这里,我就想是否可以通过bbed先把这2个block 给修复了,看看是否能够起来。如下是简单的修复过程:
对于51号block 由于是Index 修改非常简单,这里不多说。26号block 是cluster table,这个相对复杂的多。首先提交事务、修改lock flag之后verify还是报错,如下:


BBED> verify
DBVERIFY - Verification starting
FILE = /u01/fix/SYSTEM_OLD.dbf
BLOCK = 26
 
Block Checking: DBA = 4194330, Block Type = KTB-managed data block
data header at 0x105d485c
kdbchk:  key comref count wrong
         keyslot=7
Block 26 failed with check code 6121
 
DBVERIFY - Verification complete
 
Total Blocks Examined         : 1
Total Blocks Processed (Data) : 1
Total Blocks Failing   (Data) : 1
Total Blocks Processed (Index): 0
Total Blocks Failing   (Index): 0
Total Blocks Empty            : 0
Total Blocks Marked Corrupt   : 0
Total Blocks Influx           : 0

这里继续修改聚簇对应的kdbr信息(这里以其中一个kdbr为例):

BBED> p *kdbr[7]
rowdata[7568]
-------------
ub1 rowdata[7568]                           @8012     0xac
 
BBED> x /rcccccc
rowdata[7568]                               @8012
-------------
flag@8012: 0xac (KDRHFL, KDRHFF, KDRHFH, KDRHFK)
lock@8013: 0x00
cols@8014:    1
kref@8015:   31
mref@8017:   30
hrid@8019:0x0040001b.0
nrid@8025:0x0040001b.0
 
BBED> modify /x 1f offset 8017
 File: /u01/fix/SYSTEM_OLD.dbf (1)
 Block: 26               Offsets: 8017 to 8020           Dba:0x0040001a
------------------------------------------------------------------------
 1f000040
 
 <32 bytes per line
 
BBED> verify
DBVERIFY - Verification starting
FILE = /u01/fix/SYSTEM_OLD.dbf
BLOCK = 26
 
Block Checking: DBA = 4194330, Block Type = KTB-managed data block
data header at 0x105d485c
kdbchk: space available on commit is incorrect
        tosp=987 fsc=0 stb=0 avsp=32
Block 26 failed with check code 6111
 
DBVERIFY - Verification complete
 
Total Blocks Examined         : 1
Total Blocks Processed (Data) : 1
Total Blocks Failing   (Data) : 1
Total Blocks Processed (Index): 0
Total Blocks Failing   (Index): 0
Total Blocks Empty            : 0
Total Blocks Marked Corrupt   : 0
Total Blocks Influx           : 0
 
BBED> p kdbh
struct kdbh, 14 bytes                       @92
   ub1 kdbhflag                             @92       0x00 (NONE)
   b1 kdbhntab                              @93       6
   b2 kdbhnrow                              @94       141
   sb2 kdbhfrre                             @96      -1
   sb2 kdbhfsbo                             @98       320
   sb2 kdbhfseo                             @100      352
   b2 kdbhavsp                              @102      32
   b2 kdbhtosp                              @104      987
 
BBED> d /v offset 104 count 2
 File: /u01/fix/SYSTEM_OLD.dbf (1)
 Block: 26      Offsets:  104 to  105  Dba:0x0040001a
-------------------------------------------------------
 db03                                l ..
 
 <16 bytes per line>
 
BBED> modify /x 2000 offset 104
 File: /u01/fix/SYSTEM_OLD.dbf (1)
 Block: 26               Offsets:  104 to  105           Dba:0x0040001a
------------------------------------------------------------------------
 2000
 
 <32 bytes per line>
 
BBED> sum apply
Check value for File 1, Block 26:
current = 0x87ce, required = 0x87ce
BBED> verify
DBVERIFY - Verification starting
FILE = /u01/fix/SYSTEM_OLD.dbf
BLOCK = 26
 
DBVERIFY - Verification complete
 
Total Blocks Examined         : 1
Total Blocks Processed (Data) : 1
Total Blocks Failing   (Data) : 0
Total Blocks Processed (Index): 0
Total Blocks Failing   (Index): 0
Total Blocks Empty            : 0
Total Blocks Marked Corrupt   : 0
Total Blocks Influx           : 0

我们经过几处简单修改之后,再次verify校验已经不再报错了;不过再次open数据库时,发现报另外一个错误了:

Errors in file /u01/app/oracle/admin/orcl/udump/orcl1_ora_18955.trc:
ORA-00704: bootstrap process failure
ORA-00704: bootstrap process failure
ORA-00600: internal error code, arguments: [kdoirp-3], [139], [0], [], [], [], [], []

从错误来看,bootstrap的初始化过程仍然有问题。通过10046 trace跟踪发现还是那几个block。
回想前面这个block的dump时,看到的几行操作是delete,如下:tl: 4 fb: -CHDFL– lb: 0×2  cc: 0 cki: 0
那么我们这里试做将这几个被删除的操作进行还原是否ok 呢? 也就是用bbed来恢复这7个delete操作。
由于是cluster table 的block,操作相对麻烦一些。不过我尝试修改之后,最后发现错误仍然一样。
其中[kdoirp-3]是什么含义呢? 我们来看下Oracle 文档的描述:


Layer 11:  KCOCODRW -  Row
opcode 1 :  KDOIUR  - interpret undo redo
opcode 2 :  KDOIRP  - insert row  piece
opcode 3 :  KDODRP  - drop row piece
opcode 4 :  KDOLKR  - lock row  piece
opcode 5 :  KDOURP  - update row piece
opcode 6 :  KDOORP  - overwrite row piece
opcode 7 :  KDOMFC  - manipulate first column
opcode 8 :  KDOCFA  - change forwarding address
opcode 9 :  KDOCKI  - change cluster key index
opcode 10 :  KDOSKL  - set key links
opcode 11 :  KDOQMI  - quick multi-insert (ex. insert as select...)
opcode 12 :  KDOQMD  - quick multi-delete
opcode 13 :  KDOTBF  - toggle block header flags
很明显,这表示insert row piece。 看来我们单纯的修改这2个block 并不能绕过这个问题。 实际上后面我dump分析发现又涉及到_next_object,又将问题复杂化了。
虽然我相信多折腾几次可以解决这个问题。但是操作确实麻烦,费劲。不过此时通过之前的备份restore出来的system文件已经ok了。这里我用bbed 将涉及到的几个block 进行替换,最后再修改resetlogs信息,重建控制文件之后,进行recover。
非常顺利的打开了数据库。最后检查alert log 还涉及到smon 回滚某个事务失败。那么如何完美处理呢?
首先dump undo header,然后获取该事务涉及的操作对象,然后使用如下参数屏蔽回滚段后,将undo表空间重建即可。
如下是dump undo header获取的信息:
针对这部分对象,由于破坏了事务的完整性,那么建议对表进行分析,其中Index进行重建。

相关文章

精彩推荐