使用 mod_wsgi 从 Django 上的 Apache 随机延迟 7 秒答案

【问题标题】：Random 7 second delay from Apache on Django with mod_wsgi使用 mod_wsgi 从 Django 上的 Apache 随机延迟 7 秒
【发布时间】：2013-08-03 22:22:24
【问题描述】：

我遇到了问题，并将其范围缩小到 Apache。我在 SSL 上的 mod_wsgi（worker mpm，守护进程模式）上运行 Django w/Tastypie。我正在通过另一台服务器上的 htaccess 代理调用 API，以避免 ajax 跨域访问错误。

一切都运行得非常好。但是，在调用 api 时，我收到了一个非常随机的延迟，通过我们的用户界面点击特定项目。似乎网络服务器有一个非常一致的不一致。延迟总是 7 秒。它每 5-15 分钟随机发生一次。

这是我的 Apache 设置：

<IfModule mpm_worker_module>
    StartServers         25
    MinSpareThreads      25
    MaxSpareThreads      75
    ThreadLimit          64
    ThreadsPerChild      25
    MaxClients          150
    MaxRequestsPerChild   0
    MaxMemFree         1024
</IfModule>

在我的虚拟主机中：

    WSGIDaemonProcess www.domain.com processes=4 threads=1
    WSGIProcessGroup www.domain.com
    WSGIScriptAlias / /var/www/domain/wsgi.py process-group=www.domain.com application-group=%{GLOBAL}
    WSGIPassAuthorization On

所有通过 Django 服务的请求都是 JSON 格式（纯 API）。

任何帮助将不胜感激。

谢谢，标记

更新：我怀疑这实际上很可能是 Apache 问题而不是 DNS 问题。看起来它正在创建额外的进程来在实际响应任何内容之前提供请求。

172.31.4.91 - - [03/Aug/2013:19:01:29 -0700] "GET /api/v1/clock/?limit=1 HTTP/1.1" 200 5159 "https://www.domain.com/" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:20.0) Gecko/20100101 Firefox/20.0"
172.31.4.91 - - [03/Aug/2013:19:01:29 -0700] "-" 408 142 "-" "-"
172.31.4.91 - - [03/Aug/2013:19:01:29 -0700] "-" 408 142 "-" "-"
172.31.4.91 - - [03/Aug/2013:19:01:30 -0700] "-" 408 142 "-" "-"
172.31.4.91 - - [03/Aug/2013:19:01:29 -0700] "PATCH /api/v1/check/546d48e9-f15f-4dee-8742-864d1fc5e0f7/ HTTP/1.1" 202 7334 "https://www.domain.com/" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:20.0) Gecko/20100101 Firefox/20.0"
172.31.4.91 - - [03/Aug/2013:19:01:32 -0700] "-" 408 142 "-" "-"
172.31.4.91 - - [03/Aug/2013:19:01:32 -0700] "-" 408 142 "-" "-"
172.31.4.91 - - [03/Aug/2013:19:01:33 -0700] "-" 408 142 "-" "-"
172.31.4.91 - - [03/Aug/2013:19:01:36 -0700] "-" 408 142 "-" "-"
172.31.4.91 - - [03/Aug/2013:19:01:36 -0700] "-" 408 142 "-" "-"
172.31.4.91 - - [03/Aug/2013:19:01:36 -0700] "-" 408 142 "-" "-"
172.31.4.91 - - [03/Aug/2013:19:01:36 -0700] "-" 408 142 "-" "-"
172.31.4.91 - - [03/Aug/2013:19:01:36 -0700] "-" 408 142 "-" "-"
172.31.4.91 - - [03/Aug/2013:19:01:36 -0700] "-" 408 142 "-" "-"
172.31.4.91 - - [03/Aug/2013:19:01:37 -0700] "-" 408 142 "-" "-"
172.31.4.91 - - [03/Aug/2013:19:01:37 -0700] "-" 408 142 "-" "-"
172.31.4.91 - - [03/Aug/2013:19:01:38 -0700] "POST /api/v1/check/ HTTP/1.1" 201 1492 "https://www.domain.com/" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:20.0) Gecko/20100101 Firefox/20.0"

请注意补丁和发布之间的 8 秒延迟。空行是什么意思？

172.31.4.91 - - [03/Aug/2013:19:01:36 -0700] "-" 408 142 "-" "-"

更新：这是我收到延迟 7 秒的“信息”日志中的要点...

[Sun Aug 04 13:14:15 2013] [info] [client 172.31.28.237] (70007)The timeout specified has expired: SSL input filter read failed.
[Sun Aug 04 13:14:15 2013] [info] [client 172.31.28.237] Connection closed to child 81 with standard shutdown (server api.chanj.com:443)
[Sun Aug 04 13:14:16 2013] [info] Initial (No.1) HTTPS request received for child 136 (server api.chanj.com:443)
[Sun Aug 04 13:14:16 2013] [info] [client 172.31.28.237] Connection to child 147 established (server api.chanj.com:443)
[Sun Aug 04 13:14:16 2013] [info] Seeding PRNG with 656 bytes of entropy
[Sun Aug 04 13:14:16 2013] [info] [client 172.31.28.237] Connection closed to child 136 with standard shutdown (server api.chanj.com:443)
[Sun Aug 04 13:14:16 2013] [info] [client 172.31.28.237] Connection to child 79 established (server api.chanj.com:443)
[Sun Aug 04 13:14:16 2013] [info] Seeding PRNG with 656 bytes of entropy
[Sun Aug 04 13:14:16 2013] [info] Initial (No.1) HTTPS request received for child 79 (server api.chanj.com:443)
[Sun Aug 04 13:14:16 2013] [info] [client 172.31.28.237] Connection to child 17 established (server api.chanj.com:443)
[Sun Aug 04 13:14:16 2013] [info] Seeding PRNG with 656 bytes of entropy
[Sun Aug 04 13:14:17 2013] [info] [client 172.31.28.237] Connection closed to child 79 with standard shutdown (server api.chanj.com:443)
[Sun Aug 04 13:14:17 2013] [info] [client 172.31.28.237] Connection to child 67 established (server api.chanj.com:443)
[Sun Aug 04 13:14:17 2013] [info] Seeding PRNG with 656 bytes of entropy
[Sun Aug 04 13:14:21 2013] [info] Initial (No.1) HTTPS request received for child 67 (server api.chanj.com:443)
[Sun Aug 04 13:14:21 2013] [info] [client 172.31.28.237] Connection to child 140 established (server api.chanj.com:443)
[Sun Aug 04 13:14:21 2013] [info] Seeding PRNG with 656 bytes of entropy
[Sun Aug 04 13:14:21 2013] [info] [client 172.31.28.237] Connection closed to child 67 with standard shutdown (server api.chanj.com:443)
[Sun Aug 04 13:14:21 2013] [info] [client 172.31.28.237] Connection to child 78 established (server api.chanj.com:443)
[Sun Aug 04 13:14:21 2013] [info] Seeding PRNG with 656 bytes of entropy
[Sun Aug 04 13:14:21 2013] [info] [client 172.31.28.237] (70007)The timeout specified has expired: SSL input filter read failed.
[Sun Aug 04 13:14:21 2013] [info] [client 172.31.28.237] Connection closed to child 144 with standard shutdown (server api.chanj.com:443)
[Sun Aug 04 13:14:26 2013] [info] Initial (No.1) HTTPS request received for child 78 (server api.chanj.com:443)

【问题讨论】：

标签： python django apache apache2 mod-wsgi

【解决方案1】：

如中所述：

Significant overhead on Django apache vs. built-in dev server

您没有做任何事情来解决您的 WSGI 应用程序中处理请求的线程太少（总共 4 个），而 Apache 一次可以尝试代理多达 150 个。所以我不排除您的 WSGI 应用程序缺乏处理许多并发长时间运行请求的能力。换句话说，如果您偶尔会收到一些长时间运行的请求，这可能会导致其他请求的积压，从而导致延迟。

另一个导致延迟的潜在原因是 WSGI 应用程序在进程重启时的加载时间。这种延迟可能是因为预加载数据库信息或编译模板。

现在从技术上讲，您的配置不会因为最大请求、不活动等原因而重新启动进程，但是如果正在触摸 WSGI 脚本文件或者您正在运行自动代码重新加载器并且正在触摸其他代码，则进程可以重新启动。

为了确定是否与进程重启有关，您应该确保在 Apache 中将 LogLevel 设置为 'info'，并监控 mod_wsgi 在 Apache 错误日志中记录的有关进程重启和 WSGI 脚本文件加载的内容。还要留意守护进程崩溃，因为这也可能是一个原因。特别是因为你没有使用：

WSGIApplicationGroup %{GLOBAL}

除此之外，真的很难推测。我建议您也许考虑使用监控工具。此处的选项是具有生产能力的系统，例如 New Relic，或者如果在开发环境中，您可以使用 Django 调试工具栏。它们可能有助于缩小延迟发生的位置以及网络请求的范围。

【讨论】：

嗨，格雷厄姆，我刚刚在您发布您的帖子的同时发布了此主题的更新。谢谢（你的）信息。空白行能否为您提供任何信息？所以我认为我应该增加 Apache 的线程数，你有什么建议吗？我很少有任何长时间运行的请求（在小得多的请求上频率更高）。在此测试期间，我不会重新启动任何进程或进行任何更新。
呸，超时了。这将回到这一行 WSGIDaemonProcess www.domain.com processes=4 threads=1。我将其更新为 WSGIDaemonProcess www.domain.com processes=25 threads=5，并将进行额外测试。
我在打开信息的情况下从访问日志中添加了另一个更新，这些行中的某处是发生延迟的地方。我目前将 MaxClients 设置为 75，processes=75 threads=3。
我真的建议你试试 New Relic。如果问题发生在您的实际应用程序代码的上下文中，它将有助于缩小范围。 New Relic 有一个免费层，还有一个完整功能的试用期。那 75 个进程，甚至 25 个进程现在都可能过多。 New Relic 的容量分析报告将有助于确定您真正需要什么来处理您获得的流量。请参阅 blog.newrelic.com/2011/11/08/new-relic-supports-python 和 blog.newrelic.com/2012/09/11/… 了解 New Relic 之旅。
谢谢，前几天我确实添加了新的遗物。容量分析显示最大约为 2.5%。请注意，这不是一个普通的网站，它是一个锁定的相当私有的 api，严格用作一个 restful api。我们已经注意到很多标准思维和逻辑在我们的设置中消失了……无论如何，我有 50 个进程，5 个线程，而且事情现在飞得难以置信的快。我已经使用相当实时的数据进行了测试，但随着我们通过更多连接增加流量，我会在接下来的几天内获得更多信息。谢谢你的帮助，太棒了。

【解决方案2】：

因此，出现问题的地方的网络路由器将 UDP 超时设置为 200 秒。就是这样。与 Apache 等无关。我确实将线程设置得更高，它有所帮助，但这不是导致延迟的原因......

【讨论】：