ISUCON11にソロチームBPM200で参加して予選敗退しました。
結果
- 最終スコア: 13458
- 最高スコア: 14484
- 使用言語: Ruby
去年↓よりは1人でも戦えた気がしたものの順位上の結果としては大差なく終わってしまい残念。
使用したツール
ちょっとしたコード変更はサーバ内でVimで書いてベンチマーカー回して良ければコミットして、複雑なコードの変更はRubyMine側でじっくり書いてからコミットするスタイル。
DBの中身を見たりクエリをExplainするのに最初はmariadbのREPLで頑張ってたのですが途中からDataGripでリモート接続して確認することにしました。クエリの補完や情報の見やすさなど、全てが圧倒的に優れているのでめっちゃ良かったです。
NewRelicは普段業務でも使うのでその延長で使わせてもらいました。スポンサー感謝です。
戦略
昨年と同じくソロなので時間は絶対に足りない、という前提のもと予めフォーカスするポイントはある程度決めておきました。
- 1台構成でできるところまでやる
- 素振りしてない計測ツールやプロファイラは使わない
- アプリケーションのすべての仕様を理解しようとしない
振り返り
良かった点
良くなかった点
- 全体的にアプリケーションコード側での解決に拘った
- 12:30に9,000点まで伸ばせて前半の滑り出しは悪くなかったのですがそこからずっと伸び悩み
- 多少時間をかけてでもNginxのチューニングや複数台構成に挑戦すべきところだったかなと思います（できたかどうかは別）
終了後に学んだこと
追試終了後の日曜以降に残った環境でいろいろ試してました。
- APIとDBのサーバ分離
- MySQLの設定周りでハマると思ったら意外とかんたんだったので素振りしておけばよかった
- 繰り返し実行するコマンドをMakefile化
- サーバのrestartとかlogの削除とかそのへん。一人作業だからいいか…と言い訳して毎回typeしてたのですがMakefile書くぐらいはちゃんとやろう
- NginxとAPIの通信をUnix domain socket化
- 数字に効くのかはわからないのですが試しても良かった
- kataribeやdstatなど使わなかった計測ツールの使い方を調べた
- なにこれ、めっちゃ便利...ってなった
あと競技そのものとはあまり関係ないですがCloudFormationでの環境構築とても簡単で良かったですね。構成図を見たりしてました。
すでに$17ぐらいかかっていたので気をつけよう…。
自分の引き出しが「API >> DB >>>>>> Nginx > インフラ周り」と偏り過ぎているのでボトルネックがわかっても打ち手が適切でなかったり、そもそも思いつかなかったりと、総合格闘技的な"力"不足を改めて感じるISUCONでした。
所感
2年連続でソロチームで出た所感としては、やはり、ISUCONはスキルポートフォリオの不足を知るとても良い機会だということです。
チームで出るならほとんどの場合は各自の得意領域で勝負をすることになると思うのですが、ソロなのでなんでも自分でやらなければいけない。そのぶんトラブルシューティング・課題発見・司令塔・問題解決力・実装力などすべてを合わせた総合格闘技力がモロに試されることになります。普段チームで開発しているとなかなか得難い体験だなと思います。
複数人で参加して効率重視で優勝を狙うところとは離れており*1、運営の意図とは異なるのかもしれませんがこのような楽しみ方ができるのもISUCONの好きなところです。
運営の皆様、本当にお疲れさまでした && ありがとうございました。
[おまけ] やったこと
ここからは競技時間内にやったことの羅列です。
環境構築: 1529
一人なのでまずは最初の1時間で落ち着いて開始できるように持っていくところ。
- CloudFormationでの環境構築
- サーバへのssh確認
- 直前にマシンを交換してたので鍵がローカルになくてsshできずとても焦った
- 環境チェッカーの実行
- ローカルマシンのブラウザでアプリケーションが動いていることを確認
- 去年はここを怠ったのでアプリケーションの挙動をコードから特性や仕様を理解しようとして時間を浪費した
git initしてGitHubにpush- 初期設定のままベンチマーカーを実行する
Ruby実装に切り替える: 4732
なぜか点が伸びた
[11:00] NewRelic導入: 1532
スッ...と下がった
NewRelicでmost time consumingが GET /api/trendとわかりました。
N+1で明らかにマズいのだけどけっこう直すの重そうだな…と日和りましたが、ボトルネックから片付けないといけないことは学んできたので覚悟決めて倒すことに。
[12:30] GET /api/trendのN+1を倒す: 9035
かなり苦戦しつつもGET /api/trendのN+1を消し、クエリ1回で必要な全データを取れるようにしました。
途中クエリをミスってFailするようになってしまったバグの修正でけっこう時間がかかったものの、一気に点数が伸びて昼飯を食べる気が湧きました。
ベンチマーカー走行時に凡ミスでFailするとかなり心臓に悪いので、これ以降の修正は基本的にRubyのREPLでコードをある程度実行してからコミットすることにしました。
また、ボトルネックが POST /api/condition/:jia_isu_uuidになったのでこの辺を読んでいく。
[13:00] [Revert] drop_probabilityの調整: 8685
「いっぱいデータが貯まったほうがスコアが伸びるんだな？」程度の仕様理解をしていたのでこの値をいじって点数の増減を確かめてみました。
結果、下げるほど点数が下がることがわかったので0.9に戻す。
[13:30] POST /api/condition/:jia_isu_uuidのbulk insert化: 9149
コードを読んで遅そうなところはinsertがN回走るところだったのでbulk insert化したところ微増。
NewRelicでは依然としてこのエンドポイントが遅いままだったので「うーん、非同期化しないとダメか...？いや、構成変更の素振りが足りないから手を出すのは危険な気が…」と逡巡。
[14:30] indexをisu_condition (jia_isu_uuid, timestamp)に追加: 9909
NewRelicで見えるAPIレイヤのメトリクスでは手を出せる改善箇所が定まらなくなったため、MySQL slow query logを出力してクエリ傾向を見てみる。
isu_conditionテーブルのRows_examinedの数値が異常に高いクエリがいっぱいあった。初期のベンチマーカー走行時は高々1,000程度しかレコードがなかったもののこの時点で21,118件のレコードが入っていたのでインデックスを貼ることにした。
このあとしばらく迷走します。
[15:00] GET /api/trend のsortで減点されていたのを修正: 6858
deductionが20ほど出てて不穏だったので直した。N+1直したときのクエリにORDER BY のDESC付け忘れがあった。
なぜこれで点が下がるの...?と思ったところ、ユーザーが増えたせいみたいだ。
revertするか悩んだが後々活きてくることに期待してそのままいくことにした。
[15:10] 毎回static fileをreadするのをやめる: 6574
ボトルネックじゃないところに手を出し始めているので良くない兆候。しかも点が下がっている
Nginxのtry_files思いつきたかったな〜
[15:30] drop_conditionを思い切って0.1に下げる: 9358
打つ手を見失って実験しただけなのだけど、今度はなぜか伸びている...! のでこのままいく。
[16:30] GET /api/isu のN+1を倒す: 9266
GET /api/trend と同様の倒し方。こちらも結構手こずった
[17:00] GET /api/isu/:id/icon をキャッシュさせる: 9320
画像は変更されないようなのでNgnxで GET /api/isu/:id/icon に expires つけてキャッシュさせるようにした。
[18:10] 計測ツールをオフにする: 13020
しばらく見てないのでNginxのログ出力、MySQL slow query log、NewRelicをオフにしたところようやく10,000点超えた
[18:20] Pumaをcluster modeで動かす: 14328
ずっと1台でRubyプロセスのCPUが100%に張り付いているのは気になっていたが手が回っていなかった...。puma -w 2でcluster modeでPumaを起動したところやや伸び。CPUは2つのRubyプロセスが60%程度になりました。
以下を試したがあまり伸びませんでした。
- preload: 13542
- worker数の調整: 12982
[18:40] 祈りのラストベンチマーカー: 14484
特に何をするわけでもなく祈りながらベンチマーカーを実行したところこれまでで最高スコアになりました。
*1:もちろん勝つ気持ちでやってますが
