Database Reference
In-Depth Information
Statement Sort Order
Unlike TKPROF, ESQLTRCPROF does not have any command line options for sorting. At first
glance, this may seem like a disadvantage; however this is one of the strengths of ESQLTRCPROF.
ESQLTRCPROF always sorts statements by the
total elapsed time
attributed to each statement.
At the extended SQL trace file level, this means that ESQLTRCPROF calculates the total elapsed
time by summing up the
e
values of
PARSE
,
EXEC
, and
FETCH
entries of a certain cursor and adds
the
ela
values of inter database call wait events except for
SQL*Net message from client
waits,
which are classified as think time. Think time is ignored, since it is not indicative of a problem
with the DBMS instance. This approach is superior to the way TKPROF sorts statements on the
following three counts:
TKPROF sorts either by executed elapsed time (exeela) or fetch elapsed time (fchela), but
not by the entire elapsed time of
PARSE
,
EXEC
, and
FETCH
entries. For the purpose of sorting, it
is irrelevant where the time was spent, since response time is what matters.
TKPROF ignores inter database call wait events when sorting statements.
TKPROF subtracts the recursive resource utilization (
dep
values greater than zero) when
reporting on statements at recursive call depth 0. This makes it impossible to sort by the
most expensive statements executed by the client.
In my view, it is more appropriate not to subtract recursive resource utilization. Then a
statement sent by a client (
dep=0
) appears higher in the sort order than recursive statements
engendered by that same statement. Thus, it is evident which statements merit a closer look
and are candidates for drilling down to higher recursive call depths. Ideally, ESQLTRCPROF
would create a separate report section that depicts the recursive relationship among state-
ments, but this is beyond the capabilities of the current version.
ESQLTRCPROF has a peculiar feature for dealing with trace file entries that relate to cursor
number 0 as well as for cursors that lack a
PARSING
IN
CURSOR
entry. The latter phenomenon may
be seen when tracing is begun while an application is in mid-flight. There may be
EXEC
,
FETCH
,
and
WAIT
entries for a cursor without a corresponding
PARSING
IN
CURSOR
entry. Thus, the SQL
statement text for such a cursor cannot be determined.
6
There is never a
PARSING
IN
CURSOR
entry for cursor 0. LOB access with OCI may also be attributed to cursor 0. Instead of ignoring
entries pertaining to such cursors, which is what TKPROF does in the section on individual
statements, ESQLTRCPROF defines a default cursor with the impossible “hash value” -1 to
account for any such trace file entries. The ESQLTRCPROF report based on the trace file from
the previous section's case study is continued in the next code example. Note that even this
short trace file contained almost ten seconds of think time and a log file sync, which were attrib-
uted to cursor 0.
Statements Sorted by Elapsed Time (including recursive resource utilization)
==============================================================================
Hash Value: 2228079888 - Total Elapsed Time (excluding think time): 1.526s
INSERT INTO customer(name, phone) VALUES (:name, :phone)
6.
The measurement scripts
sp_capture.sql
and
awr_capture.sql
presented in Chapter 28 create a level 2
error stack dump, since this dump may contain the missing SQL statement texts.
