Skip to content

Commit c6c84d3

Browse files
test(plugin-security): the explain/enforce parity table shares a read-only principal rig per posture source (#23748)
Refs #23184 (plugin-security rows: explain-enforce-parity, position-write-through) Clause-②: no (test wall time only; no published schema, behaviour or export moves) A partial landing for the `@objectstack/plugin-security` slice of the test-budget card. The diff is tests-only: one file, `packages/plugins/plugin-security/src/explain-enforce-parity.test.ts`, +62 / -8. No production file, option, constant, timeout or export changes, and no `plugin-security` source module (the C2/C3 epic's territory) is touched. ## Rows this answers | row | card reading | answered by | |:--|--:|:--| | `src/explain-enforce-parity.test.ts` | 37.7 s (run `38332198724`) | this diff: module line 7.37 s to 1.73 s locally (interleaved medians of 3, final head) | | `src/position-write-through.test.ts` | 26.5 s (run `38267594064`) | its deletion: the test file left `main` in `150da61aa5` (#22962, the stage-8 test half), and the module it tested, `position-write-through.ts`, left in `5c9bfb0d3f` (#23302, C3 stage 7b). Both are ancestors of `origin/main` (`merge-base --is-ancestor` exit 0). No change is owed; the next refresh PR's list should not name it. | A correction to the claim: it says C3 stage 7b deleted the test file. That commit deleted the module; the test file had already gone one commit earlier in the series, in `150da61aa5`. ## Cause, measured A temporary per-phase probe of the base file (deleted, never committed) showed where the wall went: - **60 of the 98 rows are principal-rig rows, and they carried about 7.4 s of the 7.9 s.** Each one booted its own `bootPrincipal` rig, about 84 ms per boot: `syncSchemas` of 11 objects (2.5 s across the 60 boots), 21 seed inserts (1.8 s), and the administrator's authz context (0.5 s). The rows' own faces cost about 28 ms each. The 33 RLS rows and 5 sharing rows cost about 8-12 ms each. - **Leaked async-hook storages cost about half of the rest.** On Node 22 (the version `ci.yml` pins), `AsyncLocalStorage` runs on `async_hooks`. A storage that has served one `run()` stays on a process-wide list until `disable()`, and every later promise creation walks that list. `ObjectQL` holds three storages per engine and `SecurityPlugin` one per plugin, and neither `destroy()` disables them. So each of the 98 torn-down rigs left its storages behind, and each later row walked all of them. A CPU profile of an intermediate build showed `_propagate` (`node:internal/async_local_storage/async_hooks`) as the top self-time frame. - **PM assumption 2's other shapes, checked:** no real timer is waited on. The first case pays a first-use premium of about 150 ms (driver load about 20 ms, the first find's compile about 37 ms, the rest spread out), not one module load inside a clocked case, so it is left where it is. Assumption 3 (a declared budget) does not apply: per-case rig boots are neither of `TEST_BUDGET_CLASSES`, and the cost could be cut without weakening any row. Each mechanism, measured alone (module line, ms): base 7790/7967/7374; storages released only 3572/4054; shared principal rig only 2350/2522; both 1609/1724. ## The change 1. **One principal rig per posture source, shared by that source's rows** (`withPrincipal` / `sharedPrincipalRig`). The source's first row boots the rig, and an `afterAll` tears the 4 rigs down. Every principal row only reads: explain, the explained user's own find through the real resolver and middleware, the permission sets enforcement hands the user, and a system read of an explained filter. The RLS and sharing rows can write (by-id update, delete, insert), so they still boot their own rig per row. 2. **Each rig's teardown releases the `AsyncLocalStorage` instances its engine and plugin own** (`releaseAsyncContexts`). It runs after the rig's last row is judged, on objects nothing uses again. ## Nothing weakened - **Static lines:** `it(` 1/1, `describe(` 1/1, `expect(` 19/19, byte-identical and in order between base and head (`cmp` exit 0). One hook line is added: the shared rigs' `afterAll`. - **Runtime assertions per case** (`expect.getState().assertionCalls` in temporary instrumented base and head copies, deleted): identical per case and in order, 335 over 98 cases, no zero-assertion case, every case `pass`. - **Isolation, per principal row** (a temporary probe over the head file, deleted). For all 60 principal rows: - the shared rig's raw SQLite state (every table and row, read in rowid order: 11 tables, 21 rows) is byte-equal before and after the row; - that state equals a fresh rig's for the same source (rig suffix and timestamps normalised); - the fresh rig's state is unchanged by the row; - the row's faces on the shared rig equal the same faces on a fresh rig: explain's full answer, enforcement's full answer, and the explained `readFilter` applied as a system read. 60/60 on every reading. - **A leak would be loud** (a one-off mutation via `scripts/ablation-replace.mjs`, never committed): the removed user's `sets` face was made to write a `sys_member` row into the shared rig. 15 rows went red, 13 of them later rows of the same rig (`isolated`, `group` and `org-scoping`). Restore was proven: blob `378d595c80` equal to HEAD, and `git diff HEAD` empty. - **Order independence:** head under `--sequence.shuffle.tests` with seeds 11 / 2026 / 23184: 98/98 passed each time. - No row moved from the real stack to a stub. No timeout, budget or project changed. Nothing was deleted. ## Wall time Vitest default-reporter module line (hooks plus cases, collection excluded; the number `test-core.log` carries). Command: `pnpm exec vitest run --maxWorkers=2 FILE --reporter=default --reporter=json`, in `packages/plugins/plugin-security`, under `os-verify-lock`, on a 4-vCPU box. | reading | base (ms) | head (ms) | |:--|:--|:--| | standalone, idle box (load 0.5-0.8), base `534ca13eb5`, head `5cad7b98dd` | 7790 / 7967 / 7374 | 1833 / 1760 / 1629 | | interleaved, `5cad7b98dd` (load 1.1-1.6) | 7653 / 7237 / 7197 | 1792 / 1682 / 1673 | | interleaved, final head `db5121f2d6` (load 1.7-2.3, other agents' work beside it) | 7373 / 7317 / 7620 | 1922 / 1729 / 1650 | - At the final head the medians are 7.37 s and 1.73 s, a ratio of 0.23. Applied to the card's 37.7 s, that projects to about **8.8 s**; against the idle-box base the card's ratio (4.8) projects to about **8.4 s**. - Today's hourly-battery maxima are NOT MEASURED. This container's egress refuses the timing artifacts' blob-storage redirect (403), as the earlier slices recorded. - vitest's whole-file Duration (collection plus run) fell too, from about 25-27 s to about 19.5-20.5 s. Nothing moved into collection. ## Verification (at final head `db5121f2d6`, closure rebuilt after the merge) - `pnpm --filter @objectstack/plugin-security run typecheck`: `VERDICT command-exit 0`. `check:test-typecheck` OK, 0 files in the debt ledger; `tsc -p tsconfig.test.json --listFilesOnly` lists the file. - `pnpm --filter @objectstack/plugin-security exec vitest run --maxWorkers=2`: Test Files 186 passed (186), Tests 3714 passed, 45 skipped (in other files), `VERDICT command-exit 0`. - `eslint --no-inline-config` on the file: exit 0. Control-byte self-scan: 0 hits. ## Gates `node scripts/pm/dispatch-gates.mjs --commands --repo objectstack-ai/objectstack` at `db5121f2d6`: 1 path, 54 commands, identical to the seat's lead. Each was run separately, exit captured before any pipe. - 52 exited 0 on the first pass. `check:dual-build-cjs-loads` and `check:i18n` exited 3 (PREREQUISITE NOT MET, workspace not built) and exited 0 after `turbo run build --filter=!@objectstack/docs` (75/75). - `dispatch-gates --ran`: 54 derived, 54 run, 0 NOT-MEASURED, 0 UNRUN. - The families CI runs (Test Core, Build Core, dogfood, type-check lanes, full lint) are CI's, read from this PR's check-runs. ## Acceptance notes - **Observation, not filed (承接者:无):** `ObjectQL.destroy()` and `SecurityPlugin.destroy()` leave their `AsyncLocalStorage` instances enabled. On Node 22 every one of them stays on the process-wide `async_hooks` list that each later promise creation walks. In this file that was about half the wall (7.8 s to 3.6-4.1 s with the release alone). Any suite that builds many engines in one process pays the same. A production process builds one engine, and no public door was measured giving a wrong answer, so no defect class applies. If `destroy()` later disables them, `releaseAsyncContexts` becomes a no-op and can go. - **Observation:** the file spends about 17-19 s in vitest import/transform on this box, before and after. That is collection, outside the per-file reading the budget grades. - **Left in the clock deliberately:** the first case's first-use premium, about 150 ms, spread over first use of the driver, the compile and the find path. --- _Generated by [Claude Code](https://claude.ai/code/session_017WLmd5in9RXu7AjyHR8fKQ)_ Co-authored-by: Claude <noreply@anthropic.com>
1 parent 140238a commit c6c84d3

1 file changed

Lines changed: 62 additions & 8 deletions

File tree

‎packages/plugins/plugin-security/src/explain-enforce-parity.test.ts‎

Lines changed: 62 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -34,7 +34,9 @@
3434
* Every row drives BOTH faces through the real stack — the real
3535
* `SecurityPlugin`, a real `ObjectQL` over a real SQL driver (better-sqlite3,
3636
* one in-memory database per rig) — and asserts enforcement's own outcome as
37-
* well, so a row cannot go green by both faces drifting together. The rows are
37+
* well, so a row cannot go green by both faces drifting together. A row that
38+
* can write boots its own rig; the principal rows, which only read, share one
39+
* rig per posture source ({@link withPrincipal}). The rows are
3840
* the explain-versus-enforce family's shapes so far: the record-grained write
3941
* verdict's inputs (#19963), the record-grained read verdict's read depth
4042
* (#19986), a shared dependency that throws (#20002), the record matcher under
@@ -75,7 +77,8 @@
7577
* built `dist/` here, as this package's other suites read them.
7678
*/
7779

78-
import { describe, it, expect, vi } from 'vitest';
80+
import { describe, it, expect, vi, afterAll } from 'vitest';
81+
import { AsyncLocalStorage } from 'node:async_hooks';
7982
import { ObjectQL } from '@objectstack/objectql';
8083
import { SqlDriver } from '@objectstack/driver-sql';
8184
import { resolveAuthzContext, assembleExecutionContext } from '@objectstack/core';
@@ -95,6 +98,22 @@ import { defaultPermissionSets } from './objects/default-permission-sets.js';
9598
const SYS = { context: { isSystem: true } } as never;
9699
const MEMBER_DEFAULT = defaultPermissionSets.find((p) => p.name === 'member_default')!;
97100

101+
/**
102+
* Releases the `AsyncLocalStorage` instances a torn-down rig's engine and
103+
* plugin hold. On Node 22 a storage runs on `async_hooks`: once it has served a
104+
* `run()` it stays on a process-wide list that EVERY later promise creation
105+
* walks, until `disable()`. `ObjectQL` holds three and `SecurityPlugin` one,
106+
* and neither `destroy()` disables them, so each rig this table tore down left
107+
* its storages behind and every later row paid to walk all of them. Called
108+
* after the rig's last row is judged, on objects nothing uses again, so it
109+
* changes nothing any row observes.
110+
*/
111+
const releaseAsyncContexts = (...owners: object[]): void => {
112+
for (const owner of owners) {
113+
for (const value of Object.values(owner)) if (value instanceof AsyncLocalStorage) value.disable();
114+
}
115+
};
116+
98117
// ── the two faces ─────────────────────────────────────────────────────────
99118

100119
/**
@@ -322,7 +341,10 @@ async function bootRls(predicate: string, opts: { grantCrud?: boolean } = {}) {
322341
readAs: async (filter: unknown) =>
323342
((await engine.find(OBJ, { ...(filter ? { where: filter } : {}), context: { isSystem: true } } as never)) as Array<{ id: string }>)
324343
.map((r) => String(r.id)).sort(),
325-
teardown: async () => { try { await engine.destroy(); } catch { /* noop */ } },
344+
teardown: async () => {
345+
try { await engine.destroy(); } catch { /* noop */ }
346+
releaseAsyncContexts(engine, plugin);
347+
},
326348
};
327349
}
328350

@@ -519,7 +541,10 @@ async function bootPrincipal(source: PostureSource) {
519541
((await engine.find(objects[object], { ...(filter ? { where: filter } : {}), context: { isSystem: true } } as never)) as Array<{ id: string }>)
520542
.map((r) => String(r.id)).sort(),
521543
tenantOf: async (userId: string) => (await enforced(userId)).tenantId,
522-
teardown: async () => { try { await engine.destroy(); } catch { /* noop */ } },
544+
teardown: async () => {
545+
try { await engine.destroy(); } catch { /* noop */ }
546+
releaseAsyncContexts(engine, plugin);
547+
},
523548
};
524549
}
525550

@@ -622,7 +647,10 @@ async function bootSharing(opts: { faultReadFilter?: boolean } = {}) {
622647
find: (caller: object, id: string) => rowsOf(engine.find(LINE, { where: { id }, context: { ...caller } } as never)),
623648
update: (caller: object, id: string) =>
624649
landed(engine.update(LINE, { name: 'renamed' }, { where: { id }, context: { ...caller } } as never)),
625-
teardown: async () => { try { await engine.destroy(); } catch { /* noop */ } },
650+
teardown: async () => {
651+
try { await engine.destroy(); } catch { /* noop */ }
652+
releaseAsyncContexts(engine, plugin);
653+
},
626654
};
627655
}
628656

@@ -650,7 +678,11 @@ interface Row {
650678
run: RowRun;
651679
}
652680

653-
/** A row's run: boots its own rig, and hands back the teardown the table calls once the row is judged. */
681+
/**
682+
* A row's run: boots its own rig, or takes its posture source's shared one (a
683+
* principal row), and hands back the teardown the table calls once the row is
684+
* judged: the rig's own, or none for the shared rig, torn down after the table.
685+
*/
654686
type RowRun = () => Promise<RowFaces & { teardown: () => Promise<void> }>;
655687
interface RowFaces {
656688
explain: Explained;
@@ -671,9 +703,31 @@ const withSharing = (
671703
const rig = await bootSharing(opts);
672704
try { return { ...(await f(rig)), teardown: rig.teardown }; } catch (e) { await rig.teardown(); throw e; }
673705
};
706+
/**
707+
* One principal rig per posture source, booted by the source's first row and
708+
* shared by the rest. Every principal row only READS: explain, the explained
709+
* user's own find, the sets enforcement resolves, and a system read of an
710+
* explained filter. None of them writes a row, a grant or a policy, so a row
711+
* reads the state the rig was booted with, as if the rig were its own. A row
712+
* that can write (the RLS and sharing rigs) still boots its own. Booting all 60
713+
* principal rows' rigs was most of this file's wall.
714+
*/
715+
const principalRigs = new Map<string, Promise<PrincipalRig>>();
716+
const sharedPrincipalRig = (source: PostureSource): Promise<PrincipalRig> => {
717+
const key = JSON.stringify(source);
718+
let rig = principalRigs.get(key);
719+
if (!rig) {
720+
rig = bootPrincipal(source);
721+
principalRigs.set(key, rig);
722+
}
723+
return rig;
724+
};
725+
afterAll(async () => {
726+
for (const rig of principalRigs.values()) await (await rig.catch(() => undefined))?.teardown();
727+
});
674728
const withPrincipal = (source: PostureSource, f: (rig: PrincipalRig) => Promise<RowFaces>): RowRun => async () => {
675-
const rig = await bootPrincipal(source);
676-
try { return { ...(await f(rig)), teardown: rig.teardown }; } catch (e) { await rig.teardown(); throw e; }
729+
const rig = await sharedPrincipalRig(source);
730+
return { ...(await f(rig)), teardown: async () => undefined };
677731
};
678732

679733
const REFUSED_INVALID: Enforced = { kind: 'refused', ...INVALID };

0 commit comments

Comments
 (0)