查看執(zhí)行計劃的命令有很多種,但是,其實究其原理無非是通過如下四種途徑:
- 查詢PLAN_TABLE$表,并將表中的記錄格式化成執(zhí)行計劃
- 查詢SQL相關(guān)動態(tài)性能視圖,并將其中的記錄格式化成執(zhí)行計劃
- 通過AWR將Shared Pool中的內(nèi)容轉(zhuǎn)存到 AWR Repository 中,然后調(diào)用Repository中的信息,格式化成執(zhí)行計劃
- 通過執(zhí)行SQL語句時的TRACE文件查看查看執(zhí)行計劃
執(zhí)行計劃的種類可以分為兩種,一種是EXPLAIN PLAN一種是EXECUTED PLAN。EXPLAIN PLAN是在真正執(zhí)行之前的解釋型計劃,而EXECUTED PALN是實際SQL執(zhí)行過后保存的實際執(zhí)行計劃。相對準(zhǔn)確的是執(zhí)行過后的執(zhí)行計劃,而解釋型的執(zhí)行計劃是為了分析和計算用的。
而平時常用的查看執(zhí)行計劃的命令有如下幾種:
- EXPLAIN PLAN
- DBMS_XPLAN
- SQLPLUS AUTOTRACE
- 10046 EVENT
- 10053 EVENT (針對執(zhí)行計劃的生成過程進(jìn)行詳細(xì)分析時使用)
1. EXPLAIN PLAN
使用方法:
explain plan for <SQL STATEMENT>;
select * from table(dbms_xplan.display);
這種方法是典型的對PLAN_TABLE$進(jìn)行格式化的方法。所使用的PLAN_TABLE$是一個GLOBAL TEMPORARY TABLE。關(guān)于GLOBAL TEMPORARY TABLE的特點這里不多解釋。
例子:
SCOTT@dbec11g 02:36:10> explain plan for select * from emp;
Explained.
SCOTT@dbec11g 02:36:24> select * from table(dbms_xplan.display);
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------
Plan hash value: 3956160932
--------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 14 | 532 | 3 (0)| 00:00:01 |
| 1 | TABLE ACCESS FULL| EMP | 14 | 532 | 3 (0)| 00:00:01 |
--------------------------------------------------------------------------
8 rows selected.
2. DBMS_XPLAN
DBMS_XPALN是一個對執(zhí)行計劃進(jìn)行格式化的包,里面提供了很多函數(shù),常用的如下:
- dbms_xplan.display
- dbms_xplan.display_cursor
- dbms_xplan.display_awr
使用方法:
select * from table(dbms_xplan.display);
select * from table(dbms_xplan.display_cursor(null, null, 'advanced'));
select * from table(dbms_xplan.display_cursor(<SQL_ID/HASH_VALUE>, CHILD_CURSOR_NUMBER, 'advanced'));
select * from table(dbms_xplan.display_awr(<SQL_ID>));
dbms_xplan.display是從PLAN_TABLE$中查詢執(zhí)行計劃。
dbms_xplan.display_cursor是從Shared Pool中查詢執(zhí)行計劃。
dbms_xplan.display_awr是從AWR的Repository中查詢執(zhí)行計劃。
例子:
SCOTT@dbec11g 02:37:35> select count(*) from emp;
COUNT(*)
----------
14
SCOTT@dbec11g 02:37:46> select * from table(dbms_xplan.display_cursor(null, null, 'advanced'));
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------
SQL_ID g59vz2u4cu404, child number 0
-------------------------------------
select count(*) from emp
Plan hash value: 2937609675
-------------------------------------------------------------------
| Id | Operation | Name | Rows | Cost (%CPU)| Time |
-------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | 1 (100)| |
| 1 | SORT AGGREGATE | | 1 | | |
| 2 | INDEX FULL SCAN| PK_EMP | 14 | 1 (0)| 00:00:01 |
-------------------------------------------------------------------
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------
1 - SEL$1
2 - SEL$1 / EMP@SEL$1
Outline Data
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------
-------------
/*+
BEGIN_OUTLINE_DATA
IGNORE_OPTIM_EMBEDDED_HINTS
OPTIMIZER_FEATURES_ENABLE('11.2.0.1')
DB_VERSION('11.2.0.1')
ALL_ROWS
OUTLINE_LEAF(@"SEL$1")
INDEX(@"SEL$1" "EMP"@"SEL$1" ("EMP"."EMPNO"))
END_OUTLINE_DATA
*/
Column Projection Information (identified by operation id):
-----------------------------------------------------------
1 - (#keys=0) COUNT(*)[22]
39 rows selected.
關(guān)于使用dbms_xplan.display_cursor通過SQL_ID或HASH_VALUE查看執(zhí)行計劃和使用dbms_xplan.display_awr的方法不做詳細(xì)解釋
3. SQLPLUS AUTOTRACE
AUTOTRACE是SQLPLUS中提供的功能,只在SQLPLUS中有效。
語法如下:
SET AUTOTRACE {OFF|ON|TRACEONLY} [EXPLAIN] [STATISTICS]
在使用命令的時候可以應(yīng)用如下的縮寫:
AUTOTRACE --> AUTOT
TRACEONLY --> TRACE
EXPLAIN --> EXP
STATISTICS --> STAT
當(dāng)使用SET AUTOTRACE TRACEONLY EXPLAIN的時候,查看某一個select語句的執(zhí)行計劃時,它其實是不執(zhí)行的,因為命令的本身要求看的就是解釋型計劃。而使用AUTOTRACE命令查看INERT, UPDATE, DELETE語句的執(zhí)行計劃時,該語句都是執(zhí)行后的真實執(zhí)行計劃。而除了SET AUTOTRACE TRACEONLY EXPLAIN計劃以外的其他命令,若顯示了執(zhí)行時資源的消耗情況的話,該語句其實都是執(zhí)行過的語句,因為只有執(zhí)行過了才能看到執(zhí)行過程中的資源消耗情況。但是,要注意的是語句中如果有綁定變量的話,顯示的執(zhí)行計劃也會不準(zhǔn)確,這個時候就需要使用10046 EVENT來查看準(zhǔn)確的執(zhí)行計劃。
例子:
SCOTT@dbec11g 02:38:17> set autot on
SCOTT@dbec11g 02:41:45> select count(*) from emp;
COUNT(*)
----------
14
Execution Plan
----------------------------------------------------------
Plan hash value: 2937609675
-------------------------------------------------------------------
| Id | Operation | Name | Rows | Cost (%CPU)| Time |
-------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 1 (0)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | | |
| 2 | INDEX FULL SCAN| PK_EMP | 14 | 1 (0)| 00:00:01 |
-------------------------------------------------------------------
Statistics
----------------------------------------------------------
0 recursive calls
0 db block gets
1 consistent gets
0 physical reads
0 redo size
346 bytes sent via SQL*Net to client
475 bytes received via SQL*Net from client
2 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
1 rows processed
SCOTT@dbec11g 02:41:52> set autot off
4. 10046 EVENT
10046 EVENT中不僅顯示了執(zhí)行計劃,也包含了執(zhí)行過程中每一步執(zhí)行時的具體情況,例如,每一步中耗費(fèi)的邏輯讀、物理讀等信息。
使用方法1:
-- 開啟10046
alter session set events '10046 trace name context forever, level 12';
...execute some SQL Statement...
-- 關(guān)閉10046
alter session set events '10046 trace name context off';
-- 查看DUMP文件的路徑
select value from v$diag_info where name='Default Trace File';
使用方法2(需要sys權(quán)限):
-- 對當(dāng)前會話使用oradebug命令
oradebug setmypid;
-- 開啟10046
oradebug event 10046 trace name context forever, level 12;
...execute some SQL Statement...
-- 關(guān)閉10046
oradebug event 10046 trace name context off;
-- 查看DUMP文件的路徑
oradebug tracefile_name;
得到的TRACE文件的格式是裸格式(Raw Trace),內(nèi)容并不直觀,所以需要用TKPROF命令進(jìn)行格式化。
關(guān)于TKPROF命令的使用方法可以直接輸入tkprof查看使用幫助文檔。
10046 Event Level
level 1 SQL Trace
level 4 SQL Trace + Bind Variable
level 8 SQL Trace + Wait Event
level 12 SQL Trace + Bind Variable + Wait Event
如果只想查看level 1的SQL Trace信息,也可以使用如下方法:
alter session set sql_trace = true;
...execute some SQL Statement...
alter session set sql_trace = false;
例子:
SCOTT@dbec11g 02:42:54> alter session set events '10046 trace name context forever, level 12';
Session altered.
SCOTT@dbec11g 02:43:21> select count(*) from emp;
COUNT(*)
----------
14
SCOTT@dbec11g 02:43:32> alter session set events '10046 trace name context off';
Session altered.
SCOTT@dbec11g 02:43:38> select value from v$diag_info where name='Default Trace File';
VALUE
---------------------------------------------------------------------------------------------
/u01/app/oracle/diag/rdbms/dbec11g/dbec11g/trace/dbec11g_ora_8666.trc
在命令行中查看Raw Trace文件:
[oracle@dbec-lnx-svr ~]$ cat /u01/app/oracle/diag/rdbms/dbec11g/dbec11g/trace/dbec11g_ora_8666.trc
Trace file /u01/app/oracle/diag/rdbms/dbec11g/dbec11g/trace/dbec11g_ora_8666.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/dbecrdb11g
System name: Linux
Node name: dbec-lnx-svr
Release: 3.8.13-16.2.1.el6uek.x86_64
Version: #1 SMP Thu Nov 7 17:01:44 PST 2013
Machine: x86_64
Instance name: dbec11g
Redo thread mounted by this instance: 1
Oracle process number: 24
Unix process pid: 8666, image: oracle@dbec-lnx-svr
*** 2016-03-26 14:43:21.899
*** SESSION ID:(8.58671) 2016-03-26 14:43:21.899
*** CLIENT ID:() 2016-03-26 14:43:21.899
*** SERVICE NAME:(dbec11g) 2016-03-26 14:43:21.899
*** MODULE NAME:(SQL*Plus) 2016-03-26 14:43:21.899
*** ACTION NAME:() 2016-03-26 14:43:21.899
WAIT #8: nam='SQL*Net message to client' ela= 5 driver id=1413697536 #bytes=1 p3=0 obj#=540 tim=1458971001898756
*** 2016-03-26 14:43:32.193
WAIT #8: nam='SQL*Net message from client' ela= 10294485 driver id=1413697536 #bytes=1 p3=0 obj#=540 tim=1458971012193806
CLOSE #8:c=0,e=23,dep=0,type=1,tim=1458971012193924
=====================
PARSING IN CURSOR #10 len=24 dep=0 uid=84 oct=3 lid=84 tim=1458971012195125 hv=2295140356 ad='aec63070' sqlid='g59vz2u4cu404'
select count(*) from emp
END OF STMT
PARSE #10:c=1000,e=1152,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=2937609675,tim=1458971012195124
EXEC #10:c=0,e=43,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2937609675,tim=1458971012195268
WAIT #10: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=540 tim=1458971012195344
FETCH #10:c=0,e=33,p=0,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=2937609675,tim=1458971012195414
STAT #10 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=1 pr=0 pw=0 time=0 us)'
STAT #10 id=2 cnt=14 pid=1 pos=1 obj=73202 op='INDEX FULL SCAN PK_EMP (cr=1 pr=0 pw=0 time=0 us cost=1 size=0 card=14)'
WAIT #10: nam='SQL*Net message from client' ela= 802 driver id=1413697536 #bytes=1 p3=0 obj#=540 tim=1458971012196336
FETCH #10:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=2937609675,tim=1458971012196385
WAIT #10: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=540 tim=1458971012196418
*** 2016-03-26 14:43:38.378
WAIT #10: nam='SQL*Net message from client' ela= 6181927 driver id=1413697536 #bytes=1 p3=0 obj#=540 tim=1458971018378369
CLOSE #10:c=0,e=16,dep=0,type=0,tim=1458971018378473
=====================
PARSING IN CURSOR #17 len=55 dep=0 uid=84 oct=42 lid=84 tim=1458971018378623 hv=2217940283 ad='0' sqlid='06nvwn223659v'
alter session set events '10046 trace name context off'
END OF STMT
PARSE #17:c=0,e=104,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=1458971018378622
EXEC #17:c=1000,e=402,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=1458971018379098
格式化后查看:
[oracle@dbec-lnx-svr ~]$ tkprof /u01/app/oracle/diag/rdbms/dbec11g/dbec11g/trace/dbec11g_ora_8666.trc ~/dbec11g_ora_8666.txt
TKPROF: Release 11.2.0.1.0 - Development on Sat Mar 26 14:47:13 2016
Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.
[oracle@dbec-lnx-svr ~]$ cat dbec11g_ora_8666.txt
TKPROF: Release 11.2.0.1.0 - Development on Sat Mar 26 14:47:13 2016
Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.
Trace file: /u01/app/oracle/diag/rdbms/dbec11g/dbec11g/trace/dbec11g_ora_8666.trc
Sort options: default
********************************************************************************
count = number of times OCI procedure was executed
cpu = cpu time in seconds executing
elapsed = elapsed time in seconds executing
disk = number of physical reads of buffers from disk
query = number of buffers gotten for consistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call
********************************************************************************
SQL ID: g59vz2u4cu404
Plan Hash: 2937609675
select count(*)
from
emp
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 1 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.00 0 1 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 84
Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=1 pr=0 pw=0 time=0 us)
14 INDEX FULL SCAN PK_EMP (cr=1 pr=0 pw=0 time=0 us cost=1 size=0 card=14)(object id 73202)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
SQL*Net message from client 2 6.18 6.18
********************************************************************************
SQL ID: 06nvwn223659v
Plan Hash: 0
alter session set events '10046 trace name context off'
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
Parsing user id: 84
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 0 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 1 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 6 0.00 0.00 0 1 0 1
Misses in library cache during parse: 1
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 3 0.00 0.00
SQL*Net message from client 3 10.29 16.47
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 0 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
2 user SQL statements in session.
0 internal SQL statements in session.
2 SQL statements in session.
********************************************************************************
Trace file: /u01/app/oracle/diag/rdbms/dbec11g/dbec11g/trace/dbec11g_ora_8666.trc
Trace file compatibility: 11.1.0.7
Sort options: default
1 session in tracefile.
2 user SQL statements in trace file.
0 internal SQL statements in trace file.
2 SQL statements in trace file.
2 unique SQL statements in trace file.
50 lines in trace file.
6 elapsed seconds in trace file.