tkprof 整理

tkprof 用于格式化trace文件

TKPROF stands for transient kernel profiler？

 

1.tkprof命令
tkprof的结果是不包含绑定变量值的，同时也不包括真正的SQL执行顺序，而trace文件中我们则可以看到按照时间排列的parse,binds,executes,fetch等等，这在某西场合下是很有用处的。

$ tkprof Usage: tkprof tracefile outputfile [explain= ] [table= ]               [print= ] [insert= ] [sys= ] [sort= ]   table=schema.tablename   Use 'schema.tablename' with 'explain=' option.   explain=user/password    Connect to ORACLE and issue EXPLAIN PLAN.   print=integer    List only the first 'integer' SQL statements.   aggregate=yes|no   insert=filename  List SQL statements and data inside INSERT statements.   sys=no           TKPROF does not list SQL statements run as user SYS.   record=filename  Record non-recursive statements found in the trace file.   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:     prscnt  number of times parse was called     prscpu  cpu time parsing     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     execnt  number of execute was called     execpu  cpu time spent executing     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     fchcnt  number of times fetch was called     fchcpu  cpu time spent fetching     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

  PRINT        只列出输出文件的第一个integer 的SQL语句。默认为所有的SQL语句。
AGGREGATE    如果= NO ，则不对多个相同的SQL进行汇总。
INSERT       SQL 语句的一种，用于将跟踪文件的统计信息存储到数据库中。在TKPROF创建脚本后，在将结果输入到数据库中。
SYS         禁止或启用 将SYS用户所发布的SQL语句列表到输出文件中。
TABLE       在输出到输出文件前，用于存放临时表的用户名和表名。
EXPLAIN     没有设置时，看到的执行计划里面有些显示的是object_id。设置了具有查询相关视图权限的用户，则可以将object_id变为object的实际名字，并将执行规划写到输出文件中。但结果很可能与实际使用的不一致。最好不用。
SORT     默认为sql执行的先后顺序，比较有用的排序选项是按照CPU或fchela（即elapsed time fetching）来对分析的结果排序（记住要设置初始化参数timed_statistics=true），生成的文件将把最消耗时间的sql放在最前面显示。或者也可以选择IO比较多的查询。另外一个有用的参数就是sys，这个参数设置为no可以阻止所有以sys用户执行的sql被显示出来，这样可以减少分析出来的文件的复杂度，便于查看。

 

prs- 与parse相关

prscnt number of times parse was called 语句解析的数目
prscpu cpu time parsing 语句解析所占用的CPU时间
prsela elapsed time parsing 语句解析所占用的时间（总是大于或等于CPU时间）；
prsdsk number of disk reads during parse 语句解析期间，从磁盘进行物理读取的数目
prsqry number of buffers for consistent read during parse 语句解析期间，一致模式块读取（CONSISTENT MODE BLOCK READ）的数目
prscu number of buffers for current read during parse 语句解析期间，当前模式读取（CURRENT MODE BLOCK READ）的数目
prsmis number of misses in library cache during parse 语句解析期间，库缓存失败的数目

exe- 与execute相关
execnt number of execute was called 语句执行的数目
execpu cpu time spent executing 语句执行所占用的CPU时间
exeela elapsed time executing 语句执行所占用的时间（总是大于或等于CPU时间）
exedsk number of disk reads during execute 语句执行期间，从磁盘进行物理读取的数目
exeqry number of buffers for consistent read during execute 语句执行期间，一致模式块读取（CONSISTENT MODE BLOCK READ）的数目
execu number of buffers for current read during execute 语句执行期间，当前模式读取（CURRENT MODE BLOCK READ）的数目
exerow number of rows processed during execute 语句执行期间，所处理的语句行数
exemis number of library cache misses during execute 语句执行期间，库缓存失败的数目

fct- 与fetch相关
fchcnt number of times fetch was called 取数据的数目
fchcpu cpu time spent fetching 取数据所占用的CPU时间
fchela elapsed time fetching 取数据所占用的时间（总是大于或等于CPU时间）
fchdsk number of disk reads during fetch 取数据期间，从磁盘进行物理读取的数目
fchqry number of buffers for consistent read during fetch 取数据期间，一致模式块读取（CONSISTENT MODE BLOCK READ）的数目
fchcu number of buffers for current read during fetch 取数据期间，当前模式读取（CURRENT MODE BLOCK READ）的数目
fchrow number of rows fetched 所获取的行数
userid userid of user that parsed the cursor 
 

2.tkprof结果查看

 

这里对同样的sql执行了3次，下面是第一次的结果。

 

select owner ,count(*) from all_objects group by owner call     count       cpu    elapsed       disk      query    current        rows ------- ------  -------- ---------- ---------- ---------- ----------  ---------- Parse        1      0.12       0.14          0          0          0           0 Execute      2      0.00       0.00          0          0          0           0 Fetch        2      0.03       0.09         10        591          0           9 ------- ------  -------- ---------- ---------- ---------- ----------  ---------- total        5      0.15       0.24         10        591          0           9 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: SYS

 

此查询的3个阶段：

Parse：这步将SQL语句转换成执行计划，包括检查是否有正确的授权和所需要用到的表、列以及其他引用到的对象是否存在。
Execute：这步是真正的由Oracle来执行语句。对于insert、update、delete操作，这步会修改数据，对于select操作，这步就只是确定选择的记录。
Fetch：返回查询语句中所获得的记录，这步只有select语句会被执行。

 

CALL：表示每次SQL语句的处理位于那一阶段。
COUNT:这个语句被parse、execute、fetch的次数。
CPU：这个语句对于所有的parse、execute、fetch所消耗的cpu的时间，以秒为单位。
ELAPSED：这个语句所有消耗在parse、execute、fetch的总的时间。
DISK：对磁盘的物理IO次数。一般来说更想知道的是正在从缓存中读取的数据而不是从磁盘上读取的数据。
QUERY：在一致性读模式下，所有parse、execute、fetch所获得的buffer的数量。一致性模式的buffer是用于给一个长时间运行的事务提供一个一致性读的快照，缓存实际上在头部存储了状态。包括从回滚段读的块数。
CURRENT：在current模式下所获得的buffer的数量。一般在current模式下执行insert、update、delete操作都会获取buffer。在current模式下如果在高速缓存区发现有新的缓存足够给当前的事务使用，则这些buffer都会被读入了缓存区中。
ROWS: 所有SQL语句返回的记录数目，但是不包括子查询中返回的记录数目。对于select语句，返回记录是在fetch这步，对于insert、update、delete操作，返回记录则是在execute这步。

 

这里对上述同样的sql执行了3次，下面分别是第二次的结果。 select owner ,count(*) from all_objects group by owner 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.04       0.05          0        591          0           9 ------- ------  -------- ---------- ---------- ---------- ----------  ---------- total        4      0.04       0.05          0        591          0           9 Misses in library cache during parse: 0 Optimizer mode: ALL_ROWS Parsing user id: SYS

 

       第二次Misses in library cache during parse:的0表示此查询在共享池中找到了。执行了一个软解析。

        Optimizer mode表示优化器的模式。它会影响到使用的执行计划。

 

 

Rows     Row Source Operation -------  ---------------------------------------------------       9  HASH GROUP BY (cr=591 pr=0 pw=0 time=0 us cost=51 size=1044 card=9)   12655   FILTER  (cr=591 pr=0 pw=0 time=63142 us)   12846    HASH JOIN  (cr=161 pr=0 pw=0 time=36754 us cost=50 size=1484452 card=12797)      36     TABLE ACCESS FULL USER$ (cr=4 pr=0 pw=0 time=35 us cost=2 size=648 card=36)   12846     HASH JOIN  (cr=157 pr=0 pw=0 time=22350 us cost=47 size=1254106 card=12797)      36      INDEX FULL SCAN I_USER2 (cr=1 pr=0 pw=0 time=35 us cost=1 size=756 card=36)(object id 47)   12846      TABLE ACCESS FULL OBJ$ (cr=156 pr=0 pw=0 time=14001 us cost=45 size=985369 card=12797)    1197    TABLE ACCESS BY INDEX ROWID IND$ (cr=265 pr=0 pw=0 time=0 us cost=2 size=8 card=1)    1362     INDEX UNIQUE SCAN I_IND1 (cr=23 pr=0 pw=0 time=0 us cost=1 size=0 card=1)(object id 41)       0    HASH JOIN  (cr=15 pr=0 pw=0 time=0 us cost=3 size=24 card=1)       8     INDEX RANGE SCAN I_OBJAUTH1 (cr=15 pr=0 pw=0 time=0 us cost=2 size=11 card=1)(object id 62)      16     FIXED TABLE FULL X$KZSRO (cr=0 pr=0 pw=0 time=3 us cost=0 size=1300 card=100)       1    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       1    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    NESTED LOOPS  (cr=46 pr=0 pw=0 time=0 us)       0     NESTED LOOPS  (cr=46 pr=0 pw=0 time=0 us cost=6 size=71 card=1)       0      NESTED LOOPS  (cr=46 pr=0 pw=0 time=0 us cost=4 size=61 card=1)      14       NESTED LOOPS  (cr=23 pr=0 pw=0 time=21 us cost=3 size=50 card=1)      14        MERGE JOIN CARTESIAN (cr=14 pr=0 pw=0 time=1 us cost=2 size=47 card=1)       7         INDEX RANGE SCAN I_OBJ5 (cr=14 pr=0 pw=0 time=0 us cost=2 size=34 card=1)(object id 40)      14         BUFFER SORT (cr=0 pr=0 pw=0 time=0 us cost=0 size=1300 card=100)      14          FIXED TABLE FULL X$KZSRO (cr=0 pr=0 pw=0 time=3 us cost=0 size=1300 card=100)      14        INDEX RANGE SCAN I_USER2 (cr=9 pr=0 pw=0 time=0 us cost=1 size=3 card=1)(object id 47)       0       INDEX RANGE SCAN I_OBJAUTH1 (cr=23 pr=0 pw=0 time=0 us cost=1 size=11 card=1)(object id 62)       0      INDEX RANGE SCAN I_DEPENDENCY1 (cr=0 pr=0 pw=0 time=0 us cost=1 size=0 card=3)(object id 106)       0     TABLE ACCESS BY INDEX ROWID DEPENDENCY$ (cr=0 pr=0 pw=0 time=0 us cost=2 size=10 card=1)       1    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    NESTED LOOPS  (cr=73 pr=0 pw=0 time=0 us cost=2 size=48 card=2)       0     INDEX RANGE SCAN I_OBJAUTH1 (cr=73 pr=0 pw=0 time=0 us cost=2 size=11 card=1)(object id 62)       0     FIXED TABLE FULL X$KZSRO (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=2)       0    HASH JOIN  (cr=23 pr=0 pw=0 time=0 us cost=3 size=24 card=1)       4     INDEX RANGE SCAN I_OBJAUTH1 (cr=23 pr=0 pw=0 time=0 us cost=2 size=11 card=1)(object id 62)       8     FIXED TABLE FULL X$KZSRO (cr=0 pr=0 pw=0 time=2 us cost=0 size=1300 card=100)       1    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=6 size=71 card=1)       0     MERGE JOIN CARTESIAN (cr=0 pr=0 pw=0 time=0 us cost=5 size=60 card=1)       0      NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us)       0       NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=5 size=47 card=1)       0        NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=3 size=37 card=1)       0         INDEX RANGE SCAN I_OBJ5 (cr=0 pr=0 pw=0 time=0 us cost=2 size=34 card=1)(object id 40)       0         INDEX RANGE SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=3 card=1)(object id 47)       0        INDEX RANGE SCAN I_DEPENDENCY1 (cr=0 pr=0 pw=0 time=0 us cost=1 size=0 card=3)(object id 106)       0       TABLE ACCESS BY INDEX ROWID DEPENDENCY$ (cr=0 pr=0 pw=0 time=0 us cost=2 size=10 card=1)       0      BUFFER SORT (cr=0 pr=0 pw=0 time=0 us cost=3 size=1300 card=100)       0       FIXED TABLE FULL X$KZSRO (cr=0 pr=0 pw=0 time=0 us cost=0 size=1300 card=100)       0     INDEX RANGE SCAN I_OBJAUTH1 (cr=0 pr=0 pw=0 time=0 us cost=1 size=11 card=1)(object id 62)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       1    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    NESTED LOOPS  (cr=8 pr=0 pw=0 time=0 us cost=2 size=74 card=2)       0     NESTED LOOPS  (cr=8 pr=0 pw=0 time=0 us cost=2 size=24 card=1)       2      TABLE ACCESS BY INDEX ROWID TRIGGER$ (cr=4 pr=0 pw=0 time=0 us cost=1 size=13 card=1)       2       INDEX UNIQUE SCAN I_TRIGGER2 (cr=2 pr=0 pw=0 time=0 us cost=0 size=0 card=1)(object id 162)       0      INDEX RANGE SCAN I_OBJAUTH1 (cr=4 pr=0 pw=0 time=0 us cost=1 size=11 card=1)(object id 62)       0     FIXED TABLE FULL X$KZSRO (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=2)       1    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       1    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    VIEW  (cr=0 pr=0 pw=0 time=0 us cost=2 size=13 card=1)       0     FAST DUAL  (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)       0    NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=2 size=21 card=1)       0     INDEX RANGE SCAN I_OBJAUTH1 (cr=0 pr=0 pw=0 time=0 us cost=2 size=8 card=1)(object id 62)       0     FIXED TABLE FULL X$KZSRO (cr=0 pr=0 pw=0 time=0 us cost=0 size=13 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=2 size=21 card=1)       0     INDEX RANGE SCAN I_OBJAUTH1 (cr=0 pr=0 pw=0 time=0 us cost=2 size=8 card=1)(object id 62)       0     FIXED TABLE FULL X$KZSRO (cr=0 pr=0 pw=0 time=0 us cost=0 size=13 card=1)       0    FIXED TABLE FULL X$KZSPR (cr=0 pr=0 pw=0 time=0 us cost=0 size=26 card=1)       0    VIEW  (cr=0 pr=0 pw=0 time=0 us cost=1 size=16 card=1)       0     SORT GROUP BY (cr=0 pr=0 pw=0 time=0 us cost=1 size=86 card=1)       0      NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=1 size=86 card=1)       0       MERGE JOIN CARTESIAN (cr=0 pr=0 pw=0 time=0 us cost=0 size=78 card=1)       0        NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=0 size=65 card=1)       0         INDEX UNIQUE SCAN I_OLAP_CUBES$ (cr=0 pr=0 pw=0 time=0 us cost=0 size=13 card=1)(object id 940)       0         TABLE ACCESS BY INDEX ROWID OLAP_DIMENSIONALITY$ (cr=0 pr=0 pw=0 time=0 us cost=0 size=52 card=1)       0          INDEX RANGE SCAN I_OLAP_DIMENSIONALITY$ (cr=0 pr=0 pw=0 time=0 us cost=0 size=0 card=1)(object id 944)       0        BUFFER SORT (cr=0 pr=0 pw=0 time=0 us cost=0 size=13 card=1)       0         INDEX FULL SCAN I_OLAP_CUBE_DIMENSIONS$ (cr=0 pr=0 pw=0 time=0 us cost=0 size=13 card=1)(object id 928)       0       INDEX RANGE SCAN I_OBJ1 (cr=0 pr=0 pw=0 time=0 us cost=1 size=8 card=1)(object id 36)       0    NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=2 size=28 card=1)       0     INDEX FULL SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=19 card=1)(object id 47)       0     INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=1 size=9 card=1)(object id 39)

     

       最后一部分则是具体的执行计划。

       

来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/23650854/viewspace-689300/，如需转载，请注明出处，否则将追究法律责任。

转载于:http://blog.itpub.net/23650854/viewspace-689300/