ISUCON12に1人チームで出て予選敗退した話 #isucon

去年のやつ

sue445.hatenablog.com

今年参加するためにやったこと

自分の得意分野は手の速さよりもツール作成による自動化なので、去年の予選敗退直後から今年のISUCONに向けて準備していました。

途中2ヶ月間くらいはAWS Certified Solutions Architect - Professional(AWS SAP-C01)の試験勉強 *1 をしてたので完全に手が止まってましたが、それ以外の期間はISUCON用のツールを作ったり過去問で素振りをしていたので、準備期間は9～10ヶ月くらいだと思います

作ったもの一覧

rubocop-isucon

github.com

ISUCONのRubyの参照実装に対して静的解析をかけるためのrubocopプラグインです。

去年の予選敗退直後に作り始めたのでこれが開発期間が一番長いです。

ISUCONの過去問のRubyの参照実装を全部読んで、汎用化できそうな改善ポイントをrubocopのcopで実装しています。

手元にISUCONのRubyの参照実装だけを集めたリポジトリを置いて何回も静的解析をかけていました。

rubocopの中でSQLのASTをparseしてN+1クエリを自動修正してる辺りはかなりの面白ポイントなので、来年のRubyKaigiのCFPに応募しようと思っています。（このgemだけで1時間話せるくらいのボリュームはある）

オチ

後でブログも書くけど、1年かけて作ったのにsqlite3のせいでほぼ見せ場のなかったgemがこちらになります。（さっきOSS化した） #ISUCONhttps://t.co/cE2y0zp1xc https://t.co/FW2LuSzazs

— sue445 (@sue445) 2022年7月23日

mysql2-nested_hash_bind

sue445.hatenablog.com

作ったものの今回は特に出番がなかった...

datadog_thread_tracer

sue445.hatenablog.com

雑に並列処理をするのに重宝。

ISUCON終了直前にDatadogを外しやすくするためにこういうラッパを作っていました。

https://github.com/sue445/isucon12-qualify/blob/main/ruby/config/thread_helper.rb

itamae-plugin-recipe-rust

sue445.hatenablog.com

Ruby 3.2のYJITを使うためにRustが必要なので作った。

itamae-plugin-recipe-datadog

github.com

競技環境でDatadogをインストールするためのプラグイン。

これだけは唯一僕が0から作ったやつではないのですが、ISUCONの素振りしてて困ったポイントをパッチ投げたら気づいたらメンテナになっていました。

僕がitamae-plugin-recipe-datadogのメンテナになった経緯は下記を参照。

sue445.hatenablog.com

isucon-snippets

github.com

これ自体は去年のISUCONから使ってたのですがprivateリポジトリじゃなくてもよさそうな気がしたのでpublicリポジトリにしました。

1年間の差分はこんな感じ。 https://github.com/sue445/isucon-snippets/compare/isucon11-qualify...isucon12-qualify

チェックリスト

esa-pages.io

• 前日まで、当日（直前）、当日（競技中）でそれぞれチェックリストを作成
• チェック項目が93個あるんだけど自動化したことによりいくつか項目が消えたのでこれでもまだ減った方
• 競技中のチェック項目は競技中に手が止まった時に振り返るために用意してる

Datadog

今までのISUCONはNewRelicを使ってたのですが、業務ではDatadogを使ってるのでISUCONでも使い慣れたツールを使うことにしました。

実際に使ってる設定は https://github.com/sue445/isucon12-itamae/tree/main/cookbooks/datadog/templates/etc/datadog-agent/conf.d ですが、有償プランじゃないと使えない機能を使ってるので注意してください。

今月分はまだ課金が発生してないので分からないけど、先月分のDatadogの費用は462.30ドルだったので個人で使うにはそこそこ勇気がいる金額だと思います。 （素振りしてない時はサーバを完全に止めてDatadogの課金がなるべく発生しないようにしてたけどこの金額になった）

Datadogでalpを実装した。

ISUCONでは https://github.com/tkuchiki/alp を使ってnginxのアクセスログをいい感じに集計するのが定番ですが、1人チームだとログを集計する手間も惜しいのでnginxのログを自動でDatadogに送信して、alpと同等のテーブルをDatadogのダッシュボードで表示するようにしました。

仕組みはいたって簡単で、nginxのアクセスログをfluentdで加工してdogstatsdでDatadogにカスタムメトリクスとして送信しています

• td-agentの設定: https://github.com/sue445/isucon12-itamae/tree/main/cookbooks/fluentd/files/etc/td-agent/conf.d
• td-agentで想定しているnginxのlog_format: https://github.com/sue445/isucon12-itamae/blob/main/cookbooks/nginx/files/etc/nginx/conf.d/log_format_ltsv.conf

デメリット

• アクセスログの正規化部分で正規表現をゴリゴリ使ってる *2 関係でベンチマーカーからのアクセスでログが大量に出力されるとtd-agentのCPU使用率が高まる。（だいたい20～30%くらい）
• カスタムメトリクスはFreeプランで使えず、カスタムメトリクス自体もそこそこ費用がかかる *3

Datadogダッシュボード

競技中に複数のダッシュボードを使い分ける余裕は無いと判断して1つのダッシュボードに集約させました。

はてなブログの仕様で巨大スクショのオリジナル画像が見れないので縮小前のスクショのURLも置いておきます。 -> オリジナル画像

詳細なメトリクスは別ページで見れるようにしてるけど基本的にはこのダッシュボードを起点にパフォーマンスチューニングできるようにしてます。

作ったダッシュボードはJSONにexportしてgistに上げてますが、そのままexportしただけなので細かいところを調整しないとダメかもしれないです。（あと、後述の https://github.com/sue445/isucon12-itamae を適用してること前提）

https://gist.github.com/sue445/05e139f07a6de340e8acac7e337c01ec

ISUCON数日前にDatadogのダッシュボードがバグって困った

DatadogのダッシュボードにService SummaryとしてDatadog APMのメトリクスを埋め込んでいるのですが、ISUCON数日前に急にエラーを出すようになってむっちゃ困りました。

下記のようなスクショを添えてサポートに報告したのですが現時点でまだ治っていません。（つらい）

ISUCON12の予選問題

isucon.net

isucon.net

自分が予選当日に書いたコード

プロビジョニング用のItamae

github.com

事前に作っておいてsshできるようになった瞬間に全台にapplyしてました。

競技用コード

github.com

• 使用言語：Ruby
• 最終スコア：2650

スコア用issue

github.com

PRで動作確認をしてマージする直前のスコアをこのissueに貼り付けてるので、実質mainブランチのスコアです

PRベースで振り返り

• 各PRの冒頭に修正前のスコアを記載してるけどスコアがどれくらい増えたか見やすくて便利
• 毎回スコアをコピペするのは面倒なんだけどデプロイしてる最中にやってるので時間のロスはなかった

初期セットアップ (3035 -> 1297)

github.com

• 手元からデプロイできるところまでなので結構コミットは多め
• 参照実装をGoからRubyに切り替えたことでスコアが下がった
• この時点でDockerを剥がそうと思ったけど手こずったので別PRにした

rubocopでauto correct (1297 -> 1757)

github.com

• rubocop-isuconとrubocop-performanceだけ有効化した状態でauto correct
• rubocop-isuconの機能として、ローカルのMySQLにISUCONのスキーマを入れておけば SELECT * FROM tenant を SELECTid,name,display_name,created_at,updated_atFROM tenant みたいな感じで自動変換してくれます
  • 使ってないカラムをSELECTするのは遅いので後から不要なカラムを削りやすくしてる
• どのcopでどんな変更が行われてるかはCommitsを見てください
  • ちなみにこのコミットは https://github.com/sue445/rubocop_auto_corrector で生成しています

Docker剥がし (1757 -> 1536)

github.com

Ruby 3.1.2から3.2.0-devにしたけどスコアそんなに変わらなかった...

DatadogとSentryの有効化 (1536 -> 1842)

github.com

• ここでスコアが増えたの本当に謎すぎる。（だいたいスコア下がるはず）

sort -> sort_by (1842 -> 1667)

github.com

• Datadog見て最初に気になったのが GET /api/player/competition/:competition_id/ranking だったので見たところ、sortをsort_byにすることで最適化されるので手始めに実施

sqliteのテーブルにindexを貼った (1667 -> 1652)

github.com

• sqliteでexplainとる方法がぱっとわからなかったので脳内explainを頼りにindexを貼った

サーバ追加 (1652 -> 2685)

sqliteがある関係でpumaを複数台にできなかったので

• host01: nginx, MySQL
• host02: puma
• host03: auth

の構成になった。MySQLとpumaが分離できたのでMySQLのinnodb_buffer_pool_sizeの設定もこの時点で行った

静的ファイルにexpiresを付与 (2685 -> 2542)

github.com

不要なカラムをSELECTしてたので削った (2542 -> 2432)

github.com

id以外使ってないことに気づいたので削った

複数のsqliteへの接続を並列化 (2432 -> 3291)

github.com

他にも並列化できそうな箇所ないか調べたんだけどなかった気がする

visit_historyにindexを追加 (3291 -> 1727)

github.com

• クエリを見てたらrowsが偉いことになってたのでindexを追加
• explain結果は改善してるんだけどスコアは下がって本当に謎

JSONエンコーダをojに差し替えた (1727 -> 2067)

github.com

こんなこともあろうかとスニペットに常備してた下記のモンキーパッチを有効化した

• https://github.com/sue445/isucon12-qualify/blob/main/ruby/config/oj_encoder.rb
• https://github.com/sue445/isucon12-qualify/blob/main/ruby/config/oj_to_json_patch.rb

app.rb内のhelperを別ファイルに移動

github.com

この時点でsidekiqでの非同期処理を検討してたんだけど、sinatraとsidekiqで同じメソッドを使えるようにsinatraのhelperメソッドをIsuconHelperに移動した

sidekiq導入

github.com

sidekiqの導入と作成したworkerへの処理の移譲を同一PRでやると切り戻しが大変なので第1段階でsidekiqのデプロイだけ実装した

ランキングデータをsidekiqで作るようにしてredisに保存するようにした (2589 -> 1295)

github.com

• エンドポイント単体だと処理時間が減ってたんだけど結果的にスコアが下がって謎
• 1時間位かけて頑張って実装したんだけど、しばらくしたらこのPRが原因でbenchmarkerの初期化処理がコケるようになったので戻すことになって本当に悲しい

csvのBULK INSERT化 (1535 -> 2778)

github.com

• MySQLへのINSERTのN+1クエリならrubocop-isuconで検出できるんだけど、sqliteへのINSERTだったので検出できずに気づくのが遅れた

dispense_idのUUID化 (2778 -> 4939)

github.com

• むっちゃクエリが発行されてるところをDatadogで見つけたのでUUIDにした

player_scoreをsidekiqで生成してredisにのせる (4939 -> 2135)

github.com

jobが多すぎてqueue詰まりを確認したのでworkerを増やしたんだけど、そうすると今度はsidekiqからToo many open filesが出るようになって厳しい

github.com

SentryとDatadogを無効化しMySQLとnginxのログを止める (2135 -> 2650)

github.com

• ラスト10分で行った作業
• ほとんど増えなくて謎

敗因

• sqlite
  • DatadogのAPMがsqliteの処理をトレースしてくれないのでボトルネックが分かりづらかった
    • activerecord経由でsqliteにアクセスしてたらトレースできてた気がする
  • sqliteのdbのせいでアプリ本体を複数台構成にできなかった
    • sqliteを使ってないエンドポイントがあればそこだけ分離する選択肢はあったが、軽く見た感じ全エンドポイントがなんらかの形でsqliteに依存しててえぐかった
    • sidekiqのworkerもsqliteに依存してるのでサーバを分けることができなかった
  • とはいえ来年以降のためにsqlite対策するかと言われるとなあ...
• ヤマが外れた
  • 今までの経験上予選は割とオーソドックスな構成なのでそこまで変な構成はこないと思いこんでた

良かったこと

• 去年まではPRを作らずmainブランチに直commitする方針だったが、今年になってからデプロイスクリプトを改修してPRのブランチをデプロイできるようにした
  • 途中で方針転換する時の切り戻しが楽
• Datadog
  • 普段から使ってるので完全に手になじんでた
  • NewRelicのAPMはmysql2に対応していなくてモンキーパッチを当てないとトレースできないのだが、DatadogのAPMはmysql2に対応してるのでその手のモンキーパッチが不要でよかった
• 頑張ってDockerを剥がしてRuby 3.2.0-dev + YJITを実戦投入できた
• Itamae
  • 今回Docker環境だったので競技環境にxbuildが入っていなかったのだが、自分のItamaeレシピでxbuildをインストールしてたので特に困らなかった
  • 1コマンドでいつもの環境が構築できるのが本当に便利
• rubocop-isucon
  • mysql2系のcopはあまり見せ場がなかったがsinatra系のcop（ログの無効化）は秒で対応できて良かった
  • rubocop-isuconの開発を通してSQLのASTが読めるようになった
• 色々OSS作ったので来年以降も使える
• 去年は再起動試験に失敗して0スコアフィニッシュだったけど、今年は正数スコアでフィニッシュできてよかった
• Copilotを使ったけど自分の脳内を先読みしてスニペットが作成されて便利だった

おまけ：isucon11-finalにパッチを投げた

素振りで去年のISUCON本選問題をやってたらバグを見つけたのでPRを投げておきました

github.com

*1:https://sue445.hatenablog.com/entry/2022/06/06/085340

*2: https://github.com/sue445/isucon12-itamae/blob/main/cookbooks/fluentd/files/etc/td-agent/conf.d/nginx.conf#L46 みたいのが数か所

*3:https://docs.datadoghq.com/ja/account_management/billing/custom_metrics/?tab=countrategauge