fix(service-messaging): stop the delivery dispatchers on the kernel's own teardown hook (#9371)

[os-zhuang]

Fixes#9371

Root-causes the EnvironmentTeardownError: [vitest-worker]: Closing rpc while "onUserConsoleLog" was pending teardown race that evicted #9365 and #9775 from the merge queue with every test passing (334/334, then 337/337).

The fault is not in test/approval-resume-relation-expand.test.ts, not a showcase fixture, and not vitest configuration. It is a plugin teardown that the kernel never reaches.

⛔ Nothing is skipped, quarantined, retry-wrapped or --reporter-silenced, and no assertion is weakened.

The defect

MessagingServicePlugin starts two setInterval dispatchers at kernel:ready — NotificationDispatcher over sys_notification_delivery and HttpDispatcher over sys_http_delivery — and released them from a method named stop():

/** Stop the dispatcher loop + retention sweep on shutdown. */asyncstop(){ ... }// the body was right; only the NAME was wrong

The intent is explicit and the body was correct. Only the name was wrong. Plugin (packages/core/src/types.ts:170) declares exactly one teardown hook — the optional member destroy?(), returning a promise or nothing — and that is the only one ObjectKernel.performShutdown() and LiteKernel.destroy() invoke. stop() is not on the interface, so nothing in the tree ever called it. Both dispatchers went on claiming and updating delivery rows after await kernel.shutdown() had resolved.

start()unref()s both timers, so a long-lived host process still exits — which is why this stayed invisible in production and surfaced somewhere else entirely.

How that becomes a red run on a green suite

Read out of the installed vitest (4.1.10), not assumed:

1. Under vitest the worker process is alive throughout teardown, so a dispatcher tick fires after the test file is over, reads a delivery table through a driver the suite already disconnected, and SqlDriver's console fallback (sql-driver.ts:3983) warns.
2. console.* in a worker is an RPC to the main process. sendLog calls state().rpc.onUserConsoleLog({...}) and discards the returned promise.
3. execute()'s finally does await rpcDone() — which awaits a snapshot of the pending set — and then $rejectPendingCalls, which rejects anything created after that snapshot with EnvironmentTeardownError.
4. Nobody holds that promise, so it lands as an unhandled rejection. Vitest fails a run on an unhandled error even when no assertion failed.

The width of the window is the duration of rpcDone(). That is the entire "load-dependence" recorded on the card: ~1 ms on an idle box, long enough on a saturated queue runner. It explains why the identical diff ran the identical suite clean PR-side and red queue-side.

Reproduced before it was fixed

4-vCPU container (same profile as the CI runner under turbo --concurrency=4), 4 concurrent full examples/app-showcase suites × 3 rounds, with a probe wrapping rpc.onUserConsoleLog:

AFTERALL 30847 t=37655 ← the file's tests and hooks are done
RPCSTART 30847 t=37899 id=135 ← eight console RPCs begin AFTER that
RPCREJECT 30847 t=38057 id=137 err=EnvironmentTeardownError: [vitest-worker]: Closing rpc while "onUserConsoleLog" was pending
… ×6, one $rejectPendingCalls sweep
PROCEXIT 30847 t=38099

Corroborating, from vitest's own leak detector on the unmodified suite — one file, and it is the file both sightings name:

⎯⎯⎯⎯⎯⎯⎯ Async Leaks 4 ⎯⎯⎯⎯⎯⎯⎯⎯
PROMISE leaking in test/approval-resume-relation-expand.test.ts (×4)
Test Files 21 passed (21)
Tests 342 passed (342)
Leaks 4 leaks

And the reason that file is the one named: instrumenting every console.* across the suite, it makes 294 of the 348 console calls in the whole showcase run — the loudest by an order of magnitude, so it is where the queue is deepest at teardown.

Effect of the fix, measured paired

Identical harness, same box, same N — 48 loaded runs of the affected file each side; dist rebuilt between legs and the rebuild verified on disk.

	before (pre-fix dist)	after (fixed dist)
console calls after the file's own afterAll	3	0
console RPC round-trips (RPCSTART)	6574	3456
RPCs never settled (RPCSTART − RPCOK)	3	0
total console calls	14251	11136

Both halves of the race shrink: the late calls that arm it are gone, and the queue depth that widens the window roughly halves.

The change

• destroy() now carries the teardown body — the hook the kernel actually calls.
• stop() is retained as a delegating alias. It is public API of an exported class, and an embedder may well have learned to call it directly precisely because the kernel never did. No accept/reject behaviour of any contract moves.
• New pin packages/services/service-messaging/src/plugin-shutdown-stops-dispatchers.test.ts: boots a real ObjectKernel + real ObjectQL + real sqlite, counts delivery traffic on the very IDataEngine the dispatchers captured, and asserts none of it happens after shutdown() resolves. The pre-shutdown leg is a load-bearing positive control — without it a dispatcher that never started would pass vacuously.
• New packages/services/service-messaging/vitest.config.ts: one anchored alias for @objectstack/core. The pin asserts a property of the kernel's teardown contract, so the @objectstack/core it runs against must be this checkout's source, not a dist artifact. Required by pnpm check:test-source-alias.

Ablation (the pin can go red)

Renamed destroy() → ABLATED_destroy(); confirmed on disk by grep against the exact text (async destroy( 0 occurrences, async ABLATED_destroy( 1). No rebuild needed — the subject is imported by relative path, so it resolves to source, not dist. Result:

 FAIL src/plugin-shutdown-stops-dispatchers.test.ts > … > stops touching the delivery tables once shutdown() has resolved
AssertionError: expected 94 to be 46
Test Files 1 failed (1)
Tests 2 failed (2)

48 further delivery reads/writes in the 80 ms after a resolved shutdown() — the defect, quantified. Restored from the commit (async destroy( back to 1, ABLATED 0) and re-run: Test Files 1 passed (1) · Tests 2 passed (2).

Verification

All gates run at head bd5293d83, working tree byte-identical to HEAD (git status --porcelain empty). Gate set derived with node scripts/pm/dispatch-gates.mjs (no path args — it derives its own change set from the merge base), re-derived after the final commit; exit codes captured before any pipe.

Suites — EXIT=0 each:

messaging-test Test Files 23 passed (23) · Tests 244 passed (244)
messaging-typecheck tsc --noEmit
showcase-test Test Files 21 passed (21) · Tests 342 passed (342)
showcase-typecheck tsc --noEmit

Gates, each quoting its own verdict line:

✓ slot-lookup ratchet holds: 107 unswept site(s) in 25 file(s), none new … no files added.
check-test-source-alias OK — 72 packages with tests scanned; 61 registered as still resolving a workspace dep through `dist/`
check-type-source-resolution OK — 76 packages with a tsconfig.json scanned
check-type-check-coverage: OK — 64/77 workspace packages type-checked (plus the root)
check-type-check-coverage --re-measure: OK — 33 ledger entr(ies) re-measured … none above its recorded number.
check-engine-double-contract: OK — 331 pinned, 133 in the DEBT ledger, 2 exempt.
where-matcher: 0 silently-wrong and 0 unjudged matcher(s) … none new.
query-options-erasure: test surface 240 site(s) in 47 file(s) — at the ceiling … no files added.
check-i18n-bundles: OK (9 package(s) — all bundles in sync, no undeclared authoring keys).
check-nul-bytes: OK (scanned 6093 text file(s) … no raw ASCII control bytes).
✓ No empty-frontmatter changeset introduced by this diff (1 declaring changeset(s) added).
✓ This diff introduces no `major` bump.
✓ check-adr-0087-registration: this PR adds no declared-breaking changeset
✓ objectui-range --self-test: all checks passed
✓ check-adr-0087-registration --self-test: 212 assertions over real temp git repos
check-affected-docs: OK

Changeset

@objectstack/service-messaging is published, and this changes its runtime behaviour, so it carries a patch changeset — notskip-changeset. (examples/app-showcase is untouched by this PR.)

Clause ② — declared

Does not change contract accept/reject behaviour, and does not widen public surface in any way a consumer can be broken by. It rests on: destroy() is an implementation of an already-declared optional hook on Plugin, not a new interface member; stop() is retained with identical semantics, so no existing call site changes meaning; no schema, validator, error code, or API shape is touched. The behavioural delta is confined to what happens afterkernel.shutdown() resolves, where the previous behaviour was the defect.

Out of scope — filed, not fixed here

• plugin-reports: the timers started by ReportsPlugin are released from stop(), which the kernel never calls #10371 — plugin-reports has the same defect (5 timer sites, stop(), no destroy()), plus five further plugins whose stop() the kernel never calls (no timers, so lower stakes).
• app-showcase: approval-resume-relation-expand.test.ts tears down driver-before-kernel, so the kernel drains against a disconnected driver #10373 — approval-resume-relation-expand.test.ts tears down driver-before-kernel, so the kernel drains against a disconnected driver.
• finding: any late console.* in a vitest worker can fail a fully green suite — the #9371 amplifier is upstream and still live #10374 — finding: the upstream amplifier is still live. Any late console.* in any package can fail a green suite; vitest's non-TTY default reporter (MinimalReporter, silent: 'passed-only') never prints that output, so a suite pays the RPC round-trips for logs nobody reads. --detectAsyncLeaks is the tool that finds the exposed files.

Flaky-signature ledger — PROPOSAL ONLY, ⛔ not self-added

Per the signature-ledger rule this promotion is a human action. Drafted for whoever takes it:

Signature:EnvironmentTeardownError: [vitest-worker]: Closing rpc while "onUserConsoleLog" was pending
Sightings: 2 — run 32049971906 Test Core (2/3) (PR #9365, 1 error, 334/334 green); run 32196793380 Test Core (3/3) (PR #9775, 3 errors, 337/337 green). Both examples/app-showcase, both naming test/approval-resume-relation-expand.test.ts.
Status: root-caused and fixed — #9371, this PR. Trigger was MessagingServicePlugin never being torn down by the kernel; dispatchers outlived the test file and logged into vitest's teardown window.
Residual risk: the upstream amplifier is unfixed (#10374). Recurrence in a different package is a new instance of the class, not a regression of this fix; diagnose with vitest --detectAsyncLeaks on the named package.
Retire when: no sighting for 30 days, or the upstream half lands.

---

Generated by Claude Code

[github-actions]

📓 Docs Drift Check

This PR changes 1 package(s): @objectstack/service-messaging, touching 2 documentable anchor(s).

⛔ 1 release-owned page(s) name something this change touched. These are read-only:

• content/docs/releases/v14.mdx(via MessagingServicePlugin (symbol))

content/docs/releases/ is RELEASE-OWNED (AGENTS.md "Documentation Guardrails"): release
notes are written centrally at release time, and a code PR that edits them is the exact PR
that guardrail exists to stop. They are still audited — read-only. If one of them is actually
wrong, file an issue or open a dedicated docs-only PR; do not edit it here.

What this run could not see

• 1 changed file(s) yielded no anchor (packages/services/service-messaging/vitest.config.ts) — pages documenting those are invisible to this run
• 2 name(s) were too generic to anchor anything (single lowercase words)

Coarse fallback — 4 page(s) merely mention a changed package (the pre-#9192 predicate, kept for the deliberately-wide backstop): node scripts/docs-audit/affected-docs.mjs --json f3996182be0b3a75c53c6cb985955d66964071f6 → packageMentionDocs.

Which tree this was computed on

This run read content/docs from 44602499ebd51e7880e30ab52029c1e3221ac5a4 — the merge of head bd5293d8365ff5fd8bbe4899868f20c1bac74f66 into base f3996182be0b3a75c53c6cb985955d66964071f6, which is what actions/checkout gives a pull_request run. Not the PR head.

A worktree cut from an older main holds a different content/docs, so re-deriving there can legitimately return a different list — that is a different tree, not a wrong row. To answer on the same tree:

# while this PR is open — GitHub drops the merge commit once it closes
git fetch origin 44602499ebd51e7880e30ab52029c1e3221ac5a4 && git checkout 44602499ebd51e7880e30ab52029c1e3221ac5a4
# afterwards, rebuild it from the two parents, which stay fetchable
git fetch origin f3996182be0b3a75c53c6cb985955d66964071f6 bd5293d8365ff5fd8bbe4899868f20c1bac74f66 && git checkout -B drift-repro f3996182be0b3a75c53c6cb985955d66964071f6 && git merge --no-ff bd5293d8365ff5fd8bbe4899868f20c1bac74f66
node scripts/docs-audit/affected-docs.mjs --json f3996182be0b3a75c53c6cb985955d66964071f6

⚠️ That checkout carried uncommitted changes, so the commit above does not fully identify what was read.

Advisory only, and a precision-first one (#9192): a page is listed because it names a
symbol, wire route or SDK method this diff touched — not because it mentions a changed
package. Each row says which anchor put it there, so a wrong row is reportable rather than
merely annoying. To re-verify, run the docs-accuracy-audit workflow scoped to these files:
node scripts/docs-audit/affected-docs.mjs f3996182be0b3a75c53c6cb985955d66964071f6 → pass the list as
args.docs, on the commit named under Which tree this was computed on.