手机版
你好,游客 登录 注册
背景:
阅读新闻

Oracle 11g R2性能优化 tkprof

[日期:2019-02-11] 来源:cnblogs.com/dbabd  作者:H_Johnny [字体: ]

目录

  • 主要说明
  • 关键选项
  • 用法示例
    • 对SCOTT开启跟踪
    • 执行一条SQL语句
    • 对SCOTT关闭跟踪
    • tkprof分析trace文件
  • 总结
  • 参考

正文

另一篇博文总结了关于SQL TRACE工具的使用方式,但是产生的trace文件格式阅读起来并不是十分友好,为了更好的分析trace文件,Oracle也自带了一个格式化工具tkproftkprof工具用于处理原始的trace文件,合并汇总trace文件当中一些项目值,然后进行格式化,这样就使得trace文件的可读性更好。

关于tkprof的详细说明可以参考官方文档:Understanding SQL Trace and TKPROF

关于trace文件的生成可以参考另一篇博文:Oracle 11g R2性能优化 SQL TRACE

主要说明

tkprof命令位于 $ORACLE_HOME/bin/路径下,通过命令tkprof直接获取相关选项参数:

$ tkprof
Usage: tkprof tracefile outputfile [explain= ] [table= ]
[print= ] [insert= ] [sys= ] [sort= ]

关键选项

  • tracefile
    需要格式化的trace文件

  • outputfile
    格式化完成后的输出文件

  • explain=
    通过给定方式连接数据库,并为每条语句生成执行计划

  • sort=
    指定排序键来展示SQL语句

其他选项如下:


  table=schema.tablename   Use 'schema.tablename' with 'explain=' option. -- 指定PLAN_TABLE生成执行计划,默认为系统的PLAN_TABLE
  explain=user/password    Connect to ORACLE and issue EXPLAIN PLAN. 
  print=integer    List only the first 'integer' SQL statements. -- 显示指定数目的SQL语句
  aggregate=yes|no -- 指定是否对重复SQL语句信息合并,默认yes合并,如果指定为no,对重复SQL语句信息会独立输出一个条目
  insert=filename  List SQL statements and data inside INSERT statements. -- 创建一张表将每个跟踪的SQL语句的一行统计信息插入到表中
  sys=no           TKPROF does not list SQL statements run as user SYS. -- 指定不记录由SYS用户执行的语句
  record=filename  Record non-recursive statements found in the trace file. -- 指定生成不包含递归语句的SQL语句文件
  waits=yes|no     Record summary for any wait events found in the trace file. -- 指定为语句生成等待事件信息(如有)

-- 以下为排序选项说明

  sort=option      Set of zero or more of the following sort options:

-- 1、解析调用期间执行排序
    prscnt  number of times parse was called                     -- 解析次数                    
    prscpu  cpu time parsing                                     -- 解析消耗CPU时间
    prsela  elapsed time parsing                                 -- 解析所消耗时间
    prsdsk  number of disk reads during parse                    -- 解析时物理读次数
    prsqry  number of buffers for consistent read during parse   -- 解析时一致读次数
    prscu   number of buffers for current read during parse      -- 解析时当前读次数
    prsmis  number of misses in library cache during parse       -- 解析时库缓存区未命中次数

-- 2、执行调用期间执行排序
    execnt  number of execute was called                         -- 执行次数
    execpu  cpu time spent executing                             -- 执行时消耗CPU时间
    exeela  elapsed time executing                               -- 执行所消耗的时间
    exedsk  number of disk reads during execute                  -- 执行时物理读次数
    exeqry  number of buffers for consistent read during execute -- 执行时一致读次数
    execu   number of buffers for current read during execute    -- 执行时当前读次数
    exerow  number of rows processed during execute              -- 执行时处理的记录数
    exemis  number of library cache misses during execute        -- 执行时库缓冲区未命中次数

-- 3、提取调用期间执行排序
    fchcnt  number of times fetch was called                     -- 提取数据次数
    fchcpu  cpu time spent fetching                              -- 提取时消耗CPU时间
    fchela  elapsed time fetching                                -- 提取所消耗的时间
    fchdsk  number of disk reads during fetch                    -- 提取时物理读次数  
    fchqry  number of buffers for consistent read during fetch   -- 提取时一致读次数
    fchcu   number of buffers for current read during fetch      -- 提取时当前读次数
    fchrow  number of rows fetched                               -- 提取的记录数
    
    userid  userid of user that parsed the cursor                -- 按游标解析时的userid排序                

关于tkprof工具更详细的用法可以参考Oracle MOS文档:TKProf Interpretation (9i and above) (文档 ID 760786.1)

用法示例

对SCOTT开启跟踪

$ sqlplus scott/tiger

SCOTT@dbabd> alter session set tracefile_identifier = 'SCOTT';

Session altered.

SCOTT@dbabd> exec dbms_session.session_trace_enable(true, true, 'all_executions');

PL/SQL procedure successfully completed.

执行一条SQL语句

SCOTT@dbabd> select * from emp;

     EMPNO ENAME      JOB                    MGR HIREDATE                   SAL       COMM     DEPTNO
---------- ---------- --------------- ---------- ------------------- ---------- ---------- ----------
      7369 SMITH      CLERK                 7902 1980-12-17 00:00:00        800                    20
      7499 ALLEN      SALESMAN              7698 1981-02-20 00:00:00       1600        300         30
      7521 WARD       SALESMAN              7698 1981-02-22 00:00:00       1250        500         30
      7566 JONES      MANAGER               7839 1981-04-02 00:00:00       2975                    20
      7654 MARTIN     SALESMAN              7698 1981-09-28 00:00:00       1250       1400         30
      7698 BLAKE      MANAGER               7839 1981-05-01 00:00:00       2850                    30
      7782 CLARK      MANAGER               7839 1981-06-09 00:00:00       2450                    10
      7788 SCOTT      ANALYST               7566 1987-04-19 00:00:00       3000                    20
      7839 KING       PRESIDENT                  1981-11-17 00:00:00       5000                    10
      7844 TURNER     SALESMAN              7698 1981-09-08 00:00:00       1500          0         30
      7876 ADAMS      CLERK                 7788 1987-05-23 00:00:00       1100                    20
      7900 JAMES      CLERK                 7698 1981-12-03 00:00:00        950                    30
      7902 FORD       ANALYST               7566 1981-12-03 00:00:00       3000                    20
      7934 MILLER     CLERK                 7782 1982-01-23 00:00:00       1300                    10

14 rows selected.

对SCOTT关闭跟踪

SCOTT@dbabd> exec dbms_session.session_trace_disable();

PL/SQL procedure successfully completed.

tkprof分析trace文件

执行如下命令生成格式化文件:

$ tkprof /data/app/oracle/diag/rdbms/dbabd/dbabd/trace/dbabd_ora_18629_SCOTT.trc /data/app/scott_trace.log explain=scott/tiger aggregate=yes sys=no waits=yes sort=fchela

查看tkprof生成文件:

$ cat /data/app/scott_trace.log

-- 开头概要部分,基本信息说明,包括tkprof版本、trace文件路径、排序选项和报告参数说明
TKPROF: Release 11.2.0.4.0 - Development on Thu Jan 17 17:41:04 2019

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

Trace file: /data/app/oracle/diag/rdbms/dbabd/dbabd/trace/dbabd_ora_18629_SCOTT.trc
Sort options: fchela
********************************************************************************
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语句文本、SQL ID和执行计划HASH

SQL ID: a2dk8bdn0ujx7 Plan Hash: 3956160932

select *
from
 emp

-- SQL执行的统计信息

/*
call:调用类型
count:调用执行次数
cpu:需要的CPU时间(单位:秒)
elapsed:需要消耗的时间(单位:秒)
disk:发生物理读次数
query:发生一致读次数
current:发生当前读次数
rows:获取的行数
*/

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          7          0          14
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.00       0.00          0          7          0          14

Misses in library cache during parse: 1     -- 库缓存没有命中数,说明是硬解析
Optimizer mode: ALL_ROWS                    -- 优化器模式
Parsing user id: 83  (SCOTT)                -- 解析用户
Number of plan statistics captured: 1       -- 执行计划统计信息获取数

-- SQL语句实际执行消耗的资源信息
/*
Rows:操作实际返回记录数
Row Source Operation:当前行操作的访问方式
    cr:一致性读的数据块,对应query的Fetch值
    pr:物理读的数据块,对应disk的Fetch值
    pw:物理写的数据块
    time:执行时间
    cost:优化器执行成本
    size:处理的字节数
    card:处理的记录数
*/
Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
        14         14         14  TABLE ACCESS FULL EMP (cr=7 pr=0 pw=0 time=211 us cost=3 size=532 card=14)

-- 指定explain选项输出的执行计划
Rows     Execution Plan
-------  ---------------------------------------------------
      0  SELECT STATEMENT   MODE: ALL_ROWS
     14   TABLE ACCESS   MODE: ANALYZED (FULL) OF 'EMP' (TABLE)

-- 指定选项waits=yes选项输出的等待事件信息统计
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      128.00        128.00
********************************************************************************

SQL ID: bnqn0qyvy59qf Plan Hash: 0

BEGIN dbms_session.session_trace_enable(true, true, 'all_executions'); END;


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         61          0           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        1      0.00       0.00          0         61          0           1

Misses in library cache during parse: 0
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: 83  (SCOTT)

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1       68.47         68.47
********************************************************************************

SQL ID: 23d3sap7cask4 Plan Hash: 0

BEGIN dbms_session.session_trace_disable(); END;


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           1
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          0          0           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 83  (SCOTT)


********************************************************************************

-- 开启跟踪期间所有非递归SQL语句执行信息统计汇总
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        2      0.01       0.01          0          0          0           0
Execute      3      0.00       0.00          0         61          0           2
Fetch        2      0.00       0.00          0          7          0          14
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        7      0.01       0.01          0         68          0          16

Misses in library cache during parse: 2
Misses in library cache during execute: 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      128.00        196.48


-- 开启跟踪期间所有递归SQL语句执行信息统计汇总
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     23      0.00       0.00          0          0          0           0
Fetch       37      0.00       0.00          2         82          0          28
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       60      0.00       0.00          2         82          0          28

Misses in library cache during parse: 0

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                         2        0.00          0.00

-- 所有分析的SQL语句汇总统计
    3  user  SQL statements in session.
   13  internal SQL statements in session.
   16  SQL statements in session.
    1  statement EXPLAINed in this session.
********************************************************************************
Trace file: /data/app/oracle/diag/rdbms/dbabd/dbabd/trace/dbabd_ora_18629_SCOTT.trc
Trace file compatibility: 11.1.0.7
Sort options: fchela
       1  session in tracefile.
       3  user  SQL statements in trace file.
      13  internal SQL statements in trace file.
      16  SQL statements in trace file.
      16  unique SQL statements in trace file.
       1  SQL statements EXPLAINed using schema:
           SCOTT.prof$plan_table
             Default table was used.
             Table was created.
             Table was dropped.
     411  lines in trace file.
     196  elapsed seconds in trace file.

总结

以上梳理了关于tkprof工具的简单用法,经过它格式化之后的trace文件更具有可读性,真实地统计了SQL语句在执行过程当中资源的消耗。但是它提供的是汇总后的统计信息,如果需要了解SQL语句执行时每个步骤的资源消耗情况可以通过阅读原始的trace文件,这里不再进行深入讨论了。SQL性能优化博大精深,涉及的知识面广泛,也经常涉及Oracle底层运行机制和操作系统底层实现,需要自己学习与提高的地方还有很多。

参考

https://docs.oracle.com/cd/E11882_01/server.112/e41573/sqltrace.htm#PFGRF94981
TKProf Interpretation (9i and above) (文档 ID 760786.1)

更多Oracle相关信息见Oracle 专题页面 https://www.linuxidc.com/topicnews.aspx?tid=12

Linux公社的RSS地址https://www.linuxidc.com/rssFeed.aspx

本文永久更新链接地址https://www.linuxidc.com/Linux/2019-02/156846.htm

linux
相关资讯       tkprof  Oracle 11g R2性能优化 
本文评论   查看全部评论 (0)
表情: 表情 姓名: 字数

       

评论声明
  • 尊重网上道德,遵守中华人民共和国的各项有关法律法规
  • 承担一切因您的行为而直接或间接导致的民事或刑事法律责任
  • 本站管理人员有权保留或删除其管辖留言中的任意内容
  • 本站有权在网站内转载或引用您的评论
  • 参与本评论即表明您已经阅读并接受上述条款