CPU負荷が下がったおかげか、インデックスを見直したおかげか
入力結果を集計してPDFで出力するシステムにおいて、前日からPDFが出力できない状況との連絡がありました。
メールでの連絡で気がついたのは、午前9時過ぎです。
確認するとタイムアウトエラーが発生しています。
タイムアウトになるまでの制限時間を確認すると、3分になっていたので、PDFを出力する処理のときだけタイムアウトになるまでの時間を延ばしました。
倍の6分にしてもPDFの出力はできず、12分にするとなぜか10分少々でタイムアウトエラーが発生しています。
12分にならないのを不思議に思いつつ、どうするかと考え、データ量が多いためだろうと考え、データベースのインデックスが適切か確認を始めました。
確認を始めたのが10時過ぎです。
システムのソースコードを確認しながら、データベースのインデックスが適切か、WHERE/ORDER BY/JOINに使われているカラムを確認した結果、処理速度の向上に効果がありそうなカラムにインデックスが無かったので、インデックスを作成しました。
データは10万レコード以上あるので、このタイミングでインデックスを作成しても、どれくらいの時間で終わるのかと思いながら作成したら、ミリ秒台でインデックス作成のコマンドは終了しました。
インデックスの作成が終わって、PDFを作成する際に大量のデータを取得するためのSQLを実行すると、速度は向上していましたが、望んでいたほどではありませんでした。
それでもPDFの作成を行うと、あるPDF以外は出力できるようになっていましたが、あるPDFだけはまだタイムアウトエラーが発生していました。
午後は昼食後1時間は予定が入っていて対応ができないので、11時半くらいに電話で、引き続き対処すると連絡するとともに、データ量を減らせないかと相談をしました。
データ量の差によって、PDFが出る場合と出ない場合があるのはわかっていたので、相談はしましたが、すぐには結論を得られませんでした。
プログラムの修正によって少しでも処理が速くできるようにならないか調べていくしかないかと思い、ソースコードに処理時間のログを追加していたら昼食の時間になりました。
速度が改善したけれど、はっきりしない要因
昼食後の予定が終わり、処理時間のログを取得しながら、データ量が少ないパターンから試していくと、意外に早く処理が終わって、PDFファイルが出力されます。
データ量のおかげだろうと思いながら、データ量を徐々に増やしていきました。
2番目にデータ量が多いパターンのPDFファイルの出力を試すと、午前中に試したときよりPDFファイルは速く出力されました。
これなら1番データ量が多いパターンでも、PDFファイルの出力ができそうに思えたので試したところ、PDFファイルは出力できました。
再現性があるのかとお思いながら、1番データ量が多いパターンで2度目、3度目のPDFファイルの出力を試したところ、どちらもできました。
データベースサーバーが共用されているので、サーバーの負荷を改めて確認すると、月が替わってから毎日業務で使われている時間帯はCPUの負荷が高い状態が続いていました。
対処を行った日は、午後からはCPUの負荷が下がっていました。
15時半頃に、状況改善したので試してもらいたいと電話連絡して以降、PDFの出力ができないと連絡はありません。
月が替わって前月分のデータを登録され、PDFの出力処理をされたので、データベースサーバーのCPU負荷が高かったのが、インデックスの作成が終わって負荷がさがったので、PDF出力ができるようになったのか、共用サーバーなので、他の利用者の負荷が高かったのが下がったおかげでなのが、対処できた要因がはっきりしません。
毎日データベースサーバーの負荷状況を確認しながら、次月同じ状態になるのか確認をする予定です。
