First, an interesting/surprising thing I found in trying to reproduce the behavior originally noted was that I wasn't able to reproduce it! What I could consistently reproduce (on both 10.2.0.1 and 11.1.0.6 instances) was essentially the opposite behavior of what the original client case showed. So, I decided to just make sure I could understand how the two operations (BITMAP AND vs AND-EQUAL) worked for what I could reproduce. This post is just about the BITMAP AND operation. I'll post another day about AND-EQUAL.
From here on out, this post has lots of code and trace data output, so if you just want the punch-line, scroll to the bottom. :)
If you'd like to try the tests yourself, here's how I created the test data and performed the test.
-- Create test table, populate with data and collect statistics (setup.sql)
drop table bitmap_test;
create table bitmap_test as
select rownum id
from all_objects
where rownum <= 50 /* make larger for more data */;
drop table bitmap_t2;
define isto="pctfree 99 storage (initial 5m)"
define tsto="pctused 1 &isto"
create table bitmap_t2
nologging
&tsto
as select /*+ ordered use_nl(v2) */
lpad('x',20,'x') facts,
mod(rownum, 2) sex,
mod(rownum, 3) eyes,
mod(rownum, 7) hair,
mod(rownum, 31) town,
mod(rownum, 47) age,
mod(rownum, 79) work
from bitmap_test v1,
bitmap_test v2
/
create index t2_i3 on bitmap_t2(hair) nologging &isto;
create index t2_i6 on bitmap_t2(work) nologging &isto;
exec dbms_stats.gather_table_stats(user, 'bitmap_t2', estimate_percent=>100, -
method_opt=>'for all columns size 1', cascade=>TRUE, no_invalidate=>FALSE)
-- Test (test.sql)
select value from v$parameter where name = 'user_dump_dest';
-- Get SPID so I can easily find trace file
select p.spid from v$session s, v$process p
where audsid = userenv('sessionid') and s.paddr = p.addr;
-- Turn on all pertinent trace events
alter session set events '10046 trace name context forever';
alter session set events '10202 trace name context forever';
alter session set events '10711 trace name context forever, level 127';
alter session set events '10713 trace name context forever, level 127';
alter session set events '10715 trace name context forever, level 127';
alter session set events '10717 trace name context forever, level 127';
alter session set statistics_level=all;
set termout off pause off
-- Run once for each query
-- Run with index_combine hint to get BITMAP AND plan
select /*+ index_combine(bitmap_t2 t2_i6 t2_i3) */ *
from bitmap_t2 where hair = 5 and work = 45;
-- Run with RULE hint to get AND-EQUAL plan
-- select /*+ rule */ * from bitmap_t2 where hair = 5 and work = 45;
set termout on
exit
Test 1 trace output (STAT lines only)
STAT #2 id=1 cnt=5 pid=0 pos=1 obj=56968 op='TABLE ACCESS BY INDEX ROWID BITMAP_T2 (cr=400 pr=362 pw=0 time=79714 us)'
STAT #2 id=2 cnt=5 pid=1 pos=1 obj=0 op='BITMAP CONVERSION TO ROWIDS (cr=395 pr=361 pw=0 time=78988 us)'
STAT #2 id=3 cnt=1 pid=2 pos=1 obj=0 op='BITMAP AND (cr=395 pr=361 pw=0 time=78694 us)'
STAT #2 id=4 cnt=1 pid=3 pos=1 obj=0 op='BITMAP CONVERSION FROM ROWIDS (cr=35 pr=1 pw=0 time=11851 us)'
STAT #2 id=5 cnt=32 pid=4 pos=1 obj=56970 op='INDEX RANGE SCAN T2_I6 (cr=35 pr=1 pw=0 time=11297 us)'
STAT #2 id=6 cnt=1 pid=3 pos=2 obj=0 op='BITMAP CONVERSION FROM ROWIDS (cr=360 pr=360 pw=0 time=66579 us)'
STAT #2 id=7 cnt=357 pid=6 pos=1 obj=56969 op='INDEX RANGE SCAN T2_I3 (cr=360 pr=360 pw=0 time=65355 us)'
Test 2 trace output (STAT lines only)
STAT #3 id=1 cnt=5 pid=0 pos=1 obj=56968 op='TABLE ACCESS BY INDEX ROWID BITMAP_T2 (cr=282 pr=4 pw=0 time=10833 us)'
STAT #3 id=2 cnt=5 pid=1 pos=1 obj=0 op='AND-EQUAL (cr=277 pr=0 pw=0 time=8651 us)'
STAT #3 id=3 cnt=38 pid=2 pos=1 obj=56969 op='INDEX RANGE SCAN T2_I3 (cr=147 pr=0 pw=0 time=4553 us)'
STAT #3 id=4 cnt=37 pid=2 pos=2 obj=56970 op='INDEX RANGE SCAN T2_I6 (cr=130 pr=0 pw=0 time=3614 us)'
Here's the result comparison
BITMAP CONVERSION cr=395 pr=361 pw=0 time=78988 us
AND-EQUAL cr=282 pr=4 pw=0 time=10833 us
I did a couple of simple count queries to verify how many rows matched each predicate. You can also note the number of buffer accesses are required to satisfy each count.
SQL> select /*+ gather_plan_statistics */ count(*) from bitmap_t2 where work = 45 ;
COUNT(*)
---------------
32
SQL> @allstats_last
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------
SQL_ID 9xbjw9v72xnty, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ count(*) from bitmap_t2 where work = 45
Plan hash value: 806960853
-------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers |
-------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:00.01 | 35 |
|* 2 | INDEX RANGE SCAN| T2_I6 | 1 | 32 | 32 |00:00:00.01 | 35 |
-------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("WORK"=45)
SQL>
SQL> select /*+ gather_plan_statistics */ count(*) from bitmap_t2 where hair = 5 ;
COUNT(*)
---------------
357
1 row selected.
SQL> @allstats_last
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------------------
SQL_ID 5h1vvmx6wd2j2, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ count(*) from bitmap_t2 where hair = 5
Plan hash value: 3466781003
-------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers |
-------------------------------------------------------------------------------------
| 1 | SORT AGGREGATE | | 1 | 1 | 1 |00:00:00.03 | 360 |
|* 2 | INDEX RANGE SCAN| T2_I3 | 1 | 357 | 357 |00:00:00.03 | 360 |
-------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("HAIR"=5)
From this information, you can see that the buffer gets for a single predicate match the cr values in the bitmap plan. So, what happened with the AND-EQUAL plan? The STAT line rowsource totals for two INDEX RANGE SCAN operations in the AND-EQUAL plan don't seem to make any sense at all.
STAT #3 id=3 cnt=38 pid=2 pos=1 obj=56969 op='INDEX RANGE SCAN T2_I3 (cr=147 pr=0 pw=0 time=4553 us)'
STAT #3 id=4 cnt=37 pid=2 pos=2 obj=56970 op='INDEX RANGE SCAN T2_I6 (cr=130 pr=0 pw=0 time=3614 us)'
The index T2_I3 is on the hair column. According to the counts, there are 357 rows where hair=5. So, why does the execution information show 38 rows returned (cnt=38) and cr=147? Further, why does the scan on the T2_I6 (work column) index show 37 rows returned and cr=130? That makes no sense to me at all. Anyway, as I said, I'll review the details of the AND-EQUAL plan in another post.
Let's go back to the BITMAP AND plan. I learned a lot from reviewing the trace file about how the BITMAP AND operation works. Here's some of the content that shows you what's going on:
-- Trace file excerpt
qerbtStart(8217284): started
qerbtStart(8228444): started
qerbtStart(8228b0c): started
qerbaStart(8217170): started
qerbtFetch bitmap to rowids(8217284):
qerbtFetch rowids to bitmap(8228444):
kdibcoinit(82286b4): srid=011389bb.0000
<< At this point a series of block gets were performed to read the T2_I6 index blocks >>
kdibcoend(82286b4): erid=013252ea.0007status=0
-- The following call is what shows up in the plan as the BITMAP CONVERSION FROM ROWIDS for T2_I6 (work) step
qerbtFetch out bitmap(8228444): bml 127 srid=011389bb.0000, erid=013252ea.0007 objn 56968
-- The following line shows the starting (srid) and ending (erid) rowids for rows where work = 45 (from index T2_I6)
kdibr1r2r(8217184): bml 127 srid=011389bb.0000, erid=013252ea.0007
kdibci3init(8351904): src_stream=a4bd1ac
qerbtFetch rowids to bitmap(8228b0c):
<< At this point a series of block gets were performed to read the T2_I3 index blocks >>
kdibcoend(8228d7c): erid=01325308.0007status=0
-- The following call is what shows up in the plan as the BITMAP CONVERSION FROM ROWIDS for T2_I3 (hair) step
qerbtFetch out bitmap(8228b0c): bml 1054 srid=011389bb.0000, erid=01325308.0007 objn 56968
-- The following line shows the starting (srid) and ending (erid) rowids for rows where hair = 5 (from index T2_I3)
kdibr1r2r(8217184): bml 1054 srid=011389bb.0000, erid=01325308.0007
kdibci3init(8351938): src_stream=a4bd1ac
-- The following call is setting up the BITMAP AND with the info collected from the two indexes
kdibc3init(8217198): buf(16116)=83527b0, srid=011389bb.0000
kdibc3end(8217198)
-- The following call is what shows up in the plan as the BITMAP AND step in the plan
kdibr2s2r out bitmap(8217184): bml 6 srid=011389bb.0000, erid=01325108.0007
-- The following shows the final range of rowids that will need to be fetched
kdibr1r2r(8217298): bml 19 srid=011389bb.0000, erid=01325108.0007
kdibci3init(82172ac): src_stream=a4bd354
-- The following call shows the number of rows to be retrieved (5) and lists their rowid
kdibc3sids(82172ac): want=57, got=5
011389bb.0000 01138bec.0000 01138e1f.0000 01139050.0000
01325108.0000
-- This call fetches the first rowid from the list
qerbtFetch(8217284): rowid=011389bb.0000 tobj 56968
-- DATA block cr 0x011389bb is fetched here
-- Then, the first FETCH line is emitted to the trace data.
-- Note that it shows cr=396. That's the total of T2_I6 index block reads plus
-- T2_I3 index block reads plus the 1 data block read that just occurred.
FETCH #2:c=15625,e=78684,p=361,cr=396,cu=0,mis=0,r=1,dep=0,og=1,tim=84895456678
-- The next series of calls gets the remaining 4 rows from the list above.
qerbtFetch bitmap to rowids(8217284):
qerbtFetch(8217284): rowid=01138bec.0000 tobj 56968
-- DATA block cr 0x01138bec is fetched here
qerbtFetch bitmap to rowids(8217284):
qerbtFetch(8217284): rowid=01138e1f.0000 tobj 56968
-- DATA block cr 0x01138e1f is fetched here
qerbtFetch bitmap to rowids(8217284):
qerbtFetch(8217284): rowid=01139050.0000 tobj 56968
-- DATA block cr 0x01139050 is fetched here
qerbtFetch bitmap to rowids(8217284):
qerbtFetch(8217284): rowid=01325108.0000 tobj 56968
-- DATA block cr 0x01325108 is fetched here
qerbtFetch bitmap to rowids(8217284):
kdibc3sids(82172ac): want=57, got=0
-- The 2nd, and final, FETCH line is emitted showing the 4 block
-- accesses for the remaining rows.
FETCH #2:c=0,e=735,p=1,cr=4,cu=0,mis=0,r=4,dep=0,og=1,tim=84895457801
So, here's the bottom-line with BITMAP AND plans as best I can decipher from my tests:
1) The index blocks are all read first and the applicable rows (i.e. ROWIDs) matching the predicate are placed into memory. The first FETCH line emitted by the 10046 trace shows the reads (cr and pr) that count these index blocks being collected.
2) A separate memory area is associated with each INDEX that is involved.
3) The index ROWIDs are converted to bitmaps.
4) Once all the index ROWIDs are collected and converted, they are AND'ed together to produce a final bitmap that represents the range of ROWIDs needed for the result.
5) That final bitmap is converted back to a list of ROWIDs.
6) Each ROWID on the list is then retrieved. This is where the data blocks are retrieved. You'll see just a cr (consistent read) or a cr and a pr (physical read) if the block isn't already in the buffer cache.
So, what you should see is that the first FETCH (10046 trace data) will have the stats for the collection of all the index blocks needed and placing them into memory. After that, only data blocks are read.
It makes sense when I look at now. I still don't quite understand what happened in the original case noted in my earlier post, but I believe I've come a long way in my understanding of how bitmap conversion operations function.
For those geeks out there like me who really find this interesting and want to do the tests yourself, please have at it! I'd love to hear back from you if you get contradictory results or if your understanding of how the process is working is different than mine. I was able to reproduce my tests with larger data sets but it would be great if you get another set of results you would share. Let me know!
No comments:
Post a Comment