使用NGINX和NGINX Plus进行应用追踪

Liam Crilly产品管理高级总监

使用变量进行应用性能管理

变量是NGINX配置中一个重要但有时会被忽视的方面。NGINX提供约150个变量，可用于增强配置的各个部分。本篇博文将介绍如何使用NGINX变量进行应用跟踪和应用性能管理（APM），重点说明如何发现应用中的性能瓶颈。本文同时适用于NGINX Open Source和NGINX Plus。为简洁起见，除非两个版本之间存在差异，否则下文均使用NGINX Plus这一名称。

应用交付环境

在示例应用交付环境中，NGINX Plus充当应用的反向代理。该应用由一个Web前端及其后端的多个微服务组成。

端到端跟踪请求

NGINX Plus R10（以及NGINX 1.11.0）引入了$request_id变量。该变量是由32个十六进制字符组成的随机字符串，会在每个HTTP请求到达时自动分配给该请求（例如444535f9378a3dfa1b8604bc9e05a303）。这一看似简单的机制提供了一种强大的跟踪和故障排除工具。通过配置NGINX Plus和所有后端服务来传递$request_id值，可以对每个请求进行端到端跟踪。以下示例配置适用于前端NGINX Plus服务器。

upstream app_server {    server 10.0.0.1:80;
}

server {
    listen 80;
    add_header X-Request-ID $request_id; # Return to client
    location / {
        proxy_pass http://app_server;
        proxy_set_header X-Request-ID $request_id; # Pass to app server
    }
}

要配置NGINX Plus进行请求跟踪，首先需要在upstream块中定义应用服务器的网络位置。为简化说明，此处仅显示一台应用server，但通常会使用多台，以实现高可用性和负载均衡。

应用程序的“server”块定义了NGINX Plus处理传入HTTP请求的方式。“listen”指令让NGINX Plus侦听端口80，这是HTTP流量的默认端口，但生产环境配置通常会使用SSL/TLS保护传输中的数据。

The add_header指令在响应中将$request_id值作为自定义标头返回给客户端。这有助于测试，也适用于会自行生成日志的客户端应用（如移动应用），以便将客户端错误与服务器日志精确匹配。

最后，location块适用于整个应用空间（/），proxy_pass指令仅将所有请求代理到应用服务器。proxy_set_header指令通过添加一个传递给应用的HTTP标头来修改代理请求。在本例中，我们创建一个名为X-Request-ID的新标头，并将$request_id变量的值赋给该标头。因此，应用会收到由NGINX Plus生成的请求ID。

记录$request_id的端到端日志

应用跟踪是应用性能管理的一部分，旨在识别请求处理生命周期中的性能瓶颈。为此，我们会记录处理过程中的重要事件，以便后续分析是否存在意外或不合理的延迟。

配置NGINX Plus

首先配置前端NGINX Plus服务器，使其在自定义日志格式$request_id中包含trace。该格式用于access_trace.log文件。

log_format trace '$remote_addr - $remote_user [$time_local] "$request" '                 '$status $body_bytes_sent "$http_referer" "$http_user_agent" '
                 '"$http_x_forwarded_for" $request_id';

upstream app_server {
    server 10.0.0.1;
}

server {
    listen 80;
    add_header X-Request-ID $request_id; # Return to client
    location / {
        proxy_pass http://app_server;
        proxy_set_header X-Request-ID $request_id;        # Pass to app server
        access_log /var/log/nginx/access_trace.log trace; # Log $request_id
    }
}

配置后端应用程序

将请求ID传递给应用固然有用，但只有应用对其进行处理，才能真正帮助实现应用追踪。本例使用一个由uWSGI管理的Python应用。接下来修改应用入口点，将请求ID获取为日志变量。

from uwsgi import set_logvar
def main(environ, start_response):
    set_logvar('requestid', environ['X_REQUEST_ID'])

然后，我们可以修改uWSGI配置，使标准日志文件中包含请求ID。

log-format = %(addr) - %(user) [%(ltime)] "%(method) %(uri) %(proto)" %(status) %(size) "%(referer)" "%(uagent)" %(requestid)

完成此配置后，生成的日志文件便可跨多个系统关联到同一个请求。

NGINX 日志条目：

172.17.0.1 - - [02/Aug/2016:14:26:50 +0000] "GET / HTTP/1.1" 200 90 "-" "-" "-" 5f222ae5938482c32a822dbf15e19f0f

应用程序日志条目：

192.168.91.1 - - [02/Aug/2016:14:26:50 +0000] "GET / HTTP/1.0" 200 123 "-" "-" 5f222ae5938482c32a822dbf15e19f0f

通过根据请求ID字段匹配事务，借助Splunk和Kibana等工具，可以识别应用服务器中的性能瓶颈。例如，可以搜索耗时超过2秒的请求。不过，常规时间戳默认采用1秒的时间分辨率，无法满足大多数实际分析需求。

高精度计时

为了准确测量请求的端到端耗时，需要使用精确到毫秒的时间戳。在日志条目中加入$msec变量后，每个条目的时间戳都能达到毫秒级分辨率。通过在应用日志中添加毫秒级时间戳，可以查找耗时超过200毫秒而非2秒的请求。

但即便如此，我们仍无法了解全貌，因为NGINX Plus仅在每个请求处理结束时写入$msec时间戳。所幸，NGINX Plus还提供了其他几个精确到毫秒的计时变量，可帮助我们更深入地了解处理过程：

• $request_time：完整请求时间，从NGINX Plus读取客户端发送的第一个字节开始，到NGINX Plus发送完响应正文的最后一个字节为止
• $upstream_connect_time：与上游服务器建立连接所用的时间
• $upstream_header_time：从与上游服务器建立连接到收到响应标头的第一个字节所用的时间
• $upstream_response_time：从与上游服务器建立连接到接收响应正文最后一个字节所用的时间

有关这些计时变量的详细信息，请参阅《使用NGINX日志监控应用性能》。

扩展log_format指令，将所有这些高精度计时变量纳入trace日志格式。

log_format trace '$remote_addr - $remote_user [$time_local] "$request" $status '                 '$body_bytes_sent "$http_referer" "$http_user_agent" '
                 '"$http_x_forwarded_for" $request_id $msec $request_time '
                 '$upstream_connect_time $upstream_header_time $upstream_response_time';

使用常用的日志分析工具，可以提取变量值并执行以下计算，从而了解NGINX Plus在连接应用服务器之前处理请求所用的时间：

NGINX Plus processing time = $request_time - $upstream_connect_time - $upstream_response_time

还可以搜索$upstream_response_time的最高值，查看这些值是否与特定URI或上游服务器相关。然后，可以进一步将其与具有相同请求ID的应用日志条目进行核对。

结论

利用新的“$request_id”变量以及部分或全部毫秒级精度变量，可以深入了解应用中的性能瓶颈，从而改进应用性能管理，而无需借助重量级代理和插件。

亲自体验NGINX Plus应用跟踪：立即开始30天免费试用，或联系我们，讨论您的用例。

关于作者

Liam Crilly产品管理高级总监

Liam Crilly 的更多博客文章