2012-12-18 44 views
4

我正在將中等規模的Django 1.4.2應用程序遷移到新的基礎架構,並試圖在新的功能非常強大的硬件上優化系統的性能。我使用django-debug-toolbar以及基於熱點的分析中間件來查找瓶頸,並且目前很難理解我從不同來源獲得的執行時間值的差異。uWSGI/Nginx下的配置Django應用程序

舉例來說,這裏是我得到的計時,如果我提出一個請求到URL中我與映射到一個相當簡單的視圖應用:

Nginx的1.2.5 - 0.409s

10.10.1.101 151a6b897ee788499fd19d6531befaac [17/Dec/2012:23:43:53 -0800] 200 0.409 1633 "GET /product/150138/?prof HTTP/1.1" "-" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.11 (KHTML, like Gecko) Chrome/23.0.1271.97 Safari/537.11" 

uWSGI 1.4.2(64位) - 387ms

Mon Dec 17 23:27:50 2012 151a6b897ee788499fd19d6531befaac GET mysite.com/product/150138/?prof HTTP/1.1 200 387ms 

Django的調試工具欄 - 112.452毫秒

Resource     Value 
User CPU time   84.005 msec 
System CPU time   4.001 msec 
Total CPU time   88.006 msec 
Elapsed time    112.452 msec 
Context switches   33 voluntary, 10 involuntary 

SQL: 16.42 ms (8 queries) 

剖析中間件 - 0.132秒

113020 function calls (110410 primitive calls) in 0.132 seconds 

    Ordered by: internal time, call count 

    ncalls tottime percall cumtime percall filename:lineno(function) 
    10232 0.046 0.000 0.046 0.000 /opt/myenv/lib/python2.7/posixpath.py:60(join) 
    10187 0.032 0.000 0.040 0.000 /opt/myenv/lib/python2.7/posixpath.py:130(islink) 
1396/1354 0.022 0.000 0.120 0.000 /opt/myenv/lib/python2.7/posixpath.py:355(realpath) 
    2682 0.018 0.000 0.018 0.000 /opt/myenv/lib/python2.7/posixpath.py:312(normpath) 
     8 0.016 0.002 0.016 0.002 /opt/myenv/lib/python2.7/site-packages/django/db/backends/postgresql_psycopg2/base.py:50(execute) 
    1568 0.010 0.000 0.022 0.000 /usr/lib/python2.7/inspect.py:440(getsourcefile) 
     214 0.009 0.000 0.138 0.001 /usr/lib/python2.7/inspect.py:472(getmodule) 
     23 0.008 0.000 0.008 0.000 /opt/myenv/lib/python2.7/linecache.py:68(updatecache) 
    1544 0.007 0.000 0.007 0.000 /opt/myenv/lib/python2.7/genericpath.py:15(exists) 
     8 0.005 0.001 0.205 0.026 /opt/myenv/lib/python2.7/site-packages/debug_toolbar/utils/tracking/db.py:85(execute) 
    10187 0.005 0.000 0.007 0.000 /opt/myenv/lib/python2.7/stat.py:55(S_ISLNK) 
     458 0.005 0.000 0.008 0.000 /opt/myenv/lib/python2.7/site-packages/django/template/base.py:673(__init__) 
     4 0.004 0.001 0.005 0.001 /opt/myenv/lib/python2.7/site-packages/memcache.py:965(_recv_value) 
     395 0.004 0.000 0.011 0.000 /opt/myenv/lib/python2.7/site-packages/django/template/base.py:524(__init__) 
    7243 0.004 0.000 0.004 0.000 /usr/lib/python2.7/inspect.py:51(ismodule) 
    4078 0.003 0.000 0.003 0.000 /opt/myenv/lib/python2.7/posixpath.py:51(isabs) 
    114/10 0.003 0.000 0.028 0.003 /opt/myenv/lib/python2.7/site-packages/django/template/base.py:234(parse) 
    2504 0.003 0.000 0.021 0.000 /opt/myenv/lib/python2.7/posixpath.py:341(abspath) 
     803 0.002 0.000 0.003 0.000 /opt/myenv/lib/python2.7/site-packages/django/template/base.py:200(create_token) 
     6 0.002 0.000 0.002 0.000 /opt/myenv/lib/python2.7/site-packages/django/db/models/options.py:388(_fill_related_objects_cache) 
    10187 0.002 0.000 0.002 0.000 /opt/myenv/lib/python2.7/stat.py:24(S_IFMT) 
     621 0.002 0.000 0.004 0.000 /opt/myenv/lib/python2.7/site-packages/django/utils/functional.py:170(wrapper) 
    1806 0.002 0.000 0.005 0.000 /usr/lib/python2.7/inspect.py:398(getfile) 
    6224 0.002 0.000 0.002 0.000 /usr/lib/python2.7/string.py:220(lower) 
    1150 0.002 0.000 0.027 0.000 /usr/lib/python2.7/inspect.py:460(getabsfile) 
    394/273 0.002 0.000 0.002 0.000 /opt/myenv/lib/python2.7/site-packages/django/template/context.py:49(__getitem__) 
     214 0.002 0.000 0.154 0.001 /usr/lib/python2.7/inspect.py:518(findsource) 
     1 0.002 0.002 0.005 0.005 /opt/myenv/lib/python2.7/site-packages/django/core/urlresolvers.py:237(_populate) 
     505 0.002 0.000 0.002 0.000 /opt/myenv/lib/python2.7/site-packages/django/utils/text.py:320(smart_split) 
    59/21 0.002 0.000 0.004 0.000 /opt/myenv/lib/python2.7/sre_parse.py:379(_parse) 
     59 0.001 0.000 0.006 0.000 /opt/myenv/lib/python2.7/site-packages/django/templatetags/i18n.py:281(do_translate) 
     10 0.001 0.000 0.005 0.000 /opt/myenv/lib/python2.7/site-packages/django/template/base.py:188(tokenize) 
    518/88 0.001 0.000 0.003 0.000 /usr/lib/python2.7/copy.py:145(deepcopy) 
     214 0.001 0.000 0.160 0.001 /opt/myenv/lib/python2.7/site-packages/debug_toolbar/utils/__init__.py:101(getframeinfo) 
     446 0.001 0.000 0.001 0.000 /opt/myenv/lib/python2.7/site-packages/django/utils/text.py:364(unescape_string_literal) 
---- By file ---- 

     tottime 
43.4% 0.102 /opt/myenv/lib/python2.7/posixpath.py 
13.2% 0.031 /usr/lib/python2.7/inspect.py 
9.4% 0.022 /opt/myenv/lib/python2.7/site-packages/django/template/base.py 
6.8% 0.016 /opt/myenv/lib/python2.7/site-packages/django/db/backends/postgresql_psycopg2/base.py 
3.4% 0.008 /opt/myenv/lib/python2.7/linecache.py 
3.0% 0.007 /opt/myenv/lib/python2.7/stat.py 
3.0% 0.007 /opt/myenv/lib/python2.7/genericpath.py 
2.1% 0.005 /opt/myenv/lib/python2.7/site-packages/debug_toolbar/utils/tracking/db.py 
1.7% 0.004 /opt/myenv/lib/python2.7/sre_parse.py 
1.7% 0.004 /opt/myenv/lib/python2.7/site-packages/memcache.py 
1.3% 0.003 /opt/myenv/lib/python2.7/site-packages/django/utils/text.py 
1.3% 0.003 /opt/myenv/lib/python2.7/site-packages/django/core/urlresolvers.py 
0.9% 0.002 /usr/lib/python2.7/string.py 
0.9% 0.002 /opt/myenv/lib/python2.7/site-packages/django/utils/regex_helper.py 
0.9% 0.002 /opt/myenv/lib/python2.7/site-packages/django/utils/functional.py 
0.9% 0.002 /opt/myenv/lib/python2.7/site-packages/django/template/context.py 
0.9% 0.002 /opt/myenv/lib/python2.7/site-packages/django/db/models/options.py 
0.9% 0.002 /opt/myenv/lib/python2.7/site-packages/debug_toolbar/utils/__init__.py 
0.4% 0.001 /usr/lib/python2.7/copy.py 
0.4% 0.001 /opt/myenv/source/portal/myenv/views/__init__.py 
0.4% 0.001 /opt/myenv/lib/python2.7/sre_compile.py 
0.4% 0.001 /opt/myenv/lib/python2.7/site-packages/django/utils/safestring.py 
0.4% 0.001 /opt/myenv/lib/python2.7/site-packages/django/utils/importlib.py 
0.4% 0.001 /opt/myenv/lib/python2.7/site-packages/django/utils/encoding.py 
0.4% 0.001 /opt/myenv/lib/python2.7/site-packages/django/templatetags/i18n.py 
0.4% 0.001 /opt/myenv/lib/python2.7/site-packages/django/template/loaders/app_directories.py 
0.4% 0.001 /opt/myenv/lib/python2.7/site-packages/django/template/defaulttags.py 
0.4% 0.001 /opt/myenv/lib/python2.7/site-packages/django/db/models/base.py 
0.4% 0.001 /opt/myenv/lib/python2.7/encodings/utf_8.py 
0.0% 0.000 
0.0% 0.000 /usr/lib/python2.7/uuid.py 
0.0% 0.000 /usr/lib/python2.7/urllib.py 
0.0% 0.000 /usr/lib/python2.7/threading.py 
0.0% 0.000 /usr/lib/python2.7/socket.py 
0.0% 0.000 /usr/lib/python2.7/pprint.py 
0.0% 0.000 /usr/lib/python2.7/multiprocessing/process.py 
0.0% 0.000 /usr/lib/python2.7/logging/handlers.py 
0.0% 0.000 /usr/lib/python2.7/logging/__init__.py 
0.0% 0.000 /usr/lib/python2.7/gettext.py 
0.0% 0.000 /usr/lib/python2.7/functools.py 

正如你所看到的,Django的調試工具欄和能人剖析中間件時機非常關。

什麼可能導致uWSGI在Django渲染模板之後處理超過〜250ms的請求?我已經嘗試在uWSGI中啓用profiler選項,但它會生成數十萬個調用的信息,因此很難與之配合。

任何建議表示讚賞。

+0

可能你會更幸運地在uwsgi郵件列表上詢問這個問題 – vad

+0

@MikeAr如果你顯示你如何進行性能分析 – nk9

回答

2

我認爲問題在於分析中間件做了大量處理,但未包含在配置文件時間中,但會影響總請求處理時間。

一看the profiler middleware code。分析器關閉後,將從臨時文件讀取結果(這可能是二進制格式的相當大的文件)。然後處理結果並將其注入響應中。

此附加處理可能會導致您所看到的差異。嘗試運行禁用Profiler的基準測試(不要在URL中傳遞?prof)並查看nginx和uwsgi處理時間是否得到改善。