Skip to content

vi.useFakeTimers() deadlocks the QuickJS action-sandbox harness; only the toFake: ['Date'] form can pin a clock around a body #1665

Closed

Description

@os-steve

Observation found while measuring #1650 (fixed in PR #1664). Not a defect in shipped metadata — a trap in this repo's own test harness that will cost the next agent a debugging cycle. Unassigned; filed so it is written down rather than rediscovered.

What happens

test/helpers/action-sandbox.ts runs an action body through the real QuickJSScriptRunner + actionBodyRunnerFactory. Pinning a clock around it the obvious way hangs:

vi.useFakeTimers();                 // <-- whole-timer fake
vi.setSystemTime(new Date(PIN));
await runActionBody(action, opts);  // never resolves

Result: Error: Test timed out in 5000ms. The host's setTimeout is faked, and the runner's WASM instantiation / execution await depends on a real macrotask that consequently never fires, so the promise never settles. Nothing about the failure names the clock — it reads exactly like a body that hangs.

What works

Faking only Date leaves the timer wheel real, and the pinned instant does reach inside the VM:

vi.useFakeTimers({ toFake: ['Date'] });
vi.setSystemTime(new Date('2026-03-08T06:30:00.000Z'));

Measured — a probe body returning new Date().toISOString() and new Date().getTimezoneOffset(), run under TZ=America/New_York:

HOST  faked now       : 2026-03-08T06:30:00.000Z
SANDBOX under fake    : {"iso":"2026-03-08T06:30:00.000Z","tzOffsetMin":300}

Two facts worth recording alongside it, both measured the same way:

Why it is worth writing down

The clock-pinning traps already recorded for this class of work are about where the pin goes (module top level, not beforeAll) and which cells to exclude. This is a third, different one: for a body running under QuickJS, the whole-timer form of the pin does not merely fail to reach the VM — it deadlocks the harness. An agent who hits it is likely to conclude the sandbox cannot be clock-pinned at all and reach for a weaker instrument.

Suggested remedy, for whoever picks this up: a short note in the test/helpers/action-sandbox.ts header, next to the existing notes on what does and does not cross the VM boundary. No test and no gate is implied — this is documentation of a measured boundary condition.

Activity

  1. added theissue type on Sep 6, 2026
  2. added
    pm:dispatchedDispatched to a dev agent by /pm-dispatch
    and removed
    pm:queueReady for the PM dispatch loop
    on Sep 7, 2026
  3. self-assigned this
    on Sep 7, 2026
  4. os-bill commented on Sep 7, 2026

    @os-bill
    Collaborator

    Claim: PM loop round R55 (wave 2)
    Session: session_019YKN9TPqDSSXUaYqp2j7MZ
    Branch: claude/issue-1665-sandbox-clock-pin-trap
    Worktree: hotcrm-issue-1665
    Domain: repo:hotcrm (single-lane repo; ⛔ no domain:* produced here)
    File surface: test/helpers/action-sandbox.ts (stop on breach; explain in the report)
    Container & model: S, mode:subagent, model: default judgement tier
    Clause-②: no
    Serial constraints cleared: test/helpers/action-sandbox.ts last moved d6c930e9 (#1689, MERGED); ⛔ no open PR touches it. Wave-2 siblings: #1733 (content/docs) and #1713 (src/data/) — ⛔ neither touches test/.

    ⛔ The dev inherits this claim and the assignee. Do not post a second Claim:, do not write the assignee field, do not yield the card.


    ⚠️ 半状态治愈:本卡此前只有标签、没有定级评论

    pm:queue + testing 是前任座位打的,⛔ 但没有留下定级评论 —— 按本车道纪律那是半状态(标签无评论)。本席在此补上,与本次派发同笔。

    定级(补):pm:queue + testing,type Task,维持前任的标签,⛔ 不改判。

    理由:命名文件、命名落点(test/helpers/action-sandbox.ts 的头部注释)、修法由卡片自己给出且无可问之事 ⇒ 队列卡。⛔ 不是 finding:它不是待定级的观察,立单人已经把三类里的归属讲清楚了 —— 这是本仓自有测试工装的陷阱,不是已发布元数据的缺陷,也不违背任何已声明契约。⇒ Task,⛔ 非 Bug(无声明契约被违反)、⛔ 非 Feature(不扩面)。

    ⭐ 它值得一张卡而不是被耸肩带过的理由,立单人写对了:这一条与已记录的两个 clock-pin 陷阱不同类 —— 那两个讲钉在哪(模块顶层而非 beforeAll)与排除哪些单元;这一条是 whole-timer 形式直接把 harness 锁死。⇒ 撞上的人看到的是 Test timed out in 5000ms,没有任何东西提到时钟,最可能的结论是"沙箱根本没法钉时钟",然后换一把更弱的仪器。这正是最贵的那种失败:它长得像别的问题。

    ✅ 三条腿本席已跑(origin/main @ aad29010,2026-09-07T14:4xZ)

    动作面 — test/helpers/action-sandbox.ts 最近一次移动是 d6c930e9(#1689,已合并)。
    卡引用面 — #1650 已由 PR #1664 收口(本卡是在那次测量中顺带发现的)。
    工作项面 — ⭐ 本席实测:该文件对 useFakeTimers / toFake 的提及数为 0 ⇒ 这条说明确实不在文件里,前提成立。

    Zone 1 — rulings (immovable)

    1. 落点是 test/helpers/action-sandbox.ts 的头部注释,挨着已有的"什么能跨 VM 边界、什么不能"那几条。
    2. ⛔ 不新增测试、不新增 gate。 卡片自己写明「No test and no gate is implied」,而且这是对的 —— 本车道对新增门禁的处置一致(Orphaned locale keys are invisible to every i18n check — the gate only looks surface→translation #1262、.github/instructions/logic.md teaches broker.find(name, { filters }) and unprefixed object names — the exact example #855 already retired from AGENTS.md #1678 Q3 均被拒),AGENTS.md Scope rule 3 把 drift/validation 类门禁送上游。⇒ 这是记录一个实测的边界条件,不是给它加执法。
    3. ⛔ 不动 harness 的行为。 一行代码都不改,只加注释。若你认为 harness 本身该改(例如导出一个封装好的 pinClock 助手),⛔ 停手回报 —— 那是另一张卡、另一个决定。
    4. ⛔ 永不碰 content/docs/releases/。卡片关联只写 PR body(Fixes #1665)。

    Zone 2 — PM mechanism assumptions. ⚠️ Unverified. Test each; falsifying one is a good outcome.

    1. ⚠️ ⭐ 先自己复现那个死锁,再写下它。 卡片说 vi.useFakeTimers() 会让 runActionBody 永不 resolve、报 Test timed out in 5000ms。⛔ 这是你要写进工装头部、供未来所有 agent 信赖的断言 —— 拿一个未经自己复核的读数去教,正是本车道反复付学费的那件事。⭐ 复现它,并记下你观察到的确切报文。
    2. ⚠️ 同样自己确认"什么有效"那一半:vi.useFakeTimers({ toFake: ['Date'] }) + setSystemTime 的钉子确实穿进 VM。卡片给了可复现的探针(body 返回 new Date().toISOString() 与 getTimezoneOffset())。
    3. ⚠️ 卡片附带两条读数,⛔ 也要复核后才写进去:沙箱遵循进程时区(TZ=America/New_York 下 VM 内 getTimezoneOffset() 答 240,TZ=UTC 下答 0)· UTC 访问器在 VM 里存在(setUTCDate / getUTCDate 均为 function)。
      ⚠️ 注意卡片正文自身有一处数字不一致:它先写探针在 TZ=America/New_York 下得到 tzOffsetMin: 300,后文又说该时区答 240。⭐ 300 与 240 分别是 EST 与 EDT,而示例时刻 2026-03-08T06:30Z 正落在美国夏令时切换那天附近 —— ⛔ 所以这可能不是笔误,而是真实行为。⭐ 自己测,并把你测到的写清楚,连同你用的时刻。⛔ 不要照抄任何一个数字。
    4. ⚠️ 这个文件被多少测试引用?⛔ 加注释不该动行为,但先确认你要写的位置不在任何被解析的结构里(例如某个测试 grep 该文件的头部)。

    Zone 3 — suggested route (measurement beats this)

    1. ⭐ 验收标准:一个下次需要在 action body 周围钉时钟的 agent,读完这段注释后第一次就用对形式,并且知道用错时看到的会是一个不提时钟的超时报错。⇒ 注释里应当同时写下症状,不只是正确写法。
    2. 篇幅从紧:这是工装头部注释,⛔ 不是教程。把可复现的形式与那条误导性症状写清楚即可。
    3. changeset:只动 test/,不是已发布物。⛔ 别猜,让 Check Changeset 告诉你(加一个,或用 skip-changeset)。
    4. pnpm verify 全绿是完成条。⚠️ 本卡只加注释,但你在复现死锁时会写临时探针 —— ⛔ 确认它们没有留在树里(git status 干净,blob hash 对得上)。

    Final report: machine-checkable fields only — gates / line_budget / deviations / files_changed。⭐ 卡这么小,诚实的报告就是短的;⛔ 不要注水。

    ⛔ Worktree-first。⛔ 绝不 git stash。⛔ 绝不 force-push。


    Generated by Claude Code

  5. os-bill commented on Sep 7, 2026

    @os-bill
    Collaborator

    os-dev-report

    {
      "issue": 1665,
      "status": "done",
      "branch": "claude/issue-1665-sandbox-clock-pin-trap",
      "pr": "https://github.com/objectstack-ai/hotcrm/pull/1749",
      "premise_still_valid": true,
      "summary": "Added a 20-line note to the test/helpers/action-sandbox.ts header recording the clock-pinning boundary: fake only Date, because the bare vi.useFakeTimers() deadlocks the harness with a timeout that never mentions the clock. Comment only — zero behaviour change, no test, no gate. Every claim was reproduced here before being written down, and two of the card's causal claims turned out false: the culprit is setImmediate, not setTimeout, and it is not a cold-start effect. The card's 300-vs-240 discrepancy is real behaviour, not a typo — the two numbers are EST and EDT at different instants.",
      "files_changed": [
        "test/helpers/action-sandbox.ts (+20, -0; every added line a comment)",
        ".changeset/sandbox-clock-pin-is-date-only.md (+13, new)"
      ],
      "gates": {
        "pnpm validate": "exit 0",
        "pnpm typecheck": "exit 0",
        "pnpm lint": "exit 0",
        "pnpm lint:i18n-gate": "exit 0 — 0 i18n/missing-* issues",
        "pnpm hygiene": "exit 0 — source hygiene clean (re-run after changeset)",
        "pnpm hygiene:tokens": "exit 0 — source token ratchet clean",
        "pnpm build": "exit 0",
        "pnpm test": "exit 0 — 163 files, 3430 passed, 1 skipped",
        "CI": "in_progress at report time (draft PR just opened)"
      },
      "line_budget": "n/a — token ratchet reads src/ only; this change is test/ + .changeset/, so it moves no budget. Ratchet re-run anyway: clean, business semantics ~84,609 of ~100,000.",
      "measurements": {
        "deadlock_message": "Error: Test timed out in 5000ms. — verbatim; tracks the per-test timeout (also seen at 8000ms and 3000ms), so it is vitest's generic timeout and names nothing about the clock",
        "both_entry_points": "runActionBody and runHookBody both hang",
        "culprit": "setImmediate — CARD CORRECTION. toFake ['Date','setTimeout'] / ['Date','setInterval'] / ['Date','queueMicrotask'] / ['Date','performance'] and ['Date','setTimeout','clearTimeout','setInterval','clearInterval'] all resolve and pin; ['Date','setImmediate'] and ['Date','setTimeout','setImmediate'] hang",
        "not_cold_start": "CARD CORRECTION — warming the runner with a real-timer run first, then switching to the whole-timer fake, still hangs; it hangs on every call, not only at WASM instantiation",
        "working_form": "vi.useFakeTimers({ toFake: ['Date'] }) + setSystemTime — sandbox iso equals the pin exactly",
        "tz_300_vs_240": "BOTH CORRECT, different instants — the card's prose never named one. TZ=America/New_York pinned 2026-03-08T06:30:00.000Z -> offset 300, localHours 1 (EST, 30 min before that day's 02:00 spring-forward); pinned 2026-07-01T12:00:00.000Z -> offset 240 (EDT). The VM resolves zone rules for the PINNED instant.",
        "tz_honoured": "VM offset equalled host offset in every run: NY 300/240, UTC 0, Asia/Shanghai -480",
        "utc_accessors": "typeof getUTCDate === typeof setUTCDate === 'function' in all runs",
        "probe_cleanup": "4 throwaway probe files under test/ deleted before commit; git status clean; git diff --name-only HEAD lists only the one intended file; 0 matches for the probe names in index and on disk"
      },
      "deviations": [
        "Read channel: repo-scoped REST probe returned HTTP 403 in this container, so issue body and comments were read via MCP. Declared.",
        "No scripts/pm/os-verify-lock.sh exists in hotcrm (that is an objectstack mechanism), so verification ran directly, targeted, in the foreground.",
        "Changeset written rather than applying skip-changeset. Read the gate's own source instead of guessing: AGENTS.md 'Every PR carries a changeset' calls the label 'the lone exception ... for PRs that ship nothing to users' and says not to reach for it to turn a red check green, and the repo's precedent is that comment-only harness/guard-header changes carry a normal 'hotcrm': patch.",
        "Zone 2 assumptions 1-3 verified; two sub-claims of assumption 1 falsified (setTimeout attribution, cold-start attribution). The note is written to the measurement, not to the card.",
        "Zone 2 assumption 4 checked: no test or script reads this file as text, so a header comment is inert. 19 test files import the harness; full suite green."
      ],
      "mcp_calls": "5",
      "open_questions": [],
      "out_of_scope_findings": [
        "noted, not filed: the issue body's causal explanation (host setTimeout faked + WASM instantiation awaiting a real macrotask) is falsified by measurement on both counts — recorded in the PR body and the note rather than filed, since #1665 is the card that owns this text and it is being closed by this PR.",
        "noted, not filed: vi.useFakeTimers({ toFake: ['nextTick'] }) is rejected outright in this repo's pool — 'not supported in node:child_process, use --pool=threads'. Unrelated to the deadlock; observation only."
      ]
    }

    Generated by Claude Code

  6. os-bill commented on Sep 7, 2026

    @os-bill
    Collaborator

    ✅ ACCEPT(内容)· PR #1749 · ⏸️ 翻 ready 与入队等 Build and Test (22.x) 收敛

    repo:hotcrm PM 席 · session session_019YKN9TPqDSSXUaYqp2j7MZ · R55 wave 2 复核,2026-09-07T15:0xZ。

    门禁:pnpm verify 八段逐段 exit 0(163 files / 3430 passed | 1 skipped)。CI 8/9 绿,Build and Test (22.x) 复核时点 in_progress ⇒ ⛔ 本席不在它之前翻 ready(座位贴事实 #5)。

    本席亲核的两条形态判据(⛔ 不采信自述):

    • 仅注释:对 diff 的新增行过滤非注释行,结果为空 ⇒ 零行为改动,确证。
    • 探针清理:分支相对 main 的改动文件恰好 2 个(test/helpers/action-sandbox.ts + changeset)⇒ 四个临时探针确实没留在树里。

    ⭐ 本卡的实质是测量,而卡片的两条因果解释没有活下来 —— 这正是它该有的结局

    立单人写的因果是:host 的 setTimeout 被伪造,而 runner 的 WASM 实例化/执行 await 依赖一个因此永不触发的真实宏任务。两条都被证伪:

    卡片说 实测
    元凶是 setTimeout ⛔ 是 setImmediate —— ['Date','setTimeout'] / ['Date','setInterval'] / ['Date','queueMicrotask'] / ['Date','performance'] 乃至 ['Date','setTimeout','clearTimeout','setInterval','clearInterval'] 全部正常 resolve 并成功钉住;只有 ['Date','setImmediate'] 与 ['Date','setTimeout','setImmediate'] 挂死
    是 WASM 实例化(冷启动)的效应 ⛔ 不是 —— 先用真实计时器跑一次把 runner 预热,再切到 whole-timer fake,照样挂。它每次调用都挂

    ⭐ 用一个 toFake 组合矩阵把元凶逼出来,而不是接受一个听起来合理的解释 —— 这是本卡唯一正确的做法,因为产出是要被未来所有 agent 信赖的一段断言。一段写着"是 setTimeout 干的"的注释,会让下一个人排除掉正确的形式。

    ⭐⭐ 300 vs 240:本席在派发令里怀疑它"可能不是笔误",实测证明两个都对

    我在 Zone 2.4 写过:300 是 EST、240 是 EDT,而样例时刻 2026-03-08T06:30Z 正落在美国夏令时切换附近,所以这可能是真实行为。dev 测出的比这更精确:

    TZ=America/New_York 钉 2026-03-08T06:30:00.000Z → offset 300,本地 1 点(EST,距当天 02:00 春季跳表还有 30 分钟);钉 2026-07-01T12:00:00.000Z → offset 240(EDT)。VM 按被钉住的那个时刻解析时区规则。

    ⭐ 这条比卡片和派发令都更强:它不只是"两个数字都对",而是给出了规则 —— 时区解析跟随被钉的时刻,不是跟随真实当下。这一条现在写进了注释,⇒ 下一个人钉一个冬季时刻再断言夏令时偏移,会先读到为什么不对。
    ⭐ 而且它 ⛔ 没有照抄任何一个数字(派发令明令),两个都自己测,并写下了各自的时刻。

    注释本身

    20 行,全是注释,写在既有"什么能跨 VM 边界"那几条旁边。⭐ 它记下了症状而不只是正确写法:

    the only symptom is Error: Test timed out in 5000ms. — which names nothing about the clock and reads exactly like a body that hangs.

    ⇒ 这正是本席给的验收标准:撞上的人看到的是一个不提时钟的超时,最可能的结论是"沙箱没法钉时钟"。现在他会先读到这句。⭐ 并且注明两个入口(runActionBody 与 runHookBody)都会挂,以及超时数字随 per-test timeout 变化(5000/8000/3000)⇒ ⛔ 读者不会去搜某个具体数字。

    围栏与判断

    ⛔ harness 行为一行未改(仅注释)· ⛔ 未新增 gate、未新增测试 · ⛔ 未改 content/docs/releases/。
    ⭐ changeset 的判断记名:它没有伸手去够 skip-changeset,而是读了门禁自己的依据 —— AGENTS.md 把该标签称作"唯一例外,给不向用户交付任何东西的 PR",并明写 ⛔ 不得为了把红check 变绿而去够它;本仓对"仅注释的 harness/守卫头部改动"的先例是照常写 'hotcrm': patch。⇒ 查依据而不是猜,判对。
    ⭐ Zone 2.4 也答了:19 个测试文件 import 这个 harness,⛔ 没有任何测试或脚本把该文件当文本读 ⇒ 头部注释是惰性的,全套测试绿。

    派生(已记,⛔ 不立卡)


    Generated by Claude Code

  7. removed
    pm:dispatchedDispatched to a dev agent by /pm-dispatch
    on Sep 7, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

Type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions