stefafafan の fa は3つです

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

ISUCON13 に参加した (最終スコア 17996点) #isucon

今年もISUCONという大会に参加しました。去年と同様「天下n品」という同僚2名とのチームで挑戦しました(が、1人諸事情により参加が難しくなったため、今回は2人で最初から最後までやりました)。例年通りGoでやりました。なおスコアについては、自分たちで観測できた最終的なもので、再起動試験を経た後どうなったかは未確認です。
isucon.net

去年はこちら: ISUCON 12予選参加したけど最終スコア12171点で惨敗 #isucon - stefafafan の fa は3つです

感想

  • 2人だとインフラ担当とアプリ担当みたいな感じになって、特にインフラを主に自分がみていたがほぼマニュアル見る時間もなく、アプリケーションも結局一度もブラウザでみることはなかった
  • マニュアル見ていないから画像ファイル書き出しのやつで無駄に時間かけてしまった、マニュアルはみたほうがいい
  • 今年色々と忙しくて素振りせずに挑んでしまったが、素振りはしたほうがいい
  • とはいえ、去年までチームで使っていたScrapboxテンプレートが活用できたので、ドキュメントがあると便利
  • サーバの負荷の様子をみながら適宜重いところからやれていたので、まあ悪くはなかった
  • 最後のほうに大きめな変更を入れてバタバタしてfailしたまま終了しそうになったので、コードフリーズをはやめにするべき

楽しかったです、おつかれさまでした!以下はタイムラインのメモです。

タイムライン

  • 8:58 空のGitHubリポジトリやメモするためのScrapbox会場を用意
  • 10:00 環境構築開始
  • 10:18 ssh用のconfigを用意し、チームメンバーに共有
  • 10:19 とりあえずベンチ入れて、3636点を確認
  • 10:36 3台ともGit管理下に置き終える
  • 10:45 頃 それぞれのサーバのスペックおよび入っているミドルウェアのバージョンやDBのテーブルの行数などを調べてページにまとめる
  • 11:08 それぞれのサーバでMySQLのスローログ有効化やnginxアクセスログをltsv形式に変える
  • 11:24 pprof および、チームの内製計測ツール導入
  • 11:29 再びベンチマークを動かす、3390点
    • 内製ツール、今回不参加メンバーに毎回お願いしていたので、なんかうまく動いていないことに気づいたもののあきらめて、手で素朴にalpやpt-query-digestを実行することにした
    • ベンチ回しているときにtopを確認し、DB負荷が支配的だったので、pt-query-digestの結果をとりあえずみることに
    • SELECT * FROM livestream_tags WHERE livestream_id = 7522\G とかがあがっていて、INDEX足すかN+1かをやっていく必要がありそうね〜と話していた。
  • 11:49 チームメンバーがINDEX足して回っていそうだったので、とりあえずいつものGoのDB周りの設定を適当に入れた、4193点
    • conf.InterpolateParams = true
    • 再起動試験対策のために、db.Pingするコード調整
    • db.SetMaxOpenConns 周りのコードを足して、適当に 25 に設定した
  • 12:00 3人目のメンバーがやってくるが、今回は参加難しいとの連絡
  • 12:03 チームメンバーが一通りindex貼って回ってくれた、12651点
  • 12:17 ベンチを再び回してtopの様子をみた。DB負荷が高すぎる
  • 12:20 チームメンバーがN+1みてくれていそうだったので、適当にMySQLのmy.cnfをいじってみる。 12597点
    • あまり効果なさそう
  • 12:36 isupipe database を別ホストにわけようとする
  • 12:59 ホストの分割に成功、5086点
    • なぜか「名前解決成功数」が増えたのに「売上」は下がって悲しむ
  • 13:16 分割後に改めてpt-query-digestをかける
    • isupipe では SELECT image FROM icons WHERE user_id = 1071\G が最強になっていたので、これはnginxから返すやつやろうと判断
  • 13:23頃から Goで画像を返す部分でついでに画像をファイルに書き出すようにしつつ、nginxで画像を返すというのを試し始める
    • nginxの書き方にしばらく悩む
  • 13:28 チームメンバーがN+1を一部潰す、12139点
  • 13:51-14:20 ベンチマーカーに問題があり、画像ファイルをnginxから返すやつが試せずに放心
  • 14:23 画像のやつ試す、17692点
  • 14:31 計測の様子みれてなかったので、ログをtruncateして再度enqueueするものの、みんなが同時にベンチマーカー使っているためタイムアウトし続ける
  • 14:47 再度試したら、17977点。iconsのスロークエリの順位は下がっているが、alpをみると全部200として返していてあれ?となる
  • 15:09 nginxの設定もGo側も凡ミスがいくつかあることに気づいて調整
  • 15:21 引き続き調整して、18986点。alpではまだ200を返していて、なんで304じゃないんだっけとなる
    • ここまで自分はマニュアルを読んでなかったが、チームメンバーがマニュアルにこれについてちょっと書いてることを言ってくれて、一旦これでマージすることにした
  • 16:13 画像の件何回も実行すると初期化時に失敗しそうだったので、initializeの時にディレクトリ以下に書き出した画像を一括で消すようにした。19663点
  • 16:15 最新のmainブランチに戻して再度ベンチ。19839点
    • まだDBが重い
  • 16:38 サーバ上でブランチの切り替えをせずにベンチ入れ続けていることに気づいて何度もミスった。改めてベンチしたら 15121点になってなぜか下がっている。
    • pt-query-digestの2位に COMMIT\G がいて気になる
  • 16:51 MySQL 8のバイナリログおよびREDO LOG無効化とpurge。15145点
  • 17:06 PowerDNSを3台目で動かそうと試みる
    • /etc/powerdns/pdns.d/gmysql-host.conf という設定ファイルと env.sh環境変数をなんかいじったらよさそうと試す
    • あとはmysql userの権限調整
  • 17:38 それぞれのサーバのmy.cnfなどを手で書き換えていたので手動で設定を見直して揃えたりして、再起動を試す
    • 再起動後、毎回failするようになる。チームメンバーも画像ファイル周り触っていたし自分はPowerDNS周り変えていたので何がおかしいんだ?となる
    • 結局PowerDNSを別ホストにするのを戻して、成功することを確認
  • 18時間際 アプリケーションログを出すのをやめた、maxOpenConnsを25から適当に50に増やす。17996点
    • nginxのアクセスログを無効化したもののギリギリ間に合わずに入らない