PostgreSQLが重い！あなたならどうしますか？
topコマンドを叩いてDBサーバの負荷を調べます。
$ top
top - 01:36:45 up 340 days, 20:16, 4 users, load average: 0.01, 0.04, 0.00
Tasks: 85 total, 1 running, 84 sleeping, 0 stopped, 0 zombie
Cpu(s): 0.8%us, 0.2%sy, 0.0%ni, 97.7%id, 1.2%wa, 0.0%hi, 0.2%si, 0.0%st
Mem: 4044720k total, 3996008k used, 48712k free, 60648k buffers
Swap: 2152700k total, 252k used, 2152448k free, 3826572k cached↑これは平常時の状況ですが、負荷が高いときは右上のload averageが5とか10とかになっているはずです。
あわわあわわ。
(ここまで30分)
topコマンドを初めて叩いた初級プログラマは、この後どうしていいかわからないはずです。
Amazonまたは最寄の書店に駆け込んで、この書籍を買いましょう。
(ここまで2時間)
本をぱらぱらとめくっていると、
「負荷が高いというのは、CPU負荷かI/O負荷(ディスク負荷)かのどちらかである」という趣旨のことが書いてあります。
ほうほう。
そこで、
「CPUかI/Oか、どちらが重いんだろう？」
「それはどうやって調べるんだろう？」
という疑問が浮かびます。
(ここまで1日)
CPU負荷とI/O負荷、どちらが高いのか？
どうやら、sarコマンドでそれがわかるようです。$ sar
00時00分01秒 CPU %user %nice %system %iowait %steal %idle
00時10分01秒 all 1.48 0.00 0.77 2.45 0.00 95.30
00時20分01秒 all 0.98 0.00 0.74 1.70 0.00 96.59
00時30分01秒 all 0.63 0.00 0.46 1.19 0.00 97.71
00時40分01秒 all 1.11 0.00 0.68 10.31 0.00 87.90
「iowaitが高い = ディスクアクセスが重い」ということのようです。
次の疑問は、
「なぜディスクアクセスが重いのか？」
「その原因はどうやったらわかるのか？」
スロークエリを探す
PostgreSQLには、実行に何秒以上かかったSQLをログに残すという機能があります。postgresql.confを開いて、log_min_duration_statementの値を設定してみましょう。
初めは3000(=3秒とか)にして、徐々に短くしていきます。
# nano /usr/local/pgsql/data/postgresql.conf
...
log_min_duration_statement = 3000
....
# pg_ctl reload
こうすると、ログディレクトリにスロークエリログが出力されるはずです。
実行時間がやたら長いSQLに注目しましょう。
そのSQLが頻発する時間帯と、負荷が高い時間帯が一致していれば、そのSQLが原因である可能性が高いです。
スロークエリについてはこの記事が参考になります。
スロークエリの分析 -- Let's Postgres
(ここまで2日)
そのSQLの頭にexplain analyzeをつけて実行してみましょう。
mydb=> explain analyze select * from hoge ... Explain出力の読み方はこちら。
Explaining Explain ～ PostgreSQLの実行計画を読む ～ (PDF版)
Indexを貼る
Explain出力の中に、"Seq Scan"という文字があれば、それが原因の可能性が高いです。つまりIndexが貼られていない(または使用されていない)ために、テーブル全体がフルスキャンされているのです。
CREATE INDEXしてあげましょう。
サービスを止められない場合は、CRATE INDEX CONCURRENTLY がおすすめです。
Index作成についてはこちら。
CREATE INDEXを使いこなす - matsuou1の日記
(ここまで１週間)
SQLチューニング
また、SQLの書き方を変えることで実行時間を速くすることもできます。アプリ側の改修が必要になりますが、地道にやるしかありません。
こちらの記事などを読んで、重いクエリから一個ずつ改善していきましょう。
PostgreSQLを遅くしている犯人はどこだ？
(ここまで１ヶ月)
適切なIndexの設定と、SQLの書き直しで、IO負荷が下がってサーバが落ち着きました。
(しばらく平和な日々)
CPU負荷の原因は？
さてサービス人気が徐々に出てきて、また負荷が上がってきました。sarで確認すると、今度はCPU負荷が高いです。
おもむろにさっきの本をとりだして、CPU負荷が高い場合の対処法を探してみましょう。
しかし、
「CPU負荷が高いのは、サーバが本来の性能を発揮している理想的な状態である」
という趣旨のことが書かれています。
理想的というか、ユーザからクレーム殺到してるんですけど(´・ω・`)
実はDBサーバのCPU負荷が高い場合の対処法というのは、なかなか本やWebを検索しても見つかりません。
悶々とした日々を過ごします。
(ここまで２ヶ月)
アプリ側のログを見る
アプリ側に原因があるかもしれないと思い立ち、アプリ側のログを調べてみましょう。覚えたてのtail -f を駆使して、ウェブアプリケーションフレームワークが出力するログや、Apacheのログを見ます。
さてApacheのログを見てみたところ、hoge.phpというのがやたらと大量にあることがわかりました。
hoge.phpというのは、サービス画面のいたるところから呼び出されているphpスクリプトです。
hoge.phpの中身をよく見ると、実行時に必ずPostgreSQLに接続する仕組みになっています。
ユーザがWebサイトにアクセスしてくるたびに、大量のhoge.phpが起動され、大量のコネクションがPostgreSQLに対して発行されていたのです。
犯人はお前だ！
(ここまで３か月)
アプリ側の仕様を変更して、hoge.phpがPostgreSQLに接続しないように変更しました。
そしたら、嘘のように負荷が下がり、Webサイトの動作が速くなり、ユーザも大喜びで、売上が伸びました。
(ここまで４か月)
おわりに
とまあこんな感じで解決に４か月もかかったりすることがあるかもしれません。サーバが苦手なウェブエンジニアでも、一個ずつやれば解決できないことはないんだ、という話でした。
解決できないよりは遥かにマシですし、意外と楽しかったりするものです。
(もっとも、実際の現場は上に書いてるようなのらくらりした感じではなく、阿鼻叫喚だと思いますw)
これを読んでいるウェブエンジニアの方も「おれサーバ管理者じゃねーし」と投げ出す前に首を突っ込んでみてはいかがでしょうか？
参考
MySQLがおかしい！あなたならどうしますか？ - MySQL Casual Advent Calendar 2011
カテゴリ:
PostgreSQL