Showing posts with label db file parallel read. Show all posts
Showing posts with label db file parallel read. Show all posts

Wednesday, August 26, 2009

Index Prefetch? db file parallel read? db file scattered read?

(このポストは多少専門的な内容を含んでいるので、関心ある方だけ読んでみてください)


Index Prefetchは少しは混乱な機能です。下の情報を読んでみれば私のいうことを理解できるでしょう。


一般的な意見は次のようです。

  1. Index Prefetchが発生すればIndex Range ScanとTable Lookup By ROWIDに対してNon-Contignous Multiblock Readを行います. すなわち, 隣接しないブロックたちをParallelに一度に読みます。
  2. この際db file parallel readという待機イベントが発生します。
  3. 一度に読み込める最大のブロックの数は_db_file_noncontig_mblock_read_count(基本値は11)によって決まります。
    Index PrefetchはOracle(CBO)が全的に決めるし、実行計画が同一してもIndex Prefetchが選択されるかどうかは確信できません。

でも、時々Index Range ScanとTable Lookup By ROWIDに対してdb file scattered readイベントを待機するばあいが報告されています。私も以前にこの現状を始めて見つけてずいぶん驚いた覚えがあります。なぜdb file parallel readでもなくdb file scattered readなのか。これはIndex Prefetchなのか、それとも全然違うPrefetch方法なのか。


この問題に対してはまだ明確な説明が存在しないと思います。


それでテストデータベースでIndex Prefetchを直接再現してみました。


まず次のようにClutering FactorがよくないIndexを作ります。Clustering Factorが不良ならばSingle Block I/Oの性能が遅くなるからOracleがMulti Block I/Oを選択する確率が高くなるからです。


UKJA@ukja1106> select * from v$version;

BANNER
--------------------------------------------------------------------------------
Oracle Database 11g Enterprise Edition Release 11.1.0.6.0 - Production
PL/SQL Release 11.1.0.6.0 - Production
CORE 11.1.0.6.0 Production
TNS for 32-bit Windows: Version 11.1.0.6.0 - Production
NLSRTL Version 11.1.0.6.0 - Production

Elapsed: 00:00:00.00

UKJA@ukja1106> create table t1(c1 int, c2 int);

Table created.

Elapsed: 00:00:00.14
UKJA@ukja1106> insert into t1
2 select level, 1 from dual connect by level <= 100000
3 order by dbms_random.random;

100000 rows created.

Elapsed: 00:00:01.82
UKJA@ukja1106> create index t1_n1 on t1(c1);

Index created.

Elapsed: 00:00:00.28
UKJA@ukja1106>
UKJA@ukja1106> @gather t1
UKJA@ukja1106> exec dbms_stats.gather_table_stats(user, '&1', no_invalidate=>false);

PL/SQL procedure successfully completed.

Elapsed: 00:00:01.20

Index Prefetchが選択される確率を極端的に高めます。

UKJA@ukja1106> alter session set "_index_prefetch_factor" = 1;

Session altered.

Elapsed: 00:00:00.00
UKJA@ukja1106> alter session set db_file_multiblock_read_count = 128;

Session altered.

Elapsed: 00:00:00.00

Buffer CacheをFlushしてからIndex Range ScanとTable Lookup By ROWIDを選択するようにヒントを与えてQueryを遂行します。
 
UKJA@ukja1106> alter system flush buffer_cache;

System altered.

Elapsed: 00:00:00.37
UKJA@ukja1106> select /*+ index(t1) */ count(*)
2 from t1 where c1 between 1 and 1000 and c2 = 1;

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

Elapsed: 00:00:00.03

SQL*Traceの結果はdb file parallel readイベントを報告します。

select /*+ index(t1) */ count(*)
from t1 where c1 between 1 and 1000 and c2 = 1

call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.01 0.02 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.03 0.11 182 998 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.04 0.13 182 998 0 1

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 88

Rows Row Source Operation
------- ---------------------------------------------------
1 SORT AGGREGATE (cr=998 pr=182 pw=182 time=0 us)
1000 TABLE ACCESS BY INDEX ROWID T1 (cr=998 pr=182 pw=182 time=8601 us cost=999 size=7000 card=1000)
1000 INDEX RANGE SCAN T1_N1 (cr=4 pr=4 pw=4 time=21 us cost=4 size=0 card=1000)(object id 72154)


Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
db file sequential read 12 0.01 0.02
db file parallel read 15 0.03 0.08
SQL*Net message from client 2 0.00 0.00
********************************************************************************

原本のTraceファイルの待機イベントに対してもっと詳しい分析をしてみます。

UKJA@ukja1106> @trace_file_short
TRACE_FILE_NAME
--------------------------------------------------------------------------------
ukja1106_ora_31724.trc

Elapsed: 00:00:00.01
ukja1106_ora_31724.trc
UKJA@ukja1106> @wait_analyze &trace_file % 'db file parallel read' nam,files,blocks
NAM FILES BLOCKS COUNT(*)
------------------------------ ---------- ---------- ----------
'db file parallel read' 1 15 1
'db file parallel read' 1 2 3
'db file parallel read' 1 37 1
'db file parallel read' 1 3 1
'db file parallel read' 1 4 2
'db file parallel read' 1 27 1
'db file parallel read' 1 11 1
'db file parallel read' 1 7 3
'db file parallel read' 1 30 1
'db file parallel read' 1 12 1

10 rows selected.

Elapsed: 00:00:00.25

Multi Block Readのブロック数が11ではなく3から37まで広範囲に分布しているのが分かります。文書化されたのとは違う現状ですよ。


Multi Block I/OがどんなObjectで発生しているのかを見ればIndexではないTableに対してだけ発生しているのが分かります。


UKJA@ukja1106> col obj new_value obj_no
UKJA@ukja1106> @wait_analyze &trace_file % 'db file parallel read' nam,obj
NAM OBJ COUNT(*)
------------------------------ ---------- ----------
'db file parallel read' 72153 15

Elapsed: 00:00:00.09
UKJA@ukja1106> @obj &obj_no
UKJA@ukja1106> exec print_table('select * from all_objects where object_id = &1');
OWNER : UKJA
OBJECT_NAME : T1
SUBOBJECT_NAME :
OBJECT_ID : 72153
DATA_OBJECT_ID : 72153
OBJECT_TYPE : TABLE
CREATED : 2009/08/26 18:02:30
LAST_DDL_TIME : 2009/08/26 18:02:32
TIMESTAMP : 2009-08-26:18:02:30
STATUS : VALID
TEMPORARY : N
GENERATED : N
SECONDARY : N
NAMESPACE : 1
EDITION_NAME :
-----------------

やっぱり文書化されたのとは違う現状です。多分Oracleが判断するにのにIndexはSingle Block I/Oで読み込むのが効果的だけど、Tableへ行く過程は重いので(Clustering Factorがよくないから)Multi Block I/Oが効果的だと判断しているみたいです。あくまでも推測です。もちろんこんなOracleの判断がいつも性能に効果的なのではありません。やや大きい性能低下が発生する可能性もあります。


やっぱり解かない疑問は”それではOracleは何時db file parallel readイベントではなくdb file scattered readイベントを報告するのか”すなわち”何時Non-Contiguous Multi Block I/OではなくContiguous Multi Block I/Oをするのか”です。まだは分かりません.:)

Footnote:wait_analyze.sqlファイルはここにあります。