LabHub
学习 学习路径 课程

nginx 故障处理

同样是 504,触发的超时却不一样

在 LabHub 中继续学习

一句话总结

502 与 504 是症状的名称,真正的元凶已经写在 error.log 的一行中。从不读那一行而开始猜测的瞬间起,时间就开始流失。

概念图: 症状的名称 · 确信了错误原因 · 亲手制造故障 · ① upstream 根本没有启动 → 502

为什么需要它

故障响应中最昂贵的错误,不是找不到原因,而是确信了错误原因

典型的一天这样过去:监控出现 502,大家猜“后端大概死了”,于是重启 WAS,没有恢复;接着猜“可能只是慢”,把 proxy_read_timeout 提高到 30 秒,仍没有恢复;再猜“服务器不够”,增加实例,还是无效。三小时过去了,而 error.log 从第一分钟起就握着答案。

因此,本课程不是从阅读日志开始,而是先亲手制造故障。手工创建关闭的端口、不接受连接的端口、缓慢响应、超过缓冲区的巨大请求头,亲眼观察 nginx 如何记录。见过一次的文字,下次在生产中 0.5 秒就能识别。

四种签名

下面四条日志均在实验镜像(nginx 1.24.0)中真实复现,并标出了哪一段指向元凶。

① upstream 根本没有启动 → 502

[error] connect() failed (111: Connection refused) while connecting to upstream,
  request: "GET /dead/ HTTP/1.1", upstream: "http://127.0.0.1:9999/"

connect() failed 表示 TCP 连接本身被拒绝。此时调大任何超时都不会改变结果。针对 502 提高超时毫无意义,这一行已经说明原因——根本没有等待,内核立即返回了 RST。

② upstream 已启动但响应慢 → 504

[error] upstream timed out (110: Connection timed out) while reading response
  header from upstream, request: "GET /app/slow?d=10 HTTP/1.1"

③ upstream 连连接都不接受 → 504

[error] upstream timed out (110: Connection timed out) while connecting to
  upstream, request: "GET /hang/ HTTP/1.1"

把②与③并排观察:状态码都是 504,括号内错误号同为 110,区别只有后半句。

短语 实际触发的设置
while connecting to upstream proxy_connect_timeout
while reading response header from upstream proxy_read_timeout
while sending request to upstream proxy_send_timeout

本课程的关键场景,就是展示不读这段短语会发生什么。实验第 5 步中,你会在对应位置加入 proxy_read_timeout 30s,声明愿意等待 30 秒,但请求仍在2 秒后返回 504,因为真正触发的是 proxy_connect_timeout 2s。你提高的并不是生效的那个超时。

这就是“提高了超时还是没有恢复”的真相。选择要调哪个值之前,必须先读日志短语。

④ 响应头超过代理缓冲区 → 502

[error] upstream sent too big header while reading response header from upstream,
  request: "GET /app/bighdr?n=8000 HTTP/1.1"

这是四种情况中最棘手的。服务器正常运行,健康检查一直为绿,你用 curl 请求甚至得到 200,却只有特定用户遇到 502。这个用户通常已通过 SSO 登录,拥有较大的 session cookie,或因权限列表很长而导致响应头膨胀。

proxy_buffer_size 默认值为 4k,整个响应头部必须放进这一个缓冲区。超过后,nginx 即使收到响应也无法处理,只能返回 502。规范中的 502 并不是“upstream 死亡”,而是“网关从 upstream 收到无效响应”,这个情况正符合定义。

还有一个陷阱:只把 proxy_buffer_size 提高到 16k,nginx 会直接无法启动。

[emerg] "proxy_busy_buffers_size" must be less than the size of all
  "proxy_buffers" minus one buffer

必须同时增大 proxy_buffers。凌晨第一次看到这条消息会不知所措,见过一次后就不再可怕。

用 access.log 两列完成第一次分流

如果 error.log 指向元凶,access.log 就决定下一步往哪个方向看。在日志格式中加入以下三个变量,是本课程成本最低的投资。

log_format ev '$time_local $status ut=$upstream_response_time '
              'rt=$request_time us=$upstream_status "$request"';

观察实测的三条日志。

504 ut=3.004 rt=3.004 us=504 "GET /app/slow?d=10 HTTP/1.1"
200 ut=0.049 rt=4.173 us=200 "GET /app/big?n=8000000 HTTP/1.1"
413 ut=-     rt=0.002 us=-   "POST /app/upload HTTP/1.1"

读懂 us=- 后,“我们的应用日志里没有该请求”就成为有依据的判断;不理解时,这句话只会被听成推卸责任。

在实际项目中

先踏上诊断阶梯的最后一级。 绕过代理,保留原始 Host 请求头,直接请求 upstream。

curl -sSI -H 'Host: api.example.com' http://127.0.0.1:8080/health

如果这里正常,问题位于代理与 upstream 之间,包括配置、请求头、缓冲区和超时;这里也失败,则代理无罪。一次请求就能把搜索空间缩小一半。若省略 -H 'Host: ...',在使用虚拟主机路由时可能请求到另一应用,比较也就失去意义。

收到只写症状的工单时,先询问状态码与日志短语。 “出现 502”几乎没有信息;“出现 502,日志中有 connect() failed (111: Connection refused)”则几乎已经是一份原因报告。这个习惯会直接改变团队的平均恢复时间。

下一实验要做什么

用 Python 制作故障发生器,亲手创建关闭端口、不响应端口、缓慢响应和巨大请求头。针对四种情况,把状态码、error.log 短语与实际触发的超时分别保存为证据文件。最后编写四行判定表与故障报告。