如何对Jinja2模板进行分析?

17

我正在分析的 Flask 应用在渲染 Jinja2 模板时花费了很长时间。

我已经安装了 flask lineprofilerpanel,虽然它很有趣,但不幸的是,它无法让我深入到模板渲染中去看看所有的时间都花在哪里了。

那么,如何最好地对 Jinja2 模板进行性能分析?


1
@akai:我不了解flask,但它看起来像Python。[这应该有效](https://dev59.com/V2855IYBdhLWcg3whEtL#4299378) - Mike Dunlavey
1
我认为在flask-debugtoolbar的分析器中,您可以看到所有调用的方法。如果您手动过滤掉那些前面带有jinja2的方法(即<jinja2\runtime.py:169(call)>),则可以估算出渲染时间。 - Alexey Smirnov
可能有一个相关的问题吗?https://dev59.com/0UbRa4cB1Zd3GeqP3sqS - intrepidhero
@MikeDunlavey 这个答案非常有趣,但似乎在这种情况下并没有帮助。我尝试了一下,但堆栈跟踪报告进程停止在一个简单的HTML行上 - 也就是说,在jinja2模板中没有Python行 - 然后是一些jinja2内部代码,而不显示在中断之前正在呈现哪个模板行。 - akai
虽然如果缓慢函数不是来自jinja2(例如来自flask)那么这并不起作用,但我觉得浏览分析结果仍然是“最好”的方法。 - akai
据我所知,如果没有更新,Flask只会编译一次jinja2模板(而且OP对于在Flask中使用的用例很感兴趣,我也是)。 - akai
3个回答

5

很好的问题。我通常不太需要使用分析器,所以这是一个很好的借口来学习。跟随这个例子: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()调用的。其余的时间被join占据。我假设这就是Jinja2处理我的两个for循环的方式。

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

希望这有所帮助。


我认为这与 Flask-DebugToolbar 提供的相同。 - akai

1
对于像运行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 来停止分析并写出统计文件。

我也尝试过这个方法,但是我发现它对jinja2的渲染帮助不大,和flask-debugtoolbar差不多。 - akai

0
如果有人需要一种快速的“hacky”方法来剖析某些Jinja片段的呈现时间,我找到了一种简单的方法。
将此添加到主应用程序文件中:
app.jinja_env.globals.update(now=datetime.datetime.now)

在您想计时的代码段周围添加以下内容:

{% set rendertime = now() %}

{% for x in test_list %}
   {{... do stuff }}
{% endfor %}

<span>Render Time: {{now()-rendertime}}</span>

网页内容由stack overflow 提供, 点击上面的
可以查看英文原文,
原文链接