バックエンドエンジニアの@cureseven です。レスポンス改善プロジェクトという名前で、BASEのレスポンス速度を早くするために10月より動いてきました。 経緯に触れた後、レスポンス改善をどう進めてきたかとおこなった施策を紹介します。
レスポンス改善プロジェクトの経緯
始めにプロジェクトが立ちあがった経緯を少しお話します。 BASEはリリースして9年ほど立ちました。その間、さまざまな機能が追加されたり、ありがたいことに多くのユーザーさんに使っていただいています。その結果、DBに保存しているデータ量が増えました。データ量が多いことによりSelectの実行時間が重くなるなどが起こっていました。 ユーザの方から複数件画面の重さについてのお問い合わせをいただいており、今回プロジェクトとして改善することになりました。
重いリクエストの特定
それではここから、どう進めてきたかとおこなった施策を紹介します。 BASEではNew Relic Oneを導入しており、リクエストごとのレスポンス速度の統計を見たり、Transactionの詳細を見ることができます。私たちはNew Relic APMで重いリクエストを突き止め、施策を実施しました。 New Relic APM Transactionsのページで、
- Most time consuming（実行回数 × 平均実行時間）
- Slowest average responce time（平均実行時間）
を見比べながら、平均実行時間が遅すぎるものやたくさんの人が利用していて不便に感じそうなものを中心に見ていくことにしました。
dashboardによる重いリクエストの可視化
オーナーさんからのお問い合わせを受けるより先に社内で重いリクエストがあったことを知るために、Transactionのdashboardを作成し監視することにしました。 dashboardでは注文数の多いshopをいくつかピックして、オーナーさんの使う管理画面に限定したTransactionの95パーセンタイルの重さが目立つリクエストを表示しました。
alert飛ばす設定
dashboardを作成しましたが、張り付いて監視しないでいいように、alertを飛ばす設定をしました。 今回は購入者が触れる画面, オーナーさんの使う管理画面両方において、それぞれにTransaction timeの閾値をセットし、リクエストごとに95パーセンタイルが閾値を超えたときにslack通知するようにしました。
設定に役立ったリンクです。
レスポンス改善施策の実施
New Relic APMのTransaction traceという機能で、Transactionの詳細を見ることができます。どのメソッドのどのクエリが重いかまで断定できます。 私たちは重いリクエストのTransaction traceを見ることでボトルネックを把握し、リファクタ方針を考えました。リファクタ施策の具体例をいくつか紹介します。
indexを貼った
重いクエリを発見したとき、explainして実行計画がどのようなものかを確認しました。indexが適切に使われていないクエリを発見したので、indexを貼る対応を実施しました。
不要な処理を消した
機能のリニューアルや機能を廃止する中でいらなくなった処理が残ってしまうことがあります。今回、そんな処理がTransaction timeを圧迫してしまっていました。不要な処理を削除することでレスポンスが改善しました。
クエリ改善
今回よく目にしたのが、レコードの存在の有無だけ分かればいい時に、集計したり大量にデータを取ってきたりしているというものでした。レコードの存在有無確認は最初の1件だけとれば良いので、集計処理などをやめることで、クエリ実行時間を短縮できました。
また、画面描画毎に一つずつのデータを取ってきて集計するのではなく、バッチで集計したデータを格納しているテーブルを利用するようにする修正を実施しました。こちらの修正では、95パーセンタイルで15秒ほどかかっていたリクエストが、1秒以下で返ってくるようになりました。
また、注文数をカウントする処理では、画面上は99以上になると「99+」という表示になるところがあります。大量に注文があるshopのクエリがとても重くなってしまっていたため、サブクエリを使って100件以上は数えないようにしました。
バッチ実行の負荷軽減
New Relic APMのTransaction traceは、1分ごとに、基準値より重かった最大Transaction timeの詳細を残しています。 取れたTransaction traceを眺めていると、どうやら15分ごとに基準値に引っかかっていることがわかりました。詳細を見ると、15分おきに出ているTransaction traceではdb接続に決まって6秒ほどかかっていることがわかりました。 原因は15分間隔で実行されるバッチにて大量レコードのtruncateおよびinsertのSQLを実行していることでした。一旦メモリにもった上でループ処理することで急激な負荷を抑えることで、15分おきに出ていた6秒のdb接続時間は解消されました。 dashboardを見ているだけではこのような傾向を読み解くことはできませんでした。Transactionの99パーセンタイル、95パーセンタイル、50パーセンタイルを見比べたり、Transaction traceの出力時間を見たりすることで見えてくるものもありました。
プロジェクトを通して
3ヶ月間対応を行なってきた結果、画面ロードが遅いことに関してお問い合わせいただいていたshopさまから改善されたねの声をいただきました。しかしながらまだまだ遅い画面はあるため、来年以降も改善にむけて動いていこうと思っています。 最後に、レスポンス改善プロジェクトを通して感じたことを記して終わろうと思います。
機能リニューアルなどのタイミングで適切に不要な処理を消すのはもちろんですが、今回のプロジェクトのようにたまにリファクタをするための期間を設けてそのような処理がないか見直すのは大事だなと思いました。大掃除の季節ですし、ソースコードの見直しを実施するいいタイミングなのかもしれません。可読性も上がります。
機能開発のタイミングで貼ったindexが、データが増えることにより効かなくなるときがあります。今回の施策で劇的に効果が上がったのはindexの付与でした。こちらもリリース後年月が経ってから改めて見直すのが良いなと思いました。
あまりにもレスポンスが遅いと素晴らしい機能も使い物にならないので、仕様を少し変更して大幅に改善するものであれば、変更することも検討してみるのがいいなと思いました。 これからも使っていけるサービスであるために、さまざまな実装方法を検討する必要があると改めて感じました。
