はじめに
どうもKizukuです.
今年初めてISUCONに参加したので,その記録をここに残します.
高スコアを取ったわけでもcoolな実装をしたわけでもないので,勉強のためにツヨツヨエンジニアのwriteupを漁ってる人はどうぞ別の記事をお読みください.
初心者がISUCONで苦しんだ記録を見たい方は,ぜひ見ていってください.
ISUCONの全記録
エントリー
ISUCONに出ようと思った私は大学の所属サークル(C3)で,ともに戦ってくれる仲間を探します.無事に2人集まって3人チームを結成することができました.ただ,チーム全員ISUCON初参加で,かつ,そのうち1人が何故か社会人だったため,私たちのチームは社会人枠での参加となりました.
エントリー(ISUCON0次予選)は,1次募集,2次募集ともに逃してしまい,3次募集でギリギリ滑り込みました.(ID 596)
あらかじめ必要な情報は用意しておいた方がいいですね.今後の教訓となりました.
過去問
全員初心者の私たちのチームはとりあえず経験値を積むため,ISUCON12の予選の過去問を解きました.(長くなるのでその詳細は割愛させていただきます.)
過去問では14593のベンチマークを出せたので,ISUCON13本番では目標10000,あわよくば20000を掲げて当日を迎えました.
9:30 起床
ライブ配信開始の直前に私たちのチームは目覚めました.全員うちに泊まっていたため,無事に全員寝過ごすことはなく「起床成功」できました.
9:40 配信視聴
配信側にトラブルがあったらしく,スタートが少し押したり動画が止まったりしましたが無事にオープニング配信が始まりました.
このトラブルが今年の問題の伏線(?)になっているとは,知る由もなく...
10:00 競技開始
みなさんご存知の通り,今年のテーマはライブ配信を行うことができるアプリケーション「ISUPipe」でした.
前日MTGで動画配信系は出ないだろうと予想していた私たちは度肝を抜かれました.
マニュアルを読むと「DNS水責め攻撃」が行われるという旨が書いており,うちのインフラ担当が震え上がっていました.
10:05 環境構築
運営から提供されたCloudFormationを用いて競技環境を整えますが,ここでトラブル発生.CloudFormationがうまく動いてくれずROLLBACK_COMPLETE
で止まってしまいます.他のチームのベンチマークを見る限り,提供されたCloudFormationに問題があるわけではなさそうなので,困っていましたが,過去問で解いたISUCON12のリソースが立ったままだったことに気がつきそれを削除することで無事に環境を立てることができました.
後日調べた感じだと1アカウントにつきElastic IPアドレスは5つまでしか持つことができないので,そこでエラーになっていたんだなぁとわかりました.
10:20 初期ベンチマーク計測
私たちのチームはGo言語での実装だったため,初期ベンチマークは3,295でした.
ここからどれだけスコアアップできるのか...
~11:00 現状把握
とりあえず,ドキュメントを隅々まで読みました
そのあと,インフラ担当がDNSの対応をしてくれてる間に残りの2人でログを取得できるように整備していきました.
以下今回取得したログです
- MySQLのスロークエリ
- my.confにログの設定を追記
- nginxのログ解析
- nginx.confを変更しaccess.logの出力形式をltsvに変更
- alpでリクエストごとの処理時間を取得
- Goのアプリケーションの関数ごとの実行時間
- pprofを導入し可視化
過去問の時に練習していたので,特に詰まることなくログを取ることができました.
また,このタイミングでサーバーの初期状態のバックアップを取るためにホームディレクトリ以下のコピーをローカルPCに保存しておきました.
- pprofを導入し可視化
alpの解析結果
+-------+-----+------+-----+-----+-----+--------+-----------------------+--------+--------+---------+--------+--------+--------+--------+--------+-----------+------------+---------------+-----------+
| COUNT | 1XX | 2XX | 3XX | 4XX | 5XX | METHOD | URI | MIN | MAX | SUM | AVG | P90 | P95 | P99 | STDDEV | MIN(BODY) | MAX(BODY) | SUM(BODY) | AVG(BODY) |
+-------+-----+------+-----+-----+-----+--------+-----------------------+--------+--------+---------+--------+--------+--------+--------+--------+-----------+------------+---------------+-----------+
| 1815 | 0 | 1772 | 0 | 40 | 3 | GET | /api/livestream/[^/]+ | 0.004 | 4.328 | 486.197 | 0.268 | 0.564 | 0.892 | 1.444 | 0.350 | 0.000 | 142102.000 | 24486711.000 | 13491.301 |
| 5647 | 0 | 5631 | 0 | 13 | 3 | GET | /api/user/[^/]+ | 0.004 | 20.004 | 392.908 | 0.070 | 0.120 | 0.172 | 0.332 | 0.615 | 0.000 | 103175.000 | 310691121.000 | 55018.792 |
| 1765 | 0 | 1736 | 0 | 24 | 5 | POST | /api/livestream/[^/]+ | 0.008 | 4.888 | 378.586 | 0.214 | 0.304 | 0.368 | 4.140 | 0.571 | 0.000 | 2744.000 | 2953927.000 | 1673.613 |
| 379 | 0 | 373 | 0 | 4 | 2 | POST | /api/register | 0.004 | 0.644 | 81.806 | 0.216 | 0.332 | 0.388 | 0.524 | 0.093 | 0.000 | 516.000 | 175061.000 | 461.902 |
| 377 | 0 | 367 | 0 | 2 | 8 | POST | /api/icon | 0.012 | 0.548 | 35.496 | 0.094 | 0.176 | 0.252 | 0.396 | 0.078 | 0.000 | 154.000 | 6890.000 | 18.276 |
| 2 | 0 | 2 | 0 | 0 | 0 | POST | /api/initialize | 12.348 | 12.980 | 25.328 | 12.664 | 12.980 | 12.980 | 12.980 | 0.316 | 27.000 | 27.000 | 54.000 | 27.000 |
| 388 | 0 | 383 | 0 | 4 | 1 | POST | /api/login | 0.004 | 0.456 | 15.706 | 0.040 | 0.120 | 0.172 | 0.256 | 0.058 | 0.000 | 166.000 | 422.000 | 1.088 |
| 206 | 0 | 205 | 0 | 0 | 1 | GET | /api/tag | 0.004 | 0.812 | 13.901 | 0.067 | 0.164 | 0.248 | 0.512 | 0.106 | 166.000 | 6095.000 | 1249167.000 | 6063.917 |
| 97 | 0 | 97 | 0 | 0 | 0 | GET | /api/livestream | 0.012 | 0.592 | 12.516 | 0.129 | 0.260 | 0.380 | 0.592 | 0.107 | 3.000 | 22512.000 | 266327.000 | 2745.639 |
| 56 | 0 | 56 | 0 | 0 | 0 | DELETE | /api/livestream/[^/]+ | 0.004 | 0.260 | 2.922 | 0.052 | 0.124 | 0.164 | 0.260 | 0.053 | 0.000 | 0.000 | 0.000 | 0.000 |
| 12 | 0 | 12 | 0 | 0 | 0 | GET | /api/user/[^/]+/theme | 0.016 | 0.068 | 0.248 | 0.021 | 0.032 | 0.068 | 0.068 | 0.017 | 38.000 | 38.000 | 456.000 | 38.000 |
| 2 | 0 | 2 | 0 | 0 | 0 | GET | /api/payment | 0.004 | 0.004 | 0.008 | 0.004 | 0.004 | 0.004 | 0.004 | 0.000 | 21.000 | 21.000 | 42.000 | 21.000 |
+-------+-----+------+-----+-----+-----+--------+-----------------------+--------+--------+---------+--------+--------+--------+--------+--------+-----------+------------+---------------+-----------+
~12:00 MySQLのIndexをはる
スロークエリのログを元にMySQLのIndexを貼りました.終わってから気が付きましたが,アプリケーションの方のDBにはIndexを貼りましたが,DNSの方のDBにはIndexを貼り忘れてました...
~16:00 アプリケーションの改善
alpでのリクエストの解析の結果livestream
系とuser
系のエンドポイントで多くの処理時間が使われていることがわかったので,まずはその部分を改善していきました.また,同時進行でアプリケーション全体に関わる部分の改善も行いました.
以下にやったことを列挙していきます.どれがどれくらい効果があったのか,そもそもパフォーマンス改善になっているのかは未検証なので,後日じっくり解き直しながら確認しようと思います.
-
fallbackImage
の読み込みをリクエストごとではなくアプリケーションの起動時に変更.その際にhash値も計算してメモリ上に置いておく - JSONのエンコーディングのパッケージを
encoding/json
からgithub.com/goccy/go-json
に変更 - themeとimageを同時にDBから持って来れるようにする
- N+1の解消
(整合性チェックが通らず,ロールバックした部分もしばしばあるのが勿体無い...)
~17:30 nginxの設定&iconのキャッシュ処理
インフラ担当がDNSの方に全振りしていてnginxの設定を弄っていないことに気がついたのでnginxの設定をいじるのとついでにiconはキャッシュしてもOKとのことだったのでその部分を残り30分で実装.
nginxの設定は
worker_connections
worker_rlimit_nofile
open_file_cache
proxy_buffers
gzip
あたりをいじりました.
iconのキャッシュはnginxだけで完結させる実装にしましたが,おそらくうまく動作していないような結果となりました.(競技終了後の交流でもnginxだけでの対応は難しそうな感じでした.)
17:59 最終提出
先ほどのnginxの設定を反映させ最後のベンチマークの提出となりました.nginxの部分は時間がなく動作確認していなかったため,チームメイトに「0になるかもしれないけど提出していい?」と確認をとり終了1分前にベンチマークを提出.その結果が出る前に18:00を迎えポータルサイトから閉め出されてしまいました.最終のベンチマークがいくらだったかは公式の発表があるまで確認することができませんでした.
↓後日ポータルにて確認できた最終提出の結果.最高スコアよりは少し下がってしまいましたが,0ではなかったので戦犯になることは逃れました.
18:00 競技終了
18:00になり競技が終了しました.8時間の競技時間でしたがあっという間に終わったなぁというのが正直な感想.
同時に来年も絶対出場してやると心に決めました.
19:00 打ち上げ
不完全燃焼感は否めませんが,とりあえずやり切ったということで,近所の中華料理屋で打ち上げをしました.
来年こそは,5桁スコアを目指します!
結果
最終スコア 7,943
最高スコア 8,366
順位 343位
ベンチを回した回数 69回 (そのうち56回Failed...)
来年の自分へ
- 計測ツールは独自なものやISUCON用にカスタマイズされたものを使うことも選択肢に含めた方が良さげ
- とりあえず過去問は解けるだけ解いておく
- まずは全員でマニュアルをよく読んで方針を決めてから動き出そう
- 落ち着いてやった方が結果的に効率いいことが多いので気をつけよう