3、使用10046診斷rebuild動作

10046診斷事件是我們經常用來使用跟蹤事件，也是我們分析Oracle內部行為的最常用工具。下面筆者將用這個工具對rebuild動作進行檢查。

首先獲取一下資料表T和索引IDX_T_ID的分割槽結構。

--資料表T

SQL> select EXTENT_ID, FILE_ID, BLOCK_ID, BYTES, BLOCKS from dba_extents where owner='SYS' and segment_name='T';

EXTENT_ID FILE_ID BLOCK_ID BYTES BLOCKS

---------- ---------- ---------- ---------- ----------

0 1 31072 65536 8 –段首

1 1 31096 65536 8

2 1 99328 65536 8

3 1 99360 65536 8

4 1 99368 65536 8

5 1 99376 65536 8

6 1 99384 65536 8

7 1 99392 65536 8

8 1 99400 65536 8

9 1 99408 65536 8

10 1 99416 65536 8

11 1 99424 65536 8

12 1 99432 65536 8

13 1 99440 65536 8

14 1 99448 65536 8

15 1 100736 65536 8

16 1 99456 1048576 128

17 1 99584 1048576 128

18 1 99712 1048576 128

19 1 99840 1048576 128

EXTENT_ID FILE_ID BLOCK_ID BYTES BLOCKS

---------- ---------- ---------- ---------- ----------

20 1 99968 1048576 128

21 1 100096 1048576 128

22 1 100224 1048576 128

23 1 100352 1048576 128

24 1 100480 1048576 128

25 rows selected

--分割槽情況

SQL> select EXTENT_ID, FILE_ID, BLOCK_ID, BYTES, BLOCKS from dba_extents where owner='SYS' and segment_name='IDX_T_ID';

EXTENT_ID FILE_ID BLOCK_ID BYTES BLOCKS

---------- ---------- ---------- ---------- ----------

0 1 100760 65536 8 –段首

1 1 100768 65536 8

2 1 100776 65536 8

3 1 100784 65536 8

4 1 100792 65536 8

5 1 100800 65536 8

6 1 100808 65536 8

7 1 100816 65536 8

8 1 100824 65536 8

9 1 100832 65536 8

10 1 100840 65536 8

11 1 100848 65536 8

12 1 100856 65536 8

13 1 100608 65536 8

14 1 100616 65536 8

15 1 100624 65536 8

16 1 100864 1048576 128

17 rows selected

瞭解資料表和索引段結構之後，就可以從Trace檔案中分析Oracle的讀取寫入動作。下面執行跟蹤過程。

--清理記憶體

SQL> alter system flush shared_pool;

System altered

SQL> alter system flush buffer_cache;

System altered

跟蹤過程：

SQL> select value from v$diag_info where name='Default Trace File';

VALUE

--------------------------------------------------------------------------------

/u01/app/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_1962.trc

SQL> alter system flush shared_pool;

System altered

SQL> alter system flush buffer_cache;

System altered

SQL> alter session set events '10046 trace name context forever, level 12';

會話已更改。

SQL> alter index idx_t_id rebuild;

索引已更改。

SQL> alter session set events '10046 trace name context off';

會話已更改。

從Trace檔案中，我們可以發現很多的SQL語句和執行過程。一個Oracle SQL語句的執行，往往伴隨著很多的recursive call呼叫過程。詳細研究可以幫助我們理解內部執行機理。篇幅有限，本次之研究與alert index … rebuild相關語句和遊標記錄。

首先找到了rebuild記錄遊標。

=====================

PARSING IN CURSOR #3075237312 len=28 dep=0 uid=0 oct=9 lid=0 tim=1427116687152197 hv=411325523 ad='35dc51e8' sqlid='1w5dx14c88p2m'

alter index idx_t_id rebuild

END OF STMT

PARSE #3075237312:c=147978,e=169400,p=26,cr=312,cu=0,mis=1,r=0,dep=0,og=1,plh=1483129259,tim=1427116687152192

Alter index …. Rebuild語句被解析parse為編號：3075237312。之後Trace檔案中包括與這個編號有關的記錄如下：

首先記錄的是從物件中大量讀取資料的過程：

WAIT #3075237312: nam='db file sequential read' ela= 148 file#=1 block#=100760 blocks=1 obj#=87690 tim=1427116687641730

WAIT #3075237312: nam='db file scattered read' ela= 155 file#=1 block#=100761 blocks=7 obj#=87690 tim=1427116687642009

WAIT #3075237312: nam='db file scattered read' ela= 339 file#=1 block#=100768 blocks=8 obj#=87690 tim=1427116687646571

WAIT #3075237312: nam='db file scattered read' ela= 176 file#=1 block#=100776 blocks=8 obj#=87690 tim=1427116687650926

WAIT #3075237312: nam='db file scattered read' ela= 204 file#=1 block#=100784 blocks=8 obj#=87690 tim=1427116687655912

WAIT #3075237312: nam='db file scattered read' ela= 197 file#=1 block#=100792 blocks=8 obj#=87690 tim=1427116687660075

WAIT #3075237312: nam='db file scattered read' ela= 207 file#=1 block#=100800 blocks=8 obj#=87690 tim=1427116687664669

WAIT #3075237312: nam='db file scattered read' ela= 203 file#=1 block#=100808 blocks=8 obj#=87690 tim=1427116687669300

WAIT #3075237312: nam='db file scattered read' ela= 220 file#=1 block#=100816 blocks=8 obj#=87690 tim=1427116687674227

WAIT #3075237312: nam='db file scattered read' ela= 162 file#=1 block#=100824 blocks=8 obj#=87690 tim=1427116687679009

WAIT #3075237312: nam='db file scattered read' ela= 210 file#=1 block#=100832 blocks=8 obj#=87690 tim=1427116687683670

*** 2015-03-23 21:18:07.688

WAIT #3075237312: nam='db file scattered read' ela= 196 file#=1 block#=100840 blocks=8 obj#=87690 tim=1427116687688942

WAIT #3075237312: nam='db file scattered read' ela= 456 file#=1 block#=100848 blocks=8 obj#=87690 tim=1427116687694629

WAIT #3075237312: nam='db file scattered read' ela= 248 file#=1 block#=100856 blocks=8 obj#=87690 tim=1427116687699340

WAIT #3075237312: nam='db file scattered read' ela= 318 file#=1 block#=100608 blocks=8 obj#=87690 tim=1427116687704678

WAIT #3075237312: nam='db file scattered read' ela= 336 file#=1 block#=100616 blocks=8 obj#=87690 tim=1427116687709104

WAIT #3075237312: nam='db file scattered read' ela= 216 file#=1 block#=100624 blocks=8 obj#=87690 tim=1427116687713798

WAIT #3075237312: nam='db file scattered read' ela= 3976 file#=1 block#=100864 blocks=32 obj#=87690 tim=1427116687724032

WAIT #3075237312: nam='db file scattered read' ela= 769 file#=1 block#=100896 blocks=32 obj#=87690 tim=1427116687749159

WAIT #3075237312: nam='db file sequential read' ela= 165 file#=1 block#=100928 blocks=1 obj#=87690 tim=1427116687771987

WAIT #3075237312: nam='Disk file operations I/O' ela= 41 FileOperation=2 fileno=3 filetype=2 obj#=0 tim=1427116687775771

WAIT #3075237312: nam='db file sequential read' ela= 170 file#=3 block#=3044 blocks=1 obj#=0 tim=1427116687776293

WAIT #3075237312: nam='db file sequential read' ela= 178 file#=1 block#=2 blocks=1 obj#=1 tim=1427116687778458

WAIT #3075237312: nam='db file sequential read' ela= 134 file#=1 block#=3 blocks=1 obj#=1 tim=1427116687778761

第一句的sequential單塊讀動作，讀取的是file#=1 block#=100760 blocks=1 obj#=87690。參考之前分割槽結構，恰好是索引IDX_T_ID段的段頭塊結構。

SQL> select EXTENT_ID, FILE_ID, BLOCK_ID, BYTES, BLOCKS from dba_extents where owner='SYS' and segment_name='IDX_T_ID';

EXTENT_ID FILE_ID BLOCK_ID BYTES BLOCKS

---------- ---------- ---------- ---------- ----------

0 1 100760 65536 8

……

之後一系列的“db file scattered read”多塊讀動作，持續的“吞”掉索引的結構塊。這些特徵完全符合index fast full scan工作特點。

之後，就將處理資料寫入結構：

WAIT #3075237312: nam='direct path write' ela= 17189 file number=1 first dba=100636 block cnt=4 obj#=0 tim=1427116687900949

WAIT #3075237312: nam='direct path write' ela= 3769 file number=1 first dba=100640 block cnt=4 obj#=0 tim=1427116687907864

WAIT #3075237312: nam='direct path write' ela= 26675 file number=1 first dba=100644 block cnt=4 obj#=0 tim=1427116687939138

WAIT #3075237312: nam='direct path write' ela= 2119 file number=1 first dba=100648 block cnt=4 obj#=0 tim=1427116687944101

WAIT #3075237312: nam='direct path write' ela= 5425 file number=1 first dba=100652 block cnt=4 obj#=0 tim=1427116687953153

（篇幅原因，有省略……）

WAIT #3075237312: nam='direct path write' ela= 6109 file number=1 first dba=100692 block cnt=4 obj#=0 tim=1427116688030198

這部分動作是rebuild的後續動作，寫入資料內容就是新索引IDX_T_ID段結構。這點從執行後新段結構資訊可以證明。

SQL> select EXTENT_ID, FILE_ID, BLOCK_ID, BYTES, BLOCKS from dba_extents where owner='SYS' and segment_name='IDX_T_ID';

EXTENT_ID FILE_ID BLOCK_ID BYTES BLOCKS

---------- ---------- ---------- ---------- ----------

0 1 100632 65536 8

1 1 100640 65536 8

2 1 100648 65536 8

3 1 100656 65536 8

4 1 100664 65536 8

5 1 100672 65536 8

6 1 100680 65536 8

7 1 100688 65536 8

8 1 100696 65536 8

9 1 100704 65536 8

10 1 100712 65536 8

11 1 100720 65536 8

12 1 100728 65536 8

13 1 100992 65536 8

14 1 101000 65536 8

15 1 101008 65536 8

16 1 101120 1048576 128

17 rows selected

這系列也就證明了rebuild操作是基於原有索引結構資料，重新構建出索引段結構。

4、使用10046診斷rebuild online動作

下面測試一下rebuild online動作。為了保證實驗質量，清理一下記憶體快取。

SQL> alter system flush shared_pool;

System altered

SQL> alter system flush buffer_cache;

System altered

開啟跟蹤事件。

SQL> select value from v$diag_info where name='Default Trace File';

VALUE

-------------------------------------------------------------------------

/u01/app/diag/rdbms/ora11g/ora11g/trace/ora11g_ora_4149.trc

SQL> alter session set events '10046 trace name context forever, level 12';

會話已更改。

SQL> alter index idx_t_id rebuild online;

索引已更改。

SQL> alter session set events '10046 trace name context off';

會話已更改。

在跟蹤檔案中，找到對應的rebuild online遊標資訊。

=====================

PARSING IN CURSOR #3075319188 len=35 dep=0 uid=0 oct=9 lid=0 tim=1427116924266395 hv=572453287 ad='35d443ac' sqlid='6bvhyk0j1xwd7'

alter index idx_t_id rebuild online

END OF STMT

PARSE #3075319188:c=92986,e=109127,p=30,cr=236,cu=0,mis=1,r=0,dep=0,og=1,plh=1193657316,tim=1427116924266390

對rebuild online語句，遊標編號：#3075319188。在檔案中找到對應遊標的記錄。

WAIT #3075319188: nam='db file sequential read' ela= 199 file#=3 block#=192 blocks=1 obj#=0 tim=1427116926331398

WAIT #3075319188: nam='db file sequential read' ela= 146 file#=3 block#=6548 blocks=1 obj#=0 tim=1427116926331706

WAIT #3075319188: nam='db file sequential read' ela= 147 file#=1 block#=31072 blocks=1 obj#=87689 tim=1427116926332503

WAIT #3075319188: nam='db file sequential read' ela= 166 file#=1 block#=31072 blocks=1 obj#=87689 tim=1427116926332741

WAIT #3075319188: nam='db file scattered read' ela= 315 file#=1 block#=31073 blocks=7 obj#=87689 tim=1427116926333268

（篇幅原因，有省略……）

WAIT #3075319188: nam='db file scattered read' ela= 961 file#=1 block#=100511 blocks=32 obj#=87689 tim=1427116926441946

WAIT #3075319188: nam='db file scattered read' ela= 392 file#=1 block#=100543 blocks=15 obj#=87689 tim=1427116926444785

首先我們看一下比較奇怪的對file#=3的讀動作，單塊讀動作可以找到對應段的情況。

SQL> select * from dba_extents where FILE_ID=3 and block_id<=192 and block_id+blocks-1>=192;

SEGMENT_NAME SEGMENT_TYPE TABLESPACE_NAME EXTENT_ID FILE_ID BLOCK_ID BYTES BLOCKS RELATIVE_FNO

-------------------------------------------------------------------------------- ------------------------------ ------------------ -------------

_SYSSMU5_3994777876$ TYPE2 UNDO UNDOTBS1 0 3 192 65536 8 3

（結果有刪減）

SQL> select * from dba_extents where FILE_ID=3 and block_id<=6548 and block_id+blocks-1>=6548;

SEGMENT_NAME SEGMENT_TYPE TABLESPACE_NAME EXTENT_ID FILE_ID BLOCK_ID BYTES BLOCKS RELATIVE_FNO

------------------------ ------------------ ------------------------------ ---------- ---------- ---------- ---------- ---------- ------------

_SYSSMU5_3994777876$ TYPE2 UNDO UNDOTBS1 10 3 6528 1048576 128 3

這兩個部分內容是Undo段中資料。說明在讀過程，有訪問Undo前映象的情景。其他的資料內容為資料表段讀取：

SQL> select EXTENT_ID, FILE_ID, BLOCK_ID, BYTES, BLOCKS from dba_extents where owner='SYS' and segment_name='T';

EXTENT_ID FILE_ID BLOCK_ID BYTES BLOCKS

---------- ---------- ---------- ---------- ----------

0 1 31072 65536 8

1 1 31096 65536 8

2 1 99328 65536 8

之後是寫入動作：

WAIT #3075319188: nam='direct path write' ela= 104461 file number=1 first dba=100618 block cnt=2 obj#=87689 tim=1427116926569710

WAIT #3075319188: nam='direct path write' ela= 13504 file number=1 first dba=100620 block cnt=4 obj#=87689 tim=1427116926604072

（篇幅原因，有省略……）

WAIT #3075319188: nam='direct path write' ela= 2319 file number=1 first dba=100928 block cnt=1 obj#=87689 tim=1427116928413458

從Trace檔案結果看，rebuild online過程是直接對資料表的訪問，將資料讀取後進行索引化過程。

5、結論

索引rebuild是一個我們經常遇到的操作過程，詳細理解rebuild和rebuild online可以幫助在實際工作中強化分析能力，更好解決問題。

聊聊索引Index Rebuild和Rebuild Online（下）

相關文章