ページの先頭行へ戻る
Interstage Application Server V12.0.0 チューニングガイド
FUJITSU Software

9.5.8 FJVMログ

FJVMでは「Java VM異常終了時のログ出力機能」の強化を行っています。
何らかの原因でJavaプロセスが異常終了した場合、Java VM異常終了時のログとしてFJVMログが出力されます。
Javaプロセスが異常終了した原因の調査のために、このFJVMログを活用することができます。

FJVMログの出力先

FJVMログは、Javaプロセスのカレントディレクトリに、以下のファイル名で出力されます。

fjvm_pid***.log (***は異常終了したJavaプロセスのプロセスID)

IJServerクラスタ使用時のカレントディレクトリの詳細は、“Java EE運用ガイド(Java EE 6編)”の“IJServerクラスタ”を参照してください。

FJVMログの調査

FJVMログとしてJavaプロセス異常終了時の各種情報が格納されますが、その中から以下の情報を原因調査用の情報として使用することができます。

9.5.8.1 異常終了箇所の情報

異常終了箇所に関する情報

異常終了箇所に関する情報が確認できます。

  1. 異常終了時に発生した例外に関する情報(シグナルコードおよび例外発生アドレス)

    「Unexpected Signal :」から始まる情報です。

  2. 異常終了した関数名(実際には異常終了したアドレスに一番近いシンボル名)

    「Function name=」から始まる情報です。

  3. 異常終了した関数を含むライブラリ名

    「Library=」から始まる情報です。

  4. 異常終了時のJavaスレッドのスタックトレース

    「Current Java thread:」から始まる情報です。

  5. 異常終了時のダイナミックライブラリ一覧

    「Dynamic libraries:」から始まる情報です。

  6. 発生時間

    「Local Time =」から始まる情報です。

調査手順

「異常終了箇所に関する情報」の1.~3.の情報で異常終了した関数を特定し、実行しているJavaアプリケーションから呼び出す関数かどうかを確認します。ただし、2.の異常終了した関数名として出力される名前は、異常終了したアドレスに一番近いシンボル名情報であるため、実際に異常終了した関数とは別の名前が出力されている場合がありますので注意してください。
そして、実行しているJavaアプリケーションが使用する関数の場合には、当該関数使用に際して何らかの問題がないか確認します。
実行しているJavaアプリケーションで使用していない関数の場合には、4.のスタックトレースを調査します。

スタックトレース情報の最初のメソッドがネイティブメソッドだった場合(メソッド名の後ろに「(Native Method)」が付加されている場合)はJNI処理に関係した問題である可能性が高いため、スタックトレース情報で出力された処理のJNI処理に関わる制御で何らかの問題がないか確認します。

また異常終了した関数を含むライブラリ名が利用者作成のライブラリである場合は、利用者側作成のライブラリ内の問題である可能性が高いため、当該ライブラリ内の処理および当該ライブラリを呼び出すJNI処理に何らかの問題がないか確認します。

スタックトレースの調査方法は、“9.5.1 スタックトレース”を参照してください。

スタックオーバーフローの検出

「異常終了箇所に関する情報」の1.の異常終了時に発生した例外に関する情報に、以下のシグナルコードの表記がある場合、例外が発生したスレッドでスタックオーバーフローが発生した( a)、c)の表記)、または発生した可能性がある(b)、d)の表記)ことを示しています。
この場合、例外が発生したスレッドに対するスタックのサイズを大きくすることで問題が解決する可能性があります。

スタックオーバーフロー発生の原因が、Java APIで生成されたスレッドに対するスタックのサイズにある場合は、“9.4.2 スタックのチューニング”を参照して、Java APIで生成されるスレッドに対するスタックのサイズをチューニングしてください。

スタックオーバーフローを示すシグナルコード

  1. 「EXCEPTION_STACK_OVERFLOW」

  2. 「EXCEPTION_ACCESS_VIOLATION (Stack Overflow ?)」

  1. 「SIGSEGV (Stack Overflow)」

  2. 「SIGSEGV (Stack Overflow ?)」

注意

Windowsエラー報告(Windows Error Reporting(WER)分析

スタックオーバーフローが原因で発生した異常終了の場合、OS側からFJVM側の処理へ制御が渡らず、そのままWindowsエラー報告へ制御が渡されることがあります。この場合は、FJVMログが出力されないため、Windowsエラー報告を確認してください。
Windowsエラー報告に以下の例外番号が出力されている場合には、スタックオーバーフローが原因と考えられます。
なお、Windowsエラー報告の説明は、“9.5.9.1 クラッシュダンプ”を参照してください。

スタックオーバーフローを示す例外番号

c00000fd (スタックオーバーフロー)

9.5.8.2 異常終了時のシグナルハンドラ情報

Java VMの実行制御で必要となる“表9.9 Java VMの制御で必要となるシグナル”の各シグナルに対するシグナルハンドラ情報が確認できます。

表9.9 Java VMの制御で必要となるシグナル

Solaris版Java VM

Linux版Java VM

SIGSEGV
SIGPIPE
SIGBUS
SIGILL
SIGFPE
INTERRUPT_SIGNAL (デフォルトはSIGUSR1)
ASYNC_SIGNAL (デフォルトはSIGUSR2)
SIGQUIT (注1)
SIGINT (注1)
SIGHUP (注1)
SIGTERM (注1)
SIGXFSZ (注3)

SIGSEGV
SIGPIPE
SIGBUS
SIGILL
SIGFPE
INTERRUPT_SIGNAL (デフォルトはSIGUSR1) (注2)
SR_SIGNUM (デフォルトはSIGUSR2)
SIGQUIT (注1)
SIGINT (注1)
SIGHUP (注1)
SIGTERM (注1)
SIGXFSZ (注3)

注1)

-Xrsオプションで操作対象となるシグナルです。

注2)

Java VMでリザーブしているシグナルです。
注1)および注2)のシグナルに関するシグナルハンドラ情報は出力しません。

注3)

Java VMで使用されているシグナルです。

シグナルハンドラ情報として、以下の情報が出力されています。

表9.9 Java VMの制御で必要となるシグナル”のシグナルハンドラがJava VM以外の処理で登録されていた場合、Java VMは正常に動作しません。この場合、当該シグナルハンドラを登録しないようにアプリケーションを修正してください。

9.5.8.3 異常終了時のJavaヒープに関する情報

異常終了時のJavaヒープの使用状況が確認できます。

Javaヒープのサイズによる異常終了の場合、異常終了時にどのJavaヒープの枯渇により異常終了が発生したかが確認できます。

9.5.8.4 出力例と調査例

出力例を元に説明します。

--------------------------------------------------------------------------------
#### Java VM: Java HotSpot(TM) 64-Bit Server VM (**.*.**_FUJITSU_MODIFIED-B**[*****] mixed mode)
>>>> Logging process start. [pid=879] Time=Tue Mar  7 19:54:10 2017

(1) 異常終了箇所の情報

異常終了箇所に関する情報が確認できます。
libjvm.soのsysThreadAvailableStackWithSlack関数の近くでSIGSEGV(メモリアクセスで不正なセグメントを参照)が発生しています。
本例の場合、Java VM内で異常が発生していると判断します。
異常終了箇所がJavaアプリケーション内でないため、異常発生時のスタックトレース情報を調査します。
本例の場合、com.appli.ap.business.AL02ABB00000.toStringの延長で不正なアクセスが発生しているので、そこからAL02ABB00000.javaの489行目で不正なアクセスを招きそうな箇所がないか調べます。

Unexpected Signal : SIGSEGV [0xb] occurred at PC= ffffffff65c0067c, pid= 879, nid=1
Function name=sysThreadAvailableStackWithSlack
Library=/opt/FJSVawjbk/jdk7/jre/lib/sparcv9/fjvm/libjvm.so

Current Java thread:
0xffffffff7b8e2850 - 0xffffffff7b8e4b7c at com.appli.ap.business.AL02ABB00000.toString(AL02ABB00000.java:489)
0xffffffff7b8e2850 - 0xffffffff7b8e4b7c at com.appli.ap.business.AL02ABB00000.toString(AL02ABB00000.java:520)
                                        at java.lang.String.valueOf(String.java:1942)
                                        at java.lang.StringBuffer.append(StringBuffer.java:365)
- locked <0xffffffff72fdea48> (a java.lang.StringBuffer)
                                        at com.appli.ap.business.AL02ABB25201.doExecute(AL02ABB25201.java:774)
                                        at com.appli.ap.formula.AFCC6842.doDelegate(AFCC6842.java:221)
                                       at com.appli.ap.formula.ejb.session.AFSF6801.doExecuteOrdinarily(AFSF6801.java:381)
                                        at com.appli.ap.formula.ejb.session.FJAFSF6801_AFSF6801RemoteImpl.doExecuteOrdinarily(FJAFSF6801_AFSF6801RemoteImpl.java:464)
- locked <0xffffffff72fdef70> (a com.appli.ap.formula.ejb.session.FJAFSF6801_AFSF6801RemoteImpl)
                                        at com.appli.ap.formula.ejb.session._FJAFSF6801_AFSF6801RemoteImpl_Tie._invoke(_FJAFSF6801_AFSF6801RemoteImpl_Tie.java:76)
                                        at com.fujitsu.ObjectDirector.CORBA.ServerRequest.call_invoke(ServerRequest.java:961)
                                        at com.fujitsu.ObjectDirector.PortableServer.POA.MsgRecv(POA.java:2578)
                                        at com.fujitsu.ObjectDirector.PortableServer.POAManager.MsgRecv(POAManager.java:1061)
                                        at com.fujitsu.ObjectDirector.PortableServer.POAnc.MsgRecv(POAnc.java:163)

Dynamic libraries:
0x0000000100000000 /opt/FJSVawjbk/jdk7/bin/java
0xffffffff7f200000 /usr/lib/libthread.so.1
0xffffffff7ed00000 /usr/lib/libdl.so.1
~~~~~~~
略
~~~~~~~
0xffffffff7be00000 /lib/64/libuutil.so.1
0xffffffff7bc00000 /lib/64/libgen.so.1

Local Time = Wed May 30 19:54:10 2017
Elapsed Time = 22

注意:

Error IDの行が出力されている場合、Error IDとして出力されている値は、Java VMが内部処理矛盾を自己検出した場合に出力する内部情報コードです。

#
# HotSpot Virtual Machine Error : SIGSEGV (0xb)
#  [ pc= ffffffff65c0067c, pid=879(0x36f), nid=1(0x0000000000000001), tid=0x000000010010e000 ]
#
# Please report this error to FUJITSU
#
# JRE version: Java(TM) SE Runtime Environment (7.0_***-b**) (build 1.7.0_***-b**_Fujitsu_**-**-**_**:**)
# Java VM: Java HotSpot(TM) 64-Bit Server VM (**.*.**_FUJITSU_MODIFIED-B** mixed mode solaris-sparc compressed oops)
~~~~~~~
略
~~~~~~~

(2)異常終了時のシグナルハンドラ情報

異常終了時のシグナルハンドラに関する情報が確認できます。
本例では、すべて「(in VM)」表示なので、シグナルハンドラの登録変更に関する問題はありません。

##>> Signal Handlers
 VM signal handler[1]=0xffffffff7d68eef8, VM signal handler[2]=0xffffffff7dff7fdc, SIG_DFL=0x0000000000000000,
SIG_IGN=0x0000000000000001, INT_SIG=(16,39), ASYNC_SIG=(17,40)
  SIGSEGV       :signal handler=0xffffffff7dff7fdc (in VM *)
  SIGPIPE       :signal handler=0xffffffff7d68eef8 (in VM)
  SIGBUS        :signal handler=0xffffffff7dff7fdc (in VM *)
  SIGILL        :signal handler=0xffffffff7d68eef8 (in VM)
  SIGFPE        :signal handler=0xffffffff7d68eef8 (in VM)
  SIGXFSZ       :signal handler=0xffffffff7d68eef8 (in VM)
  ALT_INTERRUPT_SIGNAL  :signal handler=0xffffffff7de603d8 (in VM +)
  ALT_ASYNC_SIGNAL      :signal handler=0xffffffff7d68eef8 (in VM)

(3)異常終了時のJavaヒープ領域に関する情報

異常終了時のJavaヒープ領域に関する情報が確認できます。

パラレルGC使用時:
「PSYoungGen」が「New世代領域」、
「PSOldGen」が「Old世代領域」、
「PSPermGen」が「Permanent世代領域」
に関する情報です。

CMS付きパラレルGC使用時:
「par new generation」が「New世代領域」、
「concurrent mark-sweep generation」が「Old世代領域」、
「concurrent-mark-sweep perm gen」が「Permanent世代領域」
に関する情報です。

なお「Old世代領域」および「Permanent世代領域」における「object space」についての情報は出力されません。

シリアルGC使用時:
「def new generation」が「New世代領域」、
「tenured generation」が「Old世代領域」、
「compacting perm gen」が「Permanent世代領域」
に関する情報です。

本例の場合、異常終了時点における「New世代領域」+「Old世代領域」の領域(-Xmxで最大量が指定される領域)には、空きがあることがわかります。
また「Permanent世代領域」に対しても、余裕があることがわかります。

注意:
パーセントで示されている値は、異常終了した時点でFJVMがJavaヒープ用に利用可能な状態にしている(コミットしている)メモリ量に対する比率です。利用可能な上限値に対する比率ではありません。
パーセントで示されている値は参照せず、K(キロ)単位で表示されているメモリ使用量の値と、オプションで指定された値(デフォルト値を含む)とを比較して判断してください。

注意:
パラレルGCを使用していた場合、以下の「-Xms=」「-Xmx=」に続いて表示される値は、-Xmsオプション/-Xmxオプションで指定された値およびページサイズなどのシステム情報を元に、Java VMが最適となるよう初期値/最大値を計算し直し、実際にJava VMが使用した値が出力されます。そのため、指定された値と異なる場合があります。

##>> Heap
 PSYoungGen      total 3584K, used 184K [0xffffffff72c00000, 0xffffffff73000000, 0xffffffff75800000)
  eden space 3072K, 6% used [0xffffffff72c00000,0xffffffff72c2e170,0xffffffff72f00000)
  from space 512K, 0% used [0xffffffff72f00000,0xffffffff72f00000,0xffffffff72f80000)
  to   space 512K, 0% used [0xffffffff72f80000,0xffffffff72f80000,0xffffffff73000000)
 PSOldGen        total 8192K, used 593K [0xffffffff6d800000, 0xffffffff6e000000, 0xffffffff72c00000)
  object space 8192K, 7% used [0xffffffff6d800000,0xffffffff6d894478,0xffffffff6e000000)
 PSPermGen       total 24576K, used 3098K [0xffffffff68400000, 0xffffffff69c00000, 0xffffffff6d800000)
  object space 24576K, 12% used [0xffffffff68400000,0xffffffff68706ae8,0xffffffff69c00000)
(-Xms=12288K, -Xmx=131072K, -XX:PermSize=21248K, -XX:MaxPermSize=86016K)