Oracle技術嘉年華的一個案例，redo的那些事，連載二

電梯
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。

[@more@]