反代超时返回 HTML,前端报 SyntaxError:一次 499 事故复盘
把责任推给 JavaScript 的卡片
线上面板报上来只有一行字:
读取自动处理状态失败:SyntaxError: Unexpected token '<', "<!DOCTYPE "
字面上读,这句话是在指控前端。JSON.parse 遇到 < 才会抛 SyntaxError,于是第一反应必然是「打包缓存过期」「序列化写错」「Content-Type 配错」——排查方向被钉在了错误的进程里,一钉就是几个小时。
真相是响应体本身就是 HTML。应用前面某一层吐出了一个以 <!DOCTYPE 开头的文档。JSON 路由上的应用服务器不会干这种事,反向代理会。所以这条错误信息其实是一张很精确的故障地图,只是画图的那一层不是出问题的那一层:浏览器只是老老实实报告「我拿到的是另一种文档」。
下面是完整复盘:定位真因的几组实测数据,以及让这一类故障再也无法被误判的三处契约改动。
故障形态:藏在 GET 里的全库审计
出问题的路由是发布控制台的一张状态卡片:
GET /api/automation
它返回三个开关和三个计数。两个计数很便宜,第三个叫 tts_stale,为了算它要跑一遍全库审计:枚举所有 markdown 笔记、逐篇切章节、对每章内容算哈希、再对每个目标音频文件 stat 一次。而这一切就跑在请求线程里,卡片每轮询一次就重算一次。
# 出问题的写法:一个 GET,顺手把整个库量一遍
@app.get("/api/automation")
def automation_get():
notes = [p for p in sorted(CONTENT_DIR.glob("*.md")) if not p.stem.endswith(".en")]
missing_cover = [...]
stale = tts_mod.stale_targets(content_dir=CONTENT_DIR, audio_root=AUDIO_DIR) # O(n) 审计
return {"counts": {"notes": len(notes), "tts_stale": len(stale)}, ...}
289 篇笔记时这是一次 13.6 秒的请求。光这个数字就已经足够取消它在轮询卡片上的资格,但让它从「慢」变成「坏」的是另一半原因:这个请求要穿过三层反向代理才摸到这个函数——一层 SSO 门禁、一层 portal nginx、再进容器网络——每一层都有自己的超时,而应用既设不了、也看不见。
portal 的 /api/ 位置在现行配置里是 proxy_read_timeout 120s,而它前面的 SSO 门禁放弃得更早。任何一层的计时器一到,它就按 nginx 的本分处理:停止等待、断开上游连接、把自己的 HTML 错误页交给浏览器。前端接着对这份文档执行 await res.json(),于是就有了那行 SyntaxError。
整条链上没有任何一环返回 500。应用从头到尾都不知道这个请求存在过。
三条证据钉死「其实什么都没坏」
三个产物合起来就能定位故障,不需要猜。单独看每一条都是歧义的,其中一条还会主动误导。
| 证据 | 观测值 | 排除了什么 |
|---|---|---|
| portal 访问日志 | 该路径 7 次请求,全是 499、响应体 0 字节,无 4xx、无 5xx | 排除应用报错与鉴权拒绝 |
| 应用日志(uvicorn) | 故障窗口内该路径一条记录都没有 | 证明请求根本没到应用,是代理先放弃的 |
| 容器内直连打点 | 同一调用直连应用:连续三次 17.7 秒 / 98.5 秒 / 35.8 秒 | 确认慢是真的、且慢在审计内部,不是网络抖动 |
499 是 portal nginx 在其上游调用方主动掐断连接时写下的状态码——这里是排在它前面、计时器比 portal 的 120 秒更早到期的 SSO 门禁,它转身把自己的 HTML 超时页吐给了浏览器,而 portal nginx 只看到调用方提前离场。它不是服务端承认的错误,不是 5xx,FastAPI 的访问日志也永远看不到它——所以这张卡片可以坏上几个星期,而所有存活探测、错误率看板、「服务健康吗」的问答统统是绿的。真正描述这次故障的状态码,由放弃等待的那一层写下,指向的是一个应用从未收到的请求。
而最响的那条证据恰好在误导:SyntaxError。它对文档的描述是准确的,对原因的判断是错的。
隐藏变量:空闲时 13.6 秒,满载时 2507 秒
修之前,审计的耗时看起来像个常数。它不是。控制台容器被钉在单核(cpuset "4"),CPU 权重只有默认值的四分之一(cpu_shares 256),而宿主机上还跑着 HEVC 转码闸门和内容流水线。这场审计要跟别的任务抢那一个核。
把审计挪出请求路径之后,应用开始自己记录耗时,假设才变成测量:
automation counts refreshed in 76.1s
automation counts refreshed in 82.3s
automation counts refreshed in 93.5s
automation counts refreshed in 124.2s
automation counts refreshed in 165.1s
automation counts refreshed in 633.6s
automation counts refreshed in 1282.5s
automation counts refreshed in 2507.2s
同一份代码、同一个 341 篇的库,一个数量级的跨度,最坏值比空闲机上量到的数字慢 184 倍。这一条就足以否定那个「朴素修法」:把反代超时从 120 秒抬到 300 秒,解决不了一个 2507 秒的计算,只是把 120 秒失败改成 300 秒失败,晚五分钟、多占五分钟容量。
这就是我在边缘层反复吃到的教训:端点延迟不是代码的属性,而是它被允许借用多少 CPU 与 I/O 余量的属性。 单核 cgroup 限流叠加宿主机的重载任务,会把一次 O(n) 文件审计变成耗时由邻居决定的无界操作。
修法:把读路径和计算路径彻底拆开
三处契约改动,每一处都小到可以独立验证。
一、读路径绝不计算。 计数放进 TTL 缓存(300 秒,AUTOMATION_COUNTS_TTL_SEC 可调)。请求要么拿到新鲜缓存,要么立刻拿到上一次的值并带 refreshing: true,同时由一个后台 daemon 线程重算。单飞用一把锁加一个标记守住,成串的轮询不会变成成串的审计。缓存还会在应用 lifespan 里预热一次,第一个打开面板的人不用替所有人付这笔账。
🔍 查看 stale-while-revalidate 实现 —— 缓存、单飞刷新线程与启动预热(53 行)
_AUTOMATION_TTL_SEC = float(os.environ.get("AUTOMATION_COUNTS_TTL_SEC", "300") or 300)
_automation_cache: Dict[str, Any] = {"data": None, "at": 0.0}
_automation_refreshing_flag = [False]
_automation_lock = threading.RLock()
@app.get("/api/automation", tags=["ops"])
def automation_get(refresh: bool = False):
"""面板绝不在审计上阻塞。"""
flags = autoflow.settings(db=db)
now = time.time()
cached = dict(_automation_cache)
fresh = cached["data"] is not None and (now - cached["at"]) < _AUTOMATION_TTL_SEC
if refresh or not fresh:
_start_automation_refresh()
return {
"flags": flags,
"counts": (cached["data"] or {}).get("counts")
or {"notes": 0, "missing_cover": 0, "tts_stale": 0},
"refreshing": _automation_refreshing_flag[0] or not fresh,
"cached_at": (datetime.fromtimestamp(cached["at"]).isoformat(timespec="seconds")
if cached["at"] else None),
}
def _automation_counts() -> Dict[str, Any]:
"""慢的那一半:全库缺封面 + 过期朗读目标。"""
notes = [p for p in sorted(CONTENT_DIR.glob("*.md")) if not p.stem.endswith(".en")]
missing_cover = [...]
stale = tts_mod.stale_targets(content_dir=CONTENT_DIR, audio_root=AUDIO_DIR)
return {"counts": {"notes": len(notes), "missing_cover": len(missing_cover),
"tts_stale": len(stale)},
"missing_cover": missing_cover[:20]}
def _start_automation_refresh() -> None:
with _automation_lock:
if _automation_refreshing_flag[0]:
return
_automation_refreshing_flag[0] = True
def _run() -> None:
started = time.time()
try:
data = _automation_counts()
_automation_cache.update({"data": data, "at": time.time()})
except Exception as exc: # 审计坏了也不能把卡片打成 500
logging.warning("automation counts failed: %s", exc)
finally:
_automation_refreshing_flag[0] = False
logging.info("automation counts refreshed in %.1fs", time.time() - started)
threading.Thread(target=_run, name="automation-counts", daemon=True).start()
二、陈旧值必须自己说出来。 响应里带 refreshing 与 cached_at,卡片在重算期间把「计算中…」挂在数字后面,3 秒后自动补取一次。反面做法——在数据到达前先显示 0——比慢更糟,因为积压计数器上的 0 与「确实没事可做」长得一模一样。
三、客户端绝不盲解析。 真正躺在浏览器侧的缺陷是 res.json():它把「收到了 HTML 错误页」推断成「JSON 格式错误」,顺手丢掉了状态码和本该指出故障层级的那段正文。
🔍 查看「先读文本」的响应读取器与重试契约(18 行)
function autoReadJson(res) {
// 反代超时 / 502 / 503 回的是 HTML 错误页;裸 res.json() 会把它变成
// "Unexpected token '<'",并把「哪一层挂了」这条信息彻底吞掉。
return res.text().then(function (text) {
try {
return { data: JSON.parse(text) };
} catch (e) {
var head = String(text || '').trim().slice(0, 80).replace(/\s+/g, ' ');
return { error: 'HTTP ' + res.status + ' · ' + (head || '空响应') };
}
});
}
// refreshing 时:先显示上一次的数字并标注状态,3 秒后再来一次
document.getElementById('auto-counts').textContent =
'笔记 ' + counts.notes + ' · 缺封面 ' + counts.missing_cover
+ ' · 待朗读 ' + counts.tts_stale + (data.refreshing ? ' · 计算中…' : '');
if (data.refreshing) { autoRetryTimer = setTimeout(window.autoReload, 3000); }
第四处改动更小但很关键:?refresh=1 强制重算。测试和人一样,都需要一条「立刻要新数字」的通道,否则整套测试只能靠 sleep 等 TTL 过期。
测试契约跟着端点一起改了,这是大多数人会跳过的一步:用例现在轮询到后台线程落地为止,而不是对第一次响应就断言数字。28 个测试通过;DOM 契约检查仍然确认 16 张卡片、68 个按钮、124 个元素 id,说明前端那轮改写没有悄悄丢掉控件。
复盘:我此后对每个面板端点都套用的五条规矩
- 看板端点不是查询接口。 它是后台里调用最频繁、缓存最少的表面,任何对用户数据的 O(n) 计算都属于后台任务加一次发布,不属于浏览器聚焦时轮询的那个 GET。
- 超时预算等于最小那一跳,不是各跳之和。 四层反代各自「允许」120 秒并不叠加:请求死在最先到期的那个时钟上,而应用一个都看不见。应用侧的预算必须比最小的那个还低一个数量级。
499值得配一条告警。 它是唯一一个表达「调用方放弃了」的信号,且天然绕开所有基于 5xx 的监控。从访问日志抓单条路径上 499 与 200 的比值,几乎零成本覆盖这一整类故障。- 在反代后面永远不要信
res.json()。 先读文本,留下状态码,留下第一行。下一个接手的人手里只有这条错误信息。 - stale-while-revalidate 优于一个更大的数字。 抬高超时只是把墙往后推;把计算与读拆开才是把墙拆掉——而且拆掉的是我还没量到的那个最坏值(这里的 2507 秒),不只是量到的那个(13.6 秒)。
交付结果
- 缓存读路径:连续五次容器内实测 200,0.24–0.36 秒,中位 0.26 秒,对照它所替代的 13.6 秒审计——中位快 52 倍,整个区间快 38–57 倍。
- 最坏情况不再暴露给使用者。 宿主机饱和时审计仍要 2507 秒,但它现在只花掉一个后台线程,而不是一张坏掉的卡片,面板全程照常应答。
- 正确性保留而非掩盖。 撰写时的计数:341 篇笔记、1 个缺封面、47 篇待生成朗读——同一个计算,只是搬了位置。
- 故障再也无法伪装。 任何一跳再次中断,卡片会打印
HTTP 503 · <!DOCTYPE html>…,排查从正确的层级开始。
整件事里最有用的一行,恰恰是那行说谎的 Unexpected token '<'。把 HTML 错误页递给一个 JSON 调用方,不是语法错误——那是反代用它唯一会说的语言在告诉我:我的代码还没醒,它就已经不等了。
服务器频繁异常重启、云账单过高,或缺一位能穿透内核日志的架构师?
真正的生产环境稳定性,靠的是穿透表象抓出根因。我独立管理着跨 3 台物理/云主机、162 个容器的高可用自托管生产网络。