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!

Interpreting TKPROF output

631280Aug 26 2008 — edited Aug 29 2008
Hello colleagues

Im reviewing the performance of one of our DBs (10.2.0.2 on MS 2003 SP1). I found a lookup table called ACCESS_INAB which was called frequently. Pinning this table to the keep buffer we improved the owerall reaction time of the application.
There is still one issue Im fighting with. One specific operation takes still long time (30-45 sec.) to display a comment field. I tried to trace the session and got follwoing result:


********************************************************************************

select *
from
(select rownum rn, a.* from ( SELECT TL.id, TL.process_id, TL.event_time,
TL.severity, TL.short_description, TPG.process_group_text, TP.process_text,
u.display_user_name FROM Transaction_Log TL, Transaction_Process_Groups TPG,
Transaction_Process TP, users u WHERE TP.process_group_id =
TPG.process_group_id and TL.process_id = TP.process_id and TL.pguid =
u.pguid (+) ORDER BY severity desc, event_time) a ) where rn between 1 and
10


call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 5.09 73.06 60248 47768 55 10
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 5.09 73.07 60248 47768 55 10

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 45

Rows Row Source Operation
------- ---------------------------------------------------
10 VIEW (cr=47768 pr=60248 pw=14888 time=62516706 us)
582169 COUNT (cr=47768 pr=60248 pw=14888 time=91625035 us)
582169 VIEW (cr=47768 pr=60248 pw=14888 time=91042864 us)
582169 SORT ORDER BY (cr=47768 pr=60248 pw=14888 time=90460690 us)
582169 HASH JOIN (cr=47768 pr=52211 pw=6851 time=92165669 us)
8 TABLE ACCESS FULL TRANSACTION_PROCESS_GROUPS (cr=7 pr=0 pw=0 time=52 us)
582169 HASH JOIN (cr=47761 pr=52211 pw=6851 time=91000485 us)
62 TABLE ACCESS FULL TRANSACTION_PROCESS (cr=7 pr=0 pw=0 time=86 us)
582169 HASH JOIN RIGHT OUTER (cr=47754 pr=52211 pw=6851 time=89252852 us)
618316 MAT_VIEW ACCESS FULL ACCESS_INAB (cr=12656 pr=10308 pw=0 time=21098797 us)
582169 TABLE ACCESS FULL TRANSACTION_LOG (cr=35098 pr=35052 pw=0 time=28542620 us)


Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
db file scattered read 3808 0.26 41.01
db file sequential read 361 0.15 1.78
direct path write temp 616 0.10 2.09
direct path read temp 2023 0.34 13.95
SQL*Net message to client 1 0.00 0.00
SQL*Net message from client 1 0.01 0.01
********************************************************************************

Can you help me to correctly interpret this outcome?

Kind regards

Tony

PS: I used [this |http://download.oracle.com/docs/cd/B19306_01/server.102/b14211/instance_tune.htm#i34268] reference.

Edited by: TonyDBA on Aug 26, 2008 2:19 AM
This post has been answered by Randolf Geist on Aug 27 2008
Jump to Answer
Comments
Locked Post
New comments cannot be posted to this locked post.
Post Details
Locked on Sep 26 2008
Added on Aug 26 2008
8 comments
305 views