ISUCON5、予選を無事通過して10/31(土)に開催された本選に参加し、優勝しました。
チームは ISUCON 1 の時の初代「fujiwara組」再結成ということで、@songmu, @sugyan とのカヤックの元同僚メンバーです。
最初に、毎回素晴らしいイベントを開催、運営していただいている @941 さんをはじめとした運営チームの皆様、出題の @tagomoris さん、@kamipo さん、他すべての協力いただいた皆様に感謝を申し上げます。本当にありがとうございました！
競技開始からベンチ実行まで
作った #isucon pic.twitter.com/5RZkPUsaPu
— fujiwara (@fujiwara) 2015, 10月 31ロゴがなかったので作った。
競技開始、まずは3台で相互にsshできるようにするのに一瞬戸惑う。port 22は開いていて、会場からは接続できるものの提供された3台間で接続しようとすると切断される挙動……最近の若い人は tcpwrapper とかなじみ薄いんじゃないかなあ、と思いつつおじさんなのでそこはすぐ /etc/hosts.allow にIPアドレスを追加して解決。
予選から使っていた初期設定用の Chef を流して初期設定はすんなり完了。isucon5/chef at master · fujiwara/isucon5 · GitHub
Chefの適用とアプリケーションのデプロイは、3台なので何でもいいんだけど…と思いつつせっかくなので手製の stretcher で構築。
雑に
#!/bin/bash tar czvf ~/webapp.tar.gz . sum=$(sha1sum ~/webapp.tar.gz | awk '{ print $1 }') cat <<END > ~/webapp.yml src: http://isu01a:8000/webapp.tar.gz dest: /home/isucon/webapp checksum: $sum commands: post: - sudo supervisorctl restart perl - sudo mv /var/log/nginx/access.log /var/log/nginx/access.log.`date +%Y%m%d-%H%M%S` - sudo service nginx reload END echo http://isu01a:8000/webapp.yml | nssh -i -t isu01a -t isu01b -t isu01c stretcher
isu01a (1台目) の port 8000 で nginx が /home/isucon 以下を配れるようにしておいて tarとmanifestを配信、nssh で各ホストでstretcherを並列実行。nsshというのはこれも自作の、複数のホストにsshしてコマンド実行して出力をまとめて流してくれる君。fujiwara/nssh · GitHub
この間にチームメンバーの二人にはアプリケーションを読み込んでもらい、手元で実行できるようにしてもらっていたんだけど、今回の題材は運営が用意している外部APIサーバに接続する必要があり、そこには会場から接続できずに動かせない、とのこと。
なので Squid を isu01a:3128 で動作させ、手元で動かす際には HTTP_PROXY=http://(isu01aのIPアドレス):3128/ を指定してもらうことで会場の手元のマシンから接続できるように構築。
最初のハマり
ここで、Squid で外部APIの結果をよしなに cache できたらそれだけでスコア上がったりするんじゃないか? と思いついたので cache させようとしたものの、うまくいかずにすべて MISS してしまう。最近、Squid は forward proxy としてたまに使うものの下手にcacheされると面倒なことのほうが多いので、cache させない設定の config は持ってたんだけど…
なんだかんだでここで1時間程度ロスした気がする。これが大失敗。
アプリケーションでの cache 実装
結局 Squid での cache はあきらめて、アプリケーションレイヤーで外部APIのレスポンスを memcached に cache してもらう。この実装が動いたのが14時すぎぐらいで、一発で通ってスコアは 37,000 ぐらい。一瞬2位になるものの、GoBoldは既に10万点近くまで駆け上がっていて背中が遠い。
最初の実装はすべてのAPIレスポンスを考えなしに (expireせず) cache していたので、たまたま通ればスコアは出るがチェッカーに引っかかるとfailするという状況。
API エンドポイントごとに expire を個別に設定できるいい感じの実装を @songmu につくってもらったので、それでまずは変わらなそうな ken (ken_all.CSV!!) などをベンチ走行中に切れないように長寿命に調整。
https の perfectsec_attacked, perfectsec はどうも cache するとまずそうだな、と判断して cache しないことに。 (これも実は判断ミス)
https のは実は http2 対応していたそうですが、全く気づいてなかったのと、仮に気づいてたとしてもまともな Perl の http2 クライアント実装を知らないのでスルーしていたことでしょう。
下回りの調整
この状態で、isu01a に nginx, PostgreSQL, memcached, webapp、他2台にwebappという構成で5万点前後?
isu01aでのネットワーク転送量がだいぶ大きかったのでログを見つつサイズの大きい静的ファイル(css, js)へのリクエストヘッダを観察したところ、Accept-Encoding: gzip が付いていたので gzip_static モジュールで gzip 済みのファイルを配信。一気に転送量が減ってスコアも7万点近くまで伸びた気がする。
Plack の worker 数は何も考えずに 10 (* 3台) にしていたんだけど、初期実装の5プロセスから10にしただけでスコアが倍近くになっていたので、ここをもう少し調整できていればもっと伸びたか。
迷走
16時近くまで膠着状態。 perfectsec API系は一番最初に何も考えず cache した状態でベンチを通過していたので、実はここも cache できるのでは? と思って expire 調整をしようかと提案。
が、@sugyanが「もっとアプリケーションでできることは…」と言うので、まあそれもそうだよな。cache 寿命調整はあとでもできるし、と思ってあるミドルウェアを書くことに。結果的には、16時から大改造に手を付けたのも大失敗。
自分と @sugyan が飛び道具開発、@songmu にはその間に memcached へのリクエストを最適化するために get_multi, set_multi するように改修を進めてもらうことにした。
飛び道具不発
書きたかったものは以下のようなやつ。
- Go で memcached protocol を喋る server
["uri",{"param":"value"},{"header":"value"},expire]というkeyの形式で複数 get をリクエストすると、外部に並列HTTPリクエストした結果を返してくれる- このkey形式はアプリケーションでmemcachedを扱うときのものと同一
- ついでにオンメモリcache もする
これができれば、memcached の代わりにこれを使うだけで Perl のアプリケーションは何も変わらず、しかも並列にAPIリクエストもできてレイテンシが隠蔽できるという飛び道具になるはずだった…
Go での memcached protocol server は kayac/go-katsubushi · GitHub という、Snowflake like な ID 発番をするサーバを書いていたのでこれを改造。
@sugyanとペアプロしながら外部のHTTP APIにリクエストを飛ばして結果を返すところまでは30分も掛からず書けて、あとは複数並列とオンメモリ cache、1時間半あるし行けるのでは！という感じだったものの、ここで memcached protocol の理解が浅くてドはまり。
gets で複数の値を取得するときは、gets a b c と key をリクエストされた順番でレスポンスを返す必要があったんですね。なぜかレスポンスが取れたり取れなかったりして、パケットキャプチャと睨めっこしながら1時間ハマって、キー順に sort して返す必要に気がついたのが 17:35 ごろ。
結局そこから直しても deploy して組み込む時間はない、ということで 17:40 に実装を断念。
ボトルネック開放
perfectsec 系 API、まず片方だけ10秒 cache したところ一気にスコアが上がって17:46ごろに10万点近く、両方 10 秒にして15万を17:50ごろ記録。
これは cache の寿命だけではなく、@songmu が進めていた memcached への複数 get, set、user をセッションデータ内部に持たせてログインセッション中は DB を引かないようにするという改善が、ボトルネックを開放したことで一気に伸びた要因に思われる。
再起動テスト
17:53ごろから再起動テスト。 順不同で再起動した場合、PostgreSQLに1回繋がっていたコネクションがあとから落ちると、次のリクエスト時にエラーになって500が返るのを17:57ごろ発見。
再起動後誰も一度もリクエストしなければ問題ないので、「全員開いてるタブを全部落として！」として XHR でのリクエストなども飛ばないようにして、あとは祈る感じで… (本来なら、接続が切れたら再接続するコードを入れるべきですね)
結果
結果、failすることもなく 151,509点 で優勝できました。
#isucon トロフィー pic.twitter.com/t3c0SQSINa
— fujiwara (@fujiwara) 2015, 10月 31今回は反省点が本当に多くて、Squidでハマって1時間無駄にしたことで飛び道具実装も1時間遅くなり、そこでハマって動かせず。 負けるときはこういう感じなんだろうなあとだいぶ覚悟していました。
なお、飛び道具は後日修正したら+2分でちゃんと動かせたので、当日も1時間早く手を付けていたら投入できていた可能性は高いですね…大改造するなら14時か遅くても15時までに手を付けるべし、という経験則は正しかった。
自分がハマっていた時の作業ミスを確実にすべて見つけてくれた @sugyan、2人が1時間沈黙している間黙々と改善を進めて最後に炸裂させた @songmu、両名には本当に感謝です。
ISUCONで勝つためには、チームメンバーを心底信頼して任せることが本当に必要ですね。 自分は過去すべての大会でそういう戦いができていて、幸せだと思います。
来年?
ISUCON 6 が来年あるとして、出題は他の人にやってもらいたいなあという気持ちがあります。どうも自分と @tagomoris さんは妙にかみ合うというか、ISUCON における相性がよすぎる気がするので、交互に出題していてもあんまり広がりがないのではないか、と思うのがひとつ。
今年も事前解答によるフィードバックが足りないことが課題として見えているので、自分は出題の事前解答とレビューをやることで、さらなる品質向上に貢献できるのではないかと思ってます。
最後に、運営の皆様、スポンサーの皆様、そしてすべての参加者の皆様に感謝します。ISUCON楽しかったですね！
