こんにちは。なぜか速度がめちゃくちゃ低下しているのだが。只野です。
はい。とある日の事です。私が担当しているシステムについて問い合わせがありました。「画面が待機中から復帰しません」と。最近稼働しているシステムのソースファイルなどは修正していなく謎は深まるばかりである。前から発生していたのであればその時期から調査すれば原因ソースを特定する事がしやすいのですが、その日から突然処理速度が低下していると言われたので謎である。
何か必ず原因はあるはずだと調査をします。稼働資産を変更していないのであれば画面システム稼働サーバーの問題ではないかとサーバー負荷を調査しますが正常範囲。次にpostgresql稼働サーバーを見てみると処理待ちがかなりの数が並んでいる状態でした。資産も変更していないのになぜいきなり処理待ち状態が並んでいるのか謎である。ちなみに処理待ちの確認は下記SQLを実行して実行時間(query_start)が前の物から処理が終わっていない状態となります。
select * from pg_stat_activity
そして邪魔している処理を発見したら、「pg_stat_activity」実行結果の「pid」を引数に下記コマンドを発行するとプロセスを停止できます。
select pg_cancel_backend(:pid);
原因となっていそうなプロセスを停止させてみましたが、次から次へと同様の現象が発生して一向に解決しませんでした。どうしたものかと頭を悩ませる事になります。次から次へと同様の現象が発生するのはシステムを利用している会社がシステムを利用し続けていたからですが、システム利用会社の業務を停止することはできないのでこのまま続ける事になります。私が確認して処理負荷が高いプロセスを停止して処理負荷が軽い処理は進めるというだましだましの状態で調査をします。かなり精神的に疲れる作業でした。
はい。実行資産、サーバーの問題はないととりあえず決めつけてここ最近の出来事で影響が発生していそうな事を調査していたところ、サーバー管理会社側で「PostgreSQLのVACUUM FULL」が実行されている事が判明しました。「VACUUM FULL」は簡単に説明すると不要なデータを削除してディスク容量を開けてくれるコマンドになります。
ここで異常が発生するとすれば「index」が原因の可能性が高くなります。これはPostgreSQLでVACUUM FULLを実行した場合は「reindex」またはindexの再作成が推奨されているからです。VACUUM FULLを実行すると内部でindex状態が良い状態で保たれていないのでしょう。これはもう原因を特定したようなものだろうとindexを再作成しました。
ですが改善されなかったんだな～これが。若干お手上げムードが立ち込めてきた私ですが諦めるわけにはいきません。再度原因を調査します。次は遅い処理の調査を詳細に実施します。遅い処理はplpgsqlだったためそれ内部で実行されている処理のどこまでが上記SQLだけでは特定できませんでした。ここからは目で調査です。内部で実行されているSQLを一つずつ調査しなぜかすごく遅いSQLを発見することができました。もうこれしか原因はないだろうと該当のSQLを修正し処理速度を改善したところシステムで発生していた問題は改善されました。
結果的には既存バグなのですが、今まで該当箇所で処理速度の問題が発生していないため謎は深まるばかりではあります。原因は「PostgreSQLのVACUUM FULL」したことで間違いはないだろうと思いますが、既存で動作していたSQLにこれほどの影響があるとは考えもしませんでした。これは一例にしかすぎませんがもし「PostgreSQLのVACUUM FULL」を実行する事がある場合、既存SQLの処理速度に影響がある可能性があると頭に入れておいた方がよいかもしれません。
本日はこの辺で