まず次のように空いたテーブルを一つ作ります。動的サンプリングとハードパースによるI/O発生をなくすために統計情報と収集しクエリもあらかじめ一回づつ実行しておきます。
drop table t1 purge;
create table t1(c1 char(1));
exec dbms_stats.gather_table_stats(user, 't1');
select /* no_rows */ * from t1;
select /* 1 rows */ * from t1;
次の結果を見てください。
alter system flush buffer_cache;
select /* no_rows */ *
from
t1
Rows Row Source Operation
------- ---------------------------------------------------
0 TABLE ACCESS FULL T1 (cr=3 pr=1 pw=0 time=828 us)
insert into t1 values('1');
commit;
alter system flush buffer_cache;
select /* 1 rows */ *
from
t1
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL T1 (cr=21 pr=19 pw=0 time=3303 us)
空いたテーブルに対して全表走査をする場合にはPhysical Reads=1、Logical Reads=3であります。この値はどこから来るでしょうか。行(Row)が一つのテーブルの場合は全表走査に対してPhysical Reads=19、Logical Reads=21であります。この値はまたどこから来ますか。
この質問に答えてみたらオラクルでI/Oを追いかける簡単な技法を習うようになります。まずバージョンは次のようです。
UKJA@ukja1021> @version
BANNER
----------------------------------------------------------------
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - Prod
TablespaceはASSM(Automatic Segment Space Management)で管理されていてExtentのサイズはUniform Size 10Mであります。テーブルにデータが一件もない場合のSQL*Traceに対するTkprofの結果です。
select /* no_rows */ *
from
t1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 1 0.00 0.00 1 3 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3 0.00 0.00 1 3 0 0
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61
Rows Row Source Operation
------- ---------------------------------------------------
0 TABLE ACCESS FULL T1 (cr=3 pr=1 pw=0 time=828 us)
まずPhysical Reads(1)はどこから出た値かを確認してみます。トレース原本ファイルは次のようです。
PARSING IN CURSOR #10 len=30 dep=0 uid=61 oct=3 lid=61 tim=3012155435237 hv=1069717740 ad='2836fe0c'
select /* no_rows */ * from t1
END OF STMT
PARSE #10:c=0,e=877,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=3012155435230
EXEC #10:c=0,e=46,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=3012155436544
WAIT #10: nam='SQL*Net message to client' ela= 4 driver id=1413697536 #bytes=1 p3=0 obj#=18 tim=3012155436775
WAIT #10: nam='db file sequential read' ela= 282 file#=7 block#=25630 blocks=1 obj#=55933 tim=3012155437320
FETCH #10:c=0,e=833,p=1,cr=3,cu=0,mis=0,r=0,dep=0,og=1,tim=3012155437829
WAIT #10: nam='SQL*Net message from client' ela= 1197 driver id=1413697536 #bytes=1 p3=0 obj#=55933 tim=3012155439358
STAT #10 id=1 cnt=0 pid=0 pos=1 obj=55933 op='TABLE ACCESS FULL T1 (cr=3 pr=1 pw=0 time=828 us)'
Db file sequential readイベントを見たらFile#=7、Block#=25630であります。ブロックダンプを通じて確認して見るとSegment Headerであるのが分かります。
UKJA@ukja1021> @which_obj2 7 25630
old 1: alter system dump datafile &__FILE block &__BLOCK
new 1: alter system dump datafile 7 block 25630
System altered.
Elapsed: 00:00:00.04
------------------------------------------------
dba = 7/25630
type = PAGETABLE SEGMENT HEADER
------------------------------------------------
すなわち、Segment Headerを読み込むために一回のPhysical Readsが発生します。データが一件もないのでこれ以上のI/Oは不必要です。Physical Readsが一回しかないと言うのがその証拠です。それにもかかわらずLogical Reads(cr)が3であるのはSegment Headerをもう二度(したがって総三回)読むのを意味します。その理由は文書化されていません。たぶん空間情報を得るために内部的に確認作業をするのではないかと考えています。
そんな理由で全表走査による最小のLogical Readsは三回と認識されています。ここで一つ確認したいことは10200イベントです。10200イベントはLogical Readsを追いかける時使用されます。
10200
"consistent read buffer status"
// *Cause:
// *Action:
でもこのイベントはデータを読み込む時のみ動作します。すなわち上の例のようにSegment Headerのようなメタブロックを読み込む時には記録されないようです。惜しい制約です。
一件のデータをInsertした後を観察してみます。
insert into t1 values ('1');
commit;
SQL*TraceによるTkprofの結果は次のようです。
select /* 1 rows */ *
from
t1
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 19 21 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.00 19 21 0 1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS FULL T1 (cr=21 pr=19 pw=0 time=3303 us)
私がテストしたシステムの場合にはPhysical Reads=19、Logical Reads=21であります。この値はバージョンやSegment Space Management方式、Extentのサイズによって違えます。
Physical Readsの19の値がどこから来たのかをトレース原本ファイルから確認してみます。
PARSING IN CURSOR #24 len=29 dep=0 uid=61 oct=3 lid=61 tim=3012155797727 hv=2697749229 ad='2825d88c'
select /* 1 rows */ * from t1
END OF STMT
PARSE #24:c=0,e=713,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,tim=3012155797723
EXEC #24:c=0,e=49,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=3012155799033
WAIT #24: nam='SQL*Net message to client' ela= 6 driver id=1413697536 #bytes=1 p3=0 obj#=0 tim=3012155799433
WAIT #24: nam='db file sequential read' ela= 254 file#=7 block#=25630 blocks=1 obj#=55933 tim=3012155800000
WAIT #24: nam='db file sequential read' ela= 243 file#=7 block#=25609 blocks=1 obj#=55933 tim=3012155800562
WAIT #24: nam='db file sequential read' ela= 228 file#=7 block#=25629 blocks=1 obj#=55933 tim=3012155801014
WAIT #24: nam='db file scattered read' ela= 1315 file#=7 block#=25641 blocks=16 obj#=55933 tim=3012155802707
FETCH #24:c=0,e=3316,p=19,cr=13,cu=0,mis=0,r=1,dep=0,og=1,tim=3012155803019
WAIT #24: nam='SQL*Net message from client' ela= 298 driver id=1413697536 #bytes=1 p3=0 obj#=55933 tim=3012155803696
FETCH #24:c=0,e=34,p=0,cr=8,cu=0,mis=0,r=0,dep=0,og=1,tim=3012155803938
WAIT #24: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=55933 tim=3012155803998
WAIT #24: nam='SQL*Net message from client' ela= 2449 driver id=1413697536 #bytes=1 p3=0 obj#=55933 tim=3012155806478
STAT #24 id=1 cnt=1 pid=0 pos=1 obj=55933 op='TABLE ACCESS FULL T1 (cr=21 pr=19 pw=0 time=3303 us)'
三回のSingle Block I/O(Db file sequential read)と一回のMulti Block I/O(Db file scatteread read、Blocks=16)を通じて総19ブロックをPhysical I/Oで読み込みました。Single Block I/Oがどんなブロックを読み込んだのを確認してみたら次のようです。
UKJA@ukja1021> @which_obj2 7 25630
UKJA@ukja1021> @which_obj2 7 25609
UKJA@ukja1021> @which_obj2 7 25629
------------------------------------------------
dba = 7/25630
type = PAGETABLE SEGMENT HEADER
------------------------------------------------
dba = 7/25609
type = FIRST LEVEL BITMAP BLOCK
object_id = 55933
object_name = T1
------------------------------------------------
dba = 7/25629
type = SECOND LEVEL BITMAP BLOCK
object_id = 55933
object_name = T1
------------------------------------------------
Segment HeaderとともにASSM(Automatic Segment Space Management)で使用されるFirst Level BMB、Second Level BMBを読み込んだのが分かります。（Third Level BMBはまだ生成されなかったので読み込まなかったんです）
それでは16個のPhysical Readsはどこから来たのでしょうか。スペース情報を見ると次のようです。
UKJA@ukja1021> exec show_space('T1');
Free Blocks.............................
Total Blocks............................1280
Total Bytes.............................10485760
Total MBytes............................10
Unused Blocks...........................1216
Unused Bytes............................9961472
Last Used Ext FileId....................7
Last Used Ext BlockId...................25609
Last Used Block.........................64
PL/SQL procedure successfully completed.
High Water Markが64番目のブロックまでを指差しています。したがってPhysical Readsは16ではなくて61(64－3)になるべきです。全表走査と言うのはデータブロックの初めてからHigh Water MarkまでをSequentialに読み込むのではありませんか。しかしオラクルはただ16個のブロックだけをPhysical Readsで読み込みました。これを説明しようとすればブロックの分布を管理するFirst Level BMBブロックの内容を見る必要があります。First Level BMB(file#=7, block#=25609)の内容は次のようです。
--------------------------------------------------------
DBA Ranges :
--------------------------------------------------------
0x01c06409 Length: 64 Offset: 0
0:Metadata 1:Metadata 2:Metadata 3:Metadata
4:Metadata 5:Metadata 6:Metadata 7:Metadata
8:Metadata 9:Metadata 10:Metadata 11:Metadata
12:Metadata 13:Metadata 14:Metadata 15:Metadata
16:Metadata 17:Metadata 18:Metadata 19:Metadata
20:Metadata 21:Metadata 22:unformatted 23:unformatted
24:unformatted 25:unformatted 26:unformatted 27:unformatted
28:unformatted 29:unformatted 30:unformatted 31:unformatted
32:75-100% free 33:75-100% free 34:75-100% free 35:75-100% free
36:75-100% free 37:75-100% free 38:75-100% free 39:75-100% free
40:75-100% free 41:75-100% free 42:75-100% free 43:75-100% free
44:75-100% free 45:75-100% free 46:75-100% free 47:75-100% free
48:unformatted 49:unformatted 50:unformatted 51:unformatted
52:unformatted 53:unformatted 54:unformatted 55:unformatted
56:unformatted 57:unformatted 58:unformatted 59:unformatted
60:unformatted 61:unformatted 62:unformatted 63:unformatted
上の情報をみると総16個のブロック(32－47)のみが実際に使われていて残りのブロックは使わないUnformattedと言うのが分かります。オラクルはこの情報を利用して16個のブロックのみを一回のMulti Block I/Oで読み込んだのであります。
Physical Readsが19でここで上で見たように追加的なLogical Readsが二回発生するのでLogical Readsは21だと報告されているのです。
今頃ならなぜ安いながらも難しい質問だと言ったのか分かるんでしょう。意味のないテストのようですが(Just for Fun?)、その過程で得られる経験と知識は相当なものです。
テストで使われたスクリプトは次のURLを参照してください。
Posts
No comments:
Post a Comment