pprofをWeb上で見られるツールを作って、ISUCON13に挑戦しました

デプロイ周りで手戻りが起こってしまい若干後悔が残る結果になりましたが、去年よりは着実にスコアを上げられた気がします。

最終スコアは33,789点で、694チーム中56位でした。

僕(シバニャン)は、メトリクス、オンメモリキャッシュ、NGワード登録時の判定、N+1の解消(ちょっとだけ)を担当しました。

学び

やるべきだったこと

  • 大きな変更を入れるのではなく、じわじわと効きそうなものを入れていくべきだった。
  • デプロイスクリプトのミスのチェックのために、コミットログが新しいか、ビルドが更新されているかを毎回確認するべきだった。

やってよかったこと

ボトルネックの特定に、felixge/fgprofとshiba6v/go-fprof、pprofpageが役に立ちました。

felixge/fgprof

fgprofは、pprofと似たように使用できますが、CPUを使っていない時間(DB待ちなど)も測定してくれます。

github.com

shiba6v/go-fprof

github.com

shiba6v/go-fprofは、去年のISUCONから導入しているツールです。 alpと比べると、privateメソッドや関数の途中などの好きな場所に計測を増やしていける点がメリットで、エラーの回数やbodyサイズを計測できないのがデメリットです。

計測すると、以下のような結果が得られます。

FProf Result [us]
Sum      1172, Max    1172, Avg    1172, Min   1172, Count     1, main.GetPaymentResult:L15
Sum   6122746, Max  224235, Avg   21333, Min    661, Count   287, main.getTagHandler:L27
Sum 103671832, Max  456753, Avg   73526, Min    658, Count  1410, main.getReactionsHandler:L38
Sum    387096, Max  108662, Avg   21505, Min    960, Count    18, main.getStreamerThemeHandler:L60
Sum  31469279, Max 3999090, Avg 1656277, Min 414043, Count    19, main.getUserStatisticsHandler:L64
Sum  81552906, Max  253907, Avg   59397, Min   1459, Count  1373, main.getLivecommentsHandler:L71
Sum  36140357, Max  340977, Avg  122095, Min    340, Count   296, main.reserveLivestreamHandler:L72
Sum  31210139, Max 3987903, Avg 1642638, Min 407561, Count    19, main.getUserStatisticsHandler:L81
...

pprofpage

github.com

pprofpageは、今年新しく作ったツールです。pprofやfgprofの計測結果をPOSTすると、URLを発行してくれます。

PPROF_PATH=$(curl -X POST -F file=@/home/isucon/tmp/cpu.pprof https://emaaxnj6hk.execute-api.ap-northeast-1.amazonaws.com/prod/pprof/register)
echo https://emaaxnj6hk.execute-api.ap-northeast-1.amazonaws.com/prod${PPROF_PATH}

ファイルをURLに向けてpostすればページが完成します。 LambdaとS3、API Gatewayでサーバーレスで作ったので維持費がほぼ0円で、スパイクが来ても耐えられるはずです。(DDoSされた場合を除く)

ざっくりやったこと

やったこと

  • インデックスを貼りまくる
  • N+1を解消
    • userStatistics
    • reactions
  • オンメモリキャッシュ
    • User
    • Icon
      • userのidで取る部分とnameで取る部分があるのでそれぞれ
    • Livestream & Tags
  • DBを分ける
    • DB1台とApp1台になりました。
  • NGワード登録時のNGワード判定をDBからAppに移す

やろうとしたけどできなかったこと

  • DNSサーバーとAppを分けようとした
  • totalTipsのN+1を分ける部分で時間切れ

時系列

序盤イケイケ期

10:24 4,134点

序盤は、メトリクスの整備を行い、LiveStreamとTagsのローカルキャッシュを入れ、DBを分けました。

12:00 7,005点
12:42 13,068点

中盤絶望期

13:42
立て続けにベンチがfailし、そこからinitializeが叩けなくなりました。

15:00
原因を切り分けていった結果、昼ごろからずっとコードが反映されていないことが発覚しました。 これまでにマージしたものは、ベンチが通ったと勘違いしていただけということが分かり、絶望の瞬間が訪れました。

15:30ごろに、デプロイスクリプトの修正が終わりました。

後半マージ期

15:30からは、ベンチが通らない状態だったmasterブランチを捨て、 最後のベンチが通る状態から、12:00-13:40の間の変更を確認しながらマージしていきました。 インデックスを貼り、User, Iconのキャッシュを入れ、userStatistics, reactionsのN+1を解消し、NGワード判定をDBからAppに移しました。

16:25 21,521点
16:51 25,835点
17:31 28,088点

最終チェック

競技終了時点でも、まだまだやれそうなことがありそうな気配がしていましたが、万全を期すために17:30ごろに終わりにすることにしました。

goccy/go-jsonへの切り替え、MySQLのconfig変更、ログ切り、再起動試験、点数ガチャを行いました。

17:49 33,789点

今年も楽しい問題でした。 運営の方々、ありがとうございました。 非同期周りのコーディングの訓練や、DBの知識の習得に役立っており、感謝しています。