Zenn
😭

ISUCON12 に初出場してほぼ初期スコアフィニッシュという話

2022/07/24に公開
ISUCON
ISUCON12
idea

2022/7/23(土) ISUCON12 予選 に初出場した記録。
チーム名「元同僚_最新_最終版コピー(2)_old決定版.xlsx」
最終スコア 3160 (Go実装)

TL;DR

  • Ruby で挑戦
    • 何も手を入れてない時点のスコアが 900〜1400 くらい
  • 14:00 SQLite → MySQL の移行を決断
    • 移行できたと思った後のベンチでデータチェックが通らず 17:30頃捨てる
    • 翌日の予選スコア発表後に見直してみると 2.db 〜 100.db が移行できてなかった
  • 17:40 @VTRyo がほぼ１人で作業してたサーバー3 を最終スコアにすることに
    • スコア 1600〜1999 ぐらい
  • 17:45 「これなら Go 実装の方が早いんじゃね？」つって 何もしてない Go実装 に切り替える
    • スコア 3000 ぐらい
  • 17:52 visit_history テーブルにインデックスを貼る
  • 17:57 ベンチ2回回してスコア 3160 を記録したのでフィニッシュ

チームメンバーのエントリ

https://blog.vtryo.me/entry/entry-isucon12

さて完走した感想ですが（激ウマギャグ）

  • 楽しかったが、絶望感がすごい
  • バックエンド専門で、もう20年近くキャリアあるけど僕はポンコツでした
    • 激ウマギャグとか書いてるけど、こういう逃げをしないと屈辱感で頭おかしくなりそう
  • SQLite → MySQL 移行は完遂したかった
  • 来年も同じチームで戦いたいので戦力外通告されないためにもゼロからやり直す

記録ある限りの当日タイムライン

commit 履歴や Slack のやりとりログと記憶からできる限り詳細に記載
時間がある程度経った後にも振り返られるよう細かめに当日タイムラインを書き上げた

競技開始前

  • 8:00 起床 実は自分の起床にかなり懸念してたので一安心。早く寝るの大事
  • 9:20 メンバー集合完了
  • 9:30 メンバーのローカル Ruby のバージョン合わせ完了 (ruby 3.1.2p20）
  • 9:40 Discord 音声通話開始
  • 10:00 競技開始

10:00〜14:00 の SQLite→MySQL意思決定まで

  • 10:00 マニュアル読み合わせ
  • 10:10 @dyoshikawa1993 が CloudFormation 実行
  • 10:20 起動したサーバーに SSH 確認OK、sudo vim /etc/hosts を編集してブラウザアクセス確認OK
    • アプリのコードを見始める
    • 曖昧だけど、この辺りで割と早期にローカル環境構築諦める判断した記憶がある
  • 10:28 @VTRyo が3台分の git init 完了、各種計測ツール導入開始
    • @VTRyo が事前に各種計測ツールの導入スニペットを用意してあった
    • マニュアル不備があり 11:40 頃当日質問回答に root ユーザの id pass が共有されるのだが、なぜか @VTRyo はこの時点で MySQL root ユーザにログインしてる
      • @VTRyo「どうせ root / root だろと思ってやってみたらいけた」
  • 10:40 Ruby 実装に切り替えて初回ベンチ実行 SCORE: 1668 (+1668 0(0%))
  • 10:42 GitHub に 初回 commit push
  • 10:55 ベンチ回しながら計測開始、alpの微調整など実施
  • 10:58 この時点で /home/isucon/initial_data に 1.db〜100.db　っていうファイルがあることに気づくが、これらのファイルが何なのかはまだ気づいてない
  • 11:10 @dyoshikawa1993 が正規表現alpのログ潰せそうなAPIエンドポイントを調整
  • 11:15 alpの結果がかなり見やすくなる
    • Slackで ぼく「うおおお最高www」 って言ってるのでこの時点ではかなり元気
    • @VTRyo がalp結果の AVG と P99 の違いについて教えてくれる
  • 11:20 @dyoshikawa1993 が /api/player/competition/:competition_id/ranking を、ぼくが /api/organizer/billing の調整に取りかかる
  • 11:42 rack-mini-profiler と rack-lineprof を入れる準備だけする
    • 結果的に競技時間中には使わなかった（使うところまでいけなかった）
  • 11:50 このあたりでチームの集中力がMAXになったような一体感を感じる
    • 練習してたことをやれてる感覚というか
    • @VTRyo「11時48分: 祭り化してきた」って言ってるログがある
  • 12:05 @dyoshikawa1993 がローカルMySQLWorkbench から　TCP/IP over SSH で接続できるようにする
  • 12:10 このあたりで sql/admin/10_schema.sql　や sql/tenant/10_schema.sql を変更しても Schema が変わらないことに気づく。
    • sql/init.sh を確認し始める
    • sql/init.sql　で範囲削除してるので単純に DROP TABLE するとおかしくなりそうって気づく
    • @dyoshikawa1993 が gitignore されてる sql/admin/90_data.sql に気づく
  • 12:15 SQLite に気づく
    • def connect_to_tenant_db と flock_by_tenant_id の衝撃をうけとめきれない
  • 12:30 このあたりでローカル開発を諦めてる結果、同時作業が困難であることに気づく
    • @dyoshikawa1993 が1台目、ぼくはサーバー2台目、@VTRyo が3台目で作業をはじめる
  • 12:53 @VTRyo が Redis 動いてることに気づく
  • 12:54 @VTRyo が docker のログみるコマンドを作ってくれる
docker logs -f `docker ps | grep webapp | awk '{print $1}'`
  • 12:55 @VTRyo が Netdata をみれるようにしてくれる
    • @VTRyo が　Disk Write の重さに気づく
    • 結果的にぼくは　Netdata を、ほとんど見れてないので猛省
  • 13:00 sinatra で puts できない、app.rb を編集しても反映されないみたいな話をする
    • サーバー再起動で対処できるのでそれで戦うことにする
  • 13:15 ぼくはサーバー2で作業してたが git pull できないことに気づく、できるようにする
  • 13:34 @VTRyo がマニュアルのスコア計算を改めて確認、チームに展開
  • 13:38 この時点では 11:20時点で取り掛かったエンドポイントの対処をまだやってたみたい
  • 14:00 時間的に折り返し地点だが、SQLite→MySQL をやろう！と決める
    • 話ししたことは以下だったと思う
      • SQLite の知見がなさすぎて、SQLite のままだと計測もチューニングもできない
        • インデックス貼ることもできない
          • CREATE TABLE で INDEX を持つようにしても 1.db〜100.db に INDEX は適用されない
        • どうやってレコードを確認するかもわからない
        • この時点ではまだ 1.db〜100.db は物理 dump ファイルだと思っていた
      • 移行しろという意志をコードの節々から感じる
        • SQLite はマルチテナント的なのに WHERE tenant_id = ? が既に仕込まれている
        • sqlite3-to-sql というスクリプトがある

14:00〜17:30 の SQLite→MySQL の破棄まで

  • 14:00 SQLite→MySQL意思決定直後から @dyoshikawa1993 が 移行作業に取り掛かる

  • 14:19 ぼくがやってた /api/organizer/billing のチューニングがベンチ回してもなんの成果もないので作業を切り上げる

  • 14:39 @dyoshikawa1993 が sql/init.sh の改修を終え SQLite→MySQL のデータ投入を開始する

  • 14:43 ぼくは /api/player/player/:player_id のチューニングに取り掛かる

  • 14:48 当日ポータルの質疑で以下みたいなやりとりがあり、tenant などの初期データ投入は 90_data.sql で間違いないみたいな話をする。実際にデータ消して sql/admin/90_data.sql 実行してベンチコケないことも確認する。

  • 15:05 SQLite→MySQL のデータ投入が全然終わらんみたいな話になり、sqlite3-to-sql というスクリプトで作ったクエリは1行ずつ INSERT してるので bulk insert にしなきゃみたいな話をする

    • ぼくはサーバー2で bulk insert 化に取り掛かる

  • 15:07 3時間きって焦燥感がヤバいことになり始めた記憶がある

  • 15:10 ローカル環境を作らない判断をしたのもあり、 app.rb の変更をうまくできなくなってくる

    • racksh 入れるかみたいな話をするが bundle install できないのが解決できない

  • 15:23 @VTRyo「仕事よりきついです」

    • ぼく「わかる」

  • 15:51 この辺で sql/admin/90_data.sql の .gitignore を外したからかサーバー１からの GitHub push ができなくなる

    • ERROR 1153 (08S01) at line 1: Got a packet bigger than 'max_allowed_packet' bytes

  • 16:00 ぼくはまだ bulk insert 化しようとしてる

    • sed でがんばろうとしてた

  • 16:02 @VTRyo がサーバー3で app.rb のチューニングをやり続ける

    • def billing_report_by_competition の player_count のカウントアップをどうにかしたいが何も思いつかない気持ちになる
    • bulk insert 化もできないしアプリのチューニングもなんもできないので、今思うとぼくは完全にパニック？になってた気がするこの時間帯

  • 16:20 @dyoshikawa1993 が bulk insert 化する node script 書けたのでSQLite→MySQL のデータ投入をそっちに切り替える。1時間半かけても終わってなかった投入が数分で終わった気がする

    • ので結局ぼくは 15:00〜16:20 で何の成果も出せてない

  • 16:30 @dyoshikawa1993 がサーバー1で SQLite→MySQL 移行の app.rb 編集をブラウザから動作確認しながらひたすら実施

    • ぼくも相談乗ったりするけどコードの同時編集してるわけでもないのでほぼ何もできなかった記憶だけある
    • 修正してベンチ回すがデータ検証が通らない。。。
    • 終了直前のベンチ回してる時に MySQL のデータをみたが tenant_id が 1 のデータしか player テーブルなどになかったので、 2.db 以降のデータ移行できてなかったぽいが、この時点では気づけなかったのでベンチ落ちの理由が特定できなかった

  • 16:51 def dispense_id をどうにかしようとする

    • @VTRyo が SecureRandom 使っていけるんじゃねって閃いたので採用
    • しかしベンチが通らず。。。 SCORE: 0

  • 17:17 @VTRyo が def dispense_id の SecureRandom をやめて 100.times do を 2.times do にしてサーバー3のスコアちょっと上げる

  • 17:20 この辺で 17:30 まででサーバー１のベンチ終わらなかったらサーバー3を最終スコアにしようという話になる

17:30〜18:00 の競技終了まで

  • 17:30 無常にもベンチ通らず 17:30 になる。 @VTRyo が各種計測ツールの削除や環境戻しをサーバー1〜3 に実施
    • env-checkerに引っかかって失格になるから戻せ 的なことを実施してくれた
    • このあたりちゃんとマニュアル読んで戻す予定組み込んでた @VTRyo さすがすぎた
  • 17:40 @VTRyo がほぼ１人で作業してたサーバー3で最終ベンチを回し始める。 SCORE: 1999
  • 17:45 「ほとんど初期状態なんだから、RubyじゃなくてGoに切り替えてベンチ回したほうがスコア上がるんじゃね」
    • 初期から何もしてない Goサンプル実装 に切り替えてベンチを回す SCORE: 3000
  • 17:52 サーバー3の visit_history テーブルにインデックスを貼る
  • 17:57 ベンチ2回回してスコア 3160 を記録したのでフィニッシュにする
  • 18:00 競技終了

当日の感想

反省

  • 8時間取り組んだ Ruby サンプル実装を改善したアプリよりも、Goサンプル実装の方がスコアが高いとか信じられるか……？
    • 現実を受け止められない
  • bundle install できないのわからなかったの無念すぎる
  • N.db のMySQL投入のバルク変換に1時間以上かけて何もできないのはダメすぎ。できないならできないって言おう
    • もっと sed や awk のスキル高めてホラ
  • SQLite→MySQL移行しきれなかった無念さはやばい
  • タイムラインみたらわかるけど、ぼく @JUNKI555 はほぼ何もやってない
    • commit も 8時間で2個しかない
    • 途中から二人の作業を眺めるだけになっちゃった。。。
  • とはいえ GitHub に細かく commit して共有しつつをできたのか
    • zoom の画面操作でやるのがよかったのかも
    • 16:30〜 @dyoshikawa1993 がやってくれてた SQLite→MySQL 移行の app.rb 編集 を手分けしたかったのはかなりある
    • どうすればよかったのか
  • 無念
  • ローカル作れなかったし、SQLite→MySQL移行にリソース突っ込むんじゃなくて3人それぞれ別のことをした方が良かったのかも
  • SQLite→MySQL移行やりきりたかった。これに尽きる

よかったこと

  • かなり楽しかった
    • 当日までの、当日までの練習もよかった
  • SQLite使ってるのにかなり早期に気づけはしたのはよかった
    • 気づかない可能性さえあった

翌日時点での、もっとどうすればよかったか

※翌日時点でのぼくの１人の考えなので、今後チームで話し合って考えが変わる可能性もある
※時間がある程度経った後にも振り返られるよう細かめに当日タイムラインを書き上げた

もっと早い段階で Goベンチを回しておいてもよかった

-　競技開始時点で Goサンプル実装なら何点、Rubyサンプル実装なら何点 がわかってたら 14:00時点の判断も変わってたかもしれない

僕たちの目標はなんだったのか

  • 初参加で本戦に出るぞが目標なのか
    • これが目標なら SQLite→MySQL移行の判断も間違いではなかったかもしれない
  • 1点でも多く取った結果が本戦出場につながればいいのか
    • これが目標なら SQLite→MySQL移行の判断は完全に間違い
  • 目標もなしに振り返りとな

ISUCON運営「本選で会いたくなった時にお使いください」

当日何をやって行くのかの認識合わせができてないまま当日を迎えてしまった

  • @VTRyo が Netdata を見れるようにする準備をしてくれてることも、ぼくは把握できてなかった
  • 練習中寝てたのかと言われても反論できないレベルの失態なので　ぼく=@JUNKI555 は猛省すること
    • はい……

ISUCON運営「お茶を汲むくらいしか出来ることがない時にお使いください」

SQLite→MySQL移行の判断は正しかったのか

  • 結果論だが、やりきれなかった以上は移行を決めたのは間違いだったということになる
    • ただ、繰り返しになるがこれは目標次第で判断すべきことのはず
  • 目の前にぶら下げられたデカい餌に抗えなかった
  • 普段やってないことは本番ではできないを守れなかった
    • やったことないことを本番に突然全力を尽くそうとしても難しい
  • 競技終了後の参加者による Discord After Party での話などを踏まえると、以下のような対応をしたチームもあった模様
    • 新しいテナントの分だけ MySQL に移行（1.db〜100.db まではそのまま）
    • SQLiteを残したまま Read をCache化
    • 一部分だけ移行
  • 移行するにしても、一気に全部やらない判断をできなかったのは厳しい
    • 小さく試すのは基本
  • SQLite→MySQL移行でどれぐらい良くなるかの試算もなしに判断してしまった
  • というかSQLiteなのがどいう影響を及ぼしているのかも整理しきれてなかった
    • SQLite 使ってるところがアプリのどこに影響してるのかもぼくは把握しないまま作業を進めてしまったかもしれないレベル
  • つまり推測で作業を進めてしまった

ISUCON運営「計測が必要な時にお使いください」

SQLiteを調べようとしたのか

  • しなかった
    • 焦りすぎた
    • SQLite ってなんだよォ！？　という気持ちが強すぎた
  • 翌日のスコア確定後の頭がクリアな状態で考えてみたら、sqlite3 コマンドでクエリ発行できるじゃんとなってこれをやっていればデータ移行で欠損が出てることもすぐ気づいたはず
    • 1.db などが dump ではなく、これらが SQLite のDBそのものであることも気づけたはず

（スコア確定後にこれに気づくのは遅すぎ）

最後に

  • ISUCON は存在は知ってたが存在を知ってる程度の認知レベルだった
    • こんなに感情を揺さぶられるコンテンツだったとは
    • 誘ってくれた @VTRyo ありがとう
  • 一緒に戦ってくれた @VTRyo, @dyoshikawa1993 ありがとう
  • 来年も戦おう
    • ぼく もっと強くなります
  • 本戦出場の皆さん頑張ってください！
  • 主催、出題、運営の皆さん素晴らしいコンテンツをありがとうございます

https://twitter.com/JUNKI555/status/1550774569451286528?s=20&t=chxi6QGCWyV5SpqPI4D--A

  • ISUCON12 予選 参加者の皆さん、対戦ありがとうございました

https://twitter.com/JUNKI555/status/1550768780854185984?s=20&t=chxi6QGCWyV5SpqPI4D--A

メモ：当日夜にfacebookへ投稿してた感想

今日は ISUCON 12 予選 に参加してきました。

ISUCON とは簡単にいうと「全日本Webアプリケーション高速化大会」みたいなもので、
大会ごとに異なる問題（なんらかの、高速化が必要なWebアプリケーション）について
3人1チームで高速化に取り組んで、8時間の競技時間の中でどこまで高速化できるかを競う大会です。
2年ぐらい前に一緒に働いてた元同僚2人と僕の3人で参加しました。

予選の結果発表は明日なのですが、結果発表を待つまでもなく結果は惨敗で、
自分の力不足が身に染みました。

ただ、大会までのチームで集まって行う練習や大会当日に過ごす8時間は濃密で、とても楽しかったです。

gloopsにいた人には
「障害起きて超遅延起きてるコンテンツをみんなでアレコレ言いながら修正してどうにかする数時間」の
あの感覚を競技として味わえる、といえば伝わるのではないでしょうか（笑）
ただ、負けにもいい面はあって、
経験を重ねると「得意分野で全力を出したのに全く歯がたたない」という経験がなかなかできないが、
それが得られるのはいいことだなと感じました。

ISUCON 12 予選 終了後のアフターパーティでは他の参加者の皆さんのお話も色々聞けたのですが、
上位チームの方でも
「もっとこうできたはず」「こうすればよかった」「あそこはどう判断すればよかったのか」というような話が出ていて、
みんながもっと上を目指そうとする素晴らしい場だなと、身の引き締まる思いです。

とはいえ勝てることに越したことはないので、次の大会に向けてまた勉強しなおします💪
ISUCON 主催の企業や運営、出題担当の方々本当にありがとうございます。
本戦出場の皆さんは来月も頑張ってください！ #ISUCON

Discussion