浏览 AI 知识库
偶发 Bug 怎样用日志、时间线和最小复现缩小范围
用一个 Node.js 缓存刷新竞态案例,把“每天偶尔 502”还原成请求时间线、成功/失败对照、最小复现代码和可重复回归测试。
接口 99% 正常,缓存刚过期时两条并发请求偶尔一起失败
教学案例是一条 Node.js 商品接口:平时响应 200,运营每天第一次批量打开商品页时偶尔出现 502。最初日志只有“load failed”,没有请求 ID、节点、缓存状态或上游耗时,团队只能反复重启。
补齐日志后发现,失败只出现在 cache=expired 且同一节点 50 毫秒内收到多条请求时。两条请求同时刷新缓存,上游限并发后其中一条超时。这个结论来自失败与成功样本对照,不是看到‘缓存’两个字后的猜测。
- 一条端到端故障时间线
- 能稳定触发竞态的最小复现
- 修复前后使用同一断言的回归结果
先把四次请求排在同一时区,再找失败组独有条件
| 时间 UTC+8 | request_id | 节点 | 缓存 | 上游耗时 | 结果 |
|---|---|---|---|---|---|
| 10:14:03.112 | req-81 | api-2 | hit | 0 ms | 200 / 42 ms |
| 10:15:00.006 | req-82 | api-2 | expired | 1,980 ms | 200 / 2,014 ms |
| 10:15:00.041 | req-83 | api-2 | expired | 5,000 ms | 502 / 5,018 ms |
| 10:15:04.210 | req-84 | api-1 | hit | 0 ms | 200 / 39 ms |
样本是为教学构造的最小数据。真实排查要保留原始日志、部署版本、时区和采集缺口。
过期判断没有互斥,两条请求会同时进入刷新分支
问题代码
每个并发请求都会调用上游
let cache = { value: null, expiresAt: 0 };
export async function getCatalog() {
if (Date.now() >= cache.expiresAt) {
const value = await loadCatalogFromUpstream();
cache = { value, expiresAt: Date.now() + 60_000 };
}
return cache.value;
}最小复现
让 20 条请求在过期瞬间同时进入
cache.expiresAt = 0;
upstream.reset({ maxConcurrent: 1, delayMs: 80 });
const results = await Promise.allSettled(
Array.from({ length: 20 }, () => getCatalog())
);
expect(upstream.calls).toBe(1);
expect(results.every(x => x.status === 'fulfilled')).toBe(true);修复前第一条断言稳定失败,证明复现捕获的是并发刷新,而不是随机网络波动。
用 single-flight 共享一次刷新,并保留失败后的重试能力
修复代码
同一进程只保留一个 refreshPromise
let cache = { value: null, expiresAt: 0 };
let refreshPromise = null;
export async function getCatalog() {
if (Date.now() < cache.expiresAt) return cache.value;
if (!refreshPromise) {
refreshPromise = loadCatalogFromUpstream()
.then(value => {
cache = { value, expiresAt: Date.now() + 60_000 };
return value;
})
.finally(() => { refreshPromise = null; });
}
return refreshPromise;
}多实例部署仍可能同时刷新;若上游限制是全局的,还要评估分布式锁、抖动过期或允许陈旧值等方案。
同一组 20 并发请求,修复前后只比较三个指标
| 检查项 | 修复前 | 修复后 | 通过标准 |
|---|---|---|---|
| 上游调用次数 | 20 | 1 | 同一进程一次过期窗口只刷新 1 次 |
| fulfilled | 1-2 / 20 | 20 / 20 | 20 条全部返回有效目录 |
| refreshPromise 失败后状态 | 无此状态 | finally 后为 null | 下一次请求可以重新刷新 |
| 缓存命中路径 | 约 40 ms | 约 40 ms | 正常路径无明显回归 |
复现不稳定时,不要同时改超时、重试、缓存和日志
压力测试能失败,但与线上不是同一错误
- 原因
- 只追求出现 500,没有对齐状态码、调用链和失败位置。
- 怎么改
- 把线上 request_id 的时间线与复现逐字段对照;不一致就不是同一个 Bug。
加重试后看似恢复,调用量却暴涨
- 原因
- 重试掩盖了并发刷新,还把压力放大给上游。
- 怎么改
- 先验证根因;修复后再单独评估重试次数、退避和幂等。
本地 20 并发通过,线上仍偶发
- 原因
- 修复只在单进程内生效,线上有多个实例。
- 怎么改
- 把 node_id 加入日志,按实例与全局窗口重做对照。
只保留最终代码,没有故障证据
- 原因
- 无法证明修复针对原问题,也无法判断回归。
- 怎么改
- 保留原始样本、最小复现、diff、测试输出和观察窗口。
