実行時間超過への対応

事象説明

各サーバプロセスの制御スレッドでオペレーションの実行時間を常に監視しています。WebOTX V8では既定値で実行時間の上限を超過した場合、情報出力を行うための警告メッセージ出力機能を提供しています。運用管理ツールで「実行時間の上限」を設定し、かつ「プロセスを強制停止する」設定を行っている場合、各オペレーションの処理時間がこの時間を超えるとプロセスを終了します。
プロセスを強制停止する設定で実行時間の上限を超えた時、その時点で実行中のスレッドがあった場合は実行中のスレッドの処理が完了するまでプロセス停止を待ち合わせます。停止を待ち合わせる時間は既定値で600秒です。600秒を経過しても実行中のスレッドが存在する場合、スレッドの処理を強制終了してプロセス再起動処理が実行されます。

状況の確認方法

既定値(プロセス再起動の無の設定)で実行時間超過が起きた場合、イベントログ・syslogにはINFOレベルで以下のメッセージが出力されます。

OTXM:<システム名>:<プロセスグループ名>:<プロセスID>: I:1:TPS10-13302 Tx ELAPSED TIME:xx SEC. TX-GROUP <プロセスグループ名> <プロセスID>

プロセス再起動の有の設定で実行時間超過が起きプロセスが終了した場合、イベントログ・syslogには以下のメッセージが出力されます。

OTXM:<システム名>:<プロセスグループ名>:<プロセスID>: E:1:TPS10-13301 Tx TIME OVER ERROR. CODE:1 TX-GROUP <プロセスグループ名> <プロセスID>

また、クライアントアプリケーションにはNO_RESPONSE(3927)のエラーを返します。

問題の検出方法

イベントログ・syslogの監視

TPS10-13301、TPS10-13302で始まるメッセージを監視してください。

採取資料

イベントログ(アプリケーション、システム)・syslog
APログ : ${INSTANCE_ROOT}/logs/tpsystem/<アプリケーショングループ名>/<プロセスグループ名 >/save/<プロセスグループ名>.<数字>.<PID>.log
システムトレース : ${INSTANCE_ROOT}/logs/tpsystem/<アプリケーショングループ名>/<プロセスグループ名>/save/<プロセスグループ名>_sys.<数字>.<PID>.log
${INSTANCE_ROOT}/logs/tpsystem/history.act、history.<数字>
${INSTANCE_ROOT}/logs/tpsystem/sysmsg.trc、sysmsg.<数字>
イベントジャーナル : ${INSTANCE_ROOT}/logs/tpsystem/logcollect

原因の特定

イベントログ・syslogに出力される、TPS10-13301、TPS10-13302のメッセージから該当のプロセスグループを特定します。

(1) 実行時間超過が発生した場合は、システムトレースに実行途中であったオペレーションの情報が以下のように記録されます。システムトレースについては [ ドメイン構築・基本設定ガイド > 8. ログ > 8.2. 各サービスのログ > 8.2.11. TPモニタ > 8.2.11.3. ${PGNAME}_sys.${PID}.log ] を参照してください。

Error: The following TX execution is unfinished.
-------------------------------------
PID ThID TxID StartTime
-------------------------------------
03761 00001 QKAAAC 7/15 10:19:09.703
QKAAAC: LoopBack (IDL:sample/LoopBackSample:1.0;loopback_jsv.jar)

実行時間超過が発生したオペレーションはオペレーション名LoopBack、インタフェース名IDL:sample/LoopBackSample:1.0、モジュール名loopback_jsv.jar であることがわかります。

(2) AP ログに以下のように出力されます。

TPS10-13301 Tx TIME OVER ERROR. CODE:x TX-GROUP <プロセスグループ名> <プロセスID> elptime-over info : TXID=AAABAB,…

このAP ログのTXID から実行時間超過が発生したオペレーションを特定できます。TXID とオペレーション名の関連を調べるためにイベントジャーナルを採取してください。イベントジャーナルは統合運用管理ツールのTP システムを右クリックし、「イベントジャーナルとキュー滞留数の採取」の実行で採取できます。実行すると、${INSTANCE_ROOT}/config/tpsystem/tmp ディレクトリにotx.t2o ファイルが作成され、その中にTXID とオペレーションの対応関係が記載されています。

該当AP がJava の場合、実行時間超過が発生するとシステムトレースにスタックトレースが記録されます。これより対象コードが特定できます。