剖析并发现烧瓶应用的瓶颈 - 电流响应时间为30秒

Question

我的Flask应用程序在过去一个月突然变得非常慢,我不知道哪些更改可以将响应时间从1s 提升到30s.

我一直在使用Flask和MongoEngine,Redis也用于缓存.MongoDB与Flask应用程序放在同一台服务器上.

我试过剖析Flask,这是报告:

127.0.0.1 - - [17/Feb/2014 19:51:47] "GET / HTTP/1.0" 200 -
--------------------------------------------------------------------------------
PATH: '/items'
         637497 function calls (618866 primitive calls) in 30.961 seconds

   Ordered by: internal time, call count
   List reduced from 702 to 30 due to restriction <30>

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
      153   30.127    0.197   30.127    0.197 {method 'recv' of '_socket.socket' objects}
   319965    0.150    0.000    0.150    0.000 {isinstance}
 1322/740    0.079    0.000    0.178    0.000 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/dereference.py:147(_attach_objects)
       77    0.079    0.001    0.079    0.001 {method 'sendall' of '_socket.socket' objects}
 1322/740    0.077    0.000    0.159    0.000 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/dereference.py:68(_find_references)
    54670    0.046    0.000    0.046    0.000 {hasattr}
   774/80    0.032    0.000    0.207    0.003 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/base/document.py:539(_from_son)
      774    0.031    0.000    0.119    0.000 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/base/document.py:35(__init__)
12932/12792    0.028    0.000    0.057    0.000 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/base/document.py:113(__setattr__)
    15557    0.016    0.000    0.020    0.000 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/common.py:4(_import_class)
    46648    0.016    0.000    0.016    0.000 {method 'get' of 'dict' objects}
     8228    0.015    0.000    0.029    0.000 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/base/fields.py:94(__set__)
 1532/287    0.012    0.000    0.161    0.001 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/base/fields.py:233(to_python)
    11901    0.012    0.000    0.061    0.000 {setattr}
     8960    0.010    0.000    0.010    0.000 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/base/document.py:547(<genexpr>)
15629/5700    0.010    0.000    0.022    0.000 /usr/lib/python2.7/json/encoder.py:335(_iterencode_dict)
3328/3207    0.009    0.000    0.019    0.000 /usr/lib/python2.7/copy.py:145(deepcopy)
   685/61    0.008    0.000    0.032    0.001 /home/deploy/shopping/env/local/lib/python2.7/site-packages/pymongo/cursor.py:843(__deepcopy)
     3660    0.008    0.000    0.024    0.000 /usr/lib/python2.7/copy.py:66(copy)
10295/5668    0.008    0.000    0.019    0.000 /usr/lib/python2.7/json/encoder.py:282(_iterencode_list)
      424    0.007    0.000    0.361    0.001 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/base/fields.py:189(__get__)
      740    0.007    0.000    0.348    0.000 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/dereference.py:12(__call__)
      660    0.006    0.000    0.008    0.000 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/base/datastructures.py:15(__init__)
       72    0.005    0.000    0.007    0.000 {bson._cbson.decode_all}
      183    0.005    0.000    0.034    0.000 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/queryset/base.py:533(clone_into)
      241    0.005    0.000    0.023    0.000 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/queryset/transform.py:31(query)
      694    0.005    0.000    0.114    0.000 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/document.py:64(__init__)
      900    0.004    0.000    0.004    0.000 {sorted}
5388/5387    0.004    0.000    0.007    0.000 {getattr}
     5940    0.004    0.000    0.004    0.000 /home/deploy/shopping/env/lib/python2.7/site-packages/mongoengine/fields.py:241(to_python)

任何人都可以指出我找到瓶颈的方向,或者更有用的分析方式吗？

Answer 1

你的30秒被用于153次通话sock.recv,每次约需0.2秒.

您现在需要了解的是谁正在调用此函数,为此您需要来自探查器的调用图报告.遗憾的是,调用图不包含在Werkzeug Profiler中间件的摘要输出中,但如果使用profile_dir参数,则可以将配置文件数据保存到文件中.

获得数据文件后,可以使用简短的Python脚本获取调用图:

import pstats
stats = pstats.Stats('tmp/GET.root.000255ms.1392663371.prof')
stats.sort_stats('time', 'calls')
stats.print_stats()
stats.print_callers()

该print_stats()调用打印出与Werkzeug相同的报告.该print_callers()调用打印相应的调用图.输出将很长,因此您应该将其重定向到文件.

如果查看文本报告不是您的事,那么您可以使用gprof2dot从相同的数据生成GraphViz图.

希望这可以帮助.

Answer 2

http://pythonhosted.org/line_profiler/

这是一个使用两个分析工具的教程,它在类似的情况下帮助了我.