python - 如何分析 Jinja2 模板？

Question

我正在分析的 Flask 应用会花费很长时间来呈现其 Jinja2 模板。

我已经安装了flask lineprofilerpanel这很有趣，但不幸的是，我无法深入了解模板渲染以查看所有时间都花在了哪里。

分析 Jinja2 模板的最佳方法是什么？

Answer 1

好问题。我通常对分析器用处不大，所以这是学习的好借口。按照此处的示例:https://docs.python.org/2/library/profile.html#module-cProfile我编写了一个分析神社模板的简单示例。

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}

正如我所说，我没有太多解释分析器输出的经验，但我认为在这个例子中你可以看到程序按预期在 time.sleep 上花费了 2 秒多一点，这是由 slow() 调用的。剩下的时间由join占用。我假设这就是 Jinja2 处理我的两个 for 循环的方式。

将此示例改编成 Flask 应用程序应该不会太难，只需在模板生成步骤周围添加分析位并将报告写入文件即可。也许您甚至可以从 Web 应用程序中提取您的模板并在 Flask 之外对它们进行分析。

希望对您有所帮助。