Javaシステム障害診断ガイド:CPU、メモリ、ディスクI/O、ネットワーク、GCの徹底解析

本番環境で稼働中のJavaアプリケーションに問題が発生した場合、その原因は多岐にわたります。CPU使用率の急増、ディスクI/Oのボトルネック、メモリ不足、ネットワーク通信の遅延やエラー、そしてガベージコレクション(GC)の異常などが考えられます。多くの場合、これらの問題は単一の原因ではなく、複数の要因が絡み合って発生します。効果的なトラブルシューティングのためには、CPU、メモリ、ディスク、ネットワーク、そしてGCといった各側面を系統的に確認することが重要です。

本稿では、これらの主要な領域におけるJavaシステム障害の診断手法と、問題特定に役立つツールおよびその活用方法について解説します。

CPU使用率の診断

CPU使用率の異常な高騰は、多くの場合、ビジネスロジックの非効率性(無限ループやデッドロック)、過剰なガベージコレクション、または頻繁なコンテキストスイッチが原因で発生します。特に、アプリケーションコードに起因する問題は、Javaスレッドダンプを解析することで特定できることが多いです。

スレッドダンプによるCPU問題の解析

高CPU使用率の原因となっているJavaスレッドを特定するには、以下の手順が有効です。

  1. まず、topコマンドを使用して、高CPU使用率のプロセスID(PID)を見つけます。
  2. 次に、そのPIDに対してtop -Hp <PID>コマンドを実行し、CPUを最も消費しているスレッドID(TID)を確認します。
  3. 見つけたTIDを16進数に変換します。例えば、TIDが12345であれば、printf '%x\n' 12345と実行します。
  4. 最後に、jstack <PID>コマンドでJavaスレッドダンプを取得し、変換した16進数のTIDを含むスレッドのスタックトレースを検索します。
# 高CPUプロセスのPIDを確認
top

# 高CPUプロセスのスレッドごとのCPU使用率を確認(例:PIDが12345の場合)
top -Hp 12345

# 最も高いCPUを使っているTIDを16進数に変換(例:TIDが12350の場合)
printf '%x\n' 12350
# 出力例: 303e

# jstackでスレッドダンプを取得し、該当スレッドのスタックトレースを検索
jstack 12345 | grep -A 10 -B 5 "nid=0x303e"

スタックトレースを詳細に分析することで、どのコードパスがCPUを消費しているのか、無限ループやデッドロックが発生していないかなどを特定できます。

また、スレッドダンプ全体からスレッドの状態分布を確認することも有効です。例えば、RUNNABLE状態のスレッドが異常に多い場合は、CPUを消費する処理が集中している可能性があり、WAITINGBLOCKED状態のスレッドが多い場合は、ロック競合やリソース待ちがボトルネックになっている可能性があります。

jstack 12345 > jstack.log
grep "java.lang.Thread.State" jstack.log | sort | uniq -c

頻繁なガベージコレクション (GC)

CPU使用率が高い原因が頻繁なGCである場合もあります。jstatコマンドを使用すると、GCの統計情報をリアルタイムで監視できます。

jstat -gc <PID> 1000

このコマンドは、1秒(1000ミリ秒)間隔でGCの状況を表示します。出力されるYGC (Young GC回数)、FGC (Full GC回数)、EU (Eden使用量)、OU (Old領域使用量) などのメトリクスを確認し、GCが過剰に発生していないか、特定の領域のメモリ使用量が異常に増加していないかを判断します。GCの頻度や所要時間が異常であれば、GC関連のチューニングやメモリリークの調査に進みます。

コンテキストスイッチの監視

CPU使用率が高くなくても、アプリケーションの応答性が低い場合、過剰なコンテキストスイッチが原因である可能性があります。コンテキストスイッチは、OSがCPUの実行コンテキストをあるプロセス/スレッドから別のプロセス/スレッドに切り替える際に発生します。

vmstat 1

vmstatコマンドの出力にあるcs列は、1秒あたりのコンテキストスイッチ数を示します。この値が非常に高い場合、コンテキストスイッチがパフォーマンスに影響を与えている可能性があります。

特定のプロセスのコンテキストスイッチ数を監視するには、pidstatコマンドが便利です。

pidstat -w <PID> 1

cswchは自発的なコンテキストスイッチ数(I/O待ちなど)、nvcswchは非自発的なコンテキストスイッチ数(CPUタイムスライス終了など)を示します。これらの数値が高い場合、スレッド数の見直しや、I/O処理の最適化を検討する必要があります。

ディスクI/Oの診断

ディスクI/Oの問題は、アプリケーションの応答速度低下やシステム全体のパフォーマンス劣化につながります。ディスク容量の不足とI/O性能のボトルネックが主な原因です。

ディスク容量の確認

まず、システム全体のディスク使用状況を確認します。

df -h

このコマンドで、各ファイルシステムの使用済み容量と空き容量を確認できます。特に、アプリケーションログやデータファイルを保存している領域が逼迫していないかを確認します。

ディスクパフォーマンスの監視

ディスクのI/Oパフォーマンスを詳細に分析するにはiostatコマンドが有効です。

iostat -x 1

出力されるr/s (読み込みリクエスト/秒)、w/s (書き込みリクエスト/秒)、rMB/s (読み込みMB/秒)、wMB/s (書き込みMB/秒)、svctm (サービス時間)、そして%util (ディスク使用率) などのメトリクスから、特定のディスクデバイスにボトルネックがないか、I/Oが過剰に集中していないかを判断できます。%utilが長時間100%に近い場合、ディスクが飽和状態にあることを示唆しています。

プロセスごとのI/O分析

どのプロセスが大量のディスクI/Oを生成しているかを知ることは、問題解決の鍵となります。iotopコマンドはリアルタイムでプロセスごとのI/O使用率を表示します。

sudo iotop

iotopが利用できない環境では、pidstat -dコマンドも有効です。

pidstat -d 1

特定のプロセスのI/O詳細を確認するには、/proc/<PID>/ioファイルを直接参照します。

cat /proc/<PID>/io

これにより、プロセスの読み書きバイト数などの詳細情報が得られます。また、lsof -p <PID>コマンドで、そのプロセスが開いているファイルの一覧を確認し、どのファイルに対してI/Oが行われているかを特定する手助けになります。

メモリ問題の診断

メモリの問題は、Javaアプリケーションにおいて最も複雑で頻繁に発生する障害の一つです。主にヒープメモリの枯渇(OutOfMemoryError)と、オフヒープメモリの問題に分けられます。

システムメモリの概況確認

最初に、システム全体のメモリ使用状況をfreeコマンドで確認します。

free -h

このコマンドは、物理メモリ、スワップメモリの総量、使用量、空き容量などを分かりやすく表示します。特にavail(利用可能メモリ)が低い場合は、システム全体でメモリが不足している可能性があります。

ヒープメモリの課題

Javaアプリケーションのメモリ問題の多くは、JVMヒープメモリの不足に起因します。

OutOfMemoryError (OOM)の種類と対策

JavaのOutOfMemoryError (OOM) にはいくつかの種類があります。

  • java.lang.OutOfMemoryError: unable to create new native thread
    このエラーは、JVMが新しいOSスレッドを生成するためのネイティブメモリを確保できない場合に発生します。多くの場合、アプリケーションが過剰なスレッドを生成しているか、OSレベルでのスレッド数制限に達していることを示します。Javaアプリケーションのスレッドプール設定を見直す、またはOSのユーザープロセス/ファイル記述子の上限(ulimit -aで確認・設定)を調整することが対策となります。また、JVMの-Xssオプションでスレッドスタックサイズを減らすことも有効ですが、StackOverflowErrorのリスクも考慮する必要があります。

  • java.lang.OutOfMemoryError: Java heap space
    最も一般的なOOMで、JVMのヒープメモリが-Xmxオプションで設定された最大値に達し、新しいオブジェクトを割り当てられなくなった場合に発生します。これはメモリリークの兆候であるか、あるいは単に-Xmx設定が不足していることを示しています。まずはメモリリークの有無を疑い、jmapでヒープダンプを取得し、Eclipse Memory Analyzer Tool (MAT) などのツールで解析します。コードに問題がないと判断された場合のみ、-Xmxの値を増やすことを検討します。

  • java.lang.OutOfMemoryError: Metaspace
    Java 8以降で導入されたMetaspace領域のメモリ不足を示します。クラス定義などのメタデータが保存される領域です。デフォルトでは上限がありませんが、-XX:MaxMetaspaceSizeで上限を設定できます。MetaspaceのOOMが発生する場合、アプリケーションが大量のクラスを動的にロードしているか、クラスローダーのリークが発生している可能性があります。-XX:MaxMetaspaceSizeの値を調整するか、クラスローダーのリークを調査します。

StackOverflowError

java.lang.StackOverflowError は、スレッドのスタックメモリが不足した際に発生します。多くの場合、無限再帰呼び出しや、非常に深い再帰呼び出しが原因です。アプリケーションコードの修正が最優先ですが、-Xssオプションでスレッドスタックサイズを増やすことで一時的に回避できる場合もあります。ただし、-Xssを大きくしすぎると、スレッド数が増加した際にネイティブメモリ不足によるOOMを引き起こす可能性もあります。

メモリリークの特定と解析

メモリリークの兆候がある場合、ヒープダンプを取得して詳細に解析します。

jmap -dump:live,format=b,file=/tmp/heapdump.hprof <PID>

liveオプションはGCが可能なオブジェクトを除外し、現在使用されているオブジェクトのみをダンプするため、リークしているオブジェクトを見つけやすくなります。取得した.hprofファイルをMATなどのツールで開き、「Leak Suspects」レポートや「Top Consumers」レポートを確認することで、リークしている可能性のあるオブジェクトや、メモリを大量に消費しているオブジェクトを特定できます。また、OOM発生時に自動的にヒープダンプを取得するようにJVMを設定することも可能です。

-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/path/to/dump/directory

オフヒープメモリの課題

Javaアプリケーションはヒープメモリ以外にも、ネイティブメモリ(オフヒープメモリ)を消費します。これには、JNIコードが確保するメモリ、DirectByteBufferが使用するメモリ、スレッドスタック、JITコンパイラのコードキャッシュなどが含まれます。オフヒープメモリのリークは診断がより困難です。

Native Memory Tracking (NMT) の活用

Java 7 Update 40以降で導入されたNative Memory Tracking (NMT) は、JVMのネイティブメモリ使用状況を詳細に追跡できる強力なツールです。NMTを有効にするには、JVM起動オプションに以下のいずれかを追加します。

-XX:NativeMemoryTracking=summary
-XX:NativeMemoryTracking=detail

NMTを有効にすると、jcmdコマンドを使ってメモリ使用状況のベースラインを取得し、時間経過による変化を監視できます。

# ベースラインの取得
jcmd <PID> VM.native_memory baseline

# しばらく経過後、差分を確認
jcmd <PID> VM.native_memory summary.diff
# または詳細レベルで
jcmd <PID> VM.native_memory detail.diff

summary.diffの出力では、InternalDirectカテゴリのメモリが増加している場合、オフヒープメモリのリークを疑うことができます。detail.diffでは、さらに細分化されたメモリ領域ごとの変化を確認できます。

DirectByteBufferとオフヒープメモリ

NIO (Non-blocking I/O) を使用する際、DirectByteBufferはJVMヒープ外にメモリを直接割り当てます。これらのメモリはJavaオブジェクトとは異なり、GCによって直接回収されません。DirectByteBufferオブジェクト自体がGCされる際にその内部で解放処理が実行されます。したがって、DirectByteBufferを大量に使用し、かつJVMヒープに十分な余裕があるためにYoung GCやFull GCが頻繁に発生しない場合、オフヒープメモリが蓄積され続ける可能性があります。

DirectByteBufferによるオフヒープメモリの最大サイズは-XX:MaxDirectMemorySizeで設定できます。この値が不足している場合は増加を検討します。また、System.gc()を呼び出すことで明示的にFull GCをトリガーし、DirectByteBufferのメモリ解放を促すことも可能ですが、これはGCに予期せぬ影響を与える可能性があるため、-XX:+DisableExplicitGCと併用されていないか確認し、使用は推奨されません。

GCパフォーマンスの最適化

ガベージコレクション(GC)は、メモリ管理の自動化に不可欠ですが、そのパフォーマンスはアプリケーションの応答性、スループット、そしてCPU使用率に大きな影響を与えます。GCがボトルネックになっている場合、その詳細な分析とチューニングが必要です。

GCログの活用

GCの問題を診断する上で最も重要な情報は、GCログから得られます。JVM起動オプションに以下のフラグを追加することで、詳細なGCログを出力できます。

-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -Xloggc:/path/to/gc.log
  • -verbose:gc:簡易的なGC情報を標準出力に出力。
  • -XX:+PrintGCDetails:詳細なGC情報を出力。
  • -XX:+PrintGCDateStamps:GC発生時刻を日付形式で出力。
  • -XX:+PrintGCTimeStamps:GC発生時刻をJVM起動からの秒数で出力。
  • -Xloggc:/path/to/gc.log:GCログをファイルに出力。

これらのログを分析することで、Young GCとFull GCの頻度、それぞれの所要時間、GC前後のメモリ使用量などを把握し、問題の性質を理解できます。本稿では、推奨されるG1GCを例に解説します。

Young GCの頻発

Young GCが非常に頻繁に発生する場合、以下の原因が考えられます。

  • Eden領域が小さい: Eden領域が小さすぎると、新しいオブジェクトがすぐにいっぱいになり、短時間でYoung GCがトリガーされます。-Xmn(新生代全体のサイズ)や、G1GCの場合は-XX:G1NewSizePercent-XX:G1MaxNewSizePercentなどのオプションで新生代のサイズを調整することを検討します。

  • 短命オブジェクトの大量生成: アプリケーションが非常に多くの短命オブジェクトを生成している場合、Young GCの頻度は自然と高まります。これは必ずしも問題ではありませんが、異常に高い場合は、アプリケーションコードでオブジェクト生成パターンを見直す必要があるかもしれません。jmap -histoでヒープ上のオブジェクト分布を確認すると、大量に生成されているオブジェクトのタイプを特定できます。

Young GCの長時間化

Young GCの1回の処理に時間がかかりすぎる場合、アプリケーションの応答性に悪影響を及ぼします。G1GCのログには、GCの各フェーズ(Root Scanning, Object Copy, Ref Procなど)にかかった時間が詳細に記録されています。これらの時間を分析し、どのフェーズがボトルネックになっているかを特定します。

  • Root Scanning: このフェーズが長い場合、アクティブなJavaスレッドが多すぎるか、GCルート(スタック上の参照、静的フィールドなど)の数が多すぎる可能性があります。スレッドプールのサイズや静的変数の利用状況を見直します。

  • Object Copy: 生存しているオブジェクトのコピーに時間がかかっていることを示します。オブジェクトの生存期間が予想よりも長い、またはコピーするオブジェクトの数が多すぎる可能性があります。アプリケーションのオブジェクトライフサイクルを分析します。

  • Ref Proc (Reference Processing): 弱参照、ソフト参照、ファントム参照などの処理に時間がかかっていることを示します。これらの参照タイプを多用している場合、その使用方法を見直す必要があるかもしれません。

Full GCの発生

G1GCは、ほとんどのゴミをMixed GCで処理し、Full GCの発生を極力避けるように設計されています。したがって、G1GCがFull GCにフォールバックすることは、何らかの深刻な問題が発生している兆候です。G1のFull GCはSerial GCに退行し、アプリケーションの一時停止時間が秒単位になることがあり、非常に大きなパフォーマンス劣化を引き起こします。

Full GCが発生する主な原因と対策は以下の通りです。

  • 同時マーキングフェーズの失敗: G1がMixed GCを開始する前に、Old領域がフルになってしまった場合。ヒープサイズを増やすか、-XX:ConcGCThreadsで同時GCスレッド数を調整します。また、-XX:InitiatingHeapOccupancyPercentを小さく設定して、同時マーキングを早めに開始させることも有効です。

  • 昇格失敗 (Promotion Failure / Evacuation Failure): GC中に、生存オブジェクトをOld領域に昇格させたり、新しい領域に移動させたりするための十分なメモリが確保できなかった場合。-XX:G1ReservePercentで予約メモリの割合を増やす、またはヒープサイズを増やすことを検討します。

  • 大オブジェクトの割り当て失敗: サイズの大きなオブジェクト(Humongous Object)が、適切なリージョンに割り当てられない場合。ヒープサイズを増やすか、-XX:G1HeapRegionSizeを調整してリージョンサイズを大きくすることを検討します。

  • System.gc()の明示的な呼び出し: アプリケーションコード内でSystem.gc()が呼び出された場合、強制的にFull GCが実行されます。これはほとんどの場合、避けるべきです。

Full GC前後のヒープダンプを取得し、メモリ使用量の変化やオブジェクトの生存状況を比較することで、Full GCの原因となっているオブジェクトやメモリリークの箇所を特定できます。これにはjinfoコマンドが役立ちます。

jinfo -flag +HeapDumpBeforeFullGC <PID>
jinfo -flag +HeapDumpAfterFullGC <PID>

ネットワーク問題の診断

ネットワークに関連する問題は、その性質上、診断が最も複雑で困難な領域の一つです。タイムアウト、TCPキューの溢れ、RSTパケットによる接続リセットなどが主な症状です。

タイムアウト

タイムアウトは、ネットワーク問題の最も一般的な症状です。大きく分けて接続タイムアウトと読み書きタイムアウトがあり、多くはアプリケーション層で設定されます。

  • 接続タイムアウト (Connection Timeout): クライアントがサーバーとのTCP接続を確立する最大待機時間。サーバー側の接続タイムアウトは、アイドル接続の維持時間など、フレームワークによって意味が異なる場合があります。

  • 読み書きタイムアウト (Read/Write Timeout, Socket Timeout): 接続が確立された後、データストリームの読み書き操作が完了するまでの最大待機時間。クライアント側で設定されることが一般的です。

タイムアウト設定においては、クライアントのタイムアウト値をサーバーのタイムアウト値よりも短く設定することが重要です。これにより、クライアントがサーバーよりも先にタイムアウトし、サーバーにリソースが残り続けることを防ぎ、システム全体の健全性を保てます。また、APIの応答時間(RT)がサーバー側で低下しているのに、クライアント側でタイムアウトが頻発する場合、クライアントとサーバー間のネットワーク遅延、中間プロキシのバッファリング、またはサーバー側のリクエストキュー処理などが原因である可能性を考慮する必要があります。

TCPキューの溢れ

TCP接続確立プロセスには、半接続キュー(SYNキュー)と全接続キュー(Acceptキュー)の2つのキューが存在します。これらのキューが溢れると、接続の拒否や予期せぬ接続リセットが発生します。

  • 半接続キュー (SYN Queue): クライアントからのSYNパケットを受け取り、SYN+ACKを返した後、クライアントからのACKを待っている状態の接続を保持します。

  • 全接続キュー (Accept Queue): TCPの3ウェイハンドシェイクが完了し、確立された接続を、アプリケーションがaccept()システムコールで処理するまで保持します。

キューの溢れは、netstat -sコマンドで確認できます。

netstat -s | egrep "listen|LISTEN"

出力中のoverflowedは全接続キューの溢れ回数を、sockets droppedは半接続キューの溢れ回数を示します。これらのカウンターが継続的に増加している場合、キューのサイズが不足しています。

より詳細なキューの状態はssコマンドで確認できます。

ss -lnt

Recv-Q列は全接続キューの現在の使用量、Send-Q列は全接続キューの最大容量を示します。Recv-QSend-Qに頻繁に近づいている場合、キューが飽和している兆候です。

これらのキューのサイズは、OSパラメータ(net.ipv4.tcp_max_syn_backlognet.core.somaxconn)と、アプリケーション(例:TomcatのacceptCount)の設定によって決まります。これらの値を適切に調整することで、キューの溢れを緩和できます。

RSTパケットによる異常終了

RST(Reset)パケットは、TCP接続が正常な4ウェイハンドシェイクではなく、強制的にリセットされたことを示します。アプリケーションログにConnection reset by peerBroken pipeなどのエラーが出力される場合、RSTパケットが原因である可能性が高いです。

RSTパケットが発生する主なシナリオは以下の通りです。

  • 存在しないポートへの接続試行: クライアントがサーバーの存在しないポートに接続しようとした場合、サーバーはRSTを返して接続を拒否します。

  • ピアプロセスの異常終了: 接続相手のアプリケーションプロセスがクラッシュしたり、リソース不足で応答できなくなったりした場合、OSがRSTを送信して接続を強制的に閉じることがあります。

  • タイムアウトまたは再送上限超過: 片方のホストが長期間相手からのACKを受け取れず、タイムアウトや再送上限に達した場合、接続が不要と判断しRSTを送信します。

  • 閉じられた接続へのデータ送信: 既に閉じられた接続に対してアプリケーションがデータを送信しようとした場合、RSTが返されます。

RSTパケットの有無やその発生源を特定するには、tcpdumpコマンドでネットワークパケットをキャプチャし、Wiresharkなどのツールで分析するのが最も効果的です。

sudo tcpdump -i <ネットワークインターフェース> tcp -w capture.pcap

キャプチャファイルをWiresharkで開くと、RSTフラグが設定されたパケット(通常は赤色で表示される)を視覚的に確認できます。

TIME_WAITおよびCLOSE_WAIT状態

TCP接続の終了プロセスにおいて、TIME_WAITとCLOSE_WAITという2つの重要な状態が存在します。これらの状態のソケットが過剰に蓄積すると、システムリソースを消費し、新しい接続の確立を妨げることがあります。

現在のTCP接続の状態を把握するには、netstatまたはssコマンドを使用します。

# netstatコマンド
netstat -n | awk '/^tcp/ {print $NF}' | sort | uniq -c

# ssコマンド (より高速)
ss -ant | awk '{print $1}' | sort | uniq -c

TIME_WAIT状態

TIME_WAITは、TCP接続をアクティブに閉じた側(通常はクライアント)が遷移する状態です。最後のACKを送信した後、2MSL(Maximum Segment Lifetime)期間だけ待機します。これは、ネットワーク上の遅延パケットが新しい接続に影響を与えないようにするため、およびリモートピアが最終的なACKを確実に受け取るための仕組みです。短命な接続が頻繁に発生するシナリオでは、TIME_WAITソケットが大量に発生することがあります。

過剰なTIME_WAITソケットの対策として、OSカーネルパラメータを調整する方法があります。ただし、安易な変更は新たな問題を引き起こす可能性があるため、慎重に検討する必要があります。

# TIME_WAITソケットの再利用を許可 (注意: NAT環境では問題発生の可能性あり)
net.ipv4.tcp_tw_reuse = 1

# TIME_WAITソケットの最大数を設定し、超過した場合は強制的に破棄
net.ipv4.tcp_max_tw_buckets = 5000

CLOSE_WAIT状態

CLOSE_WAITは、TCP接続をパッシブに閉じた側(通常はサーバー)がFINパケットを受信した後、アプリケーションがソケットをクローズするのを待っている状態です。この状態のソケットが長時間大量に存在する場合、それはアプリケーション層での問題を示唆しています。つまり、アプリケーションがFINパケットを受信したにもかかわらず、何らかの理由でソケットを正常にクローズできていないことを意味します。

CLOSE_WAITが蓄積すると、スレッドやファイルディスクリプタなどのシステムリソースが枯渇し、最終的には新しい接続を受け付けられなくなる可能性があります。この問題を解決するには、jstackコマンドでJavaプロセスのスレッドダンプを取得し、多くのスレッドがI/O操作の完了待ちや、何らかのリソース待ちでブロックされていないかを詳細に分析する必要があります。多くの場合、アプリケーションコードが期待通りにソケットをクローズしていない、または例外処理が不完全であるためにリソースが解放されていないことが原因です。

タグ: Java JVM トラブルシューティング CPU診断 メモリ診断

9月4日 14:46 投稿