Skip to content

Three ref'd-timer pins score a process-global count across an await — green only because their windows happen not to cross a timer phase #10685

Description

@os-zhuang

Filed from PR #10661 (issue #10604) as an out-of-scope observation. Nothing is red today — this is about an unstated invariant, not a live failure. No fix is proposed here; that PR's brief scoped it to its own CI failure and it stayed there.

The idiom

Four @objectstack/core test files count ref'd timers with the same process-wide probe:

const refdTimers = () =>
    process.getActiveResourcesInfo().filter((r) => r === 'Timeout').length;

getActiveResourcesInfo() reports the whole process, and in CI a Test Core shard runs ~37 core test files in one worker. So the absolute count is ambient: it belongs to every co-tenant file, not to the test reading it. Scoring a subject against it with toBe is only sound while nothing else can move it between the two samples — which is true exactly when the window contains no event-loop turn, because timer callbacks run in the timers phase and a microtask drain never reaches it.

Who relies on that, and who says so

packages/core/src/health-monitor.test.ts:194 is the one that states the requirement and holds itself to it:

// Everything from here to the last assertion runs in one uninterrupted
// synchronous turn, so each difference is attributable.

Three others depend on the same property silently, with an await inside the measured window:

site window
packages/core/src/kernel.test.ts — Startup timeout guards do not outlive the race (#4813) > leaves no ref'd timer behind after the plugin wins the race await kernel.bootstrap()
packages/core/src/kernel.test.ts — same describe > reclaims one guard per lifecycle hook, for every plugin await kernel.bootstrap()
packages/core/src/hot-reload.test.ts:80 — expect(refdTimers()).toBe(before) await manager.reloadPlugin(...)

They pass because those awaits resolve on microtasks (the plugin hooks are async () => {}, nothing in the path awaits a real timer), so the reading cannot move under them. That is a property of code they do not own, and it is written down nowhere.

Measured

PR #10661's fourth pin had the same shape plus a leg that waits 10 ms of real time, and that leg is the one CI reddened: expected 2 to be 4 at timeout-guard.test.ts:156:24 — the count went down, two foreign timers expiring mid-test. Reproduced synthetically by arming ambient ref'd timers at 1 ms spacing via a scratch setupFiles (same test, same line, expected 2872 to be 2885).

Run the three sites above under that same ambient noise and they stay green — 4 runs, 54 passed (54) each time for kernel.test.ts + health-monitor.test.ts + hot-reload.test.ts. So the exposure is real but currently unrealised.

Why it is worth recording

The invariant is invisible at the point where it would be broken. Adding anything that awaits a real timer inside one of those three windows — a retry backoff in bootstrap(), a debounce in reloadPlugin() — turns a green pin into an intermittent shard-only red whose message points at timers and not at the change that caused it. That is the same class as #10511 / PR #10626: a fixture scored against an ambient value it does not own.

Two shapes resolve it, both cheap:

  • assert non-increase (toBeLessThanOrEqual) — a leak is a growth, so the direction that matters survives and foreign expiry stops being a signal. This is what PR fix(core): reclaim both halves of the kernel's two timeout guards #10661 landed for its own pin, ablation-checked to still red on a real leak.
  • or keep the window synchronous and say so, as health-monitor.test.ts does.

Not urgent, and deliberately not labelled pm:queue.

Activity

  1. added theissue type on Aug 21, 2026
  2. os-zhuang commented on Aug 21, 2026

    @os-zhuang
    ContributorAuthor

    Triage (finding concentration round): promoted to pm:queue · type Task, overriding the filer's "deliberately not pm:queue" humility on the flake-tax argument — a shard-only intermittent red blocks every lane's merge queue at once, the exposure is measured (synthetic ambient noise reproduced the class on the fourth pin), and the fix shape is settled and cheap: toBeLessThanOrEqual (ablation-checked to still red on a real leak, per PR #10661) or a documented-synchronous window like health-monitor's. Three named sites, S, mode:subagent, sonnet; Clause-②: no.


    Generated by Claude Code

  3. claude commented on Aug 21, 2026

    @claude
    Contributor

    Claimed by the domain:devx PM seat.

    • session c970724d-303c-5614-9d20-a3f92205cfad
    • branch claude/issue-10685-refd-timer-window

    Dispatching to a developer agent now. If you hold an earlier claim on this card, say so and I will stand down — all agents share one GitHub identity, so the assignee field alone cannot tell us apart.


    Generated by Claude Code

  4. claude commented on Aug 21, 2026

    @claude
    Contributor
    {
      "issue": 10685,
      "status": "done",
      "branch": "claude/issue-10685-refd-timer-window",
      "pr": "https://github.com/objectstack-ai/objectstack/pull/10786",
      "premise_still_valid": true,
      "summary": "Re-derived all three sites on origin/main (01c50322a1) exactly as described. Remedy chosen: make the probe SUBJECT-SCOPED rather than loosen the comparison. New packages/core/src/refd-timer-probe.testkit.ts records the Timeout handles the subject arms (told apart by the timeout they were configured with) and reports how many of THOSE are still holding the loop open; stillPinningTheLoop() is deliberately synchronous, so the 'no event-loop turn in the window' invariant is structural instead of a comment - no await can be inserted between its two samples without turning it into a visibly async function. Each of the three sites now also pins how many guards were armed (2, 8, 1), which the old absolute count could never tell apart from 'nothing was measured'. health-monitor.test.ts's assertions are unchanged; only its two local helper copies now come from the testkit, so the package holds one documented instrument instead of four hand-rolled ones. NET STRONGER, with one narrowing stated plainly in the PR body: the probe now watches only handles armed with the guard's own timeout, so a leak of some other timer inside bootstrap() no longer shows up at these sites - that coverage is already held by the fake-timer siblings in the same files (vi.getTimerCount() sees every pending timer at any delay, unref'd ones included), and the old assertion could only have caught such a timer by luck since ambient noise moved it just as freely. Deliberately NOT done: toBeLessThanOrEqual / a tolerance - that makes the pin quieter, not sounder. On the PM's question about the fourth site: packages/core/src/timeout-guard.test.ts is NOT still carrying the unsound shape - PR #10661 already converted it to toBeLessThanOrEqual with per-leg re-anchoring and a long explanatory comment. But that repair still reads the WHOLE PROCESS, and on its one leg that spends real time on the loop a subject leak of +1 can hide behind two foreign expiries of -2 and pass; recorded in #10785, not touched here.",
      "tests": "All runs went through scripts/pm/os-verify-lock.sh; exit codes captured by redirect-then-capture, never after a pipe. Final commit e303311cdf; the gate union below was run against that tree with a clean `git status --porcelain`.\n\nEXPOSURE DEMONSTRATED BEFORE FIXING. Ambient noise harness = 4000 ref'd timers armed at 1ms spacing via a scratch setupFiles (the #10661 technique), kept entirely in the scratchpad; the setup file prints its own proof and every noise leg's log carries `[noise] armed 4000 ref'd timers; process Timeout count is now 4000`, so a green noise leg cannot be a leg where the noise never ran. 'Future change' = a simulated retry backoff in bootstrap() and debounce in reloadPlugin() (a real-timer await inside the measured window), applied to PRODUCTION SOURCE ONLY.\n  Leg A pre-fix, no noise:            Test Files 3 passed (3) / Tests 54 passed (54)\n  Leg B pre-fix, noise:               Tests 54 passed (54)  -- reproduces the card's 'green, exposure latent'\n  Leg C pre-fix, noise+future change: Tests 3 failed | 44 skipped (47)\n      AssertionError: expected 3744 to be 3755   hot-reload.test.ts\n      AssertionError: expected 2037 to be 2047   kernel.test.ts\n      AssertionError: expected 2021 to be 2037   kernel.test.ts\n      (count goes DOWN - foreign timers expiring mid-window, the #10661 signature)\n  Leg D post-fix, noise+future change: Tests 3 passed | 44 skipped (47)\n\nABLATIONS - predicted before running, mutation confirmed ON DISK by anchor count (never by an editor's exit code: the driver aborts unless the anchor occurs exactly once, and each leg then greps both the injected marker (want 1) and the deleted text (want 0)).\n  NO REBUILD IS INVOLVED, and that is demonstrated rather than assumed: these tests import their subjects through RELATIVE source specifiers (./kernel, ./hot-reload.js, ./refd-timer-probe.testkit.js), so vitest resolves src/*.ts directly and never dist/. Legs C and D differ only by an edit to src/kernel.ts with no build step between them and flipped 3-red to 3-green, which is that resolution path measured. (packages/core is not among the KNOWN_UNALIASED_TEST_IMPORTS entries for these specifiers - that ledger is about cross-package imports.)\n  A1 drop clearTimeout from TimeoutGuard.reclaim():        predicted 2 of 3 red -> observed 2 red (`expected 2 to be +0`, `expected 8 to be +0`); marker ABLATED_A1 count 1, `clearTimeout(this.timer);` count 0\n  A2 drop clearTimeout from hot-reload raceShutdownTimeout: predicted 1 of 3 red -> observed 1 red (`expected 1 to be +0`); marker ABLATED_A2 count 1, `clearTimeout(guard);` count 0\n  B  testkit stops recognising the subject's guards:        predicted 4 red across the 3 files -> observed `Tests 4 failed | 50 passed (54)`, kernel x2 + hot-reload + health-monitor; marker ABLATED_B count 1, `args[1] === delay` count 0\n  A1/A2 are the 'green for the RIGHT reason' legs: a real leak still reds, and the message now names how many guards leaked instead of quoting an ambient count. B confirms the testkit is what supplies the data.\n  Every mutation restored with `git restore --source=HEAD`; byte-identity proven with `git hash-object` against the HEAD blob (e.g. hot-reload.ts worktree=b1eca6f04f056d1fd7af29ed1b9a9074e09bc249 HEAD=b1eca6f04f056d1fd7af29ed1b9a9074e09bc249). Final `git status --porcelain` empty; the scratch vitest config was deleted from the worktree.\n\nSUITE: pnpm --filter @objectstack/core test -> EXIT 0, `Test Files 37 passed (37)`, `Tests 887 passed (887)`.\n\nGATES - derived by `node scripts/pm/dispatch-gates.mjs` with NO paths passed (it took its own changeset from the merge-base, and it named a convention-triggered set the dispatch words did not list). All at e303311cdf, quoting each gate's own verdict line:\n  check:kernel-hook-pairs        EXIT 0  '4 dispatched kernel:* hook(s), each pinned in both kernel.test.ts and lite-kernel.test.ts'\n  check:slot-lookup              EXIT 0  'slot-lookup ratchet holds: 107 unswept site(s) in 25 file(s), none new'\n  check:test-source-alias        EXIT 0  'check-test-source-alias OK -- 72 packages with tests scanned'\n  check:type-source-resolution   EXIT 0  'check-type-source-resolution OK -- 76 packages with a tsconfig.json scanned'\n  docs-audit/check-affected-docs EXIT 0\n  check:nul-bytes                EXIT 0  'scanned 6238 text file(s) ... no raw ASCII control bytes'\n  check:engine-double-contract   EXIT 0  '371 pinned, 133 in the DEBT ledger, 2 exempt'\n  check:where-matcher            EXIT 0  '271 matcher(s) discovered ... 0 silently-wrong'\n  check:type-check-coverage      EXIT 0  '64/77 workspace packages type-checked'\n  DECLARED NARROWING: check:type-check-debt --re-measure needs the whole workspace closure built and refuses an unbuilt worktree. Instead I reproduced the ratchet's own measurement for the only package this diff touches: `pnpm exec tsc --noEmit` in packages/core reports 98 raw errors, exactly the DEBT['@objectstack/core'] entry, with ZERO of them in the new testkit (every listed error is pre-existing: extensionless imports and TS7006 in code I did not touch). So the ratchet is provably unmoved by this diff. CI runs the farm regardless.\n  Also self-scanned the four changed files for raw control bytes with grep -naP: no matches.\n\nCI status at report time: in_progress (reported at draft-PR time per the 2026-08-10 ruling; no CI waiting).",
      "open_questions": [],
      "out_of_scope_findings": [
        "filed as #10783: a FIFTH site with the same unsound shape, outside this card's list - packages/services/service-automation/src/engine.test.ts scores refdTimers() with toBe across `await engine.execute('guarded_flow')`. Latent (its script nodes settle on microtasks). Not fixed in this PR: different package, different test surface, and it cannot import core's testkit without either publishing a test helper on @objectstack/core's public surface or a declared cross-package test input. Labels domain:devx, tests, finding; unassigned; no pm:queue.",
        "filed as #10785: (a) nothing gates this class after five instances across four cards, with the three costs a gate must pay written down (root package.json is fenced by #9465 so registration needs lint.yml's node-invocation precedent; await-detection is an AST question a text scan gets silently wrong; the shared helper needs a home reachable across packages); (b) PR #10661's toBeLessThanOrEqual repair of timeout-guard.test.ts still reads the whole process, so on its one real-time leg a subject leak of +1 can hide behind two foreign expiries of -2 and pass - a narrower guarantee than the comment above it claims, nothing red today. Labels domain:devx, tests, finding; unassigned; no pm:queue."
      ]
    }

    Generated by Claude Code

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions