本帖最后由 sundog315 于 2011-10-31 16:11 编辑
电梯
Oracle技术嘉年华的一个案例，redo的那些事，连载一
Oracle技术嘉年华的一个案例，redo的那些事，连载三
前篇的结论是，由于没有开启附加日志，导致这条记录无法正确的解析。那么进一步，到底是什么原因导致这条记录不能得到正确的解析呢？决定进一步探究一下
我们再来看一下logfile dump的结果，在eygle大师的PPT里，信息并不完整，下面是完整的信息：
REDO RECORD - Thread:1 RBA: 0x00309e.00028b4d.0010 LEN: 0x0114 VLD: 0x01
SCN: 0x0001.4be86fb9 SUBSCN: 1 07/05/2011 16:41:54
CHANGE #1 TYP:0 CLS:22 AFN:2 DBA:0x00801542 OBJ:0 SCN:0x0001.4be86efe SEQ: 1 OP:5.1
ktudb redo: siz: 116 spc: 7530 flg: 0x0022 seq: 0xaf17 rec: 0x05
xid: 0x0003.022.0019482c
ktubu redo: slt: 34 rci: 4 opc: 11.1 objn: 66237 objd: 67018 tsn: 8
Undo type: Regular undo Undo type: Last buffer split: No
Tablespace Undo: No
0x00000000
KDO undo record:
KTB Redo
op: 0x04 ver: 0x01
op: L itl: xid: 0x000a.01e.001a0c96 uba: 0x00800c0a.b193.29
flg: C--- lkc: 0 scn: 0x0001.4bb7744a
KDO Op code: URP row dependencies Disabled
xtype: XA flags: 0x00000000 bdba: 0x0bc01db2 hdba: 0x0900e509
itli: 3 ispac: 0 maxfr: 4863
tabn: 0 slot: 47(0x2f) flag: 0x0c lock: 0 ckix: 0
ncol: 33 nnew: 2 size: -1
col 7: [ 1] 35
col 15: [ 1] 80
CHANGE #2 TYP:2 CLS: 1 AFN:47 DBA:0x0bc01db2 OBJ:0 SCN:0x0001.4be1efdb SEQ: 1 OP:11.5
KTB Redo
op: 0x01 ver: 0x01
op: F xid: 0x0003.022.0019482c uba: 0x00801542.af17.05
KDO Op code: URP row dependencies Disabled
xtype: XA flags: 0x00000000 bdba: 0x0bc01db2 hdba: 0x0900e509
itli: 3 ispac: 0 maxfr: 4863
tabn: 0 slot: 47(0x2f) flag: 0x0c lock: 3 ckix: 0
ncol: 33 nnew: 2 size: 1
col 7: [ 1] 31
col 15: [ 2] c3 05
是不是觉得很奇怪？这里的object id居然是0？那么到底是不是这个原因导致logminer无法解析呢？我们来做个实现。我们直接对归档日志进行修改，看看是否能够让logminer正确解析。
这里需要使用BBED工具
BBED: Release 2.0.0.0.0 - Limited Production on Thu Oct 27 16:22:22 2011
Copyright (c) 1982, 2005, Oracle. All rights reserved.
************* !!! For Oracle Internal Use only !!! ***************
BBED> SET FILENAME '/1_12446.dbf'
FILENAME /1_12446.dbf
BBED> set blocksize 512
BLOCKSIZE 512
BBED> set block 166733
BLOCK# 166733
BBED> d
File: /1_12446.dbf (0)
Block: 166733 Offsets: 0 to 511 Dba:0x00000000
------------------------------------------------------------------------
0000309e 00028b4d 2d0b49d2 0010fb83 00000114 01010001 4be86fb9 05010016
#####这里是OP:5.1
00000002 00801542 4be86efe 00010000 01000000 00100014 00180020 001d0004
#####红色部分是5.1的OBJ部分，等下我们要修改
00010001 00741d6a 00220000 00030022 0019482c af170500 000102bd 000105ca
00000008 00000000 0b012204 00000000 04010000 00000000 000a001e 001a0c96
00800c0a b1932900 80000001 4bb7744a 0bc01db2 0900e509 12ff0501 03000000
0c000000 002f2102 ffff0000 00010000 0007000f 35040014 80010100 0b050001
#####这里是OP:11.5
0000002f 0bc01db2 4be1efdb 00010000 01020000 000c0018 001d0004 00010002
#####红色部分是11.5的OBJ部分，等下我们要修改
01010000 00000000 00030022 0019482c 00801542 af170500 0bc01db2 0900e509
…
<32 bytes per line>
找到了位置，我们做一下修改
BBED> set offset 50
OFFSET 50
BBED> m /x deb8
File: /1_12446.dbf (0)
Block: 166733 Offsets: 50 to 511 Dba:0x00000000
------------------------------------------------------------------------
deb80010 00140018 0020001d 00040001 00010074 1d6a0022 00000003 00220019
…
BBED> set offset 210
OFFSET 210
BBED> m /x f050
Warning: contents of previous BIFILE will be lost. Proceed? (Y/N) y
File: /1_12446.dbf (0)
Block: 166733 Offsets: 210 to 511 Dba:0x00000000
------------------------------------------------------------------------
f050000c 0018001d 00040001 00020101 00000000 00000003 00220019 482c0080
…
OK，修改完毕，我们来重新logminer挖掘一下：
SQL> select t.RBABLK,t.RBABYTE,t.DATA_OBJ#,t.ROW_ID,t.OPERATION,t.SQL_REDO,t.INFO from v$logmnr_contents t where t.RBABLK=166733;
select t.RBABLK,t.RBABYTE,t.DATA_OBJ#,t.ROW_ID,t.OPERATION,t.SQL_REDO,t.INFO from v$logmnr_contents t where t.RBABLK=166733
*
ERROR at line 1:
ORA-00368: checksum error in redo log block
ORA-00353: log corruption near block 166733 change 5568491448 time 07/05/2011 16:41:54
ORA-00334: archived log: '/1_12446.dbf'
额，报错了，checksum有问题，导致Oracle根本就不去读这个redo。我们试着清除一下checksum
继续使用BBED，修改checksum
BBED> SET FILENAME '/1_12446.dbf'
FILENAME /1_12446.dbf
BBED> set blocksize 512
BLOCKSIZE 512
BBED> set block 166733
BLOCK# 166733
BBED> set offset 14
OFFSET 14
这里需要注意的是，REDO BLOCK的checksum在第14至16字节处
BBED> m /x 0000 --将checksum清空为0
Warning: contents of previous BIFILE will be lost. Proceed? (Y/N) y
File: /1_12446.dbf (0)
Block: 166733 Offsets: 14 to 511 Dba:0x00000000
------------------------------------------------------------------------
00000000 01140101 00014be8 6fb90501 00160000 00020080 15424be8 6efe0001
我们再来用logminer读取一下
SQL> select t.RBABLK,t.RBABYTE,t.DATA_OBJ#,t.ROW_ID,t.OPERATION,t.SQL_REDO,t.INFO from v$logmnr_contents t where t.RBABLK=166733;
166733 16 66237 AAAQXKAAAAAAAAAAAA UNSUPPORTED Unsupported Object or Data type Unsupported
居然没有报错，checksum清除以后，即使内容发生了变化，也可以顺利的读取。
一个引申的问题，一般当我们的数据库出现ORA-00368错误时，基本都是采用清空logfile的方式（非当前在线日志），或resetlogs，那么我们是否也可以通过修改checksum来使Oracle跳过checksum错误呢？这值得有时间时试验一下。
但是，我们的问题依然没有解决，到底我们的修改有没有生效？logfile dump看一下：
CHANGE #1 TYP:0 CLS:22 AFN:2 DBA:0x00801542 OBJ:57016 SCN:0x0001.4be86efe SEQ: 1 OP:5.1
CHANGE #2 TYP:2 CLS: 1 AFN:47 DBA:0x0bc01db2 OBJ:61520 SCN:0x0001.4be1efdb SEQ: 1 OP:11.5
已经更新了，看来不是这个问题。
再仔细看一下logfile dump文件，找找看还有什么可疑的地方
itli: 3 ispac: 0 maxfr: 4863
tabn: 0 slot: 47(0x2f) flag: 0x0c lock: 3 ckix: 0
ncol: 33 nnew: 2 size: 1
col 7: [ 1] 31
col 15: [ 2] c3 05
flag，大家想到了什么？这里怎么好像是data block里的row flag？在DSI里，有这部分的详细描述
flag: 0x0c=First data piece and Last data piece
正常的记录，row flag应该是0x2c，对应—H-FL--，而现在是0x0c，对应----FL--，这个不就是行迁移以后的数据段么？难道是因为这个原因？最简单的验证方法，即将0x0c强制修改为0x2c，虽然这样修改后，ROWID应该是错误的，但至少应该可以正确解析
BBED> f /x 0c000000
File: /1_12446.dbf (0)
Block: 166733 Offsets: 160 to 511 Dba:0x00000000
------------------------------------------------------------------------
0c000000 002f2102 ffff0000 00010000 0007000f 35040014 80010100 0b050001
<32 bytes per line>
BBED> m /x 2c000000
Warning: contents of previous BIFILE will be lost. Proceed? (Y/N) y
File: /1_12446.dbf (0)
Block: 166733 Offsets: 160 to 511 Dba:0x00000000
------------------------------------------------------------------------
2c000000 002f2102 ffff0000 00010000 0007000f 35040014 80010100 0b050001
这回再logminer看看
166733 16 66237 AAAQXKAAvAAAB2yAAv UPDATE update "UNKNOWN"."OBJ# 66237" set "COL 8" = HEXTORAW('31'), "COL 16" = HEXTORAW('c305') where "COL 8" = HEXTORAW('35') and "COL 16" = HEXTORAW('80') and ROWID = 'AAAQXKAAvAAAB2yAAv';
Dictionary Mismatch
可以正确解析了。
大致猜测一下logminer的原理吧，logminer在解析标准SQL时，where中会带着这条记录的ROWID，但是，请大家注意，如果这条记录不是行头，那么，根据这个redo 向量中记录的object id，file#，block#，slot#算出的ROWID其实不是这条记录真正的ROWID，而当没有开启附加日志时，Header piece是不会进行记录的，所以，logminer根本就没有办法得到准确的ROWID。 | 
IP卡
狗仔卡
发表于 2011-10-31 09:49
收藏
提升卡
置顶卡
变色卡
显身卡
发表于 2011-10-31 09:53
楼主
