悩ませ過ぎは及ばざるがごとし #1 Tweet
あるクエリを実行していて、目標時間は3秒程度のオンライン処理向けクエリ、初回だけ異常に遅いんですけど……。 と再び、大人の事情に縛られて心が痣だらけ（どんなだ）な人達からお呼びがかかりました。
こんな感じの表（索引は似たようなのが数多くありそれもイケてないといえばイケテてないが）を自己結合しているだけ（イケてるクエリとか、イケてないクエリだというのは置いといて）で実行計画もそんなに悪くないし、実行統計を見る限り
初回とそれ以降で大きく乖離しているようにも見えません。
表は次のように定義されています。
SCOTT> desc test
名前 NULL? 型
----------------------------------------- -------- ----------------------------
ID NOT NULL NUMBER(10)
SURRO_ID NOT NULL NUMBER(10)
SURRO_ACD NOT NULL CHAR(2)
SURRO_BCD NOT NULL CHAR(1)
SURRO_CCD NOT NULL CHAR(3)
SURRO_DCD NOT NULL CHAR(5)
NAME NOT NULL VARCHAR2(100)
DESCRIPTION VARCHAR2(300)
CREATED NOT NULL TIMESTAMP(6)
MODIFIED NOT NULL TIMESTAMP(6)
索引は以下のようになってます。
INDEX_NAME COLUMN_NAME
------------------------------ ------------------------------
IX01_TEST SURRO_ID
SURRO_ACD
IX02_TEST SURRO_ID
SURRO_BCD
IX03_TEST SURRO_ID
SURRO_CCD
IX04_TEST SURRO_ID
SURRO_DCD
PK_TEST ID
なんだか、どれも似たような索引がならんでいます。
INDEX_NAME INDEX_TYPE NUM_ROWS DISTINCT_KEYS CLUSTERING_FACTOR
------------------------------ --------------------------- ---------- ------------- -----------------
IX04_TEST NORMAL 700000 700000 7653
IX03_TEST NORMAL 700000 700000 7653
IX02_TEST NORMAL 700000 700000 7653
IX01_TEST NORMAL 700000 700000 7653
PK_TEST NORMAL 700000 700000 7653
どーーーーーーーしてでしょう。
このつづきは次回のお楽しみ。
一緒に考えてみてくらちい ;)
１回目の処理行数、処理時間、実行計画及び実行統計。
・・・中略・・・
5999行が選択されました。
経過: 00:00:48.83
実行計画
----------------------------------------------------------
Plan hash value: 1865103575
--------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 5999 | 351K| 5718 (1)| 00:01:09 |
|* 1 | HASH JOIN | | 5999 | 351K| 5718 (1)| 00:01:09 |
| 2 | INLIST ITERATOR | | | | | |
|* 3 | INDEX RANGE SCAN | IX01_TEST | 5999 | 59990 | 1935 (1)| 00:00:24 |
|* 4 | HASH JOIN | | 5999 | 292K| 3782 (1)| 00:00:46 |
| 5 | VIEW | | 5999 | 95984 | 1858 (1)| 00:00:23 |
| 6 | HASH UNIQUE | | 5999 | 53991 | 1858 (1)| 00:00:23 |
| 7 | INLIST ITERATOR | | | | | |
|* 8 | INDEX RANGE SCAN | IX02_TEST | 5999 | 53991 | 1857 (1)| 00:00:23 |
| 9 | INLIST ITERATOR | | | | | |
| 10 | TABLE ACCESS BY INDEX ROWID| TEST | 5999 | 199K| 1923 (1)| 00:00:24 |
|* 11 | INDEX RANGE SCAN | IX02_TEST | 5999 | | 1857 (1)| 00:00:23 |
--------------------------------------------------------------------------------------------
・・・中略・・・
統計
----------------------------------------------------------
1 recursive calls
0 db block gets
1897 consistent gets
0 physical reads
0 redo size
247808 bytes sent via SQL*Net to client
69769 bytes received via SQL*Net from client
401 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
5999 rows processed
２回目の処理行数、処理時間、実行計画及び実行統計。
１回目とくらべて随分処理時間が短いです。。。。
・・・中略・・・
5999行が選択されました。
経過: 00:00:00.08
実行計画
----------------------------------------------------------
Plan hash value: 1865103575
--------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 5999 | 351K| 5718 (1)| 00:01:09 |
|* 1 | HASH JOIN | | 5999 | 351K| 5718 (1)| 00:01:09 |
| 2 | INLIST ITERATOR | | | | | |
|* 3 | INDEX RANGE SCAN | IX01_TEST | 5999 | 59990 | 1935 (1)| 00:00:24 |
|* 4 | HASH JOIN | | 5999 | 292K| 3782 (1)| 00:00:46 |
| 5 | VIEW | | 5999 | 95984 | 1858 (1)| 00:00:23 |
| 6 | HASH UNIQUE | | 5999 | 53991 | 1858 (1)| 00:00:23 |
| 7 | INLIST ITERATOR | | | | | |
|* 8 | INDEX RANGE SCAN | IX02_TEST | 5999 | 53991 | 1857 (1)| 00:00:23 |
| 9 | INLIST ITERATOR | | | | | |
| 10 | TABLE ACCESS BY INDEX ROWID| TEST | 5999 | 199K| 1923 (1)| 00:00:24 |
|* 11 | INDEX RANGE SCAN | IX02_TEST | 5999 | | 1857 (1)| 00:00:23 |
--------------------------------------------------------------------------------------------
・・・中略・・・
統計
----------------------------------------------------------
0 recursive calls
0 db block gets
1897 consistent gets
0 physical reads
0 redo size
247808 bytes sent via SQL*Net to client
69766 bytes received via SQL*Net from client
401 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
5999 rows processed
３回目の処理行数、処理時間、実行計画及び実行統計。
３回目も２回目と同じようです。１回目だけなぜか異常に遅い。ちなみに、Oracle11g R2 11.2.0.1.0 for Linux x86_64です。
・・・中略・・・
5999行が選択されました。
経過: 00:00:00.08
実行計画
----------------------------------------------------------
Plan hash value: 1865103575
--------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 5999 | 351K| 5718 (1)| 00:01:09 |
|* 1 | HASH JOIN | | 5999 | 351K| 5718 (1)| 00:01:09 |
| 2 | INLIST ITERATOR | | | | | |
|* 3 | INDEX RANGE SCAN | IX01_TEST | 5999 | 59990 | 1935 (1)| 00:00:24 |
|* 4 | HASH JOIN | | 5999 | 292K| 3782 (1)| 00:00:46 |
| 5 | VIEW | | 5999 | 95984 | 1858 (1)| 00:00:23 |
| 6 | HASH UNIQUE | | 5999 | 53991 | 1858 (1)| 00:00:23 |
| 7 | INLIST ITERATOR | | | | | |
|* 8 | INDEX RANGE SCAN | IX02_TEST | 5999 | 53991 | 1857 (1)| 00:00:23 |
| 9 | INLIST ITERATOR | | | | | |
| 10 | TABLE ACCESS BY INDEX ROWID| TEST | 5999 | 199K| 1923 (1)| 00:00:24 |
|* 11 | INDEX RANGE SCAN | IX02_TEST | 5999 | | 1857 (1)| 00:00:23 |
--------------------------------------------------------------------------------------------
・・・中略・・・
統計
----------------------------------------------------------
0 recursive calls
0 db block gets
1897 consistent gets
0 physical reads
0 redo size
247808 bytes sent via SQL*Net to client
69766 bytes received via SQL*Net from client
401 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
5999 rows processed
| 固定リンク | 0
コメント