diff --git a/.github/workflows/lint.yml b/.github/workflows/lint.yml index c2f0d5c7ac..298768bbb1 100644 --- a/.github/workflows/lint.yml +++ b/.github/workflows/lint.yml @@ -1834,6 +1834,33 @@ jobs: - name: Test-source alias gate run: pnpm check:test-source-alias + # The process-global ref'd-timer probe lives in ONE module (#10785). A + # `'Timeout'` count derived from `getActiveResourcesInfo()` reports the + # WHOLE process, so comparing two readings across an `await` scores a + # subject against a number the test does not own — every co-tenant file's + # timers and the runner's own non-unref'd 100ms throttle. The shape was + # found FIVE times over four cards and repaired at the site each time; + # twice the first signal was a shard-only intermittent red (once in CI, + # `expected 2 to be 4`; once in the MERGE QUEUE, where it stalls every + # lane at once) whose message names a timer count rather than the change + # that caused it. Nothing prevented the sixth. + # ⛔ The rule is deliberately NOT "is there an `await` between these two + # readings" — that is an AST question, and a text scan that answers it + # approximately fails SILENTLY on spellings it does not know, which is the + # failure mode AGENTS.md already records for source-scanning gates. This + # bans the RAW PROBE outside the one approved module instead: a + # grep-level question, a one-entry allowlist, and a RED default that names + # the file, the line and the import to write. Matched by IDENTIFIER rather + # than by `process.`-receiver, so a destructure or a `node:process` named + # import cannot slip past; comments are masked, so the docblocks that must + # NAME the probe to explain the rule do not have to dodge the scanner. + # A clean run also asserts the approved module is present and still reads + # the probe — otherwise "nobody reads it" would be true of a tree where + # the instrument was deleted. + # Static scan of ~4.8k sources; sub-second. + - name: Ref'd-timer probe containment + run: pnpm check:refd-timer-probe + # The TYPE axis of the same invariant (#8180). The gate above reads # `vitest.config.*` and nothing else, so the identical exposure on the # type axis was unguarded repo-wide — and its symptom is likewise a GREEN diff --git a/package.json b/package.json index a003b2dbca..fadf55e063 100644 --- a/package.json +++ b/package.json @@ -103,6 +103,7 @@ "check:examples-live-imports": "node scripts/check-examples-live-imports.mjs --self-test && node scripts/check-examples-live-imports.mjs", "examples:live-imports": "node scripts/check-examples-live-imports.mjs --list", "check:test-source-alias": "node scripts/check-test-source-alias.mjs --self-test && node scripts/check-test-source-alias.mjs", + "check:refd-timer-probe": "node scripts/check-refd-timer-probe.mjs --self-test && node scripts/check-refd-timer-probe.mjs", "check:type-source-resolution": "node scripts/check-type-source-resolution.mjs --self-test && node scripts/check-type-source-resolution.mjs", "check:published-files": "node scripts/check-published-files.mjs --self-test && node scripts/check-published-files.mjs", "check:published-readme-exports": "node scripts/check-published-readme-exports.mjs --self-test && node scripts/check-published-readme-exports.mjs", diff --git a/packages/core/package.json b/packages/core/package.json index daa56a2c38..7cab7e0463 100644 --- a/packages/core/package.json +++ b/packages/core/package.json @@ -25,6 +25,7 @@ }, "devDependencies": { "@objectstack/metadata-core": "workspace:*", + "@objectstack/refd-timer-testkit": "workspace:*", "@types/node": "^26.2.0", "esbuild": "^0.28.2", "typescript": "^6.0.3", diff --git a/packages/core/src/health-monitor.test.ts b/packages/core/src/health-monitor.test.ts index 94b2c22f14..25d8c9cfe1 100644 --- a/packages/core/src/health-monitor.test.ts +++ b/packages/core/src/health-monitor.test.ts @@ -7,7 +7,7 @@ import { recordGuards, refdTimeouts, stillPinningTheLoop, -} from './refd-timer-probe.testkit.js'; +} from '@objectstack/refd-timer-testkit'; describe('PluginHealthMonitor', () => { let monitor: PluginHealthMonitor; @@ -123,7 +123,7 @@ describe('PluginHealthMonitor', () => { /** * The instrument these pins measure with lives in - * `refd-timer-probe.testkit.ts`, together with the argument for its shape: + * `@objectstack/refd-timer-testkit`, together with the argument for its shape: * `getActiveResourcesInfo()` is PROCESS-global, so two readings are only * comparable across a window that crosses no event-loop turn — the very * property this suite states below and the one three sibling pins were diff --git a/packages/core/src/hot-reload.test.ts b/packages/core/src/hot-reload.test.ts index ea0db7d03d..c4ebc61b9a 100644 --- a/packages/core/src/hot-reload.test.ts +++ b/packages/core/src/hot-reload.test.ts @@ -5,7 +5,7 @@ import { HotReloadManager } from './hot-reload.js'; import type { ObjectLogger } from './logger.js'; import type { Plugin } from './types.js'; import type { HotReloadConfigParsed } from '@objectstack/spec/kernel'; -import { recordGuards, stillPinningTheLoop } from './refd-timer-probe.testkit.js'; +import { recordGuards, stillPinningTheLoop } from '@objectstack/refd-timer-testkit'; /** Records `error` reports; every other level is dropped. `child()` is self. */ function createRecordingLogger(errors: { message: string; error?: unknown }[]): ObjectLogger { @@ -73,7 +73,7 @@ describe('HotReloadManager', () => { manager.registerPlugin('guarded-plugin', config); // The guard is named by the timeout it was armed with rather than - // counted out of the process — `refd-timer-probe.testkit.ts` explains + // counted out of the process — `@objectstack/refd-timer-testkit` explains // why `reloadPlugin()`'s `await` makes an absolute count unsound (#10685). let reloaded = false; const guards = await recordGuards(config.shutdownTimeout, async () => { diff --git a/packages/core/src/kernel.test.ts b/packages/core/src/kernel.test.ts index a638cfcca4..7efd0060cc 100644 --- a/packages/core/src/kernel.test.ts +++ b/packages/core/src/kernel.test.ts @@ -2,7 +2,7 @@ import { describe, it, expect, beforeEach, afterEach, vi } from 'vitest'; import { ObjectKernel } from './kernel'; import { ServiceLifecycle, PluginMetadata } from './plugin-loader'; import type { Plugin, PluginContext } from './types'; -import { recordGuards, stillPinningTheLoop } from './refd-timer-probe.testkit.js'; +import { recordGuards, stillPinningTheLoop } from '@objectstack/refd-timer-testkit'; describe('ObjectKernel', () => { let kernel: ObjectKernel; @@ -243,7 +243,7 @@ describe('ObjectKernel', () => { /** * The real value that hung one-shot CLI processes: ObjectQLPlugin's. * It is also what tells these guards apart from every other timer on - * the shared loop — see `refd-timer-probe.testkit.ts`, which explains + * the shared loop — see `@objectstack/refd-timer-testkit`, which explains * why these pins name their guards instead of counting the process * (#10685). */ diff --git a/packages/core/src/timeout-guard.test.ts b/packages/core/src/timeout-guard.test.ts index 7211e00bf1..26f4ea4984 100644 --- a/packages/core/src/timeout-guard.test.ts +++ b/packages/core/src/timeout-guard.test.ts @@ -2,6 +2,11 @@ import { describe, it, expect, afterEach, vi } from 'vitest'; import { TimeoutGuard, raceWithTimeout } from './timeout-guard.js'; +import { + recordGuards, + refdTimeouts, + stillPinningTheLoop, +} from '@objectstack/refd-timer-testkit'; /** * A guard has two reclaimable halves — the TIMER and the PROMISE — and the @@ -14,9 +19,6 @@ describe('TimeoutGuard (#4813, #10604)', () => { vi.useRealTimers(); }); - const refdTimers = () => - process.getActiveResourcesInfo().filter((r) => r === 'Timeout').length; - /** * Whether `expiry` has SETTLED, decided without hanging the suite: a * settled promise runs its reaction in the current microtask drain, which @@ -85,13 +87,19 @@ describe('TimeoutGuard (#4813, #10604)', () => { // loop, Node exits before an unref'd guard can report the timeout // (#4813). A leak-free kernel that no longer enforces its timeouts // is strictly worse than the leak. - const before = refdTimers(); + // `refdTimeouts()` is the RAW, process-global reading, and it is + // sound here for the one reason it is ever sound: this whole window + // is synchronous. No `await` sits between the samples, so no timer + // callback can run between them and the ambient value cancels + // exactly. Adding an `await` anywhere below silently invalidates it + // — that is when `recordGuards`/`stillPinningTheLoop` is the answer. + const before = refdTimeouts(); const guard = new TimeoutGuard(120_000, () => new Error('must not fire')); - expect(refdTimers()).toBe(before + 1); + expect(refdTimeouts()).toBe(before + 1); guard.reclaim(); - expect(refdTimers()).toBe(before); + expect(refdTimeouts()).toBe(before); }); it('builds the timeout error only when the guard actually fires', async () => { @@ -139,42 +147,80 @@ describe('raceWithTimeout (#10604)', () => { }); /** - * ⚠️ `process.getActiveResourcesInfo()` is PROCESS-wide, and in CI this file + * ⚠️ Why this no longer reads the process-global count at all (#10785). + * + * `process.getActiveResourcesInfo()` is PROCESS-wide, and in CI this file * shares one worker with three dozen others — so the absolute count is * AMBIENT and this test does not own it. Foreign timers alive at the sample * expire while this test awaits, pulling the reading DOWN: the shard read - * `expected 2 to be 4` on the third leg (#10661), the only one that spends + * `expected 2 to be 4` on the third leg (#10604), the only one that spends * real time on the loop (the first two settle on microtasks, where no timer * phase can run and the reading cannot move under the test). * - * A leak is a GROWTH, so the assertion is about the direction the SUBJECT - * can move the count, never the ambient value. Non-increase keeps every bit - * of the detection — an unreclaimed 120s guard is `+1` here, which is what - * ablating the `clearTimeout` half reds — and gives up only the decrease, - * which nothing `raceWithTimeout` does can cause. Each leg re-anchors on its - * own sample so a comparison spans one outcome instead of the whole test. + * #10661 repaired that by asserting NON-INCREASE, on the reasoning that a + * leak is a GROWTH so the direction that matters survives while foreign + * expiry stops being a signal. That decision was deliberate and correct as + * far as it went — and it is superseded here rather than reverted, because + * the reading it kept is still the whole process, and the arithmetic + * composes the wrong way on the one leg that spends real time on the loop: + * + * subject leaks +1 + * two foreign timers expire -2 + * reading before - 1 => toBeLessThanOrEqual PASSES + * + * A real leak, green. Nothing was ever red from this — the ablation cited + * on #10661 does red, run without ambient noise — but under shard load the + * detection is probabilistic rather than certain, which is a narrower + * guarantee than the comment above it claimed. + * + * The instrument removes the ambience instead of choosing a direction that + * survives it: `recordGuards` captures the `Timeout` handles THIS subject + * arms, told apart from every other timer on the shared loop by the very + * timeout they were configured with, and `stillPinningTheLoop` reports how + * many of those are still holding the loop open across a window that is + * synchronous by construction. So the assertion is `toBe(0)` again — an + * exact count of the subject's OWN leak, immune to foreign expiry in either + * direction, on all three legs including the one that burns 10ms of real + * time. `@objectstack/refd-timer-testkit` carries the full argument. + * + * ⚠️ The third leg's guard is SUPPOSED to fire — that is how the race is + * decided — so what it pins is different from the first two and is stated + * rather than implied: exactly one guard is armed for the losing race, and a + * fired guard reclaims itself (`stillPinningTheLoop` counts what a + * `clearTimeout` can still take away, and a timer that already ran is gone + * either way). The `clearTimeout`-half leak is detected by the first two + * legs, whose 120s guards are `+1` there when `reclaim()` stops clearing. * * ⛔ Do not "fix" the ambience by isolating this file or pinning the shard * layout: that would make the pin's validity a property of the runner * config rather than of its own assertion. */ it('leaves no ref\'d timer behind on any of the three outcomes', async () => { - const refd = () => process.getActiveResourcesInfo().filter((r) => r === 'Timeout').length; - let before = refd(); - - await raceWithTimeout(Promise.resolve('ok'), 120_000, () => new Error('must not fire')); - expect(refd()).toBeLessThanOrEqual(before); - - before = refd(); - await expect( - raceWithTimeout(Promise.reject(new Error('x')), 120_000, () => new Error('must not fire')), - ).rejects.toThrow('x'); - expect(refd()).toBeLessThanOrEqual(before); - - before = refd(); - await expect( - raceWithTimeout(new Promise(() => {}), 10, () => new Error('hung')), - ).rejects.toThrow('hung'); - expect(refd()).toBeLessThanOrEqual(before); + // Leg 1 — the operation wins. Each leg re-anchors on its own recording, + // so a verdict spans one outcome instead of the whole test. + const won = await recordGuards(120_000, () => + raceWithTimeout(Promise.resolve('ok'), 120_000, () => new Error('must not fire')), + ); + expect(won).toHaveLength(1); + expect(stillPinningTheLoop(won)).toBe(0); + + // Leg 2 — the operation rejects. + const threw = await recordGuards(120_000, async () => { + await expect( + raceWithTimeout(Promise.reject(new Error('x')), 120_000, () => new Error('must not fire')), + ).rejects.toThrow('x'); + }); + expect(threw).toHaveLength(1); + expect(stillPinningTheLoop(threw)).toBe(0); + + // Leg 3 — the guard wins, after 10ms of real time on the loop. The leg + // #10661 had to weaken; it needs no weakening now. + const fired = await recordGuards(10, async () => { + await expect( + raceWithTimeout(new Promise(() => {}), 10, () => new Error('hung')), + ).rejects.toThrow('hung'); + }); + expect(fired).toHaveLength(1); + expect(stillPinningTheLoop(fired)).toBe(0); }); }); diff --git a/packages/qa/refd-timer-testkit/package.json b/packages/qa/refd-timer-testkit/package.json new file mode 100644 index 0000000000..f81c916523 --- /dev/null +++ b/packages/qa/refd-timer-testkit/package.json @@ -0,0 +1,33 @@ +{ + "name": "@objectstack/refd-timer-testkit", + "version": "0.1.0", + "private": true, + "license": "Apache-2.0", + "description": "The subject-scoped instrument the ref'd-timer leak pins measure with (#4813, #6329, #10604, #10685, #10783). A process-global `getActiveResourcesInfo()` timer count is ambient — it belongs to every co-tenant test file in the worker — so this records the handles the SUBJECT arms and asks how many of those still pin the loop, across a window that is synchronous by construction. Not published; the one home `pnpm check:refd-timer-probe` allows the raw probe to be read from.", + "type": "module", + "exports": { + ".": "./src/index.ts" + }, + "scripts": { + "typecheck": "tsc --noEmit" + }, + "devDependencies": { + "@types/node": "^26.2.0", + "typescript": "^6.0.3" + }, + "keywords": [ + "objectstack", + "qa", + "testkit", + "event-loop", + "timers" + ], + "author": "ObjectStack", + "repository": { + "type": "git", + "url": "https://github.com/objectstack-ai/objectstack.git", + "directory": "packages/qa/refd-timer-testkit" + }, + "homepage": "https://objectstack.ai/docs", + "bugs": "https://github.com/objectstack-ai/objectstack/issues" +} diff --git a/packages/core/src/refd-timer-probe.testkit.ts b/packages/qa/refd-timer-testkit/src/index.ts similarity index 71% rename from packages/core/src/refd-timer-probe.testkit.ts rename to packages/qa/refd-timer-testkit/src/index.ts index a8cc03c9c1..6cd305d811 100644 --- a/packages/core/src/refd-timer-probe.testkit.ts +++ b/packages/qa/refd-timer-testkit/src/index.ts @@ -61,9 +61,51 @@ * instead: that would make a pin's validity a property of the runner config * rather than of its own assertion. * - * `.testkit.ts`, not `.test.ts`: it holds no assertions and must not be - * collected as a suite. It is imported only by tests, so tsup (entries - * `src/index.ts` and `src/logger.ts`) never bundles it into `dist`. + * ## This module is the ONLY place the raw probe may be read (#10785) + * + * `pnpm check:refd-timer-probe` enforces that repo-wide, by identifier and with + * comments masked, and its allowlist is this one file. The rule is deliberately + * the cheap one — ban the raw probe outside one approved module — rather than + * the precise-sounding "no `await` between two readings", which is an AST + * question that a text scan answers approximately and therefore SILENTLY; the + * gate's own header carries that argument and the five-instance table behind it. + * + * ⛔ Do not fork a copy of this file into another package. A second copy leaves + * two instruments with one argument between them, which is how the argument + * gets lost. + * + * ## Why it lives in a private package of its own (#10783) + * + * It sat in `packages/core/src/` until a FIFTH site turned up in + * `@objectstack/service-automation` and could not reach it — `@objectstack/core` + * exports exactly `.` and `./logger`. The three ways out were MEASURED rather + * than argued: + * + * - A test-only RELATIVE import into `packages/core/src` puts a foreign file + * into the consumer's tsc program, and that consumer's `rootDir` rejects it: + * `TS6059`, counted against `@objectstack/service-automation`'s frozen + * type-check debt (measured 3 → 4), a ledger that is shrink-only with no + * tolerance band and whose only other remedy is ⛔ MAINTAINER-ONLY. Most + * packages here set `rootDir: src`, so this was a trap for the next adopter + * too, not a quirk of one manifest. + * - Publishing it on `@objectstack/core`'s `exports` map would put a test + * helper on a runtime package's PUBLIC npm surface, under semver, for every + * consumer of the kernel — capability expansion with no external pull. + * - A bare specifier resolved through `node_modules` is exempt from `rootDir` + * (measured, with `--noEmit` and with emit), so a private workspace package + * is reachable from any consumer whatever its own build config says. + * + * Hence: `private: true`, no build step, `exports` straight at `src` — there is + * no `dist` for a consumer to go stale against, which is the exposure + * `check:test-source-alias` exists for. Every consumer takes it as a + * `devDependency`, and turbo hashes it through that edge rather than through a + * hand-written input glob: measured on `turbo run test --dry=json`, editing this + * file moves `@objectstack/service-automation#test`'s hash + * (`ee8253e9cb374faa` → `77680cb1d4bdd2d4`), so the cache cannot replay a green + * over a changed instrument. + * + * `src/index.ts` holding no assertions is load-bearing: it must never be + * collected as a suite, and this package declares no `test` script at all. * * ⚠️ Real timers only. Under `vi.useFakeTimers()` the handles are fakes and * `getActiveResourcesInfo()` cannot see them — use `vi.getTimerCount()` there, diff --git a/packages/qa/refd-timer-testkit/tsconfig.json b/packages/qa/refd-timer-testkit/tsconfig.json new file mode 100644 index 0000000000..4edce1722a --- /dev/null +++ b/packages/qa/refd-timer-testkit/tsconfig.json @@ -0,0 +1,17 @@ +{ + "extends": "../../../tsconfig.json", + "compilerOptions": { + "outDir": "./dist", + "rootDir": "./src", + "types": [ + "node" + ] + }, + "include": [ + "src/**/*" + ], + "exclude": [ + "node_modules", + "dist" + ] +} diff --git a/packages/services/service-automation/package.json b/packages/services/service-automation/package.json index bae3224def..7762aa89ec 100644 --- a/packages/services/service-automation/package.json +++ b/packages/services/service-automation/package.json @@ -27,6 +27,7 @@ "@objectstack/metadata-core": "workspace:*", "@objectstack/objectql": "workspace:*", "@objectstack/plugin-security": "workspace:*", + "@objectstack/refd-timer-testkit": "workspace:*", "@objectstack/service-job": "workspace:*", "@objectstack/service-messaging": "workspace:*", "@types/node": "^26.2.0", diff --git a/packages/services/service-automation/src/engine.test.ts b/packages/services/service-automation/src/engine.test.ts index c5e0d366a0..4a89187430 100644 --- a/packages/services/service-automation/src/engine.test.ts +++ b/packages/services/service-automation/src/engine.test.ts @@ -9,6 +9,13 @@ import { InMemorySuspendedRunStore } from './suspended-run-store.js'; import type { NodeExecutor } from './engine.js'; import type { IAutomationService } from '@objectstack/spec/contracts'; import { defineActionDescriptor } from '@objectstack/spec/automation'; +// The shared ref'd-timer instrument (#10783). A private, test-only workspace +// package rather than a subpath on `@objectstack/core`: a test helper does not +// belong on a runtime package's published npm surface, and a relative import +// into `packages/core/src` would put a foreign file into this package's tsc +// program, where `rootDir` rejects it. That module's header carries the full +// argument and the measurements behind it. +import { recordGuards, stillPinningTheLoop } from '@objectstack/refd-timer-testkit'; /** * A pausing fixture's `resumeAuthority: 'any'` declaration (#5561). @@ -2005,24 +2012,46 @@ describe('AutomationEngine - Node Timeout', () => { }; /** - * Ref'd `Timeout` handles — `getActiveResourcesInfo()` reports only - * resources currently keeping the event loop alive, which is exactly - * the property that made `os migrate` idle ~120s in #4813. + * ⚠️ This pin used to score an ABSOLUTE `process.getActiveResourcesInfo()` + * `'Timeout'` count either side of `await engine.execute(...)` (#10783). + * That reading is PROCESS-global, so it belongs to every co-tenant test + * file in the worker and to the runner itself — never to this test — and + * comparing two of them with `toBe` is sound only while the window + * crosses no event-loop turn. It was green only because + * `registerInstantScript` resolves on a microtask, which is a property + * of code this test does not own and was written down nowhere. The day + * anything in `engine.execute()`'s path awaits a real timer (a node + * retry, a queue drain, a rate limiter) a FOREIGN expiry inside the + * window pulls the count DOWN and the message points at a timer count + * rather than at the change that caused it. The sibling sites went red + * exactly that way under ambient noise: `expected 2037 to be 2047`. + * + * So: name the guards this flow arms — told apart from every other timer + * on the shared loop by the `GUARD_MS` they are configured with — and + * ask how many of THOSE are still holding the loop open, across a window + * that is synchronous by construction. `@objectstack/refd-timer-testkit` + * carries the full argument, including why `stillPinningTheLoop` is + * deliberately synchronous. `pnpm check:refd-timer-probe` now keeps the + * raw probe out of every package (#10785). */ - const refdTimers = () => - process.getActiveResourcesInfo().filter(r => r === 'Timeout').length; - it("leaves no ref'd timer behind when the nodes win the race", async () => { const calls = { count: 0 }; registerInstantScript(engine, calls); registerGuardedFlow(engine, 'guarded_flow', 3); - const before = refdTimers(); - const result = await engine.execute('guarded_flow'); + let result!: Awaited>; + const guards = await recordGuards(GUARD_MS, async () => { + result = await engine.execute('guarded_flow'); + }); expect(result.success).toBe(true); expect(calls.count).toBe(3); - expect(refdTimers()).toBe(before); + // One guard per guarded node, so the instrument demonstrably saw + // this flow's own timers — a zero below cannot stand for "nothing + // was ever armed" (`stillPinningTheLoop` throws on an empty set for + // the same reason). + expect(guards).toHaveLength(3); + expect(stillPinningTheLoop(guards)).toBe(0); }); it('still reports the timeout when a node never answers', async () => { diff --git a/pnpm-lock.yaml b/pnpm-lock.yaml index 704b88939e..609b4c10bf 100644 --- a/pnpm-lock.yaml +++ b/pnpm-lock.yaml @@ -814,6 +814,9 @@ importers: '@objectstack/metadata-core': specifier: workspace:* version: link:../metadata-core + '@objectstack/refd-timer-testkit': + specifier: workspace:* + version: link:../qa/refd-timer-testkit '@types/node': specifier: ^26.2.0 version: 26.2.0 @@ -1959,6 +1962,15 @@ importers: specifier: ^4.1.10 version: 4.1.10(@opentelemetry/api@1.9.1)(@types/node@26.2.0)(@vitest/coverage-v8@4.1.10)(happy-dom@20.10.2)(jsdom@30.0.1(@noble/hashes@2.3.0))(msw@2.14.6(@types/node@26.2.0)(typescript@6.0.3))(vite@8.0.16(@types/node@26.2.0)(esbuild@0.28.2)(jiti@2.7.0)(tsx@4.23.12)(yaml@2.9.0)) + packages/qa/refd-timer-testkit: + devDependencies: + '@types/node': + specifier: ^26.2.0 + version: 26.2.0 + typescript: + specifier: ^6.0.3 + version: 6.0.3 + packages/rest: dependencies: '@objectstack/core': @@ -2185,6 +2197,9 @@ importers: '@objectstack/plugin-security': specifier: workspace:* version: link:../../plugins/plugin-security + '@objectstack/refd-timer-testkit': + specifier: workspace:* + version: link:../../qa/refd-timer-testkit '@objectstack/service-job': specifier: workspace:* version: link:../service-job diff --git a/scripts/check-refd-timer-probe.mjs b/scripts/check-refd-timer-probe.mjs new file mode 100644 index 0000000000..63e9dd93f8 --- /dev/null +++ b/scripts/check-refd-timer-probe.mjs @@ -0,0 +1,453 @@ +#!/usr/bin/env node +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. + +/** + * check-refd-timer-probe -- the PROCESS-GLOBAL ref'd-timer probe is reachable + * from ONE module, and every leak pin that needs it goes through that module. + * + * node scripts/check-refd-timer-probe.mjs # the sweep (the gate) + * node scripts/check-refd-timer-probe.mjs --list # every site the sweep sees + * node scripts/check-refd-timer-probe.mjs --self-test # the detector's own rules + * + * ## The class this closes (#10785) + * + * `process.getActiveResourcesInfo()` reports the WHOLE process, so a `'Timeout'` + * count derived from it is AMBIENT: it belongs to every co-tenant test file in + * the worker and to the runner itself, not to the test reading it. Scoring a + * subject against it -- + * + * const before = refdTimers(); + * await subject(); // anything can happen in here + * expect(refdTimers()).toBe(before); + * + * -- is sound only while the window between the two samples crosses no + * event-loop turn, because timer callbacks run in the timers phase and a + * microtask drain never reaches it. That is a property of code the test does + * not own, and it is written down nowhere. + * + * The shape was found FIVE times over four cards before this gate existed + * (#10785's table, reproduced because it is the measurement that justifies the + * cost of a gate rather than a fifth site fix): + * + * kernel.test.ts (#4813) latent + * health-monitor.test.ts (#6329) RED IN THE MERGE QUEUE -- the window + * stretched past @vitest/runner's own + * non-unref'd 100ms throttle timer, + * measured at 105ms + * timeout-guard.test.ts (#10604/#10661) RED IN CI -- `expected 2 to be 4`, + * two FOREIGN timers expiring mid-test + * kernel.test.ts x2, hot-reload.test.ts latent, fixed in #10685's PR + * service-automation/engine.test.ts latent (#10783), fixed with this gate + * + * Each was repaired at the site. Nothing prevented the next one, and the + * failure it produces is a shard-only intermittent red whose message points at + * a timer count rather than at the change that caused it -- which blocks every + * lane's merge queue at once. Two of five were found that way, not by review. + * + * ## Why THIS rule, and not the one that sounds more precise + * + * The rule the class suggests is "two readings may only be compared across a + * window that contains no `await`". That is an AST question, and #10785 turned + * it down for the reason AGENTS.md already records about source-scanning + * gates: a text scan that gets it approximately right sees only the spellings + * it knows, and an unrecognised one produces no flag, SILENTLY. A gate whose + * default is a silent pass is the failure mode, not a weaker version of the + * fix. + * + * So the rule here is the cheap, robust one: BAN THE RAW PROBE OUTSIDE ONE + * APPROVED MODULE. It is a grep-level question with a one-entry allowlist, its + * default is a RED gate naming the file and the line, and the invariant it + * buys is structural rather than textual -- `stillPinningTheLoop()` is a + * SYNCHRONOUS function, so its two samples are adjacent synchronous statements + * and no `await` can be inserted between them without turning it into a + * different, visibly `async`, function. The approved module argues that at + * length; this gate is only what makes the argument reachable. + * + * ## What is matched, and the boundary that is stated rather than discovered + * + * The IDENTIFIER, anywhere in code -- not the `process.`-prefixed spelling. + * A member access is one route to the function and there are others (`const { + * getActiveResourcesInfo } = process`, a named import from `node:process`, + * `process['getActiveResourcesInfo']`), so matching the receiver would leave a + * silent hole per route. The identifier has to appear whichever route is + * taken. + * + * The one spelling that evades it is a name assembled at runtime from pieces + * ('getActive' + 'ResourcesInfo'). It is stated here rather than left to be + * found later: nobody reaches for it by accident, and a gate that pretended to + * cover it would be making the claim this file exists to refuse. + * + * Comments are masked (`js-comment-mask.mjs`) because the rule is about CODE. + * That is load-bearing rather than tidy: the approved module's docblock, the + * fake-timer comments in four core suites and this header all have to NAME the + * banned probe to explain the rule, and a gate that forces authors to reword + * prose to dodge a scanner teaches them the scanner is noise. String literals + * are NOT masked -- over-collection can only cost a conversation, while a + * masked literal would be a hole. + * + * ## The vacuous green this cannot have + * + * "No file outside the approved module reads the probe" is also true of a tree + * where the approved module was deleted, renamed, or quietly emptied -- and + * every pin in the family would then be reading the raw probe under another + * name with this gate green. So the sweep asserts the approved module is + * present AND still holds the probe. Zero findings mean the rule held; they + * never stand for "there was nothing to find". + */ + +import { readFileSync } from 'node:fs'; +import { execFileSync } from 'node:child_process'; +import { join, dirname, resolve, relative, sep } from 'node:path'; +import { fileURLToPath } from 'node:url'; +import process from 'node:process'; + +import { isEntrypoint } from './invoked-as.mjs'; +import { maskComments } from './js-comment-mask.mjs'; + +const HERE = dirname(fileURLToPath(import.meta.url)); +const REPO_ROOT = resolve(HERE, '..'); + +/** This file, repo-relative. Excluded mechanically -- see EXCLUDED_SELF. */ +const SELF = relative(REPO_ROOT, fileURLToPath(import.meta.url)).split(sep).join('/'); + +/** + * The one module allowed to read the probe -- the allowlist, in full. + * + * It is a path rather than a pattern on purpose: "one approved module" is the + * whole rule, and a pattern would let the population grow without anyone + * deciding that it should. + */ +const APPROVED_HELPER = 'packages/qa/refd-timer-testkit/src/index.ts'; + +/** + * EXCLUDED_SELF, not a second allowlist entry. This file has to spell the + * identifier to look for it, so it is skipped by IDENTITY (derived from + * `import.meta.url`, so a rename cannot strand it) rather than by a listed + * exemption anyone could copy. + */ +const EXCLUDED_SELF = SELF; + +/** The banned identifier, whatever receiver it is reached through. */ +const PROBE = 'getActiveResourcesInfo'; + +/** Sources the rule applies to. A `.md` page discussing the probe is prose. */ +const SCANNED_EXTENSIONS = ['.ts', '.tsx', '.mts', '.cts', '.js', '.mjs', '.cjs', '.jsx']; + +/** Directories `git ls-files` can still name that hold no authored source. */ +const EXCLUDED_DIRS = ['node_modules/', 'dist/', 'coverage/', '.turbo/']; + +// --------------------------------------------------------------------------- + +/** Whether the sweep reads this repo-relative path at all. */ +export function isScannable(file) { + if (file === EXCLUDED_SELF) return false; + if (EXCLUDED_DIRS.some((d) => file === d.slice(0, -1) || file.includes(`/${d}`) || file.startsWith(d))) { + return false; + } + return SCANNED_EXTENSIONS.some((ext) => file.endsWith(ext)); +} + +/** + * Every CODE occurrence of the probe identifier in `source`, with 1-based line + * numbers. `maskComments` blanks comment spans and keeps every offset and + * newline, so a line number computed on the masked text indexes the original. + */ +export function probeSitesIn(source) { + const code = maskComments(source); + const sites = []; + const rx = new RegExp(`\\b${PROBE}\\b`, 'g'); + const lines = source.split('\n'); + + let match; + while ((match = rx.exec(code)) !== null) { + const line = code.slice(0, match.index).split('\n').length; + sites.push({ line, text: (lines[line - 1] ?? '').trim() }); + } + return sites; +} + +/** + * The gate's verdict over a map of repo-relative path -> source text. + * + * Takes the tree as DATA so the self-test drives the same code the sweep does; + * a detector whose rules are only reachable through the filesystem is a + * detector whose negative controls have to be believed rather than run. + */ +export function judge(tree) { + const problems = []; + const sites = []; + + for (const [file, source] of Object.entries(tree)) { + if (!isScannable(file)) continue; + const found = probeSitesIn(source); + if (found.length === 0) continue; + sites.push(...found.map((s) => ({ file, ...s }))); + if (file === APPROVED_HELPER) continue; + + for (const s of found) { + problems.push( + `RAW PROBE: ${file}:${s.line} reads the process-global timer probe directly.\n` + + ` ${s.text}\n` + + ' That reading is AMBIENT -- it counts every co-tenant test file\'s timers and the\n' + + ' runner\'s own, so comparing two of them across an `await` scores the subject against\n' + + ' a number the test does not own. It has gone red in CI and in the merge queue.\n' + + ` Fix: measure the subject's OWN handles, through ${APPROVED_HELPER} --\n` + + ' const guards = await recordGuards(, () => subject());\n' + + ' expect(guards).toHaveLength(); // the guards were really armed\n' + + ' expect(stillPinningTheLoop(guards)).toBe(0); // and none outlived its race\n' + + ' A genuinely synchronous window (no `await` between the two samples) may use that\n' + + ' module\'s `refdTimeouts()` instead. It is the private, test-only workspace package\n' + + ' `@objectstack/refd-timer-testkit`: take it as a devDependency and import it by name.\n' + + ' ⛔ There is no exemption entry to add here, and this gate offers none: the approved\n' + + ' module IS the list, and a second copy of the probe is the class this exists to end.', + ); + } + } + + const helper = tree[APPROVED_HELPER]; + if (helper === undefined) { + problems.push( + `NO APPROVED MODULE: ${APPROVED_HELPER} is not in the scan set.\n` + + ' Every finding above is measured against it, so its absence makes a clean run\n' + + ' meaningless rather than good: a tree with no probe anywhere reads exactly like a\n' + + ' tree where the rule held. If the module moved, move this gate\'s constant with it.', + ); + } else if (probeSitesIn(helper).length === 0) { + problems.push( + `APPROVED MODULE NO LONGER READS THE PROBE: ${APPROVED_HELPER} is present but its code\n` + + ' does not mention the probe any more. Either the instrument was gutted -- in which\n' + + ' case every pin in the family is measuring nothing -- or it was rewritten onto a\n' + + ' different primitive, in which case this gate is now watching the wrong identifier.', + ); + } + + return { problems, sites }; +} + +// --------------------------------------------------------------------------- + +/** One `git ls-files` invocation, NUL-split. */ +function gitFiles(cwd, args) { + return execFileSync('git', ['ls-files', '-z', ...args], { cwd, encoding: 'utf8', maxBuffer: 64 * 1024 * 1024 }) + .split('\0') + .filter(Boolean); +} + +/** + * The tree the sweep reads: tracked files PLUS untracked-but-not-ignored ones. + * + * The second half matters for the same reason it does in `check-nul-bytes.mjs` + * -- a new pin written this minute is untracked, and a gate that judged only + * the index would greenlight exactly the file the author is asking about. + */ +export function readTree(root = REPO_ROOT) { + const files = new Set([...gitFiles(root, []), ...gitFiles(root, ['--others', '--exclude-standard'])]); + const tree = {}; + for (const file of files) { + if (!isScannable(file)) continue; + try { + tree[file] = readFileSync(join(root, file), 'utf8'); + } catch { + // A path in the index with no readable file (a broken symlink, a + // deletion staged elsewhere) is not this gate's business. + } + } + return tree; +} + +// ── Self-test ─────────────────────────────────────────────────────────────── + +const HELPER_STUB = ` +export const refdTimeouts = () => + process.${PROBE}().filter((r) => r === 'Timeout').length; +`; + +function selfTest() { + const cases = [ + { + label: 'the approved module may read the probe → GREEN', + tree: { [APPROVED_HELPER]: HELPER_STUB }, + expect: 'green', + }, + { + // THE NEGATIVE CONTROL. This is the exact fifth site (#10783), and it is + // what makes a clean run mean something: without a case that reds, a + // self-test proves only that the detector can be run. + label: 'a raw probe in another package → RED, naming file and line', + tree: { + [APPROVED_HELPER]: HELPER_STUB, + 'packages/services/service-automation/src/engine.test.ts': + `const refdTimers = () =>\n process.${PROBE}().filter(r => r === 'Timeout').length;\n`, + }, + expect: 'red', + wants: [/engine\.test\.ts:2 /, /recordGuards/, /stillPinningTheLoop/], + }, + { + label: 'a COMMENT naming the probe → GREEN (prose explains the rule; it does not break it)', + tree: { + [APPROVED_HELPER]: HELPER_STUB, + 'packages/core/src/kernel.test.ts': + `// Unlike \`process.${PROBE}()\`, the fake-timer count still sees\n// an unref'd timer.\nconst before = vi.getTimerCount();\n`, + }, + expect: 'green', + }, + { + label: 'a BLOCK comment is masked, and a real hit AFTER it keeps its line number → RED at :5', + tree: { + [APPROVED_HELPER]: HELPER_STUB, + 'packages/core/src/hot-reload.test.ts': + `/*\n * ${PROBE} is process-wide.\n * Two lines of prose.\n */\nconst n = process.${PROBE}().length;\n`, + }, + expect: 'red', + wants: [/hot-reload\.test\.ts:5 /], + }, + { + // Spelling-independence, limb 1. Matching `process.` would miss this. + label: 'a DESTRUCTURED probe → RED', + tree: { + [APPROVED_HELPER]: HELPER_STUB, + 'packages/runtime/src/leak.test.ts': `const { ${PROBE} } = process;\n`, + }, + expect: 'red', + wants: [/leak\.test\.ts:1 /], + }, + { + // Spelling-independence, limb 2: the resolver route, no `process` in sight. + label: 'a NAMED IMPORT from node:process → RED', + tree: { + [APPROVED_HELPER]: HELPER_STUB, + 'packages/rest/src/leak.test.ts': `import { ${PROBE} } from 'node:process';\n`, + }, + expect: 'red', + wants: [/rest\/src\/leak\.test\.ts:1 /], + }, + { + // Spelling-independence, limb 3: computed member access. + label: 'a BRACKETED member access → RED', + tree: { + [APPROVED_HELPER]: HELPER_STUB, + 'packages/objectql/src/leak.test.ts': `const n = process['${PROBE}']().length;\n`, + }, + expect: 'red', + wants: [/objectql\/src\/leak\.test\.ts:1 /], + }, + { + label: 'a .md page discussing the probe is not scanned → GREEN', + tree: { + [APPROVED_HELPER]: HELPER_STUB, + 'content/docs/testing/timers.md': `Call \`process.${PROBE}()\` to see the loop.\n`, + }, + expect: 'green', + }, + { + // The vacuous green, limb 1. + label: 'the approved module missing → RED even though no file breaks the rule', + tree: { 'packages/core/src/kernel.test.ts': 'const before = vi.getTimerCount();\n' }, + expect: 'red', + wants: [/NO APPROVED MODULE/], + }, + { + // The vacuous green, limb 2. + label: 'the approved module present but no longer reading the probe → RED', + tree: { [APPROVED_HELPER]: 'export const refdTimeouts = () => 0;\n' }, + expect: 'red', + wants: [/NO LONGER READS THE PROBE/], + }, + { + label: 'two raw sites → two problems, each named', + tree: { + [APPROVED_HELPER]: HELPER_STUB, + 'packages/core/src/a.test.ts': `process.${PROBE}();\n`, + 'packages/core/src/b.test.ts': `\n\nprocess.${PROBE}();\n`, + }, + expect: 'red', + wants: [/a\.test\.ts:1 /, /b\.test\.ts:3 /], + }, + ]; + + let failed = 0; + for (const c of cases) { + const { problems } = judge(c.tree); + const isRed = problems.length > 0; + if (isRed !== (c.expect === 'red')) { + failed += 1; + console.error( + ` ✗ ${c.label}\n expected ${c.expect}, got ${isRed ? 'red' : 'green'}` + + (isRed ? `\n ${problems.join('\n ')}` : ''), + ); + continue; + } + const blob = problems.join('\n'); + const missing = (c.wants ?? []).filter((rx) => !rx.test(blob)); + if (missing.length > 0) { + failed += 1; + console.error( + ` ✗ ${c.label}\n red as expected, but the message does not name ` + + `${missing.map((m) => `/${m.source}/`).join(', ')}\n ${blob}`, + ); + continue; + } + console.log(` ✓ ${c.label}`); + } + + // Discovery-level assertions, against the REAL tree. The cases above pin the + // rules; these pin that the sweep still reaches anything at all -- a walk + // that silently found nothing would satisfy every case above. + const tree = readTree(); + const count = Object.keys(tree).length; + if (count < 100) { + failed += 1; + console.error(` ✗ real-tree discovery reached only ${count} source file(s) — the sweep is not walking the repo`); + } else { + console.log(` ✓ real-tree discovery: ${count} source file(s) in the scan set`); + } + if (tree[APPROVED_HELPER] === undefined) { + failed += 1; + console.error(` ✗ real-tree discovery did not reach ${APPROVED_HELPER}`); + } else { + console.log(` ✓ real-tree discovery reaches the approved module itself`); + } + if (isScannable(EXCLUDED_SELF)) { + failed += 1; + console.error(' ✗ this gate does not exclude itself — it would report its own pattern as a violation'); + } else { + console.log(' ✓ the gate excludes itself by identity, not by a listed exemption'); + } + + if (failed > 0) { + console.error(`\n✗ check-refd-timer-probe self-test failed (${failed} case(s)).`); + process.exit(1); + } + console.log(`\n✓ check-refd-timer-probe self-test: ${cases.length} cases pass, negative controls included.`); +} + +// --------------------------------------------------------------------------- + +function main() { + if (process.argv.includes('--self-test')) return selfTest(); + + const tree = readTree(); + const { problems, sites } = judge(tree); + + if (process.argv.includes('--list')) { + for (const s of sites) console.log(`${s.file}:${s.line} ${s.text}`); + console.log(`\n${sites.length} code site(s) across ${new Set(sites.map((s) => s.file)).size} file(s).`); + process.exit(0); + } + + if (problems.length > 0) { + console.error(`\n✗ check-refd-timer-probe: ${problems.length} problem(s)\n`); + for (const p of problems) console.error(` • ${p}\n`); + process.exit(1); + } + + console.log( + `OK check-refd-timer-probe: ${Object.keys(tree).length} source file(s) swept; the process-global ` + + `timer probe is read in ${APPROVED_HELPER} and nowhere else.\n` + + ` ${sites.length} code site(s), all inside the approved module, which is present and still reads it.`, + ); +} + +if (isEntrypoint(import.meta.url)) { + main(); +}