22.6.2 TKPROF
TKPROF程序格式化跟踪文件的内容，并将输出放入可读的输出文件中。
TKPROF还可以执行以下操作：
- 创建一个将统计信息存储在数据库中的SQL脚本
- 确定SQL语句的执行计划
注意：
如果未关闭SQL语句的游标，则TKPROF输出不会自动包含SQL语句的实际执行计划。在这种情况下，请将该
EXPLAIN选项与TKPROF一起使用以生成执行计划。
TKPROF报告执行的每个语句及其消耗的资源，被调用的次数以及所处理的行数。
本节包含以下主题：
22.6.2.1目的
TKPROF可以找到消耗最大资源的语句。
有了可用的基准，您可以评估所执行的工作是否合理。
22.6.2.2准则
输入和输出文件是唯一必需的参数。
如果您在不带参数的情况下调用TKPROF，则该工具将显示联机帮助。
22.6.2.3语法
tkprof input_file output_file
[ waits=yes|no ]
[ sort=option ]
[ print=n ]
[ aggregate=yes|no ]
[ insert=filename3 ]
[ sys=yes|no ]
[ table=schema.table ]
[ explain=user/password ]
[ record=filename4 ]
[ width=n ]
22.6.2.4选项
TKPROF支持许多命令行选项。
表22-3 TKPROF参数
| 参数 | 描述 |
|---|---|
| 指定输入文件，一个跟踪文件，其中包含SQL跟踪工具生成的统计信息。该文件可以是为单个会话生成的跟踪文件，也可以是通过将来自多个会话的单个跟踪文件串联而生成的文件。 |
| 指定要 |
| 指定是否为在跟踪文件中找到的任何等待事件记录摘要。有效值为 |
| 在输出文件中列出跟踪的SQL语句之前，先按指定的排序选项的降序对其进行排序。如果指定了多个选项，则输出将按照排序选项中指定的值之和以降序排序。如果省略此参数，则
|
| 仅列出输出文件中第一个整数排序的SQL语句。如果省略此参数，则 |
| 如果指定 |
| 创建一个SQL脚本，将跟踪文件统计信息存储在数据库中。 |
| 启用和禁用由用户发出的SQL语句 |
| 指定在 指定的用户必须能够发出 此选项使多个用户可以
如果不存在计划表，则 |
| 确定跟踪文件中每个SQL语句的执行计划，并将这些执行计划写入输出文件。
注意：实例启动后立即生成的跟踪文件包含反映启动过程活动的数据。特别是，当系统全局区域（SGA）中的缓存被填充时，它们反映出不成比例的I / O活动。为了进行调整，请忽略此类跟踪文件。 |
|
|
| 一个整数，用于控制某些 |
22.6.2.5输出
本节说明TKPROF输出。
本节包含以下主题：
- TKPROF ：
TKPROF中发布SQL语句的用户的标识列出了发布每个SQL语句的用户的用户ID。 - TKPROF中的表格统计TKPROF在行和列中列出了SQL跟踪工具返回的SQL语句的统计信息。
- TKPROF中 ： 的库高速缓存未命中 TKPROF还列出了每个SQL语句的解析和执行步骤所导致的库高速缓存未命中数。
- TKPROF中的行源操作在TKPROF ： 输出中，行源操作显示针对行执行的每个操作处理的行数，以及其他行源信息，例如物理读取和写入。
- TKPROF中的 ： 等待事件信息如果存在等待事件信息，则
TKPROF输出包括有关等待事件的部分。
22.6.2.5.1在TKPROF中发出SQL语句的用户的标识
TKPROF 列出发出每个SQL语句的用户的用户ID。
如果SQL Trace输入文件包含来自多个用户的统计信息，并且该语句是由多个用户发出的，则TKPROF列出最后一个要解析该语句的用户的ID。所有数据库用户的用户ID出现在列的数据字典中ALL_USERS。USER_ID。
22.6.2.5.2 TKPROF中的表格统计
TKPROF在行和列中列出了SQL跟踪工具返回的SQL语句的统计信息。
每行对应于SQL语句处理的三个步骤之一。统计信息由该CALL列的值标识。请参阅表22-4。
表22-4 CALL列值
| 通话价值 | 含义 |
|---|---|
| 将SQL语句转换为执行计划，包括检查适当的安全授权以及检查表，列和其他引用对象的存在。 |
| Oracle数据库实际执行该语句。对于 |
| 检索查询返回的行。提取仅针对 |
SQL Trace工具输出的其他列是语句的所有解析，执行和提取的组合统计信息。的总和query与current被访问缓冲器的总数，也被称为逻辑I / O（LIOS）。请参阅表22-5。
表22-5用于分析，执行和提取的SQL跟踪统计信息。
| SQL跟踪统计 | 含义 |
|---|---|
| 语句被解析，执行或获取的次数。 |
| 所有对该语句的解析，执行或获取调用的CPU总时间（以秒为单位）。如果 |
| 该语句的所有解析，执行或提取调用的总经过时间（以秒为单位）。如果 |
| 从磁盘上的数据文件实际读取的，用于所有解析，执行或获取调用的数据块总数。 |
| 在所有解析，执行或提取调用中，以一致模式检索的缓冲区总数。通常，以一致的方式检索缓冲区以进行查询。 |
| 当前模式下检索到的缓冲区总数。缓冲区在电流模式中检索的语句，例如 |
有关已处理行的统计信息显示在该ROWS列中。该列显示了SQL语句处理的行数。此总数不包括由SQL语句的子查询处理的行。对于SELECT语句，将在获取步骤中显示返回的行数。对于UPDATE，DELETE和INSERT语句，将为执行步骤显示已处理的行数。
注意：
当关闭游标时，将显示行源计数。在SQL * Plus中，只有一个用户游标，因此执行的每个语句都会导致前一个游标被关闭；因此，将显示行源计数。PL / SQL具有自己的游标处理，并且在关闭父游标时不会关闭子游标。退出或重新连接将显示计数。
22.6.2.5.3 TKPROF中的库高速缓存未命中
TKPROF还列出了每个SQL语句的解析和执行步骤所导致的库高速缓存未命中数。
这些统计信息显示在表格统计信息之后的不同行上。如果该语句未导致任何库高速缓存未命中，TKPROF则不列出该统计信息。在“ 示例 ”中，该语句导致解析步骤一个库高速缓存未命中，而执行步骤没有未命中。
22.6.2.5.4 TKPROF中的行源操作
在TKPROF输出中，行源操作显示对行执行的每个操作处理的行数，以及其他行源信息，例如物理读取和写入。
表22-6行源操作
| 行源操作 | 含义 |
|---|---|
| 行源执行的读取一致。 |
| 行源执行的物理读取 |
| 行源执行的物理写入 |
| 时间（以微秒为单位） |
在下面的示例TKPROF输出，请注意cr，r，w，和time行来源操作列下的值：
Rows Row Source Operation
------- ---------------------------------------------------
0 DELETE (cr=43141 r=266947 w=25854 time=60235565 us)
28144 HASH JOIN ANTI (cr=43057 r=262332 w=25854 time=48830056 us)
51427 TABLE ACCESS FULL STATS$SQLTEXT (cr=3465 r=3463 w=0 time=865083 us)
647529 INDEX FAST FULL SCAN STATS$SQL_SUMMARY_PK
(cr=39592 r=39325 w=0 time=10522877 us) (object id 7409)
22.6.2.5.5 TKPROF中的等待事件信息
如果存在等待事件信息，则TKPROF输出将包含有关等待事件的部分。
输出看起来类似于以下内容：
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 8084 0.12 5.34
direct path write 834 0.00 0.00
direct path write temp 834 0.00 0.05
db file parallel read 8 1.53 5.51
db file scattered read 4180 0.07 1.45
direct path read 7082 0.00 0.05
direct path read temp 7082 0.00 0.44
rdbms ipc reply 20 0.00 0.01
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 0.00 0.00
另外，在文件末尾，整个跟踪文件的等待事件被汇总。
为确保将等待事件信息写入会话的跟踪文件，请运行以下SQL语句：
ALTER SESSION SET EVENTS '10046 trace name context forever, level 8';
22.6.2.6示例
本节演示了常见的TKPROF用例。
示例22-4打印资源占用最大的语句
如果要使用SORT参数和PRINT参数的组合来处理大型跟踪文件，则可以生成TKPROF仅包含资源占用最大的语句的输出文件。以下语句在跟踪文件中显示生成最多物理I / O的10条语句：
TKPROF ora53269.trc ora53269.prf SORT = (PRSDSK, EXEDSK, FCHDSK) PRINT = 10示例22-5生成SQL脚本
本示例运行TKPROF，接受名为的跟踪文件examp12_jane_fg_sqlplus_007.trc，并编写名为的格式化输出文件outputa.prf：
TKPROF examp12_jane_fg_sqlplus_007.trc OUTPUTA.PRF EXPLAIN=hr TABLE=hr.temp_plan_table_a INSERT=STOREA.SQL SYS=NO
SORT=(EXECPU,FCHCPU)
此示例可能比屏幕上的一行长，并且您可能需要使用连续字符，具体取决于操作系统。
请注意此示例中的其他参数：
- 该
EXPLAIN值导致TKPROF以用户身份连接，hr并使用该EXPLAIN PLAN语句为每个跟踪的SQL语句生成执行计划。您可以使用它来获取访问路径和行源计数。注意：
如果未关闭SQL语句的游标，则
TKPROF输出不会自动包含SQL语句的实际执行计划。在这种情况下，您可以将EXPLAIN选项与TKPROF用于生成执行计划。 - 该
TABLE值会导致TKPROF使用该表temp_plan_table_a在架构中scott作为临时计划表。 - 该
INSERT值导致TKPROF生成名为的SQL脚本STOREA。SQL在数据库中存储所有跟踪的SQL语句的统计信息。 SYS带有NOcause 值的参数TKPROF将省略输出文件中的递归SQL语句。这样，您可以忽略内部Oracle数据库语句，例如临时表操作。- 该
SORT值使TKPROFSQL语句按照执行所花费的CPU时间和在将行写入输出文件之前获取行所花费的CPU时间之和的顺序进行排序。为了获得最大的效率，请始终使用SORT参数。
示例22-6 TKPROF标头
本示例显示了TKPROF报告的示例标题。
TKPROF: Release 12.1.0.0.2
Copyright (c) 1982, 2012, Oracle and/or its affiliates. All rights reserved.
Trace file: /disk1/oracle/log/diag/rdbms/orcla/orcla/trace/orcla_ora_917.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
********************************************************************************示例22-7 TKPROF主体
本示例显示了TKPROF报告的示例正文。
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 0.01 0.00 0 0 0 0
Misses in library cache during parse: 1
Optimizer mode: FIRST_ROWS
Parsing user id: 44
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 28.59 28.59
********************************************************************************
select condition
from
cdef$ where rowid=:1
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 1 0.00 0.00 0 2 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 2 0 1
Misses in library cache during parse: 1
Optimizer mode: CHOOSE
Parsing user id: SYS (recursive depth: 1)
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS BY USER ROWID OBJ#(31) (cr=1 r=0 w=0 time=151 us)
********************************************************************************
SELECT last_name, job_id, salary
FROM employees
WHERE salary =
(SELECT max(salary) FROM employees)
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.02 0.01 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 15 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.02 0.01 0 15 0 1
Misses in library cache during parse: 1
Optimizer mode: FIRST_ROWS
Parsing user id: 44
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL EMPLOYEES (cr=15 r=0 w=0 time=1743 us)
1 SORT AGGREGATE (cr=7 r=0 w=0 time=777 us)
107 TABLE ACCESS FULL EMPLOYEES (cr=7 r=0 w=0 time=655 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 9.62 9.62
********************************************************************************
********************************************************************************
delete
from stats$sqltext st
where (hash_value, text_subset) not in
(select --+ hash_aj
hash_value, text_subset
from stats$sql_summary ss
where ( ( snap_id < :lo_snap
or snap_id > :hi_snap
)
and dbid = :dbid
and instance_number = :inst_num
)
or ( dbid != :dbid
or instance_number != :inst_num)
)
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 29.60 60.68 266984 43776 131172 28144
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 29.60 60.68 266984 43776 131172 28144
Misses in library cache during parse: 1
Misses in library cache during execute: 1
Optimizer mode: CHOOSE
Parsing user id: 22
Rows Row Source Operation
------- ---------------------------------------------------
0 DELETE (cr=43141 r=266947 w=25854 time=60235565 us)
28144 HASH JOIN ANTI (cr=43057 r=262332 w=25854 time=48830056 us)
51427 TABLE ACCESS FULL STATS$SQLTEXT (cr=3465 r=3463 w=0 time=865083 us)
647529 INDEX FAST FULL SCAN STATS$SQL_SUMMARY_PK
(cr=39592 r=39325 w=0 time=10522877 us) (object id 7409)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 8084 0.12 5.34
direct path write 834 0.00 0.00
direct path write temp 834 0.00 0.05
db file parallel read 8 1.53 5.51
db file scattered read 4180 0.07 1.45
direct path read 7082 0.00 0.05
direct path read temp 7082 0.00 0.44
rdbms ipc reply 20 0.00 0.01
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 0.00 0.00
********************************************************************************示例22-8 TKPROF摘要
此示例显示TKPROF报告的摘要。
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 4 0.04 0.01 0 0 0 0
Execute 5 0.00 0.04 0 0 0 0
Fetch 2 0.00 0.00 0 15 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 11 0.04 0.06 0 15 0 1
Misses in library cache during parse: 4
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 6 0.00 0.00
SQL*Net message from client 5 77.77 128.88
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
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 1 0.00 0.00 0 2 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 2 0 1
Misses in library cache during parse: 1
5 user SQL statements in session.
1 internal SQL statements in session.
6 SQL statements in session.
********************************************************************************
Trace file: main_ora_27621.trc
Trace file compatibility: 9.00.01
Sort options: default
1 session in tracefile.
5 user SQL statements in trace file.
1 internal SQL statements in trace file.
6 SQL statements in trace file.
6 unique SQL statements in trace file.
76 lines in trace file.
128 elapsed seconds in trace file.