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

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

Использование программы Service Trace Viewer

Средство просмотра трассировки службы 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="{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>

Трассировка ServiceModel E2E

System.ServiceModel Если источник трассировки задается с switchValue другим, кроме Off, и ActivityTracingWCF создает действия и передачу для обработки WCF.

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

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

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

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

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

• Обработано действие Add.

• Установлен безопасный сеанс (это ПРОИЗОШЛО по первому запросу) и обработаны три ответных сообщения инфраструктуры безопасности: RST, RSTR, SCT (Process message 1, 2, 3).

• Обработаны запросы "Вычесть", "Умножить" и "Разделить".

• Закрыта фабрика каналов, в результате чего закрыт безопасный сеанс и обработана отмена ответа на сообщение безопасности.

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

Примечание.

В WCF отображаются сообщения ответа, которые обрабатываются изначально в отдельном действии (сообщение процесса), прежде чем сопоставить их с соответствующим действием действия процесса, включающим сообщение запроса, через передачу. Это происходит для сообщений инфраструктуры и асинхронных запросов из-за необходимости проверки сообщения, чтения заголовка с идентификатором activityId и идентификации существующего действия Process Action с помощью этого идентификатора для корреляции с ним. Для синхронных запросов ответ блокируется и поэтому известно, к какому действию Process Action относится ответ.

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

Когда на левой панели выбирается действие, на верхней правой панели отображаются вложенные действия и трассировки, т. е. это уменьшенное иерархическое представление списка действий слева на основе выбранного родительского действия. Поскольку первым сделанным запросом является выбранное действие Process action Add, это действие содержит действие Set Up Secure Session (перенаправление в, перенаправление назад от) и трассировки фактической обработки действия Add.

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

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

На верхней правой панели отображаются все трассировки, связанные с действием Process Action Add. В частности, передано сообщение запроса ("Передано сообщение по каналу") и в том же действии принят ответ ("Получено сообщение по каналу"). Это показано на следующей диаграмме. Для ясности действие Set up Secure Session на диаграмме свернуто.

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

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

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

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

2. Создается действие Listen At для каждого прослушивателя в ServiceHost (с перенаправлениями в действие Open ServiceHost и из этого действия).

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

4. Для каждого набора байтов, полученных в соответствии с сообщением, мы обрабатываем эти байты в действии Process Message, где мы создадим объект СООБЩЕНИЯ WCF. В этом действии отображаются ошибки, связанные с неправильным конвертом или неверно сформированным сообщением.

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

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

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

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

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

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

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

Корреляция ошибок в службе и на клиенте

Образец, использованный для создания этих трассировок, представляет собой последовательность синхронных запросов, использующих привязку wsHttpBinding. Для сценариев без обеспечения безопасности или с асинхронными запросами, где действие Process Action выполняет операции начала и окончания, составляющие асинхронный вызов, и показывает перенаправления в действие обратного вызова, диаграмма будет несколько иной. Дополнительные сведения о дополнительных сценариях см. в разделе "Комплексные сценарии трассировки".

Выявление неполадок с помощью программы Service Trace Viewer

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

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

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

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

Развертывание действий для выяснения основной причины неполадки

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

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

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

См. также

• Сценарии сквозной трассировки
• Средство просмотра трассировки служб (SvcTraceViewer.exe)
• Трассировка