実行統計による実践的SQLチューニング(その2)

実行計画を実行順に表示させる

前回の投稿では、DBMS_XPLANパッケージのDISPLAY_CURSOR関数により実行統計を併記した実行計画の表示要領を紹介した。

しかし、実行計画ツリーからどのステップが起点となりどの順番で実行されるかを読み取るのはある程度の経験が必要であり、前回紹介した程度の行数であればともかく、数百ステップにもなる場合はベテランでも投げ出したくなる。

筆者は以前から実行計画ツリーを実行順に表示させることに関して試行錯誤を繰り返してきたが、この度方法を確立するに至ったので紹介したいと思う。

実行順表示スクリプト

DBMS_XPLAN.DISPLAY_COURSORの入力ソースはV$SQL_PLAN_STATISTICS_ALLビューであるので、このビューを使って情報を取得する。

前回投稿の中で aplan.sql スクリプトから呼ばれていた aplans.sql の内容が以下となる。

set lines 1000
col ID for 9999
col Operation for a60
col Name for a20
col Pstart for a13
col Pstop for a13
col A-Time for 9,990.00
col A-Rows for 999,999,999,990
col E-Rows for 999,999,999,990
col Starts for 999,999,999,990
-- 実行順実行統計出力
select
 ID
,"Operation"
,"Name"
,"Starts"
,"E-Rows"
,"A-Rows"
,"A-Time"
,"Buffers"
,"Reads"
,"Writes"
,"Srch Cols"
,"Pstart"
,"Pstop"
,"PartID"
from
(
  select
   rownum NO
  ,ID
  ,lpad(' ',DEPTH) || OPERATION ||' '|| OPTIONS "Operation"
  ,OBJECT_NAME "Name"
  ,LAST_STARTS "Starts"
  ,nvl(CARDINALITY,1) * LAST_STARTS "E-Rows" -- 1回の操作で処理される見積行数 * 見積処理回数 = 見積処理行数
  ,LAST_OUTPUT_ROWS "A-Rows"                 -- 実際の処理行数
  ,LAST_ELAPSED_TIME/1000000 "A-Time"
  ,LAST_CR_BUFFER_GETS "Buffers"
  ,LAST_DISK_READS "Reads"
  ,LAST_DISK_WRITES "Writes"
  ,SEARCH_COLUMNS "Srch Cols"
  --,COST
  ,PARTITION_START "Pstart"
  ,PARTITION_STOP "Pstop"
  ,PARTITION_ID "PartID"
  from
  (
    select a.* from 
     V$SQL_PLAN_STATISTICS_ALL a
    where a.SQL_ID    = '&1'
    and   a.TIMESTAMP = (select max(b.TIMESTAMP) from V$SQL_PLAN_STATISTICS_ALL b where b.SQL_ID = a.SQL_ID)
  )
  start with PARENT_ID is null
  connect by prior ID = PARENT_ID
  order siblings by ID desc
)
order by NO desc
;

解説

  • 49行目のV$SQL_PLAN_STATISTICS_ALLが実行計画情報の取得元となり、50行目のWHERE条件で表示対象のSQL_IDで絞っている。(階層問い合わせでWHERE句を指定してもstart with~connect byの後に評価されるので、このビュー全件が表示対象となり非常に高負荷な問い合わせとなってしまう。)
  • 共有プールをフラッシュせずにこのスクリプトを実行させた場合、1つのSQL_IDに対して2つ以上のPLAN_HASH_VALUEが取得される場合がある。その際実行計画が正しく表示されない可能性があるので、51行目で直近のTIMESTAMPのものだけ1つを表示対象としている。
  • 53〜54行目は階層問い合わせによって、次のIdがNullとなるId=0を起点として実行順にId値をたどる。
  • 55行目のsiblings句により同じ階層(DEPTH)のId値を並び替えているが、desc[endant]を指定することでId値は逆実行順に並ぶ。ちなみに「siblings」とは「きょうだい」を意味する。
  • 35行目はNested Loops Joinにおいて実際の行数(A-Rows)と比較しやすいように見積もり行数(E-Rows)を加工している。(参考: 津島博士のパフォーマンス講座 第68回 TEMP領域の続きとA-Rowsについて
  • 29〜55行目の問い合わせにおいて、30行目のROWNUM疑似列で順序番号(NO列)を取得しているが、Id=0を先頭とした逆実行順の検索結果をNO列の降順に並び替えることで、実行順に表示させている。(当初はこの部分がなく下から順にたどっていく表示にしていたが、わかりやすさに欠けていたので改良した。)

表示結果

実行順実行統計出力スクリプトによって表示させた結果が以下である。

前回投稿の最後でこのSQLにおけるステップの実行順をまとめたが、以下の結果のID列の順序と一致していことを確認してほしい。

実行計画のステップがどんなに多くても、このスクリプトを使えば実行順に表示させることができる。

ID Operation                                         Name           Starts E-Rows A-Rows A-Time Buffers  Reads Writes  Srch Cols Pstart  Pstop PartID
-- ------------------------------------------------- -------------- ------ ------ ------ ------ ------- ------ ------ ---------- ------- ----- ------
 8         INDEX SKIP SCAN                           I_TABLE001_2        1 38,050  3,060   2.96    3619   1917      0          2
 7        TABLE ACCESS BY INDEX ROWID BATCHED        TABLE_001           1 38,046  3,060   3.12    3706   1977      0          0
11          INDEX RANGE SCAN                         I_TABLE004_8    3,060  3,060      1 204.17  117860 114690      0          5 KEY     KEY        9
10         TABLE ACCESS BY LOCAL INDEX ROWID BATCHED TABLE_004       3,060  3,060      1 204.19  117861 114691      0          0 KEY     KEY        9
 9        PARTITION RANGE ITERATOR                                   3,060  3,060      1 204.20  117861 114691      0          0 KEY     KEY        9
 6       NESTED LOOPS                                                    1      1      1 207.33  121567 116668      0          0
12       INDEX RANGE SCAN                            I_TABLE002PK        1      1      0   0.00       1      1      0          2
 5      NESTED LOOPS OUTER                                               1      1      1 207.34  121568 116669      0          0
 4     FILTER                                                            1      1      1 207.34  121568 116669      0          0
 3    FILTER                                                             1      1      1 207.34  121568 116669      0          0
 2   COUNT STOPKEY                                                       1      1      1 207.34  121568 116669      0          0
 1  SORT AGGREGATE                                                       1      1      1 207.34  121568 116669      0          0
 0 SELECT STATEMENT                                                      1      1      1 207.34  121568 116669      0          0

13行が選択されました。

経過: 00:00:00.02

A-Time列を上から順にたどっていき、値が急激に増えている箇所がボトルネックである。
この例ではId=11の「INDEX RANGE SCAN」がそれにあたる。

次回は、この結果から実際にどのようにチューニングを行なっていくかを追ってみる。

(続く)