Профилировщики времени

C# и .NET Framework --- Оптимизация приложений .NET Framework --- Профилировщики времени

Счетчики производительности и механизм ETW, рассмотренные ранее, позволяют получить массу любопытной информации о производительности приложений для Windows, однако часто бывает желательно иметь инструменты - профилировщики - позволяющие оценить время выполнения на уровне методов и отдельных строк кода (что можно рассматривать, как улучшенную поддержку трассировки стека вызовов в ETW). В этой статье будет представлено несколько коммерческих инструментов и описаны их преимущества, но имейте в виду, что более мощные и точные инструменты влекут за собой более высокие накладные расходы.

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

Первый профилировщик, с которым мы познакомимся, является частью Visual Studio и входит в состав этой среды разработки, начиная с версии Visual Studio 2005 (редакция Team Suite). Мы будем использовать профилировщик из Visual Studio 2012, доступный в редакциях Premium и Ultimate.

Дискретный профилировщик Visual Studio

Профилировщик Visual Studio действует подобно флагу profile механизма ETW. Он периодически прерывает работу приложения и сохраняет информацию о стеке вызовов для каждого процессора, где в настоящий момент протекает выполнение приложения или потока. В отличие от провайдера ядра ETW, этот дискретный профилировщик может прерывать работу процессов, опираясь на разные критерии, часть из которых перечислена в таблице ниже:

Сбор информации с использованием профилировщика Visual Studio обходится достаточно недорого, и если интервал следования событий достаточно широк (по умолчанию он составляет 10 000 000 тактов часов CPU), накладные расходы в общем времени выполнения приложения будут составлять менее 5%. Кроме того, дискретный подход к сбору информации позволяет подключиться к выполняющемуся процессу, собрать данные в течение некоторого времени и затем отключиться от процесса, чтобы проанализировать их. Из-за этой особенности, выявление проблем производительности рекомендуется начинать с поиска участков программы, оказывающих самую большую нагрузку на процессор - методов, на выполнение которых тратится больше всего процессорного времени.

По окончании сеанса сбора информации, профилировщик генерирует сводные таблицы, где каждый метод характеризуется двумя значениями: числом исключительных попаданий (exclusive samples), когда в момент отбора очередной порции данных на CPU выполнялся данный метод, и числом включительных попаданий (inclusive samples), когда выполнялся данный метод или вызванный им. Методы с большим количеством исключительных попаданий оказывают самую большую нагрузку на процессор; методы с большим количеством включительных попаданий не используют процессор непосредственно, но вызывают другие методы, суммарно занимающие значительную часть процессорного времени. (Например, в однопоточных приложениях метод Main() будет иметь 100% включительных попаданий.)

Запуск дискретного профилировщика Visual Studio

Самый простой способ запустить дискретный профилировщик - воспользоваться интерфейсом Visual Studio, хотя (как будет показано ниже) он также может запускаться из командной строки для профилирования действующих приложений. Для проведения данного эксперимента мы рекомендуем использовать одно из ваших собственных приложений.

1. В Visual Studio выберите пункт меню Analyze -> Launch Performance Wizard (Анализ --> Запустить мастер производительности).

2. На первой странице мастера отметьте радиокнопку CPU sampling (Выборка циклов ЦП (рекомендуется)) и щелкните на кнопке Next.

3. Если проект для профилирования загружен в текущем решении, щелкните на радиокнопке One or more available projects (Один или несколько доступных проектов) и выберите проект из списка. В противном случае щелкните на радиокнопке An executable (.EXE file) (Исполняемый файл). Щелкните на кнопке Next.

4. Если на предыдущем шаге вы выбрали параметр An executable (.EXE file), укажите профилировщику путь к выполняемому файлу и аргументы командной строки, если они необходимы, затем щелкните на кнопке Next. (Если у вас нет собственного подходящего приложения, используйте JackCompiler.exe из исходников.)

5. Оставьте флажок Launch profiling after the wizard finishes (Запустить профилирование после завершения работы мастера) отмеченным и щелкните на кнопке Finish (Готово).

6. Если среда разработки Visual Studio была запущена не с привилегиями администратора, вам будет предложено повысить привилегии профилировщика.

7. Когда приложение завершит выполнение, откроется отчет профилирования. Используйте раскрывающийся список Current View (Текущее представление) для навигации между представлениями, отображающими информацию, собранную в процессе профилирования.

По окончании сеанса профилирования можно также воспользоваться обозревателем производительности - Performance Explorer, чтобы запустить его, выберите пункт меню Analyze -> Windows -> Performance Explorer (Анализ --> Окна --> Обозреватель производительности). С его помощью можно изменить параметры профилирования (например, выбрать другой интервал опроса или установить другой критерий), изменить целевой файл и сравнить результаты разных сеансов профилирования.

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

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

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

На первый взгляд кажется, что дискретный мониторинг дает достаточно точные результаты, позволяющие судить о расходовании процессорного времени. Вы могли слышать утверждения, что «если данный метод имеет 65% исключительных попаданий, значит на его выполнение тратится 65% процессорного времени».

Из-за статистической природы дискретного мониторинга, такие рассуждения являются неоправданными и должны отметаться на практике. Есть несколько факторов, способных внести погрешность в результаты измерений: тактовая частота часов CPU может сотни раз в секунду изменяться в ходе выполнения приложения, из-за чего может искажаться корреляция между числом попаданий и фактическим количеством тактов часов процессора; метод может быть представлен недостаточно, когда моменты отбора информации не совпадают с моментами его выполнения; метод может быть представлен чрезмерно, когда моменты отбора информации наоборот совпадают с моментами его выполнения, но в действительности метод работает совсем непродолжительное время.

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

Помимо количества исключительных/включительных попаданий для каждого метода, профилировщик Visual Studio предлагает массу другой ценной информации. Займитесь его исследованием самостоятельно - представление Call Tree (Дерево вызовов) отображает иерархию вызовов методов в приложении (сравните с нисходящим анализом в PerfMonitor), представление Lines (Строки) отображает информацию о попаданиях на уровне строк, а представление Modules (Модули) группирует методы по сборкам, и может помочь быстро выяснить, в каком направлении двигаться в поисках узких мест.

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

Инструментированный профилировщик Visual Studio

Профилировщик Visual Studio поддерживает еще один режим работы, называемый инструментированным профилированием (instrumentation profiling), позволяющий измерить общее время выполнения, а не только процессорное время. Он хорошо подходит для профилирования приложений, выполняющих большое количество операций ввода/вывода или интенсивно использующих механизмы синхронизации.

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

public static int MyMethod(int count)
{
    List<int> evens = new List<int>();
    for (int i = 0; i < count; ++i)
        if (i % 2 == 0)
            evens.Add(i);

    return evens.Count;
}

Для оценки характеристик производительности этого метода, профилировщик Visual Studio изменит его. Помните, что изменению подвергается двоичный выполняемый файл - исходный код никак при этом не изменяется, но вы всегда сможете исследовать измененный двоичный файл с применением дизассемблера IL, такого как .NET Reflector:

public static int mmid = (int)
	Microsoft.VisualStudio.Instrumentation.g_fldMMID_2D71B909-C28E-4fd9-A0E7-ED05264B707A;
	
public static int MyMethod(int count) {
	_CAP_Enter_Function_Managed(mmid, 0x600000b, 0);
	_CAP_StartProfiling_Managed(mmid, 0x600000b, 0xa000018);
	_CAP_StopProfiling_Managed(mmid, 0x600000b, 0);
	
	List<int> evens = new List<int>();
	for (int i = 0; i < count; ++i)
		if (i % 2 == 0)
			_CAP_StartProfiling_Managed(mmid, 0x600000b, 0xa000019);
			evens.Add(i);
			_CAP_StopProfiling_Managed(mmid, 0x600000b, 0);
	_CAP_StartProfiling_Managed(mmid, 0x600000b, 0xa00001a);
	_CAP_StopProfiling_Managed(mmid, 0x600000b, 0);
	
	return evens.Count;
}

Вызовы методов, имена которых начинаются с приставки _CAP - это обращения к модулю VSPerf110.dll, на который ссылается инструментированная сборка. Они отвечают за измерение интервалов времени и запись счетчиков вызовов методов. Так как механизм учета перехватывает все вызовы методов, выполненные из инструментированного метода, информация, получаемая в результате инструментированного профилирования, может быть очень точной.

Если то же самое приложение, представленное на рисунках выше запустить в инструментированном режиме (вы можете сделать это с приложением JackCompiler.exe из исходников), профилировщик сгенерирует отчет с представлением Summary (Сводка), содержащим похожую информацию - о наиболее затратных ветвях в стеке вызовов и отдельные функциях, на выполнение которых тратится больше всего времени. Однако на этот раз информация в отчете будет основана не на дискретном мониторинге (позволяющем измерять только потоки, выполняющиеся на CPU), а на точном хронометраже, проводимом инструментированным кодом.

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

Как видно на рисунке, метод System.String.Concat() уже не выглядит узким местом в смысле производительности, теперь внимание сместилось к методам JackCompiler.Tokenizer.NextChar() и JackCompiler.Token..ctor. Первый из них был вызван почти миллион раз.

Приложение, использовавшееся для создания отчетов на рисунках выше не является исключительно вычислительным. Фактически, большую часть времени оно тратит в ожидании завершения операций ввода/вывода. Это объясняет отличия результатов дискретного мониторинга, указывающих, что наиболее дорогостоящим является метод System.String.Concat(), от результатов инструментированного профилирования, согласно которым узким местом является метод JackCompiler.Tokenizer.NextChar().

Инструментированное профилирование выглядит более точным, но на практике рекомендуется использовать дискретное профилирование, если приложение в основном решает вычислительные задачи. Прием инструментирования имеет ограниченную гибкость из-за необходимости изменять выполняемый файл приложения перед запуском и невозможности подключить профилировщик к уже запущенному процессу. Кроме того, инструментированное профилирование имеет немалые накладные расходы - объем выполняемого кода существенно увеличивается и в процессе выполнения часть времени затрачивается на отбор информации в точках входа и выхода из методов. (Некоторые инструментированные профилировщики предлагают режим построчного профилирования кода, когда каждая строка окружается кодом профилировщика, выполняющим измерения - такой код работает еще медленнее!)

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

Дополнительные приемы использования профилировщиков времени

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

Советы по дискретному профилированию

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

Профилировщик окажется весьма ценным инструментом для выявления участков кода, где наиболее часто возникают промахи кеша и ошибки чтения страниц в этих приложениях. (Используя прием инструментированного профилирования так же можно собирать информацию о различных счетчиках CPU, таких как промахи кеша, фактически выполненные машинные инструкции и ошибочно предсказанные ветвления. Для этого откройте диалог свойств сеанса профилирования в панели Performance Explorer и перейдите на вкладку CPU Counters. Собранная информация будет доступна в представлении Functions в виде дополнительных столбцов.)

Дискретное профилирование в целом обладает большей гибкостью, чем инструментированное. Например, в панели Performance Explorer можно подключить профилировщик (в дискретном режиме) к уже запущенному процессу.

Сбор дополнительных данных при профилировании

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

Совет. Профилировщик Visual Studio экспортирует свой API, который может использоваться приложениями для приостановки и возобновления профилирования программным способом. Эту возможность можно использовать, чтобы отключить сбор данных в неинтересных частях приложения и уменьшить размер файлов с данными профилировщика. За дополнительной информацией о доступных методах профилировщика обращайтесь к документации на сайте MSDN - API-интерфейсы профилировщика.

Профилировщик может также собирать информацию из счетчиков производительности Windows и провайдеров событий ETW. Для этого откройте диалог свойств сеанса профилирования в панели Performance Explorer и перейдите на вкладку Windows Events (События Windows) или Windows Counters (Счетчики Windows). Данные ETW можно просмотреть только из командной строки, с помощью команды:

VSPerfReport /summary: ETW

Счетчики производительности будут доступны в представлении Marks, в интерфейсе Visual Studio.

Наконец, если Visual Studio тратит слишком много времени на создание отчета с большим количеством данных, можно избежать этих затрат, щелкнув правой кнопкой мыши на отчете в панели Performance Explorer и выбрать пункт контекстного Save Analyzed Report (Сохранить проанализированный отчет). Сохраненные файлы отчетов имеют расширение .vspx и открываются практически мгновенно.

Рекомендации профилировщика

После открытия отчета в Visual Studio можно заметить появление раздела Profiler Guidance (Рекомендации профилировщика), содержащего множество полезных советов по устранению типичных проблем производительности, обнаруженных при профилировании, в том числе:

• «Consider using StringBuilder for string concatenations» («Рассмотрите возможность использования StringBuilder для конкатенации строк») - весьма полезное правило, которое поможет уменьшить количество операций, производимых сборщиком мусора, и, соответственно, сократить время его работы;

• «Many of your objects are being collected in generation 2 garbage collection» («Многие из ваших объектов собираются в процессе сборки мусора 2-го поколения») - феномен «кризиса среднего возраста» объектов C#, обсуждается при рассмотрении сборки мусора в одной из следующих статей;

• «Override Equals and equality operator on value types» («Переопределять Equals и оператор равенства в типах значений») - важнейший прием оптимизации для часто используемых типов значений;

• «You may be using Reflection excessively. It is an expensive operation» («Возможно, слишком интенсивно используется отражение. Это является затратной операцией»).

Дополнительные настройки профилирования

Сбор информации о производительности в промышленном окружении может оказаться сложным делом, если для этого потребуется устанавливать такие тяжеловесные инструменты, как Visual Studio. К счастью, профилировщик Visual Studio можно установить в промышленном окружении отдельно, не устанавливая всю среду разработки Visual Studio.

Файлы дистрибутива профилировщика можно найти на установочном носителе Visual Studio, в каталоге Standalone Profiler (существуют версии для 32- и 64-разрядных систем). После установки профилировщика, следуйте инструкциям на странице https://msdn.microsoft.com/ru-ru/library/ms182401 для запуска приложения под управлением профилировщика или для подключения профилировщика к существующему процессу с использованием инструмента VSPerfCmd.exe. По завершении сеанса, профилировщик сгенерирует файл .vsp, который можно будет открыть на другом компьютере в Visual Studio или на этом же компьютере воспользоваться инструментом VSPerfReport.exe, чтобы сгенерировать отчет в формате XML или CSV и исследовать их без использования Visual Studio.

При проведении инструментированного профилирования в вашем распоряжении имеется множество параметров командной строки, которые можно передать утилите VSInstr.exe. В частности, для запуска и приостановки профилирования в определенной функции, а также для включения/выключения инструментирования функций на основе шаблонов их имен можно использовать параметры START, SUSPEND, INCLUDE и EXCLUDE. Более подробную информацию об утилите VSInstr.exe можно найти на сайте MSDN: VSInstr.

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

Позже будет показан прием использования GPU для параллельных вычислений, дающий значительное увеличение производительности (до 100 раз!). Стандартные профилировщики времени оказываются бесполезными, когда требуется выявить проблемы производительности в коде, выполняющемся на GPU. Однако существуют инструменты, способные выполнять профилирование такого кода, включая и профилировщик Visual Studio 2012. Обсуждение данной темы далеко выходит за рамки этой статьи, но, если вы используете прием организации параллельных вычислений на GPU, есть смысл поближе познакомиться с инструментами, способными интегрироваться с фреймворками программирования для GPU (такими как С++ AMP, CUDA или OpenCL).

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