NaruseJunチームでISUCON11予選に出ました。

• チームメンバー¹
  • @to_hutohu
  • @takashi_trap
  • @sekai67
• 結果
  • スコア: 919720
  • 本戦に行ける！🎉🎉
    • ココ最近のNaruseJunチームは追試失敗率が高く²て、2年間本戦に行けていませんでした。悲願達成感があります。

やったこと

• NaruseJunチームは基本的に個々人が勝手に改善を突っ込んていくスタイル
  • 担当範囲などはあえて決めておらず、全員アプリを触るしインフラもいじる
  • ミドルウェアの設定、アプリコード、デプロイスクリプトが全部入ったリポジトリを使った
    • それぞれローカルで作業、ブランチを切ってリモートにプッシュ、サーバ上でプルしてデプロイ、といった動き
      • ローカルではテストしない（環境まわりでハマるのは時間の無駄なので）
      • 3人で別々に動いているので、声掛けでサーバの占有権を取ってベンチを投げ、それで動作確認する感じ
• 初動だけは担当作業を決めていた
  • to_hutohu: マニュアル読み込み
  • takashi_trap: リポジトリ、デプロイスクリプト周りの準備
  • sekai67: 環境立ち上げ、計測ツール類準備
    • 細かいツールの導入などはすべてansibleで行う
      • 最初の変更をリポジトリに入れてデプロイするまで 17分
        • 最初の動きをよく詰めておいたので、スムーズに改善へ移れた
• 計測結果を元に改善ポイントを見つけた
  • 「推測するな、計測せよ」
  • pprof, fgprof, alp, pt-query-digest, netdata を見ていた
    • pprofは基本的にFlame Graphだけ見れば大体わかる
  • pproteinというツールを作って、使った
    • pprof, alp, pt-query-digestのデータをサーバから収集し、Webブラウザ上で表示できるようにしたもの
      • 過去の計測結果を見れたり、チーム内で計測結果を見ながら相談できたりするので便利
    • こういうツールを作るのが最近流行ってそう
      • https://twitter.com/_tsuzu_/status/1429064558203731973
      • https://diary.hatenablog.jp/entry/2021/08/22/175403
    • pproteinはいまのところオープンソースなので、ご活用ください
      • ただしREADMEは書いてない
• 以下2点の理由から、15時過ぎから新たな改善を入れるのをほぼストップし、追試対策など安全に通過するための戦略に切り替えた（前年の反省）
  • 80万点に到達した15時時点で、次点は10万点代、大多数が10万点未達という状況であったこと
  • 特定の状況下（http2のGOAWAYハンドリングミス³）でベンチマーカーがエラーになり、場合によってはスコアなしになる可能性が残っていたこと
    • 競技中、これがこちら側のミスであるか、運営側のミスであるかを判断できなかった⁴ため、念の為修正を行う判断に至ったが、結果としては不要だった

こぼれ話

• 14:30〜15:10まで、コミットするたびに点数が指数関数的に増加した
  • あまりにも上がるし、自分たちの想像以上に上がるので、けっこう驚いていた
    • 運営さんもかなり驚いたたようで、「ベンチマーカーの実装がバグっている可能性がある」として個別で改善方法を確認されました
      • 結果としてバグではなかったのでハッピーエンド
    • 点数が上がるたびにバグの疑念が強まり、ベンチマーカー実装担当の顔がどんどん曇っていったらしい

具体的な改善内容

• だいたい時系列順
• 初期スコア: 2000くらい
  • 改善後スコアは必ずしも当該の改善のみが寄与しているわけではないので注意

isu_condition テーブルにインデックスを貼る

• 時間: 10:40
• スコア: 19000くらい
• コミット
  • https://github.com/narusejun/isucon11-qualify/commit/4132537145c01a54b86207c9e130d3d94b8dc895
• 根拠
  • pt-query-digest結果から。この時点での合計クエリ時間上位2つがこれだった

  select * from `isu_condition` where `jia_isu_uuid` = ? order by `timestamp` desc limit ?
  select * from `isu_condition` where `jia_isu_uuid` = ? order by timestamp desc
  

/api/trend で返すデータを 0.5 秒ごとに作るようにする

• 時間: 11:10
• スコア: 26000くらい
• コミット
  • https://github.com/narusejun/isucon11-qualify/commit/1e24895db95c0ce776b8751bcf90a49e37ea17b0
• 根拠:
  • pprofのFlame Graphから。getTrendで発行してるSELECTに時間がかかっている⁵。

isu_condition テーブルを水平分割 + ログを出さない

• 時間: 12:20
• スコア: 42000くらい
• コミット
  • https://github.com/narusejun/isucon11-qualify/commit/fda74ca7e56b70a58a7a49c773cb892d3dae6765
    • UUIDを使って振り分け先のサーバを決定して、そのサーバから読み書きする。
    • トランザクションが邪魔なので、消す。よく読むと、トランザクションなしでも正常に処理できることが分かる。
• 根拠
  • alpから。POST ^/api/condition/.+$の合計時間が大きい。GETもそこそこ大きい。
  • pprofのFlame Graphから。getIsuConditions/postIsuConditionsが重い。

iconをDBにつっこむのをやめてファイルに書き出す

• 時間: 12:50
• スコア: 52000くらい
• コミット
  • https://github.com/narusejun/isucon11-qualify/commit/e3cc31346fb89455a0f0123e9ea08156914e28c4

微調整

• 時間: 13:30
• スコア: 64000くらい
• コミット
  • https://github.com/narusejun/isucon11-qualify/commit/68f2d06510e6ad147a623bce64dcc0d2b1ab56ca
    • あえてtrendを返すのを遅くして、ユーザー数の増加を抑える。
  • https://github.com/narusejun/isucon11-qualify/commit/72368dc1582670ccdce6fc2e727bb82da5292b30
    • DBを3台から2台に減らして、appへよりCPU時間を配分する。
• 根拠
  • netdata等から。appとDBが同居しているサーバでCPU使用率がほぼ100%なのに対して、DBのみが動くサーバではまだ余裕があったため。

backendを複数台に

• 時間: 14:00
• スコア: 72000くらい
• コミット
  • https://github.com/narusejun/isucon11-qualify/commit/99ec56508bb5fc501133f06cc913e20c98de1ec7
    • appを3台にして、postIsuConditionのみを複数台で処理させる。
• 根拠
  • netdata等から。appサーバからDBを剥がしてもまだCPU使用率が100%だったため。

getIsuConditionsFromDBの高速化

• 時間: 14:30
• スコア: 107000くらい
• コミット
  • https://github.com/narusejun/isucon11-qualify/commit/7981a778309e216b3734d817c3458c15f20d5564
    • Generated Column追加、SQLでLIMITする。
• 根拠
  • pt-query-digestから。以下のクエリが遅い＋Rows_sentが異常に大きい。

    select * from `isu_condition` where `jia_isu_uuid` = ? and `timestamp` < ? order by `timestamp` desc
    

  • pprofのFlame Graphから。getIsuConditionsFromDBの圧倒的存在感。。。

postIsuCondition バルクインサート + postIsuCondition全受理

• 時間: 14:40
• スコア: 158000くらい
• コミット
  • https://github.com/narusejun/isucon11-qualify/commit/d375e46e3d72547b8a3d67a97f26133981264680
  • https://github.com/narusejun/isucon11-qualify/commit/4e2da32e02b079fbe56ed2188dabd5639ef7f2c3

nginx調整

• 時間: 14:50
• スコア: 295000くらい
• コミット
  • https://github.com/narusejun/isucon11-qualify/commit/9e47a40a1f1af444a07fa93c1cc3a33372904b5a
    • getIsuGraphを3台処理に変更、nginx-backend間通信のkeepalive化。
• 根拠
  • netdata等から。1台目のappサーバがキツそうだったのと、その割にほか2つがヒマそうだったので。

getTrend調整

• 時間: 15:00
• スコア: 346000くらい
• コミット
  • https://github.com/narusejun/isucon11-qualify/commit/6cc6d718095b0e1d4ffbc3277e53d8ac4966bf52
    • 意図的にtrendを返すのを遅くしていたところを少しだけ早くしてユーザー数を増やす。

グラフ作成時の取得データ量を減らす

• 時間: 15:00
• スコア: 631000くらい
• コミット
  • https://github.com/narusejun/isucon11-qualify/commit/659cb46e1210c56aaabf6f40681bfe705453a686
    • WHERE句にtimestampの範囲で絞る条件を追加。
• 根拠
  • pt-query-digestから。以下のクエリが遅い＋Rows_sentが異常に大きい。

  select * from `isu_condition` where `jia_isu_uuid` = ? order by `timestamp`
  

nginx調整

• 時間: 15:10
• スコア: 836000〜932000くらい
• コミット
  • https://github.com/narusejun/isucon11-qualify/commit/3d9f96bfe12f263a0ea8f3aa759b8e73c2659f0a
    • nginxとappが同居してる場合はnginx-app間通信をunix domain socket経由に
  • https://github.com/narusejun/isucon11-qualify/commit/5f4f37918c900ae106da1b54da66d59399da3a41
    • nginx-app間のkeepaliveコネクション数調整

微調整

• 時間: 16:00〜17:00
• スコア: 1010000〜1173984(ベストスコア)
• パラメータをいろいろ調整してた
  • MySQL設定
  • nginx設定
  • getTrend待ち時間

最終

• 時間: 17:00〜
• スコア: 988417(最終スコア)
• http2のGOAWAY問題⁶でベンチマークがまれに失敗する問題の対応
  • 安全に追試をパスできるように少し性能を落とした

おわり

運営の皆さんありがとうございました。