待ちイベントに関する検証 その１０
＜待ちイベントに関する検証 その１０＞
ペンネーム： ダーリン
【log file sync/log file parallel write】
さてさて、待ちイベントの検証も大詰めを迎えました。
前回は、更新処理が行われたときに発生する待ちイベントとして、
log buffer space が待ちイベントの最上位に来ていました。この待ちイベント
は log buffer が足りないときに発生するので、これを回避するために初期化
パラメータの log_buffer を大きく設定してその効果を確認してみました。す
ると、待ちイベントの発生回数が下がり、待ち時間も減少していることが確認
できましたね。
log buffer = 6120448 のときの待ちイベント： ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ event wait_class total_wait time_waited ---------------------------- -------------- ---------- ------------ log buffer space Configuration 106 7499 log file parallel write System I/O 31 4789 control file parallel write System I/O 35 1872 log file sync Commit 18 1496 log file switch completion Configuration 3 279 .........
log buffer = 34590720 のときの待ちイベント： ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ event wait_class total_wait time_waited ---------------------------- -------------- ---------- ------------ log file parallel write System I/O 16 3166 log buffer space Configuration 14 1183 control file parallel write System I/O 43 733 log file single write System I/O 4 6 db file scattered read User I/O 96 2 .........
次に待ちイベントの上位に来たのが、log file parallel write です。
が、、次に進む前に、なぜ log buffer space の待ちイベントが発生したのか
おさえておきましょう。
log buffer space は、REDO 情報が log buffer に書き込めない状況が発生し
ていることをあらわしています。
その直接の原因は、 log buffer の不足です。
これは前回の検証でも明らかになっています。 log buffer を増やせば待ちが
解消したのですから。
ではなぜ、log buffer が不足するのでしょうか？
一つ目は、log buffer が小さすぎた場合です。
二つ目は？？
今一度 log buffer の役割を整理しましょう。
Oracle では DML などの処理で発生する更新情報をバックグランドプロセスの
ひとつである LGWR がオンライン REDO ログファイルに書き出す前に一時的に
メモリ上に格納します。この情報を適切なタイミングで、LGWR がオンライン
REDO ログファイルへ書き出していくのですが、これがスムーズに書き出せな
いと、log buffer には更新情報はたまるし、でもオンラインREDOログファイ
ルにはまだ書き込めていないし、、、、という状況になる場合があります。
このようなケースでは、log buffer に更新情報が徐々にたまり続け、その結果
log buffer space が出てしまうことが考えられます。
と言うわけで、二つ目は、オンライン REDO ログファイルへの書き出しをスム
ーズにしてあげるという方法です。
でも、オンライン REDO ログファイルへの書き出しがスムーズかどうかはどう
やって判断すればよいのでしょうか。判断材料があると便利なのですが。
そこで登場するのが、log file parallel write です。
log file parallel write の説明を再度見直すと、、
------------------------------------------------------------------
log file parallel write
LGWR プロセスがオンライン REDO ログファイルにlog buffer の情報を
書き込む際に発生する待ちイベント。
------------------------------------------------------------------
というわけで、この待ちイベントの発生状況を見ることで、オンライン REDO
ログファイルへの書き込みが滞っているかどうかを判断することができそうで
す。
今回の例で言うと、待ちイベントの log buffer space の次に
log file parallel write がリストされていることから、オンライン REDO
ログファイルへの書き込みで遅延が発生していると考えてよいでしょう。
そこで、この場合のチューニング方法としては、大きく分けて 2 つあります。
1) オンライン REDO ログファイルへの書き込み量を減らす。
ex. 無駄なインデックスを減らす。
2) オンライン REDO ログファイルを書き込み速度が高速なディスクへ配置する。
ex. RAID5 は避ける。
I/O競合が発生しないようにホットファイルとは分ける。
上記は、オンラインREDO ログファイル関連の配置でよく言われていることです。
これらが、Oracle 内部の待ちイベントとどのように関連しているのか理解して
いただけたでしょうか？
さて、次は前回の最後に少し触れた待ちイベントを見てみましょう。
下記は、前回の説明文です。
------------------------------------------------------------------
log file sync
log buffer の情報がオンライン REDO ログファイルに書き込まれる際、
LGWR プロセスの書き込み処理の終了を待つ待ちイベント。
------------------------------------------------------------------
しかし、log file sync の待ちイベントは log buffer のサイズを変更する前
でも後でも、大して発生していません。さほど問題になるような待ちイベント
ではないように思われます。
でも、これは処理のパターンで大きく変わってきます。同じ環境で上記とは異
なった処理をシミュレートしてみましょう。
その結果、以下のような待ちイベントが出てきました。
event wait_class total_wait time_waited ---------------------------- -------------- ---------- ------------ log file sync Commit 2015 141016 log file switch completion Configuration 932 69125 log file switch (checkpoint Configuration 678 64440 incomplete) log file parallel write System I/O 232 30416 buffer busy waits Concurrency 3099 18141 .........
待ちイベントの最上位が log file sync です。
前回見てきた処理と、上記でシミュレートした処理の大きな違いは、前者はバ
ッチ系の処理であったのに対し、後者はOLTP系の処理だった点です。
簡単に違いを整理すると次のようになります。
バッチ系：10万件一括commit
OLTP系：10万件毎回commit * 10セッション
ポイントは、OLTP系の処理で毎回commitしている点です。
commit処理は更新情報を確定させるために、該当する log buffer の内容をオ
ンライン REDO ファイルへ完全に書き込む必要があります。書き込めなければ
処理が先に進まないのでここで待ちが発生します。しかし、自分自身が更新し
た処理の結果なので他の誰かにまたされているというわけではありません。
一方、これが他人の（他のセッションの）commit処理が先行している場合は、
話が変わってきます。つまり自分以外のcommit待ちで待たされると待ちイベン
トとしてカウントされます。これが log file sync です。
先の log file parallel write と log file sync の大きな違いをひとつ明確
にしておきましょう。
ともに待ちイベントではありますが、待たされているプロセスが異なります。
log file parallel write : バックグランドプロセス(LGWR)
log file sync : フォアグランドプロセス(専用サーバプロセスなど)
log file sync が発生する状況を間単に整理しておくと以下のようになります。
1) (Session A) DML 処理が実施されデータが更新される。
2) (Session A) log buffer に更新情報が記録される。
3) (Session B) DML 処理が実施されデータが更新される。
4) (Session B) log buffer に更新情報が記録される。
5) (Session A) commit実行。
6) (Session B) commit実行。
この後、Session B の commit 情報がオンラインREDO ログファイルに記録さ
れる前に、Session A の commit 情報が記録されているはず、、、
なんですが、まだ Session A の commit 情報が記録が終了していない！？
という場合に、Session B で log file sync がカウントされます。
さて、なぜ、こんなことになるのでしょうか？
先ほどと同じくその理由を考えてみましょう。
log file sync はフォアグランドプロセスで commit が実行されたときに発生
するのですが、commit により log buffer に格納されている情報をオンライン
REDO ログファイルへ書き込む要求を投げる相手は、LGWR です。
すると、当然 LGWR で発生していた待ちイベント ( log file parallel write )
がここでも発生する可能性があります。
実は、log file sync の待ち時間には、commit のタイミングで発生している
log file parallel writeの分も含まれます。つまり、log file sync が発生
している場合、オンライン REDO ログファイルへの書き込み遅延が影響してい
る可能性があるということです。
となると、打つ手は log file parallel write が発生していたときと同じ方
法が有効になりますね。
一日中バッチ処理が実行されているようなサイトと、オンライン処理を実行し
ているサイト（こちらのほうが多いかと思いますが）では、log buffer (とい
うかオンライン REDO ログファイル)関連の待ちイベントの出方が変わってく
ることを頭の片隅に置いておいてください。
ただ、いずれにしてもチューニングのアプローチは似ています。
# log buffer のサイズに関しては OLTP 環境においては、バッチ系メインの
# サイトほど大きくする必要はないはずですが。
さて、10回に亘り Oracle からデータを取得・更新する際に発生する待ちイベ
ントをざっくりと見てきました。
待ちイベントに関する検証（というか整理）については、ひとまず今回でおし
まいです。Oracleには本当にたくさんの待ちイベントがあり、これらは複雑に
絡み合っています。次の機会に特定の待ちイベントに絞ってもっと詳細に取り
上げて行きたいと思います。
次週からは ASSM (Automatic Segment Space Management) を題材に検証する
予定です。お楽しみに。
ナビを使って道に迷う 茅ヶ崎にて