Thursday 17 December 2009

Miracle Open World 2010, April 14-16, Legoland

Finally Miracle has published the first official advertisement for Miracle Open World 2010 event, which will take place in Legoland, Billund, Jutland, Denmark, from 14-16 April 2010. Here is the link to the event site.

I'll be presenting at this spectacular and unique event. Hopefully the weather will permit me to fly to Legoland by myself and land at Billund airport which is just several hundred meters away from the conference venue.

Wednesday 16 December 2009

Force Cursor Invalidation

Many times it occurs that an inappropriate execution plan is used which was produced by using the current values of bind variables provided at the time of the hard parse. But later on the variables change so much that another execution plan would be required. Unfortunately there is no automatism in 9i and 10g that would spot this fact. Oracle finally resolved this problem in 11g.

The trick is to virtually set the statistics for the object which is involved in the query. What I mean by virtually is that I read the current statistics and store the same statistics back what makes no harm but the side effect is that the cursor is invalidated and hence it will be re-parsed and hopefully this time optimized for the right values of bind variables.

Here is the code:

CREATE OR REPLACE PROCEDURE Invalidate_statistics (
p_ownname VARCHAR2,
p_tabname VARCHAR2
) IS
m_srec DBMS_STATS.STATREC;
m_distcnt NUMBER;
m_density NUMBER;
m_nullcnt NUMBER;
m_avgclen NUMBER;
m_colname VARCHAR2(30);
--
-- This procedure invalidates all cursors present in v$sql
-- which refer to the table passed as input parameter
--
-- requires DBA privileges
--
-- This is a workaround to solve the problem of bind variable peeking
--
BEGIN
-- first find column definition for the first column - doesn't matter for which
-- column we reset the statistics
BEGIN
SELECT column_name INTO m_colname
FROM DBA_TAB_COLUMNS
WHERE owner = p_ownname
AND table_name = p_tabname
AND ROWNUM = 1;
EXCEPTION
WHEN NO_DATA_FOUND THEN RAISE_APPLICATION_ERROR( -20000,
'Table '||p_ownname||'.'||p_tabname||' does not exist');
END;
-- virtually change the statistics - replace with the same values what will cause
-- invalidation of all cursors which refer to this table - NO_INVALIDATE must be FALSE
DBMS_STATS.GET_COLUMN_STATS (ownname => p_ownname,
tabname => p_tabname,
colname => m_colname,
distcnt => m_distcnt,
density => m_density,
nullcnt => m_nullcnt,
srec => m_srec,
avgclen => m_avgclen
);
DBMS_STATS.SET_COLUMN_STATS (ownname => p_ownname,
tabname => p_tabname,
colname => m_colname,
distcnt => m_distcnt,
density => m_density,
nullcnt => m_nullcnt,
srec => m_srec,
avgclen => m_avgclen,
no_invalidate => FALSE
);
END;
/

The procedure reads and stores back the statistics for the first column of the table.

SQL> exec Invalidate_statistics('SCOTT','EMP')

PL/SQL procedure successfully completed.

Sometimes it requires to re-execute the invalidation as the cursor is currently executing. One can use this in 9i,10g,11g.

Thursday 10 December 2009

"Optimizer Internals" - Celebrity Seminar in Netherlands

On June 15th 2010 I will be speaking about internals of the Cost Based Optimizer in Netherlands. This is a one day seminar organized by Oracle University which goes in details in some sections of the cost based optimization. The topics are related to hot themes for which people would like to get a good explanation. Here is a detailed table of contents.

This seminar is one of four that I have contributed to the series of celebrity seminars organized by Oracle University.

Tuesday 8 December 2009

CBO oddities in determining selectivity on NVARCHAR2 data type

Some time ago I was involved in solving of a performance problem which was really weird - a simple select on a indexed column with unique value always resulted in a full table scan. The key column was of type NVARCHAR2. To better understand the behavior I created a simple reproducible test case.

Let us start with table and index creation.

SQL> select * from v$version;

BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.1.0.6.0 - Production
PL/SQL Release 11.1.0.6.0 - Production
CORE 11.1.0.6.0 Production
TNS for 32-bit Windows: Version 11.1.0.6.0 - Production
NLSRTL Version 11.1.0.6.0 - Production

SQL> show parameter semant

NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
nls_length_semantics string CHAR

SQL> create table x2 (id varchar2(32), idn nvarchar2(32), id16 nvarchar2(16), id20 nvarchar2(20));

Table created.

SQL> insert into x2 select lpad(rownum,32,'0'), lpad(rownum,32,'0'),lpad(rownum,16,'0'),lpad(rownum,20,'0')
from dual connect by level <= 20000; 20000 rows created. SQL> commit;

Commit complete.

SQL> create index x2_idn on x2(idn);

Index created.

SQL> analyze table x2 compute statistics;

Table analyzed.

SQL> explain plan for select * from x2 where idn=U'00000000000000000000000000000009';

Explained.

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

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------
Plan hash value: 156302112

--------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 20000 | 3281K| 136 (0)| 00:00:02 |
|* 1 | TABLE ACCESS FULL| X2 | 20000 | 3281K| 136 (0)| 00:00:02 |
--------------------------------------------------------------------------

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

1 - filter("IDN"=U'00000000000000000000000000000009')


We have 20,000 rows with unique values in IDN column in the table, we have statistics and still the CBO produces an execution plan with FULL TABLE SCAN and with a very strange estimate of 20,000 rows reurned by this query.
Therefore our first question should be: What is wrong with the statistics? A simple query on USER_TAB_COLS shows the following results:

SQL> select column_name,num_distinct, low_value,high_value from user_tab_cols where table_name='X2';

COLUMN_NAME NUM_DISTINCT LOW_VALUE HIGH_VALUE
------------------------------ ------------ ---------------------------------------------------------------- ----------------------------------------------------------------
ID 20000 3030303030303030303030303030303030303030303030303030303030303031 3030303030303030303030303030303030303030303030303030303230303030
IDN 1 0030003000300030003000300030003000300030003000300030003000300030 0030003000300030003000300030003000300030003000300030003000300030
ID16 20000 0030003000300030003000300030003000300030003000300030003000300031 0030003000300030003000300030003000300030003000320030003000300030
ID20 3 0030003000300030003000300030003000300030003000300030003000300030 0030003000300030003000300030003000300030003000300030003000300032

To display raw values I used function developed by Greg Rahn which gives the following result:

SQL> column lo_val format a32
SQL> column hi_val format a32
SQL> select column_name,
2 num_distinct,
3 display_raw(low_value,data_type) lo_val,
4 display_raw(high_value,data_type) hi_val
5 from user_tab_cols
6 where table_name='X2';

COLUMN_NAME NUM_DISTINCT LO_VAL HI_VAL
------------------------------ ------------ -------------------------------- --------------------------------
ID 20000 00000000000000000000000000000001 00000000000000000000000000020000
IDN 1 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
ID16 20000 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 2 0 0 0 0
ID20 3 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2

We can see that the NUM_DISTINCT column has quite strange values. Reason for this is that Oracle analyzes only first 32 bytes (and not characters) of the string. The default character set for NVARCHAR2 type is AL16UTF16 - a 2 byte character set.
The column IDN was defined as NVARCHAR2(32) and was actually completely filled so every row stores 64 bytes in this column. Here is the proof:


SQL> select dump(idn) from x2 where rownum = 1;

DUMP(IDN)
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Typ=1 Len=64: 0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,48,0,56,0,51

Due to considering only first 32 bytes analyze comes back with a strange result that there is only one distinct value, what is of course true, as all distinct digits are beyond first 32 bytes.

Let us continue and use DBMS_STATS.GATHER_TABLE_STATS for analysis.

SQL> begin
2 dbms_stats.gather_table_stats(
3 ownname=> user ,
4 tabname=> 'X2',
5 cascade=> TRUE,
6 estimate_percent=> DBMS_STATS.AUTO_SAMPLE_SIZE,
7 degree=> DBMS_STATS.AUTO_DEGREE,
8 no_invalidate=> FALSE,
9 granularity=> 'ALL',
10 method_opt=> 'FOR ALL COLUMNS SIZE AUTO');
11 end;
12 /

SQL> select column_name,num_distinct,
2 display_raw(low_value,data_type) lo_val,
3 display_raw(high_value,data_type) hi_val
4 from user_tab_cols where table_name='X2'
5 /

COLUMN_NAME NUM_DISTINCT LO_VAL HI_VAL
------------------------------ ------------ -------------------------------- --------------------------------
ID 19820 00000000000000000000000000000001 00000000000000000000000000020000
IDN 20000 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
ID16 20000 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 1 0 0 0 0 0 0 0 0 0 0 0 2 0 0 0 0
ID20 19942 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 2

DBMS_STATS produces much more reliable cardinalities but the low/high values are still showing only 0 for IDN column. Here there is no difference between ANALYZE and DBMS_STATS as it can't be. Oracle looks only at first 32 bytes and that is the fact. Therefore the CBO will be not able to properly determine the cardinality for the range predicates. We will look closer this in the continuation of this post.
This fact might become dangerous also for all databases which use multi-byte character set as default character set. Actually Oracle will always look only at first 32 bytes and in case that the column will contain many many multi-byte characters this can become pretty odd. All this is something new and becomes more critical in now days when a lot of databases are migrated from single-byte character set to a multi-byte character sets. For sure migrating to any flavor of UTF-8/AL32UTF8 character set represent such a thread.

Conclusions about statistics for NVARCHAR2 data type
When I realized what is the reason behind for such behavior I suggested to my customer to switch back to rule based optimizer what solved the problem. The other possibility would be to change all NVARCHAR2 columns to VARCHAR2 but the customer accept this.
First, but the most important conclusion would be not to use NVARCHAR2 data type for key columns, but rather VARCHAR2. Or paraphrasing Mogens Norgard: "We don't use NVARCHAR2 data type!" :-)

*Range cardinalities on columns of NVARCHAR2 data type*
Reason for this part of post is my involvement in one thread on OTN where a lady from Austria, my neighbor country, was complaining about the "strange" execution plans and consequently also "un-wanted" performance. In one mail she explained me that they are experiencing performance problems since they have upgraded from Oracle9i to 10g. She also said that at the same time they moved from VARCHAR2 data type to NVARCHAR2 datatype.
My first impression was that this might be the same situation as I have already explained above. But after digging deeply in the problem, I realized that the problem lies in completely mis-estimated selectivity and consequently also the cardinality when NVARCHAR2 data type column is in question.

To be able to study the case I prepared an extremely simple reproducible test case. Let us start with the setup of the test environment:


SQL> create table x1 (cv varchar2(10), cn nvarchar2(10));

Table created.

SQL> insert into x1 select lpad(rownum,8,'0'), lpad(rownum,8,'0')
from dual connect by level <= 20000; 20000 rows created. SQL> commit;

Commit complete.

SQL> select cv,cn from x1 where rownum <= 10; CV CN ---------- ---------- 00000469 00000469 00000470 00000470 00000471 00000471 00000472 00000472 00000473 00000473 00000474 00000474 00000475 00000475 00000476 00000476 00000477 00000477 00000478 00000478 10 rows selected. SQL> begin
2 dbms_stats.gather_table_stats(
3 ownname=> user ,
4 tabname=> 'X1',
5 cascade=> TRUE,
6 estimate_percent=> DBMS_STATS.AUTO_SAMPLE_SIZE,
7 degree=> DBMS_STATS.AUTO_DEGREE,
8 no_invalidate=> FALSE,
9 granularity=> 'ALL',
10 method_opt=> 'FOR ALL COLUMNS SIZE 1');
11* end;
SQL> /

PL/SQL procedure successfully completed.


Let us run our first test SQL. I have used bind variables named :a1, :a2 of type VARCHAR2 and :n1, :n2 of type NVARCHAR2. I have event written a simple anonymous PL/SQL block where I selected the values for bind variables from the same table in order to be sure that the binding is done properly. While I was running the tests I enabled events 10053 and 10046.


SQL> select * from table(dbms_xplan.display_cursor(null,null,'allstats last'));
SQL_ID 1fj17ram77n5w, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ /* run 20 */ *
from x1
where cn >= to_nchar(:a1)
and cn <= to_nchar(:a2) Plan hash value: 2189453339 ------------------------------------------------------------------------------------- | Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | ------------------------------------------------------------------------------------- |* 1 | FILTER | | 1 | | 9999 |00:00:00.08 | 102 | |* 2 | TABLE ACCESS FULL| X1 | 1 | 1 | 9999 |00:00:00.03 | 102 | ------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 1 - filter(SYS_OP_C2C(:A1)<=SYS_OP_C2C(:A2)) 2 - filter(("CN"<=SYS_OP_C2C(:A2) AND "CN">=SYS_OP_C2C(:A1)))


PARSING IN CURSOR #12 len=111 dep=0 uid=88 oct=3 lid=88 tim=254514943459 hv=2792607932 ad='23f7056c' sqlid='1fj17ram77n5w'
select /*+ gather_plan_statistics */ /* run 20 */ *
from x1
where cn >= to_nchar(:a1)
and cn <= to_nchar(:a2) END OF STMT PARSE #12:c=0,e=734,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=254514943452 BINDS #12: Bind#0 oacdty=01 mxl=32(10) mxlc=10 mal=00 scl=00 pre=00 oacflg=03 fl2=1000010 frm=01 csi=170 siz=64 off=0 kxsbbbfp=0fec0abc bln=32 avl=08 flg=05 value="00000000" Bind#1 oacdty=01 mxl=32(10) mxlc=10 mal=00 scl=00 pre=00 oacflg=03 fl2=1000010 frm=01 csi=170 siz=0 off=32 kxsbbbfp=0fec0adc bln=32 avl=08 flg=01 value="00009999"

I got a hard parse (mis=1), optimizer peeked at the values of bind variables and the estimated cardinality was 1 while the actual one was 9999. From 10046 trace we can clearly see the values of bind variables used by optimizer for the optimization. I used VARCHAR2 type of columns as bind variables but used TO_NCHAR function to convert to NVARCHAR2 data type. The optimizer internally rewrote the SQL so that instead of TO_NCHAR used internal function SYS_OP_C2C which performs conversion from one character set to another.


SQL> select SYS_OP_C2C('Š') from dual;

S
-
S


For next run I used NVARCHAR2 type bind variables and here is the result:

SQL_ID d1bn5vyb6dcgn, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ /* run 15 */ *
from x1
where cn >= to_nchar(:n1)
and cn <= to_nchar(:n2) Plan hash value: 2189453339 ------------------------------------------------------------------------------------- | Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | ------------------------------------------------------------------------------------- |* 1 | FILTER | | 1 | | 9999 |00:00:00.08 | 759 | |* 2 | TABLE ACCESS FULL| X1 | 1 | 50 | 9999 |00:00:00.04 | 759 | ------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 1 - filter(:N1<=:N2) 2 - filter(("CN">=:N1 AND "CN"<=:N2)) PARSING IN CURSOR #15 len=111 dep=0 uid=88 oct=3 lid=88 tim=254434564390 hv=2523312628 ad='2c8d2200' sqlid='d1bn5vyb6dcgn' select /*+ gather_plan_statistics */ /* run 15 */ * from x1 where cn >= to_nchar(:n1)
and cn <= to_nchar(:n2) END OF STMT PARSE #15:c=0,e=746,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=254434564383 BINDS #15: Bind#0 oacdty=01 mxl=128(40) mxlc=20 mal=00 scl=00 pre=00 oacflg=03 fl2=1000010 frm=02 csi=2000 siz=256 off=0 kxsbbbfp=0febbee0 bln=128 avl=16 flg=05 value="" Bind#1 oacdty=01 mxl=128(40) mxlc=20 mal=00 scl=00 pre=00 oacflg=03 fl2=1000010 frm=02 csi=2000 siz=0 off=128 kxsbbbfp=0febbf60 bln=128 avl=16 flg=01 value=""

Here we got the estimated number of rows 50 what is exactly the default use by the CBO for ranges - selectivity is 0.0025. So the CBO simply decided to throw in the default selectivity. The values of bind variables are empty ("") - CBO just ignored them during the optimization phase but they were of course respected by the runtime engine.


SQL_ID cx88wv0q05tst, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ /* run 14 */ *
from x1
where substr(cn,1,10) >= to_nchar(:a1)
and substr(cn,1,10) <= to_nchar(:a2) Plan hash value: 2189453339 ------------------------------------------------------------------------------------- | Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | ------------------------------------------------------------------------------------- |* 1 | FILTER | | 1 | | 9999 |00:00:00.09 | 759 | |* 2 | TABLE ACCESS FULL| X1 | 1 | 50 | 9999 |00:00:00.05 | 759 | ------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 1 - filter(SYS_OP_C2C(:A1)<=SYS_OP_C2C(:A2)) 2 - filter((SUBSTR("CN",1,10)>=SYS_OP_C2C(:A1) AND
SUBSTR("CN",1,10)<=SYS_OP_C2C(:A2))) PARSING IN CURSOR #12 len=137 dep=0 uid=88 oct=3 lid=88 tim=254227180414 hv=2415463600 ad='23f7e900' sqlid='f5wapff7zk35h' select /*+ gather_plan_statistics */ /* run 16 */ * from x1 where substr(cn,1,10) >= to_nchar(:a1)
and substr(cn,1,10) <= to_nchar(:a2) END OF STMT PARSE #12:c=0,e=767,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=254227180407 BINDS #12: Bind#0 oacdty=01 mxl=32(10) mxlc=10 mal=00 scl=00 pre=00 oacflg=03 fl2=1000010 frm=01 csi=170 siz=64 off=0 kxsbbbfp=0ff75ac0 bln=32 avl=08 flg=05 value="00000000" Bind#1 oacdty=01 mxl=32(10) mxlc=10 mal=00 scl=00 pre=00 oacflg=03 fl2=1000010 frm=01 csi=170 siz=0 off=32 kxsbbbfp=0ff75ae0 bln=32 avl=08 flg=01 value="00009999"

In this case I added used SUBSTR function on the column and VARCHAR2 type bind variables and again the CBO threw in the default for range 0.0025, but we can see the values of bind variables.


SQL_ID auyacfyb6bj9r, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ /* run 14 */ *
from x1
where substr(cn,1,10) >= to_nchar(:n1)
and substr(cn,1,10) <= to_nchar(:n2) Plan hash value: 2189453339 ------------------------------------------------------------------------------------- | Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | ------------------------------------------------------------------------------------- |* 1 | FILTER | | 1 | | 9999 |00:00:00.09 | 759 | |* 2 | TABLE ACCESS FULL| X1 | 1 | 50 | 9999 |00:00:00.05 | 759 | ------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 1 - filter(:N1<=:N2) 2 - filter((SUBSTR("CN",1,10)>=:N1 AND SUBSTR("CN",1,10)<=:N2)) PARSING IN CURSOR #16 len=137 dep=0 uid=88 oct=3 lid=88 tim=254203929826 hv=1230940210 ad='23f78074' sqlid='13u552p4pxa1k' select /*+ gather_plan_statistics */ /* run 15 */ * from x1 where substr(cn,1,10) >= to_nchar(:n1)
and substr(cn,1,10) <= to_nchar(:n2) END OF STMT PARSE #16:c=0,e=770,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=254203929819 BINDS #16: Bind#0 oacdty=01 mxl=128(40) mxlc=20 mal=00 scl=00 pre=00 oacflg=03 fl2=1000010 frm=02 csi=2000 siz=256 off=0 kxsbbbfp=10460bd0 bln=128 avl=16 flg=05 value="" Bind#1 oacdty=01 mxl=128(40) mxlc=20 mal=00 scl=00 pre=00 oacflg=03 fl2=1000010 frm=02 csi=2000 siz=0 off=128 kxsbbbfp=10460c50 bln=128 avl=16 flg=01 value=""

In the CBO trace the inforamation was:

*******************************************
Peeked values of the binds in SQL statement
*******************************************
----- Bind Info (kkscoacd) -----
Bind#0
oacdty=01 mxl=32(20) mxlc=10 mal=00 scl=00 pre=00
oacflg=03 fl2=1000010 frm=02 csi=2000 siz=64 off=0
kxsbbbfp=0f1f5a1c bln=32 avl=16 flg=05
value=""
Bind#1
oacdty=01 mxl=32(20) mxlc=10 mal=00 scl=00 pre=00
oacflg=03 fl2=1000010 frm=02 csi=2000 siz=0 off=32
kxsbbbfp=0f1f5a3c bln=32 avl=16 flg=01
value=""

In the last case I just changed from VARCHAR2 to NVARCHAR2 bind variables and the result was expected - the default selectivity and the values of bind variables were again "".

Every time, when the CBO used binds for estimating selectivity I could see the following section after the execution plan:

Peeked Binds
============
Bind variable information
position=1
datatype(code)=1
datatype(string)=VARCHAR2(32)
char set id=170
char format=1
max length=32
value=00000000
Bind variable information
position=2
datatype(code)=1
datatype(string)=VARCHAR2(32)
char set id=170
char format=1
max length=32
value=00009999
Outline Data:
/*+
BEGIN_OUTLINE_DATA
IGNORE_OPTIM_EMBEDDED_HINTS
OPTIMIZER_FEATURES_ENABLE('11.1.0.6')
DB_VERSION('11.1.0.6')
ALL_ROWS
OUTLINE_LEAF(@"SEL$1")
FULL(@"SEL$1" "X1"@"SEL$1")
END_OUTLINE_DATA
*/

And finally one case with VARCHAR2 data type.

SQL_ID bznnx6zk4hm11, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ /* run 22 */ *
from x1 where cv >=:a1
and cv <= :a2 Plan hash value: 2189453339 ------------------------------------------------------------------------------------- | Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | ------------------------------------------------------------------------------------- |* 1 | FILTER | | 1 | | 9999 |00:00:00.07 | 102 | |* 2 | TABLE ACCESS FULL| X1 | 1 | 9999 | 9999 |00:00:00.02 | 102 | ------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 1 - filter(:A1<=:A2) 2 - filter(("CV"<=:A2 AND "CV">=:A1))


PARSING IN CURSOR #13 len=89 dep=0 uid=88 oct=3 lid=88 tim=265619391820 hv=3829943329 ad='2e0c3568' sqlid='bznnx6zk4hm11'
select /*+ gather_plan_statistics */ /* run 22 */ *
from x1
where cv >= :a1
and cv <= :a2 END OF STMT PARSE #13:c=0,e=762,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=265619391813 BINDS #13: Bind#0 oacdty=01 mxl=32(10) mxlc=10 mal=00 scl=00 pre=00 oacflg=03 fl2=1000010 frm=01 csi=170 siz=64 off=0 kxsbbbfp=0fec0abc bln=32 avl=08 flg=05 value="00000000" Bind#1 oacdty=01 mxl=32(10) mxlc=10 mal=00 scl=00 pre=00 oacflg=03 fl2=1000010 frm=01 csi=170 siz=0 off=32 kxsbbbfp=0fec0adc bln=32 avl=08 flg=01 value="00009999"

In this last case I was querying the VARCHAR2 column and using bind variables of VARCHAR2 type and this time the optimizer estimated cardinality correctly. Of course it performed peeking at the values of bind variables.

Randolf Geist responded to my post on OTN and he suggested to confuse the CBO by using values like 'A0000000' to 'A00009999'. According to his observations also the selectivity for range predicates on VARCHAR2 data types is quite off after using this trick. Building a histogram returns things back to normal on both data types.
He pointed out that the CBO is obviously so smart to spot stored digits in VARCHAR2 columns and do good estimations by treating them as numbers while this is not true for the VARCHAR2 data type.

CONCLUSION
It is obvious that the CBO is not capable to perforem same estimates for ranges on NVARCHAR2 column as it is capable to do on VARCHAR2 column when numbers are stored as strings.
But the most important conclusion to be made is that one should use *appropriate* data types.

Of course that are many possibilities that the CBO might behave differently (like using DYNAMIC_SAMPLING, ...). So I am looking forward for the contributions of others, not just Randolf Geist.

This case was used to raise SR #3-1193039441: CBO and nvarchar2 --> A new Bug: 9220704 has been filed with development.

Monday 7 December 2009

What is the purpose of SYS_OP_C2C internal function

Recently I was involved in one problem with CBO's selectivity estimations on NVARCHAR2 data type column. What I spotted in predicate information was the usage of internal Oracle function SYS_OP_C2C.

Here is an example of the run-time execution plan using bind variables:


SQL_ID 1fj17ram77n5w, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ *
from x1 where cn >= to_nchar(:a1) and cn <= to_nchar(:a2)

Plan hash value: 2189453339

-------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers |
-------------------------------------------------------------------------------------
|* 1 | FILTER | | 1 | | 9999 |00:00:00.08 | 102 |
|* 2 | TABLE ACCESS FULL| X1 | 1 | 1 | 9999 |00:00:00.03 | 102 |
-------------------------------------------------------------------------------------

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

1 - filter(SYS_OP_C2C(:A1)<=SYS_OP_C2C(:A2))
2 - filter(("CN"<=SYS_OP_C2C(:A2) AND "CN">=SYS_OP_C2C(:A1)))

As you can see the bind variables are converted to national character set using TO_NCHAR function. Column X1.CN is of type NVARCHAR2. It is easy to spot the difference between the SQL statement and the predicate information from the execution plan: to_nchar(:a2) from SQL statement is transformed to SYS_OP_C2C(:A2) in predicate information. The internal Oracle function SYS_OP_C2C performs conversion from one character set to another character set - C(haracterSet)2C(haracterSet). There are situations when one will see this conversion going on without explicit command as in this case what should be a sign that the data types are not the same and implicit conversion is taking place and this might be also a problem from performance perspective as it may disable index usage.

Jonathan Lewis and Charles Hooper, my fellows from the OakTable, had a discussion about this internal function back in 2007.

Saturday 5 December 2009

Measurement Error Trap In Trace File (event 10046)


Some time ago I had an interesting case which I can use to clearly describe how one can be caught in measurement error trap.

But let us start at the beginning with this response time analysis:


Response Time Component Time % Elap AvgEla
---------------------------------------- ----------- ------- ---------
CPU service 3934.97s 48.39% 0.000716
un-accounted for time 1363.01s 16.76%
db file sequential read 1122.00s 13.80% 0.032253
gc buffer busy 451.73s 5.56% 0.011746
log buffer space 451.64s 5.55% 0.123974
buffer busy waits 176.79s 2.17% 0.029579
gc cr block 2-way 156.49s 1.92% 0.003287
gc cr grant 2-way 100.20s 1.23% 0.006541
latch: cache buffers chains 98.92s 1.22% 0.005708
gc current grant 2-way 69.68s 0.86% 0.006728
latch: library cache 30.10s 0.37% 0.010030
row cache lock 28.95s 0.36% 0.018727
gc current block 2-way 26.72s 0.33% 0.003828
gc cr block busy 19.35s 0.24% 0.006802
gc current grant busy 15.30s 0.19% 0.004999
latch: row cache objects 14.28s 0.18% 0.006165
gc cr block 3-way 11.73s 0.14% 0.002952
gc current block 3-way 11.34s 0.14% 0.003440
log file sync 10.71s 0.13% 0.315066
enq: SQ - contention 9.14s 0.11% 0.060911

My first thought was that there is an I/O problem as the average single block I/O took 32 milliseconds.









After digging for a while I have produced the following graphs which represent the I/O timing.











Let's first look at some facts:
- 3 node RAC
- Same storage
- Single block read time for Instance 1 was substantially different from read times for other instances during off hours
- 5 batch jobs during off hours
- The timings for Instance 1 are obviously not correct

I used the fact that I was performing the analysis on a 3 node RAC to check what are the timings on other two nodes and as you can see from the second graph, they were quite different.

Here is now the explanation:

The output from strace showed:


gettimeofday({1159440978, 931945}, NULL) = 0
pread(14, "\6\242\0\0\375\23\0\2+\254.\0\0\0\1\6\0054\0\0\1\0\5\0"..., 8192, 455 057408) = 8192
gettimeofday({1159440978, 944159}, NULL) = 0



Oracle records time just before performing a system call (pread). When the system call completes Oracle again records the current time and the difference reports as a wait time. Unfortunately due to high CPU load the process was for quite a while waiting at the system level to get on CPU and only then was able to read the current time and therefore the reported elapsed time was quite exaggerated.


Conclusion: Waiting in runque for CPU exaggerates all wait times of the process.

It is always a good practice to confirm findings with a different method. In this case I could use also the operating system tools to measure I/O timings. The same situation one can have on any other kind of wait event but there is not always a possibility to check it independently.

Finally, there was not really an I/O problem but the system was quite CPU bound. Of course the average single block I/O time over 5 - 10 ms shows that probably we are experiencing also I/O bottleneck. The customer later on replaced disk storage with a faster one together with the HW used for RAC.

Thursday 3 December 2009

V$SQL_MONITOR and V$SQL_PLAN_MONITOR

In my recent presentation at UKOUG 2009 in Birmingham I also mentioned the new feature of Oracle11gR1 which is a neat solution for monitoring long running SQL statements. It captures statistics about SQL execution every second.

For parallel execution every process involved gets separate entries in V$SQL_MONITOR and V$SQL_PLAN_MONITOR.

It is enabled by default for long running statements if parameter CONTROL_MANAGEMENT_PACK_ACCESS if it is set to “DIAGNOSTIC+TUNING” and STATISTICS_LEVEL=ALL|TYPICAL

It can be enabled at statement level as well with /*+ MONITOR */ hint or disabled with /*+ NO_MONITOR */ hint.

There are some defaults defined which can be altered by setting hidden parameters:
_sqlmon_max_plan - Maximum number of plans entries that can be monitored. Defaults to 20 per CPU
_sqlmon_max_planlines - Number of plan lines beyond which a plan cannot be monitored (default 300)

Just for demonstration purposes I used a simple performance killing statement which runs quite for a while and could be used to test this new feature.



SQL_ID b0zm3w4h1hbff, child number 0
-------------------------------------
select count(*) from obj$,obj$,obj$ --performance killer

Plan hash value: 3679021907

----------------------------------------------------
| Id | Operation | Name | E-Rows |
----------------------------------------------------
| 1 | SORT AGGREGATE | | 1 |
| 2 | MERGE JOIN CARTESIAN | | 341T|
| 3 | MERGE JOIN CARTESIAN | | 4886M|
| 4 | INDEX FAST FULL SCAN | I_OBJ1 | 69901 |
| 5 | BUFFER SORT | | 69901 |
| 6 | INDEX FAST FULL SCAN| I_OBJ1 | 69901 |
| 7 | BUFFER SORT | | 69901 |
| 8 | INDEX FAST FULL SCAN | I_OBJ1 | 69901 |
----------------------------------------------------

SQL> SELECT status, KEY, SID, sql_id, elapsed_time, cpu_time, fetches, buffer_gets,
2 disk_reads
3 FROM v$sql_monitor where sql_id='b0zm3w4h1hbff';

STATUS KEY SID SQL_ID ELAPSED_TIME CPU_TIME FETCHES BUFFER_GETS DISK_READS
--------- ----------- --- ------------- ------------ ---------- ------- ----------- ----------
EXECUTING 21474836481 170 b0zm3w4h1hbff 674281628 624578125 0 0 0

SQL> SELECT plan_line_id, plan_operation || ' ' || plan_options operation,
2 starts, output_rows
3 FROM v$sql_plan_monitor where key=21474836481
4 ORDER BY plan_line_id;

PLAN_LINE_ID OPERATION STARTS OUTPUT_ROWS
------------ --------------------- ---------- -----------
0 SELECT STATEMENT 1 0
1 SORT AGGREGATE 1 0
2 MERGE JOIN CARTESIAN 1 4283731363
3 MERGE JOIN CARTESIAN 1 156731
4 INDEX FAST FULL SCAN 1 3
5 BUFFER SORT 3 156731
6 INDEX FAST FULL SCAN 1 70088
7 BUFFER SORT 156731 4283731363
8 INDEX FAST FULL SCAN 1 70088

The above result I got after running this statement for about 10 minutes. There are of course more statistics available which I have omitted here as they were useless for my demo case which had all data already in buffer cache.

One can use DBMS_SQLTUNE.REPORT_SQL_MONITOR() function to produce a formatted report of monitoring results. Unfortunately the below report is too wide to be cleary seen. I got it for a statement run by DBMS_STATS package


SQL> set long 10000000
SQL> set longchunksize 10000000
SQL> set linesize 200
SQL> select dbms_sqltune.report_sql_monitor from dual;

SQL Monitoring Report

SQL Text
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
select /*+ no_parallel_index(t, "I_WRI$_OPTSTAT_H_OBJ#_ICOL#_ST") dbms_stats cursor_sharing_exact use_weak_name_resl dynamic_sampling(0) no_monitoring no_expand
index(t,"I_WRI$_OPTSTAT_H_OBJ#_ICOL#_ST") */ count(*) as nrw,count(distinct sys_op_lbid(461,'L',t.rowid)) as nlb,count(distinct
hextoraw(sys_op_descend("OBJ#")||sys_op_descend("INTCOL#")||sys_op_descend(SYS_EXTRACT_UTC("SAVTIME"))||sys_op_descend("COLNAME"))) as ndk,sys_op_countchg(substrb(t.rowid,1,15),1)
as clf from "SYS"."WRI$_OPTSTAT_HISTGRM_HISTORY" t where "OBJ#" is not null or "INTCOL#" is not null or SYS_EXTRACT_UTC("SAVTIME") is not null or "COLNAME" is not null
-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

Global Information

Status : DONE (ALL ROWS)
Instance ID : 1
Session ID : 127
SQL ID : 1d7qn8b9wam8h
SQL Execution ID : 16777216
Plan Hash Value : 3428983716
Execution Started : 12/04/2009 01:09:20
First Refresh Time : 12/04/2009 01:09:28
Last Refresh Time : 12/04/2009 01:09:30

--------------------------------------------------------------------
| Elapsed | Cpu | IO | Other | Fetch | Buffer | Reads |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Calls | Gets | |
--------------------------------------------------------------------
| 8.65 | 1.94 | 6.58 | 0.13 | 1 | 1327 | 694 |
--------------------------------------------------------------------


SQL Plan Monitoring Details
=========================================================================================================================================================================
| Id | Operation | Name | Rows | Cost | Time | Start | Starts | Rows | Memory | Activity | Activity Detail |
| | | | (Estim) | | Active(s) | Active | | (Actual) | (Max) | (percent) | (sample #) |
=========================================================================================================================================================================
| 0 | SELECT STATEMENT | | | 1026 | 1 | +10 | 1 | 1 | 274K | | |
| 1 | SORT GROUP BY | | 1 | | 6 | +5 | 1 | 1 | 274K | 37.50 | Cpu (3) |
| 2 | INDEX FULL SCAN | I_WRI$_OPTSTAT_H_OBJ#_ICOL#_ST | 179K | 1026 | 8 | +3 | 1 | 179K | | 62.50 | db file sequential read (5) |
=========================================================================================================================================================================

Saturday 28 November 2009

My interview at Miracle Open World 2008 in Lalandia, Denmark

Just for fun I post here two videos related to my presentation at Miracle Open World 2008 in Lalandia, Denmark. I had a presentation titled "Cost Based Optimizer Falacies Caused By The Application Design".
This is a short video where I announce my presentation at Miracle Open World 2008. I took this video while I was baking pizzas for my grandchildren. The oven is homemade and if you are interested you can see more details how I have built it.



After the presentation I was interviewed by Mogens Norgard and if you know him then you can expect that he was trying to make this short interview very amusing.

Tuesday 24 November 2009

RMOUG Training days 2010

I'm very proud to participate again in one of the greates conferences on the world - RMOUG Training Days 2010, February 16-18, 2010 at Denver, Colorado, USA.

You can find the conference agenda here.

I will have two presentations:

1.) Rman Tips

2.) Services - Why Should One Use Them?

UKOUG 2009


UKOUG 2009 conference will take place next week in Birmingham. I will speak on Wednesday, December 2nd about "Execution Plan Stability in Oracle11g". As the audience at UKOUG conference is very technical I will add more technical stuff to my presentation this week.

Here is the link for for the conference agenda.

On Sunday evening I will attend Oracle ACE dinner for the first time. I'm looking forward to meet some new people there although most of them I know already from OakTable or from other conference events.

Table Expressions, Cardinality, SYS_OP_ATG and KOKBF$

Recently I was involved in discussion on OTN form (see http://forums.oracle.com/forums/thread.jspa?threadID=986657)
and I found an interesting information inside the posted execution plan which was in "Predicate information" section and was

filter(SYS_OP_ATG(VALUE(KOKBF$),2,3,2)='HQPRM003')


Googling showed some interesting information in Vlad Sadilovski's blog that KOKBF$ is a generic alias given the table expressions. What was more interesting was undocumented SYS_OP_ATG function which attracted my interest. So I decided to create a simple case to observe what is going on.


SQL> CREATE TYPE demo_object AS OBJECT
2 ( ID NUMBER(6)
3 , first_name VARCHAR2(30)
4 , last_name VARCHAR2(20));
5 /

Type created.

SQL> create type demo_object_t as AS TABLE OF demo_object;
2 /

Type created.

SQL> CREATE or replace FUNCTION demo_func( p_num_rows number )
2 RETURN demo_object_t
3 as
4 r_demo_object_t demo_object_t;
5 BEGIN
6 SELECT demo_object(rownum,dbms_random.string('k',30), dbms_random.string('k',20))
7 BULK COLLECT INTO r_demo_object_t
8 FROM dual connect by level <= p_num_rows;
9 RETURN r_demo_object_t;
10 END;
11 /

Function created.

SQL> select * from table(demo_func(10));

ID FIRST_NAME LAST_NAME
---------- ------------------------------ --------------------
1 POXXOPVQXYPXUIGCQLVBWLNXXLUEQC JAIAUCWHIMCRRJQXWUJY
2 SVYYKMZRBERFQFZKAQQOOSDNKMIJSG JMAOAUMHSWGNMYRCBSAG
3 LKNMLDIGIDTJECSRZDNSGHECNGVEFL TUUFTVPIVIXGRWYZFMCF
4 UIAEJZRIRROBBCINFTKNAXJEPFGKPP LPNGQCTLNLMEJWLGTWQJ
5 MGKMJJOHOZPCYEXEDVOWYSYUJMDDBF PTQACVZBNFCJOMQKJNRA
6 DSOODWTOPLPDAFZRXXGKKGECIPCHHB MHWPUTQJOSGOFOKCALJW
7 VTTVCLHRWLXGVMAKWQPOJDMLYUIEOS MXABXPTDHQENPKEHYCFZ
8 QJPWITNBARETOWMUVOQHABEEYNKLOD UYOEOUROCXHXXVNQILYU
9 PZDJEPXAHXXIAOVTOGKPSCMNDORNQX IZLRNYOLEWSPWDMCQMCY
10 FBOKISOVXUNFASOLGOZZPGVHSEFDAG MXOEIQSZMLTBREPGBDSM

10 rows selected.



So now we are ready to see what is going on.


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

Plan hash value: 2056388305

-----------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-----------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 8168 | 16336 | 29 (0)| 00:00:01 |
| 1 | COLLECTION ITERATOR PICKLER FETCH| DEMO_FUNC | | | | |
-----------------------------------------------------------------------------------------------


The estimated cardinality is 8168 rows what is a default value used for 8k block size.
The actual cardinality was 10 rows. With additional condition id=8 the estimate changes to 82 rows.


SQL> explain plan for
2 select a.id, a.first_name,a.last_name
3 from table(demo_func(10)) a
4 where a.id = 8;

Explained.

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

Plan hash value: 2056388305

-----------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-----------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 82 | 164 | 29 (0)| 00:00:01 |
|* 1 | COLLECTION ITERATOR PICKLER FETCH| DEMO_FUNC | | | | |
-----------------------------------------------------------------------------------------------

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

1 - filter(SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=8)


I wanted to correct the cardinality estimate and I used undocumented hint CARDINALITY which is available since Oracle9i.


SQL> explain plan for
2 select /*+ cardinality( a 1 ) */ a.id, a.first_name,a.last_name
3 from table(demo_func(10)) a
4 where a.id = 8;

Explained.

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

Plan hash value: 2056388305

-----------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-----------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 2 | 29 (0)| 00:00:01 |
|* 1 | COLLECTION ITERATOR PICKLER FETCH| DEMO_FUNC | | | | |
-----------------------------------------------------------------------------------------------

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

1 - filter(SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=8)


I also used event 10053 to get CBO trace and there I found the following information:


SQL> alter session set events '10053 trace name context forever';

Session altered.

SQL> explain plan for
2 select /*+ cardinality( a 1 ) */ a.id, a.first_name,a.last_name
3 from table(demo_func(10)) a
4 where a.id = 8;

Explained.

SQL> alter session set events '10053 trace name context off';



***************************************
BASE STATISTICAL INFORMATION
***********************
Table Stats::
Table: KOKBF$ Alias: KOKBF$ (NOT ANALYZED)
#Rows: 8168 #Blks: 100 AvgRowLen: 100.00
Access path analysis for KOKBF$
***************************************
SINGLE TABLE ACCESS PATH
Single Table Cardinality Estimation for KOKBF$[KOKBF$]
Table: KOKBF$ Alias: KOKBF$
Card: Original: 8168.000000 >> Single Tab Card adjusted from:81.680000 to:1.000000
Rounded: 1 Computed: 1.00 Non Adjusted: 81.68
Access Path: TableScan
Cost: 29.29 Resp: 29.29 Degree: 0
Cost_io: 29.00 Cost_cpu: 6429744
Resp_io: 29.00 Resp_cpu: 6429744
Best:: AccessPath: TableScan
Cost: 29.29 Degree: 1 Resp: 29.29 Card: 1.00 Bytes: 0

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


My next experiment was creating a join between two row sets returned by the function and I have used the cardinality hint again.


SQL> explain plan for
2 select /*+ cardinality(a 1) cardinality (b 1 ) */ a.id, a.first_name,a.last_name
3 from table(demo_func(10)) a, table(demo_func(10)) b
4 where a.id = 8
5 and a.id = b.id;

Explained.

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

Plan hash value: 2170227849

------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 4 | 59 (2)| 00:00:01 |
|* 1 | HASH JOIN | | 1 | 4 | 59 (2)| 00:00:01 |
|* 2 | COLLECTION ITERATOR PICKLER FETCH| DEMO_FUNC | | | | |
|* 3 | COLLECTION ITERATOR PICKLER FETCH| DEMO_FUNC | | | | |
------------------------------------------------------------------------------------------------

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


1 - access(SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=SYS_OP_ATG(VALUE(KOKBF$),1,2,2))
2 - filter(SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=8)
3 - filter(SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=8)


In the CBO trace file I found this interesting piece of information where the SQL was
transformed in the following way:


SELECT /*+ OPT_ESTIMATE (TABLE "B" ROWS=1.000000 ) OPT_ESTIMATE (TABLE "A" ROWS=1.000000 ) */
"A"."SYS_NC_ROWINFO$"."ID" "ID",
"A"."SYS_NC_ROWINFO$"."FIRST_NAME" "FIRST_NAME",
"A"."SYS_NC_ROWINFO$"."LAST_NAME" "LAST_NAME"
FROM (SELECT VALUE (kokbf$) "SYS_NC_ROWINFO$"
FROM TABLE ("JOC"."DEMO_FUNC" (10)) "KOKBF$") "A",
(SELECT VALUE (kokbf$) "SYS_NC_ROWINFO$"
FROM TABLE ("JOC"."DEMO_FUNC" (10)) "KOKBF$") "B"
WHERE "A"."SYS_NC_ROWINFO$"."ID" = 8
AND "A"."SYS_NC_ROWINFO$"."ID" = "B"."SYS_NC_ROWINFO$"."ID"

Query block SEL$1 (#0) unchanged
PL/SQL function (DEMO_FUNC) is not secure.


Here CBO transformed CARDINALITY hint to a new undocumented hint used in SQL Profiles
OPT_ESTIMATE (TABLE "B" ROWS=1.000000 ) which does exactly the same -
scales down the number of rows to 1 in this case.

Another very interesting piece of information here is how the statement is internally transformed to use SYS_NC_ROWINFO$ which is a virtual column that references the row XMLType instance and is there since Oracle9i. In later releases this was replaced with a new OBJECT_VALUE pseudo column but obviousl CBO still uses that internally (for more details see "Oracle Database SQL Language Reference")

There was also other interesting transformation present which was:


SELECT /*+ OPT_ESTIMATE (TABLE "KOKBF$" ROWS=1.000000 ) OPT_ESTIMATE (TABLE "KOKBF$" ROWS=1.000000 ) */
sys_op_atg (VALUE (kokbf$), 1, 2, 0) "ID",
sys_op_atg (VALUE (kokbf$), 2, 3, 0) "FIRST_NAME",
sys_op_atg (VALUE (kokbf$), 3, 4, 0) "LAST_NAME"
FROM TABLE ("JOC"."DEMO_FUNC" (10)) "KOKBF$",
TABLE ("JOC"."DEMO_FUNC" (10)) "KOKBF$"
WHERE sys_op_atg (VALUE (kokbf$), 1, 2, 0) = 8
AND sys_op_atg (VALUE (kokbf$), 1, 2, 0) = sys_op_atg (VALUE (kokbf$), 1, 2, 0)

Query block SEL$2B5797BE (#0) unchanged
query block SEL$1 transformed to SEL$2B5797BE (#0)
Considering Query Transformations on query block SEL$2B5797BE (#0)
**************************
Query transformations (QT)
**************************
CBQT: copy not possible on query block SEL$2B5797BE (#0) because nested table
CBQT bypassed for query block SEL$2B5797BE (#0): Cannot copy query block.


Here Oracle uses undocumented function sys_op_atg which returns a column from object type.
The first parameter specifies the starting column, the second one specifies the ending column and for the third parameter I was not able to figure out what does it mean. In all cases which I have found on Interenet or in Oracle manuals this parameter had always value of 2.

Then CBO was trying to push the filter condition inside function execution what was of course not possible.

FPD: Considering simple filter push in query block SEL$2B5797BE (#0)


In next step CBO generated transitive predicate which could be observed under the "Predicate Information" section of execution plan.


SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=8 AND SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=SYS_OP_ATG(VALUE(KOKBF$),1,2,2)
try to generate transitive predicate from check constraints for query block SEL$2B5797BE (#0)
finally: SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=8 AND SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=SYS_OP_ATG(VALUE(KOKBF$),1,2,2) AND SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=8

FPD: transitive predicates are generated in query block SEL$2B5797BE (#0)
SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=8


From my presentation at IUOG back in 2005 about the Extensible optimizer I used the trick to associate the function with statistics type. Of course I could use also DYNAMIC_SAMPLING but this is more elegant way. Here is what I have done:


SQL> CREATE OR REPLACE TYPE demo_func_stats_type AS OBJECT (
2 dummy_attribute NUMBER,
3 STATIC FUNCTION odcigetinterfaces (p_interfaces OUT SYS.odciobjectlist)
4 RETURN NUMBER,
5 STATIC FUNCTION odcistatstablefunction (
6 p_function IN SYS.odcifuncinfo,
7 p_stats OUT SYS.odcitabfuncstats,
8 p_args IN SYS.odciargdesclist,
9 p_num_rows IN NUMBER
10 )
11 RETURN NUMBER
12 );
13 /

Type created.

SQL> CREATE OR REPLACE TYPE BODY demo_func_stats_type AS
2 STATIC FUNCTION odcigetinterfaces (p_interfaces OUT SYS.odciobjectlist)
3 RETURN NUMBER IS
4 BEGIN
5 p_interfaces :=
6 SYS.odciobjectlist (SYS.odciobject ('SYS', 'ODCISTATS2'));
7 RETURN odciconst.success;
8 END odcigetinterfaces;
9 STATIC FUNCTION odcistatstablefunction (
10 p_function IN SYS.odcifuncinfo,
11 p_stats OUT SYS.odcitabfuncstats,
12 p_args IN SYS.odciargdesclist,
13 p_num_rows IN NUMBER
14 )
15 RETURN NUMBER IS
16 BEGIN
17 p_stats := SYS.odcitabfuncstats (p_num_rows);
18 RETURN odciconst.success;
19 END odcistatstablefunction;
20 END;
21 /

Type body created.

SQL> explain plan for
2 select a.id, a.first_name,a.last_name
3 from table(demo_func(10)) a, table(demo_func(1000)) b
4 where a.id = 8
5 and a.id = b.id;

Explained.

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

Plan hash value: 2170227849

------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 67 | 268 | 59 (2)| 00:00:01 |
|* 1 | HASH JOIN | | 67 | 268 | 59 (2)| 00:00:01 |
|* 2 | COLLECTION ITERATOR PICKLER FETCH| DEMO_FUNC | | | | |
|* 3 | COLLECTION ITERATOR PICKLER FETCH| DEMO_FUNC | | | | |
------------------------------------------------------------------------------------------------

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


1 - access(SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=SYS_OP_ATG(VALUE(KOKBF$),1,2,2))
2 - filter(SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=8)
3 - filter(SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=8)



Here we can see that the cardinality estimate is quite off - it should be 1. Therefore I now use my statistics type and associate it with demo_func.


SQL> associate statistics with functions demo_func using demo_func_stats_type;

Statistics associated.

SQL> explain plan for
2 select a.id, a.first_name,a.last_name
3 from table(demo_func(10)) a, table(demo_func(1000)) b
4 where a.id = 8
5 and a.id = b.id;

Explained.

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

Plan hash value: 2170227849

------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 4 | 59 (2)| 00:00:01 |
|* 1 | HASH JOIN | | 1 | 4 | 59 (2)| 00:00:01 |
|* 2 | COLLECTION ITERATOR PICKLER FETCH| DEMO_FUNC | | | | |
|* 3 | COLLECTION ITERATOR PICKLER FETCH| DEMO_FUNC | | | | |
------------------------------------------------------------------------------------------------

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


1 - access(SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=SYS_OP_ATG(VALUE(KOKBF$),1,2,2))
2 - filter(SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=8)
3 - filter(SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=8)


As we can see the CBO now correctly estimates the number of rows.
In the CBO trace file we can find the following information:


***************************************
BASE STATISTICAL INFORMATION
***********************
Table Stats::
Table: KOKBF$ Alias: KOKBF$ (NOT ANALYZED)
#Rows: 8168 #Blks: 100 AvgRowLen: 100.00
***********************
Table Stats::
Table: KOKBF$ Alias: KOKBF$ (NOT ANALYZED)
#Rows: 8168 #Blks: 100 AvgRowLen: 100.00
Access path analysis for KOKBF$
***************************************
SINGLE TABLE ACCESS PATH
Single Table Cardinality Estimation for KOKBF$[KOKBF$]
Calling user-defined function card function...
Bind :3 Value 10
JOC.DEMO_FUNC_STATS_TYPE.ODCIStatsTableFunction returned:
num_rows : 10
Table: KOKBF$ Alias: KOKBF$
Card: Original: 10.000000 Rounded: 1 Computed: 0.10 Non Adjusted: 0.10
Access Path: TableScan
Cost: 29.29 Resp: 29.29 Degree: 0
Cost_io: 29.00 Cost_cpu: 6429744
Resp_io: 29.00 Resp_cpu: 6429744
Best:: AccessPath: TableScan
Cost: 29.29 Degree: 1 Resp: 29.29 Card: 0.10 Bytes: 0

Access path analysis for KOKBF$
***************************************
SINGLE TABLE ACCESS PATH
Single Table Cardinality Estimation for KOKBF$[KOKBF$]
Calling user-defined function card function...
Bind :3 Value 1000
JOC.DEMO_FUNC_STATS_TYPE.ODCIStatsTableFunction returned:
num_rows : 1000
Table: KOKBF$ Alias: KOKBF$
Card: Original: 1000.000000 Rounded: 10 Computed: 10.00 Non Adjusted: 10.00
Access Path: TableScan
Cost: 29.29 Resp: 29.29 Degree: 0
Cost_io: 29.00 Cost_cpu: 6429744
Resp_io: 29.00 Resp_cpu: 6429744
Best:: AccessPath: TableScan
Cost: 29.29 Degree: 1 Resp: 29.29 Card: 10.00 Bytes: 0

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


As we can see the user-defined statistics function which CBO calls during the optimization phase resolves the problem of erroneously determined cardinality.

One can disassociate statistics with the following command:

SQL> disassociate statistics from functions demo_func;

Statistics disassociated.


Now we can check what is going on in run time. We use gather_plan_statistics hint on statement level to gather all execution statistics.


SQL> select /*+ gather_plan_statistics */ a.id, a.first_name,a.last_name
2 from table(demo_func(10)) a,
3 table(demo_func(1000)) b
4 where a.id = 8
5 and a.id = b.id;

ID FIRST_NAME LAST_NAME
---------- ------------------------------ --------------------
8 EMRFXDHQISONDDVTYLMPQDRDIWAHMG BMUUKQWCUCKBYGGKMBEM


SQL> select * from table(dbms_xplan.display_cursor(NULL,NULL, 'allstats last'));

SQL_ID 4kyvk4q692gqu, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ a.id, a.first_name,a.last_name
from table(demo_func(10)) a, table(demo_func(1000)) b where a.id = 8
and a.id = b.id

Plan hash value: 2170227849

----------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers |
----------------------------------------------------------------------------------------------------------
|* 1 | HASH JOIN | | 1 | 1 | 1 |00:00:00.14 | 3 |
|* 2 | COLLECTION ITERATOR PICKLER FETCH| DEMO_FUNC | 1 | | 1 |00:00:00.01 | 3 |
|* 3 | COLLECTION ITERATOR PICKLER FETCH| DEMO_FUNC | 1 | | 1 |00:00:00.14 | 0 |
----------------------------------------------------------------------------------------------------------

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

1 - access(SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=SYS_OP_ATG(VALUE(KOKBF$),1,2,2))
2 - filter(SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=8)
3 - filter(SYS_OP_ATG(VALUE(KOKBF$),1,2,2)=8)


From this plan we can see that each row source is returned by "COLLECTION ITERATOR PICKLER FETCH" and that function DEMO_FUNC is executed only once (Starts = 1).

Of course there is no chance to push predicate as a.id=b.id and a.id=8 inside the function execution. Therefore Oracle has to use SYS_OP_ATG function to decompose returned object and perform the join operation only after function calls complete there execution.

We can see that this could be very inefficient. To resolve the possible performance issues one should not use functions (this is true also for pipelined functions) if the function result is used in later join operations or the majority of returned rows is filtered out later on. One possible solution would be to pass some conditions as function parameters, but the best solution is to replace a function call with inline view which contains the query used inside function. Then the CBO has more possibility and place for optimization and can optimize the whole statement.

If I return back to the origin for this post - we got the best result when we had replaced function call with inline view containing the query from the function. The CBO can't really push any kind of predicates inside the function call and the only possibility is to use function parameter for passing them.

This was also a good example to point out the problems of cardinality estimates for table functions and how one can use extensible optimizer to resolve it.

Friday 6 November 2009

Scandinavian Trip

This week I was presenting at two Oracle User Group conferences - one in Sweden and the other one in Finland.
It was the first time for me to be in Sweden and therefore I had no experience with this country. I was planning to fly by myself but the rainy/snowy weather in Scandinavia and also across all Europe prevented me to do so.
I was in Finland several times before and this was the first time I was presenting at their Oracle users group.
Both events were nicely organized and especially in Finland I had met a lot of known people and I had a great time at the speakers dinner the evening before conference and through the whole conference as well.

Starting Oracle Blog

Quite a long time ago I was tempted to start blogging about Oracle and then I decided just not to do that but rather I started to blog about my flying around Europe to present at Oracle conferences. However, I created the blog but never activated. The nomination for Oracle ACE changed this decision and I'll try to write about technical stuff from time to time, but don't expect that I will be so active as some of Oracle bloggers.