Re: Help on understanding TKprof

"Melgar" <luis_melgar_at_yahoo.com> wrote in message news:1136584876.038803.114390_at_g49g2000cwa.googlegroups.com...
>i have this query,
> and i can notice that logical reads are by far larger that phisical
> ones, yet, the rows retrived are few.
> Since the quere seems to be taking an acceptable execution plan (to me
> at least)
>
> where can i start to find out whats going on?
>
> Thx in advance.
>
> select R.NIS_RAD ,R.SEC_NIS ,R.SEC_REC ,R.F_FACT ,R.COD_CLI ,R.SEC_CTA
> from
> RECIBOS R where (((R.NIS_RAD=:b0 and ((R.SEC_NIS=:b1 or (R.SEC_NIS<:b1
> and
> R.IND_TRASPASO=1)) or exists (select 1 from CUOTAS_PL P ,MACUERDOS M
> where
> (((((((P.NIS_RAD=R.NIS_RAD and P.SEC_NIS=R.SEC_NIS) and
> P.F_FACT=R.F_FACT)
> and P.SEC_REC=R.SEC_REC) and M.NIS_RAD=P.NIS_RAD) and
> M.NUM_ACU=P.NUM_ACU)
> and P.SEC_NIS<:b1) and M.IND_TRASPASO=1)))) and R.EST_ACT in (select
> EST_REC from GRUPO_EST where (CO_GRUPO=:b4 and EST_REC=R.EST_ACT)))
> and
> (((R.F_FACT<TO_DATE(:b5,'YYYYMMDD') and R.TIP_REC not in
> ('TR090','TR013',
> 'TR091','TR092')) or (R.F_FACT=TO_DATE(:b5,'YYYYMMDD') and
> R.SEC_REC<=:b7))
> or (R.F_FACT=TO_DATE(:b5,'YYYYMMDD') and R.TIP_REC in
> ('TR030','TR092',
> 'TR091','TR032')))) order by F_FACT,SEC_REC desc
>
> Rows Execution Plan
> ------- ---------------------------------------------------
> 0 SELECT STATEMENT GOAL: CHOOSE
> 487 SORT (ORDER BY)
> 0 CONCATENATION
> 0 NESTED LOOPS
> 0 TABLE ACCESS GOAL: ANALYZED (BY INDEX ROWID) OF
> 'RECIBOS'
> 30846 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'PK_RECIBOS_NEW'
> (UNIQUE)
> 0 NESTED LOOPS
> 0 TABLE ACCESS GOAL: ANALYZED (BY INDEX ROWID) OF
> 'CUOTAS_PL'
> 60798 INDEX GOAL: ANALYZED (RANGE SCAN) OF
> 'CUOTAS_PL_I03' (NON-UNIQUE)
> 0 TABLE ACCESS GOAL: ANALYZED (BY INDEX ROWID) OF
> 'MACUERDOS'
> 0 INDEX GOAL: ANALYZED (UNIQUE SCAN) OF
> 'PK_MACUERDOS' (UNIQUE)
> 0 INDEX GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_GRUPO_EST'
> (UNIQUE)
> 0 NESTED LOOPS
> 135 TABLE ACCESS GOAL: ANALYZED (BY INDEX ROWID) OF
> 'RECIBOS'
> 615 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'PK_RECIBOS_NEW'
> (UNIQUE)
> 0 INDEX GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_GRUPO_EST'
> (UNIQUE)
> 453 NESTED LOOPS
> 30231 TABLE ACCESS GOAL: ANALYZED (BY INDEX ROWID) OF
> 'RECIBOS'
> 30711 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'PK_RECIBOS_NEW'
> (UNIQUE)
> 29840 INDEX GOAL: ANALYZED (UNIQUE SCAN) OF 'PK_GRUPO_EST'
> (UNIQUE)
>
> ********************************************************************************
>

This execution plan is almost certainly NOT what is actually happening. It has been produced by the 'explain = ' option of tkprof, not formatted from the STAT# lines in the trace file that usually get dumped when the cursor closes.

Reasons for it being the wrong plan - the SQL has some bind variables in it so Oracle has no information about the bind types, and may be making the wrong assumptions; also, you have predicates with ranges in them R.SEC_REC<=:b7, P.SEC_NIS<:b1, which means that Oracle will be using 5% for the selectivities when using explain plan, whereas it might have peeked to get better information at run-time (assuming you are using 9i or better).

Next step - get the hash_value from the trace file (hv=) from the PARSING IN CURSOR line, and use it to extract the run-time plan from v$sql_plan (assuming again that you are on 9i or better).

-- 
Regards

Jonathan Lewis

http://www.jlcomp.demon.co.uk/faq/ind_faq.html
The Co-operative Oracle Users' FAQ

http://www.jlcomp.demon.co.uk/cbo_book/ind_book.html
Cost Based Oracle: Fundamentals

http://www.jlcomp.demon.co.uk/appearances.html
Public Appearances - schedule updated 29th Nov 2005