Home » RDBMS Server » Performance Tuning » All "Rows" equal 0 in TKPROF. Is this a setting?
All "Rows" equal 0 in TKPROF. Is this a setting? [message #121081] Wed, 25 May 2005 17:54 Go to next message
scottwmackey
Messages: 515
Registered: March 2005
Senior Member
Hi all,

I actually have two possibly related questions here.

1) I was under the impression that TKPROF is supposed to show the execution plan that was used on a query. As you can see below, though, I am not getting an execution plan. I am pretty sure I got the execution plan everywhere else I have worked and I am pretty sure I get it on my home machine. Tom Kyte, on page 460-1 of Expert One-on-One, seems to say it should be there and mentions nothing about turning it on or off. I can't find any reference to it in Oracle8i Designing and Tuning for Performance. I had always assumed it was automatic. Is it a setting that is turned off here?

edevdb1:ODV1:/opt/oracle/product/ODV1/8.1.7/admin/udump -> tkprof ora_25905_odv1.trc ~/test.txt

edevdb1:ODV1:/opt/oracle/product/ODV1/8.1.7/admin/udump -> vi ~/test.txt

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

SELECT s.emplid,
       a.home_address,
       a.mailing_address,
       a.work_address,
       a.temporary_address
FROM   swm_addresses_v a,
       swm_students s
WHERE  s.emplid = a.emplid
AND    s.major = 4
ORDER BY s.emplid

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      2      0.01       0.00          0          0          0           0
Fetch        1      0.61       0.76       2409       2382         17         100
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.62       0.76       2409       2382         17         100

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 183
********************************************************************************


2) If I use the "explain" option, I can get an execution plan, but all the "Rows" are 0. What is going on? Why am I not getting values?

edevdb1:ODV1:/opt/oracle/product/ODV1/8.1.7/admin/udump -> tkprof ora_25905_odv1.trc ~/test_explain.txt explain=apps/password

edevdb1:ODV1:/opt/oracle/product/ODV1/8.1.7/admin/udump -> vi ~/test_explain.txt


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

SELECT s.emplid,
       a.home_address,
       a.mailing_address,
       a.work_address,
       a.temporary_address
FROM   swm_addresses_v a,
       swm_students s
WHERE  s.emplid = a.emplid(+)
AND    s.major = 4
ORDER BY s.emplid

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      2      0.01       0.01          0          0          0           0
Fetch        1      3.55       6.01       8195       2382         21         100
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      3.56       6.02       8195       2382         21         100

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 183  (APPS)

Rows     Execution Plan
-------  ---------------------------------------------------
      0  SELECT STATEMENT   GOAL: CHOOSE
      0   SORT (ORDER BY)
      0    HASH JOIN (OUTER)
      0     TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'SWM_STUDENTS'
      0     VIEW OF 'SWM_ADDRESSES_V'
      0      SORT (GROUP BY)
      0       TABLE ACCESS   GOAL: ANALYZED (FULL) OF 'SWM_ADDRESSES'

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


And yes, the tables are analyzed. Explain gets the rows correctly.

SQL> explain plan for
  2  SELECT s.emplid,
  3         a.home_address,
  4         a.mailing_address,
  5         a.work_address,
  6         a.temporary_address
  7  FROM   swm_addresses_v a,
  8         swm_students s
  9  WHERE  s.emplid = a.emplid(+)
 10  AND    s.major = 4
 11  ORDER BY s.emplid
 12  ;

Explained.

SQL>  @utlxpls.sql

Plan Table
--------------------------------------------------------------------------------
| Operation                 |  Name    |  Rows | Bytes|  Cost  | Pstart| Pstop |
--------------------------------------------------------------------------------
| SELECT STATEMENT          |          |     5K|  505K|   4344 |       |       |
|  SORT ORDER BY            |          |     5K|  505K|   4344 |       |       |
|   HASH JOIN OUTER         |          |     5K|  505K|   4254 |       |       |
|    TABLE ACCESS FULL      |SWM_STUDE |     5K|   40K|     29 |       |       |
|    VIEW                   |SWM_ADDRE |    99K|    7M|   3764 |       |       |
|     SORT GROUP BY         |          |    99K|    3M|   3764 |       |       |
|      TABLE ACCESS FULL    |SWM_ADDRE |   235K|    7M|    336 |       |       |
--------------------------------------------------------------------------------

10 rows selected.

Re: All "Rows" equal 0 in TKPROF. Is this a setting? [message #121094 is a reply to message #121081] Thu, 26 May 2005 01:07 Go to previous messageGo to next message
Frank Naude
Messages: 4565
Registered: April 1998
Senior Member
Hi,

1) EXPLAIN= is used to turn this on of off. Without the EXPLAIN parameter, TKPROF would not know where to login to do the explain plan.

Quote from the Oracle Performance tuning Guide:

"EXPLAIN: Determines the execution plan for each SQL statement in the trace file and writes these execution plans to the output file. TKPROF determines execution plans by issuing the EXPLAIN PLAN statement after connecting to Oracle with the user and password specified in this parameter. The specified user must have CREATE SESSION system privileges. TKPROF takes longer to process a large trace file if the EXPLAIN option is used."

2) It may be a TKPROF bug with your version of Oracle. When I do it on my system (quick test on 10.1.0.2.0), I can see the row values.

Best regards.

Frank
Re: All "Rows" equal 0 in TKPROF. Is this a setting? [message #121105 is a reply to message #121094] Thu, 26 May 2005 02:05 Go to previous messageGo to next message
scottwmackey
Messages: 515
Registered: March 2005
Senior Member
May we have our next contestant please. I understand that it is a very bad idea to be a smart ass when seeking assistance from others, but c'mon man. I would like to think that my intro my problem indicated that I had some idea what I was doing. Hell, I even referenced our lord Kyte. Nevertheless, you didn't even bother to check if your response was even close to being correct. Did you try running a TKPROF without the explain option? See below a TKPROF done on my home machine. Note that I did not use the explain option. Note that it shows the execution plan. With regard to your seemingly rhetorical question, it knows the execution plan because it already performed it. Moreover, according to our lord, if you use the explain option with TKPROF, you could get a different explain plan than the one that was actually used because the data may have changed from the time time the query was executed. You get instead the explain plan that would be used now. He recommends never using it.

It doesn't bother me so much if you post an erroneous response, but there is a chance that some newbie pops in, reads your response and then believes and propogates something that is simply inaccurate. For their sake, verify that your responses are correct before posting them. But thanks anyway.

Anybody out there who knows what is going on?

C:\oracle\visdb\8.1.7\admin\VIS\udump>tkprof ORA03384.TRC test.txt

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

select *
from   addresses_v a,
       students s
where  a.emplid = s.emplid
order by a.emplid

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.22         14        269          0           0
Execute      2      0.00       0.00          0          0          0           0
Fetch        3      0.44       3.62       1535       2337         11          31
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        6      0.44       3.84       1549       2606         11          31

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 65  

Rows     Row Source Operation
-------  ---------------------------------------------------
     31  MERGE JOIN 
     31   VIEW ADDRESSES_V 
     31    SORT GROUP BY 
 133331     TABLE ACCESS BY INDEX ROWID ADDRESSES 
 133332      INDEX FULL SCAN (object id 290760)
     31   SORT JOIN 
  49999    TABLE ACCESS FULL STUDENTS 

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

Re: All "Rows" equal 0 in TKPROF. Is this a setting? [message #121133 is a reply to message #121105] Thu, 26 May 2005 05:55 Go to previous messageGo to next message
Frank Naude
Messages: 4565
Registered: April 1998
Senior Member
Hi,

TKPROF can get the explain plan from two sources:
1) The DB after the query executed (EXPLAIN= parameter); or
2) From STAT lines in the raw trace output (exact - produced after statement executed).

Can you please confirm that these STAT lines are missing from the trace file that doesn't display the explain plan?

If so, you may have disabled tracing while the cursors were still open; or the cursors were somehow kept open.

Best regards.

Frank
Re: All "Rows" equal 0 in TKPROF. Is this a setting? [message #121165 is a reply to message #121081] Thu, 26 May 2005 10:32 Go to previous messageGo to next message
Art Metzer
Messages: 2478
Registered: December 2002
Senior Member
Scott,

In line with Frank's latter post, I found this message, which would seem to indicate that to get those STAT lines, you need to ALTER SESSION SET SQL_TRACE = FALSE or exit out of SQL*Plus.

For what it's worth, whenever I trace SQL, I exit out of the SQL*Plus session completely before tkprof'ing the file.

I also found this AskTom link which is relevant to your issue.
Re: All "Rows" equal 0 in TKPROF. Is this a setting? [message #121185 is a reply to message #121133] Thu, 26 May 2005 14:15 Go to previous messageGo to next message
scottwmackey
Messages: 515
Registered: March 2005
Senior Member
Frank,

Now there's a response I can use. Thanks. But I still don't know if it answers my question. Please see the SQL session, trace file, and TKPROF below. This is my entire SQL*Plus session, from the sqlplus command to quit.

SQL> alter session set sql_trace = true;

Session altered.

SQL> select *
  2  from   swm_addresses_v a,
  3         swm_students s
  4  where  a.emplid = s.emplid;

<output deleted>

20 rows selected.

SQL> alter session set sql_trace = false;

Session altered.

SQL> quit


My SQL*Plus window is now gone. The application is definitely closed. (BTW, I run SQL*Plus as a client from a command window on NT 2000 connecting to HPUX, if it matters.)

Here is my UNIX
edevdb1:ODV1:/opt/oracle/product/ODV1/8.1.7/admin/udump -> vi ora_7760_odv1.trc

=====================
PARSING IN CURSOR #1 len=84 dep=0 uid=183 oct=3 lid=183 tim=43758831 hv=280523349 ad='1c19d7d0'
select *
from   swm_addresses_v a,
       swm_students s
where  a.emplid = s.emplid
END OF STMT
PARSE #1:c=3,e=5,p=17,cr=80,cu=0,mis=1,r=0,dep=0,og=4,tim=43758831
EXEC #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=43758831
FETCH #1:c=320,e=597,p=6500,cr=2382,cu=21,mis=0,r=1,dep=0,og=4,tim=43759428
FETCH #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=15,dep=0,og=4,tim=43759436
FETCH #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=15,dep=0,og=4,tim=43759521
*** 2005-05-26 10:39:26.180
UNMAP #1:c=1,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=43766922
=====================
PARSING IN CURSOR #1 len=36 dep=0 uid=183 oct=42 lid=183 tim=43766922 hv=2583722623 ad='10ced818'
alter session set sql_trace = false
END OF STMT
PARSE #1:c=0,e=0,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=4,tim=43766922
EXEC #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=43766922


edevdb1:ODV1:/opt/oracle/product/ODV1/8.1.7/admin/udump -> tkprof ora_7760_odv1.trc ~/test.txt

edevdb1:ODV1:/opt/oracle/product/ODV1/8.1.7/admin/udump -> vi ~/test.txt


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

select *
from   swm_addresses_v a,
       swm_students s
where  a.emplid = s.emplid

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.02       0.01          0          0          0           0
Execute      2      0.01       0.01          0          0          0           0
Fetch        3      3.20       5.97       6500       2382         21          31
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        6      3.23       5.99       6500       2382         21          31

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 183
********************************************************************************

alter session set sql_trace = false


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        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          0          0           0

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 183



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

I am not sure which of any of these are STAT lines. Do you see them? If they are not there, that still leaves the question of why they are not there. I know I haven't done anything to turn them off. You can see everything I entered in the SQL*Plus session. You can see I turned off sql_trace and even exited SQL*Plus, but still no execution plan. I don't think I could have "disabled tracing while the cursors were still open". I'm not even sure of what that means or how to do it if I wanted to, but I am pretty sure I didn't do it. So back to my original question. Is this a setting?
Re: All "Rows" equal 0 in TKPROF. Is this a setting? [message #121188 is a reply to message #121165] Thu, 26 May 2005 14:27 Go to previous message
scottwmackey
Messages: 515
Registered: March 2005
Senior Member
Art,

Thank you very much for the links, but one of the responses on one of them is just wrong.

Quote:


The TKPROF program has gotten a little smarter lately (i.e. since Oracle7). When you specify the "EXPLAIN=<username>/<password>" parameter on the TKPROF command-line, TKPROF uses it as an indicator that you want EXPLAIN PLAN output included in your report. If TKPROF finds the "STAT" lines in the trace file, it uses that information, which almost always includes non-zero values for "Rows". If TKPROF does not find "STAT" lines for a cursor, then it runs EXPLAIN PLAN using the "username/password" information provided.



It may be true that TKPROF uses the STAT line if it is there even if you use the EXPLAIN option. But the implication that you need to use it to display an execution plan is just wrong. As I showed above, the execution plan is automatically included on my home machine. If my memory serves me, and I am beginning to believe it does, the execution plan is automatically included on every other machine I have worked on. All the EXPLAIN option seems to do is translate the object IDs to object names.
Previous Topic: Batch Tuning
Next Topic: Datawarehouse query
Goto Forum:
  


Current Time: Tue Sep 29 07:03:54 CDT 2020