Copilotのメモリリーク問題

 (stevenharman.net)
1 ポイント 投稿者 GN⁺ 2024-05-12 | 1件のコメント | WhatsAppで共有

ActiveSupport::Notifications に関連するメモリリーク解決プロセスの整理

  • メモリリークが発生した状況

    • ある時点から web Dyno のメモリ使用量が異常に増加し始めた
    • Pager が鳴り始め、メモリリークと思われる状況が発生

  • 即時対応

    • Heroku ではメモリリークが疑われる場合、Dyno を再起動することで一時的に解決可能
    • 通常の deploy サイクルに合わせて restart するか、メモリ上限に近い Dyno を手動で再起動

  • 原因特定のための疑わしいコードの確認

    • memory spike 直前にデプロイされたコード変更を確認
    • 原因として疑われるいくつかのコードを一つずつデプロイし、メモリリーク発生の有無を確認
    • 原因らしいコードが見つからず、tooling の変更もロールバックして確認したが、メモリリークは継続

  • メモリ増加パターンの分析

    • リークは web Dyno でのみ発生。Sidekiq、Delayed::Job Dyno は正常
    • すべての web Dyno が常にリークするわけではない。数時間正常に稼働した後、1〜2台またはすべての Dyno でリークが始まる
    • トラフィック量よりも特定のトラフィックによって発生していると推測
    • Dyno 内のすべての Puma worker でリークが起きるわけではなく、少数の worker が全メモリの大半を使用

  • Heap dump の収集と分析

    • rbtrace を使ってリーク発生中の Ruby process の heap dump を収集
      • heroku ps:exec でリーク中の dyno に ssh 接続
      • ps コマンドで最もメモリを使用している Ruby worker process を選択
      • rbtrace で対象 pid に attach し、メモリ割り当て追跡を開始 (ObjectSpace.trace_object_allocations_start)
      • ObjectSpace.dump_all で heap dump を収集。サイズが大きい場合は gzip 圧縮
      • heroku ps:copy で dump ファイルをローカルへ取得
    • reap を使って heap dump を flamegraph として可視化
      • 1.9GB のメモリを参照している Thread と、その配下で 32,067 個のオブジェクトを参照する Array を発見
    • sheap を使って疑わしいオブジェクトを調査
      • その Thread は Puma の worker thread であることが判明
      • ActiveSupport::SubscriberQueueRegistry オブジェクトが Hash を参照しており、その配下に String と Array オブジェクトが存在
      • 問題の Array には 32,000 個を超える ActiveSupport::Notifications::Event オブジェクトが積み上がっていた

  • 原因の推論

    • ActiveSupport::Notifications の Event オブジェクトが #children array に誤って蓄積されていると推測
    • ActiveSupport::Notifications.instrument block 内でエラーが発生すると、その Event が #children から除去されず残り、メモリリークが発生すると推定

  • ローカルでの再現

    • production で見つかった疑わしい request path と parameter でローカルからリクエストを送信
    • 500 Internal Server Error とともに URI::InvalidURIError が発生することを確認
    • そのリクエストを送った production dyno のメモリ使用量が急増することを確認

  • 具体的な原因分析

    • Rails 7.1 で修正された ActiveSupport::Notifications の Event#children に関するバグが存在した
    • これに加えて、Bugsnag gem が request url を clean する過程で URI.parse 中に URI::InvalidURIError を raise するバグが重なり、メモリリークが発生
    • ActiveSupport::Notifications.subscribe block 内で raise されたエラーが捕捉されず、その Event が #children array から除去されないまま蓄積し続けるメモリリークが発生

  • 解決策

    • 短期: Bugsnag gem で URI::InvalidURIError が発生してもエラーを raise しないよう、バージョンを upgrade
    • 長期: ActiveSupport::Notifications のバグが修正された Rails 7.x に upgrade

GN⁺の意見

  • 問題を発見し、体系的に原因を特定していくプロセスが印象的。メモリリークが疑われる際に基本として試せる分析手順がよく整理されている
  • Ruby の heap dump 収集、可視化、分析のためのさまざまなオープンソースツール（rbtrace、reap、sheap など）が活発に開発されているようだ。Ruby に限らず、言語ごとの有用なメモリ分析ツールを把握し、問題に適用できることが重要だと感じる
  • 実際、メモリリークの原因が利用中の特定ライブラリやフレームワークのバグであることは多いが、そのバグを直接解析して修正し、デプロイできるとは限らない。そのため、回避策をできるだけ早く適用することが重要。バグレポートとあわせて実行可能な代替策を提示するのも良い方法
  • 単にメモリリークを解決するだけでなく、問題の root cause を深く掘り下げた点も良い。フレームワーク内部のコードを丁寧に追い、根本原因までたどる分析姿勢は開発者にとって必要だと感じる
  • 結局、メモリリークの原因は当初まったく無関係に見えた些細なライブラリのバージョンアップにあった。依存関係管理と変更追跡の重要性を示す事例であり、小さな変更でも影響を慎重に分析し、デプロイ後も監視が必要であることを示唆している

関連記事

1件のコメント

 
GN⁺ 2024-05-12
Hacker Newsの意見

手動メモリ管理は恐れるものではなく、エンジニアリングの訓練で解決できる

  • RAIIと明確な所有権ルールさえあれば、メモリ管理は簡単なエンジニアリング作業である
  • むしろ参照カウントや共有ポインタに固執するフレームワークのほうが所有権を曖昧にし、より難しくする
  • 生成したら解放し、移譲したら気にしないというのはエンジニアリング規律の一部である
  • メモリバグはロジックバグと何ら変わらないので、修正するのが当然である
  • OSリソース（ハンドル、ソケットなど）も自動リソース管理なしで手動管理するのだから、メモリも同様に扱える

メモリリークによる500万ドル損失の事例

  • 90年代のSolarisプリンタドライバのメモリリークバグで起きた逸話を紹介
  • 当時は銀行でFAXで取引を確認し、プリンタで出力して相手に電話で読み上げ、録音する方式で法的確認を行っていた
  • メモリリークでプリンタドライバがダウンし、出力されなかった確認書のために取引を取り消され、500万ドルの損失を被った
  • 最終的にSunのCEOの苦情によって開発者たちがバグを修正することになった

メモリリークのデバッグツールと解決策

  • Valgrindを使えばCでのリークは簡単に見つけられる
  • 設計が適切であれば、たいてい割り当てと解放は同じ関数内で行われるため修正しやすい
  • Yahoo広告サーバーのメモリリーク事例と、その場しのぎの解決策を紹介
  • PHP設計者のジョークを引用し、完璧主義より実用主義を選ぶ姿勢を示している
  • Railsでは生産性のためにハードウェアで解決するのが一般的だという

文章スタイルへの称賛

  • 書き手の文体が、絵文字やフォーマットの影響なのか楽しいというコメント