（转）Oracle 10g中如何使用TKPROF性能分析工具介绍
Oracle具有打开一个相当底层的跟踪能力的工具，就是TKPROF。一旦启用跟踪，Oracle将所有的SQL和应用程序使用的顶层PL/SQL调用记录到服务器上的跟踪文件中。
启用TKPROF在开始运行TFPROF之前需要开启一些设置，可以将其编辑称为一个脚本程序：starttfprof.sql，其中包含的内容：
?
alter session set timed_statistics=true;
alter session set events '10046 trace name context forever,level 12';
?
l??1启用了标准SQL_TRACE工具
l??4启用了SQL_TRACE并捕捉跟踪文件中的绑定变量的值
l??8启用了SQL_TRACE并捕捉跟踪文件的等待事件
l??12启用标准的SQL_TRACE并捕捉绑定变量和等待事件
?
运行TKPROF启用了TKPROF以后，就可以执行你需要执行的SQL语句了。例如，我设计了一张大表，在OE用户下进行如下操作：
?
Create table seagal_orders
As
Select * from orders
?
Insert into seagal_orders
Select * from seagal_orders
?
这样重复不断执行，直到seagal_orders表中有超过150万行记录为止，设计了一个大表，有百万条记录。但是其中包含非常多的重复的记录。（没关系）
?
执行如下的操作：
?
SQL> select count(*) from oe.seagal_orders where customer_id=118;
?
??COUNT(*)
----------
?????32768
?
?
然后，获得系统追踪文件：
?
SQL> select rtrim(c.value,'\') ||'\'||d.instance_name||
??2??'_ora_' ||ltrim(to_char(a.spid))||'.trc'
??3??from v$process a,v$session b,v$parameter c,v$instance d
??4??where a.addr=b.paddr
??5??and b.audsid =sys_context('userenv','sessionid')
??6??and c.name='user_dump_dest';
?
RTRIM(C.VALUE,'\')||'\'||D.INSTANCE_NAME||'_ORA_'||LTRIM(TO_CHAR(A.SPID))||'.TRC'
----------------------------------------------
E:\ORACLE\PRODUCT\10.2.0\ADMIN\MYORACLE\UDUMP\myoracle_ora_3708.trc
?
追踪文件的名字为myoracle_ora_3708.trc。
?
生成TKPROF报告在命令行提示符下，执行：
C:\>tkprof E:\ORACLE\PRODUCT\10.2.0\ADMIN\MYORACLE\UDUMP\myoracle_ora_3708.trc c:\tk.prof
?
TKPROF: Release?10.2.0.1.0 - Production on?星期一?3月?19 22:44:44 2007
?
Copyright (c) 1982, 2005, Oracle.??All rights reserved.
?
C:\>
?
生成的报告文件存储在C盘，文件名称为：tk.prof
阅读TKPROF报告这是一个文本文件，可以通过记事本或者EditPlus工具打开，阅读.报告的内容很长，需要自己阅读，下面截取一部分：
?
select count(*)
from
?oe. seagal _orders where customer_id=118
?
?
call?????count???????cpu????elapsed???????disk??????query????current????????rows
------- ------??-------- ---------- ---------- ---------- ----------??----------
Parse????????1??????0.00???????0.00??????????0?????????74??????????0???????????0
Execute??????1??????0.00???????0.00??????????0??????????0??????????0???????????0
Fetch????????2??????0.10???????0.11??????????0??????10360??????????0???????????1
------- ------??-------- ---------- ---------- ---------- ----------??----------
total????????4??????0.10???????0.11??????????0??????10434??????????0???????????1
?
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
?
Rows?????Row Source Operation
-------??---------------------------------------------------
??????1??SORT AGGREGATE (cr=10360 pr=0 pw=0 time=114189 us)
??32768???TABLE ACCESS FULL MYORDERS (cr=10360 pr=0 pw=0 time=131132 us)
?
?
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????????0.00??????????0.00
********************************************************************************
?
这部分就是刚才执行的查询语句的执行分析报告，理解这个报告需要首先了解一些基本的设置：
查询的三个主要阶段为：
1.?????????分析（Parse）：此阶段是Oracle在共享池中找到该查询（软分析）或创建该查询的新计划（硬分析）的所在。
2.?????????执行（Execute）：此阶段是由Oracle在该查询的OPEN或者EXECUTE语句中做的工作。对于SELECT语句，在许多情况下此阶段为空。对于UPDATE语句，此阶段将是执行所有工作的所在。
3.?????????提取（Fetch）：对于SELECT语句，大多数工作将在此阶段进行。对于UPDATE语句，将不显示任何工作（因为不从更新操作中提取）。
在报告的顶部可以看到的一些信息说明：
?
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
?
解释如下：
l??计数（Count）——查询在此阶段执行的次数。
l??CPU（cpu）——该查询在此阶段花费的CPU时间量，以毫秒为单位。
l??占用时间（Elapsed）——花费在此阶段的挂钟时间。当花费的时间大于CPU时间时，就意味着为某些事件耗费了等待时间。
l??磁盘—isk）——查询在此阶段中执行物理IO的次数。
l??查询（Query）——检索一致方式时执行逻辑IO的次数。那些块是从回滚段中重构的块。如果在查询开始时它们存在就可以看到。
l??当前（current）——到目前为止检索块时所执行的逻辑IO的次数。
l??行（Row）——此阶段中被处理或者受影响的行数。在更改操作中，将看到Exceute阶段的Rows值。在SELECT查询中，该值出现在Fetch阶段。
?
在报告中还可以看到一些信息：
Cr——表示为一致方式读取，显示一致读取数（逻辑IO）
R——物理读取
W——物理写
Time——以百万分之一秒计数的时间占用，即us秒（微秒）?
?
Create table seagal_orders
As
Select * from orders
?
Insert into seagal_orders
Select * from seagal_orders
?
这样重复不断执行，直到seagal_orders表中有超过150万行记录为止，设计了一个大表，有百万条记录。但是其中包含非常多的重复的记录。（没关系）
?
执行如下的操作：
?
SQL> select count(*) from oe.seagal_orders where customer_id=118;
?
??COUNT(*)
----------
?????32768
?
?
然后，获得系统追踪文件：
?
SQL> select rtrim(c.value,'\') ||'\'||d.instance_name||
??2??'_ora_' ||ltrim(to_char(a.spid))||'.trc'
??3??from v$process a,v$session b,v$parameter c,v$instance d
??4??where a.addr=b.paddr
??5??and b.audsid =sys_context('userenv','sessionid')
??6??and c.name='user_dump_dest';
?
RTRIM(C.VALUE,'\')||'\'||D.INSTANCE_NAME||'_ORA_'||LTRIM(TO_CHAR(A.SPID))||'.TRC'
----------------------------------------------
E:\ORACLE\PRODUCT\10.2.0\ADMIN\MYORACLE\UDUMP\myoracle_ora_3708.trc
?
追踪文件的名字为myoracle_ora_3708.trc。
?
生成TKPROF报告在命令行提示符下，执行：
C:\>tkprof E:\ORACLE\PRODUCT\10.2.0\ADMIN\MYORACLE\UDUMP\myoracle_ora_3708.trc c:\tk.prof
?
TKPROF: Release?10.2.0.1.0 - Production on?星期一?3月?19 22:44:44 2007
?
Copyright (c) 1982, 2005, Oracle.??All rights reserved.
?
C:\>
?
生成的报告文件存储在C盘，文件名称为：tk.prof
阅读TKPROF报告这是一个文本文件，可以通过记事本或者EditPlus工具打开，阅读.报告的内容很长，需要自己阅读，下面截取一部分：
?
select count(*)
from
?oe. seagal _orders where customer_id=118
?
?
call?????count???????cpu????elapsed???????disk??????query????current????????rows
------- ------??-------- ---------- ---------- ---------- ----------??----------
Parse????????1??????0.00???????0.00??????????0?????????74??????????0???????????0
Execute??????1??????0.00???????0.00??????????0??????????0??????????0???????????0
Fetch????????2??????0.10???????0.11??????????0??????10360??????????0???????????1
------- ------??-------- ---------- ---------- ---------- ----------??----------
total????????4??????0.10???????0.11??????????0??????10434??????????0???????????1
?
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
?
Rows?????Row Source Operation
-------??---------------------------------------------------
??????1??SORT AGGREGATE (cr=10360 pr=0 pw=0 time=114189 us)
??32768???TABLE ACCESS FULL MYORDERS (cr=10360 pr=0 pw=0 time=131132 us)
?
?
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????????0.00??????????0.00
********************************************************************************
?
这部分就是刚才执行的查询语句的执行分析报告，理解这个报告需要首先了解一些基本的设置：
查询的三个主要阶段为：
1.?????????分析（Parse）：此阶段是Oracle在共享池中找到该查询（软分析）或创建该查询的新计划（硬分析）的所在。
2.?????????执行（Execute）：此阶段是由Oracle在该查询的OPEN或者EXECUTE语句中做的工作。对于SELECT语句，在许多情况下此阶段为空。对于UPDATE语句，此阶段将是执行所有工作的所在。
3.?????????提取（Fetch）：对于SELECT语句，大多数工作将在此阶段进行。对于UPDATE语句，将不显示任何工作（因为不从更新操作中提取）。
在报告的顶部可以看到的一些信息说明：
?
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
?
解释如下：
l??计数（Count）——查询在此阶段执行的次数。
l??CPU（cpu）——该查询在此阶段花费的CPU时间量，以毫秒为单位。
l??占用时间（Elapsed）——花费在此阶段的挂钟时间。当花费的时间大于CPU时间时，就意味着为某些事件耗费了等待时间。
l??磁盘—isk）——查询在此阶段中执行物理IO的次数。
l??查询（Query）——检索一致方式时执行逻辑IO的次数。那些块是从回滚段中重构的块。如果在查询开始时它们存在就可以看到。
l??当前（current）——到目前为止检索块时所执行的逻辑IO的次数。
l??行（Row）——此阶段中被处理或者受影响的行数。在更改操作中，将看到Exceute阶段的Rows值。在SELECT查询中，该值出现在Fetch阶段。
?
在报告中还可以看到一些信息：
Cr——表示为一致方式读取，显示一致读取数（逻辑IO）
R——物理读取
W——物理写
Time——以百万分之一秒计数的时间占用，即us秒（微秒）?
?
select count(*)
from
?oe. seagal _orders where customer_id=118
?
?
call?????count???????cpu????elapsed???????disk??????query????current????????rows
------- ------??-------- ---------- ---------- ---------- ----------??----------
Parse????????1??????0.00???????0.00??????????0?????????74??????????0???????????0
Execute??????1??????0.00???????0.00??????????0??????????0??????????0???????????0
Fetch????????2??????0.10???????0.11??????????0??????10360??????????0???????????1
------- ------??-------- ---------- ---------- ---------- ----------??----------
total????????4??????0.10???????0.11??????????0??????10434??????????0???????????1
?
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
?
Rows?????Row Source Operation
-------??---------------------------------------------------
??????1??SORT AGGREGATE (cr=10360 pr=0 pw=0 time=114189 us)
??32768???TABLE ACCESS FULL MYORDERS (cr=10360 pr=0 pw=0 time=131132 us)
?
?
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????????0.00??????????0.00
********************************************************************************
?
这部分就是刚才执行的查询语句的执行分析报告，理解这个报告需要首先了解一些基本的设置：
查询的三个主要阶段为：
1.?????????分析（Parse）：此阶段是Oracle在共享池中找到该查询（软分析）或创建该查询的新计划（硬分析）的所在。
2.?????????执行（Execute）：此阶段是由Oracle在该查询的OPEN或者EXECUTE语句中做的工作。对于SELECT语句，在许多情况下此阶段为空。对于UPDATE语句，此阶段将是执行所有工作的所在。
3.?????????提取（Fetch）：对于SELECT语句，大多数工作将在此阶段进行。对于UPDATE语句，将不显示任何工作（因为不从更新操作中提取）。
在报告的顶部可以看到的一些信息说明：
?
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
?
解释如下：
l??计数（Count）——查询在此阶段执行的次数。
l??CPU（cpu）——该查询在此阶段花费的CPU时间量，以毫秒为单位。
l??占用时间（Elapsed）——花费在此阶段的挂钟时间。当花费的时间大于CPU时间时，就意味着为某些事件耗费了等待时间。
l??磁盘—isk）——查询在此阶段中执行物理IO的次数。
l??查询（Query）——检索一致方式时执行逻辑IO的次数。那些块是从回滚段中重构的块。如果在查询开始时它们存在就可以看到。
l??当前（current）——到目前为止检索块时所执行的逻辑IO的次数。
l??行（Row）——此阶段中被处理或者受影响的行数。在更改操作中，将看到Exceute阶段的Rows值。在SELECT查询中，该值出现在Fetch阶段。
?
在报告中还可以看到一些信息：
Cr——表示为一致方式读取，显示一致读取数（逻辑IO）
R——物理读取
W——物理写
Time——以百万分之一秒计数的时间占用，即us秒（微秒）?