問題判別 1 WASV6.1による基幹システム設計Workshop

WASV6.1による基幹システム設計Workshop
問題判別
1
Agenda
„
問題判別の心得
‹
‹
„
IHS / WebSphere Application Server問題判別
‹
‹
‹
„
‹
情報収集
症状別問題判別
通信データ問題判別
‹
„
IHS/WAS情報収集・問題判別
JVM問題判別
症状別問題判別
Edge Component問題判別
‹
„
問題が起こる前に
情報収集（既知情報）
通信データ情報収集
（参考）Rational Application Developer問題判別
‹
‹
症状別問題判別
Fix、オプション・フィーチャーの適用方法
2
2
問題判別の基本手順
問題発生
当セッションにて解説
問題の種類 / 発生箇所の特定
対応策
・パッチの適用
・設定の変更
・アプリの修正
…
問題原因の究明
採集資料（ログやトレース）の分析
既知の問題
再現手順の調査
さらなる資料の採集・分析
既知情報の
収集
情報の保存
質問・採集した資料の送付
サポートセンターに連絡
3
上記は、WebSphere製品に関わらず、一般的なOS/ソフトウェア製品の問題判別の基本手順になります。
問題判別とは、発生した問題の原因を特定し、その問題を解決するための対応策を実施して、問題が解決し
たことをテストで確認するための作業です。
問題が発生したら、その問題の種類や発生箇所の分析を行います。そして、取得したログやトレースを使用し
て、その問題が起こっている原因を究明します。その原因に応じて、パッチの適用や設定の変更、アプリケー
ションの修正などといった対応をします。原因が既知の問題である場合には既知情報を収集し、その問題に対
して適切な対応をします。
次に、その問題の再現性について調査します。再現性がある場合はその再現手順について調査します。そし
て、さらに公開されている資料や既知情報をもとに問題の分析を行います。ここで調査した情報を、今後同じよ
うな問題が起こったときのために残しておくことも大切になります。
最終的に問題への対応方法が分からず、解決されない場合は、サポートセンターに連絡し解析を依頼します。
その際、質問内容と一緒にログやトレースなどの採集した資料も送付します。
3
問題判別の心得
情報収集（既知情報）
‡
‡
‡
‡
‡
‡
‡
‡
‡
問題が起こる前に
問題判別の基本手順
はじめに確認すべきサイト
WASサポート・サイト / 重要障害情報
Defect・List / iFix・List(Edge)
(参考)WAS修正について
MustGather
IBM Support Assistant(ISA)
IBM Guided Activity Assistant(IGGA)
4
4
問題が起こる前に
„
障害情報や修正プログラム情報の収集
‹
WASサポート・サイトから最新リリースをチェック
¾
‹
„
最新リリースの適用を推奨
障害情報の確認
問題の発生を想定した設計・構成
‹
‹
‹
WASクラッシュ時にヒープダンプを出力させる
OSのCoreファイル出力先のサイズに余裕を持たせる
サービスを停止することなくFixpackを適用する
„
機能テスト、パフォーマンステストの実施
„
プロジェクト体制
‹
障害発生時の役割分担、体制などの明確化
5
問題が発生する前に、それに備えておくべきこととしては、まず障害情報や修正プログラム情報の収集
が挙げられます。これらの情報は、WASのサポート・サイトから得ることが出来ます。WASサポート・サイトは、
最新リリースの情報や障害に関する情報が随時更新されており、これらを事前に調べておくことが望まし
いです。また、WASの導入にあたっては最新リリースの適用が推奨されます。更に本番システムを導入す
るにあたり、機能テスト、パフォーマンステストを事前に行っておくことや障害発生時の役割分担などプロ
ジェクト体制を明確化することも重要です。
5
はじめに、確認すべきサイト
„
InfoCenter(製品マニュアル)
‹
„
WASサポート・サイト
‹
‹
„
‹
‹
過去のQA情報などが検索できる
http://www.ibm.com/support/jp/search
Defect・List
‹
‹
„
日本語の技術情報や連載記事、Workshop資料を入手可能
http://www.ibm.com/jp/software/websphere/developer
テクニカル・サポート検索
‹
„
Technoteや既知の障害情報を検索可能
http://www.ibm.com/software/webservers/appserv/was/support/
Developer・Domain
‹
„
http://publib.boulder.ibm.com/infocenter/wasinfo/v6r1/index.jsp?
RefreshPack・FixPackによる機能追加・修正内容の一覧表示
http://www.ibm.com/support/docview.wss?rs=180&uid=swg27007951
iFix・List（Edge)
‹
‹
iFixによる修正内容を日本語にて一覧表示
http://www.ibm.com/jp/software/websphere/download/ifix/was/edge/learnmore.html
6
上記は、問題判別の際に、”はじめに確認すべきサイト”として纏めさせて頂きました。WASサポート・サ
イト、Defect・List、iFix・List(Edge)につきましては、次ページ以降で紹介させて頂きます。
6
WASサポート・サイト
„
Technotesや既知の障害情報を検索可能
推奨される修正プログラム、
FixPackのダウンロード
情報の検索
Technotes、修正プログラムの情報
InfoCenter、RedBook
IBM Support Assistant
7
＜WASサポート・サイト＞
Technotesや既知の障害情報を検索する事が出来ます。
・TechNotesや修正プログラム情報
・情報の検索
・推奨される修正プログラム、FixPackのダウンロード
・InfomationCenter、RedBook
7
Defect・List（WAS） / iFix ・List（Edge）
„
Defect・List（WAS）
‹
RefreshPack・FixPackによる機
能追加・修正内容の一覧表示
FixPackに対する、Defect Listを一覧表示
„
iFix・List(Edge)
‹ iFixによる修正内容の一
覧表示
バージョン毎に修正/不具合の
概要、APAR番号が表示
8
Defect・Listでは、RefreshPack・FixPackによりどのような機能追加や修正が行われたのかを確認する事
が出来ます。iFix・List(Edge)では、EdgeのFix情報を日本語で確認する事が出来ます。FixPack適用の際
は、是非、ご参考にして下さい。
8
MustGather
„
WebSphere Application Serverの問題判別のサポートサイト
‹
„
発生した問題に対する情報収集の作業方法などを掲載
MustGather:
Read first for all WebSphere Application Server products
‹
http://www.ibm.com/support/docview.wss?rs=180&uid=swg21145599
問題の種類、発生コンポーネントの
リストから選択
問題の種類ごとに
取得すべき情報と作業方法を記載
9
その他、問題が発生した際に参考にするサポートサイトとして、MustGathe：Read first for all WebSphere
Application Serverがあります。このページでは、問題の種類や問題が発生したコンポーネントがリストに
なっており、問題の種類に応じて取得すべき情報収集の作業方法などが示されております。問題判別を
行う際には参考にして下さい。
(例)問題の種類、発生コンポーネント
・100% CPU Usage
・Classloader
・DB Connections/Connection Pooling
・EJB
9
IBM Support Assistant(ISA) (1/2)
„
„
製品に関する課題を解決するために役立つワークベンチ
製品導入CD もしくは、下記サイトより導入
‹
„
問題判別に役立つ情報を検索
‹
„
Googleも検索対象
製品情報を検索
‹
‹
‹
„
http://www.ibm.com/software/support/isa/
Support Link
developerWorks
推奨Fix 等
問題を診断する
‹
‹
‹
‹
MDD4J
PMAT
ThreadAnalyzer
IGAA 等
10
IBM Support Assistant(ISA)とは、製品に関する課題を解決するために役立つワークベンチになります。 WAS
製品導入CDもしくは、次のリンク先(http://www.ibm.com/software/support/isa/)より導入することが出来ます。
コンポーネント毎の使用方法・目的は以下になります。
＜アップデーター＞・・・ IBM Support Assistant (ISA) を更新する
製品・ツールをISAに追加、アップグレードする。当コンポーネントにて、必要となる製品やツール等を登録しま
す。
＜検索＞・・・製品に関する課題の解決に役立つ情報を検索する。
複数ロケーションを並行アクセスし、次を対象とし検索。(WebSphere製品だけではなく、その他の製品(Tivoli、
IMS等)も検索可能)
IBM ソフトウェア・サポート文書、IBM developerWorks、IBM ニュースグループおよびフォーラム、IBM 製品の
インフォメーション・センター、GoogleTM。
＜製品情報＞・・・製品課題の解決に役立たせることができる次の製品情報をアクセスする。
ホーム・ページ、サポート・ページ、ニュースグループおよびフォーラム、スキル、トラブルシューティング。
＜サービス＞・・・問題報告書を提出して、製品の課題を解決する。
問題報告書の作成および提出、診断データの自動収集、既存問題報告書の表示と更新、問題判別ファイル
の送信。
＜ツール＞・・・専門化されたソフトウェア・ツールを使用して製品の問題を診断する。
IBM分析ツールを使用した問題判別作業の支援、特定の製品問題に対してのツールの選択、新規ツールの
ダイナミックな追加。
＜IBM Workplace for Customer Support＞・・・IBM Workplace for Customer Supportへのリンク。
IBMソフトウェアのプレミアムサポートをご契約いただいているお客様のための個別カスタマイズ可能なポータ
ルページを表示。
10
IBM Support Assistant(ISA) (2/2)
„
検索
検索条件入力
検索対象を選択
製品枠を超えた、複数リソースの検索が可能
„
製品情報
製品毎に、各種重要情報を提示
11
上記は、IBM Support Assistant(ISA)にて、検索と製品情報を選択した場合の画面キャプチャーになります。
11
IHS / WebSphere Application Server問題判別
IHS/WAS情報収集・問題判別
‡
‡
‡
‡
‡
‡
‡
‡
‡
‡
‡
‡
各コンポーネントで取得できるログ
IHSの情報収集・取得されるログ
IHSアクセスログのカスタマイズ
IHSエラーログのログレベル
プラグインで取得されるログ
プラグインログのログレベル
プラグインログのトレース
WASの情報収集・取得されるログ
JVMログ
JVMログに出力されるメッセージ
プロセスログ
FFDCログ
‡
‡
‡
‡
‡
‡
‡
‡
‡
‡
HTTPトランスポートログ
IBM保守ログ
WASのトレース
ログ詳細レベルの変更
ロギングレベル
ログレベルの変更
ロギングレベルの変更
WASのトレースの取得例
JDBCトレースログ
JDBCトレースログの設定方法
12
12
各コンポーネントで取得できるログ・トレース
„
„
„
IHS
プラグイン
WAS
HTTP(S)
WebServer
WebServer
(IHS)
(IHS)
Plug-in
Module
access.log、error.log
http_plugin.log
HTTP(S)
Plug-in
Config
XML file
Application
Application
Server
Server
(WAS)
(WAS)
連携
DB
JDBCトレースログ
SystemOut.log、SystemErr.log、
native_stdout.log、native_stderr.log、
http_access.log、http_error.log、
activity.log、<process>_<time>.log
13
ログは問題判別の基本となるものであり、出力する製品や階層に応じてさまざまなログが出力されます。この章
では、IHSからWASに至るまでのログについて紹介します。
ブラウザから実行されるリクエストはまずIHSに届き、そのリクエストがWASに処理を委ねるものとプラグインが判
断した場合、プラグインはそのリクエストをWASに渡します。WAS内で処理されたリクエストはプラグイン、IHSを
通ってブラウザに戻されます。つまり、ブラウザから実行されるリクエストはIHSのログ、プラグインのログ、WASの
ログ(HTTPトランスポートのログ、JVMログ.etc)という順に記載されていきます。
問題判別をされる際には、クライアントに近い方から順番に問題の切り分けを実施して下さい。
13
IHSの情報収集
„
バージョン
‹
[Unix]
<IHS_ROOT>/bin/apachectl –v
‹
[WINDOWS]
<IHS_ROOT>/bin/Apache.exe –v
# <IHS_ROOT>/bin/apachectl –v
Server version: IBM_HTTP_Server/6.1.0.7 Apache/2.0.47
Server built: Jan 10 2007 17:45:55
‹
<IHS_ROOT>/bin/versionInfo.bat(sh)
# <IHS_ROOT>/bin/versionInfo.bat
インストール済み製品
-------------------------------------------------------------------------------名前
IBM HTTP Server
バージョン
6.1.0.0
ID
IHS
ビルド・レベル
b0620.14
„
設定ファイル
‹
<IHS_ROOT>/conf/httpd.conf
14
IHSで問題判別の際に収集すべき情報には、バージョン、ログ、設定ファイルがあります。バージョンは、Unix
環境では<IHS_ROOT>/apachectl –vコマンドにて、Windows環境では<IHS_ROOT>/bin/Apache.exe –vコマンド
を実行することで、IHSのバージョンと対応するApacheのバージョンが表示されます。また、IHSのバージョン情報
は、<IHS_ROOT>/bin/versionInfo.bat(sh)コマンドでも確認できます。ログファイルは<IHS_ROOT>/logs以下に
存在し、設定ファイルは<IHS_ROOT>/conf/httpd.confに存在します。
14
IHSで取得されるログ
„
ログファイル
‹
„
access.log
‹
‹
‹
„
デフォルトは、<IHS_ROOT>/logs
IHSに届いたリクエストの処理記録
LogFormatディレクティブで、記録項目はカスタマイズ可能（→後述）
出力先はディレクティブで指定（管理コンソールからも可能）
error.log
‹
‹
‹
IHSのリクエスト、もしくは処理中に発生したエラーやwarningを記録
LogLevelディレクティブで、ログレベルは変更可能（→後述）
出力先はディレクティブで指定（管理コンソールからも可能）
15
IHSで取得されるログは、access.logとerror.logの2つになります。
access.logは、クライアントからIHSに届いたリクエストに対するリプライの記録であり、アクセス数の集計によく用
いられるログです。access.logに記述される内容は、LogFormatディレクティブでカスタマイズが可能です。
error.logは、リクエストもしくはIHSがリクエストを処理する中で発生したエラーやWarningを記録するログです。
出力される内容はLogLevelディレクティブで変更することが可能です。
これら2つのログはデフォルトでは<IHS_ROOT>/logsに出力されますが、CustomLogやErrorLogディレクティブ
で出力先やログ名を変更することも可能です。またV6からはデプロイメントマネージャの管理下にあれば、管理
コンソールから出力先を変更することも可能です。
問題判別をされる際には、access_logでのリクエストのHTTPステータスやレスポンスタイム、error_logにエラー
メッセージが出力されていないか等を確認して下さい。
15
IHSアクセスログのカスタマイズ
„
LogFormatディレクティブ
‹
‹
指示子でもってログに記述する内容を定義
各々のフォーマットに識別のための名前をつけ、そのフォーマット名で
ログに結びつける
httpd.conf
LogFormat "%h %l %u %t ¥"%r¥" %>s %b ¥"%{Referer}i¥" ¥"%{User-Agent}i¥"" combined
LogFormat "%h %l %u %t ¥"%r¥" %>s %b" common
LogFormat "%{Referer}i -> %U" referer
LogFormat "%{User-agent}i" agent
フォーマット名commonを
CustomLog logs/access.log common
ログのフォーマットに指定。
ログの出力ディレクトリ、ファイル名を指定。
‹
IHSのレスポンスタイムはデフォルトでは記載がないので注意
¾
％D（マイクロ秒表示）もしくは％T（秒表示）をLogFormaｔに追加
手動でレスポンスタイムをログに記録させる設定が必要。
httpd.conf
LogFormat “%h %l %u %t ¥”%r¥“ %>s %b %D ” common
16
アクセスログのカスタマイズは、LogFormatディレクティブで行います。デフォルトでは以上4パターンの
LogFormatが指定されており、それぞれに名前が付けられています。LogFormatディレクティブの最後に指定さ
れている内容（上記のcombined、common、referer、agent）がそれぞれのフォーマット名になります。アクセスログ
の出力先はCustomLogで指定しますが、その際、最後にフォーマット名を記述します。そうすることで、指定され
たフォーマットでアクセスログに出力されます。
LogFormatでは、ログに記述する内容を指示子と呼ばれる特殊記号で表現します。デフォルトで指定されてい
るLogFormatではIHSのレスポンスタイムは記録されません。IHSのレスポンスタイムを記録するには、LogFormat
ディレクティブに%Dもしくは%Tを追加する必要があります。％Dはマイクロ秒単位、％Tは秒単位でIHSがリクエス
トを受け取ってレスポンスを返すまでにかかる時間をアクセスログに記録します。また、リクエストがIHSに入って
来た時ではなく、IHSから出て行った時にaccess_logにログが書き込まれます。従いまして、access_logでは、リク
エスト順にログが書き込まれるわけでは無い事をご注意下さい。
問題判別の観点からは、このレスポンスタイム出力を設定される事をお勧め致します。
・IHSのLogFormatディレクティブ
http://httpd.apache.org/docs/2.1/mod/mod_log_config.html#formats
16
IHSエラーログのログレベル
„
LogLevelディレクティブ
‹
‹
‹
エラーログに記録される内容のレベルを指定
デフォルト：Warn
debug,info,notice,warn,error,crit,alert,emergの8種類
httpd.conf
LogLevel debug
error.log
LogLevelをWarnからdebugに変更してIHSを起動したときの例
デフォルトのWarnでは記録されない、子プロセスの情報などが記録される
[Thu Sep 15 15:32:23 2005] [notice] IBM_HTTP_Server/6.0.2 Apache/2.0.47 (Win32) configured -- resuming
normal operations
親プロセスが子プロセス（ID 3644）を
[Thu Sep 15 15:32:23 2005] [notice] Server built: May 11 2005 17:32:46
立ち上げる
[Thu Sep 15 15:32:23 2005] [notice] Parent: Created child process 3644
[Thu Sep 15 15:32:23 2005] [debug] mpm_winnt.c(521): Parent: Sent the scoreboard to the child
[Thu Sep 15 15:32:24 2005] [notice] Child 3644: Child process is running
[Thu Sep 15 15:32:24 2005] [info] Parent: Duplicating socket 204 and sending it to child process 3644
[Thu Sep 15 15:32:24 2005] [debug] mpm_winnt.c(442): Child 3644: Retrieved our scoreboard from the
parent.
[Thu Sep 15 15:32:24 2005] [debug] mpm_winnt.c(639): Parent: Sent 1 listeners to child 3644
[Thu Sep 15 15:32:24 2005] [debug] mpm_winnt.c(598): Child 3644: retrieved 1 listeners from parent
[Thu Sep 15 15:32:24 2005] [notice] Child 3644: Acquired the start mutex.
[Thu Sep 15 15:32:24 2005] [notice] Child 3644: Starting 250 worker threads.
子プロセス（ID 3644）が
17
250個のスレッドを起動
IHSのエラーログに記録される内容は、LogLevelディレクティブで指定することが出来ます。ログレベルには
debug、info、notice、warn、error、crit、alert、emergの7種類がありdebugからemargになるにつれ重要度が高くな
ります。ログレベルはデフォルトではWarnに設定されているため、Warnより上の重要度の情報が記載されます。
さらにdebugやinfoといった詳細な情報をログに記録させたい場合には、LogLevelディレクティブの指定をdebug
に変更すると、全ての情報がエラーログに記載されるようになります。問題判別を行う際には、このログレベルを
上げて下さい。
17
各コンポーネントで取得できるログ・トレース
„
„
„
IHS
プラグイン
WAS
HTTP(S)
WebServer
WebServer
(IHS)
(IHS)
Plug-in
Module
access.log、error.log
http_plugin.log
HTTP(S)
Plug-in
Config
XML file
Application
Application
Server
Server
(WAS)
(WAS)
連携
DB
JDBCトレースログ
SystemOut.log、SystemErr.log、
native_stdout.log、native_stderr.log、
http_access.log、http_error.log、
activity.log、<process>_<time>.log
18
ログは問題判別の基本となるものであり、出力する製品や階層に応じてさまざまなログが出力されます。この章
では、IHSからWASに至るまでのログについて紹介します。
ブラウザから実行されるリクエストはまずIHSに届き、そのリクエストがWASに処理を委ねるものとプラグインが判
断した場合、プラグインはそのリクエストをWASに渡します。WAS内で処理されたリクエストはプラグイン、IHSを
通ってブラウザに戻されます。つまり、ブラウザから実行されるリクエストはIHSのログ、プラグインのログ、WASの
ログ(HTTPトランスポートのログ、JVMログ.etc)という順に記載されていきます。
問題判別をされる際には、クライアントに近い方から順番に問題の切り分けを実施して下さい。
18
プラグインで取得されるログ
„
http_plugin.log
‹
‹
‹
プラグインの処理内容を記録
WebサーバーとWAS間の通信に問題があるときに参照
plugin-cfg.xmlファイル内でログに関する設定を行う (→後述)
¾
設定は管理コンソールからも実施可能
plugin-cfg.xml
<Config ASDisableNagle="false" AcceptAllContent="false" AppServerPortPreference="HostHeader"
ChunkedResponse="false" FIPSEnable="false" IISDisableNagle="false" IISPluginPriority="High"
IgnoreDNSFailures="false" RefreshInterval="60" ResponseChunkSize="64"
VHostMatchingCompat="false">
<Log LogLevel="Error" Name="C:¥IBM¥WebSphere¥Plugins6/logs/webserver1/http_plugin.log"/>
ログレベル
ログの出力先
管理コンソール
「サーバー」→「Webサーバー」→
<WebServer name>→「プラグイン・プロパティー」 19
プラグインが出力するログがhttp_plugin.logになります。http_plugin.logはプラグインの処理内容が記録されて
おり、WebサーバーとWASとの通信に問題があると思われたときに参照して問題解析を行ってください。
プラグインログに関するログレベルや出力先の設定はplugin_cfg.xmlで記載されており、plugin_cfg.xml内の
LogLevel、Nameといった設定箇所を編集することで変更することが可能です。またV6からは管理コンソールから
の「プラグイン・プロパティー」からも設定が可能です。管理コンソールから設定を行うためには、Webサーバー
がデプロイメントマネージャの管理下である必要があります。またplugin-cfg.xmlの位置は、IHSの設定ファイルで
あるhttpd.confで指定します。
19
プラグインログのログレベル
„
Error（デフォルト）
‹
„
Warn
‹
„
リクエストおよびリプライに関する情報を記録
Debug
‹
„
リクエストに対し選択されたサーバー、ロードバランシング情報を記録
Detail
‹
„
プラグインの処理中に発生したエラーとWarningを記録
Stats
‹
„
プラグインの処理中に発生したエラーを記録
リクエストの処理中に実行された重大なステップが記録
Trace （→後述）
‹
リクエストを受けた際にプラグインが行った全過程を記録
http_plugin.log
[Wed Sep 14 15:20:09 2005] 0000049c 00000e18 - STATS: ws_server_group: serverGroupCheckServerStatus:
Checking status of mercuryNode01_server1, ignoreWeights 0, markedDown 0, retryNow 0, wlbAllows 1
reachedMaxConnectionsLimit 0
20
[Wed Sep 14 15:20:09 2005] 0000049c 00000e18 - STATS: ws_server: serverSetFailoverStatus:
Server mercuryNode01_server1 : pendingConnections 0 failedConnections 0 affinityConnections 0 totalConnections 1.
プラグインログの出力レベルは、デフォルトではErrorになっています。つまり、エラーが発生しない限り、プラグ
インがリクエストを正しく割り振ってもその記録は残りません。より詳細な記録をプラグインログに記載させるため
にはログレベルを変更する必要があります。
ログレベルにはError以外にも、Debug、Detail、Warn、Stats、Traceがあり、Traceがもっとも詳細に処理内容が
記載されます。Statsではプラグインの割り振り先やロードバランシング情報が記載されます。IHSとWASが1対N
構成時に、IHSのプラグインが割り振ったサーバーを確認したい場合にはStatsを設定されると良いかと思います。
20
プラグインログのトレース
„
ログレベルを「Trace」に設定
‹
‹
リクエストを受けた際にプラグインが行った全過程を記録
以下は、http://localhost/JVM/input.htmlのリクエストを処理した過程の抜粋
http_plugin.log
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: ws_common: websphereShouldHandleRequest: trying to match a route for:
仮想ホスト、URIを比較し、
vhost='localhost'; uri='/JVM/input.html'
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: ws_common: websphereVhostMatch: Found a match '*:80' to 'localhost:80' in
WASに処理を渡すことを判断
VhostGroup: default_host with score 1
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: ws_common: websphereUriMatch: Found a match '/JVM/*' to '/JVM/input.html' in
UriGroup: default_host_server1_mercuryNode01_Cluster_URIs with score 5
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: mod_was_ap20_http: as_translate_name: WebSphere will handle:
/JVM/input.html・・・・・
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: lib_htrequest: htrequestSetMethod: Setting the method |GET|
WASに送るリクエストのヘッダ作成
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: lib_htrequest: htrequestSetURL: Setting the url |/JVM/input.html| ・・・・・
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - STATS: ws_server_group: serverGroupCheckServerStatus: Checking status of
mercuryNode01_server1, ignoreWeights 0, markedDown 0, retryNow 0, wlbAllows 1 reachedMaxConnectionsLimit 0
リクエストを処理するサーバーの情報を取得。
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: ws_server_group: lockedServerGroupUseServer: Server mercuryNode01_server1
サーバーにアクセスし、Weightを1減らす
picked, weight 0.
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: ws_server_group: serverGroupIncrementConnectionCount: Server
mercuryNode01_server1 picked, pendingConnectionCount 1 totalConnectionsCount 1.
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: lib_htrequest: htrequestWrite: Writing the request:
WASにリクエストを送信し、レスポンスを受信する
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: GET /JVM/input.html HTTP/1.1 ・・・・
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: lib_htrequest: htrequestWrite: Writing the request content
（その際のヘッダの情報を取得）
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: lib_htresponse: htresponseRead: Reading the response: 5b9874
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: HTTP/1.1 200 OK ・・・・・
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: ws_common: websphereExecute: Done with Request to app server processing
クライアントに返すレスポンスのヘッダ作成し、
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: mod_was_ap20_http: cb_write_headers: In the write headers callback
プラグインは処理を終了
[Wed Sep 14 15:30:08 2005] 00000e00 00000ef4 - TRACE: ws_common: websphereEndRequest: Ending the request
21
プラグインログのレベルをTraceに設定すると、プラグインが処理した詳細な内容がログに記載されますので、
問題判別時には非常に有用です。以上のログは、プラグインログのレベルをトレースにしたときのログを抜粋し
て見やすくした例です。リクエストがプラグインに来てから、仮想ホストやURIを比較しWASに処理を渡すことを判
断したことを示す記述や、リクエストヘッダの生成、リクエストを処理するサーバーの選択、リクエストの送信とレス
ポンスの受信、さらにクライアントに返すレスポンスのヘッダを作成してクライアントに処理を返すまでの内容を確
認することが出来ます。
21
各コンポーネントで取得できるログ・トレース
„
„
„
IHS
プラグイン
WAS
HTTP(S)
WebServer
WebServer
(IHS)
(IHS)
Plug-in
Module
access.log、error.log
http_plugin.log
HTTP(S)
Plug-in
Config
XML file
Application
Application
Server
Server
(WAS)
(WAS)
連携
DB
JDBCトレースログ
SystemOut.log、SystemErr.log、
native_stdout.log、native_stderr.log、
http_access.log、http_error.log、
activity.log、<process>_<time>.log
22
ログは問題判別の基本となるものであり、出力する製品や階層に応じてさまざまなログが出力されます。この章
では、IHSからWASに至るまでのログについて紹介します。
ブラウザから実行されるリクエストはまずIHSに届き、そのリクエストがWASに処理を委ねるものとプラグインが判
断した場合、プラグインはそのリクエストをWASに渡します。WAS内で処理されたリクエストはプラグイン、IHSを
通ってブラウザに戻されます。つまり、ブラウザから実行されるリクエストはIHSのログ、プラグインのログ、WASの
ログ(HTTPトランスポートのログ、JVMログ.etc)という順に記載されていきます。
問題判別をされる際には、クライアントに近い方から順番に問題の切り分けを実施して下さい。
22
WASの情報収集
„
情報収集ツール <WAS_PROFILE_ROOT>/bin/collector.sh(.bat)
‹
<Hostname>-<Cellname>-<Nodename>-<Profilename>-WASenv.jarファイル
にて出力
¾
¾
¾
¾
¾
¾
¾
¾
‹
-summaryオプションで、一つのテキストファイルで出力
¾
¾
¾
¾
¾
‹
„
コレクターツールのログ
<WAS_ROOT>と<WAS_PROFILE_ROOT>以下のbin、config、logs、profiles、propertiesディレク
トリ以下のファイルのコピー
OS情報
Java 情報
WAS情報 (<WAS_ROOT>以下のディレクトリ構造とファイルが記載)
コレクターツールが実行したシェルスクリプト (バッチファイル) の実行情報
MQ情報（WebSphereMQまたは組み込みメッセージングフィーチャーをインストールした場合）
JAR ファイルのマニフェスト
ホスト、ノード名
インストールディレクトリ
WASのバージョン
Javaのフルバージョン
OSのバージョン
Collectorコマンドはプロファイル単位で実行
バージョン
‹
versionInfoコマンド
23
WASで問題発生時に情報を収集するツールとしてcollectorコマンドがあります。実行すると以上の情報を一つ
の<Host name>-<Cell name>-<Node name>-<Profile name>-WASenv.jarというJARファイルにアーカイブします。
また、このコマンドはWASのインストールディレクトリ以外で実行する必要があり、適切なディレクトリから
<WAS_PROFILE_ROOT>/bin/collector.sh(.bat)を実行します。また、collectorコマンドに-summaryオプションを
つけて実行させると、以上の情報をCollector_Summary.txtという名前のテキストファイルで出力します。このファ
イルでは、WASやJavaのバージョンを確認することも出来ます。なお、collectorコマンドは自分のプロファイル以
下の内容しか取得しませんので、プロファイルが複数ある場合は、それぞれのプロファイル毎にcollectorコマン
ドを実行して下さい。
バージョンの確認は、<WAS_PROFILE_ROOT>/bin/versionInfo.sh(.bat) コマンドで確認することが出来ます。
その他、WASで問題判別の際に収集すべき情報には、ログ、設定ファイルがございますが、次ページ以降で
ご説明させて頂きます。
23
WASで取得されるログ
„
JVMログ（SystemOut.log / SystemErr.log）
‹
‹
„
プロセスログ(native_stdout.log / native_stderr.log)
‹
„
‹
エラー情報を発生時に自動で記録される
サポートセンター、開発部門が障害対応時に見るログ
HTTPトランスポートログ（http_access.log / http_error.log）
‹
‹
„
ネイティブコードやJVM自身の出力が書き込む情報
FFDCログ（<process_name>_<timestamp>.txt）
‹
„
JVMの標準出力、標準エラー出力
アプリケーションの挙動やプロセスの稼動状況
WebコンテナーのHTTPトランスポートに対するアクセスを記録するロ
グ
IHSを介さないアクセスに対するアクセスログ、エラーログ
IBM保守ログ（activity.log）
‹
‹
JVMに詳細な情報を記録したログ
showlogコマンドを使用
24
WASで取得できるログは、以上になりますので、ご確認下さい。
・JVMログ
SystemOut.log、SystemErr.logという名前で出力され、アプリケーションの挙動やプロセスの稼動状況を記載さ
れます。
・プロセスログ
native_stdout.log、native_stderr.logという名前で出力され、ネイティブコードやJVM自身の出力が記載されます。
・FFDC(First Failure Data Capture)ログ
全てのシステムエラーを発生時点で自動的に記録されるもので、サポートセンターや開発部門が障害対応時
に確認するログです。
・HTTPトランスポートログ
WebコンテナーのHTTPトランスポートに対するアクセスを記録するログで、IHSを介さないアクセスに対するア
クセスログとエラーログです。
・IBM保守ログ
JVMログにさらに詳細な情報を記録したログで、バイナリファイルのためエディターで開くことはできません。確
認するためにはshowlog.bat(sh)というコマンド実行が必要になります。
24
JVMログ
„
SystemOut.log / SystemErr.log
‹
‹
‹
問題判別を行う上で、最も重要なログ
アプリケーションの挙動やプロセスの稼動状況が記載されているログ
アプリケーションサーバー、ノードエージェント、デプロイメントマネージャなど各プロセ
ス単位で存在
「サーバー」→「アプリケーションサーバー」→<server_name>
→「ロギングおよびトレース」→「JVMログ」
出力先ファイル名
ファイルのフォーマット（基本or拡張）
＜ログファイルの循環＞
ファイルサイズ（指定サイズが来たとき）や
時間（指定時間に達したとき）で新規ファイルを
作成可能
アプリケーション内のprint文をログに書き込むか、
また、その文を指定したフォーマットに従って
25
フォーマットするか（デフォルト両方ON）
JVMログは、アプリケーションの挙動やプロセスの稼動状況が記載されているログで、問題判別を行う上でもっ
とも重要なログの一つです。JVMログは各アプリケーションサーバー、ノードエージェント、デプロイメントマネー
ジャなど、各プロセス単位で<WAS_PROFILE_ROOT>/logs/<process_name>ディレクトリ以下に出力されます。
JVMログに関する設定は管理コンソールから行います。
25
JVMログに出力されるメッセージ
„
メッセージID
‹
‹
メッセージを発行したコンポーネントやその重要度を示す
エラーメッセージが出た際、メッセージIDでInfocenterを検索して下さい
SystemOut.log
[05/07/07 14:17:57:965 JST] 0000000a WsServerImpl A WSVR0001I: e-business の
ためにサーバー server1 がオープンされました
メッセージID
最初の4文字（もしくは5文字）がコンポーネントを示す
続く数字がそのコンポーネントでメッセージを識別するための番号
最後の1文字が重要度（I=情報、W=警告、E=エラー）を示す
Infocenterから 「参照」→「メッセージ」より、
メッセージIDとその内容と対応を見ることができる
26
JVMログに出力されるメッセージにはメッセージIDと呼ばれるIDが付けられており、メッセージが分類できるよう
になっています。メッセージIDは最初の4文字（もしくは5文字）がコンポーネントを示しており、続く数字がそれら
のメッセージを識別するための番号、最後の一文字が重要度を示しています。重要度は、Iが情報、Wが警告、
Eがエラーを示しており、一番重要度が重いのはエラーです。
WAS V6.1のInfoCenterではメッセージIDごとにその内容と対応を確認することが出来ます。出力されたメッ
セージに関して情報が知りたい場合は、InfoCenterでメッセージIDをもとに検索して下さい。
・WebSphere V6.1 InfoCenter
http://publib.boulder.ibm.com/infocenter/wasinfo/v6r1/index.jsp
26
プロセスログ
„
native_stdout.log / native_stderr.log
‹
‹
‹
‹
ネイティブコードやJVM自身の出力が書き込まれるログ
SystemOut.logへの出力は、プロセスログへは出力されない（WAS V5より）
JVMのverbose:gcを設定した場合、その出力はnative_stderr.logに記録。
循環はしないが、JVMログに比べファイルの増加率は小さい。
「ロギングおよびトレース」→「プロセスログ」
出力先ファイル名
冗長ガーベッジコレクションをONにすると、
GCの詳細な情報がnative_stderr.logに出力される
27
プロセスログはネイティブコードやJVM自身の出力が書き込まれるログであり、WASV5からはSystemOut.logの
出力はプロセスログには出力されなくなりました。JVMログと違い、プロセスログには循環させるための仕組みは
組み込まれていませんが、JVMログに比べ、ファイルの増加率は非常に小さいです。また、JVMのverbose:gcの
設定をした場合、GCの結果の出力はデフォルトではnative_stderr.logに記載されます。ガーベッジコレクション
の状況を確認されたい場合には、当ログを確認して下さい。
27
FFDCログ（<process_name>_<timestamp>.txt）
„
First Failure Data Capture
‹
„
„
„
全てのシステムエラー情報を発生時点で自動的に記録するツール
サポートセンターや開発部門が障害時に見て分析
<WAS_PROFILE_ROOT>/logs/ffdcディレクトリに出力
<process name>_exception.log
‹
‹
サーバー起動中に発生した例外情報の統計を管理する
ffdcディレクトリに作成
28
FFDCとはFirst Failure Data Captureの略で、全てのシステムエラー情報を発生時点で自動的に記録する
ツールになります。このツールによって作成されたFFDCログは、サポートセンターや開発部門が障害時に確認
して分析を行うためのものです。ログはプロセス単位のディレクトリではなく、 <WAS_PROFILE_ROOT>/logs/ffdc
というディレクトリに出力されます。ファイル名は<process_name>_<timestamp>.txt（例えば、
server1_5c655712_04.11.18.2327.48_0.txt）となります。また、サーバー起動中に発生した例外情報の統計を管
理する<process name>_exception.logというログファイルもffdcディレクトリに作成されます。
28
HTTPトランスポートログ
„
http_access.log / http_error.log
‹
WebコンテナーのHTTPトランスポートに対するアクセスの記録
‹
デフォルトでは取得されない
¾
Webサーバーを介さない場合に有用なアクセスログ
「Webコンテナトランスポートチェーン」→<Transport_name>→
「HTTPインバウンドチャネル」
「サーバー」→「アプリケーションサーバー」→
<Server_name>→「HTTPエラーおよびNCSAアクセスロギング」
サーバーの起動時に
ロギングのサービスを使用可能にする
指定したトランスポートに対して
ロギングを使用可能にする
29
HTTPトランスポート・ログはアプリケーションサーバーのWebコンテナーのHTTPトランスポートに対するアクセ
スを記録するログで、Webサーバーのアクセスログと同等のものになります。これはWebサーバーを介さないアク
セスに対して、Webサーバーのアクセスログの代わりとなるログです。ファイル名はhttp_access.logおよび
http_error.logで、JVMログと同じディレクトリに出力されます。
HTTPトランスポートのログはデフォルトでは取得されないので、取得するためには設定を変更する必要がありま
す。
管理コンソールの「サーバー」→「アプリケーション・サーバー」からアプリケーションサーバーを選択し、「HTTP
エラーおよびNCSAアクセス・ロギング」を選択します。 設定画面では、アクセスロギングやエラーロギングを使用
可能にする、といった項目にはチェックが付いていますが、「サーバー始動時にサービスを使用可能にする」に
チェックが付いていませんので、チェックを入れます。他にもファイルの最大サイズやフォーマット（共通
（Common）or結合（Combined））、ファイル名などはここで指定します。
実際にどのHTTPトランスポートのリクエストおよびエラーをロギングするかの定義は、チャネルに対して行いま
す。アプリケーションサーバーのページより、 「Webコンテナー・トランスポート・チェーン」で該当トランスポート・
チェーンを選択し、「HTTPインバウンド・チャネル」をクリックします。設定画面の一般プロパティーの下の「アク
セス・ロギングおよびエラーロギングを使用可能にする」にチェックを付けると、このチャネルに対してリクエストさ
れたアクセスログとエラーログが出力されます。
29
IBM保守ログ
„
activity.log
‹
‹
JVMログに詳細情報を追加したログ
showlog(.bat)を使用して読み取る。
# <WAS_PROFILE_ROOT>/bin/showlog <WAS_PROFILE_ROOT>/log/activity.log
ComponentId: Application Server
(省略)
TimeStamp:
2007-06-08 17:58:30.968000000
UnitOfWork:
重大度: 3
カテゴリー:
INFO
PrimaryMessage: CWPKI0002I: SSL サービスの初期化が正常に完了しました。
ExtendedMessage:
30
IBM保守ログのファイル名はactivity.logという名前でノード単位に作成されます。これは
<WAS_PROFILE_ROOT>/logsディレクトリに出力されます。このIBM保守ログはJVMログに詳細情報を追加した
ログで、showlog.bat(sh)コマンドにてactivity.logの内容を確認する事が出来ます。
30
WASのトレース
„
trace.log
‹
‹
‹
WASコンポーネントの実行時の詳細な記録
障害発生箇所特定の大きな手がかり
稼動中のサーバーでも設定が可能
稼動中のサーバーでトレースの設定を行うには
ランタイムタブを開き、
「ランタイム変更も構成に保管する」をチェックし、
適用する
「サーバー」→「アプリケーションサーバー」→
<Server_name>→「診断トレースサービス」
トレースに書き出すコンポーネントの指定
（詳細は次ページ）
トレース機能を使用可能にする
（デフォルトON）
トレースの出力ファイル名、
最大ファイルサイズとヒストリーファイルの最大数
（最大サイズに達したとき、トレースファイルが新規に作成され、
ヒストリーファイル最大数の数だけ残される）
ファイルのフォーマット
（基本or拡張orログアナライザー）
31
トレースを用いると、アプリケーションサーバーや環境内の他のプロセスなど、WASコンポーネントの実行に関
する、より詳細情報を取得することが出来ます。トレースを使用することにより、障害発生箇所特定の大きな手が
かりとなります。トレースの収集は、多くの場合テクニカルサポート担当者の依頼の元で行います。トレースは
JVMログ同様にプロセス単位でディレクトリにtrace.logという名前で取得されます。また稼動中のサーバーでもト
レースの取得を設定することが可能ですので、アプリケーションサーバーを止めることなくトレースを出力させる
ことが出来ます。
トレースの設定画面は、管理コンソール左メニューから「サーバー」→「アプリケーションサーバー」でサーバー
を選択し、「診断トレースサービス」をクリックすると表示されます。この画面からは、トレースの出力先やバッ
ファーサイズ、最大ファイルサイズやフォーマットを指定することが出来ます。トレースの使用はデフォルトでも
ONになっています。
31
ログ詳細レベルの変更
„
„
コンポーネント単位でトレースに出力させるものを指定
下のGUIから選択orログ詳細レベル仕様を直接入力
ログ詳細レベル仕様 <component>=<level>を
直接書き込んでも構わない
ConfigErrorに対し、
レベルfine（詳細-中）を指定
*=info:ConfigError=fine:
com.ibm.ws.http.*=finest
他全てのログレベルはinfo（情報）
com.ibm.ws.http.*に対し、
レベルfinest（詳細-最高）を指定
32
トレース設定画面右の追加プロパティの「ログ詳細レベル仕様」をクリックすると、どのコンポーネントに対しログ
またはトレースをどのレベルで取得するかを設定することが出来ます。画面下からコンポーネントを選択しクリッ
クすると、レベルを選択するポップアップが現れますので、レベルを選択すると、それらが上記画面に反映され
る仕組みになっています。上記例では、ConfigErrorコンポーネントのレベルを詳細-中(fine)、com.ibm.ws.http.*
に対しレベルを詳細-最高(finest)を指定しています。それらの設定は上記画面に以上のように反映されます。な
お、デフォルトでは全てのレベルが情報(info)になっています。
また、上記画面からコンポーネントとレベルを<component>=<level>という形で直接書き込んでも構いません。
複数のコンポーネントに対しレベルを指定したい場合は「:」で区切ります。
32
ロギングレベル
„
„
OｆｆからAllまでの12段階
ｔrace.logに書き込まれるのは詳細-中（fine）以降
SystemOut.logログに
書き込まれる情報量が変化
トレースとしてtrace.logに
書き込まれる
v6のロギングレベル
管理コンソール上の呼び方
Off
オフ
Fatal
致命的
Severe
重大
Warning
警告
Audit
監査
Info
状況
Config
構成
v5.1.xのトレースレベル
Detail
詳細-低
Fine
詳細-中
Event
Finer
詳細-高
EntryExit
Finest
詳細-最高
Debug
All
すべて
All
33
コンポーネントに対するログレベルは「オフ」から「すべて」までの12段階です。オフに設定するとログには何も
書き込まれません。レベルはオフがもっとも低く、致命的(fatal)、重大(severe)、警告(warning)、監査(audit)、情報
(info)、構成(config)、詳細-低(detail)、詳細-中(fine)、詳細-高(finer)、詳細-最高(finest)の順に高くなり、すべて
(all)がもっとも高くなります。管理コンソール上の呼び名とV6でのロギングレベル、またV5のトレースレベルであ
るevent、entryexit、debug、allとの対応は以上の表のようになります。
このうち詳細-低(detail)まではtrace.logには出力しません。SystemOut.logやIBM保守ログに書き込まれるレベ
ルが変わります。レベルを詳細-中(fine)以上にすると、そのコンポーネントの内容がtrace.logに出力されます。
デフォルトでトレースは取得可能になっていますが、レベルが情報(info)になっているために、デフォルトでは
trace.logは出力されません。
33
ロギングレベルの変更
SystemOut.log （ログレベルInfo）
[05/09/16 16:12:54:781 JST] 0000000a ManagerAdmin I TRAS0017I: 開始トレース状態は *=info:
com.ibm.ws.webcontainer.httpsession.SMSessionContextParameters=config:com.ibm.ws.w
ebcontainer.httpsession.SessionContext=config:com.ibm.ws.webcontainer.httpsession.Sess
ionMgrComponentImpl=config です。
[05/09/16 16:12:56:312 JST] 0000000a AdminInitiali A ADMN0015I: 管理サービスが初期設定されます。
[05/09/16 16:12:58:828 JST] 0000000a SystemOut O PLGC0057I: プラグイン構成サービスは正常に開始されました。
[05/09/16 16:13:18:297 JST] 0000001f VirtualHost E SRVE0164E: Web アプリケーション jvm は、
コンテキスト・ルート /JVM/* を使用しますが、これは Web アプリケーション {2} によってすでに使用中です。
Web アプリケーション {3} はロードされません。
[05/09/16 16:13:18:391 JST] 00000020 ResourceMgrIm I WSVR0049I: Default を jdbc/Default としてバインドしています
[05/09/16 16:13:18:516 JST] 0000001f ApplicationMg W WSVR0101W: JvmHandsOn を開始中にエラーが発生しました
SystemOut.log （ログレベルWarning）
Warning以下のレベル（AuditやInfo）の情報は
書き込まれなくなる
[05/09/16 16:00:02:219 JST] 0000000b SystemOut O PLGC0057I: プラグイン構成サービスは正常に開始されました。
[05/09/16 16:00:20:781 JST] 0000001b VirtualHost E SRVE0164E: Web アプリケーション jvm は、
コンテキスト・ルート /JVM/* を使用しますが、これは Web アプリケーション {2} によってすでに使用中です。
Web アプリケーション {3} はロードされません。
[05/09/16 16:00:21:266 JST] 0000001b ApplicationMg W WSVR0101W: JvmHandsOn を開始中にエラーが発生しました
Fine以上にすると、SystemOut.logに加え、
trace.logが取られ、詳細な情報がTrace.logに記載される
trace.log （ログレベルFine）
[05/09/16 14:41:48:656 JST] 0000000a ManagerAdmin I TRAS0017I: 開始トレース状態は *=fine:
com.ibm.ws.webcontainer.httpsession.SMSessionContextParameters=config:com.ibm.ws.web
container.httpsession.SessionContext=config:com.ibm.ws.webcontainer.httpsession.Session
SystemOut.log （Fineの内容はない）
MgrComponentImpl=config です。
[05/09/16 14:41:48:656 JST] 0000000a
[05/09/16 14:41:49:750 JST] 0000000a TraceNLS
1 No message text associated with
com.ibm.ws.webcontainer.httpsession.
key Next.clean.up.set.for.Fri.Sep.16.18:20:00.JST.2005 in bundle com.ibm.ws.ffdc.res
.webcontainer.httpsession.SessionCon
ources.FFDCMessages
[05/09/16 14:41:50:125 JST] 0000000a
[05/09/16 14:41:49:734 JST] 0000000a FFDCJanitor 1 com.ibm.ws.ffdc.FFDCJanitor setNextCle
anupTime Next clean up set for Fri Sep 16 18:20:00 JST 2005
34
[05/09/16 14:41:49:750 JST] 0000000a TraceNLS
1 No m
上記例がそれぞれのレベルでのSystemOut.logとtrace.logです。警告(warning)レベルに設定すると、それ以下
のレベルの情報は書き込まれなくなりますので、監査(Audit)、情報(Info)レベルの情報はSystemOut.logには書
き込まれません。また、詳細-中(fine)の場合は、SystemOut.logに加え、さらにtrace.logがログレベルfineで書き
込まれます。
34
WASのトレースの取得例(1/2)
„
例：データベース接続の状況を確認する際のトレース
*=info:WAS.j2c=all:RRA=all:WAS.database=all:Transaction=all
‹
WAS－DB間での問題判別に有用
¾
¾
¾
接続プールの使用状況
リソース参照の情報（アイソレーションレベル・共用接続の有無、など）
トランザクションの開始・終了
trace.log
コネクションオブジェクトは
接続プール内で1つはInUse。
4つはFree。
その接続は共用接続
[06/05/24 14:55:38:484 JST] 00000038 PoolManager 3 reserve()
PoolManager name:jdbc/testDS
PoolManager object:1590132124
Total number of connections: 5 (max/min 10/1, reap/unused/aged 180/1800/0, connectiontimeout/purge 180/EntirePool)
(testConnection/inteval false/0, stuck timer/time/threshold 0/0/0, surge time/connections 0/-1)
Shared Connection information (shared partitions 200)
com.ibm.ws.LocalTransaction.LocalTranCoordImpl@7f957d83;RUNNING; MCWrapper id 20fb3d86 Managed connection
WSRdbManagedConnectionImpl@2ec3fd81 State:STATE_ACTIVE_INUSE
Total number of connection in shared pool: 1
Free Connection information (free distribution table/partitions 5/1)
(2)(0)MCWrapper id 7828fd84 Managed connection WSRdbManagedConnectionImpl@750bfd86 State:STATE_ACTIVE_FREE
(2)(0)MCWrapper id 423e7d89 Managed connection WSRdbManagedConnectionImpl@41f7fd89 State:STATE_ACTIVE_FREE
(2)(0)MCWrapper id 78c57d87 Managed connection WSRdbManagedConnectionImpl@4b82bd87 State:STATE_ACTIVE_FREE
(2)(0)MCWrapper id 2839bd84 Managed connection WSRdbManagedConnectionImpl@5e253d86 State:STATE_ACTIVE_FREE
Total number of connection in free pool: 4
UnShared Connection information
No unshared connections
35
ここでは実際にトレースを取得した際のサンプルを紹介します。
発生した問題に対してどのようなトレースを取得するかは、サポートセンターの指示や、先述した
MustGatherのサポートサイトなどを参考にして取得を行います。上記はデータベース接続の状況を確認
する際に有用な、j2cに関するトレースを取得した例になります。このトレース結果から、接続プールの使用
状況や、アイソレーションレベルや共用接続の有無といったリソース参照の情報、トランザクションに関す
る情報などがわかりますので、WASとデータベースとの間で問題が発生した際には、問題判別のために
非常に有用です。
以下は、ログレベルの設定が可能なコンポーネントとその中のサブコンポーネントの一覧になります。
・WebSphere V6.x Trace Groups and Components trace specification strings
http://www1.ibm.com/support/docview.wss?rs=180&context=SSEQTP&q1=Trace&q2=v6&uid=swg21199169&loc=en
_US&cs=utf-8&lang=en
以下は、MustGatherのページになります。
・MustGather：Read first for all WebSphere Application Server products
http://www-1.ibm.com/support/docview.wss?rs=180&uid=swg21145599
35
WASのトレースの取得例(2/2)
„
例：重要なアプリケーション・アクティビティーのロギング/トレース
*=info:WAS.clientinfopluslogging=all
‹
アプリケーションの問題判別に有用
¾
¾
trace.log
¾
実行された SQL ストリング（下記例）
トランザクションの開始、コミット、およびロールバック。
EJB 呼び出し (Create、Remove、findByPrimaryKey など)
[08/06/16 20:37:39:484 JST] 00000040 clientinfoplu > getConnection Entry
WSRdbManagedConnectionImpl@6bf26bf2
<null>
com.ibm.ws.rsadapter.spi.WSConnectionRequestInfoImpl@6b086b08
[08/06/16 20:37:39:484 JST] 00000040 clientinfoplu 3 setClientInformation(Properties
props,WSRdbManagedConnectionImpl mc, boolean explicitCall) with sqlConn
<null>
WSRdbManagedConnectionImpl@6bf26bf2
false
com.ibm.db2.jcc.c.dc@4b004b0
[08/06/16 20:37:39:484 JST] 00000040 clientinfoplu < getConnection Exit
com.ibm.ws.rsadapter.jdbc.WSJccSQLJConnection@58945894
[08/06/16 20:37:39:500 JST] 00000040 clientinfoplu > prepareStatement Entry
com.ibm.ws.rsadapter.jdbc.WSJccSQLJConnection@58945894
SELECT * FROM STAFF WHERE ID=?
TYPE FORWARD ONLY (1003)
CONCUR READ ONLY (1007)
[08/06/16 20:37:39:500 JST] 00000040 clientinfoplu < prepareStatement Exit
com.ibm.ws.rsadapter.jdbc.WSJccPreparedStatement@414c414c
36
続いて実際にトレースを取得した際のサンプルを紹介します。
上記はデータベース接続の状況を確認する際に有用な、j2cに関するトレースを取得した例になります。
このトレース結果から、接続プールの使用状況や、アイソレーションレベルや共用接続の有無といったリ
ソース参照の情報、トランザクションに関する情報などがわかりますので、WASとデータベースとの間で問
題が発生した際には、問題判別のために非常に有用です。
36
trace解析ツール － Trace and Request Analyzer
„
GUIベースのTrace解析ツール
‹
以下からフリーで入手可能
¾
„
解析
http://www.alphaworks.ibm.com/tech/tra
以下のコマンドにて起動し、ファイルを選択する
‹
ｊava –jar <HRA_ROOT>¥tra13.jar
¾
¾
¾
WebSphere Trace
HTTP Plugin Trace
WebSphere MQ JMS Trace
37
trace解析ツールにIBM Trace and Request Analyzer for WebSphere Application Serverがあります。
Trace and Request AnalyzerはJavaで書かれたtrace解析用のツールであり、Javaが動作できる環境であれ
ば、全てのプラットフォームで利用出来ます。操作はすべてGUIから実行できるのが特徴です。
Trace and Request Analyzerの起動は、以下のコマンドを実行します。 Trace and Request Analyzer起動
後、ファイルを選択して下さい。
#java –jar <TRA_ROOT>¥tra13.jar （<TRA_ROOT>はTrace and Request Analyzerをインストールしたディ
レクトリを指します）
・WebSphere Trace
・HTTP Plugin Trace
・WebSphere MQ JMS Trace
37
JDBCトレースログ
„
JDBCトレースログとは
‹
‹
„
効果的なケース
‹
‹
‹
‹
‹
„
JDBCドライバーが出力するトレース
アプリケーションとデータベース間のデータの流れを確認できる
①
②
③
④
⑤
SQLExceptionの原因を探る
ドライバーの内部エラーの原因を探る
JDBC APIの実行時刻とreturn時刻を知る
パラメーターマーカーへの設定値を確認する
分離レベルを確認する
例1：分離レベルを確認する
‹
トレースに出力されていたTransactionIsolationにより確認する（0=None = UR, 2 = CS, 4 = RS, 8 = RR）
[省略] setTransactionIsolation (2) called
„
例2：JDBC APIの実行時刻とreturn時刻を知る
calledとreturnedを抽出する
更に、ネットワークに要した時間、Driver内の処理時間を算出できる
[省略][Time:2007-05-17-14:05:51.794][省略] executeUpdate (insert into Table (sampleColumn) values (1)) called
[省略][Time:2007-05-17-14:05:51.888][省略] executeUpdate () returned
[省略][SystemMonitor:stop] core: 94.63ms | network: 48.102ms | server: 0.0ms
‹
‹
38
JDBCトレースログとは、JDBCドライバーが出力するトレースになり、ドライバーのプロパティの設定値や実行し
ているSQLステートメント・JDBC API等、アプリケーションとデーターベース間のデータの遣り取りの流れを確認
する事が出来ます。JDBCトレースログを取得する効果的なケースとしては、次が挙げられます。
① SQLExceptionの原因を探る
② ドライバーの内部エラーの原因を探る
③ JDBC APIの実行時刻とreturn時刻を知る
④ パラメーターマーカーへの設定値を確認する
⑤ 分離レベルを確認する
・分離レベルとは
実行するトランザクションが、RDBMSによってどの程度のデータ保証すべきかを定義したもの。
UR: Uncommitted Read(未コミット読み取り)
CS: Cursor Stability(カーソル固定)
RS: Read Stability(読み取り固定)
RR: Repeatable Read(反復可能読み取り)
38
JDBCトレースログの設定方法
„
設定方法
‹
管理コンソールより、データソースのカスタムプロパティに設定
‹
その他、便利なプロパティ
¾
¾
¾
‹
„
traceLevel、traceFile
traceFileAppend プロパティの指定 (デフォルト：false）
trueに設定することにより、トレースファイルが上書きされず、ログが累積される。
traceDirectory プロパティの指定 (デフォルト：未設定)
当プロパティを設定することにより、スレッド毎にトレースファイルを取得できる。
設定後、アプリケーション・サーバーの再起動を実施
トレースレベルの指定方法
複数のトレース・レベル・オプションを同時に取得可能
(例) CONNECTION_CALLSとSTATEMENT_CALLSのトレースを取得する場合
1 + 2 = 3 を指定
‹ 特定のトレース・レベル・オプション以外を取得可能
‹
39
管理コンソールの「リソース」 →「データ・ソース」 →「カスタム・プロパティ」を選択し、traceLevelとtraceFileを選
択します。
指定可能なtraceLevelについては、以下のDB2のInfoCenterをご参照下さい。全て取得する事も、複数のト
レースレベルオプションを取得する事も、特定のトレースレベルオプション以外を取得する事も出来ます。
traveFileについては、任意の出力場所を指定して下さい。traceFileAppendをtrueに設定する事により、トレース
ファイルが上書きされずログが累積させます。また、traceFileの設定では、全てのスレッドがひとつのファイルに
書き込まれますが、traceDirectoryを設定することによりスレッド毎にトレースファイルを取得する事が出来ます。
・DB2V9 - InfoCenter - 「IBM DB2 Driver for JDBC and SQLJ のプロパティー」
http://publib.boulder.ibm.com/infocenter/db2luw/v9/index.jsp?topic=/com.ibm.db2.udb.apdv.java.doc/doc/rj
vdsprp.htm
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_NONE= 0x0 (= 0)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_CONNECTION_CALLS= 0x1 (= 1)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_STATEMENT_CALLS= 0x2 (= 2)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_RESULT_SET_CALLS= 0x4 (= 4)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_DRIVER_CONFIGURATION= 0x10 (= 16)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_CONNECTS= 0x20 (= 32)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_DRDA_FLOWS= 0x40 (= 64)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_RESULT_SET_META_DATA= 0x80 (= 128)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_PARAMETER_META_DATA= 0x100 (= 256)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_DIAGNOSTICS= 0x200 (= 512)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_SQLJ= 0x400 (= 1024)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_XA_CALLS= 0x800 (= 2048)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_META_CALLS= 0x2000 (= 8192)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_DATASOURCE_CALLS= 0x4000 (=16384)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_LARGE_OBJECT_CALLS= 0x8000 (=32768)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_SYSTEM_MONITOR= 0x20000 (=131072)
com.ibm.db2.jcc.DB2BaseDataSource.TRACE_ALL= 0xFFFFFFFF (= -1)
39
クラス・ローダーの問題判別 (1/2)
クラス･ローダー・ビューワー
„
‹
‹
‹
クラス･ローダーの階層構造や各クラス･ローダー毎のクラスパス、各クラス･ロー
ダーがロードしたクラスを確認可能
管理コンソールに組み込まれたWASの基本機能
クラス･ローダーがロードしたクラスを確認するためには、事前にアプリケーショ
ン･サーバーでクラス・ローダー・ビューアー・サービスを有効にする必要あり
クラス･ローダーはディスク上のクラスファイルを
メモリー上にロードする
クラス･ローダーは対象クラス･パスごとに複数存在
メモリー
クラス･ローダーの階層構造を表示
クラス･パス等の情報のファイル保存も可能
Javaクラス･ローダー
Class Hello
WebSphere拡張クラス･ローダー
ディスク
アプリケーション･クラス･ローダー
Hello.class
WARクラス･ローダー
40
クラスローダーに関連する問題が発生した際に、非常に有用となるツール・設定を紹介させて頂きます。
クラスローダーの階層構造や各クラスローダ毎のクラスパス、特定のクラスローダーによってロードされたク
ラス等を確認して下さい。
①クラス・ローダー・ビューワー
管理コンソールより「トラブルシューティング」-「クラス・ローダー・ビューワー」を選択して下さい。
40
クラス・ローダーの問題判別 (2/2)
クラス・ローダーのトレース設定
„
‹
com.ibm.ws.classloader.*=all
[07/07/12 22:11:20:401 JST] 00000018 JarClassLoade > JarClassLoader Entry
[07/07/12 22:11:20:401 JST] 00000018 ReloadableCla > createLoader Entry
[07/07/12 22:11:20:403 JST] 00000018 CompoundClass > CompoundClassLoader this=
com.ibm.ws.classloader.CompoundClassLoader@50d250d2
Local ClassPath:Delegation Mode: PARENT_LAST Entry
trace.log
クラス・ローダーに関連するJVM引数
„
‹
-verbose：class
¾
¾
¾
管理コンソールの冗長クラス・ロードと同一の設定
クラスローダーが検索したクラスパスの階層構造を表示
特定のクラスのみ表示させる場合は、-Dibm.cl.verbose=myPackage.myClass
native_stderr.log
class load: com/ibm/ws/classloader/WsClassLoader
class load: com.ibm.ws.classloader.WsClassLoader from: file:/usr/IBM/WebSphere/AppServer1/lib/bootstrap.jar
class load: com/ibm/ws/bootstrap/ExtClassLoader
class load: com.ibm.ws.bootstrap.ExtClassLoader from: file:/usr/IBM/WebSphere/AppServer1/lib/bootstrap.jar
‹
-verbose：dynload
¾
¾
¾
クラス名とパッケージ名を表示
クラスのサイズとクラスのロードに要した時間を表示
Jarファイル名をフルパスで表示
native_stderr.log
<Loaded org/apache/tools/ant/BuildListener>
< Class size 363; ROM size 512; debug size 0>
< Read time 4 usec; Load time 23 usec; Translate time 9 usec>
41
②クラス・ローダーのトレース設定
管理コンソールより「トラブルシューティング」-「ログおよびトレース」-「ログ詳細レベルの変更」を選択して下さい。
③クラス・ローダーに関連するJVM引数
・-verbose:class
管理コンソールより、「サーバー」-「アプリケーションサーバー」-「Javaおよびプロセス管理」-「プロセス定義」「Java 仮想マシン」にて「冗長クラス・ロード」をONにして下さい。もしくは、汎用JVM引数に、-verbose:classと入
力して下さい。また、特定のクラスのみを表示させたい場合には、-Dibm.cl.verboseにて指定して下さい。
・-verbose:dynaload
管理コンソールより、「サーバー」-「アプリケーションサーバー」-「Javaおよびプロセス管理」-「プロセス定義」「Java 仮想マシン」にて「汎用JVM引数」に、-verbose:classと入力して下さい。
41
IHS / WebSphere Application Server問題判別
JVM情報収集・問題判別
‡
‡
‡
‡
‡
‡
‡
‡
ガーベッジコレクション(GC)
verbose:gc
verbose:gcの出力(GC)
verbose:gcの出力(Compaction)
verbose:gcの出力（HeapExpansion）
verbose:gcの出力（OutOfMemory）
verbose:gcの解析ツール
GCトレース
‡
‡
‡
‡
‡
‡
‡
‡
‡
‡
‡
‡
JavaDump
JavaDump出力内容の設定
JavaDumpの取得情報
JavaDumpの出力（再帰呼び出し）
JavaDumpの出力（Lock）
JavaDumpの出力（Deadlock）
JavaDumpの解析ツール
HeapDump
HeapDumpの出力
HeapDump解析ツール
JavaDump、HeapDumpに関する環境変数
その他JavaDump、HeapDumpに関する環境エントリー
42
42
ガーベッジコレクション(GC) (1/2)
„
JVMは不要になったオブジェクトをメモリ領域から開放
‹
開発者のメモリ管理を軽減、メモリリークやランタイムエラーの回避
Object Allocation
„
‹
„
heap
STEP1 Object Allocation
オブジェクトの割り当て
オブジェクト(使用中)
オブジェクト(使用されていない)
STEP2 Garbage Collection
‹
GC発生のトリガー
¾
¾
‹
Java Heap領域へのオブジェクト割り当
てが失敗した場合
System.gc()が呼び出された場合
GC処理のステップ
① Mark Phase
② Sweep Phase
③ Compaction Phase(optional)
‹
STEP1
heap
走査
GC発生中は、GC終了まで、全て
のアプリケーション・スレッドは停止
状態となる
走査
×
走査
STEP2
①
Allocation Failure
STEP2
②
heap
除
削
除
削
除
削
※ Object Allocationのためのスペースが無くなる
までSTEP1～STEP2を繰り返す
heap
STEP2
③
43
ガーベッジコレクションとは、不要になったメモリ上のオブジェクトを領域から開放するJVMの機能で、こ
れにより開発者のメモリ管理の手間を軽減し、不要なオブジェクトがメモリ上に残ることによるメモリリークや、
参照されるオブジェクトの消去によるランタイムエラーを回避することが可能となります。
ガーベッジコレクションの流れは以下のようになります。
STEP1. JVMがヒープにオブジェクトを割り当てます。
STEP2. JVMがヒープにオブジェクトを割り当てられなかったとき、また明示的にSystem.gc()を呼び出した
ときにガーベッジコレクションが実行されます。
①Mark phaseでは、使用中のオブジェクトを走査（使用中のオブジェクトのマーク付け）します。
②Sweep phaseでは、未使用のオブジェクトを除去します。
③Compaction phaseでは、ヒープの空き領域を整理をします。Compaction phaseは時間のかかる処理で
すのでJVMは可能な限り、Compactionを行いません。
基本的なフローは上記処理の繰り返しですが、それでもオブジェクトに割り当てることができないときは、
ヒープ領域の拡張が起こります。また、GCの実行中は、全てのアプリケーション・スレッドは停止状態となり
ます。(例外として、GCポリシーの選択により、Mark phaseにてアプリケーション・スレッドとGC・スレッドを同
時並行で動かすことも出来ます。）
43
ガーベッジコレクション(GC) (2/2)
-Xmx
-Xms
„
STEP3 Heap Expansion
‹
‹
GC処理後に十分な空きスペースが
無いとき、heapの拡張が行われる
heap拡張発生のトリガー
¾
¾
¾
‹
„
GCを実施しても要求されたリクエスト・オ
ブジェクト分の空き領域が確保できない
場合
GCを実施しても空き領域の割合が-Xminf
（デフォルト：0.3）値よりも小さかった場合
GC時間が全体の13%を上回った場合
heap拡張発生中は全てのアプリケー
ション・スレッドは停止状態となる
逆に必要以上の空きがあれば、
Heap Shrinkageが発生してheapが縮
小される
heap
STEP1
×
Allocation Failure
空き領域 < 30%
heap
STEP2
GC発生するが、必要なサイズの空
き領域を確保できない
heap
heap拡張
STEP3
-Xminf分の空き領域が確保できる
程度に拡張
heap
STEP1
44
ガーベッジコレクションの流れは以下のようになります。
(STEP1. JVMがヒープにオブジェクトを割り当てます。)
(STEP2. JVMがヒープにオブジェクトを割り当てられなかったとき、また明示的にSystem.gc()を呼び出した
ときにガーベッジコレクションが実行されます。)
STEP3. ガーベッジコレクションが行われた後も、ヒープに十分な空きスペースが確保できなかった場合
に、ヒープ領域を拡張して、オブジェクトを割り当てます。
具体的には、heap拡張発生のトリガーには、次の3つの場合があります。また、ヒープの拡張中は、全て
のアプリケーション・スレッドは停止状態となります。なお、ヒープ領域に必要以上の空きがある場合には
逆にHeap Shrinkageというヒープの縮小が行われます。
・GCを実施した後も、要求されたリクエスト・オブジェクト分の空き領域が確保できない場合
・GCを実施しても空き領域の割合が、-Xminf (GC後の最小の空き領域の割合。デフォルト：0.3) 値よりも
小さかった場合
・GC時間が全体の13%を上回った場合 (JVMが起動してからのトータルの時間で計算します)
44
verbose:gc
„
„
ガーベッジコレクションの実行状況を記録
native_stderr.logに出力
‹
„
汎用JVM引数に -Xverbosegclog:<path>/<filename> で変更可能
デフォルトはOFF、管理コンソールにて設定
‹
冗長ガーベッジ・コレクションにチェック or –verbose:gc
アプリケーションサーバー選択し、
「Javaおよびプロセス管理」→「プロセス定義」
→「Java仮想マシン」
冗長ガーベッジ・コレクションにチェック。
もしくは「汎用JVM引数」に-verbose:gc入力
ファイルの出力先をnative_stderr.logから変
更したい場合もここで指定する
45
verbose:gcとはガーベッジコレクションの実行状況をトレースし、native_stderr.logに出力するものです。こ
れを参照することは問題判別のみならずパフォーマンスチューニングにおいても有用です。ただし、デ
フォルトではOFFになっているためにverbose:gcを有効にするためには設定が必要です。管理コンソール
から「Java仮想マシン」設定画面に移動し、冗長ガーベッジコレクションにチェックを入れるか、汎用JVM引
数の欄に-verbose:gcと入力します。また、出力先はnative_stderr.logですが変更することも可能です。そ
の際は同じ画面の汎用JVM引数の欄に-Xverbosegclog:<path>/<filename>という形でファイル名のフルパ
スを記述します。
45
verbose:gcの出力（GC）
„
ガーベッジコレクション発生時
native_stderr.log
GCの発生回数
Allocationに
必要な容量
前回のFailure発生からの時間
<af type="tenured" id="837" timestamp="Wed May 23 16:11:47 2007" intervalms="3490.591">
<minimum requested_bytes="168" />
<time exclusiveaccessms="0.100" />
<tenured freebytes="889032" totalbytes="134217728" percent="0" >
<soa freebytes="0" totalbytes="131533824" percent="0" />
<loa freebytes="889032" totalbytes="2683904" percent="33" />
</tenured>
<gc type="global" id="837" totalid="837" intervalms="3490.817">
<refs_cleared soft="0" threshold="32" weak="1" phantom="0" />
<finalization objectsqueued="1" />
<timesms mark="61.120" sweep="3.331" compact="0.000" total="64.569" />
<tenured freebytes="87957456" totalbytes="134217728" percent="65" >
<soa freebytes="87068424" totalbytes="131533824" percent="66" />
<loa freebytes="889032" totalbytes="2683904" percent="33" />
</tenured>
</gc>
<tenured freebytes="87956616" totalbytes="134217728" percent="65" >
<soa freebytes="87067584" totalbytes="131533824" percent="66" />
<loa freebytes="889032" totalbytes="2683904" percent="33" />
</tenured>
<time totalms="64.884" />
</af>
このAllocationFailureにかかった時間
GC後の容量
46
以上はガーベッジコレクションが発生したときのverbose:gcの出力例です。ガーベッジコレクションはJVM
がオブジェクトをヒープに割り当てることができなかったときに発生します。この状態をAllocation
Failure(AF)と言います。また、Tenuredとはold領域の事であり、この出力例では記述されておりませんが、
nurseryはnew領域を示しております。
1行目：afがAllocation Failureの発生、idの数字がJVM起動後にAFが発生した回数を示しています。
Intervalms=3490.591が前回のAllocationFailureからの経過時間を示しています。上記の例では、3490ms
後に今回(837回目)のAllocation Failureが発生したことを示しています。
2行目：requested_bytes=168byteがAllocationに必要な容量になります。
11行目：このGCのmarkフェーズ（オブジェクトのマーキング）、sweepフェーズ（不要オブジェクトの開放）、
compact（空き領域の整理）の所要時間およびGC全体の所要時間を示しています。上記の例では
compactの作業は行っていません。
17行目：GC後の容量を示しています。
21行目：今回のAllocation Failureに要した合計の時間が記録されます。
46
verbose:gcの出力（Compaction）
„
Compaction発生時
移動したオブジェクトの数とサイズ、Compactionの理由
native_stderr.log
<af type="tenured" id="151" timestamp="Wed May 23 14:56:59 2007" intervalms="181.001">
<minimum requested_bytes="65536" />
<time exclusiveaccessms="0.117" />
<tenured freebytes="63485528" totalbytes="134217728" percent="47" >
<soa freebytes="63485528" totalbytes="134217728" percent="47" />
<loa freebytes="0" totalbytes="0" percent="0" />
</tenured>
<gc type="global" id="151" totalid="151" intervalms="181.206">
<compaction movecount="689474" movebytes="39607992" reason="compact to meet allocation" />
<refs_cleared soft="0" threshold="32" weak="1" phantom="0" />
<finalization objectsqueued="0" />
<timesms mark="62.511" sweep="4.676" compact="167.126" total="234.445" />
<tenured freebytes="94606872" totalbytes="134217728" percent="70" >
<soa freebytes="93264920" totalbytes="132875776" percent="70" />
<loa freebytes="1341952" totalbytes="1341952" percent="100" />
</tenured>
</gc>
<tenured freebytes="94541336" totalbytes="134217728" percent="70" >
<soa freebytes="93199384" totalbytes="132875776" percent="70" />
<loa freebytes="1341952" totalbytes="1341952" percent="100" />
</tenured>
<time totalms="234.768" />
</af>
47
GC後の容量
ガーベッジコレクションを実行しても開き領域が確保できない場合、Compactionが発生します。
Compactionはメモリ上に確保されたオブジェクトの位置を動かし参照を変更しなければいけないため、
markフェーズやsweepフェーズよりも多くの時間を要し、その間アプリケーションは停止させなくてはいけな
いため、JVMはできる限りCompactionは行いません。
(GCの実行毎にcompactionが実行されるわけではございません。）
上記はCompactionが発生したときのverbose:gcの出力例になります。Compactionによって移動したオブ
ジェクトの数とサイズ、Compactionの理由、増加された容量を示しています。以上の例では、 689474個、
計39607992 byteのオブジェクトを移動させた事を示しています。
また、soaとはSmall Object area、loaとはLarge Object areaの略になります。デフォルトでは、64KB以上
のオブジェクトが割り当てられた場合、もしくはsoaにオブジェクトが割り当てられなかった場合にloaにオブ
ジェクトが割り当てられます。loaでは、複数スレッドにより同時にオブジェクトを割り当てる事が出来ないの
が、注意点になります。
47
verbose:gcの出力（HeapExpansion）
„
HeapExpansion発生時
拡張できた容量と最終的な容量、理由
native_stderr.log
<af type="tenured" id="880" timestamp="Wed May 23 16:15:49 2007" intervalms="15.194">
<minimum requested_bytes="13571688" />
<time exclusiveaccessms="1.106" />
<tenured freebytes="18640136" totalbytes="134217728" percent="13" >
<soa freebytes="11929352" totalbytes="127506944" percent="9" />
<loa freebytes="6710784" totalbytes="6710784" percent="100" />
</tenured>
<gc type="global" id="880" totalid="880" intervalms="15.413">
<expansion type="tenured" amount="6989824" newsize="141207552" timetaken="0.635"
reason="insufficient free space following gc" />
<refs_cleared soft="0" threshold="32" weak="0" phantom="0" />
<finalization objectsqueued="0" />
<timesms mark="174.618" sweep="1.148" compact="0.000" total="176.527" />
<tenured freebytes="55934424" totalbytes="141207552" percent="39" >
<soa freebytes="47462360" totalbytes="132735488" percent="35" />
<loa freebytes="8472064" totalbytes="8472064" percent="100" />
</tenured>
</gc>
<tenured freebytes="42362736" totalbytes="141207552" percent="30" >
<soa freebytes="33890672" totalbytes="132735488" percent="25" />
<loa freebytes="8472064" totalbytes="8472064" percent="100" />
</tenured>
<time totalms="177.862" />
</af>
48
さらにCompactionでも充分な容量が確保できない場合、ヒープ領域の拡張が行われます。ヒープの拡
張が行われるのは、容量が確保できない場合以外にも、空き領域が最小空き領域として指定した値（デ
フォルト0.3）よりも少なくなった場合、GCの総実行時間がシステム起動からの経過時間の13％を越えた場
合に発生します。
上記は、HeapExpansionが発生したときのverbose:gcの出力例です。GC後に十分な領域を確保すること
が出来ず、ヒープの拡張を試みています。最終的に6989824 byteの領域が拡張され、全体として領域が
141207552byteになったことを示しています。また、JDK5.0より、HeapExpansionの理由が記録されるように
なりました。(例：reason="insufficient free space following gc" )
48
verbose:gcの出力（OutOfMemory）
„
OutOfMemory発生時
SnapDump、HeapDump、JavaDump
が出力されたことを示す
native_stderr.log
JVMDUMP006I Processing Dump Event "uncaught", detail "java/lang/OutOfMemoryError" - Please Wait.
JVMDUMP013I Processed Dump Event "uncaught", detail "java/lang/OutOfMemoryError".
JVMDUMP007I JVM Requesting Snap Dump using
'/usr/IBM/WebSphere/AppServer1/profiles/AppSrv01/Snap0003.20070523.161857.536664.trc'
JVMDUMP010I Snap Dump written to
/usr/IBM/WebSphere/AppServer1/profiles/AppSrv01/Snap0003.20070523.161857.536664.trc
JVMDUMP007I JVM Requesting Heap Dump using
'/usr/IBM/WebSphere/AppServer1/profiles/AppSrv01/heapdump.20070523.161857.536664.phd'
JVMDUMP010I Heap Dump written to
/usr/IBM/WebSphere/AppServer1/profiles/AppSrv01/heapdump.20070523.161857.536664.phd
JVMDUMP007I JVM Requesting Java Dump using
'/usr/IBM/WebSphere/AppServer1/profiles/AppSrv01/javacore.20070523.161857.536664.txt'
UTE436: Unable to get formatString for mm .14045 component not registered
JVMDUMP010I Java Dump written to
/usr/IBM/WebSphere/AppServer1/profiles/AppSrv01/javacore.20070523.161857.536664.txt
JVMDUMP013I Processed Dump Event "uncaught", detail "java/lang/OutOfMemoryError".
„
verbose:gcからメモリの圧迫の様子がわかる
‹
メモリが圧迫されているときの特徴
¾
¾
GCの発生間隔が短い
1回のGCの開放量が少ない
49
それでも空き領域が確保できないと、やがてメモリ領域を使い果たし、OutOfMemoryとなり、JVMがダウ
ンしてしまいます。上記はOutOfMemoryが発生したときのverbose:gcの出力例です。JVMがSnapDumpと
HeapDump、JavaDumpの出力を要求し、指定された位置に出力されたことがわかります。なお
OutOfMemory発生時は、SnapDumpもHeapDump、JavaDumpも自動で出力されるようにデフォルトで設定
されています。
また、verbose:gcの出力結果より、メモリリークの有無を確かめることが可能です。メモリが圧迫されると、
GCの発生間隔が短くなる、1回のGCの開放量が小さくなる、といった現象が見られます。verbose:gcを取
得するとGCの発生間隔やメモリの開放量が確認できますので、メモリに問題があると思われる場合に
verbose:gcは非常に有用です。
49
verbose:gc解析ツール － PMAT
„
„
GUIベースのverbose:gc解析ツール
以下からフリーで入手可能
‹
„
http://www.alphaworks.ibm.com/tech/pmat
以下のコマンドにて起動し、native_stderr.logファイルを選
択する
‹
„
解析
ｊava –jar <PMAT_ROOT>¥ga16.jar
ISAを導入していれば、ISAプラグインとしてツールから使
用可能（事前にプラグイン追加しておく必要がある）
50
verbose:gc解析ツールの一つにPMAT （IBM Pattern Modeling and Analysis Tool for java Garbage
Collector）があります。PMATはJavaで書かれたverbose:gc解析用のツールであり、操作はすべてGUIから
実行できるのが特徴です。
PMATは単体で使用する場合、起動は以下のコマンドを実行します。PMAT起動後、native_stderr.log
ファイルを選択して下さい。(<PMAT_ROOT>はPMATをインストールしたディレクトリを指します。)
#java –jar <PMAT_ROOT>¥ga16.jar
また、PMATはISAのプラグインとして使用することも可能です。この場合は、事前にISAにPMATをプラグ
イン追加しておくことで、ISAのツールから起動することができます。
PMATについての詳細は下記URLをご参照ください。
- IBM Pattern Modeling and Analysis Tool for Java Garbage Collector
http://www.alphaworks.ibm.com/tech/pmat
50
PMATを用いたverbose:gc解析
解析
統計情報
推奨チューニング
グラフ表示も可能
51
PMATを起動してnative_stderr.logを読み込ませると上記のような概要画面が表示されます。ここではGC
やAllocation Falureの発生回数などの概要に加え、Recommendationsには現状で推奨されるチューニン
グ内容も表示されます。また、「Graph View」を選択することにより、ヒープの使用状況やGCの発生状況な
ど、確認したい項目をグラフ化することができます。
51
GCトレース
„
„
GCトレースを利用することで、GCの挙動を更に詳細に把握
できる
出力される量が膨大で、出力内容の絞込みが必要
‹
設定方法
¾
JVM引数に以下のオプションを指定する
-Xtgc:<オプション名>
例：-Xtgc:backtrace,compaction
‹
ログの出力先
¾
¾
デフォルト：各AppServerのnative_stderr.log
出力場所は変更可能
52
GCトレース(-Xtgc：<オプション名>)とは、verbose:gcよりも更に詳細にガーベッジコレクションの実行状況をト
レースし、native_stderr.logに出力するものです。これを参照することは問題判別のみならずパフォーマンス
チューニングにおいても有用です。ただし、膨大な量が出力されるので、出力内容の絞込みが重要です。Xtgcのオプションについては、次ページを参照して下さい。
52
GCトレースのオプション
オプション
内容
サンプル出力
backtrace
GCのトリガーとなったスレッド情報
"main" (0x0003691C)
compaction
compactionに関連する情報
Compact(3): reason = 7 (forced compaction)
Compact(3): Thread 0, setup stage: 8 ms.
Compact(3): Thread 0, move stage: handled 42842 objects in
13 ms, bytes moved 2258028.
concurrent
Concurrent Mark情報
<CONCURRENT GC BK thread 0x0002645F (started after
GC(5)) traced 25435>
dump
Sweepフェーズ情報
<GC(4) 13F9FE44 freelen=x000002C4 -- x00000038
spec/jbb/Stock>
excessiveGC
GCのサイクルの統計情報
excessiveGC:
gcid="10" intimems="122.269" outtimems="1.721"
percent="98.61" averagepercent="37.89"
freelist
前回のGCからのfreelistとallocation
の統計情報
<Alloc TLH: count 3588, size 3107, discard 31>
< non-TLH: count 6219, search 0, size 183, discard 0>
parallel
Parallel Mart、Parallel Sweep情報
Mark: busy stall tail acquire release
0:
30 30 0 0 3
1:
53 7 0 91 94
references
GC中の活動情報
enqueuing ref sun/misc/SoftCache$ValueCell@0x1564b5ac >0x1564b4c8
scavenger
Scavenger GCの情報
{SCAV: | class | instances of age 0-14 in semi-space
terse
GC前後のheapの内容をdump
*DH(1)* 230AD778 a x0000001C java/lang/String
*DH(1)* 230AD794 a x00000048 char[]
53
上記表は、GCトレースのオプションになります。JVMの各サブコンポーネントが出力可能なトレースは、取得す
る内容に応じて複数のオプションに分かれています。この中からひとつのオプションを選択してトレースを出力
するだけでも非常に大きなサイズのログが出力されるため、必要なオプションのみを必要な時にだけ取得するよ
うに心がける必要があります。
53
JavaDump (1/3)
„
Javaプロセスが異常終了したとき、または明示的に命令を
送った時に出力されるテキストベースの診断情報
‹
Javacore、Javaスレッドのダンプファイル、スレッドダンプとも呼ばれている。
‹
遮断直前のJVMの状態についての情報を出力
取得できる情報は稼動プラットフォームに依存
‹
¾
ダンプから取得できる情報例：
z
z
z
z
z
z
OS関連情報
環境変数
スレッド情報
native stack
lock情報
memory情報
54
JavaDumpは、ある時点におけるJVMのコンポーネントの状態を示すダンプ情報になります。JavaDumpは
Javacoreとも呼ばれ、WebSphere Application ServerのInfoCenterではJavaスレッドのダンプファイル、ス
レッドダンプとも表記されるが、どれも同一のダンプを示しています。JavaDumpはJVMプロセスがクラッシュ
等で遮断された場合やユーザーが外部から明示的に出力命令を送ることで出力されます。JVMプロセス
が遮断された場合は、OSが命令を送って出力されます。デフォルトではJavaDumpの設定はONであり、
JVMプロセスがクラッシュしたり、JVMが明示的な出力指令を受け取ると自動的にJavaDumpを生成します。
JavaDumpは、JVMの異常終了やヒープが使い果たされたときに生成されます。命令が送られると、その
瞬間にJVMが持っている情報をテキストファイルとして出力します。JavaDumpの出力先はJVMの作業ディ
レクトリ（デフォルトは環境変数USER_INSTALL_ROOT）になり、ファイル名はOSによって上記のように異な
ります。CPU_TIMEは1970年1月1日からの経過時間を秒単位で示したものになります。また、出力先ディ
レクトリはプロセス定義の環境エントリーIBM_JAVACOREDIRの設定により変更することも可能です。
54
JavaDump (2/3)
„
JavaDumpの生成条件
‹
JVMがダウン →デフォルト設定では、ダウンした際に自動的に出力。
¾
¾
JVMが異常終了した場合
OutOfMemoryエラーが発生した場合
z
‹
環境変数IBM_JAVADUMP_OUTOFMEMORY=FALSEにより出力しないことも可能
ユーザーがJavaプロセスに対して明示的に命令を発行して生成
¾
ユーザーがOSのコンソールから明示的に命令を送信して取得
z
z
¾
kill -3 <PID>
kill –QUIT <process id>
WASの管理ツール（wsadmin）により取得
wsadmin>set jvm [$AdminControl completeObjectName type=JVM,process=server01,*]
wsadmin>$AdminControl invoke $jvm dumpThreads
wsadmin>jvm = AdminControl.completeObjectName('type=JVM,process=server01,*')
wsadmin>AdminControl.invoke(jvm, 'dumpThreads')
¾
アプリケーションからstatic com.ibm.jvm.Dump.JavaDump()を実行
z
static com.ibm.jvm.Dump.JavaDump()
55
JavaDumpの生成条件をJVMプロセスのダウンのケースと明示的に出力させるケースとに分けてご説明さ
せて頂きます。
JVMプロセスがダウンした場合、デフォルト設定では自動的にJavaDumpが出力されます。また、ユーザ
が意図的にJavaDumpを出力させることも可能です。AIXやLinuxのkillコマンドを用いて取得したいプロセ
スIDにkill –3 、kill –QUITのコマンドを送信することにより生成する方法、WASのwsadminを使用して生成
する方法、アプリケーション内でstaticメソッドcom.ibm.jvm.Dump.JavaDump()を呼び出すことで生成する方
法があります。
WASに関連する問題が発生し、ログやトレースの解析では判明できない場合は、WASを再起動される
前にJavaDumpを出力させておくと、今後の解析に役立つ事がございます。
55
JavaDump (3/3)
„
JavaDump取得のための設定
‹
‹
デフォルトでONのため特に設定は必要ない。
OFFに設定することも可能
¾
„
JavaDumpの出力先
‹
以下の存在の有無と書き込み属性を上の候補からチェックし、書き込み可能
な場所に出力
¾
¾
¾
¾
¾
„
環境エントリー： DISABLE_JAVADUMP=trueと指定することでOffの設定となる
環境エントリー： IBM_JAVACOREDIR の場所
ＪＶＭプロセスのカレント・ワーキング・ディレクトリ（デフォルトは USER_INSTALL_ROOT ）
（setされている場合）環境変数： TMPDIR の場所
/tmpディレクトリ、または(Windows環境のみ)環境変数： TEMP の場所
(Windows環境のみ)上記のどの場所も不可能だった場合はSTDERRへ出力
JavaDumpファイル名
‹
‹
[Windows & Linux]
[AIX]
javacore.YYYYMMDD.HHMMSS.PID.txt
javacorePID.TIME.txt
56
JavaDumpは、以下の環境エントリーの設定、または実行時のJVM引数の設定によりOFFにすることも可
能ですが、特別な理由がない限りOFFしないで下さい。
環境エントリー：DISABLE_JAVADUMP=true
JVM引数：-Xdisablejavadump
また、出力先ディレクトリは環境エントリーIBM_JAVACOREDIRの設定により変更することも可能です。
JavaDumpのファイル名は以下になります。
(Windows & Linux)javacore.YYYYMMDD.HHMMSS.PID.txt
(AIX)javacorePID.TIME.txt
56
JavaDumpの取得情報
„
いくつかのサブコンポーネントに分類
‹
‹
‹
‹
‹
‹
‹
TIＴLE subcomponent
GPINFO subcomponent
ENVINFO subcomponent
MEMINFO subcomponent
LOCKS subcomponent
THREADS subcomponent
CLASSES subcomponent
：OS発行のシグナル、日付、ファイル名の情報
：OSレベル、CPUの情報
：Java・VM・JITのバージョン、実行時の引数の情報
：メモリーに関する情報
：LOCKに関する情報
：存在しているスレッドとスタックトレースのリスト
：クラスローダーに関する情報
57
JavaDumpの出力はいくつかのサブコンポーネントに分類されています。そのサブコンポーネントの説明
は上記の通りです。このうち問題判別に特に有効なのはLOCKS(Lockに関する情報)とTHREADS(スレッド
のスタックトレース)のサブコンポーネントになります。次ページ以降にて出力例をご紹介させて頂きます。
57
JavaDumpの出力（再帰呼び出し）
„
THREADS subcomponentに注目
‹
‹
存在するスレッドとスタックトレースの情報
スタックトレースより、同じメソッドが何度も呼ばれていることがわかる
javacoreYYYYMMDD.HHMMDD.<process id>.txt
0SECTION
THREADS subcomponent dump routine
NULL
=================================
1XMCURTHDINFO Current Thread Details
NULL
---------------------3XMTHREADINFO
"Signal dispatcher" (TID:0x101EB960, sys_thread_t:0x213638A0, state:R, native ID:0x960)
prio=5 NULL
1XMTHDINFO All Thread Details
出力時点での全スレッドの状態を記録
NULL
-----------------NULL
2XMFULLTHDDUMP Full thread dump J9SE VM (J2RE 5.0 IBM J9 2.3 AIX ppc-32 build
20070322_12058_bHdSMR, native threads):
3XMTHREADINFO
"WebContainer : 1" (TID:0x1034AD60, sys_thread_t:0x25847B48, state:CW, native
ID:0x1490) prio=5
Thread.sleepを呼び出した状態
4XESTACKTRACE
at java.lang.Thread.sleep(Native Method)
4XESTACKTRACE
at com.ise.waspd.jvm.RecursiveCall.doRecursiveCall(RecursiveCall.java:17)
4XESTACKTRACE
at com.ise.waspd.jvm.RecursiveCall.doRecursiveCall(RecursiveCall.java:18)
4XESTACKTRACE
at com.ise.waspd.jvm.RecursiveCall.doRecursiveCall(RecursiveCall.java:18)
4XESTACKTRACE
at com.ise.waspd.jvm.RecursiveCall.doRecursiveCall(RecursiveCall.java:18)
RecursiveCall.javaの17行目
4XESTACKTRACE
at com.ise.waspd.jvm.RecursiveCall.doRecursiveCall(RecursiveCall.java:18)
doRecursiveCallメソッドがsleep
4XESTACKTRACE
at RecursiveCall.javaの18行目
com.ise.waspd.jvm.RecursiveCall.doRecursiveCall(RecursiveCall.java:18)
メソッドを呼び出した
4XESTACKTRACE
at doRecursiveCallメソッドが
com.ise.waspd.jvm.RecursiveCall.doRecursiveCall(RecursiveCall.java:18)
58
4XESTACKTRACE
at 再度doRecurisiveCallメソッドを呼んでいる
com.ise.waspd.jvm.RecursiveCall.doRecursiveCall(RecursiveCall.java:18)
・・・・・・
（この状態が無限に続き、ループに）
上記例は、同一メソッドによる再帰メソッドが無限に起こり続けている際のJavaDumpの出力例です。
THREAD subcomponent dump routineを参照します。存在するスレッドとスタックトレースの情報が記録さ
れていますので、スレッドのスタックトレースを確認すると、WebContainer:1というスレッドがThread.sleepメ
ソッドを呼び出した状態で停止しており、さらにそのsleepメソッドは
com.ise.waspd.jvm.RecursiveCall.doReCursiveCallメソッドから呼ばれたことがわかります。さらにその後に
同じメソッドが何度も繰り返し呼ばれていることから、このプログラムが再帰処理を続けていることがわかり
ます。
58
JavaDumpの出力（Lock）
„
LOCKS subcomponentに注目
‹
‹
LOCKに関する情報
Monitor Pool Dump欄により、どのスレッドのオブジェクトがどのスレッドのオ
ブジェクトによってLockされているかが判断できる
javacoreYYYYMMDD.HHMMDD.<process id>.txt
0SECTION
LOCKS subcomponent dump routine
オブジェクトのLockに関する情報を記録
NULL ============================
・・・・・・・
1LKMONPOOLDUMP Monitor Pool Dump (flat & inflated object-monitors):
2LKMONINUSE
sys_mon_t:0x0028AE90 infl_mon_t: 0x0028A898:
3LKMONOBJECT com.ibm.ws.util.BoundedBuffer@124E1798/124E17A0: <unowned>
3LKNOTIFYQ Waiting to be notified:
“Thread-0”はjava.lang.Object@3030DF38/3030DF40のロック開
3LKWAITNOTIFY "WebContainer : 0" (0x250BA170)
放待ち状態にあり、そのObjectが0x07によってロックされている。
2LKMONINUSE sys_mon_t:0x3020DAE8 infl_mon_t: 0x00000000:
3LKMONOBJECT java.lang.Object@3030DF38/3030DF40: Flat locked by thread ident 0x07, entry count 1
3LKNOTIFYQ Waiting to be notified:
3LKWAITNOTIFY "Thread-0" (0x353366F0)
・・・・・・・
ID 0x07は”Thread-1”を示している
1LKFLATMONDUMP Thread identifiers (as used in flat monitors):
2LKFLATMON ident 0x07 "Thread-1" (0x35336E90) ee 0x35336C64
2LKFLATMON ident 0x06 "Thread-0" (0x353366F0) ee 0x353364C4
・・・・・・・
59
上記例は、あるスレッドのオブジェクトが他のオブジェクトにLockされている際のJavaDumpの出力例です。
LOCKS subcomponent dump routineを参照します。ここにはオブジェクトのLockに関する情報が記録さ
れています。Monitor Pool Dump欄から各スレッドが要求しているオブジェクトと、そのオブジェクトがどのス
レッドによって所有されているのかがわかります。どのスレッドによっても所有されていない場合は
<unowned>と記載されますが、所有されている場合はそのスレッドのIDが記載されます。上記例ではスレッ
ドID 0x07によってロックされていることがわかります。
さらにThread identifierの欄を見ると、スレッドIDとスレッド名との紐付けを読み取れます。上記例ではID
0x07が「Thread-1」と結び付けられていますので、Thread-0のオブジェクト
java.lang.Object@3030DF38/3030DF40がThread-1のオブジェクトによってロック開放待ちになっているこ
とがわかります。
59
JavaDumpの出力（Deadlock）
„
LOCKS subcomponentに注目
‹
‹
LOCKに関する情報
「Deadlock detected!」の内容から、デッドロックの発生箇所が特定できる
javacoreYYYYMMDD.HHMMDD.<process id>.txt
1LKDEADLOCK Deadlock detected !!!
Deadlockに関する情報を記録
NULL
--------------------NULL
2LKDEADLOCKTHR Thread "RightToLeft" (0x886C718)
3LKDEADLOCKWTR is waiting for:
RightToLeftはLeftToRightのス
4LKDEADLOCKMON
sys_mon_t:0x08A49B08 infl_mon_t: 0x0898B128: レッドの保持しているオブジェクト
4LKDEADLOCKOBJ
のロック開放待ち
com.ibm.jp.ws.diagnose.SynchronizedObject@13DE5770/13DE5778:
3LKDEADLOCKOWN which is owned by:
2LKDEADLOCKTHR Thread "LeftToRight" (0x891C458)
3LKDEADLOCKWTR which is waiting for:
4LKDEADLOCKMON
sys_mon_t:0x063E9BE0 infl_mon_t: 0x00000000:
LeftToRightはRightToLeftのス
4LKDEADLOCKOBJ
レッドの保持しているオブジェクト
com.ibm.jp.ws.diagnose.SynchronizedObject@13DE5728/13DE5730:
のロック開放待ち
3LKDEADLOCKOWN which is owned by:
2LKDEADLOCKTHR Thread "RightToLeft" (0x886C718)
60
上記例はデッドロックが発生し、DeadLock detectedが検出された際のJavaDumpの出力例です。
片方のオブジェクトがもう一方のオブジェクトのロック開放を待ち、さらにもう一方のオブジェクトが片方の
オブジェクトのロック開放を待っている状態がデッドロックです。この状態になると、どちらのスレッドも先に
進めず、処理がそこで止まってしまいます。この際にJavaDumpを取得すると、LOCKS subcomponentに
「DeadLock detected!」の記述が記録されます。
上でスレッド”RightToLeft“がオブジェクト
com.ibm.jp.ws.diagnose.SynchronizedObject@13DE5770/13DE5778を要求していますが、それがスレッ
ド”LeftToRight“によって保持されていることを示しています。さらに下でスレッド”LeftToRight“がオブジェ
クトcom.ibm.jp.ws.diagnose. SynchronizedObject@13DE5728/13DE5730を要求しているが、それがスレッ
ド”RightToLeft“によって保持されていることを示しています。これより、上記例で
は”LeftToRight“と”RightToLeft“がデッドロックの状態に陥っていることがわかります。
このようにして、JavaDumpは現在のスレッドやオブジェクトの状況を知ることができるため、ハングやスロー
ダウン時の原因箇所特定に非常に有用です。
60
JavaDump解析ツール － IBM Thread and Monitor
Dump Analyzer for Java Technology
„
„
GUIベースのJavaDump解析ツール
以下からフリーで入手可能
‹
„
解析
http://www.alphaworks.ibm.com/tech/jca
以下のコマンドにて起動し、javacoreファイルを選択する
‹
ｊava –jar <JCA_ROOT>¥jca17.jar
61
JavaDump解析ツールの一つにIBM Thread and Monitor Dump Analyzer for Java Technologyがあります。
IBM Thread and Monitor Dump Analyzer for Java TechnologyはJavaで書かれたJavaDump解析用のツー
ルであり、操作はすべてGUIから実行できるのが特徴です。
IBM Thread and Monitor Dump Analyzer for Java Technologyの起動は以下のコマンドを実行します。
IBM Thread and Monitor Dump Analyzer for Java Technology起動後、javacoreファイルを選択して下さい。
(<JCA_ROOT>はIBM Thread and Monitor Dump Analyzer for Java Technologyをインストールしたディレ
クトリを指します。)
#java –jar <JCA_ROOT>¥jca17.jar
IBM Thread and Monitor Dump Analyzer for Java Technologyについての詳細は下記URLをご参照くだ
さい。
- IBM Thread and Monitor Dump Analyzer for Java Technology
http://www.alphaworks.ibm.com/tech/jca
61
IBM Thread and Monitor Dump Analyzer for Java
Technologyを用いたJavaDump解析
解析
Thread Detail画面
代表的なスレッドの状態は以下のとおり
・Runnable： 処理を受付可能な状態
・Blocked： 別スレッドが保持しているロッ
クの解放待ち状態
・Waiting on condition： sleep()、wait()メ
ソッドやI/O、join()メソッドによる待ち状態
Monitor Detail画面
リソースのロック解放待ちスレッドの
一覧を表示
62
JVM上のスレッドの状況を確認するには[Analysis] – [Thread Detail]で起動するツールを使用します。こ
の画面ではRunnable、Blockedなどのスレッドの状態を見やすい形で確認することができます。左画面で
スレッドを選択するとそのスレッドのスタックトレースが確認できます。
複数スレッドから要求されているリソースのロック状況を確認するには[Analysis] – [Monitor Detail]で起
動するツールを使用します。上記の赤線内の例ではWebContainer:16が保持しているリソースの解放を6
つのスレッドが待っている状態が確認できます。
62
HeapDump (1/2)
„
JVMがHeapを使い切ったときに生成
„
Heap上の全てのオブジェクトの情報を出力
„
wsadminを用いた手動によるHeapDumpの作成
wsadmin> set obj [$AdminControl queryNames WebSphere:type=JVM,process=server01,*]
wsadmin> $AdminControl invoke $obj generateHeapDump
wsadmin> jvm = AdminControl.queryNames(‘WebSphere:type=JVM,process=server01,*’)
wsadmin> AdminControl.invoke(jvm,’generateHeapDump’)
63
HeapDumpはJVMがヒープを使い果たしたときやクラッシュしたとき、またはユーザーが明示的に命令を
送ったときに生成されます。命令が送られると、その瞬間のヒープ上の全てのオブジェクト情報を出力しま
す。
HeapDumpは、ヒープを使い切ったときにはJavaDumpと同時に出力されます。またV6.0.2から新たに、
wsadminを用いて手動でHeapDumpのみを出力させることも可能になりました。
63
HeapDump (2/2)
„
ヒープ内に割り当てられているすべての到達可能（live）オブ
ジェクトの状態を記録
‹
ある時点のヒープの状態を示すスナップショット
¾
‹
HeapDumpによって分かること
¾
¾
„
アプリケーションのオブジェクトによるヒープの利用状況
ヒープの状態（分断化の度合い、オブジェクトのロード状況）
HeapDumpの出力先
‹
以下に示す場所について存在の有無と書き込み属性を上の候補からチェックし、書
き込み可能な場所に出力
¾
¾
¾
¾
„
HeapDump出力前に必ずGCが起動し、到達不可能な“ゴミ”オブジェクトがあまり残らないような形でデータ
を出力
環境エントリー： IBM_HEAPDUMPDIR の場所
ＪＶＭプロセスのカレント・ワーキング・ディレクトリ（デフォルトは USER_INSTALL_ROOT ）
（setされている場合）環境変数： TMPDIR の場所
/tmpディレクトリ、(Windows環境 x:¥tmp ここでxはカレントドライブ名)
HeapDumpファイル名
‹
‹
Java SDK 1.4.2 SR1より出力フォーマットがphd形式に変更
SR1以降の環境でテキストファイルで出力するには
¾
環境エントリー： IBM_JAVA_HEAPDUMP_TEXT=true の設定が必要
Windows
heapdump.YYYYMMDD.HHMMSS.PID.phd
Linux & AIX
heapdumpPID.TIME.phd
64
JavaDumpがJVMのコンポーネントの状態についての情報を取得するためのデータであるのに対して、
HeapDumpではJVMの仮想ストレージの状態、つまりヒープの中でどのようなオブジェクトがどのように格納
されているか、及びどこに空き領域が存在するかなどの状態を表す情報を取得することが出来ます。
JavaDumpにおいてSTコンポーネントについてのダンプを出力することが可能ですが、これはOSから割り
当てているメモリ領域の情報や、GCの方法などのSTコンポーネントそのものの状態についてのダンプ情
報であるため、HeapDumpの内容とは異なります。
HeapDumpの出力先はJVMの作業ディレクトリ(デフォルトは環境変数USER_INSTALL_ROOT)になり、
ファイル名はOSによって上記のように異なります。また、出力先ディレクトリは環境エントリー
IBM_HEAPDUMPDIRの設定により変更することが可能です。
WASV6からHeapDumpの出力ファイルはテキストファイルではなく、PHDファイルになりました。これをテ
キストファイルで出力させるには、環境エントリーIBM_JAVA_HEAPDUMP_TEXTの設定が必要です。テキ
スト形式でHeapDumpを出力するとヒープサイズとほぼ同じ大きさの出力になり、システムのディスクI/Oに
大きな負荷がかかるため、V1.4.2 SR1からはデフォルトの出力フォーマットがテキストからphd形式に変更
され、一回の出力量がテキストのおよそ1/4程度まで小さくなっています。
64
HeapDumpの出力
„
„
オブジェクトのアドレス、サイズ、タイプと参照されている
オブジェクトアドレスをリストで表示
HeapDumpの解析には解析ツールが必要
‹
‹
‹
HeapAnalyzer
MDD4J
Heaproots
heapdump.YYYYMMDD.HHMMDD.<process id>.txt
// Version: J2RE 5.0 IBM J9 2.3 AIX ppc-32 build 20070322_12058
0x101EBCB8 [56] array of java/lang/Object
0x11cffd38 0x10342e98 0x103925b0 0x102a24f8 0x10268468
・・・・・・
// Breakdown - Classes: 9473, Objects: 207102, ObjectArrays: 37404, PrimitiveArrays:
59884
// EOF: Total 'Objects',Refs(null) : 313863,713853(185700)
1行目：オブジェクトのアドレス、サイズ、タイプ
2行目：参照されている他のオブジェクトのアドレス
65
HeapDumpは、ヒープの構造をシンプルに表現した形式になっています。上記例のように、先頭にJRE情
報があり、オブジェクトの構造を1行目にオブジェクトのアドレス、サイズ、タイプ。2行目に参照されている
オブジェクトのアドレス、という形で羅列し、最後にファイルのサマリーが載っている形式になっています。
しかし、このファイルだけを見て解析を行うのは非常に困難ですので、通常はHeapDumpの解析用ツール
を用いて解析を行います。
HeapDumpをメモリリークやOutOfMemoryの発生時に取得し解析ツールにて解析することで、どのオブ
ジェクトがヒープを占領しているのかを見分けることが出来ます。
65
HeapDump解析ツール － HeapAnalyzer
„
„
GUIベースのHeapDump解析ツール
以下からフリーで入手可能
‹
„
解析
http://www.alphaworks.ibm.com/tech/heapanalyzer
以下のコマンドにて起動し、HeapDumpファイルを選択する
‹
ｊava –jar <HA_ROOT>¥ha150.jar
66
HeapDump解析ツールの一つにHeapAnalyzerがあります。HeapAnalyzerはJavaで書かれたHeapDump
解析用のツールであり、Javaが動作できる環境であれば、全てのプラットフォームで利用出来ます。操作
はすべてGUIから実行できるのが特徴です。
HeapAnalyzerの起動は、以下のコマンドを実行します。HeapAnalyzer起動後、heapdumpファイルを選択
して下さい。(<HA_ROOT>はHeapAnalyzerをインストールしたディレクトリを指します。)
#java –jar <HA_ROOT>¥ha150.jar
66
HeapAnalyzerを用いたHeapDump解析 (1/2)
„
状況に応じて、以下の項目を選択し、表示する
‹
‹
‹
‹
‹
‹
‹
‹
ツリー構造
オブジェクトリスト
タイプリスト
ルートリスト
オブジェクト間のサイズのギャップ
ギャップサイズ毎の数
オブジェクト名/タイプ名による検索
アドレスによる検索
解析
67
HeapAnalyzerでは、以下の項目を調査する事が出来ます。問題発生状況に応じて選択して下さい。
・ツリー構造
・オブジェクトリスト
・タイプリスト
・ルートリスト
・オブジェクト間のサイズのギャップ
・ギャップサイズ毎の数
・オブジェクト名/タイプ名による検索
・アドレスによる検索
67
HeapAnalyzerを用いたHeapDump解析 (2/2)
„
ツリー構造よりリークの疑いがある場所を教えてくれる
‹
Locate a leak suspect
解析
68
HeapAnalyzerの効果的な使用方法として、ツリー構造よりリークの疑いがある場所を教えてくれる機能が
あります。「Analysis」-「Tree Views」より右クリックにて「Locate a leak suspect」を選択して下さい。
68
HeapDump解析ツール － MDD4J
„
解析
GUIベースのHeapDump解析ツール
‹
‹
ISAより起動し、プライマリー・メモリー・ダンプ・URLにHeapDumpファイルを
入力する
アップロードと分析をクリックする
HeapDumpファイル名の入力
解析する際にクリックする
69
HeapDump解析ツールの一つにMDD4Jがあります。ISAを起動し、「ツール」→「製品」からJava 用メモ
リー・ダンプ診断 (MDD4J)を選択して下さい。
その他、当ページでは以下を実施する事が出来ます。
1.プライマリー・メモリー・ダンプ・ファイル URL 入力ボックスに、ヒープ・ダンプ・ファイルを指す URL を入
力して、「アップロードと分析」ボタンをクリックし、単一ダンプ分析機能を起動します。
2.ペアのヒープ・ダンプ・ファイルを指す 2 つの URL を 1 つはベースライン・メモリー・ダンプ・ファイル
URL 入力ボックスに、もう 1 つはメモリー・ダンプ・ファイル URL 入力ボックスに入力して「アップロードと
分析」ボタンをクリックし、比較分析機能を起動します。
3.メモリー・ダンプ URL の例:
a.GZIP 圧縮した PHD ダンプへの HTTP URL: http://productionmachine/opt/WebSphere/AppServer/profiles/default/heapdump.20040819.115809.3716.phd.gz
b.GZIP 圧縮した HPROF ダンプへの HTTP URL: http://productionmachine/opt/WebSphere/AppServer/profiles/default/hprof20040813.txt.gz
c.解凍した IBM TXT ダンプへの HTTP URL: http://productionmachine/opt/WebSphere/AppServer/profiles/default/heapdump20820.1090614135.txt
d.SVC ダンプへの FTP URL: ftp://userid:password@productionmachine/opt/WebSphere/AppServer/profiles/default/dump1.bin
e.ローカル・ファイル・システムにある IBM TXT ダンプへのファイル URL:
file:///c:/WebSphere/AppServer/profiles/default/heapdump20820.1090614135.txt
f.ローカル Windows ファイル・システムにある IBM TXT ダンプ・ファイルへのパス:
c:¥WebSphere¥AppServer¥profiles¥default¥heapdump20820.1090614135.txt
4.メモリー・ダンプ分析結果セクションのドロップダウン選択リストで、以前に実行された分析によって保管
された結果を含むディレクトリーを選択して、「分析結果のロード」ボタンをクリックし、分析結果を表示しま
す。すべての分析結果が、IBM サポート・アシスタント Java プロセスのデフォルト作業ディレクトリーに保
管されています。「構成オプション」ページを介して分析結果を保管する代替作業ディレクトリーの構成が
可能です。
5.構成オプションのリンクをクリックして、修正が可能な別の構成オプションを表示します。
6.ヘルプのリンクをクリックして、この文書を表示します。
69
MDD4Jを用いたHeapDump解析 (1/5)
„
解析
分析サマリー
‹
分析結果のサマリーと分析結果を表示するために行なう次の一連のステッ
プを表示
分析結果のサマリーを確認する
次のステップを確認する
70
当ページでは、以下の内容を確認する事が出来ます。
分析結果のサマリー:
プライマリーおよびベースライン・ダンプの全体の増加、比較分析機能で検出されたデータ構造サスペ
クト数 (存在すれば)、到達サイズの最大ドロップがあるデータ構造サスペクト数、およびタイプ・サスペクト
とパッケージ・サスペクトの数がリストされます。
メモリー・ダンプ・コンテンツのサマリー：
プライマリーおよびベースライン・ダンプに関する情報が表示されます。
次のステップ：
分析結果ページと相互作用可能な、さまざまな次のステップがリストされます。このセクションでの最初の
3 つのアクションにより、次の 3 つのタブ (サスペクト、コンテキストとコンテンツの探索、およびブラウズ) へ
誘導されます。その 3 つのタブでは、最大サスペクトに関連のある情報が強調表示されます。4 番目のア
クションを選択して、アプリケーション Java ヒープの占有スペースへの主なコントリビューターを表示できま
す。4 番目のアクションを選択して、メモリー・ダンプ内で検出されたすべてのルート・オブジェクトを「ブラ
ウズ」タブに表示できます。6 番目のオプションを選択して、すべてのオブジェクトと型を表示する表形式
で Java ヒープのすべてのコンテンツをリストできます。7 番目のオプションを選択して、分析結果をテキス
ト形式で表示できます。このテキスト・ファイルは、分析結果の要約版を伝えるのに使用できます。8 番目
のオプションを選択して、分析の結果を削除できます。これは、ハード・ドライブから分析結果ディレクト
リーを削除し、対応するメモリー・ダンプから、分析結果を再計算する必要があります。9 番目である最後
のオプションは、この分析セッションのメモリー・セッション状態にあるすべてを閉じて、初期入力ページに
戻ります。
70
MDD4Jを用いたHeapDump解析 (2/5)
„
解析
サスペクト
‹
以下の4 つのタイプのサスペクトを表示
¾
¾
¾
¾
増加に最も寄与するデータ構造
到達サイズにおいて大きなドロップが起きているデータ構造
大量のインスタンスを持つオブジェクトのタイプ
大量のオブジェクト・インスタンスを持つ Java パッケージ)
オブジェクト毎のインスタンス数、バイト数を確認する
パッケージ毎のインスタンス数を確認する
71
当ページでは、以下の内容を確認する事が出来ます。
・比較分析技法によって検出されたデータ構造または領域
各データ構造サスペクトに対して、領域の増加サイズおよびプライマリー・ダンプでの領域の実際のサイ
ズを伴ってリーク・ユニット・タイプが表示されます。領域の実際のサイズは、合計ヒープ・サイズのパーセ
ントとして表示されます。データ構造サスペクトは、リーク・ユニットの増加数の結果および領域の実際のサ
イズに従って、ランク付けされます。デフォルトでは、最初のデータ構造サスペクトが選択されます。大幅
な増加のあるデータ構造サスペクトが検出されない場合は、このセクションは表示されません。
・単一ダンプ分析技法によって検出された、コンテナー・オブジェクトの到達サイズで大きなドロップを持つ
データ構造
到達サイズで大きなドロップを持つ各データ構造サスペクトに対して、コンテナー・オブジェクトのオブ
ジェクト・タイプが、コンテナー・オブジェクトの到達サイズと、最大到達サイズを持つ子オブジェクトの到達
サイズへのコンテナー・オブジェクトの到達サイズでのドロップを伴って表示されます。大きなドロップを持
つデータ構造サスペクトは、到達サイズのドロップに従ってソートされます。比較分析技法、または単一ダ
ンプ分析で検出されたデータ構造サスペクトがない場合は、デフォルトで、最初のドロップ・サスペクトが
選択されます。到達サイズの大きなドロップを持つデータ構造が検出されない場合は、このセクションは表
示されません。
・プライマリーおよびベースライン・ダンプ内でインスタンス数の最大増加が起こっているオブジェクト・タイ
プ
多くのメモリー・リーク事例において、サスペクトを持つオブジェクト・タイプのインスタンスのすべてが、
リーク・データ構造の一部ではなく、増加オブジェクト・タイプのすべてがリークしているわけではありませ
んが、大幅な増加のあるオブジェクト・タイプは、しばしば、メモリー・リークに関与しています。
・プライマリーおよびベースライン・ダンプ内でインスタンス数の最大増加が起こっているオブジェクトの
Java パッケージ名
パッケージ名は、メモリー・リークに関与するアプリケーション・コンポーネントを示します。
また、任意のサスペクト・テーブル行をクリックすると、そのサスペクトが強調表示され、選択したサスペク
トに関連した別のタイプのサスペクトのすべてを表示出来ます。
71
MDD4Jを用いたHeapDump解析 (3/5)
„
解析
コンテキストとコンテキストの検索
‹
プライマリー・メモリー・ダンプの Java ヒープの占有スペースへの
¾
¾
主なコントリビューターのオーナーシップ・コンテキストのグラフ
グラフで選択されたノードのコンテンツを表示
(オブジェクト・タイプ、インスタンス数、バイトの表示)
72
当ページでは、以下の内容を確認する事が出来ます。
「コンテキストとコンテンツの探索」タブは、タブ・ヘッダーをクリックするか、フレームの下部にある「次へ」
ボタンをクリックするか、「分析サマリー」タブの「次のステップ」セクションの 2 番目のステップをクリックする
ことで表示できます。
このタブは、「コンテキストとコンテンツの探索」に示すように Java ヒープの占有スペースへの主なコントリ
ビューターのオーナーシップ・コンテキストを表示します。「サスペクト」タブで選択された任意のサスペクト
行に対して、占有スペース内で対応する主なコントリビューター・ノードが選択されます。占有スペース内
のこれらの選択された各ノードに対して、ノードのサイズに大きく寄与するオブジェクトのタイプが、コンテ
ンツ・セクションに表示されます。
選択されたサスペクトのために強調表示されているノードを除いて、オーナーシップ・コンテキストにある
他のノードは、ノード・テーブルの行をクリックすることによっても選択できます。これによって、コンテンツ・
テーブルが更新され、選択したノードで最大インスタンス数を持つ大きなオブジェクト・タイプを表示します。
選択されたサスペクトに対して、「ノードの選択」ボタンは、選択されたサスペクトを含むオーナーシップ・
コンテキスト内のノードのみを強調表示します。
選択されたデータ構造サスペクトまたはドロップ・サスペクトに対しては、「ブラウズ」ボタンで、「ブラウズ」
タブに進み、サスペクトの場所を探索されている深さ優先検索ツリーの特定の部分を表示します。
72
MDD4Jを用いたHeapDump解析 (4/5)
„
解析
ブラウズ
‹
オブジェクト参照グラフの深さ優先全探索に基づいたツリー表示で、プライ
マリー・メモリー・ダンプのすべてのコンテンツを表示
73
当ページでは、以下の内容を確認する事が出来ます。
「ブラウズ」タブは、タブ・ヘッダーをクリックするか、フレームの下部にある「次へ」ボタンをクリックするか、
「分析サマリー」タブの「次のステップ」セクションの 3 番目のステップをクリックすることでアクセスできます。
「ブラウズ」タブは、「コンテキストとコンテンツの探索」タブで、選択されたデータ構造またはドロップ・サス
ペクトに対する「ブラウズ」ボタンをクリックすることによってもアクセスできます。
「ブラウズ」タブでは、デフォルトでは、ツリーが、選択されたデータ構造サスペクトのリーク・コンテナーま
で展開されています。デフォルトでは、最初のデータ構造サスペクトが選択され、対応するリーク・コンテ
ナーまでツリーが展開されます。他のサスペクトへツリーを展開するには、「サスペクト」タブで、そのサスペ
クトを選択する必要があります。
「ブラウズ」タブには、オブジェクト参照グラフの深さ優先全探索に従って構成されたツリー表示で、プラ
イマリー・ダンプのすべてのコンテンツを表示します。展開されたノードの子は、深さ優先全探索中に計算
された合計到達サイズの順番に表示されます。先頭 20 個の子のみが展開されたノードに表示されます。
それ以上の子を表示する場合は、親ノードを選択せずに、左側のパネルで「子の追加表示」アクションを
選択する必要があります。
ツリー内の各ノードには、オブジェクト ID (アドレス)、オブジェクトの種類 (クラス、オブジェクト配列、プリ
ミティブ配列)、および型名が表示されます。ツリー表示で任意のノードの情報をさらに表示するには、ノー
ドを選択する必要があります。すべての親 (ノードへの入力参照) を含む、選択したツリー・ノードの追加
情報が左に表示されます。親テーブルの任意の行をクリックして、親ノードまでツリーを展開できます。
「ブラウズ」タブで使用可能なその他のアクションは、後で特定のオブジェクトをアドレス毎に表示および
検索できるように、ツリー・ノードにブックマークを付ける能力があります。
73
MDD4Jを用いたHeapDump解析 (5/5)
„
オブジェクト・テーブル
‹
„
解析
すべてのメモリー・ダンプ情
報を表示する
タイプ・テーブル
‹
インスタンス数を表示する
74
当ページでは、以下の内容を確認する事が出来ます。
＜オブジェクト・テーブル＞
「オブジェクト・テーブル」タブは、「分析サマリー」タブの「次のステップ」セクションの 6 番目のステップを
クリックすることでアクセスできます。
「オブジェクト・テーブル」に示されるオブジェクト・テーブルは、プライマリー・メモリー・ダンプ内のすべて
の項目をページに表示します。特定のページは、ページ番号を選択するか、「ページに進む」ボタンをク
リックするか、「前のページ」または「次のページ」ボタンをクリックすることで選択できます。オブジェクト・
テーブルは列ヘッダーをクリックすることでソートできます。 オブジェクト・テーブル内に表示される項目は、
使用可能なフィルターのリストからフィルターを適用し、フィルター値を指定して、「フィルター」ボタンをク
リックすることにより、フィルターに掛けることができます。たとえば、1KB より大きなサイズのオブジェクトは、
「サイズ」>「フィルター」を選択して、フィルター値に 1024 バイトを指定すると表示されます。
＜タイプ・テーブル＞
「タイプ・テーブル」タブは、「分析サマリー」タブの「次のステップ」セクションの 6 番目のステップをクリッ
クし、「タイプ・テーブル」タブを選択することでアクセスできます。
タイプ・テーブルに示されるタイプ・テーブルは、他のオブジェクト・タイプのすべてとこれらの各型のインス
タンス数を表示します。タイプ・テーブルは、オブジェクト・テーブルと似た方法で操作できます。
74
IBM Supprt Assistant Workbench (ISA)
„
問題判別に関する情報、ツール、過程を提示するワークベンチ
‹
‹
‹
情報
ツール
過程
ƒ
Wizard
w/ expandable
information
ƒ
Detailed
Information
・・・Technotes , Redbook , Education Video 等
・・・MDD4J , PMAT 等
・・・問題判別の推奨手順 等
Tools
75
IBM Guided Activity Assistant(IGGA)とは、問題判別に関する情報、ツール、過程を提示するワークベンチに
なります。ISAより「ツール」から対象製品を選択し、以下のリンクを選択することで起動されます。
IBM Guided Activity Assistant (IGAA)
IGAAは、「Quick Views」、「Wizard」、「Detailed Information」の3つのポートレットに分割されています。画面
メッセージに従い現象を選択していくことにより問題判別、トラブルシューティングを行うことができます。現在、
英語版のみの提供となっております。
IGAAの詳細につきましては、以下のサイトをご参照下さい。
・About - IBM Guided Activity Assistant
http://www-1.ibm.com/support/docview.wss?uid=swg27010135
75
その他問題判別ツール一覧
„
代表的な解析対象資料に対する問題判別ツール一覧
‹
これらツールの一部はISAのプラグインとして組み込まれており、ISAからの起動
が可能
解析対象資料
設定方法
説明
冗長ガーベッジ
コレクション
（verbose:gcログ）
管理コンソール、または、 GC状況のトレース
JVM引数で設定する
JavaDump（javacore)
デフォルトで、JVMのク
ラッシュ時やQUIT(kill 3)シグナルを受け取った
ときに生成する
HeapDump
デフォルトで
OutOfMemory発生時に
自動生成する
(クラッシュ時にも生成す
るように環境変数で設定
変更可能)
解析ツール
PMAT(ISAから起動可能)
◎
EVTK（ISAから起動可能）
○
GC Collector
△
JVMに関するダンプ情報。 IBM Thread and Monitor
Dump Analyzer for Java
OS情報、環境変数、稼
Technology
動する全スレッドのダン
プ情報など
ThreadAnalyzer
(ISAから起動可能)
JVMが使用するヒープ上
に存在する全liveオブ
ジェクトのダンプ情報
お勧め度
◎
○
HeapAnalyzer
◎
HeapRoots
○
MDD4J(ISAから起動可能)
△
76
問題判別時に使用するツールの一覧を纏めました。表からもわかるようにISAを使用することにより、冗長ガー
ベッジコレクション・JavaDump・HeapDump等の問題判別ツールを登録することができます。
PMAT：IBM Pattern Modeling and Analysis Tool for Java Garbage Collector
EVTK
：Extensible Verbose Toolkit
MDD4J：Memory Dump Diagnostic for Java
その他、ISAに登録されている以外のツールにつきましては、以下をご参照下さい。
・GC Collector
http://www.alphaworks.ibm.com/tech/gcdiag
・IBM Thread and Monitor Dump Analyzer for Java Technology
http://www.alphaworks.ibm.com/tech/jca
・HeapAnalyzer
http://www.alphaworks.ibm.com/tech/heapanalyzer
・HeapRoots
http://www.alphaworks.ibm.com/tech/heaproots
76
JavaDump、HeapDump出力内容の設定（1/2）
„
V6.1New
汎用JVM引数-Xdump設定
‹
ダンプファイルの種類
‹
ダンプイベントの種類
設定例①：予期せぬクラッシュでheapdumpを出力させる場合
名前：汎用JVM引数
値：-Xdump:heap:events=gpf
設定例②：heapdumpの出力回数を3回に変更する場合
名前：汎用JVM引数
値：-Xdump:heap:range=1..3
77
JVMのバージョン5.0では、ダンプ機能の実装においてRAS(Reliability, Availability, and Serviceability)機能が拡充
され、新しく-Xdumpオプションが追加されました。
それ以前のバージョンでは、環境変数のJAVA_DUMP_OPTSやIBM_HEAPDUMP_OUTOFMEMORY等でダンプ機能
を設定することが可能でしたが、今後は、よりきめ細かい設定が可能である-Xdumpオプションをお勧め致します。
＜参考＞
・JVM 5.0 SR5未満の環境では、OutOfMemoryError発生時にJavacoreおよびHeapdumpが出力されません (WAS08-006)
http://www-06.ibm.com/jp/domino01/mkt/cnpages1.nsf/page/default-0003F586
77
JavaDump、HeapDump出力内容の設定（2/2）
„
環境エントリーJAVA_DUMP_OPTS
‹
‹
出力するダンプの種類を設定可能
環境変数
JAVA_DUMP_OPT=“ON<condition>(<dumptype>),・・・・・”
condition
ANYSIGNAL, DUMP, ERROR, INTERRUPT, EXCEPTION,OUTOFMEMORY
dumptype
ALL, NONE, JAVADUMP, SYSDUMP, HEAPDUMP
condition: Javacoreファイルの生成条件を指定
¾
¾
¾
¾
‹
dumptype: 生成するダンプの種類
¾
¾
¾
‹
DUMP： CTRL-BREAK(Windows環境)やCTRL-¥（AIX, Linux）によりJavacoreを出力
ERROR： JVMの内部で検知されたエラーによって異常終了
INTERRUPT： CTRL-CなどによりJavacoreを出力
OUTOFMEOMRY： OutOfMemory（メモリ不足）エラーが発生
SYSDUMP： OSが生成するコアファイル
HEAPDUMP： ヒープダンプ
JAVADUMP： JavaDumpファイル
推奨値
¾
JAVA_DUMP_OPTS="ONERROR(JAVADUMP,SYSDUMP)
ONEXCEPTION(JAVADUMP,SYSDUMP), ONDUMP(JAVADUMP)"
78
前ページで、ダンプの設定を行う際は-Xdumpを使用することをお勧めしておりますが、これまで同様に
環境エントリーJAVA_DUMP_OPTSを使用して引き続き設定することも可能です。この環境変数を使用する
ことで、どのような状況で (どのような命令が送られたときに) 、どの種類のダンプを生成するか設定するこ
とが可能です。
生成条件のDUMP,ERROR,INTERRUPTの各レベルに対してどの信号がマッピングされているかはプ
ラットフォームによって異なっており、詳細はdiagnostic guideに掲載されています。問題判別を行うときに
は、一般に各OSが生成するCoredumpファイルも有用な情報を提供する場合が多いため、設定を以下の
ように変更することが望ましいとされています。
・Diagnostic Guide, Chapter 25 Using Heapdump(p.370)
JAVA_DUMP_OPTS="ONERROR(JAVADUMP,SYSDUMP) ONEXCEPTION(JAVADUMP,SYSDUMP),
ONDUMP(JAVADUMP)"
78
その他JavaDump、HeapDumpに関する環境エントリー
„
管理コンソールにて設定
‹
アプリケーションサーバー選択後、 「Javaおよびプロセス管理」から「プロセ
ス定義」→「環境エントリー」 にて設定
環境変数名
値
Memo
IBM_HEAPDUMP 又は
IBM_HEAP_DUMP
true/false
Heap Dumpの機能を有効にする
IBM_HEAPDUMP_OUTOFMEMORY
true/false
IBM_JAVACOREDIR
fullpath
OutOfMemoryをhookし、Heap Dumpを生成する
機能を有効にする
JavaDumpの出力先変更
IBM_HEAPDUMPDIR
fullpath
HeapDumpの出力先変更
IBM_JAVA_HEAPDUMP_TEXT
true/false
IBM_JAVA_HEAPDUMP_TEST
true/false
TMPDIR
fullpath
PHDフォーマットかTXTフォーマットかを選択す
る
PHD＋TXTフォーマットの二種類のHeap Dump
を同時に生成する
Heap Dumpの出力先が利用不能な場合に書き
出し先となるディレクトリ
79
上記の表は、JavaDumpとHeapDumpに関する環境エントリーの一覧になります。これらの環境変数は管
理コンソールからアプリケーションサーバーを選択し、「Javaおよびプロセス管理]から「プロセス定義」→
「環境エントリー」の画面から設定可能です。デフォルトでは何も表記されていませんので、手動で変数と
値を設定する必要があります。出力先やファイル名を変更したいときは参考にして下さい。
79
【ご注意下さい】JVM5.0 SR5未満の環境では、OutOfMemoryError発生時に
JavacoreおよびHeapdumpが出力されません
„
JVM5.0 SR5未満の場合、障害によりOutOfMemoryError時にJavacore
またはHeapdumpが出力されない
„
対応方法（以下の3つ内、1つを選択ください。）
1.
2.
3.
JVMのバージョンを5.0.0 SR5以上にアップグレードする
アプリケーション側で、OutOfMemoryErrorをキャッチしてスローする
管理コンソールで以下のいずれかを設定する
¾
¾
アプリケーション・サーバー > <アプリケーション・サーバー名>Java およびプロセス管理>プ
ロセス定義>環境エントリーを選択し以下のパラメータを追加
名前：IBM_HEAPDUMP_OUTOFMEMORY 値：true
名前：IBM_JAVADUMP_OUTOFMEMORY 値：true
アプリケーション・サーバー > <アプリケーション・サーバー名>Java およびプロセス管理>プ
ロセス定義>環境エントリーを選択し以下のパラメータを追加
名前：JAVA_DUMP_OPTS
値：
ONERROR(JAVADUMP,SYSDUMP),ONEXCEPTION(JAVADUMP,SYSDUMP),ONDUMP(JAV
ADUMP),ONOUTOFMEMORY(JAVADUMP,HEAPDUMP)
(注意）
JVM5.0 SR2では対応可能な事を確認済み
JVMがその他のバージョンの場合には、確認テストを行ってください
80
JVMでは、デフォルト設定でJavacoreおよびHeapdumpが出力されるようになっていますが、JVMのバージョンによっ
ては、障害によりOutOfMemoryError時にJavacoreまたはHeapdumpが出力されないことが確認されています。
JavacoreおよびHeapdumpは問題解析の際にとても大切な情報であり、問題発生時にこれらの情報が出力されること
は問題の早期解決につながります。
よって、上記の対応策を早期に実施されることをお勧め致します。
80
IHS / WebSphere Application Server問題判別
症状別問題判別
‡
‡
‡
‡
ハング
スローダウン
OutOfMemory
ブラウザから応答が返ってこない時の一例
81
81
症例１：スローダウン
„
„
レスポンスが遅い
主な原因
‹
マシンのリソースの限界
¾
¾
¾
‹
他のアプリケーション（バッチなど）
¾
‹
‹
„
CPU使用率の調査
事前に負荷テスト・パフォーマンスチューニングを行い、リクエストをどこまで受付
可能か、限界値を見極めておく
負荷分散装置などでそれ以上のリクエストがこないように流量制限
grep/find/tailなどのコマンドもシステムに負荷を与えることがあるので注意
アプリケーションロジックの不備
他システムの遅延
ボトルネックの特定が必要
‹
‹
OS、ネットワーク、ソフトウェアなど、全体を見て検出
Webサーバーでレスポンスタイム記録 ＋ 要求メトリックが有用
（→ 「IHSアクセスログのカスタマイズ」）
82
スローダウンは、個々の構成要素は正常に稼動しているにも関わらず、レスポンスが返ってくるのが非常
に遅い現象になります。
主な原因は、マシンのリソースの限界や他のアプリケーションの影響が考えられます。マシンのリソース
はCPU使用率などを調査し、必要以上に負荷がかかっていないかを確認します。その場合には、負荷分
散装置などを利用し、それ以上のリクエストがこないように流量制限することも考慮にいれなくてはなりませ
ん。また、事前に負荷テストやパフォーマンスチューニングを行い、リクエストをどこまで受付可能か、限界
値を見極めておくことも重要になります。
また、他のアプリケーションやバッチの影響もあります。見落としがちですが、grepやfind、tailなどのコマ
ンドもシステムに負荷を与えることがあるので注意が必要です。
スローダウンを解決するには、そのボトルネックがどこにあるのかを検出することが非常に重要です。考
えられるボトルネックとしては、OSレベル、Network、ソフトウェアなどシステム全体からそのボトルネックを
検出することが重要です。OSレベルであればvmstatコマンド、ソフトウェアであれば、 Webサーバーでレス
ポンスタイム記録を取得し、要求メトリックを利用してコンポーネントごとのレスポンスタイムを取得すること
が有用です。(→「IHSアクセスログのカスタマイズ」)
82
症例２：ハングアップ
„
„
WAS（App)プロセスは存在しているが、応答が無い状態
主な原因
‹
アプリケーションや製品の問題（→「JavaDump」）
¾
¾
¾
‹
‹
„
デッドロック
再帰呼び出しによる無限ループ
JavaDumpの取得が有用
他連携システムからの応答待ち
パフォーマンスの劣化による長時間スローダウン
JavaDumpからハングアップポイントの判定
83
ハングは、プロセスは存在しているにもかかわらず応答がない現象になります。
主な原因としては、アプリケーションまたは製品のバグに起因する場合があります。スレッドがデッドロッ
クを起こし停止してしまう場合や、再起呼び出しによる無限ループが発生し、結果的に応答がなくなる場
合があり、最終的にStackOverflowでJVMがダウンしてしまう可能性もあります。ハングが発生した際、CPU
使用率があまり高くない場合にはデッドロック、CPU使用率が高い場合には再起呼び出しによる無限ルー
プの状態になっていることが考えられます。この場合は、JavaDumpの取得が有用です。 （→「JavaDump」）
また、後方リソースの処理待ちに起因する場合もあります。この場合、DBやMQなど、後方リソース処理
やネットワーク処理などにより、スレッドがI/O処理待ちの状態となります。この場合、後方のリソースについ
て問題判別を行う必要があります。
また、パフォーマンスの劣化により、レスポンスが返ってこないように感じられる場合です。この場合、遅く
てもレスポンスが帰ってくる状態であれば、後方リソースまたはパフォーマンスの問題と考えられます。(次
ページ「スローダウン」参照)
83
症例３：OutOfMemory
„
„
ヒープ領域を使い切ってしまった
主な原因
‹
‹
„
Java heap領域の不足
Native heap領域の不足
GCやメモリ領域のチェック
‹
verbose:gc （→ 「verbose:gc」）
¾
¾
‹
出来る限り、通常時から取得して下さい
より詳細なGCの挙動を確認したい場合には、GCトレースを取得して下さい
HeapDump （→ 「HeapDump」）
¾
¾
正常時に1回取得しておくと、障害発生時の分析に便利である
PDを行う際には、問題発生までの時間の経過に合わせて（もしくは、状況に応じ
て）2回程取得することを推奨
84
OutOfMemoryは、メモリー領域を使い切ってしまい、ログにOutOfMemoryエラーが出力されJVMがダウ
ンする現象になります。
主な原因としては、Java heap領域の不足の場合とNative heap領域の不足の場合があります。
OutOfMemoryが発生した時には、GCがどのように行われ、メモリ領域がどのように使われているのか
チェックする必要があります。そのために取得すべき情報としては、 verbose:gc、HeapDumpがあります。
（→「verbose:gc」）また、より詳細なGCの挙動を確認したい場合には、GCトレースを取得して下さい。
(→Hits&Tips「GCトレース」)
正常時の状況のHeapDumpを事前に取得しておき、問題発生時に比較することにより、問題判別がより
スムーズに進みますので、正常時に一度HeapDumpを取得しておくことをお勧め致します。また、問題判
別を行う場合には、問題発生までの時間の経過に合わせて２回程度Heapdumpを取得することを推奨しま
す。また、AIXであれば、svmonコマンドによりメモリー使用量の変化を追うことも有効です。
84
症例４：クラッシュ
„
„
JVMの異常終了
主な原因
‹
‹
„
Native Code（JNI）の問題
JVMそのものの問題
サポートセンターに依頼
‹
クラッシュ時はCore、JavaDumpは自動で出力される
85
クラッシュは、SIGSEGV (incorrect access to memory) 、SIGILL (illegal instruction) などでJVMが異常終
了する現象になります。
主な原因としては、Native Code (JNI)の問題やJVMそのものの問題が考えられます。JNIの問題としては、
JDBCドライバーの問題なども含まれます。
この場合には、CoreやJavaDumpが自動で取得されます。その原因がJVMの問題と考えられる場合には、
CoreとJavaDumpファイルを取得し、IBMサポートセンターに報告します。通常、クラッシュの場合、IBMサ
ポートセンターに問題を解析してもらうことになりますが、JavaDumpを参照することによって、現場のSEが
その問題判別をできる場合もございます。
85
ブラウザから応答が返ってこないときの一例 (1/6)
•F/Wや負荷分散装置がある場合、そこに対する調査も行う。
Pingは通るか
ネットワークの問題判別
No
Yes
Webサーバーは起動しているか（プロセスのチェック）
No
Yes
静的コンテンツへのリクエストは返ってくるか
Webサーバーダウン?
ログ/設定coreの確認
No
Yes
アプリケーションサーバーは起動しているか（プロセスのチェック）
Javaプロセスダウン?
ログ/JavaDumpのチェック
No
Yes
WASやアプリケーションのログの確認、解析
Plug-inが怪しい
ログの確認
Fixの有無の確認
トレース取得
特に何も出ていない
Yes
Webサーバーを経由せず、HTTPトランスポートから
アプリケーションサーバーへ直接アクセスしたときは応答が返ってくるか
No
アプリケーション
高負荷
CPU使用率の調査
CPUを使っているの サーバープロセス
はどのプロセスか？
ほとんど使っていない
リソースの限界の可能性?
ループ?→JavaDumpの取得/解析
他のプロセス
そのプロセスの調査
（バッチなどが重い?）
他のアプリケーションへのリクエストへの応答は正常に返ってくるか
Yes
問題のアプリケーション内でのトレースの取得・解析（どこで止まるのか）
No
ハング? 再現性の確認
アプリケーションの見直し
JavaDumpの取得/解析
86
上記はブラウザから応答が返ってこないときの問題判別手順の一例を示したものになります。
Pingは正常に通るか、Webサーバーは起動しているか、静的コンテンツへのリクエストは返ってくるか、な
ど一つ一つの問題を切り分けて問題判別を行います。また負荷分散装置やファイアウォールなどがある
場合は、それに対する調査も必要になります。
86
ブラウザから応答が返ってこないときの一例 (2/6)
„
Pingは通るか
‹
クライアント・サーバー間のネットワークの問題？
ping の出力（Windows）
C:¥Documents and Settings¥user1>ping mercury
Pinging mercury [9.170.251.57] with 32 bytes of data:
Reply from 9.170.251.57: bytes=32 time<1ms TTL=128
Reply from 9.170.251.57: bytes=32 time<1ms TTL=128
Reply from 9.170.251.57: bytes=32 time<1ms TTL=128
Reply from 9.170.251.57: bytes=32 time<1ms TTL=128
Ping statistics for 9.170.251.57:
Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
Approximate round trip times in milli-seconds:
Minimum = 0ms, Maximum = 0ms, Average = 0ms
送った全てに対し、リプライが返っている
87
まずはクライアントとサーバー間のネットワークに問題がないかを確認するために、pingを実行します。マ
シンのホスト名に対しpingコマンドを実行します。成功すると、Reply fromという形で応答が返ってきます。
失敗した場合は、クライアント・サーバー間のネットワークで問題が発生している可能性があります。
87
ブラウザから応答が返ってこないときの一例 (3/6)
„
Webサーバーは起動しているか
‹
プロセス確認（ps、tasklist）
ps –ef | grep http の出力（AIX）
host1@root[/usr/IBMIHS60/conf] ps -ef | grep http
root 35698 20872 0 16:53:17 pts/4 0:00 grep http
nobody 36180 42056 0 16:53:14
- 0:00 /usr/IBMIHS60/bin/httpd -d /usr/IBMIHS60 -k start
root 42056 1 1 16:53:13
- 0:00 /usr/IBMIHS60/bin/httpd -d /usr/IBMIHS60 -k start
nobody 42772 42056 0 16:53:14
- 0:00 /usr/IBMIHS60/bin/httpd -d /usr/IBMIHS60 -k start
nobody 48984 42056 0 16:53:14
- 0:00 /usr/IBMIHS60/bin/httpd -d /usr/IBMIHS60 -k start
„
静的コンテンツへの応答があるか
‹
‹
‹
IHS上のコンテンツにアクセス
Webサーバーのダウン？
ログの確認
http://localhost/
88
次にWebサーバーが起動しているかを確認するために、プロセスを確認します。プロセス確認のコマンド
はAIXやLinuxならpsコマンド、Windowsならtasklistコマンドを実行します。正常にプロセスが起動していれ
ば、一つの親プロセスに対し複数の子プロセスが起動していることが確認出来ます。（上記はAIXでの例）
WindowsであればtasklistコマンドでApache.exeを確認します。また、タスクマネージャでも確認出来ます。
また、IHS上の静的コンテンツに対しリクエストを投げ、IHS上のコンテンツが正常に表示されるかどうかを
確認します。例ではIHSのデフォルトページにアクセスして、IHSが正常に動作していることを確認していま
す。
以上の2つが失敗する場合、IHSが正常に起動していない可能性がありますので、IHSのログを確認しま
す。（→「IHSで取得されるログ」）
88
ブラウザから応答が返ってこないときの一例 (4/6)
„
アプリケーションサーバーは起動しているか
‹
‹
プロセス確認（ps、tasklist）
WASのプロセスダウン？
ps –ef | grep java の出力（AIX）
host1@root[/usr/WebSphere/AppServer6]ps -ef | grep java
root 26240 1 0 17:07:45 pts/4 0:40 /usr/WebSphere/AppServer6/java/bin/java -Xbootclasspath/p:/usr
・・・・・・・・
r6/profiles/Dmgr01/config silver2Cell01 silver2CellManager01 dmgr
root 42962 1 0 17:11:07 pts/4 0:24 /usr/WebSphere/AppServer6/java/bin/java -Xbootclasspath/p:/usr
・・・・・・・・
ere/AppServer6/profiles/Custom71/config silver2Cell01 silver2Node71 nodeagent
„
WAS、アプリケーションのログの確認
‹
SystemOut.log、SystemErr.logなどにエラーメッセージが出力されて
いないか
89
次にWASが起動しているかを確認するために、プロセスを確認します。psコマンドを実行すると、プロセ
ス末尾にセル名、ノード名、サーバー名が書かれたプロセスがありますので、それぞれ正常に起動してい
るかどうかを確認します（上はAIXでの例）。Windowsであればtasklistコマンドでjava.exeが存在しているか
どうかを確認します。この場合、どのjava.exeが何のプロセスを表しているか判断できませんので、PIDファ
イルとプロセスIDを照らし合わせる必要があります。プロセスが起動していない場合、WASのプロセスダウ
ンの可能性がありますので、JavaDumpなどを確認します。
また、WASやアプリケーションのログを確認し、エラーメッセージが出力されていないか確認します。 （→
「WASで取得されるログ」 ）エラーが出力されていれば、そのエラーに対して解決策を施す必要があります。
89
ブラウザから応答が返ってこないときの一例 (5/6)
„
„
HTTPトランスポートに直接アクセスしたときに応答があるか
http://localhost:9080/snoopなどにアクセス
‹
‹
トランスポートは管理コンソールで確認
起動時SystemOut.logにもメッセージが表示
アプリケーションサーバーを選択し、
「Webコンテナー設定」→「Webコンテナー・ト
ランスポートチェーン」
‹
‹
プラグインの割り振りの問題？
実際のどのHTTPトランスポートを使って通信したかはプラグインログのレベ
ルをトレースにすると判断できる
http_plugin.log
[Tue Sep 20 14:59:09 2005] 0000aad6 00000203 - TRACE: ws_common: websphereFindTransport: Finding
the transport
[Tue Sep 20 14:59:09 2005] 0000aad6 00000203 - TRACE: ws_common: websphereFindTransport: Setting
the transport (case 2): silver2.makuhari.japan.ibm.com on port 9080
90
次にWebサーバーを経由せず、HTTPトランスポートに直接アクセスしたときに応答があるかを確認しま
す。アプリケーションサーバーのトランスポートを指定して直接アクセスして、応答の有無を確認します。ア
プリケーションサーバーが所有しているHTTPトランスポートは管理コンソールからも確認出来ますし、起
動時にSystemOut.logにも「TCP チャネル TCP_2 は、ホスト * (IPv4)、ポート 9080 で listen しています。」
というメッセージが出力されます。
HTTPトランスポートに直接アクセスしたときに正しい応答が返ってくれば、IHSからWASに渡す際のプラ
グインの挙動に問題がある可能性があります。プラグインログを確認し、必要であればプラグインのログレ
ベルをトレースに設定してプラグインの挙動を確認します。プラグインを経由してWASにアクセスする際に、
どのHTTPトランスポートにアクセスしたかも、プラグインログのレベルをトレースにすると確認出来ます。
（→「プラグインで取得されるログ」）
90
ブラウザから応答が返ってこないときの一例 (6/6)
„
„
CPU使用率の確認
使用率が高いプロセスの調査
‹
‹
リソース上の限界
無限ループなどによるリソースの消費
vmstat -t 10 の出力（AIX）
host1@root[/]vmstat -t 10
kthr メモリ
ページ
フォルト
CPU
時間
------- -------------------- ------------------------ ----------------- --------------- ----------r b avm fre
re pi po fr sr cy in sy cs us sy id wa hr mi se
1 1 115652 95387 0 0 0 0 0 0 159 1693 127 1 3 95 1 14:18:24
0 0 115662 95377 0 0 0 0 0 0 153 1275 107 1 1 98 0 14:18:34
0 0 115660 95379 0 0 0 0 0 0 152 1819 107 1 3 96 0 14:18:44
2 0 115659 95380 0 0 0 0 0 0 162 2779 130 2 5 89 4 14:18:54
1 0 122849 88190 0 0 0 0 0 0 155 3968 104 83 6 10 0 14:19:04
ps v(ww) <process id> の出力（AIX）
host1@root[/usr/WebSphere/AppServer6]ps vww 22952
PID TTY STAT TIME PGIN SIZE
RSS LIM TSIZ TRS %CPU %MEM COMMAND
22952 pts/0 A 0:30 228 130448 130504 32768 39 56
11.8 11.0 /usr/WebSphere/AppSer
ver6/java/bin/jav・・・・・
91
次にマシン自体のCPU使用率を確認します。もしCPU使用率が非常に高い状態であれば、どこがCPU
を多く消費しているのか確認します。 もしその原因がアプリケーションサーバーのプロセスであれば、アプ
リケーションで無限ループなどが発生していないか確認します。リソースの限界である場合には、必要以
上の負荷がマシンにかからないように、パフォーマンスチューニングを行い、流量制限を行う必要がありま
す。
91
Edge Component問題判別
情報収集・症状別問題判別
‡
‡
‡
‡
‡
‡
‡
‡
‡
‡
‡
‡
(参考)Edgeの構成要素と役割
Edgeの情報収集/ログ
Manager Reportコマンド
ケース1：dsserverが起動しない
ケース2：「エラー: サーバーが応答していません」
ケース3：Manager Reportが全サーバー「-1」を返す
ケース4：割振りが行われない
ケース5：Takeoverが正常に完了しない
ケース6：意図しないTakeoverが発生する
ケース7：セッションが維持できない
ケース8：割振りが偏る
ケース9：接続数が異常に多い
92
92
(参考)Edgeの構成要素と役割
„
Edge構成要素
‹
‹
‹
Executor
Manager
Advisor
サーバーの監視を行い
レスポンスの時間を
Managerに伝える
Server
dsserver(javaコンポーネント）
監視
Manager
Advisor
Server
リク
Client
エス
ト
Executor
カーネル
Executorから接続数を
受け取り、それらの情報を基に
負荷を計算してExecutorに
”重み”として伝える
割り振り
Server
Load Balancer
Managerに接続数
を伝え、“重み”を基に
割り振りを行う
Cluster
93
Dispatcherは、主にExecutor, Manager, Advisorの3つの要素から構成されております。
Executor・・・接続数をカウントし、その情報をManagerに渡します。またManagerが計算した重みを受け取
り、その情報を基に割り振りを行います。
Manager・・・Executorからは接続数の情報を、Advisorからはレスポンスタイムを受け取り、割り振り先サー
バーの重み付けを計算します。
Advisor・・・割り振り先サーバーに対し監視リクエストを投げることで障害検知を行います。またレスポンス
タイムをManagerへ渡します。
93
Edgeの情報収集 (1/3)
„
情報収集ツール lbpd
‹
‹
‹
Dispatcher用問題判別基本情報収集ツール
<EDGE_ROOT>/lbディレクトリ下にlbpmr.tar.Zが作成される
lbpmr.tar.Zに含まれるもの
¾
¾
¾
lbpd実行結果（lbinfo.txt）
<EDGE_ROOT>/lb/logs/下の
ログファイル全て
<EDGE_ROOT>/lb/
configurations/dispatcher/下の
構成ファイル全て
lbpdの中で採取している情報 < AIXの例>
[/opt/ibm/edge/lb/servers/bin] ./lbpd
Running java -version................................Done.
Running netstat -ni..................................Done.
Running netstat -nr..................................Done.
Running lslpp -l.....................................Done.
Running no -a........................................Done.
Running arp -a.......................................Done.
Running dscontrol executor status....................Done.
Running dscontrol executor report....................Done.
Running dscontrol cluster report :...................Done.
Running dscontrol cluster status :...................Done.
Running dscontrol port report ::.....................Done.
Running dscontrol port status ::.....................Done.
Running dscontrol server report ::...................Done.
Running dscontrol server status ::...................Done.
Running dscontrol highavailability status............Done.
Running dscontrol manager report.....................Done.
Running dscontrol file save ibmpmr.cfg force.........Done.
94
Edgeで問題発生時に情報を収集するツールとしてlbpdコマンドがあります。実行すると、
<EDGE_ROOT>/libディレクトリ下にlbpmr.tar.Zファイルが作成されます。このファイルにはlbpd実行結果、
ログファイル、構成ファイルが含まれます。
94
Edgeの情報収集 (2/3)
„
現行構成ファイル
‹
dscontrol file save <ファイル名>
¾
¾
„
<EDGE_ROOT>/lb/servers/configurations/dispatcher
<EDGE_ROOT>¥lb¥servers¥configurations¥dispatcher
Dispatcherの詳細バージョン
¾
¾
¾
¾
„
[AIX/Linux]
[Windows]
[AIX]
[Linux]
[Solaris]
[Windows]
lslpp –l | grep ibmlb
rpm -qa | grep ibmlb
pkginfo -l ibmlbadm
dscontrol executor report
Active code page: 437
C:¥work>dscontrol executor report
Executor Report:
---------------Version level ................................. 06.00.00.00 20041028-142356 WSBLD39]
Total packets received since starting ......... 0
Packets sent to nonforwarding address ......... 0
Packets processed locally on this machine ..... 0
Packets sent to collocated server ............. 0
Dispatcherと割振り先サーバーのネットワーク情報
‹
‹
‹
‹
設定
ルーティング
接続テーブル
インターフェース
[Unix] netstat –in
[Windows] ipconfig –all
[Unix] netstat –rn
[Windows] route print
[Unix] netstat –an
[Windows] netstat –an
[UnixOnly] ifconfig –a
95
Edgeで問題判別の際に収集すべき情報には、現行構成ファイル、バージョン、ネットワーク情報、ログ
ファイル、ネットワーク・トレースがあります。現行構成ファイル、バージョン、ネットワーク情報は、以上のコ
マンドを実行することで取得出来ます。
95
Edgeの情報収集 (3/3)
„
ログファイル
‹
‹
‹
‹
„
スクリプトファイル
‹
„
<EDGE_ROOT>¥lb¥servers¥logs¥ディレクトリ下のログファイル
ログレベル５のhamon.log
dscontrol set loglevel 5
ログレベル５のreach.log
dscontrol manager reach set loglevel 5
ログレベル５のアドバイザー・ログ dscontrol advisor loglevel <アドバイザー名> 5
<EDGE_ROOT>¥lb¥servers¥binディレクトリ下のスクリプト・ファイル
ネットワーク・トレース
‹
[AIX]
¾
‹
[AIX]
¾
‹
‹
ユーザー・トラフィックに問題がある場合
iptrace -a -s <クライアントIP> -d <クラスター・アドレス> -b <出力ファイル名>
Heartbeatに問題がある場合
iptrace –abp <HeartBeat使用ポート> <出力ファイル名>
[Linux]
tcpdump -w <出力ファイル名>
[Windows] snifferやEtherealなどパケット・トレース・ツールを使用
96
ログファイル、ネットワークトレースは、以上のコマンドを実行することで取得出来ます。Edgeではデフォ
ルトのログファイルサイズが1MBになりますので、ログレベルを5にされた場合はログサイズを増やして下さ
い。また、最終的にログなどから問題を切り分ける事が出来ない場合は、ネットワークトレースを採取するこ
とがあります。AIX環境でのIPトレースの使用方法につきましては、以下をご紹介させて頂きます。
・InfoCenter - 「iptrace デーモン」
http://publib.boulder.ibm.com/infocenter/pseries/v5r3/index.jsp?topic=/com.ibm.aix.cmds/doc/aixcmd
s3/iptrace.htm
96
Edgeのログ
„
Load Balancerのログは循環ログ
‹
‹
„
サイズがオーバーしたら古いログから上書き
ログ・サイズは変更可能
ログの種類
‹
server.log
‹
manager.log
‹
使用advisor名_ポート.log
¾
¾
¾
‹
dsserverの活動の記録、発行したコマンド等の情報
managerの活動記録等
使用するadvisorに関する情報
subagent.log
¾
SNMP subagentに関する情報
‹
hamon.log
‹
reach.log
¾
¾
high availabilityに関する情報（Primary, Backupの両方）
reach advisorがとばしたping情報等
97
上記のログは、コマンドdscontrol loglevel <0～5> にて書き込む情報量を変更することが可能です。
ログレベルを0~5まで変更することが出来ます。ログレベルが3以上の場合は、最大サイズを設定することを望
まれます。ログの最大サイズを指定した場合は、ログサイズの最大値に達すると、上から上書きされていきます。
ログのサイズは、現在の値よりも小さいものには設定できません。
(※) LoadBalancerのログは問題判別用ですので、常時ログレベルを5にして運用する事は一般的ではありませ
ん。ログレベルを高くするとパフォーマンスが悪くなります。
Load Balancerを再起動したときに、前回使用していたログファイルに.bak拡張子を付加して保存し、新しいロ
グファイルが作成されます。ログを保存したい場合は、再起動する前に、.bakを保存する事をお奨め致します。
97
Manager Reportコマンド
„
dscontrol manager report コマンド
‹
managerが持っている情報を表示する
¾
¾
¾
¾
問題判別では、このPORT値をまず確かめます
PORT値は，advisorを使用してサーバの状態を監視した時の、割り振り先サーバに対するリク
エストのレスポンス時間に依存した値を表しております。
PORTが-1の場合、割振り先サーバがダウンしている状況です
WEIGHTが-1の場合、割振りを停止している状況です
z ACTV
現在接続中の接続数
z NEWC
直近４秒の新規接続数
z PORT
アドバイザーへの応答時間
------------------------------------------------------------------|
9.170.19.100
| WEIGHT | ACTV | NEWC | PORT |
SYS |
|
PORT:
80
|NOW NEW|
49% |
50% |
1% |
0% |
------------------------------------------------------------------|
9.170.19.10 | 9 9 |
13 |
1 |
32 |
0 |
|
9.170.19.20 | 0 0 |
0 |
0 |
-1 |
0 |
------------------------------------------------------------------＜参考＞
WEIGHT
更新
WEIGHT
更新
2秒
WEIGHT
更新
2秒
2秒
ACTV, NEWC
更新
WEIGHT
更新
ACTV, NEWC
更新
98
Webシステムの問題判別時には、まずはじめにどこで問題が発生しているかを切り分ける必要がございます。
その切り分けを実施してくれるのが、Edgeのmanager reportコマンドになります。このコマンドを実行しPORT値を
確認することで、どの割振り先に問題が発生しているかを確認する事が出来ます。
以下、manager reportコマンドの出力結果についてご説明させて頂きます。
・WEIGHTのNOW値は、現在executorが使用している重みです。
・WEIGHTのNEW値は、次のサイクルでexecutorが使用する重みです。
ACTV値、NEWC値に関しては、executorが内部カウンターからカウントした接続数をmanagerに渡したもので
す。managerは、default2秒間隔でWEIGHTを更新しており(参考図)、そのサイクルを2回(default)繰り返すごとに
接続数(ACTV,NEWC)の情報を更新しています(参考図)。その2サイクルの間に(点線部)新しく入ってきた接続
数が、次の「NEWC」として反映されます。また、総接続数から次の接続数の更新時までに接続が終了した数を
引いたものが、「ACTV」として反映されます。
・PORT値は，advisorを使用してサーバの状態を監視した時の、サーバに対するリクエストのレスポンス時間に
依存した値を表しております。レスポンスがない場合は、PORT値は「-1」となります。
・SYS値は、Metric Serverなどのシステムの負荷を監視するツールにより、割振り先サーバーのCPU使用率やメ
モリ使用率などのシステム負荷を監視している場合、その値が反映されます。
お客様によっては、定期的にmanager reportの出力結果を保管している事例もございます。
98
ケース1：dsserver / cbrserverが起動しない
„
ポートの競合が発生しているケースが多い
‹
‹
‹
‹
dsserverが使用するポート
ポート
設定ファイル
変数名
用途
10099
dsserver
LB_RMIPORT
dsserverとdscontrolコマンドの通信
10199
dsserver
LB_RMISERVERPORT
dsserver自身の使用するポート
10004
metricserver
LB_RMIPORT
メトリック・サーバーとの通信
cbrserverが使用するポート
ポート
設定ファイル
変数名
用途
10099
dsserver
LB_RMIPORT
dsserverとdscontrolコマンドの通信
10199
dsserver
LB_RMISERVERPORT
dsserver自身の使用するポート
10004
metricserver
LB_RMIPORT
メトリック・サーバーとの通信
競合するアプリケーションの停止を行う
各設定ファイルの変数値を変更することでも対応可能
¾
¾
AIXやLinux、Solarisの場合 ：/usr/binディレクトリに存在
Windowsの場合 ：C:¥WINDOWS¥system32に存在
99
・ケース1：dsserver / cbrserverが起動しない
ポートの競合が発生しているケースが多いです。netstatコマンド等にてポートが競合していないかを確認し、
競合している場合にはアプリケーションの停止、設定ファイルの見直しを実施して下さい。
99
ケース2：「エラー: サーバーが応答していません。」
„
dsserverとdscontrolコマンドとが通信出来ない場合に表示さ
れるメッセージ
‹
dsserverプロセスは起動しているか？
¾
¾
¾
Javaプロセスが起動しているか確認して下さい。
Dispatcherの場合
ps –ef | grep java | grep SRV_KNDConfigServer
CBRの場合
ps –ef | grep java | grep SRV_WTEConfigServer
/opt/ibm/edge/lb/java/jre/bin/java -Djava.net.preferIPv4Stack=true -Djava.net.preferIPv6Stack=false -cp
/opt/ibm/edge/lb/servers/lib:/opt/ibm/edge/lb/servers/lib/ibmlb.jar:/opt/ibm/edge/lb/admin/lib/ChartRuntime.jar:/opt/ibm/
edge/lb/admin/lib/management.jar:/opt/ibm/edge/lb/admin/lib/tmx4jc.jar:/opt/ibm/edge/lb/servers/lib/CustomAdvisors DLB_INSTALL_PATH=/opt/ibm/edge/lb -DLB_CLIENT_KEYS_DIRECTORY=/opt/ibm/edge/lb/admin/keys
-Dcom.ibm.edge.nd.ServerKeysDirectory=/opt/ibm/edge/lb/servers/key
-Djava.protocol.handler.pkgs=com.ibm.net.ssl.internal.www.protocol
com.ibm.internet.nd.server.SRV_KNDConfigServer 10099 /var/log/edge/
/opt/ibm/edge/lb/servers/configurations/dispatcher/ /opt/ibm/edge/lb/servers/bin/ default.cfg 10199
‹
dscontrolコマンドの通信に使われるカギが壊れていませんか？
¾
¾
¾
「lbkeys create force」コマンドで、鍵を再生成して下さい
生成された鍵は、/opt/ibm/edge/lb/admin/keysディレクトリにあります
それでも直らない場合は、鍵ファイル名に付加されるIPアドレスをご確認下さい
z
z
例）dispatcher-<NFAアドレス>-10099.key、cbr-<NFAアドレス>-11099.key
IPアドレスがNFAアドレスではない場合は、/etc/hostsファイルなどの設定を確認して下さい
100
・ケース2：エラー：サーバーが応答していません。
dsserverとdscontrolコマンドとが通信出来ない場合に表示されるメッセージになります。dsserverプロセスの起
動確認とdscontrolコマンドの通信に使用される鍵が壊れていないかを確認して下さい。
(※)dscontrolコマンドとdsserver間にてSSLによる暗号化通信が実施されてます。IPアドレスを変更した場合に発
生する事がございますので、ご注意下さい。
100
ケース3： Manager Reportで全サーバー「-1」を返す (1/7)
„
クラスター・アドレスはDispatcherに設定しましたか？
‹
ネットワークインターフェースに正しく登録されているか？
¾
¾
¾
‹
„
[AIX] netstat –in
[Windows] ipconfig /all
[Linux] ifconfig -an
goActive / goStandbyスクリプトを確認して下さい。
[MAC] 割振り先サーバー側の設定は行いましたか？
‹
[Windows/AIX]
‹
[Linux]
¾
¾
¾
割振り先サーバーのループバック・アダプターにクラスター・アドレスを設定して下さい。
割振り先サーバーでiptablesの設定をして下さい
iptables -t nat -A PREROUTING -d <CLUSTER_ADDRESS> -j REDIRECT
101
・ケース3：Manager Reportで全サーバー「-1」を返す
＜クラスター・アドレスはDispactcherに設定しましたか？＞
クラスター・アドレスをネットワークインターフェースに正しく登録されているかを確認して下さい。また、
goActive・goStandbyスクリプトの設定を再度確認して下さい。
＜[MAC]割振り先サーバー側の設定は行いましたか？＞
[WINDOWS/AIX]割振り先サーバーのループバック・アダプターにクラスター・アドレスを設定して下さい。
[Linux]割振り先サーバーでiptablesの設定をして下さい。
詳細につきましては、以下のTechnotesをご参照下さい。
・Technotes - 「Aliasing alternatives for a loopback device when using MAC forwarding for Load
Balancer」
http://www1.ibm.com/support/docview.wss?rs=180&context=SSEQTP&q1%20=iptables&uid=swg21177105&loc=en_
US&cs=utf-8&lang=en
101
ケース3： Manager Reportが全サーバー「-1」を返す (2/7)
„
[MAC]割振り先サーバー側でエキストラ経路の削除を行い
ましたか？
‹
AIX5.1以降は、ループバック・アダプターにエイリアスを設定した際に
不要なエキストラ経路が作成されます
¾
¾
¾
エイリアスのネットマスクを実際のネットマスク(255.255.255.0等)ではなく、255.255.255.255で
設定すればエキストラ経路は作成されません。
実際のネットマスクでエイリアスを設定している場合は、route deleteコマンドでエキストラ経路
を削除します
マシンIP：
192.168.10.10
Cluster：192.168.10.20
netstat -rnでルーティング・テーブルを確認
[/] netstat -rn
Routing tables
Destination
Gateway
Flags
Refs
Route Tree for Protocol Family 2 (Internet):
default
192.168.10.1
UG
2 116730
192.168.10.0
192.168.10.10
UHSb
0
0
192.168.10/24
192.168.10.10
U
3 128811
192.168.10/24
192.168.10.20
U
1
1
192.168.10.1
127.0.0.1
UGHS
8
1946
192.168.10.255 192.168.10.10
UHSb
0
1
127/8
127.0.0.1
U
4
268
Use
If
en0
en0
en0
lo0
lo0
en0
lo0
PMTU Exp Groups
-
- =>
- =>
- 網掛け部がエキストラ経路
-
Route Tree for Protocol Family 24 (Internet
「route v6):
delete 192.168.10/24 192.168.10.20」で削除
::1
::1
UH
0
32
lo0
- -
102
・ケース3：Manager Reportで全サーバー「-1」を返す
＜ [MAC]割振り先サーバー側でエキストラ経路の削除を行いましたか？＞
AIX5.1以降は、ループバック・アダプターにエイリアスを設定した際に不要なエキストラ経路が作成され
ますので、ご注意下さい。
102
ケース3： Manager Reportが全サーバー「-1」を返す (3/7)
„
[MAC]割振り先サーバー側でエキストラ経路の削除を行い
ましたか？
‹
Windows2000では、ループバック・アダプターにエイリアスを設定した
際に不要なエキストラ経路が作成されます
¾
‹
AIXと異なり255.255.255.255のネットマスクでエイリアスの設定はできません
route deleteコマンドでエキストラ経路を削除
¾
¾
再起動の度にエキストラ経路が作成されるので、タスク・スケジューラーに経路削
除スクリプトを作成し登録するなど工夫が必要
route printでルーティング・テーブルを確認
z
網掛けの経路がエキストラ経路「route delete 192.168.10.0 192.168.10.20 」で経路削除
Active Routes:
Network Destination
Netmask
0.0.0.0
0.0.0.0
0.0.0.0
0.0.0.0
192.168.10.0
255.255.255.0
192.168.10.0
255.255.255.0
192.168.10.10
255.255.255.255
192.168.10.20
255.255.255.255
192.255.255.255 255.255.255.255
192.255.255.255 255.255.255.255
127.0.0.0
255.0.0.0
224.0.0.0
224.0.0.0
224.0.0.0
224.0.0.0
255.255.255.255
255.255.255.255
Default Gateway:
192.168.10.1
Gateway
192.168.10.1
192.168.10.1
192.168.10.10
192.168.10.20
127.0.0.1
127.0.0.1
192.168.10.10
192.168.10.20
127.0.0.1
192.168.10.10
192.168.10.20
192.168.10.20
Interface
Metric
192.168.10.10 1
192.168.10.20 1
192.168.10.10 1
192.168.10.20 1
127.0.0.1
1
127.0.0.1
1
192.168.10.10
1
192.168.10.20
1
127.0.0.1
1
192.168.10.10
1
192.168.10.20
1
192.168.10.20
1
マシンIP：192.168.10.10
Cluster：192.168.10.20
103
ケース3：Manager Reportで全サーバー「-1」を返す
＜[MAC]割振り先サーバー側でエキストラ経路の削除を行いましたか？＞
WINDOWS2000では、ループバック・アダプターにエイリアスを設定した際に不要なエキストラ経路が作
成されますので、ご注意下さい。
103
ケース3： Manager Reportが全サーバー「-1」を返す (4/7)
„
[Windows] NICの設定を見直してみましょう
‹
TCP/IPフィルタリングを設定していませんか？
¾
‹
NDは割振り先サーバーのヘルスチェックにpingも使用しています。このため、ICMPプロトコル
が許可されている必要があります。IP プロトコルの Protocol 1(icmp) を許可してください
Broadcom社製Ethernet Adapterを使用している場合
¾
¾
Broadcom社製Ethernet Adapterをご使用の場合は、Ethernet@Wirespeed機能を無効にする
必要があります。
ネットワーク・アダプター・プロパティーの詳細設定で、［Ethernet@Wirespeed］を［None］に設
104
定してください。（デフォルトはYes）
ケース3：Manager Reportで全サーバー「-1」を返す
＜[Windows] NICの設定を見直してみましょう＞
ICMPプロトコルが許可されている必要がありますので、ご注意下さい。また、Broadcom社製Ethernet
Adapterを使用している場合は、 Ethernet@Wirespeed機能を無効にする必要がありますので、ご確認下さ
い。
104
ケース3： Manager Reportが全サーバー「-1」を返す (5/7)
„
[Windows] NICの設定を見直してみましょう
‹
Task/ChecksumのOffload機能を使用していませんか？
¾
Task Offload機能とはOSではなくアダプター･レベルでTCP Checksumの計算を行う機能
です。Dispatcherでこの機能を使うと、Advisor機能が正常に稼動しませんので、無効化し
て下さい
¾
ネットワーク・アダプターの製品によって、呼び方が異なることがありますので
注意してください。
例）Intel Pro 1000CT Network Connection
9
9
9
9
9
TCPセグメンテーションのオフロード
受信IPチェックサムのオフロード
受信TCPチェックサムのオフロード
送信IPチェックサムのオフロード
送信TCPチェックサムのオフロード
105
・ケース3：Manager Reportで全サーバー「-1」を返す
＜[Windows] NICの設定を見直してみましょう＞
Task/ChecksumのOffload機能を使用している場合、無効化にする必要がありますので、ご確認下さい。
105
ケース3： Manager Reportが全サーバー「-1」を返す (6/7)
„
Advisorのリクエストは正しく届いていますか？
‹
割振り先サーバーのアクセスログを確認してください
¾
¾
監視リクエストがちゃんと届いていますか？
200 OKで返していますか？
DispatcherのNFAアドレスからの監視リクエスト
デフォルトは” HEAD / HTTP/1.0”
192.168.10.10 - - [21/Apr/2005:00:51:27 +0900] "HEAD / HTTP/1.0" 200 192.168.10.10 - - [21/Apr/2005:00:51:34 +0900] "HEAD / HTTP/1.0" 200 -
‹
監視リクエスト・監視文字列は正しく設定されていますか？
¾
¾
dscontrol server status ：： で確認
監視リクエスト設定時の注意
z
z
dscontrol file newloadで読み込む
構成ファイルの中での設定
dscontrolプロンプトの中での設定
dscontrol server set ::
adovisorrequest ”GET /TestServlet HTTP/1.0”
adovisorresponse ”SUCCESS”
z
OSのプロンプトから入力するときは
dscontrol server set ::
adovisorrequest “¥”GET /TestServlet HTTP/1.0¥””
adovisorresponse “¥”SUCCESS¥””
„ 以下のように表示されてしまっている場合は、間違い
advisor 要求 ................... ¥"GET /TestServlet HTTP/1.0¥“
advisor 応答 ................... ¥”SUCCESS¥”
サーバー状況:
------------サーバー ................bronze
ポート番号 ..............80
クラスター ..............192.168.10.20
クラスター・アドレス ....192.168.10.20
静止 ....................N
サーバー・アップ ........Y
重み ....................10
固定重み ................N
ルールのスティッキー ....Y
リモート・サーバー ......N
ネットワーク・ルーター・アドレス 0.0.0.0
連結 ....................N
advisor 要求 ............GET /TestServlet HTTP/1.0
advisor 応答 ............SUCCESS
Cookie (クッキー) 値 ....適用なし
クローン ID .............適用なし
106
・ケース3：Manager Reportで全サーバー「-1」を返す
＜Advisorのリクエストは正しく届いていますか？＞
Advisorのリクエストが割振り先サーバーに届いているかを、割振り先サーバーのアクセスログにて確認し
て下さい。また、監視リクエスト・監視文字列が正しく設定されているかを確認して下さい。dscontrol server
status ::コマンドにて以下のように出力されている場合には、正しく設定されておりません。
advisor 要求 ................... ¥"GET /TestServlet HTTP/1.0¥“
advisor 応答 ................... ¥”SUCCESS¥”
106
ケース3： Manager Reportが全サーバー「-1」を返す (7/7)
„
Advisorのレスポンスは正しく返ってきていますか？
‹
アドバイザーのログレベルを５に上げて確認
¾
dscontrol advisor loglevel http 80 5
¾
ログレベル５のアドバイザーログの例
423 17:02:41.894 JST THD (192.168.10.20:80:cube):
send method on socket 48
投げたアドバイザー
>>>GET /test.html HTTP/1.0^M
要求の文字列
Accept: */*^M
User-Agent: IBM_Network_Dispatcher_HTTP_Advisor^M
^M
<<<
423 17:02:41.895 JST THD (192.168.10.20:80:cube):
timeoutreceive method (16) on socket 48
（中略）
423 17:02:41.764 JST THD (192.168.10.20:80:cube):
Sleeping for socket 48 to open.
iSleepTime ....... 128 ms
_iCurrentLoad .... 136 ms
Socketのオープンを待機中
_iTimeoutConnectMs 21000 ms
423 17:02:41.898 JST THD (192.168.10.20:80:cube):
Select to receive - iRc = 1
423 17:02:41.898 JST THD (192.168.10.20:80:cube):
Load is 124
監視している文字列
423 17:02:41.894 JST THD (192.168.10.20:80:cube):
isSocketOpen() checking thread status:
CMN_OpenSocketThread:
Target(Cluster/Server) .. 192.168.10.20
Socket .................. 48
Port .................... 80
SleepTimeMs ............. 80
Status .................. Success
Initialized ............. true
KillMeNow ............... false
Object Counts ........... 326/2/326
423 17:02:41.898 JST HTTPAdvisorResponse string : SUCCESS
423 17:02:41.898 JST HTTPReceivedData string : HTTP/1.1 200 OK^M
Date: Sat, 23 Apr 2005 07:51:44 GMT^M
Server: IBM_HTTP_SERVER/1.3.19.6 Apache/1.3.20 (Unix)^M
Last-Modified: Sat, 23 Apr 2005 07:51:32 GMT^M
ETag: "cce-72-4269fe84"^M
Accept-Ranges: bytes^M
Content-Length: 114^M
返ってきたレスポンスの文字列
Connection: close^M
・監視文字列が含まれているか？
Content-Type: text/html^M
^M
<HTML>
<HEAD><TITLE>HealthCheckPage</TITLE></HEAD>
<BODY> DB Access is SUCCESS ! All works well! </BODY>
</HTML>
423 17:02:41.894 JST THD (192.168.10.20:80:cube):
Socketがオープンできた
Advisor socket 48 opened.
423 17:02:41.898 JST THD (192.168.10.20:80:cube):
doRun: After getLoad. Returned 0.
423 17:02:41.894 JST THD (192.168.10.20:80:cube):
doRun: Calling getLoad.
423 17:02:41.898 JST THD (192.168.10.20:80:cube):
doRun: returning.
423 17:02:41.894 JST THD (192.168.10.20:80:cube):
doRun: Calling getLoad.
423 17:02:41.898 JST THD (192.168.10.20:80:cube):
The load returned: 124, the current load: 124
423 17:02:41.893 JST THD (192.168.10.20:80:cube):
isSocketWaiting/_thNativeSocketThread.getStatus() = Success
正の値を返している
107
・ケース3：Manager Reportで全サーバー「-1」を返す
＜Advisorのレスポンスは正しく返ってきていますか？＞
Advisorのレスポンスが正しく返ってきているかは、アドバイザーのログレベルを5に上げて確認して下さ
い。上記にサンプル出力を添付させて頂きます。
107
ケース4：割振りが行われない (1/3)
„
Dispatcherにパケットは届いていますか？
‹
誰がクラスター・アドレスに応答しているか確認する
1.
Dispatcherと同一ネットワークに存在するマシンからクラスター・アドレスにPing
[/] ping cluster.internal.com
PING cluster.internal.com: (192.168.10.20): 56 data bytes
64 bytes from 192.168.10.20: icmp_seq=0 ttl=255 time=0 ms
64 bytes from 192.168.10.20: icmp_seq=1 ttl=255 time=0 ms
64 bytes from 192.168.10.20: icmp_seq=2 ttl=255 time=0 ms
2.
クラスター・ア
ドレスは正し
くDispatcher
に解決されて
いますか？
Pingを発行したマシンのARPテーブルを確認
[/] arp -a | more
cluster.internal.com (192.168.10.20) at 8:0:5a:f8:63:91 [ethernet] stored in bucket 19
web2.internal.com (192.168.10.31) at 0:60:94:a3:8a:6d [ethernet] stored in bucket 20
web3.internal.com (192.168.10.33) at 0:2:55:76:16:4 [ethernet] stored in bucket 28
proxy.internal.com (192.168.10.11) at 0:6:29:4:5b:be [ethernet] stored in bucket 30
? (192.168.10.1) at 0:e:38:91:a2:41 [ethernet] stored in bucket 66
・・・
DispatcherマシンのMACアドレスを確認するには、Dispatcherマシン上でnetstat -inを
実行します。
¾
[/] netstat
Name Mtu
en0
1500
en0
1500
lo0
16896
lo0
16896
lo0
16896
-in
Network
link#2
192.168.10
link#1
127
::1
Address
8.0.5a.f8.63.91
192.168.10.20
127.0.0.1
Ipkts Ierrs
5602361
5602361
22553
22553
22553
0
0
0
0
0
Opkts Oerrs
457932
457932
22625
22625
22625
Coll
0
0
0
0
0
0
0
0
0
0
108
・ケース4：割振りが行われない
＜Dispatcherにパケットは届いていますか？>
誰がクラスター・アドレスに応答しているかを確認する為、以下を実施して下さい。
1.Dispatcherと同一ネットワークに存在するマシンからクラスター・アドレスにPing
2. Pingを発行したマシンのARPテーブルを確認
108
ケース4：割振りが行われない (2/3)
„
割振り先サーバー側の仮想ホストの設定は正しいですか？
‹
割振り先サーバー側で仮想ホストを設定したり、ListenするIPアドレス
を限定する場合、Dispatcherのパケットがどのように変換されている
か考える必要があります。
¾
„
„
„
MAC転送方式の場合は、宛先IPアドレスは変換されませんので、仮想ホストはク
ラスター・アドレスで設定する必要があります
[MAC] エキストラ経路の削除は行いましたか？
[MAC] 割振り先サーバー側での設定は行いましたか？
[NAT/KCBR]ReturnAddressは正しく付けられていますか？
‹
‹
NAT転送方式、KCBR転送方式では割振り先サーバーへのリクエスト
の送信、および割振り先サーバーからのレスポンスの受信ために
ReturnAddressが必要です。
構成ファイルの中で、指定したReturnAddressがDispatcher筐体上に
正しく設定されていますか？
109
・ケース4：割振りが行われない
＜割振り先サーバー側の仮想ホストの設定は正しいですか？＞
転送方式により異なりますが、Dispatcherのパケットがどのように変換されているかを確認して下さい。
＜[MAC] エキストラ経路の削除は行いましたか？＞ →ケース3をご参照下さい。
＜[MAC] 割振り先サーバー側での設定は行いましたか？＞→ケース3をご参照下さい。
＜[NAT/KCBR]ReturnAddressは正しく付けられていますか？＞
構成ファイルの中で、指定したReturnAddressがDispatcher筐体上に正しく設定されているかを確認して
下さい。
109
ケース4：割振りが行われない (3/3)
„
ネットワーク・トレースでどこまでパケットが届いているか
確認してください。
‹
以下の2箇所にネットワーク・トレースを仕掛ける
¾ Dispatcherマシン
¾ 割振り先サーバー
Dispatcher
‹
IHS
どこでパケットが行方不明になっているのか切り分けて下さい
1.
2.
3.
4.
5.
クラスター・アドレス宛にパケットが届いているか？
割振り先サーバーにパケットは送っているか？
IHSにパケットは届いているか？
IHSからレスポンスは正しく返っているか？
Dispatcherからパケットは正しく返っているか？
110
・ケース4：割振りが行われない
＜ネットワーク・トレースでどこまでパケットが届いているかを確認して下さい＞
Dispatchedrマシンと割振り先サーバーにてネットワーク・トレースを仕掛け、どこでパケットが行方不明に
なっているかを確認して下さい。
110
ケース5： Takeoverが正常に完了しない
„
goActive/goStandbyが正しく設定されているかご確認下さい
‹
„
[Unix] 各スクリプトに実行権限があることを確認してください
障害時にdsserverのjavaプロセスは存在しましたか？
‹
goActive/goStandby各スクリプトの呼出しはjavaプロセスによって行
われるため、プロセスもダウンしていた場合はTakeoverが発生しませ
ん
111
・ケース5： Takeoverが正常に完了しない
＜goActive/goStandbyが正しく設定されているかご確認下さい＞
各スクリプトの設定内容、実行権限等を再度ご確認下さい。
＜障害時にdsserverのjavaプロセスは存在しましたか？＞
プロセスダウン時に、dserverのjavaプロセスが存在したかどうかを確認して下さい。
111
ケース6：意図しないTakeoverが発生する
„
Dispatcherマシン上でNTPが動いていませんか？
‹
HA構成時に、Heartbeatにより正副機相互で監視を行うロジックの中でシステム時間
が使われており、NTP（Network Time Protocol)により時間の調整が行われると、予期
せぬTakeoverの原因となることがあります。
¾
„
NTPをsleuthモードで稼動させることにより、許容される時間の変更幅を0.1秒以内に抑えれば
Dispatcherは問題なく稼動すると考えられますが、NTPが原因で発生した問題は、Best Effort
でのサポートとなります。
NTPを停止しても問題が解消しない場合
‹
Heartbeat間隔を広げ、 Heartbeatの断絶の可能性を減らします
¾
dscontrol executor set hatimeout <断絶を許容する秒数（デフォルト２）>
z
‹
Heartbeatを2重化し、Heartbeatの断絶の可能性を減らします
¾
‹
広げすぎると障害発生時の検知が遅くなりますので注意が必要です
Heartbeatを2重化した際にはReachabilityの設定が必要になります
Heartbeatを行っているポートのネットワークトレースを採取します
¾
¾
正しくHeartbeatが行われているか確認してください
Heartbeatは0.5秒間隔で送られているGREというパケットです
112
・ケース6：意図しないTakeoverが発生する
＜Dispatcherマシン上でNTPが動いていませんか？>
HA構成時に、Heartbeatにより正副機相互で監視を行うロジックの中でシステム時間が使われており、
NTP(Network Time Protocol)により時間の調整が行われると、予期せぬTakeoverが発生する事がありま
す。
詳細は、以下のTechnoteをご確認下さい。
・Technotes - 「Network Time Protocol support with WebSphere Edge Components」
http://www-1.ibm.com/support/docview.wss?rs=180&context=SSEQTP&q1=NTP&uid=
swg21178386&loc=en_US&cs=utf-8&lang=en
＜NTPを停止しても問題が解消しない場合＞
以下の対策を実施してみて下さい。
・Heartbeat間隔を広げ、 Heartbeatの断絶の可能性を減らします
・Heartbeatを2重化し、Heartbeatの断絶の可能性を減らします
・Heartbeatを行っているポートのネットワークトレースを採取します
112
ケース7：セッションが維持できない
„
IPStickyを使用している場合
‹
‹
„
携帯電話や一部プロバイダーからのリクエストはラウンド・ロビン・プ
ロキシーを通過してくるものがあります
ラウンド・ロビン・プロキシーを通過してきている場合、IPStickyでは
セッションを維持できませんので、CookieやURL再書き込みでセッショ
ンを維持する必要があります
Cookieを使用している場合
‹
Cookieはリクエストに含まれていますか？
¾
‹
Cookieを発行する側の設定
¾
‹
クライアントのブラウザの設定を確認してください。
Cookieのパスは明示的に指定されていますか？
PassiveCookieの設定が正しくできていますか
¾
Cookie名前、Cookie値にスペルミスなどありませんか？
z
z
dscontrol rule status :: でCookie名の確認
dscontrol server status :: でCookie値の確認
113
・ケース7：セッションが維持できない
＜IPStickyを使用している場合>
ラウンド・ロビン・プロキシーを通過している場合、IPStickyではセッションを維持できませんので、ご注意下さい。
＜Cookieを使用している場合＞
以下の観点から、ご確認下さい。
・Cookieはリクエストに含まれていますか？
・Cookieを発行する側の設定
・PassiveCookieの設定が正しくできていますか
(参考)セッションアフィニティについて
・IPSticky（MAC、NAT/NAPT転送方式）
負荷分散装置がクライアントのIPアドレスを覚えていてアフィニティを維持する。
・PassiveCookie（KCBR転送方式、CBRコンポーネント）
割振り先サーバー側で発行したCookie を利用してアフィニティを維持する。
・ActiveCookie（CBRコンポーネント）
CBR自身が発行するCookieを利用してアフィニティを維持する。
・SSLSessionID（KCBR転送方式）
SSLのHandshake中に生成されるIDを用いてアフィニティを維持する。
クライアントがInternetExplorerの環境では使用できません。
113
ケース8：割振りが偏る
„
割振り先サーバーのアクセス・ログを確認してみて下さい
‹
‹
„
複数のIPアドレスからのアクセスですか？
特定IPからのアクセスではないですか？
Dispatcherの前段にProxyServerが存在する場合など、特定
のIPからしかリクエストが来ない場合には、IPStickyは使用
できません。
114
・ケース8：割振りが偏る
＜割振り先サーバーのアクセス・ログを確認してみて下さい＞
複数のIPアドレスからのアクセスはないか、特定のIPからのアクセスではないかを確認して下さい。また、
Dispatcherの前段にProxyServerが存在する場合など、特定のIPからしかリクエストが来ない場合には、
IPStickyは使用出来ませんので、ご注意下さい。
114
ケース9：接続数が異常に多い
„
通常時と比べ、異常
な数ではないか？
Manager Reportで表示される接続数が異常な値を示す
‹
‹
特定の時間のみ、突然に接続
数が急増したのであれば、 ------------------------------------------------------------------|
clsuter.com
| WEIGHT | ACTV | NEWC | PORT | SYS |
|
PORT:
80
|NOW NEW|
49% |
50% |
1% |
0% |
攻撃されている可能性も
------------------------------------------------------------------|
server1 | 10 10 |
141 |
0 |
-1 |
0 |
あります。
|
server2 | 10 10 |
283 |
0 |
-1 |
0 |
|
sorryServer | 10 10 |
926 |
273 |
-1 |
0 |
------------------------------------------------------------------SYNフラッド攻撃
¾
¾
DoS攻撃の手法の一つで、確立しないTCP接続を大量に試みる攻撃
接続の確立時の３ウェイ・ハンド・シェイクにおいて、SYNを大量に送りつけるが、
サーバー側からのSYN/ACKにはACKを返さず、サーバー側には不完全な接続
が滞留し、新たな接続が受けつけれない状況となる
SYN
SYN/ACK
netstat –anで接続情報を表示
し、”SYNRCVD”のステータス
が異常に多いようであれば、
DoS攻撃の可能性あり
ACK
¾
Dispatcherでは攻撃を止めることはできないが、特定のIPからのみSYN攻撃を
受けているのであれば、IPルールでパケットをDropすることは可能
z
IPルールを設定し、ルールの割振り先サーバーに何も指定しない
115
・ケース9：接続数が異常に多い
＜Manager Reportで表示される接続数が異常な値を示す＞
特定の時間のみ、突然に接続数が急増したのであれば、外部から攻撃されている可能性があります。SYNフ
ラッド攻撃について、上記に纏めましたので、ご確認下さい。
115
通信データ問題判別
通信データ解析
‡ ipパケットの確認 - iptrace
‡ ipパケットの確認 - WireShark
‡ ieHTTPHeaders
116
116
IPパケットの確認 - iptrace
„
ネットワークを流れるパケットをキャプチャするコマンド（AIX）
‹
‹
‹
iptraceコマンドでキャプチャを開始し、killコマンドで停止
ipreportコマンドによりフォーマット
iptraceの一例
¾
¾
¾
¾
¾
‹
-a : ARPパケットを除く
-b : 双方向のパケットを記録
-d : パケット送信先を指定
-s : パケット受信元を指定
-p : ポート番号を指定
9.170.251.98から9.188.52.71の80番ポートにアクセスする、
ARPパケットを除いた双方向のパケットについてキャプチャ
ipreportの一例
¾
¾
-n : パケット出力の先頭にパケット番号を記載
-s : 各行先頭にプロトコルを記載
（iptraceコマンド実行）
host1@root[/usr/IBMIHS60]iptrace -ab -d 9.188.52.71 -s 9.170.251.98 -p 80 /tmp/trace/itrace
（プロセス番号確認）
host1@root[/usr/IBMIHS60]ps -ef | grep iptrace
root 38242 1 0 18:28:43
- 0:00 iptrace -ab -d 9.188.52.71 -s 9.170.251.98 -p 80 /tmp/trace/itrace
root 43666 42878 0 18:28:59 pts/4 0:00 grep iptrace
（キャプチャ終了したら、iptraceのプロセス番号をkill）
host1@root[/usr/IBMIHS60]kill -9 38242
（ipreportでフォーマット）
host1@root[/usr/IBMIHS60]ipreport -ns /tmp/trace/itrace > /tmp/trace/ireport
117
クライアントとIHS間、IHSとWAS間でパケットレベルでトレースを取得したい場合に用いられるツールの
一つにiptraceがあります。iptraceはAIXでのみ用いることが出来ます。iptraceは、iptraceコマンドを実行に
よりネットワークを流れるパケットのキャプチャを開始し、killコマンドで停止した後、さらにipreportコマンド
を用いてフォーマットすることで、パケットの様子を知ることが出来ます。iptrace、ipreportコマンド実行時に
よく用いられるオプションは以上の通りです。上記の例では、9.170.251.98から9.188.52.71の80番ポート
にアクセスする、ARPパケットを除いた双方向のパケットについてキャプチャし、さらにそれをipreportコマ
ンドでフォーマットして出力させています。
117
iptraceで取得したパケットトレースファイル
Packet Number 4
ETH: ====( 406 bytes received on interface en0 )====18:29:26.547582540
ETH: [ 00:0e:38:91:a2:41 -> 00:09:6b:2e:93:5d ] type 800 (IP)
IP: < SRC = 9.170.251.98 >
IP: < DST = 9.188.52.71 > (silver2)
IP: ip_v=4, ip_hl=20, ip_tos=0, ip_len=392, ip_id=58485, ip_off=0 DF
IP: ip_ttl=124, ip_sum=d5ea, ip_p = 6 (TCP)
TCP: <source port=4614, destination port=80(http) >
TCP: th_seq=9219e724, th_ack=698ffbb7
TCP: th_off=5, flags<PUSH | ACK>
TCP: th_win=32120, th_sum=9545, th_urp=0
TCP: 00000000 47455420 2f204854 54502f31 2e310d0a |GET / HTTP/1.1..|
TCP: 00000010 41636365 70743a20 696d6167 652f6769 |Accept: image/gi|
TCP: 00000020 662c2069 6d616765 2f782d78 6269746d |f, image/x-xbitm|
TCP: 00000030 61702c20 696d6167 652f6a70 65672c20 |ap, image/jpeg, |
TCP: 00000040 696d6167 652f706a 7065672c 20617070 |image/pjpeg, app|
TCP: 00000050 6c696361 74696f6e 2f766e64 2e6d732d |lication/vnd.ms-|
TCP: 00000060 65786365 6c2c2061 70706c69 63617469 |excel, applicati|
TCP: 00000070 6f6e2f76 6e642e6d 732d706f 77657270 |on/vnd.ms-powerp|
TCP: 00000080 6f696e74 2c206170 706c6963 6174696f |oint, applicatio|
TCP: 00000090 6e2f6d73 776f7264 2c206170 706c6963 |n/msword, applic|
TCP: 000000a0 6174696f 6e2f782d 73686f63 6b776176 |ation/x-shockwav|
TCP: 000000b0 652d666c 6173682c 202a2f2a 0d0a4163 |e-flash, */*..Ac|
TCP: 000000c0 63657074 2d4c616e 67756167 653a206a |cept-Language: j|
TCP: 000000d0 610d0a41 63636570 742d456e 636f6469 |a..Accept-Encodi|
TCP: 000000e0 6e673a20 677a6970 2c206465 666c6174 |ng: gzip, deflat|
TCP: 000000f0 650d0a55 7365722d 4167656e 743a204d |e..User-Agent: M|
TCP: 00000100 6f7a696c 6c612f34 2e302028 636f6d70 |ozilla/4.0 (comp|
TCP: 00000110 61746962 6c653b20 4d534945 20362e30 |atible; MSIE 6.0|
TCP: 00000120 3b205769 6e646f77 73204e54 20352e31 |; Windows NT 5.1|
TCP: 00000130 290d0a48 6f73743a 20392e31 38382e35 |)..Host: 9.188.5|
TCP: 00000140 322e3731 0d0a436f 6e6e6563 74696f6e |2.71..Connection|
TCP: 00000150 3a204b65 65702d41 6c697665 0d0a0d0a |: Keep-Alive....|
Packet Number 5
ETH: ====( 362 bytes transmitted on interface en0 )====18:29:26.557472149
ETH: [ 00:09:6b:2e:93:5d -> 00:0e:38:91:a2:41 ] type 800 (IP)
IP: < SRC = 9.188.52.71 > (silver2)
IP: < DST = 9.170.251.98 >
IP: ip_v=4, ip_hl=20, ip_tos=0, ip_len=348, ip_id=39246, ip_off=0 DF
IP: ip_ttl=60, ip_sum=613e, ip_p = 6 (TCP)
TCP: <source port=80(http), destination port=4614 >
TCP: th_seq=698ffbb7, th_ack=9219e884
TCP: th_off=5, flags<PUSH | ACK>
TCP: th_win=17520, th_sum=0, th_urp=0
パケットの受信元と送信先
受信元と送信先のポート番号
HTTPレスポンスヘッダの内容
118
上は先程の手順でipreportにより出力されたパケットトレースの一部です。クライアントから<SYN>パケット
をリクエストし、サーバーが<SYN | ACK>をレスポンスを返すと言ったHTTP接続の一連の流れも見ること
が出来ますし、HTTPリクエストやレスポンスのヘッダの内容を確認することが出来ます。
118
Wireshark(旧Ethereal)(1/2)
フリーのパケットキャプチャーツール
„
‹
以下のサイトからダウンロード可能
http://www.wireshark.org/
Windows、Linux、Unixといった多くのOSをサポート
„
‹
‹
Wireshark導入マシンのネットワークインターフェースに対してパケットキャプチャーが可能
他OSで取得したネットワークトレースコマンド(tcpdump、iptraceなど)出力も読み込み可能
□ Wireshark導入マシン上のパケットキャプチャー
①｢Capture｣メニューから
｢Interfaces｣を選択
④キャプチャー
したパケットが
表示される
③任意のタイミングで
｢Capture｣メニューから
｢Stop｣を選択
②調査対象インター
フェースを選択し、
｢Start｣をクリック
119
119
Wireshark(旧Ethereal)(2/2)
その他便利な機能
„
‹
‹
任意のTCPストリームを構成する全てのパケットを連結して表示(Follow TCP Stream)
表示するパケットのフィルタリングを実施(Display Filters)
□ Follow TCP Stream
①任意のパケットを
選択し、 ｢Analyze｣
メニューから｢Follow
TCP Stream｣を選択
②任意のパケット
を含むTCPスト
リームがTCPヘッ
ダを除いた形で表
示される
□ Display Filters
①｢Analyze｣メニューから
｢Display Filters｣を選択
②HTTPのみやIPア
ドレスによるフィ
ルタリング表示を
選択可能
任意のフィルタリ
ング定義を作成す
ることも可能
120
120
ieHTTPHeaders
フリーのHTTPヘッダーモニターツール
„
‹
以下のサイトからダウンロード可能
http://www.blunck.se/iehttpheaders/iehttpheaders.html
Internet Explorer(IE)に組み込まれ、リクエスト、レスポンス内
のHTTPヘッダーをリアルタイムに表示
„
‹
‹
IEのツールバーより「表示」→「エクスプローラーバー」→「ieHTTPHeaders」を選択
IEに組み込まれるため、暗号化(HTTPS)通信でもHTTPヘッダーは表示可能
画面上はコンテンツを表示
画面下はリクエスト、レスポンス
のHTTPヘッダーを表示
121
121
おわりに
122
122
このセッションで学習したこと
„
問題判別の心得
‹
„
IHS / WebSphere Application Server問題判別
‹
‹
„
Edgeに関するログ・トレース、症状別問題判別方法について確認しま
した。
通信データ問題判別
‹
„
IHS/WASに関するログ・トレース、JVM問題判別方法、症状別問題判
別方法について確認しました。
各種ツール紹介について確認しました。
Edge Component問題判別
‹
„
確認すべきサイト、情報収集方法について確認しました。
通信データの内容を確認するためのツールについて確認しました。
（参考）Rational Application Developer問題判別
‹
RADの紹介、症状別問題判別、Fix、オプション・フィーチャーの適用
方法について確認しました。
123
123
参考資料
„
WebSphere AS V6.1 Information Center
‹
„
DB2 Information Center
‹
„
http://publib.boulder.ibm.com/infocenter/pseries/index.jsp
WebSphere Developer Domain
‹
„
http://publib.boulder.ibm.com/infocenter/db2luw/v9/index.jsp
pSeries and AIX Information Center
‹
„
http://publib.boulder.ibm.com/infocenter/wasinfo/v6r1/index.jsp
http://www-6.ibm.com/jp/software/websphere/developer/
Diagnostics Guide
‹
http://www.ibm.com/developerworks/java/jdk/diagnosis/index.html
124
124
（参照）Rational Application Developer問題判別
問題判別
‡
‡
‡
‡
Rational Software の製品ポートフォリオ
Rational Application DeveloperV7.0
パッケージ・ライセンス管理
症状別問題判別
125
125
Rational Softwareの製品ポートフォリオ
„
IBM Rational Softeware Delivery Platform（SDP）
126
上記は、Rational Softwareの製品ポートフォリオになります。V7における共通の機能向上は以下になります。
＜Open Computing＞
・Eclipse 3.2.1 & JDK5 に対応
・標準のサポート: Java 5, AJAX, Sun JRE
・Elite support for Eclipse
＜Consumability＞
・最新のIBM ミドルウェアのサポート(WAS 6.1, WP 6.0, UDB 9)
・ライセンス・コンプライアンス: フローティング・ライセンスを指定可能(オプション)
・パフォーマンスとスケーラビリティーの向上
＜Flexibility＞
・新しいインストーラー
・既存のEclipse 上へインストール
・Rose/XDE/Robot 機能のより多くの取り込み
126
Rational Application Developer V7.0
„
Java 開発者を対象に高品質の Java/J2EE, ポータル、 Web, Webサービ
スや SOA アプリケーションの迅速な開発、アセンブル、テスト、プロファ
イル、デプロイをサポートするツール群
‹
インストールするRational Application Developerのフィーチャーを選択するこ
とにより、カスタマイズ可能
‹
Rational Application Developer V7.0の新機能
¾
¾
¾
¾
¾
¾
¾
¾
¾
¾
Eclipse 3.2 およびJDK5への対応
IBMミドルウェアの最新バージョンをサポート (WAS 6.1、WP 6.0、UDB 9)
Webダイアグラム・エディターの強化
JSF開発機能の強化
Webサービス開発のユーザビリティ向上
J2EEセキュリティ・ツールの追加
J2Cサポートの拡大
静的コード・レビューの改善
デバッグ・ツールの強化
ポータル・ツールの新機能
127
Rational Application Developer V7.0は、Java 開発者を対象に高品質の Java/J2EE, ポータル、 Web, Web
サービスや SOA アプリケーションの迅速な開発、アセンブル、テスト、プロファイル、デプロイをサポートする
ツール群になります。インストールするRational Application Developerのフィーチャーを選択することにより、カス
タマイズ可能です。
また、Rational Application Developer V7.0の新機能は、以下になります。
・Eclipse 3.2 およびJDK5への対応
・IBMミドルウェアの最新バージョンをサポート (WAS 6.1、WP 6.0、UDB 9)
・Webダイアグラム・エディターの強化
・JSF開発機能の強化
・Webサービス開発のユーザビリティ向上
・J2EEセキュリティ・ツールの追加
・J2Cサポートの拡大
・静的コード・レビューの改善
・デバッグ・ツールの強化
・ポータル・ツールの新機能
127
パッケージの管理
„
オンライン、オフラインで適用可能
http://www.ibm.com/jp/software/rational/download/ifix/level.html
„
IBM Installation Managerによるパッケージの管理
‹
‹
‹
‹
‹
既存のEclipse環境へプラグインする事で、Rational製品を導入できる
インストールするフィーチャーを選択できる
最新を含め、すべてのバージョンが表示される
適用したいバージョンを選択する
パッケージのアンインストール、ロールバックも可能
128
RADのFix、オプション・フィーチャーの適用はオンライン、オフラインで適用可能です。詳細は、以下をご参照
下さい。
http://www-6.ibm.com/jp/software/rational/download/ifix/index.html
適用の際には、IBM Installation Managerを使用し、パッケージを管理します。非常に便利な機能であり、ネット
ワークにつないでいる場合、自動検出をしてくれます。表示された項目を選択して、適用することが可能です。
また、IBM Installation Manager自身のFixpackも存在しますので、最新版にされます事をお勧め致します。
128
ライセンスの管理
„
IBM Installation Managerによるライセンスの管理
‹
‹
製品導入CDよりアクティベーション・キットを選択し、ライセンスキーを
入力する
評価版をアンインストールすることなく、そのまま製品版へとアップグ
レードできる
129
IBM Installation Managerを使用し、ライセンスを管理します。RADを導入した際には、製品導入CDよりアクティ
ベーション・キッドを選択し、ライセンスキーを入力して下さい。また、評価版をアンインストールすることなく、そ
のまま製品版へとアップグレードする事が出来ます。
129
RAD症状別問題判別
„
どこで起こった問題か切り分ける！！
‹
ツールの使い方が分からない
¾
‹
WASコンソール上でエラーメッセージ
¾
¾
‹
WASの問題判別と同様、コンソールやログより解析を行う
解析の際はPAコールも活用
アプリケーションの障害の場合は、デバッグを行い、バグの発見・修正
ウィザード使用やコンパイル時にエラー
¾
¾
‹
ヘルプ、チュートリアル、Webの記事(WebSphere/Rational Developer Domain etc.)
を参照
まずはツールのFixを当ててみる（次項参照）
org.eclipse.xxxx とトレースで出ていた場合は、ツールの障害である可能性も
再現を確認して、PAコール
ツールのパフォーマンスが遅い
¾
IBM Rational Software Development Platform 製品群 パフォーマンスTips
http://www-6.ibm.com/jp/developerworks/rational/mdd/performance/sdptips.html
上記以外では、
¾
¾
ディスクのデフラグ、ワークスペースの分割も有用
といっても、やはりPCのスペック(CPU/メモリ）を向上させることが一番！！
130
ツールを使用していて、何かおかしいと思ったときの問題判別としては、まず「どこで起こった問題か切り分け
る」必要があります。
ツールの使い方が分からない
ヘルプ、チュートリアル、Webの記事(WebSphere/Rational Developer Domain etc.)を参照して下さい。RADに
は機能がたくさんありますので、これを参照することで解決する場合が多いです。
・WebSphere Developer Domain
http://www-6.ibm.com/jp/software/websphere/developer/
・Rational Developer Domain ～Rational 製品に関する技術情報サイト
http://www-06.ibm.com/jp/developerworks/rational/index.html
・Rational Developer Domainの中のRSDP
http://www-06.ibm.com/jp/developerworks/rational/category/mdd/rsdp/
WebSphere フォーラム（日本語）～RAD、Eclipse、Java 開発に関するオンライン意見交換が可能
http://www.wsdeveloper.com/viewforum.php?f=7&sid=2d9db4ab6dfdda02359973dc11ded37d
WASコンソール上でエラーメッセージ
テスト環境のWASのコンソールでエラーメッセージが表示した場合は、通常のWAS問題判別と同様、コンソー
ルやログより解析を行ってください。アプリケーションの障害の場合は、RADでデバッグを行い、バグの発見・修
正を行うことが出来ます。また、解析の際は必要に応じて、PAコールも利用して下さい。
ウィザード使用やコンパイル時にエラー
まずはツールのパッケージを当ててみることを検討してみて下さい。修正リストに同じような症状があった場合
は、解決する可能性があります。パッケージの適用に関しては次頁を参照してください。org.eclipse.xxxx とト
レースで出ていた場合は、ツール自体の障害である可能性があります。再現を確認して、PAコールして下さい。
ツールのパフォーマンスが遅い
RADで開発する際には、開発ツール&WASテスト環境（その他にはDBMSなど）が同時に稼動することになりま
すので、高スペックのPC環境が必要となります。以下にパフォーマンスTipsがまとめられていますので、パ
フォーマンスが遅いと感じられる場合は、試してみる価値があります。
・IBM Rational Software Development Platform 製品群 パフォーマンスTips
http://www-6.ibm.com/jp/developerworks/rational/mdd/performance/sdptips.html
これ以外には、ディスクのデフラグ、ワークスペースの分割も有用ですが、やはりPCのスペック(CPU/メモリ）を
向上させることが一番の解決策となります。
130