トラブルシューティングガイド：トランザクションログの使用 - Support and Troubleshooting

トラブルシューティングガイド：トランザクションログの使用 Issue  このトラブルシューティングガイドの情報を使用してトランザクションログテーブルの関連エントリーを調べることが、問題の原因解明に役立ちます。

問題点を把握するための重要な手法の 1 つは、報告された例に関連するトランザクション履歴の詳細を追跡することです。トランザクションの詳細を知るための鍵は、トランザクションログテーブル [syslog_transaction] を使用することです。この記事では、このテーブルの機能と使用方法について説明します。このテーブルに豊富に含まれる詳細情報から、問題の解決に十分な情報が得られるかもしれません。問題解決に十分な情報ではないとしても、調査できる多くの手がかりが得られます。

トランザクションログテーブルからわかること ボトルネックはどこですか？ パフォーマンスの問題に対処するときはいつでも重要になる質問が、「ボトルネックはどこか」です。トランザクションログには、サーバー、クライアント、SQL、ビジネスルール、クライアントスクリプト、UI ポリシー、待機時間などに費やされた時間のブレークダウンが表示されるため、パフォーマンスの問題の原因を切り分けることができます。

ユーザーは何をしていましたか？ トランザクションログの URL フィールドを確認することで、ユーザーがアクセスしていたページを特定できます。また、フォーム送信の場合、トランザクション URL にはパラメーターが含まれます。URL パスの意味と「?」に続く部分に含まれるパラメーターを理解することは、あるトランザクションで何が起こっていたかを正確に解釈するのに大いに役立ちます。(詳細については、「 URL による移動 」を参照してください。)

[ユーザーエージェント] フィールドを確認することで、ユーザーが使用していたブラウザと OS を特定できます。この情報は、問題がクライアント側の問題であり、問題を再現する方法を知る必要がある場合に非常に重要です。正確かつ詳細な問題の再現手順 (STR) を見つけることは、問題のトラブルシューティングの重要な部分です。ユーザーエージェント文字列は解読しにくい場合があります。 UserAgentString.com のようなツールが役立ちます。

[IP アドレス] フィールドを確認することで、ServiceNow への要求の発信元ネットワークを特定できます。この情報は、場合によって発生する問題を診断するときに非常に役立ちます。例えば、ユーザーが企業ネットワーク内からログオンすると発生するものの、自宅からログインすると発生しない問題があるかもしれません。または、パフォーマンスの問題が、同じ地理的な場所にある特定のユーザーグループから報告されているような場合もあります。特定の IP アドレスからのトランザクションが他の IP アドレスよりも遅いことが判明するかもしれません。 問題はどこで発生しましたか？ ServiceNow は「クラスター化された」アーキテクチャを採用しており、複数の Java ノードが存在するため、問題が ServiceNow アーキテクチャのどこで発生したかを知ることは重要です。ここでは、[セッション ID] と [システム ID] フィールドが重要です。[システム ID] は、問題が発生したノードを示します。あるノードのすべてのトランザクションが影響を受け、他のノードのトランザクションは影響を受けなかった場合を考えてみましょう。この情報は、考えられる原因を切り分ける上で重要です。問題がどこで発生したかを知ることも重要です。詳細なシステムログ (ログファイルダウンローダーまたはログファイルブラウザからアクセス) を検索できます。

影響を受けたとされる期間に何が生じていたでしょうか？ 特定の期間中に複数のユーザーが問題を経験したものの、その後問題が解消した場合、たいていはこの質問を考えることになります。トランザクションログテーブルを使用して、特定の期間中にどのようなトランザクションやスケジュール済みジョブが実行されていたかを判断できます。トランザクションログテーブルの [作成日時] フィールドにはトランザクションの完了時刻が反映されるため、この情報の判断は思ったより複雑です。

次の例を考えてみてください。午前 7 時 15 分から 7 時 45 分の間に、速度が低下する期間が報告されたとします。さらに、その根本原因が、午前 7 時 10 分に開始し、午前 9 時 15 分に終了したトランザクションにあるとします。スケジュール済みジョブが終了したのは午前 9 時 15 分であり、作成時刻はやはり午前 9 時 15 分になります。それで、午前 7 時 15 分から 7 時 45 分の間に作成されたすべてのトランザクションを検索しても、原因は明らかになりません。

実行時間が非常に長いトランザクションを見つけるには、検索する時間の範囲を広げ、かつ応答時間が 120,000 ミリ秒 (2 分) を上回るという条件を含めることができます。対象の範囲を 24 時間に広げた場合でも、このタイプの検索は 10 ～ 20 秒以内に完了するはずです。

仕組み トランザクションログテーブル [syslog_transaction] には、ServiceNow 製品によって処理される多くのトランザクションがキャプチャされます。これには、ユーザートランザクション (SOAP または実際のユーザー) とバックグラウンドトランザクション (スケジュール済みジョブ) の両方が含まれます。ただし、次のタイプのトランザクションはキャプチャされません。

AJAX や Angular など、一部の非同期トランザクション 大量の REST トランザクションの一部 完了しなかったトランザクション。例外として、製品のバージョン (Fuji など) によっては、キャンセルされたトランザクションも記録されます。 各トランザクションには、応答時間 (サーバー上の時間)、クライアントネットワーク時間 (合計時間 - (サーバー + クライアント時間))、データベース包括時間、ビジネスルール包括時間、ブラウザ時間など、どこで時間が費やされたかのブレークダウンが含まれます。追跡されるその他の詳細情報には、どのユーザーがどのトランザクションを実行していたか、ユーザーがログインしたノード、ユーザーの送信元 IP アドレス、使用されたブラウザとオペレーティングシステムを示すユーザーエージェント文字列が含まれます。 トランザクションログテーブルのパフォーマンスについて トランザクションログテーブルは非常に大きいため、クエリの実行には常に注意が必要です。ほとんどのアクティブな顧客のシステムでは、トランザクションログテーブルに対して一度にクエリを実行する範囲は 24 時間以内にする必要があります。ただし、他のフィルター条件で結果セットを効率的に絞り込める場合は、それを超えるクエリも実行できます。このため、テーブルにアクセスするモジュール ([システム診断] > [トランザクション]、[システム診断] > [トランザクション (バックグラウンド)]、[システム診断] > [トランザクション (すべてのユーザー)]) では、すべて [作成日] = [今日] のフィルターがデフォルトで有効になっています。ただし、一部の顧客システムでは、24 時間以内のトランザクションの照会でも、システムが妥当な処理時間内に処理するには件数が多すぎる場合があります。そのため、ベストプラクティスとして、まず URL でテーブルにアクセスし、sysparm_filter_only=true パラメーターを使用してリストフィルターのみを表示するようにします。そこから、必要な情報のみを問い合わせる、条件を厳密に絞ったクエリを指定することができます。[Between] フィルターと他の制約フィルター ([応答時間] > 1000 や [作成者] = joe.employee など) を使用して、できるだけ短い期間を指定するようにしてください。

関連するログエントリーを効率的にクエリする手順 問題が発生したユーザーのユーザー ID を (ユーザーテーブルから) 見つけます。

問題がいつ発生したかを調べます (可能であれば分単位まで)。

問題が発生したときのユーザーの操作を確認します。

アドミンユーザーとしてインスタンスにログインします。

/syslog_transaction_list.do?sysparm_filter_only=true に移動します。

リストに対してグラフィカルフィルタービルダーを展開し、次のフィルターを追加して、報告された時間前後のそのユーザーによるすべてのトランザクションを取得します。 [Created] [between] [ ] and [ ] [Created by] [is] [ ]

[実行] をクリックします。 support.servicenow.com の KB0997495 も、解決の参考になります。

トランザクションログテーブルのフィールドの定義 まだカスタマイズしていない場合は、リストの歯車アイコンをクリックして、リストに表示される列をカスタマイズします。このセクションで説明する列は、役に立つ場合があります。

サーバー測定基準 作成日時：(sys_created_on) トランザクションが記録された時点。トランザクションはそのトランザクションの終了時に記録されることに注意してください。従って、トランザクション (スケジュール済みジョブを含む) の開始時刻を判定するには、[作成日時] から [応答時間] の値を引く必要があります。 作成者：(sys_created_by) トランザクションを実行したユーザーのユーザー ID (sys_user.user_name)。ほとんどのバックグラウンド/スケジュール済みジョブは、「system」と呼ばれる特別なユーザーによって実行されます。ユーザーの事前認証によって開始したトランザクションには、「guest」と呼ばれる特別なシステムユーザーが記録されます。 応答時間：(response_time) サーバーがトランザクションの実行に費やした時間の長さ (ミリ秒)。リダイレクト前に費やされたサーバー時間 (HTTP 302) は含まれません。その後の部分的なページ要求 (AJAX など) やリソース (CSS、JavaScript、画像など) の提供に費やされた時間は含まれません。セマフォの待機時間や、同一セッションの前のトランザクション完了を待機する時間は含まれます。従って、一部のトランザクションでは応答時間の 90% 以上が別のトランザクションの完了待機に費やされ、測定値が大きく上昇して原因がわかりにくくなる可能性があります。 ネットワーク時間：(network_time) Istanbul バージョン以降の場合、ネットワーク時間はサーバーが要求のすべてのバイトを出力ストリームに書き込むのにかかる時間であり、インターネット経由でそれらのバイトを送信するのにかかる時間ではありません。この値の内容は、この測定基準に対して一般に予想されるものとは異なります。一般に予想されるよりはるかに低い数値になります。 ビジネスルール時間：(business_rule_time) ビジネスルールまたはスクリプトジョブの実行にかかった時間 (ミリ秒)。スクリプトジョブには、スケジュール済みスクリプト実行と非同期ビジネスルールが含まれます。これには、最初のビジネスルール呼び出しからダウンストリームにかかった時間が含まれます。タイマーはビジネスルールの開始とともにスタートし、そのビジネスルールが完了したときにのみ停止します。これには、SQL の完了待ち、または最上位ビジネスルールのスクリプトからトリガーされた他のビジネスルールやプロセスの待ち時間も含まれます。SQL のトリガー方法はビジネスルール以外にも存在するため、SQL 時間として、ビジネスルール時間よりも長い時間が表示されることはあり得ます。ただし、ビジネスルールによってトリガーされた SQL の実行にかかった時間はすべて、ビジネスルール時間の計算に含まれることに注意してください。 SQL 時間：(sql_time) データベースへの要求と応答の待機にかかった時間 (ミリ秒)。データベースへの要求/応答の処理に関与するリソース (アプリケーションサーバーの CPU、アプリケーションサーバーと db サーバー間のネットワーク帯域幅など) が過負荷になっている場合、この値が不自然に増大する場合があります。なお、ホームページでは、マルチスレッドを使用することで複数の SQL ステートメントを同時に実行することが可能です。SQL 時間は、メインスレッドまたは子スレッドでトランザクションの一部として実行されたすべての SQL の合計であるため、home.do トランザクションの SQL 時間は、多くの場合トランザクションの合計処理時間より長くなります。 タイプ：(type) トランザクションのタイプ (フォームやリストなど)。 テーブル：(table) 表示されたテーブル (incident、change_request など)。 ビュー：(view_id) このフォーム/リストに使用されたビュー (sys_ui_view テーブル)。 セッション：(session) ログインしたユーザーの Java セッション ID。この ID は、同じユーザーがシステムログに出力したログメッセージの判別に役立ちます。バックグラウンドジョブの場合、セッション ID には、ジョブを実行しているワーカーの名前が含まれます。 システム ID：(system_id) このフィールドには、トランザクションが実行されたノードの名前が含まれます。 IP アドレス：(ip_address) ServiceNow に入ってくるトランザクションのソース IP アドレス。 ユーザーエージェント：(user_agent) ユーザーエージェント文字列は、トランザクションを開始したブラウザとオペレーティングシステムを識別する一意の識別子です ( http://www.useragentstring.com/index.php を参照)。 合計待機時間 (total_wait_time)： サーバーがトランザクションを処理できるようになる前に、トランザクションが待機していた時間 (ミリ秒)。 トランザクション処理時間 (transaction_processing_time)： サーバーの応答時間から待機時間を差し引いた時間。すべての処理時間を実際にはどのトランザクションが使用しているかを測定するのに適した方法です。 セッション待機時間 (session_wait_time)： 同一ユーザーセッションが最初のトランザクションが完了する前に 2 番目のトランザクションを開始したことによる待機時間 (ミリ秒)。 セマフォ待機時間 (semaphore_wait_time)： すべてのセマフォが使用中であることに起因する待機時間 (ミリ秒)。 アプリスコープ (app_scope)： トランザクションが実行された親スコープ。 トランザクションパターン：(transaction_pattern) 匿名化された URL を識別する一意のハッシュコード。これは、ログ内の特定のトランザクションを遅いトランザクションモジュール (sys_transaction_pattern テーブル) とリンクするために使用できます。 クライアントトランザクションタイミング クライアント側 (ブラウザやモバイルデバイスなど) で操作を追跡するタイミング。すべてのトランザクションタイプで使用できるわけではありません。Safari では利用できません。

クライアントトランザクション：(client_transaction) トランザクションでクライアントタイミングが正常に記録された場合、true。 クライアント応答時間：(client_response_time) navigationStart から loadEventEnd までの時間 (ミリ秒)。つまり、ページ要求から HTML 読み込みイベントの実行完了までの合計時間 (サーバー時間を含む)。これには、onLoad クライアントスクリプトと、結果として起動した onChange スクリプトが含まれます。つまり、サーバー時間、ブラウザ時間、javascript、および HTTP 要求や HTTP 応答にかかった時間がこれに含まれます。これは最も包括的なタイミング測定基準であるため、他の時間よりも大きくなるはずです。ただし、SQL 時間のように複数のスレッドの累積時間をカウントする可能性があるものは、このルールの例外になります。 クライアントネットワーク時間：(client_network_time) client_response_time の合計値からサーバーおよびブラウザの応答時間とみなされる値を差し引いた値が反映されます。一部のトランザクションではこの式とわずかに差異が発生する可能性がありますが、概して正確です。

注意点として、HTTP 302 リダイレクト直後のトランザクションでは、直前のトランザクション応答時間が client_network_time に反映されます。[2018 年 10 月 30 日の時点] これは製品の現行の動作であり、変更の予定はありません。この点は、 PRB632265 に記載されています。サーバー時間が誤ってクライアントネットワーク時間とされてしまう現象は、サービスカタログ内のトランザクションで頻繁に発生します。これは、アイテムの注文開始の時点から注文概要ページに遷移するまでのすべてのサービスカタログトランザクションは、service_catalog.do プロセッサを介して処理され、適切なページにリダイレクトされるためです。

Fuji および Chrome、Firefox、IE9+ で一部の古いバージョンを実行している場合：requestStart から navigationStart までの時間 (ミリ秒。下図を参照)。つまり、client_network_time は、最初のページ要求から、要求に対するペイロードの先頭バイトのアップロードが開始されるまでの時間です (つまり、TCP ハンドシェイクのみ)。この値では、この測定基準について一般的に予測される内容と異なる値が示されます。一般的に予測されるよりもはるかに低い値となります。

パフォーマンスタイミング DOM オブジェクトをサポートしていないブラウザの場合、client_network_time は、ページの読み込み開始時点とページ要求時点の差からサーバー時間を引いた値によって決まります。 ブラウザ時間 (browser_time)： ブラウザ時間は、リスト V2 とリスト V3 のどちらを使用しているかによって測定方法が異なります。

[Live V2 以前] responseEnd から loadEventEnd までの時間 (ミリ秒)。これは、現在のページが最初のワイヤフレーム HTML ページのダウンロードを完了してから、「load」イベントとその結果生じるすべてのアクションが完了するまでの時間です。リンクされたすべてのリソース (画像、CSS、JavaScript など) をダウンロードする時間が含まれます。スクリプトを実行する時間は含まれません。

[リスト V3：Helsinki で利用可能][おそらく Jakarta 以降のすべてのトランザクションについて、KB のこの段落は改訂が必要] リスト V3 では、browser_time によって、JavaScript が最初に実行を開始する時間から、AJAXClientTimings 要求がサーバーに送り返されるまでの時間が追跡されます。この時間は、loadEventEnd - responseEnd の window.performance.timing イベントを実行する以前の方法に比べて長くなります。そのため、リスト V3 への移行後に browser_time 測定基準が増大したとしても、驚く必要はありません。部分的にはユーザーエクスペリエンスの実際の低下を反映している可能性もありますが、単純に測定基準が変更されたことの影響も考えられます。例えば、リスト V3 では browser_time が client_response_time の 2 ～ 3 倍になることがあり、混乱を招く場合があります。これは client_response_time で window.performance.timing オブジェクトを使用する古いモデルが採用されているためです。 クライアントスクリプト時間：(client_script_time) クライアントスクリプトの実行にかかった時間 (ミリ秒)。 その他のクライアントタイミングの詳細 Fuji 以降、ServiceNow はほとんどのクライアントタイミングの計算処理に window.performance オブジェクトを使用しています。このオブジェクトは、執筆時点 (2016 年 10 月 14 日) において、すべてのブラウザの最新版でサポートされている Web 標準です。Window.performance は IE9 以降でサポートされています。この window.performance の詳細については、次のリソースを参照してください。 https://www.html5rocks.com/en/tutorials/webperformance/basics/ http://w3c.github.io/navigation-timing/ https://www.w3.org/TR/navigation-timing/#dom-performancetiming-requeststart 次の図は、ナビゲーションタイミング Web 標準のタイムラインのクイックリファレンスです。