Load testing a django 1.21/Apache/mod_wsgi configuration on an AWS small instance (Ubuntu 10.04) with Apache bench is showing extremely high CPU load (using uptime and vmstat) at  low concurrent requests:



    ab -c 5 -n 1000 "my_url"

...causes this uptime output:

    18:04:54 up 9 days, 16:54,  3 users,  load average: 5.33, 2.45, 1.91

CPU is at 100% even with an Apache bench concurrency value of 2. I'm running Apache bench from a different AWS instance in the same region/zone. Ideas on what's the problem, or how I should continue to debug this?

Details:

- Out of desperation, I installed a  vanilla django project/app with a simple "Hello World" view (no DB calls, etc). Same results. So I doubt it's my application code.
- Memory usage looks fine during the load test. 

Here's a vmstat output before/during/after load test:


    procs -----------memory---------- ---swap-- -----io---- -system-- ----cpu----
    r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa
    0  0      0 1034484  94848 321320    0    0     0     0   13   29  0  0 100  0
    6  0      0 1032916  94848 321328    0    0     0     0  262  720  4 32 12  0
    6  0      0 1031684  94848 321336    0    0     0     0  312  796  7 33  0  0
    8  0      0 1030892  94856 321344    0    0     0    12  302  763  4 36  0  0
    ...
    6  0      0 1030268  94864 321376    0    0     0     0  302  843  3 39  0  0
    0  0      0 1032452  94868 321380    0    0     0    12  183  516  3 22 34  0
    1  0      0 1033988  94868 321388    0    0     0     0   24   38  1  2 92  0
    0  0      0 1033996  94868 321388    0    0     0     0   17   28  0  0 100  0



- I'm running a prefork version of apache2 since I'm also running WordPress, which relies on PHP. (PHP doesn't play well with Apache worker version)

Here's my virtual hosts file:

    WSGIPythonHome /home/xxx/webapps/ve/api
    <VirtualHost *:80>
            ServerAdmin webmaster@localhost
            ServerName  app.xxx.mobi
    
            WSGIDaemonProcess snaplive user=www-data group=www-data processes=10 threads=1 maximum-requests=10000
            WSGIProcessGroup snaplive
            WSGIScriptAlias / /home/xxx/webapps/api/settings/apache/prod.wsgi
            DocumentRoot /home/xxx/webapps/api/static
            ErrorLog /var/log/apache2/django-live/error.log
            CustomLog /var/log/apache2/django-live/access.log combined
    </VirtualHost>

Here's my httpd.conf file:

    Alias /media /home/xxx/Django-1.2.1/django/contrib/admin/media
    LoadModule headers_module /usr/lib/apache2/modules/mod_headers.so
    
    StartServers 2
    MinSpareServers 2
    MaxSpareServers 5
    MaxClients 50
    MaxRequestsPerChild 3000
    ServerLimit 8
    Keepalive off
    HostnameLookups Off

Here's my wsgi file:

    import os
    import sys
    sys.stdout = sys.stderr
    
    from django.core.handlers.wsgi import WSGIHandler
    os.environ['DJANGO_SETTINGS_MODULE'] = 'settings'
    application = WSGIHandler()
    
    sys.path.append("/home/xxx/webapps/api")

By hitting a django url from a browser during the load test, I've confirmed qualitatively that the high CPU load is impacting performance.

I've read that this might not be important, but I'm seeing this a lot in my error logs:

    [Sun Sep 19 18:04:58 2010] [error] Exception KeyError: KeyError(-1218693376,) in <module 'threading' from '/usr/lib/python2.6/threading.pyc'> ignored

Here are my Apache bench results, in case helpful:

    Server Software:        Apache/2.2.14
    Server Hostname:        app.xxx.mobi
    Server Port:            80
    
    Document Path:          /plist_catalog/test_data
    Document Length:        0 bytes
    
    Concurrency Level:      5
    Time taken for tests:   27.720 seconds
    Complete requests:      1000
    Failed requests:        0
    Write errors:           0
    Non-2xx responses:      1000
    Total transferred:      269000 bytes
    HTML transferred:       0 bytes
    Requests per second:    36.08 [#/sec] (mean)
    Time per request:       138.598 [ms] (mean)
    Time per request:       27.720 [ms] (mean, across all concurrent requests)
    Transfer rate:          9.48 [Kbytes/sec] received
    
    Connection Times (ms)
                  min  mean[+/-sd] median   max
    Connect:        1    2   8.5      1      88
    Processing:     9  136 176.9     81    1182
    Waiting:        9  135 176.6     81    1182
    Total:         10  138 176.7     83    1183
    
    Percentage of the requests served within a certain time (ms)
      50%     83
      66%     98
      75%    128
      80%    140
      90%    423
      95%    576
      98%    727
      99%    819
     100%   1183 (longest request)