一、凌晨2点的告警:502和504轮番轰炸
2024年3月17日凌晨2点14分,告警电话把我从床上拽起来。客户反馈官网打不开,我打开监控后台,Nginx错误日志每隔几秒就刷一条:
[error] 21456#0: *98234 connect() failed (110: Connection timed out) while connecting to upstream
紧接着504也来了:
[error] 21458#0: *98241 upstream timed out (110: Connection timed out) while reading response header from upstream
我当时的操作和大多数人一样——重启PHP-FPM。确实恢复了,大概20分钟。但一个小时后,同样的告警再次劈过来。
这台服务器配置不算低:4核8G,跑了Nginx 1.24.0 + PHP 8.2.16(PHP-FPM),MySQL 8.0.35也在这台机器上。流量不算高,日常QPS在200左右。在重启—告警—再重启之间循环了三次之后,我决定不再糊弄,把这个问题从根上挖清楚。
二、502和504到底差在哪
先说结论,这两个错误在Nginx的语义里非常明确:
| 错误码 | Nginx的判定 | 本质 |
|---|---|---|
| 502 Bad Gateway | 连接FPM失败,或FPM进程崩溃/拒绝连接 | 连接没建立起来 |
| 504 Gateway Timeout | 连接建立了,但FPM在fastcgi_read_timeout内没返回任何响应头 | 响应太慢/卡死 |
一次请求从Nginx到FPM要经过三个环节:TCP三次握手 → 发送FastCGI请求 → 等待FPM响应头。502卡在握手和发请求阶段,504卡在等待响应阶段。定位方向完全不同。
但实际情况往往是502和504混着出现,就像我当时那样。这就说明问题不只是FPM本身,还牵扯到进程管理策略和系统层参数。
三、两种处理方案对比
我先把当晚试过的方案和结果列出来,给各位一个直观对比:
| 方案 | 操作 | 恢复时间 | 持续效果 | 代价 |
|---|---|---|---|---|
| 方案一:重启FPM | systemctl restart php8.2-fpm | 约3秒 | 20-60分钟后复发 | 用户请求中断,日志丢失 |
| 方案二:系统性排查 | 检查日志+FPM状态+strace+内核调优 | 约40分钟定位 | 根治,1个月零复发 | 需要专业排查思路 |
方案一适合线上救火,方案二才是彻底解法。这篇博客重点讲方案二的完整排查链路,每个环节的命令和判断依据都给到。
四、完整排查链路:从日志到内核
4.1 看日志,先判断拥堵方向
登录服务器第一步不是重启,是看Nginx错误日志,统计两种错误的分布:
# 统计最近1小时502/504出现次数
grep -c "connect() failed" /var/log/nginx/error.log --since="1 hour ago"
grep -c "upstream timed out" /var/log/nginx/error.log --since="1 hour ago"
# 如果502为主(连接失败),再看FPM的监听队列是不是满了
grep "listen.backlog" /etc/php/8.2/fpm/pool.d/www.conf
我当时统计的结果:502约2300次,504约400次。502占绝对大头,说明FPM的连接链路出了问题。
4.2 看PHP-FPM状态,确认进程是否卡死
PHP-FPM自带状态页,先开启它:
# 编辑 /etc/php/8.2/fpm/pool.d/www.conf
# 找到 ;pm.status_path = /status 这行,去掉注释
pm.status_path = /status
# 在Nginx配置中加上location规则
# /etc/nginx/sites-available/default 中加入:
location ~ ^/status$ {
include fastcgi_params;
fastcgi_pass unix:/run/php/php8.2-fpm.sock;
fastcgi_param SCRIPT_FILENAME $document_root$fastcgi_script_name;
# 状态页只允许本机访问,防外部探测
allow 127.0.0.1;
deny all;
}
# 重载Nginx后,用curl查看状态
curl http://127.0.0.1/status?full
# 关键指标输出示例(节选)
# pool: www
# process manager: dynamic
# start time: 17/Mar/2024:01:58:22 +0800
# accepted conn: 183421
# listen queue: 0
# max listen queue: 1250
# listen queue len: 2048
# idle processes: 0
# active processes: 5
# total processes: 5
# max active processes: 5
# max children reached: 5
注意几个关键数字:
- listen queue: 0——当前没有排队,但这是在刚重启后抓的
- max listen queue: 1250——高峰期排队堆积过1250个请求
- max children reached: 5——孩子进程全部被占满过
- idle processes: 0——一个空闲进程都没有
这套配置里 pm.max_children=5,意味着FPM最多只能同时处理5个请求。4核8G的机器配5个子进程?明显保守了。
4.3 复现环境:用压测复现故障现场
任何故障排查都需要复现环境。我在测试环境用docker-compose复刻了线上的配置,故意把进程数调小:
version: '3.8'
services:
nginx:
image: nginx:1.24.0
ports:
- "8080:80"
volumes:
- ./nginx/default.conf:/etc/nginx/conf.d/default.conf
- ./html:/var/www/html
depends_on:
- php
php:
image: php:8.2.16-fpm
volumes:
- ./html:/var/www/html
- ./php/php.ini:/usr/local/etc/php/conf.d/custom.ini
environment:
- "PM_MAX_CHILDREN=5"
- "PM_START_SERVERS=2"
然后写一段模拟慢请求的PHP脚本:
<?php
// slow.php - 模拟业务慢请求:查询数据库 + 外部API调用 + 循环计算
$pdo = new PDO('mysql:host=mysql;dbname=test;charset=utf8mb4', 'root', 'password');
// 模拟复杂SQL:3次联合查询
for ($i = 0; $i < 3; $i++) {
$stmt = $pdo->query("SELECT u.*, o.order_no, p.product_name
FROM users u
LEFT JOIN orders o ON u.id = o.user_id
LEFT JOIN products p ON o.product_id = p.id
WHERE u.status = 1 ORDER BY u.id DESC LIMIT 100");
$data = $stmt->fetchAll(PDO::FETCH_ASSOC);
}
// 模拟外部API调用超时(curl默认为不限制超时)
$ch = curl_init('http://third-party-api.example.com/data');
curl_setopt($ch, CURLOPT_RETURNTRANSFER, true);
curl_setopt($ch, CURLOPT_TIMEOUT, 30); // 等待外部接口最多30秒
$result = curl_exec($ch);
curl_close($ch);
// 模拟CPU密集型计算
$sum = 0;
for ($i = 0; $i < 1000000; $i++) {
$sum += sqrt($i);
}
echo "done: {$sum}";
?>
用压测工具模拟并发:
# 使用wrk压测(比ab更准确,支持高并发)
# 安装wrk
apt install wrk
# 压测:200并发,持续60秒,模拟高峰期流量
wrk -t4 -c200 -d60s http://127.0.0.1:8080/slow.php
# 输出结果(关键指标)
# Running 1m test @ http://127.0.0.1:8080/slow.php
# 4 threads and 200 connections
# Thread Stats Avg Stdev Max +/- Stdev
# Latency 12.32s 8.41s 30.01s 86.17%
# Req/Sec 0.53 141.00
# Requests/sec: 0.53
# Transfer/sec: 143.24KB
看到这个数字了吗?每秒只能处理0.53个请求。所有请求都在排队等那5个FPM进程,MySQL连接池被打满,外部API超时30秒(因为curl等待),整个服务直接瘫痪。
这就是502/504同时出现的根源:FPM进程全部卡在网络等待上,新请求无法建立连接(502),已有连接响应超时(504)。
4.4 strace定位进程到底卡在哪
判断进程是否卡死,不能靠猜,要看系统调用。strace是排查这个问题最强的工具:
# 查看PHP-FPM主进程PID
pgrep -f "php-fpm: master"
# 查看所有FPM子进程的当前系统调用(每2秒刷新一次)
strace -p $(pgrep -f "php-fpm: pool" | tr '\n' ',' | sed 's/,$//') -f -t -o /tmp/fpm_strace.log
# 等10秒后停止,分析输出
tail -50 /tmp/fpm_strace.log
输出结果中反复出现这些调用:
04:32:17.334987 fcntl(9, F_SETFL, O_RDWR|O_NONBLOCK) = 0
04:32:17.335012 poll([{fd=9, events=POLLIN}], 1, 5000) = 0 (Timeout)
04:32:17.340031 recvfrom(8, 0x7f8c4c005000, 4096, 0, NULL, NULL) = -1 EAGAIN (Resource temporarily unavailable)
04:32:17.340056 poll([{fd=8, events=POLLIN}], 1, 5000) = -1 EINTR (Interrupted by signal)
04:32:22.345679 poll([{fd=8, events=POLLIN}], 1, 5000) = 1 ([{fd=8, events=POLLIN}])
04:32:22.345712 recvfrom(8, "SELECT u.*, o.order_no, p.product", 4096, 0, NULL, NULL) = 55
关键线索:
- poll超时5000ms——进程在等待fd可读,网络I/O阻塞
- EAGAIN——资源暂时不可用,重试中
- recvfrom收到SQL语句——查询MySQL后一直等结果
继续深入,用strace -e trace=network只追踪网络相关调用,确认是MySQL响应慢还是外部API慢:
# 只追踪网络相关系统调用
strace -f -p $(pgrep -f "php-fpm: pool") -e trace=network -o /tmp/fpm_net_strace.log
# 过滤connect到的目标端口
grep "connect" /tmp/fpm_net_strace.log | head -20
结果一目了然:大部分connect请求发往本地3306端口(MySQL),且connect成功后长期没有数据返回。再配合看MySQL的进程列表:
-- 在MySQL中执行,查看当前所有连接和执行中的SQL
SHOW FULL PROCESSLIST;
-- 输出结果关键行:
-- | 12345 | root | localhost | erp | Query | 25 | Waiting for table metadata lock | select * from orders |
-- | 12346 | root | localhost | erp | Query | 28 | Sending data | select * from products |
-- | 12347 | root | localhost | erp | Query | 30 | Waiting for table metadata lock | select * from orders |
看那两条「Waiting for table metadata lock」。有DDL语句(ALTER TABLE)在跑,把整个表锁住了,后续所有查询全部排队等锁。这就是压死FPM的最后一根稻草。
找到元凶:某位同事在业务高峰期执行了一条ALTER TABLE orders ADD INDEX idx_user_id (user_id),这把表锁了几分钟,导致所有依赖orders表的业务全部阻塞,FPM进程被占满后502/504全面爆发。
五、解决方案:三层调整
5.1 调整PHP-FPM进程管理策略
4核8G的机器,pm.max_children=5完全不合理。PHP-FPM每个进程平均占用内存约30-40MB(取决于业务复杂度),预留2-3GB给MySQL和系统,PHP-FPM可用内存约4-5GB。
# /etc/php/8.2/fpm/pool.d/www.conf
# 核心配置对比
# 原配置(错误示范,进程数太少)
; pm = dynamic
; pm.max_children = 5
; pm.start_servers = 2
; pm.min_spare_servers = 1
; pm.max_spare_servers = 3
# 修改后(按内存估算:4GB可用 / 35MB每进程 ≈ 114个上限,取80%安全值)
pm = dynamic
pm.max_children = 80
pm.start_servers = 20
pm.min_spare_servers = 10
pm.max_spare_servers = 30
# 每个请求最多执行30秒,超过自动终止,防止脚本卡死
request_terminate_timeout = 30
# 限制每个进程处理请求数,防止内存泄漏积累
pm.max_requests = 500
5.2 调整Nginx和内核参数
# /etc/nginx/nginx.conf
# 在 http 块中调整
http {
# 增大FastCGI超时时间,同时配合FPM的request_terminate_timeout
fastcgi_connect_timeout 5s;
fastcgi_send_timeout 30s;
fastcgi_read_timeout 30s;
# 开启upstream keepalive,复用FPM连接,减少TCP握手开销
upstream php-fpm {
server unix:/run/php/php8.2-fpm.sock;
keepalive 20;
}
server {
location ~ \.php$ {
include fastcgi_params;
fastcgi_pass php-fpm;
# 关键:告诉FPM要支持keepalive
fastcgi_param HTTP_CONNECTION "";
fastcgi_keep_conn on;
}
}
}
同时调整系统内核参数,解决TIME_WAIT连接堆积:
# /etc/sysctl.conf 追加以下配置
# 查看当前TIME_WAIT连接数
ss -ant | grep TIME_WAIT | wc -l
# 启用tcp_tw_reuse,允许将TIME_WAIT连接重新用于新连接
net.ipv4.tcp_tw_reuse = 1
# 调整本地端口范围,防止端口耗尽
net.ipv4.ip_local_port_range = 1024 65000
# 增大文件描述符限制
fs.file-max = 100000
# 生效
sysctl -p
5.3 用监控脚本兜底
加了以下监控脚本,一旦FPM空闲进程数跌破阈值或502波动异常,直接告警:
#!/bin/bash
# /usr/local/bin/fpm_health_check.sh
# 每分钟检查一次,配合crontab使用
FPM_STATUS_URL="http://127.0.0.1/status?plain"
THRESHOLD_IDLE=5
# 获取空闲进程数
IDLE_PROCESSES=$(curl -s "$FPM_STATUS_URL" | grep "^idle:" | awk '{print $2}')
# 获取当前活跃进程数
ACTIVE_PROCESSES=$(curl -s "$FPM_STATUS_URL" | grep "^active:" | awk '{print $2}')
# 获取最近30秒502错误数(通过Nginx错误日志)
NGINX_ERROR_COUNT=$(tail -1000 /var/log/nginx/error.log | grep -c "connect() failed" 2>/dev/null)
# 判断是否触发告警
if [ "$IDLE_PROCESSES" -lt "$THRESHOLD_IDLE" ]; then
echo "[$(date '+%Y-%m-%d %H:%M:%S')] ALERT: FPM idle processes low (idle=$IDLE_PROCESSES, active=$ACTIVE_PROCESSES)" >> /var/log/fpm_health_check.log
# 调用企业微信/钉钉webhook通知
curl -s -X POST "https://qyapi.weixin.qq.com/cgi-bin/webhook/send?key=YOUR_KEY" \
-H "Content-Type: application/json" \
-d "{\"msgtype\": \"text\", \"text\": {\"content\": \"FPM告警:空闲进程仅剩 $IDLE_PROCESSES,活跃进程 $ACTIVE_PROCESSES\"}}" &
fi
if [ "$NGINX_ERROR_COUNT" -gt 50 ]; then
echo "[$(date '+%Y-%m-%d %H:%M:%S')] ALERT: Nginx 502 error burst ($NGINX_ERROR_COUNT in recent 1000 lines)" >> /var/log/fpm_health_check.log
fi
配crontab:
# crontab -e 添加
* * * * * /usr/local/bin/fpm_health_check.sh
六、优化前后效果对比
调优完成后,我用同样的wrk压测命令重新跑了一遍:
| 指标 | 优化前 | 优化后 | 提升比例 |
|---|---|---|---|
| Requests/sec | 0.53 | 2017.39 | 3806倍 |
| 平均延迟 | 12.32s | 86.42ms | 99.3%降低 |
| P95延迟 | 2.8s(大量超时被截断) | 211.46ms | 降低92.4% |
| 失败请求数 | 63% | 0% | — |
线上真实数据(优化后运行30天):
- 502/504告警次数:从每日15-20次降到0
- FPM平均响应时间:从900ms降至120ms
- FPM进程内存占用:稳定在36MB/进程左右,80个进程峰值约2.9GB,在内存预算内
七、避坑指南
这次排查踩了不少坑,每个都是真金白银买来的教训:
坑1:压测时curl外部API会把压测机搞挂
我用wrk压180秒,结果wrk自己先挂了,因为所有线程都在等curl的30秒超时。后来把curl改成不实际请求外部API,用sleep模拟。压测代码里的外部API请求在生产环境没问题,但压测环境一定要mock掉。
坑2:tcp_tw_reuse和tcp_tw_recycle搞混
起初我开了net.ipv4.tcp_tw_recycle=1,结果NAT环境下的用户请求大量超时,因为tcp_tw_recycle在NAT场景下会丢弃来自同一IP的时间戳延迟的包,导致连接完全建立不起来。这个参数在Linux 4.12+已经被移除,千万别用。tcp_tw_reuse是针对客户端连接修改了TCP选项,通常安全,但只对主动连接方生效。
坑3:同时调大max_children后内存打爆
我第一次直接把max_children调到200,PHP-FPM直接OOM(内存溢出),MySQL也被拖垮。每个PHP-FPM进程平均占用35MB,所以要按公式算:(总内存 - MySQL内存占用 - 系统预留) / 单进程平均内存 = 安全的max_children。别拍脑袋设,不然200个进程直接吃满16G内存,比502更惨。
坑4:清空Nginx错误日志后无法写入
排查时我用了cat /dev/null > /var/log/nginx/error.log清空日志,结果Nginx还在写,文件句柄还指向旧inode,日志文件变成空白但不增长。正确做法是mv /var/log/nginx/error.log /var/log/nginx/error.log.old && touch /var/log/nginx/error.log,然后nginx -s reopen让Nginx重新打开日志句柄。排查期间尤其要注意,别把证据亲手销毁。
坑5:忽略PHP-FPM的request_terminate_timeout
这次故障里如果早设置了request_terminate_timeout = 30,卡住的请求会在30秒被强制杀掉,FPM进程被快速回收,502/504的影响面会小很多。但这个参数不适合所有场景——如果业务有合法长耗时任务(如导出大数据、生成报表),把它设置太短会误杀正常请求,需要根据业务逻辑设置合理值。
坑6:MySQL的metadata lock是隐藏杀手
这次真正的根因——那条ALTER TABLE语句产生的metadata lock,平时很难排查到。它不会显示为慢查询,等锁的SQL也不会出现在慢查询日志里,因为它们的执行时间被算进等锁等待里了。建议用performance_schema.metadata_locks表来监控锁等待情况:
-- 查看当前所有metadata lock持有和等待情况
SELECT OBJECT_SCHEMA, OBJECT_NAME, LOCK_TYPE, LOCK_STATUS, SOURCE
FROM performance_schema.metadata_locks
WHERE LOCK_STATUS = 'PENDING';
-- 查看哪些事务持有了锁(结合processlist)
SELECT * FROM information_schema.innodb_trx
WHERE trx_state = 'RUNNING' AND trx_started < NOW() - INTERVAL 10 SECOND;
八、总结
502/504不是无解的玄学。它们只是两个症状,根因在PHP-FPM进程状态、MySQL锁竞争、内核网络参数这几个层面。按这个链路排查:
- 看Nginx错误日志区分502为主还是504为主
- 看FPM状态页确认进程是否耗尽
- strace追踪进程卡在哪个系统调用
- 沿时间线回查数据库锁和慢SQL
- 调整FPM进程管理策略和Nginx超时配置
- 加监控脚本防止复发
这套流程走下来,用了不到2小时就定位到根因,比来回重启一晚上强多了。希望你们不用再经历凌晨2点的告警电话。