[20211105]索引分裂 块清除 日志增加.txt

[20211105]索引分裂 块清除 日志增加.txt

--//题目起的有点怪,只是我昨天在测试时遇到的怪问题,我通过测试环境演示出来。
--//当非主键索引发生分裂时发生的情况。

1.环境:
SCOTT@book> @ ver1
PORT_STRING                    VERSION        BANNER
------------------------------ -------------- --------------------------------------------------------------------------------
x86_64/Linux 2.4.xx            11.2.0.4.0     Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production

2.首先确定索引分裂发生的位置:

SCOTT@book> create table t1 (id number,vc varchar2(100));
Table created.

SCOTT@book> create index i_t1_id on t1(id);
Index created.

SCOTT@book> insert into t1 select rownum,rpad(rownum,100,'x') from dual connect by level<=1e3;
1000 rows created.

SCOTT@book> commit ;
Commit complete.

--//分析略。注意不要遗漏这步,避免查询取样问题的影响。

$ cat treedump.sql
column object_id new_value m_index_id
select object_id from user_objects where object_name = upper('&&1') and object_type = 'INDEX';
alter session set events 'immediate trace name treedump level &m_index_id';

SCOTT@book> @ treedump.sql  i_t1_id
 OBJECT_ID
----------
    329447
Session altered.

--//查看转储文件:
----- begin tree dump
branch: 0x10002b3 16777907 (0: nrow: 2, level: 1)
   leaf: 0x10002b6 16777910 (-1: nrow: 540 rrow: 540)
   leaf: 0x10002b7 16777911 (0: nrow: 460 rrow: 460)
----- end tree dump
--//检查转储,可以发现分裂发生在插入id=541值的情况。

3.开始测试:
--//truncate table t1;

SCOTT@book> insert into t1 select rownum,rpad(rownum,100,'x') from dual connect by level<=540;
540 rows created.

SCOTT@book> commit ;
Commit complete.

SCOTT@book> @  tix
New tracefile_identifier =  /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_60241_0001.trc

SCOTT@book> @ treedump.sql  i_t1_id
 OBJECT_ID
----------
    329447
Session altered.

--//查看转储文件:
----- begin tree dump
leaf: 0x10002b3 16777907 (0: nrow: 540 rrow: 540)
----- end tree dump

--//插入数据,为了实现50-50分裂,我不插入最大值。而是中间值100,注意不要提交。
SCOTT@book> insert into t1 select 100,rpad(100,100,'x') from dual ;
1 row created.

SCOTT@book> select rowid,id from t1 where id in (1,100,540,539);
ROWID                      ID
------------------ ----------
AABQbpAAEAAAAIkAAA          1
AABQbpAAEAAAAIlAAh        100
AABQbpAAEAAAAK9AAM        100
AABQbpAAEAAAAK9AAK        539
AABQbpAAEAAAAK9AAL        540
--//可以看出id =1,id = 100记录在不同块中,后面id=539,540以及插入id=100的记录在同一块中。

--//打开新的会话:
SCOTT@book> @ tix
New tracefile_identifier =  /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_60301_0001.trc

SCOTT@book> @ treedump.sql  i_t1_id
 OBJECT_ID
----------
    329447
Session altered.

--//查看转储文件:
----- begin tree dump
branch: 0x10002b3 16777907 (0: nrow: 2, level: 1)
   leaf: 0x10002b6 16777910 (-1: nrow: 279 rrow: 279)
   leaf: 0x10002b7 16777911 (0: nrow: 262 rrow: 262)
----- end tree dump
--//可以发生了索引块分裂,一块占279条(键值id=1-279),另外一块262条。也就是id=100插入发生在dba=0x10002b6块中。

--//打开新的会话session 1:
SCOTT@book> @ spid
       SID    SERIAL# PROCESS                  SERVER    SPID       PID  P_SERIAL# C50
---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------
        58       5405 60300                    DEDICATED 60301       28        172 alter system kill session '58,5405' immediate;
--//记下sid=58.

$ cat viewsessx.sql
column name format a70
SELECT b.NAME, a.statistic#, a.VALUE,a.sid
  FROM v$sesstat a, v$statname b
 WHERE lower(b.NAME) like lower('%&1%') AND a.statistic# = b.statistic# and a.sid='&&2'
      and a.value>0;

--//session 2:
SCOTT@book> @ viewsessx 'redo size' 58
NAME      STATISTIC#      VALUE        SID
--------- ---------- ---------- ----------
redo size        194        752         58

--//session 1:
SCOTT@book> select * from t1 where id=540;
        ID VC
---------- ----------------------------------------------------------------------------------------------------
       540 540xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx

--//session 2:
SCOTT@book> @viewsessx 'redo size' 58
NAME       STATISTIC#      VALUE        SID
---------- ---------- ---------- ----------
redo size         194       1004         58

--//可以发现日志增加 1004-752 = 252.
--//session 1:
SCOTT@book> select * from t1 where id=540;
        ID VC
---------- ----------------------------------------------------------------------------------------------------
       540 540xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx

--//session 2:
SCOTT@book> @ viewsessx 'redo size' 58
NAME      STATISTIC#      VALUE        SID
--------- ---------- ---------- ----------
redo size        194       1112         58
--//可以发现日志会再次增加 1112-1004 = 108.

--//session 1:
SCOTT@book> select rowid from t1 where id=540;
ROWID
------------------
AABQbpAAEAAAAK9AAL

SCOTT@book> @ rowid AABQbpAAEAAAAK9AAL
      OBJECT         FILE        BLOCK          ROW ROWID_DBA            DBA                  TEXT
------------ ------------ ------------ ------------ -------------------- -------------------- ----------------------------------------
      329449            4          701           11  0x10002BD           4,701                alter system dump datafile 4 block 701 ;

--//session 2:
SCOTT@book> @ viewsessx 'redo size' 58
NAME      STATISTIC#        VALUE          SID
--------- ---------- ------------ ------------
redo size        194         1112           58
--//通过索引定位并没有产生日志。

--//session 1:
SCOTT@book> select /*+ full(t1) */ rowid from t1 where id=540;
ROWID
------------------
AABQbpAAEAAAAK9AAL

--//session 2:
SCOTT@book> @ viewsessx 'redo size' 58
NAME       STATISTIC#        VALUE          SID
---------- ---------- ------------ ------------
redo size         194         1284           58
--//可以看出只要访问到数据块就会出现产生日志。

4.看看日志转储内容。

SCOTT@book> select current_scn from v$database;
CURRENT_SCN
-----------
13382392662

sqlplus scott/book <<EOF
$ (seq 1000 | xargs -IQ echo 'select vc from t1 where id=539;')
EOF

SCOTT@book> select current_scn from v$database;
CURRENT_SCN
-----------
13382394178

SCOTT@book> @ logfile
GROUP# STATUS     TYPE       MEMBER                          IS_ GROUP# THREAD# SEQUENCE#       BYTES BLOCKSIZE MEMBERS ARC STATUS     FIRST_CHANGE# FIRST_TIME          NEXT_CHANGE# NEXT_TIME
------ ---------- ---------- ------------------------------- --- ------ ------- --------- ----------- --------- ------- --- ---------- ------------- ------------------- ------------ -------------------
     1            ONLINE     /mnt/ramdisk/book/redo01.log    NO       1       1      1193    52428800       512       1 YES INACTIVE     13377207280 2021-11-04 22:00:26  13377254274 2021-11-05 08:29:41
     2            ONLINE     /mnt/ramdisk/book/redo02.log    NO       2       1      1194    52428800       512       1 YES INACTIVE     13377254274 2021-11-05 08:29:41  13382389878 2021-11-05 09:52:40
     3            ONLINE     /mnt/ramdisk/book/redo03.log    NO       3       1      1195    52428800       512       1 NO  CURRENT      13382389878 2021-11-05 09:52:40 2.814750E+14
     4            STANDBY    /mnt/ramdisk/book/redostb01.log NO
     5            STANDBY    /mnt/ramdisk/book/redostb02.log NO
     6            STANDBY    /mnt/ramdisk/book/redostb03.log NO
     7            STANDBY    /mnt/ramdisk/book/redostb04.log NO
7 rows selected.

--//当前日志是/mnt/ramdisk/book/redo03.log.
SCOTT@book> @ tix
New tracefile_identifier =  /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_60316_0001.trc

SCOTT@book> alter system dump logfile '/mnt/ramdisk/book/redo03.log' scn min 13382392662 scn max 13382394178;
System altered.

--//检查转储:
DUMP OF REDO FROM FILE '/mnt/ramdisk/book/redo03.log'
 Opcodes *.*
 RBAs: 0x000000.00000000.0000 thru 0xffffffff.ffffffff.ffff
 SCNs: scn: 0x0003.1da71b56 (13382392662) thru scn: 0x0003.1da72142 (13382394178)
 Times: creation thru eternity
 FILE HEADER:
    Compatibility Vsn = 186647552=0xb200400
    Db ID=1337401710=0x4fb7216e, Db Name='BOOK'
    Activation ID=1337448558=0x4fb7d86e
    Control Seq=50532=0xc564, File size=102400=0x19000
    File Number=3, Blksiz=512, File Type=2 LOG
 descrip:"Thread 0001, Seq# 0000001195, SCN 0x00031da71076-0xffffffffffff"
 thread: 1 nab: 0xffffffff seq: 0x000004ab hws: 0x1 eot: 1 dis: 0
 resetlogs count: 0x35711eb0 scn: 0x0000.000e2006 (925702)
 prev resetlogs count: 0x3121c97a scn: 0x0000.00000001 (1)
 Low  scn: 0x0003.1da71076 (13382389878) 11/05/2021 09:52:40
 Next scn: 0xffff.ffffffff 01/01/1988 00:00:00
 Enabled scn: 0x0000.000e2006 (925702) 11/24/2015 09:11:12
 Thread closed scn: 0x0003.1da71076 (13382389878) 11/05/2021 09:52:40
 Disk cksum: 0x6b9e Calc cksum: 0x6b9e
 Terminal recovery stop scn: 0x0000.00000000
 Terminal recovery  01/01/1988 00:00:00
 Most recent redo scn: 0x0000.00000000
 Largest LWN: 0 blocks
 End-of-redo stream : No
 Unprotected mode
 Miscellaneous flags: 0x800000
 Thread internal enable indicator: thr: 0, seq: 0 scn: 0x0000.00000000
 Zero blocks: 0
 Format ID is 2
 redo log key is 3d4b0b67edc7ae87867f8a8a286fd4
 redo log key flag is 5
 Enabled redo threads: 1

...

REDO RECORD - Thread:1 RBA: 0x0004ab.0000253a.0090 LEN: 0x0040 VLD: 0x01
SCN: 0x0003.1da72128 SUBSCN:  1 11/05/2021 10:26:35
CHANGE #1 TYP:0 CLS:1 AFN:4 DBA:0x010002bd OBJ:329449 SCN:0x0003.1da72127 SEQ:1 OP:4.1 ENC:0 RBL:0
Block cleanout record, scn:  0x0003.1da72128 ver: 0x01 opt: 0x01, entries follow...
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

REDO RECORD - Thread:1 RBA: 0x0004ab.0000253a.00d0 LEN: 0x0040 VLD: 0x01
SCN: 0x0003.1da72129 SUBSCN:  1 11/05/2021 10:26:35
CHANGE #1 TYP:0 CLS:1 AFN:4 DBA:0x010002bd OBJ:329449 SCN:0x0003.1da72128 SEQ:1 OP:4.1 ENC:0 RBL:0
Block cleanout record, scn:  0x0003.1da72129 ver: 0x01 opt: 0x01, entries follow...

REDO RECORD - Thread:1 RBA: 0x0004ab.0000253a.0110 LEN: 0x0040 VLD: 0x01
SCN: 0x0003.1da7212a SUBSCN:  1 11/05/2021 10:26:35
CHANGE #1 TYP:0 CLS:1 AFN:4 DBA:0x010002bd OBJ:329449 SCN:0x0003.1da72129 SEQ:1 OP:4.1 ENC:0 RBL:0
Block cleanout record, scn:  0x0003.1da7212a ver: 0x01 opt: 0x01, entries follow...
...
REDO RECORD - Thread:1 RBA: 0x0004ab.0000253b.01c4 LEN: 0x0060 VLD: 0x01
SCN: 0x0003.1da7212c SUBSCN:  1 11/05/2021 10:26:35
CHANGE #1 TYP:0 CLS:29 AFN:3 DBA:0x00c000e0 OBJ:4294967295 SCN:0x0003.1da7212b SEQ:1 OP:5.4 ENC:0 RBL:0
ktucm redo: slt: 0x0021 sqn: 0x00002e8a srt: 0 sta: 9 flg: 0x2 ktucf redo: uba: 0x00c04739.038a.09 ext: 2 spc: 7316 fbi: 0

REDO RECORD - Thread:1 RBA: 0x0004ab.00002545.0010 LEN: 0x0084 VLD: 0x05
SCN: 0x0003.1da72136 SUBSCN:  1 11/05/2021 10:26:43
(LWN RBA: 0x0004ab.00002545.0010 LEN: 0001 NST: 0001 SCN: 0x0003.1da72135)
CHANGE #1 MEDIA RECOVERY MARKER SCN:0x0000.00000000 SEQ:0 OP:24.4 ENC:0
END OF REDO DUMP
----- Redo read statistics for thread 1 -----
Read rate (SYNC): 4841Kb in 0.14s => 33.77 Mb/sec
Total redo bytes: 5119Kb Longest record: 16Kb, moves: 2/5518 moved: 0Mb (0%)
Longest LWN: 621Kb, reads: 2569
Last redo scn: 0x0003.1da72142 (13382394178)
Change vector header moves = 732/9665 (7%)

$ grep -B1 'Block cleanout record' /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_60316_0001.trc | grep  OBJ:329449|wc
   1001   12012   99099
--//奇怪怎么多了1次。

$ grep -B1 'Block cleanout record' /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_60316_0001.trc | grep -A1 OBJ:329449|head -7
CHANGE #1 TYP:0 CLS:1 AFN:4 DBA:0x010002bd OBJ:329449 SCN:0x0003.1da71abe SEQ:1 OP:4.1 ENC:0 RBL:0
Block cleanout record, scn:  0x0003.1da71d42 ver: 0x01 opt: 0x01, entries follow...
--
CHANGE #1 TYP:0 CLS:1 AFN:4 DBA:0x010002bd OBJ:329449 SCN:0x0003.1da71d42 SEQ:1 OP:4.1 ENC:0 RBL:0
Block cleanout record, scn:  0x0003.1da71d43 ver: 0x01 opt: 0x01, entries follow...
--
CHANGE #1 TYP:0 CLS:1 AFN:4 DBA:0x010002bd OBJ:329449 SCN:0x0003.1da71d43 SEQ:1 OP:4.1 ENC:0 RBL:0

--//0x010002bd = set dba 4,701 = alter system dump datafile 4 block 701 = 16777917
SCOTT@book> select * from dba_objects where data_object_id=329449;
OWNER  OBJECT_NAME SUBOBJECT_    OBJECT_ID DATA_OBJECT_ID OBJECT_TYPE         CREATED             LAST_DDL_TIME       TIMESTAMP           STATUS     T G S    NAMESPACE EDITION_NAME
------ ----------- ---------- ------------ -------------- ------------------- ------------------- ------------------- ------------------- ---------- - - - ------------ ------------
SCOTT  T1                           329446         329449 TABLE               2021-11-05 10:04:02 2021-11-05 10:08:48 2021-11-05:10:04:02 VALID      N N N            1

--//块清除发生在表块上 dba=0x010002bd。参考前面select rowid from t1 where id=540;的输出。
--//0x010002bd = set dba 4,701 = alter system dump datafile 4 block 701 = 16777917

5.换另外的方式看看日志转储内容。
SCOTT@book> @ tix
New tracefile_identifier =  /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_60316_0003.trc

SCOTT@book> ALTER SYSTEM DUMP LOGFILE '/mnt/ramdisk/book/redo03.log' DBA MIN 4 701 DBA MAX 4 701 scn min 13382392662 scn max 13382394178;
System altered.

DUMP OF REDO FROM FILE '/mnt/ramdisk/book/redo03.log'
 Opcodes *.*
 DBAs: (file # 4, block # 701) thru (file # 4, block # 701)
 RBAs: 0x000000.00000000.0000 thru 0xffffffff.ffffffff.ffff
 SCNs: scn: 0x0003.1da71b56 (13382392662) thru scn: 0x0003.1da72142 (13382394178)
 Times: creation thru eternity
 FILE HEADER:
    Compatibility Vsn = 186647552=0xb200400
    Db ID=1337401710=0x4fb7216e, Db Name='BOOK'
    Activation ID=1337448558=0x4fb7d86e
    Control Seq=50532=0xc564, File size=102400=0x19000
    File Number=3, Blksiz=512, File Type=2 LOG
 descrip:"Thread 0001, Seq# 0000001195, SCN 0x00031da71076-0xffffffffffff"
 thread: 1 nab: 0xffffffff seq: 0x000004ab hws: 0x1 eot: 1 dis: 0
 resetlogs count: 0x35711eb0 scn: 0x0000.000e2006 (925702)
 prev resetlogs count: 0x3121c97a scn: 0x0000.00000001 (1)
 Low  scn: 0x0003.1da71076 (13382389878) 11/05/2021 09:52:40
 Next scn: 0xffff.ffffffff 01/01/1988 00:00:00
 Enabled scn: 0x0000.000e2006 (925702) 11/24/2015 09:11:12
 Thread closed scn: 0x0003.1da71076 (13382389878) 11/05/2021 09:52:40
 Disk cksum: 0x6b9e Calc cksum: 0x6b9e
 Terminal recovery stop scn: 0x0000.00000000
 Terminal recovery  01/01/1988 00:00:00
 Most recent redo scn: 0x0000.00000000
 Largest LWN: 0 blocks
 End-of-redo stream : No
 Unprotected mode
 Miscellaneous flags: 0x800000
 Thread internal enable indicator: thr: 0, seq: 0 scn: 0x0000.00000000
 Zero blocks: 0
 Format ID is 2
 redo log key is 3d4b0b67edc7ae87867f8a8a286fd4
 redo log key flag is 5
 Enabled redo threads: 1

REDO RECORD - Thread:1 RBA: 0x0004ab.000024b8.0010 LEN: 0x006c VLD: 0x05
SCN: 0x0003.1da71d42 SUBSCN:  1 11/05/2021 10:26:35
(LWN RBA: 0x0004ab.000024b8.0010 LEN: 0133 NST: 0001 SCN: 0x0003.1da71d42)
CHANGE #1 TYP:0 CLS:1 AFN:4 DBA:0x010002bd OBJ:329449 SCN:0x0003.1da71abe SEQ:1 OP:4.1 ENC:0 RBL:0
Block cleanout record, scn:  0x0003.1da71d42 ver: 0x01 opt: 0x01, entries follow...

REDO RECORD - Thread:1 RBA: 0x0004ab.000024b8.007c LEN: 0x0040 VLD: 0x01
SCN: 0x0003.1da71d43 SUBSCN:  1 11/05/2021 10:26:35
CHANGE #1 TYP:0 CLS:1 AFN:4 DBA:0x010002bd OBJ:329449 SCN:0x0003.1da71d42 SEQ:1 OP:4.1 ENC:0 RBL:0
Block cleanout record, scn:  0x0003.1da71d43 ver: 0x01 opt: 0x01, entries follow...

REDO RECORD - Thread:1 RBA: 0x0004ab.000024b8.00bc LEN: 0x0040 VLD: 0x01
SCN: 0x0003.1da71d44 SUBSCN:  1 11/05/2021 10:26:35
CHANGE #1 TYP:0 CLS:1 AFN:4 DBA:0x010002bd OBJ:329449 SCN:0x0003.1da71d43 SEQ:1 OP:4.1 ENC:0 RBL:0
Block cleanout record, scn:  0x0003.1da71d44 ver: 0x01 opt: 0x01, entries follow...
....

REDO RECORD - Thread:1 RBA: 0x0004ab.0000253a.00d0 LEN: 0x0040 VLD: 0x01
SCN: 0x0003.1da72129 SUBSCN:  1 11/05/2021 10:26:35
CHANGE #1 TYP:0 CLS:1 AFN:4 DBA:0x010002bd OBJ:329449 SCN:0x0003.1da72128 SEQ:1 OP:4.1 ENC:0 RBL:0
Block cleanout record, scn:  0x0003.1da72129 ver: 0x01 opt: 0x01, entries follow...

REDO RECORD - Thread:1 RBA: 0x0004ab.0000253a.0110 LEN: 0x0040 VLD: 0x01
SCN: 0x0003.1da7212a SUBSCN:  1 11/05/2021 10:26:35
CHANGE #1 TYP:0 CLS:1 AFN:4 DBA:0x010002bd OBJ:329449 SCN:0x0003.1da72129 SEQ:1 OP:4.1 ENC:0 RBL:0
Block cleanout record, scn:  0x0003.1da7212a ver: 0x01 opt: 0x01, entries follow...
END OF REDO DUMP
----- Redo read statistics for thread 1 -----
Read rate (SYNC): 5119Kb in 0.06s => 83.32 Mb/sec
Total redo bytes: 5119Kb Longest record: 16Kb, moves: 2/5518 moved: 0Mb (0%)
Longest LWN: 621Kb, reads: 2569
Last redo scn: 0x0003.1da72142 (13382394178)
Change vector header moves = 732/9665 (7%)
----------------------------------------------

6.再看看看索引分裂另外一块的情况:
SCOTT@book> select rowid from t1 where id=1;
ROWID
------------------
AABQbpAAEAAAAIkAAA

SCOTT@book> @ rowid AABQbpAAEAAAAIkAAA
    OBJECT       FILE      BLOCK        ROW ROWID_DBA            DBA                  TEXT
---------- ---------- ---------- ---------- -------------------- -------------------- ----------------------------------------
    329449          4        548          0  0x1000224           4,548                alter system dump datafile 4 block 548 ;

--//session 2:
SCOTT@book> @ viewsessx 'redo size' 58
NAME                             STATISTIC#        VALUE          SID
------------------------------ ------------ ------------ ------------
redo size                               194       137472           58

--//session 1:
SCOTT@book> select rowid from t1 where id=1;
ROWID
------------------
AABQbpAAEAAAAIkAAA

--//session 2:
SCOTT@book> @ viewsessx 'redo size' 58
NAME                             STATISTIC#        VALUE          SID
------------------------------ ------------ ------------ ------------
redo size                               194       137580           58

--//可以发现这次redo再次增加,137580-137472 = 108,注意我的查询仅仅访问索引。换成全表扫描呢?
--//session 2:
SCOTT@book> @ viewsessx 'redo size' 58
NAME                             STATISTIC#        VALUE          SID
------------------------------ ------------ ------------ ------------
redo size                               194       137688           58

--//session 1:
SCOTT@book> select /*+ full(t1) */ rowid from t1 where id=1 and rownum=1;
ROWID
------------------
AABQbpAAEAAAAIkAAA
--//注:加入条件rownum=1;避免扫描全部块,这样会扫描到id=540的块,测试出现偏差。

--//session 2:
SCOTT@book> @ viewsessx 'redo size' 58
NAME                             STATISTIC#        VALUE          SID
------------------------------ ------------ ------------ ------------
redo size                               194       137688           58
--//日志没有增加。也就是导致日志增加的情况发生在索引上。

--//看看日志内容:
SCOTT@book> select current_scn from v$database;
 CURRENT_SCN
------------
 13382419257

SCOTT@book> select rowid from t1 where id=1;
ROWID
------------------
AABQbpAAEAAAAIkAAA

SCOTT@book> select current_scn from v$database;
 CURRENT_SCN
------------
 13382419277

SCOTT@book> alter system dump logfile '/mnt/ramdisk/book/redo03.log' scn min 13382419257 scn max 13382419277;
System altered.

--//查看转储:
*** 2021-11-05 16:04:44.952
REDO RECORD - Thread:1 RBA: 0x0004ab.0000c576.0010 LEN: 0x006c VLD: 0x05
SCN: 0x0003.1da7834a SUBSCN:  1 11/05/2021 16:04:22
(LWN RBA: 0x0004ab.0000c576.0010 LEN: 0001 NST: 0001 SCN: 0x0003.1da7834a)
CHANGE #1 TYP:0 CLS:1 AFN:4 DBA:0x010002b6 OBJ:329448 SCN:0x0003.1da77e55 SEQ:1 OP:4.1 ENC:0 RBL:0
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Block cleanout record, scn:  0x0003.1da7834a ver: 0x01 opt: 0x01, entries follow...
END OF REDO DUMP
--//0x010002b6 = set dba 4,694 = alter system dump datafile 4 block 694 = 16777910
SCOTT@book> select * from dba_objects where data_object_id=329448;
OWNER  OBJECT_NAME          SUBOBJECT_  OBJECT_ID DATA_OBJECT_ID OBJECT_TYPE         CREATED             LAST_DDL_TIME       TIMESTAMP           STATUS  T G S  NAMESPACE EDITION_NAME
------ -------------------- ---------- ---------- -------------- ------------------- ------------------- ------------------- ------------------- ------- - - - ---------- ------------------------------
SCOTT  I_T1_ID                             329447         329448 INDEX               2021-11-05 10:04:24 2021-11-05 10:08:48 2021-11-05:10:04:24 VALID   N N N          4

--//块清除发生在索引上。你可能问为什么,一些细节我自己也说不上来。

6.简单总结:
--//我给出我自己的理解:
--//首先索引分裂是一个递归事务这个操作已经提交,不会回滚。
--//当查询select * from t1 where id=540;时,通过索引定位数据块,注意索引分裂已经发生,但是对应该索引块的事务已经提交不会
--//再回滚。另外我设计插入的id=100,这个事务不发生在该分裂索引块中,该索引块不会重构,而探查表时插入id=100与id=540的记录
--//在同一块中,理论将要重构该块,我不理解为什么oracle会在这样的情况下做一次块清除操作,而且如果该事务不提交,每次都会做
--//一次块清除。

--//当查询select rowid from t1 where id=1时,访问的是分裂索引块的另外一块,该索引块分裂后还做一个事务就是插入id=100,
--//这样该索引块重构,再次出现一次块清除操作,但是这次发生在索引块中。

--//你可以做一个想像,当dml插入记录导致索引块分裂时,如果有应用大量通过索引访问涉及到对应表块以及索引块时有可能出现大量
--//块清除日志,只要事务不提交,块清除日志不断出现。

--//我感觉这是不是oralce bug,实际上即使要做也仅仅需要做1次就ok了,那位给一些建议。

7.补充:
--//如果提交后这样的情况就不会出现。提交事务看看。
SCOTT@book> insert into t1 select 100,rpad(100,100,'x') from dual ;
1 row created.

SCOTT@book> commit ;
Commit complete.

--//session 2:
SCOTT@book> @ viewsessx 'redo size' 58
NAME                             STATISTIC#        VALUE          SID
------------------------------ ------------ ------------ ------------
redo size                               194       137688           58

SCOTT@book> select rowid from t1 where id=1;
ROWID
------------------
AABQbpAAEAAAAIkAAA

SCOTT@book> @ viewsessx 'redo size' 58
NAME                             STATISTIC#        VALUE          SID
------------------------------ ------------ ------------ ------------
redo size                               194       137688           58
--//redo没有增加。

SCOTT@book> select * from t1 where id=540;
        ID VC
---------- ----------------------------------------------------------------------------------------------------
       540 540xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx

SCOTT@book> @ viewsessx 'redo size' 58
NAME                           STATISTIC#      VALUE        SID
------------------------------ ---------- ---------- ----------
redo size                             194     137688         58

--//redo没有增加。
--//有机会看看逐主键或者唯一索引的情况。

--//在插入1次不提交。
SCOTT@book> insert into t1 select 100,rpad(100,100,'y') from dual ;
1 row created.

--//session 2:
SCOTT@book> @ viewsessx 'redo size' 58
NAME                           STATISTIC#      VALUE        SID
------------------------------ ---------- ---------- ----------
redo size                             194     137688         58

SCOTT@book> select * from t1 where id=540;
        ID VC
---------- ----------------------------------------------------------------------------------------------------
       540 540xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx

SCOTT@book> select rowid from t1 where id=1;
ROWID
------------------
AABQbpAAEAAAAIkAAA

SCOTT@book> select * from t1 where id=100;
        ID VC
---------- ----------------------------------------------------------------------------------------------------
       100 100xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx
       100 100xxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxxx

SCOTT@book> @ viewsessx 'redo size' 58
NAME                           STATISTIC#      VALUE        SID
------------------------------ ---------- ---------- ----------
redo size                             194     137688         58

--//日志没有增加。

上一篇:MySQL 内核原理分析(一)


下一篇:InnoDB存储引擎执行原理深度剖析(1)