はじめに
去年あたりから、運用ゲームアプリのサーバーサイドが抱える負債返済を目標に掲げて、モニタリングツール（本記事の内容を実施していた時点ではNew Relic）で処理時間が目立つAPIの調査、改善を行っていました。
特に処理時間がかかっているものに、ログインAPI（タイトル画面で呼び出される）が挙がっており、本文書はそれを改善した話になります。
調査
（応答が遅いなど）一定条件を満たしたトランザクションについて、トレースログを確認することができるので、処理時間の中で特に大きな割合を占めているもの（Slow span）を退治していきます。
デフォルトだとコード部分はApplication code in ???という表示で内訳が分からないのですが、カスタムのトレーシングを仕込むことで、method単位や code block単位でのトレースを行うことができます。
カスタムトレーシング結果
ステージング環境のコードにカスタムトレーシングを仕込んでログインAPIを何度か呼び出し、トレーシングしました。
引き続き、処理時間が大きい箇所はApplication code in ???に隠蔽されているんですが、箇所としては絞り込めていて、「デイリー／ウィークリーミッションが日／週をまたいでいたらユーザーデータをリフレッシュする」という処理でした。
（実際に動いているコードからはある程度書き換えています）
daily_mission_ids = デイリーミッションのmission_id群
weekly_mission_ids = ウィークリーミッションのmission_id群
# ここから
user.missions.each do |user_mission|
if daily_mission_ids.include?(user_mission.mission_id)
daily_user_missions << user_mission
elsif weekly_mission_ids.include?(user_mission.mission_id)
weekly_user_missions << user_mission
end
end
# ここまで
daily_user_missions.each { updated_atが本日0時以前ならrefresh!する }
weekly_user_missions.each { updated_atが今週月曜日0時以前ならrefresh!する }
原因
user.missions.eachのところで当該ユーザのUser::Mission全件がActiveRecordインスタンス化され、そこで件数がすごいことで時間がかかっていました😫
User::Missionはデイリー／ウィークリーミッションだけではなくその他すべてのミッションに対して、1ユーザーミッション1個に対して有効期限内に進捗があれば1レコード作られています。
終了したミッションでも開催当時に挑戦していたらレコードが残っているので、運用の経年によって、古参ユーザーだと1人あたり5,000レコードある人もいました。
本アプリでは後続の処理でのDB再リードを避けるためにuserのassociationに全件キャッシュしておくことを意図してこのように記述している処理がそこそこあり、たしかにそれが功を奏しているシーンもありはするのですが、本件については件数が多すぎだったかな、開発時に件数多くなる箇所への考慮検討がなされるべきだったかな、と思います。
対策
処理が必要なレコードだけ読んでくるようにSQLで絞り込むことで、ActiveRecordインスタンス化する個数を減らしました。
リフレッシュ対象をupdated_atで判断しているので、SQLでupdated_atが本日／今週内でないものだけ取得し、取得したもの＝リフレッシュ対象なのですべてリフレッシュします。
# day = 本日0時
query_to_daily_refresh = user.missions.where(panel_mission_area_id: daily_mission_ids)
.where.not(updated_at: day...(day + 1.day))
# beginning_of_week = 今週月曜日0時
query_to_weekly_refresh = user.panel_missions.where(mission_id: weekly_mission_ids)
.where.not(updated_at: beginning_of_week...(beginning_of_week + 1.week))
user_missions_to_refresh = query_to_daily_refresh.or(query_to_weekly_refresh)
user_missions_to_refresh.each(&:refresh!)
その他の呼び出し箇所対応
- ミッションに対応する処理を行った際のミッション進捗、達成判定処理
- ユーザ通知用に、達成済みかつ報酬未受取のミッションを取得する処理
でもuser.missionsの全取得があり、先ほどの箇所だけを修正しても、ここで同様に処理時間がかかってしまうため、対応を行います。
associationキャッシュが効いていたら、これらの箇所では処理時間かかっていなかったかもしれないですが、全箇所で対応を揃えないと、結局いつのタイミングでかかるかという話になってしまうためです。
ミッション進捗、達成判定
ActiveRecordインスタンスを生成してからselectしていたので、whereに置き換えました。
before
# 事前に対象mission_idsは絞り込まれている
target_user_missions = user.missions.select { |user_mission| mission_ids.include?(user_mission.mission_id) }
after
target_user_missions = user.missions.where(mission_id: mission_ids)
達成済みかつ報酬未受取のミッションを取得する処理
ここについては、対象ユーザのUser::Mission全件の確認が必要でしたが、必要なのはmission_idだけだったので、SQLで絞り込んだ上でpluckでmission_idだけ取り出して、ActiveRecordが作られないようにしました。
before
user.missions.each do |user_mission|
next unless user_mission.to_be_claimed? # 達成済みかつ報酬未受取状態を表すinstance method
# 以降 user_mission.mission_id に対する処理
end
after
# model に以下を用意
scope :to_be_claimed, -> { to_be_claimed? method と同等の SQL }
user.missions.to_be_claimed.pluck(:mission_id).each do |mission_id|
# user_mission.mission_id に対する処理
end
複合ケース
これらの処理が1APIで複数走る場合が往々にして存在し、その場合に関して言うと、従来associationキャッシュが効いてDBリード自体は1回だったのが、最大3回のリードになってしまいます。
しかし、ActiveRecordインスタンス化される個数は5,000→40程度まで減らすことができており、処理時間で言うと修正後の方がだいぶ速い結果となりました。
効果
ログインAPIについて、計測時平均で40%程度の改善が見られました！🎉
また、ミッション進捗、達成判定については、ミッションの条件となっている操作API全般で呼び出されているので、ログインAPIに限らず、かなりの数のAPIに速度改善が見られます 🌟
皆様のアクセス、ゲームプレイングが快適になっていれば幸いです。
余談
実は調査当初、ステージング環境のカスタムトレーシングでは当該箇所の処理時間があまりかかっていなかったので、「本番環境では時間かかっているのに何でだろう？🤔」となっていたのですが、新規ユーザーでUser::Missionの件数が少ない状態で確認していたことが原因でした。
本番ユーザーとの違いを考えて、デバッグ機能で過去分のUser::Missionをたくさん作ってから確認することで、本番環境で発生しているのと同じぐらいの処理時間を観測することができました。
まとめ
- レコード全件読んでいる箇所について、本当に必要か検討する
- ActiveRecordインスタンス作ってからinstance methodで絞り込んでいるところを、できるだけSQLで絞り込む
- 個別columnだけで良くてinstance method使わなくて良いところはpluckする
- associationキャッシュが効果あるケースもあるので、計測結果を基に正しく判断検討する
- 処理時間測定は本番相当のデータ多めの状態にして行う
Discussion