Re: Timing a Procedure/package using tkprof
Date: Sat, 18 Mar 1995 20:08:01 +0000
Message-ID: <795557281snz_at_jlcomp.demon.co.uk>
In article <3k8cl8$h7o_at_newsserver.trl.OZ.AU>
aaj_at_phantom.trl.OZ.AU "Tony Jambu" writes:
: Also does anyone know why tkprof' summary totals does not include
: non-resursive time.
Personally, I wonder if it was just a coding error. Since EXECUTE line of the procedure stats includes the PARSE, EXECUTE and FETCH of the SQL statements run in the procedure, I think that the time ought to be behaving in the same way.
: Has anyone written their own utility to interpret the trace files?
Way back with 6.0.29 or thereabouts, I found that it was quite easy to write an awk script that (slowly) produced summary stats from the trace file.
Looking at a v7 trace file, there is one refinement that could be brought in, the 'dep=N' bit in the 'PARSING IN CURSOR ...' to track the recursion tree.
Interestingly, if you look at the trace files, you will notice that the stats you want ARE actually recorded in against the procedure, but tkprof somehow factors them out.
Hints on an awk script:
Lines between
^PARSING IN CURSOR #n .... dep=M
and
END OF STATEMENT
are the SQL statements, trap it in the 'nth' text array.
Hold the values of n and M as array subscripts. If M is not zero, then it is a recursive statement, associated with the most recent occurrence of cursor M.
Trap all lines of the form:
^PARSE #n
^EXEC #n
^FETCH #n
Keep running totals of
c (cpu time)
e (elapsed time)
cr (consistent read blocks)
etc......
When the same value of 'n' appears again, print the current 'nth' text, and the current three lines of 'nth' statistics, clear the arrays and start again for array set n.
Sorry if this is rather obsucre, explaining it all in great detail would be rather time-consuming, and I no longer have the awk script to do the job.
-- Jonathan LewisReceived on Sat Mar 18 1995 - 21:08:01 CET