stefafafan の fa は3つです

"すてにゃん" こと id:stefafafan のブログです

ISUCONの素振りで private-isu をやってGo実装で32万点までひとまず行った

今週土曜はISUCON予選なので、今日はひとりで private-isu をやっていました。

自分のリポジトリはこれです (INDEX貼ったりとかmy.cnfいじったりとかはサーバ上でやってるのでここに反映されていないですが)
github.com

環境

作戦

  • 各種計測ツールだけを信じる、なるべく一番重いボトルネックを順番に倒す
  • 以下のような流れ
    • ベンチ実行中に top -d1 -cを実行して負荷の様子をみつつ、go tool pprof -seconds 60 http://localhost:8080/debug/pprof/profile も実行してプロファイル採取
    • CPU userが重い時は
      • mysqldの場合は pt-query-digest の結果をみる、必要に応じて pprof 結果も合わせてみる
      • appの場合は pprof の結果を主に見る
      • alpもたまに参考情報として眺める、ステータスコードの割合とか
    • CPUのsystemが重いときは ulimit とかを確認したりする (雰囲気でやっている)
    • CPUのiowait が重いときは my.cnf とか設定値を確認したりする (雰囲気でry

systemでなんか食ってるときどこをどう深ぼっていけばいいかわからなくて困っているけど今回はなんとかなった。

時系列 (自力タイム)

  • 10:03 初回ベンチ: 639点
  • 10:07 Goに切り替えたのみ: 0点
  • 10:37 pt-query-digest の一番重いクエリにINDEX適用: 19722点
    • ALTER TABLE comments ADD INDEX idx_post_id_created_at_desc (`post_id`, `created_at` DESC); とかやってた
  • 11:46 まだMySQLが重いので、クエリの様子をみる。無駄に全件取得してるのをLIMIT 20にした: 26162点
    • getIndex limit 20 by stefafafan · Pull Request #3 · stefafafan/private-isu · GitHub
    • SELECT `id`, `user_id`, `body`, `mime`, `created_at` FROM `posts` ORDER BY `created_at` DESC が遅いのを
    • SELECT posts.id, posts.user_id, posts.body, posts.mime, posts.created_at FROM posts JOIN users ON users.id = posts.user_id WHERE users.del_flg = 0 ORDER BY posts.created_at DESC LIMIT 20 にしたけど、EXPLAINした結果まだ rows が多いので最高の状態にできなかった
  • 12:06 さっき作ったクエリが重かったのでINDEXを追加: 31397点
  • 13:19 interpolateParams=trueにしたり、SetMaxOpenConnsしたり、ulimitあげたりした: 39116点
  • 15:45 DBの画像をnginxから返して304返すようにした: 71555点
    • Get image by stefafafan · Pull Request #6 · stefafafan/private-isu · GitHub
    • ISUCON本で読んだ覚えがあった、リクエストのたびに画像をファイルに書き出して、nginx側ではtry_filesするというのができてよかった。全部DBから一度に書き出すよりは省エネ
    • とはいえ慣れてなくて結局少し時間かかっていた。ちゃんと304返せてるかは alp が確認の役に立つね
  • 16:09 getPostsのほうも、11:46の頃にやったようにLIMIT 20できそうだったのでやった: 92152点
  • 16:16 makePostsのN+1が目立つけど、2位のクエリもINDEXはれそうだったのではった: 99046点
    • ALTER TABLE comments ADD INDEX idx_user_id (`user_id`); とかやった。rowsが97258から100に減った
  • 16:34 1-3位は全部N+1でやる気がないので、4位のクエリのINDEXだけ足す: 96271点
    • SELECT `id`, `user_id`, `body`, `mime`, `created_at` FROM `posts` WHERE `user_id` = 202 ORDER BY `created_at` DESC が遅いので、
    • ALTER TABLE posts ADD INDEX idx_user_id_created_at_desc (`user_id`, `created_at` DESC); とかやってみた
    • この結果 88008点に逆に下がったが、他のクエリでこのINDEXが使われるようになった結果だったのでそっちでIndex Hint使うようにしたらことなきを得た
    • 99046から96271に下がっているようにも思えるが、pt-query-digest的にはこのクエリの順位は下がったので良いと判断
  • 18:16 途中休憩してアニメみたりしてたけど、いよいよN+1のmakePosts途中まで倒した: 175231点
  • 18:25 no space left on device解消したので再実行: 146094点
    • 下がる理由ないと思うのでそういうものかと置いた
  • 18:56 さっきのN+1の残りをさらに直した: 218115点
  • このへんでMySQLやNginxのログを無効化しているけど、あまり大きな変化はなく22万点くらいかな〜という気持ちになる。

ISUCON本チラ見して続き

このあとMaxOpenConnsとか調整してみるものの、そもそもあまり多くのコネクション受け付ける余裕ないようで意味なさそうだった。

最後に再び pprof を有効化して様子みたけど、やっぱりGoのTemplateが一番重いのは変わりないんですねとテンション下がってしまった。

pprof - Graph
pprof - Flamegraph

以下の記事を読むと最後のほうに他にやれそうなことが書いてあるけど、今日一日中やってたので諦めてしまった。
dsas.blog.klab.org

感想

  • 自分1人で全部やってみるというのがやっぱり良い経験という感じがする
    • ulimitどこでどうやるんだっけとか、画像ファイル304で返すのどうするんだっけとか、プロファイラの使い方のプロになるとか
  • 倒す順番はあってると思うので今週末のISUCON予選もがんばりたい!