Striving for Optimal Performance

A reader of this blog, Paresh, asked me how I was able to find out the logic behind ITL waits without having access to Oracle code. My reply was: I wrote a test case that reproduce ITL waits and a piece of code that monitors them.

Since other readers might be interested, here is the shell script I wrote. Notice that it takes four parameters as input: user name, password, SID, and how long it has to wait in the monitoring phase.

#!/bin/sh

user=$1
password=$2
sid=$3
wait=$4

#
# Setup test environment
#

sqlplus -s $user/$password@$sid <<END
  SET ECHO OFF TERMOUT ON FEEDBACK OFF HEADING OFF
  BEGIN
    EXECUTE IMMEDIATE 'DROP TABLE t PURGE';
  EXCEPTION
    WHEN OTHERS THEN NULL;
  END;
  /
  CREATE TABLE t (n NUMBER, pad VARCHAR2(50)) PCTFREE 0 INITRANS 5 TABLESPACE users;
  INSERT INTO t SELECT rownum, rpad('*',50,'*') FROM dual CONNECT BY level <= 134 UNION ALL SELECT 135, rpad('*',48,'*') FROM dual;
  COMMIT;
  SELECT 'Setup correctly performed:', decode(count(DISTINCT dbms_rowid.rowid_block_number(rowid)),1,'YES','NO') FROM t; 
END

#
# Produce ITL wait
#

for i in 1 2 3 4 5 6
do
  echo 'SET ECHO OFF TERMOUT OFF FEEDBACK OFF' > $i.$sid.sql
  if [[ $i = 6 ]]
  then
    # make sure that the other processes have locked one row
    echo 'execute dbms_lock.sleep(1)' >> $i.$sid.sql
  fi
  echo 'UPDATE t SET n = n WHERE n =' $i ';' >> $i.$sid.sql 
  echo 'SET TERMOUT OFF' >> $i.$sid.sql
  if [[ $i < 6 ]]
  then
    echo 'execute dbms_lock.sleep(' $wait ')' >> $i.$sid.sql
  fi
  sqlplus -s $user/$password@$sid @$i.$sid.sql &
done

#
# Monitor ITL wait
#

sqlplus -s $user/$password@$sid <<END
  SET SERVEROUTPUT ON ECHO OFF TERMOUT ON FEEDBACK OFF HEADING OFF
  SELECT * FROM v\$version WHERE rownum = 1;
  DECLARE
    l_waiter_session v\$session.sid%TYPE := NULL;
    l_blocking_session_curr v\$session.blocking_session%TYPE := NULL;
    l_blocking_session_prev v\$session.blocking_session%TYPE := NULL;
    l_seconds_in_wait_curr v\$session.seconds_in_wait%TYPE := NULL;
    l_seconds_in_wait_prev v\$session.seconds_in_wait%TYPE := NULL;
    c_sleep CONSTANT NUMBER := 0.1;
    c_iterations CONSTANT NUMBER := ceil(($wait-5)/c_sleep);
  BEGIN
    WHILE l_waiter_session IS NULL
    LOOP
      BEGIN
        SELECT sid INTO l_waiter_session
        FROM v\$session
        WHERE event = 'enq: TX - allocate ITL entry';
      EXCEPTION 
        WHEN no_data_found THEN NULL;
      END;
    END LOOP;
    FOR i IN 1..c_iterations
    LOOP
      BEGIN
        SELECT blocking_session, seconds_in_wait INTO l_blocking_session_curr, l_seconds_in_wait_curr
        FROM v\$session
        WHERE sid = l_waiter_session;
      EXCEPTION
        WHEN no_data_found THEN NULL;
      END;
      IF l_blocking_session_curr <> l_blocking_session_prev 
         OR l_blocking_session_prev IS NULL
         OR i = c_iterations 
      THEN
        dbms_output.put_line(to_char((i-1)*c_sleep,'000000')||
                             ' blocking_session='||nvl(l_blocking_session_prev,l_blocking_session_curr)||
                             ' sleep='||nvl(l_seconds_in_wait_prev,l_seconds_in_wait_curr));
      END IF;
      l_blocking_session_prev := l_blocking_session_curr;
      l_seconds_in_wait_prev := l_seconds_in_wait_curr;
      dbms_lock.sleep(c_sleep);
    END LOOP;
  END;
  /
END

#
# Cleanup
#

for i in 1 2 3 4 5 6
do
  rm $i.$sid.sql
done

sleep 5

sqlplus -s $user/$password@$sid <<END
  SET ECHO OFF TERMOUT ON FEEDBACK OFF HEADING OFF
  DROP TABLE t PURGE;
END

exit 0

The outputs I got are the following:

• 10.2.0.4

000000 blocking_session=136 sleep=0
000005 blocking_session=136 sleep=6
000010 blocking_session=140 sleep=3
000015 blocking_session=152 sleep=6
000020 blocking_session=159 sleep=6
029995 blocking_session=158 sleep=29979

• 10.2.0.5

000000 blocking_session=158 sleep=0
000001 blocking_session=158 sleep=0
000002 blocking_session=152 sleep=2
000003 blocking_session=141 sleep=0
000004 blocking_session=148 sleep=0
000005 blocking_session=140 sleep=3
000007 blocking_session=158 sleep=0
000009 blocking_session=152 sleep=3
000011 blocking_session=141 sleep=3
000013 blocking_session=148 sleep=0
000015 blocking_session=140 sleep=3
000019 blocking_session=158 sleep=3
000023 blocking_session=152 sleep=6
000027 blocking_session=141 sleep=3
000031 blocking_session=148 sleep=3
000035 blocking_session=140 sleep=6
000040 blocking_session=158 sleep=3
000045 blocking_session=152 sleep=6
000050 blocking_session=141 sleep=6
000054 blocking_session=148 sleep=3
000062 blocking_session=140 sleep=9
000067 blocking_session=158 sleep=6
000072 blocking_session=152 sleep=3
000077 blocking_session=141 sleep=6
000082 blocking_session=148 sleep=6
000098 blocking_session=140 sleep=15
000103 blocking_session=158 sleep=6
000108 blocking_session=152 sleep=3
000113 blocking_session=141 sleep=6
000118 blocking_session=148 sleep=6
000149 blocking_session=140 sleep=30
000154 blocking_session=158 sleep=6
000159 blocking_session=152 sleep=6
000164 blocking_session=141 sleep=3
000169 blocking_session=148 sleep=6
000232 blocking_session=140 sleep=63
000237 blocking_session=158 sleep=6
000242 blocking_session=152 sleep=6
000247 blocking_session=141 sleep=3
000252 blocking_session=148 sleep=6
000379 blocking_session=140 sleep=129
000383 blocking_session=158 sleep=3
000388 blocking_session=152 sleep=6
000393 blocking_session=141 sleep=6
000398 blocking_session=148 sleep=3
000651 blocking_session=140 sleep=258
000656 blocking_session=158 sleep=3
000661 blocking_session=152 sleep=6
000666 blocking_session=141 sleep=6
000671 blocking_session=148 sleep=3
001177 blocking_session=140 sleep=514
001182 blocking_session=158 sleep=6
001187 blocking_session=152 sleep=3
001192 blocking_session=141 sleep=6
001197 blocking_session=148 sleep=6
014218 blocking_session=140 sleep=13184
029995 blocking_session=140 sleep=28788

• 11.1.0.6

000000 blocking_session=146 sleep=0
000005 blocking_session=146 sleep=5
000010 blocking_session=129 sleep=5
000015 blocking_session=141 sleep=5
000020 blocking_session=126 sleep=5
029995 blocking_session=132 sleep=29978

• 11.1.0.7

000000 blocking_session=136 sleep=0
000005 blocking_session=136 sleep=5
000010 blocking_session=140 sleep=5
000015 blocking_session=132 sleep=5
000020 blocking_session=131 sleep=5
029995 blocking_session=134 sleep=29979

• 11.2.0.1

000000 blocking_session=131 sleep=0
000001 blocking_session=131 sleep=1
000002 blocking_session=133 sleep=1
000003 blocking_session=196 sleep=1
000004 blocking_session=67 sleep=1
000005 blocking_session=69 sleep=1
000007 blocking_session=131 sleep=2
000009 blocking_session=133 sleep=2
000011 blocking_session=196 sleep=2
000013 blocking_session=67 sleep=2
000015 blocking_session=69 sleep=2
000019 blocking_session=131 sleep=4
000023 blocking_session=133 sleep=4
000027 blocking_session=196 sleep=4
000031 blocking_session=67 sleep=4
000035 blocking_session=69 sleep=4
000040 blocking_session=131 sleep=5
000045 blocking_session=133 sleep=5
000050 blocking_session=196 sleep=5
000054 blocking_session=67 sleep=5
000062 blocking_session=69 sleep=8
000067 blocking_session=131 sleep=5
000072 blocking_session=133 sleep=5
000077 blocking_session=196 sleep=5
000082 blocking_session=67 sleep=5
000098 blocking_session=69 sleep=16
000103 blocking_session=131 sleep=5
000108 blocking_session=133 sleep=5
000113 blocking_session=196 sleep=5
000118 blocking_session=67 sleep=5
000149 blocking_session=69 sleep=32
000154 blocking_session=131 sleep=5
000159 blocking_session=133 sleep=5
000164 blocking_session=196 sleep=5
000169 blocking_session=67 sleep=5
000232 blocking_session=69 sleep=64
000237 blocking_session=131 sleep=5
000242 blocking_session=133 sleep=5
000247 blocking_session=196 sleep=5
000252 blocking_session=67 sleep=5
000379 blocking_session=69 sleep=128
000383 blocking_session=131 sleep=5
000388 blocking_session=133 sleep=5
000393 blocking_session=196 sleep=5
000398 blocking_session=67 sleep=5
000651 blocking_session=69 sleep=256
000656 blocking_session=131 sleep=5
000661 blocking_session=133 sleep=5
000666 blocking_session=196 sleep=5
000671 blocking_session=67 sleep=5
001177 blocking_session=69 sleep=512
001182 blocking_session=131 sleep=5
001187 blocking_session=133 sleep=5
001192 blocking_session=196 sleep=5
001196 blocking_session=67 sleep=5
029995 blocking_session=69 sleep=28787

In recent releases Oracle has silently changed the behavior of ITL waits. The aim of this post it to describe what has changed and why. But, first of all, let’s review some essential concepts about ITLs and ITL waits.

Interested Transaction List

The Oracle database engine locks the data modified by a transaction at the row level. To implement this feature every data block contains a list of all transactions that are modifying it. This list is commonly called interested transaction list (ITL). Its purpose is twofold. First, it is used to store information to identify a transaction as well as a reference to access the undo data associated to it. Second, it is referenced by every modified or locked row to indicate which transaction it is involved.

INITRANS

The initial number of slots composing the ITL is set through the INITRANS parameter. Even though it can be set to 1, which is the default value as well, as of 9i at least 2 slots are always created. Note that the data dictionary lies to us on this matter. In fact, as shown in the following example, the data dictionary shows the value specified when the object was created and not the actual number of slots.

SQL> CREATE TABLE t (n NUMBER) INITRANS 1;

SQL> SELECT ini_trans FROM user_tables WHERE table_name = 'T';

 INI_TRANS
----------
         1

MAXTRANS

There is a maximum number of slots an ITL can contain. The actual maximum number depends on the blocks size. For example, an 8KB block can have up to 169 slots. Up to 9i the maximum is limited by the MAXTRANS parameter as well. As of 10g, however, this parameter is deprecated and, therefore, no longer honored. In the same way as for INITRANS, the data dictionary shows the value specified when the object was created and not the actual maximum number of slots.
Also note that while creating an object the database engine checks whether the MAXTRANS value is not greater than 255. And, if it is greater, it raises an ORA-02209 (invalid MAXTRANS option value).

ITL Waits

When a session requires a slot but all the available ones are in use by other active transactions, the database engine tries to dynamically create a new slot. This is of course only possible when a) the maximum number of slots was not already allocated b) enough free space (one slot occupies 24 bytes) is available in the block itself. If a new slot cannot be created, the session requiring it hits a so-called ITL wait. Note that the name of the actual wait event is called “enq: TX – allocate ITL entry”.
It is essential to point out that a session does not wait on the first slot becoming free. Instead, it probes, round-robin, the available slots to find out one that becomes free. And, while doing so, it waits few seconds on every one it probes. When during this short wait the slot becomes free, it uses it. Otherwise, it tries with another slot.
The actual implementation for finding a free slot is what Oracle changed in recent releases. So, let’s describe what the behavior in recent releases is.

ITL Waits in 11gR1

In 11.1.0.6 and 11.1.0.7 a session waits at most one time on every slot. For all slots but one it waits up to 5 seconds. For the other one it might wait indefinitely. The following pseudo code illustrates this (you should consider the variable called “itl” as an array referencing/containing all ITL slots).

FOR i IN itl.FIRST..itl.LAST
LOOP
  EXIT WHEN itl(i) IS FREE
  IF i <> itl.LAST
  THEN WAIT ON itl(i) FOR 5 SECONDS
  ELSE WAIT ON itl(i) FOREVER
  END IF
END LOOP

The problem of this algorithm is that an “unlucky” session might wait much longer than necessary. In fact, once it enters the WAIT FOREVER status, it no longer considers the other slots.

ITL Waits in 11gR2

In 11.2.0.1 and 11.2.0.2 a session might wait several times for the same slot. Initially the wait is short. As the time passes, the wait time increases exponentially based on the formula “wait time = power(2,iteration-1)”. For all slots but one there is a maximum wait time of 5 seconds, though. For the other one, and for the first 10 iterations only, the wait time is computed with the very same formula. Then, during the 11th iteration, the session waits indefinitely. The following pseudo code illustrates this.

iteration = 0
LOOP
  iteration++
  FOR i IN itl.FIRST..itl.LAST
  LOOP
    EXIT WHEN itl(i) IS FREE
    IF i <> itl.LAST
    THEN WAIT ON itl(i) FOR min(power(2,iteration-1),5) SECONDS
    ELSIF iteration <= 10
    THEN WAIT ON itl(i) FOR power(2,iteration-1) SECONDS
    ELSE WAIT ON itl(i) FOREVER
    END IF
  END LOOP
  EXIT WHEN free_itl_found
END LOOP

The advantage of this algorithm is that a session might probe several time all the available slots and, as a result, enters the WAIT FOREVER status after about 20 minutes only.

ITL Waits in 9i/10g

Up to 10.2.0.4 the behavior is similar to 11gR1. The only noticeable difference is that the wait time is not always 5 seconds. Instead, it is either 3 or 6 seconds. I was not able to spot a rule behind the choice between the two durations. So, there might be some randomness involved.
In 10.2.0.5 the behavior is similar to 11gR2. Also in this case the only noticeable difference is that the maximum wait time is not always 5 seconds. Instead, as in releases up to 10.2.0.4, it is either 3 or 6 seconds.

At page 383 of my book I wrote the following sentence (BTW, the same information is also provided by Table 9-3 at page 381):

With B-tree indexes, IS NULL conditions can be applied only through composite B-tree indexes when several SQL conditions are applied and at least one of them is not based on IS NULL or an inequality.

The text continues by showing the following examples (notice that in both cases the IS NULL predicate is applied through an access predicate):

SELECT /*+ index(t) */ * FROM t WHERE n1 = 6 AND n2 IS NULL

Plan hash value: 780655320

----------------------------------------------
| Id  | Operation                   | Name   |
----------------------------------------------
|   0 | SELECT STATEMENT            |        |
|   1 |  TABLE ACCESS BY INDEX ROWID| T      |
|*  2 |   INDEX RANGE SCAN          | I_N123 |
----------------------------------------------

   2 - access("N1"=6 AND "N2" IS NULL)

SELECT /*+ index(t) */ * FROM t WHERE n1 IS NULL AND n2 = 8

Plan hash value: 780655320

----------------------------------------------
| Id  | Operation                   | Name   |
----------------------------------------------
|   0 | SELECT STATEMENT            |        |
|   1 |  TABLE ACCESS BY INDEX ROWID| T      |
|*  2 |   INDEX RANGE SCAN          | I_N123 |
----------------------------------------------

   2 - access("N1" IS NULL AND "N2"=8)
       filter("N2"=8)

When I wrote that sentence I didn’t think about one case that, according to it, specifically the part “is not based on IS NULL or an inequality”, is not covered. In fact, as the following examples show, it is also possible to apply an IS NULL predicate when the other one is an IS NOT NULL. It is especially interesting to notice that the access predicate doesn’t reference at all the NOT NULL column!

SELECT /*+ index(t) */ * FROM t WHERE n1 IS NULL AND n2 IS NOT NULL

Plan hash value: 780655320

----------------------------------------------
| Id  | Operation                   | Name   |
----------------------------------------------
|   0 | SELECT STATEMENT            |        |
|   1 |  TABLE ACCESS BY INDEX ROWID| T      |
|*  2 |   INDEX RANGE SCAN          | I_N123 |
----------------------------------------------

   2 - access("N1" IS NULL)
       filter("N2" IS NOT NULL)

SELECT /*+ index(t) */ * FROM t WHERE n1 IS NOT NULL AND n2 IS NULL

Plan hash value: 3029444779

----------------------------------------------
| Id  | Operation                   | Name   |
----------------------------------------------
|   0 | SELECT STATEMENT            |        |
|   1 |  TABLE ACCESS BY INDEX ROWID| T      |
|*  2 |   INDEX SKIP SCAN           | I_N123 |
----------------------------------------------

   2 - access("N2" IS NULL)
       filter(("N2" IS NULL AND "N1" IS NOT NULL))

The aim of this post is to describe a strange (buggy) situation that I observed recently. But before doing that, I shortly summarize what a parent cursor and a child cursor are as well as when they can be shared. By the way, I borrowed this description from the pages 20/21 of my book. Hence, if you are interested in more information about this topic refer to it…

The result of a parse operation is a parent cursor and a child cursor stored in the library cache.

The key information related to a parent cursor is the text of the SQL statement. Therefore, several SQL statements share the same parent cursor if their text is exactly the same (note that there is at least an exception to this, specifically when cursor sharing is used). In the following example, four SQL statements are executed. Two have the same text. Two others differ only because of lowercase and uppercase letters or blanks. Through the V$SQLAREA view, it is possible to confirm that three distinct parent cursors were created.

SQL> ALTER SYSTEM FLUSH SHARED_POOL;

SQL> SELECT * FROM t WHERE n = 1234;

SQL> select * from t where n = 1234;

SQL> SELECT * FROM t WHERE n=1234;

SQL> SELECT * FROM t WHERE n = 1234;

SQL> SELECT sql_id, sql_text, executions
  2  FROM v$sqlarea
  3  WHERE sql_text LIKE '%1234';

SQL_ID        SQL_TEXT                          EXECUTIONS
------------- --------------------------------- ----------
2254m1487jg50 select * from t where n = 1234             1
g9y3jtp6ru4cb SELECT * FROM t WHERE n = 1234             2
7n8p5s2udfdsn SELECT * FROM t WHERE n=1234               1

The key information related to a child cursor is the execution plan and the execution environment related to it. The execution environment is important because if it changes, the execution plan might change as well. As a result, several SQL statements are able to share the same child cursor only if they share the same parent cursor and their execution environments are compatible. To illustrate, the same SQL statement is executed with two different values of the initialization OPTIMIZER_MODE parameter. The result is that a single parent cursor and two child cursors are created.

SQL> ALTER SESSION SET optimizer_mode = all_rows;

SQL> SELECT count(*) FROM t;

COUNT(*)
----------
      1000

SQL> ALTER SESSION SET optimizer_mode = first_rows_10;

SQL> SELECT count(*) FROM t;

COUNT(*)
----------
      1000

SQL> SELECT sql_id, child_number, sql_text, optimizer_mode, plan_hash_value
  2  FROM v$sql
  3  WHERE sql_id = (SELECT prev_sql_id
  4  FROM v$session
  5  WHERE sid = sys_context('userenv','sid'));

SQL_ID        CHILD_NUMBER SQL_TEXT               OPTIMIZER_MODE PLAN_HASH_VALUE
------------- ------------ ---------------------- -------------- ---------------
5tjqf7sx5dzmj            0 SELECT count(*) FROM t ALL_ROWS            2966233522
5tjqf7sx5dzmj            1 SELECT count(*) FROM t FIRST_ROWS          2966233522

To know which mismatch led to several child cursors, you can query the V$SQL_SHARED_CURSOR view.

SQL> SELECT child_number, optimizer_mode_mismatch
  2  FROM v$sql_shared_cursor
  3  WHERE sql_id = '5tjqf7sx5dzmj';

CHILD_NUMBER OPTIMIZER_MODE_MISMATCH
------------ -----------------------
           0 N
           1 Y

So far, so good… Now, let’s see what’s strange…

The interesting thing to point out about the previous example is that while I set FIRST_ROWS_10 as optimizer mode, the V$SQL view displayed the value FIRST_ROWS. Mhmm… That’s strange… They are two different optimizer modes. They cannot be considered equivalent. What are the implications? It is just the view that provides the wrong information or the database engine is able to share the same child cursor even with two different values of the OPTIMIZER_MODE parameter? Let’s try it with FIRST_ROWS (i.e. without “_10”)…

 SQL> ALTER SESSION SET optimizer_mode = first_rows;

SQL> SELECT sql_id, child_number, sql_text, optimizer_mode, executions
  2  FROM v$sql
  3  WHERE sql_id = (SELECT prev_sql_id
  4                  FROM v$session
  5                  WHERE sid = sys_context('userenv','sid'));

SQL_ID        CHILD_NUMBER SQL_TEXT                          OPTIMIZER_MODE EXECUTIONS
------------- ------------ --------------------------------- -------------- ----------
5tjqf7sx5dzmj            0 SELECT count(*) FROM t            ALL_ROWS                1
5tjqf7sx5dzmj            1 SELECT count(*) FROM t            FIRST_ROWS              2

Oh, damn! Even though the OPTIMIZER MODE is set to a different value the same child cursor is used. Since in this particular situation the execution plans associated to both child cursors are the same (their hash value are equal), it’s not a real problem. But, in practice, it might be possible that two different optimizer modes lead to different execution plans. The following example illustrates this.

• Build a table for the test:

SQL> CREATE TABLE t AS
  2  SELECT rownum AS id, rpad('*',500,'*') AS pad
  3  FROM dual
  4  CONNECT BY level <= 1000;

SQL> CREATE UNIQUE INDEX i ON t (id);

SQL> execute dbms_stats.gather_table_stats(user, 'T')

• Show that different values of the OPTIMIZER_MODE parameter lead to different execution plans:

SQL> ALTER SESSION SET optimizer_mode = FIRST_ROWS_1;

SQL> EXPLAIN PLAN FOR SELECT * FROM t WHERE id <= 500;

SQL> SELECT * FROM table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------
Plan hash value: 242607798

------------------------------------------------------------------------------------
| Id  | Operation                   | Name | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |      |     3 |  1515 |     3   (0)| 00:00:01 |
|   1 |  TABLE ACCESS BY INDEX ROWID| T    |     3 |  1515 |     3   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | I    |       |       |     2   (0)| 00:00:01 |
------------------------------------------------------------------------------------

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

   2 - access("ID"<=500)

SQL> ALTER SESSION SET optimizer_mode = FIRST_ROWS_1000;

SQL> EXPLAIN PLAN FOR SELECT * FROM t WHERE id <= 500;

SQL> SELECT * FROM table(dbms_xplan.display);

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------
Plan hash value: 1601196873

--------------------------------------------------------------------------
| Id  | Operation         | Name | Rows  | Bytes | Cost (%CPU)| Time     |
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |      |   500 |   246K|    10   (0)| 00:00:01 |
|*  1 |  TABLE ACCESS FULL| T    |   500 |   246K|    10   (0)| 00:00:01 |
--------------------------------------------------------------------------

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

   1 - filter("ID"<=500)

• Execute the test query with both values of the OPTIMIZER_MODE parameter:

SQL> ALTER SYSTEM FLUSH SHARED_POOL;

SQL> ALTER SESSION SET optimizer_mode = FIRST_ROWS_1;

SQL> SELECT * FROM t WHERE id <= 500;

        ID PAD
---------- ----------
         1 **********
         2 **********
…
       499 **********
       500 **********

SQL> ALTER SESSION SET optimizer_mode = FIRST_ROWS_1000;

SQL> SELECT * FROM t WHERE id <= 500;

        ID PAD
---------- ----------
         1 **********
         2 **********
…
       499 **********
       500 **********

• Show that a single execution plan was used for both executions:

SQL> SELECT * FROM table(dbms_xplan.display_cursor(NULL,NULL));

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------
SQL_ID  2vw03p929jzgz, child number 0
-------------------------------------
SELECT * FROM t WHERE id <= 500

Plan hash value: 242607798

------------------------------------------------------------------------------------
| Id  | Operation                   | Name | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT            |      |       |       |     3 (100)|          |
|   1 |  TABLE ACCESS BY INDEX ROWID| T    |     3 |  1515 |     3   (0)| 00:00:01 |
|*  2 |   INDEX RANGE SCAN          | I    |       |       |     2   (0)| 00:00:01 |
------------------------------------------------------------------------------------

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

   2 - access("ID"<=500)

SQL> SELECT sql_id, child_number, executions, optimizer_mode
  2  FROM v$sql
  3  WHERE sql_id = '2vw03p929jzgz';

SQL_ID        CHILD_NUMBER EXECUTIONS OPTIMIZER_MODE
------------- ------------ ---------- --------------
2vw03p929jzgz            0          2 FIRST_ROWS

Even though it is not very likely that this bug (yes, in my opinion something like this cannot be considered a restriction of the implementation…) has an impact on a production system, I really don’t understand why the developers didn’t implement it correctly. It should not be that difficult to manage a byte containing the information about the used optimizer mode! Note that this is not the only case where something like that happens with the first rows optimizer mode. For example, also in a trace file generated through SQL trace no difference is made between the old and the new first row optimizer. So, it seams that they really got it wrong.

Almost one year ago Iggy Fernandez asked me to write a short text for the Ask the Oracles column of the NoCOUG Journal. The topic was “Bind Variable Peeking: Bane or Boon?”. My text along with the ones of Wolfgang Breitling, Dan Tow and Jonathan Lewis were published in the August issue. For some (unknown) reasons I never published that text on this site. Today, I correct that oversight. The text can be downloaded from this page.