ISUCON 11 の予選にいつものチーム「ワイハリマ」で参加していた。利用していたリポジトリは https://github.com/yuta1024/isucon11 で、予選終了後に public になっている。最終スコアは 26656、走らせたベンチマークの中で最良のものは 29189。記事執筆時点では最終結果は発表されていないが、再起動後に機能を維持すること自体は確認している。(追記:ベンチマーク周りの事情で追試の際に再計測が行われ、最終スコアは 27163 だった。)
COVID-19 による緊急事態宣言の最中であり、いくらワクチン接種済みとはいってもさすがにチームメンバーも物理的には集合せず、各自自宅からオンラインで参加。
時間としては 10:00-18:00 の8時間の予定で、定刻通り10時開始、17:20頃にポータルに問題があってベンチマークが行えなくなり18:10頃に復旧、競技は18:45まで延長となった。
いつものように言語を PHP に切り替え、ベンチマークを流して kataribe で様子を見たり実装を見たりしながら改善方針を検討した。デフォルトの Go の初期実装で走らせると 1656 だったのに対し PHP に切り替えた直後は 980、初期実装の段階では Go に負けている。PHP は(ISUCON ではいつものことのようだが) Slim が採用されており、しかし ./app/routes.php にほぼ全てが書かれている形のようだ。そして、とにかく isucondition テーブルへの書き込みに該当するリクエストの件数が多いようだ(ただし初期実装では9割のリクエストが PHP 側で無視されている。書き込んだ変更が反映されて初めて点数ではあるものの書き込みが無視されること自体のペナルティはなし)。
isucondition のテーブルで3つの値の true, false をわざわざ CSV 形式のテキストで保存しているのを発見し、 TINYINT 3 つのカラムに切り替える改修を行った。ただ、これは明確に効いたという感じではないようだ。今にして思えば結局このカラムは3カラムまとめて取得してくるものでデータベース側でどうこうするものではないので、実運用上するならともかく、速度だけ気にするなら特に影響が大きいというものではなかったのだと思う。
assets の静的ファイルがなぜか PHP の file_get_contents で実装されているという問題があり、これはメンバーが nginx で返すように修正していた。
ここまで一台のサーバーで三人が作業していたが、3 VM 同じものが動いているので、ここで3人がそれぞれ1台の VM を使うようになった。
とにかく POST /api/condition/<uuid> へのアクセスが非常に多く、無視している9割も一度 PHP で処理しているのはシンプルに問題がある。また、少なくとも ISUCON での経験上は Slim のオーバーヘッドは無視できないほど重くなることもある印象だった。ISUCON の PHP 実装は Slim で書かれており、かつほぼすべてを ./app/routes.php に書いていて Slim のメリットを生かせていないことが多く、もともと PHP が初期実装として有利でない現状では初期実装としてもフレームワークなしのべた書きにした方がバランスがとれるのではとは思うものの、Slim のメリットを活かしたコードになっていないなら逆に改修箇所も小さいので、要所を絞って一つ、二つ脱却するだけなら現実的にコンテストの時間内で行える。そのため、残りの1割でも充分リクエスト数が多いこの API は Slim を脱却したいという話になった。90% の割合は PHP 側で何もしないで処理しているはずにも関わらず、1割を超えるリクエストが nginx のログで status 499、つまり実際にはレスポンスすら返却せずタイムアウトしているのも気にはなっていた。
メンバーが nginx 側のロードバランシング機能を用いて一定の割合を nginx 側で所定の形式で返却、残りのみを PHP に回す処理を書いていて(これも冒頭にリンクを張ったリポジトリに上がっている)、これはかなり効いたようだ。さらに初期実装で 90% を無視していた割合を見直して調査した結果、そもそもこの時点では 90% でも捌き切れておらず、さらに高い値にしてある程度捌けるようにした方がスコアが伸びることが判明した。GitHub のこの時のプルリクエストでは 98% を無視する(2% しか php-fpm に流さない)ことになっていたが、この値は定期的に見直しているのでどの時点での値かは正確には思い出せない。
僕は POST /api/condition/<uuid> を Slim から脱却し単一 PHP ファイルで動作するようにする修正を行っていた。これはさらに別 VM へのオフロードもこの時点で目論んでいた。なお、この API はざっと見た限りでは WebUI からは行われずベンチマークからしか修正の正しさを確認できないのがやや面倒ではあったが、ベンチマーク自体はシステムがスムーズに動作していたので大きな問題でもなかった。
また同時に PHP の xdebug モジュールの無効化やデータベースのスロークエリを確認した上でのインデックス追加を行っているメンバーもいた。
この時点で15時過ぎ、10058 のスコアを記録した。
ここから先は3台の VM の役割を検討し始めた。まず、 php-fpm も mysql も nginx も全て CPU をまあまあ使っていたので、 MySQL は別 VM への移行を決定。更に POST /api/condition/<uuid> も別 VM に渡すことになった。ここで3台の VM の役割がわかれるが、リポジトリに置いていたファイルはあくまで全台に撒いても問題ないように書いていた。少なくとも今回は全台共通で撒けるようにする工夫に大きな手間はかかっていなかったと思うし、余計なことを考えないで良い効果の方が大きかったと思う。
多分この頃、時刻で言えば17時頃に、再起動試験も行った。とはいってもデータの置き場所は結局変更していないので、データ保持の確認は行わず機能維持のみを確認した。ミドルウェア周りはいうほどいじっていないしオンメモリ化もしていないので、特に問題なし。心配する要素がないのでデーモンが上がってくることのみのチェック。ただし無効化したつもりの余計なデーモンが起動してくるということはあった。
この後は、いくつかの重い処理をどの VM にやらせるかを移動したり POST /api/condition/<uuid> の無視割合を変更したりしてはベンチマークを走らせるといったことを3人でしていた。またこのころ、 nginx の client_body_buffer_size の調整や、 InnoDB 周りを主とした MySQL 周りのチューニング、 nginx の各種パラメータの修正をしていたメンバーもいたようだ。
なお、認証が必要な API は単に別のサーバーに逃がすだけだと 401 Unauthorized を返して正常に動作しなかった。調べた結果、 Slim 標準のセッション管理機構がサーバーローカルで閉じていて複数サーバーにまたがるとセッション管理が機能しないことが原因のようだった。ルールにはこういうサーバ側で生成する文字列は文字種を変えなければ自由にして良いと書いてあったと記憶していたこと、 Cookie に関するルールは記憶の限りではなかったこと、そもそも言語標準のセッション管理機構を用いるのであれば初期実装が複数言語あるアプリケーションで共通の何かを守らなければ外部連携に関するトラブルが発生するとは考えづらいこともあり、 Cookie に直接ユーザー名を保存して認証はユーザーの申告を全面的に信用するという方針に実装を変更した。これにより任意の API について php-fpm の負荷はどのサーバーにでも逃がすことができるようになった。
この調整を行い、分散具合や負荷のかかり具合としては良い感じになったと感じた。
この後も無視割合を変更する調整を行った。最終的に、有効1:無視5、つまり無視割合 83% 相当にすることを決定、ログなどの性能分析には有益だが直接的には不利にはなっても有利にはなりえないオプションを無効化し、その状態でベンチマークを二回ほど走らせたら一応は他の設定よりは良さそうな値にはなり、残時間もあまりなかったのでここで作業終了。
後から改めてコードを見てみると、 kataribe 報告で合計時間が多いとされていた API のいくつかには、 isu それぞれについて isu_condition テーブルから最新の情報を取得するクエリが実行されており、これが HTTP リクエスト 1 回に対して多数回呼び出されるものがあった。isu それぞれについての最新情報は isu_condition の時に併せて更新すれば isu テーブルに持たせられることから改善の余地があったと考えられ、今回は実装の修正をおろそかにしていたことが悔やまれる。
コンテストとしては、まず問題としてはプログラム自体の改善と3台の VM の活用それぞれがバランス良く織り込まれていたし、改善やその調査は ISUCON 専用の何かというものが多いわけでもなく実用的な技術の延長上にあるものが多かったので、質が高かったと感じる。また、今回は終了直前にポータルが50分ほど落ちた以外には運営側起因のトラブルは(少なくともワイハリマに影響するものは)発生しなかったし、ベンチマークボタンを押したらキュー待ちもほとんどなくほぼ即時にベンチマークが実行された。ベンチマークの結果自体も同じプログラムで実施すれば複数回実施しても大幅な変動が出ないものであった。全体を通して、8時間の競技の枠内で最大限に高速化技術を発揮できるかに集中できるものになっていたと思う。
(追記)メンバーの write up:ISUCON11 Qual writeup – yuta1024’s diary