我正在分析的 Flask 应用在渲染 Jinja2 模板时花费了很长时间。
我已经安装了 flask lineprofilerpanel,虽然它很有趣,但不幸的是,它无法让我深入到模板渲染中去看看所有的时间都花在哪里了。
那么,如何最好地对 Jinja2 模板进行性能分析?
我正在分析的 Flask 应用在渲染 Jinja2 模板时花费了很长时间。
我已经安装了 flask lineprofilerpanel,虽然它很有趣,但不幸的是,它无法让我深入到模板渲染中去看看所有的时间都花在哪里了。
那么,如何最好地对 Jinja2 模板进行性能分析?
很好的问题。我通常不太需要使用分析器,所以这是一个很好的借口来学习。跟随这个例子: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之外对它们进行分析。
希望这有所帮助。
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 来停止分析并写出统计文件。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>