Saturday, June 21, 2008

How do we make trace file readable by using TKPROF?

TKPROF is Oracle utility to convert the Orace trace file into readable format. It is one of the most useful utility available to DBAs for diagnosing performance issues

TKPROF syntax is:

tkprof filename1 filename2 [waits=yesno] [sort=option] [print=n]
[aggregate=yesno] [insert=filename3] [sys=yesno] [table=schema.table]
[explain=user/password] [record=filename4] [width=n]

Here is the example to use the TKPROF utility.

tkprof dmdprod_ora_11154.trc traceoutput.txt sys=no

TKPROF command line options.

Print – This option will list number SQL statement in trace file. We can use this command when we want to list only specific number sql statement. This command is very useful when combining SORT option to list only top N statement by CPU, disk access etc.

Aggregate – When it is YES, then combine the statistics from multiple user execution for the same SQL statement.

Waits - It is used to record summary for any wait events found in the trace file

Insert – Create file to load the trace info into table for further processing. This will be useful for future analysis.

Sys – If it is NO, then it will exclude SQL statement which is executed by SYS schema. The default value is YES.

Table – It is used to load the explain plan info into table. We need to specify the schema name and table name to load the explain plan info. The table old data will be deleted when we use this option. If the table does not exist, then oracle will create the table to load the data.

Record – It is used to store all the non recursive SQL statement from the trace file. This statement can be used if we want to log the SQL statement in separate file.

Explain – It will be used if we want to generate the pre determined execution plan in trace file. When you use this option, you will see execution plan as well as Real plan in trace file. Execution plan is pre execution plan(like asking direction to home), Real Plan(like showing direction how you got home. In trace file, Real Plan will be displayed as Row source generation).

Sort – It will be useful if we want to see the top SQL which are consumed the most resources. Resource like CPU usage, disk usage etc.

The following are the data elements available for sorting:

. prscnt – The number of times the SQL was parsed.
· prscpu – The CPU time spent parsing.
· prsela – The elapsed time spent parsing the SQL.
· prsdsk – The number of physical reads required for the parse.
· prsmis – The number of consistent block reads required for the parse.
· prscu – The number of current block reads required for the parse.
· execnt – The number of times the SQL statement was executed.
· execpu – The CPU time spent executing the SQL.
· exeela – The elapsed time spent executing the SQL.
· exedsk – The number of physical reads during execution.
· exeqry – The number of consistent block reads during execution.
· execu – The number of current block reads during execution.
· exerow – The number of rows processed during execution.
· exemis – The number of library cache misses during execution.
· fchcnt – The number of fetches performed.
· fchcpu – The CPU time spent fetching rows.
· fchela – The elapsed time spent fetching rows.
· fchdsk – The number of physical disk reads during the fetch.
· fchqry – The number of consistent block reads during the fetch.
· fchcu – The number of current block reads during the fetch.
· fchrow – The number of rows fetched for the query.

TKPROF output

update COLLECTION set body=:1, control_no=:2, STATE=:3,
created_dt=:4, author=:5
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- -------------------
Parse 0 0.00 0.00 0 0 0 0

Execute 1 55.99 145.55 1057 9495719 8238 1
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- -------------------
total 2 55.99 145.56 1057 9495719 8238 1

Misses in library cache during parse: 1

Optimizer goal: FIRST_ROWS
Parsing user id: 67
Rows Row Source Operation
------- --------------------------------------------------------------------------------

1. Parse – Parse does syntax checks, permissions, and all object dependencies.
2. Execute – The actual execution of the statement.
3. Fetch – The number of rows returned for a SELECT statement

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


EXPLAIN PLAN and v$sql_plan are providing same type of information. EXPLAIN PLAN command is used to display the execution plan of a SQL statement without actually executing it. But v$sql_plan dictionary view is used to show the execution plan of the SQL statement that has been compiled into a cursor in the cache.

What should DBA look in tkprof output file?
1. Compare the number of parses to number of executions. A Well defined system will have one parse per n executions.
2. Check any SQL do not use bind variables
3. Check if there is any Full table scan, Multiple disk reads, high CPU consumption.

No comments: