[20241004]为什么这么慢.txt --//家里无聊,做的一些测试,一些现象我无法解析。 1.环境: SCOTT@book01p> @ ver2 ============================== PORT_STRING : x86_64/Linux 2.4.xx VERSION : 21.0.0.0.0 BANNER : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production BANNER_FULL : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production Version 21.3.0.0.0 BANNER_LEGACY : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production CON_ID : 0 PL/SQL procedure successfully completed. 2.建立测试环境: --//GRANT EXECUTE ON SYS.DBMS_LOCK TO SCOTT; CREATE OR REPLACE FUNCTION SCOTT.sleep (seconds IN NUMBER) RETURN NUMBER AS BEGIN sys.DBMS_LOCK.sleep (seconds); RETURN seconds; END; / SCOTT@book01p> create table tx as select level a from dual connect by level<=3 ; Table created. SCOTT@book01p> create table ty as select level a from dual connect by level<=3 ; Table created. --//分析略。 3.测试: SCOTT@book01p> set timing on SCOTT@book01p> SELECT sleep(a) val FROM tx; VAL ---------- 1 2 3 Elapsed: 00:00:06.03 --//3+2+1=6秒没有问题. --//测试前大家先猜测看执行如下需要多少秒?12秒?15秒? SCOTT@book01p> @ sl all alter session set statistics_level = all; Session altered. with t1 as ( SELECT /*+ inline */ sleep(a) val FROM tx),t2 as ( SELECT /*+ inline */ sleep(a) val FROM ty) select * from t1 ,t2 WHERE t1.val = t2.val; with t1 as ( SELECT sleep(a) val FROM tx),t2 as ( SELECT sleep(a) val FROM ty) select * from t1 ,t2 WHERE t1.val = t2.val; VAL VAL ---------- ---------- 1 1 2 2 3 3 Elapsed: 00:00:24.28 --//噢,猜测不到需要24秒。看看执行计划: SCOTT@book01p> @ dpc '' projection '' PLAN_TABLE_OUTPUT ------------------------------------- SQL_ID 641xs1dhjk53y, child number 0 ------------------------------------- with t1 as ( SELECT sleep(a) val FROM tx),t2 as ( SELECT sleep(a) val FROM ty) select * from t1 ,t2 WHERE t1.val = t2.val Plan hash value: 1879928712 ------------------------------------------------------------------------------------------------------------------------------------------------ | Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers | OMem | 1Mem | Used-Mem | ------------------------------------------------------------------------------------------------------------------------------------------------ | 0 | SELECT STATEMENT | | 1 | | | 6 (100)| | 3 |00:00:12.10 | 5 | | | | |* 1 | HASH JOIN | | 1 | 1 | 6 | 6 (0)| 00:00:01 | 3 |00:00:12.10 | 5 | 2078K| 2078K| 963K (0)| | 2 | TABLE ACCESS FULL| TX | 1 | 3 | 9 | 3 (0)| 00:00:01 | 3 |00:00:00.01 | 2 | | | | | 3 | TABLE ACCESS FULL| TY | 1 | 3 | 9 | 3 (0)| 00:00:01 | 3 |00:00:00.01 | 3 | | | | ------------------------------------------------------------------------------------------------------------------------------------------------ Query Block Name / Object Alias (identified by operation id): ------------------------------------------------------------- 1 - SEL$18780C30 2 - SEL$18780C30 / "TX"@"SEL$1" 3 - SEL$18780C30 / "TY"@"SEL$2" Predicate Information (identified by operation id): --------------------------------------------------- 1 - access("SLEEP"("A")="SLEEP"("A")) Column Projection Information (identified by operation id): ----------------------------------------------------------- 1 - (#keys=1) "A"[NUMBER,22], "A"[NUMBER,22] 2 - "A"[NUMBER,22] 3 - "A"[NUMBER,22] 35 rows selected. --//A-Time 显示也是12.10,而实际的执行需要24秒。 --//注意看一个细节id=2,id=3.结合Column Projection Information (identified by operation id):部分: --//仅仅取字段A,而不是sleep(A),id=2,3的a-time很小。 --//真正做HASH JOIN的是id=1,在这里调用函数sleep。消耗6+6秒。 --//在id=0时,select输出,再次调用sleep函数,导致再需要6+6秒这样总共24秒。 --//做1个10046跟踪就很清楚了。 $ grep "lock time" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_3832.trc WAIT #140437728019360: nam='PL/SQL lock timer' ela= 1008297 duration=0 p2=0 p3=0 obj#=24401 tim=3977086831 WAIT #140437728019360: nam='PL/SQL lock timer' ela= 2019544 duration=0 p2=0 p3=0 obj#=24401 tim=3979106823 WAIT #140437728019360: nam='PL/SQL lock timer' ela= 3000002 duration=0 p2=0 p3=0 obj#=24401 tim=3982107136 --//第1次扫描表tx,形成hash table。需要6秒 WAIT #140437728019360: nam='PL/SQL lock timer' ela= 1018749 duration=0 p2=0 p3=0 obj#=24401 tim=3983126232 WAIT #140437728019360: nam='PL/SQL lock timer' ela= 999545 duration=0 p2=0 p3=0 obj#=24401 tim=3984126149 WAIT #140437728019360: nam='PL/SQL lock timer' ela= 1003211 duration=0 p2=0 p3=0 obj#=24401 tim=3985129576 --//第2次扫描表ty,先取出a=1,每条记录都调用sleep 3次作为比较。 WAIT #140437728019360: nam='PL/SQL lock timer' ela= 2006211 duration=0 p2=0 p3=0 obj#=24401 tim=3987135920 WAIT #140437728019360: nam='PL/SQL lock timer' ela= 2000298 duration=0 p2=0 p3=0 obj#=24401 tim=3989136349 WAIT #140437728019360: nam='PL/SQL lock timer' ela= 2002598 duration=0 p2=0 p3=0 obj#=24401 tim=3991139069 WAIT #140437728019360: nam='PL/SQL lock timer' ela= 3012665 duration=0 p2=0 p3=0 obj#=24401 tim=3994153622 WAIT #140437728019360: nam='PL/SQL lock timer' ela= 3006930 duration=0 p2=0 p3=0 obj#=24401 tim=3997160698 WAIT #140437728019360: nam='PL/SQL lock timer' ela= 3001133 duration=0 p2=0 p3=0 obj#=24401 tim=4000161986 --//一个很简单验证如果输出不包括val(执行函数部分),就可以减少执行时间。 SCOTT@book01p> with t1 as ( SELECT sleep(a) val,a FROM tx),t2 as ( SELECT sleep(a) val,a FROM ty) select t1.a,t2.a from t1 ,t2 WHERE t1.val = t2.val; VAL VAL ---------- ---------- 3 3 2 2 1 1 Elapsed: 00:00:12.11 --//使用MATERIALIZE提示就可以减少函数调用。 with t1 as ( SELECT /*+ MATERIALIZE */ sleep(a) val FROM tx),t2 as ( SELECT /*+ MATERIALIZE */ sleep(a) val FROM ty) select * from t1 ,t2 WHERE t1.val = t2.val; VAL VAL ---------- ---------- 1 1 2 2 3 3 Elapsed: 00:00:12.04 SCOTT@book01p> @ dpc '' projection '' PLAN_TABLE_OUTPUT ------------------------------------- SQL_ID 2081zkrcxfn69, child number 0 ------------------------------------- with t1 as ( SELECT /*+ MATERIALIZE */ sleep(a) val FROM tx),t2 as ( SELECT /*+ MATERIALIZE */ sleep(a) val FROM ty) select * from t1 ,t2 WHERE t1.val = t2.val Plan hash value: 2067585427 ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers | OMem | 1Mem | Used-Mem | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | | | 10 (100)| | 3 |00:00:12.04 | 6 | | | | | 1 | TEMP TABLE TRANSFORMATION | | 1 | | | | | 3 |00:00:12.04 | 6 | | | | | 2 | LOAD AS SELECT (CURSOR DURATION MEMORY)| SYS_TEMP_0FD9D6615_63B4FD | 1 | | | | | 0 |00:00:06.03 | 3 | 1024 | 1024 | | | 3 | TABLE ACCESS FULL | TX | 1 | 3 | 9 | 3 (0)| 00:00:01 | 3 |00:00:00.01 | 2 | | | | | 4 | LOAD AS SELECT (CURSOR DURATION MEMORY)| SYS_TEMP_0FD9D6616_63B4FD | 1 | | | | | 0 |00:00:06.01 | 2 | 1024 | 1024 | | | 5 | TABLE ACCESS FULL | TY | 1 | 3 | 9 | 3 (0)| 00:00:01 | 3 |00:00:00.01 | 2 | | | | |* 6 | HASH JOIN | | 1 | 1 | 26 | 4 (0)| 00:00:01 | 3 |00:00:00.01 | 0 | 2546K| 2546K| 1063K (0)| | 7 | VIEW | | 1 | 3 | 39 | 2 (0)| 00:00:01 | 3 |00:00:00.01 | 0 | | | | | 8 | TABLE ACCESS FULL | SYS_TEMP_0FD9D6615_63B4FD | 1 | 3 | 9 | 2 (0)| 00:00:01 | 3 |00:00:00.01 | 0 | | | | | 9 | VIEW | | 1 | 3 | 39 | 2 (0)| 00:00:01 | 3 |00:00:00.01 | 0 | | | | | 10 | TABLE ACCESS FULL | SYS_TEMP_0FD9D6616_63B4FD | 1 | 3 | 9 | 2 (0)| 00:00:01 | 3 |00:00:00.01 | 0 | | | | ------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- Query Block Name / Object Alias (identified by operation id): ------------------------------------------------------------- 1 - SEL$3 2 - SEL$1 3 - SEL$1 / "TX"@"SEL$1" 4 - SEL$2 5 - SEL$2 / "TY"@"SEL$2" 7 - SEL$D67CB2D2 / "T1"@"SEL$3" 8 - SEL$D67CB2D2 / "T1"@"SEL$D67CB2D2" 9 - SEL$EC770CBA / "T2"@"SEL$3" 10 - SEL$EC770CBA / "T1"@"SEL$EC770CBA" Predicate Information (identified by operation id): --------------------------------------------------- 6 - access("T1"."VAL"="T2"."VAL") Column Projection Information (identified by operation id): ----------------------------------------------------------- 1 - "T1"."VAL"[NUMBER,22], "T2"."VAL"[NUMBER,22] 2 - SYSDEF[4], SYSDEF[0], SYSDEF[1], SYSDEF[120], SYSDEF[0] 3 - "A"[NUMBER,22] 4 - SYSDEF[4], SYSDEF[0], SYSDEF[1], SYSDEF[120], SYSDEF[0] 5 - "A"[NUMBER,22] 6 - (#keys=1) "T1"."VAL"[NUMBER,22], "T2"."VAL"[NUMBER,22] 7 - (rowset=256) "T1"."VAL"[NUMBER,22] 8 - (rowset=256) "C0"[NUMBER,22] 9 - "T2"."VAL"[NUMBER,22] 10 - "C0"[NUMBER,22] Hint Report (identified by operation id / Query Block Name / Object Alias): Total hints for statement: 2 --------------------------------------------------------------------------- 2 - SEL$1 - MATERIALIZE 4 - SEL$2 - MATERIALIZE 66 rows selected. --//如果写成如下呢?注意sleep(rownum)。 SELECT * FROM ( SELECT sleep(ROWNUM) val FROM dual CONNECT BY LEVEL <= 3) t1, ( SELECT sleep(ROWNUM) val FROM dual CONNECT BY LEVEL <= 3) t2 WHERE t1.val = t2.val; VAL VAL ---------- ---------- 1 1 2 2 3 3 Elapsed: 00:00:13.11 --//为什么这样写,执行需要13秒呢? SCOTT@book01p> @ dpc '' projection '' PLAN_TABLE_OUTPUT ------------------------------------- SQL_ID ddyh0dg3w38a5, child number 0 ------------------------------------- SELECT * FROM ( SELECT sleep(ROWNUM) val FROM dual CONNECT BY LEVEL <= 3) t1, ( SELECT sleep(ROWNUM) val FROM dual CONNECT BY LEVEL <= 3) t2 WHERE t1.val = t2.val Plan hash value: 155859586 --------------------------------------------------------------------------------------------------------------------------------------------------- | Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | OMem | 1Mem | Used-Mem | --------------------------------------------------------------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | | | 4 (100)| | 3 |00:00:12.10 | | | | |* 1 | HASH JOIN | | 1 | 1 | 26 | 4 (0)| 00:00:01 | 3 |00:00:12.10 | 2546K| 2546K| 966K (0)| | 2 | VIEW | | 1 | 1 | 13 | 2 (0)| 00:00:01 | 3 |00:00:06.08 | | | | | 3 | COUNT | | 1 | | | | | 3 |00:00:00.01 | | | | | 4 | CONNECT BY WITHOUT FILTERING| | 1 | | | | | 3 |00:00:00.01 | 2048 | 2048 | 2048 (0)| | 5 | FAST DUAL | | 1 | 1 | | 2 (0)| 00:00:01 | 1 |00:00:00.01 | | | | | 6 | VIEW | | 1 | 1 | 13 | 2 (0)| 00:00:01 | 3 |00:00:06.02 | | | | | 7 | COUNT | | 1 | | | | | 3 |00:00:00.01 | | | | | 8 | CONNECT BY WITHOUT FILTERING| | 1 | | | | | 3 |00:00:00.01 | 2048 | 2048 | 2048 (0)| | 9 | FAST DUAL | | 1 | 1 | | 2 (0)| 00:00:01 | 1 |00:00:00.01 | | | | --------------------------------------------------------------------------------------------------------------------------------------------------- Query Block Name / Object Alias (identified by operation id): ------------------------------------------------------------- 1 - SEL$1 2 - SEL$2 / "T1"@"SEL$1" 3 - SEL$2 5 - SEL$2 / "DUAL"@"SEL$2" 6 - SEL$3 / "T2"@"SEL$1" 7 - SEL$3 9 - SEL$3 / "DUAL"@"SEL$3" Predicate Information (identified by operation id): --------------------------------------------------- 1 - access("T1"."VAL"="T2"."VAL") Column Projection Information (identified by operation id): ----------------------------------------------------------- 1 - (#keys=1) "T1"."VAL"[NUMBER,22], "T2"."VAL"[NUMBER,22] 2 - "T1"."VAL"[NUMBER,22] 3 - ROWNUM[8] 4 - LEVEL[4] 6 - "T2"."VAL"[NUMBER,22] 7 - ROWNUM[8] 8 - LEVEL[4] 50 rows selected. --//仔细看执行计划显示形成view,然后做hash join。按照道理怎么会多1秒呢? --//如果在toad下执行就会发现显示的是12秒,为什么呢?这与sqlplus的fetch有关,缺省ROWPREFETCH=1, --//一般fetch的数量是1,arraysize,arraysize,...剩下部分小于arraysize。 --//这个参数仅仅12c以上的sqlplus版本可以修改。 SCOTT@book01p> set rowprefetch 2 SELECT * FROM ( SELECT sleep(ROWNUM) val FROM dual CONNECT BY LEVEL <= 3) t1, ( SELECT sleep(ROWNUM) val FROM dual CONNECT BY LEVEL <= 3) t2 WHERE t1.val = t2.val; VAL VAL ---------- ---------- 1 1 2 2 3 3 Elapsed: 00:00:14.13 SCOTT@book01p> set rowprefetch 3 SCOTT@book01p> / VAL VAL ---------- ---------- 1 1 2 2 3 3 Elapsed: 00:00:15.09 SCOTT@book01p> set rowprefetch 4 SCOTT@book01p> / VAL VAL ---------- ---------- 1 1 2 2 3 3 Elapsed: 00:00:12.06 --//画一个表格: rowprefetch 执行时间 ---------------------- 1 13 2 14 3 15 4 12 ---------------------- --//set rowprefetch 2 做一个10046跟踪,结果如下: $ grep "lock time" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_3832_0001.trc WAIT #140437727524480: nam='PL/SQL lock timer' ela= 1003922 duration=0 p2=0 p3=0 obj#=24401 tim=4599768595 WAIT #140437727524480: nam='PL/SQL lock timer' ela= 2005582 duration=0 p2=0 p3=0 obj#=24401 tim=4601774372 WAIT #140437727524480: nam='PL/SQL lock timer' ela= 3005814 duration=0 p2=0 p3=0 obj#=24401 tim=4604780368 WAIT #140437727524480: nam='PL/SQL lock timer' ela= 1013875 duration=0 p2=0 p3=0 obj#=24401 tim=4605794487 WAIT #140437727524480: nam='PL/SQL lock timer' ela= 2100977 duration=0 p2=0 p3=0 obj#=24401 tim=4607895631 WAIT #140437727524480: nam='PL/SQL lock timer' ela= 2006217 duration=0 p2=0 p3=0 obj#=24401 tim=4609902047 WAIT #140437727524480: nam='PL/SQL lock timer' ela= 3019542 duration=0 p2=0 p3=0 obj#=24401 tim=4612923536 --//跟踪内容如下: *** 2024-10-04T16:25:21.864147+08:00 (BOOK01P(3)) WAIT #140437728019360: nam='SQL*Net message from client' ela= 1098883 driver id=1413697536 #bytes=1 p3=0 obj#=24401 tim=4598763528 CLOSE #140437728019360:c=9,e=9,dep=0,type=1,tim=4598763661 ===================== PARSING IN CURSOR #140437727524480 len=178 dep=0 uid=109 oct=3 lid=109 tim=4598763876 hv=109321450 ad='702ce860' sqlid='0u8agsn38877a' SELECT * FROM ( SELECT sleep(ROWNUM) val FROM dual CONNECT BY LEVEL <= 3) t1, ( SELECT sleep(ROWNUM) val FROM dual CONNECT BY LEVEL <= 3) t2 WHERE t1.val = t2.val END OF STMT PARSE #140437727524480:c=165,e=164,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=155859586,tim=4598763874 EXEC #140437727524480:c=77,e=76,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=155859586,tim=4598764061 WAIT #140437727524480: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=24401 tim=4598764141 *** 2024-10-04T16:25:22.869210+08:00 (BOOK01P(3)) WAIT #140437727524480: nam='PL/SQL lock timer' ela= 1003922 duration=0 p2=0 p3=0 obj#=24401 tim=4599768595 *** 2024-10-04T16:25:24.875003+08:00 (BOOK01P(3)) WAIT #140437727524480: nam='PL/SQL lock timer' ela= 2005582 duration=0 p2=0 p3=0 obj#=24401 tim=4601774372 *** 2024-10-04T16:25:27.880989+08:00 (BOOK01P(3)) WAIT #140437727524480: nam='PL/SQL lock timer' ela= 3005814 duration=0 p2=0 p3=0 obj#=24401 tim=4604780368 *** 2024-10-04T16:25:28.895107+08:00 (BOOK01P(3)) WAIT #140437727524480: nam='PL/SQL lock timer' ela= 1013875 duration=0 p2=0 p3=0 obj#=24401 tim=4605794487 *** 2024-10-04T16:25:30.996254+08:00 (BOOK01P(3)) WAIT #140437727524480: nam='PL/SQL lock timer' ela= 2100977 duration=0 p2=0 p3=0 obj#=24401 tim=4607895631 FETCH #140437727524480:c=1653,e=9131571,p=0,cr=0,cu=0,mis=0,r=2,dep=0,og=1,plh=155859586,tim=4607895763 --//r=2. *** 2024-10-04T16:25:33.002666+08:00 (BOOK01P(3)) WAIT #140437727524480: nam='PL/SQL lock timer' ela= 2006217 duration=0 p2=0 p3=0 obj#=24401 tim=4609902047 WAIT #140437727524480: nam='SQL*Net message from client' ela= 1585 driver id=1413697536 #bytes=1 p3=0 obj#=24401 tim=4609903841 --//无法解析为什么重新执行sleep(2).视乎总是fetch的数量到达arraysize时重新读取最后1条。 *** 2024-10-04T16:25:36.024159+08:00 (BOOK01P(3)) WAIT #140437727524480: nam='PL/SQL lock timer' ela= 3019542 duration=0 p2=0 p3=0 obj#=24401 tim=4612923536 WAIT #140437727524480: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=24401 tim=4612923661 FETCH #140437727524480:c=435,e=3019843,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=155859586,tim=4612923753 --//r=1. STAT #140437727524480 id=1 cnt=3 pid=0 pos=1 obj=0 op='HASH JOIN (cr=0 pr=0 pw=0 str=1 time=12151372 us cost=4 size=26 card=1)' STAT #140437727524480 id=2 cnt=3 pid=1 pos=1 obj=0 op='VIEW (cr=0 pr=0 pw=0 str=1 time=6015966 us cost=2 size=13 card=1)' STAT #140437727524480 id=3 cnt=3 pid=2 pos=1 obj=0 op='COUNT (cr=0 pr=0 pw=0 str=1 time=67 us)' STAT #140437727524480 id=4 cnt=3 pid=3 pos=1 obj=0 op='CONNECT BY WITHOUT FILTERING (cr=0 pr=0 pw=0 str=1 time=60 us)' STAT #140437727524480 id=5 cnt=1 pid=4 pos=1 obj=0 op='FAST DUAL (cr=0 pr=0 pw=0 str=1 time=2 us cost=2 size=0 card=1)' STAT #140437727524480 id=6 cnt=3 pid=1 pos=2 obj=0 op='VIEW (cr=0 pr=0 pw=0 str=1 time=6134942 us cost=2 size=13 card=1)' STAT #140437727524480 id=7 cnt=3 pid=6 pos=1 obj=0 op='COUNT (cr=0 pr=0 pw=0 str=1 time=54 us)' STAT #140437727524480 id=8 cnt=3 pid=7 pos=1 obj=0 op='CONNECT BY WITHOUT FILTERING (cr=0 pr=0 pw=0 str=1 time=46 us)' STAT #140437727524480 id=9 cnt=1 pid=8 pos=1 obj=0 op='FAST DUAL (cr=0 pr=0 pw=0 str=1 time=1 us cost=2 size=0 card=1)' *** 2024-10-04T16:25:41.639727+08:00 (BOOK01P(3)) WAIT #140437727524480: nam='SQL*Net message from client' ela= 5614581 driver id=1413697536 #bytes=1 p3=0 obj#=24401 tim=4618539112 CLOSE #140437727524480:c=46,e=45,dep=0,type=0,tim=4618539290 PARSE #140437730665600:c=8,e=9,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=4618539361 EXEC #140437730665600:c=381,e=381,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=4618539770 SCOTT@book01p> set arraysize 2 SCOTT@book01p> set rowprefetch 1 SELECT * FROM ( SELECT sleep(ROWNUM) val FROM dual CONNECT BY LEVEL <= 3) t1, ( SELECT sleep(ROWNUM) val FROM dual CONNECT BY LEVEL <= 3) t2 WHERE t1.val = t2.val; VAL VAL ---------- ---------- 1 1 2 2 3 3 Elapsed: 00:00:16.07 $ grep "lock time" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_3832_0002.trc WAIT #140437725180264: nam='PL/SQL lock timer' ela= 1007989 duration=0 p2=0 p3=0 obj#=-1 tim=5365884132 WAIT #140437725180264: nam='PL/SQL lock timer' ela= 2007088 duration=0 p2=0 p3=0 obj#=-1 tim=5367891438 WAIT #140437725180264: nam='PL/SQL lock timer' ela= 3004928 duration=0 p2=0 p3=0 obj#=-1 tim=5370896531 WAIT #140437725180264: nam='PL/SQL lock timer' ela= 1028788 duration=0 p2=0 p3=0 obj#=-1 tim=5371925572 WAIT #140437725180264: nam='PL/SQL lock timer' ela= 1001489 duration=0 p2=0 p3=0 obj#=-1 tim=5372927420 WAIT #140437725180264: nam='PL/SQL lock timer' ela= 2000780 duration=0 p2=0 p3=0 obj#=-1 tim=5374930090 WAIT #140437725180264: nam='PL/SQL lock timer' ela= 3007603 duration=0 p2=0 p3=0 obj#=-1 tim=5377937946 WAIT #140437725180264: nam='PL/SQL lock timer' ela= 3002644 duration=0 p2=0 p3=0 obj#=-1 tim=5380940882 SCOTT@book01p> set arraysize 2 SCOTT@book01p> set rowprefetch 1 SELECT * FROM ( SELECT sleep(ROWNUM) val FROM dual CONNECT BY LEVEL <= 6) t1, ( SELECT sleep(ROWNUM) val FROM dual CONNECT BY LEVEL <= 6) t2 WHERE t1.val = t2.val; VAL VAL ---------- ---------- 1 1 2 2 --//停一下 3 3 4 4 --//停一下 5 5 6 6 6 rows selected. Elapsed: 00:00:51.51 $ grep "lock time" /u01/app/oracle/diag/rdbms/book/book/trace/book_ora_3832_0003.trc WAIT #140437729984976: nam='PL/SQL lock timer' ela= 1003361 duration=0 p2=0 p3=0 obj#=-1 tim=5751379853 WAIT #140437729984976: nam='PL/SQL lock timer' ela= 2004139 duration=0 p2=0 p3=0 obj#=-1 tim=5753384201 WAIT #140437729984976: nam='PL/SQL lock timer' ela= 3012769 duration=0 p2=0 p3=0 obj#=-1 tim=5756397136 WAIT #140437729984976: nam='PL/SQL lock timer' ela= 4003654 duration=0 p2=0 p3=0 obj#=-1 tim=5760400923 WAIT #140437729984976: nam='PL/SQL lock timer' ela= 5011354 duration=0 p2=0 p3=0 obj#=-1 tim=5765412478 WAIT #140437729984976: nam='PL/SQL lock timer' ela= 6012046 duration=0 p2=0 p3=0 obj#=-1 tim=5771424705 WAIT #140437729984976: nam='PL/SQL lock timer' ela= 1025651 duration=0 p2=0 p3=0 obj#=-1 tim=5772450679 WAIT #140437729984976: nam='PL/SQL lock timer' ela= 1006917 duration=0 p2=0 p3=0 obj#=-1 tim=5773458196 WAIT #140437729984976: nam='PL/SQL lock timer' ela= 2006345 duration=0 p2=0 p3=0 obj#=-1 tim=5775466558 WAIT #140437729984976: nam='PL/SQL lock timer' ela= 3002809 duration=0 p2=0 p3=0 obj#=-1 tim=5778469546 WAIT #140437729984976: nam='PL/SQL lock timer' ela= 3002833 duration=0 p2=0 p3=0 obj#=-1 tim=5781472619 WAIT #140437729984976: nam='PL/SQL lock timer' ela= 4011207 duration=0 p2=0 p3=0 obj#=-1 tim=5785484372 WAIT #140437729984976: nam='PL/SQL lock timer' ela= 5000575 duration=0 p2=0 p3=0 obj#=-1 tim=5790485205 WAIT #140437729984976: nam='PL/SQL lock timer' ela= 5372975 duration=0 p2=0 p3=0 obj#=-1 tim=5795858417 WAIT #140437729984976: nam='PL/SQL lock timer' ela= 6012395 duration=0 p2=0 p3=0 obj#=-1 tim=5801871454 --//那位能给出更好的解析。 --//我测试许多例子,只要第2个表含有sleep(ROWNUM)就会出现这样的情况。 --//补充1个例子: SELECT /*+ LEADING(@"SEL$8976F1A6" "TX"@"SEL$3" "T1"@"SEL$1" ) USE_HASH(@"SEL$8976F1A6" "T1"@"SEL$1" ) */ * FROM ( SELECT sleep(ROWNUM) val FROM dual CONNECT BY LEVEL <= 3) t1, ( SELECT sleep(a) val FROM tx) t2 WHERE t1.val = t2.val; VAL VAL ---------- ---------- 1 1 2 2 3 3 Elapsed: 00:00:19.17 SCOTT@book01p> @ dpc '' projection,outline '' PLAN_TABLE_OUTPUT ------------------------------------- SQL_ID 03nruuwk92tnk, child number 0 ------------------------------------- SELECT /*+ LEADING(@"SEL$8976F1A6" "TX"@"SEL$3" "T1"@"SEL$1" ) USE_HASH(@"SEL$8976F1A6" "T1"@"SEL$1" ) */ * FROM ( SELECT sleep(ROWNUM) val FROM dual CONNECT BY LEVEL <= 3) t1, ( SELECT sleep(a) val FROM tx) t2 WHERE t1.val = t2.val Plan hash value: 4252884107 ------------------------------------------------------------------------------------------------------------------------------------------------------------- | Id | Operation | Name | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time | A-Rows | A-Time | Buffers | OMem | 1Mem | Used-Mem | ------------------------------------------------------------------------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | | | 5 (100)| | 3 |00:00:12.05 | 3 | | | | |* 1 | HASH JOIN | | 1 | 1 | 16 | 5 (0)| 00:00:01 | 3 |00:00:12.05 | 3 | 2078K| 2078K| 945K (0)| | 2 | TABLE ACCESS FULL | TX | 1 | 3 | 9 | 3 (0)| 00:00:01 | 3 |00:00:00.01 | 3 | | | | | 3 | VIEW | | 1 | 1 | 13 | 2 (0)| 00:00:01 | 3 |00:00:06.02 | 0 | | | | | 4 | COUNT | | 1 | | | | | 3 |00:00:00.01 | 0 | | | | | 5 | CONNECT BY WITHOUT FILTERING| | 1 | | | | | 3 |00:00:00.01 | 0 | 2048 | 2048 | 2048 (0)| | 6 | FAST DUAL | | 1 | 1 | | 2 (0)| 00:00:01 | 1 |00:00:00.01 | 0 | | | | ------------------------------------------------------------------------------------------------------------------------------------------------------------- Query Block Name / Object Alias (identified by operation id): ------------------------------------------------------------- 1 - SEL$8976F1A6 2 - SEL$8976F1A6 / "TX"@"SEL$3" 3 - SEL$2 / "T1"@"SEL$1" 4 - SEL$2 6 - SEL$2 / "DUAL"@"SEL$2" Outline Data ------------- /*+ BEGIN_OUTLINE_DATA IGNORE_OPTIM_EMBEDDED_HINTS OPTIMIZER_FEATURES_ENABLE('21.1.0') DB_VERSION('21.1.0') ALL_ROWS OUTLINE_LEAF(@"SEL$2") OUTLINE_LEAF(@"SEL$8976F1A6") MERGE(@"SEL$3" >"SEL$1") OUTLINE(@"SEL$1") OUTLINE(@"SEL$3") FULL(@"SEL$8976F1A6" "TX"@"SEL$3") NO_ACCESS(@"SEL$8976F1A6" "T1"@"SEL$1") LEADING(@"SEL$8976F1A6" "TX"@"SEL$3" "T1"@"SEL$1") USE_HASH(@"SEL$8976F1A6" "T1"@"SEL$1") NO_CONNECT_BY_FILTERING(@"SEL$2") CONNECT_BY_COMBINE_SW(@"SEL$2") END_OUTLINE_DATA */ Predicate Information (identified by operation id): --------------------------------------------------- 1 - access("T1"."VAL"="SLEEP"("A")) Column Projection Information (identified by operation id): ----------------------------------------------------------- 1 - (#keys=1) "T1"."VAL"[NUMBER,22], "A"[NUMBER,22] 2 - "A"[NUMBER,22] 3 - "T1"."VAL"[NUMBER,22] 4 - ROWNUM[8] 5 - LEVEL[4] Hint Report (identified by operation id / Query Block Name / Object Alias): Total hints for statement: 2 --------------------------------------------------------------------------- 1 - SEL$8976F1A6 - LEADING(@"SEL$8976F1A6" "TX"@"SEL$3" "T1"@"SEL$1" ) 1 - SEL$8976F1A6 / "T1"@"SEL$1" - USE_HASH(@"SEL$8976F1A6" "T1"@"SEL$1" ) 77 rows selected.
[20241004]为什么这么慢.txt
来源:这里教程网
时间:2026-03-03 20:41:13
作者:
编辑推荐:
- [20241004]为什么这么慢.txt03-03
- [20241002]21c Temporary Tables and RedoUndo.txt03-03
- [20241006]跟踪library cache lock library cache pin使用gdb(补充测试3).txt03-03
- [20241006]索引建立与虚拟列.txt03-03
- 推荐几本学习Oracle初期阅读的书03-03
- [20241009]oracle timestamp with time zone数据类型的存储.txt03-03
- 很多国产数据库厂商在构建第三方服务体系时,也在学习Oracle的经验03-03
- 很多国产数据库厂商在构建第三方服务体系时,也在学习Oracle的经验03-03
下一篇:
相关推荐
-
雷神推出 MIX PRO II 迷你主机:基于 Ultra 200H,玻璃上盖 + ARGB 灯效
2 月 9 日消息,雷神 (THUNDEROBOT) 现已宣布推出基于英
-
制造商 Musnap 推出彩色墨水屏电纸书 Ocean C:支持手写笔、第三方安卓应用
2 月 10 日消息,制造商 Musnap 现已在海外推出一款 Oce
热文推荐
- 推荐几本学习Oracle初期阅读的书
推荐几本学习Oracle初期阅读的书
26-03-03 - oracle数据坏块处理(一)-通过rman备份修复
oracle数据坏块处理(一)-通过rman备份修复
26-03-03 - golden gate目录从standby端迁移到primary端
golden gate目录从standby端迁移到primary端
26-03-03 - Oracle数据恢复—异常断电导致Oracle数据库数据库打不开的数据恢复案例
- 数据库管理-第244期 一次无法switchover的故障处理(20240928)
- 史上最详细的,Oracle数据库AI落地理论及实践
史上最详细的,Oracle数据库AI落地理论及实践
26-03-03 - 数据库管理-第247期 23ai:全球分布式数据库-Schema对象(20241004)
- Oracle 数据库架构
Oracle 数据库架构
26-03-03 - Oracle + JSON = 王炸!!!
Oracle + JSON = 王炸!!!
26-03-03 - 大事件! Oracle CloudWorld 是"真高光"还是"挤牙膏"?
