ISUCON13に@eiya、@oribe、@tokiで「織時屋」として出場し、全体2位、学生チーム内では1位になりました。
事前準備
チームでの練習として、ISUCON11予選とISUCON11本選を解いた。
ISUCON11予選はtraPで開催された部内ISUCON(通称PISCON)に参加してのもの。
当日
10:00~ 初動
当初の予定通り初動を進める。
- @oribe: 環境セットアップとリポジトリの載せ
- @eiya: 計測ツールの設定(slow query log、alp、fgprof)
- @toki: マニュアル読み → 改善にあたり重要そうな箇所を抜き出し共有
- アイコンのキャッシュ, スパムに関するアプリの仕様など
10:23 3,180点 初ベンチ
開始した作業
- slow queryを見て@eiyaが
SELECT * FROM livestream_tags WHERE livestream_id = 7534\G
にindexを張る
10:39 4,820点 livestream_tags
にindexを張った
開始した作業
- alpのP99を見て
^/api/user/[^/]+/statistics
が遅いのでなんとかしてくれと@tokiに投げる- あからさまなN+1があるので@tokiが直す
- initializeでtableが作り直されないのが面倒なので@oribeが修正する
- 毎回
10_schema.sql
で作り直すようにすれば、ここにindexの記述を追加することでバージョン管理ができるので
- 毎回
- slow queryを見て
SELECT image FROM icons WHERE user_id = 1013\G
が遅いので↑のついでにインデックスを張ってもらう - slow queryを見て
ADMIN PREPARE
が多いので@eiyaがInterpolateParams = true
をする - alpのP99を見て
^/api/livestream/[0-9]+/moderate
が遅いのでなんとかする@eiya
11:01 5,607点 moderateHandler
のrange livecomments
のN+1だけ直した
11:05 7,399点 icons
にindexを張った
開始した作業
- logが標準出力に沢山流れてくるので@oribeが消す
- netdataで見るとまだmysqlがCPUを使っていそうなので、@oribeにindexを確認して張ってもらう
- alpと多分fgprofで
getLivecommentsHandler
が重いので@eiyaがなんとかしようとする
11:16 8,478点 logを切ってthemes.user_id
にindexを張った
このあたりからベンチマークのキューが詰まり始める
11:28 10,690点 ^/api/user/[^/]+/statistics
のN+1を直した
開始した作業
- slow queryで
SELECT image FROM icons WHERE user_id = 1011\G
が重い- @eiyaがgetLivecommentsHandlerのJOINの過程でここに手を出そうとしていて作業が滞る
- @eiyaがgetLivecommentsHandlerを後回しにして、先にiconのhashをDBに入れる改善をすることに
- slow queryで
SELECT * FROM tags WHERE id = 58\G
があるので@tokiが直す
11:46 11,313点 ng_words
にindexを張った
11:51 10,527点 isudns
のrecords.name
にindexを張った
12:01 11,136点 tagを纏めて取得するように
@eiyaがやっているgetLivecommentsHandlerのJOINとiconの修正とがボトルネックなので、改善してもスコアが上がらないし負荷計測も上手くできない
実装は出来ていたがバグらせていたので@oribe,@tokiに助けを求める
12:14 12,967点 iconhashをDBに保存する
icon周りのバグがなおってボトルネックが少しうつる
開始した作業
- alpのP99で
/api/livestream/[0-9]+/statistics
が重いのでなんとかしてと@toki
に投げる- user statisticsと同様の手法でN+1だけ@tokiが改善
- CPU負荷が半々になってきたので、app-db 2台構成の準備を@oribeに投げる
- getLivecommentsHandlerが重い問題に@eiyaが再びとりかかる
12:27 14,491点 getLivestreamStatisticsHandlerのN+1を改善
12:55 17,274点 getLivecommentsHandlerをJOINする
開始した作業
- alpで
^/api/user/[^/]+/icon$
のリクエスト数が多いので、iconで304を返す作業を@tokiがやる
12:59 23,657点 app-db 2台構成(baseline: 12:27 14491点)
isupipeのデータベースを2台目に振り分けた
flowchart TB bench[ベンチマーカー] bench == HTTPリクエスト ==> nginx bench == 名前解決リクエスト ==> pdns subgraph s1 nginx[Nginx] pdns[PowerDNS] app isudns[isudns - MySQL] pdns -.-> isudns nginx --> app end app -.-> isupipe subgraph s2 isupipe[isupipe - MySQL] end
13:02 22,914点 iconsクエリをキャッシュする、user iconで304を返す(baseline: 12:55 17274点)
開始した作業
- slow queryでthemes, users, iconsへの単純SELECTクエリがそれぞれ5万件ほど飛んでおり、user timeでトップなので@tokiがキャッシュする
13:06 43,491点 2台構成とiconsキャッシュの改善がmergeされる
開始した作業
- slow queryで
SELECT * FROM themes WHERE user_id = 1017\G
が重いので@tokiが直す - slow queryで
SELECT * FROM users WHERE id = 1058\G
の呼び出し回数が多いので@tokiが直す - 1台目のCPUがまだ重いので、DNSとnginx+appを@oribeが分ける
- alpで
GET ^/api/livestream/[0-9]+/reaction
が重いので@eiyaが直す
13:11 48,494点 themeをcacheする
13:27 63,968点 usersをcacheする
13:30 ベンチマーカーが完全に止まる
計測が出来ないので、以前の作業の継続か勘で作業
- alpの上位なので@eiyaがgetReactionsHandlerのN+1を直す
- alpの上位なので@eiyaがsearchLivestreamsHandlerのN+1を直す
- しかし忘れ去られた
- post commentに失敗したというログがベンチマーカーから出力されているので、@eiyaがpostLivecommentHandlerのngword判定をgo側で行うように直す
- CPU負荷の分散のため@oribeがDNSサーバーを分ける設定を引き続きする
- ログにコミット失敗のエラーが流れているので@tokiがトランザクションを外す
- pprofでsearchLivestreamsHandlerの中で時間がかかっているtagsの取得部分に@tokiがキャッシュを作る
14:20 ベンチマーカーが再開する
14:26 80,108点 getReactionsHandlerのN+1を直す
14:31 78,472点 トランザクションを外す&tagsをキャッシュ
15:05 81,037点 ngword判定をgo側で行うように直す
15分くらい別のブランチでベンチ回しててなんで点数出ないんだ?って言ってた
15:10 82,954点 LivestreamのJOINをばらしてキャッシュを使うものに置き換え
開始した作業
- JOINしているとキャッシュしにくいので、よく見ると単純にlivestreamとusersを取るだけなので、ばらしてusersのキャッシュを効かせる (@toki)
- alpの上位なので@eiyaがpostLivecommentHandlerを引き続き見る
- alpの上位なので@tokiがsearchLivestreamsHandlerのN+1を直す
- @eiyaがやったブランチがあることに気が付かずに再発名だけど@toki版のが優れている
15:37 160,819点 nginx+dns+db(isudns)/db(isupipe)/app構成 (baseline: 14:31 78,472点)
すぐにmergeして点数おそらくそんなに変わらず
この時点での構成
- メインのアプリケーションを3台目に分離
- PowerDNSへの新規ドメインの登録のためのpdnsutilコマンドの実行だけを行うAPI
/api/register/pdnsutil
を生やす/api/register
でpdnsutilコマンド叩いて新規サブドメインの登録していたのを気づかず時間を溶かしまくった
flowchart TB bench[ベンチマーカー] bench == HTTPリクエスト ==> nginx bench == 名前解決リクエスト ==> pdns subgraph s1 nginx[Nginx] pdns[PowerDNS] appdns[app] isudns[isudns - MySQL] pdns -.-> isudns end subgraph s2 isupipe[isupipe - MySQL] end subgraph s3 appmain[app] end appmain -.-> isupipe nginx -->|/api以下をプロキシ | appmain appmain -->|/api/register/pdnsutil| appdns appdns -. pdnsutilの実行 .-> pdns
- DNS権威サーバのクラウドサービス向けに行われた攻撃および対策 〜後編〜 | さくらのナレッジを参考にしようとするものの、今回の条件ではサクッとそのまま使える手法ではなさそうで以降の対応方針に悩む
- 攻撃による問い合わせであると明確にフィルタリングできる条件がわからなかった
- PowerDNSの、MySQLよりも早いと紹介されている形式が更新に対応していなさそう
15:42 171,977点 searchLivestreamsHandlerのN+1を直す
15:47 168,000点 postLivecommentHandlerのselectを一個減らす
開始した作業
- pprofの上位のjson encodeを@tokiが別の早いライブラリに変える
- alpのp99の上位の
POST /api/register
を@eiyaが見る- DNSを変えるときに生まれたapp->DNSのリクエストを投機的に実行する
15:47 169,993点 sonic-jsonを使う
16:05 172,196点 app->DNSのリクエストを投機的に実行する
スコアは出てないけどDNSを試行錯誤中
- @tokiもDNS水攻め対策を考える
- PowerDNSのBackend一覧の表だけ見て、BIND backendは更新できないのか~とだけ考えてあまり試さなかった
- Wildcard Aレコードを貼ってしまうと、HTTPリクエストが増加してスコアが下がる
- 反省会にて、ファイルを置き換えて
pdns_control reload
とかすればよかったと判明 くやしい~
- SQLite backendを試そうとするが、
pdns-backend-sqlite
パッケージをインストールしたにも関わらず、shared libraryが無いとか言われて断念 なんで?
- PowerDNSのBackend一覧の表だけ見て、BIND backendは更新できないのか~とだけ考えてあまり試さなかった
16:20 169,342点 (revert)reportの500対策でpostReportのトランザクションを復活させる
存在しないコメントに対するreportの閲覧要請が来ていて、500になっていた。
500が消えなかったのでmergeしなかった。
16:52 207,292点 SELECT reservation_slotsのN+1を解消しindexを張る
slow query上位のSELECT slot FROM reservation_slots WHERE start_at = 1702335600 AND end_at = 1702339200\G
にindexが張られていないことに気が付いたので張った。
17:17 225,969点 SELECT reservation_slotsのstart_atだけを使って検索する
17:22 198,724点 nginx+dns/db(isupipe)+db(isudns)/app構成 (baseline: 16:52 207292点)
flowchart TB bench[ベンチマーカー] bench == HTTPリクエスト ==> nginx bench == 名前解決リクエスト ==> pdns subgraph s1 nginx[Nginx] pdns[PowerDNS] appdns[app] end subgraph s2 isudns[isudns - MySQL] isupipe[isupipe - MySQL] end subgraph s3 appmain[app] end pdns -.-> isudns appmain -.-> isupipe nginx -->|/api以下をプロキシ | appmain appmain -->|/api/register/pdnsutil| appdns appdns -. pdnsutilの実行 .-> pdns
17:22 244,339点 merge
17:36 ログを切る
- db(isudns)をどこに逃がすのが点が高いか確認する
最終スコア 243852点
-
競技終了後に気が付いたんですが
isudns
のrecords.name
にindexを張った最終的にdb(isudns)が動いている二台目でこれやってないのでもっとスコア伸びたかも
結果発表
昨年に引き続き、全体2位&学生1位を獲得しました。
企業賞としてはNew Relic賞、はてな賞を受賞しました。ありがとうございます。
ツール準備
基本的には去年と同じツール構成なため、差分のみ記述。
Task
コマンド管理をMakefileからTaskへ移行。
よく使うコマンドにだけdescを書いておくことでtask -l
で簡単に確認できたり、
複数の処理を並列で実行できたり、
prof:
desc: pprofとfgprofで記録する
deps:
- task: pprof
- task: fgprof
状況に合わせての「一部の処理だけ実行しない」を行単位のコメントアウトで簡単に切り替えられたり、
restart:
cmds:
- sudo systemctl daemon-reload
- sudo systemctl restart {{.SERVICE_NAME}}
- sudo systemctl restart mysql
- sudo systemctl restart nginx
# 特定のサーバーでだけ実行したい場合の例
# - sh -c "if [ $SERVER_ID = "s1" ]; then (sudo systemctl restart nginx) fi"
-g
をつけるとこで常にホームディレクトリにあるTaskfile.yaml
を参照できたりと、様々な点でISUCONのコマンド管理において便利だった。
テンプレートリポジトリ
今年はリポジトリの構成を効率よく改良するためにテンプレートリポジトリを作成して運用した。
過去問のリポジトリはisucon13-templateから作成し、練習で使ってみてのフィードバックをisucon13-templateに施すサイクルを実施。
本番リポジトリのoribe1115/isucon13も、仕上がったisucon13-templateから作成した。
isucrud
各関数とDBテーブルの依存関係の可視化に@mazreanが開発したiscrudを使用。
isucrudの詳細はこちらから。
グラフが少し見にくいのを置いておけば テーブルごとにほんの一部しか更新が入らないことがすぐに分かるので、キャッシュ戦略を立てるときに役立つ。
キャッシュ実装
オンメモリキャッシュの実装には、transparentなキャッシュをtypesafeに実装できる@tokiの自作ライブラリを使用。
事前の練習でメンバーも使い方を確認した。
Read時にはtransparentに(そこにあることを意識せず)使うことができ、no-write-allocate, write-throughな(そもそもsetの挙動を持たない)キャッシュであるので、バグを埋め込みづらい仕組みになっている。
ただし、単純なオンメモリキャッシュのため、キャッシュしたテーブルに関する処理は複数サーバーに分けづらくなってしまう。
反省
- index張り忘れ
- cache使い忘れ
- slow queryのisudnsを除くと4位(10%くらい)のところにJOINクエリがあり、その一部がオンメモリキャッシュに乗っているデータだった
- nginxの負荷に悩んでいたのでnginxを剥がす作業をするべきだった
- 名前解決の応答でs3のIPアドレスを答えれば、ベンチマーカー自身にHTTPリクエストのプロキシをさせられたのでは
- @eiya: でもオンメモリキャッシュしてるからapp二台に分けられないしな...で思考止まってしまっていた(nginxの負荷だけでも分散させれば良かった)
- DNSの自前実装は思いつかなかった...
- PowerDNSのBIND Backendと
pdns_control reload
の組み合わせが思いつかなかった- 終盤で焦ってドキュメントを読み飛ばしていた
- 細かい改善
- icons のDELETE&INSERTのraceはUPDATEにすればよかった