Oracle FAQ | Your Portal to the Oracle Knowledge Grid |
Home -> Community -> Mailing Lists -> Oracle-L -> Re: Interpreting tkprof output???
In your message dated Thursday 11, January 1996 you wrote :
> Does anyone know how to interpret tkprof output? We are
> trying to determine why a program is so slow and this is
> the output we get. Is it explained somewhere how to
> interpret this? Probably in the Oracle Tuning and DBA
> handbook, right?
>
>
> TKPROF: Release 7.1.3.0.0 - Production on Thu Jan 11 09:20:46 1996
>
> Copyright (c) Oracle Corporation 1979, 1994. All rights reserved.
>
> ******************************************************************************
> count = number of times OCI procedure was executed
> cpu = cpu time in seconds executing
> elapsed = elapsed time in seconds executing
> disk = number of physical reads of buffers from disk
> query = number of buffers gotten for consistent read
> current = number of buffers gotten in current mode (usually for update)
> rows = number of rows processed by the fetch or execute call
> ******************************************************************************
>
> BEGIN FR_SUPPLY_ITEM_PKG.DOES_ROW_EXIST(:b1,:b2,:b3);END;
>
>
> call count cpu elapsed disk query current rows
> -------- ------- -------- --------- -------- -------- ------- ----------
> Parse 37 0.02 0.02 0 0 0 0
> Execute 66 0.24 0.28 3 228 0 66
Here the stored procedure was executed 66 times
> Fetch 0 0.00 0.00 0 0 0 0
>
> -------- ------- -------- --------- -------- -------- ------- ----------
> total 103 0.26 0.30 3 228 0 66
>
This line shows the total cost of executing the procedure
cpu time .26 secs elapsed time .30 cost in terms of database reads 3 physical reads to disk and 228 logical reads ( logical reads = query + current)
> Misses in library cache during parse: 0
> Optimizer hint: CHOOSE
> Parsing user id: 26 (ZM00484)
> ******************************************************************************
>
> BEGIN FR_SUPPLY_ITEM_PKG.ADD_TO_SI(:b1,:b2,:b3,:b4,:b5,:b6,:b7,:b8,:b9,:b10,
> :b11,:b12,:b13,:b14,:b15,:b16,:b17,:b18,:b19,:b20,:b21,:b22,:b23,:b24,:b25,
> :b26,:b27,:b28,:b29,:b30,:b31,:b32,:b33,:b34,:b35,:b36,:b37,:b38,:b39,:b40,
> :b41,:b42,:b43,:b44,:b45,:b46,:b47,:b48,:b49,:b50,:b51,:b52);END;
>
>
> call count cpu elapsed disk query current rows
> -------- ------- -------- --------- -------- -------- ------- ----------
> Parse 32 0.01 0.01 0 0 0 0
> Execute 30 0.23 0.28 0 60 90 30
> Fetch 0 0.00 0.00 0 0 0 0
>
> -------- ------- -------- --------- -------- -------- ------- ----------
> total 62 0.24 0.29 0 60 90 30
>
> Misses in library cache during parse: 0
> Optimizer hint: CHOOSE
> Parsing user id: 26 (ZM00484)
> ******************************************************************************
>
> BEGIN FR_SUPPLY_ITEM_DEMAND_PKG.ADD_ONE(:b1,:b2,:b3,:b4,:b5,:b6,:b7,:b8,:b9,
> :b10,:b11);END;
>
>
> call count cpu elapsed disk query current rows
> -------- ------- -------- --------- -------- -------- ------- ----------
> Parse 30 0.01 0.02 0 0 0 0
> Execute 30 0.21 0.26 0 60 32 30
> Fetch 0 0.00 0.00 0 0 0 0
>
> -------- ------- -------- --------- -------- -------- ------- ----------
> total 60 0.22 0.28 0 60 32 30
The stored procedure has been executed 30 times here and it has processed 30 rows in the database. Therefore 1 row per call
> Misses in library cache during parse: 0
> Optimizer hint: CHOOSE
> Parsing user id: 26 (ZM00484)
> ******************************************************************************
>
> BEGIN FR_STOCK_FISC_PKG.DOES_ROW_EXIST(:b1,:b2,:b3,:b4,:b5,:b6);END;
>
>
> call count cpu elapsed disk query current rows
> -------- ------- -------- --------- -------- -------- ------- ----------
> Parse 30 0.00 0.00 0 0 0 0
> Execute 64 0.18 0.26 9 255 0 64
> Fetch 0 0.00 0.00 0 0 0 0
>
> -------- ------- -------- --------- -------- -------- ------- ----------
> total 94 0.18 0.26 9 255 0 64
>
> Misses in library cache during parse: 0
> Optimizer hint: CHOOSE
> Parsing user id: 26 (ZM00484)
> ******************************************************************************
>
>
> What is it trying to tell me? The ADD routines are only
> supposed to add one row - why does it say 30 under the
> rows column? Thanks.
>
> Amy
>
Come, let us retract the foreskin of ignorance, and apply the wirebrush of enlightenment Tim London phone : +44 1753 662393 Oracle DBA,Trainer and mobile: +44 836 287064 part time OU tutor Email : tim_at_artemis.demon.co.uk ----------------------------------------------------------------------------Received on Sun Jan 14 1996 - 09:03:24 CST