Профайлинг в программировании (на примере языка C)

Профайлинг (Profiling) представляет собой автоматизированный анализ того, сколько времени тратится на выполнение различных частей вашей программы. Хороший профиль будет давать детальное описание количества вызовов и количества времени CPU, занятого каждой функцией. Это плоский профиль. А очень хороший профиль способен на большее: он анализирует последовательности вызовов и сообщает, какие функции вызывают другие функции (и какие именно) чаще всего и, опять же, время и количество этих вызовов. Такой профиль называется графическим.

Профили почти исключительно определяют время CPU и количество вызовов, но они не в состоянии определять время ввода/вывода, задержки сети и решать возможные проблемы. Однако во многих случаях эти задержки могут быть выведены из того, как часто вызываемая библиотечная функция ассоциируется с проблемами времени в вашей задаче. Например, частые обращения к функции fread могут говорить о том, что ваша программа связана с вводом/выводом, а время работы CPU — не проблема. Уделите особое внимание анализу этих факторов тогда, когда общее время CPU, указываемое профилем, является только долей от наблюдаемого предельного времени, затрачиваемого вашей программой, поскольку это указывает на то, что узкое место программы находится в некоторой другой подсистеме и связано, возможно, с памятью, диском или активностью сети.

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

Примечание: Небольшое дополнение: для инструментов С-профайлинга нет стандарта ANSI/ISO, и в настоящее время для каждой среды программирования нужно иметь свои собственные инструменты для выполнения профиля в собственном конкретном формате этой среды. В этой главе будут использоваться примеры свойств prof и gprof из среды программирования UNIX, но это только примеры. Вы можете полистать документацию по вашей собственной среде программирования, чтобы определить, какие инструменты профайлинга вам доступны. Представленные здесь абстрактные концепции должны применяться для всех сред, в которых выполняется профайлинг, хотя детали будут, конечно, существенно различаться в зависимости от конкретной среды программирования.

Плоский профиль

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

А теперь подробнее рассмотрим содержащиеся в колонках величины для этого конкретного примера:

1. В первой колонке представлено время, затраченное на выполнение каждой функции, в процентах от общего времени выполнения программы; сортировка порядка следования функций в списке проводилась по этой колонке. Как видно, самая верхняя функция больше других нуждается в оптимизации и может дать существенный выигрыш по общему времени выполнения программы.
2. Накопленное время в секундах — показано суммарное время, затрачиваемое всеми функциями до рассматриваемой позиции. Заметим, что это общее время на все обращения к конкретной функции, а не время одного ее вызова.
3. Индивидуальное время показывает, сколько секунд занимает работа каждой функции. Это также общее время на все вызовы функции, а не время одного вызова.
4. Четвертая колонка — это просто количество вызовов каждой конкретной функции.
5. Собственное время одного вызова — это время в миллисекундах, затрачиваемое на одно обращение к каждой функции. Вы можете надеяться на то, что ваш профиль будет немного более расторопным по времени и будет измеряться не в миллисекундах, как в нашем примере, а в микросекундах!
6. Общее время одного вызова — расширение данных предыдущей колонки, которое включает время, затрачиваемое в подпрограммах.
7. Последняя колонка содержит название каждой исследуемой функции.
   

Теперь остановимся на нескольких важных моментах. Оригинальная программа имеет только три явно определенные функции — compare, bubblesort и main. Но построенный профиль показывает много других, якобы не относящихся к делу функций. Первая из них, которую мы можем не принимать в расчет, — это функция internal_mcount, которая фактически является артефактом (Artifact — искусственный объект. — Прим. пер.) процесса измерений.

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

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

А вот о чем нам не говорит профиль, так это о том, что фактическая проблема, связанная с этой программой, состоит в использовании функции bubblesort (поскольку это достаточно хилый алгоритм сортировки), а также о том, какие вызовы strlen или toupper действительно нужны, поскольку эти функции, в принципе, могут быть вызваны из самых разных мест в программе.

Графические профили

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

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

Показанный в этой таблице профиль содержит три раздела, в которых подытожено время выполнения и подсчитано количество вызовов функций main, bubblesort и compare. Каждый раздел идентифицирован именем функции с отступом в колонке "Имя" (колонка 6). Внутри каждого раздела вызванные подпрограммы перечисляются ниже строки функции, а вызывающие — выше строки в порядке убывания затраченного на их выполнение времени.

Смысл отдельных колонок в этом профиле следующий:

1. Первая колонка представляет некоторый числовой индекс и не несет значительной информации.
2. Время в % показывает общее количество времени, затраченного данной функцией и всеми вызывавшими ее функциями (а также функциями, которые они вызывают повторно, и т.п.). Поскольку каждая из них первоначально вызывалась из main, она появляется одной из первых вверху каждого раздела отчета, как здесь показано, но это не означает, что именно эти функции должны быть целью оптимизации.
3. Собственное (время) — общее количество секунд, затраченных на выполнение этой функции, не включает время, затраченное вызываемыми ею подпрограммами. Другими словами, хотя профиль указывает, что main затрачивает 46.2% времени в работе программы, фактически main затратила 0 секунд, а остальное время было затрачено подпрограммами, которые вызвала main.
4. По убыванию — общее количество секунд, затраченных в функциях, вызванных данной функцией.
5. Вызвана/Итого — отношение количества вызовов данной функции из конкретной родительской функции к количеству вызовов ею дочерних функций.
6. Имя — названия функций, как они упоминаются в запросах. Функции, которые появляются выше записанной с отступом функции, являются вызывающими, те же, которые появляются ниже ее, — это вызываемые функции.

Графический профиль дает нам пищу для размышлений о.том, какие функции следовало бы оптимизировать. В отличие от плоского профиля, на графическом профиле проявляется факт чрезмерно большого количества обращений bubblesort к функции compare, хотя самой функцией bubblesort расходуется совсем не много времени.

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

Другие методы профайлинга

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

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

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

© Ричард Хэзфилд, "Искусство программирования на C", 2001 год.