Май 2015

Том 30 выпуск 5

Visual Studio 2015 - Применение IntelliTrace для ускорения диагностики

Angelos Petropoulos | Май 2015

Продукты и технологии:

Visual Studio 2015 Enterprise, IntelliTrace

В статье рассматриваются:

• отладка с хронологией (historical debugging), используя IntelliTrace;
• конфигурирование отладки с хронологией;
• анализ результатов отладочной процедуры.

Подумайте о типичном рабочем процессе, применяемом вами при отладке. Пока не будет выявлена корневая причина какой-то проблемы, вы застреваете в цикле установки точек прерывания и повторения этапов тестирования, которые воспроизводят проблему. Теперь вы можете задействовать IntelliTrace для записи отладочной информации с хронологией (historical debugging information), когда приложение выполняется. Это помогает разорвать этот цикл. Вы можете лишь раз выполнить этапы тестирования, чтобы воспроизвести проблему, а затем использовать отладку с хронологией, чтобы идентифицировать корневую причину.

IntelliTrace — это набор технологий отладки с хронологией, расширяющий отладчик в Visual Studio 2015 Enterprise. Кроме того, имеется автономный компонент, который можно использовать вне Visual Studio. IntelliTrace записывает выполнение вашего приложения, отбирая интересующие вас события. Когда такое событие происходит, IntelliTrace автоматически записывает стек вызовов и состояние локальных переменных; при этом выполнение приложения продолжается. Вы можете контролировать, какие события IntelliTrace будет считать интересными, через Tools | Options | IntelliTrace | IntelliTrace Events.

IntelliTrace предоставляет вам хронологию выполнения вашего приложения, используя шкалу времени (timeline) с высокоуровневым представлением событий и таблицу, которая сообщает детали по каждому событию. Кроме того, вы получаете доступ к хронологическим отладочным данным при интеграции с отладчиком Visual Studio. Это позволяет вам возвращаться назад во времени и просматривать стек вызовов и состояние локальных переменных на момент сбора того или иного события.

IntelliTrace нашел новое пристанище в окне Diagnostic Tools в Visual Studio 2015. Окно Diagnostic Tools содержит наряду с IntelliTrace такие инструменты, как CPU Usage и Memory Usage. Если ваш тип проекта и отладочная конфигурация поддерживаются (проверяйте актуальную информацию по ссылке aka.ms/diagtoolswindow), вы увидите окно Diagnostic Tools, когда начнете отладку в Visual Studio 2015 (можно нажать F5 или самому открыть это окно в любой момент, выбрав Debug | Show Diagnostic Tools). Когда вы активируете Historical Debugging, на экране появится нечто вроде того, что показано на рис. 1.

Рис. 1. Historical Debugging с IntelliTrace

Исследуем UI

Ниже дан список всех компонентов IntelliTrace UI, их предназначения и функциональности.

Debugger Events Таблица подробных сведений Debugger Events (рис. 2) — это табличное представление событий, собранных IntelliTrace. Рассмотрим столбцы слева направо.

1. Указатель на событие, для которого отладчик показывает информацию в данный момент; только в одной строке появится желтая стрелка, указывающая текущую позицию указателя команд, и, кроме того, еще в одной строке может быть розовая стрелка, указывающая, какое событие в хронологии вы активировали.
2. Значок, представляющий это событие на временной шкале Debugger Events.
3. Краткое описание события.
4. Количество секунд от начала сеанса отладки до момента сбора данного события.
5. Длительность события (заметьте, что не у всех событий может быть длительность).
6. Идентификатор и имя потока, который сгенерировал событие (заметьте, что не все события связаны с каким-либо потоком).

Рис. 2. Таблица Debugger Events

Щелкнув событие в списке, чтобы раскрыть его, вы можете выбрать Activate Historical Debugging и перевести отладчик в точку, где IntelliTrace записал выбранное событие.

Управление фильтром категорий Этот элемент управления фильтрацией позволяет скрывать или показывать категории событий в то время, как они продолжают собираться. Если вы хотите сфокусироваться на определенной категории или если вас совершенно не интересует какая-то другая категория, то можно использовать этот элемент для ее быстрого вывода или скрытия. Текущий список категорий включает ADO.NET, ASP.NET, Console, Data Binding, Debugger, Environment Variables, Exception, File, Gesture, Lazy Initialization, Output, Registry, Service Model, Threading, Tracing, User Prompt и XAML.

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

Кнопка Show Events from External Code IntelliTrace подчиняется параметру отладчика Just My Code. Это означает, что по умолчанию он скрывает события, исходящие не из пользовательского кода; тем самым убирается лишний шум. Щелчок этой кнопки приведет к обходу данной настройки отладчика и отображению событий из внешнего кода. По большей части это ведет к чрезмерно подробному выводу.

Временная шкала Debugger Events Это графическое представление событий, собранных IntelliTrace за какое-то время. Это другое представление той же информации, которая показывается в таблице подробностей Events. Чтобы получить высокоуровневое представление, используйте временную шкалу, а чтобы идентифицировать и выбрать области, которые вы хотите изучить поглубже, — табличное представление Events. Вы можете фильтровать содержимое таблицы Events, выбирая конкретный временной диапазон.

Управляющая линейка Над временной шкалой есть управляющая линейка (ruler), которая показывает вам точку во времени, в которой происходило каждое событие. Она также позволяет выбирать конкретный временной диапазон щелчком и последующим перетаскиванием. Выберите временной диапазон для фильтрации таблицы подробностей Debugger Events.

Дорожка Break Events Всякий раз, когда происходит событие, связанное с прерыванием, оно появляется на этой дорожке временной шкалы. К событиям прерывания относятся достижение точек прерывания, выполненные шаги, щелчок кнопки Break All, вызов Debugger.Break или необработанное исключение, прерывающее выполнение. Считайте ее мастер-дорожкой временной шкалы, помогающей ориентироваться в том, где другие события происходили при выполнении программы (поскольку вы контролируете выполнение приложения с помощью точек прерывания и шагов). Щелкнув какое-то событие на этой дорожке, вы применяете временной фильтр, который будет фильтровать события в таблице Debugger Events. Тем самым вы можете легко фильтровать только те события, которые происходили при проходе строки кода или между нажатием F5 и достижением точки прерывания.

Дорожка Output Events Эта дорожка показывает события для сообщений, появляющихся в окне Output. На этой дорожке отображаются события следующих категорий: Thrown Exceptions, Program Output (или Console.WriteLine), Module Loaded/Unloaded, Thread Exit и Process Exit. Это позволяет вам соотносить стандартные сообщения отладочного вывода с остальной хронологической информацией отладчика.

Дорожка IntelliTrace Event Отображает события всех остальных категорий, собранные IntelliTrace: ADO.NET, ASP.NET, Console, Data Binding, Environment Variables, File, Gesture, Lazy Initialization, Registry, Service Model, Threading, Tracing, User Prompt и XML.

Панель инструментов Diagnostic Tools На этой панели инструментов имеют кнопки Zoom In и Zoom Out, а также кнопка Reset View для сброса временной шкалы обратно в исходный масштаб и очистки любого текущего выделения временного диапазона. Раскрывающийся список Select Tools позволяет выбирать инструменты, которые вы хотели бы включить в окно Diagnostic Tools (помимо IntelliTrace).

Вы можете одновременно запускать несколько диагностических средств. Окно Diagnostic Tools может выступать в роли хоста для параллельной работы таких средств, как Memory Usage, CPU Usage и IntelliTrace. Это дает вам комплексное представление о поведении вашего приложения. Например, на рис. 3 показано, как серия событий Module Load приводит к увеличению объема занимаемой памяти и использования процессора при запуске приложения ASP.NET.

Рис. 3. Окно Diagnostic Tools показывает, как ведет себя и работает ваше приложение

Исправление реальной ошибки с помощью IntelliTrace

Теперь я подробно опишу процесс исправления реальной ошибки, используя средства Live Debugging в IntelliTrace в Visual Studio 2015 Enterprise. Я буду отлаживать приложение Windows Forms из CodeProject под названием «SocialClub».

Приложение поддерживает базу данных членов общественного клуба. Ошибка заключается в том, что код поиска ведет себя неправильно после регистрации члена клуба. Чтобы воспроизвести эту ошибку, я запускаю приложение и регистрирую нового члена. Затем выполняю поиск Get All, который должен был бы возвращать всех зарегистрированных членов. Я ожидаю только один результат, но вместо этого получаю два (рис. 4). Второй результат поиска является неожиданным, так что именно это я и должен исправить.

Рис. 4. Результат поиска Get All содержит неожиданную запись

Что делать дальше, чтобы исправить эту ошибку? В этот момент моя гипотеза заключалась в том, что либо что-то неладно с функцией поиска Get All, либо проблема в процессе регистрации нового члена. У приложения есть другой режим поиска, который принимает конкретные критерии поиска, поэтому я воспользовался им для поиска неожиданной записи, возвращаемой Get All (с отсутствующими данными и значениями Unknown).

Вот возможные сценарии. Если я не получу никаких результатов, то, вероятно, неожиданная запись не существует в базе данных и проблема связана с функцией поиска Get All. Если же я получу результат, совпадающий с записью, где значения Occupation и MaritalStatus равны Unknown, то проблема скорее всего в функции регистрации, вводящей в базу данных больше записей, чем следовало бы.

Поэтому я выполняю поиск с Unknown для Occupation и MaritalStatus, получая ровно один результат: запись, где я успешно зарегистрировал нового члена со значениями Engineer и Married в полях Occupation и MaritalStatus соответственно. Это странно и, увы, ничуть не продвинуло меня в поисках корневой причины ошибки. Вместо траты времени на установку точек прерывания, регистрацию новых членов и поиска их записей я проверю, сможет ли IntelliTrace помочь мне ускорить расследование.

Я хочу увидеть события, собранные IntelliTrace, но события IntelliTrace не обновляются, пока отладчик не прервет выполнение приложения (т. е. пока не будет достигнута точка прерывания). Поскольку у меня нет заинтересованности в какой-либо конкретной точке прерывания, я просто щелкаю Break All на панели инструментов Visual Studio. Теперь приложение находится в состоянии прерывания, когда все потоки приостановлены. IntelliTrace отображает собранные данные как на временной шкале, так и в табличном представлении в окне Diagnostic Tools.

К этому моменту я довольно много взаимодействовал с приложением от начала отладки. Я вошел, зарегистрировал нового члена, выполнил поиск, используя Get All, а также осуществил поиск по специфическому критерию. Однако меня интересуют события, которые происходили только в ответ на щелчок кнопки Register. Чтобы отфильтровать представление и видеть лишь эти события, я перемещаю курсор мыши по событиям на временной шкале, пока не нахожу точку, где я щелкнул Register. Затем я перетаскиваю группу событий. Глядя на детализированное табличное представление после выбора времени, я замечаю, что два наиболее недавних события (отличных от нажатия Break All) относятся к двум выражениям INSERT (рис. 5).

Рис. 5. Табличное представление, отфильтрованное для отображения событий из выделенного временного диапазона

Щелчок события в списке раскрывает его в набор строк, чтобы показать полное выполненное SQL-выражение. Я вижу, что у меня два выражения INSERT. Второе вставляет неправильную запись с NULL-значениями. Вот эти два SQL-выражения:

Execute Reader "insert [dbo].[ClubMembers]([Name],
  [DateOfBirth], [Occupation], [Salary], [MaritalStatus],
  [HealthStatus], [NumberOfChildren], [ExpirationDate])values
  (@0, @1, @2, @3, @4, @5, @6, @7)
  select [Id] from [dbo].[ClubMembers] where @@ROWCOUNT > 0
  and [Id] = scope_identity()"
Execute Reader "insert [dbo].[ClubMembers]([Name],
  [DateOfBirth], [Occupation], [Salary], [MaritalStatus],
  [HealthStatus], [NumberOfChildren], [ExpirationDate])values
  (null, @0, @1, null, @2, @3, null, @4) select [Id] from
  [dbo].[ClubMembers] where @@ROWCOUNT > 0 and [Id] =
  scope_identity()"

Выражение SELECT, следующее за INSERT, можно игнорировать. Это Entity Framework извлекает идентификатор (ID) только что вставленной записи. Следующий вопрос таков: почему я получаю выполнение двух SQL-выражений для одного щелчка кнопки Register? IntelliTrace помогает мне быстро ответить на этот вопрос, позволяя мне активировать Historical Debugging (отладку с хронологией) для каждого из событий (рис. 6) и проверить хронологию состояния их стеков вызовов в окне Call Stack.

Рис. 6. Активация Historical Debugging для первого из двух выражений INSERT

Стек вызовов в хронологии для первого INSERT выглядит так:

John.SocialClub.Data.dll!John.SocialClub.Data.Service.
  ClubMemberService.Create(...)
John.SocialClub.Desktop.exe!John.SocialClub.Desktop.Forms.
  Membership.Manage.RegisterMember()
John.SocialClub.Desktop.exe!John.SocialClub.Desktop.Forms.
  Membership.Manage.Register_Click(...)
John.SocialClub.Desktop.exe!John.SocialClub.Desktop.
  Program.Main()

Стек вызовов в хронологии для второго INSERT с неправильной записью:

John.SocialClub.Data.dll!John.SocialClub.Data.Service.
  ClubMemberService.Create(...)
John.SocialClub.Desktop.exe!John.SocialClub.Desktop.Forms.
  Membership.Manage.RegisterMember()
John.SocialClub.Desktop.exe!John.SocialClub.Desktop.Forms.
  Membership.Manage.btnRegister_MouseClick(...)
John.SocialClub.Desktop.exe!John.SocialClub.Desktop.
  Program.Main()

Щелчок каждого фрейма переключает на соответствующую строку кода. После изучения двух стеков вызовов в хронологии я определил, что у меня два разных обработчика подписаны на одно и то же событие щелчка кнопки: Register_Click(…) и btnRegister_MouseClick(…). Читая код в этих двух функциях, я быстро обнаружил, что, поскольку поля формы сбрасываются после регистрации каждого нового члена, первый обработчик корректно вставляет записи в базу данных. Однако второй обработчик вставляет запись с пустыми и NULL-полями. Вот так быстро, используя Break All, а затем IntelliTrace для выявления и перехода к подозрительным частям кода, я смог найти причину ошибки.

Что делать, если событий IntelliTrace недостаточно для обнаружения причины ошибки?

К этому моменту, как бы вы ни были восхищены IntelliTrace тем, как он улучшает отладку, вас, вероятно, интересует, что делать, если IntelliTrace не записывает те события, которые могли бы привести вас к корневой причине ошибки. Не повезло? Нет, отнюдь. Не забывайте, что вы можете управлять тем, какие события IntelliTrace включены, используя Tools | Options | IntelliTrace | IntelliTrace Events. Не все из них включены по умолчанию, но даже включение всех событий не всегда будет достаточно для некоторых запутанных ошибок.

В таких случаях вы можете настроить IntelliTrace на запись не только событий, но и каждого вызова метода и передаваемых ему параметров. Просто откройте Tools | Options | IntelliTrace и выберите события и информацию IntelliTrace о вызовах. Это мощное средство отладки, но за его использование придется расплачиваться издержками при выполнении приложения. При этой настройке IntelliTrace будет перехватывать каждый вызов метода и записывает его, что сильно повлияет на скорость работы приложения. Вот почему IntelliTrace не делает этого по умолчанию.

Вы можете просматривать эту новую информацию и осуществлять навигацию в ней двумя разными способами. Можно использовать вложенную вкладку (sub-tab) Calls в таблице Debugger Events, где перечисляются все записанные вызовы (подробнее о представлении Calls см. на aka.ms/itracecalls). Другой способ — активировать Historical Debugging для события и использовать элемент управления IntelliTrace в текстовом редакторе для навигации назад и вперед по хронологии выполнения приложения. Элементы управления появляются между вашим кодом и указателем команд. Поэтому IntelliTrace обеспечивает вам поддержку во всех сценариях активной отладки (live debugging).

Как быть, если не удается воспроизвести ошибку на компьютере для разработки?

Здесь на сцене появляется Non-Live Debugging с IntelliTrace. До сих пор я исходил из того, что вам известны шаги, необходимые для воспроизведения отлаживаемой вами проблемы. Так бывает не всегда. К некоторым из наиболее трудных и требующих длительной отладки ошибок относятся те, для воспроизведения которых вам, возможно, не известны точные шаги. IntelliTrace может исключить этот неприятный сценарий «воспроизвести нельзя», позволяя вам записывать выполнение приложения в производственной или тестовой среде. Затем вы можете отлаживать его на своем компьютере для разработки, анализируя собранную информацию с помощью того же окна Diagnostic Tools.

IntelliTrace предлагает автономный сборщик, который можно развертывать в других средах, к которым Visual Studio нельзя подключить. Вы не должны столкнуться с сопротивлением со стороны администраторов, так как никакой установки здесь не требуется. Вы просто копируете сборщик в целевую среду. Сборщик записывает выполнение приложения в файл .itrace, который можно перенести на компьютер для разработки и открыть в Visual Studio. Этот сценарий называют Non-Live Debugging потому, что при отладке нельзя управлять выполнением приложения. За актуальной информацией о том, как использовать автономный сборщик IntelliTrace, обращайтесь на aka.ms/itracecollector.

Заключение

Новое средство — IntelliTrace — и его интеграция с окном Diagnostic Tools открывает ряд захватывающих возможностей. Вы можете следить за актуальной информацией об этом и других диагностических средствах в блоге aka.ms/DiagnosticsBlog.

Angelos Petropoulos — старший менеджер программ в группе Visual Studio. После получения степени магистра в проектировании объектно-ориентированного ПО работал в качестве ИТ-консультанта в Великобритании. После переезда в США присоединился к группе Diagnostic Tools в группе Visual Studio и теперь является менеджером программ по IntelliTrace.

Выражаю благодарность за рецензирование статьи экспертам Microsoft Эндрю Холлу (Andrew Hall), Дэниэлю Моту (Daniel Moth), Дэну Тейлору (Dan Taylor) и Чарльзу Уиллису (Charles Willis).