昨天晚上洗澡時新想到一個可以有效測試index rebuild online的方式, 也就是同時使用10046與10704 的trace event再配合lock阻塞的機制來測試index rebuild online的過程.
測試的過程如下.
01 |
--1. 構造一個500w條記錄的表. 並建立需要rebuild online的索引. |
02 |
--表的數量設定到這麼大,,主要是為了給後續的操作留出手工執行的時間. |
03 |
create table james_t as |
04 |
select rownum id,dbms_random.string('l',20) user_name |
06 |
connect by level <= 5e6; |
08 |
create index james_t_pk on james_t (id); |
10 |
--2. 在Session 2 (故意設定阻塞的程式)執行一個針對表james_t 的單條記錄的更新. |
11 |
update james_t set user_name = 'test 1' where rownum <= 1; |
13 |
--3. 在Session 3中觀察,當觀察到session 1被堵塞在Table Share Lock的Request模式時進行下一步. |
14 |
select /*+ rule*/a.* from v$lock a,v$session b where a.sid = b.sid and b.username = 'JAMES'; |
16 |
--4. 在Session 1 (執行index rebuild online的程式)執行如下語句. |
17 |
alter session set events '10704 trace name context forever,level 10'; |
18 |
alter session set events '10046 trace name context forever,level 12'; |
19 |
alter index james_t_pk rebuild online; |
21 |
--5. 在Session 2 提交前一個事務,使得rebuild online 過程繼續,並執行一個需要大量index欄位的更新操作. |
22 |
--構造需要rebuild online在獲取下一次Table Share lock之前需要Merge的資料. |
24 |
update james_t set id = 5000000 + id where rownum <= 3e5; |
27 |
--6. 在Session 2上執行一個類似於第二步的簡單更新,意在阻塞Rebuild Online獲取Table Share Lock. |
28 |
update james_t set user_name = 'test 1' where rownum <= 1; |
30 |
--7. 在Session 3中觀察,當觀察到session 1被堵塞在Table Share Lock的Request模式時,執行下面的語句後進行下一步. |
31 |
--清空Buffer Cache以觀察Session 1在獲取Table Share Lock後執行的操作.(可供下載的Trace檔案沒有做這一步) |
32 |
alter session set events = 'immediate trace name flush_cache'; |
34 |
--8. 提交Session 2的事務, 等待Rebuild Online結束.. |
36 |
--9. 從Session 3中提取出Session 1對應的Trace檔案,,以及下面的v$session_longops 的結果. |
37 |
SID SERIAL# OPNAME TARGET TARGET_DESC SOFAR TOTALWORK UNITS START_TIME LAST_UPDATE_TIME |
38 |
10 19 Sort Output 14759 14759 Blocks 07/28/2010 09:14:26 07/28/2010 09:14:41 |
1. 取得表上的Sub Share鎖. 索引的object_id = 6399.
*** 2010-07-27 23:07:16.000
ksqcmi: TM,18fe,0 mode=2 timeout=21474836
ksqcmi: returns 0
2. 建立日誌表.
"JAMES"."SYS_JOURNAL_6399"
create table "JAMES"."SYS_JOURNAL_6399" (C0 NUMBER, opcode char(1), partno number, rid rowid, primary key( C0 , rid ))
organization index TABLESPACE "USERS"
CREATE UNIQUE INDEX "JAMES"."SYS_IOT_TOP_6406" on "JAMES"."SYS_JOURNAL_6399"("C0","RID") INDEX ONLY TOPLEVEL TABLESPACE "USERS" NOPARALLEL
3. 請求表上的Share鎖.
*** 2010-07-27 23:07:16.000
ksqcmi: TM,18fe,0 mode=4 timeout=21474836
WAIT #1: nam='enqueue' ela= 3072242 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072273 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072430 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3071962 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072350 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072367 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072086 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072453 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 387366 p1=1414332420 p2=6398 p3=0
ksqcmi: returns 0
2010-07-27 23:07:16.000 + 24.965529 = 2010-07-27 23:07:40.966
--此時間與下面獲取Table Sub Share Lock的時間僅相差20ms左右. 中間的時間主要為統計誤差,,因為Trace中的輸出是連續的.
4. 取得完畢之後,,立即獲取表上的Sub Share鎖.
*** 2010-07-27 23:07:41.000
ksqcmi: TM,18fe,0 mode=2 timeout=21474836
ksqcmi: returns 0
5. 讀取基礎表,,建立索引.
WAIT #1: nam='db file scattered read' ela= 42228 p1=5 p2=4709 p3=4
WAIT #1: nam='db file scattered read' ela= 326 p1=5 p2=4710 p3=3
WAIT #1: nam='db file scattered read' ela= 236 p1=5 p2=4711 p3=2
.................
WAIT #1: nam='db file scattered read' ela= 549 p1=5 p2=36357 p3=4
WAIT #1: nam='db file scattered read' ela= 481 p1=5 p2=36358 p3=3
6. 開始Sort並輸出索引. (寫入臨時檔案)
WAIT #1: nam='direct path write' ela= 6 p1=201 p2=19942 p3=31
WAIT #1: nam='direct path write' ela= 2 p1=201 p2=19973 p3=4
WAIT #1: nam='direct path write' ela= 2 p1=201 p2=19721 p3=31
WAIT #1: nam='direct path write' ela= 395 p1=201 p2=19752 p3=12
--繼續從表上讀取內容.
WAIT #1: nam='db file scattered read' ela= 476 p1=5 p2=36359 p3=2
WAIT #1: nam='db file sequential read' ela= 417 p1=5 p2=36360 p3=1
WAIT #1: nam='direct path write' ela= 6 p1=201 p2=19942 p3=31
WAIT #1: nam='direct path write' ela= 2 p1=201 p2=19973 p3=4
WAIT #1: nam='direct path write' ela= 2 p1=201 p2=19721 p3=31
WAIT #1: nam='direct path write' ela= 395 p1=201 p2=19752 p3=12
--從臨時檔案讀出排好序的結果.
WAIT #1: nam='direct path read' ela= 211 p1=201 p2=19763 p3=1
WAIT #1: nam='direct path read' ela= 57865 p1=201 p2=27472 p3=31
WAIT #1: nam='direct path read' ela= 14829 p1=201 p2=34281 p3=31
..........
WAIT #1: nam='direct path read' ela= 14853 p1=201 p2=20342 p3=19
WAIT #1: nam='direct path read' ela= 16932 p1=201 p2=26315 p3=31
WAIT #1: nam='direct path read' ela= 12710 p1=201 p2=21154 p3=31
WAIT #1: nam='direct path read' ela= 16599 p1=201 p2=32412 p3=31
寫索引檔案,擴充套件segment資訊.
select file# from file$ where ts#=:1
select type#,blocks,extents,minexts,maxexts,extsize,extpct,user#,iniexts,NVL(lists,65535),NVL(groups,65535),cachehint,hwmincr, NVL(spare1,0) from seg$ where ts#=:1 and file#=:2 and block#=:3
insert into seg$ (file#,block#,type#,ts#,blocks,extents,minexts,maxexts,extsize,extpct,user#,iniexts,lists,groups,cachehint,bitmapranges,scanhint, hwmincr, spare1) values (:1,:2,:3,:4,:5,:6,:7,:8,:9,:10,:11,:12,:13,:14,:15,0,0,:16,DECODE(:17,0,NULL,:17))
中間再夾雜部分
WAIT #1: nam='direct path read' ela= 20442 p1=201 p2=31559 p3=1
--結束Sort Output並使用Direct path write寫入新索引.
WAIT #1: nam='direct path read' ela= 8504 p1=201 p2=19849 p3=1
WAIT #1: nam='direct path read' ela= 263 p1=201 p2=19974 p3=1
WAIT #1: nam='direct path read' ela= 46962 p1=201 p2=19721 p3=1
WAIT #1: nam='direct path write' ela= 359 p1=5 p2=48351 p3=7
WAIT #1: nam='direct path write' ela= 5 p1=5 p2=48358 p3=7
---在此時間點結束新索引的建立工作.
SID SERIAL# OPNAME TARGET TARGET_DESC SOFAR TOTALWORK UNITS START_TIME LAST_UPDATE_TIME
10 19 Sort Output 14759 14759 Blocks 07/28/2010 09:14:26 07/28/2010 09:14:41
7. 讀取Journal表上的變更,,將變更Merge到新的索引上.
--從10046 的traced Event的角度看,,新的索引檔案寫完成,開始讀取Journal表的內容,以merge新索引.
WAIT #1: nam='direct path read' ela= 23577 p1=201 p2=31718 p3=1
WAIT #1: nam='direct path read' ela= 60459 p1=201 p2=31877 p3=1
WAIT #1: nam='direct path write' ela= 5622 p1=5 p2=52496 p3=7
WAIT #1: nam='direct path write' ela= 3 p1=5 p2=52503 p3=2
WAIT #1: nam='db file sequential read' ela= 32390 p1=5 p2=397 p3=1
WAIT #1: nam='db file sequential read' ela= 34345 p1=5 p2=397 p3=1
WAIT #1: nam='db file sequential read' ela= 100004 p1=5 p2=52005 p3=1
--結束新索引的Merge工作.
WAIT #1: nam='db file sequential read' ela= 1521 p1=5 p2=32192 p3=1
WAIT #1: nam='db file sequential read' ela= 205 p1=5 p2=32192 p3=1
WAIT #1: nam='db file sequential read' ela= 252 p1=5 p2=32200 p3=1
WAIT #1: nam='db file sequential read' ela= 375 p1=5 p2=32200 p3=1
8. 請求表上的Share所.
--請求表上的Share 鎖,,以準備結束索引重建..
*** 2010-07-28 09:15:17.000
ksqcmi: TM,18fe,0 mode=4 timeout=21474836
WAIT #1: nam='enqueue' ela= 3071546 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072536 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072024 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072293 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072416 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072140 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072175 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072294 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072249 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072318 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072184 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072216 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 3072247 p1=1414332420 p2=6398 p3=0
WAIT #1: nam='enqueue' ela= 1244788 p1=1414332420 p2=6398 p3=0
ksqcmi: returns 0
9. 讀取剛剛阻塞Index Rebuild獲取Share 鎖所產生的Journal日誌並將變更merge到索引上.
--說明,,由於Index Rebuild Online程式是做Enqueue Conversion,所以只可能有一個Session會阻塞此程式.
--此次需要Merge的變更量只是阻塞程式產生的變更量,因此一般情況下,,持有Share鎖的時間比較短.
--但是會比第一次持有要稍長一點. 需要等後續清理物件的操作結束才能釋放.
10. 刪除Journal表
drop table "JAMES"."SYS_JOURNAL_6399"
9. 申請Journal表上的Exclusive 鎖.
*** 2010-07-27 23:11:03.000
ksqcmi: TM,1906,0 mode=6 timeout=0
ksqcmi: returns 0
=====================
10. 結束索引重建,,修改相關資料字典表
--更新索引上的data_object_id.
update ind$ set ts#=:2,file#=:3,block#=:4,intcols=:5,type#=:6,flags=:7,property=:8,pctfree$=:9,initrans=:10,maxtrans=:11,blevel=:12,leafcnt=:13,distkey=:14,lblkkey=:15,dblkkey=:16,clufac=:17,cols=:18,analyzetime=:19,samplesize=:20,dataobj#=:21,degree=decode(:22,1,null,:22),instances=decode(:23,1,null,:23),rowcnt=:24,pctthres$=:31*256+:25, indmethod#=:26, trunccnt=:27,spare1=:28,spare4=:29,spare2=:30,spare6=:32where obj#=:1
bind 19: dty=2 mxl=22(22) mal=00 scl=00 pre=00 acflg=08 oacfl2=1 size=24 ffset=0
bfp=032cc81c bln=24 avl=03 flg=05
value=6405
bind 33: dty=2 mxl=22(22) mal=00 scl=00 pre=00 acflg=08 oacfl2=1 size=24 ffset=0
bfp=032cd8dc bln=22 avl=03 flg=05
value=6399
更新物件的data_object_id
update obj$ set obj#=:6,type#=:7,ctime=:8,mtime=:9,stime=:10,status=:11,dataobj#=:13,flags=:14,oid$=:15,spare1=:16, spare2=:17 where owner#=:1 and name=:2 and namespace=:3 and(remoteowner=:4 or remoteowner is null and :4 is null)and(linkname=:5 or linkname is null and :5 is null)and(subname=:12 or subname is null and :12 is null)
設定物件新關聯的seg實體.透過ts#,header_file#,header_block#
update seg$ set type#=:4,blocks=:5,extents=:6,minexts=:7,maxexts=:8,extsize=:9,extpct=:10,user#=:11,iniexts=:12,lists=decode(:13, 65535, NULL, :13),groups=decode(:14, 65535, NULL, :14), cachehint=:15, hwmincr=:16, spare1=DECODE(:17,0,NULL,:17) where ts#=:1 and file#=:2 and block#=:3
執行Ojbect Checkpoint.
WAIT #1: nam='rdbms ipc reply' ela= 54 p1=5 p2=21474836 p3=0
WAIT #1: nam='rdbms ipc reply' ela= 44 p1=5 p2=21474836 p3=0
11. 到此索引Rebuild完成.
完整的Trace檔案檔案下載.