あー、負けたー。「Asakusaの方から来ました」というチーム名で、Asakusa.rbでよくいっしょする @joker1007 さん、および @yancya さんと出た。最終結果は111400くらい? ただし20時*1を過ぎても4〜6万くらいをうろうろしてて、最終的には20:10頃に入れた変更でスコアが倍になり、なんだこれー? と言ってる間にタイムアップした。
去年のISUCON6決勝はやるべきことをやれなくて負けたので素直に悔しかったけど、今年はなんか問題設定の意図がまったくわからなくてそのまま不完全燃焼で手が停まって4時間経過で死んだという感じなので、なんだかなー、という気分。あんま疲れないまま終わってしまった。
なんか、なんで自分があーって思ってるかはわかった。keep-aliveをなかなか切ってくれないエンドユーザクライアントがたまに混ざってくれることはあるかもしれないけど、CDNをかましてるかどうかを知らないなんてことがあるわけねーだろ、というところだった。
— tagomoris (@tagomoris) 2017年10月22日
たぶん出題者にはお礼の言葉が今週のblogエントリ等では並ぶと思うので、負けた人間としてはここで一発だけdisっておきたい。結果論として、問題設定としてはISUCON4決勝の問題で Cache-Control をみんなが有効にした後の状況を作りたかったんだろうなー、という気がする。けど、ハイコンテキストすぎるだろ。あと Cache-Control: public を明示的に有効にしないとキャッシュしてくれないっていうのは明らかに特定のCDNを意識していると思うんだけど、参加者に複数ホストを最初から与えておいて、最終的にやらせたかったのは外部サービスにいかにキャッシュさせるか*2ってことですか?
いやまあ、そういう問題だったし、そこをクリアした上で勝負を争えという問題だったんでしょうね。そういう問題だと気付いた時点で残り1時間もなくて、潜在的に抱えこんでいた問題に対処しきれず負けたのは、もう普段Webサービスから遠ざかった自分の実力なんだろうと思います。
最終的にはこれCDNかということに気付いたけど、そのときに周囲のチームのようにはスコアが上がりきらなかったのは、完全に自分のオペミスのせいだった。これだけは本当に言い訳ができないミスで、チームメイトに申し訳なかったなと思う。あの1手で本選出場を逃したと言っても過言ではない(詳細は後述)。
予選環境は快適でした*3。ベンチマークもエンキューした直後には始まる状態がずっと続いていて、1チームに複数サーバを与えるということも含めて、さくらインターネットさんの担当側は大変だっただろうなと思います。お疲れさまでした＆ありがとうございました。
環境構築であれこれあったためかスケジュール上もあれこれあって、運営の941さんも物凄く大変だっただろうなと思います。お疲れさまでした。いつもありがとうございます。
経過
joker1007さんのエントリに細かい経過がある。
SSHログイン含めてちょっと最初の環境整備でバタついて、結局この図を描いたときにはスタートから1時間半くらい経ってたと思う。負荷とトラフィックをうまく3台にバラす、ということをいつもの決勝の通りメインで考えていた。WebDAVと言ったときはまたWebDAVかと自分でも思ったけど、あとで考えたらS3的なオブジェクトストレージが欲しいときに簡単に実現するための自分の発想がWebDAVなんだなと。
メッセージまわりのコードの変更はあとの2人にお願いして、自分は画像をうまく配信するためにhttp_dav_moduleを有効にしたOpenRestyのビルドと設定、あとは手元でもちゃんと動くようにRubyのアプリケーションでもPUTを受け付けてローカルに書き出すリクエストハンドラを追加したりしてた*4。
で、多少ミスったりしつつ*5もしつつ、3ノード全部で画像をnginxから直接返せるようになったのがこのcommit、17:25。けっこう時間かけちゃってるなあ。
fix to upload icons to servers · tagomoris/isucon7-elimination@b380245 · GitHub
で、ネットワークが詰まって、なんだこりゃーとなった。今にして思えば画像をDBから出して直接nginxから返すのだけを初手にやって、それを複数台構成に直す、としていればたぶん今回のミスは踏まずにすんで、普通に戦えてたんだろうなという気はする。いきなり最初からベストな最終形を描いてそこを目指して進むのは自分の仕事の進めかたのよくない所だろうかという気はちょっとする。……んだけど、うーん、普段はそっちの方が効率いいんだよなあ。
この作業のとき、以下のような手順を踏んだ。これが後にして思えば決定的なミスだった。
- スクリプトを書いてDBからファイルシステムに画像を書き出す (OK)
- 書き出した画像をgitリポジトリに突っ込む (どちらかと言えばNG、ただし決定的ではない)
- サーバ3台でそれぞれ git pull で画像をfetch (OK)
- WebDAV用の領域に画像を cp -r で移す、というコマンドを3台でそれぞれ叩く (完全NG)
最後の手順により3台のサーバでそれぞれ初期の画像セット(67ファイル)のタイムスタンプがズレて、最終的に Cache-Control: public がついた状況でCDN(と想定されるクライアント)側にうまくキャッシュが保持されなかった。
これ、単に tar.gz で画像ファイルを固めて各3台のサーバのWebDAV領域でそれぞれ展開していれば全く問題なく処理されてただろうし、あるいは cp するときに -a つけていればそれでもよかったはずで、今となってはそのあたりの手順を当然のようにとってても不思議ではなかったと思うんだけど、なんか、そうしてしまった。本当に悔やまれる。
その後、ネットワークが詰まった状態になったのはすぐに分かったので Cache-Control のことはすぐに思い付き nginx で expires の指定を入れるものの、まったく状況が改善せず、なんで? と不可解な状況に陥った。
tcpdumpをとって調べたんだけど、Last-Modified の入ったレスポンスを返していれば普通のWebブラウザ等のクライアントであれば当然入ってるはずの If-Modified-Since の指定が入っておらず、でも周囲のスコアを見てみると画像のバイナリを返していれば不可能なスコアを達成しているのは明らかで、どういうことじゃこれは、と悩み続けてた。
あ、もひとつ思い出した。/cssや/fontが Cache-Control: public つけてない段階で If-Modified-Since が来てて /icons には来てなかったので、こいつなんなの? と思ったのでした。クライアント公開されたら確認ミスだったかもだけど。
— tagomoris (@tagomoris) 2017年10月22日
特に悩ましかったのがこれ*6で、同じ静的ファイルなのに違う傾向のリクエストを送ってくるCDNがあるなんて想定してなかったから、完全に思考が空転してた。ずっと「このクライアントはなんなの?」って言い続けてた気がする。
ずーっと煮詰まってたんだけど、20:10のこのcommit、半笑いで「まっさかねー」と言いつつ Cache-Control: public を入れた。ベンチ回してトイレいって、戻ってみたらスコアが倍増しててうぎゃあコイツCDNだ! とか言ったような気がする。
add Cache-Control: public explicitly · tagomoris/isucon7-elimination@079a30a · GitHub
ここで11万点まで上がったんだけど、しかしそれでもネットワーク帯域は使い切った状態で、なんで? と言い続けてた。
これは自分のミスでハマったところ。最初に撒いたファイルの Last-Modified および ETag が各サーバで異なってたため、CDNを想定したクライアントのエッジキャッシュヒット率が 1/3 に落ちていたんだと思う。んでそのたびに画像をダウンロードしに来ていたから初期データへのアクセスでネットワークをまず使い潰した。これでベンチマーカーの負荷も上がらず、結局初期データへのアクセスだけが続くようになってドツボにはまったっぽい。
その後にアップロードされてくるデータをサーバ3台に渡すのは、まあちゃんと気を使ってなかったとはいえ、1秒をまたぐこともほとんどなかったはずなので、概ね大丈夫だったはずと思っている。もちろんもっとちゃんとやりようはあったけど。
とはいえ「このクライアントなんなの?」という疑念が強過ぎて、Last-ModifiedおよびETagをちゃんと返せているかというところまで頭が回らなかった。CDNがエッジキャッシュを作るときには当然そこを厳密に見ているはず、という発想もなかったので、これは、うーん……もうちょい時間があればなあという気もするけど。うう。
他の2人がちゃんとメッセージ回りのロジック改善をやってくれていたので、あとは /icons の初期データさえどうにかなっていたらだいぶ上位のスコアが出てたんじゃないかなあという気がする。心残りは大きい。
結論
頑張って仕事しよう、と思ったものの、正直こっちの方向にISUCONが行くといくら自分の仕事してても弱くなる一方なので、引退かなあ、とか考えつつある。
去年の予選は*7はてなのサービスだ! というのがわかったので面白がれたところはあったけど、今年のはもう、なんなの、ちょっと無理、みたいな気分。
*1:今回は13時〜21時というスケジュール
*2:しかもそんなものが存在するという前提は教えない
*3:……fail2banを除いて。メンバーのひとりでもちょっとログイン試行に失敗を繰り返すと全員がbanされてたので、最初にちゃんと全員のvalidな公開鍵を入れ終わるまでちょっとトラブってたのはきつかった
*4:ISUCON3の決勝のときにもほぼ似たような構成だったけど、このときは何も考えずにWebDAVが有効なnginxが無いと動作確認もできない状態にしてしまって難儀した覚えがあったので、その教訓から
*5:OpenRestyビルド時に --with-ipv6 つけ忘れてアーッってなったり。IPv6がちゃんと最初から有効なの、さくらインターネットさすがだな! って感心しながらビルドしなおした。
*6:あとでfujiwaraさんもなんかtweetしてたので確認ミスではなかったようで、ちょっと安心している
*7:競プロ勢向きだなー! と思いはしたものの
