Database Reference
In-Depth Information
I discuss the same example for the output file of both profilers. The trace file used as an example in this section
was generated by executing the
long_parse.sql
script. The trace file and the output files are available in the
long_parse.zip
file.
Using TKPROF
As with quick parses, the analysis starts at the end of the TKPROF output. In this specific case, it's significant to note
that the processing lasted about 2 seconds and that the application executed only three SQL statements. All other SQL
statements were recursively executed by the database engine.
1 session in tracefile.
3 user SQL statements in trace file.
13 internal SQL statements in trace file.
16 SQL statements in trace file.
16 unique SQL statements in trace file.
9644 lines in trace file.
2 elapsed seconds in trace file.
By looking at the execution statistics of the first SQL statement in the output file, it's possible to see not only that it
was responsible for the whole response time (more than 2 seconds), but also that all the time is spent on a single parse:
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 2.65
2.65
0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 10 10 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 2.65
2.66
10 10 0 1
Using TVD$XTAT
As with quick parses, the analysis of the TVD$XTAT output starts by looking at the overall resource usage profile. The
processing lasted about 2.8 seconds. Of this time, about 98% was spent running on the CPU. Also notice that in this
case, the unaccounted-for time is very short and, therefore, completely negligible.
Total Number of Duration per
Component Duration % Events Event
--------------------------- -------- ------- --------- ------------
CPU
2.769 98.383
n/a n/a
db file sequential read 0.027 0.943 314 0.000
unaccounted-for 0.017 0.596 n/a n/a
SQL*Net message from client 0.002 0.078 3 0.001
SQL*Net message to client 0.000 0.000 3 0.000
--------------------------- -------- -------
Total 2.814 100.000
Just by looking at the summary of nonrecursive SQL statements, you can see that three SQL statements were
executed. Of them, a
SELECT
statement is responsible for almost all the response time.
