Wednesday, July 13, 2011

Peeking of User Defined Bind variables 10GR2 and 11GR2

Not something entirely learned new today - but rather revisited "something I learned". Its all about Bind in 10G and 11G database.

I will set up a very skewed set of data for emphasis.

rajesh@ORA10GR2> create table t
  2  as
  3  select case when rownum = 1 then 1 else 99 end as id,
  4        a.*
  5  from all_objects a;

Table created.

Elapsed: 00:00:03.07
rajesh@ORA10GR2>
rajesh@ORA10GR2> create index t_ind on t(id) nologging;

Index created.

Elapsed: 00:00:00.39
rajesh@ORA10GR2>
rajesh@ORA10GR2> begin
  2     dbms_stats.gather_table_stats(
  3     ownname =>user,
  4     tabname =>'T',
  5     estimate_percent=>100,
  6     method_opt=>'for all indexed columns size 254');
  7  end;
  8  /

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.28
rajesh@ORA10GR2>

So, its clear that WHERE id=1 it will return one record and WHERE id=99 it will return all the rest. Also the optimizer is aware of this fact due to histograms in place.

Now, lets see what happens if we parse the query using literals.

rajesh@ORA10GR2> set autotrace traceonly explain statistics;
rajesh@ORA10GR2> select *
  2  from t
  3  where id = 1;

Elapsed: 00:00:00.00

Execution Plan
----------------------------------------------------------
Plan hash value: 1376202287
-------------------------------------------------------------------------------------
| Id  | Operation                   | Name  | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |       |     1 |    96 |     2   (0)| 00:00:01 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T     |     1 |    96 |     2   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | T_IND |     1 |       |     1   (0)| 00:00:01 |
-------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   2 - access("ID"=1)

Statistics
----------------------------------------------------------
         44  recursive calls
          0  db block gets
          8  consistent gets
          0  physical reads
          0  redo size
       1252  bytes sent via SQL*Net to client
        396  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

rajesh@ORA10GR2>
rajesh@ORA10GR2> select *
  2  from t
  3  where id = 99;

50086 rows selected.

Elapsed: 00:00:00.21

Execution Plan
----------------------------------------------------------
Plan hash value: 1601196873
--------------------------------------------------------------------------
| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      | 50082 |  4695K|   166   (4)| 00:00:02 |
|*  1 |  TABLE ACCESS FULL| T    | 50082 |  4695K|   166   (4)| 00:00:02 |
--------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter("ID"=99)

Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
       1046  consistent gets
          0  physical reads
          0  redo size
    2045094  bytes sent via SQL*Net to client
       4059  bytes received via SQL*Net from client
        335  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
      50086  rows processed

rajesh@ORA10GR2> set autotrace off;

We see two different plans for two different literals.

But what happens if we use binds select * from t where id = :id during hard parsing Oracle will wait for the bind value to be supplied before figuring out the right way to optimize the query. This is called Bind Variable Peeking.

rajesh@ORA10GR2> exec :x := 99;

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.00
rajesh@ORA10GR2>
rajesh@ORA10GR2> select * from t
  2  where id = :x;

50086 rows selected.

Elapsed: 00:00:00.23
Execution Plan
----------------------------------------------------------
Plan hash value: 1601196873
--------------------------------------------------------------------------
| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      | 50087 |  4695K|   167   (4)| 00:00:03 |
|*  1 |  TABLE ACCESS FULL| T    | 50087 |  4695K|   167   (4)| 00:00:03 |
--------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter("ID"=TO_NUMBER(:X))

Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
       1046  consistent gets
          0  physical reads
          0  redo size
    2045094  bytes sent via SQL*Net to client
       4059  bytes received via SQL*Net from client
        335  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
      50086  rows processed

rajesh@ORA10GR2>

We started off with a id=99  as a bind and Full tablescan was choosen with 1046 Logical IOs

rajesh@ORA10GR2> exec :x := 1;

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.00
rajesh@ORA10GR2>
rajesh@ORA10GR2> select * from t
  2  where id = :x;

Elapsed: 00:00:00.00

Execution Plan
----------------------------------------------------------
Plan hash value: 1601196873
--------------------------------------------------------------------------
| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      | 50087 |  4695K|   167   (4)| 00:00:03 |
|*  1 |  TABLE ACCESS FULL| T    | 50087 |  4695K|   167   (4)| 00:00:03 |
--------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter("ID"=TO_NUMBER(:X))

Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
        716  consistent gets
          0  physical reads
          0  redo size
       1252  bytes sent via SQL*Net to client
        396  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

rajesh@ORA10GR2>

Now, for the bind id=1 Oracle has reused the same explain plan used for id=99 and went for 716 Logical IOs. We can turn on the sql_trace and see the performance characterstic of this query.

rajesh@ORA10GR2> alter session set sql_trace=true;

Session altered.

Elapsed: 00:00:00.07
rajesh@ORA10GR2>
rajesh@ORA10GR2> print x;

      X
----------
         1

rajesh@ORA10GR2>
rajesh@ORA10GR2> set autotrace traceonly statistics;
rajesh@ORA10GR2>
rajesh@ORA10GR2> select * from t
  2  where id = :x;

Elapsed: 00:00:00.04

Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
          4  consistent gets
          0  physical reads
          0  redo size
       1252  bytes sent via SQL*Net to client
        396  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

rajesh@ORA10GR2>

If you turn off the sql_trace you will see this.

rajesh@ORA10GR2> alter session set sql_trace=false;

Session altered.

Elapsed: 00:00:00.01
rajesh@ORA10GR2> select * from t
  2  where id = :x;

Elapsed: 00:00:00.01

Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
        716  consistent gets
          0  physical reads
          0  redo size
       1252  bytes sent via SQL*Net to client
        396  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

rajesh@ORA10GR2>

Again turning on the sql_trace, went for 4 IOs

rajesh@ORA10GR2> alter session set sql_trace=true;

Session altered.

Elapsed: 00:00:00.01
rajesh@ORA10GR2>
rajesh@ORA10GR2> select * from t
  2  where id = :x;

Elapsed: 00:00:00.00

Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
          4  consistent gets
          0  physical reads
          0  redo size
       1252  bytes sent via SQL*Net to client
        396  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

rajesh@ORA10GR2>

This beviour of bind peeking is changed in Oracle 11G with the introduction of Adaptive cursor sharing.

rajesh@ORA11GR2> set autotrace traceonly statistics;
rajesh@ORA11GR2> variable x number;
rajesh@ORA11GR2> exec :x := 99;

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.00
rajesh@ORA11GR2> select * from t
  2  where id = :x;

Statistics
----------------------------------------------------------
         44  recursive calls
          0  db block gets
       1533  consistent gets
          0  physical reads
          0  redo size
    2895013  bytes sent via SQL*Net to client
       5662  bytes received via SQL*Net from client
        479  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
      71655  rows processed

rajesh@ORA11GR2>
rajesh@ORA11GR2> exec :x := 1;

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.01
rajesh@ORA11GR2>
rajesh@ORA11GR2> select * from t
  2  where id = :x;

Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
       1057  consistent gets
          0  physical reads
          0  redo size
       1448  bytes sent via SQL*Net to client
        415  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

The optimizer had made the mistake and reused the same plan it used for id=99 on re-running the query again, Adaptive cursor sharing will kick start and you see this.

rajesh@ORA11GR2> /

Elapsed: 00:00:00.03

Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
          4  consistent gets
          0  physical reads
          0  redo size
       1451  bytes sent via SQL*Net to client
        415  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

rajesh@ORA11GR2>

And looking at the shared pool it shows me this.

rajesh@ORA11GR2> exec print_table(' select sql_text,sql_id,child_number,executions,buffer_gets,is_bind_sensitive,is_bind_aware,IS_SHAREABLE from v$sql where sql_text like ''select *
 from t where id = :x''');

     SQL_TEXT------------ select * from t where id = :x
     SQL_ID-------------- 9pn7r50tytugm
     CHILD_NUMBER-------- 0
     EXECUTIONS---------- 2
     BUFFER_GETS--------- 2590
     IS_BIND_SENSITIVE--- Y
     IS_BIND_AWARE------- N
     IS_SHAREABLE-------- Y

--------------------------------------------
     SQL_TEXT------------ select * from t where id = :x
     SQL_ID-------------- 9pn7r50tytugm
     CHILD_NUMBER-------- 1
     EXECUTIONS---------- 1
     BUFFER_GETS--------- 4
     IS_BIND_SENSITIVE--- Y
     IS_BIND_AWARE------- Y
     IS_SHAREABLE-------- Y

--------------------------------------------

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.12
rajesh@ORA11GR2>

So the possible solutions in 10G database is to don't gather Histograms that cause the plan to change.

rajesh@ORA10GR2>
rajesh@ORA10GR2> create table t
  2  nologging
  3  as
  4  select case when rownum = 1 then 1 else 99 end as id,
  5        a.*
  6  from all_objects a;

Table created.

Elapsed: 00:00:03.65
rajesh@ORA10GR2>
rajesh@ORA10GR2> create index t_ind on t(id) nologging;

Index created.

Elapsed: 00:00:00.31
rajesh@ORA10GR2>
rajesh@ORA10GR2> begin
  2     dbms_stats.gather_table_stats(
  3     ownname =>user,
  4     tabname =>'T',
  5     estimate_percent=>100,
  6     method_opt=>'for all indexed columns size repeat');
  7  end;
  8  /

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.17
rajesh@ORA10GR2>
rajesh@ORA10GR2> set autotrace traceonly statistics;
rajesh@ORA10GR2>
rajesh@ORA10GR2> select * from t where id = 99;

Statistics
----------------------------------------------------------
         44  recursive calls
          0  db block gets
       1050  consistent gets
          0  physical reads
          0  redo size
    2049496  bytes sent via SQL*Net to client
       4070  bytes received via SQL*Net from client
        336  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
      50127  rows processed

rajesh@ORA10GR2> select * from t where id = 1;

Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
        716  consistent gets
          0  physical reads
          0  redo size
       1252  bytes sent via SQL*Net to client
        396  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

rajesh@ORA10GR2> variable x number;
rajesh@ORA10GR2> exec :x := 99;

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.00
rajesh@ORA10GR2> select * from t where id = :x;

Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
       1046  consistent gets
          0  physical reads
          0  redo size
    2049496  bytes sent via SQL*Net to client
       4070  bytes received via SQL*Net from client
        336  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
      50127  rows processed

rajesh@ORA10GR2> exec :x := 1;

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.01
rajesh@ORA10GR2> select * from t where id = :x;

Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
        716  consistent gets
          0  physical reads
          0  redo size
       1252  bytes sent via SQL*Net to client
        396  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

rajesh@ORA10GR2>
rajesh@ORA10GR2> alter session set sql_trace=true;

Session altered.

Elapsed: 00:00:00.01
rajesh@ORA10GR2> select * from t where id = :x;

Statistics
----------------------------------------------------------
          1  recursive calls
          0  db block gets
        716  consistent gets
          0  physical reads
          0  redo size
       1252  bytes sent via SQL*Net to client
        396  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

rajesh@ORA10GR2> alter session set sql_trace=false;

Session altered.

Elapsed: 00:00:00.01
rajesh@ORA10GR2> select * from t where id = :x;

Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
        716  consistent gets
          0  physical reads
          0  redo size
       1252  bytes sent via SQL*Net to client
        396  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

rajesh@ORA10GR2> alter session set sql_trace=true;

Session altered.

Elapsed: 00:00:00.07
rajesh@ORA10GR2> select * from t where id = :x;

Elapsed: 00:00:00.06

Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
        716  consistent gets
          0  physical reads
          0  redo size
       1252  bytes sent via SQL*Net to client
        396  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
          1  rows processed

rajesh@ORA10GR2>

The another solution is to change cursor_sharing=similar


begin   
 dbms_stats.gather_table_stats(
 ownname =>user,
 tabname =>'T',
 estimate_percent=>100,
 method_opt=>'for all indexed columns size 254');
end;
/
alter session set cursor_sharing=similar;
select * from t test_4 where id = 1 and object_id = 100;
select * from t test_4 where id = 2 and object_id = 100;
select * from t test_4 where id = 3 and object_id = 100;
select * from t test_4 where id = 1 and object_id = 101;
select * from t test_4 where id = 1 and object_id = 102;
alter session set cursor_sharing=exact;

rajesh@ORA10GR2> SELECT sql_text,executions
  2  FROM V$SQL
  3  WHERE sql_text LIKE 'select * from t test_4 where id %'
  4  /
SQL_TEXT                                                                    EXECUTIONS
--------------------------------------------------------------------------- ----------
select * from t test_4 where id = :"SYS_B_0" and object_id = :"SYS_B_1"              3
select * from t test_4 where id = :"SYS_B_0" and object_id = :"SYS_B_1"              1
select * from t test_4 where id = :"SYS_B_0" and object_id = :"SYS_B_1"              1

Elapsed: 00:00:00.06
rajesh@ORA10GR2>

Whenever the bind value for the id column changes, Oracle replace the literal with bind variable and produce child cursors for each unique bind values.

So we have 3 executions for id=1 and 1 execution for each id=2 and id=3. So in total we have three unique child cursors.

rajesh@ORA10GR2> alter session set cursor_sharing=similar;

Session altered.

Elapsed: 00:00:00.00
rajesh@ORA10GR2> select * from t test_4 where id = 4 and object_id = 100;

no rows selected

Elapsed: 00:00:00.01
rajesh@ORA10GR2> alter session set cursor_sharing=exact;

Session altered.

Elapsed: 00:00:00.01
rajesh@ORA10GR2>
rajesh@ORA10GR2> SELECT sql_text,executions
  2  FROM V$SQL
  3  WHERE sql_text LIKE 'select * from t test_4 where id %'
  4  /
SQL_TEXT                                                                    EXECUTIONS
--------------------------------------------------------------------------- ----------
select * from t test_4 where id = :"SYS_B_0" and object_id = :"SYS_B_1"              3
select * from t test_4 where id = :"SYS_B_0" and object_id = :"SYS_B_1"              1
select * from t test_4 where id = :"SYS_B_0" and object_id = :"SYS_B_1"              1
select * from t test_4 where id = :"SYS_B_0" and object_id = :"SYS_B_1"              1

Elapsed: 00:00:00.06
rajesh@ORA10GR2>

you see the fourth copy of sql available in v$sql for id = 4

What happens if we change the object_id to different values

alter session set cursor_sharing=similar;
select * from t test_4 where id = 1 and object_id = 500;
select * from t test_4 where id = 2 and object_id = 500;
select * from t test_4 where id = 3 and object_id = 500;
alter session set cursor_sharing=exact;

rajesh@ORA10GR2> SELECT sql_text,executions
  2  FROM V$SQL
  3  WHERE sql_text LIKE 'select * from t test_4 where id %';

SQL_TEXT                                                                    EXECUTIONS
--------------------------------------------------------------------------- ----------
select * from t test_4 where id = :"SYS_B_0" and object_id = :"SYS_B_1"              4
select * from t test_4 where id = :"SYS_B_0" and object_id = :"SYS_B_1"              2
select * from t test_4 where id = :"SYS_B_0" and object_id = :"SYS_B_1"              2
select * from t test_4 where id = :"SYS_B_0" and object_id = :"SYS_B_1"              1

Elapsed: 00:00:00.03
rajesh@ORA10GR2>

Notice here how there are three copies of the sql in v$sql still! That is because we already had the plans for ID=1,2,3 - regardless of what the object_id was

No comments:

Post a Comment