| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
 |
 | |||
| Oracle FAQ | Your Portal to the Oracle Knowledge Grid | |
|
| |||
Home -> Community -> Usenet -> c.d.o.misc -> TKPROF - SQL fast, PL/SQL slow?
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.
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.
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 013 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.
Received on Wed Jan 12 2000 - 08:21:00 CST
 |
 |