不是应用的错的失败 — 缓冲、正文大小、连接复用
目标
能够在 nginx 的缓冲区、正文大小和连接设置中,找出状态码为 200 但用户仍反映缓慢的故障原因。 并且能够用数字说明每项设置付出的代价。
为什么重要
仪表板会告诉你 5xx。真正会拖很久的是看起来没有任何人做错事的故障。
开发团队说“我们在 0.05 秒内就响应了”,
基础设施团队说“服务器很空闲”,但用户却等待了 7 秒。
三者都是真的,缺失的那一块就在 nginx 内部。
响应可能溢写到了磁盘,请求正文可能落入了临时文件,或者每个请求都在
建立新的 TCP 连接。这三种情况都不会体现在状态码中,
只会在一行 [warn] 级别的日志里留下痕迹。
因此,将 error_log 保持在 warn 级别,是观察到这类故障的
唯一方法。
步骤
- 保存并启动
/root/ngb/upstream.py,编写/root/ngb/nginx.conf, 然后启动 nginx。监听端口 8088,并将/app/代理到upstream app组(端口 9101)。将error_log以 warn 级别写入/root/ngb/logs/error.log,将访问日志写入/root/ngb/logs/access.log,且格式中必须包含$upstream_response_time、$request_time、$upstream_status。 暂时不要添加client_max_body_size。 检查:http://127.0.0.1:8088/app/必须返回 200。 (可以在浏览器预览中打开。) - 分别发送一次两种慢请求。
- 上游缓慢:
http://127.0.0.1:8088/app/slow?d=4 - 传输缓慢:请求
http://127.0.0.1:8088/app/big?n=8000000时 使用curl --limit-rate 1000k将两个请求对应的访问日志行保存到/root/ngb/attribute.log, 并创建/root/ngb/attribute.csv。第一行为case,upstream_time,request_time,verdict,后面接两行。case为slow-upstream和slow-transfer,verdict为upstream或transfer。
- 上游缓慢:
- 找出第 2 步的大响应在
error.log中留下的警告, 创建/root/ngb/case-spill.txt。共四行。level=<대괄호 안 수준> path=<로그에 적힌 임시 파일 경로 그대로> status=<같은 요청의 액세스 로그 상태 코드> tradeoff=<disk-spill 또는 upstream-held> - 添加
/nobuf/路径。仍代理到同一个upstream app, 但在该块中加入proxy_buffering off;。reload 后, 请求http://127.0.0.1:8088/nobuf/big?n=8000000时使用相同的--limit-rate 1000k, 并创建/root/ngb/case-nobuf.txt。共四行。upstream_time=<us 칸이 아니라 ut 칸 값 그대로> request_time=<rt 칸 값 그대로> warn=<none 또는 spilled> tradeoff=<disk-spill 또는 upstream-held> - 向
http://127.0.0.1:8088/app/toobigPOST 3MB 正文。 确认状态码、访问日志中的us列,以及该请求在/root/ngb/upstream.log中 留下了多少条记录,然后创建/root/ngb/case-413.txt。 共四行。
然后将该指令设置为status=<상태 코드> upstream_status=<액세스 로그 us 칸 값> app_saw=<업스트림 로그에 남은 건수> fix=<이 실패를 푸는 지시자 이름>10m并 reload, 使向http://127.0.0.1:8088/app/uploadPOST 相同的 3MB 正文时 返回 200。 - 向
http://127.0.0.1:8088/app/spillPOST 500KB 正文后,error.log中会再出现一条临时文件警告。 创建/root/ngb/case-bodyspill.txt。共三行。
然后将该指令设置为level=<대괄호 안 수준> path=<로그에 적힌 임시 파일 경로 그대로> fix=<본문을 메모리에 담는 크기를 정하는 지시자 이름>1m并 reload,再向http://127.0.0.1:8088/app/nospillPOST 相同的 500KB 正文, 确认这次没有出现警告。 - 实际测量连接复用。首先在当前状态下
调用
http://127.0.0.1:8088/app/10 次,并统计upstream.log中conn编号有多少种。然后在upstream app块中加入keepalive 16;,在/app/块中加入proxy_http_version 1.1;和proxy_set_header Connection "";,reload 后再次调用 10 次, 并以同样方式统计。创建/root/ngb/keepalive.txt。before=<설정 전 커넥션 수> after=<설정 뒤 커넥션 수> - 编写
/root/ngb/runbook.md。必须包含## 증상별 첫 확인、## 버퍼링、## 본문 크기、## 커넥션 재사용四个 h2 标题, 并且必须出现proxy_buffering、client_max_body_size、client_body_buffer_size、keepalive、upstream_response_time五个词, 还必须用数字引用第 2 步测得的两个时间值。
参考
- 启动:
nginx -c /root/ngb/nginx.conf -p /root/ngb - 重新应用:
nginx -s reload -c /root/ngb/nginx.conf -p /root/ngb - 慢客户端:
curl -s -o /dev/null --limit-rate 1000k <URL> - 发送大正文:
head -c 3000000 /dev/zero | curl -s --data-binary @- <URL> - 统计连接数:
awk '$3=="start"{print $2}' /root/ngb/upstream.log | sort -u | wc -l(之前的请求会混在其中,请用tail截取要统计的区段) - 常见错误 1:在第 1 步提前加入
client_max_body_size。 这样就无法看到第 5 步中的默认行为。 - 常见错误 2:连接复用的三个设置中遗漏
proxy_set_header Connection "";。 即使升级到 HTTP/1.1,每个请求仍会断开连接。 - 常见错误 3:混淆响应侧临时文件路径与请求正文侧临时文件路径。 它们是不同的目录。
搭建可测量的代理
保存并启动 /root/ngb/upstream.py,编写 /root/ngb/nginx.conf,
然后启动 nginx。监听端口 8088,并将 /app/ 代理到 upstream app
组(端口 9101)。将 error_log 以 warn 级别写入
/root/ngb/logs/error.log,将访问日志写入
/root/ngb/logs/access.log,且格式中必须包含 $upstream_response_time、
$request_time、$upstream_status。
暂时不要添加 client_max_body_size。
检查:http://127.0.0.1:8088/app/ 必须返回 200。
(可以在浏览器预览中打开。)
在 /root/ngb 下重新启动与第 1 篇相同的故障发生器。本实验的成败取决于访问日志格式——如果不同时记录上游耗时和总耗时,从第 2 步开始就什么也看不到。请将上游放入 upstream 块中。第 7 步会要求在该块中加入一个指令。
应用缓慢还是传输缓慢
分别发送一次两种慢请求。
- 上游缓慢:
http://127.0.0.1:8088/app/slow?d=4 - 传输缓慢:请求
http://127.0.0.1:8088/app/big?n=8000000时 使用curl --limit-rate 1000k将两个请求对应的访问日志行保存到/root/ngb/attribute.log, 并创建/root/ngb/attribute.csv。第一行为case,upstream_time,request_time,verdict,后面接两行。case为slow-upstream和slow-transfer,verdict为upstream或transfer。
分别制造一次两种缓慢——上游拖延 4 秒的请求,以及响应瞬间生成但客户端缓慢接收的请求。可以用 curl 的 --limit-rate 模拟慢客户端。单独保存两个请求的访问日志行,并比较 ut 与 rt。
溢写到磁盘的响应
找出第 2 步的大响应在 error.log 中留下的警告,
创建 /root/ngb/case-spill.txt。共四行。
level=<대괄호 안 수준>
path=<로그에 적힌 임시 파일 경로 그대로>
status=<같은 요청의 액세스 로그 상태 코드>
tradeoff=<disk-spill 또는 upstream-held>
查看第 2 步的大响应在 error.log 中留下了什么。级别不是 error,以及同一请求的访问日志状态码是什么,正是本步骤的要点。此故障绝不会体现在状态码中。
关闭缓冲后会发生什么变化
添加 /nobuf/ 路径。仍代理到同一个 upstream app,
但在该块中加入 proxy_buffering off;。reload 后,
请求 http://127.0.0.1:8088/nobuf/big?n=8000000 时使用相同的 --limit-rate 1000k,
并创建 /root/ngb/case-nobuf.txt。共四行。
upstream_time=<us 칸이 아니라 ut 칸 값 그대로>
request_time=<rt 칸 값 그대로>
warn=<none 또는 spilled>
tradeoff=<disk-spill 또는 upstream-held>
通过关闭缓冲的路径再次接收同一个 8MB 响应。临时文件警告会消失,但访问日志中两个数字的关系会反转。该反转意味着什么,就是本步骤的答案。
应用程序永远看不到的 413
向 http://127.0.0.1:8088/app/toobig POST 3MB 正文。
确认状态码、访问日志中的 us 列,以及该请求在 /root/ngb/upstream.log 中
留下了多少条记录,然后创建 /root/ngb/case-413.txt。
共四行。
status=<상태 코드>
upstream_status=<액세스 로그 us 칸 값>
app_saw=<업스트림 로그에 남은 건수>
fix=<이 실패를 푸는 지시자 이름>
然后将该指令设置为 10m 并 reload,
使向 http://127.0.0.1:8088/app/upload POST 相同的 3MB 正文时
返回 200。
尝试上传 3MB 正文。比状态码更重要的是该请求是否到达了上游——可以在访问日志的上游状态码列和上游服务器自己的日志这两处确认。确认完成后,再修改设置使其通过。
请求正文也会溢写到磁盘
向 http://127.0.0.1:8088/app/spill POST 500KB 正文后,
error.log 中会再出现一条临时文件警告。
创建 /root/ngb/case-bodyspill.txt。共三行。
level=<대괄호 안 수준>
path=<로그에 적힌 임시 파일 경로 그대로>
fix=<본문을 메모리에 담는 크기를 정하는 지시자 이름>
然后将该指令设置为 1m 并 reload,再向
http://127.0.0.1:8088/app/nospill POST 相同的 500KB 正文,
确认这次没有出现警告。
上传小于 413 阈值、但大于内存缓冲区的正文后,会再出现一条警告。它会落入与响应侧临时文件不同的目录,请仔细查看路径。修复后,再向另一个路径上传一次,确认不再出现警告。
三行配置齐全才能复用连接
实际测量连接复用。首先在当前状态下
调用 http://127.0.0.1:8088/app/ 10 次,并统计 upstream.log 中
conn 编号有多少种。然后在 upstream app 块中加入
keepalive 16;,在 /app/ 块中加入 proxy_http_version 1.1; 和
proxy_set_header Connection "";,reload 后再次调用 10 次,
并以同样方式统计。创建 /root/ngb/keepalive.txt。
before=<설정 전 커넥션 수>
after=<설정 뒤 커넥션 수>
先在当前状态下发送 10 次,并统计上游看到的连接数量。然后将三项设置全部加入并再次统计,数字会明显变化。缺少任何一项都不会生效;如果数字没有变化,请检查三项中遗漏了哪一项。
运维决策指南
编写 /root/ngb/runbook.md。必须包含 ## 증상별 첫 확인、## 버퍼링、
## 본문 크기、## 커넥션 재사용 四个 h2 标题,
并且必须出现 proxy_buffering、client_max_body_size、client_body_buffer_size、
keepalive、upstream_response_time 五个词,
还必须用数字引用第 2 步测得的两个时间值。
只写每项设置的优点并不能构成文档。必须用前面步骤测得的数字写明获得了什么、牺牲了什么,六个月后其他人才敢调整这些值。