Javaスレッドダンプを分析する方法

投稿日: 2022-10-25 2022-10-25
タグ: DevOps, Java Concurrency, JVM

1. 序章

アプリケーションがハングアップしたり、実行が遅くなったりすることがあり、根本的な原因を特定することは必ずしも簡単な作業ではありません。 A スレッドダンプは、実行中のJavaプロセスの現在の状態のスナップショットを提供します。ただし、生成されたデータには複数の長いファイルが含まれています。したがって、Javaスレッドダンプを分析し、無関係な情報の大きな塊で問題を掘り下げる必要があります。

このチュートリアルでは、パフォーマンスの問題を効率的に診断するためにそのデータを除外する方法を説明します。また、ボトルネックや単純なバグを検出する方法も学びます。

2. JVMのスレッド

JVMはスレッドを使用して、すべての内部および外部操作を実行します。ご存知のとおり、ガベージコレクションプロセスには独自のスレッドがありますが、Javaアプリケーション内のタスクも独自のスレッドを作成します。

その存続期間中、スレッドはさまざまな状態を通過します。各スレッドには、現在の操作を追跡する実行スタックがあります。さらに、JVMは、正常に呼び出された以前のすべてのメソッドも格納します。したがって、スタック全体を分析して、問題が発生したときにアプリケーションで何が起こったかを調べることができます。

このチュートリアルのトピックを紹介するために、例として単純な Sender-Receiverアプリケーション（NetworkDriver）を使用します。 Javaプログラムはデータパケットを送受信するため、舞台裏で何が起こっているかを分析できます。

2.1. Javaスレッドダンプのキャプチャ

アプリケーションが実行されたら、診断用のJavaスレッドダンプを生成する複数の方法があります。このチュートリアルでは、JDK7+のインストールに含まれている2つのユーティリティを使用します。まず、 JVMプロセスステータス（jps）コマンドを実行して、アプリケーションのPIDプロセスを検出します。

$ jps 
80661 NetworkDriver
33751 Launcher
80665 Jps
80664 Launcher
57113 Application

次に、アプリケーションのPIDを取得します。この場合は、次のPIDです。 NetworkDriver。次に、を使用してスレッドダンプをキャプチャします jstack 。最後に、結果をテキストファイルに保存します。

$ jstack -l 80661 > sender-receiver-thread-dump.txt

2.2. サンプルダンプの構造

生成されたスレッドダンプを見てみましょう。 1行目はタイムスタンプを表示し、2行目はJVMについて通知します。

2021-01-04 12:59:29
Full thread dump OpenJDK 64-Bit Server VM (15.0.1+9-18 mixed mode, sharing):

次のセクションでは、Safe Memory Reclamation（SMR）と非JVM内部スレッドを示します。

Threads class SMR info:
_java_thread_list=0x00007fd7a7a12cd0, length=13, elements={
0x00007fd7aa808200, 0x00007fd7a7012c00, 0x00007fd7aa809800, 0x00007fd7a6009200,
0x00007fd7ac008200, 0x00007fd7a6830c00, 0x00007fd7ab00a400, 0x00007fd7aa847800,
0x00007fd7a6896200, 0x00007fd7a60c6800, 0x00007fd7a8858c00, 0x00007fd7ad054c00,
0x00007fd7a7018800
}

次に、ダンプにスレッドのリストが表示されます。各スレッドには、次の情報が含まれています。

名前：開発者が意味のあるスレッド名を含めると、有用な情報を提供できます
Priority （prior）：スレッドの優先度
Java ID （tid）：JVMによって指定された一意のID
ネイティブID（nid）：OSによって指定された一意のIDで、CPUまたはメモリ処理との相関関係を抽出するのに役立ちます
状態：スレッドの実際の状態
スタックトレース：アプリケーションで何が起こっているかを解読するための最も重要な情報源

スナップショットの時点でさまざまなスレッドが何をしているかを上から下に見ることができます。メッセージを消費するのを待っているスタックの興味深い部分だけに焦点を当てましょう。

"Monitor Ctrl-Break" #12 daemon prio=5 os_prio=31 cpu=17.42ms elapsed=11.42s tid=0x00007fd7a6896200 nid=0x6603 runnable  [0x000070000dcc5000]
   java.lang.Thread.State: RUNNABLE
	at sun.nio.ch.SocketDispatcher.read0([email protected]/Native Method)
	at sun.nio.ch.SocketDispatcher.read([email protected]/SocketDispatcher.java:47)
	at sun.nio.ch.NioSocketImpl.tryRead([email protected]/NioSocketImpl.java:261)
	at sun.nio.ch.NioSocketImpl.implRead([email protected]/NioSocketImpl.java:312)
	at sun.nio.ch.NioSocketImpl.read([email protected]/NioSocketImpl.java:350)
	at sun.nio.ch.NioSocketImpl$1.read([email protected]/NioSocketImpl.java:803)
	at java.net.Socket$SocketInputStream.read([email protected]/Socket.java:981)
	at sun.nio.cs.StreamDecoder.readBytes([email protected]/StreamDecoder.java:297)
	at sun.nio.cs.StreamDecoder.implRead([email protected]/StreamDecoder.java:339)
	at sun.nio.cs.StreamDecoder.read([email protected]/StreamDecoder.java:188)
	- locked <0x000000070fc949b0> (a java.io.InputStreamReader)
	at java.io.InputStreamReader.read([email protected]/InputStreamReader.java:181)
	at java.io.BufferedReader.fill([email protected]/BufferedReader.java:161)
	at java.io.BufferedReader.readLine([email protected]/BufferedReader.java:326)
	- locked <0x000000070fc949b0> (a java.io.InputStreamReader)
	at java.io.BufferedReader.readLine([email protected]/BufferedReader.java:392)
	at com.intellij.rt.execution.application.AppMainV2$1.run(AppMainV2.java:61)

   Locked ownable synchronizers:
	- <0x000000070fc8a668> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

一見すると、メインスタックトレースがjava.io.BufferedReader.readLineを実行していることがわかります。これは予想される動作です。さらに下を見ると、アプリケーションによって実行されるすべてのJVMメソッドが舞台裏であることがわかります。したがって、ソースコードまたはその他の内部JVM処理を調べることで、問題の原因を特定できます。

ダンプの最後に、ガベージコレクション（GC）やオブジェクト終了などのバックグラウンド操作を実行する追加スレッドがいくつかあることに気付くでしょう。

"VM Thread" os_prio=31 cpu=1.85ms elapsed=11.50s tid=0x00007fd7a7a0c170 nid=0x3603 runnable  
"GC Thread#0" os_prio=31 cpu=0.21ms elapsed=11.51s tid=0x00007fd7a5d12990 nid=0x4d03 runnable  
"G1 Main Marker" os_prio=31 cpu=0.06ms elapsed=11.51s tid=0x00007fd7a7a04a90 nid=0x3103 runnable  
"G1 Conc#0" os_prio=31 cpu=0.05ms elapsed=11.51s tid=0x00007fd7a5c10040 nid=0x3303 runnable  
"G1 Refine#0" os_prio=31 cpu=0.06ms elapsed=11.50s tid=0x00007fd7a5c2d080 nid=0x3403 runnable  
"G1 Young RemSet Sampling" os_prio=31 cpu=1.23ms elapsed=11.50s tid=0x00007fd7a9804220 nid=0x4603 runnable  
"VM Periodic Task Thread" os_prio=31 cpu=5.82ms elapsed=11.42s tid=0x00007fd7a5c35fd0 nid=0x9903 waiting on condition

最後に、ダンプにはJava Native Interface（JNI）参照が表示されます。メモリリークが発生した場合、それらは自動的にガベージコレクションされないため、特に注意する必要があります。

JNI global refs: 15, weak refs: 0

スレッドダンプの構造はかなり似ていますが、ユースケースで生成された重要でないデータを削除する必要があります。一方、スタックトレースによって生成された大量のログからの重要な情報を保持し、グループ化する必要があります。それを行う方法を見てみましょう！

3. スレッドダンプを分析するための推奨事項

アプリケーションで何が起こっているかを理解するには、生成されたスナップショットを効率的に分析する必要があります。ダンプ時のすべてのスレッドの正確なデータを含む情報がたくさんあります。ただし、ログファイルをキュレートし、フィルタリングとグループ化を行って、スタックトレースから有用なヒントを抽出する必要があります。ダンプを準備したら、さまざまなツールを使用して問題を分析できるようになります。サンプルダンプの内容を解読する方法を見てみましょう。

3.1. 同期の問題

スタックトレースを除外するための興味深いヒントの1つは、スレッドの状態です。主にはRUNNABLEまたはBLOCKEDスレッドに焦点を当て、最終的にはTIMED_WAITINGスレッドに焦点を当てます。これらの状態は、2つ以上のスレッド間の競合の方向に私たちを向けます。

デッドロック実行中の複数のスレッドが共有オブジェクトで同期ブロックを保持している状況
のスレッドの競合 、いつスレッドは他の人が終了するのを待ってブロックされます。たとえば、前のセクションで生成されたダンプ

3.2. 実行の問題

経験則として、 CPU使用率が異常に高い場合は、RUNNABLEスレッドのみを確認する必要があります。スレッドダンプを他のコマンドと一緒に使用して、追加情報を取得します。これらのコマンドの1つは、 top -H -p PID、で、特定のプロセス内でどのスレッドがOSリソースを消費しているかを表示します。念のため、GCなどの内部JVMスレッドも確認する必要があります。一方で、 処理性能が異常に低い場合 、ブロックされたスレッドを見ていきます。

そのような場合、何が起こっているのかを理解するには、1回のダンプでは十分ではないことは間違いありません。 異なる時間に同じスレッドのスタックを比較するために、を近い間隔で多数のダンプが必要になります。一方では、問題の根本を突き止めるには、1つのスナップショットだけでは必ずしも十分ではありません。一方、スナップショット間のノイズ（情報が多すぎる）を回避する必要があります。

時間の経過に伴うスレッドの進化を理解するために、推奨されるベストプラクティスは、少なくとも3つのダンプを10秒ごとに1つ取得することです。もう1つの便利なヒントは、ファイルの読み込み中にクラッシュが発生しないように、ダンプを小さなチャンクに分割することです。

3.3. 推奨事項

問題の根本を効率的に解読するには、スタックトレースに大量の情報を整理する必要があります。したがって、次の推奨事項を考慮します。

実行の問題では、 10秒間隔で複数のスナップショットをキャプチャしますは、実際の問題に焦点を当てるのに役立ちます。クラッシュの読み込みを回避するために、必要に応じてファイルを分割することもお勧めします
新しいスレッドを作成するときに名前付けを使用して、ソースコードをより適切に識別します
問題に応じて、内部JVM処理を無視します（たとえばGC）
異常なCPUまたはメモリ使用量を発行するときに長時間実行またはブロックされたスレッドに焦点を当てる
top -H -p PID を使用して、スレッドのスタックをCPU処理と関連付けます。
そして最も重要なのは、アナライザーツールを使用する

Javaスレッドダンプを手動で分析することは、退屈な作業になる可能性があります。単純なアプリケーションの場合、問題を発生させているスレッドを特定することができます。一方、複雑な状況では、このタスクを容易にするためのツールが必要になります。次のセクションでは、サンプルスレッド競合用に生成されたダンプを使用してツールを使用する方法を紹介します。

4. オンラインツール

利用可能ないくつかのオンラインツールがあります。この種のソフトウェアを使用するときは、セキュリティの問題を考慮する必要があります。 サードパーティエンティティとログを共有している可能性があることに注意してください。

4.1. FastThread

FastThread は、実稼働環境のスレッドダンプを分析するためのおそらく最高のオンラインツールです。非常に優れたグラフィカルユーザーインターフェイスを提供します。また、スレッドごとのCPU使用率、スタック長、最もよく使用される複雑なメソッドなど、複数の機能が含まれています。

FastThreadには、スレッドダンプの分析を自動化するためのRESTAPI機能が組み込まれています。簡単なcURLコマンドで、結果を即座に送信することができます。 it はスタックトレースをクラウドに保存するため、主な欠点はセキュリティです。

4.2. JStackレビュー

JStack Review は、ブラウザ内のダンプを分析するオンラインツールです。これはクライアント側のみであるため、コンピューターの外部にデータが保存されることはありません。セキュリティの観点から、これはそれを使用することの大きな利点です。すべてのスレッドのグラフィカルな概要を提供し、実行中のメソッドを表示するだけでなく、ステータスごとにグループ化します。 JStack Reviewは、スタックを生成するスレッドを残りのスレッドから分離します。これは、たとえば内部プロセスを無視することが非常に重要です。最後に、シンクロナイザーと無視された行も含まれます。

4.3。 SpotifyOnlineJavaスレッドダンプアナライザ

Spotify Online Java Thread Dump Analyser は、JavaScriptで記述されたオンラインのオープンソースツールです。結果は、スタックがある場合とない場合でスレッドを分離するプレーンテキストで表示されます。また、実行中のスレッドの上位のメソッドも表示されます。

5. スタンドアロンアプリケーション

ローカルで使用できるスタンドアロンアプリケーションもいくつかあります。

5.1。 JProfiler

JProfiler は市場で最も強力なツールであり、Java開発者コミュニティの間でよく知られています。 10日間の試用ライセンスで機能をテストすることができます。 JProfilerを使用すると、プロファイルを作成し、実行中のアプリケーションをプロファイルにアタッチできます。 CPUとメモリの使用量、データベース分析など、その場で問題を特定するための複数の機能が含まれています。 IDEとの統合もサポートしています。

5.2. IBM Thread Monitor and Dump Analyzer for Java（TMDA）

IBM TMDA を使用して、スレッドの競合、デッドロック、およびボトルネックを特定できます。これは自由に配布および保守されますが、IBMからの保証またはサポートを提供するものではありません。

5.3. イロッケルスレッドダンプアナライザー（TDA）

Irockel TDA は、LGPLv2.1でライセンスされているスタンドアロンのオープンソースツールです。最後のバージョン（v2.4）は2020年8月にリリースされたため、よく維持されています。スレッドダンプをツリーとして表示し、ナビゲーションを容易にするための統計も提供します。

最後に、IDEはスレッドダンプの基本的な分析をサポートしているため、開発時にアプリケーションをデバッグできます。

5. 結論

この記事では、Javaスレッドダンプ分析が同期または実行の問題を特定するのにどのように役立つかを示しました。

最も重要なことは、スナップショットに埋め込まれた膨大な量の情報を整理するための推奨事項を含め、それらを適切に分析する方法を確認したことです。

getdocs

13036