糟糕的Django/uwsgi性能

Question

我正在用 nginx 和 uwsgi 运行一个 django 应用。下面是我运行 uwsgi 的方式：

sudo uwsgi -b 25000 --chdir=/www/python/apps/pyapp --module=wsgi:application --env DJANGO_SETTINGS_MODULE=settings --socket=/tmp/pyapp.socket --cheaper=8 --processes=16  --harakiri=10  --max-requests=5000  --vacuum --master --pidfile=/tmp/pyapp-master.pid --uid=220 --gid=499

还有 nginx 的配置：

server {
    listen 80;
    server_name test.com

    root /www/python/apps/pyapp/;

    access_log /var/log/nginx/test.com.access.log;
    error_log /var/log/nginx/test.com.error.log;

    # https://docs.djangoproject.com/en/dev/howto/static-files/#serving-static-files-in-production
    location /static/ {
        alias /www/python/apps/pyapp/static/;
        expires 30d;
    }

    location /media/ {
        alias /www/python/apps/pyapp/media/;
        expires 30d;
    }

    location / {
        uwsgi_pass unix:///tmp/pyapp.socket;
        include uwsgi_params;
        proxy_read_timeout 120;
    }

    # what to serve if upstream is not available or crashes
    #error_page 500 502 503 504 /media/50x.html;
}

现在问题来了。当我在服务器上使用 "ab"（ApacheBenchmark）进行测试时，得到了以下结果：

nginx 版本：nginx/1.2.6

uwsgi 版本：1.4.5

Server Software:        nginx/1.0.15
Server Hostname:        pycms.com
Server Port:            80

Document Path:          /api/nodes/mostviewed/8/?format=json
Document Length:        8696 bytes

Concurrency Level:      100
Time taken for tests:   41.232 seconds
Complete requests:      1000
Failed requests:        0
Write errors:           0
Total transferred:      8866000 bytes
HTML transferred:       8696000 bytes
Requests per second:    24.25 [#/sec] (mean)
Time per request:       4123.216 [ms] (mean)
Time per request:       41.232 [ms] (mean, across all concurrent requests)
Transfer rate:          209.99 [Kbytes/sec] received

在 500 个并发连接的情况下运行时

oncurrency Level:      500
Time taken for tests:   2.175 seconds
Complete requests:      1000
Failed requests:        50
   (Connect: 0, Receive: 0, Length: 50, Exceptions: 0)
Write errors:           0
Non-2xx responses:      950
Total transferred:      629200 bytes
HTML transferred:       476300 bytes
Requests per second:    459.81 [#/sec] (mean)
Time per request:       1087.416 [ms] (mean)
Time per request:       2.175 [ms] (mean, across all concurrent requests)
Transfer rate:          282.53 [Kbytes/sec] received

如你所见，服务器上的所有请求都失败了，要么是超时错误，要么是“客户端过早断开连接”，或者：

writev(): Broken pipe [proto/uwsgi.c line 124] during GET /api/nodes/mostviewed/9/?format=json

关于我的应用程序，这里有一点更多的信息：基本上，它是一些模型的集合，这些模型反映了 MySQL 表，表中包含所有内容。在前端，我使用 django-rest-framework 来向客户端提供 json 内容。

我安装了 django-profiling 和 django debug toolbar 来查看发生了什么。在 django-profiling 中，当我运行一个请求时，得到的结果是：

Instance wide RAM usage

Partition of a set of 147315 objects. Total size = 20779408 bytes.
 Index  Count   %     Size   % Cumulative  % Kind (class / dict of class)
     0  63960  43  5726288  28   5726288  28 str
     1  36887  25  3131112  15   8857400  43 tuple
     2   2495   2  1500392   7  10357792  50 dict (no owner)
     3    615   0  1397160   7  11754952  57 dict of module
     4   1371   1  1236432   6  12991384  63 type
     5   9974   7  1196880   6  14188264  68 function
     6   8974   6  1076880   5  15265144  73 types.CodeType
     7   1371   1  1014408   5  16279552  78 dict of type
     8   2684   2   340640   2  16620192  80 list
     9    382   0   328912   2  16949104  82 dict of class
<607 more rows. Type e.g. '_.more' to view.>



CPU Time for this request

         11068 function calls (10158 primitive calls) in 0.064 CPU seconds

   Ordered by: cumulative time

   ncalls  tottime  percall  cumtime  percall filename:lineno(function)
        1    0.000    0.000    0.064    0.064 /usr/lib/python2.6/site-packages/django/views/generic/base.py:44(view)
        1    0.000    0.000    0.064    0.064 /usr/lib/python2.6/site-packages/django/views/decorators/csrf.py:76(wrapped_view)
        1    0.000    0.000    0.064    0.064 /usr/lib/python2.6/site-packages/rest_framework/views.py:359(dispatch)
        1    0.000    0.000    0.064    0.064 /usr/lib/python2.6/site-packages/rest_framework/generics.py:144(get)
        1    0.000    0.000    0.064    0.064 /usr/lib/python2.6/site-packages/rest_framework/mixins.py:46(list)
        1    0.000    0.000    0.038    0.038 /usr/lib/python2.6/site-packages/rest_framework/serializers.py:348(data)
     21/1    0.000    0.000    0.038    0.038 /usr/lib/python2.6/site-packages/rest_framework/serializers.py:273(to_native)
     21/1    0.000    0.000    0.038    0.038 /usr/lib/python2.6/site-packages/rest_framework/serializers.py:190(convert_object)
     11/1    0.000    0.000    0.036    0.036 /usr/lib/python2.6/site-packages/rest_framework/serializers.py:303(field_to_native)
    13/11    0.000    0.000    0.033    0.003 /usr/lib/python2.6/site-packages/django/db/models/query.py:92(__iter__)
      3/1    0.000    0.000    0.033    0.033 /usr/lib/python2.6/site-packages/django/db/models/query.py:77(__len__)
        4    0.000    0.000    0.030    0.008 /usr/lib/python2.6/site-packages/django/db/models/sql/compiler.py:794(execute_sql)
        1    0.000    0.000    0.021    0.021 /usr/lib/python2.6/site-packages/django/views/generic/list.py:33(paginate_queryset)
        1    0.000    0.000    0.021    0.021 /usr/lib/python2.6/site-packages/django/core/paginator.py:35(page)
        1    0.000    0.000    0.020    0.020 /usr/lib/python2.6/site-packages/django/core/paginator.py:20(validate_number)
        3    0.000    0.000    0.020    0.007 /usr/lib/python2.6/site-packages/django/core/paginator.py:57(_get_num_pages)
        4    0.000    0.000    0.020    0.005 /usr/lib/python2.6/site-packages/django/core/paginator.py:44(_get_count)
        1    0.000    0.000    0.020    0.020 /usr/lib/python2.6/site-packages/django/db/models/query.py:340(count)
        1    0.000    0.000    0.020    0.020 /usr/lib/python2.6/site-packages/django/db/models/sql/query.py:394(get_count)
        1    0.000    0.000    0.020    0.020 /usr/lib/python2.6/site-packages/django/db/models/query.py:568(_prefetch_related_objects)
        1    0.000    0.000    0.020    0.020 /usr/lib/python2.6/site-packages/django/db/models/query.py:1596(prefetch_related_objects)
        4    0.000    0.000    0.020    0.005 /usr/lib/python2.6/site-packages/django/db/backends/util.py:36(execute)
        1    0.000    0.000    0.020    0.020 /usr/lib/python2.6/site-packages/django/db/models/sql/query.py:340(get_aggregation)
        5    0.000    0.000    0.020    0.004 /usr/lib64/python2.6/site-packages/MySQLdb/cursors.py:136(execute)
        2    0.000    0.000    0.020    0.010 /usr/lib/python2.6/site-packages/django/db/models/query.py:1748(prefetch_one_level)
        4    0.000    0.000    0.020    0.005 /usr/lib/python2.6/site-packages/django/db/backends/mysql/base.py:112(execute)
        5    0.000    0.000    0.019    0.004 /usr/lib64/python2.6/site-packages/MySQLdb/cursors.py:316(_query)
       60    0.000    0.000    0.018    0.000 /usr/lib/python2.6/site-packages/django/db/models/query.py:231(iterator)
        5    0.012    0.002    0.015    0.003 /usr/lib64/python2.6/site-packages/MySQLdb/cursors.py:278(_do_query)
       60    0.000    0.000    0.013    0.000 /usr/lib/python2.6/site-packages/django/db/models/sql/compiler.py:751(results_iter)
       30    0.000    0.000    0.010    0.000 /usr/lib/python2.6/site-packages/django/db/models/manager.py:115(all)
       50    0.000    0.000    0.009    0.000 /usr/lib/python2.6/site-packages/django/db/models/query.py:870(_clone)
       51    0.001    0.000    0.009    0.000 /usr/lib/python2.6/site-packages/django/db/models/sql/query.py:235(clone)
        4    0.000    0.000    0.009    0.002 /usr/lib/python2.6/site-packages/django/db/backends/__init__.py:302(cursor)
        4    0.000    0.000    0.008    0.002 /usr/lib/python2.6/site-packages/django/db/backends/mysql/base.py:361(_cursor)
        1    0.000    0.000    0.008    0.008 /usr/lib64/python2.6/site-packages/MySQLdb/__init__.py:78(Connect)
  910/208    0.003    0.000    0.008    0.000 /usr/lib64/python2.6/copy.py:144(deepcopy)
       22    0.000    0.000    0.007    0.000 /usr/lib/python2.6/site-packages/django/db/models/query.py:619(filter)
       22    0.000    0.000    0.007    0.000 /usr/lib/python2.6/site-packages/django/db/models/query.py:633(_filter_or_exclude)
       20    0.000    0.000    0.005    0.000 /usr/lib/python2.6/site-packages/django/db/models/fields/related.py:560(get_query_set)
        1    0.000    0.000    0.005    0.005 /usr/lib64/python2.6/site-packages/MySQLdb/connections.py:8()

..等等

然而，django-debug-toolbar 显示了以下内容：

Resource Usage
Resource    Value
User CPU time   149.977 msec
System CPU time 119.982 msec
Total CPU time  269.959 msec
Elapsed time    326.291 msec
Context switches    11 voluntary, 40 involuntary

and 5 queries in 27.1 ms

问题在于，“top”显示负载平均值迅速上升，而我在本地服务器和网络内的远程机器上运行的 apache benchmark 显示我每秒处理的请求并不多。问题出在哪里？这是我在分析代码时能找到的结果，如果有人能指出我在做什么，那将不胜感激。

编辑（2013年2月23日）：根据 Andrew Alcock 的回答添加更多细节： 需要我关注/回答的要点是 (3)(3) 我在 MySQL 上执行了“show global variables”，发现 MySQL 的 max_connections 设置为 151，这足够支持我为 uwsgi 启动的工作进程。

(3)(4)(2) 我正在分析的单个请求是最重的。根据 django-debug-toolbar，它执行了 4 个查询。查询的执行时间分别是： 3.71 毫秒，2.83 毫秒，0.88 毫秒，4.84 毫秒。

(4) 你在提到内存分页吗？如果是的话，我怎么判断？

(5) 在 16 个工作进程、100 个并发率和 1000 个请求的情况下，负载平均值上升到 ~ 12 我在不同数量的工作进程上进行了测试（并发级别为 100）：

1 个工作进程，负载平均值 ~ 1.85，每秒 19 个请求，请求时间：5229.520 毫秒，0 个非 2xx 响应
2 个工作进程，负载平均值 ~ 1.5，每秒 19 个请求，请求时间：516.520 毫秒，0 个非 2xx 响应
4 个工作进程，负载平均值 ~ 3，每秒 16 个请求，请求时间：5929.921 毫秒，0 个非 2xx 响应
8 个工作进程，负载平均值 ~ 5，每秒 18 个请求，请求时间：5301.458 毫秒，0 个非 2xx 响应
16 个工作进程，负载平均值 ~ 19，每秒 15 个请求，请求时间：6384.720 毫秒，0 个非 2xx 响应

如你所见，工作进程越多，系统的负载就越大。我在 uwsgi 的守护进程日志中看到，当我增加工作进程的数量时，响应时间（毫秒）也在增加。

在 16 个工作进程的情况下，运行 500 个并发请求时，uwsgi 开始记录错误：

 writev(): Broken pipe [proto/uwsgi.c line 124]

负载也上升到 ~ 10。而且测试并没有花费太多时间，因为非 2xx 响应有 923 个是 1000 个请求中的，这就是为什么响应速度很快，因为几乎是空的。这也回应了你在总结中的第 4 点。

假设我面临的是基于 I/O 和网络的操作系统延迟，那么有什么推荐的措施来扩展这个系统？新的硬件？更大的服务器？

谢谢

mysql django nginx concurrency uwsgi performance tuning load testing request profiling

糟糕的Django/uwsgi性能

3 个回答

撰写回答