实验内容:非IMU模式下DML语句产生的REDO日志内容格式解读,数据库版本:11.2.0.4
最详细的解读是UPDATE的。
实验环境准备
11G中默认是开启IMU特性的,做此实验需要关闭此特性。
alter system set "_in_memory_undo"=false;
alter system set "_in_memory_undo"=true; --实验结束后使用此语句改回使用IMU特性。
修改参数完成后,重启数据库:
shutdown immediate;
startup;
准备好实验用的表----BYS.DEPT表。
SYS@ bys3>select object_id from dba_objects where object_name='DEPT';
OBJECT_ID
----------
22327
SYS@ bys3>select * from bys.dept;
DEPTNO DNAME LOC
---------- -------------- -------------
10 ACCOUNTING NEW YORK
20 RESEARCH DALLAS
40 OPERATIONS BOSTON
11 chedan bj
22 test sh
BYS@ bys3>col file_name for a35
SYS@ bys3>col name for a15
SYS@ bys3>
select a.file_id,b.ts#,b.name,a.file_name from dba_data_files a,v$tablespace b where a.TABLESPACE_NAME=b.name;
FILE_ID TS# NAME FILE_NAME
---------- ---------- --------------- -----------------------------------
1 0 SYSTEM /u01/oradata/bys3/system01.dbf
2 1 SYSAUX /u01/oradata/bys3/sysaux01.dbf
3 2 UNDOTBS1 /u01/oradata/bys3/undotbs01.dbf
4 4 USERS /u01/oradata/bys3/user01.dbf
###################################################
开始实验分三步,分别是插入、更新、删除语句的操作。
最详细的解读是UPDATE的。
实验一:insert 操作的REDO日志解读
会话1: --SYS用户切换日志并查出当前日志名:
SYS@ bys3>alter system switch logfile;
System altered.
col MEMBER for a30
SYS@ bys3>select a.group#,a.sequence#,a.archived,a.status,b.type,b.member from v$log a,v$logfile b where a.group#=b.group#;
GROUP# SEQUENCE# ARC STATUS TYPE MEMBER
---------- ---------- --- ---------------- ------- ------------------------------
1 310 NO CURRENT ONLINE /u01/oradata/bys3/redo01.log
2 308 YES INACTIVE ONLINE /u01/oradata/bys3/redo02.log
3 309 YES ACTIVE ONLINE /u01/oradata/bys3/redo03.log
普通用户做插入语句:
SYS@ bys3>conn bys/bys
select * from dept;
Connected.
BYS@ bys3>
DEPTNO DNAME LOC
---------- -------------- -------------
10 ACCOUNTING NEW YORK
20 RESEARCH DALLAS
40 OPERATIONS BOSTON
11 chedan bj
22 test sh
BYS@ bys3>set time on
20:34:07 BYS@ bys3>insert into dept values(33,'imutest','hz');
1 row created.
20:34:12 BYS@ bys3>commit;
Commit complete.
会话2:DUMP当前REDO日志:
SYS@ bys3>alter system dump logfile '/u01/oradata/bys3/redo01.log';
System altered.
SYS@ bys3>select value from v$diag_info where name like 'De%' ;
VALUE
----------------------------------------------------------------------------------------------------
/u01/diag/rdbms/bys3/bys3/trace/bys3_ora_29063.trc
######################
查看此TRACE文件: 方法是:vi /u01/diag/rdbms/bys3/bys3/trace/bys3_ora_29063.trc 然后搜索修改的对象的OBJECT_ID-- 22327
详解参考下一步的UPDATE的REDO讲解。
REDO RECORD - Thread:1
RBA: 0x000136.0000000d.0010 LEN: 0x01a0 VLD: 0x05
SCN: 0x0000.00702f08 SUBSCN: 1 01/06/2014 20:34:13
(LWN RBA: 0x000136.0000000d.0010 LEN: 0002 NST: 0001 SCN: 0x0000.00702f08)
CHANGE #1 TYP:0 CLS:21
AFN:3 DBA:0x00c000a0 OBJ:4294967295 SCN:0x0000.00702eda SEQ:1
OP:5.2 ENC:0 RBL:0
ktudh redo: slt: 0x0003 sqn: 0x00000eaa flg: 0x0012 siz: 112 fbi: 0
uba: 0x00c01ac7.0250.25 pxid: 0x0000.000.00000000
CHANGE #2 TYP:0 CLS:22
AFN:3 DBA:0x00c01ac7 OBJ:4294967295 SCN:0x0000.00702ed9 SEQ:3
OP:5.1 ENC:0 RBL:0
ktudb redo: siz: 112 spc: 3494 flg: 0x0012 seq: 0x0250 rec: 0x25
xid: 0x0003.003.00000eaa
ktubl redo: slt: 3 rci: 0 opc: 11.1 [
objn: 22327 objd: 22327 tsn: 4] -------
tsn: 4
,
插入的这个是在表空间号为4--
OBJ:22327--是插入的对象的OBJECT_ID
Undo type: Regular undo Begin trans Last buffer split: No
Temp Object: No
Tablespace Undo: No
0x00000000 prev ctl uba: 0x00c01ac7.0250.22
prev ctl max cmt scn: 0x0000.007029ac prev tx cmt scn: 0x0000.007029d6
txn start scn: 0xffff.ffffffff logon user: 32 prev brb: 12589763 prev bcl: 0 BuExt idx: 0 flg2: 0
KDO undo record:
KTB Redo
op: 0x03 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: Z
KDO Op code: DRP row dependencies Disabled
xtype: XA flags: 0x00000000 bdba: 0x010000ff hdba: 0x010000fa
itli: 1 ispac: 0 maxfr: 4858
tabn: 0 slot: 0(0x0)
CHANGE #3 TYP:0 CLS:1
AFN:4 DBA:0x010000ff OBJ:22327 SCN:0x0000.003eec75 SEQ:1
OP:11.2 ENC:0 RBL:0 --
OP:11.2 这个应该是插入的操作的了。
KTB Redo -----
AFN:4,
插入的这个是在4号数据文件中--
OBJ:22327--是插入的对象的OBJECT_ID
op: 0x01 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: F xid: 0x0003.003.00000eaa uba: 0x00c01ac7.0250.25
KDO Op code: IRP row dependencies Disabled
xtype: XA flags: 0x00000000 bdba: 0x010000ff hdba: 0x010000fa
itli: 1 ispac: 0 maxfr: 4858
tabn: 0 slot: 0(0x0) size/delt: 17
fb: --H-FL-- lb: 0x1 cc: 3
null: ---
col 0: [ 2] c1 22 ---插入语句是:insert into dept values(33,'imutest','hz'); 对应是:select dump(33,16) from dual; --要注意数字在DUMP时不要加单引号
col 1: [ 7] 69 6d 75 74 65 73 74 --对应select dump('imutest',16) from dual; [7]--中括号里的是字节数,col 1:对应的是第二列,
col 2: [ 2] 68 7a ---对应 select dump('hz',16) from dual; --中括号里的是字节数 col 2:
select chr(to_number(substr(replace('69 6d 75 74 65 73 74',' '),rownum*2-1,2),'xxxxxxxxxxxxxxxx')) from v$bh where rownum<11;
CHR(
----
i
m
u
t
e
s
t
REDO RECORD - Thread:1 RBA: 0x000136.0000000d.01b0 LEN: 0x0060 VLD: 0x01
SCN: 0x0000.00702f09 SUBSCN: 1 01/06/2014 20:34:13 ----
OP:5.4,提交操作
CHANGE #1 TYP:0 CLS:21
AFN:3 DBA:0x00c000a0 OBJ:4294967295 SCN:0x0000.00702f08 SEQ:1
OP:5.4 ENC:0 RBL:0
ktucm redo:
slt: 0x0003 sqn: 0x00000eaa srt: 0 sta: 9 flg: 0x2 ktucf redo:
uba: 0x00c01ac7.0250.25ext: 12 spc: 3380 fbi: 0
############################
实验二:update 操作的REDO日志解读
会话3: --SYS用户切换日志:
SYS@ bys3>alter system switch logfile;
System altered.
SYS@ bys3>col MEMBER for a30
SYS@ bys3>select a.group#,a.sequence#,a.archived,a.status,b.type,b.member from v$log a,v$logfile b where a.group#=b.group#;
GROUP# SEQUENCE# ARC STATUS TYPE MEMBER
---------- ---------- --- ---------------- ------- ------------------------------
1 310 YES ACTIVE ONLINE /u01/oradata/bys3/redo01.log
2 311 NO CURRENT ONLINE /u01/oradata/bys3/redo02.log
3 309 YES INACTIVE ONLINE /u01/oradata/bys3/redo03.log
切换到普通用户做更新语句:
SYS@ bys3>conn bys/bys
Connected.
BYS@ bys3>select * from dept;
DEPTNO DNAME LOC
---------- -------------- -------------
10 ACCOUNTING NEW YORK
20 RESEARCH DALLAS
40 OPERATIONS BOSTON
11 chedan bj
22 test sh
33 imutest hz
6 rows selected.
BYS@ bys3>set time on
20:39:23 BYS@ bys3>update dept set dname='database' where deptno=11;
1 row updated.
20:39:43 BYS@ bys3>commit;
Commit complete.
20:39:46 BYS@ bys3>
会话4:DUMP当前REDO日志:
SYS@ bys3>alter system dump logfile '/u01/oradata/bys3/redo02.log';
System altered.
SYS@ bys3>select value from v$diag_info where name like 'De%' ;
VALUE
----------------------------------------------------------------------------------------------------
/u01/diag/rdbms/bys3/bys3/trace/bys3_ora_29141.trc
##############
查看此TRACE文件: 方法是:vi /u01/diag/rdbms/bys3/bys3/trace/bys3_ora_29141.trc 然后搜索修改的对象的OBJECT_ID:22327
UPDATE 一行记录产生一个REDO RECORD,提交产生一个REDO RECORD。非IMU下如果一个UPDATE更新多行,则会产生多条REDO RECORD。关于这个UPDATE语句 产生多少REDO RECORD的话题详见另一篇:
非IMU模式下一条update语句产生REDO RECORD条数的探究
######
一个REDO RECORD: RECORD头+CHANGE VECTOR组成(一个CV就是一个操作)
REDO RECORD - Thread:1 RBA: 0x000137.00000003.0010 LEN: 0x01ec VLD: 0x05
SCN: 0x0000.00702fe0 SUBSCN: 1 01/06/2014 20:39:45
(LWN RBA: 0x000137.00000003.0010 LEN: 0001 NST: 0001 SCN: 0x0000.00702fdf)
##以上是日志头,Thread:1 线程号,RAC时会有1,2等
RBA: 0x000137.00000003.0010 将16进制转换为十进制分别是日志文件号、日志块号、在块上第N字节
VLD: 0x05日志类型;
SCN: 0x0000.00702fe0 SUBSCN: 1 01/06/2014 20:39:45
--是此REDO条目产生时的SCN号,转为十进制现转为时间戳为:06-JAN-14 08.39.42, 更新语句完成是在20:39:43 BYS@bys3>commit;
(LWN RBA: 0x000137.00000003.0010 LEN: 0001 NST: 0001 SCN: 0x0000.00702fdf)
括号中SCN: SCN: 0x0000.00702fdf 比上一句:SCN: 0x0000.00702fe0 SUBSCN: 1 01/06/2014 20:39:45
少了1个SCN。
######
CHANGE #1 TYP:0 CLS:17 AFN:3 DBA:0x00c00080 OBJ:4294967295 SCN:0x0000.00702f9a SEQ:1 OP:5.2 ENC:0 RBL:0
ktudh redo:
slt: 0x000f sqn: 0x00000e9c flg: 0x0012 siz: 164 fbi: 0 --这一行信息与下一条提交的
REDO RECORD可以对上,证明是同一个事务的。
uba: 0x00c01cbf.0250.0f pxid: 0x0000.000.00000000
### #####################
事务信息
TYP:0 普通块 ,CLS:17 class大于16是UNDO块-递增。AFN:3 绝对文件号dba_data_files.file_id--这里是UNDO文件的文件号
DBA:0x00c00080 数据块在内存中地址, 80十进制128,,select SEGMENT_NAME from dba_segments where HEADER_FILE=3 and HEADER_BLOCK=128; 查出对象名。
OBJ:4294967295 --十进制,转为16进制是FFFFFFFF
SCN:0x0000.00702f9a 转换为16进制可与操作时对比
OP:5.2 -> operation code 向UNDO段头的事务表写事务信息-事务开始
uba: 0x00c01cbf.0250.0f UNDO块地址
####################
CHANGE #2 TYP:0
CLS:18 AFN:3 DBA:0x00c01cbf OBJ:4294967295 SCN:0x0000.00702f99 SEQ:2 OP:5.1 ENC:0 RBL:0
##
OP:5.1 --把数据修改前值放到UNDO --AFN:3 --在UNDO文件里操作,UNDO文件号是3。。
CLS:18 --比
CHANGE #1中大1,顺序增长哈哈
ktudb redo: siz: 164 spc: 6494 flg: 0x0012 seq: 0x0250 rec: 0x0f
xid: 0x0001.00f.00000e9c
ktubl redo: slt: 15 rci: 0 opc: 11.1
[objn: 22327 objd: 22327 tsn: 4] -------
tsn: 4,
插入的这个是在表空间号-USERS的表空间号,--
OBJ:22327--是插入的对象的OBJECT_ID
Undo type: Regular undo Begin trans Last buffer split: No
Temp Object: No
Tablespace Undo: No
0x00000000 prev ctl uba: 0x00c01cbf.0250.0d
prev ctl max cmt scn: 0x0000.00702afa prev tx cmt scn: 0x0000.00702b2e
txn start scn: 0xffff.ffffffff logon user: 32 prev brb: 12590267 prev bcl: 0 BuExt idx: 0 flg2: 0
KDO undo record:
KTB Redo
op: 0x04 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: L itl: xid: 0x0005.008.00000e9d uba: 0x00c01840.02e4.13
flg: C--- lkc: 0 scn: 0x0000.00702b1f
KDO Op code: URP row dependencies Disabled
xtype: XA flags: 0x00000000 bdba: 0x010000fd hdba: 0x010000fa
itli: 1 ispac: 0 maxfr: 4858
tabn: 0 slot: 5(0x5) flag: 0x2c lock: 0 ckix: 0
ncol: 3 nnew: 1
size: -2
##列字符长度减少2:
chedan减去database就是-2---根据多次update并DUMP的日志来看,这里的
size的值应该是:当前
CHANGE中的值减去另一个
col 1: [ 6] 63 68 65 64 61 6e --修改语句是:update dept set dname='database' where deptno=11; deptno=11时的为chedan-DUMP为16进制,与col 1: [ 6] 63 68 65 64 61 6e对应,[ 6]
与
chedan对应,
col 1是第二列--修改的dname列就是第二列。
SYS@ bys3>
select dump('chedan',16) from dual;
DUMP('CHEDAN',16)
-------------------------------
Typ=96 Len=6: 63,68,65,64,61,6e
##############
CHANGE #3 TYP:2 CLS:1
AFN:4DBA:0x010000fd
OBJ:22327
SCN:0x0000.00702d7aSEQ:1 OP:11.5 ENC:0 RBL:0
## OP:11.19 或者OP:11.5都是--UPDATE语句,开始修改数据, AFN:4 --这次是在USERS表空间修改数据-文件号就是4
KTB Redo
op: 0x11 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: F xid: 0x0001.00f.00000e9c uba: 0x00c01cbf.0250.0f
Block cleanout record, scn: 0x0000.00702fe0 ver: 0x01 opt: 0x02, entries follow...
itli: 1 flg: 2 scn: 0x0000.00702b1f
itli: 2 flg: 2 scn: 0x0000.00702d7a
KDO Op code: URP row dependencies Disabled
###此语句也说明是UPDATE语句,URP row dependencies Disabled --URP=UPDATE ROW PIECE。有时会是:KDO Op code:21 row dependencies Disabled
xtype: XA flags: 0x00000000 bdba: 0x010000fd hdba: 0x010000fa
itli: 1 ispac: 0 maxfr: 4858
tabn: 0 slot: 5(0x5) flag: 0x2c lock: 1 ckix: 0
ncol: 3 nnew: 1 size: 2 ##size: 2,列字符长度增加2:database减去
chedan---根据多次update并DUMP的日志来看,这里的
size的值应该是:当前
CHANGE中的值减去另一个
col 1: [ 8] 64 61 74 61 62 61 73 65 ---update dept set dname='database' where deptno=11;,对应
select dump('database',16) from dual;
col 1: [ 8] ---第二列,8位,
####################################################
REDO RECORD - Thread:1 RBA: 0x000137.00000004.0010 LEN: 0x008c VLD: 0x05
SCN: 0x0000.00702fe2 SUBSCN: 1 01/06/2014 20:39:46
(LWN RBA: 0x000137.00000004.0010 LEN: 0001 NST: 0001 SCN: 0x0000.00702fe1)
CHANGE #1 TYP:0 CLS:17
AFN:3 DBA:0x00c00080 OBJ:4294967295 SCN:0x0000.00702fe0 SEQ:1
OP:5.4 ENC:0 RBL:0
ktucm redo:
slt: 0x000f sqn: 0x00000e9c srt: 0 sta: 9 flg: 0x2 ktucf redo: uba: 0x00c01cbf.0250.0f ext: 4 spc: 6328 fbi: 0
###########
OP:5.4 表明是提交操作。
CHANGE #1 TYP:0 CLS:17 AFN:3 DBA:0x00c00080 OBJ:4294967295 SCN:0x0000.00702fe0 SEQ:1 OP:5.4 ENC:0 RBL:0
AFN:3 对应的是UNDO文件,
slt: 0x000f slot是槽位号,slot是每一个事务的入口,在一个事务中是不变的。这里与上一条REDO RECORD中的第一个CHANGE #1中的slt: 0x000f是相同的。
SCN: 0x0000.00702fe2 SUBSCN: 1 01/06/2014 20:39:46 提交操作的时间 :
20:39:43 BYS@ bys3>commit;
Commit complete.
20:39:46 BYS@ bys3>
########################################
实验三:delete 操作的REDO日志解读
会话5: --SYS用户切换日志:
alter system switch logfile;
SYS@ bys3>col member for a30
SYS@ bys3>select a.group#,a.sequence#,a.archived,a.status,b.type,b.member from v$log a,v$logfile b where a.group#=b.group#;
GROUP# SEQUENCE# ARC STATUS TYPE MEMBER
---------- ---------- --- ---------------- ------- ------------------------------
1 310 YES INACTIVE ONLINE /u01/oradata/bys3/redo01.log
2 311 YES ACTIVE ONLINE /u01/oradata/bys3/redo02.log
3 312 NO CURRENT ONLINE /u01/oradata/bys3/redo03.log
切换到普通用户做删除语句:
conn bys/bys
BYS@ bys3>select * from dept;
DEPTNO DNAME LOC
---------- -------------- -------------
10 ACCOUNTING NEW YORK
20 RESEARCH DALLAS
40 OPERATIONS BOSTON
11 database bj
22 test sh
33 imutest hz
6 rows selected.
BYS@ bys3>set time on
20:43:18 BYS@ bys3>delete dept where deptno=33;
1 row deleted.
20:43:25 BYS@ bys3>commit;
Commit complete.
会话6,DUMP当前REDO日志:
SYS@ bys3>alter system dump logfile '/u01/oradata/bys3/redo03.log';
System altered.
SYS@ bys3>select value from v$diag_info where name like 'De%' ;
VALUE
----------------------------------------------------------------------------------------------------
/u01/diag/rdbms/bys3/bys3/trace/bys3_ora_29214.trc
##############
查看此TRACE文件: 方法是:vi /u01/diag/rdbms/bys3/bys3/trace/bys3_ora_29214.trc 然后搜索修改的对象的OBJECT_ID:22327
REDO RECORD - Thread:1 RBA: 0x000138.0000002b.0010 LEN: 0x01c8 VLD: 0x05
SCN: 0x0000.0070306c SUBSCN: 1 01/06/2014 20:43:26
(LWN RBA: 0x000138.0000002b.0010 LEN: 0002 NST: 0001 SCN: 0x0000.0070306b)
CHANGE #1 TYP:0 CLS:29 AFN:3 DBA:0x00c000e0 OBJ:4294967295 SCN:0x0000.0070303f SEQ:1 OP:5.2 ENC:0 RBL:0
ktudh redo: slt: 0x0008 sqn: 0x00000e9b flg: 0x0012 siz: 168 fbi: 0
uba: 0x00c0193e.02b8.03 pxid: 0x0000.000.00000000
CHANGE #2 TYP:0 CLS:30 AFN:3 DBA:0x00c0193e OBJ:4294967295 SCN:0x0000.0070303e SEQ:1 OP:5.1 ENC:0 RBL:0
ktudb redo: siz: 168 spc: 7794 flg: 0x0012 seq: 0x02b8 rec: 0x03
xid: 0x0007.008.00000e9b
ktubl redo: slt: 8 rci: 0 opc: 11.1 [objn: 22327 objd: 22327 tsn: 4]
Undo type: Regular undo Begin trans Last buffer split: No
Temp Object: No
Tablespace Undo: No
0x00000000 prev ctl uba: 0x00c0193e.02b8.02
prev ctl max cmt scn: 0x0000.00702b2d prev tx cmt scn: 0x0000.00702b3e
txn start scn: 0xffff.ffffffff logon user: 32 prev brb: 12589367 prev bcl: 0 BuExt idx: 0 flg2: 0
KDO undo record:
KTB Redo
op: 0x03 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: Z
KDO Op code: IRP row dependencies Disabled
xtype: XA flags: 0x00000000 bdba: 0x010000ff hdba: 0x010000fa
itli: 2 ispac: 0 maxfr: 4858
tabn: 0 slot: 0(0x0) size/delt: 17
fb: --H-FL-- lb: 0x0 cc: 3
null: ---
col 0: [ 2] c1 22 ---记录删除前的原值,delete dept where deptno=33; 删除的是这一行值: 33 imutest hz
col 1: [ 7] 69 6d 75 74 65 73 74
col 2: [ 2] 68 7a
###################
BYS@ bys3>select dump(33,16),dump('imutest',16),dump('hz',16) from dual;
DUMP(33,16) DUMP('IMUTEST',16) DUMP('HZ',16)
------------------ ---------------------------------- -------------------
Typ=2 Len=2: c1,22 Typ=96 Len=7: 69,6d,75,74,65,73,74 Typ=96 Len=2: 68,7a
#####################
CHANGE #3 TYP:2 CLS:1 AFN:4 DBA:0x010000ff OBJ:22327 SCN:0x0000.00702f09 SEQ:1 OP:11.3 ENC:0 RBL:0
KTB Redo
op: 0x11 ver: 0x01
compat bit: 4 (post-11) padding: 1
op: F xid: 0x0007.008.00000e9b uba: 0x00c0193e.02b8.03
Block cleanout record, scn: 0x0000.0070306c ver: 0x01 opt: 0x02, entries follow...
itli: 1 flg: 2 scn: 0x0000.00702f09
KDO Op code: DRP row dependencies Disabled
xtype: XA flags: 0x00000000 bdba: 0x010000ff hdba: 0x010000fa
itli: 2 ispac: 0 maxfr: 4858
tabn: 0 slot: 0(0x0)
REDO RECORD - Thread:1 RBA: 0x000138.0000002b.01d8 LEN: 0x0060 VLD: 0x01
SCN: 0x0000.0070306d SUBSCN: 1 01/06/2014 20:43:26
CHANGE #1 TYP:0 CLS:29 AFN:3 DBA:0x00c000e0 OBJ:4294967295 SCN:0x0000.0070306c SEQ:1 OP:5.4 ENC:0 RBL:0
ktucm redo: slt: 0x0008 sqn: 0x00000e9b srt: 0 sta: 9 flg: 0x2 ktucf redo: uba: 0x00c0193e.02b8.03 ext: 3 spc: 7624 fbi: 0