Профилировщики Python

Исходный код: Lib/profile.py и Lib/pstats.py

---

Введение в профилировщики

single: deterministic profiling single: profiling, deterministic

cProfile и profile обеспечивают детерминированное профилирование <deterministic profiling> программ Python. profile - ряд статистики, которая описывает как часто и как долго различные части выполненной программы. Эти статистические данные могут быть отформатированы в отчеты через модуль pstats.

Стандартная библиотека Python предоставляет две различные реализации одного и того же интерфейса профилирования:

1. cProfile рекомендуется большинству пользователей; это расширение C с разумными накладными расходами, которое делает его подходящим для профилирования продолжительных программ. Основана на lsprof, внесена Brett Rosen и Ted Czotter.
2. profile, чисто Python модуль, интерфейс которого имитируется cProfile, но который добавляет значительные накладные расходы к профилированным программам. Если вы пытаетесь расширить профилировщик каким-то образом, задача может быть проще с этим модулем. Первоначально разработан и написан Jim Roskind.

Примечание

Модули профилировщика разработаны, чтобы обеспечить профиль выполнения для данной программы, не для сопоставительного анализа целей (для который, есть timeit для довольно точных результатов). Это особенно касается бенчмаркинга Python кода в сравнении с C кодом: профайлеры вводят накладные расходы для Python код, но не для функций C-уровня, и поэтому C код будет казаться более быстрым, чем любой Python.

Мгновенное руководство пользователя

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

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

import cProfile
import re
cProfile.run('re.compile("foo|bar")')

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

Вышеуказанное действие приведет к запуску re.compile() и печати результатов профиля, как показано ниже:

      197 function calls (192 primitive calls) in 0.002 seconds

Ordered by: standard name

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
     1    0.000    0.000    0.001    0.001 <string>:1(<module>)
     1    0.000    0.000    0.001    0.001 re.py:212(compile)
     1    0.000    0.000    0.001    0.001 re.py:268(_compile)
     1    0.000    0.000    0.000    0.000 sre_compile.py:172(_compile_charset)
     1    0.000    0.000    0.000    0.000 sre_compile.py:201(_optimize_charset)
     4    0.000    0.000    0.000    0.000 sre_compile.py:25(_identityfunction)
   3/1    0.000    0.000    0.000    0.000 sre_compile.py:33(_compile)

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

ncalls

для количества вызовов.

tottime

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

percall

частное от tottime, деленное на ncalls

cumtime

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

percall

частное от cumtime, разделенное примитивными призывами

filename:lineno(function)

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

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

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

import cProfile
import re
cProfile.run('re.compile("foo|bar")', 'restats')

Класс pstats.Stats считывает результаты профиля из файла и форматирует их различными способами.

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

python -m cProfile [-o output_file] [-s sort_order] (-m module | myscript.py)

-o записывает результаты профиля в файл, а не в stdout

-s указывает один из sort_stats() sort значения для сортировки выходных данных. Это применимо только в том случае, если параметр -o не указан.

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

Добавлено в версии 3.7: Добавлен параметр -m для cProfile.

Добавлено в версии 3.8: Добавлен параметр -m для profile.

У класса модуля pstats Stats есть множество методов для управления, и печать данных, сохраненных в профиль, заканчивается файл:

import pstats
from pstats import SortKey
p = pstats.Stats('restats')
p.strip_dirs().sort_stats(-1).print_stats()

Метод strip_dirs() удалил внешний путь из всех имен модулей. Метод sort_stats() отсортировал все записи по напечатанному стандартному модулю/строке/имени строка. Метод print_stats() распечатал всю статистику. Можно попробовать выполнить следующую сортировку вызовов:

p.sort_stats(SortKey.NAME)
p.print_stats()

Первый вызов фактически сортирует список по имени функции, а второй вызов распечатывает статистику. Ниже приведены некоторые интересные призывы экспериментировать с:

p.sort_stats(SortKey.CUMULATIVE).print_stats(10)

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

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

p.sort_stats(SortKey.TIME).print_stats(10)

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

Вы также можете попробовать:

p.sort_stats(SortKey.FILENAME).print_stats('__init__')

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

p.sort_stats(SortKey.TIME, SortKey.CUMULATIVE).print_stats(.5, 'init')

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

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

p.print_callers(.5, 'init')

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

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

p.print_callees()
p.add('restats')

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

profile и cProfile справочник модуля

Модули profile и cProfile обеспечивают следующие функции:

profile.run(command, filename=None, sort=-1)

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

exec(command, __main__.__dict__, __main__.__dict__)

и собирает статистику профилирования из выполнения. Если никакое имя файла не присутствует, то эта функция автоматически создает Stats сущность и печатает простой профильный отчет. Если вид, значение определен, он передан к этому Stats сущность, чтобы управлять, как результаты сортированы.

profile.runctx(command, globals, locals, filename=None, sort=-1)

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

exec(command, globals, locals)

и собирает профильную статистику как в функции run() выше.

class profile.Profile(timer=None, timeunit=0.0, subcalls=True, builtins=True)

Этот класс обычно является используемый только в том случае, если требуется более точный контроль за профилированием, чем то, что обеспечивает функция cProfile.run().

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

Непосредственно использование класса Profile позволяет форматировать результаты профиля, не в письме к данные о профиле файлу:

import cProfile, pstats, io
from pstats import SortKey
pr = cProfile.Profile()
pr.enable()
# ... дель что-нибудь ...
pr.disable()
s = io.StringIO()
sortby = SortKey.CUMULATIVE
ps = pstats.Stats(pr, stream=s).sort_stats(sortby)
ps.print_stats()
print(s.getvalue())

Класс Profile может также быть используемый как менеджером контекст (поддержанный только в модуле cProfile. см. Типы менеджера контекста):

import cProfile

with cProfile.Profile() as pr:
    # ... делать что-то ...

pr.print_stats()

Изменено в версии 3.8: Добавлена поддержка диспетчера контекст.

enable()

Начать сбор данных профилирования. Только в cProfile.

disable()

Прекратить сбор данных профилирования. Только в cProfile.

create_stats()

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

print_stats(sort=-1)

Создайть объект Stats на основе текущего профиля и распечатайте результаты для stdout.

dump_stats(filename)

Записать результаты текущего профиля в filename.

run(cmd)

Выполнить профилирование cmd через exec().

runctx(cmd, globals, locals)

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

runcall(func, *args, **kwargs)

Профиль func(*args, **kwargs)

Следует отметить, что профилирование будет работать только в том случае, если вызываемая команда/функция действительно возвращает. Если интерпретатор завершается (например, посредством вызова sys.exit() во время выполнения вызываемой команды/функции), результаты профилирования не будут напечатаны.

Класс Stats

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

class pstats.Stats(*filenames or profile, stream=sys.stdout)

Конструктор класса создает сущность «объекта статистики» от filename (или список имен файлов) или от Profile сущность. Выходные данные будут напечатаны в потоке, указанном параметром stream.

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

Вместо того, чтобы читать данные о профиле из файла, объект cProfile.Profile или profile.Profile может быть используемый как источником данных профиля.

Объекты Stats имеют следующие методы:

strip_dirs()

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

add(*filenames)

Этот метод класса Stats накапливает дополнительную профильную информацию в текущий профильный объект. Его аргументы должны ссылаться на имена файлов, созданные соответствующей версией profile.run() или cProfile.run(). Статистика для идентично именованных функций (re: file, line, name) автоматически накапливается в статистику одной функции.

dump_stats(filename)

Сохраните данные, загруженные в объект Stats, в файл с именем filename. Файл создается, если он не существует, и перезаписывается, если он уже существует. Это эквивалентно одноименному методу в классах profile.Profile и cProfile.Profile.

sort_stats(*keys)

Этот метод изменяет объект Stats путем его сортировки в соответствии с предоставленными критериями. Аргумент может быть или строка или SortKey enum, определяющим в некотором роде основание (пример: 'time', 'name', SortKey.TIME или SortKey.NAME). Аргумент SortKey enums имеет преимущество перед аргументом строка в том, что он более надежен и менее подвержен ошибкам.

Когда больше чем один ключ обеспечен, тогда дополнительные ключи - используемый как вторичные критерии, когда есть равенство во всех ключах, отобранных перед ними. Например, sort_stats(SortKey.NAME, SortKey.FILE) будет сортировать все записи в соответствии с их именем функции и разрешить все связи (идентичные имена функций) путем сортировки по имени файла.

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

Ниже приведены допустимые строка и SortKey:

Правильная строка Arg	Правильный enum Arg	Смысл
'calls'	SortKey.CALLS	количество вызовов
'cumulative'	SortKey.CUMULATIVE	совокупное время
'cumtime'	N/A	совокупное время
'file'	N/A	имя файла
'filename'	SortKey.FILENAME	имя файла
'module'	N/A	имя файла
'ncalls'	N/A	количество вызовов
'pcalls'	SortKey.PCALLS	примитивный счетчик вызовов
'line'	SortKey.LINE	номер строки
'name'	SortKey.NAME	имя функции
'nfl'	SortKey.NFL	имя/файл/строка
'stdname'	SortKey.STDNAME	стандартное имя
'time'	SortKey.TIME	внутреннее время
'tottime'	N/A	внутреннее время

Следует отметить, что все виды статистики находятся в порядке убывания (при этом наиболее трудоемкие элементы помещаются в первую очередь), где поиск по имени, файлу и номеру строки выполняется в порядке возрастания (алфавитном). Тонкое различие между SortKey.NFL и SortKey.STDNAME заключается в том, что стандартное имя является видом печатаемого названия, что означает, что номера встроенных строк сравниваются нечетным образом. Например, строки 3, 20 и 40 (если имена файлов одинаковы) будут отображаться в порядке 20, 3 и 40 строка. В отличие от этого, SortKey.NFL выполняет числовое сравнение номеров строк. На самом деле, sort_stats(SortKey.NFL) то же самое, что и sort_stats(SortKey.NAME, SortKey.FILENAME, SortKey.LINE).

По причинам обратной совместимости разрешены числовые аргументы -1, 0, 1 и 2. Они интерпретируются как 'stdname', 'calls', 'time' и 'cumulative' соответственно. Если этот старый формат стиля (числовой) имеет значение используемый, будет используемый только один ключ сортировки (числовой ключ), и дополнительные аргументы будут игнорироваться молча.

Добавлено в версии 3.7: Добавлен перечисление SortKey.

reverse_order()

Этот метод для класса Stats изменяет порядок основного списка в объекте. Обратите внимание, что по умолчанию по возрастанию и убыванию выбирается правильно на основе выбранного ключа сортировки.

print_stats(*restrictions)

Метод для класса Stats выводит отчет, как описано в определении profile.run().

Заказ печати на основе последней операции sort_stats(), сделанной на объекте (подвергающийся протестам в add() и strip_dirs()).

Обеспеченными аргументами (если таковые имеются) может быть используемый, чтобы ограничить список вниз значительными записями. Первоначально список принимается за полный набор профилированных функций. Каждое ограничение является либо целым числом (для выбора числа строк), либо десятичной дробью в диапазоне от 0,0 до 1,0 включительно (для выбора процента строк), либо строка, которая будет интерпретироваться как регулярное выражение (для сопоставления со стандартным именем, которое печатается). Если предусмотрено несколько ограничений, то они применяются последовательно. Например:

print_stats(.1, 'foo:')

сначала ограничит печать первыми 10% списка, а затем только функциями печати, которые были частью имени файла .*foo:. В отличие от команды:

print_stats('foo:', .1)

ограничит список всеми функциями, имеющими имена файлов .*foo:, а затем начнет печатать только первые 10% из них.

print_callers(*restrictions)

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

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

print_callees(*restrictions)

Этот метод для класса Stats печатает список всех функций, которые были вызваны указанной функцией. Помимо этого разворота направления вызовов (re: called vs был вызван), аргументы и порядок идентичны методу print_callers().

Что такое детерминированное профилирование?

детерминированное профилирование <deterministic profiling> предназначен для отражения того факта, что все события вызов функции, возврат функции и исключение отслеживаются, и для интервалов между этими событиями (в течение этого времени выполняется код пользователя) выполняются точные временные интервалы. В отличие от этого, статистическое профилирование <statistical profiling> (что не выполняется этим модулем) случайным образом дискретизирует эффективный указатель команды и выводит, где уходит время. Последний метод традиционно включает в себя меньше накладных расходов (так как код не нуждается в инструментарии), но обеспечивает только относительные указания того, где уходит время.

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

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

Ограничения

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

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

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

Ограничения

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

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

Метод выполняет количество вызовов Python, заданных аргументом, непосредственно и снова под профилировщиком, измеряя время для обоих. Затем он вычисляет скрытые накладные расходы на событие профилировщика и возвращает это как float. Например, на 1.8 Ghz Intel Core i5, управляющем Mac OS X и использующем время Python’а time.process_time() как таймер, волшебное число о 4.04e-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)

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

Использование пользовательского таймера

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

pr = profile.Profile(your_time_func)

Полученный профилировщик вызовет your_time_func. В зависимости от того, используется ли profile.Profile или cProfile.Profile, возвращает значение your_time_func будет интерпретироваться по-разному:

profile.Profile

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

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

cProfile.Profile

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

pr = cProfile.Profile(your_integer_time_func, 0.001)

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

Python 3.3 добавляет несколько новых функций в time, которые могут быть используемый для точного измерения технологического или настенного времени. Например, см. раздел time.perf_counter().