ISUCON 5 決勝戦で負けてきました
lily white というチームで ISUCON 5 決勝戦に出場してきました。 終盤が、結果 fail でスコアなしに終わってしまいました。
チームメンバーは僕の他に、新人の @gam0022 と、学生の @koki_cheese さんです。
二人とも経験が殆ど無い状態だったので、 @gam0022 には主に MySQL を、 @koki_cheese さんには アプリ側で僕が予選でやったことを練習してもらい、少しでも僕が戦略的に動ける余裕を作るという作戦でした。
結果的に、DB が MySQL でなかった、 @koki_cheese さんが練習時間をあまり取れなかった、 僕が2人を信頼しきれずアプリの実装に回ってしまい、戦略的な所ができなかったために、実力を発揮できずに終わってしまいました。
11:00 ~ 12:00 初回ベンチ実行
下回りは @gam0022 にまかせていたのですが、レギュレーションを読んでる間に ssh の設定をしてもらうはずが、
/etc/hosts.deny
に気付かずにハマっていました。
状況を聴いて調べようかと思ったら @koki_cheese がすぐに見つけてくれましたが、そこから ruby 止めて Go 動かして計測したのが 12:00 頃でした。
12:00 ~ 13:40 API endpoint のハードコード
アクセスログを眺めたりコードを読んだりお弁当をごちそうになったりしていました。
/data
が遅いので、外部 API 呼び出し先をコード上にベタ書きしたところ、かなり下らないバグを
仕込んで数回 fail してしまい、たぶん15分ほど無駄にしました。つらい。。。
var Services = make(map[string]*Endpoint) func init() { ss := []Endpoint{ Endpoint{"ken", "GET", "", "", "http://api.five-final.isucon.net:8080/%s"}, Endpoint{"ken2", "GET", "", "", "http://api.five-final.isucon.net:8080/"}, ... } for _, e := range ss { Services[e.Service] = &e
こう書くと e
はローカル変数になるから、C言語とちがってちゃんとエスケープ解析されてヒープ確保されるものの、
ループ毎に新しくオブジェクトを作るわけじゃないから、 Services[s]
でどのサービスを選んでも最後の Endpoint
へのポインタになっているという痛恨のミス。
ハマった僕が言うのもなんだけど、これは簡単だったので @koki_cheese に任せるべきだった。。。
13:40 ~ 14:40 コネクション数の削減
netstat -tn を見たら ESTABLISHED も TIME_WAIT も大量にあったので、ポートを見ながら 調整していきました。
nginx から go へのリバースプロキシは最初のほうで keepalive 32 にしていたのですが、 足りないようだったので keepalive 256 にして、 TIME_WAIT が消えてから unix domain socket に 切り替えました。
PostgreSQL への接続はコア数と同じだけあればいいので MaxIdleConns と MaxOpenConns を両方 3 にし、 逆に API 呼び出しのコネクションは不自然に大量にあって調べてみたらAPI呼び出しのたびにコネクションプール 自体を作るという (たぶん他言語実装との差を埋めるための) 極悪コードになっていたのでその部分をごっそり 消して、TLSのサーバー検証をスキップする設定をデフォルトのコネクションプールに移動しました。
その間、 @gam0022 には静的ファイルを nginx から返す設定を、 @koki_cheese にはセッション ストアを secure cookie から、 cookie に直接 user_id を書ように書き換えを依頼していました。 (これは後でアクセスログに載せるつもりだったけど結局最後まで手が回らなかった)
他にも sysctl.conf の設定とかもこの辺でやっていたはず。
TIME_WAIT 問題は「エラーは出ないけどなんかCPU使い切れないし性能が伸びない」という状況でハマらない ために早めに対策して置くのが良いと思うけど、それ以上の最適化は早すぎた。
14:40 ~ 16:20 Redis cache の導入
API のレスポンスがパラメータやユーザーによってどれくらい変わるかの調査を @koki_cheese に依頼していて、 ken, ken2, surname, givenname がユーザーにも依存しないし、ベンチマーク実行のたびに変わるわけでもない ということが解ったので、永続化が簡単な redis を使ってキャッシュすることに。
その間 @koki_cheese には tenki API が Date だけ偽造したらキャッシュを許してくれないかの検証を、 @gam0022 には nginx に gzip_static の導入をお願いしていました。
Redis のクライアントには redigo を使いました。 redigo には標準のコネクションプールの他に、 redigo/redisx という コネクションマルチプレクサがあります。これを使うと、複数の goroutine からの redis へのアクセスを 1つのコネクションに集約して実行してくれるので、 redis 側の負荷が減ります。
prefork 型の LL だと twemproxy など外部の proxy を利用しないと多重化できないのでマシン間の 通信にしか意味がありませんが、 Go だと同一ホスト内の通信も最適化できます。
他に工夫したのが、APIサーバーからのレスポンスをそのまま redis に突っ込んだりして、最終段で JSON を作るときに 文字列結合で JSON を作るようにしたことです。 これで JSON の Marshal, Unmarshal が減って性能が稼げるはずだったのですが、この時 API サーバーが 不安定でステータスが 200 じゃない事があり、エラーメッセージを redis に格納してしまってそれを消すまで fail が続く状態にハマったりもしました。
16:20 ~ 17:20 API呼び出しの並列化と too many connections
tenki API や https を使う API は、結果が高頻度に変わるし、パラメータもユーザーごとに分散が激しくて キャッシュヒットしなさそうと判断し、 API の並列化にとりかかりました。
が、これは殆ど効果なかった上に too many connections 問題が起こったのとベンチマークのキューが 伸び始めてたせいで予想以上に時間を食ってしまい、敗北が決定したのがこの段階だと思います。
17:20 ~ 18:00 終了
@koki_cheese に頼んでいた subscriptions のオンメモリキャッシュができたというのでマージしてもあまりスコアが上がらず。
焦って気づかなかったけど、実は /modify
でしかオンメモリキャッシュに store しておらず、負荷のほとんどでは
キャッシュが全く効いてなかった。
/data
内からの DB アクセスはもう一つ getCurrentUser()
経由のユーザーテーブル参照があったんだけど、
これのオンメモリキャッシュ実装にラスト15分位でとりかかるも、ベンチマーカーのキューが長くなっていた状況で
一発 success できなかったため revert して終了。
結局 fail だったんだけど、これは nginx の負荷が高いし秘伝のタレからコピペで設定入れといたあと、 一度も nginx を再起動することなく試合終了していたためでした。
反省と感想
- もともと fail 覚悟で最後までチューニングしていたものの、実際にスコアなしを初経験したら想像以上に堪えたので来年からはちゃんとスコア出す
- 「
/data
でのDBアクセス殲滅しておいて」と大まかな指示を出しておけば @koki_cheese さんの力をもっと発揮できたはず - 下回りは知識と経験がものを言って練習でカバーしにくいので、 @gam0022 には redis の練習しておいてもらうんだった
- 天気APIのキャッシュを諦めた& If-Modified-Since を見逃したのが最大の敗因で、これは完全に僕のミス
- 僕が一番実装力あったとはいえ、実装の主力になって調査や試行錯誤が必要最小限になると勝てないので実装を我慢するべきだった
- 今回の問題は突き詰めると Go が有利だったはず。また Perl に優勝をさらわれて悔しい
数百台の仮想マシンクラスタを用意してくださっている NHN テコラス様、このイベントを運営してくださっている LINE 様、特に櫛井様、 毎年ありがとうございます。
出題してくださった Treasure Data の田籠様、上薗様もありがとうございました。予選本戦通して、過去最高に面白い内容と、快適なベンチマーカー、 そして最大の敗北感でした。
来年こそは優勝するぞ!
@methane