デバッグログなどをトレースしてみたところ、Oracleへのデータの登録・更新のSQLの実行時間がテスト環境などと比較しても顕著に長かったため、更にStatsPackを使用してバッチ処理実行中のパフォーマンス統計情報を取得してみました。
StatsPackレポートの中の待機イベントTOP5のところを見ると、以下のようになっていました。
Top 5 Timed Events Avg %Total ~~~~~~~~~~~~~~~~~~ wait Call Event Waits Time (s) (ms) Time ----------------------------------------- ------------ ----------- ------ ------ log file parallel write 31,557 670 21 34.2 log file sync 30,801 621 20 31.7 CPU time 377 19.3 latch: library cache 789 187 237 9.5 control file parallel write 595 78 132 4.0 -------------------------------------------------------------
REDOログの書き込み関連の待機イベント（"log file parallel write"、"log file sync"）の待ち時間（Time）が著しく長いように見えます。
テスト環境で同様の処理を実行中に取得したStatsPackレポートでは以下のようになっていました。
Top 5 Timed Events Avg %Total ~~~~~~~~~~~~~~~~~~ wait Call Event Waits Time (s) (ms) Time ----------------------------------------- ------------ ----------- ------ ------ log file sync 28,517 63 2 31.6 log file parallel write 28,536 57 2 28.4 CPU time 51 25.7 control file sequential read 3,720 10 3 5.1 db file parallel write 1,203 8 6 3.9 -------------------------------------------------------------
REDOログの書き込み関連の待機イベント（"log file parallel write"、"log file sync"）が同じように上位には来ていますが、その待ち時間を比較すると10分の1程度になっています。
これはディスクI/O周りで何らかのハードウェア障害が発生している可能性もあるのではと思い、確認してもらったところ、RAIDコントローラのバッテリ不良が発生しており、そのためにRAIDのライトキャッシュが無効になっていたようです。
早速、RAIDコントローラのバッテリを交換を手配し、交換後に再度StatsPackレポートを取得したところ、以下のようになりました。
Top 5 Timed Events Avg %Total ~~~~~~~~~~~~~~~~~~ wait Call Event Waits Time (s) (ms) Time ----------------------------------------- ------------ ----------- ------ ------ log file parallel write 31,517 97 3 38.4 log file sync 30,587 90 3 35.5 CPU time 51 20.0 db file sequential read 2,494 12 5 4.9 log buffer space 282 3 10 1.1 -------------------------------------------------------------
REDOログの書き込み関連の待機イベント（"log file parallel write"、"log file sync"）が同じように上位には来ていますが、その待ち時間は大幅に改善しています。
RAIDのライトキャッシュが無効になっていたことで、もっとも頻繁にディスクI/Oが発生するREDOログの書き込みのところで詰まっていたわけですね。
この手のハード障害によるパフォーマンスの低下は、OracleやOSの挙動だけを追い掛けているとなかなか原因にたどり着けないことも多いものですが、こうして一度経験すると、今後同じような現象が発生した時に迅速な対応が可能になります。
勉強になりました。