前天某客户的11203 rac(asm)出现掉电，导致数据库无法启动，注意数据库是归档模式。可见是多么倒霉。据同事说开始是由于发redo和undo损坏导致无法启动，部分信息如下：? 1 2 3 4 5 6 7 8 9 thu may 08 20:51:07 2014 dumping diagnostic data in directory=[c
前天某客户的11203 rac(asm)出现掉电，导致数据库无法启动，注意数据库是归档模式。可见是多么倒霉。据同事说开始是由于发redo和undo损坏导致无法启动，部分信息如下： ?1 2 3 4 5 6 7 8 9 thu may 08 20:51:07 2014 dumping diagnostic data in directory=[cdmp_20140508205107], requested by (instance=1, osid=13828272), summary=[incident=77085]. abort recovery for domain 0 aborting crash recovery due to error 354 errors in file /oracle/db/diag/rdbms/hiatmpdb/hiatmpdb1/trace/hiatmpdb1_ora_13828272.trc: ora-00354: corrupt redo log block header ora-00353: log corruption near block 67856 change 13820540000932 time 05/08/2014 13:12:44 ora-00312: online log 3 thread 2: '+data/hiatmpdb/onlinelog/group_3.269.830653613' ora-00312: online log 3 thread 2: '+data/hiatmpdb/onlinelog/group_3.268.830653613'
他做了一些recover database until cancel操作。甚至还使用了隐含参数，但是仍然无法open数据库，如下： sql> alter system set “_allow_resetlogs_corruption”=true scope=spfile ; sql> alter system set “_allow_error_simulation”=true scope=spfile ; open数据库时报undo存坏块，如下： 可以看到，在使用隐含参数进行open都仍然报undo存在坏块。本来我想进行不完全恢复，发现后面执行recover database using backup controlfile until cancel 居然报ora-16433错误，很明显，同事之前做过resetlogs了，解决这个错误只能重建undo，本想通过如下方式来重建controlfile的，发现居然不行： oradebug setmypid alter database backup controlfile to trace; 居然错误我记不住了。既然是报undo错误，那么首先的想法就是吧该undo坏块涉及的回滚段进行屏蔽。通过10046 event可以定位到问题回滚段，但是，11g的回滚段格式发生了变化，仅仅是这样还不够的，如下是 10046 event的跟踪信息： ?
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 ===================== parsing in cursor #4574130432 len=142 dep=1 uid=0 oct=3 lid=0 tim=237352129855 hv=361892850 ad='700000160cd5178' sqlid='7bd391hat42zk' select /*+ rule */ name,file#,block#,status$,user#,undosqn,xactsqn,scnbas,scnwrp,decode(inst#,0,null,inst#),ts#,spare1 from undo$ where us#=:1 end of stmt parse #4574130432:c=9,e=14,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=4258302260,tim=237352129854 binds #4574130432: 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=110a3acb8 bln=22 avl=02 flg=05 value=3 exec #4574130432:c=47,e=88,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=4258302260,tim=237352130029 fetch #4574130432:c=8,e=13,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=3,plh=4258302260,tim=237352130065 stat #4574130432 id=1 cnt=1 pid=0 pos=1 obj=15 op='table access by index rowid undo$ (cr=2 pr=0 pw=0 time=10 us)' stat #4574130432 id=2 cnt=1 pid=1 pos=1 obj=34 op='index unique scan i_undo1 (cr=1 pr=0 pw=0 time=5 us)' close #4574130432:c=3,e=5,dep=1,type=1,tim=237352130125 parse #4574130432:c=5,e=9,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=4258302260,tim=237352130158 binds #4574130432: 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=110a3ab88 bln=22 avl=02 flg=05 value=4 exec #4574130432:c=44,e=71,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=3,plh=4258302260,tim=237352130278 fetch #4574130432:c=7,e=12,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=3,plh=4258302260,tim=237352130308 close #4574130432:c=2,e=3,dep=1,type=3,tim=237352130335 wait #4573319128: nam='db file sequential read' ela= 6947 file#=3 block#=176 blocks=1 obj#=0 tim=237352137334 dde rules only execution for: ora 1110 ----- start event driven actions dump ---- ---- end event driven actions dump ---- ----- start dde actions dump ----- executing sync actions ----- start dde action: 'db_structure_integrity_check' (async) ----- successfully dispatched ----- end dde action: 'db_structure_integrity_check' (success, 0 csec) ----- executing async actions ----- end dde actions dump (total 0 csec) ----- wait #4573319128: nam='control file sequential read' ela= 258 file#=0 block#=1 blocks=1 obj#=0 tim=237352138057 wait #4573319128: nam='control file sequential read' ela= 205 file#=1 block#=1 blocks=1 obj#=0 tim=237352138319 wait #4573319128: nam='control file sequential read' ela= 190 file#=0 block#=40 blocks=1 obj#=0 tim=237352138539 wait #4573319128: nam='control file sequential read' ela= 251 file#=0 block#=42 blocks=1 obj#=0 tim=237352138818 wait #4573319128: nam='control file sequential read' ela= 192 file#=0 block#=48 blocks=1 obj#=0 tim=237352139044 wait #4573319128: nam='control file sequential read' ela= 255 file#=0 block#=113 blocks=1 obj#=0 tim=237352139328 wait #4573319128: nam='ksv master wait' ela= 1 p1=0 p2=0 p3=0 obj#=0 tim=237352139400 byte offset to file# 3 block# 176 is unknown incident 115456 created, dump file: /oracle/db/diag/rdbms/hiatmpdb/hiatmpdb1/incident/incdir_115456/hiatmpdb1_ora_12583082_i115456.trc ora-01578: oracle data block corrupted (file # 3, block # 176) ora-01110: data file 3: '+data/hiatmpdb/datafile/undotbs1.264.830644315' ora-01578: oracle data block corrupted (file # 3, block # 176) ora-01110: data file 3: '+data/hiatmpdb/datafile/undotbs1.264.830644315' ora-01578: oracle data block corrupted (file # 3, block # 176) ora-01110: data file 3: '+data/hiatmpdb/datafile/undotbs1.264.830644315'
我们可以看到，在访问回滚段4的时候报错了，但是无法获得回滚段的时间戳。oracle 11g中的回滚段名称的格式如下： _syssmux_时间戳. 实际上，回滚段的信息都存在undo$基表中，我们只需要获得该基表的数据即可。11g中该基表的数据在file 1 block 225block中。因此只需要dd该block，然后strings+grep就行了。最后利用隐含参数_offline_rollback_segments=(_syssmux$) 和_corrupted_rollback_segments=(_syssmux$) 来屏蔽，讲数据库open。 open之后发现想drop问题回滚段居然报错，既然能open也就能够查询dba_rollback_segs试图了，最后发现还有部分回滚段状态也是异常的，因此通过类似这一点 方法来drop 回滚段： ?1 2 3 4 5 alter session set _smu_debug_mode = 4; alter rollback segment _syssmu3_83481414$ offline; drop rollback segment _syssmu3_83481414$ ; alter rollback segment _syssmu4_2115859630$ offline; drop rollback segment _syssmu4_2115859630$ ;
注意，这里如果不这样做的话，无法清理回滚段，你想切换undo 表空间也会报错的。这个问题搞完后，最后发现一个数据文件的坏块，这个坏块折腾了我很长时间，非常奇怪： ?1 2 3 4 5 6 7 8 9 10 11 continued from file: /oracle/db/diag/rdbms/hiatmpdb/hiatmpdb2/trace/hiatmpdb2_ora_13959382.trc ora-01578: oracle 数据块损坏 (文件号 97, 块号 373505) ora-01110: 数据文件 97: '+data/hiatmpdb/datafile/hiatmpts_in06.dbf' ========= dump for incident 197185 (ora 1578) ======== *** 2014-05-11 16:38:55.665 dbkeddefdump(): starting incident default dumps (flags=0x2, level=3, mask=0x0) ----- current sql statement for this session (sql_id=47bt6vfv19g6z) ----- select t.nid ,t.cpic1path,t.cpic2path from hiatmp.detect_speed_data_ehl_extend t where t.cdevicecode like '%44900100000001%' and row num
可以看到，97号文件存在一个坏块，我dump了一下该block，发现比较怪： ?1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 ** 2014-05-11 18:51:21.074 start dump data blocks tsn: 6 file#:97 minblk 373505 maxblk 373505 block dump from cache: dump of buffer cache at level 4 for tsn=6 rdba=407220993 bh (0x70000012ef08528) file#: 97 rdba: 0x1845b301 (97/373505) class: 8 ba: 0x70000012e5fe000 set: 33 pool: 3 bsz: 8192 bsi: 0 sflg: 2 pwc: 1575,18 dbwrid: 0 obj: 90762 objn: 90762 tsn: 6 afn: 97 hint: f hash: [0x700000157972b00,0x700000157972b00] lru: [0x70000012ef09348,0x70000012ef091d0] ckptq: [null] fileq: [null] objq: [0x70000012ef087b0,0x70000014153f8a0] objaq: [0x70000012ef087c0,0x70000014153f890] st: scurrent md: null fpin: 'ktspfwh13: ktspgetnextl1forscan' tch: 4 le: 0x700000043fd8780 flags: auto_bmr_tried lrba: [0x0.0.0] lscn: [0x0.0] hscn: [0xffff.ffffffff] hsub: [65535] block dump from disk: buffer tsn: 6 rdba: 0x1845b301 (97/373505) scn: 0x0c91.d8604ed8 seq: 0xff flg: 0x04 tail: 0x4ed845ff frmt: 0x02 chkval: 0xcafb type: 0x45=nglob: lob extent header hex dump of block: st=0, typ_found=1 dump of memory from 0x0000000110aea800 to 0x0000000110aec800 110aea800 45a20000 1845b301 d8604ed8 0c91ff04 [e....e...`n.....] 110aea810 cafb0000 b9138f29 9dc40000 05b6ccda [.......)........]
大家可以看下这个坏块的type，居然是0×45，说这是一个lob extent header block。开始我还以为这个表存在lob字段，最后desc看了下表结构，根本没有lob字段。可见这个block是写乱了。大家知道处理坏块的方法无法就是10231 event，dbms_repair，以及dbms_rowid来处理。当时试了几种方法均不行。其中10231 event和dbms_repair本质上差不多，都是标记坏块，跳过多块读。而dbms_rowid则是根据坏块获取rowid，然后根据rowid来抢救数据。居然也不行，比较怪。最后我干脆创建一个空间，分配到该文件，然后delete掉数据，然后dd一个空块，修改掉rdba和obj id，然后直接dd替换。后记：后面让同事全库检查，还发现了20来个数据坏块，不过大多是index，处理相对简单，我就不参与了。