デプロイ直後のレイテンシスパイクを調べたら、 Railsの仕様にたどり着いた

Gotanda.rb#69 での登壇資料です。
https://gotanda-rb.connpass.com/event/400850/

Transcript

1. デプロイ直後のレイテンシスパイクを調べたら、 Railsの仕様にたどり着いた Naohisa Yokoyama / 株式会社マイベスト 2026-08-26 @Gotanda.rb
2. 自己紹介 Naohisa Yokoyama 株式会社マイベスト プロダクト開発部 イネーブリングチーム 家の周りの草むしりに追われています。 X : @_shrrk 2
3. 今日話すこと デプロイ直後にレイテンシがスパイクする問題 2 Railsはスキーマをいつ読むのか 3 解決の選択肢と、試してみた結果 1 3
4. デプロイ、してますか？ マイベストでは原則featureブランチをマージするたびにデプロイする運用 バックエンドだけで、平日は1日10回ほど 4
5. デプロイのたびにレイテンシが跳ねる デプロイ後、ほぼ必ずスパイクする状況。何が起こっているのか？ 5
6. 最初の仮説: Blueの残りが歪めている？ デプロイはBlue/Greenで、切り替えの最中は新旧が並走する。 ▬ 完了済み ▬ まだ処理中 トラフィックをGreen に切り替え Blue（旧） 時間 ← 新規は来ない 生き残るのは長いリクエストだけ Green（新） （切り替え前は、まだ存在しない） 切り替え後の新規は全部こっち。短く終わっていく 見ていたのはALB単位のレイテンシ ALB単位の集計だと新旧が混ざる → この遅い残りがメトリクスを押し上げている…？ 6
7. 遅いのは新しいプロセス側だけだった ALBではなくアプリ側のAPMを見てみると同じようにスパイクしていた バージョン別で見てみると、跳ねているのはほぼデプロイ後のバージョン 7
8. 初回リクエストのトレースを開く 72本・合計0.8秒 72本・合計1.5秒 起動直後のリクエストに、スキーマを問い合わせるクエリが集中する 平常時のリクエストには、このクエリは出てこない 8
9. クエリを出しているのは、この2つのメソッド # activerecord 8.1.3.1 — connection_adapters/abstract_mysql_adapter.rb def column_definitions(table_name) # 992行目 internal_exec_query("SHOW FULL FIELDS FROM #{quote_table_name(table_name)}", "SCHEMA", allow_retry: true) end def primary_keys(table_name) # 611行目 query_values(<<~SQL, "SCHEMA") SELECT column_name FROM information_schema.statistics WHERE index_name = 'PRIMARY' AND table_schema = ... AND table_name = ... SQL end : カラム名・型・DEFAULT・NULL許可 → attribute methodsの定義 / 型キャスト / Model.new の初期値 primary_keys : 主キーがどのカラムか → find や id の解決 column_definitions どちらも、プロセスがそのモデルに初めて触れたときに発行される。以降はそのプロセスのメモリから読む 9
10. attribute methodsとは 普段皆さんが書いている user.name や user.name_changed? などがそれ モジュール 生えるメソッド（抜粋） Read / Write name Query name? Dirty name_changed? Dirty（ActiveRecord） saved_change_to_name? will_save_change_to_name? BeforeTypeCast name_before_type_cast name_came_from_user? / name= name_was name_will_change! restore_name! name_in_database 10
11. スキーマは遅延読み込みされている 新しいプロセス 1回目のリクエスト リクエスト モデル（User） DB モデルに初めて触れる カラム定義が要る → load_schema キャッシュが空なので問い合わせる レスポンス（遅い） カラム定義 @schema_loaded = true → 以降このモデルは読まない これを触るモデルごとに 2回目以降 レスポンス（速い） キャッシュ済みなのでDBに行かない 11
12. スキーマキャッシュはプロセスごとに持つ 読んだスキーマが残るのはそのプロセスのメモリだけ。隣のプロセスからは見えない ECSサービス …（タスクは数十個） タスク プロセス 数十モデル タスク プロセス 数十モデル プロセス 数十モデル タスク プロセス 数十モデル プロセス 数十モデル プロセス 数十モデル 初回リクエスト 初回リクエスト 初回リクエスト 初回リクエスト 初回リクエスト 初回リクエスト プロセス プロセス プロセス プロセス プロセス プロセス 数十モデル 初回リクエスト 数十モデル 初回リクエスト 数十モデル 初回リクエスト 数十モデル 初回リクエスト 数十モデル 初回リクエスト 数十モデル 初回リクエスト 発行されるのは各プロセスが初めてそのモデルに触ったとき。 デプロイで全プロセスが入れ替わるので、そのたびに一巡する 12
13. なぜ遅延読み込みになっているのか？ # activerecord 8.1.3.1 — active_record/railtie.rb:149 initializer の冒頭 # For resiliency, it is critical that a Rails application should be # able to boot without depending on the database (or any other service) # being responsive. # # Otherwise a bad deploy adding a lot of load on the database may require to # entirely shutdown the application so the database can recover before a fixed # version can be deployed again. # 同ファイル:168 — 条件式の直前 # This means the attribute methods will be lazily defined when the model is accessed, # likely as part of the first few requests or jobs. This isn't good for performance # but we unfortunately have to arbitrate between resiliency and performance, and chose # resiliency. DBが重いだけでアプリが起動できない → 修正版もデプロイできず、復旧はアプリを全部止めるしかない Railsは「何があっても起動できること」を優先し、コストを起動直後のリクエストに先送りしている 13
14. Schema Cache Dump とは スキーマ情報を1ファイルに書き出しておき、起動時にそこから読むRails標準の機能 コマンドが用意されている → rails db:schema:cache:dump で db/schema_cache.yml ができる これがあれば、テーブルごとの問い合わせが要らない バージョン照合（ check_schema_cache_dump_version 、既定で有効） 起動時に、dumpに入っているスキーマバージョンと、いまDBにあるバージョンを突き合わせる ずれていたらdumpを捨て、いつもどおりテーブルごとに問い合わせる 目的は古い定義のまま動かさないこと # activerecord 8.1.3.1 — connection_adapters/schema_cache.rb:128 if new_cache.version(connection) != current_version warn "Ignoring #{@cache_path} because it has expired. ..." return end 14
15. 遅延定義をやめる選択肢 何もしない : 遅延のまま。デプロイのたびにスパイクが発生する ✕ Dumpを置く（照合ON） : 問い合わせは消えるが、Ridgepoleでは照合が効かない ✕ 照合が見ているのは schema_migrations の最新バージョン → Ridgepoleはこのテーブルを更新しないので、常に一致してしまう △ Dumpを置く（照合OFF） : 起動時に全モデルが定義される。 ridgepole:apply の直後に生成すれば古くならない 生成したダンプファイルを各タスクに配布する仕組みが必要（S3に置いて起動時に取得するなど） ◦ 自前で起動時に定義 : 起動が数秒延びる。ファイルは要らない。一番小さい変更なので、まずはこれにした 15
16. 実装: 起動時に全モデルを温める # config/initializers/schema_warmup.rb — 実装イメージ（実物は約60行・gemなし） Rails.application.config.after_initialize do ApplicationRecord.descendants.each do |model| model.define_attribute_methods # スキーマ情報の取得と定義を実行 end rescue => e # DBが不健全でも起動自体は成功させる Rails.logger.warn("SchemaWarmup: failed error=#{e.class} message=#{e.message}") end マスタープロセス（fork前） 全モデルを定義 = 1回だけ fork プロセス1 定義済み 起動が数秒延びる。ヘルスチェックの猶予には収まる dumpを介さないので、ファイルの生成も配布も要らない プロセス2 定義済み プロセス3 定義済み プロセス4 定義済み fork後のプロセスは自分で定義しなくていい 16
17. リクエスト中のスキーマ問い合わせは消えた Webリクエスト由来のスキーマ問い合わせ／日（サンプリング後のスパン数）。7/31に対策を投入 対策の前後で約9割減 残りもデプロイと相関している 17
18. やったか！？ 18
19. 測り直した結果 赤い縦線がデプロイ（対策後・ALBレイテンシ） 悪化が2分以上続いたデプロイが32% → 7%、3分以上は0% スパイク自体は消えていない 19
20. この先どうするか、まだ決めていない プロセス起動直後の挙動をもう一度プロファイリングしてみる？ このまま受け入れる、という手もある → 悪化はほぼ2分以内に縮まったので影響は限定的？ 20
21. まとめ Railsはスキーマを起動時に読まない。プロセスごと・モデルごとに、初回アクセスで遅延ロードする 2 その1回のロードで、attribute methods・型キャスト・デフォルト値までまとめて用意される 3 キャッシュはプロセスの中だけ。タスク数 × プロセス数 × モデル数をデプロイごとに読み直す 4 遅延なのは意図的。DBに繋がらない状況でも起動できることを優先している 1 皆さんのプロダクトでは、デプロイ直後の遅さをどうしていますか 21