Skip to content

Commit 5e2c04d

Browse files
test(objectql,verify,runtime): declare OS_REGISTRY_LOG=warn in each suite's own vitest harness (#14016)
* test(objectql,verify,runtime): declare OS_REGISTRY_LOG=warn in each suite's own vitest harness Measured per suite on origin/main b1b7d60, one full run each: objectql 16,194 stdout lines · 4,744 [Registry] · 10,984 structured-logger verify 5,670 stdout lines · 2,323 [Registry] · 3,113 structured-logger runtime 6,730 stdout lines · 1,155 [Registry] · 4,760 structured-logger Against the console-carried population each suite emits (the structured logger writes to process.stdout directly and is a separate question), [Registry] is 91.5% in objectql, 91.3% in verify and 59.0% in runtime. OS_REGISTRY_LOG is @objectstack/objectql's own published seam for that verbosity (SchemaRegistryOptions.logLevel / REGISTRY_LOG_LEVELS). The engine's shipped default stays 'info', and no library code learns what a test runner is: the request lives in each harness, declaratively. Claude-Session: https://claude.ai/code/session_01F3jdziLbAPGeceVNmSox5L Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> * test(objectql): let registry-log-level.test.ts own the variable it is about The package harness now declares OS_REGISTRY_LOG=warn for every worker, and this file's subject IS that variable. Its `afterEach` already deleted the var; the symmetric `beforeEach` was missing, so the FIRST case ran at 'warn' under a name that says 'info' — and stayed green, because both of its expectations are negative ("not called"). Measured rather than reasoned: with the premise assertion added and the `beforeEach` withheld, the case fails with `expected 'warn' to be 'info'`. Both "default level" cases now assert the level they run at, so a future harness key cannot silently re-point them again. Claude-Session: https://claude.ai/code/session_01F3jdziLbAPGeceVNmSox5L Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> --------- Co-authored-by: Claude <noreply@anthropic.com>
1 parent 0d80862 commit 5e2c04d

4 files changed

Lines changed: 124 additions & 1 deletion

File tree

packages/objectql/src/registry-log-level.test.ts

Lines changed: 17 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -18,7 +18,18 @@ import { SchemaRegistry, REGISTRY_LOG_LEVELS } from './registry';
1818
describe('SchemaRegistry log-level gating (#3420)', () => {
1919
const warn = vi.spyOn(console, 'warn').mockImplementation(() => {});
2020
const debug = vi.spyOn(console, 'debug').mockImplementation(() => {});
21-
beforeEach(() => { warn.mockClear(); debug.mockClear(); });
21+
// This file's SUBJECT is `OS_REGISTRY_LOG`, so it owns that variable rather
22+
// than inheriting it. The package's vitest harness declares
23+
// `OS_REGISTRY_LOG=warn` for every worker (#13517), and without this
24+
// `beforeEach` the FIRST case below ran at `'warn'` under a name that says
25+
// `info` — green, because both of its expectations are negative. Measured,
26+
// not reasoned: the premise assertion in that case fails with
27+
// `expected 'warn' to be 'info'` when this line is removed.
28+
beforeEach(() => {
29+
delete process.env.OS_REGISTRY_LOG;
30+
warn.mockClear();
31+
debug.mockClear();
32+
});
2233
afterEach(() => { delete process.env.OS_REGISTRY_LOG; });
2334

2435
const reRegisterSameOwner = (r: SchemaRegistry) => {
@@ -28,6 +39,10 @@ describe('SchemaRegistry log-level gating (#3420)', () => {
2839

2940
it('at the default (info) level, re-registering an owned object is silent — no warn, no debug', () => {
3041
const r = new SchemaRegistry({ multiTenant: false });
42+
// The case's NAME is a premise about the level, so assert it rather than
43+
// assume it: both expectations below are negative, so a quieter level
44+
// satisfies them while measuring something this file never claimed.
45+
expect(r.logLevel).toBe('info');
3146
reRegisterSameOwner(r);
3247
expect(warn).not.toHaveBeenCalledWith(expect.stringContaining('Re-registering owned object'));
3348
expect(debug).not.toHaveBeenCalledWith(expect.stringContaining('Re-registering owned object'));
@@ -44,6 +59,7 @@ describe('SchemaRegistry log-level gating (#3420)', () => {
4459
const manifest = { id: 'com.test', name: 'Test', namespace: 'test', version: '1.0.0' } as any;
4560

4661
const info = new SchemaRegistry({ multiTenant: false });
62+
expect(info.logLevel).toBe('info');
4763
info.installPackage(manifest);
4864
info.installPackage(manifest); // same-package reload → "Overwriting package"
4965
expect(warn).not.toHaveBeenCalledWith(expect.stringContaining('Overwriting package'));

packages/objectql/vitest.config.ts

Lines changed: 40 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,42 @@
44
// vitest's defaults, deliberately — a key added here re-specifies behaviour
55
// for every test file in the package (packages/cli/vitest.config.ts's header
66
// records the incident that taught that).
7+
//
8+
// ── #13517: this suite asks the SchemaRegistry for quiet, DECLARATIVELY ─────
9+
//
10+
// Measured on THIS suite (one full `pnpm --filter @objectstack/objectql test`,
11+
// `origin/main` b1b7d6088a): 16,194 lines on the run's stdout, 4,744 of them
12+
// `[Registry] …`. 10,984 of the rest are the structured logger's
13+
// `<ts> INFO …` lines, which do not go through `console` at all and are NOT
14+
// what this key reaches (#13986) — so against the console-carried population
15+
// this suite emits, `[Registry]` is 4,744 of 5,210 = 91.1%, and 3,869 of those
16+
// are the single `Registered object:` line, emitted once per registered object
17+
// per registry construction across the package's 250 test files.
18+
//
19+
// `OS_REGISTRY_LOG` is `@objectstack/objectql`'s OWN published seam for that
20+
// verbosity (`SchemaRegistryOptions.logLevel` / `REGISTRY_LOG_LEVELS`,
21+
// registry.ts) — at `warn` the registry's private `log()` returns before
22+
// writing. What it does NOT silence is the diagnostics: the ADR-0005
23+
// `[Registry] Collision` lines go through a bare `console.warn` that the level
24+
// never gates, so a real shadowing still speaks here — measured, not inferred:
25+
// `registry-collision-order.test.ts` passes identically on both sides, and it
26+
// sets `logLevel = 'silent'` per registry anyway.
27+
//
28+
// ⛔ Two things this deliberately is NOT. It does not move the engine's
29+
// SHIPPED default (still `'info'` at registry.ts:1265, unchanged for every
30+
// production reader), and it does not make library code sniff
31+
// `process.env.VITEST` — a library that behaves differently under a test
32+
// runner would make every log reading in tests a reading of something other
33+
// than production. The request lives HERE, in the harness, where the test
34+
// author can see it.
35+
//
36+
// ⚠️ One test file in THIS package reads the same env var as its subject:
37+
// `registry-log-level.test.ts` pins how `OS_REGISTRY_LOG` resolves. It now
38+
// deletes the var in `beforeEach` (it already did in `afterEach`) and asserts
39+
// the level its "default" cases actually run at, so the harness key below
40+
// cannot silently re-point that file's premise. Without those two lines the
41+
// file's first case stays GREEN while testing `'warn'` under a name that says
42+
// `info` — measured red before they were added.
743
import { defineConfig } from 'vitest/config';
844

945
export default defineConfig({
@@ -15,5 +51,9 @@ export default defineConfig({
1551
// Mechanism + measured costs: examples/app-showcase/vitest.config.ts.
1652
// Enforced repo-wide by scripts/check-console-intercept-disarm.mjs.
1753
disableConsoleIntercept: true,
54+
// #13517: quiet the registry's per-item registration chatter — the
55+
// engine's own `OS_REGISTRY_LOG` seam, not a change to its shipped
56+
// default. Header docblock carries the measurement and the rationale.
57+
env: { OS_REGISTRY_LOG: 'warn' },
1858
},
1959
});

packages/runtime/vitest.config.ts

Lines changed: 38 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,38 @@
11
// Copyright (c) 2025 ObjectStack. Licensed under the Apache-2.0 license.
22

3+
// ── #13517: this suite asks the SchemaRegistry for quiet, DECLARATIVELY ─────
4+
//
5+
// Measured on THIS suite (one full `pnpm --filter @objectstack/runtime test`,
6+
// `origin/main` b1b7d6088a): 6,730 lines on the run's stdout, 1,155 of them
7+
// `[Registry] …`. 4,760 of the rest are the structured logger's `<ts> INFO …`
8+
// lines, which do not go through `console` at all and are NOT what this key
9+
// reaches (#13986).
10+
//
11+
// ⚠️ Read the share honestly, because this suite is NOT the dogfood one.
12+
// Against the console-carried population (1,957 lines) `[Registry]` is 1,155 —
13+
// **59%**, the largest single family but a long way from dogfood's 94.9%. The
14+
// remaining ~800 are a mixed tail this key cannot reach: `[sql-driver] while
15+
// creating/syncing table …` column reports, `[HonoServerPlugin] Server
16+
// stopped`, `Paged read of … is NOT deterministic`, `[action-audit] …` and
17+
// `[Protocol] DB hydration skipped …`. So the declaration below is worth its
18+
// line here, and it is also not the whole story here — quieting the rest is a
19+
// different question about those specific call sites, not a log level.
20+
//
21+
// `OS_REGISTRY_LOG` is `@objectstack/objectql`'s OWN published seam for that
22+
// verbosity (`SchemaRegistryOptions.logLevel` / `REGISTRY_LOG_LEVELS`,
23+
// registry.ts) — at `warn` the registry's private `log()` returns before
24+
// writing. What it does NOT silence is the diagnostics: the ADR-0005
25+
// `[Registry] Collision` lines go through a bare `console.warn` that the level
26+
// never gates, so a real shadowing still speaks here.
27+
//
28+
// ⛔ Two things this deliberately is NOT. It does not move the engine's
29+
// SHIPPED default (still `'info'` at objectql's registry.ts:1265, unchanged
30+
// for every production reader), and it does not make library code sniff
31+
// `process.env.VITEST` — a library that behaves differently under a test
32+
// runner would make every log reading in tests a reading of something other
33+
// than production. The request lives HERE, in the harness, where the test
34+
// author can see it.
35+
336
import { defineConfig } from 'vitest/config';
437
import path from 'node:path';
538

@@ -120,6 +153,11 @@ export default defineConfig({
120153
// Mechanism + measured costs: examples/app-showcase/vitest.config.ts.
121154
// Enforced repo-wide by scripts/check-console-intercept-disarm.mjs.
122155
disableConsoleIntercept: true,
156+
// #13517: quiet the registry's per-item registration chatter — the
157+
// engine's own `OS_REGISTRY_LOG` seam, not a change to its shipped
158+
// default. Header docblock carries the measurement and the rationale,
159+
// including the tail this key does NOT reach in this package.
160+
env: { OS_REGISTRY_LOG: 'warn' },
123161
globals: true,
124162
environment: 'node',
125163
include: ['src/**/*.test.ts'],

packages/verify/vitest.config.ts

Lines changed: 29 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4,6 +4,31 @@
44
// vitest's defaults, deliberately — a key added here re-specifies behaviour
55
// for every test file in the package (packages/cli/vitest.config.ts's header
66
// records the incident that taught that).
7+
//
8+
// ── #13517: this suite asks the SchemaRegistry for quiet, DECLARATIVELY ─────
9+
//
10+
// Measured on THIS suite (one full `pnpm --filter @objectstack/verify test`,
11+
// `origin/main` b1b7d6088a): 5,670 lines on the run's stdout, 2,323 of them
12+
// `[Registry] …`. 3,113 of the rest are the structured logger's `<ts> INFO …`
13+
// lines, which do not go through `console` at all and are NOT what this key
14+
// reaches (#13986) — so against the console-carried population this suite
15+
// emits, `[Registry]` is 2,323 of 2,557 = 90.8%. This package boots real app
16+
// stacks in its harness, so the count is per-boot registration chatter.
17+
//
18+
// `OS_REGISTRY_LOG` is `@objectstack/objectql`'s OWN published seam for that
19+
// verbosity (`SchemaRegistryOptions.logLevel` / `REGISTRY_LOG_LEVELS`,
20+
// registry.ts) — at `warn` the registry's private `log()` returns before
21+
// writing. What it does NOT silence is the diagnostics: the ADR-0005
22+
// `[Registry] Collision` lines go through a bare `console.warn` that the level
23+
// never gates, so a real shadowing still speaks here.
24+
//
25+
// ⛔ Two things this deliberately is NOT. It does not move the engine's
26+
// SHIPPED default (still `'info'` at objectql's registry.ts:1265, unchanged
27+
// for every production reader), and it does not make library code sniff
28+
// `process.env.VITEST` — a library that behaves differently under a test
29+
// runner would make every log reading in tests a reading of something other
30+
// than production. The request lives HERE, in the harness, where the test
31+
// author can see it.
732
import { defineConfig } from 'vitest/config';
833

934
export default defineConfig({
@@ -15,5 +40,9 @@ export default defineConfig({
1540
// Mechanism + measured costs: examples/app-showcase/vitest.config.ts.
1641
// Enforced repo-wide by scripts/check-console-intercept-disarm.mjs.
1742
disableConsoleIntercept: true,
43+
// #13517: quiet the registry's per-item registration chatter — the
44+
// engine's own `OS_REGISTRY_LOG` seam, not a change to its shipped
45+
// default. Header docblock carries the measurement and the rationale.
46+
env: { OS_REGISTRY_LOG: 'warn' },
1847
},
1948
});

0 commit comments

Comments
 (0)