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

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

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

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

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

Примечание

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

Профилирование кода

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

Для профилирование кода с cProfile достаточно импортировать модуль и вызвать его функцию run. Давайте посмотрим на простой пример:

import cProfile

def print_hi():
    print('Hi, cPrifile!')

cProfile.run('print_hi()')
1
2
3
4
5
6

cProfile.run('print_hi()') - запустит print_hi() и напечатает результаты профиля, как показано ниже:

Hi, cPrifile!
        5 function calls in 0.000 seconds

Ordered by: standard name

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    1    0.000    0.000    0.000    0.000 <string>:1(<module>)
    1    0.000    0.000    0.000    0.000 python_cprofile.py:4(print_hi)
    1    0.000    0.000    0.000    0.000 {built-in method builtins.exec}
    1    0.000    0.000    0.000    0.000 {built-in method builtins.print}
    1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
1
2
3
4
5
6
7
8
9
10
11

Первая строка выводит результат выполнения профилированного кода: Hi, cPrifile! Вторая строка указывает, что было отслежено 5 вызовов. Следующая строка говорит нам, в каком порядке результаты выдачи. Заголовки столбцов включают в себя:

  • ncalls - на количество вызовов.
  • tottime - общее время, потраченное на данную функцию (и исключая время, затраченное на вызовы подфункций).
  • percall - ссылается на коэффициент tottime, деленный на ncalls;
  • cumtime - совокупное время, проведенное в этой и всех подфункциях (от вызова до выхода). Эта цифра точна даже для рекурсивных функций.
  • Второй столбец percall - это отношение cumtime, деленное на примитивные вызовы (вызов, который не был совершен при помощи рекурсии).

Создадим код с искусственными задержками, и посмотрим, обнаружит ли их cPrifile:

import cProfile
import time

def run_fast():
    print("The fast function has finished.")

def run_medium():
    time.sleep(0.5)
    print("The medium function has finished.")

def run_slow():
    time.sleep(2)
    print("The slow function has finished.")

def main():
    run_fast()
    run_slow()
    run_medium()

cProfile.run('main()')
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20

Результатом работы cProfile в этой программе:

The fast function has finished.
The slow function has finished.
The medium function has finished.
        12 function calls in 2.503 seconds

Ordered by: standard name

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    1    0.000    0.000    2.503    2.503 <string>:1(<module>)
    1    0.000    0.000    0.000    0.000 python_cprofile.py:13(run_fast)
    1    0.001    0.001    0.501    0.501 python_cprofile.py:16(run_medium)
    1    0.000    0.000    2.001    2.001 python_cprofile.py:20(run_slow)
    1    0.000    0.000    2.503    2.503 python_cprofile.py:24(main)
    1    0.000    0.000    2.503    2.503 {built-in method builtins.exec}
    3    0.000    0.000    0.000    0.000 {built-in method builtins.print}
    2    2.502    1.251    2.502    1.251 {built-in method time.sleep}
    1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17

Видим, что у программы ушло 2.5 секунды на запуск. Если вы изучите результаты, то увидите, что cProfile выявил медленную функцию, которая тратит 2 секунды на запуск. Это и есть самая "слабая" часть основной функции. Обычно, когда вы обнаруживаете такие места, вы можете попытаться найти самый быстрый способ выполнения вашего кода, или прийти к выводу, что такая задержка приемлема. В этом примере, мы знаем, что лучший способ ускорить функцию, то убрать вызов time.sleep(), или, по крайней мере, снизить продолжительность сна.

Выясняем скорость загрузки сайтов

Давайте немного развлечемся и узнаем какой сайт быстрее всех откроется из нашей программы:

import requests
import cProfile

def get_google():
    requests.get('https://google.com')

def get_yandex():
    requests.get('https://yandex.ru')

def main():
    get_google()
    get_yandex()

cProfile.run('main()')
1
2
3
4
5
6
7
8
9
10
11
12
13
14

Результат:

    17383 function calls (17281 primitive calls) in 0.787 seconds

Ordered by: standard name

ncalls  tottime  percall  cumtime  percall filename:lineno(function)
    ...
    1    0.000    0.000    0.352    0.352 python_cprofile.py:37(get_google)
    1    0.000    0.000    0.435    0.435 python_cprofile.py:40(get_yandex)
    ...
1
2
3
4
5
6
7
8
9

Получили большой список результатов. Поиск по нему можно осуществить используя сочетание клавиш Ctrl+F. давайте найдем только наши функции. Запуск всех сайтов выполнился в 0.787 секунды. Быстрее открылся Google. Это не идеальный тест скорости, но наша задача была выполнена. Мы выясняли скорость открытия сайтов используя cProfile.

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

import cProfile
импорт re

cProfile.run ('re.compile ("foo | bar")', 'restats')
1
2
3
4

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

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

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

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

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

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