このトピックでは、トレース データの形式、表示方法、およびサービス トレース ビューアーを使用してアプリケーションのトラブルシューティングを行う方法について説明します。
サービス トレース ビューアー ツールの使用
Windows Communication Foundation (WCF) サービス トレース ビューアー ツールを使用すると、WCF リスナーによって生成された診断トレースを関連付けて、エラーの根本原因を特定できます。 このツールを使用すると、トレースを簡単に表示、グループ化、およびフィルター処理できるため、WCF サービスの問題を診断、修復、検証できます。 このツールの使用方法の詳細については、「 サービス トレース ビューアー ツール (SvcTraceViewer.exe)」を参照してください。
このトピックには、サービス トレース ビューアー ツール (SvcTraceViewer.exe) を使用して表示したトレースとメッセージ ログのサンプルを実行して生成されたトレースのスクリーンショットが含まれています。 このトピックでは、トレースの内容、アクティビティ、およびその相関関係を理解する方法と、トラブルシューティング時に多数のトレースを分析する方法について説明します。
トレース コンテンツの表示
トレース イベントには、次の最も重要な情報が含まれています。
設定時のアクティビティ名。
放出時間。
トレース レベル。
トレース ソース名。
プロセス名。
スレッド ID。
一意のトレース識別子。これは、トレースに関連する詳細情報を提供する Microsoft テクニカル リファレンスを指す URL です。
これらはすべて、サービス トレース ビューアーの右上のパネル、またはトレースを選択するときに右下パネルの書式設定されたビューの [基本情報 ] セクションで確認できます。
注
クライアントとサービスが同じコンピューター上にある場合、両方のアプリケーションのトレースが存在します。 これらは、[ プロセス名] 列を使用してフィルター処理できます。
さらに、書式設定されたビューには、トレースの説明と、使用可能な場合の追加情報も表示されます。 後者には、例外の種類とメッセージ、呼び出し履歴、メッセージ アクション、from/to フィールド、およびその他の例外情報を含めることができます。
XML ビューでは、便利な xml タグには次のものが含まれます。
<SubType>(トレース レベル)。<TimeCreated>。<Source>(トレース ソース名)。<Correlation>(トレースの出力時に設定されるアクティビティ ID)。<Execution>(プロセスとスレッド ID)。<Computer>。<ExtendedData>(メッセージの送信時にメッセージ ヘッダーに設定された<Action>、<MessageID>、および<ActivityId>を含む)。
"チャネル経由でメッセージを送信しました" トレースを調べると、次の内容が表示されることがあります。
<E2ETraceEvent xmlns="http://schemas.microsoft.com/2004/06/E2ETraceEvent">
<System xmlns="http://schemas.microsoft.com/2004/06/windows/eventlog/system">
<EventID>262163</EventID>
<Type>3</Type>
<SubType Name="Information">0</SubType>
<Level>8</Level>
<TimeCreated SystemTime="2006-08-04T18:45:30.8491051Z" />
<Source Name="System.ServiceModel" />
<Correlation ActivityID="{bbbb1111-cc22-3333-44dd-555555eeeeee}"/>
<Execution ProcessName="client" ProcessID="1808" ThreadID="1" />
<Channel />
<Computer>TEST1</Computer>
</System>
<ApplicationData>
<TraceData>
<DataItem>
<TraceRecord xmlns="http://schemas.microsoft.com/2004/10/E2ETraceEvent/TraceRecord" Severity="Information">
<TraceIdentifier>http://msdn.microsoft.com/library/System.ServiceModel.Channels.MessageSent.aspx</TraceIdentifier>
<Description>Sent a message over a channel.</Description>
<AppDomain>client.exe</AppDomain>
<Source>System.ServiceModel.Channels.ClientFramingDuplexSessionChannel/35191196</Source>
<ExtendedData xmlns="http://schemas.microsoft.com/2006/08/ServiceModel/MessageTransmitTraceRecord">
<MessageProperties>
<AllowOutputBatching>False</AllowOutputBatching>
</MessageProperties>
<MessageHeaders>
<Action d4p1:mustUnderstand="1" xmlns:d4p1="http://www.w3.org/2003/05/soap-envelope" xmlns="http://www.w3.org/2005/08/addressing">http://Microsoft.ServiceModel.Samples/ICalculator/Multiply</Action>
<MessageID xmlns="http://www.w3.org/2005/08/addressing">urn:uuid:7c6670d8-4c9c-496e-b6a0-2ceb6db35338</MessageID>
<ActivityId CorrelationId="aaaa0000-bb11-2222-33cc-444444dddddd" xmlns="http://schemas.microsoft.com/2004/09/ServiceModel/Diagnostics">bbbb1111-cc22-3333-44dd-555555eeeeee</ActivityId>
<ReplyTo xmlns="http://www.w3.org/2005/08/addressing">
<Address>http://www.w3.org/2005/08/addressing/anonymous</Address>
</ReplyTo>
<To d4p1:mustUnderstand="1" xmlns:d4p1="http://www.w3.org/2003/05/soap-envelope" xmlns="http://www.w3.org/2005/08/addressing">net.tcp://localhost/servicemodelsamples/service</To>
</MessageHeaders>
<RemoteAddress>net.tcp://localhost/servicemodelsamples/service</RemoteAddress>
</ExtendedData>
</TraceRecord>
</DataItem>
</TraceData>
</ApplicationData>
</E2ETraceEvent>
ServiceModel E2E トレース
System.ServiceModel トレース ソースが Off 以外のswitchValueで設定され、ActivityTracingされると、WCF は WCF 処理用のアクティビティと転送を作成します。
アクティビティは、その処理単位に関連するすべてのトレースをグループ化する処理の論理単位です。 たとえば、要求ごとに 1 つのアクティビティを定義できます。 転送により、エンドポイント内のアクティビティ間に因果関係が作成されます。 アクティビティ ID を伝達すると、エンドポイント間でアクティビティを関連付けられます。 これを行うには、すべてのエンドポイントで構成に propagateActivity=true を設定します。 アクティビティ、転送、伝達を使用すると、エラーの相関関係を実行できます。 この方法では、エラーの根本原因をより迅速に見つけることができます。
クライアントでは、オブジェクト モデルの呼び出しごとに 1 つの WCF アクティビティが作成されます (Open ChannelFactory、Add、Divide など)。各操作呼び出しは、"処理アクション" アクティビティで処理されます。
次のスクリーンショットでは、 トレースとメッセージ ログ のサンプルから抽出された左側のパネルには、クライアント プロセスで作成されたアクティビティの一覧が、作成時間で並べ替えられて表示されます。 アクティビティの時系列リストを次に示します。
チャネル ファクトリ (ClientBase) を構築しました。
チャネル ファクトリをオープンしました。
[追加] アクションを処理しました。
セキュリティで保護されたセッション (最初の要求で発生しました) を設定し、3 つのセキュリティ インフラストラクチャ応答メッセージ (RST、RSTR、SCT (プロセス メッセージ 1、2、3) を処理しました。
減算、乗算、除算の要求を処理しました。
チャネル ファクトリを閉じ、セキュリティで保護されたセッションを閉じ、セキュリティ メッセージ応答のキャンセルを処理しました。
wsHttpBinding が原因で、セキュリティ インフラストラクチャ メッセージが表示されます。
注
WCF では、最初は別のアクティビティ (プロセス メッセージ) で処理されている応答メッセージを示します。その前に、転送を通じて、要求メッセージを含む対応するプロセス アクション アクティビティに関連付けます。 これはインフラストラクチャ メッセージと非同期要求で発生します。これは、メッセージを検査し、activityId ヘッダーを読み取り、その ID を持つ既存のプロセス アクション アクティビティを識別して関連付ける必要があるためです。 同期要求の場合、応答をブロックしているため、応答が関連するプロセス アクションがわかっています。
次の図は、作成時間 (左パネル) とその入れ子になったアクティビティとトレース (右上のパネル) で一覧表示される WCF クライアント アクティビティを示しています。
左側のパネルでアクティビティを選択すると、入れ子になったアクティビティとトレースが右上のパネルに表示されます。 したがって、これは、選択した親アクティビティに基づいて、左側のアクティビティの一覧の縮小された階層ビューです。 選択したプロセス アクションの追加が最初に行われた要求であるため、このアクティビティには、セキュリティで保護されたセッションの設定アクティビティ (転送先、転送元)、および追加アクションの実際の処理のトレースが含まれます。
左側のパネルで [プロセス] アクションの [追加] アクティビティをダブルクリックすると、追加に関連するクライアント WCF アクティビティがグラフィカルに表示されます。 左側の最初のアクティビティは、既定のアクティビティであるルート アクティビティ (0000) です。 WCF はアンビエント アクティビティから転送します。 これが定義されていない場合、WCF は 0000 から転送します。 ここで、2 番目のアクティビティであるプロセス アクションの追加は、0 から転送されます。 その後、セキュリティで保護されたセッションのセットアップが表示されます。
次の図は、WCF クライアント アクティビティ、特にアンビエント アクティビティ (ここでは 0)、プロセス アクション、およびセキュリティで保護されたセッションの設定のグラフ ビューを示しています。
右上のパネルには、プロセス アクションの追加アクティビティに関連するすべてのトレースが表示されます。 具体的には、要求メッセージ ("チャネル経由でメッセージを送信しました") を送信し、同じアクティビティで応答 ("チャネル経由でメッセージを受信しました") を受信しました。 これを次のグラフに示します。 わかりやすくするために、セキュリティで保護されたセッションの設定アクティビティはグラフで折りたたまれます。
次の図は、プロセス アクション アクティビティのトレースの一覧を示しています。 要求を送信し、同じアクティビティで応答を受信します。
ここでは、わかりやすくするためにクライアント トレースのみを読み込みますが、サービス トレース (受信した要求メッセージと送信された応答メッセージ) もツールに読み込まれ、 propagateActivity が true. に設定されている場合は、同じアクティビティに表示されます。これは、後の図に示します。
サービスでは、アクティビティ モデルは次のように WCF の概念にマップされます。
ServiceHost を構築して開きます (セキュリティの場合など、ホスト関連のアクティビティがいくつか作成される場合があります)。
ServiceHost 内の各リスナーに対して Listen At アクティビティを作成します (Open ServiceHost との間の転送を伴います)。
リスナーは、クライアントによって開始された通信要求を検出すると、クライアントから送信されたすべてのバイトが処理される "受信バイト" アクティビティに転送します。 このアクティビティでは、クライアント とサービスの対話中に発生した接続エラーを確認できます。
メッセージに対応する受信バイトのセットごとに、"メッセージの処理" アクティビティでこれらのバイトを処理し、WCF Message オブジェクトを作成します。 このアクティビティでは、無効なエンベロープまたは形式が正しくないメッセージに関連するエラーが表示されます。
メッセージが形成されると、プロセス アクション アクティビティに転送されます。
propagateActivityがクライアントとサービスの両方でtrueに設定されている場合、このアクティビティは、クライアントで定義されたものと同じ ID を持ち、前に説明しました。 この段階から、要求に関連する WCF で出力されるすべてのトレースが、応答メッセージ処理を含む同じアクティビティ内にあるため、エンドポイント間の直接的な相関関係の恩恵を受け始めます。アウトプロセス アクションの場合は、"ユーザー コードの実行" アクティビティを作成して、ユーザー コードで出力されたトレースを WCF で出力されたトレースから分離します。 前の例では、"サービス送信応答" トレースは、クライアントによって伝達されたアクティビティに含まれていない "ユーザー コードの実行" アクティビティに出力されます (該当する場合)。
次の図では、左側の最初のアクティビティはルート アクティビティ (0000) です。これは既定のアクティビティです。 次の 3 つのアクティビティでは、ServiceHost を開きます。 列 5 のアクティビティはリスナーであり、残りのアクティビティ (6 から 8) は、バイト処理からユーザー コードのアクティブ化までのメッセージの WCF 処理を記述します。
次の図は、WCF サービス アクティビティのグラフ ビューを示しています。
次のスクリーンショットは、クライアントとサービスの両方のアクティビティを示しており、プロセス間のプロセス アクションの追加アクティビティ (オレンジ色) が強調表示されています。 矢印は、クライアントとサービスによって送受信される要求メッセージと応答メッセージを関連付けます。 プロセス アクションのトレースはグラフ内のプロセス間で分離されますが、右上のパネルには同じアクティビティの一部として表示されます。 このパネルでは、送信されたメッセージのクライアント トレースと、受信したメッセージと処理されたメッセージのサービス トレースを確認できます。
次の図は、WCF クライアントアクティビティとサービス アクティビティの両方のグラフ ビューを示しています
次のエラー シナリオでは、サービスとクライアントでのエラートレースと警告トレースが関連しています。 最初に、サービスのユーザー コードで例外がスローされます ("サービスはユーザー コードでこの要求を処理できません" という例外の警告トレースを含む最も緑色のアクティビティ)。 応答がクライアントに送信されると、エラー メッセージ (左ピンクのアクティビティ) を示す警告トレースが再度出力されます。 その後、クライアントは WCF クライアント (左下の黄色のアクティビティ) を閉じ、サービスへの接続を中止します。 サービスがエラー (右側で最も長いピンクのアクティビティ) をスローします。
サービスとクライアント間のエラーの相関関係
これらのトレースの生成に使用されるサンプルは、wsHttpBinding を使用した一連の同期要求です。 セキュリティのないシナリオ、または非同期要求を使用するシナリオでは、このグラフから逸脱しています。プロセス アクション アクティビティには、非同期呼び出しを構成する開始操作と終了操作が含まれており、コールバック アクティビティへの転送が表示されます。 その他のシナリオの詳細については、「 エンドTo-End トレースのシナリオ」を参照してください。
サービス トレース ビューアーを使用したトラブルシューティング
サービス トレース ビューアー ツールでトレース ファイルを読み込むときは、左側のパネルで赤または黄色のアクティビティを選択して、アプリケーションの問題の原因を追跡できます。 通常、000 アクティビティには、ユーザーにバブル アップするハンドルされない例外があります。
次の図は、赤または黄色のアクティビティを選択して問題の根本を特定する方法を示しています。
右上のパネルで、左側で選択したアクティビティのトレースを調べることができます。 その後、そのパネルで赤または黄色のトレースを調べて、それらがどのように相関しているかを確認できます。 前のグラフでは、同じプロセス アクション アクティビティ内のクライアントとサービスの両方に対する警告トレースが表示されています。
これらのトレースでエラーの根本原因が得られない場合は、左側のパネルで選択したアクティビティ (プロセス アクション) をダブルクリックしてグラフを利用できます。 その後、関連するアクティビティを含むグラフが表示されます。 その後、関連するアクティビティ ("+" 記号をクリック) を展開して、関連するアクティビティで最初に生成されたトレースを赤または黄色で見つけることができます。 問題の根本原因を追跡するまで、関心のある赤または黄色のトレースの直前に発生したアクティビティを、エンドポイント間の関連アクティビティまたはメッセージ フローへの転送に続けて拡張し続けます。
問題の根本原因を追跡するためのアクティビティの展開
ServiceModel ActivityTracing がオフで ServiceModel トレースがオンになっている場合は、0000 アクティビティで出力された ServiceModel トレースを確認できます。 ただし、これらのトレースの相関関係を理解するには、より多くの労力が必要です。
メッセージ ログが有効になっている場合は、[メッセージ] タブを使用して、エラーの影響を受けるメッセージを確認できます。 赤または黄色のメッセージをダブルクリックすると、関連するアクティビティのグラフ ビューが表示されます。 これらのアクティビティは、エラーが発生した要求に最も密接に関連するものです。
トラブルシューティングを開始するには、赤または黄色のメッセージ トレースを選択し、それをダブルクリックして根本原因を追跡することもできます。