Re: newbie, getting cost plan

On Sep 8, 3:31 am, codefragm...@xxxxxxxxxxxxxx wrote:
On 7 Sep, 16:45, Charles Hooper <hooperc2...@xxxxxxxxx> wrote:

On Sep 7, 7:43 am, sybrandb <sybra...@xxxxxxxxx> wrote:

On Sep 7, 1:07 pm, codefragm...@xxxxxxxxxxxxxx wrote:

Hi
I want to get the -real- cost and plan of an sql statement, not
estimated I can use:

(1) Explain Plan and DBMS_XPLAN from sqlplus, I gather this isn't the
real plan?
(2) Autotrace On, I gather this will be the real plan?
(3) tracing and tkprof, which can use explain plan, is this the real
plan?

and there are other ways I've seen mentioned?
In my present scenario I can do what I want with the database and
application.

thanks

tracing and tkprof is the easiest, provided you do NOT use the
explain= option (as this will run a new explain plan) and you left
sql*plus properly before running tkprof (ie you issued a COMMIT or
ROLLBACK which will have Oracle dump the real explain plan)

Other than that you could of course run statspack on level 6. This
will save the real explain plan, in the statspack tables. Doing so,
you can use sprepsql to retrieve the explain plan. Note: the method to
do so is user unfrienly, however it works.

--
Sybrand Bakker
Senior Oracle DBA

I have effectively used the TKPROF method mentioned by Sybrand. Once
you have an understanding of how to read the STAT lines in the raw
trace files (see Cary Millsap's book), you can even skip the use of
TKPROF - as long as multiple cursors are not opened simultaneously it
is easy to keep things straight.

Cost -> Time in the actual plan.

To set up for this, modify the original SQL statement with a hint like
this:
SELECT /*+ GATHER_PLAN_STATISTICS */
MIN(SYSDATE)
FROM
ALL_TABLES;

Execute the SQL statement, and then to retrieve the actual execution
statistics:
SELECT
*
FROM
TABLE (DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

If instead you wanted the estimated statistics:
SELECT
*
FROM
TABLE (DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,NULL));

More information can be found here:http://jonathanlewis.wordpress.com/2006/11/09/dbms_xplan-in-10g/

Charles Hooper
IT Manager/Oracle DBA
K&M Machine-Fabricating, Inc.

Oracle version 9 for me (and in some cases 8!)

Sorry, I didn't mention it as I'm from a Microsoft SQL background and
didn't think this
would be a new thing but something thats been there for a large number
of years.

No problem, we will just use the method suggested by Sybrand. Let's
assume that you can execute the SQL statement in question in SQL*Plus,
or some other query tool. Before you execute the SQL statement,
execute the following:
ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT FOREVER, LEVEL 8';

The above turns on a 10046 trace at level 8, meaning the Oracle will
not only retrieve the execution plan, but will also indicate what
causes the delays. Once the above is executed, execute your SQL
statement. The following is a trace from Oracle 8.1.7.3 (you will
likely find yours in the udump directory), my comments are in {}:

PARSING IN CURSOR #1 len=799 dep=0 uid=22 oct=3 lid=22 tim=250719498
hv=1165133217 ad='7ac4abc'
{dep=0 indicates SQL statement was executed in an application, dep=1,
dep=2, etc. indicates trigger or space management code executed
automatically in response to the SQL statement executed in the
application. uid=Schema user ID of the user who parsed the SQL
statement. oct=Oracle command type. hv=Statement ID of the SQL
statement, may not be a unique number - can be used with the various V
$SQL_ views}
SELECT
CO.CUSTOMER_ID,
CO.CUSTOMER_PO_REF,
COL.CUST_ORDER_ID||:"SYS_B_0"||COL.LINE_NO AS CUST_ORDER,
COL.PART_ID,
P.DESCRIPTION,
P.WEIGHT,
COL.DESIRED_SHIP_DATE,
COL.TOTAL_SHIPPED_QTY||:"SYS_B_1"||COL.ORDER_QTY AS QTY_SHIPPED,
(COL.ORDER_QTY-COL.TOTAL_SHIPPED_QTY) AS QTY_NEEDED,
COL.UNIT_PRICE AS PRICE,
P.QTY_ON_HAND,
QAP.QTY QAP_QTY
FROM
CUST_ORDER_LINE COL,
CUSTOMER_ORDER CO,
PART P,
QS_AVAILABLE_PARTS QAP
WHERE COL.DESIRED_SHIP_DATE Between :"SYS_B_2" AND :"SYS_B_3"
AND COL.ORDER_QTY > COL.TOTAL_SHIPPED_QTY
AND COL.CUST_ORDER_ID=CO.ID
AND CO.CUSTOMER_ID <> :"SYS_B_4"
AND CO.STATUS <> :"SYS_B_5"
AND COL.PART_ID=P.ID
AND COL.PART_ID=QAP.PART_ID(+)
ORDER BY
CO.CUSTOMER_ID,
COL.CUST_ORDER_ID,
COL.LINE_NO
{Note the :"SYS_B_0", :"SYS_B_1", etc. in the SQL statement - I had
CURSOR_SHARING set to true when I passed in constants, and Oracle
automatically replaced the constants with bind variables}
END OF STMT
PARSE #1:c=2,e=2,p=0,cr=2,cu=0,mis=1,r=0,dep=0,og=0,tim=250719500
{On 8i, c= and e= are specified in 1/100th of a second, on 9i and
above these are specified in 1/1,000,000th of a second - it took 0.02
seconds of CPU time to parse the SQL statement, the elapsed (wall
clock, actual) time was also 0.02 seconds. There were no physical
blocks read from disk (p), but there were 2 blocks read in consistent
read mode (cr), and 0 blocks read in current mode (cu). This SQL
statement was not found in the shared pool (mis=1), and Oracle's
optimizer goal was choose (?) (1=ALL_ROWS, 2=FIRST_ROWS, 3=RULE,
4=CHOOSE)}
EXEC #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=250719500
{Not much new information presented here when the SQL statement was
executed, although we now see that the optimizer goal was choose.}
WAIT #1: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1
p3=0
FETCH
#1:c=17,e=17,p=0,cr=2557,cu=23,mis=0,r=10,dep=0,og=4,tim=250719517
{The initial fetch requires 0.17 seconds of CPU time, the elapsed time
is also 0.17 seconds, no blocks were read from disk, 2557 blocks were
read from the buffer cache in consistent read mode, 23 blocks were
read from the buffer cache in current mode (faster than consistent
read), the client retrieved 10 rows, and you may also note that the
tim= value increased by 17.}
XCTEND rlbk=0, rd_only=1
{The client commits, but does not change anything}
WAIT #1: nam='SQL*Net more data to client' ela= 0 p1=1413697536
p2=2062 p3=0
WAIT #1: nam='SQL*Net message from client' ela= 0 p1=1413697536 p2=1
p3=0
WAIT #1: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1
p3=0
{Data is sent to the client, and the client requests additional data}
FETCH #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=11,dep=0,og=4,tim=250719517
{11 rows are retrieved for the client}
WAIT #1: nam='SQL*Net message from client' ela= 0 p1=1413697536 p2=1
p3=0
WAIT #1: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1
p3=0
FETCH #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=11,dep=0,og=4,tim=250719517
WAIT #1: nam='SQL*Net message from client' ela= 0 p1=1413697536 p2=1
p3=0
WAIT #1: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1
p3=0
FETCH #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=11,dep=0,og=4,tim=250719517
WAIT #1: nam='SQL*Net message from client' ela= 0 p1=1413697536 p2=1
p3=0
WAIT #1: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1
p3=0
FETCH #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=11,dep=0,og=4,tim=250719517
WAIT #1: nam='SQL*Net message from client' ela= 1 p1=1413697536 p2=1
p3=0
WAIT #1: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1
p3=0
FETCH #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=11,dep=0,og=4,tim=250719518
WAIT #1: nam='SQL*Net message from client' ela= 0 p1=1413697536 p2=1
p3=0
WAIT #1: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1
p3=0
FETCH #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=11,dep=0,og=4,tim=250719518
WAIT #1: nam='SQL*Net message from client' ela= 0 p1=1413697536 p2=1
p3=0
WAIT #1: nam='SQL*Net message to client' ela= 0 p1=1413697536 p2=1
p3=0
FETCH #1:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=6,dep=0,og=4,tim=250719520
WAIT #1: nam='SQL*Net message from client' ela= 1 p1=1413697536 p2=1
p3=0
STAT #1 id=1 cnt=192 pid=0 pos=0 obj=0 op='SORT ORDER BY '
STAT #1 id=2 cnt=192 pid=1 pos=1 obj=0 op='NESTED LOOPS '
STAT #1 id=3 cnt=193 pid=2 pos=1 obj=0 op='HASH JOIN OUTER '
STAT #1 id=4 cnt=192 pid=3 pos=1 obj=0 op='HASH JOIN '
STAT #1 id=5 cnt=192 pid=4 pos=1 obj=3380 op='TABLE ACCESS FULL
CUST_ORDER_LINE '
STAT #1 id=6 cnt=5250 pid=4 pos=2 obj=3356 op='TABLE ACCESS FULL
CUSTOMER_ORDER '
STAT #1 id=7 cnt=590 pid=3 pos=2 obj=0 op='VIEW QS_AVAILABLE_PARTS '
STAT #1 id=8 cnt=590 pid=7 pos=1 obj=0 op='SORT GROUP BY '
STAT #1 id=9 cnt=73926 pid=8 pos=1 obj=4446 op='TABLE ACCESS FULL
QUALITY_SCAN '
STAT #1 id=10 cnt=192 pid=2 pos=2 obj=3619 op='TABLE ACCESS BY INDEX
ROWID PART '
STAT #1 id=11 cnt=384 pid=10 pos=1 obj=36798 op='INDEX UNIQUE SCAN '
{The STAT lines indicate the row source execution plan - more recent
versions provide additional information in the STAT lines. pid=
indicates the parent id of the operation, obj can be used to determine
the actual index or table name (query DBA_OBJECTS for SEGMENT_NAME,
where OBJECT_ID=), cnt=cardinality (think of it as the number of
rows)}

id=1 cnt=192 SORT ORDER BY
id=2 cnt=192 NESTED LOOPS
id=3 cnt=193 HASH JOIN OUTER
id=4 cnt=192 HASH JOIN
id=5 cnt=192 TABLE ACCESS FULL CUST_ORDER_LINE
id=6 cnt=5250 TABLE ACCESS FULL CUSTOMER_ORDER
id=7 cnt=590 VIEW QS_AVAILABLE_PARTS
id=8 cnt=590 SORT GROUP BY
id=9 cnt=73926 TABLE ACCESS FULL QUALITY_SCAN
id=10 cnt=192 TABLE ACCESS BY INDEX ROWID PART
id=11 cnt=384 INDEX UNIQUE SCAN (look up obj=36798 to find the
index name)

You could of course just send the trace file into TKPROF once it is
available either on the local drive or a mapped drive. From a command
line:
c:\> TKPROF C:\SourceTraceFile.trc C:\Output.txt sort=EXEELA

However, be aware that this dilutes the information in the trace file,
and may be a bit misleading. An example output (using a different
trace file as the source):
select NVL(sum(order_qty - total_shipped_qty), 0)
from CUST_ORDER_LINE l, CUSTOMER_ORDER o
where part_id = :1
and l.cust_order_id = o.id
and ((l.desired_ship_date is not null and l.desired_ship_date <= :
2 )
or (l.desired_ship_date is null and o.desired_ship_date <= :
3 ))
and o.status in ('F', 'R')
and order_qty > total_shipped_qty

call count cpu elapsed disk query
current rows
------- ------ -------- ---------- ---------- ---------- ----------
----------
Parse 2412 6.28 6.75 0 0
0 0
Execute 2412 0.38 0.42 0 0
0 0
Fetch 2412 0.87 1.41 62 4864
0 2412
------- ------ -------- ---------- ---------- ---------- ----------
----------
total 7236 7.53 8.58 62 4864
0 2412

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

Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE
0 NESTED LOOPS
1 TABLE ACCESS BY INDEX ROWID CUST_ORDER_LINE
1 INDEX RANGE SCAN (object id 4602)
0 TABLE ACCESS BY INDEX ROWID CUSTOMER_ORDER
0 INDEX UNIQUE SCAN (object id 36784)

Note that you can also activate a trace for another session, from
SQL*Plus, after retrieving the SID and SERIAL# of the session to be
traced from V$SESSION:
EXEC SYS.DBMS_SYSTEM.SET_EV(sid,serial#,10046,8)

Charles Hooper
IT Manager/Oracle DBA
K&M Machine-Fabricating, Inc.

.

Relevant Pages

  • Re: Slow SQL, too many logical reads ?
    ... I would be tempted to try reformating the SQL statement like this to ... Oracle is performing a nested loop join between the subquery and the ... The explain plan for... ... (Run your query) ...
    (comp.databases.oracle.server)
  • Re: Q: sys_context() vs. regular function call
    ... Are there any differences between using sys_context in an SQL statement ...  I'm not concerned here with the security ... but maybe there are situations where it would make a speed difference that ... I dunno, if the plan the way you are using it is the same, it should ...
    (comp.databases.oracle.misc)
  • Re: EXISTS and OR statement
    ... i posted the explain plan above. ... i wrote the sql statement with the EXISTS and OR statement but it's ... Daniel Morgan ... Puget Sound Oracle Users Group ...
    (comp.databases.oracle.misc)
  • Re: 9i: Execution plan: Avoid "recursive execution"?
    ... I have a SQL statement here which runs fine on our internal ... development database but crashes with ORA-01652 on the customer ... I received an execution plan from the customer for this query which is ... first of all you could try the NL hint. ...
    (comp.databases.oracle.misc)
  • Re: Chkdsk Failing to Start
    ... Enquire, plan and execute ... You can access Event Viewer by selecting Start, ...
    (microsoft.public.windowsxp.general)