ACCESS[20170909]为什么是12秒.txt

[20170909]为什么是12秒.txt

–//在开发顺序时自一般会强调开发尽量不要写一些于定义函数,往往或致CPU忙。
–//例子很像这样:

CREATE OR REPLACE FUNCTION get_dept (p_deptno dept.deptno%TYPE)
   RETURN dept.dname%TYPE
IS
   l_dname   dept.dname%TYPE;
BEGIN
   DBMS_LOCK.sleep (1);

   SELECT dname
     INTO l_dname
     FROM dept
    WHERE deptno = p_deptno;

   RETURN l_dname;
END;
/

–//这样定义实际上非常坏,如果尽如下,相当给每行都见面调用函数get_dept,形成不必要的递交归.
–//本来应该采取说明连接解决的,使用函数,有接触像标量子查询.
–//当时自我提议外好好看一下自身勾勒的blog,链接如下:
–// http://blog.itpub.net/267265/viewspace-2138042/ =>
[20170426]怎是4秒.txt
–// 结果对方发现在12c for
windows下,测试结果以及自家之测试不符,我再也测试看看.

1.环境:
SCOTT@test01p> @ ver1
PORT_STRING                    VERSION       
BANNER                                                                              
CON_ID




IBMPC/WIN_NT64-9.1.0           12.1.0.1.0     Oracle Database 12c
Enterprise Edition Release 12.1.0.1.0 – 64bit Production             
0

2.建立函数:
CREATE OR REPLACE FUNCTION get_dept (p_deptno dept.deptno%TYPE)
   RETURN dept.dname%TYPE
IS
   l_dname   dept.dname%TYPE;
BEGIN
   DBMS_LOCK.sleep (1);

   SELECT dname
     INTO l_dname
     FROM dept
    WHERE deptno = p_deptno;

   RETURN l_dname;
END;
/

set timing on
set autot traceonly;

SCOTT@test01p> select empno, ename, deptno, get_dept(deptno) c20
from emp;
14 rows selected.
Elapsed: 00:00:14.02
–//执行多次稳定性递归的数量.需要14秒完成.

Execution Plan

Plan hash value: 3956160932

| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time    

|

|   0 | SELECT STATEMENT  |      |    14 |   182 |     3   (0)| 00:00:01
|
|   1 |  TABLE ACCESS FULL| EMP  |    14 |   182 |     3   (0)| 00:00:01

|

Statistics

         14  recursive calls
          0  db block gets
         36  consistent gets
          0  physical reads
          0  redo size
       1130  bytes sent via SQL*Net to client
        544  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
         14  rows processed
–//可以发现递归执行14赖(如果非是,执行多次说到底见面安居乐业于14不良)

–//换成标量子查询:
SCOTT@test01p> select empno, ename, deptno, (select get_dept(deptno)
from dual )c20 from emp;
14 rows selected.
Elapsed: 00:00:12.04

Execution Plan

Plan hash value: 1340320406

| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time    

|

|   0 | SELECT STATEMENT  |      |    14 |   182 |     9   (0)| 00:00:01
|
|   1 |  FAST DUAL        |      |     1 |       |     2   (0)| 00:00:01
|
|   2 |  TABLE ACCESS FULL| EMP  |    14 |   182 |     3   (0)| 00:00:01

|

Statistics

         12  recursive calls
          0  db block gets
         32  consistent gets
          0  physical reads
          0  redo size
       1130  bytes sent via SQL*Net to client
        544  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
         14  rows processed
–//执行时间是12秒,递归12次.与己以11g下测试不同,11g下测试3秒.

set autot off
alter session set statistics_level=all;

SCOTT@test01p> show array
arraysize 200

SCOTT@test01p> select empno, ename, deptno, (select get_dept(deptno)
from dual )c20 from emp;

SCOTT@test01p> @ dpc ” ”

PLAN_TABLE_OUTPUT

SQL_ID  apagxtf1p2puy, child number 1

select empno, ename, deptno, (select get_dept(deptno) from dual )c20
from emp

Plan hash value: 1340320406

| Id  | Operation         | Name | Starts | E-Rows |E-Bytes| Cost

(%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |

|   0 | SELECT STATEMENT  |      |      1 |        |       |     9
(100)|          |     14 |00:00:00.01 |       8 |
|   1 |  FAST DUAL        |      |     12 |      1 |       |     2  
(0)| 00:00:01 |     12 |00:00:00.01 |       0 |
|   2 |  TABLE ACCESS FULL| EMP  |      1 |     14 |   182 |     3  

(0)| 00:00:01 |     14 |00:00:00.01 |       8 |

Query Block Name / Object Alias (identified by operation id):

   1 – SEL$2 / DUAL@SEL$2
   2 – SEL$1 / EMP@SEL$1
21 rows selected.

–//从执行计划吧得以窥见fast
dual执行了12次.为什么?不好理解?要么3差,要么14次?什么也未应当12次.

3.分析:
–//用10046跟踪看看
@ 10046on 12
select empno, ename, deptno, (select get_dept(deptno) from dual )c20
from emp;
@ 10046off

–//检查跟踪文件.
*** 2017-09-09 21:20:16.366
WAIT #181607424: nam=’PL/SQL lock timer’ ela= 999265 duration=0 p2=0

p3=0 obj#=665 tim=5412716150

PARSING IN CURSOR #181597968 len=42 dep=1 uid=109 oct=3 lid=109
tim=5412716418 hv=328320763 ad=’7ff13e15ba0′ sqlid=’56r5sd49t3jrv’
SELECT DNAME FROM DEPT WHERE DEPTNO = :B1
END OF STMT
BINDS #181597968:
 Bind#0
  oacdty=02 mxl=22(21) mxlc=00 mal=00 scl=00 pre=00
  oacflg=03 fl2=1206001 frm=00 csi=00 siz=24 off=0
  kxsbbbfp=212a7fb0  bln=22  avl=02  flg=05
  value=20
EXEC
#181597968:c=0,e=8900,p=0,cr=0,cu=0,mis=0,r=0,dep=1,og=1,plh=2852011669,tim=5412725274
FETCH
#181597968:c=0,e=28,p=0,cr=2,cu=0,mis=0,r=1,dep=1,og=1,plh=2852011669,tim=5412725381
STAT #181597968 id=1 cnt=1 pid=0 pos=1 obj=92285 op=’TABLE ACCESS BY
INDEX ROWID DEPT (cr=2 pr=0 pw=0 time=30 us cost=1 size=13 card=1)’
STAT #181597968 id=2 cnt=1 pid=1 pos=1 obj=92286 op=’INDEX UNIQUE SCAN
PK_DEPT (cr=1 pr=0 pw=0 time=19 us cost=0 size=0 card=1)’
CLOSE #181597968:c=0,e=3,dep=1,type=3,tim=5412735882
FETCH
#181607424:c=0,e=1019217,p=0,cr=7,cu=0,mis=0,r=1,dep=0,og=1,plh=1340320406,tim=5412735943
WAIT #181607424: nam=’SQL*Net message from client’ ela= 1165 driver
id=1413697536 #bytes=1 p3=0 obj#=665 tim=5412737203

d:\tools\rlwrap>grep “BINDS #181597968:”
D:\app\oracle\diag\rdbms\test\test\trace\test_ora_6436.trc
|wc
     12      24     216

–//确实12次.

d:\tools\rlwrap> grep -A5 “BINDS #181597968:”
D:\app\oracle\diag\rdbms\test\test\trace\test_ora_6436.trc |
grep “^  value=”
  value=20
  value=30
  value=20
  value=30
  value=10
  value=20
  value=10
  value=30
  value=20
  value=30
  value=20
  value=10

SCOTT@test01p> select empno, ename, deptno, (select get_dept(deptno)
from dual )c20 from emp;
     EMPNO ENAME          DEPTNO C20


      7369 SMITH              20 RESEARCH
      7499 ALLEN              30 SALES
      7521 WARD               30 SALES
      7566 JONES              20 RESEARCH
      7654 MARTIN             30 SALES
      7698 BLAKE              30 SALES
      7782 CLARK              10 ACCOUNTING
      7788 SCOTT              20 RESEARCH
      7839 KING               10 ACCOUNTING
      7844 TURNER             30 SALES
      7876 ADAMS              20 RESEARCH
      7900 JAMES              30 SALES
      7902 FORD               20 RESEARCH
      7934 MILLER             10 ACCOUNTING
14 rows selected.

–//对比你可以窥见,如果凑的价一样,函数调用仅仅1次.

SCOTT@test01p> select * from (select empno, ename, deptno,
lag(deptno,1) over(order by rownum) next from emp) where deptno=next;
     EMPNO ENAME          DEPTNO       NEXT


      7521 WARD               30         30
      7698 BLAKE              30         30

–//这样减少2次调用,说明12c与11g在标量子查询及处理同原本不同.不明了凡是啊回事,上班又仔细比看看(与11g).
–//或者是OS版本的题材….
–//一个粗略的印证,建立一个如约deptno排序的表.
create table empx as select * from emp order by deptno;

SCOTT@test01p> select empno, ename, deptno, (select get_dept(deptno)
from dual )c20 from empx;
     EMPNO ENAME          DEPTNO C20


      7782 CLARK              10 ACCOUNTING
      …
      7654 MARTIN             30 SALES
14 rows selected.
Elapsed: 00:00:03.03

–//现在3秒…要这么实践:

select t.* ,(select get_dept(t.deptno) from dual ) c20 from ( select
empno, ename, deptno  from emp order by deptno) t;

Elapsed: 00:00:12.00

–//竟然也是12秒.不了圈行计划就知道:
SCOTT@test01p> @ dpc ” ”

PLAN_TABLE_OUTPUT

SQL_ID  248fpg2995yz8, child number 0

select t.* ,(select get_dept(t.deptno) from dual ) c20 from ( select
empno, ename, deptno  from emp order by deptno) t

Plan hash value: 3996307794

| 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 |        |       |     9
(100)|          |     14 |00:00:12.00 |      31 |       |      
|          |
|   1 |  FAST DUAL         |      |     12 |      1 |       |     2  
(0)| 00:00:01 |     12 |00:00:00.01 |       0 |       |       |         
|
|   2 |  SORT ORDER BY     |      |      1 |     14 |   182 |     9  
(0)| 00:00:01 |     14 |00:00:12.00 |      31 |  2048 |  2048 | 2048 
(0)|
|   3 |   TABLE ACCESS FULL| EMP  |      1 |     14 |   182 |     3  
(0)| 00:00:01 |     14 |00:00:00.01 |       7 |       |       |         

|

–//可以窥见 SORT ORDER BY
消耗12秒.也尽管是以排序前纵进展递归调用函数了.
–//对比前面的尽计划,再次发现竟问题,看无产生前的履行计划12秒消耗在那边?

–//用提示MATERIALIZE改写如下:

SCOTT@test01p> with t as ( select /*+MATERIALIZE */ empno, ename,
deptno  from emp order by deptno)  select t.*,(select
get_dept(t.deptno) from dual ) c20 from t;
     EMPNO ENAME          DEPTNO C20


      7782 CLARK              10 ACCOUNTING
      7839 KING               10 ACCOUNTING
      ..
      7654 MARTIN             30 SALES
14 rows selected.
Elapsed: 00:00:03.02

SCOTT@test01p> @ dpc ” ”

PLAN_TABLE_OUTPUT

SQL_ID  fwvgq6403j0nx, child number 0

with t as ( select /*+MATERIALIZE */ empno, ename, deptno  from emp
order by deptno)  select t.*,(select get_dept(t.deptno) from dual )
c20
from t

Plan hash value: 2014637640

| Id  | Operation                  | Name                       | Starts
| E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers

| Reads  | Writes |  OMem |  1Mem | Used-Mem |

|   0 | SELECT STATEMENT           |                            |      1
|        |       |    11 (100)|          |     14 |00:00:00.01 |      21
|      1 |      1 |       |       |          |
|   1 |  FAST DUAL                 |                            |      3
|      1 |       |     2   (0)| 00:00:01 |      3 |00:00:00.01 |       0
|      0 |      0 |       |       |          |
|   2 |  TEMP TABLE TRANSFORMATION |                            |      1
|        |       |            |          |     14 |00:00:00.01 |      21
|      1 |      1 |       |       |          |
|   3 |   LOAD AS SELECT           |                            |      1
|        |       |            |          |      0 |00:00:00.01 |      11
|      0 |      1 |  1036K|  1036K|          |
|   4 |    SORT ORDER BY           |                            |      1
|     14 |   182 |     3   (0)| 00:00:01 |     14 |00:00:00.01 |       7
|      0 |      0 |  2048 |  2048 | 2048  (0)|
|   5 |     TABLE ACCESS FULL      | EMP                        |      1
|     14 |   182 |     3   (0)| 00:00:01 |     14 |00:00:00.01 |       7
|      0 |      0 |       |       |          |
|   6 |   VIEW                     |                            |      1
|     14 |   322 |     2   (0)| 00:00:01 |     14 |00:00:00.01 |       7
|      1 |      0 |       |       |          |
|   7 |    TABLE ACCESS FULL       | SYS_TEMP_0FD9D660E_18A8CC5
|      1 |     14 |   182 |     2   (0)| 00:00:01 |     14 |00:00:00.01

|       7 |      1 |      0 |       |       |          |

4.继续测试用 DETERMINISTIC Functions:
–//一般如果当当某个函数定义索引,需要DETERMINISTIC,表示回去结果一定。其实就算不稳定,也得以如此定义。
CREATE OR REPLACE FUNCTION get_dept (p_deptno dept.deptno%TYPE)
   RETURN dept.dname%TYPE
   DETERMINISTIC
IS
   l_dname   dept.dname%TYPE;
BEGIN
   DBMS_LOCK.sleep (1);

   SELECT dname
     INTO l_dname
     FROM dept
    WHERE deptno = p_deptno;

   RETURN l_dname;
END;
/

SCOTT@test01p> select empno, ename, deptno, get_dept(deptno) c20 
from emp;

14 rows selected.
Elapsed: 00:00:14.01
–//奇怪!
又回去14秒,而在11g下这么的测试是4秒(注意设置array=200的状态,如果尽小,时间会转变).

5.终极补充测试RESULT CACHE的动静:

CREATE OR REPLACE FUNCTION get_dept (p_deptno dept.deptno%TYPE)
   RETURN dept.dname%TYPE
   RESULT_CACHE
IS
   l_dname   dept.dname%TYPE;
BEGIN
   DBMS_LOCK.sleep (1);

   SELECT dname
     INTO l_dname
     FROM dept
    WHERE deptno = p_deptno;

   RETURN l_dname;
END;
/

SCOTT@test01p> select empno, ename, deptno, get_dept(deptno) c20 
from emp;
14 rows selected.
Elapsed: 00:00:03.13

SCOTT@test01p> select empno, ename, deptno, get_dept(deptno) c20 
from emp;
14 rows selected.
Elapsed: 00:00:00.00

–//第1涂鸦执行3秒,第2次等执行0秒.改要下结果一样.
CREATE OR REPLACE FUNCTION get_dept (p_deptno dept.deptno%TYPE)
   RETURN dept.dname%TYPE
   RESULT_CACHE
   DETERMINISTIC
IS
   l_dname   dept.dname%TYPE;
BEGIN
   DBMS_LOCK.sleep (1);

   SELECT dname
     INTO l_dname
     FROM dept
    WHERE deptno = p_deptno;

   RETURN l_dname;
END;
/

总结:
–//不知道是不是是OS版本的题目,有机会安装12c在linux下更测试看看.
–//看来测试环境该转会12c了….那位有12c for linux的本测试看看…
–//补充测试11g的状态:
SCOTT@book> @ &r/ver1
PORT_STRING                    VERSION        BANNER



x86_64/Linux 2.4.xx            11.2.0.4.0     Oracle Database 11g
Enterprise Edition Release 11.2.0.4.0 – 64bit Production

SYS@book> GRANT EXECUTE ON SYS.dbms_lock TO SCOTT;
Grant succeeded.

CREATE OR REPLACE FUNCTION get_dept (p_deptno dept.deptno%TYPE)
   RETURN dept.dname%TYPE
IS
   l_dname   dept.dname%TYPE;
BEGIN
   DBMS_LOCK.sleep (1);

   SELECT dname
     INTO l_dname
     FROM dept
    WHERE deptno = p_deptno;

   RETURN l_dname;
END;
/

set timing on
set autot traceonly;
select empno, ename, deptno, (select get_dept(deptno) from dual )c20
from emp;

SCOTT@book> select empno, ename, deptno, (select get_dept(deptno)
from dual )c20 from emp;
14 rows selected.
Elapsed: 00:00:03.01

Execution Plan

Plan hash value: 1340320406

| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time    

|

|   0 | SELECT STATEMENT  |      |    14 |   182 |     3   (0)| 00:00:01
|
|   1 |  FAST DUAL        |      |     1 |       |     2   (0)| 00:00:01
|
|   2 |  TABLE ACCESS FULL| EMP  |    14 |   182 |     3   (0)| 00:00:01

|

Statistics

          3  recursive calls
          0  db block gets
         13  consistent gets
          0  physical reads
          0  redo size
       1114  bytes sent via SQL*Net to client
        520  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
         14  rows processed

–//执行多次,基本平静在3独递归调用.

set autot off
alter session set statistics_level=all;
select empno, ename, deptno, (select get_dept(deptno) from dual )c20
from emp;

SCOTT@book> @ &r/dpc ” ”

PLAN_TABLE_OUTPUT

SQL_ID  apagxtf1p2puy, child number 1

select empno, ename, deptno, (select get_dept(deptno) from dual )c20
from emp

Plan hash value: 1340320406

| Id  | Operation         | Name | Starts | E-Rows |E-Bytes| Cost

(%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |

|   0 | SELECT STATEMENT  |      |      1 |        |       |     3
(100)|          |     14 |00:00:00.01 |       7 |
|   1 |  FAST DUAL        |      |      3 |      1 |       |     2  
(0)| 00:00:01 |      3 |00:00:00.01 |       0 |
|   2 |  TABLE ACCESS FULL| EMP  |      1 |     14 |   182 |     3  

(0)| 00:00:01 |     14 |00:00:00.01 |       7 |

Query Block Name / Object Alias (identified by operation id):

   1 – SEL$2 / DUAL@SEL$2
   2 – SEL$1 / EMP@SEL$1
21 rows selected.

–//Id=2.starts=3不善,也证明函数调用3不善.
–//不知道为何,也许12.2.0.N版和11g一模一样,没有这个oracle版本等以后重新测试吧….

相关文章