Rotate your logs

If you are using Linux and not rotating your alert logs, listener logs, any log actually, or rotating them with your own scripts, check out logrotate. I did not know this existed. From Dizwell.

Bind peeking change in 10g

A new note called "10g Upgrade Companion" has been published in Metalink recently. The note talks about the upgrade from 9i to 10g and lists recommended patches, behavior changes and best practices. While I was going through it I saw something I was not aware of before. In the "behavior changes" section it says: "Bind peeking has been extended to binds buried inside expressions.".

I have talked about bind variable peeking and a behavior change of that feature in 11g before.

In 9i bind variables in expressions were not peeked at, 10g changes this. Now bind variables in expressions are also peeked at.

To see the change in action I have done a simple test. Let's start with the behavior in 9i.

SQL> create table t (col1 number,col2 varchar2(30));

Table created.

SQL> insert into t select 1,object_name from all_objects where rownum<=10000;

10000 rows created.

SQL> update t set col1=0 where rownum=1;

1 row updated.

SQL> create index tind on t(col1);

Index created.

SQL> exec dbms_stats.gather_table_stats(ownname=>user,tabname=>'T',cascade=>true,method_opt=>'for columns col1 size 10');

PL/SQL procedure successfully completed.

Now I have a table with 10,000 rows with skewed data distribution, one row has col1=0, all other rows have col1=1.

SQL> alter session set events '10046 trace name context forever, level 12';

Session altered.

After enabling the trace I execute the following two blocks.

declare
b1 varchar2(1);
begin
b1:=0;
for t in (select * from t where col1=to_number(b1)) loop
    null;
end loop;
end;
/

PL/SQL procedure successfully completed.

declare
b1 varchar2(1);
begin
b1:=1;
for t in (select * from t where col1=to_number(b1)) loop
  null;
end loop;
end;
/

PL/SQL procedure successfully completed.

What I expect in 9i is; since the bind variable b1 is used in an expression it will not be peeked at, the optimizer will think that b1=0 will return 5000 rows since the number of distinct values for the column is 2 and since there are 10000 rows in the table and it will full scan the table.

When we tkprof the resulting trace file with the "aggregate=no" option what we see is:

SELECT *
FROM
T WHERE COL1=TO_NUMBER(:B1 )


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.01       0.01          0         48          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.01       0.01          0         48          0           1

Misses in library cache during parse: 1
Optimizer goal: CHOOSE
Parsing user id: SYS   (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
1  TABLE ACCESS FULL T

SELECT *
FROM
T WHERE COL1=TO_NUMBER(:B1 )


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch    10000      0.35       0.26          0      10003          0        9999
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total    10002      0.35       0.26          0      10003          0        9999

Misses in library cache during parse: 0
Optimizer goal: CHOOSE
Parsing user id: SYS   (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
9999  TABLE ACCESS FULL T

It chose a full table scan for b1=0 and used it for the two queries.

If we run the same test in 10g what we see is:

SELECT *
FROM
T WHERE COL1=TO_NUMBER(:B1 )


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      0.00       0.00          0          3          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.00       0.00          0          3          0           1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 43     (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
  1  TABLE ACCESS BY INDEX ROWID T (cr=3 pr=0 pw=0 time=101 us)
  1   INDEX RANGE SCAN TIND (cr=2 pr=0 pw=0 time=43 us)(object id 44327)



SELECT *
FROM
T WHERE COL1=TO_NUMBER(:B1 )


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch      100      0.01       0.01          0        256          0        9999
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total      102      0.01       0.01          0        256          0        9999

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 43     (recursive depth: 1)

Rows     Row Source Operation
-------  ---------------------------------------------------
9999  TABLE ACCESS BY INDEX ROWID T (cr=256 pr=0 pw=0 time=269978 us)
9999   INDEX RANGE SCAN TIND (cr=120 pr=0 pw=0 time=139980 us)(object id 44327) 

It peeked at the bind variable in the expression, found out that b1=0 will return one row and decided to use the index. After that since the plan is fixed now it used the same plan for b1=1 also.

This is one of many changes in 10g that can change the execution plans after the upgrade from 9i. Be aware of this if you have bind variables in expressions in your sql statements. Who does not have actually?