php - 几秒钟的延迟 apache 响应

Question

自从新的centos 7服务器以来，我就遇到了这个问题，大约一个月我在谷歌上搜索它没有运气。

我的问题是 apache 在执行 php 脚本后延迟大约 4 秒发送响应。

我使用 xdebug 来查看任何长脚本/函数有延迟但没有。

下面的例子是我的 xdebug 跟踪文件。

TRACE START [2019-06-10 08:58:27]
0.0080     295160     -> define('ENVIRONMENT', 'testing') /var/www/html/index.php:64
0.0097     295160      >=> TRUE
0.0097     295160     -> define('HAVE_EMAIL', FALSE) /var/www/html/index.php:68
0.0097     295160      >=> TRUE
0.0098     295160     -> ini_set('display_errors', 0) /var/www/html/index.php:86
0.0098     295576      >=> '1'
.
.
.
1.1370    7960056         -> log_message($level = 'debug', $message = 'Total execution time: 1.1056') /var/www/html/system/core/Output.php:532
1.1370    7960104           -> write_log($level = 'debug', $msg = 'Total execution time: 1.1056') /var/www/html/system/Common.php:478
1.1370    7960152             -> strtoupper('debug') /var/www/html/system/core/Log.php:168
1.1370    7960184              >=> 'DEBUG'
1.1370    7960152            >=> FALSE
1.1370    7960104          >=> NULL
1.1370    7959800        >=> NULL
1.1370    7959800       -> Hooks->call_hook($which = 'post_system') /var/www/html/system/core.php:543
1.1370    7959848        >=> FALSE
1.1370    7959752      >=> 1
1.1371    7901032     -> xdebug_stop_trace() /var/www/html/index.php:298
1.1371    7901080
TRACE END   [2019-06-10 08:58:28]

从上面的跟踪我们可以看到脚本从 0.0080 秒开始，在 1.1371 秒完成。完成脚本大约需要 1.1 秒。

但在我的 apache 访问文件日志中被捕获:

[06/11/2019:10:32:13 +0800] XXX.XXX.XXX.XXX XXX.XXX.XXX.XXX TLSv1.2 DHE-RSA-AES256-GCM-SHA384 "GET report/stat/sh1 HTTP/1.1" 16972 -ms- 5298889

并且显然 apache 在 5298889 毫秒(5.298 秒)后发送响应。

其中 5.2 减去 1.1 = 4.1 秒，我需要找出这额外的 4++ 秒发生了什么。

这里有一些 Firebug 裁剪图像瀑布时间线也显示了 5.3 秒的总时间。



PHP:版本 5.6，
Apache :2.4.6，
操作系统:Centos 7，
防火墙:禁用，
SElinux:禁用

Apache 错误日志:没有运气和/var/log/message:没有运气

有人知道发生了什么吗？任何帮助将不胜感激。

谢谢。

编辑:

另一个发现，我尝试打开和关闭浏览器。浏览器打开后的第一个请求很快，然后一直持续 5 秒。 :(

<here im close and open again browser>

[06/11/2019:15:00:15 +0800] xxx.xxx.xxx.xxx xxx.xxx.xxx.xxx TLSv1.2 DHE-RSA-AES256-GCM-SHA384 "GET report/stat/sh1 HTTP/1.1" 12218 -ms- 449531
[06/11/2019:15:00:44 +0800] xxx.xxx.xxx.xxx xxx.xxx.xxx.xxx TLSv1.2 DHE-RSA-AES256-GCM-SHA384 "GET report/stat/sh1 HTTP/1.1" 12218 -ms- 5261276
[06/11/2019:15:12:27 +0800] xxx.xxx.xxx.xxx xxx.xxx.xxx.xxx TLSv1.2 DHE-RSA-AES256-GCM-SHA384 "GET report/stat/sh1 HTTP/1.1" 12218 -ms- 5210857
[06/11/2019:15:20:33 +0800] xxx.xxx.xxx.xxx xxx.xxx.xxx.xxx TLSv1.2 DHE-RSA-AES256-GCM-SHA384 "GET report/stat/sh1 HTTP/1.1" 12218 -ms- 5324744
[06/11/2019:15:22:23 +0800] xxx.xxx.xxx.xxx xxx.xxx.xxx.xxx TLSv1.2 DHE-RSA-AES256-GCM-SHA384 "GET report/stat/sh1 HTTP/1.1" 12218 -ms- 5193830
[06/11/2019:15:24:15 +0800] xxx.xxx.xxx.xxx xxx.xxx.xxx.xxx TLSv1.2 DHE-RSA-AES256-GCM-SHA384 "GET report/stat/sh1 HTTP/1.1" 12218 -ms- 5298699
[06/11/2019:15:31:05 +0800] xxx.xxx.xxx.xxx xxx.xxx.xxx.xxx TLSv1.2 DHE-RSA-AES256-GCM-SHA384 "GET report/stat/sh1 HTTP/1.1" 12218 -ms- 5484622



<here im close and open again browser>

[06/11/2019:15:31:35 +0800] xxx.xxx.xxx.xxx xxx.xxx.xxx.xxx TLSv1.2 DHE-RSA-AES256-GCM-SHA384 "GET report/stat/sh1 HTTP/1.1" 12218 -ms- 333542
[06/11/2019:15:31:56 +0800] xxx.xxx.xxx.xxx xxx.xxx.xxx.xxx TLSv1.2 DHE-RSA-AES256-GCM-SHA384 "GET report/stat/sh1 HTTP/1.1" 12218 -ms- 5195283
[06/11/2019:15:32:03 +0800] xxx.xxx.xxx.xxx xxx.xxx.xxx.xxx TLSv1.2 DHE-RSA-AES256-GCM-SHA384 "GET report/stat/sh1 HTTP/1.1" 12218 -ms- 5275482
[06/11/2019:15:32:11 +0800] xxx.xxx.xxx.xxx xxx.xxx.xxx.xxx TLSv1.2 DHE-RSA-AES256-GCM-SHA384 "GET report/stat/sh1 HTTP/1.1" 12218 -ms- 5664277
[06/11/2019:15:33:47 +0800] xxx.xxx.xxx.xxx xxx.xxx.xxx.xxx TLSv1.2 DHE-RSA-AES256-GCM-SHA384 "GET report/stat/sh1 HTTP/1.1" 16269 -ms- 5224315

Answer 1

经过几天的努力发现，现在显然我的 memcached 触摸功能花费了额外的时间。当 xdebug 从未捕获延迟并且现在我正在努力修复它时，这很痛苦。无论如何，感谢所有愿意提供帮助的人。