Как профилировать функции Cython построчно

Я часто изо всех сил пытаюсь найти узкие места в моем cython код. Как я могу профиль cython функции построчно?

2 ответа

Решение

Роберт Брэдшоу помог мне получить Роберт Керн line_profiler инструмент, работающий для cdef функции, и я думал, что поделюсь результатами на stackru,

Короче, настроить регулярный .pyx файл и сценарий сборки и добавить следующее перед вызовом cythonize,

from Cython.Compiler.Options import directive_defaults

directive_defaults['linetrace'] = True
directive_defaults['binding'] = True

Кроме того, вам нужно определить макрос C CYTHON_TRACE=1 изменив ваш extensions настроить так, чтобы

extensions = [
    Extension("test", ["test.pyx"], define_macros=[('CYTHON_TRACE', '1')])
]

Рабочий пример с использованием %%cython магия в iPython Блокнот находится здесь: http://nbviewer.ipython.org/gist/tillahoffmann/296501acea231cbdf5e7

Хотя ответ @Till показывает способ профилирования Cython-кода с использованиемsetup.py-approach, этот ответ касается специального профилирования в ноутбуке IPython/Jupiter и является более или менее "переводом" документации Cython на IPython/Jupiter.

%prun-магия:

Если %prun-magic следует использовать, тогда достаточно установить директиву компилятора Cythonprofile к True (здесь с примером из Cython-документации):

%%cython
# cython: profile=True

def recip_square(i):
    return 1. / i ** 3

def approx_pi(n=10000000):
    val = 0.
    for k in range(1, n + 1):
        val += recip_square(k)
    return (6 * val) ** .5 

Использование глобальной директивы (т.е. # cython: profile=True) - лучший способ, чем изменение глобального состояния Cython, поскольку его изменение приведет к перекомпиляции расширения (чего не происходит, если изменяется глобальное состояние Cython - старая кэшированная версия, скомпилированная со старым глобальным состоянием, будет перезагружена / повторно используется).

И сейчас

%prun -s cumulative approx_pi(1000000)

дает:

        1000005 function calls in 1.860 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    1.860    1.860 {built-in method builtins.exec}
        1    0.000    0.000    1.860    1.860 <string>:1(<module>)
        1    0.000    0.000    1.860    1.860 {_cython_magic_404d18ea6452e5ffa4c993f6a6e15b22.approx_pi}
        1    0.612    0.612    1.860    1.860 _cython_magic_404d18ea6452e5ffa4c993f6a6e15b22.pyx:7(approx_pi)
  1000000    1.248    0.000    1.248    0.000 _cython_magic_404d18ea6452e5ffa4c993f6a6e15b22.pyx:4(recip_square)
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}

%lprun-магический

Если профилировщик линии (т.е. %lprun-magic), тогда модуль Cython должен быть скомпилирован с разными директивами:

%%cython
# cython: linetrace=True
# cython: binding=True
# distutils: define_macros=CYTHON_TRACE_NOGIL=1
...

linetrace=True запускает создание трассировки в сгенерированном C-коде и подразумевает profile=Trueпоэтому его нельзя устанавливать дополнительно. Безbinding=True line_profiler не имеет необходимой кодовой информации и CYTHON_TRACE_NOGIL=1необходим, поэтому профилирование строки также активируется при компиляции с помощью C-компилятора (а не отбрасывается препроцессором C). Также можно использоватьCYTHON_TRACE=1 если nogil-блоки не следует профилировать построчно.

Теперь его можно использовать, например, следующим образом, передав функции, которые должны быть профилированы через -f вариант (используйте %lprun? чтобы получить информацию о возможных вариантах):

%load_ext line_profiler
%lprun -f approx_pi -f recip_square approx_pi(1000000)

что дает:

Timer unit: 1e-06 s

Total time: 1.9098 s
File: /XXXX.pyx
Function: recip_square at line 5

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     5                                           def recip_square(i):
     6   1000000    1909802.0      1.9    100.0      return 1. / i ** 2

Total time: 6.54676 s
File: /XXXX.pyx
Function: approx_pi at line 8

Line #      Hits         Time  Per Hit   % Time  Line Contents
==============================================================
     8                                           def approx_pi(n=10000000):
     9         1          3.0      3.0      0.0      val = 0.
    10   1000001    1155778.0      1.2     17.7      for k in range(1, n + 1):
    11   1000000    5390972.0      5.4     82.3          val += recip_square(k)
    12         1          9.0      9.0      0.0      return (6 * val) ** .5

line_profiler´ has however a minor hiccup withcpdef`-function: она неправильно определяет тело функции. В этом сообщении SO показан возможный обходной путь.


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

Method (N=10^6):        Running Time:       Build with:
%timeit                 1 second
%prun                   2 seconds           profile=True
%lprun                  6.5 seconds         linetrace=True,binding=True,CYTHON_TRACE_NOGIL=1

Хотя я бы не назвал это профилированием, есть еще одна возможность проанализировать ваш код Cython, запустив cython с -a (аннотировать), это создает веб-страницу, на которой выделены основные узкие места. Например, когда я забыл объявить некоторые переменные:

После правильного их объявления (cdef double dudz, dvdz):

Другие вопросы по тегам