Använda Service Trace Viewer för att visa korrelerade spårningar och felsökning

Det här avsnittet beskriver formatet för spårningsdata, hur du visar dem och metoder som använder Tjänstspårningsvisaren för att felsöka ditt program.

Använda visningsverktyget för tjänstspårning

Verktyget Windows Communication Foundation (WCF) Service Trace Viewer hjälper dig att korrelera diagnostikspårningar som skapats av WCF-lyssnare för att hitta rotorsaken till ett fel. Verktyget ger dig ett sätt att enkelt visa, gruppera och filtrera spårningar så att du kan diagnostisera, reparera och verifiera problem med WCF-tjänster. Mer information om hur du använder det här verktyget finns i Service Trace Viewer Tool (SvcTraceViewer.exe).

Det här avsnittet innehåller skärmbilder av spårningar som genererats genom att köra exemplet spårning och meddelandeloggning när det visas med hjälp av verktyget Service Trace Viewer (SvcTraceViewer.exe). Det här avsnittet visar hur du förstår spårningsinnehåll, aktiviteter och deras korrelation samt hur du analyserar ett stort antal spårningar vid felsökning.

Visa spårningsinnehåll

En spårningshändelse innehåller följande viktigaste information:

• Aktivitetsnamn när det anges.

• Utsläppstid.

• Spårningsnivå.

• Namn på spårningskälla.

• Processnamn.

• Tråd-ID.

• En unik spårningsidentifierare, som är en URL som pekar på en teknisk Microsoft-referens som ger mer information om spårningen.

Alla dessa kan visas i den övre högra panelen i tjänstspårningsvisaren, eller i avsnittet Grundläggande information i den formaterade vyn i den nedre högra panelen när du väljer en spårning.

Kommentar

Om klienten och tjänsten finns på samma dator kommer spårningarna för båda programmen att finnas. Dessa kan filtreras med hjälp av kolumnen Processnamn .

Dessutom innehåller den formaterade vyn även en beskrivning av spårningen och ytterligare detaljerad information när den är tillgänglig. Det senare kan innehålla undantagstyp och meddelande, anropsstackar, meddelandeåtgärd, från/till-fält och annan undantagsinformation.

I XML-vyn innehåller användbara XML-taggar följande:

• <SubType> (spårningsnivå).

• <TimeCreated>.

• <Source> (namn på spårningskälla).

• <Correlation> (aktivitets-ID anges när spårningen genereras).

• <Execution> (process- och tråd-ID).

• <Computer>.

• <ExtendedData>, inklusive <Action>, <MessageID> och <ActivityId> uppsättningen i meddelandehuvudet när du skickar ett meddelande.

Om du undersöker spårningen "Skickat ett meddelande över en kanal" kan du se följande innehåll.

<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-spårning

När spårningskällan System.ServiceModel har angetts med en switchValue annan än Av, och ActivityTracing, skapar WCF aktiviteter och överföringar för WCF-bearbetning.

En aktivitet är en logisk bearbetningsenhet som grupperar alla spårningar som är relaterade till den bearbetningsenheten. Du kan till exempel definiera en aktivitet för varje begäran. Överföringar skapar ett orsakssamband mellan aktiviteter inom slutpunkter. Genom att sprida aktivitets-ID:t kan du relatera aktiviteter mellan slutpunkter. Detta kan göras genom att ange propagateActivity=true i konfigurationen vid varje slutpunkt. Med aktiviteter, överföringar och spridning kan du utföra felkorrelation. På så sätt kan du hitta rotorsaken till ett fel snabbare.

På klienten skapas en WCF-aktivitet för varje objektmodellanrop (till exempel Open ChannelFactory, Add, Divide och så vidare.) Var och en av åtgärdsanropen bearbetas i en processåtgärdsaktivitet.

I följande skärmbild, extraherad från exemplet Spårning och meddelandeloggning , visar den vänstra panelen listan över aktiviteter som skapats i klientprocessen, sorterade efter skapandetid. Följande är en kronologisk lista över aktiviteter:

• Konstruerade kanalfabriken (ClientBase).

• Öppnade kanalfabriken.

• Bearbetade åtgärden Lägg till.

• Konfigurera den säkra sessionen (detta inträffade vid den första begäran) och bearbeta tre svarsmeddelanden för säkerhetsinfrastruktur: RST, RSTR, SCT (processmeddelande 1, 2, 3).

• Bearbetade begäranden subtrahera, multiplicera och dividera.

• Stängde kanalfabriken och stängde den säkra sessionen och bearbetade svaret på säkerhetsmeddelandet Avbryt.

Vi ser meddelandena om säkerhetsinfrastrukturen på grund av wsHttpBinding.

Kommentar

I WCF visar vi svarsmeddelanden som bearbetas initialt i en separat aktivitet (processmeddelande) innan vi korrelerar dem med motsvarande processåtgärdsaktivitet som innehåller begärandemeddelandet via en överföring. Detta sker för infrastrukturmeddelanden och asynkrona begäranden och beror på att vi måste inspektera meddelandet, läsa activityId-huvudet och identifiera den befintliga processåtgärdsaktiviteten med det ID:t för att korrelera med det. För synkrona begäranden blockerar vi svaret och vet därför vilken processåtgärd svaret avser.

Följande bild visar WCF-klientaktiviteter som anges efter skapandetid (vänster panel) och deras kapslade aktiviteter och spårningar (övre högra panelen):

När vi väljer en aktivitet i den vänstra panelen kan vi se kapslade aktiviteter och spårningar i den övre högra panelen. Därför är detta en reducerad hierarkisk vy över listan över aktiviteter till vänster, baserat på den valda överordnade aktiviteten. Eftersom den valda processåtgärden Lägg till är den första begäran som görs innehåller den här aktiviteten aktiviteten Konfigurera säker session (överföring till, överföring tillbaka från) och spårningar för den faktiska bearbetningen av åtgärden Lägg till.

Om vi dubbelklickar på processåtgärden Lägg till aktivitet i den vänstra panelen kan vi se en grafisk representation av klientens WCF-aktiviteter relaterade till Lägg till. Den första aktiviteten till vänster är rotaktiviteten (0000), som är standardaktiviteten. WCF överför från den omgivande aktiviteten. Om detta inte har definierats överförs WCF av 0000. Här överförs den andra aktiviteten, Process Action Add, av 0. Sedan ser vi installation av säker session.

Följande bild visar en grafvy över WCF-klientaktiviteter, särskilt Omgivande aktivitet (här 0), Processåtgärd och Konfigurera säker session:

I den övre högra panelen kan vi se alla spårningar som är relaterade till aktiviteten Lägg till processåtgärd. Mer specifikt har vi skickat begärandemeddelandet ("Skickat ett meddelande via en kanal") och tagit emot svaret ("Tog emot ett meddelande via en kanal") i samma aktivitet. Detta visas i följande diagram. För tydlighetens skull döljs aktiviteten Konfigurera säker session i diagrammet.

Följande bild visar en lista över spårningar för aktiviteten Processåtgärd. Vi skickar begäran och tar emot svaret i samma aktivitet.

Här läser vi bara in klientspårningar för tydlighetens skull, men tjänstspårningar (mottaget begärandemeddelande och skickat svarsmeddelande) visas i samma aktivitet om de också läses in i verktyget och propagateActivity har angetts till true. Detta visas i en senare bild.

I tjänsten mappar aktivitetsmodellen till WCF-begreppen enligt följande:

1. Vi skapar och öppnar en ServiceHost (detta kan skapa flera värdrelaterade aktiviteter, till exempel när det gäller säkerhet).

2. Vi skapar en Lyssna på-aktivitet för varje lyssnare i ServiceHost (med överföringar in och ut från Open ServiceHost).

3. När lyssnaren identifierar en kommunikationsbegäran som initierats av klienten överförs den till aktiviteten "Ta emot byte", där alla byte som skickas från klienten bearbetas. I den här aktiviteten kan vi se eventuella anslutningsfel som har inträffat under interaktionen mellan klient och tjänst.

4. För varje uppsättning byte som tas emot som motsvarar ett meddelande bearbetar vi dessa byte i en processmeddelandeaktivitet, där vi skapar WCF-meddelandeobjektet. I den här aktiviteten visas fel som rör ett felaktigt kuvert eller ett felaktigt meddelande.

5. När meddelandet har skapats överförs vi till en processåtgärdsaktivitet. Om propagateActivity är inställt true på både klienten och tjänsten har den här aktiviteten samma ID som den som definierats i klienten och beskrevs tidigare. Från den här fasen börjar vi dra nytta av direkt korrelation mellan slutpunkter, eftersom alla spårningar som genereras i WCF som är relaterade till begäran finns i samma aktivitet, inklusive bearbetning av svarsmeddelanden.

6. För out-of-process-åtgärder skapar vi en "Kör användarkod"-aktivitet för att isolera spårningar som genereras i användarkod från de som genereras i WCF. I föregående exempel genereras spårningen "Tjänsten skickar Lägg till svar" i aktiviteten "Kör användarkod" som inte finns i aktiviteten som sprids av klienten, om tillämpligt.

I bilden nedan är den första aktiviteten till vänster rotaktiviteten (0000), som är standardaktiviteten. De kommande tre aktiviteterna är att öppna ServiceHost. Aktiviteten i kolumn 5 är lyssnaren och de återstående aktiviteterna (6 till 8) beskriver WCF-bearbetningen av ett meddelande, från bytebearbetning till aktivering av användarkod.

Följande bild visar en grafvy över WCF-tjänstaktiviteter:

Följande skärmbild visar aktiviteterna för både klienten och tjänsten och markerar processåtgärden Lägg till aktivitet mellan processer (orange). Pilarna relaterar de begärande- och svarsmeddelanden som skickas och tas emot av klienten och tjänsten. Spårningarna av processåtgärden avgränsas mellan processer i diagrammet, men visas som en del av samma aktivitet i den övre högra panelen. I den här panelen kan vi se klientspårningar för skickade meddelanden följt av tjänstspårningar för mottagna och bearbetade meddelanden.

Följande bilder visar en grafvy över både WCF-klient- och tjänstaktiviteter

I följande felscenario är fel- och varningsspårningar i tjänsten och klienten relaterade. Ett undantag utlöses först i användarkoden på tjänsten (den gröna aktiviteten till höger som innehåller en varningsspårning för undantaget "Tjänsten kan inte bearbeta den här begäran i användarkoden."). När svaret skickas till klienten genereras återigen en varningsspårning för att ange felmeddelandet (vänster rosa aktivitet). Klienten stänger sedan sin WCF-klient (gul aktivitet längst ned till vänster), vilket avbryter anslutningen till tjänsten. Tjänsten genererar ett fel (den längsta rosa aktiviteten till höger).

Felkorrelation mellan tjänsten och klienten

Exemplet som används för att generera dessa spårningar är en serie synkrona begäranden med hjälp av wsHttpBinding. Det finns avvikelser från det här diagrammet för scenarier utan säkerhet, eller med asynkrona begäranden, där processåtgärdsaktiviteten omfattar de start- och slutåtgärder som utgör det asynkrona anropet och visar överföringar till en återanropsaktivitet. Mer information om ytterligare scenarier finns i Spårningsscenarier från slutpunkt till slutpunkt.

Felsökning med hjälp av tjänstspårningsvisaren

När du läser in spårningsfiler i verktyget Tjänstspårningsvisning kan du välja valfri röd eller gul aktivitet på den vänstra panelen för att spåra orsaken till ett problem i programmet. 000-aktiviteten har vanligtvis ohanterade undantag som bubblar upp till användaren.

Följande bild visar hur du väljer en röd eller gul aktivitet för att hitta roten till ett problem.

I den övre högra panelen kan du undersöka spårningar för den aktivitet som du har valt till vänster. Du kan sedan undersöka röda eller gula spårningar i panelen och se hur de korreleras. I föregående diagram visas varningsspårningar både för klienten och tjänsten i samma processåtgärdsaktivitet.

Om dessa spårningar inte ger dig rotorsaken till felet kan du använda diagrammet genom att dubbelklicka på den valda aktiviteten på den vänstra panelen (här Processåtgärd). Diagrammet med relaterade aktiviteter visas sedan. Du kan sedan expandera relaterade aktiviteter (genom att klicka på "+"-tecknen) för att hitta den första avgivna spårningen i rött eller gult i en relaterad aktivitet. Fortsätt att expandera de aktiviteter som inträffade precis innan den röda eller gula spårningen av intresse, efter överföringar till relaterade aktiviteter eller meddelandeflöden över slutpunkter, tills du spårar rotorsaken till problemet.

Expandera aktiviteter för att spåra rotorsaken till ett problem

Om ServiceModel ActivityTracing är inaktiverat men ServiceModel-spårning är aktiverat kan du se ServiceModel-spårningar som genereras i 0000-aktiviteten. Detta kräver dock mer arbete för att förstå korrelationen mellan dessa spårningar.

Om Meddelandeloggning är aktiverat kan du använda fliken Meddelande för att se vilket meddelande som påverkas av felet. Genom att dubbelklicka på ett meddelande i rött eller gult kan du se grafvyn över relaterade aktiviteter. Dessa aktiviteter är de som är mest relaterade till begäran där ett fel inträffade.

Om du vill börja felsöka kan du också välja en röd eller gul meddelandespårning och dubbelklicka på den för att spåra rotorsaken.

Se även

• Spårningsscenarier från slutpunkt till slutpunkt
• Visningsverktyg för tjänstspårning (SvcTraceViewer.exe)
• Spårning