ITPub博客

首页 > Linux操作系统 > Linux操作系统 > 并行dml操作所需的TM锁

并行dml操作所需的TM锁

原创 Linux操作系统 作者:redhouser 时间:2012-02-06 17:06:58 0 删除 编辑

目的:
跟踪分析并行查询,并行更新时获取锁情况,结论如下:
(1)并行查询不请求表上的TM锁,同时执行的更新操作不影响并行查询的执行计划;
(2)在会话不启用并行dml时,使用并行更新提示的sql中只有查询部分使用并行,获取mode=3的TM锁;
(3)在会话启用并行dml时,并行dml会请求mode=6的TM锁(会与非并行更新mode=3的锁请求冲突),直至更新结束

0,版本
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - Production
With the Partitioning, OLAP and Data Mining options
ORACLE_HOME = /oracle/10g
System name: Linux
Node name: rhel5
Release: 2.6.18-8.el5xen
Version: #1 SMP Thu Mar 15 21:02:53 EDT 2007
Machine: i686
Instance name: ora10ctg

1,测试表
select * from t
drop table t;
create table t
as
select object_id rn from dba_objects;

begin
  dbms_stats.gather_table_stats(ownname => user,tabname => 't',degree => 8);
end;
/


SQL> select * from user_objects where object_name='T';
OBJECT_NAME   OBJECT_ID DATA_OBJECT_ID OBJECT_TYPE        
------------ ---------- -------------- -------------------
T                 63275          63275 TABLE              
SQL> select to_char(63275,'XXXXXX') from dual;
TO_CHAR(63275,'XXXXXX')
-----------------------
   F72B

2,使用工具,在会话内启用sql/enqueue事件跟踪
alter session set events '10704 trace name context forever,level 10';
alter session set events '10046 trace name context forever,level 12'; 

3,并行查询
3.1并行查询
select /*+ parallel(t1 4) */ count(*) from t t1;

--session跟踪文件分析:
====================================================
递归查询/更新了ORA_TQ_BASE$序列

获取锁:
PS:请求mode=6->转换为mode=4->update->转换为mode=6->释放
PR:请求mode=6->释放->update

等待事件:
WAIT #1: nam='PX Deq: Join ACK'
WAIT #1: nam='PX qref latch'
WAIT #1: nam='PX Deq: Execute Reply'
WAIT #1: nam='enq: PS - contention'

执行计划中包含:
SORT AGGREGATE (cr=3 pr=0 pw=0 time=172437 us)
  PX COORDINATOR  (cr=3 pr=0 pw=0 time=171106 us)
    PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
      SORT AGGREGATE (cr=0 pr=0 pw=0 time=0 us)
        PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)
          TABLE ACCESS FULL T (cr=0 pr=0 pw=0 time=0 us)

3.2在更新同时并行查询
--session 1
update t t4 set rn=2 where rownum<10;

--session 2
select 0 from dual t41;

select /*+ parallel(t4 4) */ count(*) from t t4;

select 0 from dual t42;

--session 1
commit;

--session 2跟踪文件分析:
====================================================
递归查询/更新了ORA_TQ_BASE$序列

获取锁:
PS:请求mode=6->转换为mode=4->update->转换为mode=6->释放

等待事件:
WAIT #1: nam='PX Deq: Join ACK'
WAIT #1: nam='PX Deq: Execute Reply'

执行计划中包含:
SORT AGGREGATE (cr=3 pr=0 pw=0 time=23168 us)
  PX COORDINATOR  (cr=3 pr=0 pw=0 time=22470 us)
    PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
      SORT AGGREGATE (cr=0 pr=0 pw=0 time=0 us)
        PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)
          TABLE ACCESS FULL T (cr=0 pr=0 pw=0 time=0 us)

4,并行更新
4.1会话没有启用并行dml,并行更新
select 0 from dual t21;

update /*+ parallel(t2 4) */ t t2 set rn=1;
commit;

select 0 from dual t22;

--session跟踪文件分析:
====================================================
递归查询/更新了ORA_TQ_BASE$序列

获取锁:
TM:请求mode=3->update->释放
PS:请求mode=6->转换为mode=4->update->转换为mode=6->释放

等待事件:
WAIT #4: nam='PX Deq: Join ACK'
WAIT #4: nam='PX qref latch'
WAIT #4: nam='PX Deq: Execute Reply'

执行计划中包含:
UPDATE  T (cr=28 pr=0 pw=0 time=10663796 us)
  PX COORDINATOR  (cr=3 pr=0 pw=0 time=314492 us)
    PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
      PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)
        TABLE ACCESS FULL T (cr=0 pr=0 pw=0 time=0 us)
==>由于会话没有启用dml并行,只有查询部分使用了并行

4.2 会话启用并行dml,并行更新
alter session enable parallel dml;
update /*+ parallel(t3 4) */ t t3 set rn=1;
commit;
alter session disable parallel dml;

--session跟踪文件分析:
====================================================
递归查询/更新了ORA_TQ_BASE$序列

获取锁:
TM:请求mode=6->update->释放
PS:请求mode=6->转换为mode=4->update->转换为mode=6->释放

等待事件:
WAIT #1: nam='PX Deq: Join ACK'
WAIT #1: nam='PX Deq: Execute Reply'

执行计划中包含:
PX COORDINATOR  (cr=6 pr=0 pw=0 time=4741864 us)
  PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
    UPDATE  T (cr=0 pr=0 pw=0 time=0 us)
      PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)
        TABLE ACCESS FULL T (cr=0 pr=0 pw=0 time=0 us)


4.3 会话启用并行dml,并行更新,被阻塞
--session 1
update t t5 set rn=2 where rn=2;

--session 2
alter session enable parallel dml;
update /*+ parallel(t5 4) */ t t5 set rn=1 where rn=1;

--blocked:request mode=6 TM lock,blocked by mode=3 TM lock;

--session 1
commit;

--session 2
commit;
alter session disable parallel dml;

--session 2跟踪文件分析:
====================================================
递归查询/更新了ORA_TQ_BASE$序列

获取锁:
TM:请求mode=6->被阻塞->阻塞会话提交后获取mode=6的锁->update->释放,等待期间有等待事件:'enq: TM - contention'
PS:请求mode=6->转换为mode=4->update->转换为mode=6->释放

等待事件:
WAIT #1: nam='PX Deq: Join ACK'
WAIT #1: nam='PX Deq: Execute Reply'
WAIT #1: nam='enq: PS - contention'

执行计划中包含:
PX COORDINATOR  (cr=6 pr=0 pw=0 time=4754763 us)
  PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)
    UPDATE  T (cr=0 pr=0 pw=0 time=0 us)
      PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)
        TABLE ACCESS FULL T (cr=0 pr=0 pw=0 time=0 us)


附录:
附录1:3.1并行查询跟踪文件(对应3.1)
====================================================
=====================
PARSING IN CURSOR #2 len=37 dep=1 uid=0 ct=3 lid=0 tim=1358526699275990 hv=2907401737 ad='5f8f4270'
SELECT ORA_TQ_BASE$.NEXTVAL FROM DUAL
END OF STMT
=====================
PARSING IN CURSOR #1 len=47 dep=0 uid=0 ct=3 lid=0 tim=1358526699283354 hv=1038421536 ad='5b67eb38'
select /*+ parallel(t1 4) */ count(*) from t t1
END OF STMT

*** 2014-01-31 09:22:20.066
ksqgtl *** PS-00000001-00000000 mode=6 flags=0x10 timeout=0 ***

*** 2014-01-31 09:22:20.066
ksqgtl *** PR-00000000-00000000 mode=6 flags=0x10 timeout=21474836 ***
*** 2014-01-31 09:22:20.101
ksqrcl: PR,0,0

WAIT #1: nam='os thread startup' ela= 33168 p1=0 p2=0 p3=0 obj#=-1 tim=1358526699317588

*** 2014-01-31 09:22:20.101
ksqcnv: PS-00000001,00000000 mode=4 timeout=0
*** 2014-01-31 09:22:20.101
ksqcmi: PS,1,0 mode=4 timeout=0

*** 2014-01-31 09:22:20.101
ksqgtl *** PS-00000001-00000001 mode=6 flags=0x10 timeout=0 ***

*** 2014-01-31 09:22:20.101
ksqgtl *** PR-00000000-00000000 mode=6 flags=0x10 timeout=21474836 ***

WAIT #1: nam='os thread startup' ela= 32884 p1=0 p2=0 p3=0 obj#=-1 tim=1358526699351473

*** 2014-01-31 09:22:20.135
ksqrcl: PR,0,0

*** 2014-01-31 09:22:20.136
ksqcnv: PS-00000001,00000001 mode=4 timeout=0
*** 2014-01-31 09:22:20.136
ksqcmi: PS,1,1 mode=4 timeout=0

*** 2014-01-31 09:22:20.136
ksqgtl *** PS-00000001-00000002 mode=6 flags=0x10 timeout=0 ***

WAIT #1: nam='os thread startup' ela= 32764 p1=0 p2=0 p3=0 obj#=-1 tim=1358526699385185

*** 2014-01-31 09:22:20.136
ksqgtl *** PR-00000000-00000000 mode=6 flags=0x10 timeout=21474836 ***
*** 2014-01-31 09:22:20.170
ksqrcl: PR,0,0

*** 2014-01-31 09:22:20.170
ksqcnv: PS-00000001,00000002 mode=4 timeout=0
*** 2014-01-31 09:22:20.170
ksqcmi: PS,1,2 mode=4 timeout=0

*** 2014-01-31 09:22:20.170
ksqgtl *** PS-00000001-00000003 mode=6 flags=0x10 timeout=0 ***

*** 2014-01-31 09:22:20.171
ksqgtl *** PR-00000000-00000000 mode=6 flags=0x10 timeout=21474836 ***
*** 2014-01-31 09:22:20.204
ksqrcl: PR,0,0

WAIT #1: nam='os thread startup' ela= 29589 p1=0 p2=0 p3=0 obj#=-1 tim=1358526699418776

*** 2014-01-31 09:22:20.205
ksqcnv: PS-00000001,00000003 mode=4 timeout=0
*** 2014-01-31 09:22:20.205
ksqcmi: PS,1,3 mode=4 timeout=0

WAIT #1: nam='PX Deq: Join ACK' ela= 2340 sleeptime/senderid=268500992 passes=1 p3=0 obj#=-1 tim=1358526699421643
...
EXEC #1:c=0,e=153280,p=0,cr=3,cu=0,mis=0,r=0,dep=0,og=1,tim=1358526699436760
WAIT #1: nam='SQL*Net message to client' ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526699436873

WAIT #1: nam='PX Deq: Execute Reply' ela= 9 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526699437033
[...重复11次]

WAIT #1: nam='PX qref latch' ela= 57 function=1 sleeptime=1605637172 qref=0 obj#=-1 tim=1358526699440279
WAIT #1: nam='PX Deq: Execute Reply' ela= 86 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526699440434
WAIT #1: nam='PX Deq: Execute Reply' ela= 4 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526699440564
WAIT #1: nam='PX Deq: Execute Reply' ela= 8 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1358526699440652
WAIT #1: nam='PX Deq: Execute Reply' ela= 432 sleeptime/senderid=200 passes=3 p3=0 obj#=-1 tim=1358526699441163
WAIT #1: nam='PX Deq: Execute Reply' ela= 3 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526699441298
WAIT #1: nam='PX Deq: Execute Reply' ela= 362 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1358526699441745
[以上7行重复11次]

WAIT #1: nam='PX qref latch' ela= 24 function=1 sleeptime=1605637172 qref=0 obj#=-1 tim=1358526699455523
WAIT #1: nam='PX Deq: Execute Reply' ela= 115 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526699455686
WAIT #1: nam='PX Deq: Signal ACK' ela= 320 sleeptime/senderid=0 passes=1 p3=0 obj#=-1 tim=1358526699456104
FETCH #1:c=8001,e=19244,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,tim=1358526699456205
WAIT #1: nam='PX Deq: Signal ACK' ela= 968 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526699457265
WAIT #1: nam='PX Deq: Signal ACK' ela= 4 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526699457458
WAIT #1: nam='PX Deq: Signal ACK' ela= 10 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1358526699457539
WAIT #1: nam='PX Deq: Signal ACK' ela= 31 sleeptime/senderid=200 passes=3 p3=0 obj#=-1 tim=1358526699457626

*** 2014-01-31 09:22:20.244
ksqcnv: PS-00000001,00000003 mode=6 timeout=10
*** 2014-01-31 09:22:20.244
ksqcmi: PS,1,3 mode=6 timeout=10
*** 2014-01-31 09:22:20.245
ksqrcl: PS,1,3

WAIT #1: nam='enq: PS - contention' ela= 196 name|mode=1347616774 instance=1 slave ID=3 obj#=-1 tim=1358526699458114
-->PS:PX Process Reservation,Parallel Execution Server Process reservation and synchronization

*** 2014-01-31 09:22:20.245
ksqcnv: PS-00000001,00000002 mode=6 timeout=10
*** 2014-01-31 09:22:20.245
ksqcmi: PS,1,2 mode=6 timeout=10
*** 2014-01-31 09:22:20.245
ksqrcl: PS,1,2

WAIT #1: nam='enq: PS - contention' ela= 347 name|mode=1347616774 instance=1 slave ID=2 obj#=-1 tim=1358526699458863

*** 2014-01-31 09:22:20.246
ksqcnv: PS-00000001,00000001 mode=6 timeout=10
*** 2014-01-31 09:22:20.246
ksqcmi: PS,1,1 mode=6 timeout=10
*** 2014-01-31 09:22:20.246
ksqrcl: PS,1,1

*** 2014-01-31 09:22:20.246
ksqcnv: PS-00000001,00000000 mode=6 timeout=10
*** 2014-01-31 09:22:20.246
ksqcmi: PS,1,0 mode=6 timeout=10
*** 2014-01-31 09:22:20.246
ksqrcl: PS,1,0

WAIT #1: nam='SQL*Net message from client' ela= 634 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526699460173

FETCH #1:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=1358526699460235
WAIT #1: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526699460282
WAIT #1: nam='SQL*Net message from client' ela= 355 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526699460721
STAT #1 id=1 cnt=1 pid=0 pos=1 bj=0 p='SORT AGGREGATE (cr=3 pr=0 pw=0 time=172437 us)'
STAT #1 id=2 cnt=4 pid=1 pos=1 bj=0 p='PX COORDINATOR  (cr=3 pr=0 pw=0 time=171106 us)'
STAT #1 id=3 cnt=0 pid=2 pos=1 bj=0 p='PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)'
STAT #1 id=4 cnt=0 pid=3 pos=1 bj=0 p='SORT AGGREGATE (cr=0 pr=0 pw=0 time=0 us)'
STAT #1 id=5 cnt=0 pid=4 pos=1 bj=0 p='PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)'
STAT #1 id=6 cnt=0 pid=5 pos=1 bj=63275 p='TABLE ACCESS FULL T (cr=0 pr=0 pw=0 time=0 us)'
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526699461109
*** 2014-01-31 09:24:14.201
WAIT #0: nam='SQL*Net message from client' ela= 111282279 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526810743431
====================================================


附录2:在更新同时并行查询跟踪文件(对应3.2)
====================================================
=====================
PARSING IN CURSOR #2 len=22 dep=0 uid=0 ct=3 lid=0 tim=1358526879471560 hv=166340928 ad='5b67dd80'
select 0 from dual t41
END OF STMT
=====================
PARSING IN CURSOR #1 len=37 dep=1 uid=0 ct=3 lid=0 tim=1358526885840791 hv=2907401737 ad='5f8f4270'
SELECT ORA_TQ_BASE$.NEXTVAL FROM DUAL
END OF STMT

=====================
PARSING IN CURSOR #4 len=47 dep=0 uid=0 ct=3 lid=0 tim=1358526885844738 hv=177403074 ad='5b67db44'
select /*+ parallel(t4 4) */ count(*) from t t4
END OF STMT

*** 2014-01-31 09:25:31.105
ksqgtl *** PS-00000001-00000000 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:25:31.105
ksqcnv: PS-00000001,00000000 mode=4 timeout=0
*** 2014-01-31 09:25:31.105
ksqcmi: PS,1,0 mode=4 timeout=0

*** 2014-01-31 09:25:31.105
ksqgtl *** PS-00000001-00000001 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:25:31.106
ksqcnv: PS-00000001,00000001 mode=4 timeout=0
*** 2014-01-31 09:25:31.106
ksqcmi: PS,1,1 mode=4 timeout=0

*** 2014-01-31 09:25:31.106
ksqgtl *** PS-00000001-00000002 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:25:31.106
ksqcnv: PS-00000001,00000002 mode=4 timeout=0
*** 2014-01-31 09:25:31.106
ksqcmi: PS,1,2 mode=4 timeout=0

*** 2014-01-31 09:25:31.106
ksqgtl *** PS-00000001-00000003 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:25:31.106
ksqcnv: PS-00000001,00000003 mode=4 timeout=0
*** 2014-01-31 09:25:31.107
ksqcmi: PS,1,3 mode=4 timeout=0

WAIT #4: nam='PX Deq: Join ACK' ela= 4 sleeptime/senderid=268500992 passes=1 p3=0 obj#=-1 tim=1358526885847533
WAIT #4: nam='PX Deq: Join ACK' ela= 246 sleeptime/senderid=268500992 passes=2 p3=0 obj#=-1 tim=1358526885847858
WAIT #4: nam='PX Deq: Join ACK' ela= 9 sleeptime/senderid=268500995 passes=1 p3=0 obj#=-1 tim=1358526885847943
WAIT #4: nam='PX Deq: Join ACK' ela= 108 sleeptime/senderid=268500995 passes=2 p3=0 obj#=-1 tim=1358526885848112
WAIT #4: nam='PX Deq: Parse Reply' ela= 2656 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526885850954
EXEC #4:c=0,e=6289,p=0,cr=3,cu=0,mis=0,r=0,dep=0,og=1,tim=1358526885851150
WAIT #4: nam='SQL*Net message to client' ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526885851240

WAIT #4: nam='PX Deq: Execute Reply' ela= 8 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526885851373
[...重复45次]

WAIT #4: nam='PX Deq: Signal ACK' ela= 136 sleeptime/senderid=0 passes=1 p3=0 obj#=-1 tim=1358526885868202
FETCH #4:c=0,e=16955,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,tim=1358526885868283
WAIT #4: nam='PX Deq: Signal ACK' ela= 8 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526885868375
WAIT #4: nam='PX Deq: Signal ACK' ela= 1256 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1358526885869707

*** 2014-01-31 09:25:31.130
ksqcnv: PS-00000001,00000003 mode=6 timeout=10
*** 2014-01-31 09:25:31.130
ksqcmi: PS,1,3 mode=6 timeout=10
*** 2014-01-31 09:25:31.130
ksqrcl: PS,1,3

*** 2014-01-31 09:25:31.130
ksqcnv: PS-00000001,00000002 mode=6 timeout=10
*** 2014-01-31 09:25:31.130
ksqcmi: PS,1,2 mode=6 timeout=10
*** 2014-01-31 09:25:31.131
ksqrcl: PS,1,2

*** 2014-01-31 09:25:31.131
ksqcnv: PS-00000001,00000001 mode=6 timeout=10
*** 2014-01-31 09:25:31.131
ksqcmi: PS,1,1 mode=6 timeout=10
*** 2014-01-31 09:25:31.131
ksqrcl: PS,1,1

*** 2014-01-31 09:25:31.131
ksqcnv: PS-00000001,00000000 mode=6 timeout=10
*** 2014-01-31 09:25:31.131
ksqcmi: PS,1,0 mode=6 timeout=10
*** 2014-01-31 09:25:31.131
ksqrcl: PS,1,0

WAIT #4: nam='SQL*Net message from client' ela= 271 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526885871061
FETCH #4:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=1358526885871117
WAIT #4: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526885871160
WAIT #4: nam='SQL*Net message from client' ela= 250 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526885871447
STAT #4 id=1 cnt=1 pid=0 pos=1 bj=0 p='SORT AGGREGATE (cr=3 pr=0 pw=0 time=23168 us)'
STAT #4 id=2 cnt=4 pid=1 pos=1 bj=0 p='PX COORDINATOR  (cr=3 pr=0 pw=0 time=22470 us)'
STAT #4 id=3 cnt=0 pid=2 pos=1 bj=0 p='PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)'
STAT #4 id=4 cnt=0 pid=3 pos=1 bj=0 p='SORT AGGREGATE (cr=0 pr=0 pw=0 time=0 us)'
STAT #4 id=5 cnt=0 pid=4 pos=1 bj=0 p='PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)'
STAT #4 id=6 cnt=0 pid=5 pos=1 bj=63275 p='TABLE ACCESS FULL T (cr=0 pr=0 pw=0 time=0 us)'
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526885871766
WAIT #0: nam='SQL*Net message from client' ela= 10938317 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526896810124

=====================
PARSING IN CURSOR #2 len=22 dep=0 uid=0 ct=3 lid=0 tim=1358526896811444 hv=1833286546 ad='5b67d908'
select 0 from dual t42
END OF STMT
====================================================

 

附录3:会话没有启用并行dml,并行更新跟踪文件(对应4.1)
====================================================
=====================
PARSING IN CURSOR #3 len=22 dep=0 uid=0 ct=3 lid=0 tim=1358526810744813 hv=2561678926 ad='5b6c4f80'
select 0 from dual t21
END OF STMT
=====================
PARSING IN CURSOR #2 len=37 dep=1 uid=0 ct=3 lid=0 tim=1358526817733252 hv=2907401737 ad='5f8f4270'
SELECT ORA_TQ_BASE$.NEXTVAL FROM DUAL
END OF STMT
=====================
PARSING IN CURSOR #4 len=42 dep=0 uid=0 ct=6 lid=0 tim=1358526817737358 hv=4265420547 ad='5b67e650'
update /*+ parallel(t2 4) */ t t2 set rn=1
END OF STMT

*** 2014-01-31 09:24:21.363
ksqgtl *** TM-0000f72b-00000000 mode=3 flags=0x401 timeout=21474836 ***

*** 2014-01-31 09:24:21.363
ksqgtl *** PS-00000001-00000000 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:24:21.364
ksqcnv: PS-00000001,00000000 mode=4 timeout=0
*** 2014-01-31 09:24:21.364
ksqcmi: PS,1,0 mode=4 timeout=0

*** 2014-01-31 09:24:21.364
ksqgtl *** PS-00000001-00000001 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:24:21.364
ksqcnv: PS-00000001,00000001 mode=4 timeout=0
*** 2014-01-31 09:24:21.364
ksqcmi: PS,1,1 mode=4 timeout=0

*** 2014-01-31 09:24:21.364
ksqgtl *** PS-00000001-00000002 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:24:21.365
ksqcnv: PS-00000001,00000002 mode=4 timeout=0
*** 2014-01-31 09:24:21.365
ksqcmi: PS,1,2 mode=4 timeout=0

*** 2014-01-31 09:24:21.365
ksqgtl *** PS-00000001-00000003 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:24:21.365
ksqcnv: PS-00000001,00000003 mode=4 timeout=0
*** 2014-01-31 09:24:21.365
ksqcmi: PS,1,3 mode=4 timeout=0

WAIT #4: nam='PX Deq: Join ACK' ela= 792 sleeptime/senderid=268500992 passes=1 p3=0 obj#=-1 tim=1358526817740997
WAIT #4: nam='PX Deq: Join ACK' ela= 134 sleeptime/senderid=268500992 passes=2 p3=0 obj#=-1 tim=1358526817741192
WAIT #4: nam='PX Deq: Join ACK' ela= 2 sleeptime/senderid=268500994 passes=1 p3=0 obj#=-1 tim=1358526817741248
WAIT #4: nam='PX Deq: Join ACK' ela= 318 sleeptime/senderid=268500994 passes=2 p3=0 obj#=-1 tim=1358526817741607
WAIT #4: nam='PX qref latch' ela= 38 function=1 sleeptime=1605636800 qref=0 obj#=-1 tim=1358526817741767
WAIT #4: nam='PX Deq: Parse Reply' ela= 6059 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526817747948
WAIT #4: nam='PX Deq: Parse Reply' ela= 48366 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526817796389
WAIT #4: nam='PX Deq: Parse Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526817796489
WAIT #4: nam='PX Deq: Parse Reply' ela= 50101 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1358526817846637
WAIT #4: nam='PX qref latch' ela= 50 function=1 sleeptime=1605636800 qref=0 obj#=-1 tim=1358526817846864
WAIT #4: nam='PX Deq: Execute Reply' ela= 100 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526817847095
WAIT #4: nam='PX Deq: Execute Reply' ela= 3 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526817847173

*** 2014-01-31 09:24:21.475
ksqgtl *** TX-00090016-00001d27 mode=6 flags=0x401 timeout=0 ***

*** 2014-01-31 09:24:23.239
ksqgtl *** TT-00000001-00000010 mode=4 flags=0x11 timeout=21474836 ***

*** 2014-01-31 09:24:23.240
ksqgtl *** HW-00000001-00800089 mode=6 flags=0x11 timeout=21474836 ***

*** 2014-01-31 09:24:23.243
ksqrcl: HW,1,800089

*** 2014-01-31 09:24:23.244
ksqrcl: TT,1,10

WAIT #4: nam='PX Deq: Execute Reply' ela= 5 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526828284679
WAIT #4: nam='PX Deq: Signal ACK' ela= 4 sleeptime/senderid=0 passes=1 p3=0 obj#=-1 tim=1358526828307208
WAIT #4: nam='PX Deq: Signal ACK' ela= 94310 sleeptime/senderid=10 passes=2 p3=0 obj#=-1 tim=1358526828401616
EXEC #4:c=10712669,e=10664227,p=0,cr=28,cu=52836,mis=0,r=51287,dep=0,og=1,tim=1358526828401711
WAIT #4: nam='PX Deq: Signal ACK' ela= 495 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526828402305
WAIT #4: nam='PX Deq: Signal ACK' ela= 138 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526828402549
WAIT #4: nam='PX Deq: Signal ACK' ela= 10 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526828402691
WAIT #4: nam='PX Deq: Signal ACK' ela= 482 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1358526828403234

*** 2014-01-31 09:24:32.285
ksqcnv: PS-00000001,00000003 mode=6 timeout=10
*** 2014-01-31 09:24:32.285
ksqcmi: PS,1,3 mode=6 timeout=10
*** 2014-01-31 09:24:32.285
ksqrcl: PS,1,3

*** 2014-01-31 09:24:32.285
ksqcnv: PS-00000001,00000002 mode=6 timeout=10
*** 2014-01-31 09:24:32.285
ksqcmi: PS,1,2 mode=6 timeout=10
*** 2014-01-31 09:24:32.285
ksqrcl: PS,1,2

*** 2014-01-31 09:24:32.285
ksqcnv: PS-00000001,00000001 mode=6 timeout=10
*** 2014-01-31 09:24:32.285
ksqcmi: PS,1,1 mode=6 timeout=10
*** 2014-01-31 09:24:32.285
ksqrcl: PS,1,1

*** 2014-01-31 09:24:32.285
ksqcnv: PS-00000001,00000000 mode=6 timeout=10
*** 2014-01-31 09:24:32.285
ksqcmi: PS,1,0 mode=6 timeout=10
*** 2014-01-31 09:24:32.285
ksqrcl: PS,1,0

WAIT #4: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526828404416
WAIT #4: nam='SQL*Net message from client' ela= 358 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526828404821
STAT #4 id=1 cnt=0 pid=0 pos=1 bj=0 p='UPDATE  T (cr=28 pr=0 pw=0 time=10663796 us)'
STAT #4 id=2 cnt=51287 pid=1 pos=1 bj=0 p='PX COORDINATOR  (cr=3 pr=0 pw=0 time=314492 us)'
STAT #4 id=3 cnt=0 pid=2 pos=1 bj=0 p='PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)'
STAT #4 id=4 cnt=0 pid=3 pos=1 bj=0 p='PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)'
STAT #4 id=5 cnt=0 pid=4 pos=1 bj=63275 p='TABLE ACCESS FULL T (cr=0 pr=0 pw=0 time=0 us)'
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526828405116
WAIT #0: nam='SQL*Net message from client' ela= 5546351 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526833951508

=====================
PARSING IN CURSOR #2 len=6 dep=0 uid=0 ct=44 lid=0 tim=1358526833951764 hv=3480936638 ad='0'
commit
END OF STMT
XCTEND rlbk=0, rd_only=0

*** 2014-01-31 09:24:37.966
ksqrcl: TX,90016,1d27

*** 2014-01-31 09:24:37.967
ksqrcl: TM,f72b,0

EXEC #2:c=0,e=418,p=0,cr=0,cu=1,mis=0,r=0,dep=0,og=0,tim=1358526833952309
WAIT #2: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526833952373
WAIT #2: nam='SQL*Net message from client' ela= 277 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526833952695
WAIT #0: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526833952789
WAIT #0: nam='SQL*Net message from client' ela= 3796603 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526837749439

=====================
PARSING IN CURSOR #3 len=22 dep=0 uid=0 ct=3 lid=0 tim=1358526837750791 hv=2677574508 ad='5b675f5c'
select 0 from dual t22
END OF STMT
====================================================


附录4:会话启用并行dml,并行更新跟踪文件(对应4.2)
====================================================
=====================
PARSING IN CURSOR #4 len=33 dep=0 uid=0 ct=42 lid=0 tim=1358526845415656 hv=659989950 ad='5f8e6d20'
alter session enable parallel dml
END OF STMT
=====================
PARSING IN CURSOR #3 len=37 dep=1 uid=0 ct=3 lid=0 tim=1358526850894528 hv=2907401737 ad='5f8f4270'
SELECT ORA_TQ_BASE$.NEXTVAL FROM DUAL
END OF STMT

=====================
PARSING IN CURSOR #2 len=42 dep=0 uid=0 ct=6 lid=0 tim=1358526850898277 hv=1192967268 ad='5b6762a8'
update /*+ parallel(t3 4) */ t t3 set rn=1
END OF STMT
PARSE #2:c=4000,e=5112,p=0,cr=1,cu=3,mis=1,r=0,dep=0,og=1,tim=1358526850898272

*** 2014-01-31 09:24:55.319
ksqgtl *** TM-0000f72b-00000000 mode=6 flags=0x401 timeout=21474836 ***

*** 2014-01-31 09:24:55.320
ksqgtl *** TX-000a0028-00001cb0 mode=6 flags=0x401 timeout=0 ***

*** 2014-01-31 09:24:55.320
ksqcnv: TM-0000f72b,00000000 mode=6 timeout=21474836
*** 2014-01-31 09:24:55.320
ksqcmi: TM,f72b,0 mode=6 timeout=21474836

*** 2014-01-31 09:24:55.321
ksqgtl *** PS-00000001-00000000 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:24:55.321
ksqcnv: PS-00000001,00000000 mode=4 timeout=0
*** 2014-01-31 09:24:55.321
ksqcmi: PS,1,0 mode=4 timeout=0

*** 2014-01-31 09:24:55.321
ksqgtl *** PS-00000001-00000001 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:24:55.322
ksqcnv: PS-00000001,00000001 mode=4 timeout=0
*** 2014-01-31 09:24:55.322
ksqcmi: PS,1,1 mode=4 timeout=0

*** 2014-01-31 09:24:55.322
ksqgtl *** PS-00000001-00000002 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:24:55.322
ksqcnv: PS-00000001,00000002 mode=4 timeout=0
*** 2014-01-31 09:24:55.322
ksqcmi: PS,1,2 mode=4 timeout=0

*** 2014-01-31 09:24:55.322
ksqgtl *** PS-00000001-00000003 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:24:55.323
ksqcnv: PS-00000001,00000003 mode=4 timeout=0
*** 2014-01-31 09:24:55.323
ksqcmi: PS,1,3 mode=4 timeout=0

WAIT #2: nam='PX Deq: Join ACK' ela= 652 sleeptime/senderid=268500992 passes=1 p3=0 obj#=-1 tim=1358526850902319
WAIT #2: nam='PX Deq: Join ACK' ela= 144 sleeptime/senderid=268500992 passes=2 p3=0 obj#=-1 tim=1358526850902545
WAIT #2: nam='PX Deq: Join ACK' ela= 7 sleeptime/senderid=268500994 passes=1 p3=0 obj#=-1 tim=1358526850902671
WAIT #2: nam='PX Deq: Join ACK' ela= 161 sleeptime/senderid=268500994 passes=2 p3=0 obj#=-1 tim=1358526850902890

*** 2014-01-31 09:24:55.324
ksucti: init session DID from txn DID: 0001-0011-00000018

WAIT #2: nam='PX Deq: Parse Reply' ela= 8097 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526850911372
WAIT #2: nam='PX Deq: Parse Reply' ela= 118 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526850911570
WAIT #2: nam='PX Deq: Parse Reply' ela= 48917 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526850960547
WAIT #2: nam='PX Deq: Parse Reply' ela= 2835 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526850963499

*** 2014-01-31 09:24:55.386
ksucti: init session DID from txn DID: 0001-0011-00000018

WAIT #2: nam='PX Deq: Execute Reply' ela= 235133 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526851199006
WAIT #2: nam='PX Deq: Execute Reply' ela= 9346 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526851208501

WAIT #2: nam='PX qref latch' ela= 36 function=1 sleeptime=1605639420 qref=0 obj#=-1 tim=1358526851208650
WAIT #2: nam='PX Deq: Execute Reply' ela= 1950 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526851210666
WAIT #2: nam='PX Deq: Execute Reply' ela= 15474 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526851226231
WAIT #2: nam='PX Deq: Execute Reply' ela= 216621 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526851442966
WAIT #2: nam='PX Deq: Execute Reply' ela= 10180 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526851453301
WAIT #2: nam='PX Deq: Execute Reply' ela= 558 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526851453958
[以上7行重复18次]

WAIT #2: nam='PX Deq: Signal ACK' ela= 190 sleeptime/senderid=0 passes=1 p3=0 obj#=-1 tim=1358526855802981
EXEC #2:c=36003,e=4904789,p=0,cr=6,cu=2,mis=0,r=51287,dep=0,og=1,tim=1358526855803191
WAIT #2: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526855803307
WAIT #2: nam='SQL*Net message from client' ela= 1249 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526855804607

STAT #2 id=1 cnt=4 pid=0 pos=1 bj=0 p='PX COORDINATOR  (cr=6 pr=0 pw=0 time=4741864 us)'
STAT #2 id=2 cnt=0 pid=1 pos=1 bj=0 p='PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)'
STAT #2 id=3 cnt=0 pid=2 pos=1 bj=0 p='UPDATE  T (cr=0 pr=0 pw=0 time=0 us)'
STAT #2 id=4 cnt=0 pid=3 pos=1 bj=0 p='PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)'
STAT #2 id=5 cnt=0 pid=4 pos=1 bj=63275 p='TABLE ACCESS FULL T (cr=0 pr=0 pw=0 time=0 us)'

WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526855804935
WAIT #0: nam='SQL*Net message from client' ela= 5489977 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526861294955

*** 2014-01-31 09:25:05.966
PARSE #4:c=0,e=15,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=1358526861295112
XCTEND rlbk=0, rd_only=1
WAIT #4: nam='PX Deq: Execute Reply' ela= 989 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526861296383
WAIT #4: nam='PX Deq: Execute Reply' ela= 77 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526861296529
WAIT #4: nam='PX Deq: Execute Reply' ela= 48 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526861296631

*** 2014-01-31 09:25:05.967
ksqrcl: TX,a0028,1cb0
ksqrcl: returns 0

WAIT #4: nam='log file sync' ela= 3 buffer#=5744 p2=0 p3=0 obj#=-1 tim=1358526861296827
WAIT #4: nam='log file sync' ela= 111 buffer#=5744 p2=0 p3=0 obj#=-1 tim=1358526861296979
WAIT #4: nam='PX Deq: Execute Reply' ela= 749 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526861297816
WAIT #4: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526861297902
WAIT #4: nam='PX Deq: Execute Reply' ela= 2 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526861297953
WAIT #4: nam='PX Deq: Execute Reply' ela= 53 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1358526861298046

*** 2014-01-31 09:25:05.969
ksqrcl: TM,f72b,0
ksqrcl: returns 0

WAIT #4: nam='PX Deq: Signal ACK' ela= 637 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526861298908
WAIT #4: nam='latch free' ela= 51 address=536943924 number=271 tries=1 obj#=-1 tim=1358526861299449

*** 2014-01-31 09:25:05.970
ksqcnv: PS-00000001,00000003 mode=6 timeout=10
*** 2014-01-31 09:25:05.970
ksqcmi: PS,1,3 mode=6 timeout=10
*** 2014-01-31 09:25:05.970
ksqrcl: PS,1,3

*** 2014-01-31 09:25:05.971
ksqcnv: PS-00000001,00000002 mode=6 timeout=10
*** 2014-01-31 09:25:05.971
ksqcmi: PS,1,2 mode=6 timeout=10
*** 2014-01-31 09:25:05.971
ksqrcl: PS,1,2

WAIT #4: nam='enq: PS - contention' ela= 2 name|mode=1347616774 instance=1 slave ID=2 obj#=-1 tim=1358526861299931
WAIT #4: nam='enq: PS - contention' ela= 23 name|mode=1347616774 instance=1 slave ID=2 obj#=-1 tim=1358526861299991
WAIT #4: nam='enq: PS - contention' ela= 316 name|mode=1347616774 instance=1 slave ID=2 obj#=-1 tim=1358526861300343

*** 2014-01-31 09:25:05.971
ksqcnv: PS-00000001,00000001 mode=6 timeout=10
*** 2014-01-31 09:25:05.971
ksqcmi: PS,1,1 mode=6 timeout=10
*** 2014-01-31 09:25:05.971
ksqrcl: PS,1,1

*** 2014-01-31 09:25:05.971
ksqcnv: PS-00000001,00000000 mode=6 timeout=10
*** 2014-01-31 09:25:05.971
ksqcmi: PS,1,0 mode=6 timeout=10
*** 2014-01-31 09:25:05.972
ksqrcl: PS,1,0

EXEC #4:c=4000,e=5810,p=0,cr=345,cu=52865,mis=0,r=0,dep=0,og=0,tim=1358526861300961
WAIT #4: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526861301023
WAIT #4: nam='SQL*Net message from client' ela= 347 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526861301416
WAIT #0: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526861301504
WAIT #0: nam='SQL*Net message from client' ela= 4236300 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526865537902

=====================
PARSING IN CURSOR #1 len=34 dep=0 uid=0 ct=42 lid=0 tim=1358526865538463 hv=745144456 ad='5f8e2a80'
alter session disable parallel dml
END OF STMT
====================================================


附录5:会话启用并行dml,并行更新,被阻塞跟踪文件(对应4.3)
====================================================
=====================
PARSING IN CURSOR #1 len=33 dep=0 uid=0 ct=42 lid=0 tim=1358526941370166 hv=659989950 ad='5f8e6d20'
alter session enable parallel dml
END OF STMT
=====================
PARSING IN CURSOR #2 len=37 dep=1 uid=0 ct=3 lid=0 tim=1358526941386911 hv=2907401737 ad='5f8f4270'
SELECT ORA_TQ_BASE$.NEXTVAL FROM DUAL
END OF STMT
=====================
PARSING IN CURSOR #4 len=53 dep=0 uid=0 ct=6 lid=0 tim=1358526941390827 hv=1783015312 ad='5b67d254'
update /*+ parallel(t5 4) */ t t5 set rn=1 where rn=1
END OF STMT

*** 2014-01-31 09:26:27.984
ksqgtl *** TM-0000f72b-00000000 mode=6 flags=0x401 timeout=21474836 ***
ksqgtl: xcb=0x0x5ef81da0, ktcdix=2147483647, topxcb=0x0x5ef81da0
 ktcipt(topxcb)=0x0
*** 2014-01-31 09:26:27.984
ksucti: init txn DID from session DID 0001-0011-00000018
ksqgtl:
 ksqlkdid: 0001-0011-00000018
*** 2014-01-31 09:26:27.984
*** ksudidTrace: ksqgtl
 ktcmydid(): 0001-0011-00000018
 ksusesdi:   0000-0000-00000000
 ksusetxn:   0001-0011-00000018
-->被阻塞

*** 2014-01-31 09:26:27.984
ksqcmi: TM,f72b,0 mode=6 timeout=21474836
WAIT #4: nam='enq: TM - contention' ela= 9 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526941391344
WAIT #4: nam='enq: TM - contention' ela= 2951098 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526944342493
WAIT #4: nam='enq: TM - contention' ela= 2929727 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526947272354
WAIT #4: nam='enq: TM - contention' ela= 2929780 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526950202227

*** 2014-01-31 09:26:40.007
WAIT #4: nam='enq: TM - contention' ela= 2929814 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526953132124
WAIT #4: nam='enq: TM - contention' ela= 2929705 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526956061960
WAIT #4: nam='enq: TM - contention' ela= 2929781 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526958991825
WAIT #4: nam='enq: TM - contention' ela= 2929777 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526961921701

*** 2014-01-31 09:26:52.008
WAIT #4: nam='enq: TM - contention' ela= 2929790 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526964851567
WAIT #4: nam='enq: TM - contention' ela= 2929739 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526967781416
WAIT #4: nam='enq: TM - contention' ela= 2929787 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526970711294
WAIT #4: nam='enq: TM - contention' ela= 2929784 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526973641159

*** 2014-01-31 09:27:04.008
WAIT #4: nam='enq: TM - contention' ela= 2929773 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526976571037
WAIT #4: nam='enq: TM - contention' ela= 2929747 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526979500899
WAIT #4: nam='enq: TM - contention' ela= 1666627 name|mode=1414332422 object #=63275 table/partition=0 obj#=-1 tim=1358526981167618
ksqcmi: returns 0
ksqgtl: RETURNS 0

*** 2014-01-31 09:27:08.715
ksqgtl *** TX-0005002d-00001c7a mode=6 flags=0x401 timeout=0 ***

*** 2014-01-31 09:27:08.716
ksqcnv: TM-0000f72b,00000000 mode=6 timeout=21474836
*** 2014-01-31 09:27:08.716
ksqcmi: TM,f72b,0 mode=6 timeout=21474836
ksqcmi: returns 0
ksqcnv: RETURNS 0

*** 2014-01-31 09:27:08.716
ksqgtl *** PS-00000001-00000000 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:27:08.716
ksqcnv: PS-00000001,00000000 mode=4 timeout=0
*** 2014-01-31 09:27:08.717
ksqcmi: PS,1,0 mode=4 timeout=0

*** 2014-01-31 09:27:08.717
ksqgtl *** PS-00000001-00000001 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:27:08.717
ksqcnv: PS-00000001,00000001 mode=4 timeout=0
*** 2014-01-31 09:27:08.717
ksqcmi: PS,1,1 mode=4 timeout=0

*** 2014-01-31 09:27:08.717
ksqgtl *** PS-00000001-00000002 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:27:08.718
ksqcnv: PS-00000001,00000002 mode=4 timeout=0
*** 2014-01-31 09:27:08.718
ksqcmi: PS,1,2 mode=4 timeout=0

*** 2014-01-31 09:27:08.718
ksqgtl *** PS-00000001-00000003 mode=6 flags=0x10 timeout=0 ***
*** 2014-01-31 09:27:08.718
ksqcnv: PS-00000001,00000003 mode=4 timeout=0
*** 2014-01-31 09:27:08.718
ksqcmi: PS,1,3 mode=4 timeout=0

WAIT #4: nam='PX Deq: Join ACK' ela= 1140 sleeptime/senderid=268500992 passes=1 p3=0 obj#=-1 tim=1358526981171883
WAIT #4: nam='PX Deq: Parse Reply' ela= 4 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526981172168
WAIT #4: nam='PX Deq: Parse Reply' ela= 7815 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1358526981180032

WAIT #4: nam='PX qref latch' ela= 35 function=1 sleeptime=1605637932 qref=0 obj#=-1 tim=1358526981604958
WAIT #4: nam='PX Deq: Execute Reply' ela= 59818 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526981664846
WAIT #4: nam='PX Deq: Execute Reply' ela= 48436 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526981713377
WAIT #4: nam='PX Deq: Execute Reply' ela= 23108 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526981736607
WAIT #4: nam='PX Deq: Execute Reply' ela= 110746 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526981847469
[以行5行重复18次]

WAIT #4: nam='PX Deq: Signal ACK' ela= 138 sleeptime/senderid=0 passes=1 p3=0 obj#=-1 tim=1358526985954004
EXEC #4:c=20002,e=44563142,p=0,cr=6,cu=2,mis=0,r=51278,dep=0,og=1,tim=1358526985954094
WAIT #4: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526985954203
WAIT #4: nam='SQL*Net message from client' ela= 3407 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526985957666

STAT #4 id=1 cnt=4 pid=0 pos=1 bj=0 p='PX COORDINATOR  (cr=6 pr=0 pw=0 time=4754763 us)'
STAT #4 id=2 cnt=0 pid=1 pos=1 bj=0 p='PX SEND QC (RANDOM) :TQ10000 (cr=0 pr=0 pw=0 time=0 us)'
STAT #4 id=3 cnt=0 pid=2 pos=1 bj=0 p='UPDATE  T (cr=0 pr=0 pw=0 time=0 us)'
STAT #4 id=4 cnt=0 pid=3 pos=1 bj=0 p='PX BLOCK ITERATOR (cr=0 pr=0 pw=0 time=0 us)'
STAT #4 id=5 cnt=0 pid=4 pos=1 bj=63275 p='TABLE ACCESS FULL T (cr=0 pr=0 pw=0 time=0 us)'
WAIT #0: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526985958057
WAIT #0: nam='SQL*Net message from client' ela= 242 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526985958336

--parsing in #1 commit;-->没有找到对应cursor
PARSE #1:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=1358526985958416
XCTEND rlbk=0, rd_only=1
WAIT #1: nam='PX Deq: Execute Reply' ela= 9241 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526985967942
WAIT #1: nam='PX Deq: Execute Reply' ela= 3 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526985968042
WAIT #1: nam='PX Deq: Execute Reply' ela= 5 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1358526985968089
WAIT #1: nam='PX Deq: Execute Reply' ela= 46 sleeptime/senderid=200 passes=3 p3=0 obj#=-1 tim=1358526985968175

*** 2014-01-31 09:27:13.631
ksqrcl: TX,5002d,1c7a
ksqrcl: returns 0

WAIT #1: nam='log file sync' ela= 122 buffer#=6656 p2=0 p3=0 obj#=-1 tim=1358526985968533
WAIT #1: nam='PX Deq: Execute Reply' ela= 825 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526985969467

*** 2014-01-31 09:27:13.632
ksqrcl: TM,f72b,0

WAIT #1: nam='PX Deq: Signal ACK' ela= 4 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526985969747
WAIT #1: nam='PX Deq: Signal ACK' ela= 8 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1358526985969832
WAIT #1: nam='PX Deq: Signal ACK' ela= 479 sleeptime/senderid=200 passes=3 p3=0 obj#=-1 tim=1358526985970372
WAIT #1: nam='PX Deq: Signal ACK' ela= 7 sleeptime/senderid=200 passes=1 p3=0 obj#=-1 tim=1358526985970531
WAIT #1: nam='PX Deq: Signal ACK' ela= 140 sleeptime/senderid=200 passes=2 p3=0 obj#=-1 tim=1358526985970727

*** 2014-01-31 09:27:13.634
ksqcnv: PS-00000001,00000003 mode=6 timeout=10
*** 2014-01-31 09:27:13.634
ksqcmi: PS,1,3 mode=6 timeout=10
*** 2014-01-31 09:27:13.634
ksqrcl: PS,1,3

*** 2014-01-31 09:27:13.634
ksqcnv: PS-00000001,00000002 mode=6 timeout=10
*** 2014-01-31 09:27:13.634
ksqcmi: PS,1,2 mode=6 timeout=10
*** 2014-01-31 09:27:13.634
ksqrcl: PS,1,2

*** 2014-01-31 09:27:13.634
ksqcnv: PS-00000001,00000001 mode=6 timeout=10
*** 2014-01-31 09:27:13.634
ksqcmi: PS,1,1 mode=6 timeout=10
*** 2014-01-31 09:27:13.635
ksqrcl: PS,1,1

WAIT #1: nam='enq: PS - contention' ela= 329 name|mode=1347616774 instance=1 slave ID=1 obj#=-1 tim=1358526985971761

*** 2014-01-31 09:27:13.635
ksqcnv: PS-00000001,00000000 mode=6 timeout=10
*** 2014-01-31 09:27:13.635
ksqcmi: PS,1,0 mode=6 timeout=10
*** 2014-01-31 09:27:13.635
ksqrcl: PS,1,0

EXEC #1:c=0,e=13748,p=0,cr=332,cu=52838,mis=0,r=0,dep=0,og=0,tim=1358526985972204
WAIT #1: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526985972269
WAIT #1: nam='SQL*Net message from client' ela= 315 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526985972630
WAIT #0: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526985972711
WAIT #0: nam='SQL*Net message from client' ela= 249 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1358526985972996

=====================
PARSING IN CURSOR #3 len=34 dep=0 uid=0 ct=42 lid=0 tim=1358526985973118 hv=745144456 ad='5f8e2a80'
alter session disable parallel dml
END OF STMT
====================================================

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

下一篇: dbms_system
请登录后发表评论 登录
全部评论

注册时间:2011-05-26

  • 博文量
    211
  • 访问量
    804295