nginx可通过$upstream_response_time实现毫秒级上游延迟定位,其默认三位小数格式(如"0.123")即等价于123毫秒;配合json格式log_format及grep/jq/awk等工具可快速筛选、排序、关联慢请求。

要利用 log_format 结合 $upstream_response_time 实现毫秒级请求延迟定位,核心是让 Nginx 日志精确记录上游服务响应耗时,并配合可解析的格式快速筛选慢请求。关键不在“加一个变量”,而在于日志结构是否支持按毫秒粒度过滤、关联和归因。
确保 $upstream_response_time 输出毫秒精度
Nginx 默认的 $upstream_response_time 是以秒为单位、保留三位小数的浮点字符串(如 "0.123"),本质已是毫秒级精度(0.123 秒 = 123 毫秒)。但需注意:
– 它只记录成功转发后收到上游响应的时间,不包含 DNS 解析、连接建立、SSL 握手等前置耗时;
– 若有多个 upstream server(如负载均衡),该变量会以逗号分隔多个值(如 "0.012, 0.045, 0.008"),表示每次重试的耗时。
建议在 log_format 中统一用 $upstream_response_time,不手动乘 1000 或格式化——保持原始字符串最利于后续日志分析工具(如 ELK、Grafana Loki)做数值解析。
定义可分析的 log_format 格式
避免使用空格或歧义分隔符。推荐用 JSON 或固定分隔符(如 |),并显式标注字段名:
log_format upstream_detail
'{'
'"time_local":"$time_local",'
'"remote_addr":"$remote_addr",'
'"request":"$request",'
'"status":"$status",'
'"upstream_addr":"$upstream_addr",'
'"upstream_response_time":"$upstream_response_time",'
'"request_time":"$request_time",'
'"upstream_status":"$upstream_status"'
'}';
这样每行日志都是合法 JSON,可直接被 Filebeat、Fluentd 或 jq 解析。特别注意:
– $request_time 是整个请求生命周期(含 Nginx 处理、网络等待、上游响应),与 $upstream_response_time 对比可判断瓶颈是否在 upstream;
– $upstream_status 可确认是否发生重试(如出现 "502,200" 表示第一次失败、第二次成功)。
定位慢请求的实操方法
无需写脚本,用标准 Linux 工具即可快速下钻:
- 查单次响应 > 500ms 的请求:
grep '"upstream_response_time":"[0-9]+.[5-9][0-9][0-9]"' access.log - 查存在重试的请求(多值):
grep -E '"upstream_response_time":"[^"]+,[^"]+"' access.log - 提取耗时并排序(用 jq):
jq -r '.upstream_response_time | select(test("^[0-9]+\.[0-9]{3}$")) | tonumber' access.log | sort -nr | head -20 - 关联 upstream_addr 和耗时,看哪个后端节点延迟高:
awk -F'"' '/upstream_response_time/ {split($10,a,","); for(i in a) if(a[i]+0 > 0.3) print $6 " → " a[i]}' access.log | sort | uniq -c | sort -nr
补充:识别非 upstream 类延迟
如果 $request_time 显著大于 $upstream_response_time(例如 request_time=1.8s,upstream_response_time=0.012s),说明延迟来自:
– 客户端上传慢(大 Body + 弱网);
– Nginx 自身处理慢(如 rewrite 过多、Lua 脚本阻塞、limit_req 触发排队);
– upstream 连接建立慢(DNS 解析卡顿、TCP SYN 重传、SSL handshake 耗时高——这些 Nginx 不记录,需结合 tcpdump 或 $upstream_connect_time 分析)。
此时应开启 $upstream_connect_time 和 $upstream_header_time,它们同样支持毫秒精度,可进一步拆解 upstream 阶段耗时。











