Showing posts with label Fundamentals. Show all posts
Showing posts with label Fundamentals. Show all posts

Monday, November 14, 2011

Star Transformation And Cardinality Estimates

If you want to make use of Oracle's cunning Star Transformation feature then you need to be aware of the fact that the star transformation logic - as the name implies - assumes that you are using a proper star schema.

Here is a nice example of what can happen if you attempt to use star transformation but your model obviously doesn't really correspond to what Oracle expects:


drop table d;

purge table d;

drop table t;

purge table t;

create table t
as
select
rownum as id
, mod(rownum, 100) + 1 as fk1
, 1000 + mod(rownum, 10) + 1 as fk2
, 2000 + mod(rownum, 100) + 1 as fk3
, rpad('x', 100) as filler
from
dual
connect by
level <= 1000000
;

exec dbms_stats.gather_table_stats(null, 't')

create bitmap index t_fk1 on t (fk1);

create bitmap index t_fk2 on t (fk2);

create bitmap index t_fk3 on t (fk3);

create table d
as
select
rownum as id
, case when rownum between 1 and 100 then 'Y' else 'N' end as is_flag_d1
, case when rownum between 1001 and 1010 then 'Y' else 'N' end as is_flag_d2
, case when rownum between 2001 and 2100 then 'Y' else 'N' end as is_flag_d3
, rpad('x', 100) as vc1
from
dual
connect by
level <= 10000
;

exec dbms_stats.gather_table_stats(null, 'd', method_opt => 'FOR ALL COLUMNS SIZE 1 FOR COLUMNS SIZE 254 IS_FLAG_D1, IS_FLAG_D2, IS_FLAG_D3');


This is a simplified example of a model where multiple, potentially small, dimensions are stored in a single physical table and the separate dimensions are represented by views that filter the corresponding dimension data from the base table.

So we have a fact table with one million rows and a "collection" dimension table that holds three dimensions, among others.

In order to enable the star transformation bitmap indexes on the foreign keys of the fact table are created.

The dimension table has histograms on the flag columns to tell the optimizer about the non-uniform distribution of the column data.

Now imagine a query where we query the fact table (and possibly do some filtering on the fact table by other means like other dimensions or direct filtering on the fact table) but need to join these three dimensions just for displaying purpose - the dimensions itself are not filtered so the join will not filter out any data.

Let's first have a look at an execution plan of such a simply query with star transformation disabled:


select /*+ no_star_transformation */
count(*)
from
t f
, (select * from d where is_flag_d1 = 'Y') d1
, (select * from d where is_flag_d2 = 'Y') d2
, (select * from d where is_flag_d3 = 'Y') d3
where
f.fk1 = d1.id
and f.fk2 = d2.id
and f.fk3 = d3.id
;

SQL> explain plan for
2 select /*+ no_star_transformation */
3 count(*)
4 from
5 t f
6 , (select * from d where is_flag_d1 = 'Y') d1
7 , (select * from d where is_flag_d2 = 'Y') d2
8 , (select * from d where is_flag_d3 = 'Y') d3
9 where
10 f.fk1 = d1.id
11 and f.fk2 = d2.id
12 and f.fk3 = d3.id
13 ;

Explained.

SQL>
SQL> select * from table(dbms_xplan.display(format => 'BASIC +ROWS +PREDICATE'));
Plan hash value: 77569906

----------------------------------------------
| Id | Operation | Name | Rows |
----------------------------------------------
| 0 | SELECT STATEMENT | | 1 |
| 1 | SORT AGGREGATE | | 1 |
|* 2 | HASH JOIN | | 940K|
|* 3 | TABLE ACCESS FULL | D | 100 |
|* 4 | HASH JOIN | | 945K|
|* 5 | TABLE ACCESS FULL | D | 100 |
|* 6 | HASH JOIN | | 950K|
|* 7 | TABLE ACCESS FULL| D | 10 |
| 8 | TABLE ACCESS FULL| T | 1000K|
----------------------------------------------

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

2 - access("F"."FK3"="D"."ID")
3 - filter("IS_FLAG_D3"='Y')
4 - access("F"."FK1"="D"."ID")
5 - filter("IS_FLAG_D1"='Y')
6 - access("F"."FK2"="D"."ID")
7 - filter("IS_FLAG_D2"='Y')


So clearly the optimizer got it quite right - the join to the dimensions is not going to filter out significantly - the slight reduction in rows comes from the calculations based on the histograms generated.

But now try the same again with star transformation enabled:


SQL> explain plan for
2 select /*+ star_transformation opt_param('star_transformation_enabled', 'temp_disable') */
3 count(*)
4 from
5 t f
6 , (select * from d where is_flag_d1 = 'Y') d1
7 , (select * from d where is_flag_d2 = 'Y') d2
8 , (select * from d where is_flag_d3 = 'Y') d3
9 where
10 f.fk1 = d1.id
11 and f.fk2 = d2.id
12 and f.fk3 = d3.id
13 ;

Explained.

SQL>
SQL> select * from table(dbms_xplan.display(format => 'BASIC +ROWS +PREDICATE'));
Plan hash value: 459231705

----------------------------------------------------------
| Id | Operation | Name | Rows |
----------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 |
| 1 | SORT AGGREGATE | | 1 |
|* 2 | HASH JOIN | | 9 |
|* 3 | HASH JOIN | | 9 |
|* 4 | HASH JOIN | | 10 |
|* 5 | TABLE ACCESS FULL | D | 10 |
| 6 | TABLE ACCESS BY INDEX ROWID | T | 10 |
| 7 | BITMAP CONVERSION TO ROWIDS| | |
| 8 | BITMAP AND | | |
| 9 | BITMAP MERGE | | |
| 10 | BITMAP KEY ITERATION | | |
|* 11 | TABLE ACCESS FULL | D | 100 |
|* 12 | BITMAP INDEX RANGE SCAN| T_FK1 | |
| 13 | BITMAP MERGE | | |
| 14 | BITMAP KEY ITERATION | | |
|* 15 | TABLE ACCESS FULL | D | 100 |
|* 16 | BITMAP INDEX RANGE SCAN| T_FK3 | |
| 17 | BITMAP MERGE | | |
| 18 | BITMAP KEY ITERATION | | |
|* 19 | TABLE ACCESS FULL | D | 10 |
|* 20 | BITMAP INDEX RANGE SCAN| T_FK2 | |
|* 21 | TABLE ACCESS FULL | D | 100 |
|* 22 | TABLE ACCESS FULL | D | 100 |
----------------------------------------------------------

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

2 - access("F"."FK3"="D"."ID")
3 - access("F"."FK1"="D"."ID")
4 - access("F"."FK2"="D"."ID")
5 - filter("IS_FLAG_D2"='Y')
11 - filter("IS_FLAG_D1"='Y')
12 - access("F"."FK1"="D"."ID")
15 - filter("IS_FLAG_D3"='Y')
16 - access("F"."FK3"="D"."ID")
19 - filter("IS_FLAG_D2"='Y')
20 - access("F"."FK2"="D"."ID")
21 - filter("IS_FLAG_D1"='Y')
22 - filter("IS_FLAG_D3"='Y')


What an astonishing result: Not only Oracle will try now to access all rows of the fact table by single-block random I/O, which by itself can be a disaster for larger real-life fact tables, in particular when dealing with Exadata features like Smart Scans which are only possible with multi-block direct-path reads, but furthermore if this was part of a more complex execution plan look at the cardinality estimates: They are off by five orders of magnitude - very likely a receipt for disaster for any step following afterwards.

The point here is simple: The Star Transformation calculation model obviously doesn't cope with the "collection" of dimensions in a single table very well, but assumes a dimensional model where each dimension is stored in separate table(s). If you don't adhere to that model the calculation will be badly wrong and the results possibly disastrous.

Here the Star Transformation assumes a filtering on dimension tables that are effectively no filter but this is something the current calculation model is not aware of. If you put the three dimensions in separate tables no "artificial" filter is required and hence the calculation won't be mislead.

Of course one could argue that the star transformation optimization seems to do a poor job since the normal optimization based on the same input data produces a much better estimate, but at least for the time being that's the way this transformation works and the model chosen better reflects this.

Tuesday, October 11, 2011

Parallel Downgrade

There are many reasons why a parallel execution might not run with the expected degree of parallelism (DOP), beginning with running out of parallel slaves (PARALLEL_MAX_SERVERS or PROCESSES reached), PARALLEL_ADAPTIVE_MULTI_USER, downgrades at execution time via the Resource Manager, or the more recent features like PARALLEL_DEGREE_LIMIT or the Auto DOP introduced in Oracle 11.2.

However what do you do if you've already checked all these possibilities but still see a downgrade occurring? You can always enable the parallel execution tracing facility (see for example the MOS document ID 444164.1 "Tracing Parallel Execution with _px_trace. Part I" for details how to use it) via the "_px_trace" parameter in the session, and if you see there that parallel slaves are getting acquired but released again immediately then possibly followed by an error message raised then you might want to have a look at the ancient Profile setting SESSIONS_PER_USER. This setting is probably mostly known and used to limit the number of concurrent sessions that a particular user is able to perform, but it is probably forgotten or mostly unknown that this profile setting also will be respected by the parallel execution and each parallel slave started will count towards this limit. Actually up to Oracle 9.2.0.7 you could end up with an ORA-12805 (parallel query server died unexpectedly) error in such a case rather then seeing a downgrade occurring as described in bug 4041253.

So the next time you see an otherwise unexplainable downgrade or think about using the SESSIONS_PER_USER Profile limit, and the user is supposed to make use of Parallel Execution, consider those implications.

Sample px_trace snippet from 10.2.0.5 when downgrading to serial due to SESSIONS_PER_USER Profile setting:

kxfrSysInfo
DOP trace -- compute default DOP from system info
# instance alive = 1 (kxfrsnins)
kxfrDefaultDOP
DOP Trace -- compute default DOP
# CPU = 4
Threads/CPU = 2 ("parallel_threads_per_cpu")
default DOP = 8 (# CPU * Threads/CPU)
default DOP = 8 (DOP * # instance)
kxfrSysInfo
system default DOP = 8 (from kxfrDefaultDOP())
kxfralo
DOP trace -- requested thread from best ref obj = 8 (from kxfrIsBestRef(
))
kxfralo
threads requested = 8 (from kxfrComputeThread())
kxfralo
adjusted no. threads = 8 (from kxfrAdjustDOP())
kxfralo
about to allocate 8 slaves
kxfrAllocSlaves
DOP trace -- call kxfpgsg to get 8 slaves
kxfpgsg
num server requested = 8
num server requested = 8 KXFPLDBL/KXFPADPT/ load balancing:on adaptive:o
n
kxfpiinfo
inst[cpus:mxslv]
1[4:80]
kxfpclinfo
inst(load:user:pct:fact)aff
1(1:0:100:400)
kxfpAdaptDOP
Requested=8 Granted=8 Target=32 Load=1 Default=8 users=0 sets=1
load adapt num servers requested to = 8 (from kxfpAdaptDOP())
kxfpgsg
getting 1 sets of 8 threads, client parallel query execution flg=0x30
Height=8, Affinity List Size=0, inst_total=1, coord=1
Insts 1
Threads 8
kxfpg1sg
q:000007FF4656C058 req_threads:8 nthreads:8 #inst:1 normal
kxfpg1srv
trying to get slave P000 on instance 1 for q:000007FF4656C058
slave P000 is local
found slave P000 dp:000007FF49682A98 flg:0
kxfpcre1
Creating slave 0 flg:30
free descriptor found dp:000007FF49680318
Allocated slave P000 dp:000007FF49680318 pnum:0 flg:4
Got It. 1 so far.
kxfpg1srv
trying to get slave P001 on instance 1 for q:000007FF4656C058
slave P001 is local
found slave P001 dp:000007FF49682A98 flg:0
kxfpcre1
Creating slave 1 flg:30
free descriptor found dp:000007FF49680398
Allocated slave P001 dp:000007FF49680398 pnum:1 flg:4
Got It. 2 so far.
kxfpg1srv
trying to get slave P002 on instance 1 for q:000007FF4656C058
slave P002 is local
found slave P002 dp:000007FF49682A98 flg:0
kxfpcre1
Creating slave 2 flg:30
free descriptor found dp:000007FF49680418
Allocated slave P002 dp:000007FF49680418 pnum:2 flg:4
Got It. 3 so far.
kxfpg1srv
trying to get slave P003 on instance 1 for q:000007FF4656C058
slave P003 is local
found slave P003 dp:000007FF49682A98 flg:0
kxfpcre1
Creating slave 3 flg:30
free descriptor found dp:000007FF49680498
Allocated slave P003 dp:000007FF49680498 pnum:3 flg:4
Got It. 4 so far.
kxfpg1srv
trying to get slave P004 on instance 1 for q:000007FF4656C058
slave P004 is local
found slave P004 dp:000007FF49682A98 flg:0
kxfpcre1
Creating slave 4 flg:30
free descriptor found dp:000007FF49680518
Allocated slave P004 dp:000007FF49680518 pnum:4 flg:4
Got It. 5 so far.
kxfpg1srv
trying to get slave P005 on instance 1 for q:000007FF4656C058
slave P005 is local
found slave P005 dp:000007FF49682A98 flg:0
kxfpcre1
Creating slave 5 flg:30
free descriptor found dp:000007FF49680598
Allocated slave P005 dp:000007FF49680598 pnum:5 flg:4
Got It. 6 so far.
kxfpg1srv
trying to get slave P006 on instance 1 for q:000007FF4656C058
slave P006 is local
found slave P006 dp:000007FF49682A98 flg:0
kxfpcre1
Creating slave 6 flg:30
free descriptor found dp:000007FF49680618
Allocated slave P006 dp:000007FF49680618 pnum:6 flg:4
Got It. 7 so far.
kxfpg1srv
trying to get slave P007 on instance 1 for q:000007FF4656C058
slave P007 is local
found slave P007 dp:000007FF49682A98 flg:0
kxfpcre1
Creating slave 7 flg:30
free descriptor found dp:000007FF49680698
Allocated slave P007 dp:000007FF49680698 pnum:7 flg:4
Got It. 8 so far.
kxfpqsrls
Release Slave q=0x000007FF4656C058 qr=0x000007FF465615A8 action=1 slave=
0 inst=1
kxfpqsrls
Release Slave q=0x000007FF4656C058 qr=0x000007FF46561D68 action=1 slave=
2 inst=1
kxfpqsrls
Release Slave q=0x000007FF4656C058 qr=0x000007FF46562148 action=1 slave=
3 inst=1
kxfpqsrls
Release Slave q=0x000007FF4656C058 qr=0x000007FF46562CE8 action=1 slave=
4 inst=1
kxfpqsrls
Release Slave q=0x000007FF4656C058 qr=0x000007FF4655FE68 action=1 slave=
5 inst=1
kxfpqsrls
Release Slave q=0x000007FF4656C058 qr=0x000007FF46562ED8 action=1 slave=
6 inst=1
kxfpqsrls
Release Slave q=0x000007FF4656C058 qr=0x000007FF46560058 action=1 slave=
7 inst=1
kxfpg1sg
got 1 servers (sync), returning...
kxfpgsg
serial - too few slaves alloc'd
kxfpqsrls
Release Slave q=0x000007FF4656C058 qr=0x000007FF46561988 action=1 slave=
1 inst=1
kxfplsig
signaling OER(10387) in serial 4609

Wednesday, August 10, 2011

Logical I/O Evolution - Part 3: 11g

Preface (with apologies to Kevin Closson)

This blog post is too long

Introduction

In the previous part of this series I've already demonstrated that the logical I/O optimization of the Table Prefetching feature depends on the order of the row sources - and 11g takes this approach a big step further.

It is very interesting that 11g does not require any particular feature like Table Prefetching or Nested Loop Join Batching (another new feature introduced in 11g) to take advantage of the Logical I/O optimization - it seems to be available even with the most basic form of a Nested Loop join.

Note that this optimization has already been mentioned several times, but there was always some confusion so far whether this optimization was related to another new feature that has been introduced with 11g - the so called "fastpath" consistent gets.

Buffer Pinning Optimization

So, let's repeat the already known test case from the previous parts in 11g. Another nice feature of 11g is that we have now full control over the Nested Loop plan shapes / features used by Oracle - we can choose from "classic" Nested Loop Join, Table Prefetching and Nested Loop Join Batching.

This is controlled via the [NO_]NLJ_BATCHING and [NO_]NLJ_PREFETCH hints which you will also find in the "outline" hint list generated for Plan Stability from 11g on.

Interestingly if I wanted to have the "classic" Nested Loop shape then I couldn't achieve that by combining the NO_NLJ_BATCHING and NO_NLJ_PREFETCH hint - one seemed to disable the other one - so I had to resort to the "_nlj_batching_enabled" parameter to disable Nested Loop Join Batching.

So this is what the query hints need to look like if we want to have the classic Nested Loop Join shape in 11g:

select
max(b_filler), max(a_filler)
from (
select /*+ leading(a) use_nl(a b) opt_param('_nlj_batching_enabled', 0) no_nlj_prefetch(b) */
a.id as a_id, a.filler as a_filler, b.id as b_id, b.filler as b_filler
from
t2 a
, t1 b
where
a.id = b.id
);


If you want to test with different plan shapes you can simply modify the hint section as required, for example you can get the Table Prefetching shape by changing above hint from NO_NLJ_PREFETCH to NLJ_PREFETCH etc.

Let's start with the data set where T1 and T2 are not in the same order, and stick to the classic plan shape:

11.2.0.1 Classic Nested Loop - Random order

Inner row source Unique Index - T1 different order than T2

---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 202K(100)| 1 |00:00:03.67 | 310K|
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:03.67 | 310K|
| 2 | NESTED LOOPS | | 1 | 100K| 202K (1)| 100K|00:00:03.47 | 310K|
| 3 | TABLE ACCESS FULL | T2 | 1 | 100K| 2720 (1)| 100K|00:00:00.21 | 10010 |
| 4 | TABLE ACCESS BY INDEX ROWID| T1 | 100K| 1 | 2 (0)| 100K|00:00:02.54 | 300K|
|* 5 | INDEX UNIQUE SCAN | T1_IDX | 100K| 1 | 1 (0)| 100K|00:00:00.76 | 200K|
---------------------------------------------------------------------------------------------------------------


Inner row source Non-Unique Index - T1 different order than T2

---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 202K(100)| 1 |00:00:04.40 | 311K|
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:04.40 | 311K|
| 2 | NESTED LOOPS | | 1 | 100K| 202K (1)| 100K|00:00:04.20 | 311K|
| 3 | TABLE ACCESS FULL | T1 | 1 | 100K| 2720 (1)| 100K|00:00:00.20 | 10010 |
| 4 | TABLE ACCESS BY INDEX ROWID| T2 | 100K| 1 | 2 (0)| 100K|00:00:03.28 | 301K|
|* 5 | INDEX RANGE SCAN | T2_IDX | 100K| 1 | 1 (0)| 100K|00:00:01.08 | 201K|
---------------------------------------------------------------------------------------------------------------


So far no difference to previous results, the non-unique index variant is still slower than the unique one, and we do not see any special buffer pinning optimization apart from the one we've already seen in the baseline test.

The relevant session statistics:

Statistics Name Unique Non-Unique Difference
----------------------------------------------------- -------- ----------- -----------
STAT..table scan blocks gotten 10,000 10,000 0
STAT..table scan rows gotten 100,000 100,000 0
STAT..table fetch by rowid 100,000 100,002 2
STAT..consistent gets 310,012 311,108 1,096
STAT..consistent gets from cache 310,012 311,108 1,096
STAT..session logical reads 310,012 311,108 1,096
STAT..buffer is not pinned count 200,002 100,012 -99,990
STAT..buffer is pinned count 99,999 199,993 99,994
STAT..index fetch by key 100,000 2 -99,998
STAT..rows fetched via callback 100,000 2 -99,998
STAT..index scans kdiixs1 0 100,000 100,000
STAT..consistent gets - examination 300,001 100,007 -199,994
STAT..consistent gets from cache (fastpath) 10,011 211,101 201,090
STAT..no work - consistent read gets 10,001 211,091 201,090
LATCH.cache buffers chains 320,024 522,216 202,192


Nothing spectacular here either, but there are at least some interesting points to mention:

- We can see that Oracle took advantage of the so called "fastpath" consistent gets for the "normal" consistent gets - they still took two latch acquisitions per get though. The "fastpath" seems to be about a code optimization when buffers get pinned that probably requires less CPU cycles. I don't know if the code change addresses any further contention/concurrency issues apart from being "faster" (faster is always better, isn't it :-)

- The "buffer is pinned count" statistics are not consistent with what we've seen from 10g:

* The "unique index" variant already misses 90,000 pins, but does not produce more consistent gets, so in total we do not arrive at the anticipated 500,000 buffer visits any more - either something seems to be missing from the instrumentation or Oracle does something fundamentally different
* The "non-unique index" variant however records 10,000 excess pinned buffers, so we end up with 510,000 buffer visits recorded in total

Let's repeat the same with the T1 and T2 data ordered in the same way - but not ordered by ID (so simply uncomment the second call to DBMS_RANDOM.SEED(0)):

11.2.0.1 Classic Nested Loop - Same random order

Inner row source Unique Index - T1 same random order as T2

---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 202K(100)| 1 |00:00:03.55 | 310K|
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:03.55 | 310K|
| 2 | NESTED LOOPS | | 1 | 100K| 202K (1)| 100K|00:00:03.35 | 310K|
| 3 | TABLE ACCESS FULL | T2 | 1 | 100K| 2720 (1)| 100K|00:00:00.22 | 10010 |
| 4 | TABLE ACCESS BY INDEX ROWID| T1 | 100K| 1 | 2 (0)| 100K|00:00:02.41 | 300K|
|* 5 | INDEX UNIQUE SCAN | T1_IDX | 100K| 1 | 1 (0)| 100K|00:00:00.77 | 200K|
---------------------------------------------------------------------------------------------------------------


Inner row source Non-Unique Index - T1 same random order as T2

---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 202K(100)| 1 |00:00:04.23 | 221K|
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:04.23 | 221K|
| 2 | NESTED LOOPS | | 1 | 100K| 202K (1)| 100K|00:00:04.02 | 221K|
| 3 | TABLE ACCESS FULL | T1 | 1 | 100K| 2720 (1)| 100K|00:00:00.21 | 10010 |
| 4 | TABLE ACCESS BY INDEX ROWID| T2 | 100K| 1 | 2 (0)| 100K|00:00:03.10 | 211K|
|* 5 | INDEX RANGE SCAN | T2_IDX | 100K| 1 | 1 (0)| 100K|00:00:01.09 | 201K|
---------------------------------------------------------------------------------------------------------------


So, that's interesting: We can already see here the same optimization for the non-unique index kicking in as we saw in 10g with Table Prefetching, although the classic plan shape gets used.

The statistics correspond to the result - but there is a slight difference to the 10.2 Table Prefetching case: The "buffer is pinned count" is at least "self-consistent" for the "non-unique index" variant, so there is no "excess" pinning recorded as with the Table Prefetching.

Statistics Name Unique Non-Unique Difference
----------------------------------------------------- -------- ----------- -----------
STAT..table scan blocks gotten 10,000 10,000 0
STAT..table scan rows gotten 100,000 100,000 0
STAT..table fetch by rowid 100,000 100,002 2
LATCH.cache buffers chains 320,030 342,242 22,212
STAT..consistent gets 310,012 221,124 -88,888
STAT..consistent gets from cache 310,012 221,124 -88,888
STAT..session logical reads 310,012 221,124 -88,888
STAT..Cached Commit SCN referenced 110,000 20,007 -89,993
STAT..index fetch by key 100,000 2 -99,998
STAT..rows fetched via callback 100,000 2 -99,998
STAT..index scans kdiixs1 0 100,000 100,000
STAT..consistent gets from cache (fastpath) 10,011 121,117 111,106
STAT..no work - consistent read gets 10,001 121,107 111,106
STAT..buffer is not pinned count 200,002 10,028 -189,974
STAT..buffer is pinned count 99,999 289,977 189,978
STAT..consistent gets - examination 300,001 100,007 -199,994


Redundant Filter Optimization

As I've just demonstrated the inner table lookup for the "unique index" variant does not use the buffer pinning optimization. It's an interesting little detail that in 11.1.0.7 and 11.2.0.1 putting a filter on the inner table lookup changes the result for the "unique index" variant, so running a query like this using a redundant filter that doesn't change the overall result:

select
max(b_filler), max(a_filler)
from (
select /*+ leading(a) use_nl(a b) opt_param('_nlj_batching_enabled', 0) no_nlj_prefetch(b) */
a.id as a_id, a.filler as a_filler, b.id as b_id, b.filler as b_filler
from
t2 a
, t1 b
where
a.id = b.id
and substr(b.filler, 1, 1) = 'x'
);


will result in such an output:

---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 202K(100)| 1 |00:00:03.25 | 220K|
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:03.25 | 220K|
| 2 | NESTED LOOPS | | 1 | 1000 | 202K (1)| 100K|00:00:03.05 | 220K|
| 3 | TABLE ACCESS FULL | T2 | 1 | 100K| 2720 (1)| 100K|00:00:00.21 | 10010 |
|* 4 | TABLE ACCESS BY INDEX ROWID| T1 | 100K| 1 | 2 (0)| 100K|00:00:02.12 | 210K|
|* 5 | INDEX UNIQUE SCAN | T1_IDX | 100K| 1 | 1 (0)| 100K|00:00:00.77 | 200K|
---------------------------------------------------------------------------------------------------------------


Session Statistics:

Statistics Name Unique Non-Unique Difference
----------------------------------------------------- -------- ----------- -----------
STAT..buffer is pinned count 289,998 289,977 -21
STAT..buffer is not pinned count 10,003 10,028 25
LATCH.JS queue state obj latch 0 36 36
LATCH.row cache objects 67 110 43
STAT..CPU used when call started 59 119 60
STAT..DB time 59 119 60
STAT..CPU used by this session 56 119 63
LATCH.enqueues 2 78 76
LATCH.enqueue hash chains 3 80 77
LATCH.simulator hash latch 9,111 9,304 193
STAT..consistent gets 220,012 221,124 1,112
STAT..consistent gets from cache 220,012 221,124 1,112
STAT..session logical reads 220,012 221,124 1,112
STAT..consistent gets - examination 200,001 100,007 -99,994
STAT..index fetch by key 100,000 2 -99,998
STAT..index scans kdiixs1 0 100,000 100,000
STAT..consistent gets from cache (fastpath) 20,011 121,117 101,106
STAT..no work - consistent read gets 20,001 121,107 101,106
LATCH.cache buffers chains 240,024 342,248 102,224


The interesting part here is that the "unique index" variant now uses the same buffer pinning optimization as the "non-unique index" one - but resorts to "normal" consistent gets (using the "fastpath" version in this case) for the random table access.

I don't know if this is feature or a side-effect of a bug because it ceases to work in 11.2.0.2 - there the "unique index" variant can not be convinced to make use of the "buffer pinning" optimization, it always performs the "shortcut" logical I/O on in the inner table lookup even with a filter specified.

We'll see later on that this has some interesting consequences with concurrent executions.

Ordered Data Sets

OK, now finally the big one: Let's repeat the test case with data sorted by ID, so by using the ORDER BY ID instead of ORDER BY DBMS_RANDOM.VALUE when populating the tables:

11.2.0.1 Classic Nested Loop - data ordered by ID

Inner row source Unique Index - T1 and T2 ordered by ID

---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 202K(100)| 1 |00:00:03.42 | 122K|
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:03.42 | 122K|
| 2 | NESTED LOOPS | | 1 | 100K| 202K (1)| 100K|00:00:03.21 | 122K|
| 3 | TABLE ACCESS FULL | T2 | 1 | 100K| 2720 (1)| 100K|00:00:00.21 | 10010 |
| 4 | TABLE ACCESS BY INDEX ROWID| T1 | 100K| 1 | 2 (0)| 100K|00:00:02.27 | 112K|
|* 5 | INDEX UNIQUE SCAN | T1_IDX | 100K| 1 | 1 (0)| 100K|00:00:00.55 | 12314 |
---------------------------------------------------------------------------------------------------------------


Inner row source Non-Unique Index - T1 and T2 ordered by ID

---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 202K(100)| 1 |00:00:03.64 | 33143 |
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:03.64 | 33143 |
| 2 | NESTED LOOPS | | 1 | 100K| 202K (1)| 100K|00:00:03.45 | 33143 |
| 3 | TABLE ACCESS FULL | T1 | 1 | 100K| 2720 (1)| 100K|00:00:00.20 | 10010 |
| 4 | TABLE ACCESS BY INDEX ROWID| T2 | 100K| 1 | 2 (0)| 100K|00:00:02.55 | 23133 |
|* 5 | INDEX RANGE SCAN | T2_IDX | 100K| 1 | 1 (0)| 100K|00:00:00.67 | 13126 |
---------------------------------------------------------------------------------------------------------------


The result is staggering: The "non-unique" index variant apparently manages to visit 500,000 buffers with just 33K logical I/Os. It is also almost as fast as the "unique index" variant that obviously does not keep the buffers pinned for the inner table random lookup - let's check the session statistics:

Statistics Name Unique Non-Unique Difference
----------------------------------------------------- -------- ----------- -----------
STAT..table scan blocks gotten 10,000 10,000 0
STAT..table scan rows gotten 100,000 100,000 0
STAT..table fetch by rowid 100,000 100,002 2
STAT..consistent gets from cache (fastpath) 11,059 26,587 15,528
STAT..no work - consistent read gets 11,049 26,577 15,528
LATCH.cache buffers chains 133,384 60,829 -72,555
STAT..consistent gets 122,324 33,149 -89,175
STAT..consistent gets from cache 122,324 33,149 -89,175
STAT..session logical reads 122,324 33,149 -89,175
STAT..index fetch by key 100,000 2 -99,998
STAT..rows fetched via callback 100,000 2 -99,998
STAT..index scans kdiixs1 0 100,000 100,000
STAT..consistent gets - examination 111,265 5,470 -105,795
STAT..buffer is not pinned count 200,014 10,028 -189,986
STAT..buffer is pinned count 5,107 195,440 190,333


We can tell now different things from these statistics:

- The "non-unique index" variant requires just 60,000 latch acquisitions - which corresponds to the reduced number of logical I/Os

- The session statistics only "explain" 195,000 buffer visits via already pinned and 33,000 buffer visits recorded as logical I/Os, so we are missing approx. 270,000 buffer visits from the statistics. Compared to the results of the "unordered" test case we actually see a "reduction" of buffers visited that are already pinned (199,993 vs. 195,440), so that seems to be questionable

- The "unique index" variant still does the "short-cut" logical I/O on the inner table random lookup and hence requires actually more logical I/O and latch acquisitions in this case than the "non-unique index" variant

As we've seen above if in 11.1.0.7 and 11.2.0.1 a filter is put on the inner table random lookup Oracle 11g switches to "normal" consistent gets for the "unique index" variant, and in fact when repeating this experiment with the ordered data set, we see these results:

---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 202K(100)| 1 |00:00:02.97 | 32315 |
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:02.97 | 32315 |
| 2 | NESTED LOOPS | | 1 | 1000 | 202K (1)| 100K|00:00:02.76 | 32315 |
| 3 | TABLE ACCESS FULL | T2 | 1 | 100K| 2720 (1)| 100K|00:00:00.22 | 10010 |
|* 4 | TABLE ACCESS BY INDEX ROWID| T1 | 100K| 1 | 2 (0)| 100K|00:00:01.81 | 22305 |
|* 5 | INDEX UNIQUE SCAN | T1_IDX | 100K| 1 | 1 (0)| 100K|00:00:00.56 | 12302 |
---------------------------------------------------------------------------------------------------------------


So by switching to the "normal" consistent gets the buffer pinning optimization gets used for the inner table lookup also for the "unique index" variant (only reproducible in 11.1.0.7 and 11.2.0.1). The session statistics:

Statistics Name Unique Non-Unique Difference
----------------------------------------------------- -------- ----------- -----------
STAT..table scan blocks gotten 10,000 10,000 0
STAT..table scan rows gotten 100,000 100,000 0
STAT..table fetch by rowid 100,000 100,002 2
STAT..buffer is not pinned count 10,018 10,028 10
STAT..buffer is pinned count 195,103 195,440 337
STAT..consistent gets 32,315 33,149 834
STAT..consistent gets from cache 32,315 33,149 834
STAT..session logical reads 32,315 33,149 834
STAT..consistent gets from cache (fastpath) 21,050 26,587 5,537
STAT..no work - consistent read gets 21,040 26,577 5,537
STAT..consistent gets - examination 11,265 5,470 -5,795
LATCH.cache buffers chains 53,366 60,835 7,469
STAT..index fetch by key 100,000 2 -99,998
STAT..index scans kdiixs1 0 100,000 100,000


So we see now the "unique index" variant with similar results and the also a similar "gap" in the buffer visits explained by the statistics.

A slightly funny point is that by adding a "useless" filter we seem to arrive actually at a faster execution time due to the optimization kicking in - something that looks quite counter-intuitive and only seems to work in particular versions.

"Fastpath" consistent gets

To see if this optimization depends on the new "fastpath" consistent gets, let's turn this new feature off by setting "_fastpin_enable" to 0 and restarting the instance:

alter system set "_fastpin_enable" = 0 scope = spfile;


I'm showing here the results for the "inner table filter" variation - but those for the original case without the additional filter are also corresponding to those with "fast pinning" enabled:

11.2.0.1 Classic Nested Loop - data ordered by ID, fast pins disabled, inner table filter

Inner row source Unique Index - T1 and T2 ordered by ID

---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 202K(100)| 1 |00:00:02.90 | 32315 |
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:02.90 | 32315 |
| 2 | NESTED LOOPS | | 1 | 1000 | 202K (1)| 100K|00:00:02.70 | 32315 |
| 3 | TABLE ACCESS FULL | T2 | 1 | 100K| 2720 (1)| 100K|00:00:00.21 | 10010 |
|* 4 | TABLE ACCESS BY INDEX ROWID| T1 | 100K| 1 | 2 (0)| 100K|00:00:01.79 | 22305 |
|* 5 | INDEX UNIQUE SCAN | T1_IDX | 100K| 1 | 1 (0)| 100K|00:00:00.53 | 12302 |
---------------------------------------------------------------------------------------------------------------


Inner row source Non-Unique Index - T1 and T2 ordered by ID

---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 202K(100)| 1 |00:00:03.86 | 33143 |
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:03.86 | 33143 |
| 2 | NESTED LOOPS | | 1 | 1000 | 202K (1)| 100K|00:00:03.67 | 33143 |
| 3 | TABLE ACCESS FULL | T1 | 1 | 100K| 2720 (1)| 100K|00:00:00.21 | 10010 |
|* 4 | TABLE ACCESS BY INDEX ROWID| T2 | 100K| 1 | 2 (0)| 100K|00:00:02.74 | 23133 |
|* 5 | INDEX RANGE SCAN | T2_IDX | 100K| 1 | 1 (0)| 100K|00:00:00.71 | 13126 |
---------------------------------------------------------------------------------------------------------------


So the same optimization kicked in, and we can tell from the session statistics that the "fastpath" consistent gets indeed have not been used:

Statistics Name Unique Non-Unique Difference
----------------------------------------------------- -------- ----------- -----------
STAT..table scan blocks gotten 10,000 10,000 0
STAT..table scan rows gotten 100,000 100,000 0
STAT..table fetch by rowid 100,000 100,002 2
STAT..buffer is not pinned count 10,018 10,028 10
STAT..buffer is pinned count 195,103 195,440 337
STAT..consistent gets 32,315 33,149 834
STAT..consistent gets from cache 32,315 33,149 834
STAT..session logical reads 32,315 33,149 834
STAT..no work - consistent read gets 21,040 26,577 5,537
STAT..consistent gets - examination 11,265 5,470 -5,795
LATCH.cache buffers chains 53,372 60,829 7,457
STAT..index fetch by key 100,000 2 -99,998
STAT..index scans kdiixs1 0 100,000 100,000


The only significant difference is the absence of the "consistent gets from cache (fastpath)" statistics.

Nested Loop Join Batching

Finally let's check if the new "Nested Loop Batching" optimization does have any additional effects on the test case here by enabling the Nested Loop Join Batching. Changing the hints like this does the job:

.
.
.
select /*+ leading(a) use_nl(a b) opt_param('_nlj_batching_enabled', 1) no_nlj_prefetch(b) */
.
.
.


11.2.0.1 Nested Loop Batching - data ordered by ID, inner table filter

Inner row source Unique Index - T1 and T2 ordered by ID

---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 202K(100)| 1 |00:00:02.89 | 32306 |
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:02.89 | 32306 |
| 2 | NESTED LOOPS | | 1 | | | 100K|00:00:02.70 | 32306 |
| 3 | NESTED LOOPS | | 1 | 1000 | 202K (1)| 100K|00:00:01.43 | 22306 |
| 4 | TABLE ACCESS FULL | T2 | 1 | 100K| 2720 (1)| 100K|00:00:00.20 | 10010 |
|* 5 | INDEX UNIQUE SCAN | T1_IDX | 100K| 1 | 1 (0)| 100K|00:00:00.53 | 12296 |
|* 6 | TABLE ACCESS BY INDEX ROWID| T1 | 100K| 1 | 2 (0)| 100K|00:00:00.57 | 10000 |
---------------------------------------------------------------------------------------------------------------


Inner row source Non-Unique Index - T1 and T2 ordered by ID

---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 202K(100)| 1 |00:00:03.05 | 33128 |
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:03.05 | 33128 |
| 2 | NESTED LOOPS | | 1 | | | 100K|00:00:02.85 | 33128 |
| 3 | NESTED LOOPS | | 1 | 1000 | 202K (1)| 100K|00:00:01.57 | 23128 |
| 4 | TABLE ACCESS FULL | T1 | 1 | 100K| 2720 (1)| 100K|00:00:00.20 | 10010 |
|* 5 | INDEX RANGE SCAN | T2_IDX | 100K| 1 | 1 (0)| 100K|00:00:00.67 | 13118 |
|* 6 | TABLE ACCESS BY INDEX ROWID| T2 | 100K| 1 | 2 (0)| 100K|00:00:00.57 | 10000 |
---------------------------------------------------------------------------------------------------------------


Apart from some minor differences in the number of logical I/Os it doesn't change the outcome. The same applies to the session statistics:

Statistics Name Unique Non-Unique Difference
----------------------------------------------------- -------- ----------- -----------
STAT..table scan blocks gotten 10,000 10,000 0
STAT..table scan rows gotten 100,000 100,000 0
STAT..table fetch by rowid 100,000 100,002 2
STAT..buffer is not pinned count 10,006 10,010 4
STAT..buffer is pinned count 195,115 195,458 343
STAT..consistent gets 32,306 33,134 828
STAT..consistent gets from cache 32,306 33,134 828
STAT..session logical reads 32,306 33,134 828
STAT..consistent gets from cache (fastpath) 21,041 26,572 5,531
STAT..no work - consistent read gets 21,031 26,562 5,531
STAT..consistent gets - examination 11,265 5,470 -5,795
LATCH.cache buffers chains 53,348 60,816 7,468
STAT..index fetch by key 100,000 2 -99,998
STAT..index scans kdiixs1 0 100,000 100,000


What is interesting to see however is that it seems to perform faster, in particular the "non-unique index" variant is now really pretty close to the "unique index" variant - so although the Nested Loop Join Batching doesn't show any significant changes in the statistics and latch acquisition, it seems to save CPU cycles and performs better even without any physical I/O involved.

As a side note, if you want to check the effects of the "Nested Loop Join Batching" on physical I/O you need to be aware of an odd behaviour I've experienced during my tests: If any kind of row source statistics sampling was enabled by either using STATISTICS_LEVEL = ALL, the GATHER_PLAN_STATISTICS hint or even enabling (extended) SQL trace, the optimized, batched form of physical I/O could not be reproduced. You could tell this from the session statistics that start with "Batched IO%" - these all stayed at 0. Only when disabling all these things the effects were visible and the corresponding statistics where non-zero. I don't know why this is the case, but it is an important detail when testing this feature. I'll probably publish a separate post on the physical I/O optimizations of the Vector/Batched I/O at some time in the future.

Scalability

When running the "data ordered by ID" version concurrently it can be seen that the "non-unique index" variant scales now almost equally well as the "unique index" variant - so these two variants are now quite close not only in single-user mode, but they both scale very well, too.

There is another interesting effect that can only be observed when running the test case with the unordered data set concurrently: In recent code releases (10.2.0.5, 11.2.0.1 and 11.2.0.2) the "shortcut" consistent gets on the inner table lookup that are used with the "unique index" variant gets "downgraded" to "normal" consistent gets if there is concurrent access to the block. This can be observed in the session statistics and latch acquisitions:

Statistics Name Value
----------------------------------------------------- -----------
STAT..shared hash latch upgrades - no wait 99,995
STAT..RowCR attempts 100,000
STAT..RowCR hits 100,000
STAT..consistent gets from cache (fastpath) 10,011
STAT..no work - consistent read gets 10,000
STAT..consistent gets - examination 200,013
STAT..consistent gets 310,024
STAT..consistent gets from cache 310,024
LATCH.cache buffers chains 1,680,173


Note in particular how the "consistent gets - examination" statistics have been decreased from 300,000 to 200,000. So with four concurrent executions this "unique index" variant suddenly requires approx. 420,000 latch acquisitions per execution in contrast to the usual 320,000. Since 11.2.0.2 does not support the "filter" trick to make use of the buffer pinning optimization for the inner table lookup with the ordered data set and the "unique index" variant, it suffers twice: Not only it requires single latch acquisitions for the inner table lookup but due to the "downgrade" it performs two latch acquisitions per iteration requiring a whopping 200,000 excess latch acquisitions per concurrent execution with the ordered by ID data set.

It's also interesting to note that the "RowCR" optimization is recorded in the session statistics. I couldn't find much information about this - it seems to be in the code since 10.2 (partial support already in 9.2 RAC), but until 10.2.0.5 it is only enabled in RAC mode and not in single-instance mode (see MOS note "Bug 4951888 - Row CR is not enabled for non RAC systems"). I could reproduce this only in 10.2.0.5, 11.2.0.1 and 11.2.0.2. According to the description it has been specifically introduced for using row-level consistent gets instead of rolling back complete block versions for read-consistency in RAC environments where generating the previous version of a block might require undo blocks from remote instances. Why this optimization shows up in the above single-instance, read-only scenario where no rollback to the block version is required is not clear to me. It is however measurable that the "fallback" seems to slow down execution.

Whether this is a side-effect or a deliberate design choice that performs better in RAC environments or certain consistent read scenarios I can't tell yet, however when switching off this optimization via "alter system set "_row_cr" = false" this "downgrade" with concurrent execution doesn't happen any longer, and 11.2.0.2 performs better in my test cases, although it doesn't bring back the "filter" trick, so 11.2.0.2 is the only release where the "non-unique index" variant scales better with the ordered data set than the "unique index" variant.

A final word on scalability in general: I think it is important to point out that the test harness provided so far only checks for concurrent read access. Since it is interesting to see if the "buffer pinning" optimization observed does have any negative side effects on mixed read/write access to the buffers I've published an updated script set that includes new versions of the concurrent execution master and slave scripts. These allow to run a SELECT FOR UPDATE on both tables involved as first session, and all other sessions in read-only mode in order to test the effects of a mixed read/write concurrency scenario.

The result of this quite simple test shows that the buffer pinning optimization not only scales very well for read-only concurrency but also scales very good for the tested mixed read-write scenario. The provided test case might be a specific and simplistic case (there are some specialities with SELECT FOR UPDATE) and there might be other concurrency scenarios where the buffer pinning might not scale that well (for example potentially "free buffer waits" due to many blocks being pinned) but at least with this test case the result is quite impressive.

As a side note, the mixed read-write test is very interesting on its own in several ways, for example:

- It adds additional pressure on the buffer cache due to clone copies created. A query similar to the one provided by Jonathan Lewis here can be quite revealing. You'll find out that you need a much larger cache to still have a fully cached test case (with 8KB block size at least 512MB for keeping two 80MB segments! fully cached)

- It requires additional buffer cache for the undo blocks

- It will generate a much higher contention on the "cache buffers chains" latches due to the additional buffer cache activity (creating clone copies, rollbacks for consistent reads, current mode gets etc.)

- It requires applying undo to the blocks to arrive at a read-consistent version

- The buffers will have to be accessed in exclusive mode for write access

The updated script set also contains an Excel sheet with results from my test runs on different hardware and Oracle versions as well as a sample query to analyse the buffer cache.

Summary

Oracle 11g extends the logical I/O optimizations that could already been seen in Oracle 10g when using the Table Prefetching Nested Loop shape - and it is available without any further optimizations like Table Prefetching or Nested Loop Join Batching. It is also not depending on the new "fastpath" consistent gets introduced with 11g.

The efficiency of the optimization largely depends on the order of the data, so predicting it is not that easy - a bit similar to predicting the efficiency of the Subquery / Filter caching feature that also depends on data patterns.

However this knowledge might offer additional options how to take advantage of this optimization. Of course introducing additional sort operations might easily outweigh the benefits achieved, but there might be cases where a sort is not that costly and allows to improve scalability/concurrency in extreme cases.

Closing remarks

This blog post got way too long

Monday, July 25, 2011

Logical I/O - Evolution: Part 2 - 9i, 10g Prefetching

In the initial part of this series I've explained some details regarding logical I/O using a Nested Loop Join as example.

To recap I've shown in particular:

- Oracle can re-visit pinned buffers without performing logical I/O

- There are different variants of consistent gets - a "normal" one involving buffer pin/unpin cycles requiring two latch acquisitions and a short-cut variant that visits the buffer while holding the corresponding "cache buffers chains" child latch ("examination") and therefore only requiring a single latch acquisition

- Although two statements use a similar execution plan and produce the same number of logical I/Os one is significantly faster and scales better than the other one

The initial part used the "classic" shape of the Nested Loop Join, but Oracle introduced in recent releases various enhancements in that area - in particular in 9i the "Table Prefetching" and in 11g the Nested Loop Join Batching using "Vector/Batched I/O".

Although these enhancements have been introduced primarily to optimize the physical I/O patterns, they could also have an influence on logical I/O.

The intention of Prefetching and Batching seems to be the same - they both are targeted towards the usually most expensive part of the Nested Loop Join: The random table lookup as part of the inner row source. By trying to "prefetch" or "batch" physical I/O operations caused by this random block access Oracle attempts to minimize the I/O waits.

I might cover the effect on physical I/O of both "Prefetching" and "Batching" in separate posts, here I'll only mention that you might see "db file scattered read" or "db file parallel read" multi-block I/O operations instead of single block "db file sequential read" operations for the random table access with those optimizations (Index prefetching is also possible, by the way). Note also that if you see the Prefetching or Batching plan shape it does not necessarily mean that it is actually going to happen at execution time - Oracle monitors the effectiveness of the Prefetching and can dynamically decide whether it will be used or not.

10.2.0.4 Table Prefetching - Random order

Let's enable table prefetching in 10.2 and re-run the original test case. The first run will use the different order variant of T1 and T2:

Inner row source Unique Index - T1 different order than T2


---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:04.12 | 310K|
| 2 | NESTED LOOPS | | 1 | 100K| 202K (1)| 100K|00:00:03.90 | 310K|
| 3 | TABLE ACCESS FULL | T2 | 1 | 100K| 2716 (1)| 100K|00:00:00.30 | 10010 |
| 4 | TABLE ACCESS BY INDEX ROWID| T1 | 100K| 1 | 2 (0)| 100K|00:00:02.71 | 300K|
|* 5 | INDEX UNIQUE SCAN | T1_IDX | 100K| 1 | 1 (0)| 100K|00:00:01.20 | 200K|
---------------------------------------------------------------------------------------------------------------


Inner row source Non-Unique Index - T1 different order than T2


--------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:05.03 | 311K|
| 2 | TABLE ACCESS BY INDEX ROWID| T2 | 1 | 1 | 2 (0)| 100K|00:00:04.40 | 311K|
| 3 | NESTED LOOPS | | 1 | 100K| 202K (1)| 200K|00:00:03.02 | 211K|
| 4 | TABLE ACCESS FULL | T1 | 1 | 100K| 2716 (1)| 100K|00:00:00.30 | 10010 |
|* 5 | INDEX RANGE SCAN | T2_IDX | 100K| 1 | 1 (0)| 100K|00:00:01.49 | 201K|
--------------------------------------------------------------------------------------------------------------


As you'll see, in 10g even with table prefetching enabled the unique index variant does look the same and performs similar as in the original post.

This changes in 11g by the way, where the unique index variant also supports the table prefetching plan shape.

For the non-unique variant you'll see a different shape of the execution plan where the inner row source random table lookup is actually a parent operation to the Nested Loop Join (and hence will only be started once and consumes the information generated by the child Nested Loop operation).

Note that in case of nested Nested Loop Joins only the inner-most row source will make use of the Table Prefetching shape. The same applies to the 11g Nested Loop Join Batching. If you happen to have several Nested Loops Joins that are not directly nested then each of the inner-most row sources might use the Table Prefetching/Batching shape - which means that it can be used more than once as part of a single execution plan.

If you compare the Runtime profile of the non-unique index variant with the original Runtime profile without Table Prefetching you'll not see any difference in terms of logical I/O, however it becomes obvious that the overall execution is actually slightly faster (more significant with row source sampling overhead enabled). In particular the random table access requires significantly less time than in the original Runtime profile, so it seems to be more efficient, although it is still slower than the unique index variant.

Begin Update

Having focused on the logical I/O I completely forgot to mention the inconsistency in the A-Rows column (thanks to Flado who pointed this out in his comment below), which shows 200K rows for the Nested Loop operation although only 100K rows have been identified in the inner index lookup. I believe this is an inconsistency that also shows up when performing an SQL trace so it seems to be a problem with the row source statistics. In principle with this plan shape the Nested Loop Join operation seems to account for the sum of both the rows identified in the driving row source and the inner index lookup, rather than the expected number of rows identified in the inner index lookup only.

However, as mentioned below in the "Statistics" section there is another anomaly - a consistent get and "buffer is pinned count" for every row looked up in the inner table, so this might not be just coincidence but another indicator that there is really some excess work happening with Table Prefetching.

By the way - both anomalies are still present in 11.1 / 11.2 when using Table Prefetching there.

End Update

Let's have a look at the session statistics.


Statistics Name Unique Non-Unique Difference
----------------------------------------------------- -------- ----------- -----------
STAT..table scan blocks gotten 10,000 10,000 0
STAT..table scan rows gotten 100,000 100,000 0
STAT..table fetch by rowid 100,000 100,002 2
STAT..consistent gets 310,012 311,101 1,089
STAT..consistent gets from cache 310,012 311,101 1,089
STAT..session logical reads 310,012 311,101 1,089
STAT..index fetch by key 100,000 2 -99,998
STAT..rows fetched via callback 100,000 2 -99,998
STAT..index scans kdiixs1 0 100,000 100,000
STAT..buffer is not pinned count 200,001 99,997 -100,004
STAT..buffer is pinned count 189,998 290,006 100,008
STAT..consistent gets - examination 300,001 100,007 -199,994
STAT..no work - consistent read gets 10,001 211,084 201,083
LATCH.cache buffers chains 320,031 522,195 202,164


So the only significant difference in this case is the increased "buffer is pinned count" / decreased "buffer is not pinned" count statistics, although the number of logical I/O stays the same. I don't know if this really means excess work with Table Prefetching enabled or whether this is an instrumentation problem. Nevertheless with Table Prefetching enabled in this case you'll end up with both a "buffer is pinned count" and "consistent get" for each row looked up in the inner row source table operation. The number of logical I/O and latch acquisitions stays the same, so it's not obvious from the statistics why this performs better than the non-Table Prefetching case - according to the statistics it even performs more work, but may be the table random access as parent operation to the Nested Loop allows a more efficient processing requiring less CPU cycles.

10.2.0.4 Table Prefetching - Same (Random) order

Let's change the data order and use either the same "Pseudo-Random" order (by uncommenting the second "dbms_random.seed(0)" call) or order by ID - it doesn't matter with Table Prefetching in 10g.

Inner row source Unique Index - T1 and T2 same order


---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:03.91 | 310K|
| 2 | NESTED LOOPS | | 1 | 100K| 202K (1)| 100K|00:00:03.70 | 310K|
| 3 | TABLE ACCESS FULL | T2 | 1 | 100K| 2716 (1)| 100K|00:00:00.30 | 10010 |
| 4 | TABLE ACCESS BY INDEX ROWID| T1 | 100K| 1 | 2 (0)| 100K|00:00:02.54 | 300K|
|* 5 | INDEX UNIQUE SCAN | T1_IDX | 100K| 1 | 1 (0)| 100K|00:00:01.14 | 200K|
---------------------------------------------------------------------------------------------------------------


Inner row source Non-Unique Index - T1 and T2 same order


--------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
--------------------------------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:04.54 | 221K|
| 2 | TABLE ACCESS BY INDEX ROWID| T2 | 1 | 1 | 2 (0)| 100K|00:00:03.90 | 221K|
| 3 | NESTED LOOPS | | 1 | 100K| 202K (1)| 200K|00:00:02.82 | 211K|
| 4 | TABLE ACCESS FULL | T1 | 1 | 100K| 2716 (1)| 100K|00:00:00.30 | 10010 |
|* 5 | INDEX RANGE SCAN | T2_IDX | 100K| 1 | 1 (0)| 100K|00:00:01.40 | 201K|
--------------------------------------------------------------------------------------------------------------


Now we really see a difference: The unique index variant still shows the same results, but the non-unique variant saves logical I/O on the random table access - and is faster than with random order - coming closer to the unique index variant performance.

Whereas the index range scan still requires approx. 200,000 logical I/Os the random table access only requires 10,000 logical I/Os instead of 100,000.

The session statistics:


Statistics Name Unique Non-Unique Difference
----------------------------------------------------- -------- ----------- -----------
STAT..table scan blocks gotten 10,000 10,000 0
STAT..table scan rows gotten 100,000 100,000 0
STAT..table fetch by rowid 100,000 100,002 2
LATCH.cache buffers chains 320,023 342,213 22,190
STAT..consistent gets 310,012 221,110 -88,902
STAT..consistent gets from cache 310,012 221,110 -88,902
STAT..session logical reads 310,012 221,110 -88,902
STAT..index fetch by key 100,000 2 -99,998
STAT..rows fetched via callback 100,000 2 -99,998
STAT..index scans kdiixs1 0 100,000 100,000
STAT..no work - consistent read gets 10,001 121,093 111,092
STAT..buffer is not pinned count 200,001 10,006 -189,995
STAT..buffer is pinned count 189,998 379,997 189,999
STAT..consistent gets - examination 300,001 100,007 -199,994


The session statistics confirm this: The "buffer is pinned count" increases by another 90,000 for the non-unique index variant which corresponds to the 90,000 logical I/Os performed less as part of the random table access operation.

The number of latch acquisitions decreases accordingly so that we end up with a comparable number as with the unique index variant.

Scalability

If you run the non-unique index Table Prefetching variant with the concurrent execution test harness you'll see a corresponding slightly increased scalability although it still scales not as good as the unique index variant.

Summary

Table Prefetching has been introduced in Oracle 9i in order to optimize the random physical access in Nested Loop Joins, however it also seems to have a positive effect on logical I/O. The effectiveness of this optimization depends on the data order - if the data from the driving row source is in the same order as the inner row source table buffers can be kept pinned. Note that the same doesn't apply to the index lookup - even if the data is ordered by ID and consequently the same index branch and leaf blocks will be accessed repeatedly with each iteration, a buffer pinning optimization could not be observed.

In the next part we'll see what happens with this example in Oracle 11g and its new features.

Thursday, July 7, 2011

Logical I/O - Evolution: Part 1 - Baseline

Forward to Part 2

This is the first part in a series of blog posts that shed some light on the enhancements Oracle has introduced with the recent releases regarding the optimizations of logical I/O.http://www.blogger.com/img/blank.gif

Before we can appreciate the enhancements, though, we need to understand the baseline. This is what this blog post is about.

The example used throughout this post is based on a simple Nested Loop Join which is one area where Oracle has introduced significant enhancements.

It started its life as a comparison of using unique vs. non-unique indexes as part of a Nested Loop Join and their influence on performance and scalability.

This comparison on its own is very educating and also allows to demonstrate and explain some of the little details regarding logical I/O.

Here is the basic script that gets used. It creates two tables with a primary defined, one table using a unique index, the other one a non-unique index.

The tables are specifically crafted to have exactly 100,000 rows with 10 rows per block resulting in 10,000 blocks (using the MINIMIZE RECORDS_PER_BLOCK option). These "obvious" numbers hopefully allow for nice pattern recognition in the resulting figures. Using the default 8K block size the resulting indexes will have slightly more than 1,000 blocks.

It will run then a Nested Loop Join from one table to the other and then the other way around along with a snapshot of the session statistics using Adrian Billington's RUNSTATS package which is based on Tom Kyte's well known package of the same name. You can get it from here.

If you run this against 9i to 10.2 you'll need to disable table prefetching to get the results explained here. This can only be done by setting the static parameter "_table_lookup_prefetch_size" equal to 0 which requires to restart the instance.

11g allows to control the behaviour via various hints and parameters, see the script for more details.

In order to be in line with the baseline explanations presented here this should be executed against pre-11g since 11g introduces some significant changes that will be covered in upcoming posts.


--------------------------------------------------------------------------------
--
-- File name: unique_non_unique_index_difference.sql
--
-- Purpose: Compare the efficiency of NESTED LOOP joins via index lookup
-- between unique and non-unique indexes
--
-- Author: Randolf Geist http://oracle-randolf.blogspot.com
--
-- Prereqs: RUNSTATS_PKG by Adrian Billington / Tom Kyte
--
-- Last tested: June 2011
--
-- Versions: 10.2.0.4
-- 10.2.0.5
-- 11.1.0.7
-- 11.2.0.1
-- 11.2.0.2
--------------------------------------------------------------------------------

set echo on timing on linesize 130 pagesize 999 trimspool on tab off serveroutput off doc on

doc
From 9i to 10.2 you need to disable table prefetching
to get the "original" version of NL joins

-- Disable table prefetchting
alter system set "_table_lookup_prefetch_size" = 0 scope = spfile;

-- Back to defaults
alter system reset "_table_lookup_prefetch_size" scope = spfile sid = '*';

From 11g on this can handled via the nlj_prefetch and nlj_batching hints

But they work a bit counterintuitive when combined therefore

opt_param('_nlj_batching_enabled', 0)

is also required to get exactly the NL join optimization requested

Since this is about logical I/O, not physical I/O you need sufficient cache
defined (256M should be fine) otherwise the results will differ
when physical I/O happens
#

spool unique_non_unique_index_difference.log

drop table t1;

purge table t1;

exec dbms_random.seed(0)

-- Random order
-- Create 10 rows in a single block
create table t1
--pctfree 0
as
select
rownum as id
, rpad('x', 100) as filler
from
dual
connect by
level <= 10
order by
-- id
dbms_random.value
;

-- Tell Oracle to store at most 10 rows per block
alter table t1 minimize records_per_block;

truncate table t1;

-- Populate the table, resulting in exactly 10,000 blocks with MSSM
insert /*+ append */ into t1
select
rownum as id
, rpad('x', 100) as filler
from
dual
connect by
level <= 100000
order by
-- id
dbms_random.value
;

-- Force BLEVEL 2 for UNIQUE index (with 8K blocks, root->branch->leaf)
create unique index t1_idx on t1 (id) pctfree 80;

-- Avoid any side effects of dynamic sampling
-- (and perform delayed block cleanout when not using direct-path load)
exec dbms_stats.gather_table_stats(null, 't1', estimate_percent => null)

-- Add PK constraint
alter table t1 add constraint t1_pk primary key (id);

drop table t2;

purge table t2;

-- exec dbms_random.seed(0)

-- Random order (but different from T1 order)
-- Create 10 rows in a single block
create table t2
--pctfree 0
as
select
rownum as id
, rpad('x', 100) as filler
from
dual
connect by
level <= 10
order by
-- id
dbms_random.value
;

-- Tell Oracle to store at most 10 rows per block
alter table t2 minimize records_per_block;

truncate table t2;

-- Populate the table, resulting in exactly 10,000 blocks with MSSM
insert /*+ append */ into t2
select
rownum as id
, rpad('x', 100) as filler
from
dual
connect by
level <= 100000
order by
-- id
dbms_random.value
;

-- Force BLEVEL 2 for NON-UNIQUE index (with 8K blocks, root->branch->leaf)
create index t2_idx on t2 (id) pctfree 80;

-- Avoid any side effects of dynamic sampling
-- (and perform delayed block cleanout when not using direct-path load)
exec dbms_stats.gather_table_stats(null, 't2', estimate_percent => null)

-- Add PK constraint based on non-unique index
alter table t2 add constraint t2_pk primary key (id);

alter session set statistics_level = all;

-- Run the commands once to cache the blocks and get a runtime profile
select
max(b_filler), max(a_filler)
from (
select /*+ leading(a) use_nl(a b) opt_param('_nlj_batching_enabled', 0) no_nlj_prefetch(b) */
a.id as a_id, a.filler as a_filler, b.id as b_id, b.filler as b_filler
from
t2 a
, t1 b
where
a.id = b.id
);

select * from table(dbms_xplan.display_cursor(null, null, '+COST +OUTLINE ALLSTATS LAST'));

select
max(b_filler), max(a_filler)
from (
select /*+ leading(a) use_nl(a b) opt_param('_nlj_batching_enabled', 0) no_nlj_prefetch(b) */
a.id as a_id, a.filler as a_filler, b.id as b_id, b.filler as b_filler
from
t1 a
, t2 b
where
a.id = b.id
);

select * from table(dbms_xplan.display_cursor(null, null, '+COST +OUTLINE ALLSTATS LAST'));

-- Eliminate row source statistics overhead
-- for the "real" test
alter session set statistics_level = typical;

exec runstats_pkg.rs_start

select
max(b_filler), max(a_filler)
from (
select /*+ leading(a) use_nl(a b) opt_param('_nlj_batching_enabled', 0) no_nlj_prefetch(b) */
a.id as a_id, a.filler as a_filler, b.id as b_id, b.filler as b_filler
from
t2 a
, t1 b
where
a.id = b.id
);

exec runstats_pkg.rs_middle

select
max(b_filler), max(a_filler)
from (
select /*+ leading(a) use_nl(a b) opt_param('_nlj_batching_enabled', 0) no_nlj_prefetch(b) */
a.id as a_id, a.filler as a_filler, b.id as b_id, b.filler as b_filler
from
t1 a
, t2 b
where
a.id = b.id
);


set serveroutput on

exec runstats_pkg.rs_stop(-1)

spool off


Expectations

What are the expected results - here explained based on 10.2? This is a nested loop join of 100,000 rows to 100,000 rows table allocating each 10,000 blocks. The inner row source will be using the available index and perform a table lookup by ROWID 100,000 times.

The script specifically crafts the indexes to have a height of 3 (BLEVEL = 2) when using a default block size of 8K which means that they have a root block with a number of branch blocks on the second level and finally the leaf blocks on the third level. Note that different block sizes can lead to different index heights and therefore different results.

In terms of "buffer visits" required to complete the statement we could think of the following:

- 100,000 block visits for the outer row source running a simple full table scan. For every iteration of the loop we need to visit the buffer and read the next row that will be used for the lookup into the inner row source

- 300,000 block visits for the inner row source index lookup, since for every index lookup we need to traverse the index from root to branch to leaf

- 100,000 block visits for the inner row source table lookup by ROWID

So according to this model in total we need to "explain" 500,000 block visits for this example.

Let's have a look at the various results from the script.

1. The runtime profile

a) Running the Nested Loop Join using the "Unique Index" inner row source


Plan hash value: 3952364803

---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:03.95 | 310K|
| 2 | NESTED LOOPS | | 1 | 100K| 202K (1)| 100K|00:00:03.70 | 310K|
| 3 | TABLE ACCESS FULL | T2 | 1 | 100K| 2716 (1)| 100K|00:00:00.30 | 10010 |
| 4 | TABLE ACCESS BY INDEX ROWID| T1 | 100K| 1 | 2 (0)| 100K|00:00:02.59 | 300K|
|* 5 | INDEX UNIQUE SCAN | T1_IDX | 100K| 1 | 1 (0)| 100K|00:00:01.14 | 200K|
---------------------------------------------------------------------------------------------------------------


If everything went as expected you'll see here the "classic" shape of a Nested Loop Join using an index lookup for the inner row source. The loop is driven by the full table scan of the T2 table and for every row produced by that row source the inner row source will be examined starting with an index unique scan in this case followed by an table access by ROWID for those rows found in the index.

Comparing the runtime profile to the model described above one significant difference becomes immediately obvious: The profile only shows 310,000 logical I/Os, not 500,000. So either above model is incorrect or Oracle has introduced some "short-cuts" that allow to avoid approx. 190,000 out of 500,000 logical I/Os. The difference of 190,000 seems to come from the index unique scan which only reports 200,000 logical I/Os instead of the expected 300,000 and the full table scan of T2 driving the nested loop. It reports only 10,000 logical I/Os instead of the 100,000 pictured above. More on those differences in a moment.

b) Running the Nested Loop Join using the "Non-Unique Index" inner row source


Plan hash value: 537985513

---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | Cost (%CPU)| A-Rows | A-Time | Buffers |
---------------------------------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | | 1 |00:00:06.31 | 311K|
| 2 | NESTED LOOPS | | 1 | 100K| 202K (1)| 100K|00:00:06.10 | 311K|
| 3 | TABLE ACCESS FULL | T1 | 1 | 100K| 2716 (1)| 100K|00:00:00.30 | 10010 |
| 4 | TABLE ACCESS BY INDEX ROWID| T2 | 100K| 1 | 2 (0)| 100K|00:00:04.91 | 301K|
|* 5 | INDEX RANGE SCAN | T2_IDX | 100K| 1 | 1 (0)| 100K|00:00:01.77 | 201K|
---------------------------------------------------------------------------------------------------------------


This is very interesting: First of all the cost calculation is the same, so in terms of costs estimates of the optimizer there is no difference between the unique and non-unique case.

However the runtime is significantly different: The non-unique variant is consistently slower than the unique variant.

Furthermore, another minor difference is a slightly increased number of logical I/Os that seems to be caused by the INDEX RANGE SCAN operation (201K vs. 200K).

Why this? Although we have defined a non-deferrable primary key constraint that guarantees uniqueness Oracle still searches in case of an index range scan for the next index entry that does not satisfy the access predicate, which means that for every iteration of the loop Oracle looks at the next index entry to check if it still satisfies the predicate or not. This means in case of the last index entry in each leaf block it has to actually check the next leaf block's first entry for this comparison, hence we end up with approx. number of index leaf blocks more logical I/O in this case. It is also the first part of the explanation why Oracle has to perform more work for the non-unique variant. From the runtime profile however we can tell that although we lose time at the index range scan vs. index unique scan operation, we lose even more time at the table access by ROWID operation.

Remember for a better understanding that the A-TIME and Buffer columns are cumulative - every parent operation includes the child operation runtime/logical I/Os, so in order to understand the runtime/logical I/Os of an operation itself you need to subtract the values taken from the direct descendant operation(s).

2. Session Statistics

Let's have a look at the relevant session statistics:


Statistics Name Unique Non-Unique Difference
----------------------------------------------------- -------- ----------- -----------
STAT..buffer is pinned count 189,998 189,998 0
STAT..table scan blocks gotten 10,000 10,000 0
STAT..table scan rows gotten 100,000 100,000 0
STAT..table fetch by rowid 100,000 100,002 2
STAT..buffer is not pinned count 200,001 200,005 4
STAT..consistent gets 310,012 311,110 1,098
STAT..consistent gets from cache 310,012 311,110 1,098
STAT..session logical reads 310,012 311,110 1,098
STAT..index fetch by key 100,000 2 -99,998
STAT..rows fetched via callback 100,000 2 -99,998
STAT..index scans kdiixs1 0 100,000 100,000
STAT..consistent gets - examination 300,001 100,007 -199,994
STAT..no work - consistent read gets 10,001 211,093 201,092
LATCH.cache buffers chains 320,023 522,213 202,190


a) Pinned Buffers

Now isn't that an interesting coincidence? May be not. The "buffer is pinned count" statistics quite nicely matches the missing 190,000 buffer visits. So Oracle managed to keep 190,000 times a buffer pinned instead of re-locating it in the buffer cache by hashing the database block address to find the corresponding hash bucket, grabbing the corresponding "cache buffers chains" child latch and so on.

Which buffers does Oracle keep pinned? Further modifications of the test case and investigating logical I/O details using events 10200/10202 allows to draw the conclusion that Oracle keeps the buffers of the driving table T2 pinned and the root block of the index. Pinning the root block of the index is a good idea in particular since it saves one logical I/O per loop iteration and the index root block is also quite unlikely to change frequently.

Why does Oracle not simply keep all of the buffers pinned rather than going through the hash/latch/pin exercise again and again? Very likely for various scalability/concurrency reasons, for example:

- A pinned buffer can not be removed/replaced even if it was eligible according to the LRU logic, hence it potentially prevents other buffers from being cached

- A pinned buffer can not be accessed by other sessions that want to pin it in incompatible mode (exclusive vs. shared), although multiple sessions can pin it concurrently in compatible mode (shared). Either those sessions have to queue behind (that is what a "buffer busy wait" is about) or they may be able to create a clone copy of the block and continue their work on the clone copy. Although the "clone copy" trick is a nice one, it is undesirable for several reasons:

* The "clone" copies require each a buffer from the cache effectively reducing the number of different blocks that can be held in the buffer cache. They are also the reason why an object might require much more cache than its original segment size in order to stay completely in the cache.

* They increase the "length" of the "cache buffers chains" leading to longer search times for blocks when locating the buffer in the cache and holding the "cache buffers chains" latch while doing so, hence increasing the potential for latch contention

So here is an important point: If you want to understand the work Oracle has performed in terms of buffer visits you need to consider both, the number of logical I/Os as well as the number of buffers visited without involving logical I/O - this is represented by the "buffer is pinned count" statistics.

Quite often this fact is overlooked and people only focus on the logical I/Os - which is not unreasonable - but misses the point about pinned buffers re-visited without doing logical I/O.

Note that buffer pinning is not possible across fetch calls - if the control is returned to the client the buffers will no longer be kept pinned. This is the explanation why a the "fetchsize" or "arraysize" for bulk fetches can influence the number of logical I/Os required to process a result set.

b) "consistent gets - examination"

There is another significant difference between the two runs that explains most of the remaining runtime difference between the unique and non-unique index variant: The unique index variant performs approx. 310,000 logical I/Os quite similar to the non-unique index variant, however it grabs the corresponding "cache buffers chains" child latch only 320,000 times vs. 520,000 times for the non-unique index.

How is that possible? The explanation can be found in the statistics: The Nested Loop Join when dealing with a unique index performs all logical I/Os as part of the inner row source as "short-cut" consistent gets, which are called "consistent gets - examination". Oracle uses this shortcut whenever it knows that the block visit will be of very short duration. Oracle knows that in this particular case because the unique index guarantees that there will be at most one matching row in the index structure as well as when doing the subsequent table row lookup. So there is no need to perform a "range" scan on the index, and it is guaranteed that only one single row per iteration can be returned from the index unique scan for the table lookup by ROWID.

Hence Oracle makes use of this knowledge and works on the buffer contents while holding the latch, this is what the "consistent gets - examination" statistics is about. A "normal" consistent get grabs the latch initially and releases it after having the buffer pinned. It works then on the buffer and afterwards "unpins" the buffer which requires another latch acquisition. Therefore a "non-shortcut" consistent get requires two latch acquisitions per logical I/O. This explains why we have 10,000 non-shortcut consistent gets for the driving full table scan (that are accompanied by 90,000 buffer visits avoiding logical I/O by keeping the buffer pinned) resulting in 20,000 latch acquisitions and 300,000 latch acquisitions for the remaining 300,000 "short-cut" consistent gets which makes in total 320,000 latch acquisitions for the unique index variant.

The non-unique index variant performs 200,000 "non-shortcut" logical I/Os on the inner index and the table lookup, responsible for 400,000 latch acquisitions, another 10,000 for the driving table full table scan (this part is not different from the unique index variant) good for another 20,000 latch acquisitions. But it also performs 100,000 "short-cut" consistent gets, resulting in the remaining 100,000 latch acquisitions. Modifying the test case by creating the index with a height of 2 (BLEVEL = 1) shows that Oracle uses the "short-cut" consistent gets on the branch blocks of the index, so this is another area where Oracle makes use of the "optimized" version of logical I/O even with the non-unique index variant.

Scalability

What do these subtle differences mean in terms of scalability? Well, you can download a bunch of scripts that allow to run the same test case with as many sessions concurrently as desired. It will show that there is a significant difference between the two cases: The unique index variant not only is faster in "single-user" mode but also scales much better than the non-unique index variant when performing the test concurrently (and completely cached viz. purely logical I/O based). The provided test suite could be modified to use a more realistic scenario that runs the statement multiple times in each concurrent session with a random sleep in between, but that is left as an exercise for the interested reader.

Summary

The baseline results show that the Oracle uses many built-in features to optimize logical I/O by either avoiding the logical I/O at all or using "short-cut" versions of logical I/O where applicable.

These optimizations allow the "unique index" variant to perform significantly better than the "non-unique index" variant of this particular test case. Note that this significant difference is only that significant when dealing with the pure logical I/O variant - introducing physical I/O make the difference far less impressive since the majority of the time is then spent on physical I/O, not logical I/O.

In the upcoming parts of this series I'll focus on further enhancements introduced in the recent releases like table prefetching, Nested Loop Join batching aka. as I/O batching and an obviously significantly enhanced buffer pinning mechanism introduced in Oracle 11g.

Footnote

If you study the script carefully, then you'll notice that it allows for different ordering of the data - it could be randomly ordered, randomly ordered but the same (pseudo-random) order for T1 and T2 and it could be ordered by ID.

If you run the test with this different ordering of data you'll notice no difference in the results with 10g (and table prefetching disabled), but it might give a clue where this will be heading for in the upcoming posts.

Forward to Part 2