enq: TM – contention 实验

下面是测试在不同版本,在主表与子表上进行DML操作时,在主表与子表分别获取TM锁的情况。主键存在的表称为主表,外键存在的表称为子表。分别测试了9i,10g,11g三个测试的情况。

 

创建对象

所有的对象都创建在HTZ用户下,需要在3个版本的数据库都创建。

drop user htz cascade;

create user htz identified by oracle;

grant dba to htz;

create table htz.htz as select * from dba_objects where object_id is not null and data_object_id is not null and object_id<100;

create table htz.htz1 as select * from dba_objects where object_id is not null and data_object_id is not null and object_id<1000;

alter table htz.htz1 add constraint pk_htz1 primary key(object_id)

alter table htz add constraint fk_htz1 foreign key(object_id) references htz1(object_id);

查询对象的object_id,在整个实验过程中会用到

orcl1123.htz.pw > select object_name,to_char(object_id,'xxxxxxxxxx') from dba_objects where object_name in ('HTZ','HTZ1');

OBJECT_NAME          TO_CHAR(OBJ

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

HTZ1                       127d0

HTZ                        127cf

orcl9208.htz.pw > select object_name,to_char(object_id,'xxxxxxxxxx') from dba_objects where object_name in ('HTZ','HTZ1');

OBJECT_NAME          TO_CHAR(OBJ

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

HTZ                         764f

HTZ1                        7650

orcl1024.htz.pw > col object_name for a20

orcl1024.htz.pw > select object_name,to_char(object_id,'xxxxxxxxxx') from dba_objects where object_name in ('HTZ','HTZ1');

OBJECT_NAME          TO_CHAR(OBJ

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

HTZ1                        ca5f

HTZ                         ca5e

测试子表有索引,但是外键不在索引第一列

窗口一:

create index ind_htz on htz(data_object_id,object_id);

窗口二:

手动在子表上获取TM3级别的锁,需要在3个数据库中同时执行。

lock table htz.htz  in row exclusive mode nowait;

查询数据库锁模式

orcl1123.htz.pw > select sid,type,id1,id2,lmode,request from v$lock where type='TM';

       SID TY        ID1        ID2      LMODE    REQUEST

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

        31 TM      75727          0          3          0

orcl1024.htz.pw > select sid,type,id1,id2,lmode,request from v$lock where type='TM';

       SID TY        ID1        ID2      LMODE    REQUEST

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

       145 TM      51806          0          3          0

orcl9208.htz.pw > select sid,type,id1,id2,lmode,request from v$lock where type='TM';

       SID TY        ID1        ID2      LMODE    REQUEST

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

        10 TM      30287          0          3          0

可以看到都占用了3级别的TM

窗口一:

conn / as sysdba

oradebug setmypid

oradebug event 10704 trace name context forever,level 12;

oradebug tracefile_name;

delete htz.htz1 where object_id=652;

三个版本的delete语句都被HANG了。

查看一下TRACE文件中的锁获取情况

[root@orcl1123 # ]grep "TM" /oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_15543.trc

ksqgtl *** TM-000127cf-00000000 mode=4 flags=0x401 timeout=21474836 ***在HTZ上面获取4级别的锁

ksqcmi: TM,127cf,0 mode=4 timeout=21474836

[root@orcl1024 # ]grep 'TM' /oracle/app/oracle/admin/orcl1024/udump/orcl1024_ora_15600.trc

ksqgtl *** TM-0000ca5e-00000000 mode=4 flags=0x401 timeout=21474836 ***在HTZ上面获取4级别的锁

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

[root@orcl9208 # ]grep "TM" orcl9208_ora_15596.trc

ksqcmi: TM,764f,0 mode=4 timeout=21474836 ****在HTZ上面获取4级别的锁

在三个版本中,在子表上面都去申请TM 4的级

退出窗口二,窗口一中的delete正常执行,再次查看锁获取情况

[root@orcl1123 # ]grep "TM" /oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_15543.trc

ksqgtl *** TM-000127cf-00000000 mode=4 flags=0x401 timeout=21474836 ***

ksqcmi: TM,127cf,0 mode=4 timeout=21474836

ksqrcl: TM,127cf,0

ksqcmi: TM,127cf,0 mode=0 timeout=0

ksqgtl *** TM-000127d0-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqgtl *** TM-000127cf-00000000 mode=4 flags=0x401 timeout=21474836 ***

ksqrcl: TM,127cf,0

ksqcmi: TM,127cf,0 mode=0 timeout=0

 

[root@orcl1024 # ]grep 'TM' /oracle/app/oracle/admin/orcl1024/udump/orcl1024_ora_15600.trc

ksqgtl *** TM-0000ca5e-00000000 mode=4 flags=0x401 timeout=21474836 ***

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

ksqrcl: TM,ca5e,0

ksqcmi: TM,ca5e,0 mode=0 timeout=0

ksqgtl *** TM-0000ca5f-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqgtl *** TM-0000ca5e-00000000 mode=4 flags=0x401 timeout=21474836 ***

ksqrcl: TM,ca5e,0

ksqcmi: TM,ca5e,0 mode=0 timeout=0

 

[root@orcl9208 # ]grep "TM" orcl9208_ora_15596.trc

ksqcmi: TM,764f,0 mode=4 timeout=21474836

ksqcmi: TM,764f,0 mode=0 timeout=0

ksqcmi: TM,764f,0 mode=0 timeout=0

可以看到在子表外键列不在索引第一列时:DELETE主表记录获取锁为:子表申请TM 4,成功后释放,在主表申请TM3,再子表申请TM 4DELETE成功后释放表TM 4锁,在COMMIT后释放主表的TM 3的锁。

测试子表外键列有索引,并在第一列

会话二:

 create index htz.ind_htz on htz.htz(object_id,data_object_id);

会话一

oradebug setmypid

oradebug event 10704 trace name context forever,level 12;

oradebug tracefile_name;

delete htz.htz1 where object_id=651;

3个数据库都正常的执行

 

orcl1123.htz.pw > oradebug setmypid

Statement processed.

orcl1123.htz.pw > oradebug event 10704 trace name context forever,level 12;

Statement processed.

orcl1123.htz.pw > oradebug tracefile_name;

/oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_18403.trc

orcl1123.htz.pw > delete htz.htz1 where object_id=651;

 

1 row deleted.

 

[root@orcl1123 #]grep "TM" /oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_18403.trc

ksqgtl *** TM-000127cf-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqgtl *** TM-000127d0-00000000 mode=3 flags=0x401 timeout=21474836 ***

[root@orcl9208 # ]grep "TM" /oracle/app/oracle/admin/orcl9208/udump/orcl9208_ora_18406.trc

ksqcmi: TM,764f,0 mode=2 timeout=2147483

[root@orcl1024 # ]grep 'TM' /oracle/app/oracle/admin/orcl1024/udump/orcl1024_ora_18492.trc

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

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

ksqgtl *** TM-0000ca5f-00000000 mode=3 flags=0x401 timeout=21474836 ***

查询锁的情况

orcl1123.htz.pw > select sid,type,id1,id2,lmode,request from v$lock where type='TM';

       SID TY        ID1        ID2      LMODE    REQUEST

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

         1 TM      75727          0          3          0

         1 TM      75728          0          3          0

        27 TM      75727          0          3          0

orcl9208.htz.pw > select sid,type,id1,id2,lmode,request from v$lock where type='TM';

       SID TY        ID1        ID2      LMODE    REQUEST

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

         9 TM      30287          0          2          0

         9 TM      30288          0          3          0

        10 TM      30287          0          3          0

orcl1024.htz.pw > select sid,type,id1,id2,lmode,request from v$lock where type='TM';

       SID TY        ID1        ID2      LMODE    REQUEST

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

       145 TM      51806          0          3          0

       158 TM      51806          0          2          0

       158 TM      51807          0          3          0

从上面的测试可以看到:子表外键列有索引的时候,主表的DELETE操作,在子表获取TM 3的锁,10g,9iTM 2的锁,在主表获取TM 3的锁,在DELETE成功后,并没有立即释放TM锁,需要等commit后,才释放锁。

 

测试子表外键列无索引

drop index htz.ind_htz;

lock table htz.htz  in row exclusive mode nowait;

会话1

在个会话同时HANG

[root@orcl1123 #]grep 'TM' /oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_19364.trc

ksqgtl *** TM-000127cf-00000000 mode=4 flags=0x401 timeout=21474836 ***

ksqcmi: TM,127cf,0 mode=4 timeout=2147483

[root@orcl1024 # ]grep 'TM' /oracle/app/oracle/admin/orcl1024/udump/orcl1024_ora_19462.trc

ksqgtl *** TM-0000ca5e-00000000 mode=4 flags=0x401 timeout=21474836 ***

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

 

[root@orcl9208 # ]grep 'TM' orcl9208_ora_19370.trc

ksqcmi: TM,764f,0 mode=4 timeout=21474836

都获取4级别的锁

 

退出LOCK TABLE会话

[root@orcl1123 #]grep 'TM' /oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_19364.trc

ksqgtl *** TM-000127cf-00000000 mode=4 flags=0x401 timeout=21474836 ***

ksqcmi: TM,127cf,0 mode=4 timeout=21474836

ksqrcl: TM,127cf,0

ksqcmi: TM,127cf,0 mode=0 timeout=0

ksqgtl *** TM-000127d0-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqgtl *** TM-000127cf-00000000 mode=4 flags=0x401 timeout=21474836 ***

ksqrcl: TM,127cf,0

ksqcmi: TM,127cf,0 mode=0 timeout=0

 

[root@orcl9208 # ]grep 'TM' orcl9208_ora_19370.trc

ksqcmi: TM,764f,0 mode=4 timeout=21474836

ksqcmi: TM,764f,0 mode=0 timeout=0

ksqcmi: TM,764f,0 mode=0 timeout=0

 

[root@orcl1024 # ]grep 'TM' /oracle/app/oracle/admin/orcl1024/udump/orcl1024_ora_19462.trc

ksqgtl *** TM-0000ca5e-00000000 mode=4 flags=0x401 timeout=21474836 ***

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

ksqrcl: TM,ca5e,0

ksqcmi: TM,ca5e,0 mode=0 timeout=0

ksqgtl *** TM-0000ca5f-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqgtl *** TM-0000ca5e-00000000 mode=4 flags=0x401 timeout=21474836 ***

ksqrcl: TM,ca5e,0

ksqcmi: TM,ca5e,0 mode=0 timeout=0

整个测试结果跟测试1结果一样

测试子表的delete操作

oradebug setmypid

oradebug event 10704 trace name context forever,level 12;

oradebug tracefile_name;

delete htz.htz where object_id=2;

 

1 row deleted.

跟是否有索引无影响

[root@orcl1123 #]grep 'TM' /oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_20307.trc

ksqgtl *** TM-000127cf-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqgtl *** TM-000127d0-00000000 mode=3 flags=0x401 timeout=21474836 ***

 

[root@orcl9208 # ]grep 'TM' orcl9208_ora_20494.trc

ksqcmi: TM,7650,0 mode=0 timeout=0

ksqcmi: TM,764f,0 mode=0 timeout=0

 

[root@orcl1024 # ]grep 'TM' /oracle/app/oracle/admin/orcl1024/udump/orcl1024_ora_20716.trc

ksqgtl *** TM-0000ca5e-00000000 mode=3 flags=0x401 timeout=21474836 ***

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

可以看到:在子表上成功申请TM3级别的锁后,在主表上升级TM 3(11G)TM2(10g)的锁,DELETE语句执行完后,并没有释放。

6 INSERT语句

下面所有的测试只在11G版本中,没有在其它的版本中测试

insert主表

orcl1123.htz.pw > select object_name,to_char(object_id,'xxxxxxxxxx') from dba_objects where object_name in ('HTZ','HTZ1');

 

OBJECT_NAME                    TO_CHAR(OBJ

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

HTZ1                                 127e0

HTZ                                  127df

 

orcl1123.htz.pw > conn / as sysdba

Connected.

orcl1123.htz.pw > oradebug setmypid

Statement processed.

orcl1123.htz.pw > oradebug event 10704 trace name context forever,level 12;

Statement processed.

orcl1123.htz.pw > oradebug tracefile_name;

/oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_9770.trc

 

orcl1123.htz.pw > insert into htz.htz1 (object_id) values(100000);

1 row created.

orcl1123.htz.pw > commit;

Commit complete.

orcl1123.htz.pw > oradebug tracefile_name;

/oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_9770.trc

orcl1123.htz.pw > !grep 'TM' /oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_9770.trc

ksqgtl *** TM-000127df-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqgtl *** TM-000127e0-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqrcl: TM,127e0,0

ksqrcl: TM,127df,0

在子表成功申请TM 3级别锁后,在主表再升级TM 3级别的锁。

 

子表INSERT语句

orcl1123.htz.pw > oradebug setmypid

Statement processed.

orcl1123.htz.pw > oradebug event 10704 trace name context forever,level 12;

Statement processed.

orcl1123.htz.pw > oradebug tracefile_name;

/oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_9964.trc

orcl1123.htz.pw > insert into htz.htz (object_id) values(100000);

1 row created.

orcl1123.htz.pw > commit;

Commit complete.

orcl1123.htz.pw > !grep 'TM' /oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_9964.trc

ksqgtl *** TM-000127df-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqgtl *** TM-000127e0-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqrcl: TM,127e0,0

ksqrcl: TM,127df,0

在子表成功申请TM 3级别锁后,在主表再升级TM 3级别的锁。

 

8 UPDATE语句

更新主表

orcl1123.htz.pw > oradebug setmypid

Statement processed.

orcl1123.htz.pw > oradebug event 10704 trace name context forever,level 12;

Statement processed.

orcl1123.htz.pw > oradebug tracefile_name;

/oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_10491.trc

orcl1123.htz.pw > update htz.htz1 set object_id='23000' where object_id='555';

1 row updated.

orcl1123.htz.pw > commit;

 

Commit complete.

 

orcl1123.htz.pw > !grep 'TM' /oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_10491.trc

ksqgtl *** TM-000127df-00000000 mode=4 flags=0x401 timeout=21474836 ***

ksqrcl: TM,127df,0

ksqcmi: TM,127df,0 mode=0 timeout=0

ksqgtl *** TM-000127e0-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqgtl *** TM-000127df-00000000 mode=4 flags=0x401 timeout=21474836 ***

ksqrcl: TM,127df,0

ksqcmi: TM,127df,0 mode=0 timeout=0

ksqrcl: TM,127e0,0

DELETE主表一样的锁模式

非主键列

orcl1123.htz.pw > update htz.htz1 set owner='HTZ' where object_id=2;

1 row updated.

orcl1123.htz.pw > commit;

Commit complete.

orcl1123.htz.pw > !grep 'TM' /oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_11669.trc

ksqgtl *** TM-000127e0-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqrcl: TM,127e0,0

更新非主键列时,只升级主表上面的锁,子表不影响

 

子表有索引的情况

orcl1123.htz.pw > create index htz.htz_4 on htz.htz(object_id);

Index created.

orcl1123.htz.pw > update htz.htz1 set object_id=333333 where object_id=333;

1 row updated.

orcl1123.htz.pw > commit;

Commit complete.

[oracle@www.htz.pw sql]$grep  'TM' /oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_11805.trc

ksqgtl *** TM-000127df-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqgtl *** TM-000127e0-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqrcl: TM,127e0,0

ksqrcl: TM,127df,0

DELETE主表一样的锁模式

 

更新子表外键列

orcl1123.htz.pw > update htz.htz set object_id=3 where object_id=2;

1 row updated.

orcl1123.htz.pw > commit;

Commit complete.

 

 

orcl1123.htz.pw > !grep 'TM' /oracle/app/oracle/diag/rdbms/orcl1123/orcl1123/trace/orcl1123_ora_10838.trc

ksqgtl *** TM-000127df-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqgtl *** TM-000127e0-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqrcl: TM,127e0,0

ksqcmi: TM,127e0,0 mode=0 timeout=0

ksqrcl: TM,127df,0

ksqcmi: TM,127df,0 mode=0 timeout=0

ksqgtl *** TM-000127df-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqgtl *** TM-000127e0-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqrcl: TM,127e0,0

ksqrcl: TM,127df,0

在更新子表外键列中:先申请子表TM3级别的锁,再升级主表的TM3级别的锁,2个都释放,再升级2个表的TM3级别的锁。

 





1,测试环境

10.2.0.1

 

网友说delete删除表慢,其它表外键引用了此表的列。

 

创建测试环境:

TEST2ID列上创建外键,引用TEST1ID

SQL> create table scott.test1 as select rownum id,dbms_random.string('A',20) name from dual  connect by rownum<100000;

SQL> c/1/2

  1* create table scott.test2 as select rownum id,dbms_random.string('A',20) name from dual  connect by rownum<100000;

SQL> /

SQL> alter table scott.test1 add constraint pk_test1_id primary key (id);

SQL> alter table scott.test2 add constraint fk_test2_id foreign key (id) references scott.test1(id);

 

Owner        Constraint   Column                        Reference   Reference   Index      

tablename    Name         Name    Type         STATUS   Object      Constraint  Name       

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

SCOTT:TEST1  PK_TEST1_ID  ID      Primary key  ENABLED  .                       PK_TEST1_ID

SCOTT:TEST2  FK_TEST2_ID  ID      Foreign Key  ENABLED  SCOTT.TEST1 PK_TEST1_ID            

下面我们测试一下在表上直接删除数据,会报错

SQL> delete scott.test1;

delete scott.test1

*

ERROR at line 1:

ORA-02292: integrity constraint (SCOTT.FK_TEST2_ID) violated - child record found

所以这里我们先删除test2表中的内容

SQL> delete scott.test2;

 

99999 rows deleted.

 

SQL> commit;

 

Commit complete.

开始DELETE测试

SQL> oradebug setmypid

Statement processed.

SQL> oradebug event 10704 trace name context forever,level 12;

Statement processed.

SQL> delete scott.test1;

 

99999 rows deleted.

 

[oracle@orcl9i sql]$ grep "TM"  /oracle/app/oracle/admin/orcl1021/udump/orcl1021_ora_6658.trc|grep "mode=4"|grep "0000c89d"|wc -l

100000

 

这里可以看到在TEST2上面获取了10W次TM为4(共享锁,阻塞其它的DML语句),所以意思着在外键表上面做任何的DML语句都会被HANG住的。

SQL> @16to10.sql

Enter value for number16: c89d

 

                    NUMBER10

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

                       51357

 

SQL> @object_by_id.sql

 

+------------------------------------------------------------------------+

| display one object type,owner,time,status                              |

+------------------------------------------------------------------------+

 

Enter Search Object Id (i.e. 1235) : 51357

 

                                            Object          Create               Last_Ddl                         

OWNER                OBJECT_NAME            Type            Time                 Time                 STATUS      

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

SCOTT                TEST2                  TABLE           2014-02-14 09:27:29  2014-02-14 09:30:12  VALID       

 

这里发现在TEST2上面获取了10000TM4的锁。

 

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

 

 OBJECT_ID

----------

     51356

    

SQL> @10to16.sql

Enter value for number10: 51356

 

TO_CHAR('51356','XXXXXXXXXXXXXXXXXXXXXXXXXXXX

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

                                         c89c

                                        

[oracle@orcl9i sql]$ grep "0000c89c" /oracle/app/oracle/admin/orcl1021/udump/orcl1021_ora_6658.trc|wc -l

1

ksqgtl *** TM-0000c89c-00000000 mode=3 flags=0x401 timeout=21474836 ***

然而在TEST1上面只获取了一次为TM 3的锁。

下面是测试在DELETE删除的时候,后台到底在执行什么操作

SQL> select count(*) from scott.test1;

 

  COUNT(*)

----------

     99999

 

SQL> select count(*) from scott.test2;

 

  COUNT(*)

----------

         0

        

SQL> @sess_current.sql

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

USERNAME=SYS

SESSION ID=144  SERIAL#=22

AUDSID=4294967295      MODULE#=HTZ

PID=20          SPID#=7220

TRACE_FILE_LOCATION=/oracle/app/oracle/admin/orcl1021/udump/orcl1021_ora_7220.trc

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

 

PL/SQL procedure successfully completed.

 

SQL> oradebug setmypid

Statement processed.

SQL> oradebug event 10046 trace name context forever,level 12;

Statement processed.

SQL> delete  scott.test1;

 

过一会儿后,我们SUSPEND这个进程,用于观察

SQL> delete  scott.test1;

SQL> oradebug setospid 7220;

Oracle pid: 20, Unix process pid: 7220, image: oracle@orcl9i (TNS V1-V3)

SQL> oradebug suspend;

Statement processed.

 

 

SQL> select * from v$locked_object;

 

    XIDUSN    XIDSLOT     XIDSQN  OBJECT_ID SESSION_ID ORACLE_USERNAME                OS_USER_NAME                   PROCESS      LOCKED_MODE

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

         4         10        295      51356        144 SYS                            oracle                         7219                   3

        

        

        

SQL> select * from v$lock where type='TM';

 

ADDR             KADDR                   SID TY        ID1        ID2      LMODE    REQUEST      CTIME      BLOCK

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

0000000180BCFB50 0000000180BCFB78        144 TM      51356          0          3          0        102          0

 

SQL> delete  scott.test1;

 

99999 rows deleted.

这里使用/oracle/app/oracle/admin/orcl1021/udump/orcl1021_ora_7220.trc文件生成一个HTML文件来分析

d:\wendang\SkyDrive\rs2\win\tvdxtat_40beta9>tvdxtat.cmd -s yes -w yes -i orcl1021_ora_7220.trc -o  orcl1021_ora_7220.html

00:00:00 WARNING line 20 not processed

00:00:00 WARNING line 22 not processed

 

整个等待事件

Component

Total Duration [s]

%

Number of Events

Duration per Event [s]

CPU

127.681

89.891

n/a

n/a

SQL*Net message from client

13.797

9.714

4

3.449

unaccounted-for

0.314

0.221

n/a

n/a

Data file init write

0.164

0.115

24

0.007

log file switch completion

0.061

0.043

5

0.012

control file parallel write

0.017

0.012

9

0.002

db file single write

0.006

0.004

3

0.002

control file sequential read

0.000

0.000

57

0.000

rdbms ipc reply

0.000

0.000

2

0.000

db file sequential read

0.000

0.000

6

0.000

SQL*Net message to client

0.000

0.000

5

0.000

Total

 

 

 

 

这里我们看到CPU使用占有89.8%,说明整个SQL一直在运行,不停的消耗CPU

下面查看那个SQL消耗大量的CPU

CPU   overall

8 statements contributed to this event.

Statement ID

Type

Total Duration [s]

%

2

SELECT (SYS recursive)

107.219

83.974

1

DELETE

20.442

16.010

4

SELECT (SYS recursive)

0.014

0.011

5

SELECT (SYS recursive)

0.002

0.002

6

SELECT (SYS recursive)

0.002

0.002

7

SELECT (SYS recursive)

0.001

0.001

8

SELECT (SYS recursive)

0.001

0.001

9

PL/SQL

0.000

0.000

Total

 

127.681

100.000

这里我们看到是一个递归SQL消耗了84%CPU。下面查看递归SQL的消息信息,通过下面的信息可以得到,在有外键引用的表上执行DELETE删除操作的时候,每删除一条SQL都会递归去扫描外键所在的表上面是否存在行,如果不存在,删除继续,如果存在,则报错。

 

Statement 2  overall

Session ID

144.22

Service Name

SYS$USERS

Module Name

HTZ

Action Name

ACTIVE

Parsing User

0

Recursive Level

1

Parent Statement

1 

Hash Value

848510211

Text

select /*+ all_rows */ count(1) from "SCOTT"."TEST2" where "ID" = :1

Bind Variables

99999 bind variable sets were used to execute this statement. 

In the following table, only the first 100 bind variable sets are reported.

Execution

Bind

Datatype

Value

1

1

NUMBER

"1"

2

1

NUMBER

"2"

3

1

NUMBER

"3"

4

1

NUMBER

"4"

5

1

NUMBER

"5"

6

1

NUMBER

"6"

 

 

Execution Plans

Optimizer Mode

ALL_ROWS

 

Rows

Operation

99,999

SORT AGGREGATE (cr=43199568 pr=0 pw=0 time=99291202 us)

0

   TABLE ACCESS FULL TEST2 (cr=43199568 pr=0 pw=0 time=97872781 us)

Database Call Statistics with Recursive Statements

Call

Count

Misses

CPU [s]

Elapsed [s]

PIO [b]

LIO [b]

Consistent [b]

Current [b]

Rows

Parse

1

1

0.000

0.000

0

0

0

0

0

Execute

99,999

1

8.615

8.017

0

65

65

0

0

Fetch

99,999

0

98.605

98.981

0

43,199,568

43,199,568

0

99,999

Total

199,999

2

107.220

106.999

0

43,199,633

43,199,633

0

99,999

Average (per execution)

2

0

0.001

0.001

0

432

432

0

1

Average (per row)

2

0

0.001

0.001

0

432

432

0

1

Database Call Statistics without Recursive Statements

Call

Count

Misses

CPU [s]

Elapsed [s]

PIO [b]

LIO [b]

Consistent [b]

Current [b]

Rows

Parse

1

1

0.000

0.000

0

0

0

0

0

Execute

99,999

1

8.614

8.016

0

1

1

0

0

Fetch

99,999

0

98.605

98.981

0

43,199,568

43,199,568

0

99,999

Total

199,999

2

107.219

106.997

0

43,199,569

43,199,569

0

99,999

Average (per execution)

2

0

0.001

0.001

0

432

432

0

1

Average (per row)

2

0

0.001

0.001

0

432

432

0

1

Resource Usage Profile  overall current

Component

Total Duration [s]

%

Number of Events

Duration per Event [s]

CPU

107.219

99.999

n/a

n/a

recursive statements

0.001

0.001

n/a

n/a

Total

107.220

100.000

 

 

通过上面的信息,这里我们知道为什么delete会慢了,解决方案很简单,就是在外键列上面创建一个索引就解决问题。

 

下面通过创建索引来看看扫描效率的变化

SQL> oradebug setmypid

Statement processed.

SQL> create index scott.fk_test2_id on scott.test2(id);

 

Index created.

 

SQL> oradebug event 10046 trace name context forever ,level 12;

Statement processed.

SQL> set timing;

SP2-0265: timing must be set ON or OFF

SQL> set timing on

SQL> oradebug tracefile_name;

/oracle/app/oracle/admin/orcl1021/udump/orcl1021_ora_7765.trc

SQL> delete scott.test1;

 

99999 rows deleted.

 

Elapsed: 00:00:01.51

 

这里可以看到只发了1S就完成了。

 

 

下面再生成HMTL文件看一下。

Resource Usage Profile  overall current

Component

Total Duration [s]

%

Number of Events

Duration per Event [s]

SQL*Net message from client

168.207

99.134

3

56.069

CPU

1.375

0.810

n/a

n/a

unaccounted-for

0.079

0.047

n/a

n/a

log file switch completion

0.013

0.008

3

0.004

db file sequential read

0.001

0.001

21

0.000

db file scattered read

0.000

0.000

5

0.000

SQL*Net message to client

0.000

0.000

4

0.000

Total

 

 

 

 

这里看到等待事件,已经变成了SQL*NET的等待事件。在HTML中也找到不TEST2上面的任何操作了。

 

下面再看看锁的情况

SQL> oradebug eventdump session;

10046 trace name CONTEXT level 12, forever

SQL> oradebug event 10046 trace name context off;

Statement processed.

SQL> oradebug event 10704 trace name context forever,level 12;

Statement processed.

 

SQL> !rm /oracle/app/oracle/admin/orcl1021/udump/orcl1021_ora_7765.trc

SQL> oradebug close_trace

Statement processed.

SQL> oradebug flush;

Statement processed.

 

SQL> delete scott.test1;

 

99999 rows deleted.

 

Elapsed: 00:00:01.74

SQL> oradebug flush;

Statement processed.

 

 

TRACE文件中

ksqgtl *** CU-8165f880-00000001 mode=6 flags=0x10 timeout=300 ***

ksqgtl: no transaction

ksqgtl: use existing ksusetxn DID

ksqgtl:

ksqgtl *** CU-8156bcb8-00000001 mode=6 flags=0x10 timeout=300 ***

ksqgtl: no transaction

ksqgtl: use existing ksusetxn DID

ksqgtl:

ksqgtl *** TM-0000c89c-00000000 mode=3 flags=0x401 timeout=21474836 ***

ksqgtl:

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

 

这里我们可以看到在表上面有一个2级别的锁(共享表锁,不能执行DDL语句),

SQL> @table_index.sql

+----------------------------------------------------------------------------+

| DISPLAY INDEX INFO ABOUT TABLE:TABLE_NAME                                 |

+----------------------------------------------------------------------------+

Enter Search Table Owner (i.e. SCOTT|ALL(DEFAULT)) : scott

Enter Search Table Name (i.e. DEPT|DEFAULT(ALL)) : test2

Enter Search Index Name (i.e. DEPT|DEFAULT(ALL)) :

 

OWNER

TABLE_NAME                                    tablespace                                                          Dinsinct                          PAR

INDEX_NAME                                    name                 STATUS     INDEX_TYPE UNIQUENES  PCT LOG  B        Keys LEAF_BLOCKS     NUM_ROWS TI  POST COLUMNNAME

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

TEST2:FK_TEST2_ID                             USERS                VALID      NORMAL     NONUNIQUE   10 YES                                         NO     1 ID

 

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

 

 OBJECT_ID

----------

     51359

 

SQL> @10to16.sql

Enter value for number10: 51359

 

TO_CHAR('51359','XXXXXXXXXXXXXXXXXXXXXXXXXXXX

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

                                         c89f                                 

在锁文件中,没有找到任何与c89f相当的锁。


来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/30430420/viewspace-1787705/,如需转载,请注明出处,否则将追究法律责任。

转载于:http://blog.itpub.net/30430420/viewspace-1787705/

  • 0
    点赞
  • 0
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值