あらまし

2021/08/21に開催されたISUCON11の予選に参加してきました。

今回で3回目の参加になりましたISUCON11だったのですが、思う様な結果が残せず惨敗したので、恥をしのんで今後に活かすためにも当日の動きや対応や考えたことや失敗を残していきたいと思います。

結果

チーム名: L&R
最終スコア: 19944 (220位/600チーム中)

ベンチを実行してた時の観測したかぎりの最高スコアは21000点くらいでした。

役割分担

今回も例年のごとく会社の同期(今は元同期)のleedotdevと二人で参加してきました。

主な担当分けとしてはleedotdevがNginxを含むインフラの担当。僕がアプリケーション、DBを主に担当し、少しNginxチューニングするという感じで行っていました。

例年ですが、もともと二人の得意分野がうまいこと被らなかったので作業のカニバリとかはなくスムーズに作業を行うことができていました。

ざっくりとしたタイムライン

前日まで

• privateの作業リポジトリの作成
• 通話にmeetを使うとPCのリソースを大量に食ってしまうことが辛かったので、discordサーバの作成と招待
• 二人で使ってるslackにisucon11用のチャンネルの作成。当日行うことの確認

当日朝9時

• 集合
• 通話ツールの挙動確認

• 事前に準備していた開始後に行うことを二人で確認し、作戦を立てる

  • 僕たちのチームでは過去３年分での経験から当日の朝にすぐ動ける様に各種準備内容や対応方法、秘伝のタレ系のものを全てgithub上で管理し、やることに困らないようにしています。

• レギュレーションの確認
• モンスターエナジーで乾杯🍻

9:40~

• 開会式をyoutubeで見る。

  • 「えんじぃにぃありんぐ」が頭からはなれない
  • サービスの説明動画のクオリティに感動
  • 締め切りが先に決まってるリリースを目前にした何かはすごく気持ちがわかって見てて辛くなった

10:00

• 競技開始

• 役割分担をして準備実施

  • CFnでサーバの構築
  • ソースコードのGit管理
  • nginx,mysqlのシンボリックリンク並びにgit管理
  • 計測系ツールのインストール
  • alp,pt-query-digest
  • netdata,glances
  • mysqlのslow　queryの設定
  • nginxにalp用のいつもの秘伝のタレを一瞬で挿入
  • デプロイスクリプトの調整
  • 言語をRubyに設定
  • ギリギリまでNodeでやるかRubyでやるかを悩んでしまったのがちょっと失敗した。どうせ僕しか触らないのだからとっとと決めてRubyにしておくべきだった

• 一旦ここで初期のベンチ実行

  • 2800点くらい
  • alpの結果とslowqueryの結果をまとめてgitのissueに追加
• じっくり今回のアプリケーションの仕様を読み込んで二人で確認する。

10:30

• glancesを見るとCPUが常に100%に張り付いていてアプリケーション側の負荷が大きすぎたので、まずはアプリケーションのエンドポイントで負荷が高いことがわかる/api/conditionのリクエストのみを別のインスタンスに切り離した。 サーバーの使われ方はこの段階では以下の通りの構成

  • 切り離した段階でのベンチの結果は7878

• server1  main, app, mysql
  server2 /api/condition
  server3 放置

• 一旦slowqueryを見てわかりやすく改善できるところからということでindex戦略に走り、アプリケーションないの全てのクエリを抜き取って、問題のあるクエリに適応するようにindexを貼った。

  • CREATE INDEX idx_jia_isu_uuid ON isu_condition(jia_isu_uuid);
  • ベンチ実行結果を忘れたけど多少の増加が見られた。

11:40

• alpの結果で/api/trendと/api/conditionと/api/isuに問題があったので、まずは可能なところからということで/api/trendの改善を実施

  • 内容を確認していくとSELECT文をループのなかで実行しているので、一行で取得するようにアプローチ。
  • また、性格の一覧を取得するSQLが最初に実行されていたが、内容が変わるものではないのでハードコーディングに切り替えた。
  • 上記対応で多少は効果が得られると思ったが、スコアの改善はそこまで見られなかった。
  • ここ完全に対応ミスで、ちゃんとソースコードを読めばわかるんですが、そもそも全部のクエリを取得する必要がなく、最新のクエリだけ引っ張ってくる実装に切り替えるのが正しいアプローチだったことに後から気づきました。

13:30

• アプリケーションの中で重たい処理が大体洗い出せたので、処理の重たい物は別のインスタンスに切り分ける戦略をとることにした。
• 余っていたサーバー3をメインのサーバとし、サーバー1をDBサーバー、/api/conditionだけをサーバー2に変更
• ベンチの実行結果は11000点くらいに

14:40

• サーバ-1に/api/isu/＊/iconと/api/isu/*/graphの二つを向けるように変更

  • ベンチが14000点台に

15:00

• alpを見てるとassets系の静的ファイルが上位の方に出てくることが確認できるので単純にキャッシュするかーと思い、nginx側でキャッシュさせようと思ったが、うまく行かなかったのでアプリケーション側からキャッシュした。
• set :static_cache_control, [:public, max_age: 60 * 60 * 24 * 365]
• 　これも結構効いて17000点台になった

17:00

• /api/condition/:jia_isu_uuidがボトルネックになっているのは明白なので、この処理を改善する
• この処理はリクエストタイム的に重たいわけではなかったがcpuリソースへの影響は高かったので、一つ一つ確認して行ったところループ内でinsertしてるのが結局悪そうだったので、bulk　insertに切り替えた。
• ベンチを実行したらこのタイミングでようやく20000点になった。

17:30

• drop_probabilityの値を下げるためにあれこれしてみる
• ここの処理で10%のリクエストしか受け取れない様になっていたので修正方法を考慮していたがおもいつかず断念

18:00

• /api/condition/:jia_isu_uuidのSELECT文にアプリケーション側で指定しているデフォルトの取得件数分のLIMITをつける対応を行おうと試みる。

  • ただ、公式でも説明しているように単純に改善することができず、修正途中でチームないで撤収作業に入る予定の15分前になったので、リバートして断念。

18:25

• 撤収作業開始

  • 各種解析ツールのアンインストール
  • いらないprocessの削除
  • sshから全員が抜ける

• 最後にベンチの実行

  • スコアは21000点くらい
• チームメイトと雑談しつつ時間を過ごす。

18:40

• 競技終了

やれなかったこと

timestampにindexを貼るのを試さなかった

これは本当に反省している点でslow queryの結果を見て、以下の系統のクエリに問題があることを認識していたのですが、なぜかtimestampにindex貼っても効かないよなーとか謎の感想を抱きindexを貼ることを試さないでしまいました。これがのちの感想戦で初手一番効いたというのが話されていてものすごくショックを受けました。 timestampって効くんですね。しかも結構大幅な点数増加が見込めるものだったので、試してみるべきだった…。

SELECT * FROM `isu_condition` WHERE `jia_isu_uuid` = ? AND `timestamp` < ? AND ? <= `timestamp` ORDER BY `timestamp` DESC',

/api/isu/:jiaisuuuid/graphの改善

この処理がポイントの増加に大きく影響することがわかっていたのですが、対応方針が思い付かず対応することができませんでした。正しい対応方針はSELECT文でtimestampで取得する範囲を指定するのが正しい対応方法だったようですが、全然思い付かずかなり後で反省しました。

キャッシュ戦略

今回はRedisを利用することを予定していたが結局実行に移せていなかったです。導入ポイントが思いつかなかったのが最大の理由だけど、もしかしたらキャッシュさせることを前提にコードを読めば対応が変わっていた可能性もあるので、多角的視野でアプローチを考慮することが大切でしたね。

最後の最後までCPUリソースを下げ切ることができなかった

アプリケーション側に常に問題が残り続けCPUリソースを下げ切ることができなかったので、アプリケーション担当としてはかなり残念ポイントでした。かなり悔しい気持ちでいっぱいでしたね。

反省ポイント

ここからはできなかったこととは別にISUCON11全体での反省ポイントを挙げていきます。

大会前の過ごし方

今回の大会は今までで一番準備ができていませんでした。チームメイトが母国に帰る＆転職の準備を行っていたり、私自身も引越し作業をする必要があり、土日の時間に集まって練習するということができず、結局一週間前にちょっとだけ集まって準備ドキュメントの内容だけ確認するみたいな絶対的に練習時間が足りない状態で当日を迎えてしまったのがやはり影響し、最初のぐだり方は過去1でしたね。 やはり事前に過去問を解くことは重要です。次回は余念なく当日を迎えられる様に練習時間の確保をしたいですね。

ツール系

なぜかいつもアプリの解析ツールの導入を忘れているんですが、やはり効率的にアプリケーションの弱点を見つけるためにもrubyであればstackprof等の導入は早めに検討すべきでした。

また、キャッシュ戦略に移るのがいつも遅くてやろうと思った時には時間ないなーってなってしまうので、システム解析ツールでメモリに余裕があればRedisやインメモリにキャッシュさせる方法でキャッシュさせることを検討すべきでしたね。

/api/trendの改善

ソースコードを読まずにすぐにN+1問題だ！と飛び付いたのが大きな失敗でした。ここのソースコードは冷静に読むと最新の一件だけ返せばいいコードだったのに、冷静さを失ってしまって内容を確認しないままに実装を開始してしまって無駄な時間を使ってしまいました。改善の一番最初はソースコードの意味を理解するにあるなというさも当たり前なことを述べる失敗です。

アプリケーションを全然触らない

結構よくあることなのですが、開始して直後にアプリケーションの仕様とレギュレーションは確認するものの実際に動くアプリケーションを触ってアプリケーションを理解するという作業をどうしても蔑ろにしてしまうことが多く、かなりその部分で後から苦しむ経験をしています。 やはり最初にはアプリケーションを触ってその特性を理解するのが重要だと再認識しました。

アプリケーション側の改修担当としての力量不足

最後までアプリケーション側のCPU負荷を下げ切ることができず、ミドルウェア側の解決がメインでどうにかスコアを伸ばしましたが、やはり根本解決にはつながらず、対応仕切ることができなかったことに痛く実力不足を感じました。 ここは多角的視野を養いつつより多くのアプローチでの解決方法を自分のものにしていくため研鑽を積む必要があると感じました。

さいごに

ISUCON運営の皆様本当に準備いただきありがとうございました。

今年も本当に多くの学びがあり、楽しく参加させていただくことができました。

また、いつも一緒に参加してくれてるチームメイトのleedotdevにも感謝しています。 初めて参加した社内でのISUCONイベント以来ずっと共に参加してくれる彼との時間を大切にしています。

来年も一緒に出られるといいな。

そして、ISUCONはやっぱり楽しい！！！

Tags

• isucon
• tech