こんにちは！フルサポート開発チームの高畑（Sorarinu (@int_sorarinu) / Twitter）です。
つい最近、ISUCON 12 の予選があったようで、 Twitter のトレンドに「SQLite」が上がっていて DB 屋さんたちがザワザワしていたようですが、皆さんいかがお過ごしでしょうか。
自分は ISUCON 9 以来参加できていなくそろそろ参加したいなと思っているのですが、その前に社内の管理画面をパフォーマンスチューニングして ISUCON の雰囲気を思い出してきたのでご紹介します。
これまでの現状
ビザスクの管理画面が出来てから結構年数が経ってきており（first commit が 2012 年）、所々 N+1 を許容する実装や DB の JSON カラムなどが存在しており、ユーザが増えていくにつれて段々とパフォーマンスに影響が出てきていました。
情報量が多いページになると遂にはタイムアウトで開かなくなり業務に支障が出てきてしまうのと、最近着々と進んでいる新システムへの移行に際しタイムアウト制限がより厳しくなってくることが予想されたためパフォーマンスチューニングを行なっていきました。
パフォーマンスチューニングの進め方
今回パフォーマンスチューニングを行うにあたり、いくつか前準備を行なって本番環境で動作検証を行えるようにしていきました。
速度改善検証モードに切り替えるボタンを設置
ローカル環境やステージング環境では圧倒的にデータ量が不足しているため、本番環境で効果検証するために開発チームに限定して表示する速度改善検証モードのボタンを仕込みました。
これにより、管理画面を利用するユーザに影響を与えず改善前・改善後の効果検証を行えるようになったため、気軽に本番環境へ出して効果を見てみるといった動きができるようになりました。
メソッドごとに時間計測するためのログを仕込む
特に遅い API エンドポイントでは複数の情報をまとめて取りにいって整形を行なっているため、実際にどのメソッドがどれくらい時間がかかっているのかを可視化できるようにログとして処理時間を出力するようにしました。
このログを見ながら「どのメソッドが遅いのか」、「改善前と後でどのような変化があったのか」を逐一モニタリングしています。
ISUCON だったら最後このログを削除したりしますが、まだまだ改善は続くので今も出力されています。
（本当は APM も見たいけど現状は APM は入っていないので今後の課題ですね...）
重複ユーザチェックの N+1 脱却
まず初めに取り掛かったのが電話番号をもとにした重複ユーザチェック部分の N+1 解消です。
ビザスクの管理画面では候補者リストといった、案件に紐づくアドバイザーの一覧が表示される画面が存在します。
そこで呼び出す API でアドバイザーの登録している電話番号をもとに重複しているアドバイザーがいないかを見ているのですが、アドバイザーを全件取得してきて電話番号検索を人数分かけるという所謂 N+1 の状態となっており、候補者リストにアドバイザーが多く追加されればされるほど非常に重たくなっている状態でした。
そのため、今回のパフォーマンスチューニングで候補者リストに存在するアドバイザー全員の電話番号を取得して一括で重複ユーザを取ってこれるように Django の QuerySet を組み立てていきました。
これにより、まだスパイクはあるものの遅いところで 17,039ms かかっていたものが 1,039 ms で捌けるようになったので着実に進歩していると感じています。
アドバイザーに紐付くデータから取得するカラムを絞り込む
次に取り掛かったのが SQL のカラム絞り込みです。 これまではアドバイザーに紐付くデータを取ってくるために SQL を発行した際、JOIN したテーブル含め全てのカラムを取得してきていたため結果セットに含まれるデータ量が多くなりメモリ消費やパフォーマンス影響が出ている状態でした。
そのため、本当に利用するデータのみ取得してくるように QuerySet を修正したところ、遅いところで 24,837 ms かかっていたものが 14,992 ms まで改善しました。 それでも約 15 秒もかかっていることに変わりはないのですが、これは次の施策の時に効いてくるため良しとしています。
これだけでパフォーマンスが上がるので全てのカラムを取ってきているクエリがないかどうかを今一度確認したほうが良いですね。
アンケートの設問・回答をタイトルクリックした時に取得してくるようにする
ビザスクの管理画面は歴史的経緯によりアンケートの設問と回答がセットになった JSON がカラムに詰め込まれていて、上記の API で JSON で保存された回答と設問を整形して返している処理がめちゃくちゃ重たくなっている状況でした。
レスポンスとして返された設問と回答はアンケート一覧のタイトルをクリックしたときに表示されるようになっているのですが、これはタイトルをクリックするたびにアンケートの詳細を取得する API を叩けば良いのでそもそも JSON カラムを取得してこないようにクエリの改善を行いました。
結果、上記で 14,922ms かかっていたものが 1,394ms まで改善されたため、上記の結果を合わせて全体的に約 18 倍の高速化を図ることができました。
おわりに
ISUCON 12 が盛り上がっている後ろ側で社内 ISUCON をしてみましたがいかがだったでしょうか。
まだまだデータの正規化やインデックス見直しの余地があったりするので、これからもパフォーマンスチューニングを継続できたら良いと思っています！
