时间:2021-07-01 10:21:17 帮助过:18人阅读
SQL_TRACE是Oracle的一个非常强大的工具。打开SQL_TRACE就可以逐步捕获任何一个会话的数据库活动,或者捕获整个数据库的活动,并将数据库活动记录成跟踪文件。每次使用完之后需要关闭跟踪,否则会降低系统的性能。
跟踪整个数据库实例。
只需要简单的修改参数文件(pfile/spfile)参数 SQL_TRACE = TRUE ,在全局启用SQL_TRACE会导致所有进程的活动被跟踪,包括后台进程及所有用户进程,这样也会数据库导致性能下降比较明显。
会话级跟踪。
SQL_TRACE的通常使用方式是仅跟踪一个会话。被跟踪的会话可以是您自己的,也可以是其它用户的会话。如果是自己的会话,只需要在SQL*PLUS中运行一下命令即可:
SQL> alter session set sql_trace = true;
类似的如果取消对会话的跟踪,运行一下命令:
SQL> alter session set sql_trace = false;
如果需要跟踪一个特定的会话,首先需要获取会话的SID和Serial#,这些信息可以在视图V$SESSION中获得,一旦知道了这两个参数,就可以运行一下命令:
SQL> execute SYS.dbms_system.set_sql_trace_in_session(13,9,true);
同样也可以使用这个过程关闭会话跟踪:
SQL> execute SYS.dbms_system.set_sql_trace_in_session(13,9,false);
跟踪文件的位置:
一旦为会话激活了SQL_TRACE,ORACLE就会在udump管理区创建跟踪文件,文件的目标位置由参数user_dump_dest来确定。每个操作都不会覆盖原来的文件,新的跟踪记录将会被追加到文件末尾。通常情况下,可以根据文件的修改时间判断目录下哪个文件是最新的文件。
SQL> show parameter user_dump_dest NAME TYPE VALUE ------------------------------------ --------------------------------- ------------------------------ user_dump_dest string /u01/app/oracle/diag/rdbms/11g dg1/dgtst/trace SQL>
也可以通过以下SQL来确定文件名:
SQL> SELECT d.VALUE || ‘/‘ || LOWER (RTRIM (i.instance, CHR (0))) || ‘_ora_‘ || p.spid || ‘.trc‘ trace_file_name FROM (SELECT p.spid FROM v$mystat m, v$session s, v$process p WHERE m.statistic# = 1 AND s.sid = m.sid AND p.addr = s.paddr) p, (SELECT t.instance FROM v$thread t, v$parameter v WHERE v.name = ‘thread‘ AND (v.VALUE = 0 OR t.thread# = TO_NUMBER (v.VALUE))) i, (SELECT VALUE FROM v$parameter WHERE name = ‘user_dump_dest‘) d; TRACE_FILE_NAME ----------------------------------------------------------------------------------------- /u01/app/oracle/diag/rdbms/11gdg1/dgtst/trace/dgtst_ora_11347.trc
计时信息:
为了最大限度的利用跟踪文件,应该打开计时标志,通过参数TIMED_STATISTICTS=TRUE进行设置,这样可以对每个SQL语句的执行时间等进行记录,这个功能对系统性能的负担很小。
打开会话的计时信息:
SQL> alter session set timed_statistics = true ;
打开数据库系统的计时信息
SQL> alter system set timed_statistics = true ;
我们来做一个实验:
SQL> alter session set sql_trace=true; ERROR: ORA-01031: insufficient privileges
SQL> conn / as sysdba Connected. SQL> grant alter session to scott; Grant succeeded.
执行一个查询
SQL> alter session set sql_trace=true; Session altered. SQL> select * from emp,dept where emp.deptno=dept.deptno;
获取trace_file_name
TRACE_FILE_NAME ---------------------------------------------------------------------------------------------------- /u01/app/oracle/diag/rdbms/11gdg1/dgtst/trace/dgtst_ora_11450.trc
查看trace file
11gdg1-> cat /u01/app/oracle/diag/rdbms/11gdg1/dgtst/trace/dgtst_ora_11450.trc Trace file /u01/app/oracle/diag/rdbms/11gdg1/dgtst/trace/dgtst_ora_11450.trc Oracle Database 11g Enterprise Edition Release 11.2.0.3.0 - 64bit Production With the Partitioning, OLAP, Data Mining and Real Application Testing options ORACLE_HOME = /u01/app/oracle/product/11.2.0/db_1 System name: Linux Node name: 11gdg1.localdomain.com Release: 2.6.39-400.17.1.el6uek.x86_64 Version: #1 SMP Fri Feb 22 18:16:18 PST 2013 Machine: x86_64 VM name: VMWare Version: 6 Instance name: dgtst Redo thread mounted by this instance: 1 Oracle process number: 23 Unix process pid: 11450, image: oracle@11gdg1.localdomain.com (TNS V1-V3) *** 2015-07-13 09:38:29.695 *** SESSION ID:(42.57) 2015-07-13 09:38:29.695 *** CLIENT ID:() 2015-07-13 09:38:29.695 *** SERVICE NAME:(SYS$USERS) 2015-07-13 09:38:29.695 *** MODULE NAME:(SQL*Plus) 2015-07-13 09:38:29.695 *** ACTION NAME:() 2015-07-13 09:38:29.695 ===================== PARSING IN CURSOR #139672104506696 len=32 dep=0 uid=83 oct=42 lid=83 tim=1436751509693664 hv=1569151342 ad=‘7f07f227fe10‘ sqlid=‘4tk6t8tfsfqbf‘ alter session set sql_trace=true END OF STMT EXEC #139672104506696:c=0,e=601,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1436751509693625 *** 2015-07-13 09:38:47.624 CLOSE #139672104506696:c=0,e=17,dep=0,type=0,tim=1436751527624224 ===================== PARSING IN CURSOR #139672104506696 len=51 dep=0 uid=83 oct=3 lid=83 tim=1436751527625170 hv=4289413451 ad=‘8bd40480‘ sqlid=‘arvwqrbzuqhab‘ select * from emp,dept where emp.deptno=dept.deptno END OF STMT PARSE #139672104506696:c=0,e=814,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=844388907,tim=1436751527625164 EXEC #139672104506696:c=0,e=315,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=844388907,tim=1436751527625549 FETCH #139672104506696:c=1000,e=1189,p=0,cr=8,cu=0,mis=0,r=1,dep=0,og=1,plh=844388907,tim=1436751527641018 FETCH #139672104506696:c=0,e=52,p=0,cr=2,cu=0,mis=0,r=13,dep=0,og=1,plh=844388907,tim=1436751527641868 STAT #139672104506696 id=1 cnt=14 pid=0 pos=1 obj=0 op=‘MERGE JOIN (cr=10 pr=0 pw=0 time=1393 us cost=6 size=812 card=14)‘ STAT #139672104506696 id=2 cnt=4 pid=1 pos=1 obj=75333 op=‘TABLE ACCESS BY INDEX ROWID DEPT (cr=4 pr=0 pw=0 time=605 us cost=2 size=80 card=4)‘ STAT #139672104506696 id=3 cnt=4 pid=2 pos=1 obj=75334 op=‘INDEX FULL SCAN PK_DEPT (cr=2 pr=0 pw=0 time=286 us cost=1 size=0 card=4)‘ STAT #139672104506696 id=4 cnt=14 pid=1 pos=2 obj=0 op=‘SORT JOIN (cr=6 pr=0 pw=0 time=818 us cost=4 size=532 card=14)‘ STAT #139672104506696 id=5 cnt=14 pid=4 pos=1 obj=75335 op=‘TABLE ACCESS FULL EMP (cr=6 pr=0 pw=0 time=766 us cost=3 size=532 card=14)‘
如果你直接用cat命令查看上面的文件的话,根本看不懂。Oracle提供了一个工具TKPROF
11gdg1-> tkprof /u01/app/oracle/diag/rdbms/11gdg1/dgtst/trace/dgtst_ora_11450.trc trace.sql TKPROF: Release 11.2.0.3.0 - Development on Mon Jul 13 09:41:05 2015 Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
11gdg1-> cat trace.sql TKPROF: Release 11.2.0.3.0 - Development on Mon Jul 13 09:41:05 2015 Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved. Trace file: /u01/app/oracle/diag/rdbms/11gdg1/dgtst/trace/dgtst_ora_11450.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: 4tk6t8tfsfqbf Plan Hash: 0 alter session set sql_trace=true call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 0 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 1 0.00 0.00 0 0 0 0 Misses in library cache during parse: 0 Misses in library cache during execute: 1 Optimizer mode: ALL_ROWS Parsing user id: 83 ******************************************************************************** SQL ID: arvwqrbzuqhab Plan Hash: 844388907 select * from emp,dept where emp.deptno=dept.deptno 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 10 0 14 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 4 0.00 0.00 0 10 0 14 Misses in library cache during parse: 0 Optimizer mode: ALL_ROWS Parsing user id: 83 Number of plan statistics captured: 1 Rows (1st) Rows (avg) Rows (max) Row Source Operation ---------- ---------- ---------- --------------------------------------------------- 14 14 14 MERGE JOIN (cr=10 pr=0 pw=0 time=1393 us cost=6 size=812 card=14) 4 4 4 TABLE ACCESS BY INDEX ROWID DEPT (cr=4 pr=0 pw=0 time=605 us cost=2 size=80 card=4) 4 4 4 INDEX FULL SCAN PK_DEPT (cr=2 pr=0 pw=0 time=286 us cost=1 size=0 card=4)(object id 75334) 14 14 14 SORT JOIN (cr=6 pr=0 pw=0 time=818 us cost=4 size=532 card=14) 14 14 14 TABLE ACCESS FULL EMP (cr=6 pr=0 pw=0 time=766 us cost=3 size=532 card=14) ******************************************************************************** OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 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 10 0 14 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 5 0.00 0.00 0 10 0 14 Misses in library cache during parse: 0 Misses in library cache during execute: 1 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/11gdg1/dgtst/trace/dgtst_ora_11450.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. 44 lines in trace file. 17 elapsed seconds in trace file.
四、使用DBMS_XPLAY
DBMS_XPLAN提供了5个函数
DISPLAY - 格式化和显示plan table中的内容。
DISPLAY_AWR - 格式化和显示存储在AWR中的sql语句的执行计划。
DISPLAY_CURSOR - 格式化和显示任意shared pool中加载的sql语句的执行计划。
DISPLAY_SQL_PLAN_BASELINE - 显示被SQL handle标识的SQL语句的一个或者多个执行计划。
DISPLAY_SQLSET - 格式化和显示存储在SQL tuning set中的sql语句的执行计划
1.DISPLAY
SQL> EXPLAIN PLAN FOR SELECT * FROM emp e, dept d WHERE e.deptno = d.deptno AND e.ename=‘benoit‘; Explained. SQL> SET LINESIZE 130 SQL> SET PAGESIZE 0 SQL> SELECT * FROM table(DBMS_XPLAN.DISPLAY); Plan hash value: 3625962092 ---------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ---------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | 58 | 4 (0)| 00:00:01 | | 1 | NESTED LOOPS | | | | | | | 2 | NESTED LOOPS | | 1 | 58 | 4 (0)| 00:00:01 | |* 3 | TABLE ACCESS FULL | EMP | 1 | 38 | 3 (0)| 00:00:01 | |* 4 | INDEX UNIQUE SCAN | PK_DEPT | 1 | | 0 (0)| 00:00:01 | | 5 | TABLE ACCESS BY INDEX ROWID| DEPT | 1 | 20 | 1 (0)| 00:00:01 | ---------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 3 - filter("E"."ENAME"=‘benoit‘) 4 - access("E"."DEPTNO"="D"."DEPTNO") 18 rows selected.
2. DISPLAY_AWR
SQL> SELECT SQL_ID FROM DBA_HIST_SQLTEXT WHERE ROWNUM<=1; 424h0nf7bhqzd SQL> SELECT * FROM TABLE(DBMS_XPLAN.DISPLAY_AWR(‘424h0nf7bhqzd‘));
查看历史查询中包含TOTO的语句的执行计划
SELECT tf.* FROM DBA_HIST_SQLTEXT ht, TABLE (DBMS_XPLAN.DISPLAY_AWR (ht.sql_id, NULL, NULL, ‘ALL‘)) tf WHERE ht.sql_text LIKE ‘%TOTO%‘;
3.DISPLAY_CURSOR
SQL> CONN SCOTT/tiger Connected. SQL> select * from emp where ename=‘KING‘; EMPNO ENAME JOB MGR ---------- ------------------------------ --------------------------- ---------- HIREDATE SAL COMM DEPTNO ------------------- ---------- ---------- ---------- 7839 KING PRESIDENT 1981/11/17 00:00:00 5000 10 SQL> set pagesize 200 SQL> select * from table(dbms_xplan.display_cursor); PLAN_TABLE_OUTPUT -------------------------------------------------------------------------------- SQL_ID 7y29yzz506y9t, child number 0 ------------------------------------- select * from emp where ename=‘KING‘ Plan hash value: 3956160932 -------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | -------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | | | 3 (100)| | |* 1 | TABLE ACCESS FULL| EMP | 1 | 38 | 3 (0)| 00:00:01 | -------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 1 - filter("ENAME"=‘KING‘) 18 rows selected.
DISPLAY_CURSOR还有很多丰富的用法,我们看看官方文档是怎么描述的。
查看一个具体sql_id的执行计划
SQL> SELECT SQL_ID FROM V$SQLAREA WHERE ROWNUM<=1; SQL_ID --------------------------------------- 4dy1xm4nxc0gf SQL> select * from table(dbms_xplan.display_cursor(‘4dy1xm4nxc0gf‘,NULL,‘ALL ALLSTATS‘));
4.DISPLAY_SQL_PLAN_BASELINE
SET LINESIZE 150 SET PAGESIZE 2000 SELECT t.* FROM (SELECT DISTINCT sql_handle FROM dba_sql_plan_baselines WHERE sql_text LIKE ‘%DEPT%‘) pb, TABLE ( DBMS_XPLAN.DISPLAY_SQL_PLAN_BASELINE (pb.sql_handle, NULL, ‘BASIC‘)) t;
本文出自 “叮咚” 博客,请务必保留此出处http://lqding.blog.51cto.com/9123978/1686138
Oracle 学习之性能优化(五)执行计划
标签:sql plan 执行计划