Как профилировать шаблон Jinja2?

Ответ 1

Отличный вопрос. Обычно я не использую профилировщика, поэтому это было хорошим предлогом для изучения. Следуя приведенному здесь примеру: https://docs.python.org/2/library/profile.html#module-cProfile Я закодировал простой пример профилирования шаблона jinja.

import cProfile as profile
import pstats
import StringIO

import jinja2
import time

pr = profile.Profile()

def slow():
    time.sleep(2)
    return "Booga!"

template = jinja2.Template(r'''
    {% for i in RANGE1 %}<h1>hello world {{ i}}</h1>{% endfor %}
    {% for i in RANGE2 %}<h1>foo bar {{ i}}</h1>{% endfor %}
    {{ SLOW() }}
        '''
        )

# here is the bit we want to profile
pr.enable()
context = {"RANGE1": range(1000000), "RANGE2":range(100), "SLOW":slow}
template.render(context)
pr.disable()


s = StringIO.StringIO()
ps = pstats.Stats(pr, stream=s).sort_stats("cumulative")
ps.print_stats()
print(s.getvalue())

Вот фрагмент отчета:

         1000130 function calls in 2.448 seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    2.438    2.438 /usr/local/lib/python2.7/dist-packages/jinja2/environment.py:974(render)
        1    0.122    0.122    2.438    2.438 {method 'join' of 'unicode' objects}
  1000104    0.315    0.000    2.317    0.000 <template>:5(root)
        1    0.000    0.000    2.002    2.002 /usr/local/lib/python2.7/dist-packages/jinja2/runtime.py:169(call)
        1    0.000    0.000    2.002    2.002 profilej.py:10(slow)
        1    2.002    2.002    2.002    2.002 {time.sleep}
        2    0.010    0.005    0.010    0.005 {range}
        1    0.000    0.000    0.000    0.000 /usr/local/lib/python2.7/dist-packages/jinja2/environment.py:1015(new_context)
        1    0.000    0.000    0.000    0.000 /usr/local/lib/python2.7/dist-packages/jinja2/runtime.py:55(new_context)
        1    0.000    0.000    0.000    0.000 /usr/local/lib/python2.7/dist-packages/jinja2/runtime.py:115(__init__)
        3    0.000    0.000    0.000    0.000 {hasattr}
        1    0.000    0.000    0.000    0.000 /usr/local/lib/python2.7/dist-packages/jinja2/_compat.py:59(<lambda>)
        1    0.000    0.000    0.000    0.000 /usr/local/lib/python2.7/dist-packages/jinja2/nodes.py:81(__init__)
        3    0.000    0.000    0.000    0.000 {getattr}
        3    0.000    0.000    0.000    0.000 /usr/local/lib/python2.7/dist-packages/jinja2/runtime.py:149(resolve)
        1    0.000    0.000    0.000    0.000 /usr/local/lib/python2.7/dist-packages/jinja2/runtime.py:126(<genexpr>)
        1    0.000    0.000    0.000    0.000 {callable}
        1    0.000    0.000    0.000    0.000 {method 'disable' of '_lsprof.Profiler' objects}
        1    0.000    0.000    0.000    0.000 {method 'iteritems' of 'dict' objects}
        1    0.000    0.000    0.000    0.000 {isinstance}

Как я уже сказал, у меня нет большого опыта интерпретации вывода профилировщиков, но я думаю, что в этом примере вы можете видеть, что программа тратит чуть более 2 секунд на time.sleep, как ожидалось, который вызывается slow(). Остальная часть времени занята объединением. Я предполагаю, что Jinja2 обрабатывает мои два цикла.

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

Я надеюсь, что это будет полезно.

Ответ 2

Для многопоточного приложения, такого как запущенный сервер Flask, я обнаружил, что обычные инструменты профилирования Python не так уж велики.

У меня были хорошие результаты с yappi, который был разработан для многопоточных приложений. Это довольно просто:

import yappi
yappi.start()

   [.. do stuff ..]

yappi.stop()
yappi.convert2pstats(yappi.get_func_stats()).dump_stats('myfile.pstats')

Это сохраняет данные профиля в pstats совместимом файле, поэтому вы можете инспектировать его в интерактивном режиме в python:

>>> import pstats 
>>> s = pstats.Stats('myfile.pstats')
>>> s.strip_dirs().sort_stats('cumtime').print_stats()

Если вы хотите быть умным, вы можете поместить бит start() и бит stop() в обработчики Flask, чтобы вы могли нанести URL-адрес, чтобы начать профилирование, диск вашего приложения, а затем нажмите другой URL-адрес, чтобы остановить профилирование и запись из файла статистики.