Zenn
株式会社ログラス テックブログPublicationへの投稿
🤨

OOM発生時にヒープダンプを取得しようとしたが、断念した話

atsushi
2024/12/16に公開
AWS
datadog
JVM
tech

はじめに

こんにちは！
株式会社ログラスでクラウドエンジニアをしているAtsushiです。

本記事では、ECS上で稼働しているコンテナからヒープダンプを取得しようとして、見事に失敗したので、そこで得た学びをご紹介します。

今回の内容はDatadogのmeetupでお話ししたこちらの内容を元に作成した記事となっています。

そもそもなぜやろうと思ったのか

ログラスでは主にDatadogを使ってシステムの監視を行っています。
その中で、Datadog Profilerの機能を活用し、OOMエラー発生時のメモリ使用状況を確認する方法を考えました。後述しますが、実際にはデータが欠落している場合があり、直前の情報が取れないことがあります。そのためコンテナからヒープダンプを取得する方法を検討し始めました。

仮にヒープダンプが取得できない場合でも、OOM発生時のメトリクスやログを追い、検証環境で現象を再現することで原因を特定することは可能です。しかし、この作業は非常に手間がかかり、大変です。

そのため、OOM発生時にヒープダンプが取得できれば、メモリを消費しているオブジェクトがどこで作成されたかを特定し、それらのオブジェクトへの参照をソースコード内で見つけることができます。これにより、原因特定までの時間を大幅に短縮できるのではないかと考えています。

参考: https://docs.oracle.com/javase/jp/6/technotes/guides/visualvm/heapdump.html

OOM（OutOfMemoryError）の理解と事例

ヒープダンプを取得する仕組みを作るに当たって、まず、OOMエラーが発生する原因を理解することが重要です。特にJVM（Java Virtual Machine）を使用するアプリケーションでは、メモリ管理に関する知識が欠かせません。

JVMのメモリ管理

ここでは、メモリ領域やメモリ解放の仕組みについて、大まかにまとめた内容を記載します。

ヒープメモリ

ヒープメモリには、プログラムが生成したオブジェクトや配列が格納されます。JVMでは、ヒープメモリをさらにYoung世代とOld世代に分けて管理しており、Young世代には新しく生成されたオブジェクトが、Old世代には長期間使用されているオブジェクトが格納されます。

これらのオブジェクトが大量に生成され、かつ不要になったオブジェクトが適切にガベージコレクション（GC）で解放されないと、メモリが枯渇し、java.lang.OutOfMemoryError: Java heap spaceというエラーが発生します。

*一部GCによってはOld/Young管理しないものもあります。

非ヒープメモリ

非ヒープメモリには、JVMの動作に必要なメタデータ（クラス定義、コードキャッシュ、JVMの内部処理に関連するデータ）などが格納されます。また、Java 8以降ではメタスペース（Metaspace）が導入され、ネイティブメモリ上に確保されるようになりましたが、メタスペースが枯渇するとjava.lang.OutOfMemoryError: Metaspaceというエラーが発生します。

ダイレクトバッファメモリ

さらに、JVMにはダイレクトバッファメモリという領域もあります。これは、NIO（New I/O）やgzipなど、サードパーティのライブラリが使用するメモリ領域です。ヒープメモリとは別に管理されており、メモリ不足になるとjava.lang.OutOfMemoryError: Direct buffer memoryというエラーが発生します。

GC（ガベージコレクション）

ガベージコレクション（GC）は、不要になったオブジェクトを解放し、メモリを再利用可能にするプロセスです。GCにはいくつかの種類があります：

  • Minor GC: Young世代内の不要なオブジェクトを回収し、有効なオブジェクトをSurvivor空間に移動します。
  • Full GC (Major GC): ヒープメモリ全体を対象にしたGCで、Old世代の回収も行います。通常、Full GCは時間がかかるため、アプリケーションのパフォーマンスに大きな影響を与えることがあります。
    GCはメモリの使用効率を高め、アプリケーションがメモリ不足になるのを防ぎますが、GCの回数が多すぎたり、Full GCが頻繁に発生したりすると、アプリケーションのパフォーマンスが低下します。その結果、最終的にjava.lang.OutOfMemoryError: Java heap spaceや、java.lang.OutOfMemoryError: GC overhead limit exceededなどのエラーが発生することがあります。

実際の事例

ログラスでは、AWS ECS on Fargateでサービスを運用しており、実際にアプリケーションのメモリ使用量が急増したことが原因でOOMエラーが発生した事例が過去にありました。
内容としては、以下です。

  1. アプリケーションでメモリを大量に使用する処理が実行
  2. Full GCが実行
  3. java.lang.OutOfMemoryErrorが発生
  4. アプリケーション異常終了
  5. ヘルスチェックが通過しなくなり、コンテナ停止

このような事例では、トラブルシューティングが難しく、早期に原因を特定し解決策を見つける必要があります。

この辺りのお話は、こちらの記事にまとまっているので、ぜひご覧ください。

Datadogによる監視

前述した通り、ログラスでは、Datadogを使用して、アプリケーションのパフォーマンスやメトリクスを監視しています。
具体的には、サイドカーとしてDatadog AgentとFluentBitを稼働させ、アプリケーションログやコンテナのメトリクスをDatadogへ集約しています。

また、集めたログ、メトリクスに対して閾値を設け、問題があった場合はSlackにアラート通知を設定することで、ニアリアルタイムで問題を把握できるようにしています。

図のようなイメージです。

Datadog Profilerの活用と問題点

OOMエラーが発生した際には、Datadog Profilerを使用し、問題が発生した時間帯のメモリの使用状況を確認することができます。

ただし、タイミングによっては、OOMエラーが発生した直前のデータが欠落していることもあります。
考察として、Profilerは60秒間隔でデータを収集しており、OOMエラーが発生するタイミングによっては、データが収集される前にコンテナが停止してしまうケースがあるのでは、と考えています。

この問題があるため、OOMエラーが発生した直前の状態を追跡できず、トラブルシュートにおいて、原因の特定が難しくなることがあります。

ヒープダンプを取得する仕組みの実装

直前のデータが欠落してしまうという問題があるため、自前でヒープダンプを取得する仕組みを実装する運びとなりました。

私たちのケースでは、OOMエラー発生時にヒープダンプをS3にアップロードする仕組みを作成することにしました。
図に表すと全体像は以下のような感じになっています。

JVM起動オプションの修正

はじめに、JAVA_OPTSの修正を行いました。

以下はJAVA_OPTSとして追加した内容です。これらの起動オプションを設定することで、OOMエラー発生時にヒープダンプを書き出すことができます。

-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=/tmp/heap_dump.hprof

やっていることはシンプルです。OOMエラー発生時に、ヒープダンプを tmp/heap_dump.hprof に書き出しています。

参考: https://docs.oracle.com/javase/jp/8/docs/technotes/guides/troubleshoot/clopts001.html

S3アップロード用のスクリプト作成

次に、起動用スクリプトを新規で作成しました。
上記でご紹介したJAVA_OPTSに加え、-XX:OnOutOfMemoryErrorオプションも起動コマンドへ追加しました。
このオプションへはOutOfMemoryError例外がスローされたときに実行されるコマンドまたはスクリプトの指定が可能です。
今回は、書き出したヒープダンプのファイルをS3へアップロードさせる処理を指定しています。

JVMの起動オプションを使用することで、OOMエラー発生時にヒープダンプを指定したファイルに書き出し、S3へアップロードする仕組みを実現できました。

#!/bin/bash
set -e

echo "Starting the application"

OOM_OPT=(-XX:OnOutOfMemoryError="aws s3 mv /tmp/heap_dump.hprof s3://$SYSTEM_LOG_BUCKET/heap_dump/$DUMP_KEY/$(date +%F_%H-%M-%S).hprof ; kill -9 %p")

exec java $JAVA_OPTS "${OOM_OPT[@]}" -jar /app.jar "$@"

結果

ここまで、ご説明した内容で色々と検証しましたが、最終的には断念しました。

理由としては、ダンプファイルを作成し、S3にアップロードするまでにかかる時間が長すぎて、ALBのDeregistration Delayのタイムアウト(デフォルト300秒)に間に合わないことが判明したためです。具体的に、ダンプファイルの書き出しからアップロード完了までに、検証では5分〜10分ほどの時間がかかりました。

Deregistration Delayの時間は最大で3600秒に延ばすことができますが、長めに設定すると、タスクがDraining状態のまま長時間残り続けることになります。これにより、新しいリクエストを処理できるリソースが一定時間減少するというデメリットが発生します。また、Blue/Green Deploymentsを使用したデプロイの運用との兼ね合いもあり、今回のケースではこの方法を選ばないことにしました。

とはいえ、Profilerを見れば、OOMエラー発生時のデータは仮に欠落していても、傾向は確認することが可能なため、今後もDatadog Profilerを主に活用し続けるという方向に落ち着きました。

Profilerを使えば、画像のような感じでJVMのメモリ状況が確認可能です。

おわりに

今後は、開発者向けにDatadogの使い方をさらに広め、プロファイリングとメモリ管理の重要性を理解してもらうための取り組みを強化していきたいと考えています。具体的には、Datadog Profilerの活用方法をチーム内で共有し、パフォーマンスのボトルネックを早期に発見・解決するためのノウハウを蓄積していきます。

適切な監視とプロファイリングを活用することで、問題を早期に発見し、サービスの安定性を高めることが可能になるので、Datadog Profilerを使いこなし、より効率的にパフォーマンスの問題を解決していきたいと思います！

株式会社ログラス テックブログ
株式会社ログラス テックブログPublication

株式会社ログラスは「良い景気を作ろう。」をミッションに、企業経営を推進する次世代型経営管理クラウド「Loglass 経営管理」を開発し提供しています。

Discussion