待ちイベントに関する検証 その９
＜待ちイベントに関する検証 その９＞
ペンネーム： ダーリン
【log buffer space/log file sync】
先週まで 8 回に亘ってデータを取得する際に発生する待ちイベントを見てき
ました。Oracleの待ちイベントは、処理の整合性を保つために必要な内部ロッ
クなどの待ちにより発生するものや、また、純粋にデータのやり取りに時間が
かかるために発生する待ちなどがありました。
さて、今回はデータの取得ではなくデータを更新する際に発生する待ちを見て
みましょう。ただし、同一行の更新による行ロックやあるいは、デッドロック
といったどちらかというとアプリケーションよりの待ちではなく、Oracle の内
部的な待ちイベントを取り上げます。
最初に、検索処理における Oracle の処理の流れを簡単に整理しておきましょう。
あわせてその際に発生していた待ちイベントも載せておきます。
1. クライアントから、Oracleデータベースに向けてデータを処理するために
SQL を発行します。
2. SQL は必要に応じて解析され、その解析イメージは共有プールに格納され
ます。
待ちイベント：latch: shared pool/latch: library cache
3. 実際に、解析イメージを使ってデータを取得する際には、まず、データベ
ース・バッファ上にその対象のデータが存在するかどうかをチェックします。
待ちイベント：latch: cache buffer chains/latch: cache buffer lru chain
4. データベース・バッファ上に存在しない場合は、ディスクから取得する必
要があります。
待ちイベント：db_file_sequential_read/db_file_scattered_read
5. 取得したデータを順にクライアントアプリケーションに送信します。
待ちイベント : SQL*Net message from client/SQL*Net message to client
データを更新する処理では、これに加えていくつかのステップが発生します。
データ更新処理の例として、UPDATEを対象に見ていきます。
大まかには、以下のような処理が行われます。
-----------------------------------------------------------------------
WAIT #5: nam='db file sequential read' ela= 24
file#=15 block#=44179 blocks=1 obj#=74029 tim=1143865915962092
WAIT #5: nam='db file scattered read' ela= 81
file#=15 block#=44180 blocks=5 obj#=74029 tim=1143865915962372
FETCH #5:c=0,e=412,p=6,cr=4,cu=0,mis=0,r=1,dep=0,og=1,tim=1143865915962427
-----------------------------------------------------------------------
さて、やはりここでもいくつかの待ちイベントが発生します。
そして、今回取り上げるのはあちらこちらのサイトで見かけるログ・バッファ
関連の待ちイベントです。
弊社検証環境でUPDATE処理を実行しながら待ちイベントを取得すると以下の
ようなイベントが上位に出てきました。
event
—————————————
log buffer space
log file sync
log file parallel write
log file switch completion
log file switch (checkpoint incomplete)
……
もちろん、アプリケーションの実装や、パラメータの設定、ハードウェア等も
ろもろの条件により影響を受けるため、この順番で待ちイベントが多く発生す
るわけではありません。
これらがどのような待ちイベントなのか、簡単に説明を加えておきます。
------------------------------------------------------------------
log buffer space
Oracle の SGA に確保される log buffer と呼ばれるメモリ領域が不足
した場合に発生する待ちイベント。
log buffer は更新データを一時的に記録する領域なので、更新データ
量が多いか、更新データの書き出しが遅い場合に不足することがある。
log file sync
log buffer の情報がオンライン REDO ログファイルに書き込まれる際、
LGWR プロセスの書き込み処理の終了を待つ待ちイベント。
log file parallel write
LGWR プロセスがオンライン REDO ログファイルにlog buffer の情報を
書き込む際に発生する待ちイベント。
log file switch completion
ログスイッチの完了を待機している際に発生する待ちイベント。
log file switch (checkpoint incomplete)
ログスイッチの際に、該当するオンライン REDO ログファイルのチェ
ックポイント処理が完了していない場合に発生する待ちイベント。
------------------------------------------------------------------
下の 2 つの待ちイベントは、特にログスイッチに関係する待ちイベントで、
今回検証環境で実行した更新量に対して、オンライン REDO ログファイルの
サイズが小さすぎたために発生した模様です。
cf. 10 万件の更新をそれぞれ 10 セッションで実施。
オンライン REDO ログファイルは、50MB 3 グループ 1 メンバ。
さて、残る、3つの待ちイベントはどんな理由で発生しているのでしょうか。
まず、log buffer space 。
この待ちイベントが発生したときの待ちイベントの状況はこんな感じです。
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 のサイズは、、
SQL> show parameter log_buffer
NAME TYPE VALUE
———————————— ———– ——————–
log_buffer integer 6120448
およそ、6MB です。
少なくて待ちが発生しているということなので、本当に効果があるかどうかを
確認するために、とにかく大きくしてみましょう。
ただし、このパラメータは動的に変更できないので、インスタンスの再起動を
伴います。ご注意を。
SQL> alter system set log_buffer=31457280 scope=spfile;
SQL> show parameter log_buffer
NAME TYPE VALUE
———————————— ———– ——————–
log_buffer integer 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 buffer のサイズに関
しては、ひとまずクリアしたということにしましょう。
次は、 log file parallel write です。
前出の説明では、log file sync との違いがどこにあるのか少々わかりにくい
説明文をしてしまいました。確かに、これらは関連する部分があるのですが、
皆さんはこの待ちイベントの違いを整理できているでしょうか？
違いのひとつは、一方はフォアグランドプロセスの待ちイベントで、もう一方
はバックグランドプロセスの待ちイベントだという点にあります。
この続きは、また来週。
夢の中に SHARED POOL 登場。いや、SHARED POOL の中に夢があるのか？
茅ヶ崎にて