kashinoki38 blog

something like tech blog

ISUCON12 予選参戦記録

今回のISUCONはこれまでの経験をもとにかなり効率よく改善を回せたのでその記録。

事前準備

とりあえず初めてのメンバーもいるということで、1回過去問を半日通しでやってみて、その後各自キャッチアップして、予選1週間前に手順を再度確認という予定で準備を実施。

半日通しでやった結果以下のような方針に。

  • リソース監視はtopだけでやる(NetData結局いらない)
  • makeコマンドでベンチ前後の処理を自動化する
    • ログ削除、サーバー再起動
    • alp結果取得
  • 分担
    • インフラ系変更は自分に集約
    • 各種導入ツールはバイネームで指定
  • 導入ツール
  • VSCODEのRemote-SSH使いたいけど、サーバー側のメモリがカツい場合は微妙

Make運用について

紆余曲折を経て以下Makefileにて運用。
どのブランチでの結果なのかがSlackに流れるのが割と便利だった。

restart:
  echo "🌟make restart 実行しました" | notify_slack
  git branch | notify_slack
  sudo systemctl daemon-reload
  sudo rm /var/log/nginx/access.log
  sudo rm /var/log/mysql/mysql-slow.log
  sudo systemctl restart nginx.service
  sudo systemctl restart isuports.service
  sudo systemctl restart mysql.service
  sudo systemctl status nginx.service
  sudo systemctl status isuports.service
  sudo systemctl status mysql.service

restart_nginx:
  sudo systemctl restart nginx

alp:
  echo "make alp 実行しました" | notify_slack
  sudo  cat /var/log/nginx/access.log |alp ltsv --sort sum --reverse -m "/api/player/player/,/api/organizer/competition/.*/finish,/api/organizer/competition/.*/score, /api/player/competition/.*/ranking,/api/organizer/player/.*/disqualified"|notify_slack --snippet

# pprofのデータをwebビューで見る
# サーバー上で sudo apt install graphvizが必要
.PHONY: pprof
pprof:
  echo "make pprof 実行しました on port 8080" | notify_slack
  go tool pprof -http=0.0.0.0:8080 /home/isucon/webapp/go/isports http://localhost:6060/debug/pprof/profile

pprofについて

めっちゃ便利すね。
去年Golangで挑んだのに、情弱過ぎてプロファイラ一切使わなかったんだよね。

予選

点数の推移と結果

最終点は 14927 だった。

が、まさかの失格。

ちょっと原因をちゃんとわかってないけど、最後に systenctl stop した種々のサービスを disable してなかったのは一因かなと思ってるけど、

17時の段階では19位にいたので興奮したものですが、もし失格になってなくても49位なので諦めはつきます。

当日やったことサマリ

ちょっとやったことを振り返ってみる。

MySQL分離

とりあえずMySQLを別サーバーにするのはさっさと実施。

CPU使用率(上がAP、下がMySQL)を見るとMySQLがまだまだCPUバウンド。

Score: 3086

UUIDを利用

pt-query-digestを見てみると、ほぼ REPLACE が食っている。

# Profile
# Rank Query ID           Response time  Calls R/Call V/M   Item
# ==== ================== ============== ===== ====== ===== ==============
#    1 0xA1FC19A5563AD0F5 966.7505 78.3% 24557 0.0394  0.02 REPLACE id_generator
#    2 0xFCB05D4948FC2248 212.6763 17.2% 10070 0.0211  0.28 SELECT visit_history
# MISC 0xMISC              55.9784  4.5% 92740 0.0006   0.0 <33 ITEMS>

全文見ると、IDをただ作成するためだけに使っているぽい。

REPLACE INTO id_generator (stub) VALUES ('a')\G

重複嫌ならUUIDにすればいいんじゃんということで、UUID化改修実施。

だいぶCPUがマシになる(左AP、右MySQL

Score: 5591

インデックス

REPLACE が消えると、特定 SELECT で8割弱という状況に。

# Profile
# Rank Query ID           Response time Calls R/Call V/M   Item
# ==== ================== ============= ===== ====== ===== ===============
#    1 0xFCB05D4948FC2248 33.9508 76.2%  4513 0.0075  0.10 SELECT visit_history
#    2 0x2A1217500A0400FE  7.2372 16.3%  1356 0.0053  0.00 INSERT visit_history
#    3 0x348974B3D332E575  2.1916  4.9%     1 2.1916  0.00 DELETE visit_history
# MISC 0xMISC              1.1517  2.6% 27141 0.0000   0.0 <10 ITEMS>

WHERE条件とかにインデックスを貼ろうということで、インデックス作成。

SELECT player_id, MIN(created_at) AS min_created_at FROM visit_history WHERE tenant_id = 1 AND competition_id = '547f03113' GROUP BY player_id\G

後で、created_atにもあったほうがイイよねということで以下でfix。

alter table visit_history add index visit_history_idx2 (competition_id, tenant_id, player_id, created_at);

ロック削除

以下のエラーが出ていることに気づく。

"isuports.go","line":"193","message":"error at /api/player/player/:player_id: error retrievePlayer from viewer: error Select player: id=bf329cc0-0a46-11ed-a518-0ad21e537945, database is locked"

なんかロック機構がソースに入りまくっていることに気付く。

// player_scoreを読んでいるときに更新が走ると不整合が起こるのでロックを取得する
fl, err := flockByTenantID(v.tenantID)
if err != nil {
   return fmt.Errorf("error flockByTenantID: %w", err)
}
defer fl.Close()
pss := make([]PlayerScoreRow, 0, len(cs))

とりあえず外してみる?って乱暴にしたら点数上がる。

Score: 7417

SQLite にインデックス作成

pprof見るとまだSQLが遅い。

良く見るとこれ player_score とか tenant って、SQLiteじゃんとなって、SQLiteの調査開始。

インデックスが全く無いので、SQLを見た感じとにかく以下インデックスを貼りたい。

create index tenant_name_idx on tenant(name);
create index player_score_idx on player_score(tenant_id, competition_id, player_id);

テナントが追加されれば /home/isucon/webapp/sql/tenant/10_schema.sql をベースに新規テナントDBを追加しているので、ここにインデックスコマンド追加。

けど、それ以外に初期データをファイルからインポートしている。
/home/isucon/initial_data.db 形式で初期データが100テナント分ある。

これらの初期データの置き換えも必要なので、ごり押しでファイル置き換え。

echo 'create index player_score_idx on player_score(tenant_id, competition_id);' | sqlite3 1.db 
echo 'create index player_score_idx on player_score(tenant_id, competition_id);' | sqlite3 2.db 
...
...
cp 1.db  /home/isucon/initial_data 
cp 2.db  /home/isucon/initial_data
...

Score: 9235

PlayerScoreRowをバルクインサート

Score: 12620

Nginx→Go→MySQLでサーバー分離

ガチャと後処理

回しまくりながら、去年の反省でチェッカー(isucon-env-checker)を走らせる。
後は各種不要サービスをストップ。
ログも無効化。

Score: 14927

反省

  • 追試で失格になった
    • 理由不明だが一因と思われるのは、systemctl disable にしなかったこと
    • 再起動試験も次回はしたほうがいい
  • SQLiteインメモリモードだとどうだったか
  • SQLiteトランザクション化する必要があった模様
  • redis使えたか
  • N+1をJOINしたかった
    • 実装力不足
  • pprofがリセットされなかった(Webプロセスが残っていたせいで、Killするとリセットできた)
  • visit_historyの初期データ破棄
    • created_at最小しか使わないため大部分いらない
  • 以下やったけど裏目
    • visit_history をキャッシュに載せてBulk_insertする
    • visit_historyの参加者select キャッシュ化

今年は、過去最高に戦えた気がする。
楽しかったのでまた来年がんばります。