细说tkprof的使用方法
熟悉oracle的同学，对tkprof应该不会陌生。今天用到tkprof，有些语法变得模糊起来。查看文档，重新梳理有关tkprof的有关知识，加深记忆。
通过tkfprof可以非常方便的跟踪诊断sql语句的执行效率。结合explain plan的使用，更是如虎添翼。
sql trace为我们查看某天sql 语句的性能信息提供了可能，通常sqltrace可以生成下面的统计信息：
- Parse, execute, and fetch counts 解析 执行和抓取的动作数量
- CPU and elapsed times 花费在cpu和整个操作上的时间
- Physical reads and logical reads 物理读和逻辑读
- Number of rows processed 处理的记录数量
- Misses on the library cache 库缓存的丢失率
- Username under which each parse occurred 执行用户
- Each commit and rollback 每次的提交和回滚操作 （tkprofl不会处理这些信息）
- Wait event data for each SQL statement, and a summary for each trace file 针对每条sql语句和所有的sql语句生成事件信息数据
除此之外，如果在sql trace期间，跟踪的语句游标已经关闭，sql trace还会提供如下的行源信息
- Row operations showing the actual execution plan of each SQL statement
- Number of rows, number of consistent reads, number of physical reads, number ofphysical writes, and time elapsed for each operation on a row
语法格式：
[oracle@oadata trace]$ tkprof
Usage: tkprof tracefile outputfile [explain= ] [table= ]
[print= ] [insert= ] [sys= ] [sort= ]
table=schema.tablename Use 'schema.tablename' with 'explain=' option. --手动生成explain plan时，存储中间信息的临时表，默认为PROF$PLAN_TABLE
explain=user/password Connect to ORACLE and issue EXPLAIN PLAN. --手动生成explain时，连接数据库的用户名和密码
print=integer List only the first 'integer' SQL statements.--仅仅处理前integer数量的sql语句，如果我们需要生成脚本，该参数对脚本中包含的sql数量是不影响的
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. --是否包含sys用户生成的信息，如递归sql
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: --对语句进行排序
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
sql trace与执行计划：
如果在sqltrace期间，sql语句的游标已经关闭，sqltrace中会包含执行计划的相关信息
SQL> show user
USER 为 "SCOTT"
SQL> explain plan for select object_id,object_name,object_type from tab1 where object_id = 1000;
已解释。
SQL> select * from table(dbms_xplan.display());
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
Plan hash value: 2086140937
------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 41 | 1 (0)| 00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| TAB1 | 1 | 41 | 1 (0)| 00:00:01 |
|* 2 | INDEX RANGE SCAN | IND1 | 1 | | 1 (0)| 00:00:01 |
------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------
---------------------------------------------------
2 - access("OBJECT_ID"=1000)
Note
-----
- dynamic sampling used for this statement (level=2)
已选择18行。
SQL> alter session set sql_trace=true;
会话已更改。
SQL> alter session set tracefile_identifier='test1';
会话已更改。
SQL> select object_id,object_name,object_type from tab1 where object_id = 1000;
未选定行
******************************************************************************** SQL ID: 25kr54b04dq4v Plan Hash: 2086140937 select object_id,object_name,object_type from tab1 where object_id = 1000 call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 0 2 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 1 0.00 0.00 0 2 0 0 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 3 0.00 0.00 0 4 0 0 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: 83 Number of plan statistics captured: 1 --Rows (1st) Rows (avg) Rows (max) Row Source Operation ------------ ---------- ---------- --------------------------------------------------- -- 0 0 0 TABLE ACCESS BY INDEX ROWID TAB1 (cr=2 pr=0 pw=0 time=20 us cost=1 size=41 card=1) -- 0 0 0 INDEX RANGE SCAN IND1 (cr=2 pr=0 pw=0 time=16 us cost=1 size=0 card=1)(object id 101626) ********************************************************************************
如果游标没有关闭，则跟踪文件中不会包含该游标的执行计划信息。
SQL> Declare --Cursor C Is Select Object_Id,Object_Name,Object_Type From Tab1 Where Object_Id = 1111; Object_Id Number; Object_Name Varchar2(30); Object_Type Varchar2(19); Begin Open C; Fetch C Into Object_Id,Object_Name,Object_Type; Dbms_Lock.Sleep(1000); Close C; 11 End;
******************************************************************************** SQL ID: dxz49cn75rxtz Plan Hash: 2086140937 SELECT OBJECT_ID,OBJECT_NAME,OBJECT_TYPE FROM TAB1 WHERE OBJECT_ID = 1111 call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 0 2 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 1 0.00 0.00 0 3 0 1 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 3 0.00 0.00 0 5 0 1 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: 83 (recursive depth: 1) ********************************************************************************
如果之前sql语句已经执行过，则会包含执行计划
Declare --Cursor C Is Select Object_Id,Object_Name,Object_Type From Tab1 Where Object_Id = 1000; Object_Id Number; Object_Name Varchar2(30); Object_Type Varchar2(19); Begin Open C; Fetch C Into Object_Id,Object_Name,Object_Type; Dbms_Lock.Sleep(1000); Close C; 11 End; 12 /
********************************************************************************
SQL ID: 9guk3zj6busz4 Plan Hash: 2086140937
SELECT OBJECT_ID,OBJECT_NAME,OBJECT_TYPE
FROM
TAB1 WHERE OBJECT_ID = 1000
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 2 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 2 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 4 0 0
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 83 (recursive depth: 1)
Number of plan statistics captured: 1
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
0 0 0 TABLE ACCESS BY INDEX ROWID TAB1 (cr=2 pr=0 pw=0 time=19 us cost=1 size=41 card=1)
0 0 0 INDEX RANGE SCAN IND1 (cr=2 pr=0 pw=0 time=16 us cost=1 size=0 card=1)(object id 101626)
********************************************************************************
如果在跟踪文件中，不存在执行计划的相关信息，是否有其他的方法来生成执行计划那？当然有，利用explain参数选项就可以达到这个目的，测试tkprof会议explain指定的用户登录数据库，执行explain plan相关的语句来生成执行计划，并写入到跟踪文件：
SQL> Declare Cursor C Is Select Object_Id,Object_Name,Object_Type From Tab1 Where Object_Id = 2000; Object_Id Number; Object_Name Varchar2(30); Object_Type Varchar2(19); Begin Open C; Fetch C Into Object_Id,Object_Name,Object_Type; Dbms_Lock.Sleep(1000); Close C; 11 End; 12 /
********************************************************************************
SQL ID: 9k9wj84nxpm6t Plan Hash: 2086140937
SELECT OBJECT_ID,OBJECT_NAME,OBJECT_TYPE
FROM
TAB1 WHERE OBJECT_ID = 2000
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 2 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 3 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 0 5 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 83 (SCOTT) (recursive depth: 1)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT MODE: ALL_ROWS
0 TABLE ACCESS (BY INDEX ROWID) OF 'TAB1' (TABLE)
0 INDEX MODE: ANALYZED (RANGE SCAN) OF 'IND1' (INDEX)
********************************************************************************
SQL> Select Object_Id,Object_Name,Object_Type From Tab1 Where Object_Id = 2000;
OBJECT_ID OBJECT_NAME OBJECT_TYPE
---------- ------------------------------ -------------------
2000 V_$SQLSTATS_PLAN_HASH VIEW
SQL> Select Object_Id,Object_Name,Object_Type From Tab1 Where Object_Id = 2000;
OBJECT_ID OBJECT_NAME OBJECT_TYPE
---------- ------------------------------ -------------------
2000 V_$SQLSTATS_PLAN_HASH VIEW
跟踪文件内容：
PARSING IN CURSOR #47244034021040 len=73 dep=0 uid=83 oct=3 lid=83 tim=1388022158115297 hv=2221247730 ad='c9810e20' sqlid='88tvucq26b37k' Select Object_Id,Object_Name,Object_Type From Tab1 Where Object_Id = 2000 END OF STMT PARSE #47244034021040:c=3999,e=4256,p=0,cr=73,cu=0,mis=1,r=0,dep=0,og=1,plh=2086140937,tim=1388022158115296 EXEC #47244034021040:c=0,e=27,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2086140937,tim=1388022158115394 FETCH #47244034021040:c=0,e=41,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=1,plh=2086140937,tim=1388022158115541 FETCH #47244034021040:c=0,e=11,p=0,cr=1,cu=0,mis=0,r=0,dep=0,og=1,plh=2086140937,tim=1388022158115877 STAT #47244034021040 id=1 cnt=1 pid=0 pos=1 obj=101625 op='TABLE ACCESS BY INDEX ROWID TAB1 (cr=4 pr=0 pw=0 time=34 us cost=2 size=41 card=1)' STAT #47244034021040 id=2 cnt=1 pid=1 pos=1 obj=101626 op='INDEX RANGE SCAN IND1 (cr=3 pr=0 pw=0 time=28 us cost=1 size=0 card=1)' *** 2013-12-26 09:42:39.915 CLOSE #47244034021040:c=0,e=16,dep=0,type=0,tim=1388022159915788 ===================== PARSING IN CURSOR #47244034021040 len=73 dep=0 uid=83 oct=3 lid=83 tim=1388022159916048 hv=2221247730 ad='c9810e20' sqlid='88tvucq26b37k' Select Object_Id,Object_Name,Object_Type From Tab1 Where Object_Id = 2000 END OF STMT PARSE #47244034021040:c=0,e=113,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2086140937,tim=1388022159916046 EXEC #47244034021040:c=0,e=53,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2086140937,tim=1388022159916171 FETCH #47244034021040:c=0,e=65,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=1,plh=2086140937,tim=1388022159916330 FETCH #47244034021040:c=0,e=139,p=0,cr=1,cu=0,mis=0,r=0,dep=0,og=1,plh=2086140937,tim=1388022159916721 STAT #47244034021040 id=1 cnt=1 pid=0 pos=1 obj=101625 op='TABLE ACCESS BY INDEX ROWID TAB1 (cr=4 pr=0 pw=0 time=65 us cost=2 size=41 card=1)' STAT #47244034021040 id=2 cnt=1 pid=1 pos=1 obj=101626 op='INDEX RANGE SCAN IND1 (cr=3 pr=0 pw=0 time=186 us cost=1 size=0 card=1)'
tkprof格式化跟踪文件后的内容：
SQL ID: 88tvucq26b37k Plan Hash: 2086140937
Select Object_Id,Object_Name,Object_Type
From
Tab1 Where Object_Id = 2000
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.00 0 73 0 0
Execute 2 0.00 0.00 0 0 0 0
Fetch 4 0.00 0.00 0 8 0 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 8 0.00 0.00 0 81 0 2
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 83 (SCOTT)
Number of plan statistics captured: 2
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
1 1 1 TABLE ACCESS BY INDEX ROWID TAB1 (cr=4 pr=0 pw=0 time=50 us cost=2 size=41 card=1)
1 1 1 INDEX RANGE SCAN IND1 (cr=3 pr=0 pw=0 time=107 us cost=1 size=0 card=1)(object id 101626)
insert和records使用示例：
sqlplus中执行的脚本
SQL> select user from dual;
USER
------------------------------
SCOTT
SQL> select object_id ,object_name from tab1 where object_id < 20;
OBJECT_ID OBJECT_NAME
---------- ------------------------------
2 C_OBJ#
3 I_OBJ#
4 TAB$
5 CLU$
6 C_TS#
7 I_TS#
8 C_FILE#_BLOCK#
9 I_FILE#_BLOCK#
10 C_USER#
11 I_USER#
12 FET$
OBJECT_ID OBJECT_NAME
---------- ------------------------------
13 UET$
14 SEG$
15 UNDO$
16 TS$
17 FILE$
18 OBJ$
19 IND$
已选择18行。
SQL> select count(*) from tab1;
COUNT(*)
----------
73124
tkprof处理跟踪文件：
[oracle@oadata trace]$ tkprof *_test1.trc test1.txt insert=insert.sql record=record.sql
TKPROF: Release 11.2.0.3.0 - Development on 星期四 12月 26 10:10:06 2013
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
[oracle@oadata trace]$ cat insert.sql
REM Edit and/or remove the following CREATE TABLE
REM statement as your needs dictate.
CREATE TABLE tkprof_table
(
date_of_insert DATE
,cursor_num NUMBER
,depth NUMBER
,user_id NUMBER
,parse_cnt NUMBER
,parse_cpu NUMBER
,parse_elap NUMBER
,parse_disk NUMBER
,parse_query NUMBER
,parse_current NUMBER
,parse_miss NUMBER
,exe_count NUMBER
,exe_cpu NUMBER
,exe_elap NUMBER
,exe_disk NUMBER
,exe_query NUMBER
,exe_current NUMBER
,exe_miss NUMBER
,exe_rows NUMBER
,fetch_count NUMBER
,fetch_cpu NUMBER
,fetch_elap NUMBER
,fetch_disk NUMBER
,fetch_query NUMBER
,fetch_current NUMBER
,fetch_rows NUMBER
,ticks NUMBER
,sql_statement LONG
);
set sqlterminator off
INSERT INTO tkprof_table VALUES
(
SYSDATE, 1, 0, 83, 1, 1000, 1321, 0, 0, 0, 1
, 1, 0, 40, 140733193388032, 0, 206158430208, 140733193388032, 140733193388032
, 2, 0, 20, 0, 0, 0, 1, 625
, 'select user from dual
')
/
INSERT INTO tkprof_table VALUES
(
SYSDATE, 2, 1, 83, 1, 0, 658, 0, 0, 0, 1
, 1, 2000, 1288, 140733193388032, 0, 0, 1, 0
, 1, 1000, 1824, 0, 69, 0, 1, 18354695
, 'SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE NO_PARALLEL(SAMPLESUB) opt_param(''parallel_execution_enabled'', ''false'') NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_0"), NVL(SUM(C2),:"SYS_B_1") FROM (SELECT /*+ IGNORE_WHERE_CLAUSE NO_PARALLEL("TAB1") FULL("TAB1") NO_PARALLEL_INDEX("TAB1") */ :"SYS_B_2" AS C1, CASE WHEN "TAB1"."OBJECT_ID"<:"SYS_B_3" THEN :"SYS_B_4" ELSE :"SYS_B_5" END AS C2 FROM "SCOTT"."TAB1" SAMPLE BLOCK (:"SYS_B_6" , :"SYS_B_7") SEED (:"SYS_B_8") "TAB1") SAMPLESUB
')
/
INSERT INTO tkprof_table VALUES
(
SYSDATE, 2, 1, 83, 1, 0, 624, 0, 0, 0, 1
, 1, 2000, 1436, 140733193388032, 0, 0, 1, 0
, 1, 0, 73, 0, 2, 0, 1, 2487
, 'SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS opt_param(''parallel_execution_enabled'', ''false'') NO_PARALLEL(SAMPLESUB) NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_0"), NVL(SUM(C2),:"SYS_B_1"), NVL(SUM(C3),:"SYS_B_2") FROM (SELECT /*+ NO_PARALLEL("TAB1") INDEX("TAB1" IND1) NO_PARALLEL_INDEX("TAB1") */ :"SYS_B_3" AS C1, :"SYS_B_4" AS C2, :"SYS_B_5" AS C3 FROM "SCOTT"."TAB1" "TAB1" WHERE "TAB1"."OBJECT_ID"<:"SYS_B_6" AND ROWNUM <= :"SYS_B_7") SAMPLESUB
')
/
INSERT INTO tkprof_table VALUES
(
SYSDATE, 1, 0, 83, 1, 3998, 2275, 0, 2, 0, 1
, 1, 0, 25, 140733193388032, 0, 0, 0, 0
, 3, 0, 83, 0, 7, 0, 18, 1697
, 'select object_id ,object_name from tab1 where object_id < 20
')
/
INSERT INTO tkprof_table VALUES
(
SYSDATE, 2, 1, 83, 1, 1000, 614, 0, 0, 0, 1
, 1, 1000, 1204, 140733193388032, 0, 0, 1, 0
, 1, 1000, 1447, 0, 69, 0, 1, 8979687
, 'SELECT /* OPT_DYN_SAMP */ /*+ ALL_ROWS IGNORE_WHERE_CLAUSE NO_PARALLEL(SAMPLESUB) opt_param(''parallel_execution_enabled'', ''false'') NO_PARALLEL_INDEX(SAMPLESUB) NO_SQL_TUNE */ NVL(SUM(C1),:"SYS_B_0"), NVL(SUM(C2),:"SYS_B_1") FROM (SELECT /*+ NO_PARALLEL("TAB1") FULL("TAB1") NO_PARALLEL_INDEX("TAB1") */ :"SYS_B_2" AS C1, :"SYS_B_3" AS C2 FROM "SCOTT"."TAB1" SAMPLE BLOCK (:"SYS_B_4" , :"SYS_B_5") SEED (:"SYS_B_6") "TAB1") SAMPLESUB
')
/
INSERT INTO tkprof_table VALUES
(
SYSDATE, 1, 0, 83, 1, 2000, 1703, 0, 2, 0, 1
, 1, 0, 35, 140733193388032, 0, 0, 0, 0
, 2, 12998, 12565, 159, 169, 0, 1, 13861
, 'select count(*) from tab1
')
/
set sqlterminator on
[oracle@oadata trace]$ cat record.sql
select user from dual ;
select object_id ,object_name from tab1 where object_id < 20 ;
select count(*) from tab1 ;
[oracle@oadata trace]$
Avoiding the Argument Trap
If you are not aware of the values being bound at run time, then it is possible to fall into the argument trap.EXPLAINPLANcannot
determine the type of a bind variable from the text of SQL statements, and it always assumes that the type isvarchar. If the bind variable is actually a number or a date, thenTKPROFcan
cause implicit data conversions, which can cause inefficient plans to be executed. To avoid this situation, experiment with different data types in the query.
To avoid this problem, perform the conversion yourself.
Avoiding the Read Consistency Trap
The next example illustrates the read consistency trap. Without knowing that an uncommitted transaction had made a series of updates to theNAMEcolumn, it is very
difficult to see why so many block visits would be incurred.
Cases like this are not normally repeatable: if the process were run again, it is unlikely that another transaction would interact with it in the same way.
SELECT name_id
FROM cq_names
WHERE name = 'FLOOR';
call count cpu elapsed disk query current rows
---- ----- --- ------- ---- ----- ------- ----
Parse 1 0.10 0.18 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.11 0.21 2 101 0 1
Misses in library cache during parse: 1
Parsing user id: 01 (USER1)
Rows Execution Plan
---- --------- ----
0 SELECT STATEMENT
1 TABLE ACCESS (BY ROWID) OF 'CQ_NAMES'
2 INDEX (RANGE SCAN) OF 'CQ_NAMES_NAME' (NON_UNIQUE)
Avoiding the Schema Trap
This example shows an extreme (and thus easily detected) example of the schema trap. At first, it is difficult to see why such an apparently straightforward indexed query needs to look at so many database blocks, or why it should access any blocks at all in current mode.
SELECT name_id
FROM cq_names
WHERE name = 'FLOOR';
call count cpu elapsed disk query current rows
-------- ------- -------- --------- ------- ------ ------- ----
Parse 1 0.06 0.10 0 0 0 0
Execute 1 0.02 0.02 0 0 0 0
Fetch 1 0.23 0.30 31 31 3 1
Misses in library cache during parse: 0
Parsing user id: 02 (USER2)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT
2340 TABLE ACCESS (BY ROWID) OF 'CQ_NAMES'
0 INDEX (RANGE SCAN) OF 'CQ_NAMES_NAME' (NON-UNIQUE)
Two statistics suggest that the query might have been executed with a full table scan. These statistics are the current mode block visits, plus the number of rows originating from the Table Access row
source in the execution plan. The explanation is that the required index was built after the trace file had been produced, but beforeTKPROFhad been run.
Generating a new trace file gives the following data:
SELECT name_id
FROM cq_names
WHERE name = 'FLOOR';
call count cpu elapsed disk query current rows
----- ------ ------ -------- ----- ------ ------- -----
Parse 1 0.01 0.02 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 0 2 0 1
Misses in library cache during parse: 0
Parsing user id: 02 (USER2)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT
1 TABLE ACCESS (BY ROWID) OF 'CQ_NAMES'
2 INDEX (RANGE SCAN) OF 'CQ_NAMES_NAME' (NON-UNIQUE)
One of the marked features of this correct version is that the parse call took 10 milliseconds of CPU time and 20 milliseconds of elapsed time, but the query apparently took no time at all to execute and perform the fetch. These anomalies arise because the clock tick of 10 milliseconds is too long relative to the time taken to execute and fetch the data. In such cases, it is important to get lots of executions of the statements, so that you have statistically valid numbers.
Avoiding the Time Trap
Sometimes, as in the following example, you might wonder why a particular query has taken so long.
UPDATE cq_names SET ATTRIBUTES = lower(ATTRIBUTES)
WHERE ATTRIBUTES = :att
call count cpu elapsed disk query current rows
-------- ------- -------- --------- -------- -------- ------- ----------
Parse 1 0.06 0.24 0 0 0 0
Execute 1 0.62 19.62 22 526 12 7
Fetch 0 0.00 0.00 0 0 0 0
Misses in library cache during parse: 1
Parsing user id: 02 (USER2)
Rows Execution Plan
------- ---------------------------------------------------
0 UPDATE STATEMENT
2519 TABLE ACCESS (FULL) OF 'CQ_NAMES'
Again, the answer is interference from another transaction. In this case, another transaction held a shared lock on the tablecq_namesfor several seconds before and
after the update was issued. It takes a fair amount of experience to diagnose that interference effects are occurring. On the one hand, comparative data is essential when the interference is contributing only a short delay (or a small increase in block visits
in the previous example). However, if the interference contributes only modest overhead, and if the statement is essentially efficient, then its statistics may not require analysis.
分享到：
发表评论
相关推荐
Oracle跟踪文件分析工具TKPROF使用简介[文].pdf
使用 Tkprof 分析 ORACLE 跟踪文件，通过这个文档，告诉大家如何使用tkprof这个工具。
系统的执行效率比较低，一个比较好的方法是通过跟踪用户的会话并且使用Tkprof 工具使用排序功能格式 化输出，从而找出有问题的SQL 语句。 TKPROF 工具是oracle 提供的免费工具，有人习惯称之为"Trace Kernel Profile...
tkprof介绍,简要介绍了tkprof的原理和方法。
Tkprof工具介绍和分析 kprof是一个用于分析Oracle跟踪文件并且产生一个...如果一个系统的执行效率比较低，一个比较好的方法是通过跟踪用户的会话并且使用Tkprof工具使用排序功能格式化输出，从而找出有问题的SQL语句。
Oracle Ebs官方工具Tidy 代替tkprof，Oracle Trace 跟踪文件格式化工具，可观测语句绑定变量的值。
详解tkprof转换后的文件格式，用于SQL语句的分析和性能调优
SQL Trace and TKPROF
本人整理的几種oralce性能優化分析。命令和使用方法主要是EXPLAIN和TKPROF的使用
• 使用解释计划工具或 tkprof 工具优化你的 SQL 语句。 • 使用 SQL*Plus 或另外的工具在你的数据库里查看或修改其它对象和数据。 这些任务 - 编辑、编译、纠正、测试、调试、优化和查询 - 在不离开 PL/SQL ...
6.sql trace分析工具--TKPROF详细讲解 7.V$SQL视图详解加几个实例 8.autotrace验证压缩表性能 9.autotrace验证消除子查询后的性能 10.基于基本的优化CBO 11.如何统计数据库数据 12.Oracle如何统计操作系统数据 13./*...
从目前来看，分析Oracle日志的唯一方法就是使用Oracle公司提供的LogMiner来进行， Oracle数据库的所有更改都记录在日志中，但是原始的日志信息我们根本无法看懂，而LogMiner就是让我们看懂日志信息的工具。...
1.如何分析SQL语句 2.选用适合的ORACLE优化器 3.用EXPLAIN PLAN 分析SQL语句 4.使用TKPROF 工具来查询SQL性能状态 5.表分区的应用
PL/SQL Developer 是一个为 Oracle 数据库开发存储程序单元的集成开发环境(IDE)， ...• 使用解释计划工具或 tkprof 工具优化你的 SQL 语句。 • 使用 SQL*Plus 或其他工具在你的数据库中查看或修改其他对象和数据。
sqlmonitor 1. 找出sid和serial# select sid,serial#,osuser from v$session t where t.USERNAME='USERNAME' ... 使用tkprof文件解析trace文件 例: tkprof sqltrace文件.trc a.out 8. 打开a.out
介绍 PL/SQL Developer 是一个为 Oracle 数据库开发存储程序单元的集成开发环境(I...• 使用解释计划工具或 tkprof 工具优化你的 SQL 语句。 • 使用 SQL*Plus 或另外的工具在你的数据库里查看或修改其它对象和数据。
· 使用解释计划工具或 tkprof 工具优化你的 SQL 语句。 · 使用 SQL*Plus 或另外的工具在你的数据库里查看或修改其它对象和数据。 这些任务 - 编辑、编译、纠正、测试、调试、优化和查询，在不离开 PL/SQL ...
· 使用解释计划工具或 tkprof 工具优化你的 SQL 语句。 · 使用 SQL*Plus 或另外的工具在你的数据库里查看或修改其它对象和数据。 这些任务 - 编辑、编译、纠正、测试、调试、优化和查询，在不离开 PL/SQL ...
PL/SQL Developer 是一个为 Oracle 数据库开发存储程序单元的集成开发环境(IDE)，使用 ... 使用解释计划工具或 tkprof 工具优化你的 SQL 语句。 ? 使用 SQL*Plus 或另外的工具在你的数据库里查看或修改其它对象和数据。
1. 介绍 PL/SQL Developer 是一个为 Oracle 数据库开发存储程序单元的集成开发环境...• 使用解释计划工具或 tkprof 工具优化你的 SQL 语句。 • 使用 SQL*Plus 或另外的工具在你的数据库里查看或修改其它对象和数据