Использование инструмента просмотра трассировок для просмотра коррелированных трассировок и устранения неполадок

В этом разделе описывается формат данных трассировки, его просмотр и подходы, использующие средство просмотра трассировки службы для устранения неполадок приложения.

Использование средства просмотра трассировки службы

Средство просмотра трассировки службы Windows Communication Foundation (WCF) помогает сопоставить диагностические трассировки, созданные прослушивателями WCF, чтобы найти первопричину ошибки. Это средство позволяет легко просматривать, группировать и фильтровать трассировки, чтобы можно было диагностировать, восстанавливать и проверять проблемы со службами WCF. Дополнительные сведения об использовании этого средства см. в разделе Средство просмотра трассировки службы (SvcTraceViewer.exe).

В этом разделе содержатся снимки экрана трассировок, созданные с помощью примера «Трассировка и ведение журнала сообщений», при просмотре с помощью инструмента просмотра трассировки службы (SvcTraceViewer.exe). В этом разделе показано, как понять содержимое трассировки, действия и их корреляцию, а также как анализировать большое количество трассировок при устранении неполадок.

Просмотр содержимого трассировки

Трассировочное событие содержит следующие наиболее важные сведения

• Название активности при установке.

• Время выбросов.

• Уровень отслеживания.

• Имя источника трассировки.

• имя процесса;

• Идентификатор потока.

• Уникальный идентификатор трассировки, который является URL-адресом, указывающим на техническую ссылку Майкрософт, которая предоставляет дополнительные сведения, связанные с трассировкой.

Все это можно увидеть на правой верхней панели в средстве просмотра трассировки служб или в разделе "Базовая информация " в отформатируемом представлении нижней правой панели при выборе трассировки.

Кроме того, форматированное представление также содержит описание трассировки и дополнительных подробных сведений при наличии. Последний может включать тип исключения и сообщение, стеки вызовов, операцию с сообщением, поля 'от'/'до' и другие сведения об исключении.

В представлении XML полезные xml-теги включают следующие:

• <SubType> (уровень трассировки).

• <TimeCreated>.

• <Source> (имя источника трассировки).

• <Correlation> (идентификатор активности, установленный в ходе создания трассировки).

• <Execution> (идентификатор процесса и потока).

• <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 Если источник трассировки настроен с switchValue значением отличным от Off, то ActivityTracing WCF создает активности и передачи для обработки в WCF.

Действие — это логическая единица обработки, которая группирует все трассировки, связанные с этой единицей обработки. Например, можно определить одно действие для каждого запроса. Передача данных создает причинную связь между действиями в конечных точках. Распространение идентификатора действия позволяет связывать действия между конечными точками. Это можно сделать, установив propagateActivity=true в конфигурации на каждой конечной точке. Действия, передачи и распространение позволяют выполнять корреляцию ошибок. Таким образом, можно быстро найти первопричину ошибки.

На клиенте для каждого вызова объектной модели создается одно действие WCF (например, Open ChannelFactory, Add, Divide и т. д.). Каждый вызов операции обрабатывается в действии "Действие процесса".

На следующем снимке экрана, извлеченном из примера "Трассировка и ведение журнала сообщений ", на левой панели отображается список действий, созданных в процессе клиента, отсортированных по времени создания. Ниже приведен хронологический список действий:

• Создана фабрика каналов (ClientBase).

• Открыл фабрику каналов.

• Обработано действие "Добавить".

• Установите защищённый сеанс (это произошло на первом запросе) и обработайте три ответных сообщения инфраструктуры безопасности: RST, RSTR, SCT (обработка сообщения 1, 2, 3).

• Обработаны запросы вычитания, умножения и деления.

• Закрыли фабрику каналов, таким образом закрыли сеанс Secure и обработали ответ отмены сообщения безопасности.

Мы видим сообщения инфраструктуры безопасности из-за wsHttpBinding.

На следующем рисунке показаны действия клиента WCF, перечисленные по времени создания (в левой панели) и их вложенные действия и трассировки (правая панель).

При выборе действия на левой панели, мы видим дополнительные действия и трассировки на верхней правой панели. Таким образом, слева представлена сокращенная иерархическая структура списка действий на основе выбранного родительского действия. Так как выбранное действие процесса "Добавить" является первым запросом, это действие содержит действие "Настройка безопасного сеанса" (передача туда и обратно) и трассировки для фактической обработки действия "Добавить".

Если дважды щелкнуть действие "Добавить действие процесса" на левой панели, можно увидеть графическое представление действий WCF клиента, связанных с добавлением. Первое действие слева — это корневое действие (0000), которое является действием по умолчанию. WCF переносится из фоновой активности. Если это не определено, WCF передает за пределы 0000. Здесь, второе действие, добавление действия процесса, передается из 0. Затем мы видим, как настроить безопасный сеанс.

На следующем изображении показано представление графа действий клиента WCF, в частности фоновой активности (здесь 0), действия процесса и установления безопасного сеанса:

На правой верхней панели отображаются все трассировки, связанные с действием "Добавление действия процесса". В частности, мы отправили сообщение запроса ("Отправлено сообщение по каналу") и получили ответ ("Получено сообщение по каналу") в том же действии. Это показано на следующем графике. Для ясности действие "Настройка безопасного сеанса" свернуто на графике.

На следующем изображении показан список трассировок для операции "Процесс действия". Мы отправляем запрос и получаем ответ в той же активности.

Здесь мы загружаем только трассировки клиентов для ясности, но трассировки служб (полученные сообщения запроса и отправленные ответы) также появляются в той же активности, если они загружены в инструменте и propagateActivity установлено значение true.. Это показано на следующем рисунке.

В службе модель действий сопоставляется с концепциями WCF следующим образом:

1. Мы создаем и открываем ServiceHost (это может привести к выполнению нескольких процедур, связанных с хостом, например, в случае безопасности).

2. Мы создаём Listen At activity для каждого прослушивателя в ServiceHost (с передачей и выходом из Open ServiceHost).

3. Когда прослушиватель обнаруживает запрос на связь, инициированный клиентом, он передается в действие "Получение байтов", в котором обрабатываются все байты, отправляемые клиентом. В этом действии можно увидеть любые ошибки подключения, которые произошли во время взаимодействия с клиентом.

4. Для каждого набора байтов, полученных, соответствующих сообщению, мы обрабатываем эти байты в действии Process Message, где мы создаем объект WCF Message. В рамках этого мероприятия мы видим ошибки, связанные с проблемным конвертом или искаженным сообщением.

5. Когда сообщение будет сформировано, мы переходим к действию "Процесс действий". Если propagateActivity установлено на true как на клиенте, так и на службе, эта активность имеет тот же идентификатор, что и у клиента, и описанная ранее. На этом этапе мы начинаем извлекать выгоду из прямой корреляции между конечными точками, так как все трассировки, эмитированные в WCF и связанные с запросом, присутствуют в той же активности, включая обработку ответных сообщений.

6. Для внепроцессного действия мы создаем операцию "Выполнить пользовательский код", чтобы изолировать трассировки, создаваемые в пользовательском коде, от тех, которые были созданы в WCF. В предыдущем примере результат трассировки "Служба отправляет ответ на добавление" создается в действии "Выполнение пользовательского кода", а не в действии, инициированном клиентом, если это применимо.

На следующем рисунке первое действие слева является корневым действием (0000), которое является действием по умолчанию. Следующие три действия — открыть ServiceHost. Действие в столбце 5 — прослушиватель, а остальные действия (от 6 до 8) описывают обработку сообщения WCF, от обработки байтов до активации пользовательского кода.

На следующем рисунке показано представление графа действий службы WCF:

На следующем снимке экрана показаны активности для клиента и службы, а также выделено действие «Добавить действие процесса» между процессами (оранжевым). Стрелки показывают связь между сообщениями запроса и ответа, отправленными и полученными клиентом и службой. Трассировки действия процесса разделены между процессами в графе, но отображаются как часть того же действия на правой верхней панели. На этой панели можно увидеть трассировки клиентов для отправленных сообщений, за которыми следует трассировка служб для полученных и обработанных сообщений.

На следующих изображениях показано представление графа действий клиента и службы WCF.

В следующем сценарии ошибки, трассировки ошибок и предупреждений в службе и клиенте связаны. Исключение сначала создается в пользовательском коде службы (правой частью зеленого действия, включающее трассировку предупреждения для исключения "Служба не может обработать этот запрос в пользовательском коде."). Когда ответ отправляется клиенту, трассировка предупреждения снова создается, чтобы обозначить сообщение об ошибке (левое розовое действие). Затем клиент закрывает свой клиент WCF (желтое действие в левой нижней части), что прерывает подключение к службе. Сервис выдает ошибку (самая длинная розовая активность справа).

Корреляция ошибок между службой и клиентом

Пример, используемый для создания этих трассировок, представляет собой ряд синхронных запросов с помощью wsHttpBinding. Существует отклонение от этого графа для сценариев без безопасности или с асинхронными запросами, где действие действия процесса охватывает начальные и конечные операции, составляющие асинхронный вызов, и показывает передачу в действие обратного вызова. Дополнительные сведения о дополнительных сценариях см. в разделе "КонечныеTo-End сценарии трассировки".

Устранение неполадок с помощью средства просмотра служебных трассировок

При загрузке файлов трассировки в средстве просмотра трассировки службы можно выбрать любое красное или желтое действие на левой панели, чтобы отследить причину проблемы в приложении. Действие 000 обычно содержит необработанные исключения, которые передаются пользователю.

На следующем рисунке показано, как выбрать красное или желтое действие, чтобы найти корень проблемы.

На верхней правой панели вы можете изучить следы выбранной активности слева. Затем можно проверить красные или желтые трассировки на этой панели и увидеть, как они коррелируются. На приведенном выше графике отображаются трассировки предупреждений для клиента и сервиса в одном действии процесса.

Если эти трассировки не предоставляют первопричину ошибки, вы можете использовать граф, дважды щелкнув выбранное действие на левой панели (здесь действие обработки). Затем отображается граф со связанными действиями. Затем можно развернуть связанные действия, щелкнув знаки "+", чтобы в связанном действии найти первую трассу, выделенную красным или жёлтым цветом. Продолжайте расширять действия, которые произошли непосредственно перед красной или желтой интересующей трассировкой, следуя к связанным действиям или потокам сообщений через конечные точки, пока не будет найдена первопричина проблемы.

Расширение действий для отслеживания первопричин проблемы

Если ServiceModel ActivityTracing отключен, но трассировка ServiceModel включена, можно увидеть трассировки ServiceModel, созданные в действии 0000. Однако для этого требуется больше усилий, чтобы понять корреляцию этих трассировок.

Если включено ведение журнала сообщений, можно использовать вкладку "Сообщение", чтобы увидеть, какое сообщение влияет на ошибку. Дважды щелкнув на сообщение, выделенное красным или желтым цветом, вы можете увидеть представление графа связанных действий. Эти действия наиболее тесно связаны с запросом, в котором произошла ошибка.

Чтобы начать устранение неполадок, можно также выбрать красную или желтую трассировку сообщений и дважды щелкнуть ее, чтобы отслеживать первопричину.

См. также

• Конечные сценарии трассировкиTo-End
• Инструмент просмотра трассировок службы (SvcTraceViewer.exe)
• Трассировка