Skip to Main Content

Oracle Database Discussions

Announcement

For appeals, questions and feedback about Oracle Forums, please email oracle-forums-moderators_us@oracle.com. Technical questions should be asked in the appropriate category. Thank you!

TKProf output

user641444Sep 27 2011 — edited Sep 27 2011
Hi!

I have some difficulties understanding the output of TKProf.

The overall time is 162h, CPU was used 27h and the sum of all wail time is about 2,3h,
what was done during the missing 132h?

br
Daniel


OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 13709189 1292.69 12515.65 0 0 1738 0
Execute 39127742 97425.06 564763.11 634753 329999305 84108745 4092665
Fetch 37575889 249.31 6185.73 328060 101823071 272767 43510020
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 90412820 98967.06 583464.49 962813 431822376 84383250 47602685

Misses in library cache during parse: 2373
Misses in library cache during execute: 11703

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file sequential read 340272 2.18 2553.83
library cache: mutex X 13575208 0.56 239.02
cursor: mutex S 103614004 0.25 5733.17
latch: In memory undo latch 1038 0.00 0.06
latch: cache buffers lru chain 120 0.06 0.22
buffer busy waits 2361 0.02 0.14
log file switch (private strand flush incomplete)
360 0.81 17.94
row cache lock 399 0.00 0.08
cursor: pin S 120 0.05 0.33
read by other session 2 0.00 0.00
enq: TX - index contention 51 0.05 0.39
latch: cache buffers chains 508 0.00 0.02
latch: shared pool 72 0.31 4.45
kksfbc child completion 103 0.05 5.10
cursor: pin S wait on X 1607 4.89 45.56
latch: row cache objects 22 0.00 0.00
enq: TX - row lock contention 2 14.36 16.86
resmgr:cpu quantum 5868 0.07 29.47
enq: SQ - contention 29 0.00 0.00
enq: TM - contention 12 53.06 228.95
asynch descriptor resize 2 0.00 0.00
SGA: allocation forcing component growth 22 5.31 61.99
library cache lock 15 3.81 6.53
latch: undo global data 1 0.00 0.00
latch: object queue header operation 5 0.00 0.00
log file switch (checkpoint incomplete) 1 0.03 0.03
latch: enqueue hash chains 9 0.00 0.00
latch free 40 0.00 0.00
library cache load lock 5 0.08 0.16
log file switch completion 8 0.08 0.37
Disk file operations I/O 1 0.00 0.00
undo segment extension 3 0.02 0.02
resmgr:internal state change 35 0.10 3.10
latch: redo writing 1 0.00 0.00
buffer exterminate 15 0.01 0.15
buffer deadlock 2 0.00 0.00
latch: redo allocation 2 0.00 0.00

8336223 user SQL statements in session.
249046 internal SQL statements in session.
8585269 SQL statements in session.
********************************************************************************
Trace file: p_j002_2117830.trc
Trace file compatibility: 11.1.0.7
Sort options: exeela
1 session in tracefile.
8336223 user SQL statements in trace file.
249046 internal SQL statements in trace file.
8585269 SQL statements in trace file.
9696 unique SQL statements in trace file.
617605845 lines in trace file.
501791 elapsed seconds in trace file.

Edited by: user641444 on Sep 26, 2011 11:02 PM
Comments
Locked Post
New comments cannot be posted to this locked post.
Post Details
Locked on Oct 25 2011
Added on Sep 27 2011
7 comments
299 views