3.6.2 システムログを使用した異常原因の調査方法(非同期)

システムがダウンした場合、業務データのメッセージはキューに滞留、またはフロー定義の異常処理定義に従って異常処理が行われています。
業務データのメッセージを以下の手順で確認し、リカバリを行ってください。

OSのシステムログを確認し、エラーメッセージが出力されている場合は、メッセージ集の対処に従い、対処してください。
標準ログを、“Error-”および“IBS-AP-SYSTEM”という文字列で検索してください。
2の検索でログが抽出された場合、フロー定義の異常処理定義に従って、異常処理が行われています。異常処理が行われている業務データのメッセージを検索したログから確認し、コマンドでリカバリを行ってください。
その後、システムを再起動した後、リカバリした業務データのメッセージが、フロー定義に従って正しく遷移されていることを確認してください。標準ログを用いて確認する場合は、リカバリした業務データのコリレーションIDと“IBS-AP-SYSTEM”という文字列を利用して検索し、目視で確認してください。

3.6.2.2 システムがハングアップし、メッセージが結果受信JMSキューおよびフロー定義の終点に届かなかった場合

システムがハングアップした場合、業務データのメッセージはキューに滞留、またはフロー定義の異常処理定義に従って異常処理が行われています。
業務データのメッセージを以下の手順で確認し、リカバリを行ってください。

OSのシステムログを確認し、エラーメッセージが出力されている場合は、メッセージ集の対処に従い、対処してください。
標準ログを、“Error-”および“IBS-AP-SYSTEM”という文字列で検索してください。
2の検索でログが抽出された場合、フロー定義の異常処理定義に従って、異常処理が行われています。異常処理が行われている業務データのメッセージを検索したログから確認し、コマンドでリカバリを行ってください。
2の検索でログが抽出されなかった場合、業務データのメッセージがフロー定義の遷移途中でキューに滞留している可能性があります。結果受信キューまたはフロー定義の終点に届いていないメッセージを確認し、そのコリレーションIDをキーにして、標準ログを検索してください。抽出されたログの最後が、業務データのメッセージの現在の状況を表します。それに従い、対処を行ってください。
システムを再起動した後、リカバリしたメッセージがフロー定義に従って正しく遷移されていることを確認してください。標準ログを用いて確認する場合は、リカバリした業務データのコリレーションIDと“IBS-AP-SYSTEM”という文字列を利用して検索し、目視で確認してください。

3.6.2.3 異常処理JMSキューに退避されたメッセージをリカバリ後に、実際に再送されたかどうかを確認する場合

“Error-EvacuateMessage-ErrorQueue”という文字列をキーにし、標準ログからログを検索します。
以下に、ログを検索する例を示します。
2004/11/20 19:07:11.121 [ContextID] IBS-AP-SYSTEM Error-EvacuateMessage-ErrorQueue 8028 [Queue001] FlowA ID0001 ***** ***** ***** ***** ErrorMessage ***** *****

1で抽出したログのコリレーションID“ID001”、および“IBS-AP-SYSTEM”という文字列をキーにし、標準ログからログを検索します。
抽出されたログの中から、“Error-EvacuateMessage-ErrorQueue”という文字列がある行の周辺のログを以下に示します。
“Error-EvacuateMessage-ErrorQueue”がある行を太字にしています。

2004/11/20 19:07:11.000 [ContextID] IBS-AP-SYSTEM Apfw-Activity-Start 8025 [Queue001] FlowA ID0001 ***** ***** ***** ***** Normal ***** *****
2004/11/20 19:07:11.002 [ContextID] IBS-AP-SYSTEM Business-Application-Call 8017 [Queue001] FlowA ID0001 BusinessApp BusinessApplication JavaApplication ***** Normal ***** *****
2004/11/20 19:07:11.002 [ContextID] IBS-AP-SYSTEM Business-Application-Call 8017 [Queue001] FlowA ID0001 BusinessApp.throwException BusinessApplication JavaApplication ***** Normal ***** *****
2004/11/20 19:07:11.110 [ContextID] IBS-AP-SYSTEM Business-Application-Error 8019 [Queue001] FlowA ID0001 BusinessApp.throwException BusinessApplication JavaApplication ***** Normal FSP_INTS-BAS_AP: エラー: 1258: 業務処理実行アプリケーションのメソッドから例外が発行されました: フロー定義名=FlowA, コリレーションID=ID0001, アプリケーション=処理1, クラス名=BusinessApp, メソッド名=throwException(java.lang.Integer, java.lang.String, java.lang.String), 例外情報=java.lang.NullPointerException] *****
2004/11/20 19:07:11.110 [ContextID] IBS-AP-SYSTEM Business-Application-Error 8019 [Queue001] FlowA ID0001 BusinessApp BusinessApplication JavaApplication ***** Normal ***** *****
2004/11/20 19:07:11.111 [ContextID] IBS-AP-SYSTEM Apfw-Activity-End 8027 [Queue001] FlowA ID0001 ***** ***** ***** ***** Normal ***** *****
2004/11/20 19:07:11.121 [ContextID] IBS-AP-SYSTEM Error-ErrorProcess-Start 8033 [Queue001] FlowA ID0001 ***** ***** ***** ***** ErrorMessage ***** *****
2004/11/20 19:07:11.121 [ContextID] IBS-AP-SYSTEM Error-EvacuateMessage-ErrorQueue 8028 [Queue001] FlowA ID0001 ***** ***** ***** ***** ErrorMessage ***** *****
2004/11/20 19:07:11.122 [ContextID] IBS-AP-SYSTEM Message-sendMessageQueue-Call 8021 [Queue001] FlowA ID0001 ***** ***** ***** EvacuateErrorQueueRoute ErrorMessage ***** ErrorQueue
2004/11/20 19:07:11.210 [ContextID] IBS-AP-SYSTEM Message-sendMessageQueue-Normal 8022 [Queue001] FlowA ID0001 ***** ***** ***** EvacuateErrorQueueRoute ErrorMessage ***** ErrorQueue
2004/11/20 19:07:11.210 [ContextID] IBS-AP-SYSTEM Error-ErrorProcess-End 8034 [Queue001] FlowA ID0001 ***** ***** ***** ***** ErrorMessage ***** *****
2004/11/20 19:23:34.820 [ContextID] IBS-AP-SYSTEM Apfw-Activity-Start 8025 [Queue001] FlowA ID0001 ***** ***** ***** ***** Normal ***** *****
2004/11/20 19:23:34.822 [ContextID] IBS-AP-SYSTEM Business-Application-Call 8017 [Queue001] FlowA ID0001 BusinessApp BusinessApplication JavaApplication ***** Normal ***** *****
2004/11/20 19:23:34.824 [ContextID] IBS-AP-SYSTEM Business-Application-Call 8017 [Queue001] FlowA ID0001 (java.lang.String)setData(java.lang.Boolean) BusinessApplication JavaApplication ***** Normal ***** *****
2004/11/20 19:23:34.843 [ContextID] IBS-AP-SYSTEM Business-Application-Normal 8018 [Queue001] FlowA ID0001 (java.lang.String)setData(java.lang.Boolean) BusinessApplication JavaApplication ***** Normal ***** *****
2004/11/20 19:23:34.843 [ContextID] IBS-AP-SYSTEM Business-Application-Normal 8018 [Queue001] FlowA ID0001 BusinessApp BusinessApplication JavaApplication ***** Normal ***** *****
2004/11/20 19:23:34.844 [ContextID] IBS-AP-SYSTEM Message-sendMessageQueue-Call 8021 [Queue001] FlowA ID0001 ***** ***** ***** NormalRoute Normal ***** Queue2
2004/11/20 19:23:34.912 [ContextID] IBS-AP-SYSTEM Message-sendMessageQueue-Normal 8022 [Queue001] FlowA ID0001 ***** ***** ***** NormalRoute Normal ***** Queue2
2004/11/20 19:23:34.912 [ContextID] IBS-AP-SYSTEM Apfw-Activity-End 8027 [Queue001] FlowA ID0001 ***** ***** ***** ***** Normal ***** *****

目視で、“Error-EvacuateMessage-ErrorQueue”という文字列がある行より後のログを確認します。“Error-ErrorProcess-End”という文字列のある行が、異常処理を終了したことを示し、メッセージ退避処理そのものが終了したことを示します。その次の“Apfw-Activity-Start”という文字列がある行が、メッセージ再送による処理が開始されたことを示し、正しく再送できたことが確認できます。この行の時間は、メッセージ再送処理を行った時間と同じになります。

3.6.2.4 通常ルートと代行ルートのキューがともに閉塞しているため、フロー定義の途中でメッセージ送信処理が停止していることを確認する場合

“IBS-AP-SYSTEM”、調査対象のメッセージのコリレーションID、および“Error”という文字列で標準ログからログを検索します。
以下のようなログが抽出されます。

2004/11/20 21:34:04.243 [ContextID] IBS-AP-SYSTEM Message-sendMessageQueue-Error 8023 [Queue001] FlowA ID0001 ***** ***** ***** NormalRoute Normal  FSP_INTS-BAS_AP: エラー: 1509: メッセージの送信でエラーが発生しました。（エラー情報=UX:JMS:エラー:jms2573: イベントチャネルは閉塞状態のため利用できません。 METHOD 'ChannelUtil.local_begin', EXCEPTION 'org.omg.CORBA.NO_RESOURCES: CORBA_Request_get_response  vmcid: 0x464a0000  minor code: 2491  completed: No',JMSDestination名=Queue002） Queue002  (注1)
2004/11/20 21:34:04.341 [ContextID] IBS-AP-SYSTEM Message-sendMessageQueue-Error 8023 [Queue001] FlowA ID0001 ***** ***** ***** AgencyRoute Normal  FSP_INTS-BAS_AP: エラー: 1509: メッセージの送信でエラーが発生しました。（エラー情報=UX:JMS:エラー:jms2573: イベントチャネルは閉塞状態のため利用できません。 METHOD 'ChannelUtil.local_begin', EXCEPTION 'org.omg.CORBA.NO_RESOURCES: CORBA_Request_get_response  vmcid: 0x464a0000  minor code: 2491  completed: No',JMSDestination名=Queue003） Queue003  (注2)
2004/11/20 21:34:04.409 [ContextID] IBS-AP-SYSTEM Message-sendMessageQueue-Error 8023 [Queue001] FlowA ID0001 ***** ***** ***** NormalRoute Normal  FSP_INTS-BAS_AP: エラー: 1509: メッセージの送信でエラーが発生しました。（エラー情報=UX:JMS:エラー:jms2573: イベントチャネルは閉塞状態のため利用できません。 METHOD 'ChannelUtil.local_begin', EXCEPTION 'org.omg.CORBA.NO_RESOURCES: CORBA_Request_get_response  vmcid: 0x464a0000  minor code: 2491  completed: No',JMSDestination名=Queue002） Queue002  (注1)
2004/11/20 21:34:04.534 [ContextID] IBS-AP-SYSTEM Message-sendMessageQueue-Error 8023 [Queue001] FlowA ID0001 ***** ***** ***** AgencyRoute Normal  FSP_INTS-BAS_AP: エラー: 1509: メッセージの送信でエラーが発生しました。（エラー情報=UX:JMS:エラー:jms2573: イベントチャネルは閉塞状態のため利用できません。 METHOD 'ChannelUtil.local_begin', EXCEPTION 'org.omg.CORBA.NO_RESOURCES: CORBA_Request_get_response  vmcid: 0x464a0000  minor code: 2491  completed: No',JMSDestination名=Queue003） Queue003  (注2)

注1) “NormalRoute”という文字列が示されている行のログが、通常ルートの遷移先キュー“Queue002”が閉塞されているため、エラーが発生していることを示します。
注2) “AgencyRoute”という文字列が示されている行のログが、代行ルートの遷移先キュー“Queue003”が閉塞されているため、エラーが発生していることを示します。
これによって、通常ルートおよび代行ルートがメッセージ遷移途中でキュー閉塞し、それぞれ2回ずつ閉塞事象が発生していたために、本例では時間がかかったことがわかります。
ほかにも、メッセージIDなどを検索キーに組み合わせることにより、任意のログを抽出することが可能です。

3.6.2.5 シリアライズファイル化されたメッセージ数、およびどのアクティビティでエラーが発生したかを確認する場合

ログの検索方法	抽出されたログの見方	エラーへの対処
“Error-EvacuateMessage-SeriarizeFile”という文字列で標準ログからログを検索します。	抽出されたログの数が、シリアライズファイル化されたメッセージ数となります。また、それぞれのログの行にある“アクティビティのキューDestination名”がアクティビティに関連付けられたキュー名、“フロー定義名”がフロー定義名を表します。	抽出されたログの前後を目視で確認して、エラー原因を示すログのメッセージの対処を行ってください。業務データを修正する必要がない場合には、apfwrecovmsgコマンドでエラーメッセージをリカバリしてください。また、業務データを修正する場合には、apfwconvfileコマンドで、エラーメッセージをメッセージファイル化してから、エディタ等で修正し、apfwrecovfileコマンドでリカバリしてください。

3.6.2.6 退避されたメッセージ数を確認する場合

ログの検索方法	抽出されたログの見方	エラーへの対処
“Error-EvacuateMessage-ErrorQueue”という文字列で標準ログからログを検索します。	抽出されたログの数が、退避されたメッセージ数となります。メッセージの詳細については、apfwlistmsgコマンドで確認してください。	抽出されたログの前後を目視で確認して、エラー原因を示すログのメッセージの対処を行ってください。業務データを修正する必要がない場合には、apfwrecovmsgコマンドでエラーメッセージをリカバリしてください。また、業務データを修正する場合には、apfwconvfileコマンドで、エラーメッセージをメッセージファイル化してから、エディタ等で修正し、apfwrecovfileコマンドでリカバリしてください。

3.6.2.7 異常が発生した業務処理実行アプリケーションを確認する場合

ログの検索方法	抽出されたログの見方	エラーへの対処
“Business-Application”および任意のクラス名をキーとし、標準ログからログを検索します。	抽出されたログが、任意のアプリケーションのログとなります。“Business-Application-Error”とあった場合、エラーが発生しています。抽出したログの前後を目視で確認し、動作を確認してください。	“Business-Application-Error”とあった場合は、そのエラーの原因となった例外情報が同じログの行に出力されます。その例外情報の対処を行ってください。

3.6.2.8 業務処理実行アプリケーションから処理が復帰せず、メッセージ処理が止まってしまった場合に、業務処理実行アプリケーション名を確認する場合

ログの検索方法	抽出されたログの見方	エラーへの対処
復帰しないメッセージのコリレーションID、および“IBS-AP-SYSTEM”という文字列でログを検索します。	抽出されたログの、最後の行を確認してください。 “Business-Application-Call”という採取契機のログが抽出されているはずですので、同じ行の業務処理実行アプリケーション名を確認してください。	エラーとなっている業務処理実行アプリケーションが配備されているワークユニットを停止してから、業務処理実行アプリケーションの処理を確認してください。業務処理実行アプリケーションを修正した場合は、配備ファイルを再作成し、再配備を行ってから、ワークユニットを再起動してください。