Database Reference
In-Depth Information
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 10000 0.00 0.02
SQL*Net message from client 10000 0.02
6.24
latch: shared pool 5 0.00 0.00
log file sync 1 0.00 0.00
Since you know that parsing is a problem, it's wise to take a look at the SQL statements. In this case, by looking at
a few of them (the following are the top five), it's evident that they are very similar. Only the literals used in the
WHERE
clauses are different. This is a typical case where bind variables aren't used.
SELECT pad FROM t WHERE val = 0
SELECT pad FROM t WHERE val = 2139
SELECT pad FROM t WHERE val = 9035
SELECT pad FROM t WHERE val = 8488
SELECT pad FROM t WHERE val = 1
The problem in such situations is that TKPROF doesn't recognize SQL statements that differ only in their literals.
In fact, even when the
aggregate
option is set to
yes
, which is the default, only the SQL statements that have the same
text are grouped together. This is a major flaw that in real cases makes analyzing quick parse problems with TKPROF
difficult. To make it a bit easier, it's possible to specify the
record
option. In this way, a file containing only the SQL
statements is generated.
tkprof <trace file> <output file> sys=no sort=prsela,exeela,fchela record=<sql file>
Then you can use command-line utilities such as
grep
and
wc
to find out how many similar SQL statements are
available. For example, the following command returns the value 10,000:
grep "SELECT pad FROM t WHERE val =" <sql file> | wc -l
Using TVD$XTAT
TVD$XTAT is executed without specifying particular options:
tvdxtat -i <trace file> -o <output file>
The analysis of the output file starts by looking at the overall resource usage profile. The processing here lasted
about 14 seconds. Of this time, about 43% was spent waiting for the client, and 40% was spent running on the CPU.
The figures are basically the same as the ones described in the previous section. Only the precision is different. The
only additional information in the first section is that the unaccounted-for time is explicitly given.
Total Number of Duration per
Component Duration % Events Event
--------------------------- -------- ------- --------- ------------
SQL*Net message from client 6.243
43.075
10,000 0.001
CPU 5.862
40.444
n/a n/a
unaccounted-for
2.364 16.309 n/a n/a
SQL*Net message to client 0.024 0.168 10,000 0.000
latch: shared pool 0.000 0.002 5 0.000
log file sync 0.000 0.002 1 0.000
