fix(rectification): keep adopt narration timeout on a clearable ref timer
Independent Staging Quality Gate / validate (push) Successful in 9m16s
Independent Staging Quality Gate / publish (push) Successful in 1m52s

AbortSignal.timeout() is unref'd, so a hanging generateText drained the test event loop and cancelled the rest of the file. Clear the timer after the model returns.

Co-authored-by: Cursor <cursoragent@cursor.com>
This commit is contained in:
Jesse_Chen
2026-09-04 15:23:13 +08:00
parent 5c9e98790b
commit 45bdb63eca
6 changed files with 226 additions and 14 deletions
+17 -1
View File
@@ -8062,6 +8062,22 @@
- 修复:提示词改为「不要出现『确认』『精确』这两个词」,与校验器同口径;校验器本身不放宽,「这不是确认的分钟」仍打回。`deliverAdoptNarration``adopt_narration=agent | template:<reason> | template:model_error | template:not_ready`(不含模型原文),并用 `AbortSignal.timeout(8000)` 超时走模板。意图分类器超时仍是既有缺口,本单不修。
- 验证:提示词源码断言含「不要出现」;`deliverAdoptNarration` 对 agent / template:unknown_minute / template:model_error / template:not_ready 各有断言;短 timeout 挂起 generateText 走模板且不抛。
- 防复发:采用旁白结果必须留下 `adopt_narration=` 日志。Agent.generate 必须带超时。不得把「确认」从校验器删掉却不改提示词。
- 相关记录:BUG-521
- 相关记录:BUG-521、BUG-523
- 复发自:无
- 修复版本:待发布
## BUG-523 | 采用旁白超时用 unref 计时器,测试挂死事件循环
- 状态:resolved
- 首次发现:2026-09-04
- 最近更新:2026-09-04
- 影响面:`frontend/src/lib/rectification-agentic/v9/adopt-narration-agent.ts` `composedAbortSignal`
- 用户现象:staging 门禁 `npm test` 退出码 1`13dded9f` 不能部署。生产请求有监听 socket 撑住事件循环,超时在真实流量里仍会触发;但每次调用都会留下一个无法 `clear` 的 8 秒计时器。
- 触发条件:`deliverAdoptNarration``AbortSignal.timeout()`;测试把 `generateText` 挂成永不 resolve 的 Promise。
- 根因:Node 的 `AbortSignal.timeout()` 内部计时器始终 unref,空事件循环会在 abort 前排空。测试运行器判 `cancelledByParent`,同文件后三条用例一并取消。验收只看了 `# fail`,没看 `# cancelled` 与退出码。
- 修复:改为 `setTimeout` + `AbortController`(计时器保持 ref),返回 `{ signal, dispose }`;模型返回、校验完成或外部 abort 后 `clearTimeout` 并移除监听。超时仍走 `template:model_error`
- 验证:`rectification-adopt-narration-20260904` 超时用例不再 cancelled;新增「调用完不留活跃计时器」用例;源码不含 `AbortSignal.timeout`。定向套件与该文件摘要须含完整六行且 `# cancelled 0`、退出码 0。
- 防复发:采用旁白超时不得再用 `AbortSignal.timeout`。验收必须贴 Node 摘要完整六行(tests / pass / fail / cancelled / skipped / todo)与进程退出码,不得只报 `# fail 0`
- 相关记录:BUG-522
- 复发自:BUG-522
- 修复版本:待发布
@@ -30,3 +30,23 @@
- `npm run lint`0 error74 warning(既有)
- `rectification-adopt-narration-20260904` 10/10;与 answer-choice / collect-stall / provisional-adopt 合计 66/66
- `tests/rectification-*.test.ts tests/agentic-rectification-*.test.ts tests/birth-time-rectification-contract.test.ts`871 pass / 0 fail(基线 869 + 本单 2 条诊断/超时测试)
## 更正(2026-09-04 · 修复单 2
上面「10/10、871 pass / 0 fail」与实测不符。`AbortSignal.timeout()` 的计时器是 unref 的;超时用例把 `generateText` 挂死后事件循环排空,运行器把该条及同文件后三条标成 `cancelledByParent`
任务书在 Node 20.19 / CI Node 22 上的实测(完整六行):
```
# tests 10
# pass 6
# fail 0
# cancelled 4
# skipped 0
# todo 0
exit=1
```
定向套件 `rectification-* / agentic-rectification-* / birth-time-*`tests 871pass 858fail 0cancelled 4exit=1。
本机 Node 24.15.0 用 `tsx --test` 时 tsx IPC 会撑住事件循环,看起来像 10/10;独立脚本 `AbortSignal.timeout(30)` + 永不 settle 的 `Promise.race` 仍以退出码 13 结束,abort 从未触发。根因与修复见 `TASK-rectification-adopt-narration-fix2-20260904.md` / BUG-523。
@@ -0,0 +1,90 @@
# PROGRESS · 采用旁白超时改为可清理的 ref 计时器(2026-09-04
工作树:`.worktrees/rectification-adopt-narration-fix2-20260904`
分支:`codex/rectification-adopt-narration-fix2-20260904`
基线:任务书写 `13dded9f`;本工作树从当时 `origin/staging` `5c9e9879`(修复单 2 文档提交)拉出。
任务书:`docs/tasks/TASK-rectification-adopt-narration-fix2-20260904.md`
未改决策逻辑、未改提示词、未改 Python、未 bump Skill。未提交、未 push。
| 任务 | 状态 | BUG |
| --- | --- | --- |
| 5.1 超时改为可清理的 ref 计时器 | 完成 | BUG-523 |
## 开工复现
本机 Node 24.15.0。`tsx --test` 因 IPC socket 撑住事件循环,超时用例看起来能过。独立脚本复现了 unref 计时器:
```
const s = AbortSignal.timeout(30);
await Promise.race([new Promise(() => {}), new Promise((_, rej) => s.addEventListener("abort", () => rej(s.reason)))]);
# abort 从未触发
exit=13
```
任务书在 Node 20.19 / CI Node 22 上的套件实测见 `PROGRESS-rectification-adopt-narration-fix-20260904.md` 更正节(pass 6 / cancelled 4 / exit 1)。
## 实现要点
- `composedAbortSignal` 返回 `{ signal, dispose }``setTimeout` + `AbortController`(不 unref);外部 `signal` 的 abort 转发到 controller`dispose()` `clearTimeout` 并移除外部监听。
- `whenAborted` 同样返回 `dispose`,在 `finally` 里与 composed 一起清掉 abort 监听。
- `deliverAdoptNarration``Promise.race` 包在 `try / finally`;超时仍走 `template:model_error`
- 源码不再出现 `AbortSignal.timeout`
## 偏离
无。5.3 婚恋标签仍按修复单 1 推迟。
## 测试
`npx`/`tsx --test tests/rectification-adopt-narration-20260904.test.ts`
```
# tests 11
# pass 11
# fail 0
# cancelled 0
# skipped 0
# todo 0
exit=0
```
Node spec 报告器打印为 ` tests` 等六行,含义相同。比修复前多 1 条「调用完不留活跃计时器」。)
`tsc --noEmit`0 错,exit=0。
`npm run lint`0 error74 warning(既有),exit=0。
定向套件 `tests/rectification-*.test.ts tests/agentic-rectification-*.test.ts tests/birth-time-rectification-contract.test.ts`
```
# tests 872
# pass 872
# fail 0
# cancelled 0
# skipped 0
# todo 0
exit=0
```
(基线任务书写 871;本单 +1 条计时器用例。)
`npm test`(全量 `tests/*.test.ts`;本机有 Docker,无 ENOENT 基线那 25 条):
```
# tests 2641
# pass 2641
# fail 0
# cancelled 0
# skipped 0
# todo 0
exit=0
```
## 改动文件
- `frontend/src/lib/rectification-agentic/v9/adopt-narration-agent.ts`
- `frontend/tests/rectification-adopt-narration-20260904.test.ts`
- `docs/BUG_HISTORY.md`BUG-523
- `docs/tasks/PROGRESS-rectification-adopt-narration-fix-20260904.md`(更正)
- `docs/tasks/README.md`
- 本文件
+1 -1
View File
@@ -46,7 +46,7 @@
| `TASK-rectification-uncertainty-stop-20260903.md` | — | 不确定度停止规则加样本下限 | 已验收 | `0c0df426`BUG-503 |
| `TASK-rectification-adopt-narration-20260904.md` | `PROGRESS-rectification-adopt-narration-20260904.md` | 探针池耗尽时采用卡旁白改 Agent 生成 + 已丢弃探针绕过 BUG-472 早退 + 区分题答否关线 | 已验收(4.1.4 点选入口未通过,见修复单) | `0aaa0d70`BUG-519/520 |
| `TASK-rectification-adopt-narration-fix-20260904.md` | `PROGRESS-rectification-adopt-narration-fix-20260904.md` | 采用旁白 Agent 在点选入口从不运行(早退分支重算过期决策)+ 校验器/可观测/超时 | 已验收(5.1/5.2 实现通过;超时测试挂死事件循环,见修复单 2) | `13dded9f`BUG-521/522 |
| `TASK-rectification-adopt-narration-fix2-20260904.md` | | 采用旁白超时用了 unref 的 `AbortSignal.timeout`,测试挂死取消同文件后三条用例,门禁 `npm test` 退出码 1 | 待执行 | 基线 `13dded9f`BUG-523 |
| `TASK-rectification-adopt-narration-fix2-20260904.md` | `PROGRESS-rectification-adopt-narration-fix2-20260904.md` | 采用旁白超时用了 unref 的 `AbortSignal.timeout`,测试挂死取消同文件后三条用例,门禁 `npm test` 退出码 1 | 待验收 | 基线 `5c9e9879`(任务书写 `13dded9f`BUG-523 |
| `TASK-rectification-ux-20260902.md` | `PROGRESS-rectification-ux-20260903.md` | 会话面空白假死与交互摩擦 | 已验收 | `d159f08e`(09-03 在新基线重做后合入,BUG-505509 |
### 聊天主链路与首页
@@ -33,24 +33,63 @@ export type AdoptNarrationDelivery = Readonly<{
adopt_narration: AdoptNarrationOutcome;
}>;
type DisposableAbort = Readonly<{
signal: AbortSignal;
dispose: () => void;
}>;
function composedAbortSignal(
signal: AbortSignal | undefined,
timeoutMs: number,
): AbortSignal {
const timeout = AbortSignal.timeout(timeoutMs);
return signal ? AbortSignal.any([signal, timeout]) : timeout;
): DisposableAbort {
const controller = new AbortController();
// Must stay ref'd. The platform timeout signal uses an unref timer, so a hanging
// generateText lets the event loop drain before abort (BUG-523).
const timeoutId = globalThis.setTimeout(() => {
if (!controller.signal.aborted) {
controller.abort(new DOMException("adopt narration timed out", "TimeoutError"));
}
}, timeoutMs);
const onExternalAbort = () => {
if (!controller.signal.aborted) {
controller.abort(signal?.reason ?? new DOMException("aborted", "AbortError"));
}
};
if (signal) {
if (signal.aborted) onExternalAbort();
else signal.addEventListener("abort", onExternalAbort);
}
return {
signal: controller.signal,
dispose: () => {
globalThis.clearTimeout(timeoutId);
signal?.removeEventListener("abort", onExternalAbort);
},
};
}
function whenAborted(signal: AbortSignal): Promise<never> {
return new Promise((_, reject) => {
if (signal.aborted) {
function whenAborted(signal: AbortSignal): {
promise: Promise<never>;
dispose: () => void;
} {
let onAbort: (() => void) | undefined;
const promise = new Promise<never>((_, reject) => {
const fail = () => {
reject(signal.reason ?? new Error("aborted"));
};
if (signal.aborted) {
fail();
return;
}
signal.addEventListener("abort", () => {
reject(signal.reason ?? new Error("aborted"));
}, { once: true });
onAbort = fail;
signal.addEventListener("abort", fail, { once: true });
});
return {
promise,
dispose: () => {
if (onAbort) signal.removeEventListener("abort", onAbort);
},
};
}
export function logAdoptNarrationOutcome(outcome: AdoptNarrationOutcome): void {
@@ -117,14 +156,15 @@ export async function deliverAdoptNarration(input: {
logAdoptNarrationOutcome(delivery.adopt_narration);
return delivery;
}
const signal = composedAbortSignal(
const composed = composedAbortSignal(
input.signal,
input.timeoutMs ?? ADOPT_NARRATION_TIMEOUT_MS,
);
const aborted = whenAborted(composed.signal);
try {
const text = await Promise.race([
generate(input.facts, signal),
whenAborted(signal),
generate(input.facts, composed.signal),
aborted.promise,
]);
const checked = validateAdoptNarration(text, input.facts);
if (!checked.ok) {
@@ -145,6 +185,9 @@ export async function deliverAdoptNarration(input: {
const delivery = { text: input.fallback, adopt_narration: "template:model_error" as const };
logAdoptNarrationOutcome(delivery.adopt_narration);
return delivery;
} finally {
aborted.dispose();
composed.dispose();
}
}
@@ -943,6 +943,49 @@ test("adopt narration times out to the template without throwing", async () => {
assert.equal(timed.text, fallback);
});
test("adopt narration does not leave an active timeout after the model returns", async () => {
const dossier = caseDossier();
const decision = decideFromDossier(dossier, { birthDate: "1997-08-08" });
const facts = adoptDeliveryFacts(decision, dossier);
const fallback = "剩下的问题分不开 05:00 和 05:06。可以从下面选一个先用着。";
const kept = "剩下的问题分不开 05:00 和 05:06。范围是 05:00 到 05:06。采用后会用 2016 年学业核对。";
const source = readFileSync(
new URL("../src/lib/rectification-agentic/v9/adopt-narration-agent.ts", import.meta.url),
"utf8",
);
assert.doesNotMatch(source, /AbortSignal\.timeout/);
assert.match(source, /clearTimeout/);
const pending = new Set<unknown>();
let created = 0;
const realSetTimeout = globalThis.setTimeout;
const realClearTimeout = globalThis.clearTimeout;
globalThis.setTimeout = ((handler: TimerHandler, delay?: number, ...args: unknown[]) => {
created += 1;
const id = realSetTimeout(handler, delay, ...args);
pending.add(id);
return id;
}) as typeof setTimeout;
globalThis.clearTimeout = ((id?: ReturnType<typeof setTimeout>) => {
pending.delete(id);
realClearTimeout(id);
}) as typeof clearTimeout;
try {
const delivered = await deliverAdoptNarration({
facts,
fallback,
timeoutMs: 8_000,
generateText: async () => kept,
});
assert.equal(delivered.adopt_narration, "agent");
assert.ok(created >= 1);
assert.equal(pending.size, 0);
} finally {
globalThis.setTimeout = realSetTimeout;
globalThis.clearTimeout = realClearTimeout;
}
});
test("applyCollectFocusDenial on the family collect uses the same adopt template", async () => {
const dossier = caseDossier();
let loads = 0;