オペレーション遅延への対応

事象説明

    以前に比べて応答が遅くなったことをここでは遅延として扱いますが、システム構築段階で試行させてみたら考えられない程遅かった、という場合も本記述を参考にしてください。遅延としては主に以下のケースが考えられます。

    サーバ側に遅延の要因が見つからない場合はネットワークを含めどこで遅延しているか広範囲に調査する必要があります。

状況の確認方法

    1. 運用アシスタントによるスローダウン検出

        運用アシスタント機能により通常よりオペレーション処理が遅くなったことを検出できます。 スローダウンが検出されると以下のメッセージがイベントログ・シスログに通知されます。

        “OTX20110100 オペレーションｚｚｚのスローダウンを検出しました。current:平均実行時間=xxx秒。normal:平均実行時間=www秒。プロセスグループ=vvv。 ObjectName=yyy”
        “OTX20110100 The Operation ｚｚｚ get late. Average of current time is xxx s. Average of normal time is www s. The Process Group is vvv. The ObjectName is yyy“

        詳しくは「TPモニタの運用操作 2.40.5 スローダウン障害の検出」を参照してください。
        スローダウン検出は、遅くなり始めた状態を検出するものであり、致命的な遅延となる前に自然復旧される場合もあります。復旧された場合は、以下のメッセージがイベントログ・シスログに出力されます。
        遅くなったまま長期間状態が落ち着いた場合も以下のメッセージとなります。

        “OTX20120100 オペレーションｚｚｚがスローダウン状態からノーマル状態に遷移しました。current:平均実行時間=xxx秒。normal:平均実行時間=www秒。プロセスグループ=vvv, ObjectName=yyy”
        “OTX20120100 The Operation ｚｚｚ transit from slowdown to normal. Average of current time is xxx s. Average of normal time is www s. The Process Group is vvv. The ObjectName is yyy “

        オペレーションのスローダウンを検出してから「スローダウン継続監視時間」を超えてなお、スローダウン状態が継続していると、以下のメッセージがイベントログ・シスログに出力され、スタックトレースが採取されます。スローダウンが一時的なものでなく、恒久的な障害となっている可能性があります。復旧に向けた対処を検討してください。

        “OTX20110200 オペレーションｚｚｚの長期にわたるスローダウン状態を検出しました。current:平均実行時間=xxx秒。normal:平均実行時間=www秒。スローダウン継続時間=uuu分。プロセスグループ名=vvv, ObjectName=yyy”
        “OTX20110200 The Operation zzz is slow for a long time. Average of current time is xxx s. Average of normal time is www s. Duration of slow is uuu m. The Process Group is vvv. The ObjectName is yyy “

    2. オペレーション処理時間の確認

        統合運用管理ツールやオペレーションジャーナルでオペレーションの処理時間を調査し、 システム運用に影響を与えるような致命的な遅延となっていないか確認してください。

        最近AP置換を行っているというのであればAPの処理時間に変化がないか確認してください。 オペレーションジャーナルを採取することにより、各APでの処理時間の統計や推移を確認することができます。 「TPモニタの運用操作 2.38 オペレーションジャーナルの編集」を参照してください。 統合運用管理ツールで確認する場合は[統計情報]の該当オペレーションの統計属性をご覧ください。
        　該当オペレーションのアプリケーショングループ起動からの、レスポンス時間（キュー待ち時間を含む）、 　実行時間（キュー待ち時間を含まない）、CPU時間の総計を確認できます。
        　また、オペレーションまたはプロセスグループの「運用アシスタント」タブの「スローダウン継続時間」が0以上となっていないか確認してください。通常は-1が表示されます。

    3. 処理件数、キュー滞留数の確認

        オペレーションジャーナルで処理件数や稼動スレッド数を確認できます。また、quewrtコマンドでリクエストの受付件数やキュー滞留数の確認が出来ます。キュー滞留については「キュー滞留によるレスポンス遅延への対応」を参照してください。

    4. サーバ環境の確認

        psコマンド、topコマンド、sarコマンド、タスクマネージャ、パフォーマンスモニタを使用することにより、サーバでのCPU使用率やメモリ使用率を確認してください。
        APのCPU使用率は統合運用管理ツールでも確認できます。プロセスグループの「動作情報」の「プロセス情報」を参照してください。この情報はオペレーションジャーナルからも確認できます。

採取資料

    イベントログ(アプリケーション、システム)・シスログ

    ジャーナル（採取方法は「TPモニタの運用操作 2.39 障害解析」）

    APログ:
    ${INSTANCE_ROOT}/logs/tpsystem/<アプリケーショングループ名>/<プロセスグループ名>/save/<プロセスグループ名>.<数字>.<PID>.log

    システムトレース:
    ${INSTANCE_ROOT}/logs/tpsystem/<アプリケーショングループ名>/<プロセスグループ名>/save/<プロセスグループ名>_sys.<数字>.<PID>.log

    イベントジャーナル（採取方法は「TPモニタの運用操作 2.39 障害解析」）

    quewrt, DI X TR（採取方法は「TPモニタの運用操作 2.39 障害解析」）

対象APの特定

    オペレーションジャーナルを採取して各APでの処理時間を確認することにより、対象APを特定できます。

対象オペレーションの特定

    オペレーションジャーナルを採取すればAPだけでなくオペレーションも特定できます。
    運用アシスタントのスローダウン検出メッセージからもオペレーションを特定できます

原因の特定

    オペレーションジャーナルによりオペレーションのCPU使用時間を確認してください。実行時間に比べてCPU使用時間が少ない場合は、データベース・ACOSなどのバックエンド処理やネットワークに原因がある可能性があります。ユーザモードCPU使用時間が増加しているのであれば、サーバAPの処理に問題がある可能性があります。カーネルモードCPU使用時間が多い場合は、リソース使用の効率化等を検討してください。CPU時間が増加している場合は、CPU使用率の過剰への対応を参考にして下さい。

    また、統合運用管理ツールから、レスポンス時間（キュー待ち時間を含む）、実行時間（キュー待ち時間を含まない）、CPU時間を確認してください。レスポンス時間に比べて実行時間が少ない場合は、キュー滞留により遅延しています。
    →　キュー滞留によるレスポンス遅延への対応
    「長期にわたるスローダウン状態」が検出された場合は、デフォルト設定では自動的にJavaプロセスのスタックトレースが採取されます。APログに記録されたスタックトレースからから処理内容を調査してください。

回避方法

    サーバ側に実装したユーザロジックに問題がある場合は問題のあるオペレーションを一時的に閉塞して運用する方法が考えられます。

復旧方法

    遅延した原因が、データベースやOSなどにあれば、そちらの障害を復旧させてください。

    サーバ側に実装したユーザロジックに問題がある場合は、該当プロセスグループを再起動することで一時的に復旧する可能性もありますが、アプリケーションの処理を見直す必要があります。

    運用アシスタントによりスローダウンが検出されたものの、一時的な遅延であり、何も処理を行わずとも正常状態に復帰する場合があります。この場合は、再起動のなどの復旧処置は必要ありません。

    「長期にわたるスローダウン」が検出されている場合は、恒久的な障害に陥っている可能性がありますので、原因を調査し、サーバ側に実装したユーザロジックに問題がある場合はプロセスグループの再起動を検討してください。

予防のための対策

    サーバ側に実装したユーザロジックに問題がある場合はその処理を見直す必要があります。

    リクエスト数増加が見込まれる場合はあらかじめプロセス数またはスレッド数を増やしておいてください。

その他

    DNS解決が遅いために遅延していた、という事例が稀にあります。nslookupで応答時間を確認してください。可能であればホスト名をIPに変えて試してください。

関連情報

    キュー滞留によるレスポンス遅延への対応
    キュー滞留数超過への対応
    CPU使用率の過剰への対応

    オペレーション呼び出しでの障害
    TPモニタ機能の障害解析

    トラブルシューティング(障害解析)