« db file scattered read と db file parallel read と db file sequential read (その2) | トップページ | db file scattered read と db file parallel read と db file sequential read (その4) »

2013年4月 4日 (木)

db file scattered read と db file parallel read と db file sequential read (その3)

続きです。

リクエストにお答えして生SQLトレース(抜粋)を見てみましょう :)

最初に実行したSQL文のSQLトレースを見てみることにします。

select
/*+
leading(t2 t1)
use_nl(t2 t1)
index(t2 pk_high_clustering_factor)
*/
t2.id
,t2.name
,t1.name
from
low_clustering_factor t1
inner join high_clustering_factor t2
on
t1.id = t2.id
where
t2.id between 30001 and 35000
/

実行計画は以下の通り、index range/unique scan + nested loop joinが行われていました。

Rows     Row Source Operation
------- ---------------------------------------------------
2421 NESTED LOOPS (cr=5252 pr=2841 pw=0 time=2771706 us)
2421 NESTED LOOPS (cr=2831 pr=2522 pw=0 time=4204941 us cost=5012 size=1530612 card=2501)
2421 TABLE ACCESS BY INDEX ROWID HIGH_CLUSTERING_FACTOR (cr=2589 pr=2458 pw=0 time=4188001 us cost=2510 size=765612 card=2502)
2421 INDEX RANGE SCAN PK_HIGH_CLUSTERING_FACTOR (cr=168 pr=121 pw=0 time=7663 us cost=8 size=0 card=2502)(object id 82774)
2421 INDEX UNIQUE SCAN PK_LOW_CLUSTERING_FACTOR (cr=242 pr=64 pw=0 time=0 us cost=0 size=0 card=1)(object id 82772)
2421 TABLE ACCESS BY INDEX ROWID LOW_CLUSTERING_FACTOR (cr=2421 pr=319 pw=0 time=0 us cost=1 size=306 card=1)

待機イベント見てみると、index range/unique scan + table access by index rowidという実行計画からは想像できない待機イベントが....(実は狙って発生させてるくせに〜w

Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 163 0.00 0.00
db file scattered read 107 0.01 0.30
SQL*Net message from client 163 0.96 3.36
db file parallel read 161 0.01 0.63
SQL*Net more data to client 161 0.00 0.00
db file sequential read 14 0.00 0.00
********************************************************************************

(生)SQLトレース抜粋

...中略...
PARSE #4:c=1000,e=1534,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=1087412721,tim=1364725159601671
EXEC #4:c=1000,e=97,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1087412721,tim=1364725159601925
WAIT #4: nam='SQL*Net message to client' ela= 7 driver id=1650815232 #bytes=1 p3=0 obj#=82773 tim=1364725159602105 
WAIT #4: nam='db file scattered read' ela= 19499 file#=7 block#=371968 blocks=32 obj#=82774 tim=1364725159621743
WAIT #4: nam='db file scattered read' ela= 11156 file#=7 block#=373703 blocks=32 obj#=82774 tim=1364725159633042
WAIT #4: nam='db file scattered read' ela= 1699 file#=7 block#=375476 blocks=32 obj#=82773 tim=1364725159635032
WAIT #4: nam='db file scattered read' ela= 5889 file#=7 block#=367232 blocks=32 obj#=82772 tim=1364725159641300
WAIT #4: nam='db file scattered read' ela= 17223 file#=7 block#=368599 blocks=32 obj#=82771 tim=1364725159658667
FETCH #4:c=2999,e=56653,p=160,cr=6,cu=0,mis=0,r=1,dep=0,og=1,plh=1087412721,tim=1364725159658788
WAIT #4: nam='SQL*Net message from client' ela= 430 driver id=1650815232 #bytes=1 p3=0 obj#=82771 tim=1364725159659311 
WAIT #4: nam='db file parallel read' ela= 10307 files=1 blocks=14 requests=14 obj#=82773 tim=1364725159669764 
WAIT #4: nam='db file scattered read' ela= 1931 file#=7 block#=374755 blocks=29 obj#=82773 tim=1364725159671819 
WAIT #4: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=82773 tim=1364725159671902 
WAIT #4: nam='SQL*Net more data to client' ela= 40 driver id=1650815232 #bytes=8330 p3=0 obj#=82773 tim=1364725159672223
FETCH #4:c=2000,e=12910,p=43,cr=38,cu=0,mis=0,r=15,dep=0,og=1,plh=1087412721,tim=1364725159672272
WAIT #4: nam='SQL*Net message from client' ela= 9227 driver id=1650815232 #bytes=1 p3=0 obj#=82773 tim=1364725159681536 
WAIT #4: nam='db file parallel read' ela= 5766 files=1 blocks=12 requests=12 obj#=82773 tim=1364725159687404 
WAIT #4: nam='db file scattered read' ela= 1922 file#=7 block#=376416 blocks=32 obj#=82773 tim=1364725159689681
WAIT #4: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=82773 tim=1364725159689951 
WAIT #4: nam='SQL*Net more data to client' ela= 13 driver id=1650815232 #bytes=8278 p3=0 obj#=82773 tim=1364725159690473
FETCH #4:c=4000,e=8972,p=44,cr=32,cu=0,mis=0,r=15,dep=0,og=1,plh=1087412721,tim=1364725159690547
WAIT #4: nam='SQL*Net message from client' ela= 7980 driver id=1650815232 #bytes=1 p3=0 obj#=82773 tim=1364725159698617 
WAIT #4: nam='db file parallel read' ela= 2716 files=1 blocks=13 requests=13 obj#=82773 tim=1364725159701431 
WAIT #4: nam='db file scattered read' ela= 2179 file#=7 block#=374240 blocks=32 obj#=82773 tim=1364725159703739 
WAIT #4: nam='SQL*Net message to client' ela= 5 driver id=1650815232 #bytes=1 p3=0 obj#=82773 tim=1364725159704315 
WAIT #4: nam='SQL*Net more data to client' ela= 40 driver id=1650815232 #bytes=8278 p3=0 obj#=82773 tim=1364725159704541 
FETCH #4:c=3999,e=5937,p=45,cr=32,cu=0,mis=0,r=15,dep=0,og=1,plh=1087412721,tim=1364725159704589
WAIT #4: nam='SQL*Net message from client' ela= 11759 driver id=1650815232 #bytes=1 p3=0 obj#=82773 tim=1364725159716396 
WAIT #4: nam='db file parallel read' ela= 1999 files=1 blocks=13 requests=13 obj#=82773 tim=1364725159718604 
WAIT #4: nam='db file scattered read' ela= 1667 file#=7 block#=374066 blocks=32 obj#=82773 tim=1364725159720394 
WAIT #4: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=82773 tim=1364725159720497 
WAIT #4: nam='SQL*Net more data to client' ela= 43 driver id=1650815232 #bytes=8278 p3=0 obj#=82773 tim=1364725159720707 
FETCH #4:c=1000,e=4261,p=45,cr=32,cu=0,mis=0,r=15,dep=0,og=1,plh=1087412721,tim=1364725159720752
WAIT #4: nam='SQL*Net message from client' ela= 6700 driver id=1650815232 #bytes=1 p3=0 obj#=82773 tim=1364725159727511 
WAIT #4: nam='db file parallel read' ela= 5874 files=1 blocks=14 requests=14 obj#=82773 tim=1364725159733551 
WAIT #4: nam='db file sequential read' ela= 337 file#=7 block#=374065 blocks=1 obj#=82773 tim=1364725159733959 
WAIT #4: nam='SQL*Net message to client' ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=82773 tim=1364725159734041 
WAIT #4: nam='SQL*Net more data to client' ela= 77 driver id=1650815232 #bytes=8278 p3=0 obj#=82773 tim=1364725159734271 
...以下略...


db file * read待機イベントとアクセスブロック数及び参照オブジェクトとオブジェクト名を見やすくすると以下のようになります。
db_file_multiblock_read_count=32なのでscatterd readのblocksは理解できるのですが、parallel readのblocksってどこで制御してるんだ..わからんw..というか調べきれてない..

db file scattered read  blocks=32 (INDEX:PK_HIGH_CLUSTERING_FACTOR)
db file scattered read blocks=32 (INDEX:PK_HIGH_CLUSTERING_FACTOR)
db file scattered read blocks=32 (TABLE:HIGH_CLUSTERING_FACTOR)
db file scattered read blocks=32 (INDEX:PK_LOW_CLUSTERING_FACTOR)
db file scattered read blocks=32 (TABLE:LOW_CLUSTERING_FACTOR)
db file parallel read blocks=14 (TABLE:HIGH_CLUSTERING_FACTOR)
db file scattered read blocks=29 (TABLE:HIGH_CLUSTERING_FACTOR)
db file parallel read blocks=12 (TABLE:HIGH_CLUSTERING_FACTOR)
db file scattered read blocks=32 (TABLE:HIGH_CLUSTERING_FACTOR)
db file parallel read blocks=13 (TABLE:HIGH_CLUSTERING_FACTOR)
db file scattered read blocks=32 (TABLE:HIGH_CLUSTERING_FACTOR)
db file parallel read blocks=13 (TABLE:HIGH_CLUSTERING_FACTOR)
db file scattered read blocks=32 (TABLE:HIGH_CLUSTERING_FACTOR)
db file parallel read blocks=14 (TABLE:HIGH_CLUSTERING_FACTOR)
db file sequential read blocks=1 (TABLE:HIGH_CLUSTERING_FACTOR)

発生しているdb file * read待機イベントでアクセスしているオブジェクトは以下の通り。
実行計画上 index unique/range scan なのですが、索引でもscatterd readが発生することがあるんですよ〜っ。

db file parallel read
- obj# = 82773 - HIGH_CLUSTERING_FACTOR(表)

db file scattered read
- obj# = 82771 - LOW_CLUSTERING_FACTOR(表)
- obj# = 82772 - PK_LOW_CLUSTERING_FACTOR(索引)
- obj# = 82773 - HIGH_CLUSTERING_FACTOR(表)
- obj# = 82774 - PK_HIGH_CLUSTERING_FACTOR(索引)

db file sequential read
- obj# = 82771 - LOW_CLUSTERING_FACTOR(表)
- obj# = 82773 - HIGH_CLUSTERING_FACTOR(表)


2つ目のクエリは db file parallel readが発生しないだけで傾向は同じです。 :)

次回へつづく。


バックナンバー

db file scattered read と db file parallel read と db file sequential read (その1)
db file scattered read と db file parallel read と db file sequential read (その2)

|

トラックバック

この記事のトラックバックURL:
http://app.cocolog-nifty.com/t/trackback/106341/57100794

この記事へのトラックバック一覧です: db file scattered read と db file parallel read と db file sequential read (その3):

コメント

コメントを書く