diary.sorah.jp

ISUCON5 予選に参加した (白金動物園) #isucon

eventtechtext

A photo posted by Sorah Fukumori (@sora_h) on

ISUCON 5 予選に白金動物園として @mirakui, @rosylilly と参加してきました。結果は 15666 点で両日通したランキングの内 top 4 を除いて 5 位 で本戦にはなんとか出場できそうって所。

問題

高負荷に耐えられるSNSコミュニティサイトへようこそ!

まあそのうち公式で解説・講評あがってくると思うから詳しくは書かないけど、ISUxi という SNS Web アプリで、予選にしてはそこそこ MySQL のテーブル数が多くて複雑なもの。 (users, salts, profiles, entries, comments, footprints, relations)

ログイン・ログアウト・プロフィールページ・友達・日記 (友達限定公開あり) の個別ページ、ユーザー日記リスト・足あと、諸々の情報を全部見れる便利なトップページ、などなど。

個人的に問題を読んだ限り倒すべき鍵となりそうなポイントは is_friend? と get_user あたり。初期実装ではどちらも愚直に SQL を叩いていて、どちらも N+1 問題らしい感じになっていた。

特にトップページがそれにより重いコードになってて、とりあえずそのへんを潰す事に集中してた。

なおチームの暗黙的了解としていざ仕事で書くとさすがにそれはみたいな感じの奴は避ける、ってのがあった気がする。具体的には過剰なオンメモリとかね。ただアプリケーション仕様を考えて妥当だな、という類のキャッシュはアリ。

やったこと

  • unicorn worker 20, unix socket, reload 時に旧 master 終了などの細かいところ
    • RACK_ENV=production
  • app にクエリログ吐かせるようにした (mysql2 へのモンキーパッチだよ)
  • redis 導入、あちこちでキャッシュとして利用
    • get_user, user_from_account とか
    • ただ効果ないところもあった気がする。今後のために要調査
  • relations からフレンドリストをリクエスト中キャッシュ
  • nginx-1.9.4-1+vivid0
  • sysctl.conf で RFS やローカルポートの調整
  • varnish に挑戦するも断念
  • title/content カラム分離
  • comments_of_friends で entries を JOIN するようにする
  • footprint を redis sorted set ベースの実装に入れ替え
  • comments_for_me をキャッシュ
  • relations へ index 追加
  • relations そもそも one/another 両方引く必要ないと判断して one だけ引くようにする
  • その他各種クエリ改善
  • my.cnf 調整 (kamipo my.cnf ベース)

やりのこしたこと

  • is_friend? まだもうちょっとはやくできた
  • comments_of_friend、entries は WHERE IN の別クエリとかにすればもうちょっとはやくなったっぽい
  • user はオンメモリキャッシュしてもよかったかも。話きいて再検討したけど十分妥当な実装にはできたし、UPDATEもINSERT も発生しないからプロセス内キャッシュに価値はあった

くやしい

まとめ

  • もうだめ
  • 本戦がんばります…

タイムライン

主観なので rosylilly, mirakui のはうろ覚えと git commit log でしか追えてない。というかチームメイトが何やったかそれ以外で正確に把握してない…。

  • 9:00 集合する

  • 9:30 チームビルディングと称して アイカツ! #152 を見る

  • 10:00 チームビルディングの一環でリアルタイムでプリパラ #64 を見て、前頭葉を破壊される

  • 10:30 チームビルディング、そして緊張を解くために ゆるゆり なちゅやちゅみ!+ +2 を見る

  • 11:00 競技開始 (sorah)

  • 11:07 インスタンス起動 (sorah)

  • 11:15 チームのリポジトリに webapp の初期実装をコミット (sorah)

  • 11:17 ps auxf と netstat -pln を眺める (ISUCON4 の反省) (sorah)

  • 11:41 unicorn の設定調整と、systemd の unit file みて reload の設定がすでに入っていて便利! を感じた (sorah)

  • 11:41 app にクエリログ吐かせるようにしてうわぁってなる (sorah)

  • 11:51 mysqldump 時間かかるな〜とおもっていたが、ここで /var/lib/mysql の巨大さを確認する (sorah)

  • 11:46 unicorn の設定調整する (sorah)

  • 11:55 htop と dstat 入れとく (sorah)

  • 12:07 mysqldump の実行中。1300MB を突破してもなお終わらない…と嘆く (sorah)

  • 12:13 コードだけ見て分かるレベルで挙動をまとめる (sorah)

  • 12:13 dpkg -l も眺めておく。ついでに nginx を 1.9.4-1+vivid0 に上げる (sorah)

  • 12:20 mysqldump が終わる。gzip 圧縮後 67MB。最初から |gzip で圧縮しつつやったほうが(ディスクパフォーマンスが悪いので)良かった気がする。 (sorah)

  • 12:21 unicorn プロセス数を 4 にする (sorah)

  • 12:27 redis の準備をする (sorah)

  • 12:36 雑に手元で開発できるようにした (sorah)

  • 12:38 Sinatra の設定を RACK_ENV=production に切り替える (sorah)

  • 12:38 my.cnf を設置して設定したつもりになる (後述) (mirakui)

  • 12:56 is_friend? 対策でとりあえず SELECT one, another, created_at FROM relations WHERE one = ? OR another = ? を 1 リクエスト中で使い回すようにする (sorah)

  • 12:58 Redis によるキャッシュを導入する (rosylilly)

    • 効果微妙なところもある気がしている

  • 13:05 雑なコミットにより実装が巻き戻されたのでキレながら git revert する (sorah)

  • 13:12 クエリログで呼び出し元表示するようにする (sorah)

  • 13:14 get_user, user_from_account に Redis キャッシュが導入される (rosylilly) なお効果は未検証

  • 13:19 stackprof.gem 導入 (sorah)

  • 13:25 ベンチマーカーのリクエストヘッダを確認する (mirakui)

  • 13:31 そういえば redis の初期化を /initialize でしてなかったのでするようにした (sorah)

  • 13:36 sysctl.conf 調整。RFS の有効化や、TCP ローカルポートの調整 (mirakui)

  • 13:36 varnish に挑戦しはじめる (mirakui)

  • 13:58 トップページ対策などで、title, content の分離・トップページの relations への SELECT を 12:56 に導入したキャッシュを利用・comments_of_friends で entries を JOIN するようにする (sorah)

  • 13:58 title と content カラム分離の ALTER TABLE と UPDATE を開始 (sorah)

  • 14:20-30? 上記 alter が終了する (sorah)

  • 14:40 footprint を redis sorted set ベースにした実装が完成、 pull request になる (rosylilly)

  • 14:52 なんかベンチこけるなーと思ったら entries の作成で title カラムへ値突っ込んでなかったてへぺろ (sorah)

  • 14:57 footprint の redis 実装のレビューを受けてマージ (rosylilly)

  • 14:59 この時点でスコア 920。みんな敗退かなぁと考えはじめる

    • 時間を食ってるのは引続きトップページ

  • 15:00 日記リストページのコメント数に、 Redis によるカウンタキャッシュを導入する (sorah)

  • 15:07 /friends ページの users を WHERE IN で引いてくるように変更 (sorah)

  • 15:21 relations にインデックス追加してフレンドリスト取得の 120ms ほどのクエリを 7ms 台にする (sorah)

    ALTER TABLE relations ADD INDEX friendship_a (`one`,`created_at`);
ALTER TABLE relations ADD INDEX friendship_b (`another`,`created_at`);

    mysql> EXPLAIN SELECT one, another FROM relations WHERE one = 10 OR another = 10;
+----+-------------+-----------+-------+---------------+------------+---------+------+--------+--------------------------+
| id | select_type | table     | type  | possible_keys | key        | key_len | ref  | rows   | Extra                    |
+----+-------------+-----------+-------+---------------+------------+---------+------+--------+--------------------------+
|  1 | SIMPLE      | relations | index | friendship    | friendship | 8       | NULL | 495426 | Using where; Using index |
+----+-------------+-----------+-------+---------------+------------+---------+------+--------+--------------------------+
1 row in set (0.00 sec)

mysql> EXPLAIN SELECT one, another FROM relations WHERE one = 10 OR another = 10;
+----+-------------+-----------+-------------+--------------------------------------+-------------------------+---------+------+------+--------------------------------------------------------+
| id | select_type | table     | type        | possible_keys                        | key                     | key_len | ref  | rows | Extra                                                  |
+----+-------------+-----------+-------------+--------------------------------------+-------------------------+---------+------+------+--------------------------------------------------------+
|  1 | SIMPLE      | relations | index_merge | friendship,friendship_a,friendship_b | friendship,friendship_b | 4,4     | NULL |  208 | Using sort_union(friendship,friendship_b); Using where |
+----+-------------+-----------+-------------+--------------------------------------+-------------------------+---------+------+------+--------------------------------------------------------+

  • 15:36 varnish を突っ込んでみるが、コケたので断念 (mirakui)

  • 16:41 スコア 7653

  • 15:44 entries_of_friends クエリがフレンドリストを元に WHERE user_id IN (?) をするようになる (rosylilly)

  • 15:48 unicorn worker 12 に (mirakui)

  • 16:00 comments_of_friend クエリの改善を一旦あきらめキャッシュする (rosylilly)

  • 16:13 pt-query-digest コマンドを試す (mirakui)

    • comments_for_me_query は重いなぁなど
    • redis の sorted set にない足あとは初回アクセス時に SQL で引いて ZADD するようにしてたけどそれも重い

  • 16:27 comments_for_me をキャッシュする (sorah)

  • 16:27 コメント投稿で SELECT するカラムを減らす (sorah)

  • 16:33 innodb_flush_log_at_trx_commit = 0 にした(つもりになる) (mirakui)

  • 16:36 ログ解析の時間。やはりトップページが支配的。次にコメント投稿、日記リスト

  • 16:48 初期データチェックの結果 relations テーブルで one, another 両方を見る必要はないと判断してクエリから another を削る (rosylilly)

  • 17:10 足あとよく見ると同じユーザーは日を跨ぐとリストに複数回出現しうる、ので実装を念のため変更 (sorah)

  • 17:23 たしかこの辺で my.cnf が実は効いてない事に気付く。よくわからんが symlink をやめて解決 (mirakui)

    • AppArmor ときいて確かにとなる。普段仕事で datadir に対しては apparmor 調整したりしているけど my.cnf は盲点だった…。
    • バッファプールが無事 2GB になるしスローログも出るようになった。

  • 17:23 footprints に index 追加 ALTER TABLE footprints ADD INDEX idx1 (user_id, created_at); (mirakui)

  • 17:29 足あとリスト表示時に user を Redis から一個ずつ引くのではなく SQL で WHERE IN するようにしたら効果が出たどころかむしろ遅くなった懸念があったので一旦戻す (sorah)

  • 17:37 ユーザーに対するコメントリストのキャッシュはコメント追加時に再作成していたのをやめて、1秒キャッシュするように (rosylilly)

    • 1秒キャッシュは redis だと 1 秒ピッタリにしかできないのでビビって TIme.now.to_i をキーに突っ込んでいました

  • 17:45 謎の表示されるべきでないフレンド「タマキ」が表示されているというエラーで Fail。しばらく真剣に調査するが分からず頭を抱え、再度ベンチまわしたら通ったのでみなかったことに

  • 17:58 実装の変更により is_friend? を叩くと relations から全フレンドを取得していたので、必要ないリクエストでは SELECT で確認するように変更した (sorah)

    • 変更漏れがあってここ潰したらもっとはやくなったのではという…。

  • 17:58 各種ログ出力の停止 (mirakui)

  • 18:01 erb テンプレートから空白除去 (rosylilly)

  • 18:11 tmm1/gctools の oobgc を導入 (sorah)

  • 18:15 unicorn worker を 12 → 20 に (mirakui)

  • 18:16-35 再起動試験や、ベンチ複数回回して良い結果が出るまでガチャ。

  • 18:35 最終スコア 15666 確定で作業終了

  • 18:40 15時頃は敗退覚悟してたのにこの頃になると「4 位以内で本戦出場したすぎるんだよなあ〜〜????」などと叫びくねくねしていた

Published at