Oracle 调优工具（SQL Trace）

Oracle 调优工具（SQL Trace）当我们需要为特定的事务或应用的一批SQL进行调优时，我们可以使用该工具收集执行统计信息。该工具提供了EXPLAIN和DBMS_XPLAN的所有信息，并且更加准确。 SQL TRACE主要包括如下两个组成部分：SQL跟踪：在当前会话或其他会话中，启用跟踪。tkprof工具：格式化跟踪文件，得到容易理解的格式。下面，我们以例子的形式进行说明。我们先来看一个例子：SQL> alter session set sql_trace = true 2 /ERROR:ORA-01031: 权限不足SQL> show userUSER is "DJP01"SQL>在djp01用户启用跟踪时，发现没有权限，下面我system用户对其进行授权，并重新启用，如下：SQL> show userUSER is "SYSTEM"SQL> grant alter session to djp01 2 /Grant succeeded.SQL> conn djp01/djp2012Connected.SQL> alter session set sql_trace = true 2 /Session altered.SQL>在会话级，启用跟踪成功。 SQL> alter session set tracefile_identifier = tmp_trace_01 2 /Session altered.SQL>说明：由于trace文件比较多，识别起来比较困难一些，为了能更好的进行识别，在上述，我设置了一个标识符，这样就容易识别出来。下面，我们运行一个SQL，并查看跟踪文件，如下：SQL> select emp_name,phone_number,salary,dept_name 2 from employees join departments using(dept_id) 3 where emp_name like 'ABC%' 4 /EMP_NAME PHONE_NUMBER SALARY---------------------------------------- ---------------------- ----------DEPT_NAME--------------------------------------------------------------------------------ABCNNTTZYPXKTWQCBSNR 8769595105 4213.49BRUWHHGUMTCFAEXOOKMSQL> host tkprof E:\app\Administrator\diag\rdbms\invmt\invmt\trace\invmt_ora_4052_TMP_TRACE_01.trc-> E:\test_trace_out.prf explain=djp01/djp2012 waits=yes sort=(prsela,fchela,exeela)TKPROF: Release 11.2.0.1.0 - Development on 星期日 3月 3 10:36:04 2013Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.SQL>说明：上述中，我简单地执行了一个SQL，并紧接着调用tkprof工具来格式化对应的跟踪文件，tkprof的常用格式O：tkprof trace_file ouput_file explain=connect waits=yes|no sort=(sort keys)。trace_file：生成的跟踪文件，如上述的invmt_ora_4052_TMP_TRACE_01.trc。ouput_file ：格式化后的内容将被写入的文件。如上述的test_trace_out.prf。explain=connect：使用给定的连接参数连接到Oracle，并为第一条SQL语句执行一次explain plan。一般我们不需要这么做。如 果需要，可以这样用，如：explain=djp01/djp2012，即可。waits：是否为所有的SQL语句提供一份等待信息的小结。sort：按照排序键的降序值展示SQL语句（prsela,fchela,exeela为常用的排序方式，表示按照消耗的时间对SQL语句进行排 序）。关于tkprof的sort排序包括两个部分：第一部分为将要被排序的调用的类型。第二部分为将要排序的值。tkprof排序键的组成部分如下： 第一部分：prs：根据解析调用期间的值进行排序。exe：根据执行调用期间的值进行排序（等价于查询语句打开游标）。fch：根据提取调用期间的值进行排序（只针对查询语句）。第二部分：cnt：根据调用次数进行排序。cpu：根据CPU的时间消耗进行排序。ela：根据时间消耗进行排序。dsk：根据磁盘读次数排序。qry：根据一致读次数排序。cu：根据当前读次数进行排序。mis：根据库缓存未命中次数进行排序。row：根据处理记录数进行排序。其中：mis只能用在prs上，row只能用在exe或fch上。关于tkprof还有一些其他的选项，在特定的场合可能会用到，下面我们介绍一下。table=owner.table_name：如果想使用不同的PLAN_TABLE来生成执行计划，那么可以指定眩选项。print=number_of_statemen：限制显示出来的SQL语句的数据。aggregate=yes/no：如果设置为yes（默认），跟踪文件中相同的SQL将只被记录一次，相应的执行统计信息将被汇总。如查 为no，每当SQL语句被解析一次，tkprof的输出就会被记录一个独立的条目，即使这个SQL语句与之前遇到 的相同。sys=yes/no：如果设置为no，sys用户下执行的语句将不会输出到跟踪文件中。record=filename：生成一个包含跟踪文件中，除了递归SQL以为的所有SQL语句的文件。insert=filename：生成一个可以在SQL*Plus中运行的文件，来记录跟踪文件中的SQL语句以及它们的执行统计信息。这个功能 可以用来设置并比较SQL语句在不同时间的运行情况，也可以用来确定不断增长的数据是或用户负载下的效果。下面，我们来看一下格式化后的，部分跟踪文件：********************************************************************************select emp_name,phone_number,salary,dept_namefrom employees join departments using(dept_id)where emp_name like 'ABC%'call count cpu elapsed disk query current rows------- ------ -------- ---------- ---------- ---------- ---------- ----------Parse 1 0.00 0.00 0 0 0 0Execute 1 0.00 0.00 0 0 0 0Fetch 2 0.01 0.24 1633 1636 0 1------- ------ -------- ---------- ---------- ---------- ---------- ----------total 4 0.01 0.25 1633 1636 0 1Misses in library cache during parse: 1Optimizer mode: ALL_ROWSParsing user id: 33 (DJP01)Rows Row Source Operation------- --------------------------------------------------- 1 NESTED LOOPS (cr=1636 pr=1633 pw=0 time=0 us) 1 NESTED LOOPS (cr=1635 pr=1632 pw=0 time=0 us cost=366 size=58 card=1) 1 TABLE ACCESS FULL EMPLOYEES (cr=1634 pr=1631 pw=0 time=0 us cost=365 size=41 card=1) 1 INDEX UNIQUE SCAN DEPT_ID_PK (cr=1 pr=1 pw=0 time=0 us cost=0 size=0 card=1)(object id 13535) 1 TABLE ACCESS BY INDEX ROWID DEPARTMENTS (cr=1 pr=1 pw=0 time=0 us cost=1 size=17 card=1)Rows Execution Plan------- --------------------------------------------------- 0 SELECT STATEMENT MODE: ALL_ROWS 1 NESTED LOOPS 1 NESTED LOOPS 1 TABLE ACCESS MODE: ANALYZED (FULL) OF 'EMPLOYEES' (TABLE) 1 INDEX MODE: ANALYZED (UNIQUE SCAN) OF 'DEPT_ID_PK' (INDEX (UNIQUE)) 1 TABLE ACCESS MODE: ANALYZED (BY INDEX ROWID) OF 'DEPARTMENTS' (TABLE)********************************************************************************说明：第一段落，展示了所执行SQL的文件。接着是一个包含统计信息的表格。 count：每个类型调用发生的次数。cpu：所需的CPU时间（单位为秒）。elapsed：所需的时间消耗（单位为秒）。disk：所需要的磁盘读取的数量。query、current：查询模式和当前模式缓存的数据。查询模式读取的块，通常是由一致读取的查询产生。而当前模式读取的 块，通常来自自己存在块的变更。它们可以称为逻辑读。rows：处理记录的条数。Parse：进行解析，这一步会检查SQL语句的语法、对象的有效性及权限。接着由优化器确定这条语句的执行计划。Execute：进行执行。SQL语句在这一步执行，如果是查询语句的话，则为第一次的提取操作做准备。对于有些查询（比如含有 for update的语句或执行排序的语句），系统会在这一步就检索出每一条记录。Fetch：进行提取。查询语句从这里返回记录。total：是对上面的一个总数的计算。从这个表格当中，我们可以得到一些重要的比率，如下：在fetch行中，块读取数据（query+current）与获取的记录数据（rows）的比率。这是查询语句的相对开销的一个粗略指标。返回一定数量的记录时，要访问的内存块越多，每条记录就显得越可贵。在count列中，解析次数（Parse）与执行次数（Execute）的比率。在理想的情况下，解析次数应接近于1。如果解析次数相对于执行次数来讲显得较高，那么，就表明这条语句在执行没有必要的重解析。在fetch行中，提取记录数（rows）与提取次数（count）的比率。它表明数组提取机制使用的级别。在total行中，磁盘读取数（disk）与逻辑读取数（query+current）的比率。它表明数据库缓存区高速缓存的命中率。再往下面看，它有两段执行计划。第一次执行计划来自于语句关闭时存储在跟踪文件中的信息。这个执行计划不是由EXPLAIN PLAIN命令执行出来的，它代表了实际执行时的执行计划。这个执行计划更加准确一些。第二次的执行计划则是由tkprof工具中的explain命令得出来的。在第一次执行计划中，第一个执行步骤中，都含有一些参数说明，下面，我们来介绍一下：cr：表明这一步中，处理的逻辑块读取的数据。pr：表明这一步中，处理物理块的读取的数据。pw：表明这一步中，物理块的写的数量。time：这一步所消耗的微秒数。cost：这一步对应的优化成本。size：处理的字节数。card：处理的记录数。关于跟踪文件的启用，在上述，我只介绍了使用sql_trace参数，我们还可以使用dbms_session程序包进行启动。例子如下：SQL> begin 2 dbms_session.session_trace_enable( 3 waits=>true, 4 binds=>true, 5 plan_stat=>'all_executions'); 6 end; 7 /PL/SQL procedure successfully completed.SQL> alter session set tracefile_identifier = 'tmp_trace_02' 2 /Session altered.SQL>说明：上述，我使用了session_trace_enable对会话的跟踪进行了启用。waits为true，则收集等信息，为false，则不收集。binds为true，则收集绑定变量的信息，为false，则不收集。plan_stat：确定在何时收集执行计划的每一步记录数，其值包括，never、first_execution、all_executions。我们可以通过查询V$视图来查看会话的跟踪状态与对应的跟踪文件，如下：SQL> select sql_trace,sql_trace_waits,sql_trace_binds, 2 traceid,tracefile 3 from v$session s,v$process p 4 where s.paddr = p.addr 5 and audsid = userenv('sessionid') 6 /SQL_TRACE SQL_TRACE_ SQL_TRACE_---------------- ---------- ----------TRACEID--------------------------------------------------------------------------------TRACEFILE--------------------------------------------------------------------------------ENABLED TRUE TRUEtmp_trace_02e:\app\administrator\diag\rdbms\invmt\invmt\trace\invmt_ora_4052_tmp_trace_02.trc1 row selected.SQL>仔细观察一下跟踪文件的名称，它是有规律的。第一部分为ORACLE_SID（可以使用视图v$instance获取），第二部分为进程ID（可以使用v$process获取），第三部分为可选项，是一个标识（可选）。第四部分为.trc扩展名。下面我们可以自己一个SQL来定位trace文件：SQL如下：SQL> select c.value || '\' || d.instance_name || '_ora_' || b.spid || 2 case when b.traceid is not null then '_' || b.traceid 3 else '' end || '.trc' trace_file_path 4 from v$session a,v$process b,v$parameter c,v$instance d 5 where a.paddr = b.addr 6 and a.audsid = userenv('sessionid') 7 and c.name = 'user_dump_dest' 8 /TRACE_FILE_PATH--------------------------------------------------------------------------------e:\app\administrator\diag\rdbms\invmt\invmt\trace\invmt_ora_4052_tmp_trace_02.trc1 row selected.SQL>下面我们运行一条比较有负载性的SQL，并查询跟踪文件，如下：SQL> column dept_name format a30SQL> select dept_name,count(*) 2 from employees e,departments d 3 where e.dept_id = d.dept_id 4 and e.phone_number like '123%' 5 group by dept_name 6 /DEPT_NAME COUNT(*)------------------------------ ----------RBSSRJQFCSD 1SCJIMNDVPQYBVMRK 3RWEXOTTRSEF 1DBCAOBRH 4AXALKAO 1HMTOHLISVHXL 5LEADLTGEXEXYUVYMJM 2QINODNMPRYTISAIOLTYD 2QIQKODN 2........................................................UDUPXUJBBQOQM 3WXMFCELSWNQGEE 3RYTPPCXHILK 1SHRGJGICVOWTCUMKCXX 144 rows selected.SQL> host tkprof E:\app\Administrator\diag\rdbms\invmt\invmt\trace\invmt_ora_4052_tmp_trace_02.trc-> E:\sql_trace_out01.prf waits=yes sys=no aggregate=no sort=(prsela,fchela,exeela)TKPROF: Release 11.2.0.1.0 - Development on 星期日 3月 3 15:27:13 2013Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.SQL>跟踪文件如下：********************************************************************************select dept_name,count(*)from employees e,departments dwhere e.dept_id = d.dept_id and e.phone_number like '123%'group by dept_namecall count cpu elapsed disk query current rows------- ------ -------- ---------- ---------- ---------- ---------- ----------Parse 1 0.00 0.00 0 0 0 0Execute 1 0.00 0.00 0 0 0 0Fetch 4 0.01 0.23 1630 1737 0 44------- ------ -------- ---------- ---------- ---------- ---------- ----------total 6 0.01 0.23 1630 1737 0 44Misses in library cache during parse: 0Optimizer mode: ALL_ROWSParsing user id: 33 Rows Row Source Operation------- --------------------------------------------------- 44 HASH GROUP BY (cr=1737 pr=1630 pw=0 time=0 us cost=367 size=31 card=1) 100 NESTED LOOPS (cr=1737 pr=1630 pw=0 time=304425 us) 100 NESTED LOOPS (cr=1637 pr=1630 pw=0 time=303039 us cost=366 size=31 card=1) 100 TABLE ACCESS FULL EMPLOYEES (cr=1633 pr=1630 pw=0 time=301356 us cost=365 size=14 card=1) 100 INDEX UNIQUE SCAN DEPT_ID_PK (cr=4 pr=0 pw=0 time=0 us cost=0 size=0 card=1)(object id 13535) 100 TABLE ACCESS BY INDEX ROWID DEPARTMENTS (cr=100 pr=0 pw=0 time=0 us cost=1 size=17 card=1)Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 4 0.00 0.00 direct path read 104 0.03 0.20 asynch descriptor resize 2 0.00 0.00 SQL*Net message from client 3 0.01 0.02********************************************************************************当我们不需要时，停止其会话的跟踪，如下：SQL> exec dbms_session.session_trace_disable;PL/SQL procedure successfully completed.SQL>关于会话的跟踪，还有一些其他的启动方法，比如在其他的会话中调用跟踪，可以使用dbms_monitor.session_trace_enable过程进行启动。在RAC中，可以使用dbms_monitor.serv_mod_act_trace_enable过程，通过匹配特定的服务、模块、动作以及实例标识来启动跟踪。我这里就不一一进行列举了，有需要的，请查阅相关资料或纵然留言。关于跟踪，我们也可以启用高级事件来完成，比如10053，10046等，如alter session set events '10046 trace name context forever'。这里，我不再进行具体的介绍，有需要的，请查阅相关资料或给我留言。