Oracle Diagnostics Loggingのツールの利用

Oracle Diagnostics Logging (ODL)はOracle Fusion Middlewareの機能の1つです。管理者はこの機能を使用して、Oracle Formsのセッションをすべて記録し、Oracle Forms関連のネットワークの通信量を監視し、サイトの構成問題をデバッグできます。

Forms Servicesで使用できるOracle Diagnostics Loggingの機能には、次のものがあります。

セッションの開始時間と終了時間、ユーザーのIPアドレス、ホスト名を含むのすべてのOracle Formsセッションの記録(セッション・レベルのロギング)
Oracle Forms関連のネットワークの通信量とパフォーマンスの監視(セッション・パフォーマンスとリクエスト・パフォーマンス・レベルのロギング)
サイトの構成に関するデバッグ情報の生成(デバッグ・レベルのロギング)
Fusion Middleware Controlで処理されるロギング
これらのログ・ファイル内のイベントとデータベースのイベントとの関連付け
ログ・ファイルのローテーションの自動処理
以前のようなOSレベルのスクリプトによる方法ではなく、メカニズムによるログ・サイズ制限の処理

この節の内容は以下のとおりです。

Oracle Diagnostics Loggingの有効化

ロギングを起動すると、Listener Servletがログ・メッセージをサーブレットのログ・ファイルに書き込みます。

各ロギング・レベルにおける出力例を確認するには、「各レベルのサーブレット・ロギングの出力例」を参照してください。

次の表では、サポートされているロギング機能について説明します。serverURLに文字列を付加しない場合は、デフォルトのロギングがサポートされます。別のロガーを開始するには、次の項の説明にあるようにそれらをserverURLで指定する必要があります。

表-47 サポートされているロギング機能

serverURLクライアント・パラメータに追加する文字列	ロギングの説明
(なし)	Formsサーブレットの初期化時に、使用される構成ファイルの名前とパスを示すメッセージがログ・ファイルに書き込まれます。logging.xmlでデフォルトのロガーに対して設定されたログ・レベル以上のレベルのメッセージがログに記録されます。デフォルト値はNOTIFICATION:1で、NOTIFICATION:1、WARNING:1、ERROR:1およびINTERNAL_ERRORの各レベルがログに記録されます。
/session	Formsセッションが開始または終了するときには、必ずログ・メッセージが書き込まれます。このメッセージには、クライアント(ユーザーのWebブラウザが稼働しているコンピュータ)のホスト名とIPアドレス、ランタイム・プロセスID、および一意の内部セッションID番号が含まれます。
/sessionperf	セッション終了メッセージにパフォーマンス・サマリー統計が含まれます。
/perf	クライアントからのリクエストすべてに、パフォーマンス・メッセージが書き込まれます。
/debug	すべてのデバッグ・メッセージ。前述のメッセージを含むその他のデバッグ・メッセージが書き込まれます。このロギング・レベルは情報量が多く、主にデバッグやサポート用に使用します。

ロギングの指定

すべてのユーザーに対してロギングを指定するには、「Web構成」ページのデフォルト・セクションでserverURLエントリを次のように変更します。

serverURL=/forms/lservlet/<string>

このエントリの<string>には、表-47で説明されているロギング機能を指定します。stringを指定しないとデフォルトのロギングになります。たとえば、セッションレベルのロギングを開始するには、serverURLを次のように変更します。

serverURL=/forms/lservlet/session

Fusion Middleware Controlを使用したロギング・レベルの指定

Fusion Middleware Controlを使用してFormsサーブレットのロギングにログ・レベルを設定するには、次の手順を実行します。

Fusion Middleware Controlで管理対象サーバーを選択します(WLS_FORMSなど)。
「WebLogic Server」メニューで、「ログ」→「ログ構成」を選択します。
「ロガー名」フィールドでルート・ロガーを開きます。oracleとoracle.formsをそれぞれ開きます。serverURLに定義されたロガー名(前項を参照)が表示されます。たとえば、oracle.forms.servlet.debugと表示されます。

「Oracle Diagnostic Loggingレベル」フィールドのリストから、必要なログ・レベルを選択します。内部Formsログ・レベルからJavaレベルへのマッピングは、次の表を参照してください。

表-48 Oracle Diagnostic Loggingレベル

内部Formsログ・レベル	Javaログ・レベル
DEBUG	TRACE:32
REQUEST_PERFORMANCE	TRACE:16
SESSION_PERFORMANCE	TRACE:1
SESSION_START_END	NOTIFICATION:16
NOTIFICATION	NOTIFICATION:1
WARNING	WARNING:1
ERROR	ERROR:1
INTERNAL_ERROR	INTERNAL_ERROR

ノート:

この構成によって、管理対象サーバーのlogging.xmlファイルが変更されます。

Formsサーブレットを起動するURLでの完全診断の指定

完全診断を開始するには、次のようにformsweb.cfgでserverURLパラメータを指定します。

serverURL=/forms/lservlet/debug

次のURLを使用してOracle Formsアプリケーションを起動します。

http://example.com/forms/frmservlet/debug?

診断ログの表示

診断ログの内容は、Fusion Middleware Controlから表示します。

診断ログの内容を表示するには:

「Forms」メニューから「ホーム」を選択します。

Fusion Middleware Controlホームページが表示されます。
「Formsデプロイメント」リージョンで、「サーブレット・ログ」列にスクロールします。
対象の配布済アプリケーションに対応するログ・リンクをクリックします。

「ログ・メッセージ」ページが表示されます。

「サーブレット」ページの使用

「Forms」メニューから「監視」→「サーブレット・ログ」を選択します。このページで、収集されたサーバー診断ログの検索、ソート、表示、ダウンロードおよびエクスポートを実行できます。

ログ・ファイルの管理および表示の詳細は、『Oracle Fusion Middlewareの管理』の「ログ・ファイルと診断データの管理」を参照してください。

ログ・ファイルの場所

デフォルトのサーブレット・ログ・ファイル名はformsapp-diagnostic.logです。これは、Formsが配置されているOracle WebLogic管理対象サーバーのWLS_FORMS/logsディレクトリに書き込まれます。

Oracle Forms Servicesでのフル・パスは、次のとおりです。

$DOMAIN_HOME/servers/WLS_FORMS/logs/<application name>-diagnostic.log

デフォルトでは、forms_pid.trcファイルにトレース・ログが格納されます。pidはユーザー・セッションのプロセスIDです。このトレース・ログのデフォルトの場所は次のとおりです。

$DOMAIN_HOME/system_components/FORMS/forms1/trace/forms_pid.trc

このログを表示するには、Translateユーティリティを使用します(詳細は、「Translateユーティリティの実行」を参照)。

各レベルのサーブレット・ロギングの出力例

次のロギング・レベルを使用した場合の各種の出力例を示します。

(なし)

[2008-09-10T06:58:47.106-07:00] [WLS_FORMS] [NOTIFICATION] [FRM-93100]
 [oracle.forms.servlet] [tid: 11] [ecid: 0000HlCYKnmD4i8nvgy0V118lx4u000000,0]
 [APP: formsapp] [arg: 
configFileName:     <configfilename>
testMode:           false] Initializing the Forms Servlet.  Initialization
 parameters are:[[
    configFileName:    <configfilename> 
    testMode:           
false
]]
[2008-09-10T06:58:53.517-07:00] [WLS_FORMS] [NOTIFICATION] [FRM-93180]
 [oracle.forms.servlet] [tid: 11] [ecid: 0000HlCZfTDD4i8nvgy0V118lx4u000003,0]
 [APP: formsapp] [arg: 
envFile:            null
executable:         null
WaitTime:           500
MaxBlockTime:       1000] 
Initializing ListenerServlet.  Initialization parameters
 are:[[
    envFile:            null
    executable:         null
    WaitTime:           500
    MaxBlockTime:       1000
]]

/session

[2008-09-11T07:35:01.507-07:00] [WLS_FORMS] [NOTIFICATION:16] [FRM-93251]
[oracle.forms.servlet.session] [tid: 14] [ecid:
0000HlHpYGDD4i8nvgy0V118mFuv00000V,0] [SRC_CLASS:
oracle.forms.servlet.RunformSession] [APP: formsapp] [SRC_METHOD: <init>] [FORMS
SESSION_ID: ..8] [arg: sup-pc1] [arg: xxx.xxx.xxx.xxx] Runtime session started
for client <pc1> (IP address <ip address>).
2008-09-11T07:35:01.798-07:00] [WLS_FORMS] [NOTIFICATION:16] [FRM-93548]
[oracle.forms.servlet.session] [tid: 14] [ecid:
0000HlHpYGDD4i8nvgy0V118mFuv00000V,0] [SRC_CLASS:
oracle.forms.servlet.RunformProcess] [APP: formsapp] [SRC_METHOD: connect] [FORMS
SESSION_ID: ..8] [arg: 7765] Runtime process ID is 7765.
2008-09-11T07:38:11.372-07:00] [WLS_FORMS] [NOTIFICATION:16] [FRM-93252]
[oracle.forms.servlet.session] [tid: 14] [ecid:
0000HlHpYGDD4i8nvgy0V118mFuv00000V,0] [SRC_CLASS:
oracle.forms.servlet.RunformSession] [APP: formsapp] [SRC_METHOD: stop] [FORMS
SESSION_ID: ..8] Forms session ended.

/sessionperf

[2008-09-11T07:40:25.923-07:00] [WLS_FORMS] [NOTIFICATION:16] [FRM-93251]
[oracle.forms.servlet.sessionperf] [tid: 17] [ecid:
0000HlHqlS9D4i8nvgy0V118mFuv00000Y,0] [SRC_CLASS:
oracle.forms.servlet.RunformSession] [APP: formsapp] [SRC_METHOD: <init>] [FORMS
SESSION_ID: ..9] [arg: <pc1>] [arg: xxx.xxx.xxx.xxx] Runtime session started
for client <pc1> (IP address xxx.xxx.xxx.xxx).
2008-09-11T07:40:26.223-07:00] [WLS_FORMS] [NOTIFICATION:16] [FRM-93548]
 [oracle.forms.servlet.sessionperf] [tid: 17] [ecid:
0000HlHqlS9D4i8nvgy0V118mFuv00000Y,0] [SRC_CLASS:
oracle.forms.servlet.RunformProcess] [APP: formsapp] [SRC_METHOD: connect] [FORMS
SESSION_ID: ..9] [arg: 8023] Runtime process ID is 8023.
2008-09-11T07:40:43.593-07:00] [WLS_FORMS] [NOTIFICATION:16] [FRM-93252]
[oracle.forms.servlet.sessionperf] [tid: 17] [ecid:
0000HlHqlS9D4i8nvgy0V118mFuv00000Y,0] [SRC_CLASS:
oracle.forms.servlet.RunformSession] [APP: formsapp] [SRC_METHOD: stop] [FORMS
SESSION_ID: ..9] Forms session ended.
[2008-09-11T07:40:43.594-07:00] [WLS_FORMS] [TRACE] [FRM-93710]
[oracle.forms.servlet.sessionperf] [tid: 17] [ecid:
0000HlHqlS9D4i8nvgy0V118mFuv00000Y,0] [SRC_CLASS:
oracle.forms.servlet.RunformSession] [APP: formsapp] [SRC_METHOD: stop] [FORMS
SESSION_ID: ..9] [arg: 1.557] [arg: 6] [arg: 0] [arg: 1.000] [arg: 0.259] [arg:
5106] [arg: 352] Total duration of network exchanges is 1.557.[[
Total number of network exchanges is 6 (0 long ones over 1.000 sec).
Average time for one network exchange (excluding long ones) is 0.259.
Total number of bytes sent is 5106.
Total number of bytes received is 352.
]]

/perf

[2008-09-11T07:42:46.560-07:00] [WLS_FORMS] [NOTIFICATION:16] [FRM-93251]
[oracle.forms.servlet.perf] [tid: 14] [ecid: 0000HlHrJmWD4i8nvgy0V118mFuv00000^,0]
[SRC_CLASS: oracle.forms.servlet.RunformSession] [APP: formsapp] [SRC_METHOD:
<init>] [FORMS_SESSION_ID: ..10] [arg: <pc1>] [arg: xxx.xxx.xxx.xxx] Runtime
session started for client <pc1> (IP address <ip address>).
[2008-09-11T07:42:46.854-07:00] [WLS_FORMS] [NOTIFICATION:16] [FRM-93548]
[oracle.forms.servlet.perf] [tid: 17] [ecid: 0000HlHqlS9D4i8nvgy0V118mFuv00000Y,0]
[SRC_CLASS: oracle.forms.servlet.RunformProcess] [APP: formsapp] [SRC_METHOD:
connect] [FORMS_SESSION_ID: ..10] [arg: 8149] Runtime process ID is 8149.
[2008-09-11T07:42:46.865-07:00] [WLS_FORMS] [TRACE:16] [FRM-93700]
[oracle.forms.servlet.perf] [tid: 17] [ecid: 0000HlHqlS9D4i8nvgy0V118mFuv00000Y,0]
[SRC_CLASS: oracle.forms.servlet.ListenerServlet] [APP: formsapp] [SRC_METHOD:
doPost] [FORMS_SESSION_ID: ..10] [arg: 0.011] [arg: 8] [arg: 8] [arg: null]
Request duration is 0.011 seconds.  Request size is 8 bytes; response size is 8
bytes.
[2008-09-11T07:42:47.921-07:00] [WLS_FORMS] [TRACE:16] [FRM-93700]
[oracle.forms.servlet.perf] [tid: 17] [ecid: 0000HlHqlS9D4i8nvgy0V118mFuv00000Y,0]
[SRC_CLASS: oracle.forms.servlet.ListenerServlet] [APP: formsapp] [SRC_METHOD:
doPost] [FORMS_SESSION_ID: ..10] [arg: 0.438] [arg: 272] [arg: 5022] [arg: null]
Request duration is 0.438 seconds.  Request size is 272 bytes; response size is
5022 bytes.

/debug

[2009-02-11T14:39:03.016+00:00] [WLS_FORMS] [NOTIFICATION:16] [FRM-93250]
 [oracle.forms.servlet] [tid: [ACTIVE].ExecuteThread: '2' for queue:
 'weblogic.kernel.Default (self-tuning)'] [userId: <anonymous>] [ecid: 0000Hx
_lhDcD4i8nvgy0V119Xz350000HZ,0] [APP: formsapp#12.2.1] Forms session started.
[2009-02-11T14:39:03.017+00:00] [WLS_FORMS] [TRACE:32] [FRM-94200]
 [oracle.forms.servlet] [tid: [ACTIVE].ExecuteThread: '2' for queue:
'weblogic.kernel.Default (self-tuning)'] [userId: <anonymous>] [ecid: 0000Hx
_lhDcD4i8nvgy0V119Xz350000HZ,0] [SRC_CLASS: oracle.forms.servlet.FormsServlet]
 [APP: formsapp#12.2.1] [SRC_METHOD: doRequest] [FORMS_SESSION_ID: ..43] [arg:
 GET] [arg: 
cmd:                frmservlet
config:             null
requestCharset:     null
QueryString:        null
Content-Type:       null
Accept-Charset:     null    
responseCharset:    null] FormsServlet receiving GET request.  Details:[[
    cmd:                frmservlet
    config:             null
    requestCharset:     null
    QueryString:        null
    Content-Type:       null
    Accept-Charset:     null
    responseCharset:    null
]]
[2009-02-11T14:39:03.017+00:00] [WLS_FORMS] [TRACE:32] [FRM-94281]
 [oracle.forms.servlet] [tid: [ACTIVE].ExecuteThread: '2' for queue:
 'weblogic.kernel.Default (self-tuning)'] [userId: <anonymous>] [ecid: 0000Hx
_lhDcD4i8nvgy0V119Xz350000HZ,0] [SRC_CLASS: oracle.forms.servlet.ListenerServlet]
 [APP: formsapp#12.2.1] [SRC_METHOD: printSessionDetails] [FORMS_SESSION_ID: ..43]
 No current servlet session ID.
[2009-02-11T14:39:03.017+00:00] [WLS_FORMS] [TRACE:32] [FRM-94170]
 [oracle.forms.servlet] [tid: [ACTIVE].ExecuteThread: '2' for queue:
 'weblogic.kernel.Default (self-tuning)'] [userId: <anonymous>] [ecid: 0000Hx
_lhDcD4i8nvgy0V119Xz350000HZ,0] [SRC_CLASS: oracle.forms.servlet.FormsServlet]
 [APP: formsapp#12.2.1] [SRC_METHOD: findFile] [FORMS_SESSION_ID: ..43] [arg:
 basejpi.htm] [arg: <config folder>] File basejpi.htm is missing from the
 current directory, looking in <config folder>
[2009-02-11T14:39:21.460+00:00] [WLS_FORMS] [TRACE:32] [FRM-94200]
 [oracle.forms.servlet] [tid: [ACTIVE].ExecuteThread: '2' for queue:
 'weblogic.kernel.Default (self-tuning)'] [userId: <anonymous>] [ecid: 0000Hx
_llhoD4i8nvgy0V119Xz350000Hd,0] [SRC_CLASS: oracle.forms.servlet.FormsServlet]
 [APP: formsapp#12.2.1] [SRC_METHOD: doRequest] [FORMS_SESSION_ID: ..43] [arg:
 GET] [arg: 
cmd:                startsession
config:             null
requestCharset:     null
QueryString:       ifsessid=..43&acceptLanguage=en-us&ifcmd=startsession&iflocale=en-US
    Content-Type:       null
Accept-Charset:     null
responseCharset:    null] 
FormsServlet receiving GET request.  Details:[[
    cmd:                startsession
    config:             null
    requestCharset:     null
    QueryString:        ifsessid=..43&acceptLanguage=en-us&ifcmd=startsession&iflocale=en-US
    Content-Type:       null
    Accept-Charset:     null
    responseCharset:    null
]]
 
 
.
.
.
.
 
[2009-02-11T14:39:21.716+00:00] [WLS_FORMS] [TRACE:32] [FRM-94201]
 [oracle.forms.servlet] [tid: [ACTIVE].ExecuteThread: '2' for queue:
 'weblogic.kernel.Default (self-tuning)'] [userId: <anonymous>] [ecid: 0000Hx
_llloD4i8nvgy0V119Xz350000Hf,0] [SRC_CLASS: oracle.forms.servlet.ListenerServlet]
[APP: formsapp#12.2.1] [SRC_METHOD: doGet] [FORMS_SESSION_ID: ..43] [arg: GET]
 [arg: 
cmd:                getinfo
QueryString:        ifcmd=getinfo&ifhost=sup-pc1&ifip=xxx.xxx.xxx.xxx]
 ListenerServlet receiving GET request.  Details:[[
    cmd:                getinfo
    QueryString:        ifcmd=getinfo&ifhost=sup-pc1&ifip=xxx.xxx.xxx.xxx
]]
 
[2009-02-11T14:39:21.717+00:00] [WLS_FORMS] [TRACE:32] [FRM-94282]
 [oracle.forms.servlet] [tid: [ACTIVE].ExecuteThread: '2' for queue:
 'weblogic.kernel.Default (self-tuning)'] [userId: <anonymous>] [ecid: 0000Hx
_llloD4i8nvgy0V119Xz350000Hf,0] [SRC_CLASS: oracle.forms.servlet.ListenerServlet]
 [APP: formsapp#12.2.1] [SRC_METHOD: printSessionDetails] [FORMS_SESSION_ID: ..43]
 [arg:
 HyLhJSjZ85F5GWbZLDgwp1MY02FK5tC6yVDP1LylbCvgmv9y3CfK!126690176!1234363161461]
 Existing servlet session, ID =
 HyLhJSjZ85F5GWbZLDgwp1MY02FK5tC6yVDP1LylbCvgmv9y3CfK!126690176!1234363161461
[2009-02-11T14:39:21.717+00:00] [WLS_FORMS] [TRACE:32] [FRM-94286]
 [oracle.forms.servlet] [tid: [ACTIVE].ExecuteThread: '2' for queue:
'weblogic.kernel.Default (self-tuning)'] [userId: <anonymous>] [ecid: 0000Hx
_llloD4i8nvgy0V119Xz350000Hf,0] [SRC_CLASS: oracle.forms.servlet.ListenerServlet]
 [APP: formsapp#12.2.1] [SRC_METHOD: printSessionDetails] [FORMS_SESSION_ID: ..43]
 Session ID is not from cookie.
[2009-02-11T14:39:21.717+00:00] [WLS_FORMS] [TRACE:32] [FRM-94430]
 [oracle.forms.servlet] [tid: [ACTIVE].ExecuteThread: '2' for queue:
 'weblogic.kernel.Default (self-tuning)'] [userId: <anonymous>] [ecid: 0000Hx
_llloD4i8nvgy0V119Xz350000Hf,0] [SRC_CLASS: oracle.forms.servlet.RunformSession]
 [APP: formsapp#12.2.1] [SRC_METHOD: <init>] [FORMS_SESSION_ID: ..43] Trying to
 get a prestarted process.
[2009-02-11T14:39:21.717+00:00] [WLS_FORMS] [TRACE:32] [FRM-94432]
 [oracle.forms.servlet] [tid: [ACTIVE].ExecuteThread: '2' for queue:
 'weblogic.kernel.Default (self-tuning)'] [userId: <anonymous>] [ecid: 0000Hx
_llloD4i8nvgy0V119Xz350000Hf,0] [SRC_CLASS: oracle.forms.servlet.RunformSession]
 [APP: formsapp#12.2.1] [SRC_METHOD: <init>] [FORMS_SESSION_ID: ..43] Prestarted
 process is not available.
[2009-02-11T14:39:21.718+00:00] [WLS_FORMS] [TRACE:32] [FRM-94522]
 [oracle.forms.servlet] [tid: [ACTIVE].ExecuteThread: '2' for queue:
 'weblogic.kernel.Default (self-tuning)'] [userId: <anonymous>] [ecid: 0000Hx
_llloD4i8nvgy0V119Xz350000Hf,0] [SRC_CLASS: oracle.forms.servlet.RunformSession]
 [APP: formsapp#12.2.1] [SRC_METHOD: <init>] [FORMS_SESSION_ID: ..43] [arg: null]
 Creating new runtime process using default executable.
[2009-02-11T14:39:21.718+00:00] [WLS_FORMS] [TRACE:32] [FRM-94532]
 [oracle.forms.servlet] [tid: [ACTIVE].ExecuteThread: '2' for queue:
 'weblogic.kernel.Default (self-tuning)'] [userId: <anonymous>] [ecid: 0000Hx
_llloD4i8nvgy0V119Xz350000Hf,0] [SRC_CLASS: oracle.forms.servlet.RunformProcess]
 [APP: formsapp#12.2.1] [SRC_METHOD: startProcess] [FORMS_SESSION_ID: ..43] [arg:
 frmweb webfile=HTTP-0,default] RunformProcess.startProcess():  executing frmweb
 webfile=HTTP-0,default
 
.
.
.
.