Ruby のメモリ使用量問題を調査し upstream で解決していただいた話

はじめに

こんにちは。リアーキテクティングチームの髙橋と申します。この記事では、アンドパッドの施工管理サービスで利用している Ruby をバージョンアップしたときに発生したメモリ使用量の問題の発生から解決までをお話しします。

Ruby のバージョンアップ（3.0 -> 3.2）

アンドパッドでは昨年 2023 に、施工管理サービスで利用している Ruby を 3.0 から 3.2 にバージョンアップしました。バージョンアップ自体は過去に確立済みの手法（詳しくは過去記事をご参照ください）により、粛々と進められリリースされました。

ところがこのリリースから数日後、とある問題が発覚しました。

メモリ増大問題

アプリケーションのリソース使用状況を監視している SRE チームのメンバーから、以下のような連絡がありました。

Ruby バージョンアップのリリース以降、アプリケーションの利用するメモリ量が増えている
このままだと OOM Killer によるプロセスの終了が発生しうる

インフラ設定で割り当てるメモリ量に余裕を持たせることでその場は凌ぎましたが、具体的になぜ問題が起きたのか、また回避しうるのかはすぐには判断がつきませんでした。そこで後日、この問題の調査を開始しました。

調査

heap-profiler gem を利用して原因を調査してみたところ、以下のようなことがわかりました。

Hash オブジェクトがヒープメモリ全体の 1/3〜1/2 程度を占めていること
その Hash オブジェクトは Ruby の標準添付ライブラリである set.rb によって作成されたものであること
ActionController::Base#action_methods というメソッドの付近でメモリの大量確保が起きていること
Rails アプリケーションなら常に起きるというわけではなく、以下の複合的かつ限定的な条件で起きること
- コントローラとルーティングが大量に存在すること
- Rails.application.config.eager_load が真であること
- before_eager_load フックのタイミングで Rails.application.reload_routes! が呼び出されること

問題の切り分けができてきたところで次に、Ruby のどの部分が問題なのかを調査しました。するとメモリが増大し始めたのはどうやらこの [Bug #16996] かららしい、ということがわかってきました。

調査の詳細

結果だけ先に述べましたが、調査についてもう少し詳しく説明します。

手元のローカル環境だと再現しない問題への対応

手元では Ruby のバージョンに関わらず、bin/rails server や bin/rails runner で Rails を立ち上げてもメモリ消費量はそれほど大きくなりませんでした。こういったことはよくありますが、手元で再現しないというのはそれだけで試行錯誤の頻度と幅を悪化させるため、なかなか大変でした。本番環境の可動サーバーにプロファイラを入れるのも、調査の初手としては難しいものがありました。

幸い開発用の社内サーバでは再現したので、heap-profiler で情報を取得することで Set や Hash が問題になっていることわかってきました。ここではオブジェクトの種類くらいしかまだわからなかったため、この Set がどこでどのように作られたものなのかを引き続き調査しました。

アプリケーション中の問題箇所の特定

施工管理サービスのアプリケーションコードは巨大で利用している gem も多いため、問題がどこで起きているかを特定するのは当てずっぽうでは難しい状態でした。

問題の調査にあたり Set オブジェクト作成時にバックトレースとオブジェクト ID を記録するようにモンキーパッチを当ててみました。メモリ使用量が増えてから Set オブジェクトを列挙して ObjectSpace.memsize_of の結果と先ほど記録したバックトレースを突き合わせることで、具体的な問題の箇所がわかってきました。

具体的には、ActionController::Flash.action_methods というクラスメソッドで Set の差分を計算したときに問題が発生していました。

      def action_methods # :nodoc:
        @action_methods ||= super - _flash_types.map(&:to_s).to_set
      end

この差分計算の左項の super はAbstractController::UrlFor.action_methodsを呼び出します。そのため、_routes が定義されている場合はさらにここでも差分計算がなされます。

      def action_methods
        @action_methods ||= if _routes
          super - _routes.named_routes.helper_names
        else
          super
        end
      end

左項の super ではAbstractController::Base.action_methodsによってコントローラの公開メソッドほぼ全ての名前を返します。また右項の _routes.named_routes.helper_names はルーティングヘルパー全ての名前を返します。ここが問題になってきます。

ルーティングが多数存在するアプリケーションでは、大量の重複した要素を含む Set 同士の差分を取得した結果としてごく小さな Set が作成されます。ここで Ruby は処理の高速化のためなのか、内部で確保したメモリを解放せずそのまま保持していました。この小さな Set に対して ActionController::Flash.action_methods ではさらに差分計算しますので、ここでオブジェクトのコピーが発生します。ここでもやはり、メモリの解放は行われていませんでした。

つまり (1) 巨大な Set 同士の差分計算 (2) その Set オブジェクトのコピー、という一連の処理が何回も行われ、その結果メモリが異常に圧迫されていたようでした。

Ruby 内の問題箇所の特定

ここまで辿り着ければあとは根気の問題で、コードや利用する gem を削って最小の再現コードを作成し、git bisect で Ruby 側のコードの具体的な問題箇所を特定するに至りました。再現コードと実行例を示します。

% ruby -v -rset -e 's1 = Set.new(10000.times); s2 = Set.new(9999.times); Array.new(10000) { s1 - s2 - [0] }; puts "#{`ps -o rss= -p #{$$}`.to_i / 1024} MiB"'
ruby 3.2.2 (2023-03-30 revision e51014f9c0) [arm64-darwin22]
2304 MiB

% rbenv local 3.0.4 
% ruby -v -rset -e 's1 = Set.new(10000.times); s2 = Set.new(9999.times); Array.new(10000) { s1 - s2 - [0] }; puts "#{`ps -o rss= -p #{$$}`.to_i / 1024} MiB"'
ruby 3.0.4p208 (2022-04-12 revision 3fa771dded) [arm64-darwin21]
186 MiB

Ruby 本体への報告と Ruby 開発チームの対応

社内で事象を共有したところ、この問題は Ruby 本体に報告するべきだという話になり、Ruby フルタイムコミッタの柴田さんから代わりに [Bug #19969] として報告していただきました。

その後、問題を修正するコミットが Ruby の master ブランチに入り、バックポートも Ruby 3.1, 3.2 それぞれに入りました。

さらに先日 Ruby 3.2.3 がリリースされました。手元で確認したところ確かにメモリ使用量が削減されていました。今後本番環境にも修正バージョンをリリース予定です。

% ruby -v -rset -e 's1 = Set.new(10000.times); s2 = Set.new(9999.times); Array.new(10000) { s1 - s2 - [0] }; puts "#{`ps -o rss= -p #{$$}`.to_i / 1024} MiB"'
ruby 3.2.3 (2024-01-18 revision 52bb2ac0a6) [arm64-darwin23]
42 MiB

変更内容

先にも述べたように、メモリ使用量の問題が発生したのは [Bug #16996] という速度改善の変更が入ってからでした。単純にこの変更がリバートされてしまうとメモリの問題が改善されても速度が低下してしまうのではないかという懸念がありましたが、実際に入った変更ではメモリ改善と速度が両立されていて、全くの杞憂でした。

ざっくりとした理解では、以下のような変更だったようです。（私が読んだ限りの理解なので、誤っていたらすみません）

速度改善の変更([Bug #16996])では、Hash オブジェクトのコピー時に rehash という重い処理をしていた箇所を、単純な構造体のコピーに置き換えた。
- この時構造体が無駄にメモリを使うケースが存在した。
- 具体的には、削除した要素のためのメモリ領域が確保されたままだった。
メモリ使用量改善の変更([Bug #19969])では、要素の削除時に確保領域の大きさを確認し、不要なメモリがあまりに大きいようなら構造体を再構築してメモリを解放・再確保するようにした。
- 「あまりに大きいようなら」というのがポイントで、問題が軽微な間は再構築処理が行われないため高速に動作する。