oracle sql_trace 简单应用介绍

sql_TRACE是oracle提供的用于进行SQL跟踪的手段，是强有力的辅助诊断工具.在日常的数据库问题诊断和解决中，SQL_TRACE是非常常用的方法。

1.通过putty 或其他主机工具进入数据库所在主机.

2.在命令行中通过sqlplus登录oracle.

   连接数据库命令:sqlplus username/passWord

3.使用SQL_TRACE分析sql语句.

SQL_TRACE可以作为初始化参数在全局启用，也可以通过命令行方式在具体session启用。(以下案例均在session下进行)

 1).在全局启用 

 在参数文件(pfile/spfile)中指定:

 sql_trace =true

在全局启用SQL_TRACE会导致所有进程的活动被跟踪，包括后台进程及所有用户进程，这通常会导致比较严重的性能问题，所以在生产环境中要谨慎使用，这个参数在10g之后是动态参数，可以随时调整，在某些诊断中非常有效。
提示: 通过在全局启用sql_trace，我们可以跟踪到所有后台进程的活动，很多在文档中的抽象说明，通过跟踪文件的实时变化，我们可以清晰的看到各个进程之间的紧密协调.

所以不建议使用以上方式

 2).在当前session级设置

 大多数时候我们使用sql_trace跟踪当前进程.通过跟踪当前进程可以发现当前操作的后台数据库递归活动(这在研究数据库新特性时尤其有效)，
 研究SQL执行，发现后台错误等.

启用当前session的跟踪:
SQL> alter session set sql_trace=true;

Session altered.

此时的SQL操作将被跟踪:
SQL> select count(*) from dba_users;--此sql语句可被更换成需要跟踪分析的sql.

  COUNT(*)
----------
        34
结束跟踪:
SQL> alter session set sql_trace=false;

Session altered.

或者使用 DBMS_SESSION程序包 来开启或关闭sql_trace
SQL> exec DBMS_SESSION.SET_SQL_TRACE (sql_trace boolean);

一般放seesion追踪的信息，对应系统初始化参数文件参数show parameter user_dump   --11g之前使用user_dump_dest
对应的就是它的位置。

SQL> show parameter user_dump --查看session中trace文件的存放位置

NAME                                 TYPE                              VALUE
------------------------------------ --------------------------------- ------------------------------
user_dump_dest                       string                            /oracle/diag/rdbms/templatedb/
                                                                                      templatedb/trace
  
  SQL> show parameter trace --查看trace在当前session中的相关参数的值,sql_trace的值会随着trace的开启与关闭发生变化,如下为仅为验证过程.

NAME                                 TYPE                              VALUE
------------------------------------ --------------------------------- ------------------------------
log_arcHive_trace                    integer                           0
sec_protocol_error_trace_action      string                            TRACE
sql_trace                            boolean                           FALSE
trace_enabled                        boolean                           TRUE
tracefile_identifier                 string
SQL> alter session set sql_trace=TRUE;

Session altered.

SQL> show parameter trace

NAME                                 TYPE                              VALUE
------------------------------------ --------------------------------- ------------------------------
log_archive_trace                    integer                           0
sec_protocol_error_trace_action      string                            TRACE
sql_trace                            boolean                           TRUE
trace_enabled                        boolean                           TRUE
tracefile_identifier                 string



SQL> select value from v$diag_info where name='Default Trace File';--查看当前session默认的trace文件url

VALUE
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
/oracle/diag/rdbms/templatedb/templatedb/trace/templatedb_ora_5581.trc

--设置自定义标识符,也可以不设置,设置后的则会改变当前session文件名末尾的字符串 如:templatedb_ora_5581.trc 变为 templatedb_ora_5581_testsession.trc,如下所示
SQL> alter session set tracefile_identifier='testsession';

Session altered.

SQL> select value from v$diag_info where name='Default Trace File';

VALUE
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
/oracle/diag/rdbms/templatedb/templatedb/trace/templatedb_ora_5581_testsession.trc

5 退出sqlplus

使用exit命令即可退出.

6 根据刚才设置的标示符可以很容易的锁定当前session所涉及的trace文件

[oracle@uatcrvcrtdb trace]$ ll *test*

-rw-r----- 1 oracle oinstall 2780 Dec 11 11:41 templatedb_ora_10420_testsession.trc

-rw-r----- 1 oracle oinstall  136 Dec 11 11:41 templatedb_ora_10420_testsession.trm

7 使用Oracle自带的一个命令行工具tkprof，将trace文件生成一个易读的文本文件

[oracle@uatcrvcrtdb trace]$ tkprof templatedb_ora_10420_testsession.trc testsession.txt

[oracle@uatcrvcrtdb trace]$ ll *test*

-rw-r----- 1 oracle oinstall 2780 Dec 11 11:41 templatedb_ora_10420_testsession.trc

-rw-r----- 1 oracle oinstall  136 Dec 11 11:41 templatedb_ora_10420_testsession.trm

-rw-r--r-- 1 oracle oinstall 5605 Dec 11 11:44 testsession.txt

cat testsession.txt

TKPROF: Release 11.2.0.4.0 - Development on Mon Dec 11 11:44:46 2017

Copyright (c) 1982, 2011, Oracle and/or its affiliates.  All rights reserved.

Trace file: templatedb_ora_10420_testsession.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: 61yfbh4s7h6x1 Plan Hash: 2596900044
select count(1) from test_random_04
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.10       0.10          0       2769          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.10       0.10          0       2769          0           1
Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 62
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         1          1          1  SORT AGGREGATE (cr=2769 pr=0 pw=0 time=102729 us)
    999999     999999     999999   TABLE ACCESS FULL TEST_RANDOM_04 (cr=2769 pr=0 pw=0 time=192830 us cost=762 size=0 card=999999)
********************************************************************************

oracle性能优化：如何读懂tkprof

CALL ：每次SQL语句的处理都分成以下三个部分
  Parse：这步将SQL语句转换成执行计划，包括检查是否有正确的授权和所需要用到的表、列以及其他引用到的对象是否存在。
  Execute：这步是真正的由Oracle来执行语句。对于insert、update、delete操作，这步会修改数据，对于select操作，这步就只是确定选择的记录。
  Fetch：返回查询语句中所获得的记录，这步只有select语句会被执行。 
COUNT:这个语句被parse、execute、fetch的次数。 
CPU：这个语句对于所有的parse、execute、fetch所消耗的cpu的时间，以秒为单位。
ELAPSED：这个语句所有消耗在parse、execute、fetch的总的时间。
DISK：从磁盘上的数据文件中物理读取的块的数量。一般来说更想知道的是正在从缓存中读取的数据而不是从磁盘上读取的数据。
QUERY：在一致性读模式下，所有parse、execute、fetch所获得的buffer的数量。一致性模式的buffer是用于给一个长时间运行的事务提供一个一致性读的快照，缓存实际上在头部存储了状态。 
CURRENT： 在current模式下所获得的buffer的数量。一般在current模式下执行insert、update、delete操作都会获取 buffer。在current模式下如果在高速缓存区发现有新的缓存足够给当前的事务使用，则这些buffer都会被读入了缓存区中。 
ROWS: 所有SQL语句返回的记录数目，但是不包括子查询中返回的记录数目。对于select语句，返回记录是在fetch这步，对于insert、update、delete操作，返回记录则是在execute这步。

A、query+current/rows 平均每行所需的block数，太大的话（超过20）SQL语句效率太低
B、Parse count/Execute count parse count应尽量接近1，如果太高的话，SQL会进行不必要的reparse
C、rows Fetch/Fetch Fetch Array的大小，太小的话就没有充分利用批量Fetch的功能，增加了数据在客户端和服务器之间的往返次数。
D、disk/query+current 磁盘IO所占逻辑IO的比例，太大的话有可能是db_buffer_size过小(也跟SQL的具体特性有关)
E、elapsed/cpu 太大表示执行过程中花费了大量的时间等待某种资源
F、cpu　Or　elapsed 太大表示执行时间过长，或消耗了了大量的CPU时间，应该考虑优化
G、执行计划中的Rows 表示在该处理阶段所访问的行数，要尽量减少