Oracle FAQ Your Portal to the Oracle Knowledge Grid
HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US
 

Home -> Community -> Mailing Lists -> Oracle-L -> Re: Interpreting tkprof output???

Re: Interpreting tkprof output???

From: tim <tim_at_ARTEMIS.DEMON.CO.UK>
Date: Sun, 14 Jan 1996 08:50:45 GMT
Message-Id: <9601141403.AA10523@alice.jcc.com>


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

Original text of this message

HOME | ASK QUESTION | ADD INFO | SEARCH | E-MAIL US