3.1.2　トラブル事象別の原因切り分け方法

(a)　調査の流れ

プロセスがダウンをしたときに，原因を切り分けるための調査の流れを次の図に示します。

【調査ポイント】

ダウンした個所を特定し，該当モジュールの提供元に調査を依頼します。

【有効な資料】

• エラーリポートファイル

• coreダンプ／スタックトレースファイル

1. エラーリポートファイルを解析し，ダウンした個所を特定します。

   ユーザのモジュール内と特定できた場合は，ダウン原因がないかどうかを見直します。

   サードベンダ製品と特定できた場合は，製品提供元に調査を依頼します。

   特定できない場合は，保守員に調査を依頼します。

2. coreファイルが出力されている場合は，スタックトレースの情報を取得します。

   保守員に調査を依頼するときの資料です。

(b)　エラーリポートファイルの解析

エラーリポートファイルを解析します。

【解析のポイント】

• ポイント1

  JavaVM以外で異常終了（ダウンしたフレームの種別）

• ポイント2

  ダウンしたライブラリとライブラリ内の位置

• ポイント3

  ダウン原因の例外コード

• ポイント4

  ネイティブメソッドが呼び出されたJavaプログラムのファイル名と行番号

この例では，ダウンしたライブラリは/home/jdk/APS/User.soで，ダウンしたライブラリ内の位置は「0x91」です。

/home/jdk/APS/User.soの提供元に調査を依頼します。

• エラーリポートファイルでの確認点

  JavaVM以外の異常終了かどうか確認する場合について説明します。

  【解析のポイント】のポイント1に示すフレームの種別が“C”の場合は，「JavaVM以外の異常終了」を示します。“C”ではない場合（“V”や“j”などがある）は，JavaVMのフレームです。フレームの種別を次に示します。

  表3‒4　フレームの種別

  フレームの種別	フレーム
  C	ネイティブのCフレーム
  J	Cフレーム以外のフレーム（コンパイルされたJavaのフレームも含む）
  j	インタプリタで実行されるJavaのフレーム
  V	JavaVMのフレーム
  v	JavaVMが生成したスタブのフレーム

• スタックトレースの情報の解析

  JavaVMが異常終了してcoreダンプが出力された場合，異常終了した原因の究明に必要なネイティブ関数の情報（スタックトレース情報）を，javatraceコマンドで取得できます。全スレッドのスタックトレース情報が出力されます。ダウンしたライブラリの提供元が解析する資料は，ダウンしたモジュールを特定するための参考情報となることがあります。

  

【解析のポイント】

• ポイント1

  ダウンしたライブラリとダウンした関数と個所

• ポイント2

  ダウンした関数の呼び出し元

この例では「Java_User_UserNameCheck関数」，「get_name関数」，「Index_check関数」の順で呼び出され「Index_check関数」で異常が発生しています。

(a)　調査の流れ

プロセスがハングアップをしたときに，原因を切り分けるための調査の流れを次の図に示します。

【調査ポイント】

該当するプロセスのCPU使用率と突き合わせて，原因を推定し，スレッドダンプで特定します。

【有効な資料】

• OS稼働情報

• スレッドダンプ

1. CPU利用率の調査をします。

   該当するプロセスのCPU利用率の調査をします。

   100%に近い場合は，無限ループや再帰呼び出しに陥っている可能性が高いです。

   0%に近い場合は，次の2点が考えられます。

   • プロセスから応答が返ってこない

   • デッドロック

   この場合「プロセスから応答が返ってこない」の方が多くみられます。

2. スレッドダンプを取得します。

3. JavaVM自身がハングアップしているとスレッドダンプが取得できない場合があります。

4. スレッドダンプが取得できた場合は，スレッドダンプを解析しハングアップしたモジュールを特定し，モジュールの提供元に調査依頼をします。

5. スレッドダンプが取得できない場合は，javacoreコマンドでcoreダンプを取得して，保守員に調査依頼をします。

   coreダンプ取得時，ヒープ領域が大きいプロセスでは，プロセスの動作を一時的に停滞させることがあるので注意してください。

(b)　スレッドダンプ（プロセス無応答）の解析例

ネイティブメソッドの実行応答が返ってこないため，ハングアップが発生している例を次の図に示します。

【解析のポイント】

スレッドダンプを複数回取得して時系列で観察し，それぞれのスレッドダンプでtid（スレッドID）が同じスレッドのスタックトレースを比較調査します。

• ポイント1

  スレッド属性がrunnableの場合，このスレッドは実行可能状態にあります。

  このスレッドがCPU利用率の増加に関与しています（wait for monitor entryである場合はCPU利用率を増加させません）。

• ポイント2

  複数のスレッドダンプファイルで，同じtidのスレッド属性がすべてrunnableです。長時間にわたって実行中となっている可能性があります。

• ポイント3

  複数のスレッドダンプファイルで，同じtidのスレッドがすべて同じ場所を実行中です。

この例では，Native Method実行の応答が返ってこないためハングアップが発生している可能性が高いです。

(c)　スレッドダンプ（デッドロック）の解析例

デッドロックが発生しているスレッドダンプの例を次の図に示します。

【解析のポイント】

• ポイント1

  スレッド属性がrunnableの場合，このスレッドは実行可能状態にあります。

  このスレッドはデッドロックとは無関係です。

• ポイント2

  スレッド属性がwait for monitor entryの場合，このスレッドはロックの取得待ちであることを示しています。

  デッドロックを起こしているスレッドである可能性があります。

• ポイント3

  スレッドがロックを取得していて，かつポイント2でスレッドのロック取得待ちである場合，デッドロックを起こしているスレッドである可能性が高いです。

ポイント2，3に当てはまるスレッドに対し，ロックしているオブジェクトのアドレスを突き合わせながらデッドロックを検出します。

この例の場合，Thread-1は，＜0x00002aaaaf886648＞のロックを取得して，＜0x00002aaaaf886628＞の取得待ちを示します。一方，Thread-0は，＜0x00002aaaaf886628＞のロックを取得していて，かつ＜0x00002aaaaf886648＞の取得待ちとなっています。Thread-1とThread-0がデッドロックしていることが分かります。

(d)　スレッドダンプ（無限ループ）の解析例

無限ループが発生しているスレッドダンプの例を次の図に示します。

【解析のポイント】

スレッドダンプを複数回取得して時系列で観察し，それぞれのスレッドダンプでtid（スレッドID）が同じスレッドのスタックトレースを比較調査します。

• ポイント1

  スレッド属性がrunnableの場合，このスレッドは実行可能状態にあります。このスレッドがCPU利用率の増加に関与しています（wait for monitor entryである場合はCPU利用率を増加させません）。

• ポイント2

  複数のスレッドダンプファイルで，同じtidのスレッド属性がすべてrunnableです。長時間にわたって実行中となっている可能性があります。

• ポイント3

  同一メソッド内の特定の行が複数回繰り返し実行されているような場合，無限ループの可能性があります。

(e)　スレッドダンプ（無限ループ）のローカル変数情報による解析例

プログラムがローカル変数に作成したカウンタの使い方を誤ったために，無限ループが発生しているスレッドダンプの例を次の図に示します。

【解析のポイント】

スレッドダンプを複数回取得して時系列で観察し，それぞれのスレッドダンプでtid（スレッドID）が同じスレッドでループカウンタなどのループ処理に影響するローカル変数の値を確認します。

• ポイント1

  プログラムで，ループの動作に関与するローカル変数を確認します。

• ポイント2

  スレッドダンプに出力されている，該当するローカル変数の値を確認します。

この例では，ローカル変数countの値が増えてループ処理が抜けることを期待したプログラムにもかかわらず，countの値が減少しています。

(a)　調査の流れ

プロセスがスローダウンをしたときに，原因を切り分けるための調査の流れを次の図に示します。

【調査ポイント】

拡張verbosegc情報とスレッドダンプで特定します。

【有効な資料】

• JavaVMログファイル（拡張verbosegc情報）

• スレッドダンプ

• coreダンプ

• OS稼働情報

1. 拡張verbosegc情報で，FullGCが多発していないかどうかを確認します。

   拡張verbosegc情報はJavaVMログファイルに出力されます。

2. GCが原因の場合は，メモリリークを調査します。

   メモリリークがない場合はメモリの設定変更の対処をします。

3. GCが原因ではない場合は，スレッドダンプを解析し，問題個所を特定します。

4. スレッドダンプの解析の結果，スローダウンをしている個所がネイティブメソッドの場合，さらにcoreダンプの解析をします。

5. coreダンプの解析の結果，スローダウンをしたモジュールを特定し，各モジュールの開発元に調査を依頼します。

6. サードベンダ製品を含めて問題個所を特定できない場合は，保守員に調査依頼をします。

メモリリークの調査方法は，OutOfMemory障害の時と同じ方法を用います。

スレッドダンプの調査方法は，プロセスハングアップの時と同じ方法を用います。

(a)　調査の流れ

OutOfMemoryError障害が発生したときに，原因を切り分けるための調査の流れを次の図に示します。

【調査ポイント】

該当する症状に応じて切り分けたあと，メモリ量の変化を調査します。

【有効な資料】

• JavaVMログファイル

• OS稼働情報

1. 症状の切り分けをします。

   メモリ不足が発生すると標準出力にOutOfMemoryErrorが出現します。標準出力に出力されるメッセージに詳細が記述される場合があるため，そちらを参照し症状の切り分けをします。

2. メモリ使用量の変化を調査します。

   症状が「Cヒープ不足」または「スレッドが生成できない」場合には，OS稼働情報を使ってメモリ使用量の変化を調査します。症状が「Javaヒープ不足」および「Metaspace不足」の場合には，JavaVMログの拡張verbosegc情報を使ってメモリ使用量の変化を調整します。

3. メモリ使用量の変化を観察した結果，メモリリークではない場合は，設定変更による対処をします。

   設定変更による対処ができない場合は，メモリ使用量の多いモジュールを特定し，モジュールの提供元に調査依頼をします。

4. メモリリークの場合は，メモリリークしているモジュールを特定します。

   サードベンダ製品を含めてリークが見当たらない場合は，保守員に調査依頼をします。

(b)　メッセージによる症状の切り分け

Javaヒープ，Metaspaceが確保できなかった場合

各メモリ領域が不足した場合のメッセージの例を示します。

• Javaヒープが確保できなかった場合

  JavaVMログファイルの詳細情報に“Java Heap”と出力されます。

• Metaspaceが確保できなかった場合

  JavaVMログファイルの詳細情報に“Meta Space”と出力されます。

Cヒープが確保できなかった場合

Cヒープが確保できなかった場合のメッセージの例を示します。

• JavaVMのネイティブライブラリ（JNI）内でCヒープが確保できなかった場合

  JavaVMログファイルの詳細情報に“C Heap”と出力されます。

• ネイティブライブラリ（java.awt.font）内でC ヒープが確保できなかった場合

  標準出力でjava.lang.OutOfMemoryErrorが出力されます。エラーリポートファイルとcoreダンプが出力されます。エラーリポートファイルの内容は，標準出力にも出力されます。

• JavaVM自身がCヒープの確保ができなかった場合

  OutOfMemoryError例外の詳細情報に“requested xxx bytes”と出力されます。

ユーザプログラム内でOutOfMemoryErrorを発生させた場合

ユーザプログラム内でOutOfMemoryErrorを発生させた場合のメッセージの例を示します。

• ユーザプログラム内で明示的にOutOfMemoryErrorを発生させた場合，またはユーザのネイティブライブラリ（JNI）内でCヒープが確保できなかった場合など，JavaVMがOutOfMemoryError発生要因を特定できないとき，JavaVMログファイルの詳細情報に“Unknown”と出力されます。

(c)　各使用量の分析

Javaヒープ使用量の分析

Javaヒープ使用量を分析した例を示します。

FullGC時に，Javaヒープ使用量（DefNewとTenured）を確認するときの例です。

この例では，“Tenured”のFullGC後の値が15780K→31566K→47026K→50566Kと増えていることが確認できます。

Metaspace使用量の分析

Metaspace使用量を分析した例を示します。

FullGC時に，Metaspace使用量（Metaspaceの値）を確認するときの例です。

この例では，“Metaspace”のFullGC後の値が5599K→7372K→7886K→8286Kと増えていることが確認できます。

Cヒープ使用量の分析

JavaVMを実行しているプロセスのメモリ使用量を分析します。

OSの稼働情報からメモリ使用量の増加状況を確認します。

(d)　スレッドダンプによるローカル変数情報の解析例

プログラムがローカル変数に設定する値を誤ったために，OutOfMemoryが発生しているスレッドダンプの例を次の図に示します。

【解析のポイント】

スレッドダンプを取得して，領域を確保する処理に関与するローカル変数の値を確認します。

• ポイント1

  プログラムで，領域を確保する処理に関与するローカル変数を確認します。

• ポイント2

  スレッドダンプに出力されている，該当するローカル変数の値を確認します。

この例では，ローカル変数newcountの値である268443242（約250MB）または，それ以上の値でbyte領域を確保しています。

(e)　設定変更による対処

設定を変更することで対処できる場合は，症状とシステムの状況に応じて対処をします。