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

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

在上一篇中，修改row flag後，logminer已經可以正確的解析日誌了，那麼，這個問題是否可以重現呢？我們來做個測試。
由於沒有9i環境，我們使用11g環境進行測試，測試結果稍微有些偏差，但不影響結論

首先，我們建立varchar2(4000)型別的三條資料，然後，對這三條資料進行修改，將4000位元組全部佔滿，那麼，必然有一條記錄將發生遷移。

SQL*Plus: Release 11.2.0.3.0 Production on Fri Oct 28 08:34:33 2011

Copyright (c) 1982, 2011, Oracle. All rights reserved.

SQL> conn / as sysdba
Connected.
SQL> create table t (a varchar2(4000));

Table created.

SQL> insert into t values ('a');

1 row created.

SQL> insert into t values ('b');

1 row created.

SQL> insert into t values ('c');

1 row created.

SQL>
SQL> commit;

Commit complete.

SQL> select t.rowid from t;

ROWID
------------------
AAADZiAABAAAIDBAAA
AAADZiAABAAAIDBAAB
AAADZiAABAAAIDBAAC

SQL> update t set t.a=lpad('a',4000,'a') where t.a='a';

1 row updated.

SQL> update t set t.a=lpad('b',4000,'b') where t.a='b';

1 row updated.

SQL> update t set t.a=lpad('c',4000,'c') where t.a='c';

1 row updated.

SQL> commit;

Commit complete.

SQL> select t.rowid from t;

ROWID
------------------
AAADZiAABAAAIDBAAA
AAADZiAABAAAIDBAAB
AAADZiAABAAAIDBAAC

應該是AAADZiAABAAAIDBAAC這條記錄發生了遷移，我們看一下資料的物理位置，並將這部分記錄dump出來

SQL> select dbms_rowid.rowid_relative_fno('AAADZiAABAAAIDBAAA') || '.' ||
dbms_rowid.rowid_block_number('AAADZiAABAAAIDBAAA')
from dual 2 3 ;

DBMS_ROWID.ROWID_RELATIVE_FNO('AAADZIAABAAAIDBAAA')||'.'||DBMS_ROWID.ROWID_BLOCK
--------------------------------------------------------------------------------
1.32961

SQL> alter system dump datafile 1 block 32961;

System altered.

對於這條記錄，會在兩次dump中出現，首先是行頭，它沒有資料，但記錄了資料的偏移地址nrid

tab 0, row 2, @0x3c
tl: 9 fb: --H----- lb: 0x2 cc: 0
nrid: 0x004080c2.0
SQL> alter system dump datafile 1 block 32962;

System altered.

真正的資料在這裡，同時，也記錄了行頭的偏移地址hrid

tab 0, row 0, @0xfdc
tl: 4012 fb: ----FL-- lb: 0x1 cc: 1 --row flag是----FL--，也就是0x0c
hrid: 0x004080c1.2col 0: [4000]
63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63

我們對這條記錄做一下修改操作，模擬一下案例發生時的情況：
SQL> select dbms_flashback.get_system_change_number from dual;

GET_SYSTEM_CHANGE_NUMBER
------------------------
278206

SQL> update t set t.a='d' where t.rowid='AAADZiAABAAAIDBAAC';

1 row updated.

SQL> commit;

Commit complete.

SQL> select dbms_flashback.get_system_change_number from dual;

GET_SYSTEM_CHANGE_NUMBER
------------------------
278213

SQL> begin
dbms_logmnr.add_logfile('/u01/app/oracle/oradata/ORAVM/redo01.log');
end;
/
PL/SQL procedure successfully completed.

SQL> begin
dbms_logmnr.start_logmnr(startScn => 278206,endScn => 278213);
end;
/
PL/SQL procedure successfully completed.

SQL> select * from v$logmnr_contents t;

no rows selected

與案例不同的是，在11g中，已經不會出現Unsupported記錄了，直接就不顯示這條記錄了。同樣，我們做一下logfile dump，看看redo log裡到底是怎麼記錄的

SQL> alter system dump logfile '/u01/app/oracle/oradata/ORAVM/redo01.log';

System altered.

CHANGE #1 TYP:0 CLS:22 AFN:3 DBA:0x00c0096c OBJ:4294967295 SCN:0x0000.00043ec4 SEQ:1 OP:5.1 ENC:0 RBL:0
ktudb redo: siz: 4080 spc: 7722 flg: 0x0022 seq: 0x0021 rec: 0x05
xid: 0x0003.00d.000000cd
ktubu redo: slt: 13 rci: 4 opc: 11.1 objn: 13922 objd: 13922 tsn: 0
Undo type: Regular undo Undo type: Last buffer split: No
Tablespace Undo: No
0x00000000
KDO undo record:
KTB Redo
op: 0x03 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: Z
KDO Op code: URP row dependencies Disabled
xtype: XA flags: 0x00000000 bdba: 0x004080c2 hdba: 0x004080c0
itli: 2 ispac: 0 maxfr: 4863
tabn: 0 slot: 0(0x0) flag: 0x0c lock: 0 ckix: 0
ncol: 1 nnew: 1 size: 4001
col 0: [4000]
63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63
......

CHANGE #2 TYP:2 CLS:1 AFN:1 DBA:0x004080c2 OBJ:13922 SCN:0x0000.00043def SEQ:5 OP:11.5 ENC:0 RBL:0
KTB Redo
op: 0x11 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: F xid: 0x0003.00d.000000cd uba: 0x00c0096c.0021.05
Block cleanout record, scn: 0x0000.00043ec2 ver: 0x01 opt: 0x02, entries follow...
itli: 1 flg: 2 scn: 0x0000.00043def
KDO Op code: URP row dependencies Disabled
xtype: XA flags: 0x00000000 bdba: 0x004080c2 hdba: 0x004080c0
itli: 2 ispac: 0 maxfr: 4863
tabn: 0 slot: 0(0x0) flag: 0x0c lock: 2 ckix: 0
ncol: 1 nnew: 1 size: -4001
col 0: [ 1] 64

與案例相同，logminer無法正確解析，但透過logfile dump，可以看到redo檔案中是包含這部分更新的內容的。

11g與9i不同的地方，9i不會記錄OBJ，而11g記錄了OBJ，雖然這個OBJ也不對。但這並不影響我們的結論

按照Oracle文件中的指示，我們需要開啟附加日誌，才可以使logmminer正確的解析，我們來測試一下。
SQL> alter database add supplemental log data;

Database altered.

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 ;

13159 16 13922 AAADZiAABAAAIDBAAC UPDATE update "UNKNOWN"."OBJ# 13922" set "COL 1" = HEXTORAW('656565') where "COL 1" = HEXTORAW('64') and ROWID = 'AAADZiAABAAAIDBAAC'; Dictionary Mismatch

Logminer確實可以正確的解析了。

最後，我們來看一下，在開啟附加日誌後，Oracle到底多記錄了什麼東西，使logminer可以正確的解析呢？

下面是開啟附加日誌後，OP:5.1部分的內容，請大家注意看紅色部分，這部分內容在未開啟附加日誌的redo log中是找不到的

05 01 20 00 03 00 ff ff fa 00 c0 00 67 43 04 00
00 00 00 00 01 00 ff ff 10 00 14 00 18 00 20 00
1d 00 02 00 01 00 1c 00 8c 00 a4 1c 22 00 00 00
08 00 01 00 cd 00 00 00 2c 00 06 00 62 36 00 00
62 36 00 00 00 00 00 00 00 00 00 00 0b 01 01 05
00 00 cd 00 04 0d 00 00 01 00 00 00 00 00 00 00
00 00 00 00 00 00 00 00 00 00 00 00 00 80 00 00
00 00 00 00 c2 80 40 00 c0 80 40 00 ff 12 25 01
03 00 00 00 0c 00 00 00 00 00 01 01 fe ff 00 00
00 0c 40 00 00 00 40 00 64 12 02 01 01 04 00 00
01 00 01 00 01 00 00 00 00 10 00 00 00 00 00 00
c1 80 40 00 02 00 00 00
這部分的內容是不是很眼熟？看看下面這段就明白了，紅色這部分內容對應的就是hrid：

tab 0, row 0, @0xfdc
tl: 4012 fb: ----FL-- lb: 0x1 cc: 1 --row flag是----FL--，也就是0x0c
hrid: 0x004080c1.2col 0: [4000]
63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63 63

沒錯，在開啟附加日誌後，對於行遷移資料，Oracle會將hrid資訊記錄下來，這樣，我們便可以根據hrid找到行頭，同時，可以計算出正確的ROWID資訊。這部分的內容，同時也證明了我們對於eygle大師這個案例為什麼無法使用logminer解析的猜想。[@more@]