A.1.7 トレース情報の分析

Interstage Application Server/Interstage Web Server トラブルシューティング集

目次索引

付録A Javaツール機能

> A.1 メソッドトレース機能

A.1.7 トレース情報の分析

　ここでは、Servletのサンプルを利用して、トレース情報の分析方法を説明します。

■サンプルNumGameの場合

　サンプルNumGameを例として、トレース情報の見方について説明します。
　ここでは、NumGameを初回呼出し後、Servletコンテナを停止した場合のトレース情報を例に説明します。

制御ファイル

　制御ファイルに、以下の定義を追加します。
　設定方法の詳細については、“制御ファイルの作成方法”を参照してください。

----------------------------------------------------------------------
traceMethod=NumGame *
traceMethod=NumGameParameter *
traceMethod=pkgNumGameBean.NumGameBean *
valueLevel=none
timeStamp=true
----------------------------------------------------------------------

トレース情報

　採取されたトレースは以下のようになります。
　注) 左端の数字は、説明のための行番号です。実際には出力されません。

-------------------------------------------------------------------------------
 1: 12/09/2003 11:06:10.187, in, Thread-20, NumGame, init
 2: 12/09/2003 11:06:10.218, out, Thread-20, NumGame, init
 3: 12/09/2003 11:06:10.343, in, Thread-20, NumGame, doGet
 4: 12/09/2003 11:06:10.531, in, Thread-20, pkgNumGameBean.NumGameBean, <init>
 5: 12/09/2003 11:06:10.531, out, Thread-20, pkgNumGameBean.NumGameBean.<init>
  ・・・(略)・・・
 6: 12/09/2003 11:06:10.671, in, Thread-20, NumGameParameter, getParameter
 7: 12/09/2003 11:06:10.765, out, Thread-20, NumGameParameter, getParameter
  ・・・(略)・・・
 8: 12/09/2003 11:06:13.546, out, Thread-20, NumGame, doGet
 9: 12/09/2003 11:06:24.156, in, Thread-20, NumGame, destroy
10: 12/09/2003 11:06:24.156, out, Thread-20, NumGame, destroy
-------------------------------------------------------------------------------

トレース情報の見方

　init,doGet,destroyメソッドの呼出しと復帰 1,2,3,8,9,10行目
　“[時刻], in, ...”はメソッドの呼出しを、“[時刻], out, ...”は復帰を表しています。
　上の例では正常に処理が行われているため、init,service,destroyともに“[時刻], in, ...”と“[時刻], out, ...”が対になって出力されています。

　初期化(initメソッド) 1,2行目
　NumGameサーブレットの初回呼出し時にinitメソッドが呼び出されます。
　NumGameのinitメソッドでは処理を行っていないため、init中のトレース情報は出力されていません。

　サービス(doGetメソッド) 3～8行目
　各メソッドとも、呼出し後正常に復帰しているため、“[時刻], in, ...”と“[時刻], out, ...”が対になって出力されています。
　doGetメソッドの中には、Servletの主処理が記述されています。
　トレース情報の意味は、“トレース情報出力の形式”を参照してください。

　終了処理(destroyメソッド) 9,10行目
　Servletコンテナの停止時に呼び出されるdestroyメソッドのトレース情報です。
　NumGameのdestroyメソッドでは処理を行っていないため、destroy中のトレース情報は出力されていません。

■異常のあるサーブレットの例

　異常のあるサーブレットを例として、トレース情報の見方について説明します。

応答がなくなるNumGameのソース

-------------------------------------------------------------------------------
 1:  import javax.servlet.http.*;
 2:  import javax.servlet.*;
 3:  import java.io.*;
 4:  public class NumGame extends HttpServlet
 5:  {
 6:  public void doGet(HttpServletRequest req, HttpServletResponse res)
 7:  throws ServletException, IOException {
 8:  HttpSession session = req.getSession(true);
 9:  try {
10:    // アプリケーションオブジェクトの取得
11:    NumGameBean _application =
12:      (NumGameBean) session.getAttribute("gamebean");
13:    if (_application == null) { // 新規またはSessionTimeOut
14:      _application = new NumGameBean();
15:      session.setAttribute("gamebean", _application);
16:      _application.init();
17:    }
18:    // 使用するパラメータクラスの決定
19:    NumGameParameter inform = new NumGameParameter();
20:    // パラメータクラスに入力されたデータを設定
21:    inform.setRequest(req);
22:    int num;
23:    try {
24:      num = Integer.parseInt(inform.getParameter("Number"));
25:    } catch (NumberFormatException ne) {
26:      num = 0;
27:    }
     以下省略
-------------------------------------------------------------------------------

制御ファイル

----------------------------------------------------------------------
traceMethod=NumGame *
traceMethod=NumGameParameter *
traceMethod=pkgNumGameBean.NumGameBean *
valueLevel=none
timeStamp=true
----------------------------------------------------------------------

トレース情報

-------------------------------------------------------------------------------
19/10/2003 10:59:53:922, in, Thread-20, NumGame, doGet
19/10/2003 10:59:54:032, in, Thread-20, pkgNumGameBean.NumGameBean, <init>
19/10/2003 10:59:55:434, out, Thread-20, pkgNumGameBean.NumGameBean, <init>
19/10/2003 10:59:58:408, in, Thread-20, NumGameParameter, <init>
19/10/2003 10:59:58:418, out, Thread-20, NumGameParameter, <init>
19/10/2003 10:59:59:630, in, Thread-20, NumGameParameter, setRequest
19/10/2003 10:59:59:640, out, Thread-20, NumGameParameter, setRequest
19/10/2003 10:59:59:670, in, Thread-20, NumGameParameter, getParameter
-------------------------------------------------------------------------------

分析結果

　トレース情報より、以下がわかります。

“19/10/2003 10:59:59:670, in, Thread-20, NumGameParameter, getParameter”が出力されていることから、NumGameParameter#getParameterメソッドは呼び出されている。
他方、対となるNumGameParameter#getParameterに対する“..., out, ...”が出力されていないことから、NumGameParameter#getParameterメソッドが復帰していない。

　以上より、NumGameParameter#getParameterメソッドの中で処理が止まっていたことがわかります。

　EJBやJavaアプリケーションの場合も同様です。ユーザアプリケーションのクラスを設定ファイルに設定し、トレース情報を採取します。“in, ...”に対して“out, ...”がなく、ログが出力されていないような場合、応答がないということがわかります。

目次索引