Oracle Real Application Clusterの検証 その3

投稿日: 2003年5月21日

<Oracle Real Application Clusterの検証 ~その3~>
ペンネーム ダーリン

— RAC環境でのチューニング —

さてシングルインスタンス下で最適化したアプリケーションを、そのままRAC
環境に移行しても、処理性能がスケーラブルどころかむしろ遅くなってしまう
可能性があることをお話しました。

どこに原因があったのでしょうか。

Oracleの動的パフォーマンスビューにV$SYSTEM_EVENTというビューがありま
す。このビューからシステムの待機イベントの情報が取得できそうです。
このビューから待機時間を取得するためには、初期化パラメータの
“TIMED_STATISTICS”をTRUEに指定する必要がありますが、Oracle 9i Release
2からは”TRUE”がデフォルトなので、時間情報もデフォルトのままで取得可能
です。
また、このビューは合計の待機時間が表示されるので、対象の処理を行う前
後の差分を取得することにより詳細に調査が出来ます。

先週お話した環境で、上記の値はどのようになっていたのでしょか。

(先週の資料)

 CASE    INSTANCE NO   SESSIONs      EPS(※1)   TPS(※2)
 =======================================================
  01          1           237       16,083       732.3
 -------------------------------------------------------
  02          1           256        5,453
              2           256        5,362
          ----------------------------------------------
           Total          512       10,815       489.4
 -------------------------------------------------------

V$SYSTEM_EVENTの情報

 CASE    INSTANCE NO   EVENT                 WAIT数  WAIT時間(sec) 
 =================================================================
  01          1        log file sync      1,763,899   422,800 << (1)
                       latch free           456,638    38,245
                       buffer busy waits    244,583    16,821
                       enqueue              122,109    12,221
 -----------------------------------------------------------------
  02          1        enqueue            2,367,703   410,303 << (2)
                       buffer busy waits  3,025,078   314,120 << (3)
                       buffer busy global
                        cache             1,736,016   206,586 << (3)
                       global cache busy  1,042,919    95,160
                       latch free         4,551,655    75,086
          --------------------------------------------------------
              2        enqueue            2,341,917   408,503 << (2)
                       buffer busy waits  3,034,419   321,680 << (3)
                       buffer busy global
                        cache             1,748,311   213,001 << (3)
                       global cache busy    968,529    85,302
                       latch free         4,638,862    73,170
 -----------------------------------------------------------------

CASE01では、”log file sync”イベントのWAIT時間がもっとも多くなっていま
す。(表中(1)) “log file sync”イベントは、DBWRがデータベースバッファ上
のダーティーブロックをディスク上に書き出す際、ログバッファにある更新
データをオンラインREDOログファイルへ書き出すイベントです。
このイベントは、トランザクション中にあまりコミットが実行されていない
場合に多く見られます。このイベントで待ちがたくさん発生しているシステ
ムをお持ちの方は、ちゃんとコミットしましょうね。

では、RACの各インスタンスで処理を実行したCASE02ではどうでしょう。
各インスタンスの最上位に”enqueue”イベントがきています。(表中(2))
どのエンキューの取得に時間がかかったのかは、V$ENQUEUE_STATビューを見
るとわかります。

CASE02では、特に”TX”エンキューが非常に高いことがわかりました。

********************************************************

EQ_TYPE     TOTAL_REQ  TOTAL_WAITS  WAITTIME (sec)
--------------------------------------------------------
TX          4,682,405    1,892,191       419,433
HW             30,123       27,898         3,011
SQ                283          172            14
              

********************************************************

しかし、”enqueue”イベントだけに、時間がかかっているわけではないようで
す。”buffer busy waits”および”buffer busy global cache”も他のイベント
と比較しても待ち時間がかなり大きくなっています。(表中(3))

これに関しても”enqueue”と同様、どのバッファに待ちが発生していたかを確
認してみましょう。
Oracle 9i Release 2では、V$SEGMENT_STATISTICSビューから各オブジェクト
の統計情報が取得できます。ここから、バッファ上の待ち回数”buffer busy
waits” や、RAC環境で確認できるINTER CONNECT経由のブロック転送量
“global cache current blocks served” などの情報が取得できます。

このビューを利用して、バッファ待ち回数の多いオブジェクトを特定してみま
す。すると、CASE02では以下のような結果となりました。

********************************************************
(buffer busy waits)
OBJECT               TYPE      WAIT回数
---------------------------------------
IDX_LOGTBL1          INDEX    2,445,422
IDX_LOGTBL2          INDEX    2,074,474
LOGTBL2              TABLE       76,123
LOGTBL1              TABLE       37,154
PK_SESINFO           INDEX       32,102

********************************************************

ログ系のインデックスで特にWAIT回数が多いですね。
このログ系のテーブルは、実はトランザクションログを残すテーブルですが、
日付や、順序などをインデックス項目にした場合、同一ブロックへの更新
(追加)が集中することはすでにご承知のとおりです。
(バックナンバー “トランザクションエントリに関する検証 8″参照のこと(※))

とくに、ログ系のテーブルであれば、データの検索を考えて日付をキーにする
ケースも多々あることでしょう。
ではこのテーブルのインデックスにはどんな列が指定されているかと言うと
、、、、おっとやっぱり登録日時だ。つまり、日付時刻データをINDEXとして
INSERTするため、ブロックの競合が発生していることが予想されます。(※)

先ほどと同様に、V$SEGMENT_STATISTICSからオブジェクトの情報を取ってみ
ます。今度は、”ITL waits”です。(“ITL”=”トランザクションエントリ”)

********************************************************
(ITL waits)
OBJECT               TYPE      WAIT回数
---------------------------------------
IDX_LOGTBL1          INDEX        1,532
IDX_LOGTBL2          INDEX        1,210
PK_SESINFO           INDEX           33
IDX_LOGTBL3          INDEX            1
PK_MSINFO            INDEX            1

********************************************************

やはりログ系のテーブルでトランザクションエントリの待ちが発生しています。
と言うことは、インデックスのトランザクションエントリの競合が発生すると、
テーブルの場合と違い待ちが発生してしまいます。(※)

実は、トランザクションエントリの待ちは、CASE01(IDX_LOGTBL1で6回程度)
でもおきています。しかしその数はけた違いに小さい値です。CASE01と02では
合計のSESSION数が違うことにお気づきの方もおられるとおもいます。CASE01
と比較するために、両インスタンスから128SESSIONで接続し同時接続数の合計
をほぼ同じにして、同様の検証を行ってみました。

その結果は以下のとおりです。

********************************************************
(ITL waits)
OBJECT               TYPE      WAIT回数
---------------------------------------
IDX_LOGTBL1          INDEX          524
IDX_LOGTBL2          INDEX          124
PK_SESINFO           INDEX           16

********************************************************

トランザクションエントリの待ちはCASE02と比較するとかなり小さな値です。
でも、CASE01と比較すると、約90倍にもなります。

なぜ、CASE02ではなぜ”buffer busy waits”や、”ITL waits”が多くなるのでし
ょうか。

続きはまた来週。

なーがーぐつでー でかけよ おぅ!!     でも 雨上がりの茅ヶ崎にて