Профилировщики Python¶The Python Profilers

Введение в профилировщики¶Introduction to the profilers

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

Стандартная библиотека Python предоставляет два различных профилировщика:

1. cProfile рекомендуется для большинства пользователей; это расширение на C с умеренными накладными расходами, что делает его подходящим для профилирования долго работающих программ. Основан на lsprof, предоставленном Бреттом Розеном и Тедом Зоттером.
2. profile – это чистый модуль Python, интерфейс которого имитируется cProfile. Добавляет значительные накладные расходы к профилируемым программам. Если вы пытаетесь расширить профилировщик каким-либо образом, эта задача может оказаться проще с этим модулем. Авторские права © 1994, InfoSeek Corporation.

Модули profile и cProfile экспортируют один и тот же интерфейс, поэтому они в основном взаимозаменяемы; cProfile имеет гораздо меньшие накладные расходы, но является более новым и может быть недоступен на всех системах. cProfile на самом деле является слоем совместимости поверх внутреннего модуля _lsprof.

Краткое руководство пользователя¶Instant User’s Manual

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

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

import cProfile
cProfile.run('foo()')

(Используйте profile вместо cProfile, если последний недоступен в вашей системе.)

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

import cProfile
cProfile.run('foo()', 'fooprof')

Файл cProfile.py также можно вызвать как скрипт для профилирования другого скрипта. Например:

python -m cProfile myscript.py

cProfile.py принимает два необязательных аргумента в командной строке:

cProfile.py [-o output_file] [-s sort_order]

-s применяется только к стандартному выводу (-o не указан). Смотрите документацию Stats для получения допустимых значений сортировки.

Когда вы хотите просмотреть профиль, следует использовать методы модуля pstats. Обычно загрузка статистических данных выполняется следующим образом:

import pstats
p = pstats.Stats('fooprof')

Класс Stats (приведенный выше код только что создал экземпляр этого класса) имеет множество методов для обработки и вывода данных, которые были только что прочитаны в p. Когда вы запустили cProfile.run() выше, выведенный результат представлял собой результат трех вызовов методов:

p.strip_dirs().sort_stats(-1).print_stats()

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

p.sort_stats('name')
p.print_stats()

Первый вызов сортирует список по имени функции, а второй вызов выводит статистику. Вот несколько интересных вызовов для экспериментов:

p.sort_stats('cumulative').print_stats(10)

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

Чтобы увидеть, какие функции много циклится и занимают много времени, можно сделать:

p.sort_stats('time').print_stats(10)

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

Можно также попробовать:

p.sort_stats('file').print_stats('__init__')

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

p.sort_stats('time', 'cum').print_stats(.5, 'init')

Эта строка сортирует статистику по первичному ключу – времени, и вторичному ключу – совокупному времени, а затем выводит часть статистики. А именно: сначала список уменьшается до 50% (ср. .5) от исходного размера, затем сохраняются только строки, содержащие init, и выводится этот под-под-список.

Если вам интересно, какие функции вызывали вышеупомянутые функции, теперь (p всё ещё отсортирован по последнему критерию) можно выполнить:

p.print_callers(.5, 'init')

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

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

p.print_callees()
p.add('fooprof')

При запуске в качестве скрипта модуль pstats является браузером статистики для чтения и изучения дампов профиля. Он имеет простой построчный интерфейс (реализованный с помощью cmd) и интерактивную справку.

Что такое детерминированное профилирование?¶What Is Deterministic Profiling?

Deterministic profiling is meant to reflect the fact that all function call, function return, and exception events are monitored, and precise timings are made for the intervals between these events (during which time the user’s code is executing). In contrast, statistical profiling (which is not done by this module) randomly samples the effective instruction pointer, and deduces where time is being spent. The latter technique traditionally involves less overhead (as the code does not need to be instrumented), but provides only relative indications of where time is being spent.

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

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

Справочное руководство – profile и cProfile¶Reference Manual – profile and cProfile

Основная точка входа для профилировщика – глобальная функция profile.run() (соотв. cProfile.run()). Обычно она используется для создания информации профилирования. Отчеты форматируются и выводятся с помощью методов класса pstats.Stats. Ниже приводится описание всех этих стандартных точек входа и функций. Для более глубокого изучения некоторого кода рекомендуется прочитать раздел о расширениях профилировщика, в котором обсуждается, как вывести «лучшие» профилировщики из представленных классов, или прочитать исходный код этих модулей.

cProfile.run(command[, filename])¶

Эта функция принимает один аргумент, который можно передать функции exec(), и необязательное имя файла. Во всех случаях эта процедура пытается выполнить exec() свой первый аргумент и собирает статистику профилирования из выполнения. Если имя файла не указано, эта функция автоматически выводит простой отчет о профилировании, отсортированный по стандартной строке имени (файл/строка/имя-функции), которая представлена в каждой строке. Ниже приведен типичный вывод такого вызова:

      2706 function calls (2004 primitive calls) in 4.504 CPU seconds

Ordered by: standard name

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     2    0.006    0.003    0.953    0.477 pobject.py:75(save_objects)
  43/3    0.533    0.012    0.749    0.250 pobject.py:99(evaluate)
 ...

Первая строка показывает, что было отслежено 2706 вызовов. Из этих вызовов 2004 были примитивными. Мы определяем примитивный как вызов, который не был вызван рекурсией. Следующая строка: Ordered by: standard name, указывает, что для сортировки вывода использовалась текстовая строка в крайнем правом столбце. Заголовки столбцов включают:

ncalls

– количество вызовов,

tottime

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

percall

– результат деления tottime на ncalls

cumtime

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

percall

– результат деления cumtime на количество первичных вызовов

filename:lineno(function)

– предоставляет соответствующие данные каждой функции

Когда в первом столбце два числа (например, 43/3), второе – это количество примитивных вызовов, а первое – фактическое количество вызовов. Обратите внимание: если функция не рекурсивна, эти два значения совпадают, и печатается только одно число.

cProfile.runctx(command, globals, locals[, filename])¶

Эта функция аналогична run(), но с дополнительными аргументами для передачи словарей globals и locals для строки command.

Анализ данных профилировщика выполняется с использованием класса Stats.

class pstats.Stats(filename[, stream=sys.stdout[, ...]])¶

Этот конструктор класса создаёт экземпляр «объекта статистики» из имени файла (или набора имён файлов). Объекты Stats управляются методами для вывода полезных отчётов. Вы можете указать альтернативный выходной поток данных, задав именованный аргумент stream.

Файл, выбранный указанным конструктором, должен быть создан соответствующей версией profile или cProfile. В частности, не гарантируется совместимость файлов с будущими версиями этого профилировщика, и нет совместимости с файлами, созданными другими профилировщиками. Если предоставлено несколько файлов, вся статистика для одинаковых функций будет объединена, так что общий вид нескольких процессов можно рассмотреть в одном отчёте. Если необходимо объединить дополнительные файлы с данными в существующем объекте Stats, можно использовать метод add().

Ограничения¶Limitations

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

The second problem is that it “takes a while” from when an event is dispatched until the profiler’s call to get the time actually gets the state of the clock. Similarly, there is a certain lag when exiting the profiler event handler from the time that the clock’s value was obtained (and then squirreled away), until the user’s code is once again executing. As a result, functions that are called many times, or call many functions, will typically accumulate this error. The error that accumulates in this fashion is typically less than the accuracy of the clock (less than one clock tick), but it can accumulate and become very significant.

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

Калибровка¶Calibration

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

import profile
pr = profile.Profile()
for i in range(5):
    print(pr.calibrate(10000))

Метод выполняет количество вызовов Python, заданное аргументом, напрямую и снова под профилировщиком, измеряя время для обоих случаев. Затем он вычисляет скрытые накладные расходы на каждое событие профилировщика и возвращает их как число с плавающей запятой. Например, на Pentium 800 МГц под Windows 2000 с использованием time.clock() в качестве таймера это магическое число составляет около 12.5e-6.

Цель этого упражнения – получить достаточно стабильный результат. Если ваш компьютер очень быстрый или функция таймера имеет низкое разрешение, возможно, придётся передать 100000 или даже 1000000, чтобы получить стабильные результаты.

Когда получен стабильный результат, его можно использовать тремя способами:

import profile

# 1. Применить вычисленное смещение ко всем экземплярам Profile, создаваемым в дальнейшем.
profile.Profile.bias = your_computed_bias

# 2. Применить вычисленное смещение к конкретному экземпляру Profile.
pr = profile.Profile()
pr.bias = your_computed_bias

# 3. Указать вычисленное смещение в конструкторе экземпляра.
pr = profile.Profile(bias=your_computed_bias)

Если есть выбор, лучше выбрать меньшую константу – тогда результаты будут «реже» отображаться как отрицательные в статистике профилирования.

Расширения – создание более совершенных профайлеров¶Extensions – Deriving Better Profilers

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

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

pr = profile.Profile(your_time_func)

Полученный профилировщик будет вызывать your_time_func().

profile.Profile

your_time_func() должна возвращать одно число или список чисел, сумма которых равна текущему времени (как os.times()). Если функция возвращает одно число или список из двух чисел, то будет использована особенно быстрая версия диспетчера.

Имейте в виду, что следует откалибровать класс профилировщика для выбранной функции таймера. Для большинства машин таймер, возвращающий одно целое число, даёт наилучшие результаты с точки зрения низких накладных расходов при профилировании. (os.times() довольно плох, так как возвращает кортеж чисел с плавающей точкой). Если вы хотите заменить таймер наиболее чистым способом, создайте производный класс и жёстко задайте заменяющий метод диспетчеризации, который наилучшим образом обрабатывает ваш вызов таймера, вместе с соответствующей константой калибровки.

cProfile.Profile

your_time_func() должна возвращать одно число. Если она возвращает целые числа, можно также вызвать конструктор класса со вторым аргументом, указывающим реальную длительность одной единицы времени. Например, если your_integer_time_func() возвращает время, измеренное в тысячных долях секунды, создайте экземпляр Profile следующим образом:

pr = profile.Profile(your_integer_time_func, 0.001)

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

Сноски