Django WSGI多线程和连接问题

2024-03-29 14:00:57 发布

您现在位置:Python中文网/ 问答频道 /正文

我按照Graham的指示使用mod wsgi:http://blog.dscpl.com.au/2010/03/improved-wsgi-script-for-use-with.html将Apache与Django集成,但是仍然遇到连接和响应时间方面的问题。由于它是随机发生的,而且Apache日志文件中没有任何错误,所以很难理解到底发生了什么。在

我的Apache是用pre-fork构建的,配置如下:

<IfModule prefork.c>
StartServers       8
MinSpareServers    5
MaxSpareServers   20
ServerLimit      256
MaxClients       256
MaxRequestsPerChild 0
</IfModule>

WSGI相关配置:

^{pr2}$

在请求处理器中,我使用以下命令监视活动线程:

logger.info("Active threads: {0}".format(threading.active_count()))

我注意到,尽管我在配置中最多有25个线程,但活动线程数永远不会超过4个,同时一些客户端可以等待新连接超过1分钟,而请求处理时间大约为2秒。在

如果一个请求到达服务器,它的处理速度会很快,但也有这样的情况(大约每100个请求中就有一个请求),因为Apache的限制,客户机有时甚至会超时:

Timeout 60 

我认为,这种行为在web应用程序世界中很容易被忽视,100个请求中有1个没有起到重要作用(用户只需重新加载一个页面),但在服务领域,这确实是个问题。在

我不明白这一点-如果所有线程都忙于为其他客户机服务,为什么Django不生成另一个线程?如果不是关于线程,那么它可能是什么呢?格雷厄姆写的应用程序重新加载问题?在

以下是我的版本:

python26-2.6.8-3.30.amzn1.x86_64
Django-1.4.3
mod_wsgi-3.2-1.6.amzn1.x86_64
Server version: Apache/2.2.23 (Unix)
Server loaded:  APR 1.4.6, APR-Util 1.4.1
Compiled using: APR 1.4.6, APR-Util 1.4.1
Architecture:   64-bit
Server MPM:     Prefork
  threaded:     no
    forked:     yes (variable process count)

==============实施Graham建议的第一次更新===================================

格雷厄姆等人

感谢您的意见和建议。我已经检查了mod\wsgi版本,它是3.2(见上文)。 我的WSGI配置现在如下所示:

LogLevel info
LoadModule wsgi_module modules/mod_wsgi.so
WSGISocketPrefix run/wsgix
WSGIDaemonProcess somename user=apache group=apache threads=25
WSGIScriptAlias /  /wsgi-dir/script.wsgi process-group=somename application-group=%{GLOBAL}

<Directory /wsgi-dir>
   Order deny,allow
   Allow from all
</Directory>

启动50个EC2客户机,每个客户机在引导时向服务发送两条消息就足够了,一个客户机的延迟时间为49秒,而所有其他客户机的平均响应时间为2.2秒,最长为7秒。在

我检查了应用程序日志文件,发现对于延迟的请求,“请求已接收”和“响应发送”之间的增量为0.16秒,而从客户端的角度来看,延迟时间为49秒。在

它给我们留下了两种可能性:

  1. 客户端在将近49秒的时间内无法建立连接
  2. 建立了一个连接,但是服务器(实际上是Django/WSGI内部)无法快速读取请求。在

很难说它是#1还是#2,因为我在客户机上使用了Python的“requests”模块来连接到服务。但我认为是#2,因为如果延迟稍微高于64-65秒,Apache发送/接收超时就会出现,我可以在Apache的日志文件中看到这一点。在

以下是我将尝试做的进一步澄清:

  1. 创建一个简单的控制器,如下所示:

    def侦听器(请求):

    logger.info("Started, active threads: {0}".format(threading.active_count()))    
    time.sleep(3)
    logger.info("Finished, active threads: {0}".format(threading.active_count()))    
    return HttpResponse('OK')
    

注意:记录器也会记录时间。在

  1. 创建一个简单的stat接口(我不想分析所有客户机EC2上的日志):

    定义日志(请求):

    id = request.REQUEST['id']
    time = request.REQUEST['time']
    res = request.REQUEST['res']
    
    if (id and time):
        logger.info("STAT Instance: {0}, Processing time: {1}, Response: {2}".format(id,time,res))
    
    return HttpResponse('OK')
    

客户将这样工作:

  1. 向“listener”URL发送两个请求并计算客户端上的处理时间
  2. 将处理时间和EC2实例id一起发送到“log”URL

    如果我能够用这个简单的方法重现这个问题,它将变得可复制,我希望Django团队能够从那里着手。

任何其他的建议也很感激。非常感谢所有回答的人。在

==============建议测试的第二次更新===================================

我已经实现了建议的侦听器,可以重现这个问题,并希望其他人也能这样做—您只需要一个AWS帐户就可以成为able要推出大量的EC2客户机—50个通常就足够了,但有时我需要去100个客户机才能看到延迟。在

有趣的是,在这个测试中,活动线程的数量从1逐渐增加到8,这可能是因为服务器上的平均处理时间增加了,所以它可以工作,但仍然不足以防止延迟。在

我把客户机的脚本放到EC2的用户数据中,如下所示。如果你需要一个关于如何创建一个自动搜索组与所有这些客户,请让我知道。在

#!/bin/bash

do_send() {

        d1=`date +%s`
        res=`python ~ec2-user/client/fetch.py ${URL_ROOT}/init/`
        res=`echo $res | tr '\n' ' ' | tr ' ' +`
        d2=`date +%s`
        delta=`expr $d2 - $d1`
        echo $ami $ins $res $delta >>$LOG
        curl -s  "${URL_ROOT}/stat/?id=$ami&time=$delta&res=$ins:$res" >/dev/null 2>&1
}

URL_ROOT=<SERVICE-ROOT_URL>
LOG=~ec2-user/log.txt

ins=`curl -s http://169.254.169.254/latest/meta-data/instance-id 2>/dev/null`
ami=`curl -s http://169.254.169.254/latest/meta-data/ami-id 2>/dev/null`
echo "Instance=[$ins]" >$LOG

# First request
do_send

# Second request
do_send

在fetch.py客户端如下所示:

@author: ogryb
'''
import requests
import datetime
import socket

from optparse import OptionParser
usage = "usage: %prog [options] init_url\n   init_url - http://<host>/init/ server's address"
parser = OptionParser(usage=usage)
parser.add_option("-i", "--id", dest="id",
                  help="instance ID", metavar="STRING")
parser.add_option("-p", "--phost", dest="phost",
                  help="public hostname", metavar="STRING")
parser.add_option("-l", "--lhost", dest="lhost",
                  help="local hostname", metavar="STRING")
parser.add_option("-t", "--type", dest="type",
                  help="instance type", metavar="STRING")
parser.add_option("-q", "--quiet",
                  action="store_true", dest="quiet", default=False,
                  help="Quiet mode")
(opt, args) = parser.parse_args()
ip = socket.gethostbyname(socket.gethostname())
if (not opt.quiet):
    print ("=== Getting metadata:\t{0} {1}".format(datetime.datetime.utcnow(), ip))
if not opt.id:
    r = requests.get(url='http://169.254.169.254/latest/meta-data/instance-id')
    opt.id = r.text
if not opt.phost:
    r = requests.get(url='http://169.254.169.254/latest/meta-data/public-hostname')
    opt.phost = r.text
if not opt.lhost:
    r = requests.get(url='http://169.254.169.254/latest/meta-data/local-hostname')
    opt.lhost = r.text
if not opt.type:
    r = requests.get(url='http://169.254.169.254/latest/meta-data/instance-type')
    opt.type = r.text
body = "id={0}&phost={1}&lhost={2}&type={3}".format(opt.id, opt.phost, opt.lhost, opt.type)
if (not opt.quiet):
    print ("=== Start sending:\t{0} {1} {2}".format(datetime.datetime.utcnow(), ip, opt.id))
r = requests.post(url=args[0], data=body, verify=False)
if (not opt.quiet):
    print ("=== End sending:\t{0} {1} {2}".format(datetime.datetime.utcnow(), ip, opt.id))
print r.text
if (not opt.quiet):
    print "Request Body={0} url={1}".format(body,args[0])
    print "Response: {0}\n{1}".format(r.status_code, r.text)

===========03/19/13-23:45错误日志中的其他信息===

我将Apache日志级别更改为debug,并在Apache error_log中发现以下内容。请告诉我这是否是延误的原因,以及对此能做些什么。我在某个地方读到“keyror”是无害的,但你永远不知道。在

一个客户在6:37:28被延迟了41秒。错误日志最近的事件发生在06:37:15:

Wed Mar 20 06:37:15 2013] [info] mod_wsgi (pid=27005): Initializing Python.
[Wed Mar 20 06:37:15 2013] [info] mod_wsgi (pid=27005): Attach interpreter '

完整的错误日志如下:

Wed Mar 20 06:29:45 2013] [info] Server built: Oct 21 2012 20:35:32
[Wed Mar 20 06:29:45 2013] [debug] prefork.c(1023): AcceptMutex: sysvsem (default: sysvsem)
[Wed Mar 20 06:29:45 2013] [info] mod_wsgi (pid=26891): Attach interpreter ''.
[Wed Mar 20 06:29:45 2013] [info] mod_wsgi (pid=26892): Attach interpreter ''.
[Wed Mar 20 06:29:45 2013] [info] mod_wsgi (pid=26893): Attach interpreter ''.
[Wed Mar 20 06:29:45 2013] [info] mod_wsgi (pid=26895): Attach interpreter ''.
[Wed Mar 20 06:29:45 2013] [info] mod_wsgi (pid=26894): Attach interpreter ''.
[Wed Mar 20 06:37:15 2013] [debug] proxy_util.c(1820): proxy: grabbed scoreboard slot 0 in child 27005 for worker proxy:reverse
[Wed Mar 20 06:37:15 2013] [debug] proxy_util.c(1839): proxy: worker proxy:reverse already initialized
[Wed Mar 20 06:37:15 2013] [debug] proxy_util.c(1936): proxy: initialized single connection worker 0 in child 27005 for (*)
[Wed Mar 20 06:37:15 2013] [info] mod_wsgi (pid=27005): Initializing Python.
[Wed Mar 20 06:37:15 2013] [info] mod_wsgi (pid=27005): Attach interpreter ''.
[Wed Mar 20 06:38:10 2013] [debug] proxy_util.c(1820): proxy: grabbed scoreboard slot 0 in child 27006 for worker proxy:reverse
[Wed Mar 20 06:38:10 2013] [debug] proxy_util.c(1839): proxy: worker proxy:reverse already initialized
[Wed Mar 20 06:38:10 2013] [debug] proxy_util.c(1936): proxy: initialized single connection worker 0 in child 27006 for (*)
[Wed Mar 20 06:38:10 2013] [info] mod_wsgi (pid=27006): Initializing Python.
[Wed Mar 20 06:38:10 2013] [info] mod_wsgi (pid=27006): Attach interpreter ''.
[Wed Mar 20 06:38:11 2013] [info] mod_wsgi (pid=26874): Destroying interpreters.
[Wed Mar 20 06:38:11 2013] [info] mod_wsgi (pid=26874): Cleanup interpreter ''.
[Wed Mar 20 06:38:11 2013] [info] mod_wsgi (pid=26874): Terminating Python.
[Wed Mar 20 06:38:11 2013] [error] Exception KeyError: KeyError(140627014572000,) in <module 'threading' from '/usr/lib64/python2.6/threading.pyc'> ignored
[Wed Mar 20 06:38:11 2013] [info] mod_wsgi (pid=26874): Python has shutdown.
[Wed Mar 20 06:38:44 2013] [debug] proxy_util.c(1820): proxy: grabbed scoreboard slot 0 in child 27007 for worker proxy:reverse
[Wed Mar 20 06:38:44 2013] [debug] proxy_util.c(1839): proxy: worker proxy:reverse already initialized
[Wed Mar 20 06:38:44 2013] [debug] proxy_util.c(1936): proxy: initialized single connection worker 0 in child 27007 for (*)
[Wed Mar 20 06:38:44 2013] [info] mod_wsgi (pid=27007): Initializing Python.
[Wed Mar 20 06:38:44 2013] [info] mod_wsgi (pid=27007): Attach interpreter ''.
[Wed Mar 20 06:38:45 2013] [info] mod_wsgi (pid=26880): Destroying interpreters.
[Wed Mar 20 06:38:45 2013] [info] mod_wsgi (pid=26880): Cleanup interpreter ''.
[Wed Mar 20 06:38:45 2013] [info] mod_wsgi (pid=26880): Terminating Python.
[Wed Mar 20 06:38:45 2013] [error] Exception KeyError: KeyError(140627014572000,) in <module 'threading' from '/usr/lib64/python2.6/threading.pyc'> ignored
[Wed Mar 20 06:38:45 2013] [info] mod_wsgi (pid=26880): Python has shutdown.

Tags: debuginfoidmodformatwsgi客户机apache
2条回答

很抱歉回答得太晚,也没有提供太多细节,但这不是Django或Apache的问题。这是它运行的环境问题。我很清楚“环境”有什么问题,但由于保密协议,不能透露更多细节。我希望你能理解我所说的“环境”是什么意思。在

还有一个提示:当我在最初的帖子中假设它是2时,我错了——实际上是1。在

我认为,知道这不是Django或Apache问题,对所有仍在研究这个问题的人来说是一个巨大的帮助。我不在乎这个答案会得到多少反对票或赞成票,我只是想帮忙,因为我知道要花多少时间研究所有这些。在

谢谢。在

配置:

<Directory /wsgi-dir/script.wsgi>
   Order deny,allow
   Allow from all
   WSGIProcessGroup  somename
</Directory>

应该是:

^{pr2}$

首先。在

当处理请求时,您所拥有的WSGI应用程序将以嵌入式模式而不是守护程序模式运行。这是因为path-to-Directory指令错误,不是它应该的目录。不能像以前那样使用文件路径。您应该使用以下方法验证它的运行位置:

同时,您可能已经在守护程序模式进程中加载了一个冗余副本,而WSGIImportScript从来没有使用过这个副本。在

即使在修复了指令路径之后,预加载也在处理请求的不同子解释器中。您需要上面给出的WSGIApplicationGroup来确保它们位于同一个子解释器(applicationgroup)中。在

如果使用mod_wsgi 3.0+,则最好删除WSGIImportScript指令,而使用:

WSGIScriptAlias / /wsgi-dir/script.wsgi process-group=somename application-group=%{GLOBAL}

<Directory /wsgi-dir>
   Order deny,allow
   Allow from all
</Directory>

使用WSGIScriptAlias同时指定进程组和应用程序组,无需单独使用WSGIProcessGroup和WSGIApplicationGroup。同时指定这两者也有预加载脚本的副作用,从而替换了WSGIImportScript所做的工作,也就是为什么可以删除WSGIImportScript。在

至于为什么请求花费这么长时间的性能问题,您可以安装并尝试使用newrelic来挖掘问题所在。在

对于一般的Apache配置,也建议您阅读PyCon US talk中我的幻灯片:

这段录像本周末前应该会上映。在

我去年的PyCon演讲也很有趣。在

相关问题 更多 >