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

Home -> Community -> Usenet -> c.d.o.server -> Re: Slow SQL, too many logical reads ?

Re: Slow SQL, too many logical reads ?

From: sybrandb <sybrandb_at_gmail.com>
Date: 1 May 2007 07:11:35 -0700
Message-ID: <1178028695.292669.266500@y5g2000hsa.googlegroups.com>


On May 1, 3:27 pm, Peter <peterny..._at_gmail.com> wrote:
> Have a look at the following tkprof output from a 9.2.0.4 Solaris
> database:
>
> ===========================================================================­=
>
> SELECT IA.IA__ICODE,IA.IA__TIMESTAMP,IA.IA__STVDATE,IA.IA__ENVDATE,
>
> IA.IA_IACT1,IA.IA_IACT2,IA.IA_NOTES,IA.IA_EXECU,IA.IA_MEANI,IA.IA_SEQUE,
> IA.IA_REASON
> FROM
> A_INDACT IA WHERE IA.IA_REASON=:"SYS_B_00" AND IA.IA_SEQUE IN
> ( :"SYS_B_01",
> :"SYS_B_02", :"SYS_B_03", :"SYS_B_04", :"SYS_B_05", :"SYS_B_06",
> :"SYS_B_07", :"SYS_B_08", :"SYS_B_09", :"SYS_B_10", :"SYS_B_11" )
> AND
> IA.IA_IACT2 IN ( SELECT AA.AA__ICODE FROM A_ACTA AA WHERE
> AA.AA_IPERM=
> :"SYS_B_12" AND AA.AA_IRSER IN
> ( :"SYS_B_13", :"SYS_B_14", :"SYS_B_15",
> :"SYS_B_16" ) AND AA.AA__DELETED=:"SYS_B_17" ) AND IA.IA__DELETED=
> :"SYS_B_18"
>
> call count cpu elapsed disk query
> current rows
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> Parse 1 0.00 0.01 0 0
> 0 0
> Execute 1 0.00 0.00 0 0
> 0 0
> Fetch 376 1.78 9.77 665 202390
> 0 5623
> ------- ------ -------- ---------- ---------- ---------- ----------
> ----------
> total 378 1.78 9.79 665 202390
> 0 5623
>
> Misses in library cache during parse: 1
> Optimizer goal: CHOOSE
> Parsing user id: 62
>
> Rows Row Source Operation
> ------- ---------------------------------------------------
> 5623 TABLE ACCESS BY INDEX ROWID OBJ#(52752) (cr=202390 r=665 w=0
> time=9731547 us)
> 11530 NESTED LOOPS (cr=197278 r=665 w=0 time=9665024 us)
> 5906 SORT UNIQUE (cr=1333 r=0 w=0 time=58608 us)
> 5906 INLIST ITERATOR (cr=1333 r=0 w=0 time=33935 us)
> 5906 TABLE ACCESS BY INDEX ROWID OBJ#(52679) (cr=1333 r=0 w=0
> time=31899 us)
> 5906 INDEX RANGE SCAN OBJ#(77622) (cr=45 r=0 w=0 time=6901 us)
> (object id 77622)
> 5623 INLIST ITERATOR (cr=195945 r=665 w=0 time=9578266 us)
> 5623 INDEX RANGE SCAN OBJ#(77480) (cr=195945 r=665 w=0
> time=9376899 us)(object id 77480)
>
> ===========================================================================­=
>
> I do not understand the high number of logical reads (cr=195945) in
> the last line.
> I would have expected a number closer to 5906 x 3 logical reads (as
> reaching an index leaf block should require 3 reads).
> This index (OBJ#(77480), non-unique) consists of all the (four)
> A_INDACT columns referenced in the where-clause.
>
> Why would it need 195945 logical reads on the index to find only 5623
> rows ?
>
> -- Peter

One reason would be the optimizer isn't using all the columns. You would need to use dbms_xplan.display to confirm that.

--
Sybrand Bakker
Senior Oracle DBA
Received on Tue May 01 2007 - 09:11:35 CDT

Original text of this message

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