Execution Plan in Trace File [message #223121] |
Wed, 07 March 2007 12:02 |
scottwmackey
Messages: 515 Registered: March 2005
|
Senior Member |
|
|
Does anybody know why the execution plan used by a query shows up only intermittently in TKPROF files. And with all due respect to anybody who is tempted to respond that I need to use the "explain" parameter when running TKPROF, that is not what I am talking about. I know the "explain" parameter will give me an execution plan, even though it may not actually have been used when the query was run. Tom Kyte implies in more than one place that there should be an execution plan in every TKPROF file, and sometimes I see one. I am just wondering why it is not always there. Does anybody know, or more importantly, does anybody know what I need to do to always get one?
|
|
|
|
|
Re: Execution Plan in Trace File [message #223217 is a reply to message #223145] |
Thu, 08 March 2007 00:47 |
rleishman
Messages: 3728 Registered: October 2005 Location: Melbourne, Australia
|
Senior Member |
|
|
I concur with @gintsp. I have seen both happen a lot.
Although I have had situations where the cursor is closed, the plan steps are in the trace file, but TK*Prof does not show them. I didn't stress about it at the time because I could get the info I needed straight from the trace file.
Ross Leishman
|
|
|
Re: Execution Plan in Trace File [message #223229 is a reply to message #223121] |
Thu, 08 March 2007 01:40 |
scottwmackey
Messages: 515 Registered: March 2005
|
Senior Member |
|
|
Thanks to all of you, especially gintsp. There appears to be one more thing that I failed to mention which seems to make a big difference. The sql statement was part of an insert, e.g.INSERT INTO t VALUES(...)
SELECT ...
FROM t
...
WHERE ... This is apparently treated differently than if the select statement is like this
SELECT ...
BULK COLLECT INTO ...
FROM t
...
WHERE ... It would appear I fell victim to my own admonition I give to newbies. Don't omit anything in your description of the problem. You don't know what is and isn't relevant.
Nevertheless, I found the following. If IALTER SESSION SET SQL_TRACE = TRUE;
BEGIN
my_proc; --(with insert/select)
END;
(Switch to udump) TKPROF ... I don't get the execution plan. If I just close the window (I am working through multi-session enabled PL/SQL Developer) on which I am working, which ends the session, and then run TKPROF, I get the execution plan. So gintsp, that's where your observation was spot on. When I do this oneALTER SESSION SET SQL_TRACE = TRUE;
BEGIN
my_proc; --(with select into bulk collect)
END;
(Switch to udump) TKPROF ... I get the execution plan without having to close the window or even turn off trace. That seems kind of strange but I can live with it.
|
|
|
Re: Execution Plan in Trace File [message #223436 is a reply to message #223229] |
Thu, 08 March 2007 22:07 |
rleishman
Messages: 3728 Registered: October 2005 Location: Melbourne, Australia
|
Senior Member |
|
|
On a similar but completely unrelated topic, I managed to break TK*Prof today. Have a look at what it gave me:
SELECT /*+ordered use_nl(m)*/ *
FROM orders o
, delivery_method m
WHERE o.order_amt BETWEEN m.lower_bound and m.upper_bound
AND m.upper_bound = (
SELECT min(m1.upper_bound)
FROM delivery_method m1
WHERE m1.upper_bound >= o.order_amt
)
call count cpu elapsed disk query
------- ------ -------- ---------- ---------- ----------
Parse 1 0.01 0.00 0 0
Execute 1 0.00 0.00 0 0
Fetch 603 0.42 0.77 78 50936
------- ------ -------- ---------- ---------- ----------
total 605 0.43 0.77 78 50936
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 33
Rows Row Source Operation
------- ---------------------------------------------------
9021 TABLE ACCESS BY INDEX ROWID DELIVERY_METHOD
20001 NESTED LOOPS
10000 TABLE ACCESS FULL ORDERS
10000 INDEX RANGE SCAN DELIVERY_METHOD_PK
There are 3 lines missing from the bottom of the plan. I checked the trace file, they're not in there either. The trace file was not tuncated, there were hundreds of following lines from other SQLs that I ran. Only this statement was truncated...?
I dopped and rebuilt the DELIVERY_METHOD table, but this time with fewer rows. Run it again and get:
SELECT /*+ordered use_nl(m)*/ *
FROM orders o
, delivery_method m
WHERE o.order_amt BETWEEN m.lower_bound and m.upper_bound
AND m.upper_bound = (
SELECT min(m1.upper_bound)
FROM delivery_method m1
WHERE m1.upper_bound >= o.order_amt
)
call count cpu elapsed disk query
------- ------ -------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0
Execute 1 0.00 0.00 0 0
Fetch 34 0.23 0.41 42 30597
------- ------ -------- ---------- ---------- ----------
total 36 0.23 0.41 42 30597
Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: 33
Rows Row Source Operation
------- ---------------------------------------------------
491 FILTER
491 NESTED LOOPS
10000 TABLE ACCESS FULL ORDERS
491 TABLE ACCESS FULL DELIVERY_METHOD
491 SORT AGGREGATE
491 FIRST ROW
491 INDEX RANGE SCAN (MIN/MAX) DELIVERY_METHOD_PK
The plan is complete this time!!! Drop and rebuild the table again back to its bigger size - bad plan again.
I'm not asking for assistance here, just pointing out that SQL Trace is not always God-like and predictable.
Ross Leishman
|
|
|