10704&10046 跟踪Create Index,Alter Index Online,Truncate过程分析锁定行为

it2022-05-05  362

首先先分析一下Alter Index Online的整个过程,只是一个分析思路而且这个行为是很有代表性的,其他的操作都是大同小异。

Technorati 标签: 10704, 10046

1 Session 1 中建表

SQL> create table xxd_t as

  2  select rownum id,dbms_random.string('l',20) user_name

  3  from dual

  4  connect by level <= 5e6;

Table created.

2 Session 1 中建索引

SQL> create index xxd_t_pk on xxd_t (id);

Index Created

3 Session 2Update表制造阻塞

SQL> update xxd_t set user_name = 'test 1' where rownum <= 1;

4 Session 3中看到session 1被堵塞在Table Share LockRequest模式时进行下一步.

SQL> select /*+ rule*/a.* from v$lock a,v$session b where a.sid = b.sid and b.username = user;

ADDR     KADDR           SID TY        ID1        ID2      LMODE    REQUEST     CTIME      BLOCK

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

405C3F90 405C3FA8        159 TM      61291          0          4          0        51          1

405C40E8 405C4100        143 TM      61291          0          0          3         4          0

405C403C 405C4054        159 TM         18          0          3          0        51          0

41BB9D58 41BB9D6C        159 DL      61291          0          3          0        51          0

41BB9CA0 41BB9CB4        159 DL      61291          0          3          0        51          0

405C34E8 405C3530        159 TS          0    4285569          6          0        30          0

40619440 4061955C        159 TX     524295       3868          6          0        51          0

7 rows selected

4. Session 1 (运行index rebuild online的进程)运行如下语句.

alter session set events '10704 trace name context forever,level 10';

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

alter index xxd_t_pk rebuild online;

5. Session 2 提交前一个事务,使得rebuild online 过程继续,并运行一个需要大量index字段的更新操作.构造需要rebuild online在获取下一次Table Share lock之前需要Merge的数据.

commit;

update xxd_t set id = 5000000 + id where rownum <= 3e5;

commit;

6. Session 2上运行一个类似于第二步的简单更新,意在阻塞Rebuild Online获取Table Share Lock.

update xxd_t set user_name = 'test 1' where rownum <= 1;

7.  Session 3中观察,当观察到session 1被堵塞在Table Share LockRequest模式时,执行下面的语句后进行下一步.清空Buffer Cache以观察Session 1在获取Table Share Lock后执行的操作.

alter session set events = 'immediate trace name flush_cache';

8. 提交Session 2的事务, 等待Rebuild Online结束..

Commit;

9. Trace文件中整个测试过程相关内容,随后进行分析

SQL> select object_id from dba_objects where object_name='XXD_T';

  61291      

SQL> select to_char('61291','xxxxxx') from dual;

TO_CHAR

-------

   ef6b

SQL> select object_id from dba_objects where object_name='XXD_T_PK';

 OBJECT_ID

----------

     61292

SQL> select to_char('61292','xxxxxx') from dual;

TO_CHAR

-------

   ef6c

node1*orcl-/u01/app/oracle/admin/orcl/udump >more orcl_ora_18245.trc | grep -n 'ef6b'

84:ksqgtl *** DL-0000ef6b-00000000 mode=3 flags=0x11 timeout=0 ***

98:ksqgtl *** DL-0000ef6b-00000000 mode=3 flags=0x11 timeout=0 ***

111:ksqcmi: DL,ef6b,0 mode=3 timeout=0

120:ksqgtl *** TM-0000ef6b-00000000 mode=2 flags=0x401 timeout=21474836 ***

133:ksqcmi: TM,ef6b,0 mode=2 timeout=21474836

2949:ksqcnv: TM-0000ef6b,00000000 mode=4 timeout=21474836

2951:ksqcmi: TM,ef6b,0 mode=4 timeout=21474836

2964:ksqcnv: TM-0000ef6b,00000000 mode=2 timeout=21474836

2966:ksqcmi: TM,ef6b,0 mode=2 timeout=21474836

40346:ksqcnv: TM-0000ef6b,00000000 mode=4 timeout=21474836

40348:ksqcmi: TM,ef6b,0 mode=4 timeout=21474836

80569:ksqrcl: DL,ef6b,0

80572:ksqrcl: DL,ef6b,0

82637:ksqrcl: TM,ef6b,0

展开分析一下

84*** 2007-02-14 07:07:20.517

ksqgtl *** DL-0000ef6b-00000000 mode=3 flags=0x11 timeout=0 ***

ksqgtl: xcb=0x0x40619e88, ktcdix=2147483647, topxcb=0x0x40619e88

        ktcipt(topxcb)=0x0

98*** 2007-02-14 07:07:20.517

ksqgtl *** DL-0000ef6b-00000000 mode=3 flags=0x11 timeout=0 ***

ksqgtl: xcb=0x0x40619e88, ktcdix=2147483647, topxcb=0x0x40619e88

        ktcipt(topxcb)=0x0

111*** 2007-02-14 07:07:20.517

ksqcmi: DL,ef6b,0 mode=3 timeout=0

ksqcmi: returns 0

ksqgtl: RETURNS 0

120*** 2007-02-14 07:07:20.518 首先获得表的行级共享锁mode=2 SS(Row-S)

ksqgtl *** TM-0000ef6b-00000000 mode=2 flags=0x401 timeout=21474836 ***

ksqgtl: xcb=0x0x40619e88, ktcdix=2147483647, topxcb=0x0x40619e88

        ktcipt(topxcb)=0x0

133 *** 2007-02-14 07:07:20.518

ksqcmi: TM,ef6b,0 mode=2 timeout=21474836

ksqcmi: returns 0

ksqgtl: RETURNS 0

284 PARSING IN CURSOR #5 len=158 dep=1 uid=0 oct=1 lid=0 tim=1267225039604101 hv=4036323617 ad='3c8d8428' 

create table "SYS"."SYS_JOURNAL_61292" (C0 NUMBER,  opcode char(1), partno number,  rid rowid, primary key( C0 , rid )) organizatio\

n index TABLESPACE "SYSTEM"

END OF STMT

2949 *** 2007-02-14 07:07:20.665 Alter Index Online发生后,此时请求表的mode=4 Share

ksqcnv: TM-0000ef6b,00000000 mode=4 timeout=21474836

2951*** 2007-02-14 07:07:20.665

ksqcmi: TM,ef6b,0 mode=4 timeout=21474836

WAIT #4: nam='enq: TM - contention' ela= 3 name|mode=1414332420 object #=61291 table/partition=0 obj#=61291 tim=1267225039712868

WAIT #4: nam='enq: TM - contention' ela= 2931299 name|mode=1414332420 object #=61291 table/partition=0 obj#=61291 tim=1267225042648\

585

WAIT #4: nam='enq: TM - contention' ela= 2931312 name|mode=1414332420 object #=61291 table/partition=0 obj#=61291 tim=1267225045580\

002

WAIT #4: nam='enq: TM - contention' ela= 2930320 name|mode=1414332420 object #=61291 table/partition=0 obj#=61291 tim=1267225048510\

425

*** 2011-02-14 07:07:32.676

WAIT #4: nam='enq: TM - contention' ela= 2931245 name|mode=1414332420 object #=61291 table/partition=0 obj#=61291 tim=1267225051441\

775

WAIT #4: nam='enq: TM - contention' ela= 2931251 name|mode=1414332420 object #=61291 table/partition=0 obj#=61291 tim=1267225054373\

156

WAIT #4: nam='enq: TM - contention' ela= 2931269 name|mode=1414332420 object #=61291 table/partition=0 obj#=61291 tim=1267225057304\

541

WAIT #4: nam='enq: TM - contention' ela= 2463661 name|mode=1414332420 object #=61291 table/partition=0 obj#=61291 tim=1267225059768\

303

ksqcmi: returns 0

ksqcnv: RETURNS 0

2964 *** 2007-02-14 07:07:41.202

ksqcnv: TM-0000ef6b,00000000 mode=2 timeout=21474836

2966 *** 2007-02-14 07:07:41.202

ksqcmi: TM,ef6b,0 mode=2 timeout=21474836

ksqcmi: returns 0

ksqcnv: RETURNS 0

WAIT #4: nam='direct path read temp' ela= 7 file number=201 first dba=1189 block cnt=1 obj#=61291 tim=1267225169849896

WAIT #4: nam='direct path read temp' ela= 3 file number=201 first dba=1190 block cnt=1 obj#=61291 tim=1267225169851138

WAIT #4: nam='direct path write' ela= 1 file number=1 first dba=138185 block cnt=7 obj#=61291 tim=1267225169874164

WAIT #4: nam='direct path write' ela= 23 file number=1 first dba=138185 block cnt=7 obj#=61291 tim=1267225169874186

WAIT #4: nam='direct path write' ela= 0 file number=1 first dba=138192 block cnt=7 obj#=61291 tim=1267225169874645

WAIT #4: nam='direct path write' ela= 16 file number=1 first dba=138192 block cnt=7 obj#=61291 tim=1267225169874660

*** 2007-02-14 07:09:44.308

WAIT #4: nam='buffer busy waits' ela= 435 file#=2 block#=8768 class#=30 obj#=0 tim=1267225179988859

WAIT #4: nam='buffer busy waits' ela= 97288 file#=2 block#=8768 class#=30 obj#=0 tim=1267225180086260

*** 2007-02-14 07:09:44.520

ksqcnv: TM-0000ef6b,00000000 mode=4 timeout=21474836

*** 2007-02-14 07:09:44.520

ksqcmi: TM,ef6b,0 mode=4 timeout=21474836

WAIT #4: nam='enq: TM - contention' ela= 8 name|mode=1414332420 object #=61291 table/partition=0 obj#=0 tim=1267225180195810

WAIT #4: nam='enq: TM - contention' ela= 2930231 name|mode=1414332420 object #=61291 table/partition=0 obj#=0 tim=1267225183126073

WAIT #4: nam='enq: TM - contention' ela= 2930254 name|mode=1414332420 object #=61291 table/partition=0 obj#=0 tim=1267225186056414

WAIT #4: nam='enq: TM - contention' ela= 2930360 name|mode=1414332420 object #=61291 table/partition=0 obj#=0 tim=1267225188986878

*** 2007-02-14 07:09:56.524

……………………….

*** 2007-02-14 07:13:53.253

ksqrcl: DL,ef6b,0

ksqrcl: returns 0

*** 2007-02-14 07:13:53.254

ksqrcl: DL,ef6b,0

ksqrcl: returns 0

XCTEND rlbk=0, rd_only=0

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

PARSING IN CURSOR #4 len=35 dep=0 uid=0 oct=9 lid=0 tim=1267225039568125 hv=3160315829 ad='3c8d229c'

alter index xxd_t_pk rebuild online

END OF STMT

PARSE #4:c=14997,e=52795,p=0,cr=10,cu=0,mis=1,r=0,dep=0,og=1,tim=1267225039568120

*** 2007-02-14 07:07:20.518

ksqgtl *** TM-0000ef6b-00000000 mode=2 flags=0x401 timeout=21474836 ***

ksqgtl: xcb=0x0x40619e88, ktcdix=2147483647, topxcb=0x0x40619e88

        ktcipt(topxcb)=0x0

*** 2007-02-14 07:07:20.518

ksucti: init session DID from txn DID: 0001-0012-000003B2

ksqgtl:

        ksqlkdid: 0001-0012-000003B2

*** 2007-02-14 07:07:20.518

*** ksudidTrace: ksqgtl

        ktcmydid(): 0001-0012-000003B2

        ksusesdi:   0000-0000-00000000

        ksusetxn:   0001-0012-000003B2

*** 2007-02-14 07:07:20.518

ksqcmi: TM,ef6b,0 mode=2 timeout=21474836

ksqcmi: returns 0

ksqgtl: RETURNS 0

BINDS #4:

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

*** 2007-02-14 07:07:20.521

ksqgtl *** TX-00060025-00000f28 mode=6 flags=0x401 timeout=0 ***

ksqgtl: xcb=0x0x4060e3c8, ktcdix=2147483647, topxcb=0x0x40619e88

        ktcipt(topxcb)=0x0

*** 2007-02-14 07:07:20.521

ksucti: init session DID from txn DID: 0001-0012-000003B2

ksqgtl:

        ksqlkdid: 0001-0012-000003B2

*** 2011-02-14 07:07:20.521

*** ksudidTrace: ksqgtl

        ktcmydid(): 0001-0012-000003B2

        ksusesdi:   0000-0000-00000000

        ksusetxn:   0001-0012-000003B2

ksqgtl: RETURNS 0

EXEC #2:c=2000,e=1663,p=0,cr=2,cu=2,mis=0,r=1,dep=1,og=4,tim=1267225039571657

STAT #2 id=1 cnt=0 pid=0 pos=1 obj=0 op='UPDATE  OBJ$ (cr=2 pr=0 pw=0 time=465 us)'

STAT #2 id=2 cnt=1 pid=1 pos=1 obj=37 op='INDEX RANGE SCAN I_OBJ2 (cr=2 pr=0 pw=0 time=114 us)'

*** 2007-02-14 07:07:20.521

ksqrcl: TX,60025,f28

ksqrcl: returns 0

*** 2007-02-14 07:07:20.521

ksqrcl: TM,12,0

ksqrcl: returns 0

*** 2007-02-14 07:07:20.521

ksqgtl *** TT-00000000-00000000 mode=4 flags=0x411 timeout=21474836 ***

ksqgtl: xcb=0x0x4061a3a4, ktcdix=2147483647, topxcb=0x0x40619e88

        ktcipt(topxcb)=0x0

*** 2007-02-14 07:07:20.521

ksucti: init txn DID from session DID 0001-0012-000003B2

ksqgtl:

        ksqlkdid: 0001-0012-000003B2

*** 2011-02-14 07:07:20.521

*** ksudidTrace: ksqgtl

        ktcmydid(): 0001-0012-000003B2

        ksusesdi:   0000-0000-00000000

        ksusetxn:   0001-0012-000003B2

ksqgtl: RETURNS 0

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

总结一下Alter Index Online的过程

1.         创建日志表

2.         首先获得表的行级共享锁mode=2 SS(Row-S)

3.         XXD_T_PK申请了 Mode=6的锁,这时禁止对碎银进行DDL操作

4.         Alter Index Online发生后,此时请求表的mode=4 Share

5.         这时索引排序,伴随着异步IO kfk: async disk IO,并行写入Temp(direct path write temp),读Tempdirect path read temp),创建索引,写入索引段,索引段扩展(enq: HW - contention),最后这些结束后,写入索引(direct path write),更新数据字典(update ind$),跟新索引段信息(update seg$)

再总结下其他操作的,这里例子就不给出了

Truncate Table T;

mode=6 exclusive (X)

Create index

Create Index idx_test on T;

mode=4的会阻塞mode=3的请求所以create index会阻塞dml操作

对比create indexcreate index online的区别

Alter Index Online 加的是DDL锁,没有Online关键词加的是DDLDML

create index online 加的是mode=2 (RS),所以不会阻塞mode=3(RX)RX锁,所以不会阻挡DML。但是会阻塞大部分的DDL加在表上的X类型的TM

create index:加的是mode=4(S)TM会阻塞DML语句加在表上面的类型为RXTM锁。这时,表锁都被阻塞,那么行锁更是不可能加载的。

Related Post

N/A

--EOF--

转载于:https://www.cnblogs.com/buro79xxd/archive/2011/03/15/1984831.html


最新回复(0)