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

Home -> Community -> Mailing Lists -> Oracle-L -> Analyze the tkprof output

Analyze the tkprof output

From: Andrey Bronfin <bronfin_at_VisualTop.com>
Date: Thu, 16 Mar 2000 10:57:18 +0200
Message-Id: <10492.105215@fatcity.com> 





This is a multi-part message in MIME format.



------=_NextPart_000_0044_01BF8F36.659F7C20
Content-Type: text/plain;


        charset="iso-8859-1"


Content-Transfer-Encoding: quoted-printable



HI , ALL !



I'm having a pretty strange tkprof output of a SQL trace .
There is a Java program that runs SQL queries  , and it looks like each =
statement is parsed 3 times for each execution when we're not using bind =
variables ,=20


and each statement is parsed 2 times  when we're  using bind variables  =
.


There is also an execution for every fetch of a query .
We use Oracle 8.1.5 on Windows2000 .


Both the Oracle8i and Windows are new for me . I previously used Oracle8 =
on HP-UX and i never seen this kind of tkprof results .
Please help !


TIA=20


Here is what i have in my *.prf file  :



Select ename,emp_id


from


 emp where ename like 'SMITH%' order by ename



call     count       cpu    elapsed       disk      query    current     =


   rows


------- ------  -------- ---------- ---------- ---------- ----------  =




Parse       15      0.03       0.03          0          0          0     =
      0
Execute     5      0.00       0.00          0          0          0      =
     0
Fetch         5      0.00       0.00          0          5          0    =
      10
------- ------ --------------------------------- -------- ---------- =
---------- ---------- ----------  ----------
total       25      0.03       0.03          0          5          0     =
     10





Misses in library cache during parse: 0




When we use bind variables in the Java program  i see the following :



SELECT  emp_data=20


from


 emp where emp_id=3D:1



call     count       cpu    elapsed       disk      query    current     =


   rows


------- ------  -------- ---------- ---------- ---------- ----------  =




Parse          8      0.01       0.01          0          0          0   =
        0
Execute      4      0.00       0.00          0          0          0     =
      0
Fetch          4      0.00       0.00          0          4         16   =
        4




------- ------  -------- ---------- ---------- ---------- ----------  =




total          16      0.01       0.01          0          4         16  =
         4







Thanks a lot in advance !!



------=_NextPart_000_0044_01BF8F36.659F7C20
Content-Type: text/html;


        charset="iso-8859-1"


Content-Transfer-Encoding: quoted-printable


<!DOCTYPE HTML PUBLIC "-//W3C//DTD HTML 4.0 Transitional//EN">
<HTML><HEAD>
<META content=3D"text/html; charset=3Diso-8859-1" =


http-equiv=3DContent-Type>

<META content=3D"MSHTML 5.00.2920.0" name=3DGENERATOR>
<STYLE></STYLE>
</HEAD>
<BODY bgColor=3D#ffffff>
<DIV><FONT face=3DArial size=3D2>HI , ALL !</FONT></DIV>
<DIV><FONT face=3DArial size=3D2>I'm having a pretty strange tkprof =


output of a SQL=20


trace .</FONT></DIV>


<DIV><FONT face=3DArial size=3D2>There is a Java program that runs SQL =
queries&nbsp;=20


, and it looks like each statement is parsed 3 times for each execution =
when=20


we're not using bind variables , </FONT></DIV>
<DIV><FONT face=3DArial size=3D2>and each statement is parsed&nbsp;2 =
times&nbsp;=20


when we're&nbsp; using bind variables&nbsp; .</FONT></DIV>
<DIV><FONT face=3DArial size=3D2>There is also an execution for every =
fetch of a=20


query .</FONT></DIV>


<DIV><FONT face=3DArial size=3D2>We use Oracle 8.1.5 on Windows2000 =
.</FONT></DIV>


<DIV><FONT face=3DArial size=3D2>Both the Oracle8i and Windows are new =
for me . I=20


previously used Oracle8 on HP-UX and i never seen this kind of tkprof =
results=20


.</FONT></DIV>

<DIV><FONT face=3DArial size=3D2>Please help !</FONT></DIV>
<DIV><FONT face=3DArial size=3D2>TIA </FONT></DIV>
<DIV>&nbsp;</DIV>
<DIV><FONT face=3DArial size=3D2>Here is what i have in my *.prf file =20


:</FONT></DIV>


<DIV>&nbsp;</DIV>


<DIV><FONT face=3DArial size=3D2>Select =
ename,emp_id<BR>from<BR>&nbsp;emp=20


where&nbsp;ename like 'SMITH%' order by ename</FONT></DIV>
<DIV><FONT face=3DArial size=3D2><BR>call&nbsp;&nbsp;&nbsp;&nbsp;=20
count&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; cpu&nbsp;&nbsp;&nbsp;=20
elapsed&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; =
disk&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20


query&nbsp;&nbsp;&nbsp; =


current&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20

rows<BR>------- ------&nbsp; -------- ---------- ---------- ----------=20
----------&nbsp;=20
----------------------------------------<BR>Parse&nbsp;&nbsp;&nbsp;&nbsp;=


&nbsp;&nbsp;=20


15&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; =


0.03&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0.03&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20

0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20


0<BR>Execute&nbsp;&nbsp;&nbsp;&nbsp; 5&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0.00&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0.00&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20

0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20


0<BR>Fetch&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; =20
5&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; 0.00&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; =



0.00&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20

0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
5&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; 10<BR>-------=20
------&nbsp;--------------------------------- -------- ---------- =
----------=20




---------- ----------&nbsp;=20


----------<BR>total&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
25&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; =


0.03&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0.03&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20

0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
5&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; 10</FONT></DIV>


<DIV>&nbsp;</DIV>


<DIV><FONT face=3DArial size=3D2>Misses in library cache during parse:=20
0</FONT></DIV>

<DIV>&nbsp;</DIV>
<DIV>&nbsp;</DIV>
<DIV><FONT face=3DArial size=3D2>When&nbsp;we use bind variables in the =


Java program=20


 i see the following :</FONT></DIV>

<DIV>&nbsp;</DIV>
<DIV><FONT face=3DArial size=3D2>SELECT&nbsp; emp_data =
<BR>from<BR>&nbsp;emp where=20




emp_id=3D:1</FONT></DIV>


<DIV><FONT face=3DArial size=3D2><BR>call&nbsp;&nbsp;&nbsp;&nbsp;=20
count&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; cpu&nbsp;&nbsp;&nbsp;=20
elapsed&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; =
disk&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20


query&nbsp;&nbsp;&nbsp; =


current&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20

rows<BR>------- ------&nbsp; -------- ---------- ---------- ----------=20
----------&nbsp;=20
-----------------------------------------<BR>Parse&nbsp;&nbsp;&nbsp;&nbsp=


;&nbsp;&nbsp;&nbsp;&nbsp;=20


 8&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; =


0.01&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0.01&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20

0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20


0<BR>Execute&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; =
4&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20


0.00&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0.00&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20

0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20


0<BR>Fetch&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; &nbsp;=20
4&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; 0.00&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; =



0.00&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
4&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
16&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; =

4<BR>-------=20
------&nbsp; -------- ---------- ---------- ---------- ----------&nbsp;=20
-----------------------------------------------<BR>total&nbsp;&nbsp;&nbsp=


;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
16&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; =


0.01&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0.01&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
0&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
4&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;=20
16&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp;&nbsp; =
4</FONT></DIV>
Received on Thu Mar 16 2000 - 02:57:18 CST












Original text of this message













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