たごもりすメモ

コードとかその他の話とか。

#ISUCON 6 予選を戦ってなんとか通過した

今年のISUCONはどうするかなあ、出ないのも寂しいけど同僚や元同僚と出るのもなー……とか考えてたんだけど飲みにいった時に声かけてたらうまい感じのチームが結成できたので @joker1007 @tnmt との3人でチームJingisukan*1として出ることにしました。やった！

事前には一度だけ集まって、Azureをちょっとさわってみたり全体の流れを確認したり、とか。集まってのちゃんとした練習は結局やらなかった。個人的にはalpの使い方とかを事前に学習したくらいかな。

予選参加は2日目にしたんだけど、事前に2日目参加メンバーをidobataで見てゲエッとか思ってた……が、真の恐怖は1日目のトップ3通過チームリストを見たときに訪れたのであった。これシングルプｒ(ry

予選経過

開始前にちゃんと集まってわいわい。

開始後しばらく(1時間くらい)は事前の打合せ通り、インスタンスの立ち上げ、SSHログイン準備からのコードのgit共有、実際に自分でアクセスしてアプリを確認、アクセスログを変更してPerlとRubyでそれぞれ初期ベンチ走行、といったあたりを実施して、それから手が空き次第コードを読んで全員でアプリケーションの中身を把握したり。

  • Perl初期スコア: 3628
  • Ruby初期スコア: 0

このとき isupam とかいう謎のプログラムがあって、うわっなんだこれという警戒心が先に立ち、考え無しに手元環境でのアプリケーション動作を諦めてしまった。なんとなく話しあってAzureのインスタンスでだけやるかーということにしたんだけど、結論だけ言うとこいつは失敗だった。マージ待ちや他の人の作業待ちみたいな時間が増えちゃってたいへん良くなかった。

それはともかくアプリの改修内容について議論。当初話した内容は以下の通り(だったと思う)。

  • static fileはnginxで返す
  • isutarのisudaへの統合、マイクロサービス的なやつ撲滅
  • / における keyword の N+1 の抹殺
  • keywordまわりをいくらかRedis化する
  • starも完全にRedis化する? 付けたユーザ名が入ってるんだよなあ
  • その後 htmlify が遅かったらなんか考える
  • その後 isupam が遅かったらなんか考える

元のアプリが遅過ぎたのと、(後から明確になったことだけど)ログインとかのどう見ても問題なさそうな処理でも大量に遅いレスポンスが出てて、なんだこりゃってなってこの時点ではあまり明確な方針が立てられていなかった。htmlifyが遅いだろうことは見ればわかるけど、というかそこしか明確に問題点になりそうな部分がなくて、本当か? みたいに疑ってたのもある。

まあとにかく確実に必要でやれることをやろう、みたいな感じでお昼前にある程度やっつけた。自分がisutar統合で盛大にハマって時間をロスト。じょーかーさんに助けてもらった。最初はあれこれやってみてもスコアがふた桁とかでウケてたが、まあちょいちょい直した結果無事上がってきたので安心したところでお昼。

  • keyword listのRedis化 + isutar統合 + static fileのnginx配信: 5006

お昼食べたあと、早目に疑念を潰しとこうと思って isupam へのリクエストにかかるレスポンスタイムを全部計測してみた、ら、特にワザと時間を稼いでいるとかいうこともなさそうだったので、あまり考えないことにした。これは正解だったように思う。検討しないといけない要素を順次減らしていくのは大事。
そんなあたりでじょーかーさんがガリガリと修正を入れる。

  • N+1抹殺: 3332、4143
  • Puma化: 5261

ログインまわりとかの軽い処理にやたら時間がかかっていたのは、本当に何か時間がかかる原因があるのか、それともhtmlifyとかの遅い処理にプロセスが占有されたせいで待たされてるだけなのかの区別が付かずちょっと混乱してたんだけど、Puma化により無事そのへんの処理の request time が下がっていったので、待たされてるだけだっためでたしめでたし、となった。今回ちゃんとそのへんは毎回アクセスログを確認しながらやっていけてたのは良かった。alp便利。

自分は htmlify の最適化にとりかかっていた。まずキーワードの置換処理を 2 pass でやっていたのを 1 pass に修正。キーワードにHTMLタグに関連する文字が含まれてたらこの処理は 2 pass じゃないといけないんだけど < も > も無いことは確認したので、まあいいじゃろ、と。
結論から言うと間違いだった……。シングルクォートを含むキーワードが「Kissin' Christmas (クリスマスだからじゃない) 」と「TV's HIGH 」のふたつあることが後から判明したのであった。見付けたときにクリスマスだからじゃない、じゃねー！とか半ギレになってた。しかしこういう確認とかでDBを叩くのとか、もう常様べったりだったので本当に助かった。ISUCONにはインフラまわり担当のスペシャリストがまじ欠かせない。

で、htmlify を 1 pass にしてみてもほとんどスコアは変わらず5000前後のまま。明らかに正規表現マッチが遅いのはわかってるんだけど、Perlにあった正規表現のコンパイルモジュールとか Trie とかのが使いたい！と思って rubygems とかを漁ってみるんだけど見付からず。うう、Perlのエコシステムの強力さよ……。。。
他に String#gsub でマッチ対象に固定文字列リストを渡したりできないかなーとか見たり、あれこれもやってたけど、有効そうな手段が見付からず。

このまま悶々と時間が過ぎていって、15時半くらいでようやく htmlify 結果をキャッシュしないとどうにもならん、と決断。
今回のアプリケーションはキーワードが追加されると既存文書がすべて影響を受けるという性質がある上にレンダリング済み文書の生成コストが極めて重いので、正直、内容を把握したときからシングルプロセスアプリケーション向きだなーとは思ってた。思ってたけど、マルチプロセスでもそこに踏み込まないことにはどうにもならん、とようやく覚悟が固まった感じになる。正直、この決断が15時半というのは遅かった。

決断ができたのは cache invalidation にかかるコストが実は思ったより安かったというのもある。転置インデックスとか作りたくないよー、と悶々考えながらふとやってみた LIKE 全文検索が 0.1 秒で返ってくるじゃありませんか。おやおや。データが全部メモリに載ってると競技が変わるなあ。

UPDATE entry SET rendered = NULL WHERE description LIKE '%#{keyword}%'

これだけで cache invalidation できるじゃん！ 便利！
データ量小さいからおもむろに entry テーブルで ALTER TABLE して rendered カラムを追加、htmlifyまわりをやるコードあたりをくくり出して適当なスクリプトにまとめて、id 7101までの全件に対してガッと実行した。ちょっとかかったけど10分くらいで完了。同時に keyword 追加時には htmlify を実行して rendered にストア、既存 keyword への description アップデートなら同じく htmlify して更新、description更新も無いなら rendered は触らない、という感じで。
あとは参照時、keywordに対して rendered が存在していればそれを返す、rendered が存在しなければ htmlify してストアした上で返す、あたりの変更をガツッとやって突っ込んだ。これが16時ちょうどだったらしい。

  • pre-rendered: 53872

上位陣が数万点とってるのに俺達は5000点……みたいに果てしなくダウナーな気分だったところ、いきなりスコアが10倍になってチーム全体の雰囲気が超改善した。pre-renderedなコンテンツを返すようにしたことでボトルネックが一気に解消、これまでの変更がようやく全部有効になったんだと思う。戦える、俺達も戦えるぞ！みたいな。

ただしここでエラーが大量に出ていて、なんだこりゃ、と思っていたらキーワードのマッチ順序に気を遣っていなかったことがわかった。エラーメッセージの意味がわかんなくて唸ってたんだけど、実際にレンダリングされてたページを見てみたら割とすぐわかった。実際の動作を確認するの、大事だなあ。
キーワードをぜんぶ最長マッチに直して、事前レンダリングのもやりなおして(ちょっと時間がかかるのがキツい)、えいやっと。

  • keyword match longer first: 108373

ほーらほらほら上位に来たぞ！！！ みたいにテンション上がる。16時半。
しかしここでシングルクォートを含むキーワードでエラーが出ているのを確認。ベンチマークがPASSになってるんだけど、果たしてこれがどんだけの減点要素になってるのかが分からなくて、直すべきかどうかで悩む。個人的には、こういうエラーがどのくらいの減点要素になるのかちゃんとレギュレーションに書いてなかったのは出題のミスだと思う。(まあ難しいよね……。)

さて残りの時間でどうするか、ということでまたアクセスログを見たら / へのリクエストが予想以上に多く、当初はキーワード登録された後に必ず invalidation 対象になるので意味がないかと思ってたんだけど、やったほうが良さそうだね、という結果だった。そこはじょーかーさんにお任せしてやってもらい、他に何か無いかなあ……と探して回る。結局自分はずっと htmlify の中の正規表現をどうにかする方法がないか探してた気がする*2。思わぬボトルネックが隠れてないか、とかは継続的に常様に slow query log を見てもらったり。安心のクオリティ。

じょーかーさんが / のキャッシュを実装し終えたのが17時半過ぎ、これはギリギリかー? と思いながらベンチを回してみたら12万点くらい出る*3ものの、エラーが大量に並んでる。5万→10万のときの経験からして、ここでエラーを全部無くせば20万点くらいには行くんじゃね? などとテンションが上がってギリギリまでエラーを無くすためにbugfixとかやってた。
しかしあれこれ改善しても変わらず、「既に表示されたページが表示されています(GET / )」とかの意味不明なエラーが消えない。えぇー、インデックスページってキーワードが追加されたら既存キーワードは次のページにズレ込んだりするから、pagenation進めていったときに表示済みのやつが出たりするのは普通なんじゃないのー? とか不満をぶいぶい言わせてた。

この付近、スコアの改善どころかベンチを回すたびにスコアが大幅に下がったりすることもあって、うーんこれはダメか、みたいな感じでいったんはトップページのキャッシュ戦略を放棄、masterブランチに戻して再起動チェックしておしまいにしようか、10万点くらい出るはずだったし、ということになった。systemd上での各ソフトウェアの自動起動等は安心のtnmtクオリティで一発で問題なし。さあベンチ回しておしまいにしよう！

  • master branchに戻して再起動後: 約6万点

えええええええええええ、なんでだよ、ちょっと待ってよおい、みたいな感じ。さっきまで10万点前後だったスコアが急降下して、予選まあ通るんじゃないの、という空気から予選落ち確定に転落。おいおいおい。
このままじゃ正直マズいだろ、ちょっと待てよ、と緊急で相談、こうなったらもう今からトップページキャッシュ有効のコードにイチかバチか切り替えてチャレンジしよう、ということでブランチを切り替え、ベンチマークをエンキューして走行を待ってたら18時タイムアップした。走ってるのはなんとなくわかるけどスコアが採用されるかどうかはタイミング的にギリギリだし、結果の確認もできないしで、あぁー終わったー予選落ちだー、とがっくりして終わった……。。。





その後

完全に自棄酒モードになった我々はPCの前に居るとコードを読みながら悪い酒を飲んでしまう、ということで雨の中を近所の築地へ。日曜なのを忘れててだいぶ店も閉まってたんだけど、運よくナイスな店がやってて入れそうだったので店の前でしばらく待機。
……してたら、なんと発表された予選通過リストに我々の名前が！ やったー！

築地の店の前でハイタッチしてた。スコアを見ると最後に走行したベンチマークが有効スコアとして認められたっぽい。結局最終スコアが10万点なので予選中の最高スコアに及んでいなくて、そういう意味では結局謎のスコア低下は残り、なんだったんだという感じはする。一方で最後の走行が有効扱いになるとはあまり思っていなくて、幸運に拾われた面もあるかもしれない。

まあとにかく通ったぞ、ということで。予選は通りゃいいんだよ通りゃ。勝負は決勝だ！



反省などあれこれ

とにかく @joker1007 さんの実装力が高くて、Rubyのコード改善はお願いしまくり。あと今回自分はMySQLやらsystemdやらは全く見てなくて、そこやら全部再起動便利スクリプトやらの足回りは @tnmt さんに完全に丸投げしてた。この2人とチーム組めてほんとに良かった、助かった、という結果だった。
最終的なアプリケーションコードも全体の設計やオペレーションも、今回の予選も完全に複数ノード構成にそのまま持っていける内容になっていた。ので、今回のチームも*4決勝でこそ実力を発揮できるチームだと思ってる。来月もがんばりたい。

自分については、もうこれまでRedisから逃げ続けてきたツケがついに、という感じ。来月までにRedis使ったWebアプリケーションを一度書いてみよう…… orz ということで反省しきり。そういえば俺のWebアプリケーション実装力はこの2〜3年は改善ゼロなのであった。もうちょっとちゃんとしよう。

今回のアプリケーションとベンチマークについては、htmlifyを理想的に高速化できるかどうかがまずひとつで、これはイチから実装して突破するか、ナイスな機能・モジュールのある言語を使うか、ということに尽きた感じ。Rubyまわりだとそのまま使えるものが何もなかったので少し厳しかった。まーC拡張をゴリゴリ書けなかった自分が悪いといえば、そのとおりかもしれぬ。
あとは生成したレンダリング済みcacheの共有や invalidation をやるのにシングルプロセスだと超絶やりやすいよなーってことで、これもまあ思うところが無くはない……が、予選はそういう傾向のことが多いので、分かっていたことではある。あるけど、マルチプロセスでも通用する構成でも今までは予選通過は固かったところ、今回はそのハードルがだいぶ上がっていた気はした。

キャッシュ戦略については、正直ベンチマークツールが出したエラーがどういう理由を示しているのかが分からなくて、本当に不整合が出ているのはどういうケースなのかを特定し切れなかった部分がある。
あとはコンテンツが正常にレンダリングされていないのにベンチは PASS になっている状態で、そのままスループットを上げる方向の判断をしちゃった方がじつは高スコアが狙えるんじゃないの、という……自分たちはエラーを消す方向に思考を向けて足を止めちゃったけど、あのままガンガンスループットを上げればいいんだったらそれなりの手はまだいくつもあったので、どうだったのかなあ、というのは気になる。

しかしコンテンツに関して出ているエラーがどういう減点要素になっているのかがレギュレーションのどこにも書いてなかったので、どう出たらいいのかが判断つかなかったんだよねー、ということで、これは決勝では改善されるといいなあ、というところだった。

全体を見ると、とにかく pre-rendered なコンテンツを準備する & キャッシュを頑張る、という方針への決断が遅かったのは最大の反省点。次はもっと決断を早目にしていきたい。あと手元環境は作ること、かな。本番ノード上でデバッグとかしてちゃ時間の無駄だ。

まとめ

出題者＆運営の方々はお疲れさまでした！ 決勝もよろしく！ 決勝頑張るぞ！

*1:チーム名は優勝したら賞金で食べに行きたいものでなんかつけよう、という話をして決めた。綴りはどうなんだと思ったけど英語版WikipediaにJingisukanって書いてあった！

*2:しかも徒労に終わった

*3:正確なスコアをメモり忘れてた……

*4:生ハム原木に引き続き