Slow SQL, too many logical reads ?
Peter
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
sybrandb
> Have a look at the following tkprof output from a 9.2.0.4 Solaris
> database:
>
>
> 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
Peter
Thanks, here is the dbms_xplan.display output:
SQL> explain plan for
2 SELECT
3 IA.IA__ICODE,IA.IA__TIMESTAMP,IA.IA__STVDATE,IA.IA__ENVDATE,
4
IA.IA_IACT1,IA.IA_IACT2,IA.IA_NOTES,IA.IA_EXECU,IA.IA_MEANI,IA.IA_SEQUE,IA.IA_REASON
5 FROM
6 A_INDACT IA
7 WHERE
8 IA.IA_REASON='#EPM#Int2Int'
9 AND IA.IA_SEQUE IN ( '17', '2', '4', '9', '11', '6', '1', '3',
'10', '5', '0' )
10 AND IA.IA_IACT2 IN (
11 SELECT AA.AA__ICODE
12 FROM A_ACTA AA
13 WHERE
14 AA.AA_IPERM='dhMPD0002CLR'
15 AND AA.AA_IRSER IN ( '#EPM#PreMd', '#EPM#Pre', '#EPM#EnsInt',
'#EPM#Med' )
16 AND AA.AA__DELETED='N'
17 )
18 AND IA.IA__DELETED='N'
19 ;
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows |
Bytes | Cost
(%CPU)|
------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 42 |
5670 | 16
(7)|
| 1 | TABLE ACCESS BY INDEX ROWID | A_INDACT | 1
| 94 | 2
(50)|
| 2 | NESTED LOOPS | | 42 |
5670 | 16
(7)|
| 3 | SORT UNIQUE | |
| |
|
| 4 | INLIST ITERATOR | |
| |
|
| 5 | TABLE ACCESS BY INDEX ROWID| A_ACTA | 34 |
1394 | 4
(0)|
|* 6 | INDEX RANGE SCAN | MORTEN | 34
| | 1
(0)|
| 7 | INLIST ITERATOR | |
| |
|
|* 8 | INDEX RANGE SCAN | ACURE_A_INDACT_1 | 1
| | 1
(0)|
------------------------------------------------------------------------------------------
Predicate Information (identified by operation
id):
---------------------------------------------------
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
6 - access("AA"."AA_IPERM"='dhMPD0002CLR' AND
("AA"."AA_IRSER"='#EPM#EnsInt'
OR
"AA"."AA_IRSER"='#EPM#Med' OR "AA"."AA_IRSER"='#EPM#Pre'
OR
"AA"."AA_IRSER"='#EPM#PreMd')
AND
"AA"."AA__DELETED"='N')
filter("AA"."AA__DELETED"='N')
8 - access("IA"."IA_IACT2"="AA"."AA__ICODE" AND
"IA"."IA_REASON"='#EPM#Int2Int'
AND
("IA"."IA_SEQUE"=0 OR "IA"."IA_SEQUE"=1 OR
"IA"."IA_SEQUE"=2 OR "IA"."IA_SEQUE"=3
OR
"IA"."IA_SEQUE"=4 OR "IA"."IA_SEQUE"=5 OR
"IA"."IA_SEQUE"=6 OR "IA"."IA_SEQUE"=9
OR
"IA"."IA_SEQUE"=10 OR "IA"."IA_SEQUE"=11 OR
"IA"."IA_SEQUE"=17)
AND
"IA"."IA__DELETED"='N')
Seems like the
|* 8 | INDEX RANGE SCAN | ACURE_A_INDACT_1 | 1
| | 1
(0)|
is actually using all the four index columns ?
(not sure I understand the meaning of
| 7 | INLIST ITERATOR | |
| | |
however ?)
-- Peter
sybrandb
> 5 FROM
> 6 A_INDACT IA
> 7 WHERE
> 8 IA.IA_REASON='#EPM#Int2Int'
> 9 AND IA.IA_SEQUE IN ( '17', '2', '4', '9', '11', '6', '1', '3',
> '10', '5', '0' )
> 10 AND IA.IA_IACT2 IN (
> 11 SELECT AA.AA__ICODE
> 12 FROM A_ACTA AA
> 13 WHERE
> 14 AA.AA_IPERM='dhMPD0002CLR'
> 15 AND AA.AA_IRSER IN ( '#EPM#PreMd', '#EPM#Pre', '#EPM#EnsInt',
> '#EPM#Med' )
> 16 AND AA.AA__DELETED='N'
> 17 )
> 18 AND IA.IA__DELETED='N'
> 19 ;
>
> PLAN_TABLE_OUTPUT
> | Id | Operation | Name | Rows |
> Bytes | Cost
> (%CPU)|
>
> | 0 | SELECT STATEMENT | | 42 |
> 5670 | 16
> (7)|
> | 1 | TABLE ACCESS BY INDEX ROWID | A_INDACT | 1
> | 94 | 2
> (50)|
> | 2 | NESTED LOOPS | | 42 |
> 5670 | 16
> (7)|
> | 3 | SORT UNIQUE | |
> | |
> |
> | 4 | INLIST ITERATOR | |
> | |
> |
> | 5 | TABLE ACCESS BY INDEX ROWID| A_ACTA | 34 |
> 1394 | 4
> (0)|
> |* 6 | INDEX RANGE SCAN | MORTEN | 34
> | | 1
> (0)|
> | 7 | INLIST ITERATOR | |
> | |
> |
> |* 8 | INDEX RANGE SCAN | ACURE_A_INDACT_1 | 1
> | | 1
> (0)|
>
>
> Predicate Information (identified by operation
> id):
> ---------------------------------------------------
> PLAN_TABLE_OUTPUT
>
> - Show quoted text -
In the past Oracle would automagically transform
select * from emp where empno in (10,20,30)
into
select *
from emp
where empno = 10
'union'
select *
from emp
where empno=20
'union'
select *
from emp
where empno = 30
This was called 'concatenation'
The inlist iterator was invented to have Oracle hit the index multiple
times to avoid this concatenation.
You state that all 4 columns of your index are in the where clause.
However you have one of these columns in an inlist. My suspicion is
a) Oracle won't transform your statement into
(seque=constant and <3 other columns> ) or (seque = constant and 3 <
other columns>)
b) your seque column is leading in the index.
I'm not very sure about this, but I seem to remember there are hints
to enable and disable the concatenation mechanism, the latter being
called NO_CONCAT.
The same probably applies to the INLIST mechanism.
I would need to search the docs, as it is getting late, I would
rather leave that to you.
Charles Hooper
> Have a look at the following tkprof output from a 9.2.0.4 Solaris
> database:
>
>
> 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
I would be tempted to try reformating the SQL statement like this to
see if it makes an improvement:
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,
(SELECT DISTINCT
AA.AA__ICODE
FROM
A_ACTA AA
WHERE
AA.AA_IPERM='dhMPD0002CLR'
AND AA.AA_IRSER IN ( '#EPM#PreMd', '#EPM#Pre', '#EPM#EnsInt',
'#EPM#Med' )
AND AA.AA__DELETED='N') AA
WHERE
IA.IA_REASON='#EPM#Int2Int'
AND IA.IA_SEQUE IN ( '17', '2', '4', '9', '11', '6', '1', '3', '10',
'5', '0' )
AND IA.IA_IACT2=AA.AA__ICODE
AND IA.IA__DELETED='N';
Oracle is performing a nested loop join between the subquery and the
ACURE_A_INDACT_1 index blocks. For every row returned by the
subquery, Oracle is scanning the entries in the ACURE_A_INDACT_1 index
for matching entries. If one row were to be returned by the subquery
and the ACURE_A_INDACT_1 index contained 1000 blocks, there would be
1000 logical reads. If the subquery returned two rows, there woudl be
2000 logical reads, etc.
The explain plan for... that you posted is one of the variants offered
by DBMS_XPLAN (the typical) setting that seems to return the same plan
statistics that would appear in a 10053 trace file. You might want to
re-run the explain plan using the ALLSTATS setting so that you return
the plan that would appear in a 10046 trace's row source lines.
---------------
ALTER SESSION SET STATISTICS_LEVEL=ALL;
(Run your query)
SELECT
*
FROM
TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS'));
---------------
Compare those results with what you receive with the following:
---------------
ALTER SESSION SET STATISTICS_LEVEL=ALL;
(Run your query)
SELECT
*
FROM
TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));
---------------
For instance, ALLSTATS (note, might want to flush the shared pool
first so that Starts indicates the number of times that portion of the
SQL statement executed):
---------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-
Rows | A-Rows | A-Time | Buffers | Reads | OMem | 1Mem | O/1/
M |
---------------------------------------------------------------------------------------------------------------------------------------------
| 1 | SORT UNIQUE | | 3 |
2 | 0 |00:00:04.06 | 10055 | 3349 | 1024 | 1024 |
3/0/0|
| 2 | UNION-ALL | | 3
| | 0 |00:00:04.06 | 10055 | 3349 | |
| |
|* 3 | TABLE ACCESS BY INDEX ROWID | PAYABLE | 3 |
1 | 0 |00:00:04.06 | 10046 | 3348 | | |
|
|* 4 | INDEX RANGE SCAN | X_PAYABLE_2 | 3 |
1 | 454K|00:00:01.07 | 828 | 276 | | |
|
| 5 | NESTED LOOPS | | 3 |
1 | 0 |00:00:00.01 | 9 | 1 | | |
|
|* 6 | TABLE ACCESS FULL | PAYABLE_INST | 3 |
1 | 0 |00:00:00.01 | 9 | 1 | | |
|
|* 7 | TABLE ACCESS BY INDEX ROWID| PAYABLE | 0 |
1 | 0 |00:00:00.01 | 0 | 0 | | |
|
|* 8 | INDEX UNIQUE SCAN | SYS_C006820 | 0 |
1 | 0 |00:00:00.01 | 0 | 0 | | |
|
---------------------------------------------------------------------------------------------------------------------------------------------
TYPICAL for the same SQL statement:
--------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes
| Cost (%CPU)| Time | Inst |
--------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | |
| 7 (100)| | |
| 1 | SORT UNIQUE | | 2 | 284
| 6 (67)| 00:00:01 | |
| 2 | UNION-ALL | | |
| | | |
|* 3 | TABLE ACCESS BY INDEX ROWID | PAYABLE | 1 | 121
| 2 (0)| 00:00:01 | TEST |
|* 4 | INDEX RANGE SCAN | X_PAYABLE_2 | 1 |
| 1 (0)| 00:00:01 | TEST |
| 5 | NESTED LOOPS | | 1 | 163
| 2 (0)| 00:00:01 | |
|* 6 | TABLE ACCESS FULL | PAYABLE_INST | 1 | 73
| 2 (0)| 00:00:01 | TEST |
|* 7 | TABLE ACCESS BY INDEX ROWID| PAYABLE | 1 | 90
| 0 (0)| | TEST |
|* 8 | INDEX UNIQUE SCAN | SYS_C006820 | 1 |
| 0 (0)| | TEST |
--------------------------------------------------------------------------------------------------------
Note - in the above example, the second DBMS_XPLAN shows a very
efficient plan, while the first DBMS_XPLAN shows a very bad plan where
Oracle selected a very unselective (wrong) index.
Charles Hooper
IT Manager/Oracle DBA
K&M Machine-Fabricating, Inc.
Peter
Thanks,
As said earlier the index consists of all the columns used in the
where-clause:
select * from user_ind_columns
where index_name = 'ACURE_A_INDACT_1';
INDEX_NAME TABLE_NAME COLUMN_NAME COLUMN_POSITION COLUMN_LENGTH
CHAR_LENGTH DESCEND
ACURE_A_INDACT_1 A_INDACT IA_IACT2 1 12 12 ASC
ACURE_A_INDACT_1 A_INDACT IA_REASON 2 12 12 ASC
ACURE_A_INDACT_1 A_INDACT IA_SEQUE 3 22 0 ASC
ACURE_A_INDACT_1 A_INDACT IA__DELETED 4 1 1 ASC
I tried using the /*+NO_EXPAND*/ hint, but that had no effect at
all !?
Then, I tried modified the query, removing the IA.IA_SEQUE from the
where-clause (in reality I *need* this predicate, but just to
troubleshoot ...) and that had a very positive effect:
=============================================
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_0"
--AND IA.IA_SEQUE IN ( '17', '2', '4', '9', '11', '6', '1', '3',
'10', '5', '0' )
AND IA.IA_IACT2 IN (
SELECT AA.AA__ICODE
FROM A_ACTA AA
WHERE
AA.AA_IPERM=:"SYS_B_1"
AND AA.AA_IRSER IN
( :"SYS_B_2", :"SYS_B_3", :"SYS_B_4", :"SYS_B_5" )
AND AA.AA__DELETED=:"SYS_B_6"
)
AND IA.IA__DELETED=:"SYS_B_7"
call count cpu elapsed disk query
current rows
------- ------ -------- ---------- ---------- ---------- ----------
----------
Parse 1 0.00 0.00 0 0
0 0
Execute 1 0.01 0.00 0 0
0 0
Fetch 381 0.24 0.33 1 18932
0 5688
------- ------ -------- ---------- ---------- ---------- ----------
----------
total 383 0.25 0.33 1 18932
0 5688
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 62 (EPM)
Rows Row Source Operation
------- ---------------------------------------------------
5688 TABLE ACCESS BY INDEX ROWID OBJ#(52752) (cr=18932 r=1 w=0
time=290890 us)
11560 NESTED LOOPS (cr=13782 r=0 w=0 time=204860 us)
5871 SORT UNIQUE (cr=1312 r=0 w=0 time=60987 us)
5871 INLIST ITERATOR (cr=1312 r=0 w=0 time=36738 us)
5871 TABLE ACCESS BY INDEX ROWID OBJ#(52679) (cr=1312 r=0 w=0
time=34603 us)
5871 INDEX RANGE SCAN OBJ#(77622) (cr=45 r=0 w=0 time=7283 us)
(object id 77622)
5688 INDEX RANGE SCAN OBJ#(77480) (cr=12470 r=0 w=0 time=119228
us)(object id 77480)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
5688 TABLE ACCESS GOAL: ANALYZED (BY INDEX ROWID) OF 'A_INDACT'
11560 NESTED LOOPS
5871 SORT (UNIQUE)
5871 INLIST ITERATOR
5871 TABLE ACCESS GOAL: ANALYZED (BY INDEX ROWID) OF
'A_ACTA'
5871 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'MORTEN'
(NON-UNIQUE)
5688 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'ACURE_A_INDACT_1'
(NON-UNIQUE)
=============================================
... now only 18932 logical reads in total (12470 from the index) !
Not that it solves my problem (it certainly does not), but it may
point to the root cause for some of you clever guys ?
My original question it still unanswered:
Why would the original query need 195945 logical reads on the index to
find only 5623 rows ?
Why does the modified query (now only referring to 3 out of 4 indexed
columns in where-clause) only need 18932 logical reads (ten times less
"work") ?
-- Peter
sybrandb
> > | Id | Operation | Name | Starts | E-
> > Rows | A-Rows | A-Time | Buffers | Reads | OMem | 1Mem | O/1/
> > M |
> > | 1 | SORT UNIQUE | | 3 |
> > 2 | 0 |00:00:04.06 | 10055 | 3349 | 1024 | 1024 |
> > 3/0/0|
> > | 2 | UNION-ALL | | 3
> > | | 0 |00:00:04.06 | 10055 | 3349 | |
> > | |
> > |* 3 | TABLE ACCESS BY INDEX ROWID | PAYABLE | 3 |
> > 1 | 0 |00:00:04.06 | 10046 | 3348 | | |
> > |
> > |* 4 | INDEX RANGE SCAN | X_PAYABLE_2 | 3 |
> > 1 | 454K|00:00:01.07 | 828 | 276 | | |
> > |
> > | 5 | NESTED LOOPS | | 3 |
> > 1 | 0 |00:00:00.01 | 9 | 1 | | |
> > |
> > |* 6 | TABLE ACCESS FULL | PAYABLE_INST | 3 |
> > 1 | 0 |00:00:00.01 | 9 | 1 | | |
> > |
> > |* 7 | TABLE ACCESS BY INDEX ROWID| PAYABLE | 0 |
> > 1 | 0 |00:00:00.01 | 0 | 0 | | |
> > |
> > |* 8 | INDEX UNIQUE SCAN | SYS_C006820 | 0 |
> > 1 | 0 |00:00:00.01 | 0 | 0 | | |
> > |
>
> > TYPICAL for the same SQL statement:
> > | Id | Operation | Name | Rows | Bytes
> > | Cost (%CPU)| Time | Inst |
> > | 0 | SELECT STATEMENT | | |
> > | 7 (100)| | |
> > | 1 | SORT UNIQUE | | 2 | 284
> > | 6 (67)| 00:00:01 | |
> > | 2 | UNION-ALL | | |
> > | | | |
> > |* 3 | TABLE ACCESS BY INDEX ROWID | PAYABLE | 1 | 121
> > | 2 (0)| 00:00:01 | TEST |
> > |* 4 | INDEX RANGE SCAN | X_PAYABLE_2 | 1 |
> > | 1 (0)| 00:00:01 | TEST |
> > | 5 | NESTED LOOPS | | 1 | 163
> > | 2 (0)| 00:00:01 | |
> > |* 6 | TABLE ACCESS FULL | PAYABLE_INST | 1 | 73
> > | 2 (0)| 00:00:01 | TEST |
> > |* 7 | TABLE ACCESS BY INDEX ROWID| PAYABLE | 1 | 90
> > | 0 (0)| | TEST |
> > |* 8 | INDEX UNIQUE SCAN | SYS_C006820 | 1 |
> > | 0 (0)| | TEST |
You have
column 1 (in the index) --> bind variable
column 2 (in the index) ---> hardcoded
column 3 (in the index) ---> bind variable
column 4 ( in the index) ---> bind variable
Leaving out the condition on column2, Oracle will probably assume the
cardinality is 1/NDV. In your case Oracle starts making assumptions.
If I would have to deal with this I would try two things
a) order the predicates correctly, so they are in order of the index,
and use the corresponding hint (I believe 'ordered_predicates')
b) mislead the optimizer by feeding the IN list to Tom Kytes 'Dynamic
IN list' function (available at http://asktom.oracle.com)
In both cases I would use event 10053 to get a trace file with CBO's
decision tree.
You simply *must* ignore part of the index, I already tried to explain
this to you, not sure why you don't want to buy this.
Charles Hooper
> On May 1, 7:15 pm, Charles Hooper <hooperc2...@yahoo.com> wrote:
> > Oracle is performing a nested loop join between the subquery and the
> > ACURE_A_INDACT_1 index blocks. For every row returned by the
> > subquery, Oracle is scanning the entries in the ACURE_A_INDACT_1 index
> > for matching entries. If one row were to be returned by the subquery
> > and the ACURE_A_INDACT_1 index contained 1000 blocks, there would be
> > 1000 logical reads. If the subquery returned two rows, there woudl be
> > 2000 logical reads, etc.
>
> > The explain plan for... that you posted is one of the variants offered
> > by DBMS_XPLAN (the typical) setting that seems to return the same plan
> > statistics that would appear in a 10053 trace file. You might want to
> > re-run the explain plan using the ALLSTATS setting so that you return
> > the plan that would appear in a 10046 trace's row source lines.
>
> > ---------------
> > ALTER SESSION SET STATISTICS_LEVEL=ALL;
>
> > (Run your query)
>
> > SELECT
> > *
> > FROM
> > TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS'));
> > ---------------
> > Compare those results with what you receive with the following:
> >
Great to hear that the rewrite helped. What the rewritten query did
was to move the subquery to an inline view. If I am reading the plan
correctly, the query execution time dropped from 9.731 seconds to
0.290 seconds (assuming that you are running 9i or higher).
This is my original explaination why there are so logical reads of the
index blocks:
> > Oracle is performing a nested loop join between the subquery and the
> > ACURE_A_INDACT_1 index blocks. For every row returned by the
> > subquery, Oracle is scanning the entries in the ACURE_A_INDACT_1 index
> > for matching entries. If one row were to be returned by the subquery
> > and the ACURE_A_INDACT_1 index contained 1000 blocks, there would be
> > 1000 logical reads. If the subquery returned two rows, there woudl be
> > 2000 logical reads, etc.
Pseudocode of the above explanation:
for i = 1 to ROWS_IN_SUBQUERY
for j = 1 to NUMBER_OF_ENTRIES_IN_ACURE_A_INDACT_1
'Read the block contents using logical read
next j
next i
I believe that the bind variables shown are system generated due to
the CURSOR_SHARING parameter. As Sybrand indicates, the bind
variables may be affecting performance to some extent.
Jonathan Lewis
"Charles Hooper" <hoope...@yahoo.com> wrote in message
news:1178039702....@o5g2000hsb.googlegroups.com...
---------------
ALTER SESSION SET STATISTICS_LEVEL=ALL;
(Run your query)
SELECT
*
FROM
TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS'));
---------------
For instance, ALLSTATS (note, might want to flush the shared pool
first so that Starts indicates the number of times that portion of the
SQL statement executed):
Charles,
There is an option for display_cursor which is 'ALLSTATS LAST'. this give
you the stats from the last execution of the query, and makes the shared
pool
flush unnecessary.
--
Regards
Jonathan Lewis
http://jonathanlewis.wordpress.com
Author: Cost Based Oracle: Fundamentals
http://www.jlcomp.demon.co.uk/cbo_book/ind_book.html
The Co-operative Oracle Users' FAQ
http://www.jlcomp.demon.co.uk/faq/ind_faq.html
Jonathan Lewis
"Peter" <peter...@gmail.com> wrote in message
news:1178030834.5...@e65g2000hsc.googlegroups.com...
8 - access("IA"."IA_IACT2"="AA"."AA__ICODE" AND
"IA"."IA_REASON"='#EPM#Int2Int'
AND
("IA"."IA_SEQUE"=0 OR "IA"."IA_SEQUE"=1 OR
"IA"."IA_SEQUE"=2 OR "IA"."IA_SEQUE"=3
OR
"IA"."IA_SEQUE"=4 OR "IA"."IA_SEQUE"=5 OR
"IA"."IA_SEQUE"=6 OR "IA"."IA_SEQUE"=9
OR
"IA"."IA_SEQUE"=10 OR "IA"."IA_SEQUE"=11 OR
"IA"."IA_SEQUE"=17)
AND
"IA"."IA__DELETED"='N')
Peter,
Can you tell us the definition of the four-column
index - the column order may have some bearing
on the resource usage.
Charles Hooper
wrote:
> "Charles Hooper" <hooperc2...@yahoo.com> wrote in message
> ALTER SESSION SET STATISTICS_LEVEL=ALL;
>
> (Run your query)
>
> SELECT
> *
> FROM
> TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS'));
> ---------------
>
> For instance, ALLSTATS (note, might want to flush the shared pool
> first so that Starts indicates the number of times that portion of the
> SQL statement executed):
>
> Charles,
>
> There is an option for display_cursor which is 'ALLSTATS LAST'. this give
> you the stats from the last execution of the query, and makes the shared
> pool
> flush unnecessary.
>
> --
> Regards
>
> Jonathan Lewis http://jonathanlewis.wordpress.com
>
Jonathan,
Thanks a lot for the tip (I was hoping that I was overlooking
something). The impact of the plan is very hard to determine without
specifying the "LAST" keyword, or without flushing the shared pool
first. Based on a very quick test, the Starts, A-Rows, Buffers
columns all increase in value with each execution, while the A-Time,
and Reads columns do not increase when the "LAST" keyword is not
specified. When the "LAST" keyword is specified, the impact of the
plan is much more clear, but the READS column is no longer returned.
Just out of curiosity, do you think that DBMS_XPLAN is retrieving its
source data by querying V$SQL_PLAN_STATISTICS_ALL (or the underlying
views), and when the LAST keyword is specified, only returns those
columns which are prefixed with LAST_ ? The reason that I ask is that
I am currently investigating performance problems with a packaged
application that is running against Oracle 10.2.0.2. Due to bind
variable peeking, and the fact that the packaged application is either
not supplying bind variable values during the initial parse call, or
is specifying out of bounds values, Oracle is selecting to perform an
index range scan using an index on a column that contains only two
distinct values, when it should be using the index on the primary key
column to retrieve table data. Oracle selects the correct index if
bind variable peeking is disabled. I am trying to develop a logical
approach to determine which SQL statements need to have an outline
developed when bind variable peeking is disabled at the session
level.
Mladen Gogala
> Just out of curiosity, do you think that DBMS_XPLAN is retrieving its
> source data by querying V$SQL_PLAN_STATISTICS_ALL (or the underlying
> views), and when the LAST keyword is specified, only returns those
> columns which are prefixed with LAST_ ?
I believe it does. Here is my proof:
Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.3.0 - Production
With the Partitioning, OLAP and Data Mining options
SQL> alter session set tracefile_identifier=CHOOPER;
Session altered.
SQL> explain plan for
2 select * from emp;
Explained.
SQL> alter session set events='10046 trace name context forever, level
12';
Session altered.
SQL> select * from
2 TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS'));
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
SQL_ID 9babjv8yq8ru3, child number 0
BEGIN DBMS_OUTPUT.GET_LINES(:LINES, :NUMLINES); END;
NOTE: cannot fetch plan for SQL_ID: 9babjv8yq8ru3, CHILD_NUMBER: 0
Please verify value of SQL_ID and CHILD_NUMBER;
It could also be that the plan is no longer in cursor cache (check v
$sql_p
lan)
8 rows selected.
SQL>
It is trying to fetch from V$SQL_PLAN. Let's see the details:
$ ls -l 10g_ora_4593_CHOOPER.trc
-rw-r----- 1 501 168820 May 5 14:56 10g_ora_4593_CHOOPER.trc
$ tkprof 10g_ora_4593_CHOOPER.trc /tmp/chooper.lis sys=yes waits=no
TKPROF: Release 10.2.0.3.0 - Production on Sat May 5 14:58:37 2007
Copyright (c) 1982, 2005, Oracle. All rights reserved.
In that file is the answer too your question:
select text
from
view$ where rowid=:1
LAST_OUTPUT_ROWS, OUTPUT_ROWS, LAST_CR_BUFFER_GETS,
CR_BUFFER_GETS, LAST_CU_BUFFER_GETS, CU_BUFFER_GETS,
LAST_DISK_READS, DISK_READS, LAST_DISK_WRITES, DISK_WRITES,
LAST_ELAPSED_TIME, ELAPSED_TIME, POLICY,
ESTIMATED_OPTIMAL_SIZE, ESTIMATED_ONEPASS_SIZE,
LAST_MEMORY_USED, LAST_EXECUTION, LAST_DEGREE,
TOTAL_EXECUTIONS, OPTIMAL_EXECUTIONS, ONEPASS_EXECUTIONS,
MULTIPASSES_EXECUTIONS, ACTIVE_TIME, MAX_TEMPSEG_SIZE,
LAST_TEMPSEG_SIZE
from
GV$SQL_PLAN_STATISTICS_ALL
where inst_id = USERENV('Instance')
The answer to your question is a resounding "yes".
Charles Hooper
wrote:
> On Fri, 04 May 2007 16:53:25 -0700, Charles Hooper wrote:
> > Just out of curiosity, do you think that DBMS_XPLAN is retrieving its
> > source data by querying V$SQL_PLAN_STATISTICS_ALL (or the underlying
> > views), and when the LAST keyword is specified, only returns those
> > columns which are prefixed with LAST_ ?
>
> I believe it does. Here is my proof:
> Please verify value of SQL_ID and CHILD_NUMBER;
> It could also be that the plan is no longer in cursor cache (check v
> $sql_p
> lan)
>
> CR_BUFFER_GETS, LAST_CU_BUFFER_GETS, CU_BUFFER_GETS,
> LAST_DISK_READS, DISK_READS, LAST_DISK_WRITES, DISK_WRITES,
> LAST_ELAPSED_TIME, ELAPSED_TIME, POLICY,
> ESTIMATED_OPTIMAL_SIZE, ESTIMATED_ONEPASS_SIZE,
> LAST_MEMORY_USED, LAST_EXECUTION, LAST_DEGREE,
> TOTAL_EXECUTIONS, OPTIMAL_EXECUTIONS, ONEPASS_EXECUTIONS,
> MULTIPASSES_EXECUTIONS, ACTIVE_TIME, MAX_TEMPSEG_SIZE,
> LAST_TEMPSEG_SIZE
>
> from
> GV$SQL_PLAN_STATISTICS_ALL
> where inst_id = USERENV('Instance')
>
> The answer to your question is a resounding "yes".
>
> --http://www.mladen-gogala.com
Mladen, thanks for setting up the test case to show from where the
source data for DBMS_XPLAN is being retrieved.
Peter
wrote:
> "Peter" <peterny...@gmail.com> wrote in message
>
> news:1178030834.5...@e65g2000hsc.googlegroups.com...
> 8 - access("IA"."IA_IACT2"="AA"."AA__ICODE" AND
> "IA"."IA_REASON"='#EPM#Int2Int'
> AND
> ("IA"."IA_SEQUE"=0 OR "IA"."IA_SEQUE"=1 OR
> "IA"."IA_SEQUE"=2 OR "IA"."IA_SEQUE"=3
> OR
> "IA"."IA_SEQUE"=4 OR "IA"."IA_SEQUE"=5 OR
> "IA"."IA_SEQUE"=6 OR "IA"."IA_SEQUE"=9
> OR
> "IA"."IA_SEQUE"=10 OR "IA"."IA_SEQUE"=11 OR
> "IA"."IA_SEQUE"=17)
> AND
>
> "IA"."IA__DELETED"='N')
>
> Peter,
>
> Can you tell us the definition of the four-column
> index - the column order may have some bearing
> on the resource usage.
>
> --
> Regards
>
>
> Author: Cost Based Oracle: Fundamentalshttp://www.jlcomp.demon.co.uk/cbo_book/ind_book.html
Jonathan, the ordering of the index was given above:
select * from user_ind_columns
where index_name = 'ACURE_A_INDACT_1';
INDEX_NAME TABLE_NAME COLUMN_NAME COLUMN_POSITION
COLUMN_LENGTH
CHAR_LENGTH DESCEND
ACURE_A_INDACT_1 A_INDACT IA_IACT2 1
12 12 ASC
ACURE_A_INDACT_1 A_INDACT IA_REASON 2
12 12 ASC
ACURE_A_INDACT_1 A_INDACT IA_SEQUE 3
22 0 ASC
ACURE_A_INDACT_1 A_INDACT IA__DELETED 4
1 1 ASC
I am answering this from home, without access to the database etc.
right now.
Anyway, I still lack a real understanding of how my original query is
processed, and if/how it could possibly be improved.
Is this what goes on:
- for each of the 5906 rows in sub-select:
-- for each of the 11 elements in the inlist:
--- retrieve the corresponding ROWIDs from the index ?
Assuming 3 reads to get to an index leaf block, if the the third step
would always visit only one index leaf block, we get:
5906 x 11 x 3 = 194898 logical reads on the index,
close to the actual 195945 reads reported from tkprof, the difference
being that it few times need to visit more than one index leaf block ?
Could the second step (inlist) be replaced with something more
efficient (filter?) ?
What would be the most efficient plan ?
-- Peter
Mladen Gogala
> Mladen, thanks for setting up the test case to show from where the
> source data for DBMS_XPLAN is being retrieved.
No problems. You are one of my favorite people on this group and
the question you asked was interesting.
Jonathan Lewis
Charles,
I see Mladen has already answered your question.
For more details, you could check the script
$ORACLE_HOME/rdbms/admin/dbmsxplan.sql
The disappearance of the READS column is simply based
on the fact that the pl/sql attempts (as far as I can tell) to
hide any column where the value is always zero.
Would event 10132 help with the problem of identifying
isolating queries where inconsistency with the supply of
bind variables was causing problems. I'd be interested
to hear of any cases where you can see a consistent
pattern with bind variables disappearing - I think I had
some email recently from someone who was seeing the
same problem.
Jonathan Lewis
Your description of the activity sounds correct -
I think someone else actually made the same point
in an earlier post.
If you switched to a filter operation, it wouldn't improve.
In fact in earlier versions of Oracle 9.2, possibly even 10.1,
the check of the third index column with its in-list would
not have been an access predicate, it would have been
delayed to a filter predicate - with the result that the 5,906
index range scans would have used the entire range dictated
by the first two column, and then filtered on the last two,
probably increasing the work done in the index.
You might try reversing the third and fourth columns of
the index - provided this doesn't cause more problems in
other queries. Depending on the data sizes and distributions,
this might reduce your logical I/O by pulling the data for the
11 different values into a smaller number of index leaf blocks,
possibly allowing Oracle to do more work with pinned blocks
than it is currently doing.
--
Regards
Jonathan Lewis
http://jonathanlewis.wordpress.com
Author: Cost Based Oracle: Fundamentals
http://www.jlcomp.demon.co.uk/cbo_book/ind_book.html
The Co-operative Oracle Users' FAQ
http://www.jlcomp.demon.co.uk/faq/ind_faq.html
"Peter" <peter...@gmail.com> wrote in message
news:1178455067.2...@o5g2000hsb.googlegroups.com...
Peter
wrote:
> Your description of the activity sounds correct -
> I think someone else actually made the same point
> in an earlier post.
>
> If you switched to a filter operation, it wouldn't improve.
> In fact in earlier versions of Oracle 9.2, possibly even 10.1,
> the check of the third index column with its in-list would
> not have been an access predicate, it would have been
> delayed to a filter predicate - with the result that the 5,906
> index range scans would have used the entire range dictated
> by the first two column, and then filtered on the last two,
> probably increasing the work done in the index.
>
> You might try reversing the third and fourth columns of
> the index - provided this doesn't cause more problems in
> other queries. Depending on the data sizes and distributions,
> this might reduce your logical I/O by pulling the data for the
> 11 different values into a smaller number of index leaf blocks,
> possibly allowing Oracle to do more work with pinned blocks
> than it is currently doing.
>
> --
> Regards
>
>
> Author: Cost Based Oracle: Fundamentalshttp://www.jlcomp.demon.co.uk/cbo_book/ind_book.html
>
> The Co-operative Oracle Users' FAQhttp://www.jlcomp.demon.co.uk/faq/ind_faq.html
>
Thanks, I will probably try your index tip (reversing the third and
fourth columns) one of these days (... but I'm not the only one using
the database, and the table is rather big, 48M rows).
Is it possible to force (hint or something) the inlist to be delayed
to a filter predicate ? As you say, it might make things worse, but I
would like to try anyway, as the first column, IA_IACT2, is very
selective (20M distinct values), while the third (inlist) column,
IA_SEQUE, is very un-selective (only 13 distinct values).
Also, see my May 1, 7:15 pm posting, where I tried removing the
predicate
--AND IA.IA_SEQUE IN ( '17', '2', '4', '9', '11', '6', '1', '3', '10',
'5', '0' )
with big performance gains.
Regards,
-- Peter
Jonathan Lewis
> fourth columns) one of these days (... but I'm not the only one using
> the database, and the table is rather big, 48M rows).
>
> Is it possible to force (hint or something) the inlist to be delayed
> to a filter predicate ? As you say, it might make things worse, but I
> would like to try anyway, as the first column, IA_IACT2, is very
> selective (20M distinct values), while the third (inlist) column,
> IA_SEQUE, is very un-selective (only 13 distinct values).
>
> Also, see my May 1, 7:15 pm posting, where I tried removing the
> predicate
> --AND IA.IA_SEQUE IN ( '17', '2', '4', '9', '11', '6', '1', '3', '10',
> '5', '0' )
> with big performance gains.
>
> Regards,
>
> -- Peter
>
Try changing the predicate to
AND IA.IA_SEQUE||'' IN ( '17', '2', '4', '9', '11', '6', '1', '3','10',
'5', '0' )
In your version of Oracle this should still be resolved
in the index (earlier versions would postpone it to the
table visit) but as a FILTER rather than an ACCESS
predicate
--
Regards
Jonathan Lewis
Peter
wrote:
> "Peter" <peterny...@gmail.com> wrote in message
>
> Author: Cost Based Oracle: Fundamentalshttp://www.jlcomp.demon.co.uk/cbo_book/ind_book.html
Oh yes, that certainly made a difference:
===============================
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 || :"SYS_B_01" IN
( :"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", :
AND IA.IA_IACT2 IN (
SELECT AA.AA__ICODE
FROM A_ACTA AA
WHERE
AA.AA_IPERM=:"SYS_B_13"
AND AA.AA_IRSER IN
( :"SYS_B_14", :"SYS_B_15", :"SYS_B_16", :"SYS_B_17" )
AND AA.AA__DELETED=:"SYS_B_18"
)
AND IA.IA__DELETED=:"SYS_B_19"
call count cpu elapsed disk query
current rows
------- ------ -------- ---------- ---------- ---------- ----------
----------
Parse 1 0.00 0.00 0 0
0 0
Execute 1 0.01 0.00 0 0
0 0
Fetch 376 0.34 0.38 1 18911
0 5623
------- ------ -------- ---------- ---------- ---------- ----------
----------
total 378 0.35 0.38 1 18911
0 5623
Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: 62 (EPM)
Rows Row Source Operation
------- ---------------------------------------------------
5623 TABLE ACCESS BY INDEX ROWID OBJ#(52752) (cr=18911 r=1 w=0
time=336463 us)
11560 NESTED LOOPS (cr=13773 r=0 w=0 time=200276 us)
5871 SORT UNIQUE (cr=1312 r=0 w=0 time=53191 us)
5871 INLIST ITERATOR (cr=1312 r=0 w=0 time=30377 us)
5871 TABLE ACCESS BY INDEX ROWID OBJ#(52679) (cr=1312 r=0 w=0
time=28464 us)
5871 INDEX RANGE SCAN OBJ#(77622) (cr=45 r=0 w=0 time=6794 us)
(object id 77622)
5688 INDEX RANGE SCAN OBJ#(77480) (cr=12461 r=0 w=0 time=121143
us)(object id 77480)
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT GOAL: CHOOSE
5623 TABLE ACCESS GOAL: ANALYZED (BY INDEX ROWID) OF 'A_INDACT'
11560 NESTED LOOPS
5871 SORT (UNIQUE)
5871 INLIST ITERATOR
5871 TABLE ACCESS GOAL: ANALYZED (BY INDEX ROWID) OF
'A_ACTA'
5871 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'MORTEN'
(NON-UNIQUE)
5688 INDEX GOAL: ANALYZED (RANGE SCAN) OF 'ACURE_A_INDACT_1'
(NON-UNIQUE)
===============================
... now only 18911 reads total (12461 on the index) !!
Thanks for explaining the version differences regarding ACCESS/FILTER
operations.
When I posted the original question, I simply did not understand why
the inlist was not processed as a FILTER ... and I'm still not sure
*why* Oracle makes the "wrong" choice in this case (we do have up-to-
date statistics in place) ? And you say it will be the same in later
9.2 versions, and 10.2 as well ?
As It is not an in-house developed application, we cannot just change
the SQL (but we might be able to make the vendor change it). Also, we
would have to make sure any proposed solution does not hurt other
queries.
Are there any other possibilities than rewriting the IA_SEQUE
predicate like above ? hints ? settings ?
I suppose another possible workaround could be to remove the IA_SEQUE
column from the index (or make a new one, and make the query use
that). But again we have to take any negative side effects (on other
queries) into consideration ... not an easy task :-(
Thanks,
-- Peter
Charles Hooper
>
> Author: Cost Based Oracle: Fundamentalshttp://www.jlcomp.demon.co.uk/cbo_book/ind_book.html
(Trying not to hijack this thread for an unrelated topic...)
Jonathan, thanks for the comments. I am digging into the situation
that I reported earlier, after performing additional analysis. It
looks like I am stumbling into an optimizer bug related to bind
variables and an index that contains one distinct value. The packaged
application apparently causes Oracle 10.2.0.2 (Oct 2006 patch) to
perform two parse calls for each SQL statement. For the first parse
call, bind variable values are not specified ("No bind buffers
allocated" appears in the Peeked Binds section of a 10053 trace). For
the second parse call, bind variable values are specified ("No bind
buffers allocated" does not appear in the Peeked Binds section of a
10053 trace). What is a bit hard to understand is why the cost based
optimizer stops using a highly selective index, and instead uses an
index that contains one distinct value. If the SQL statement is
rewritten to not use bind variables, but instead use constants in
place of the bind variables, with the same values specified during the
second parse call, Oracle continues to use them highly selective
index, as it did when bind variable values were not specified during
the parse.
>From the 10053 trace when bind variable values were not specified, a
section with these values appears:
Access Path: index (UniqueScan)
Index: SYS_C006880
resc_io: 2.00 resc_cpu: 22674
ix_sel: 1.5368e-005 ix_sel_with_filters: 1.5368e-005
Cost: 2.00 Resp: 2.00 Degree: 1
Access Path: index (AllEqUnique)
Index: SYS_C006880
resc_io: 2.00 resc_cpu: 22674
ix_sel: 1.5423e-005 ix_sel_with_filters: 1.5423e-005
Cost: 2.00 Resp: 2.00 Degree: 1
Access Path: index (AllEqRange)
Index: X_RECEIVABLE_3
resc_io: 1287.00 resc_cpu: 71639006
ix_sel: 1 ix_sel_with_filters: 1
Cost: 1299.58 Resp: 1299.58 Degree: 1
One row Card: 1.00
Best:: AccessPath: IndexUnique Index: SYS_C006880
Cost: 2.00 Degree: 1 Resp: 2.00 Card: 1.00 Bytes: 0
Note that the ix_sel for the X_RECEIVABLE_3 index is 1.
The same section of the 10053 trace when bind variable values are
specified:
Access Path: index (UniqueScan)
Index: SYS_C006880
resc_io: 2.00 resc_cpu: 22324
ix_sel: 1.5368e-005 ix_sel_with_filters: 1.5368e-005
Cost: 2.00 Resp: 2.00 Degree: 1
Access Path: index (AllEqUnique)
Index: SYS_C006880
resc_io: 2.00 resc_cpu: 22324
ix_sel: 1.5423e-005 ix_sel_with_filters: 1.5423e-005
Cost: 2.00 Resp: 2.00 Degree: 1
Access Path: index (AllEqRange)
Index: X_RECEIVABLE_3
resc_io: 2.00 resc_cpu: 22299
ix_sel: 7.7114e-006 ix_sel_with_filters: 7.7114e-006
Cost: 2.00 Resp: 2.00 Degree: 1
Best:: AccessPath: IndexRange Index: X_RECEIVABLE_3
Cost: 2.00 Degree: 1 Resp: 2.00 Card: 0.00 Bytes: 0
Note that the ix_sel for the X_RECEIVABLE_3 index is now 7.7114e-006,
which makes this index with one distinct value the most selective
index.
>From the 10053 trace, the original plan, when bind variable values
were not specified:
----------------------------------------------------------
+-----------------------------------+
| Id | Operation | Name | Rows |
Bytes | Cost | Time |
----------------------------------------------------------
+-----------------------------------+
| 0 | SELECT STATEMENT | |
| | 4 | |
| 1 | SORT AGGREGATE | | 1 |
40 | | |
| 2 | NESTED LOOPS | | 1 |
40 | 4 | 00:00:01 |
| 3 | TABLE ACCESS BY INDEX ROWID | RECEIVABLE | 1 |
20 | 2 | 00:00:01 |
| 4 | INDEX UNIQUE SCAN | SYS_C006880 | 1
| | 1 | 00:00:01 |
| 5 | TABLE ACCESS BY INDEX ROWID | RECV_MEMO_APPLY | 1 |
20 | 2 | 00:00:01 |
| 6 | INDEX RANGE SCAN | X_RECV_MEMO_APP_1| 1
| | 1 | 00:00:01 |
----------------------------------------------------------
+-----------------------------------+
Predicate Information:
----------------------
3 - filter(("I"."TOTAL_AMOUNT"<>0 AND "I"."STATUS"<>'X' AND
"I"."RECV_GL_ACCT_ID"=:3 AND "ENTITY_ID"=:4))
4 - access("I"."INVOICE_ID"=:1)
5 - filter("A"."APPLY_DATE"<=:2)
6 - access("A"."INV_INVOICE_ID"=:1)
>From the 10053 trace when bind variable values were specified:
-----------------------------------------------------------
+-----------------------------------+
| Id | Operation | Name | Rows |
Bytes | Cost | Time |
-----------------------------------------------------------
+-----------------------------------+
| 0 | SELECT STATEMENT | |
| | 4 | |
| 1 | SORT AGGREGATE | | 1
| 40 | | |
| 2 | TABLE ACCESS BY INDEX ROWID | RECV_MEMO_APPLY | 1
| 20 | 2 | 00:00:01 |
| 3 | NESTED LOOPS | | 1
| 40 | 4 | 00:00:01 |
| 4 | TABLE ACCESS BY INDEX ROWID | RECEIVABLE | 1
| 20 | 2 | 00:00:01 |
| 5 | INDEX RANGE SCAN | X_RECEIVABLE_3 | 1
| | 1 | 00:00:01 |
| 6 | INDEX RANGE SCAN | X_RECV_MEMO_APP_1| 1
| | 1 | 00:00:01 |
-----------------------------------------------------------
+-----------------------------------+
Predicate Information:
----------------------
2 - filter("A"."APPLY_DATE"<=:2)
4 - filter(("I"."RECV_GL_ACCT_ID"=:3 AND "I"."INVOICE_ID"=:1 AND
"I"."TOTAL_AMOUNT"<>0 AND "I"."STATUS"<>'X'))
5 - access("ENTITY_ID"=:4)
6 - access("A"."INV_INVOICE_ID"=:1)
DBMS XPLAN output when bind variable values are specified:
SQL_ID 417an1wrphkc2, child number 0
-------------------------------------
select sum(a.apply_amount) from RECV_MEMO_APPLY a , RECEIVABLE i
where a.inv_invoice_id = :1
and a.apply_date <= :2 and a.inv_invoice_id =
i.invoice_id and i.status != 'X'
and i.total_amount != 0 and i.recv_gl_acct_id = :
3 and ENTITY_ID = :4
Plan hash value: 1967837802
--------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts |
E-Rows | A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1
| 1 | 1 |00:00:00.38 | 4684 |
|* 2 | TABLE ACCESS BY INDEX ROWID | RECV_MEMO_APPLY | 1
| 1 | 0 |00:00:00.38 | 4684 |
| 3 | NESTED LOOPS | | 1
| 1 | 2 |00:00:00.38 | 4684 |
|* 4 | TABLE ACCESS BY INDEX ROWID| RECEIVABLE | 1
| 1 | 1 |00:00:00.38 | 4682 |
|* 5 | INDEX RANGE SCAN | X_RECEIVABLE_3 | 1
| 1 | 65070 |00:00:00.13 | 119 |
|* 6 | INDEX RANGE SCAN | X_RECV_MEMO_APP_1 | 1
| 1 | 0 |00:00:00.01 | 2 |
--------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - filter("A"."APPLY_DATE"<=:2)
4 - filter(("I"."RECV_GL_ACCT_ID"=:3 AND "I"."INVOICE_ID"=:1 AND
"I"."TOTAL_AMOUNT"<>0 AND
"I"."STATUS"<>'X'))
5 - access("ENTITY_ID"=:4)
6 - access("A"."INV_INVOICE_ID"=:1)
DBMS XPLAN when bind variables are replaced with contants that had the
same value as the bind variables:
SQL_ID 2nj9wq0b995ws, child number 0
-------------------------------------
select sum(a.apply_amount) from RECV_MEMO_APPLY a , RECEIVABLE i
where a.inv_invoice_id = '66722'
and a.apply_date <= '05-MAY-2007' and
a.inv_invoice_id = i.invoice_id
and i.status != 'X' and i.total_amount != 0 and i.recv_gl_acct_id
= '110' and
ENTITY_ID = '1'
Plan hash value: 1729902367
-------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-
Rows | A-Rows | A-Time | Buffers |
-------------------------------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1
| 1 | 1 |00:00:00.01 | 5 |
| 2 | NESTED LOOPS | | 1
| 1 | 0 |00:00:00.01 | 5 |
|* 3 | TABLE ACCESS BY INDEX ROWID| RECEIVABLE | 1
| 1 | 1 |00:00:00.01 | 3 |
|* 4 | INDEX UNIQUE SCAN | SYS_C006880 | 1
| 1 | 1 |00:00:00.01 | 2 |
|* 5 | TABLE ACCESS BY INDEX ROWID| RECV_MEMO_APPLY | 1
| 1 | 0 |00:00:00.01 | 2 |
|* 6 | INDEX RANGE SCAN | X_RECV_MEMO_APP_1 | 1
| 1 | 0 |00:00:00.01 | 2 |
-------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
3 - filter(("I"."TOTAL_AMOUNT"<>0 AND "I"."STATUS"<>'X' AND
"I"."RECV_GL_ACCT_ID"='110' AND
"ENTITY_ID"='1'))
4 - access("I"."INVOICE_ID"='66722')
5 - filter("A"."APPLY_DATE"<='05-MAY-2007')
6 - access("A"."INV_INVOICE_ID"='66722')
It would seem that the two DBMS XPLANs should be identical since the
same values were specified for both queries. The plan where constants
were supplied is identical to the plan where bind variable values were
not specified during the initial parse call. If I disable bind
variable peeking, the highly selective index is used.
The SQL statement above is not the only statement in the packaged
application that is affected by this problem. I have not
experiemented with a 10132 trace, but I will see if any additional
information can be obtained from such a trace.
Jonathan Lewis
"Charles Hooper" <hoope...@yahoo.com> wrote in message
news:1178560537....@p77g2000hsh.googlegroups.com...
> What is a bit hard to understand is why the cost based
> optimizer stops using a highly selective index, and instead uses an
> index that contains one distinct value. If the SQL statement is
> rewritten to not use bind variables, but instead use constants in
> place of the bind variables, with the same values specified during the
> second parse call, Oracle continues to use them highly selective
> index, as it did when bind variable values were not specified during
> the parse.
>
This MAY be related to the way in which 10g handles
predicates that are outside the known low/high range.
The following outputs will no doubt be a mess, but they
demonstrate the point (running on 10.2.0.1 - things may
change in 10.2.0.3).
I have an index on id which is declared non-unique (even
though the data is unique). Id ranges from 1 to 10,000.
I have an index on n1, which holds 50 rows of each of
the values from 0 to 199. A point comes where my
predicate on N1 tests for a value which is so far outside
the range that the optimizer estimates it will return fewer
rows than the one row expected from using the ID index.
SQL> select * from t1 where n1 = 394 and id = 99;
Execution Plan
----------------------------------------------------------
Plan hash value: 965905564
-------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)|
Time |
-------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 119 | 2 (0)|
00:00:01 |
|* 1 | TABLE ACCESS BY INDEX ROWID| T1 | 1 | 119 | 2 (0)|
00:00:01 |
|* 2 | INDEX RANGE SCAN | T1_I2 | 1 | | 1 (0)|
00:00:01 |
-------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("N1"=394)
2 - access("ID"=99)
SQL> select * from t1 where n1 = 395 and id = 99;
Execution Plan
----------------------------------------------------------
Plan hash value: 1429545322
-------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)|
Time |
-------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 119 | 2 (0)|
00:00:01 |
|* 1 | TABLE ACCESS BY INDEX ROWID| T1 | 1 | 119 | 2 (0)|
00:00:01 |
|* 2 | INDEX RANGE SCAN | T1_I1 | 1 | | 1 (0)|
00:00:01 |
-------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("ID"=99)
2 - access("N1"=395)
SQL> spool off
Looking at it another way - drop the predicate on id, and see what
happens to the ROWS as the predicate on N1 moves outside the low/high
SQL> select * from t1 where n1 = 150 ;
Execution Plan
----------------------------------------------------------
Plan hash value: 1429545322
-------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)|
Time |
-------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 50 | 5950 | 2 (0)|
00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| T1 | 50 | 5950 | 2 (0)|
00:00:01 |
|* 2 | INDEX RANGE SCAN | T1_I1 | 50 | | 1 (0)|
00:00:01 |
-------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("N1"=150)
SQL> select * from t1 where n1 = 250 ;
Execution Plan
----------------------------------------------------------
Plan hash value: 1429545322
-------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)|
Time |
-------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 37 | 4403 | 2 (0)|
00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| T1 | 37 | 4403 | 2 (0)|
00:00:01 |
|* 2 | INDEX RANGE SCAN | T1_I1 | 37 | | 1 (0)|
00:00:01 |
-------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("N1"=250)
SQL> select * from t1 where n1 = 300 ;
Execution Plan
----------------------------------------------------------
Plan hash value: 1429545322
-------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)|
Time |
-------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 25 | 2975 | 2 (0)|
00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| T1 | 25 | 2975 | 2 (0)|
00:00:01 |
|* 2 | INDEX RANGE SCAN | T1_I1 | 25 | | 1 (0)|
00:00:01 |
-------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("N1"=300)
SQL> select * from t1 where n1 = 350 ;
Execution Plan
----------------------------------------------------------
Plan hash value: 1429545322
-------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)|
Time |
-------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 12 | 1428 | 2 (0)|
00:00:01 |
| 1 | TABLE ACCESS BY INDEX ROWID| T1 | 12 | 1428 | 2 (0)|
00:00:01 |
|* 2 | INDEX RANGE SCAN | T1_I1 | 12 | | 1 (0)|
00:00:01 |
-------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("N1"=350)
SQL> spool off
(There is a note about this change in the book, by the way).
--
Regards
Jonathan Lewis
Charles Hooper
wrote:
> "Charles Hooper" <hooperc2...@yahoo.com> wrote in message
>
> news:1178560537....@p77g2000hsh.googlegroups.com...
> > What is a bit hard to understand is why the cost based
> > optimizer stops using a highly selective index, and instead uses an
> > index that contains one distinct value. If the SQL statement is
> > rewritten to not use bind variables, but instead use constants in
> > place of the bind variables, with the same values specified during the
> > second parse call, Oracle continues to use them highly selective
> > index, as it did when bind variable values were not specified during
> > the parse.
>
> This MAY be related to the way in which 10g handles
> predicates that are outside the known low/high range.
>
>
> --
> Regards
>
>
> Author: Cost Based Oracle: Fundamentalshttp://www.jlcomp.demon.co.uk/cbo_book/ind_book.html
Jonathan,
Thanks for the feedback. I recall reading about the potential
problems of values outside min/max in your book, so I was aware of
that possibility. I do not believe that that is what is happening.
On Oracle 10.2.0.2, if I execute the SQL statement that I previously
referenced using constants (or with binds without providing initial
values, or with binds when bind peeking is disabled), one plan is
developed that is efficient, and if I execute the same SQL statement
with bind variable values specified the plan is very inefficient (this
is in a packaged application, where I can't touch the source code). A
quick demonstration that should be easily repeatable:
Create a three column table, with the first column being the primary
key:
CREATE TABLE T1 (
INVOICE_ID VARCHAR2(15),
INVOICE_DATE DATE,
ENTITY_ID VARCHAR2(5) NOT NULL,
PRIMARY KEY(INVOICE_ID));
Create an index on the third column:
CREATE INDEX IND_T1_ENTITY_ID ON T1(ENTITY_ID);
Insert 3000 rows into the table, all with the same value for
ENTITY_ID:
INSERT INTO
T1
SELECT
TRIM(TO_CHAR(ROWNUM,'00000')) INVOICE_ID,
TRUNC((SYSDATE-3000)+ROWNUM) INVOICE_DATE,
'1' ENTITY_ID
FROM
DUAL
CONNECT BY
LEVEL<=3000;
COMMIT;
Make certain that the statistics are up to date:
EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>'table owner
here',TABNAME=>'T1',CASCADE=>TRUE)
The first test:
SELECT
INVOICE_ID,
INVOICE_DATE,
ENTITY_ID
FROM
T1
WHERE
ENTITY_ID='1'
AND INVOICE_ID='00010'
AND INVOICE_DATE<(SYSDATE-100);
The ENTITY_ID column is very unselective, as there is only one
distinct value in that column, so Oracle should not use that index,
but should use the index on the primary key (INVOICE_ID column). The
DBMS XPLAN:
------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |
A-Rows | A-Time | Buffers |
------------------------------------------------------------------------------------------------------
|* 1 | TABLE ACCESS BY INDEX ROWID| T1 | 1 | 1
| 1 |00:00:00.01 | 3 |
|* 2 | INDEX UNIQUE SCAN | SYS_C0014551 | 1 | 1
| 1 |00:00:00.01 | 2 |
------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter(("INVOICE_DATE"<SYSDATE@!-100 AND "ENTITY_ID"='1'))
2 - access("INVOICE_ID"='00010')
The above DBMS XPLAN shows that it behaved as expected. Now,
introduce bind variable values and the unexpected happens:
SELECT
INVOICE_ID,
INVOICE_DATE,
ENTITY_ID
FROM
T1
WHERE
ENTITY_ID= :1
AND INVOICE_ID= :2
AND INVOICE_DATE<(SYSDATE-100);
The DBMS XPLAN - note that the access at step #2 has changed to the
very unselective index:
----------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-
Rows | A-Rows | A-Time | Buffers |
----------------------------------------------------------------------------------------------------------
|* 1 | TABLE ACCESS BY INDEX ROWID| T1 | 1 |
1 | 1 |00:00:00.01 | 15 |
|* 2 | INDEX RANGE SCAN | IND_T1_ENTITY_ID | 1 |
1 | 3000 |00:00:00.01 | 6 |
----------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter(("INVOICE_ID"=:2 AND "INVOICE_DATE"<SYSDATE@!-100))
2 - access("ENTITY_ID"=:1)
Just to make certain that I did not submit the bind variables
incorrectly, from the 10046 trace:
Bind#0
oacdty=96 mxl=32(02) mxlc=00 mal=00 scl=00 pre=00
oacflg=00 fl2=1000010 frm=01 csi=178 siz=64 off=0
kxsbbbfp=0ed45e3c bln=32 avl=01 flg=05
value="1"
Bind#1
oacdty=96 mxl=32(10) mxlc=00 mal=00 scl=00 pre=00
oacflg=00 fl2=1000010 frm=01 csi=178 siz=0 off=32
kxsbbbfp=0ed45e5c bln=32 avl=05 flg=01
value="00010"
It appears that the cost based optimizer becomes confused when
examining the selectivity of the IND_T1_ENTITY_ID index when bind
variable values are used.
DA Morgan
> (this > is in a packaged application, where I can't touch the source code).
What happens if you apply DBMS_ADVANCED_REWRITE with malice aforethought?
--
Daniel A. Morgan
University of Washington
damo...@x.washington.edu
(replace x with u to respond)
Puget Sound Oracle Users Group
www.psoug.org
Jonathan Lewis
Charles,
I can't get the test case you sent to reproduce
on either 10.2.0.1 or 10.2.0.3; I use the unique
index in both cases.
I can send you a 10053 if you want to do a point
by point comparison to see where the difference
occurs.
Do you end up with a histogram on the ENTITY_ID
when you do the test ? (I don't - and it does look like
a histogram-related bug).
What are your setting for system stats, and do you have
any special settings for any of the optimizer parameters.
(You could cut the parameter listing from the 10053
and post it).
--
Regards
Jonathan Lewis
Charles Hooper
> Charles Hooper wrote:
> > (this > is in a packaged application, where I can't touch the source code).
>
> What happens if you apply DBMS_ADVANCED_REWRITE with malice aforethought?
> --
> Daniel A. Morgan
> University of Washington
In the past I have been able to create an outline for such a SQL
statement, and it then execute using the correct index. I believe
that DBMS_ADVANCED_REWRITE has difficulty with bind variables, so that
may not be an option. Interestingly, I could not reproduce this
problem on my production database instance.
Charles Hooper
wrote:
> "Charles Hooper" <hooperc2...@yahoo.com> wrote in message
> > | Id | Operation | Name | Starts | E-Rows |
> > A-Rows | A-Time | Buffers |
> > |* 1 | TABLE ACCESS BY INDEX ROWID| T1 | 1 | 1
> > | 1 |00:00:00.01 | 3 |
> > |* 2 | INDEX UNIQUE SCAN | SYS_C0014551 | 1 | 1
> > | 1 |00:00:00.01 | 2 |
>
> > Predicate Information (identified by operation id):
> > ---------------------------------------------------
> > 1 - filter(("INVOICE_DATE"<SYSDATE@!-100 AND "ENTITY_ID"='1'))
> > 2 - access("INVOICE_ID"='00010')
>
> > The above DBMS XPLAN shows that it behaved as expected. Now,
> > introduce bind variable values and the unexpected happens:
> > SELECT
> > INVOICE_ID,
> > INVOICE_DATE,
> > ENTITY_ID
> > FROM
> > T1
> > WHERE
> > ENTITY_ID= :1
> > AND INVOICE_ID= :2
> > AND INVOICE_DATE<(SYSDATE-100);
>
> > The DBMS XPLAN - note that the access at step #2 has changed to the
> > very unselective index:
> > | Id | Operation | Name | Starts | E-
> > Rows | A-Rows | A-Time | Buffers |
> > |* 1 | TABLE ACCESS BY INDEX ROWID| T1 | 1 |
> > 1 | 1 |00:00:00.01 | 15 |
> > |* 2 | INDEX RANGE SCAN | IND_T1_ENTITY_ID | 1 |
> > 1 | 3000 |00:00:00.01 | 6 |
>
> Author: Cost Based Oracle: Fundamentalshttp://www.jlcomp.demon.co.uk/cbo_book/ind_book.html
>
> The Co-operative Oracle Users' FAQhttp://www.jlcomp.demon.co.uk/faq/ind_faq.html- Hide
I was able to produce the problem on a test box with Oracle 10.2.0.2
with Oct 2006 patch running on 32 bit Windows. I could not reproduce
the problem on Oracle 10.2.0.2 with Oct 2006 patch running on 64 bit
Windows, nor could I reproduce the problem on a test box (running
Vista) on Oracle 10.2.0.3. The Oracle 10.2.0.2 test box (32 bit
Windows) has query_rewrite_enabled set to false,
optimizer_index_cost_adj set to 100, and optimizer_index_caching set
to 0 - Oracle 10.2.0.2 on 64 bit Windows has parameters that are much
more carefully tuned. I will be comparing the 10053 trace files from
the three runs to see if anything jumps out.
The same histograms appear both in the 32 bit and 64 bit versions of
Oracle 10.2.0.2:
SELECT
TABLE_NAME,
SUBSTR(COLUMN_NAME,1,15) COLUMN_NAME,
ENDPOINT_NUMBER,
ENDPOINT_VALUE
FROM
DBA_TAB_HISTOGRAMS
WHERE
OWNER='table owner here'
AND TABLE_NAME='T1'
ORDER BY
COLUMN_NAME,
ENDPOINT_NUMBER;
TABLE_NAME COLUMN_NAME ENDPOINT_NUMBER ENDPOINT_VALUE
============================== =============== ===============
==============
T1 ENTITY_ID 0 2.54422546
T1 ENTITY_ID 1 2.54422546
T1 INVOICE_DATE 0 2451230
T1 INVOICE_DATE 1 2454229
T1 INVOICE_ID 0 2.50207622
T1 INVOICE_ID 1 2.50268469
It does appear that there is a histogram on the ENTITY_ID column.
Parameters from the 10053 trace on Oracle 10.2.0.2 (32 bit Windows):
PARAMETERS WITH ALTERED VALUES
******************************
optimizer_features_enable = 10.2.0.1
sort_area_size = 5242880
sort_area_retained_size = 262144
sqlstat_enabled = true
query_rewrite_enabled = false
query_rewrite_integrity = trusted
statistics_level = all
PARAMETERS WITH DEFAULT VALUES
******************************
optimizer_mode_hinted = false
optimizer_features_hinted = 0.0.0
parallel_execution_enabled = false
parallel_query_forced_dop = 0
parallel_dml_forced_dop = 0
parallel_ddl_forced_degree = 0
parallel_ddl_forced_instances = 0
_query_rewrite_fudge = 90
_optimizer_search_limit = 5
cpu_count = 4
active_instance_count = 1
parallel_threads_per_cpu = 2
hash_area_size = 10485760
bitmap_merge_area_size = 1048576
_sort_elimination_cost_ratio = 0
_optimizer_block_size = 8192
_sort_multiblock_read_count = 2
_hash_multiblock_io_count = 0
_db_file_optimizer_read_count = 16
_optimizer_max_permutations = 2000
pga_aggregate_target = 307200 KB
_pga_max_size = 204800 KB
_query_rewrite_maxdisjunct = 257
_smm_auto_min_io_size = 56 KB
_smm_auto_max_io_size = 248 KB
_smm_min_size = 307 KB
_smm_max_size = 61440 KB
_smm_px_max_size = 153600 KB
_cpu_to_io = 0
_optimizer_undo_cost_change = 10.2.0.1
parallel_query_mode = enabled
parallel_dml_mode = disabled
parallel_ddl_mode = enabled
optimizer_mode = all_rows
_optimizer_percent_parallel = 101
_always_anti_join = choose
_always_semi_join = choose
_optimizer_mode_force = true
_partition_view_enabled = true
_always_star_transformation = false
_query_rewrite_or_error = false
_hash_join_enabled = true
cursor_sharing = exact
_b_tree_bitmap_plans = true
star_transformation_enabled = false
_optimizer_cost_model = choose
_new_sort_cost_estimate = true
_complex_view_merging = true
_unnest_subquery = true
_eliminate_common_subexpr = true
_pred_move_around = true
_convert_set_to_join = false
_push_join_predicate = true
_push_join_union_view = true
_fast_full_scan_enabled = true
_optim_enhance_nnull_detection = true
_parallel_broadcast_enabled = true
_px_broadcast_fudge_factor = 100
_ordered_nested_loop = true
_no_or_expansion = false
optimizer_index_cost_adj = 100
optimizer_index_caching = 0
_system_index_caching = 0
_disable_datalayer_sampling = false
_query_cost_rewrite = true
_query_rewrite_2 = true
_query_rewrite_1 = true
_query_rewrite_expression = true
_query_rewrite_jgmigrate = true
_query_rewrite_fpc = true
_query_rewrite_drj = true
_full_pwise_join_enabled = true
_partial_pwise_join_enabled = true
_left_nested_loops_random = true
_improved_row_length_enabled = true
_index_join_enabled = true
_enable_type_dep_selectivity = true
_improved_outerjoin_card = true
_optimizer_adjust_for_nulls = true
_optimizer_degree = 0
_use_column_stats_for_function = true
_subquery_pruning_enabled = true
_subquery_pruning_mv_enabled = false
_or_expand_nvl_predicate = true
_like_with_bind_as_equality = false
_table_scan_cost_plus_one = true
_cost_equality_semi_join = true
_default_non_equality_sel_check = true
_new_initial_join_orders = true
_oneside_colstat_for_equijoins = true
_optim_peek_user_binds = true
_minimal_stats_aggregation = true
_force_temptables_for_gsets = false
workarea_size_policy = auto
_smm_auto_cost_enabled = true
_gs_anti_semi_join_allowed = true
_optim_new_default_join_sel = true
optimizer_dynamic_sampling = 2
_pre_rewrite_push_pred = true
_optimizer_new_join_card_computation = true
_union_rewrite_for_gs = yes_gset_mvs
_generalized_pruning_enabled = true
_optim_adjust_for_part_skews = true
_force_datefold_trunc = false
_optimizer_system_stats_usage = true
skip_unusable_indexes = true
_remove_aggr_subquery = true
_optimizer_push_down_distinct = 0
_dml_monitoring_enabled = true
_optimizer_undo_changes = false
_predicate_elimination_enabled = true
_nested_loop_fudge = 100
_project_view_columns = true
_local_communication_costing_enabled = true
_local_communication_ratio = 50
_query_rewrite_vop_cleanup = true
_slave_mapping_enabled = true
_optimizer_cost_based_transformation = linear
_optimizer_mjc_enabled = true
_right_outer_hash_enable = true
_spr_push_pred_refspr = true
_optimizer_cache_stats = false
_optimizer_cbqt_factor = 50
_optimizer_squ_bottomup = true
_fic_area_size = 131072
_optimizer_skip_scan_enabled = true
_optimizer_cost_filter_pred = false
_optimizer_sortmerge_join_enabled = true
_optimizer_join_sel_sanity_check = true
_mmv_query_rewrite_enabled = true
_bt_mmv_query_rewrite_enabled = true
_add_stale_mv_to_dependency_list = true
_distinct_view_unnesting = false
_optimizer_dim_subq_join_sel = true
_optimizer_disable_strans_sanity_checks = 0
_optimizer_compute_index_stats = true
_push_join_union_view2 = true
_optimizer_ignore_hints = false
_optimizer_random_plan = 0
_query_rewrite_setopgrw_enable = true
_optimizer_correct_sq_selectivity = true
_disable_function_based_index = false
_optimizer_join_order_control = 3
_optimizer_cartesian_enabled = true
_optimizer_starplan_enabled = true
_extended_pruning_enabled = true
_optimizer_push_pred_cost_based = true
_sql_model_unfold_forloops = run_time
_enable_dml_lock_escalation = false
_bloom_filter_enabled = true
_update_bji_ipdml_enabled = 0
_optimizer_extended_cursor_sharing = udo
_dm_max_shared_pool_pct = 1
_optimizer_cost_hjsmj_multimatch = true
_optimizer_transitivity_retain = true
_px_pwg_enabled = true
optimizer_secure_view_merging = true
_optimizer_join_elimination_enabled = true
flashback_table_rpi = non_fbt
_optimizer_cbqt_no_size_restriction = true
_optimizer_enhanced_filter_push = true
_optimizer_filter_pred_pullup = true
_rowsrc_trace_level = 0
_simple_view_merging = true
_optimizer_rownum_pred_based_fkr = true
_optimizer_better_inlist_costing = all
_optimizer_self_induced_cache_cost = false
_optimizer_min_cache_blocks = 10
_optimizer_or_expansion = depth
_optimizer_order_by_elimination_enabled = true
_optimizer_outer_to_anti_enabled = true
_selfjoin_mv_duplicates = true
_dimension_skip_null = true
_force_rewrite_enable = false
_optimizer_star_tran_in_with_clause = true
_optimizer_complex_pred_selectivity = true
_optimizer_connect_by_cost_based = false
_gby_hash_aggregation_enabled = true
_globalindex_pnum_filter_enabled = false
_fix_control_key = 0
_optimizer_skip_scan_guess = false
_enable_row_shipping = false
statistics_level is actually set at TYPICAL, but is adjusted to ALL
for the run.
Charles Hooper
Just an update to this issue. I was able to finally force Oracle to
select the correct index on 32 bit Windows.
ALTER SYSTEM SET QUERY_REWRITE_ENABLED=TRUE SCOPE=BOTH;
ALTER SYSTEM SET QUERY_REWRITE_INTEGRITY=ENFORCED SCOPE=BOTH;
ALTER SYSTEM FLUSH SHARED_POOL;
Above did not change the plan, still using the wrong index.
ALTER SYSTEM SET OPTIMIZER_INDEX_COST_ADJ=20 SCOPE=BOTH;
ALTER SYSTEM FLUSH SHARED_POOL;
Above did not change the plan, still using the wrong index.
ALTER SYSTEM SET OPTIMIZER_INDEX_CACHING=100 SCOPE=BOTH;
ALTER SYSTEM FLUSH SHARED_POOL;
Above did not change the plan, still using the wrong index.
ALTER SYSTEM SET "_OPTIMIZER_UNDO_COST_CHANGE"='10.1.0.4' SCOPE=BOTH;
ALTER SYSTEM FLUSH SHARED_POOL;
Problem solved.
DBMS XPLAN:
------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |
A-Rows | A-Time | Buffers |
------------------------------------------------------------------------------------------------------
|* 1 | TABLE ACCESS BY INDEX ROWID| T1 | 1 | 1
| 1 |00:00:00.01 | 3 |
|* 2 | INDEX UNIQUE SCAN | SYS_C0014623 | 1 | 1
| 1 |00:00:00.01 | 2 |
------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter(("ENTITY_ID"=:1 AND "INVOICE_DATE"<SYSDATE@!-100))
2 - access("INVOICE_ID"=:2)
This was an interesting experiment - now to see if the change
positively affects the ERP package. Jonathan, thanks for the
suggestions and confirming that it appears to be an isolated issue.
Jonathan Lewis
"Charles Hooper" <hoope...@yahoo.com> wrote in message
news:1178624112.0...@w5g2000hsg.googlegroups.com...
TABLE_NAME COLUMN_NAME ENDPOINT_NUMBER ENDPOINT_VALUE
============================== =============== ===============
==============
T1 ENTITY_ID 0 2.54422546
T1 ENTITY_ID 1 2.54422546
T1 INVOICE_DATE 0 2451230
T1 INVOICE_DATE 1 2454229
T1 INVOICE_ID 0 2.50207622
T1 INVOICE_ID 1 2.50268469
It does appear that there is a histogram on the ENTITY_ID column.
Parameters from the 10053 trace on Oracle 10.2.0.2 (32 bit Windows):
PARAMETERS WITH ALTERED VALUES
******************************
optimizer_features_enable = 10.2.0.1
sort_area_size = 5242880
sort_area_retained_size = 262144
Charles,
I couldn't see any obvious reason from the parameters
why your 10.2.0.2 should behave differently.
There isn't a histogram on entity_id in your output.
A "histogram" with endpoint number (0,1) is simply
recording the low/high - it's not a real histogram.
--
Regards
Jonathan Lewis
Charles Hooper
wrote:
> Charles,
>
> I couldn't see any obvious reason from the parameters
> why your 10.2.0.2 should behave differently.
>
> There isn't a histogram on entity_id in your output.
> A "histogram" with endpoint number (0,1) is simply
> recording the low/high - it's not a real histogram.
>
> --
> Regards
>
>
> Author: Cost Based Oracle: Fundamentalshttp://www.jlcomp.demon.co.uk/cbo_book/ind_book.html
Jonathan, I greatly appreciate your comments and explanation of what I
am seeing regarding histograms.
I increased the size of the data set from 3,000 rows to 30,000 rows
and was able to reproduce the problem where Oracle attempts to access
the data using the wrong index on 32 bit and 64 bit Oracle 10.2.0.2
and 32 bit Oracle 10.2.0.3 - previously I was only able to reproduce
the problem on 32 bit Oracle 10.2.0.2.
The full test run:
Create a three column table, with the first column being the primary
key:
CREATE TABLE T1 (
INVOICE_ID VARCHAR2(15),
INVOICE_DATE DATE,
ENTITY_ID VARCHAR2(5) NOT NULL,
PRIMARY KEY(INVOICE_ID));
Create an index on the third column:
CREATE INDEX IND_T1_ENTITY_ID ON T1(ENTITY_ID);
Insert 30,000 rows into the table, all with the same value for
ENTITY_ID:
INSERT INTO
T1
SELECT
TRIM(TO_CHAR(ROWNUM,'00000')) INVOICE_ID,
TRUNC((SYSDATE-3000)+ROWNUM) INVOICE_DATE,
'1' ENTITY_ID
FROM
DUAL
CONNECT BY
LEVEL<=30000;
COMMIT;
Make certain that the statistics are up to date:
EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>'table owner
here',TABNAME=>'T1',CASCADE=>TRUE)
The first test:
SELECT
INVOICE_ID,
INVOICE_DATE,
ENTITY_ID
FROM
T1
WHERE
ENTITY_ID='1'
AND INVOICE_ID='00010'
AND INVOICE_DATE<(SYSDATE-100);
The ENTITY_ID column is very unselective, as there is only one
distinct value in that column, so Oracle should not use that index,
but should use the index on the primary key (INVOICE_ID column). The
DBMS XPLAN:
SELECT INVOICE_ID , INVOICE_DATE , ENTITY_ID FROM T1 WHERE
ENTITY_ID= '1' AND
INVOICE_ID= '00010' AND INVOICE_DATE<(SYSDATE-100)
Plan hash value: 426301786
------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows |
A-Rows | A-Time | Buffers |
------------------------------------------------------------------------------------------------------
|* 1 | TABLE ACCESS BY INDEX ROWID| T1 | 1 | 1
| 1 |00:00:00.01 | 3 |
|* 2 | INDEX UNIQUE SCAN | SYS_C0013370 | 1 | 1
| 1 |00:00:00.01 | 2 |
------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter(("INVOICE_DATE"<SYSDATE@!-100 AND "ENTITY_ID"='1'))
2 - access("INVOICE_ID"='00010')
The above DBMS XPLAN shows that it behaved as expected. Now,
introduce bind variable values and the unexpected happens:
SELECT
INVOICE_ID,
INVOICE_DATE,
ENTITY_ID
FROM
T1
WHERE
ENTITY_ID= :1
AND INVOICE_ID= :2
AND INVOICE_DATE<(SYSDATE-100);
SQL_ID 2287qj8u8scfq, child number 0
-------------------------------------
SELECT INVOICE_ID , INVOICE_DATE , ENTITY_ID FROM T1 WHERE
ENTITY_ID= :1 AND
INVOICE_ID= :2 AND INVOICE_DATE<(SYSDATE-100)
Plan hash value: 2911507501
----------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-
Rows | A-Rows | A-Time | Buffers |
----------------------------------------------------------------------------------------------------------
|* 1 | TABLE ACCESS BY INDEX ROWID| T1 | 1 |
1 | 1 |00:00:00.15 | 170 |
|* 2 | INDEX RANGE SCAN | IND_T1_ENTITY_ID | 1 |
1 | 30000 |00:00:00.09 | 83 |
----------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter(("INVOICE_ID"=:2 AND "INVOICE_DATE"<SYSDATE@!-100))
2 - access("ENTITY_ID"=:1)
>From the 10053 trace file:
SINGLE TABLE ACCESS PATH
Column (#3): ENTITY_ID(VARCHAR2)
AvgLen: 2.00 NDV: 1 Nulls: 0 Density: 1.6667e-005
Histogram: Freq #Bkts: 1 UncompBkts: 30000 EndPtVals: 1
Column (#1): INVOICE_ID(VARCHAR2)
AvgLen: 6.00 NDV: 30000 Nulls: 0 Density: 3.3333e-005
Column (#2): INVOICE_DATE(DATE)
AvgLen: 8.00 NDV: 30000 Nulls: 0 Density: 3.3333e-005 Min: 2451232
Max: 2481231
Table: T1 Alias: T1
Card: Original: 30000 Rounded: 1 Computed: 0.00 Non Adjusted:
0.00
Access Path: TableScan
Cost: 30.88 Resp: 30.88 Degree: 0
Cost_io: 29.00 Cost_cpu: 7826712
Resp_io: 29.00 Resp_cpu: 7826712
Access Path: index (UniqueScan)
Index: SYS_C0013370
resc_io: 2.00 resc_cpu: 21804
ix_sel: 3.3333e-005 ix_sel_with_filters: 3.3333e-005
Cost: 1.00 Resp: 1.00 Degree: 1
Access Path: index (AllEqRange)
Index: IND_T1_ENTITY_ID
resc_io: 2.00 resc_cpu: 21779
ix_sel: 1.6667e-005 ix_sel_with_filters: 1.6667e-005
Cost: 1.00 Resp: 1.00 Degree: 1
Access Path: index (AllEqUnique)
Index: SYS_C0013370
resc_io: 2.00 resc_cpu: 21804
ix_sel: 3.3333e-005 ix_sel_with_filters: 3.3333e-005
Cost: 1.00 Resp: 1.00 Degree: 1
Best:: AccessPath: IndexRange Index: IND_T1_ENTITY_ID
Cost: 1.00 Degree: 1 Resp: 1.00 Card: 0.00 Bytes: 0
The above example is an abbreviated example of a problem in an ERP
package that I am seeing. One report in particular that should take
45 seconds to generate (should be 1 seconds or less, but the program
is database independent), is actually taking six to eight minutes to
execute. My solution at the time is to generate a logon trigger that
disables bind variable peeking for all connections related to that ERP
package. Doing so drops the execution time back down to 45 seconds.
Thanks again for your comments.