Używanie przeglądarki danych śledzenia usługi do wyświetlania skorelowanych danych śledzenia i rozwiązywania problemów
W tym temacie opisano format danych śledzenia, sposób ich wyświetlania i podejścia korzystające z przeglądarki śledzenia usługi do rozwiązywania problemów z aplikacją.
Korzystanie z narzędzia podglądu śledzenia usługi
Narzędzie Podgląd śledzenia usługi Windows Communication Foundation (WCF) ułatwia skorelowanie śladów diagnostycznych generowanych przez odbiorniki programu WCF w celu zlokalizowania głównej przyczyny błędu. Narzędzie umożliwia łatwe wyświetlanie, grupowanie i filtrowanie śladów, dzięki czemu można diagnozować, naprawiać i weryfikować problemy z usługami WCF. Aby uzyskać więcej informacji na temat korzystania z tego narzędzia, zobacz Service Trace Viewer Tool (SvcTraceViewer.exe).
Ten temat zawiera zrzuty ekranu śledzenia generowane przez uruchomienie przykładu Śledzenie i rejestrowanie komunikatów podczas wyświetlania przy użyciu narzędzia podglądu śledzenia usługi (SvcTraceViewer.exe). W tym temacie pokazano, jak zrozumieć zawartość śledzenia, działania i ich korelację oraz jak analizować dużą liczbę śladów podczas rozwiązywania problemów.
Wyświetlanie zawartości śledzenia
Zdarzenie śledzenia zawiera następujące najważniejsze informacje:
Nazwa działania po ustawieniu.
Czas emisji.
Poziom śledzenia.
Nazwa źródła śledzenia.
Nazwa procesu.
Identyfikator wątku.
Unikatowy identyfikator śledzenia, który jest adresem URL wskazującym dokumentację techniczną firmy Microsoft, która zawiera więcej informacji związanych ze śledzeniem.
Wszystkie te elementy można zobaczyć w prawym górnym panelu w Podglądzie śledzenia usługi lub w sekcji Podstawowe informacje w sformatowanym widoku panelu w prawym dolnym rogu podczas wybierania śladu.
Uwaga
Jeśli klient i usługa znajdują się na tym samym komputerze, ślady obu aplikacji będą obecne. Można je filtrować przy użyciu kolumny Nazwa procesu.
Ponadto sformatowany widok zawiera również opis śledzenia i dodatkowych szczegółowych informacji, jeśli są dostępne. Ten ostatni może obejmować typ wyjątku i komunikat, stosy wywołań, akcję komunikatu, z/do pól i inne informacje o wyjątku.
W widoku XML przydatne tagi XML obejmują następujące elementy:
<SubType>(poziom śledzenia).<TimeCreated>.<Source>(nazwa źródła śledzenia).<Correlation>(identyfikator działania ustawiony podczas emitowania śledzenia).<Execution>(identyfikator procesu i wątku).<Computer>.<ExtendedData>, w tym<Action><MessageID>, i<ActivityId>zestaw w nagłówku wiadomości podczas wysyłania komunikatu.
Jeśli zbadasz ślad "Wysłano komunikat za pośrednictwem kanału", może zostać wyświetlona następująca zawartość.
<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="{27c6331d-8998-43aa-a382-03239013a6bd}"/>
<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="b02e2189-0816-4387-980c-dd8e306440f5" xmlns="http://schemas.microsoft.com/2004/09/ServiceModel/Diagnostics">27c6331d-8998-43aa-a382-03239013a6bd</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>
Śledzenie modelu ServiceModel E2E
System.ServiceModel Gdy źródło śledzenia jest ustawione z switchValue innym niż wyłączone, a ActivityTracingprogram WCF tworzy działania i transfery na potrzeby przetwarzania WCF.
Działanie jest jednostką logiczną przetwarzania, która grupuje wszystkie ślady związane z tym jednostką przetwarzania. Można na przykład zdefiniować jedno działanie dla każdego żądania. Transfery tworzą relację przyczynową między działaniami w punktach końcowych. Propagacja identyfikatora działania umożliwia powiązanie działań między punktami końcowymi. Można to zrobić, ustawiając propagateActivity=true konfigurację w każdym punkcie końcowym. Działania, transfery i propagacja umożliwiają wykonywanie korelacji błędów. W ten sposób można szybciej znaleźć główną przyczynę błędu.
Na kliencie jest tworzone jedno działanie WCF dla każdego wywołania modelu obiektów (na przykład Open ChannelFactory, Add, Divide itd.). Każde wywołanie operacji jest przetwarzane w działaniu "Akcja procesu".
Na poniższym zrzucie ekranu wyodrębniony z przykładu Śledzenie i rejestrowanie komunikatów na panelu po lewej stronie wyświetla listę działań utworzonych w procesie klienta, posortowanych według czasu utworzenia. Poniżej przedstawiono chronologiczną listę działań:
Zbudowano fabrykę kanałów (ClientBase).
Otwarto fabrykę kanałów.
Przetworzyliśmy akcję Dodaj.
Skonfiguruj sesję zabezpieczeń (wystąpiło to w pierwszym żądaniu) i przetworzyliśmy trzy komunikaty odpowiedzi infrastruktury zabezpieczeń: RST, RSTR, SCT (komunikat procesu 1, 2, 3).
Przetworzone żądania odejmów, mnożenia i dzielenia.
Zamknął fabrykę kanałów i zamknął sesję Secure i przetworzył odpowiedź komunikatu zabezpieczeń Anuluj.
Zobaczymy komunikaty infrastruktury zabezpieczeń z powodu wsHttpBinding.
Uwaga
W programie WCF pokazujemy komunikaty odpowiedzi przetwarzane początkowo w osobnym działaniu (komunikat procesu), zanim skorelujemy je z odpowiednim działaniem akcji procesu, które zawiera komunikat żądania za pośrednictwem transferu. Dzieje się tak w przypadku komunikatów infrastruktury i żądań asynchronicznych i wynika to z faktu, że musimy sprawdzić komunikat, odczytać nagłówek activityId i zidentyfikować istniejące działanie akcji procesu z tym identyfikatorem, aby je skorelować. W przypadku żądań synchronicznych blokujemy odpowiedź i dlatego wiemy, z którą akcją procesu odnosi się odpowiedź.
Na poniższej ilustracji przedstawiono działania klienta programu WCF wymienione przez czas tworzenia (panel po lewej stronie) oraz ich zagnieżdżone działania i ślady (w prawym górnym panelu):
Po wybraniu działania w panelu po lewej stronie zobaczymy zagnieżdżone działania i ślady w prawym górnym panelu. W związku z tym jest to ograniczony hierarchiczny widok listy działań po lewej stronie na podstawie wybranego działania nadrzędnego. Ponieważ wybrana akcja Proces Dodaj jest pierwszym żądaniem, to działanie zawiera działanie Konfigurowanie bezpiecznej sesji (transfer do, transfer z powrotem) i ślady rzeczywistego przetwarzania akcji Dodaj.
Jeśli dwukrotnie klikniemy akcję Proces Dodaj działanie w panelu po lewej stronie, zobaczymy graficzną reprezentację działań klienta WCF związanych z dodawaniem. Pierwsze działanie po lewej stronie to działanie główne (0000), które jest działaniem domyślnym. Program WCF przenosi z otoczenia działania. Jeśli to nie jest zdefiniowane, program WCF przesyła z 0000. W tym miejscu drugie działanie, Dodawanie akcji procesu, transferuje z 0. Następnie zostanie wyświetlona opcja Konfiguracja bezpiecznej sesji.
Na poniższej ilustracji przedstawiono widok grafów działań klienta programu WCF, w szczególności działania otoczenia (tutaj 0), akcji procesu i konfigurowania bezpiecznej sesji:
W prawym górnym panelu możemy zobaczyć wszystkie ślady związane z działaniem Dodawanie akcji procesu. W szczególności wysłaliśmy komunikat żądania ("Wysłano komunikat za pośrednictwem kanału") i odebraliśmy odpowiedź ("Odebrano komunikat za pośrednictwem kanału") w tym samym działaniu. Jest to pokazane na poniższym wykresie. W celu zapewnienia przejrzystości działanie Konfigurowanie bezpiecznej sesji jest zwinięte na grafie.
Na poniższej ilustracji przedstawiono listę śladów działania akcji procesu. Wysyłamy żądanie i odbieramy odpowiedź w tym samym działaniu.
W tym miejscu załadujemy ślady klienta tylko w celu zapewnienia przejrzystości, ale ślady usługi (komunikat żądania odebrany i wysłany komunikat odpowiedzi) są wyświetlane w tym samym działaniu, jeśli są również ładowane do narzędzia i propagateActivity zostały ustawione na true. Wartość Ta jest pokazana na późniejszej ilustracji.
W usłudze model działania jest mapowy na pojęcia związane z usługą WCF w następujący sposób:
Tworzymy i otwieramy element ServiceHost (może to spowodować utworzenie kilku działań związanych z hostem, na przykład w przypadku zabezpieczeń).
Tworzymy działanie Listen At dla każdego odbiornika w obiekcie ServiceHost (z transferami w i poza hostem Open ServiceHost).
Gdy odbiornik wykryje żądanie komunikacji zainicjowane przez klienta, przesyła je do działania "Odbierz bajty", w którym są przetwarzane wszystkie bajty wysyłane z klienta. W tym działaniu możemy zobaczyć wszelkie błędy połączenia, które wystąpiły podczas interakcji z usługą klienta.
Dla każdego zestawu bajtów, który odpowiada komunikatowi, przetwarzamy te bajty w działaniu "Komunikat procesu", w którym tworzymy obiekt Komunikat programu WCF. W tym działaniu widzimy błędy związane z nieprawidłową kopertą lub źle sformułowanym komunikatem.
Po utworzeniu komunikatu przenosimy do działania Akcja procesu. Jeśli
propagateActivityjest ustawionatruena wartość zarówno dla klienta, jak i usługi, to działanie ma ten sam identyfikator co ten zdefiniowany w kliencie i opisany wcześniej. Na tym etapie zaczniemy korzystać z bezpośredniej korelacji między punktami końcowymi, ponieważ wszystkie ślady emitowane w programie WCF powiązane z żądaniem znajdują się w tym samym działaniu, w tym w przetwarzaniu komunikatów odpowiedzi.W przypadku akcji poza procesem utworzymy działanie "Wykonaj kod użytkownika", aby odizolować ślady emitowane w kodzie użytkownika od tych emitowanych w programie WCF. W poprzednim przykładzie ślad "Usługa wysyła odpowiedź" jest emitowany w działaniu "Wykonaj kod użytkownika", a nie w działaniu propagowanym przez klienta, jeśli ma to zastosowanie.
Na poniższej ilustracji pierwsze działanie po lewej stronie to działanie główne (0000), które jest działaniem domyślnym. Następne trzy działania to otwarcie elementu ServiceHost. Działanie w kolumnie 5 jest odbiornikiem, a pozostałe działania (od 6 do 8) opisują przetwarzanie komunikatu w programie WCF z przetwarzania bajtów po aktywację kodu użytkownika.
Na poniższej ilustracji przedstawiono widok wykresu działań usługi WCF:
Poniższy zrzut ekranu przedstawia działania zarówno klienta, jak i usługi, oraz wyróżnia działanie Dodawanie akcji procesu między procesami (pomarańczowy). Strzałki odnoszą komunikaty żądania i odpowiedzi wysyłane i odbierane przez klienta i usługę. Ślady akcji procesu są oddzielone między procesami na grafie, ale wyświetlane jako część tego samego działania w prawym górnym panelu. Na tym panelu można zobaczyć ślady klientów dla wysłanych komunikatów, a następnie ślady usługi dla odebranych i przetworzonych komunikatów.
Na poniższych obrazach przedstawiono widok wykresu działań klienta i usługi WCF
W poniższym scenariuszu błędu powiązane są ślady błędów i ostrzeżeń w usłudze i kliencie. Wyjątek jest zgłaszany po raz pierwszy w kodzie użytkownika w usłudze (najbardziej zielone działanie z prawej strony, które zawiera ślad ostrzeżenia dla wyjątku "Usługa nie może przetworzyć tego żądania w kodzie użytkownika". Po wysłaniu odpowiedzi do klienta ponownie jest emitowany ślad ostrzegawczy, aby oznaczyć komunikat o błędzie (pozostawiono różową aktywność). Następnie klient zamyka klienta WCF (żółte działanie po lewej stronie), co przerywa połączenie z usługą. Usługa zgłasza błąd (najdłuższe różowe działanie po prawej stronie).
Korelacja błędów w usłudze i kliencie
Przykład używany do generowania tych śladów to seria synchronicznych żądań przy użyciu metody wsHttpBinding. Istnieją odchylenia od tego grafu dla scenariuszy bez zabezpieczeń lub z żądaniami asynchronicznymi, w których działanie Akcja procesu obejmuje operacje rozpoczęcia i zakończenia, które stanowią wywołanie asynchroniczne, i pokazuje transfery do działania wywołania zwrotnego. Aby uzyskać więcej informacji na temat dodatkowych scenariuszy, zobacz Kompleksowe scenariusze śledzenia.
Rozwiązywanie problemów przy użyciu przeglądarki śledzenia usługi
Podczas ładowania plików śledzenia w narzędziu Service Trace Viewer można wybrać dowolne czerwone lub żółte działanie na panelu po lewej stronie, aby śledzić przyczynę problemu w aplikacji. Działanie 000 zwykle ma nieobsługiwane wyjątki, które są bąbelkowe do użytkownika.
Na poniższej ilustracji przedstawiono sposób wybierania czerwonego lub żółtego działania w celu zlokalizowania katalogu głównego problemu.
W prawym górnym panelu możesz sprawdzić ślady działania wybranego po lewej stronie. Następnie możesz zbadać czerwone lub żółte ślady na tym panelu i zobaczyć, jak są one skorelowane. Na powyższym grafie widzimy ślady ostrzeżeń zarówno dla klienta, jak i usługi w tym samym działaniu akcji procesu.
Jeśli te ślady nie zapewniają głównej przyczyny błędu, możesz użyć grafu, klikając dwukrotnie wybrane działanie na panelu po lewej stronie (tutaj akcja Proces). Następnie zostanie wyświetlony wykres z powiązanymi działaniami. Następnie możesz rozwinąć powiązane działania (klikając znaki "+", aby znaleźć pierwszy emitowany ślad w kolorze czerwonym lub żółtym w powiązanym działaniu. Kontynuuj rozszerzanie działań, które miały miejsce tuż przed czerwonym lub żółtym śladem zainteresowania, po transferach do powiązanych działań lub przepływów komunikatów między punktami końcowymi, dopóki nie prześledzisz głównej przyczyny problemu.
Rozszerzanie działań w celu śledzenia głównej przyczyny problemu
Jeśli model ServiceModel jest wyłączony, ale śledzenie usługi ServiceModel ActivityTracing jest włączone, możesz zobaczyć ślady modelu ServiceModel emitowane w działaniu 0000. Wymaga to jednak więcej wysiłku, aby zrozumieć korelację tych śladów.
Jeśli rejestrowanie komunikatów jest włączone, możesz użyć karty Komunikat, aby zobaczyć, który komunikat ma wpływ na błąd. Klikając dwukrotnie komunikat w kolorze czerwonym lub żółtym, możesz wyświetlić widok wykresu powiązanych działań. Te działania są najbardziej powiązane z żądaniem, w którym wystąpił błąd.
Aby rozpocząć rozwiązywanie problemów, możesz również wybrać czerwony lub żółty ślad komunikatu i kliknąć go dwukrotnie, aby śledzić główną przyczynę.