Django、Apache2 和 Mod_WSGI 提供数据的速度比传真机慢

Django, Apache2 and Mod_WSGI serves data slower than a fax miachine

我在 RPi 模型 3 上设置了一个非常基本的 Django 实例。这很重要,因为这可能确实是问题所在。

我正在使用 Django 3.2、Python 3.7、Mod_WSGI,根据此版本的 python 和 Apache2 从源代码编译,通过包管理器安装(apt install apache2).由于不熟悉 Python 和 WSGI 方面的后端,我怀疑我的设置可能是问题所在……但我离题了。

Mod_WSGI设置为守护进程模式:

LoadModule alias_module /usr/lib/apache2/modules/mod_alias.so
WSGIScriptAlias / /home/pi/steve/steve/steve/wsgi.py
WSGIProcessGroup steve
WSGIDaemonProcess steve python-home=/home/pi/steve/env python-path=/home/pi/steve processes=2 threads=15
#WSGIPythonHome /home/pi/steve/env
#WSGIPythonPath /home/pi/steve
LogLevel debug
<VirtualHost *:80>
...

Django 从 PSQL 数据库收集数据,使用 return JsonResponse(JSONDataSorted, safe=False)

对其进行排序和服务

现在我只提供这种原始的 JSON。它只有 700 行,格式为:

[{"T": "Sun Aug 15 21:51:35 2021", "C": 17.0, "RH": 81.5},...]

一切都按预期工作,但速度非常慢。检查请求时间,连接花费 65 毫秒,等待花费 59.29 秒,接收花费 15 毫秒。如果我只 return 一行,则等待时间减少到 30 秒。 运行 使用 \timing 在 PSQL 中本机查询,结果在 2 或 3 秒内 returned。 运行 来自 Django shell 的查询同样产生了一个快速查询。我的观点供参考:

def last_12_hours(request):
    JSONData = []
    time_frame = datetime.datetime.now() - datetime.timedelta(hours=12) #import datetime
    AtmosphericObjects = Atmospheric.objects.filter(time__gt=time_frame).order_by('-time').all()
    for row in AtmosphericObjects:
        JSONData.append({
            "T": (row.pk).strftime("%c"), 
            "C": (float(row.temperature)), 
            "RH": (float(row.humidity))
            })
        JSONDataSorted = sorted(JSONData, key=lambda x: datetime.datetime.strptime(x['T'], '%c'))
    return JsonResponse(JSONDataSorted, safe=False)

我将我的 apache 日志设置为调试并检查了 errors.log 文件。这是启动 apache 服务后的日志:

[Mon Aug 16 10:55:34.945928 2021] [wsgi:info] [pid 20498:tid 1996366352] mod_wsgi (pid=20498): Exiting process 'steve'.
[Mon Aug 16 12:55:35.243961 2021] [so:warn] [pid 20921:tid 1995743760] AH01574: module alias_module is already loaded, skipping
[Mon Aug 16 12:55:35.255553 2021] [watchdog:debug] [pid 20922:tid 1995743760] mod_watchdog.c(454): AH010033: Watchdog: Running with WatchdogInterval 1000ms
[Mon Aug 16 12:55:35.255676 2021] [watchdog:debug] [pid 20922:tid 1995743760] mod_watchdog.c(462): AH02974: Watchdog: found parent providers.
[Mon Aug 16 12:55:35.255706 2021] [watchdog:debug] [pid 20922:tid 1995743760] mod_watchdog.c(508): AH02977: Watchdog: found child providers.
[Mon Aug 16 12:55:35.255732 2021] [watchdog:debug] [pid 20922:tid 1995743760] mod_watchdog.c(516): AH02978: Watchdog: Looking for child (_singleton_).
[Mon Aug 16 12:55:35.255757 2021] [watchdog:debug] [pid 20922:tid 1995743760] mod_watchdog.c(516): AH02978: Watchdog: Looking for child (_default_).
[Mon Aug 16 12:55:35.257199 2021] [wsgi:debug] [pid 20922:tid 1995743760] src/server/mod_wsgi.c(8514): mod_wsgi (pid=20922): Socket for 'steve' is '/var/run/apache2/wsgi.20922.0.1.sock'.
[Mon Aug 16 12:55:35.257442 2021] [wsgi:debug] [pid 20922:tid 1995743760] src/server/mod_wsgi.c(8583): mod_wsgi (pid=20922): Listen backlog for socket '/var/run/apache2/wsgi.20922.0.1.sock' is '100'.
[Mon Aug 16 12:55:35.259660 2021] [wsgi:info] [pid 20923:tid 1995743760] mod_wsgi (pid=20923): Starting process 'steve' with uid=33, gid=33 and threads=15.
[Mon Aug 16 12:55:35.260946 2021] [wsgi:info] [pid 20923:tid 1995743760] mod_wsgi (pid=20923): Python home /home/pi/steve/env.
[Mon Aug 16 12:55:35.261248 2021] [wsgi:info] [pid 20923:tid 1995743760] mod_wsgi (pid=20923): Initializing Python.
[Mon Aug 16 12:55:35.264316 2021] [mpm_event:notice] [pid 20922:tid 1995743760] AH00489: Apache/2.4.38 (Raspbian) mod_wsgi/4.9.0 Python/3.7 configured -- resuming normal operations
[Mon Aug 16 12:55:35.264433 2021] [mpm_event:info] [pid 20922:tid 1995743760] AH00490: Server built: 2021-06-10T10:13:06
[Mon Aug 16 12:55:35.264482 2021] [core:notice] [pid 20922:tid 1995743760] AH00094: Command line: '/usr/sbin/apache2'
[Mon Aug 16 12:55:35.264509 2021] [core:debug] [pid 20922:tid 1995743760] log.c(1571): AH02639: Using SO_REUSEPORT: yes (1)
[Mon Aug 16 12:55:35.264649 2021] [watchdog:debug] [pid 20925:tid 1995743760] mod_watchdog.c(567): AH02980: Watchdog: nothing configured?
[Mon Aug 16 12:55:35.265684 2021] [wsgi:info] [pid 20925:tid 1995743760] mod_wsgi (pid=20925): Initializing Python.
[Mon Aug 16 12:55:35.265877 2021] [wsgi:info] [pid 20924:tid 1995743760] mod_wsgi (pid=20924): Starting process 'steve' with uid=33, gid=33 and threads=15.
[Mon Aug 16 12:55:35.266960 2021] [watchdog:debug] [pid 20926:tid 1995743760] mod_watchdog.c(567): AH02980: Watchdog: nothing configured?
[Mon Aug 16 12:55:35.267062 2021] [wsgi:info] [pid 20924:tid 1995743760] mod_wsgi (pid=20924): Python home /home/pi/steve/env.
[Mon Aug 16 12:55:35.267307 2021] [wsgi:info] [pid 20924:tid 1995743760] mod_wsgi (pid=20924): Initializing Python.
[Mon Aug 16 12:55:35.267315 2021] [wsgi:info] [pid 20926:tid 1995743760] mod_wsgi (pid=20926): Initializing Python.
[Mon Aug 16 12:55:35.398687 2021] [wsgi:info] [pid 20923:tid 1995743760] mod_wsgi (pid=20923): Attach interpreter ''.
[Mon Aug 16 12:55:35.398961 2021] [wsgi:info] [pid 20925:tid 1995743760] mod_wsgi (pid=20925): Attach interpreter ''.
[Mon Aug 16 12:55:35.398961 2021] [wsgi:info] [pid 20926:tid 1995743760] mod_wsgi (pid=20926): Attach interpreter ''.
[Mon Aug 16 12:55:35.399685 2021] [wsgi:info] [pid 20924:tid 1995743760] mod_wsgi (pid=20924): Attach interpreter ''.
[Mon Aug 16 12:55:35.451905 2021] [wsgi:info] [pid 20923:tid 1995743760] mod_wsgi (pid=20923): Adding '/home/pi/steve' to path.
[Mon Aug 16 12:55:35.454095 2021] [wsgi:info] [pid 20924:tid 1995743760] mod_wsgi (pid=20924): Adding '/home/pi/steve' to path.
[Mon Aug 16 12:55:35.461057 2021] [wsgi:info] [pid 20926:tid 1995743760] mod_wsgi (pid=20926): Imported 'mod_wsgi'.
[Mon Aug 16 12:55:35.461627 2021] [wsgi:info] [pid 20925:tid 1995743760] mod_wsgi (pid=20925): Imported 'mod_wsgi'.
[Mon Aug 16 12:55:35.462641 2021] [mpm_event:debug] [pid 20926:tid 1981359136] event.c(2314): AH02471: start_threads: Using epoll (wakeable)
[Mon Aug 16 12:55:35.463131 2021] [mpm_event:debug] [pid 20925:tid 1981359136] event.c(2314): AH02471: start_threads: Using epoll (wakeable)
[Mon Aug 16 12:55:35.464112 2021] [wsgi:info] [pid 20923:tid 1995743760] mod_wsgi (pid=20923): Imported 'mod_wsgi'.
[Mon Aug 16 12:55:35.466929 2021] [wsgi:debug] [pid 20923:tid 1872253984] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 11 in daemon process 'steve'.
[Mon Aug 16 12:55:35.466994 2021] [wsgi:debug] [pid 20923:tid 1964573728] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 0 in daemon process 'steve'.
[Mon Aug 16 12:55:35.467120 2021] [wsgi:debug] [pid 20923:tid 1956181024] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 1 in daemon process 'steve'.
[Mon Aug 16 12:55:35.467178 2021] [wsgi:debug] [pid 20923:tid 1947788320] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 2 in daemon process 'steve'.
[Mon Aug 16 12:55:35.467201 2021] [wsgi:debug] [pid 20923:tid 1863861280] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 12 in daemon process 'steve'.
[Mon Aug 16 12:55:35.467288 2021] [wsgi:debug] [pid 20923:tid 1855468576] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 13 in daemon process 'steve'.
[Mon Aug 16 12:55:35.467304 2021] [wsgi:debug] [pid 20923:tid 1939395616] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 3 in daemon process 'steve'.
[Mon Aug 16 12:55:35.467312 2021] [wsgi:debug] [pid 20923:tid 1922610208] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 5 in daemon process 'steve'.
[Mon Aug 16 12:55:35.467341 2021] [wsgi:debug] [pid 20923:tid 1847075872] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 14 in daemon process 'steve'.
[Mon Aug 16 12:55:35.467358 2021] [wsgi:debug] [pid 20923:tid 1931002912] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 4 in daemon process 'steve'.
[Mon Aug 16 12:55:35.467371 2021] [wsgi:debug] [pid 20923:tid 1914217504] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 6 in daemon process 'steve'.
[Mon Aug 16 12:55:35.467421 2021] [wsgi:debug] [pid 20923:tid 1905824800] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 7 in daemon process 'steve'.
[Mon Aug 16 12:55:35.467490 2021] [wsgi:debug] [pid 20923:tid 1897432096] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 8 in daemon process 'steve'.
[Mon Aug 16 12:55:35.467538 2021] [wsgi:debug] [pid 20923:tid 1889039392] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 9 in daemon process 'steve'.
[Mon Aug 16 12:55:35.467588 2021] [wsgi:debug] [pid 20923:tid 1880646688] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20923): Started thread 10 in daemon process 'steve'.
[Mon Aug 16 12:55:35.467645 2021] [wsgi:info] [pid 20924:tid 1995743760] mod_wsgi (pid=20924): Imported 'mod_wsgi'.
[Mon Aug 16 12:55:35.468245 2021] [wsgi:debug] [pid 20924:tid 1964573728] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20924): Started thread 0 in daemon process 'steve'.
[Mon Aug 16 12:55:35.468337 2021] [wsgi:debug] [pid 20924:tid 1956181024] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20924): Started thread 1 in daemon process 'steve'.
[Mon Aug 16 12:55:35.468400 2021] [wsgi:debug] [pid 20924:tid 1947788320] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20924): Started thread 2 in daemon process 'steve'.
[Mon Aug 16 12:55:35.468475 2021] [wsgi:debug] [pid 20924:tid 1939395616] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20924): Started thread 3 in daemon process 'steve'.
[Mon Aug 16 12:55:35.468564 2021] [wsgi:debug] [pid 20924:tid 1931002912] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20924): Started thread 4 in daemon process 'steve'.
[Mon Aug 16 12:55:35.468647 2021] [wsgi:debug] [pid 20924:tid 1922610208] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20924): Started thread 5 in daemon process 'steve'.
[Mon Aug 16 12:55:35.468722 2021] [wsgi:debug] [pid 20924:tid 1914217504] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20924): Started thread 6 in daemon process 'steve'.
[Mon Aug 16 12:55:35.468798 2021] [wsgi:debug] [pid 20924:tid 1905824800] src/server/mod_wsgi.c(9145): mod_wsgi (pid=20924): Started thread 7 in daemon process 'steve'.

我注意到 'mod_wsgi' 被导入了很多次。生成的进程数对我的应用程序来说似乎不合理,但当我省略 threads=2 processes=15.

时,一切都 运行 一样慢

在我请求页面后检查 error.log 我得到的这一行看起来很正常:

[Mon Aug 16 12:59:55.425775 2021] [wsgi:info] [pid 20923:tid 1872253984] [remote 10.0.0.10:50953] mod_wsgi (pid=20923, process='steve', application=''): Loading Python script file '/home/pi/steve/steve/steve/wsgi.py'.

如果我在这样的请求期间检查 htop,apache 会使用 100% 的 CPU 核心来计算数据在浏览器中显示的时间。

这可能只是硬件的结果吗?我该从哪里开始?每个答案都建议守护进程模式,我正在使用它,但嵌入式或守护进程都需要很长时间,无论如何,我不相信这个问题实际上与 Django 无关,因为 Django 服务器也需要一百万年:

[16/Aug/2021 11:08:27] "GET /last_12_hours HTTP/1.1" 200 45124

有什么建议吗?

已解决!解决方案:

Django 之所以耗时如此之久,很大程度上是因为 sorted 函数。

我实现这个是因为我的查询结果:

AtmosphericObjects = Atmospheric.objects.filter(time__gt=time_frame).order_by('-time').all()
尽管有 .order_by('-time')

还是乱序了,这本身很简单,只需删除 .all()

所以问题归结为:

  1. 在 Pi 上 运行 的排序函数。
  2. 我没有正确理解 Django 模型和查询集。
  3. 不必要地做同样的事情两次(按时间排序)。