访问日志在性能问题分析中的重要性

时间：2022-01-04 作者：电脑狂魔

访问日志由 Web 服务器生成，用于记录有关它已处理的请求的详细信息。它记录有关请求的状态代码、响应时间、URL、协议、大小、客户端 IP 地址等。负载均衡器将创建类似的日志文件来记录请求详细信息。在进行任何性能分析时，这些日志起着重要作用。由于缺乏意识，它在大多数时候被忽视，并且 APM 工具的使用通过允许他们在视觉上专注于粗粒度数据而不是细粒度数据，从而将其从用户那里抽象出来。大多数人都知道应用程序服务器日志，但他们中的许多人不知道 Web 服务器/负载平衡器访问日志。大多数情况下，此日志不会在调查问题的人的脑海中引起轰动。

访问日志可用于以下服务器，但每个服务器的格式各不相同：

Apache、Nginx等Web服务器，
负载均衡器，例如 AWS ELB、AWS ALB 等，
API网关如AWS API Gateway、APIGEE等，
网关和代理服务器

在本博客中，我将介绍 apache 和 AWS ELB 的访问日志格式以及使用访问日志确定的实际性能问题。除此之外，我还列出了一些可以使用访问日志调查的问题。

Apache 访问日志格式

以下是取自 apache 访问日志的示例条目：

域名.227 - 测试 [22/Sep/2015:08:46:01 +0400] "GET /test HTTP/1.1" 404 288 "-" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/域名 (KHTML, like Gecko ) Chrome/域名.99 Safari/域名"

域名.227 - 向 Web 服务器发出请求的 IP 地址
test - 它是从 Web 服务器请求信息的用户的用户名
[22/Sep/2015:08:46:01 +0400] - 收到请求时的时间戳
"GET /test HTTP/1.1" – 'GET' 是用于请求对象的 HTTP 方法。'/test' 是请求的资源。'HTTP/1.1' 是使用的协议。
404 - 这是返回给客户端的响应代码
288 - 它是服务器返回的对象/资源的大小
"-" - 它是引用 URL，在此请求中不存在
"Mozilla/5.0 (Windows NT 6.1) AppleWebKit/域名 (KHTML, like Gecko) Chrome/域名.99 Safari/域名" - 它是发出请求的浏览器代理

ELB 日志访问格式

这是从 ELB 日志中提取的示例：

2019-11-30T15:00:域名41Z www-test-com 域名.213:46765 域名.245:80 域名64 域名6 域名4" https://域名/域名.213:46765. "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/域名 (KHTML, like Gecko) Chrome/域名.108 Safari/域名" ECDHE-RSA-AES128-GCM-SHA256 TLSv1.2

2019-11-30T15:00:域名41Z - 负载均衡器生成对客户端的响应的时间戳
www-test-com - 使用的 ELB 的资源 ID
域名.213:46765 - 客户端的 IP 地址和端口
域名.245:80 - 处理请求的目标服务器的 IP 地址和端口
域名64 - 它是从负载均衡器收到请求到将请求发送到目标服务器所经过的时间
域名6 – 从负载均衡器向目标服务器发送请求到目标服务器开始发送响应头所经过的时间
域名47 - 从负载均衡器收到来自目标服务器的响应到开始向客户端发送响应所用的时间
200 - 负载均衡器发送的响应代码
200 - 从目标服务器收到的响应代码
0 - 从客户端接收的字节大小
557178 - 作为响应发送给客户端的字节大小
"GET https://域名:443/ HTTP/1.1" – 包含请求中使用的 HTTP 方法、URL 和协议
“Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/域名 (KHTML, like Gecko) Chrome/域名.108 Safari/域名”——它包含调用请求的用户代理细节
ECDHE-RSA-AES128-GCM-SHA256 - 这是此请求中使用的 SSL 密码套件
TLSv1.2 - 它是使用的 SSL 协议版本

访问日志分析

在多层应用程序中，大多数层的入口点将是 Web 服务器或负载平衡器。因此，分析这些日志文件以检查请求是否到达服务器非常重要。如果没有条目，那么它清楚地表明请求还没有从上一层到达当前层。在这种情况下，它可能是网络通信问题或超时问题或前一层中的任何其他问题。

在其中一起生产事件中，确定 CDN 服务器返回 503 错误，即使它被配置为在收到来自下游的此类错误时服务器过时的内容。CDN 供应商报告说他们从 AWS ELB 层收到响应代码为 0。因此，他们向最终用户返回了 503 错误代码。在分析 ELB 日志时，发现没有以 0 作为状态代码返回的响应。由于当时应用程序上的流量很大，因此负载平衡器本身的请求会超时，而无需等待来自目标服务器的响应。但这与零响应代码无关，因为 ELB 返回 504 作为状态代码。以下是显示在 ELB 访问日志中出现问题期间所做的条目的行：

2019-12-11T12:58:域名81Z www-test-com 域名.207:37280 - -1 -1 -1 504 0 0 0 "GET https://域名:443/HTTP/1.1" " Apache-HttpClient/2.5.5 (Java/域名2)" ECDHE-RSA-AES128-GCM-SHA256 TLSv1.2

在上面的行中，

ELB 返回状态码 504
-1 在 elapsed time 相关字段中观察到，因为 ELB 在配置的超时时间内没有收到任何响应
0 表示来自目标的响应代码以及 0 字节的响应，因为没有从目标收到响应

后来发现CDN到AWS ELB层之间存在一些网络问题，导致0响应代码返回到CDN服务器。这种分析只有在我们分析访问日志时才有可能。任何 APM 工具都无法做到这一点，因为它可能无法以直接的方式将数据显示到这种粒度级别。

其他问题的调查

使用访问日志可以诊断的问题：

HTTP 状态代码 404 表示在服务器中找不到请求的对象/资源。可以通过将资源放在网络服务器中或从网页中删除对网络资源的引用来分析和修复。这有助于节省对服务器进行的不必要的往返。
从目标服务器收到HTTP 状态代码 500、502、503 和 504，可以进一步调查问题。504 是由于目标服务器响应时间过长造成的，如果超过配置的超时时间，负载均衡器将返回此错误代码。
用户代理字符串有助于分析发出请求的设备/浏览器的类型。Bot 攻击可以使用用户代理和 IP 地址字段来识别，这些字段将重复相同的值集。任何真实用户都不可能以该频率访问服务器。
SSL 密码和 SSL 协议版本可用于分析 SSL 连接是否存在任何问题。