第5回目となる ISUCON 。今年も参加しています。
- 優勝賞金100万円！今年もやります ISUCON5 開催と日程のお知らせ #isucon : ISUCON公式Blog
- 【締め切りました】ISUCON5 オンライン予選の参加登録を開始＆参加チームとメンバーリスト : ISUCON公式Blog
前回・前々回と社内選抜として同じチームで出場していた方々が別の会社に移ってしまって出題側に回ってしまっていたりで「どうしよう…」と思っていたところに 第1回 のときのメンバー(@fujiwaraさん、@songmuさん)で再結成しよう、という話が上がったので有り難く乗っからせていただきました。
fujiwara on Twitter: "初代fujiwara組を再結成しよう"
予選は第1日目で参戦し、結果は1位通過！やったー！
ISUCON5 本選出場者決定のお知らせ : ISUCON公式Blog
忘れないうちに、何をやったか振り返っておこうと思います。
〜前日
以前一緒に働いていたとは言え、4年近く経過しているので一度顔合わせて作戦会議的なものをしておきましょう、と2日前くらいに軽く集まって話して。自分とsongmuさんはコード書いてfujiwaraさんにサーバやミドルウェア設定などインフラ側みていただくという役割分担ですよね、と確認。自分は最近もうあまり書いてないですけどPerlしかマトモに出来なそうです、ということでPerl実装でやることに決め。
SlackのTeamはチーム結成すぐに用意していただいて、事前の情報共有などはそこで行なっていました。当日の連携もそこで。ファイル添付もできるしGithubのPrivate repositoryへのpushやpull requestの作成もhookして流すようにしていただいていたのでそれぞれの作業がすぐに分かってとても便利でしたね。
fujiwaraさんがサーバ立ち上げてすぐに作業できるようにと諸々準備していただいていたのでそれにお任せして…
あとは寝坊しないように前日早寝する、だけ。
当日朝
はてな社さんの会議室を使わせていただける、とのことで表参道オフィスに集合。静かな環境で落ち着いて一日作業できました。ありがとうございます。
開始前になってまさかの1時間延期。まぁ一息ついて…ちょっと気が抜けかけたけど Twitterを見ながら開始を待ちました。
スタート
まずはfujiwaraさんにインスタンスの立ち上げ・諸設定を進めていただき、レギュレーション読んでお題のアプリの機能を把握して。Githubのprivate repositoryに突っ込んでローカルに落としてコードをザッと眺めつつベンチマークをまず流してみてアクセスログ、slow queryを確認。ここまでで40分くらい。
トップ重いよねー。うわーこのSQLやばそう…。ここindex貼ってないわー。とか色々手を加えたい場所は出てくるけどボリューム的に時間内に全部対処するのは無理だろう、優先順位を考えて順番にボトルネックを潰していきましょう、と。
まずはとにかくslow query。これを減らしていくためにまずindexを貼り、コードの変更が必要な部分はsongmuさんと相談し手分けして着手。その間にfujiwaraさんにミドルウェア周りのチューニングなどやっていただいたり deploy環境を整えていただいたり。is_friendでWHERE (one = ? AND another = ?) OR (one = ? AND another = ?)って片方だけで十分だよね、って最初のSQL変更がmasterに入ったのが12:40くらい。開始100分後。
昼頃(ALTER TABLE, LIMIT 1000対策)
LIMIT 1000で取ってきてアプリ内でfor文まわしてフィルタリングしているところをとにかく消すぞ！とentries_of_friendsをrelationsとJOINして取るようにしてみようとしたところ、実際にSQL発行して試してみるとめっちゃ重い。こりゃまずbodyを全部取ってきてることが問題だからそっちを先に対処しないとアカン、と。どこか(第3回の予選でしたっけ？)で見たことのあるパターンでentries.titleカラム作ってそれだけを読むようにしようにしましょう、と。
しかしこのテーブルに対するALTERがめっちゃ重い、終わらないという罠。これをfujiwaraさんがSSDインスタンスを使ったウルテクで解決してくださっているのに感動しつつ無事にALTERされる前提でコードの変更を進めた。細かくpull request作ってお互いにチェックしつつ すぐにrevertも出来るよう意識しながら。
14時前後で、無事にLIMIT 1000のクエリを排除できて2800->5200->9400と一気に上昇。しかしひそかに狙っていた「最も早く3000点に到達で予選イチ抜け」は他チームに僅差で先に獲られてしまい。正直けっこうダメージありましたね。
ひとしきり凹んだあと、とにかくもうスコア上げていくしかない！！と気を取り直しお昼ご飯たべつつ午後の作戦を相談。
午後(Redisで高速化)
「足あと」、「あなたへのコメント」あたりが次のボトルネックだ、ということでここはキャッシュしていく戦略でいこう、と。足あとはユーザーと日付を繋げたものをキーにしたRedisのsorted setを使えば良いだろう、ということでRedisの導入を決定。
僕はRedisマトモに使ったことないのでそっちはsongmuさんにお任せします！ということで自分はcomments_for_meのキャッシュ化を担当。全5000ユーザに対しそれぞれlist型で必要最小限の情報だけをJSONで突っ込んでlrangeで先頭から取り出して復元できるようにしよう、と 初期データに対する処理とPOST時の更新処理を。初期化が30秒以内に終わらないかも、というのはとりあえず考えないことにしてこれが16時ちょい前にmasterに。動かしてみたらcommand sent is not an octet sequence in the native encoding (Latin-1).となってRedisにJSONが入らなくて慌ててJSON::XS->newしてた部分を->utf8つけたのだけどmasterではなく別ブランチにpushしてしまっていて、それに気付かずまだベンチがこけ続けるので悩む、という凡ミスで30分くらいロスしてしまった orz
これで11000くらいまで上がり、続いてsongmuさんの足あと対策をmerge。これまたベンチがこけ… 何が間違っているんだ？と3人でアレコレ調査。結果的にはsongmuさんがロジックのミスに気付いて修正されて、1時間くらいかかったけど無事に解決。17時半で12000点台に。
これらによって初期データからキャッシュを作っておく初期化処理が30秒で終わらなくなってしまったけど、ベンチマークごとに変わるものではなくデータセットとして用意してあれば良いだけのもの、ということでまずは別のエンドポイントで初期データを作るようにしてベンチマーク時には既に初期キャッシュがある状態にしておいて、その後でfujiwaraさんによってaofファイルから復元することで数秒でinitializeが終わるよう解決されて、そこについて悩む必要なくて安心して使うことができました。
夕方(さらなる最適化)
ここらへんでようやく、毎回ユーザー情報をSELECTする処理がボトルネックになってきているね、ということになり これも初期化時に全部ユーザー情報をRedisに突っ込んでMySQLには行かないように変更。ここでまたバグを埋め込んでしまいFAILして焦ったけど、ここは比較的すぐに解決して18時過ぎに17000点台に。
ここまでくると今度はMySQLよりRedisの方が負荷が高くなっている、とfujiwaraさんに素早く指摘していただき、毎回Redisから引くのではなくアプリ側でもメモリに保持しておいて 無かったら引く、とやるようにしたら songmuさんによるクエリ最適化も効いて一気に26000点台まで上がった。18時20分頃。
もうちょっと 最近の自分の日記一覧とかも何故か降順でなく昇順で5件だしてるだけだからキャッシュして問題ないよね、とかも書いてpull requestまでは作ったけどミスっていたのと流石に時間が無くなってきているのでコード変更はここまでにしよう、と決断。あとは再起動テストしてみたり最後の確認をするfujiwaraさんの作業を見守って、競技時間終了。
まとめ
実際に作業したリポジトリは以下で公開してあります。
80 commits, 20 pull requests.
時系列のスコア遷移( fujiwaraさん記事 からのコピペ):
timestamp score 11:41:25 305 12:03:33 0 FAIL: 12:08:14 587 12:18:27 1333 < indexを2個足した (fujiwara) 12:24:22 0 FAIL: 12:27:22 1888 < my.cnf調整(fujiwara) 12:31:27 1672 12:52:11 2008 < Gazelleに入れ替え (fujiwara) 13:47:38 2832 < entriesからtitleカラムを分離(sugyan, fujiwara) 13:49:24 2867 13:52:20 5206 < entriesから1000件取ってるのをなくす(sugyan) 13:58:35 5500 14:03:53 9353 < relationsから or を削った(songmu) 14:37:46 9593 15:05:11 20 FAIL: 15:08:00 10009 15:15:17 10092 15:25:29 10137 15:30:49 0 FAIL: 15:36:53 10138 16:27:23 11247 < comments_for_meをredisのlistに(sugyan) 16:43:50 17 FAIL: 16:48:45 17 FAIL: 16:58:10 17 FAIL: 17:04:20 17 FAIL: 17:39:28 12389 < footprintをredisのsorted setに(songmu) 17:47:06 0 FAIL: 18:01:09 17039 < userをmysqlではなくredisから読む(sugyan)、3回相手の属性調べてたのを一発に(songmu) 18:11:22 16402 18:16:07 18193 < / でコメント10件毎回entriesを取得していたのをwhere inに(songmu) 18:23:54 26338 < redisから引いたuserをプロセスのメモリにcache(sugyan) 18:30:44 26153 < initializeでaofからredisを初期化(fujiwara) 18:40:11 26694 18:42:59 27232 < 再起動試験後の最終提出スコア
とにかく3人で上手く作業分担できたのが良かったな、と思います。常にfujiwaraさんが素早く的確にボトルネックを指摘してくれていたので、「何をすればいいか」に悩むことなくひたすら手を動かし続けることができました。songmuさんともお互いどれくらいのコード変更が出来るかだいたい把握できていたので分担もスムーズに出来たと思うし、pull requestベースでのコードレビューもある程度機能しつつ進められた(結局レビューしていてもバグっていたり、とかはあったけど…ｗ)。最終的には手戻りするようなこともなく無駄な作業というのはほとんど無かった。
それにしてもボトルネックの指摘もだけど ALTER TABLEを別のインスタンスでやる、とかRedisの初期状態をサクっと作ったり、とかは僕だったらまったく思いつかずに完全に詰んでしまっていたと思うので、こういうのを素早く解決してくれる人が居るというのは本当に心強くて最高だ、と思います。
反省点としてはやっぱりバグを生んでしまってベンチマークがFAILしたときになかなか原因を発見できず時間をロスしてしまったこと、ここはもっと落ち着いて素早く解決できるようにならなければ、と思いました。
あとコード変更はすべてローカルでやってたわけですが今回の問題だとmysqldumpも重くて初期データセットをローカルまで持ってくることもできず 変更に対する動作確認はsyntax error無くアプリが起動する、くらいで「これで動く、はず」みたいになってしまったのはもうちょっとどうにかしたかったなぁ、と。
イチ抜けでの通過はできなかったものの、最終的な記録としては2日通しての最高スコアで予選通過できたのは嬉しい。本選も良い成績を残せるよう頑張りたいと思います。
とてもやり甲斐あって楽しい予選でした。問題を用意してくださった運営陣の皆様、おつかれさまでした&ありがとうございました。
本選もよろしくお願いします！
