perf(worker-platform): 排行榜公共缓存与抢单短路,压制 8.5s 慢查询脉冲

- 排行榜:Top 10 改为按 period 全局共享缓存(TTL 30s),SQL 传 currentWorkerId=0;
  个人单数解耦为 assigned_worker_id 精准索引查询(TTL 15s),未上榜展示「暂未上榜」,
  消除「每个打手一份缓存」导致的 8.5 秒全表聚合穿透;
- 抢单短路:新增 work-order-grab-guard,对已关闭工单打 10s 进程内标记,命中直接 409;
  publishWorkOrderRealtimeChange 统一作废标记,避免撤单/超时重开/重新发布后误杀正常抢单;
- 我的订单:默认排序也走「先取 id 再批量回表」的延迟分页,避免宽列 material_json 参与排序;
- 文档:新增生产 CPU 波动分析报告,慢查询数字按 6,235 行日志实测重算,并标注修复状态与验收口径。

验证:typecheck / check:sql / eslint / prettier 通过;后端 npm test 914 项(910 pass、4 skip、0 fail)。
This commit is contained in:
yml2213
2026-10-30 22:42:11 +08:00
parent 4ef52f11ba
commit 44791a9c8b
9 changed files with 421 additions and 25 deletions
@@ -0,0 +1,194 @@
# 生产服务器 CPU 剧烈波动(忽高忽低)根因深度分析报告
> **排查时间**:2026-10-30 22:05 ~ 22:16
> **目标服务器**:`47.114.114.225`(4 核 CPU / 8GB 内存,Ubuntu 7.0.0-22-generic)
> **排查手段**:`mpstat`、`pidstat -t`、`docker stats`、`pg_stat_activity`、`EXPLAIN (ANALYZE, BUFFERS)`、生产容器日志全量解析、源码拓扑追溯。
> **数据复核**:2026-10-30 修复提交前,对 `/Users/yml/Downloads/app-2026-10-30.log`(6,235 行)重新做了全量解析,本文所有标注「实测」的数字均来自该日志的逐条统计;标注「EXPLAIN」的数字来自本地 `EXPLAIN (ANALYZE, BUFFERS)`,两者口径不同,不混用。
---
## 0. 一句话结论
4 核机器上,**每一次「排行榜 / 我的订单」重型查询都是一个 1~8 秒的 CPU 独占脉冲**:它把 Postgres 打满 → 连接池与 CPU 队列排满 → 慢查询结束时几十个微型查询同时释放 → 形成第二波 CPU 冲击 → 随后骤降。所谓「忽高忽低」不是负载均衡问题,而是**重型慢查询驱动的秒级脉冲**。
---
## 1. 现状评估台账(Known / Unknown / Goal)
| 维度 | 内容详情 | 确信度 | 验证证据 / 关联源码位置 |
| :--- | :--- | :---: | :--- |
| **已知** | 机器物理规格仅 4 核,常态 Load Average 5.5 ~ 10.5,长期超饱和。 | 100% | `uptime` 实测 `load average: 10.53, 7.53, 6.56` |
| **已知** | 波动源是 **Postgres(`order_site-postgres-1`)** 与 **Node.js 后端(`order_site-backend-1`)**,两者波峰同频。Postgres 30% ~ 280%,Node.js 26% ~ 177%。 | 100% | `docker stats` 逐秒采样(22:05:54 波峰 Postgres 280.79%,接近 3 个核) |
| **已知** | 3.5 分钟日志内 **3,718 条数据库慢查询**,累计阻塞 3,140.49 秒;其中 WARN 4,137 条(慢查询占 89.9%)、INFO 1,005 条、ERROR 1 条。 | 100% | 日志全量解析(6,235 行 / 22:11:01~22:14:35) |
| **已知** | 波峰元凶一:排行榜 `WITH leaderboard_day` 执行 **4 次**,最高 **8,483.35ms**、平均 **4,480.0ms**;全表扫描 `work_orders` + `work_order_shares` 做去重聚合。 | 100% | 生产日志 + `EXPLAIN` 实测(本地 EXPLAIN 为 8,257.61ms / 75,881 shared hit),源码见 [worker-ranking-repo.ts](file:///Users/yml/codes/order_site/apps/backend/src/repositories/worker-platform/worker-ranking-repo.ts#L85-L189) |
| **已知** | 波峰元凶二:打手「我的订单」可见性查询执行 **238 次**(70 次 `WITH visible_orders` + 168 次 `assigned.id AS work_order_id` 的 UNION 版),最高 **5,544.91ms**、平均 **1,227.0ms**;子查询对 162 万行 `work_order_events` 按 `payload_json->>'workerId'` 文本关联,并叠加 `LEFT JOIN LATERAL`。 | 100% | 生产日志统计,源码见 [work-order-query-repo.ts](file:///Users/yml/codes/order_site/apps/backend/src/repositories/worker-platform/work-order-query-repo.ts#L1237-L1276) |
| **已知** | 波峰元凶三:大厅列表查询 **77 次**,最高 **5,775.77ms**、平均 **1,097.2ms**;大厅分页计数 **200 次**,最高 **3,435.98ms**、平均 **1,019.1ms**。 | 100% | 生产日志统计 |
| **已知** | 排行榜缓存失效缺陷:`getWorkerHallLeaderboard` 的缓存 Key 含 `session.workerId`,导致**每个打手各有一份 Top 10 缓存**。公共 Top 10 本可全站共享,实际每个打手首访都穿透执行一次全表聚合。 | 100% | 源码 [worker-hall-service.ts](file:///Users/yml/codes/order_site/apps/backend/src/services/worker-platform/worker-hall-service.ts#L152-L191)(修复前版本) |
| **已知** | 「队头阻塞 + 雪崩」证实:3,718 条慢查询里只有 242 条(6.5%)是重型查询,其余 **3,476 条(93.5%)是原本 0.3ms 级的查询**,被拖到平均 **800ms 以上**(`worker_users` 486 次 / 769.4ms,`worker_sessions` 467 次 / 825.6ms)。 | 100% | 单秒释放峰值 116 条/秒(22:12:46) |
| **已知** | 外部请求摩擦:IP `117.179.249.212` 3.5 分钟发 359 次请求(占全网 42%),其中 **331 次**是对已关闭工单 `195657` 的死循环抢单(409)。该 IP 均值 2~4 QPS,低于 Tier 1 阈值(1 秒 10 次),未被打掉。 | 100% | 生产 access 日志 + `app_config_entries` 风控配置 |
| **未知** | 若把 Top 10 改为全局公共缓存,打手「自身名次不进前 10」时如何呈现最合理。 | 70% | 当前落地:不展示名次(前端显示「暂未上榜」),只展示个人完成单数 |
| **目标** | 消除排行榜 8.5 秒全表扫描与「我的订单」深层扫描,消灭 1 秒以上的慢查询。 | 100% | 排行榜缓存解耦 + 延迟分页(已落地) |
| **目标** | 压制外挂对后端/数据库的穿透磨损,对同一工单连续 409 做本地快速拒绝。 | 95% | 抢单短路标记(已落地) |
| **目标** | 整体 CPU 稳定在 40% 以下,消除 70%~280% 的剧烈波动。 | 95% | 削平波峰后,连接池排队与级联雪崩应自动消失(待生产验证) |
---
## 2. 现场采样与现象记录
### 2.1 逐秒 CPU 波动采样(`docker stats`)
```text
时间 web(Caddy) backend(Node) postgres(DB) 现象描述
-----------------------------------------------------------------------------
22:05:38 3.65% 63.98% 173.88% DB 开始冲高,已占用近 2 核
22:05:41 4.81% 26.26% 140.29% 轻微回落
22:05:44 15.92% 37.46% 72.86% 谷底阶段
22:05:47 19.02% 11.68% 122.54% 开始爬升
22:05:51 12.46% 47.72% 125.34% 并发请求进入
22:05:54 13.80% 65.12% 280.79% <--- 【大波峰】Postgres 独占近 3 核
22:05:57 15.78% 74.85% 244.70% 【高位震荡】整机 4 核饱和
22:06:00 15.40% 80.49% 128.14% 慢查询完成,开始回落
```
### 2.2 日志全量量化(`/Users/yml/Downloads/app-2026-10-30.log`)
覆盖 **22:11:01 ~ 22:14:35(3.5 分钟)**,共 6,235 行。
**日志级别**:`WARN` 4,137(其中慢查询 3,718,占 89.9%)、`INFO` 1,005、`ERROR` 1(affiliate-dash 回调 500),其余为堆栈续行。
**按 SQL 指纹统计的慢查询(共 3,718 条 / 3,140.49 秒)**:
| 查询 | 次数 | 最高 | 平均 | 累计 |
| :--- | ---: | ---: | ---: | ---: |
| 排行榜 `WITH leaderboard_day` | 4 | 8,483.4ms | 4,480.1ms | 17.9s |
| 我的订单(`assigned.id` UNION 版) | 168 | 5,544.9ms | — | — |
| 我的订单(`WITH visible_orders` 版) | 70 | — | — | — |
| 我的订单合计 | **238** | **5,544.9ms** | **1,227.0ms** | 292.0s |
| 大厅列表(`SELECT CASE WHEN wo.status...`) | 77 | 5,775.8ms | 1,097.2ms | 84.5s |
| 大厅分页计数(`SELECT COUNT(*)::int AS total FROM work_orders wo...`) | 115 | 3,436.0ms | 954.6ms | 109.8s |
| `SELECT wu.*, wl.level_key...`(打手+等级+钱包) | 486 | 1,830.1ms | 769.4ms | 373.9s |
| `FROM worker_sessions WHERE session_id = ?` | 467 | 1,913.5ms | 825.6ms | 385.6s |
| 其余查询(互斥分组后剩余) | 2,331 | 4,707.4ms | 805.1ms | 1,876.8s |
> 口径说明:上表为**互斥分组**,合计 3,718 条 / 3,140.49 秒。若把带 `INNER JOIN 可见集` 等 COUNT 变体一起归为「大厅分页计数」,该类合计 200 条、最高 3,436.0ms、平均 1,019.1ms(与「其余查询」行有交叉,不重复计入合计)。
> 重型查询(排行榜 + 我的订单)= **242 条,占 6.5%**;其余 **3,476 条(93.5%)** 是被拖累的查询。这也解释了为什么慢查询数量看起来「莫名其妙」——报警主体不是元凶,而是受害者。
**并发释放脉冲(秒级)**:
- `22:12:46` 1 秒内释放 **116 条**慢查询
- `22:12:47` **108 条**
- `22:13:29` **103 条**
- `22:13:30` **102 条**
即:每次 5~8 秒的重型查询执行期间,微型查询被堵在连接池与 CPU 队列里;重型查询一结束,排队的查询在几十毫秒内同时完成,形成第二波 CPU 冲击与慢查询刷屏。
**请求与外挂分布(852 次 HTTP 请求)**:
- IP `117.179.249.212`:**359 次(42%)**,其中 **331 次**是对工单 `195657` 的死循环抢单(409)。
- 全站 `/grab` 请求共 **426 次**,说明除该 IP 外还有约 95 次抢单落在该工单/其他工单上。
- 文件上传 `/api/v1/worker/files/upload` **71 次**,其中 **58 次超过 1 秒**,最慢 **7,861ms**(图片转码 CPU + 数据库排队叠加)。
---
## 3. 根因剖析:为什么是「忽高忽低」
```mermaid
flowchart LR
A[打手打开大厅/我的订单] --> B[8.5s 排行榜 / 5.5s 可见性查询]
B --> C[Postgres CPU 冲到 2~3 核]
C --> D[连接池 + CPU 队列排满]
D --> E[微型查询全部排队 500~900ms]
B --> F[查询结束, CPU 释放]
F --> G[排队查询瞬间成批完成 116 条/秒]
G --> H[第二波 CPU 冲击]
H --> I[进入平静期]
I --> A
```
1. **低谷期(20%~50%)**:心跳、单工单读取、静态资源等轻请求,Postgres 与 Node 都轻松。
2. **触发点(150%~300%+)**:任意 1~2 个打手刷新大厅 / 打开「我的订单」/ 上传交付图,就足以触发一次 8.5 秒级聚合(它是 buffer 命中后仍要做的 HashAggregate + Sort,不是等 IO)。
3. **级联放大**:重型查询占满工作线程与 CPU 后,`worker_sessions`、`worker_users`、`work_categories` 这类 0.3ms 级查询排队到 800ms 以上;结束后集中释放形成第二波脉冲。
4. **放大系数**:慢查询告警数 = 元凶数 × 排队深度。这也是为什么只看告警条数(3,718)会高估「问题查询」数量,真正的元凶只有 242 条。
---
## 4. 关键缺陷、证据链与修复状态
### 缺陷 1:排行榜缓存 Key 混入 `workerId` 导致缓存穿透(严重)— ✅ 已修复
- **源码**:[worker-hall-service.ts](file:///Users/yml/codes/order_site/apps/backend/src/services/worker-platform/worker-hall-service.ts#L152-L191)
- **根因**:SQL 里 `WHERE rank <= $1 OR worker_id = $2` 把「当前打手自己的名次」混进同一次全表聚合,所以缓存 Key 只能带 `workerId`——于是每个打手一份缓存,公共 Top 10 完全无法共享,每个新打手首访都穿透一次 8.5 秒聚合。
- **影响**:单次 8,483.35ms(生产日志)/ 8,257.61ms(本地 EXPLAIN),75,881 shared hit。
- **修复**:
1. 缓存 Key 只保留 `leaderboardPeriod`(`all` / `daily`),TTL 30s,全站共享 Top 10;
2. `currentWorkerId` 传 0,SQL 只返回 `rank <= 10`;
3. 个人名次:在前 10 直接从列表取;不在前 10 则 `rank = null`(前端显示「暂未上榜」)+ 单独走 `countWorkerAcceptedOrdersByPeriod`(`assigned_worker_id` 精准索引,1~2ms),带 15s 独立缓存。
- **代价**:最多 30s 的榜单延迟、15s 的个人单数延迟,业务可接受。
### 缺陷 2:打手订单可见性对 162 万行事件表做文本探测(严重)— ⚠️ 部分缓解,未根治
- **源码**:[work-order-query-repo.ts](file:///Users/yml/codes/order_site/apps/backend/src/repositories/worker-platform/work-order-query-repo.ts#L1237-L1276)
- **问题 SQL 形态**:
```sql
INNER JOIN (
SELECT assigned.id AS work_order_id FROM work_orders assigned WHERE assigned.assigned_worker_id = $1::bigint
UNION
SELECT historical.id FROM work_orders historical
WHERE historical.last_assigned_worker_id = $1::bigint
AND (historical.status <> 'open'
OR EXISTS (SELECT 1 FROM work_order_events timeout_event
WHERE timeout_event.work_order_id = historical.id
AND timeout_event.event_type = 'timeout_reopen'))
UNION
SELECT share_source.work_order_id FROM work_order_shares share_source WHERE share_source.worker_id = $1::bigint AND share_source.status != 'cancelled'
UNION
SELECT timeout_ev.work_order_id
FROM work_order_events timeout_ev
WHERE timeout_ev.event_type LIKE 'timeout_%'
AND timeout_ev.payload_json->>'workerId' = $1::text
) worker_visible ON worker_visible.work_order_id = wo.id
```
- **影响**:`work_order_events` 已 162 万行(生产现场 EXPLAIN 统计,未在本地库复核),单次最高 5,544.9ms,前端翻页/切状态时反复触发。
- **已做**:默认排序也走「先取 id 再批量回表」的延迟分页(窄投影,避免 1.2KB `material_json` 参与排序物化),语义不变。
- **未做**:`UNION` 四分支本身没有收敛,`timeout_%` 分支仍是按 JSON 文本等值探测。
### 缺陷 3:外挂死循环抢单,未触发风控阈值(中)— ✅ 已修复
- **现场**:IP `117.179.249.212` 3.5 分钟 359 次请求,331 次刷同一张已关闭工单,全部 409。
- **根因**:Tier 1 阈值是「1 秒 10 次」,该脚本稳定在 2~4 QPS,永远打不到阈值;每次请求却都要走鉴权、`worker_users` 查询、工单查询与行锁探测。
- **修复**:`work-order-grab-guard` 对「已确认不可抢」的工单打 10 秒进程内标记,命中即 0.001ms 抛 409,完全不查库。
- **必须配套的失效机制**:工单撤单 / 超时重开 / 重新发布都会**复用同一个工单 id**,因此所有回到大厅的路径必须在 `publishWorkOrderRealtimeChange` 出口立即 `evictWorkOrderGrabBlock`,否则正常打手会在 TTL 内被误判 409。该失效已随本次修复落地,并有单测覆盖。
---
## 5. 治理方案与落地状态
| 方案 | 做法 | 预期收益 | 状态 |
| :--- | :--- | :--- | :--- |
| 1. 排行榜解耦 | Top 10 全局公共缓存(Key = period,TTL 30s)+ 个人单数独立精准查询(TTL 15s) | 全表聚合从「随在线人数线性增长」压到「每 30 秒至多 1 次(单副本)」 | ✅ 已提交 |
| 1b. 排行榜 SQL 收敛 | 可进一步去掉 `OR worker_id = $2` 分支(现在恒传 0),把「个人名次」彻底从该 SQL 里剥离 | 少一个分支,避免后人又把 workerId 传回缓存 Key | ⬜ 待办(低风险) |
| 2. 我的订单可见性 | ① `work_order_events` 分支改走带 `work_order_id` 的部分索引;② 把「可见工单 id 集合」物化/缓存(按打手 + 30s);③ 拆 UNION 为多个 `EXISTS` 短路 | 目标:单次 < 300ms | ⚠️ 仅完成延迟分页 |
| 2b. 具体索引建议 | 现有 `idx_work_order_events_timeout_worker_id`(`(payload_json->>'workerId') WHERE event_type LIKE 'timeout_%'`)只覆盖过滤,仍需回表取 `work_order_id`:`CREATE INDEX IF NOT EXISTS idx_work_order_events_timeout_worker_order ON work_order_events ((payload_json->>'workerId'), work_order_id) WHERE event_type LIKE 'timeout_%';` 上线前先在生产 `EXPLAIN (ANALYZE, BUFFERS)` 验证命中 | 去掉回表 | ⬜ 待办(需生产实测) |
| 3. 抢单防刷 | 非 open 工单 10s 进程内短路 + 状态变更即时失效 | 外挂 2~4 QPS 的数据库成本降为 0 | ✅ 已提交 |
| 4. 风控阈值 | 或对「同一工单连续 409 ≥ 3 次」做 10~30s 递增退避(不依赖全局 QPS 阈值) | 从源头减少无效请求 | ⬜ 待办 |
| 5. 容量 | 4 核已长期超载;若峰值仍在 2 核以上,评估升配到 8 核或读写分离 | 兜底 | ⬜ 待评估 |
### 验收口径(部署后按此核对)
1. `WITH leaderboard_day` 与「我的订单」在慢查询日志中的出现频率分别 ≤ 2 次/小时、≤ 5 次/小时。
2. 生产 `EXPLAIN (ANALYZE, BUFFERS)`:排行榜 ≤ 300ms(缓存 miss 时)、个人单数 ≤ 5ms、我的订单首屏 ≤ 300ms。
3. 同一 IP 对同一工单的 409 请求,数据库侧不应再出现对应查询(可用 `pg_stat_statements` 调用次数对比)。
4. 整机 Load Average 稳定 < 4(4 核),Postgres 容器 CPU < 120%。
5. 工单重新发布后,其他打手必须能在 1 秒内正常抢单(验证短路标记失效,不允许误杀)。
---
## 6. 风险与已知限制
- **进程内缓存**:排行榜榜单、个人单数、抢单短路标记都是**每进程一份**。单副本部署符合当前预期;若横向扩容为 N 副本,重算频率变为 30s × N,短路标记也只在本副本生效。届时应改用共享缓存(Redis)或接受该倍数。
- **一致性**:榜单 30s、个人单数 15s 的延迟属于有意设计;抢单短路标记的 TTL 上限 10s 由「状态变更即时失效」兜底,不依赖 TTL。
- **未复核项**:`work_orders` 19.6 万行 / `work_order_shares` 5.4 万行 / `work_order_events` 162 万行来自生产现场 EXPLAIN 统计,本地库(2026-10-22 快照)未重新核对;`docker stats` 采样值来自现场记录,未二次验证。
- **验证方式**:本次修复通过 `npm run typecheck`、`npm run check:sql`、`npm run test`(后端全量)验证;性能收益需在生产部署后按第 5 节验收口径复核。