かきあげせいろはラーメンがたべたい

技術プログラミングいろいろ記録メモ備忘にゃーん！

ISUCON13に参加しました！

去年に引き続き今年参加しました！ 今回は初回申し込みで開始ちょうどの10:00時点ですでに参加上限に達したことでエントリー出来ませんでした。

絶対に参加したい気持ちと、前回は学びの宝庫だったこともあり応援したいイベントなので、個人スポンサーとして参加しました。(個人スポンサーはプランによっては参加権がついてくるのです)

また、今回は初期実装で自分が慣れているJavaが存在しないのでGoで参加することにしました。

去年の参加ブログ

自分の知識レベル

  • 普段はJavaでバックエンド。たまにVueでフロントエンドを書く仕事をしています。
  • Goは数年前に入門書をよんでちょっと動かしてみた程度。
  • インフラに触る機会はここ一年で一度なく、エンジニア人生でもデプロイのためにちょこっとEC2を触る程度です。
  • EC2などの簡単なAWSサービスはプライベートで環境をつくったりアプリを動かしてみたりしたことがあります。
  • 自動スケールするようなモダンなサービスもチュートリアル程度ならさわったことがあります。
  • 自分の業務/プロダクトでモダンなサービスを適切に導入できそうか。と言われると自信がないです。

事前準備

前回参加時はとにかく広範囲の知識・経験が足りていないことが強く印象にのこっていたので、ISUCON本を最初から読み直し、本に付属の課題であるprivate-isuで素振り(実際に問題のパフォーマンスチューニングをやってみること)を3週し、ISUNARABEという有志の方が作成してくれた過去のISUCON環境を簡単に構築できるサービスで、ISUCON12を1週しました。

これらの練習時に共通で必要になるであろう手順のメモを、自分自身のチートシートとし育てていきました。これは同じ手順でも、少し環境が変わるだけで

また、練習時に実施した内容も残さずメモしました。

当日やったこと

  • 10:00
  • 10:35
    • CloudFormationで環境構築
      • 10:40 EIPが足りない旨のエラーが出たので、素振りで使っていた別のCloudFormationのリソース達を全部削除
    • hostsファイルにpipe.u.isucon.devを記述
  • 10:43
    • アプリケーションの画面確認
    • EC2インスタンス3台にsshできること確認
    • 最初のベンチ→スコア3000ぐらい
      • 3台すべてでtopした→2台目にしか負荷がかかっていない&MySQLの負荷が高いので、2台目MySQLから手を付けることを決定
  • 10:52
    • alpインストール
      • log形式が変更されない事象発生
        • 画面は1番目のサーバーにアクセスしていた
          • hostsに書いたアドレスが1番目のアドレスだったため
  • 11:04
    • nginxのログローテートのシェル作成(準備していたのでコピペ)
  • 11:07
    • MySQLスロークエリログ有効化
    • バイナリログの設定に気付いたが、複数のことを一度にしたくないので一旦放置
    • pt-query-digestとquery-digesterもインストール
  • 11:15
    • MySQLのテーブル構成確認
  • 11:20
    • alpとquery-digesterの結果をみるためにベンチ
  • 11:22
    • IDEでGoを書くためにIntellijのプロジェクトを作る
  • 11:23
    • query-digesterの結果が長すぎる(長いSQLがある)のでcatで表示しきれない→tailの逆であるheadの存在をしらなかったのでググって知る
  • 11:28
    • query-digesterの１位livestream_tagsテーブルに対してindexを張る
      • ALTER TABLE livestream_tags ADD INDEX livestream_id_idx(livestream_id DESC);
        • あとでSQL側にLimitをつけてもっと高速化出来そうなのでDESCにした
          • ライブは最近のもののほうがアクセスされやすいと考えた
    • EXPLAINでindexを使うようになったことを確認
  • 11:35
    • ベンチ→スコア4390(改善によって+1300された)
    • topでMySQLの負荷が減ったが、まだアプリより高いことを確認
    • ベンチ走行中に2番目のクエリの改善を考え始める
  • 11:39
    • icon画像を静的ファイルにしたいが、時間がかかりそうなチューニングなので一旦index張るだけにする
      • ALTER TABLE icons ADD INDEX user_id_idx(user_id);
  • 11:41
    • ベンチ→5583(+1200)
  • 11:43
    • プリペアドステートメントを消す
    • やりかたを暗記していないのでISUCON本とその課題を素振りしたprivate-isuを参照する
    • Goでsqlx.Open("mysql", conf.FormatDSN())部分をsqlx.Open("mysql", conf.FormatDSN()+"?interpolateParams=true")に変更
    • 11:47 サーバー上でgit initだけする
      • git diffで差分が表示されないことに気付く
      • git init後にaddとcommitしていないことに気付く
    • 11:51 Goの変更を反映する方法を調べる
      • Makefileを見る
      • DockerFileをみる
      • これらを見てもよくわからないので全部ChatGPTに食べさせてどうすればGoの反映が出来るかを聞いた
        • make buildコマンドすればよいことがわかった
          • 実行ファイルっぽいやつのファイルサイズが変わったことで成功と判断
    • 11:54 マニュアルに記載されていたenvチェックをやっていないことに気付いたのでやった
    • 11:56 systemctl restartする
      • systemctl statusでサービスがloadedになり、activeにならない
        • Activeまで数秒かかるだけだったみたい
    • 12:00 ベンチ
      • initializeへのリクエストで502発生
    • initializeの処理を見に行く
    • ログを出力した行を特定したいのでsyslogを見る
      • 出力されておらず、systemctl statusでloadedに戻っていることに気付く
      • Goの起動時にこけたと考える
    • 12:10 sqlxのセットアップ時とかにこけたのかもと考え、プリペアドステートメントの設定指定方法を間違えたかと思いprivate-isuで同じことをしている部分を確認する
      • 接続文字列をログ出力する実装にする
    • 12:14 systemctl restartでactiveにならないことに気付く
    • 12:16 systemctl statusでactiveになったことに確認
      • 悩む
      • restartするまえにmake buildした時点でsystemctl restartに相当する処理が行われているように見える
        • 適当にGoを書き換えてmake buildしてみる
          • systemctl statusで再起動していないことを確認
      • loadedとactiveを繰り返していることに気付く
        • 起動した時間が数秒で、5秒程度で再起動を繰り返していることに気付く
      • 12:51 Goの変更ないようを戻してmake buildとsystemctl restartしてみる
        • systemctl statusでアプリが再起動していることを確認する
        • 実装が悪いことが判明
    • 12:52 再度Goにプリペアドステートメント無効の設定を入れる
      • ログは出すようにする
      • isucon:isucon@tcp(127.0.0.1:3306)/isuphipe?parseTime=true?interpolateParams=true
      • ?が二つついていることに気付く
      • &にしてmake buildしてsystemctl restart
      • systemctl statusで起動成功している
    • 12:56 ベンチ→6700(+1100)
  • 13:01
    • 指定したライブのスコア合計しているクエリが1位
    • ALTER TABLE livecomments ADD INDEX livestream_id_idx(livestream_id DESC);
    • ベンチ→6758(+58)
      • たいして変わっていないことに疑問を持つ
      • ベンチは上がらないが、query-digesterでは順位がさがったので一旦よしとする
  • 13:17
    • ユーザー指定でテーマ取得時のクエリが1位
    • ALTER TABLE themes ADD INDEX user_id_idx(user_id);
    • ベンチ→7884(+1126)
  • 13:25
    • /iconが重いが/initializeが1回呼出しで9秒もかかっていることが気になり、こちらを改善することにする
    • データ作成部分の大量のinsertが遅そうなのでバイナリログをOFF
    • ベンチ→8299
    • /initializeが1秒になる
  • 13:45
    • ユーザー指定でライブあたりのチップ合計するクエリが1位
    • ALTER TABLE livecomments ADD INDEX livestream_tip_idx (livestream_id, tip);
    • ベンチ→8282
    • query-digesterでも合計時間があんまり変わらず
    • show profileしてみるとexecuteが一番時間がかかっている。indexを外しても変化がない
    • ChatGPTに聞いてみたらIFNULL()よりCOALESCE()のほうが速いというのでやってみた
    • 効果が見られないのでINDEXをDROP、IFNULL()に戻す
  • 14:30
    • ベンチがwaitingになるので待ち
  • 14:40
    • ライブあたりのリアクション数のクエリが2位
    • whereを狙ったindexを作る
      • ALTER TABLE reactions ADD INDEX livestream_id_idx (livestream_id);
    • 効果が見られないのでINDEXをDROP
  • 14:49
    • SELECT content,ttl,prio,type,domain_id,disabled,name,auth FROM records WHERE disabled=0 and name='*.u.isucon.dev' and domain_id=2;が3位
    • disabledはカーディナリティ低過ぎで意味なさそうなので無視する
    • ALTER TABLE records ADD INDEX domain_id_idx (domain_id);
    • EXPLAINでdomain_id_idxが使われない
    • FORCE INDEXにしてみても単発のSQLではexec timeが変わらなかった
    • domain_idもカーディナリティが低いことが判明
    • domain_id_idxをDROP
    • nameは色々あるみたいなのでnameにindex張る
    • ALTER TABLE records ADD INDEX name_idx (name);
    • ベンチ→変わらず
  • 15:07
    • 集計APIの/statisticsが重い
    • リアクション数とチップの合計をライブごとに集計する処理がN+1
    • 一発で全てJOINするように変更
    • ベンチ→変わらず
    • /statisticsが数回しか呼ばれていないことに気付く
    • query-digesterからは順位が下がった
  • 15:40
    • /iconで静的ファイル化しようとする
    • ISUCON本を参照
    • private-isuの実装をコピペ
    • nginx設定ファイル/etc/nginx/sites-available/default書き換え
      • /iconへのリクエストは静的ファイル用ディレクトリに向けtry_files $uri @app;で静的ファイルがない場合は普通のリクエストにするように
    • 16:22 ベンチ→整合性チェックで失敗。/livestream/reservationで500発生
      • ファイルアクセス時にpermission deniedしてる
      • chmod 777
    • 16:37 ベンチ→iconを更新するとicon_hashが新しくなってない
    • 16:45 ベンチ→アイコン未設定の場合はデフォルト画像のハッシュ値を返さなければならないエラー
    • 17:21 ベンチ→新たに設定したアイコンが反映されていないエラー
      • 画面であらたなアイコン画像を設定するも、デフォルトの画像になってしまう
    • 17:52 画面でアイコンを差し替えられるようになった
    • 17:54 ベンチ→7289
    • もういちどベンチ→アイコン未設定の場合はデフォルト画像のハッシュ値を返さなければならないエラー
      • 静的ファイルとして格納しているディレクトリに、前回ベンチの画像が残ることが原因と考え、削除しベンチすると通ることを確認
    • 17:57 init.shがベンチの最初に/initializeから叩かれることは分かっていたので、shの最後にrmコマンドを追記
      • 静的ファイルを削除
      • ベンチ→/initializeが500になる
  • 18:00
    • 競技終了

というわけで最終スコアはエラーが残っているため0点でした…

点数の遷移

ふりかえり

Keep

  • 画面をつかって小さく原因特定できた
  • セットアップ(環境構築・マニュアル読み・計測ツールインストール)は自分の最高速をだせた
  • ChatGPTを有効に使えている(Goの実装を聞く→ググって検証→やってみて確認)
  • わからない技術要素はバッサリ切り捨てた。PowerDNSなど
  • 設定ファイルの場所で迷わなかった
  • Lixuxの使い方がスムーズ(ctrl+r・Vim・ログ確認)
  • 動画を撮った(ふりかえりの密度が去年より充実)
    • 動画は画面キャプチャの方が画質的によかったかも
      • Macの負荷はどうなんだろうか
      • それはそれとしてスマホでも取っておくと、声が入るので良いか
  • NginxやMySQLの設定は素振り時と比較して問題なさそうであることを判断した
    • 結果的に良かったが、もうちょっとセオリーを知っておきたい
  • ベンチ走行中に次の改善に着手してしまうなど、保守的ではなく投機的な行動をとった
  • 常に自分の行動をしゃべりながら行動するのがとても良かった。何が問題になってるかを冷静に考えられる
  • 13:25時点でスコアが8299点であり、順位は80位ぐらいだったはず。これは自分ではかなり良いペース

Problem

  • 7000点到達以降、改善が効果を発揮しなくなった。ボトルネックを見定められていない？
  • 静的ファイル配信を実現するのに時間がかかった(2時間30分ぐらい使って結局実現できなかった)
  • icon_hashの仕様を破壊してしまい、直すのに手こずった
    • ファイルに無ければRDBをみて、その結果を元にhashを作るというifが2,3ネストする程度の複雑さでも頭がこんがらがる
      • 自分がGoに習熟していないことや、脳内メモリ量が少ないことが原因？
        • 割り切って全部ChatGPTに突っ込めば良かったかも
  • hostsの理解が怪しい
  • DNSはなにか仕込まれてそうとおもっているが、DNS自体の理解も、アプリケーションにおいてどのような役割なのかも怪しい
    • 理解度としては、Webサイトを公開する際にIPより便利にアクセスしてもらうために登録しなければならないもの。という程度
    • アプリケーションにおいての役割は、たぶん個別ページを作るためだと思うけど、それだけ？
  • ChatGPTでSQLのIFNULLよりCOALESCEのほうが速いというのを信じてしまった(これ自体は本当で、ボトルネック取り違えなのかも不明)
  • 競技なのに「勉強になれば良い」という意識がある。もっと闘争心を燃やしたいところ。
  • 静的ファイル配信でハマったときに、あきらめるかどうかの判断ができない(これを書いている今でも、押すべきか引くべきかどっちがよかったんだろうと思っている)
  • 動画で自分の声と顔(ターミナルを表示している画面への写り込み)を観るのがつらい
  • ベンチで出たエラーログの意味を理解していない
    • /reportで400が返ってきた時に調べずにスルーした(結果的に問題にはならなかったのでラッキー)
  • 静的ファイル化した画像を消さなかったことでベンチがこけたことに気付くのが遅かった(どうすれば早く気付ける？経験則かも)
  • ローカルでIDEでプロジェクトを作っておくべきだった
  • Makefileなんもわからん
  • go buildコマンドなんもわからん
  • クリップボードの履歴を検索する何かがあったほうが良かったかも(意外とIPを貼り付ける回数が多かったり)
  • INDEXが効かなかったとき、原因がわかっていない
    • recordsのnameに張ったときに、ベンチだけしか見ていなかった→query-digesterとEXPLAINは必須だったはず
  • 計測が甘い
    • query-digesterで上位のクエリを改善した結果、たまたまAPI自体も改善したときしかベンチに現れていない。これは1番のボトルネックを特定できていないのでは？
  • 最後にinit.shにrmコマンドを追記したと思っていたが、競技終了後に確認したら追記できていなかった。追記後ベンチを回したらfailにならなかった。なぜこんなことが…orz

去年から続投のProblem

  • インスタンスが3つあるのがなぜなのか理解していない
  • 一緒に参加する友達がいなかったorz

特筆するTry(実現可能とは言っていない)(本当はProblemを全部倒したい気持ち)

  • とにかく経験を積むことで突破できそうなProblemが多いので、素振り回数はいくらでも増やして良い。8時間でやる素振りと、時間にとらわれずじっくり向き合う素振りを両方増やしたい
  • 講評を良く読む。ISUCON12予選の講評には3台インスタンスの解説があるはずだが、読んでいないor忘れている。
  • 実践Nginx本は流し読みしただけなので、腰を据えてちゃんと読もう
  • MySQLの設定がどのような項目があるか/どう調整していくかが、学び方からわかっていないので調べるところからやる
  • Goの経験値がとにかく足りていない。未だにerrのifで目が滑る。作って/読んでを増やそう

動画を見ての気になりポイント

  • 肌がかゆそう(詰まったりすると頭を掻いていたりする)
  • 2倍速でも声が聞き取れる(意外とハキハキしゃべってる)

まとめ

去年よりわからないことが減り、改善サイクルを回す回数が大きく増えたことが嬉しいです。

自力のようなものが足りないのは目立ちますが、それでもようやくISUCONで戦うスタート地点に立てたような気がします。

とくに、去年は「改善そのものの技量」と「Linuxなどの環境を泳ぐ能力」の両方に脳みそリソースを大きく割いていましたが、今回は後者はほぼなくなりました。素振りを複数回やることでセオリーを知ったり、業務でIntellijにVimプラグインを入れたりした成果がでたようで嬉しいです。

来年も絶対に参加し、今度こそ勝負に参加できるスコアを出したいです！！

泡沫の夢。最終0点なのがくやしく、未練がましく自身の最高点の画像を貼る