☰

Apache 加载时间（以微秒为单位）-标头和日志之间的差异

tag-icon • tag-icon apache-2.2 web-server performance-monitoring
Apache 加载时间（以微秒为单位）-标头和日志之间的差异

我最近关注本指南获取 Web 服务器上站点负载的性能测量结果。

要记录 Apache 处理请求所需的时间，请将其添加到您的 Apache 配置文件中：

LogFormat "%h %D %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" combined

%D 表示您将在访问日志中看到 Apache 处理请求所用的时间。该时间以微秒为单位。

为了更轻松地调试页面加载时间，请将其添加到您的配置文件中：

Header set X-Request-Received: %t
Header set X-Request-Processing-Time: %D

请记住先通过执行 a2enmod headers 启用 mod_headers。现在您应该在响应中看到这些标头：

X-Request-Received t=1286995673038485
X-Request-Processing-Time D=251

我使用了上述代码（在 .htaccess 中定义了标头），但对于同一请求，日志中出现了“525151”，而标头中出现了“262”。总体而言，这两个数字之间似乎存在数量级的差异

192.0.2.1 525151 - - [21/Aug/2011:14:19:53 +0200] "GET /images/site/slide-1.png HTTP/1.1" 262 423285 "http://example.com/" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/535.1 (KHTML, like Gecko) Chrome/13.0.782.112 Safari/535.1"

对阵

X-Request-Processing-Time:D=262
X-Request-Received:t=1313929193502879

我怎样才能解决这个问题？

答案1

您能否验证您的 LogFormat 名称“组合”是否与您的 CustomLog 变量所使用的名称匹配。我在 OS X 上对此进行了测试，除了在写回标题时读取变量与在记录时（将所有数据发送回客户端后）读取变量之间可能存在的细微差异外，它们非常接近：

/etc/apache2# grep LogF httpd.conf
    LogFormat "%h %l %u %t \"%r\" %>s %b %t %D" common

/etc/apache2# grep CustomL httpd.conf
    # a CustomLog directive (see below).
    CustomLog "/private/var/log/apache2/access_log" common


# wget -qqO /dev/null -S http://localhost/
...
  X-Request-Received: t=1314588821970347
  X-Request-Processing-Time: D=336

/private/var/log/apache2# tail access_log 
::1 - - [28/Aug/2011:20:33:41 -0700] "GET / HTTP/1.0" 200 44 [28/Aug/2011:20:33:41 -0700] 587

答案2

我认为最好的选择可能是为自定义 LogFormat 选择一个“合适”的名称，而不是重复使用/更改combined日志格式。

除此之外（正如@polynomial 所建议的），似乎您显示的配置与您显示的输出之间存在差距。

如果只是为了使故障排除不那么模棱两可（目前，您不知道是否正在使用默认值combined（ ）或您的版本）。LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-agent}i\"" combined

所以我首先会做类似的事情：

LogFormat "%h %D %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-Agent}i\"" perf-combined

然后在需要的地方使用 perf-combined。

通过查看@polynomial 示例中 Header %D 和 AccessLog %D 值之间的相当大的差异，我还想知道这两者是否实际上代表了请求处理中的两个不同点：

  • 由于本页所有示例中 %D 的标头值都较低，因此它可能显示了形成响应标头所花费的时间，但不一定是响应主体
  • AccessLog 的 %D 值可能是发送完整响应的时间。

但这完全只是猜测。

答案3

[这是一个非常老的问题，但值得为到达这里的其他人提供更好的答案]

HTTP 标头必须在内容交付给最终用户之前生成，因此它不包括网络延迟。另一方面，access_log 条目是在所有内容交付给最终用户之后写入的（可能通过较慢的网络链接），它包括交付所花费的时间。

哪个数字对你更有用取决于你想找出什么。对于你的图片 URL，你可能正在查看最终用户的性能，而网络延迟可能是主要答案。

如果您正在调试动态生成内容的性能，您可能希望记录不包括网络延迟的时间。LogFormat 将允许您记录标头的内容%{X-Request-Processing-Time}i- 还没有尝试过，但我希望它会起作用。

相关内容