Trace Files contents for cardinality estimates on list subpartitioned tables with binds on partition, literals on subpartition

06/10/2012 Leave a comment

Just a litte addition to the previous post. It seems I cannot get much additional value out of generated tracefiles excpet, that pruning does not seem to take place somehow. This is also reflected in the plans, where you can see partition list single, but no entry for Pstart or Pstop, but instead listed as filter criteria.

(and I am sorry for the layout of the plans, but somehow the spacing gets lost all the time, I neither get code or sourcecode tags working as I would like them ….)

with additional subpartition beeing added (as in test script of previous post):

***************************************
BASE STATISTICAL INFORMATION
***********************
Table Stats::
Table: TESTSZ Alias: TESTSZ Partition [0]
#Rows: 30 #Blks: 1 AvgRowLen: 111.00
#Rows: 30 #Blks: 1 AvgRowLen: 111.00
Access path analysis for TESTSZ
***************************************
SINGLE TABLE ACCESS PATH
Single Table Cardinality Estimation for TESTSZ[TESTSZ]

Table: TESTSZ Alias: TESTSZ
Card: Original: 30.000000 Rounded: 30 Computed: 30.00 Non Adjusted: 30.00
Access Path: TableScan
Cost: 2.00 Resp: 2.00 Degree: 0
Cost_io: 2.00 Cost_cpu: 15221
Resp_io: 2.00 Resp_cpu: 15221
Best:: AccessPath: TableScan
Cost: 2.00 Degree: 1 Resp: 2.00 Card: 30.00 Bytes: 0

***************************************
============
Plan Table
============
-------------------------------------------+-----------------------------------+---------------+
| Id | Operation | Name | Rows | Bytes | Cost | Time | Pstart| Pstop |
-------------------------------------------+-----------------------------------+---------------+
| 0 | SELECT STATEMENT | | | | 2 | | | |
| 1 | SORT AGGREGATE | | 1 | 10 | | | | |
| 2 | PARTITION RANGE SINGLE | | 30 | 300 | 2 | 00:00:01 | KEY | KEY |
| 3 | PARTITION LIST SINGLE | | 30 | 300 | 2 | 00:00:01 | | |
| 4 | TABLE ACCESS FULL | TESTSZ | 30 | 300 | 2 | 00:00:01 | KEY | KEY |
-------------------------------------------+-----------------------------------+---------------+
Predicate Information:
----------------------
4 - filter(("I"=:B1 AND "J"=0))

Final query after transformations:******* UNPARSED QUERY IS *******
SELECT COUNT(*) "COUNT(*)" FROM "SZ"."TESTSZ" "TESTSZ" WHERE "TESTSZ"."I"=:B1 AND "TESTSZ"."J"=1

***************************************
BASE STATISTICAL INFORMATION
***********************
Table Stats::
Table: TESTSZ Alias: TESTSZ Partition [0]
#Rows: 30 #Blks: 1 AvgRowLen: 111.00
#Rows: 30 #Blks: 1 AvgRowLen: 111.00
Access path analysis for TESTSZ
***************************************
SINGLE TABLE ACCESS PATH
Single Table Cardinality Estimation for TESTSZ[TESTSZ]

Table: TESTSZ Alias: TESTSZ
Card: Original: 30.000000 Rounded: 1 Computed: 1.00 Non Adjusted: 1.00
Access Path: TableScan
Cost: 2.00 Resp: 2.00 Degree: 0
Cost_io: 2.00 Cost_cpu: 13771
Resp_io: 2.00 Resp_cpu: 13771
Best:: AccessPath: TableScan
Cost: 2.00 Degree: 1 Resp: 2.00 Card: 1.00 Bytes: 0

***************************************

============
Plan Table
============
-------------------------------------------+-----------------------------------+---------------+
| Id | Operation | Name | Rows | Bytes | Cost | Time | Pstart| Pstop |
-------------------------------------------+-----------------------------------+---------------+
| 0 | SELECT STATEMENT | | | | 2 | | | |
| 1 | SORT AGGREGATE | | 1 | 10 | | | | |
| 2 | PARTITION RANGE SINGLE | | 1 | 10 | 2 | 00:00:01 | KEY | KEY |
| 3 | PARTITION LIST SINGLE | | 1 | 10 | 2 | 00:00:01 | | |
| 4 | TABLE ACCESS FULL | TESTSZ | 1 | 10 | 2 | 00:00:01 | KEY | KEY |
-------------------------------------------+-----------------------------------+---------------+
Predicate Information:
----------------------
4 - filter(("J"=1 AND "I"=:B1))

without added subpartition (add subpartition in testcript commented out):

***************************************
BASE STATISTICAL INFORMATION
***********************
Table Stats::
Table: TESTSZ Alias: TESTSZ (making adjustments for partition skews)
ORIGINAL VALUES:: #Rows: 30 #Blks: 1 AvgRowLen: 111.00
SUBPARTITIONS::
PRUNED: 3
ANALYZED: 3 UNANALYZED: 0

Partition [0]
#Rows: 30 #Blks: 1 AvgRowLen: 111.00
#Rows: 30 #Blks: 3 AvgRowLen: 111.00
Access path analysis for TESTSZ
***************************************
SINGLE TABLE ACCESS PATH
Single Table Cardinality Estimation for TESTSZ[TESTSZ]

Table: TESTSZ Alias: TESTSZ
Card: Original: 30.000000 Rounded: 30 Computed: 30.00 Non Adjusted: 30.00
Access Path: TableScan
Cost: 3.00 Resp: 3.00 Degree: 0
Cost_io: 3.00 Cost_cpu: 23474
Resp_io: 3.00 Resp_cpu: 23474
Best:: AccessPath: TableScan
Cost: 3.00 Degree: 1 Resp: 3.00 Card: 30.00 Bytes: 0

***************************************
============
Plan Table
============
-------------------------------------------+-----------------------------------+---------------+
| Id | Operation | Name | Rows | Bytes | Cost | Time | Pstart| Pstop |
-------------------------------------------+-----------------------------------+---------------+
| 0 | SELECT STATEMENT | | | | 3 | | | |
| 1 | SORT AGGREGATE | | 1 | 10 | | | | |
| 2 | PARTITION RANGE SINGLE | | 30 | 300 | 3 | 00:00:01 | KEY | KEY |
| 3 | PARTITION LIST SINGLE | | 30 | 300 | 3 | 00:00:01 | 1 | 1 |
| 4 | TABLE ACCESS FULL | TESTSZ | 30 | 300 | 3 | 00:00:01 | KEY | KEY |
-------------------------------------------+-----------------------------------+---------------+
Predicate Information:
----------------------
4 - filter("I"=:B1)

***************************************
BASE STATISTICAL INFORMATION
***********************
Table Stats::
Table: TESTSZ Alias: TESTSZ (making adjustments for partition skews)
ORIGINAL VALUES:: #Rows: 90 #Blks: 2 AvgRowLen: 112.00
SUBPARTITIONS::
PRUNED: 3
ANALYZED: 3 UNANALYZED: 0
Partition [1]
#Rows: 90 #Blks: 2 AvgRowLen: 112.00
#Rows: 90 #Blks: 5 AvgRowLen: 112.00

Access path analysis for TESTSZ
***************************************
SINGLE TABLE ACCESS PATH
Single Table Cardinality Estimation for TESTSZ[TESTSZ]

Table: TESTSZ Alias: TESTSZ
Card: Original: 90.000000 Rounded: 90 Computed: 90.00 Non Adjusted: 90.00
Access Path: TableScan
Cost: 3.00 Resp: 3.00 Degree: 0
Cost_io: 3.00 Cost_cpu: 45817
Resp_io: 3.00 Resp_cpu: 45817
Best:: AccessPath: TableScan
Cost: 3.00 Degree: 1 Resp: 3.00 Card: 90.00 Bytes: 0

***************************************

============
Plan Table
============
-------------------------------------------+-----------------------------------+---------------+
| Id | Operation | Name | Rows | Bytes | Cost | Time | Pstart| Pstop |
-------------------------------------------+-----------------------------------+---------------+
| 0 | SELECT STATEMENT | | | | 3 | | | |
| 1 | SORT AGGREGATE | | 1 | 11 | | | | |
| 2 | PARTITION RANGE SINGLE | | 90 | 990 | 3 | 00:00:01 | KEY | KEY |
| 3 | PARTITION LIST SINGLE | | 90 | 990 | 3 | 00:00:01 | 2 | 2 |
| 4 | TABLE ACCESS FULL | TESTSZ | 90 | 990 | 3 | 00:00:01 | KEY | KEY |
-------------------------------------------+-----------------------------------+---------------+
Predicate Information:
----------------------
4 - filter("I"=:B1)

Categories: Uncategorized

Cardinality estimates on list subpartitioned tables with binds on partition, literals on subpartition

19/08/2012 Leave a comment

Acutually, I decided blogging is just too much pain especially the formating. Additionally considering the good quality of most of the other blogs, I would not want distribute half knowledge. However as some blog services do not allow direct formated long comments or limit comment to 4K, I will have to do this here (but even this does not format as I want).

While the bugs mentioned in http://oracle-randolf.blogspot.ch/2009/03/partition-oddities-part-1-severe-bug-in.html are according to oracle support fixed, still not all works well in 11.2.0.2. At least for range partitioned, sub list partitioned in combination with partial use of bind variables and add partition operations.

A partitioned table with identical subpartitions seems to work ok, however add one subpartition to the maxvalue partition (or any other or remove one) and you are back to square one, except for the first subpartition.

Unless I made an error or misunderstood something, a plan with cardinality 1 results:

	SQL_ID  a1d6qv0615qjg, child number 0
	-------------------------------------
	SELECT /*+ full(t) 1 off h*/ COUNT(*) FROM TESTSZ WHERE I=:B1 AND J=1
	 
	Plan hash value: 835289084
	 
	--------------------------------------------------------------------------------------------------
	| Id  | Operation               | Name   | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
	--------------------------------------------------------------------------------------------------
	|   0 | SELECT STATEMENT        |        |       |       |    14 (100)|          |       |       |
	|   1 |  SORT AGGREGATE         |        |     1 |    10 |            |          |       |       |
	|   2 |   PARTITION RANGE SINGLE|        |     1 |    10 |    14   (0)| 00:00:01 |   KEY |   KEY |
	|   3 |    PARTITION LIST SINGLE|        |     1 |    10 |    14   (0)| 00:00:01 |       |       |
	|*  4 |     TABLE ACCESS FULL   | TESTSZ |     1 |    10 |    14   (0)| 00:00:01 |   KEY |   KEY |
	--------------------------------------------------------------------------------------------------
	 
	Predicate Information (identified by operation id):
	---------------------------------------------------
	 
	   4 - filter(("J"=1 AND "I"=:B1))
	 

following first, abbreviated output of plan of different sql statements, then the script:

WITH added subpartition, note the cardinality estimate of 1 for j=1, j=2 (statement 3 and 4)
PLAN_TABLE_OUTPUT
-------------------------------------------------------------------------------------------------------
SELECT /*+ full(t) f off h*/ COUNT(*) FROM TESTSZ WHERE
|* 4 | TABLE ACCESS FULL | TESTSZ | 90 | 990 | 14 (0)| 00:00:01 | 2 | 2 |
SELECT /*+ full(t) 0 off h*/ COUNT(*) FROM TESTSZ WHERE I=:B1 AND J=0
|* 4 | TABLE ACCESS FULL | TESTSZ | 30 | 300 | 14 (0)| 00:00:01 | KEY | KEY |
SELECT /*+ full(t) 1 off h*/ COUNT(*) FROM TESTSZ WHERE I=:B1 AND J=1
|* 4 | TABLE ACCESS FULL | TESTSZ | 1 | 10 | 14 (0)| 00:00:01 | KEY | KEY |
SELECT /*+ full(t) 2 off h*/ COUNT(*) FROM TESTSZ WHERE I=:B1 AND J=2
|* 4 | TABLE ACCESS FULL | TESTSZ | 1 | 10 | 14 (0)| 00:00:01 | KEY | KEY |

SELECT /*+ full(t) 3 off h*/ COUNT(*) FROM TESTSZ WHERE I=:B2 AND J=:B1
|* 4 | TABLE ACCESS FULL | TESTSZ | 100 | 1100 | 14 (0)| 00:00:01 | KEY | KEY |

WITHOUT added subpartition resulting in reasonable estimates

PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------------------------------------
SELECT /*+ full(t) f off h*/ COUNT(*) FROM TESTSZ WHERE
|* 4 | TABLE ACCESS FULL | TESTSZ | 90 | 990 | 14 (0)| 00:00:01 | 2 | 2 |
SELECT /*+ full(t) 0 off h*/ COUNT(*) FROM TESTSZ WHERE I=:B1 AND J=0
|* 4 | TABLE ACCESS FULL | TESTSZ | 30 | 300 | 14 (0)| 00:00:01 | KEY | KEY |
SELECT /*+ full(t) 1 off h*/ COUNT(*) FROM TESTSZ WHERE I=:B1 AND J=1
|* 4 | TABLE ACCESS FULL | TESTSZ | 90 | 990 | 14 (0)| 00:00:01 | KEY | KEY |
SELECT /*+ full(t) 2 off h*/ COUNT(*) FROM TESTSZ WHERE I=:B1 AND J=2
|* 4 | TABLE ACCESS FULL | TESTSZ | 180 | 1980 | 14 (0)| 00:00:01 | KEY | KEY |

SELECT /*+ full(t) 3 off h*/ COUNT(*) FROM TESTSZ WHERE I=:B2 AND J=:B1
|* 4 | TABLE ACCESS FULL | TESTSZ | 100 | 1100 | 14 (0)| 00:00:01 | KEY | KEY |

and the script to generate above output:

set linesize 200
set pagesize 50
set echo on
set feedback off
column plan_table_output format a120

drop table testsz purge;
create table testsz
(i date, j number, v varchar2(100))
partition by range(i)
subpartition by list (j)
subpartition template
(subpartition p0 values (0),
 subpartition p1 values (1),
 subpartition p2 values (2)
)
(
partition p_100 values less than (to_date('3101201201','DDMMYYYYSS')),
partition p_200 values less than (to_date('3103201201','DDMMYYYYSS')),
partition p_max values less than (maxvalue)
);

alter table testsz modify partition p_max add subpartition values(3);


insert into testsz
select to_date('31012012','DDMMYYYY'),
        case when mod(rownum,100)  <10 then 0 when mod(rownum,100) <40 then 1 else 2 end,
       lpad('x',100)
  from dual connect by level <301;

insert into testsz
select to_date('31032012','DDMMYYYY'),
        case when mod(rownum,100)  <10 then 0 when mod(rownum,100) <40 then 1 else 2 end,
       lpad('x',100)
  from dual connect by level <301;
  
commit;

begin
 dbms_stats.gather_table_stats(ownname => user,tabname => 'TESTSZ',
                               method_opt => 'for all columns size 1',no_invalidate => false);
end;
/

-- info
select owner, table_name, partitioning_type, subpartitioning_type, partition_count, def_subpartition_count
 from dba_part_Tables where table_name='TESTSZ' and owner like 'TEST%';
select table_name, partition_name, num_rows,partition_position from user_tab_partitions where table_name='TESTSZ'
order by 1;
select table_name, subpartition_name, num_rows from user_tab_subpartitions where table_name='TESTSZ'
order by 2;

--
declare
 i1 date:=to_date('31012012','DDMMYYYY');
 h number:=1;
 j number;
begin
  select  /*+ full(t) f off h*/ count(*) into j from testsz where  I=to_date('31012012','DDMMYYYY')and j=1;
  select  /*+ full(t) 0 off h*/ count(*) into j from testsz  where I=i1 and j=0;
  select  /*+ full(t) 1 off h*/ count(*) into j from testsz  where I=i1 and j=1;
  select  /*+ full(t) 2 off h*/ count(*) into j from testsz  where I=i1 and j=2;
  select  /*+ full(t) 3 off h*/ count(*) into j from testsz  where I=i1 and j=h;
  --
  select  /*+ full(t) 4a off h*/ count(*) into j from testsz  where I=to_date('31012012','DDMMYYYY');
  select  /*+ full(t) 4b off h*/ count(*) into j from testsz  where I=to_date('31012012','DDMMYYYY') and j=h;
end;
/  

select t.sql_id, o.* from v$sql t ,
      table(dbms_xplan.display_cursor(t.sql_id, t.CHILD_NUMBER,'ADVANCED')) o
 where sql_Text like 'SELECT %full%TESTSZ%%'
 and (o.plan_table_output like '%TESTSZ %')
 and last_active_time > sysdate -1/24/60
 order by t.sql_text, o.plan_table_output desc
;

pause ...
Categories: Trouble, Uncategorized

Negativ probability

23/05/2011 Leave a comment

Not really, but this is the first thing that came to my mind, when I looked at a query, where the optimizer calculated that “condition A AND condition B” produces more rows than “condition A OR condition B”.

See for yourself on Oracle 10.2.0.4:

create table test_sz_t
 (i number, 
  d number, 
  c number, 
  v varchar2(400));

insert into test_sz_t
with gen as (select rownum-1 rn from dual connect by level <=1e5)
select rn, mod(rn, 100), trunc(rn/1000), lpad('a',300,'x') from gen;
commit;

begin
    dbms_stats.gather_table_stats(user, 'TEST_SZ_T');
end;
/

explain plan set statement_id='or' for
select * from test_sz_t where 2=:a or (3=:b  and i > -1);
select cardinality or_card from  plan_table where id=0 and statement_id='or';

explain plan set statement_id='and' for
select * from test_sz_t where 2=:a and (3=:b  and i > -1);
select cardinality and_card from  plan_table where id=0 and statement_id='and';

and here the of the expected rowcounts output. I just read the first line of the plan to get the final rowcounts.

    OR_CARD
-----------
       1990

   AND_CARD
-----------
     100000

The i> -1 will not reduce the number of rows. In the OR case, assuming independent conditions, the probability is as expected, ProbA + ProbB – ProbA*ProbB. This corresponds to the probability 1% for the completely unknown conditions number=:a, eg 1%+1% – 1%*1%. If I had used number > :a, then 5% would have been used instead of 1%.
Now in the AND case, you should expect 1%*1% e.g. 10 rows, howver this is not the case. A higher rowcount is reported, and this is only possible with a negatve probability or an oddity/bug within the optimizer.

When you look a the full plans, I omitted above, you notice quite easily what is going on, however I have to say in the orginal statements it was not so clear at first, and unfortunate, as it happend early as part of a larger query.

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
Plan hash value: 2387583053

-------------------------------------------------------------------------------
| Id  | Operation         | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |           |  1990 |   604K|  1034   (2)| 00:00:13 |
|*  1 |  TABLE ACCESS FULL| TEST_SZ_T |  1990 |   604K|  1034   (2)| 00:00:13 |
-------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------

   1 - filter(TO_NUMBER(:A)=2 OR TO_NUMBER(:B)=3 AND "I">(-1))



PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
Plan hash value: 2687592283

--------------------------------------------------------------------------------
| Id  | Operation          | Name      | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |           |   100K|    29M|  1031   (2)| 00:00:13 |
|*  1 |  FILTER            |           |       |       |            |          |
|*  2 |   TABLE ACCESS FULL| TEST_SZ_T |   100K|    29M|  1031   (2)| 00:00:13 |
--------------------------------------------------------------------------------

Predicate Information (identified by operation id):

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
---------------------------------------------------

   1 - filter(TO_NUMBER(:B)=3 AND TO_NUMBER(:A)=2)
   2 - filter("I">(-1))

You see the condition now is evaluated as filter in the and case, and this filter had no influence on the cardinality at all.

Obviously this is a very simple and maybe unfair example, but it shows the issue I also faced for a more complex query. What was my “real life” problem? A historised rule table with two different sys_context and other conditions to select relevant rows.

Categories: Uncategorized

Undocumented parameter – _bloom_filter_enabled

21/05/2011 Leave a comment

Update 24.5.2011: Turns out I seem to be wrong, these are two to separate features. So additinally I should understand those features, but kind of hard, if they are not documented. Anyway, here is the orginal artical:

You should not use undocumented parameters unless directed by Oracle Support. You ever read this? Here is post to remind, one should not set _ parameters and blindly assume they continue to work for a follow up release.

On one instance, 10g, due to some bug, directed by Oracle support _bloom_pruning_enabled was set to false. Then there was an upgrade, the parameter “survived” and one day I looked at an excecution plan, and hey, bloom filters in partition pruning appeard again.

Turns out, there is a new setting _bloom_pruning_enabled that controls now this behaviour. I do not know wheater this supercedes the former, is finer modeled or is a replacement . At least on 11.1.0.7 (no other tests done) the former setting _bloom_filter_enabled=false does not work fully.

The test:

create table testsz
(
  i number,
  j number,
  l number,
  x varchar2(1000)
)
partition by range (i)
 (
 partition partition_p1 values less than (1000) ,
 partition partition_p2 values less than (2000) ,
 partition partition_p3 values less than (3000) ,
 partition partition_p4 values less than (4000) ,
 partition partition_p5 values less than (5000) ,
 partition partition_p6 values less than (6000) ,
 partition partition_p7 values less than (7000) ,
 partition partition_p8 values less than (8000) ,
 partition partition_p9 values less than (9000) ,
 partition partition_p10 values less than (10000),
 partition partionte_max values less than (maxvalue)
 );

insert into testsz
with gen as (select rownum rn  from dual connect by levelselect rn, mod(rn, 100), trunc(rn,100),  lpad('x',300,'x') from gen;
commit;

create table testsz2 (i number);
insert into testsz2
select rownum*10 from dual connect by level commit;

exec dbms_stats.gather_table_stats(user, 'TESTSZ');
exec dbms_stats.gather_table_stats(user, 'TESTSZ2');

set echo on
set timing on

alter session set "_bloom_filter_enabled"=false;      
alter session set "_bloom_pruning_enabled"=true;   

explain plan for
  SELECT *
    FROM testsz A,
         testsz2 b
   WHERE A.i=B.i;

select * from table(dbms_xplan.display());

alter session set "_bloom_filter_enabled"=false;
alter session set "_bloom_pruning_enabled"=false;

explain plan for
  SELECT  *
    FROM testsz A,
         testsz2 b
   WHERE A.i=B.i;

select * from table(dbms_xplan.display());

and here is the output, the plans, clearly show the effect of the new parameter:

TEST @ PX> alter session set "_bloom_filter_enabled"=false;

Session altered.

Elapsed: 00:00:00.11
TEST @ PX> alter session set "_bloom_pruning_enabled"=true;

Session altered.

Elapsed: 00:00:00.04
TEST @ PX> 
TEST @ PX> explain plan for
  2    SELECT *
  3      FROM testsz A,
  4           testsz2 b
  5     WHERE A.i=B.i;

Explained.

Elapsed: 00:00:00.32
TEST @ PX> 
TEST @ PX> select * from table(dbms_xplan.display());

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------
Plan hash value: 4003749116

--------------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name    | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
--------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |         |    50 | 15800 |    61   (9)| 00:00:01 |       |       |
|*  1 |  HASH JOIN                   |         |    50 | 15800 |    61   (9)| 00:00:01 |       |       |
|   2 |   PART JOIN FILTER CREATE    | :BF0000 |    50 |   150 |     3   (0)| 00:00:01 |       |       |
|   3 |    TABLE ACCESS FULL         | TESTSZ2 |    50 |   150 |     3   (0)| 00:00:01 |       |       |
|   4 |   PARTITION RANGE JOIN-FILTER|         |   100K|    29M|    56   (6)| 00:00:01 |:BF0000|:BF0000|
|   5 |    TABLE ACCESS FULL         | TESTSZ  |   100K|    29M|    56   (6)| 00:00:01 |:BF0000|:BF0000|

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------
--------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - access("A"."I"="B"."I")

Note
-----
   - 'PLAN_TABLE' is old version

21 rows selected.

Elapsed: 00:00:00.92
TEST @ PX> 
TEST @ PX> alter session set "_bloom_filter_enabled"=false;

Session altered.

Elapsed: 00:00:00.03
TEST @ PX> alter session set "_bloom_pruning_enabled"=false;

Session altered.

Elapsed: 00:00:00.04
TEST @ PX> 
TEST @ PX> explain plan for
  2    SELECT  *
  3      FROM testsz A,
  4           testsz2 b
  5     WHERE A.i=B.i;

Explained.

Elapsed: 00:00:00.03
TEST @ PX> 
TEST @ PX> select * from table(dbms_xplan.display());

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------
Plan hash value: 1042833598

------------------------------------------------------------------------------------------------
| Id  | Operation            | Name    | Rows  | Bytes | Cost (%CPU)| Time     | Pstart| Pstop |
------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |         |    50 | 15800 |    61   (9)| 00:00:01 |       |       |
|*  1 |  HASH JOIN           |         |    50 | 15800 |    61   (9)| 00:00:01 |       |       |
|   2 |   TABLE ACCESS FULL  | TESTSZ2 |    50 |   150 |     3   (0)| 00:00:01 |       |       |
|   3 |   PARTITION RANGE ALL|         |   100K|    29M|    56   (6)| 00:00:01 |     1 |    11 |
|   4 |    TABLE ACCESS FULL | TESTSZ  |   100K|    29M|    56   (6)| 00:00:01 |     1 |    11 |
------------------------------------------------------------------------------------------------

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   1 - access("A"."I"="B"."I")

Note
-----
   - 'PLAN_TABLE' is old version

20 rows selected.

and by the way, the statement with bloom filter pruning was faster (I mean the actual one from the application). and do not say anything about old plan table ……

Categories: Uncategorized

Influence of new Oracle version – well actually not

22/04/2011 Leave a comment

Recently I have been working on application testing  related to a migration from 10.2.0.3 to 11.1.0.7.  New hardware as well. More and faster CPUs and significantly faster IO created some expectations.

So (as usual) some significantly slower batch jobs  were a bad, but somewhat expected surprise. Here is one example:

A batch job took 37 minutes instead of 15 minutes. I took one of the worst performing statements, taking 270 instead of 60 seconds, to investigate. Rather quickly the usual suspects, such as a changed plan, could be ruled out. As a matter of fact, after a while I could reduce the statement to a simple  reproducible test.

Preparation:


create table testsz
(i number, wa varchar2(5), vt varchar2(1), v varchar2(400));

create table testsz2
(i number, wa varchar2(5), vt varchar2(1), v varchar2(400));
create index testsz2_i on testsz2(wa,vt);

insert into testsz
with gen as (select rownum rn  from dual connect by level<=1e5)
select mod(rn, 1000),
       case  mod(rn,3) when 0 then 'A' when 1 then 'B' when 2 then 'C' else 'D' end||mod(rn, 2000),
       case when mod(rn,1) =0 then 'Y' else 'Q' end,
       lpad('x',300,'x'
 from gen;
commit;

Test:

set timing on

truncate table testsz2;

insert into testsz2
  select *
   from testsz;

The exact times vary depending on system and hardware, but the difference was significant on all systems tested.

Results on 10g vs 11g:   5 seconds vs 20 seconds.

This bugged me quite some time. I did all kinds of really stupid and other non-relevant stuff to investigate, to no avail. There must be something wrong with Oracle, right?

Finally I detected a increase in FB enqueue contention on 11g.  So there must be something wrong with the new Oracle release, right?

Looking for bug reports like mad, nothing found. (Not that the increase actually was significant, and if it had not been on ASSM tablespaces it would have been different anyway). Still, this triggered me to remember, that I asked a few weeks ago, about a changed init setting. But did not bother to follow up. Quickly checked, luckily the parameter  is session modifiable:

Modified test, on 11g only:

set timing on

prompt block checking false
alter session set db_block_checking=false;
truncate table testsz2;

insert into testsz2
select * from testsz;

prompt block checking true
alter session set db_block_checking=true;
truncate table testsz2;

insert into testsz2
select * from testsz;

3 seconds vs 20 seconds. So this has nothing to do with the new oracle release, but a changed initialization parameter. I have not tested much further about the causes, but the difference is also there in 10g.  At least on the systems I have access to.

Obviously the db_block_checking setting has an overhead, but frankly I am surprised by the magnitude, considering the quotes in the oracle documentation (from 11.1):

Block checking typically causes 1% to 10% overhead, depending on workload and the parameter value. The more updates or inserts in a workload, the more expensive it is to turn on block checking. You should set DB_BLOCK_CHECKING to FULL if the performance overhead is acceptable.

That difference is certainly not acceptable to me. Anyone else seen such a big difference?

Categories: Performance, Trouble

Consistent get trace file parser

16/04/2011 Leave a comment

Similar to my last post, this relates to another posting  http://hoopercharles.wordpress.com/2011/01/24/watching-consistent-gets-10200-trace-file-parser. Tracing the event 10200 allows to see consistent reads. For details read linked blog entry. So now I also learned how to quote source code and < and >.

My contribution to the topic, added as comment in above mentioned post, a small awk script, that allows direct parsing of the trace file output on unix (although, I actually used it on cygwin …., so may be not 100% compatible).

In order to change to another trace file format, you just have to change $nr references in the script.

$ more cons_get_trc.awk

BEGIN {
   FS ="[ \t<>:]+"
    print "Details for file: " trcfile
   print "---------------------------------"
   while( getline < trcfile != EOF ){
      if ( $0 ~ /started for block/ ) {
      rdba[$6]+=1
      obj[$8]+=1
      both[$6","$8]+=1
      print $6 " " rdba[$6] ", " $8 " " obj[$8]
      }
   }
   close (trcfile)
   print ""

   print ""
   print "Summary rdba and obj for file: " trcfile
   print "---------------------------------"
   for ( var in both) {
      print var " " both[var]
   }

   print ""
   print "Summary obj for file: " trcfile
   print "---------------------------------"
   for ( var in obj ) {
      print var " " obj[var]
   }
}

One third code, two thirds output. Usage demonstration,  with just head -50 of a trace file into small.trc.  (header info removed below)


Oracle Database 11g Enterprise Edition Release 11.1.0.7.0 - 64bit Production
.......

ktrget2(): started for block  <0x0104 : 0x09e3d4cc> objd: 0x00189fa5
env: (scn: 0x05b5.3bb87c76  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  statement num=0  parent xid: xid: 0x0000.000.00000000  scn: 0x0000.00000000 97sch: scn: 0x0000.00000000  mascn: (scn: 0x0000.00000000)
ktrexf(): returning 9 on:  10a102abc  scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  <0x0104 : 0x09e3d4cc> objd: 0x00189fa5
ktrget2(): completed for  block <0x0104 : 0x09e3d4cc> objd: 0x00189fa5
ktrget2(): started for block  <0x0104 : 0x09fa4692> objd: 0x00189fa5
env: (scn: 0x05b5.3bb87c76  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  statement num=0  parent xid: xid: 0x0000.000.00000000  scn: 0x0000.00000000 96sch: scn: 0x0000.00000000  mascn: (scn: 0x0000.00000000)
ktrexf(): returning 9 on:  10a102abc  scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  <0x0104 : 0x09fa4692> objd: 0x00189fa5
ktrget2(): completed for  block <0x0104 : 0x09fa4692> objd: 0x00189fa5
ktrget2(): started for block  <0x0104 : 0x0a0ac450> objd: 0x00189fa5
env: (scn: 0x05b5.3bb87c76  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  statement num=0  parent xid: xid: 0x0000.000.00000000  scn: 0x0000.00000000 96sch: scn: 0x0000.00000000  mascn: (scn: 0x0000.00000000)
ktrexf(): returning 9 on:  10a102abc  scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  <0x0104 : 0x0a0ac450> objd: 0x00189fa5
ktrget2(): completed for  block <0x0104 : 0x0a0ac450> objd: 0x00189fa5
ktrget2(): started for block  <0x0104 : 0x009d94fc> objd: 0x00189fa5
env: (scn: 0x05b5.3bb87c76  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  statement num=0  parent xid: xid: 0x0000.000.00000000  scn: 0x0000.00000000 96sch: scn: 0x0000.00000000  mascn: (scn: 0x0000.00000000)
ktrexf(): returning 9 on:  10a102abc  scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  <0x0104 : 0x009d94fc> objd: 0x00189fa5
ktrget2(): completed for  block <0x0104 : 0x009d94fc> objd: 0x00189fa5
ktrget2(): started for block  <0x0104 : 0x09fa4698> objd: 0x00189fa5
env: (scn: 0x05b5.3bb87c76  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  statement num=0  parent xid: xid: 0x0000.000.00000000  scn: 0x0000.00000000 96sch: scn: 0x0000.00000000  mascn: (scn: 0x0000.00000000)
ktrexf(): returning 9 on:  10a102abc  scn: 0xffff.ffffffff  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  scn: 0xffff.ffffffff  sfl: 0
ktrgcm(): completed for block  <0x0104 : 0x09fa4698> objd: 0x00189fa5
ktrget2(): completed for  block <0x0104 : 0x09fa4698> objd: 0x00189fa5
ktrget2(): started for block  <0x0104 : 0x009d94ff> objd: 0x00189fa5
env: (scn: 0x05b5.3bb87c76  xid: 0x0000.000.00000000  uba: 0x00000000.0000.00  statement num=0  parent xid: xid: 0x0000.000.00000000  scn: 0x0000.00000000 96sch: scn: 0x0000.00000000  mascn: (scn: 0x0000.00000000)

$ awk -v trcfile=small.trc -f cons_get_trc.awk

Details for file: small.trc
---------------------------------
0x09e3d4cc 1, 0x00189fa5 1
0x09fa4692 1, 0x00189fa5 2
0x0a0ac450 1, 0x00189fa5 3
0x009d94fc 1, 0x00189fa5 4
0x09fa4698 1, 0x00189fa5 5
0x009d94ff 1, 0x00189fa5 6

Summary rdba and obj for file: small.trc
---------------------------------
0x0a0ac450,0x00189fa5 1
0x09fa4698,0x00189fa5 1
0x09fa4692,0x00189fa5 1
0x009d94ff,0x00189fa5 1
0x009d94fc,0x00189fa5 1
0x09e3d4cc,0x00189fa5 1

Summary obj for file: small.trc
---------------------------------
0x00189fa5 6

Categories: Tracing

TM enqueues and deadlock with one user session

16/04/2011 2 comments

For quite some time now, I have been thinking about writing some blog items, but never did. A recent blog entry on http://jonathanlewis.wordpress.com/2011/04/08/deadlock prompted me to give it a try.

So the first post is just a repetition of the comment I made:

TM-enqueues for foreign key locking seems to be a well known fact. What I personally would like to know, what other reasons can cause TM-Locks.
A few times already I had issues with them, not involving foreign keys.

Another reason are exclusive lock and the following. Did anyone know, that a single user connected session can cause a deadlock?

on 10.2.0.3 and 11.1.0.7 verified:


DROP TABLE TESTSZ;
CREATE TABLE TESTSZ
( I NUMBER,
  K VARCHAR2(50));
 INSERT INTO TESTSZ
 SELECT MOD(ROWNUM,1000), LPAD(‘X’,40,’Y') FROM DUAL CONNECT BY ROWNUM < 1000000;
 COMMIT;

LOCK TABLE TESTSZ IN EXCLUSIVE MODE;
 INSERT INTO TESTSZ X
 WITH X1 AS  (SELECT /*+ no_PARALLEL(T) MATERIALIZE*/ 2000, K FROM TESTSZ T
 WHERE I=1)
 SELECT * FROM X1;
 rollback;

LOCK TABLE TESTSZ IN EXCLUSIVE MODE;
 set timing on
 INSERT INTO TESTSZ X
 WITH X1 AS (SELECT /*+ PARALLEL(T,4) MATERIALIZE*/ 2000, K FROM TESTSZ T
 WHERE I=1)
 SELECT * FROM X1;
 rollback;

Result of the last insert statement:

INSERT INTO TESTSZ X
*
FEHLER in Zeile 1:
ORA-12801: error signaled in parallel query server P000
ORA-00060: deadlock detected while waiting for resource

Before anyone complains there are more than one session involved,
yes, but the importance is only one “user” connected session.

Moving back to TM locks, in the case above with the factored subquery
in combination with parallel query, the deadlock occurs while the sessions
are trying to get TM-locks.

SID PROGRAM LAST_CALL_ET BLOCKING_SESSION EVENT SECONDS_IN_WAIT
116 sqlplus.exe               48        PX Deq: Parse Reply     3  WAITING
117 oracle@cyber-ora10 (P005) 48        PX Deq: Execution Msg   3  WAITING
128 oracle@cyber-ora10 (P004) 48        PX Deq: Execution Msg   3  WAITING
115 oracle@cyber-ora10 (P003) 48        PX Deq: Execution Msg   3  WAITING
129 oracle@cyber-ora10 (P002) 48  116   enq: TM – contention   48 WAITING
120 oracle@cyber-ora10 (P001) 48  116   enq: TM – contention   48 WAITING
136 oracle@cyber-ora10 (P000) 48  116   enq: TM – contention   48 WAITING

To finish, Oracle support agreed, that this is not supposed to happen. The workaround is to use the inline hint.

And to credit, this originally happened to a co-worker sitting two desks next to me.

Categories: Locking, Trouble
Follow

Get every new post delivered to your Inbox.