django性能分析
一般情况我们使用django-debug-toolbar就能够看到每个步骤的耗时等信息，不过如果需要调试某个接口就不那么直观了，这种情况下我们可以使用下面的中间件来解决问题：
# Orignal version taken from http://www.djangosnippets.org/snippets/186/
# Original author: udfalkso
# Modified by: Shwagroo Team and Gun.io
import sys
import os
import re
import hotshot, hotshot.stats
import tempfile
import StringIO
from django.conf import settings
words_re = re.compile( r'\s+' )
group_prefix_re = [
re.compile( "^.*/django/[^/]+" ),
re.compile( "^(.*)/[^/]+$" ), # extract module path
re.compile( ".*" ), # catch strange entries
]
class ProfileMiddleware(object):
"""
Displays hotshot profiling for any view.
http://yoursite.com/yourview/?prof
Add the "prof" key to query string by appending ?prof (or &prof=)
and you'll see the profiling results in your browser.
It's set up to only be available in django's debug mode, is available for superuser otherwise,
but you really shouldn't add this middleware to any production configuration.
WARNING: It uses hotshot profiler which is not thread safe.
"""
def process_request(self, request):
if (settings.DEBUG or request.user.is_superuser) and 'prof' in request.GET:
self.tmpfile = tempfile.mktemp()
self.prof = hotshot.Profile(self.tmpfile)
def process_view(self, request, callback, callback_args, callback_kwargs):
if (settings.DEBUG or request.user.is_superuser) and 'prof' in request.GET:
return self.prof.runcall(callback, request, *callback_args, **callback_kwargs)
def get_group(self, file):
for g in group_prefix_re:
name = g.findall( file )
if name:
return name[0]
def get_summary(self, results_dict, sum):
list = [ (item[1], item[0]) for item in results_dict.items() ]
list.sort( reverse = True )
list = list[:40]
res = " tottime\n"
for item in list:
res += "%4.1f%% %7.3f %s\n" % ( 100*item[0]/sum if sum else 0, item[0], item[1] )
return res
def summary_for_files(self, stats_str):
stats_str = stats_str.split("\n")[5:]
mystats = {}
mygroups = {}
sum = 0
for s in stats_str:
fields = words_re.split(s);
if len(fields) == 7:
time = float(fields[2])
sum += time
file = fields[6].split(":")[0]
if not file in mystats:
mystats[file] = 0
mystats[file] += time
group = self.get_group(file)
if not group in mygroups:
mygroups[ group ] = 0
mygroups[ group ] += time
return "<pre>" + \
" ---- By file ----\n\n" + self.get_summary(mystats,sum) + "\n" + \
" ---- By group ---\n\n" + self.get_summary(mygroups,sum) + \
"</pre>"
def process_response(self, request, response):
if (settings.DEBUG or request.user.is_superuser) and 'prof' in request.GET:
self.prof.close()
out = StringIO.StringIO()
old_stdout = sys.stdout
sys.stdout = out
stats = hotshot.stats.load(self.tmpfile)
stats.sort_stats('time', 'calls')
stats.print_stats()
sys.stdout = old_stdout
stats_str = out.getvalue()
if response and response.content and stats_str:
response.content = "<pre>" + stats_str + "</pre>"
response.content = "\n".join(response.content.split("\n")[:40])
response.content += self.summary_for_files(stats_str)
os.unlink(self.tmpfile)
return response
把这个文件保存为middleware.py，然后在settings.py中的MIDDLEWARE_CLASSES添加刚才写好的中间件
'yourproject.yourapp.middleware.ProfileMiddleware',
添加完成后，在原本要访问的url后添加’?prof'就可以看到性能分析结果了：
<pre> 202188 function calls (182154 primitive calls) in 2.948 seconds
Ordered by: internal time, call count
ncalls tottime percall cumtime percall filename:lineno(function)
302 2.444 0.008 2.454 0.008 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/MySQLdb/cursors.py:277(_do_query)
2 0.086 0.043 0.104 0.052 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/MySQLdb/connections.py:62(__init__)
2 0.017 0.009 0.017 0.009 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/MySQLdb/connections.py:287(set_character_set)
2 0.016 0.008 0.016 0.008 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/django/db/backends/mysql/base.py:299(_set_autocommit)
302 0.008 0.000 2.488 0.008 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/django/db/backends/utils.py:76(execute)
19410 0.008 0.000 0.008 0.000 /usr/lib64/python2.7/copy.py:267(_keep_alive)
10237 0.008 0.000 0.008 0.000 /usr/lib64/python2.7/json/encoder.py:33(encode_basestring)
600 0.008 0.000 0.012 0.000 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/django/db/models/sql/query.py:246(clone)
6 0.007 0.001 0.007 0.001 /usr/lib64/python2.7/urlparse.py:336(unquote)
500 0.007 0.000 2.712 0.005 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/django/db/models/query.py:229(iterator)
1152 0.005 0.000 0.029 0.000 /usr/lib64/python2.7/copy.py:253(_deepcopy_dict)
1 0.005 0.005 0.014 0.014 /usr/lib64/python2.7/json/encoder.py:212(iterencode)
302 0.005 0.000 0.010 0.000 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/MySQLdb/cursors.py:117(_do_get_result)
300 0.005 0.000 0.121 0.000 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/django/db/models/sql/compiler.py:351(as_sql)
300 0.004 0.000 0.033 0.000 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/django/db/models/sql/query.py:1114(build_filter)
302 0.004 0.000 0.004 0.000 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/MySQLdb/cursors.py:313(_get_result)
1 0.003 0.003 0.017 0.017 /usr/lib64/python2.7/json/encoder.py:186(encode)
1300 0.003 0.000 0.004 0.000 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/django/db/backends/mysql/operations.py:176(get_db_converters)
600 0.003 0.000 0.006 0.000 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/django/db/models/sql/query.py:1334(names_to_path)
300 0.003 0.000 0.004 0.000 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/django/db/models/sql/query.py:110(__init__)
302 0.003 0.000 0.003 0.000 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/MySQLdb/cursors.py:82(_warning_check)
200 0.003 0.000 0.004 0.000 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/django/db/models/base.py:388(__init__)
302 0.003 0.000 2.469 0.008 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/MySQLdb/cursors.py:139(execute)
300 0.003 0.000 0.022 0.000 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/django/db/models/sql/compiler.py:155(get_select)
300 0.003 0.000 0.007 0.000 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/django/db/models/sql/compiler.py:472(get_default_columns)
908 0.003 0.000 0.003 0.000 /home/xsy/.virtualenvs/calc/lib64/python2.7/encodings/utf_8.py:15(decode)
3500 0.003 0.000 0.005 0.000 /home/xsy/.virtualenvs/calc/lib/python2.7/site-packages/django/db/models/sql/compiler.py:325(quote_name_unless_alias)
<pre> ---- By file ----
简单解释下主要的信息，ncalls是函数调用的次数，percall指调用一次所需时间，cumtime是运行时占用的总时间。比如percall时间很短而cumtime时间很长，则代表循环次数过多了，试着从算法角度进行优化;如果从输出中看到大量时间消耗和“sql”有关的，则试着从数据库相关代码优化;如果看见大量时间消耗和"template"有关，则尝试从模板渲染处着手优化。
