isucon8本戦に参加してきた - nakarioのほぼISUCONブログ

昨年に引き続きISUCON予選を突破した。去年はたまたま出場できた感が強かったけど、今回は結果的に学生枠２位で通ったのでちょっと自信は芽生えた。

ISUCONでの自分の役割はアプリケーション(Go)。去年は本当にコード書くしかできなかったけど、過去問を解きまくったのでデータベースも基本的な知識はついて全面的にロジックの改修はできるようになった。

競技開始まで

前日の新幹線の運行停止に巻き込まれたりしたものの、無事東京に到着して起床も成功。

開場前に会場に到着していい席を確保したあとは、Wi-Fiの設定したりリポジトリ作成したりKMCから同じく参加した別チームと談笑するなどして時間を潰した。

isuconやっていき pic.twitter.com/2DXbXTs8tE
— nakario (@nakario_jp) 2018年10月20日

準備も万端で時間の余裕もあり緊張がほぐれてきたくらいで競技開始時間。
去年も思ったけどISUCONはオープニングがすごく凝っててモチベめっちゃあがった。

問題の詳細は公式参照。

競技中のログ

開始〜11時：Dockerの操作に慣れておらずアクセスログやスロークエリログ、フレームグラフの生成にとまどる。
チームメイトのmurataがコンテナに入って無理やりフレームグラフを取ってくれたのでそれを確認。
f:id:nakario_jp:20181027220646p:plain
GET /infoが処理時間の大半を占めているため、ここを調査。
よく読まなくても無駄にtradeを取ってきているのがわかったので、LIMIT 1を追加したら一気に5000点を突破して一位に躍り出た(数百点差で別の学生チームがいたので単にガチャに勝ったっぽい)。ここが当日のハイライト。

11時〜13時：Dockerに阻まれて色々データが取れないのでどこがネックになっているのか把握できず、とりあえずフレームグラフからログイン処理内の暗号化が重いようなのでTODOに書かれているBAN機能を実装することに。
(たぶんこの時点でCPU使用率が90%切ってたはずで、アプリケーションがネックでないので判断ミス)
実装できたもののスコア改善せず。

13時〜16時：この頃にはmurataとaokabiがDocker全排除に成功していたのでスロークエリログを確認すると、ローソク足の生成のための集計に時間がかかってるようだったので、別テーブルに予め計算結果を保存しておくことに。ここもCPUネック処理なので判断ミス。
明らかに遅そうなSQLだったのと解決策をサクッと思いついてしまったので食いついてしまった(その割に実装に時間がかかったのはcreated_atとSTR_TO_DATE(DATE_FORMAT(created_at, '%Y-%m-%d %H:%i:%s'), '%Y-%m-%d %H:%i:%s')の違いで一秒ズレたりズレなかったりするバグの解決に時間がかかったから)。

16時〜18時：htopを見てCPUネックじゃないことに気づく。過去の経験からデータベースのロックだと決めつけてしまった(判断ミス)。スロークエリログにも総ロック時間がとても長いクエリがあったため競技終了まで勘違いに気づけなかった。
その問題のロックが長いクエリというのが椅子のトレード関連のもので、トレードのロジックがめちゃ難しかったので途方に暮れている間に競技終了。雑にN+1を解消しようともしたけどバグが治りきらなかった。

反省点

もろもろの計測環境が整う前に方針を決めてしまってるのでかなり時間を無駄にしている。特別賞に目が眩んだというのはある。
計測環境が整ってからも全体の情報を見ていないため、一つのソースから間違った判断をし続けてしまった。
レギュレーション(仕様書)の読み込みが甘い。バルク送信は完全に気づいてなかった。ログの欠損のエラーが出たときもトレードに時間がかかりすぎているのが原因と(何故か)思い込んでた。
チームメンバーが詰まってたり非効率的なことをしてそうな時の声かけが(去年よりはできてたものの)足りなかった。

SNSシェア機能には気づいていたものの、ALL or NOTHINGだと思ってたので10%だけ有効化するみたいなのはどっちみち思いつかなかったと思う。これは反省というよりも普段からABテストみたいな経験を積んでるかどうかの違いかと。

感想

去年に比べて成長しているものの、まだまだできることがあるなぁというのが大きい。ISUCONは奥が深い……。
学生なので交通費＋宿泊費もでるし昼夜のご飯も食べられるし、マジで最高のイベント。
運営＆協賛の皆様、お疲れ様でした＆ありがとうございました！