浏览 AI 知识库

偶发 Bug 怎样用日志、时间线和最小复现缩小范围

用一个 Node.js 缓存刷新竞态案例,把“每天偶尔 502”还原成请求时间线、成功/失败对照、最小复现代码和可重复回归测试。

故障现场

接口 99% 正常,缓存刚过期时两条并发请求偶尔一起失败

教学案例是一条 Node.js 商品接口:平时响应 200,运营每天第一次批量打开商品页时偶尔出现 502。最初日志只有“load failed”,没有请求 ID、节点、缓存状态或上游耗时,团队只能反复重启。

补齐日志后发现,失败只出现在 cache=expired 且同一节点 50 毫秒内收到多条请求时。两条请求同时刷新缓存,上游限并发后其中一条超时。这个结论来自失败与成功样本对照,不是看到‘缓存’两个字后的猜测。

  • 一条端到端故障时间线
  • 能稳定触发竞态的最小复现
  • 修复前后使用同一断言的回归结果
实际输入

先把四次请求排在同一时区,再找失败组独有条件

时间 UTC+8request_id节点缓存上游耗时结果
10:14:03.112req-81api-2hit0 ms200 / 42 ms
10:15:00.006req-82api-2expired1,980 ms200 / 2,014 ms
10:15:00.041req-83api-2expired5,000 ms502 / 5,018 ms
10:15:04.210req-84api-1hit0 ms200 / 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 并发请求,修复前后只比较三个指标

检查项修复前修复后通过标准
上游调用次数201同一进程一次过期窗口只刷新 1 次
fulfilled1-2 / 2020 / 2020 条全部返回有效目录
refreshPromise 失败后状态无此状态finally 后为 null下一次请求可以重新刷新
缓存命中路径约 40 ms约 40 ms正常路径无明显回归
常见失败

复现不稳定时,不要同时改超时、重试、缓存和日志

压力测试能失败,但与线上不是同一错误

原因
只追求出现 500,没有对齐状态码、调用链和失败位置。
怎么改
把线上 request_id 的时间线与复现逐字段对照;不一致就不是同一个 Bug。

加重试后看似恢复,调用量却暴涨

原因
重试掩盖了并发刷新,还把压力放大给上游。
怎么改
先验证根因;修复后再单独评估重试次数、退避和幂等。

本地 20 并发通过,线上仍偶发

原因
修复只在单进程内生效,线上有多个实例。
怎么改
把 node_id 加入日志,按实例与全局窗口重做对照。

只保留最终代码,没有故障证据

原因
无法证明修复针对原问题,也无法判断回归。
怎么改
保留原始样本、最小复现、diff、测试输出和观察窗口。
验收方式

满足这些条件,才可以把“疑似竞态”写成已修复

核对入口

代码行为还要结合当前运行时与生产观测核验