Hi.
Is it possible to post the entire TKPROF result file?
Michael.
In article <85i2js$qs$1_at_nnrp1.deja.com>,
johnpaulcook_at_my-deja.com wrote:
> The TKPROF totals of nonrecursive and recursive SQL statements don't
> sum to a number about 12% of the actual elapsed time for executing the
> package. Where is the rest of the time spent? PL/SQL statements?
> There is an enormous amount of processing done in PL/SQL. If the
> majority of the time is indeed spent executing PL/SQL, then recoding
in
> C might be something to consider.
>
>
>
> OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
>
> call count cpu elapsed disk query current rows
> ------- ----- ---- ------- ---- ----- ------- ----
> Parse 3 0.07 0.07 0 0 0 0
> Execute 3 0.02 0.02 0 0 0 1
> Fetch 1 0.01 0.01 0 0 0 1
> ------- ----- ---- ------- ---- ----- ------- ----
> total 7 0.10 0.10 0 0 0 2
>
> Misses in library cache during parse: 3
> Misses in library cache during execute: 1
>
> OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
>
> call count cpu elapsed disk query current rows
> ------- ------ ------ ------- ---- ------ ------- -----
> Parse 24747 14.39 14.37 0 0 0 0
> Execute 59190 18.77 54.16 324 103 74483 3964
> Fetch 80250 117.06 119.60 1373 482813 37239 39450
> ------- ------ ------ ------- ---- ------ ------- -----
> total 164187 150.22 188.13 1697 482916 111722 43414
>
> Misses in library cache during parse: 0
> Misses in library cache during execute: 1
>
> 24715 user SQL statements in session.
> 36 internal SQL statements in session.
> 24751 SQL statements in session.
> 49 statements EXPLAINed in this session.
>
> Trace file: ././test_ora_12469.trc
> Trace file compatibility: 7.03.02
> Sort options: default
>
> 1 session in tracefile.
> 24715 user SQL statements in trace file.
> 36 internal SQL statements in trace file.
> 24751 SQL statements in trace file.
> 63 unique SQL statements in trace file.
> 49 SQL statements EXPLAINed using schema:
> TEST_OWNER.prof$plan_table
> Default table was used.
> Table was created.
> Table was dropped.
> 487079 lines in trace file.
>
> The actual execution time for the entire package is 1506 seconds.
> Notice that nonrecursive statements total 0.10 second of elapsed time
> and recursive statements total 188.13 seconds of elapsed time. Where
> is the rest of the time spent?
>
> UTLBSTAT was executed, then the same package was executed on a dataset
> 1/4th of the size of the TKPROF dataset, then UTLESTAT was executed
> (there was other activity on the system):
>
> Event Name Count Total Time Avg Time
> ----------------------------- ----- ---------- --------
> rdbms ipc message 363 544863 1501
> queue messages 183 182226 995.77
> SQL*Net message from client 130 117452 903.48
> db file sequential read 89 196 2.2
> write complete waits 62 90 1.45
> log file switch completion 2 39 19.5
> log file sync 6 10 1.67
> control file sequential read 14 6 .43
> refresh controlfile command 4 4 1
> file open 36 1 .03
> SQL*Net message to client 130 0 0
> SQL*Net more data from client 82 0 0
> SQL*Net more data to client 20 0 0
> 13 rows selected.
> SVRMGR>
> SVRMGR>
> SVRMGR> Rem System wide wait events for background processes (PMON,
> SMON, etc)
> SVRMGR> select n1.event "Event Name",
> 2> n1.event_count "Count",
> 3> n1.time_waited "Total Time",
> 4> round(n1.time_waited/n1.event_count, 2) "Avg Time"
> 5> from stats$bck_event n1
> 6> where n1.event_count > 0
> 7> order by n1.time_waited desc;
> Event Name Count Total Time Avg Time
> ---------------------------- ----- ---------- --------
> rdbms ipc message 16329 711922 43.6
> smon timer 7 210007 30001
> pmon timer 604 181804 301
> log file parallel write 15169 13058 .86
> db file parallel write 133 737 5.54
> control file parallel write 638 203 .32
> direct path read 60 53 .88
> control file sequential read 88 25 .28
> log file single write 8 11 1.38
> db file sequential read 1 5 5
> log file sequential read 4 5 1.25
> log file sync 3 5 1.67
> direct path write 60 1 .02
> file identify 8 0 0
> file open 8 0 0
> 15 rows selected.
>
> All Hit ratios are 1. Zero reloads. Zero Get Miss. Zero sleeps.
> Where is all of the time being used up?
>
> I was told that rdbms ipc message, queue messages, SQL*Net message
from
> client all indicate that the time was spent communicating with the
> client via SQL*Net. Is this true?
>
> Is there a tool for profiling assignments and flow control inside
> PL/SQL code since TKPROF only profiles SQL statements?
>
> Sent via Deja.com http://www.deja.com/
> Before you buy.
>
Sent via Deja.com http://www.deja.com/
Before you buy.
Received on Thu Jan 13 2000 - 15:39:23 CST
