Skip to content

Commit 64a42b9

Browse files
committed
test(publish-smoke): judge the boot before the probes run
The registry canary could not name a WARN-level boot failure. Two properties of the server-log scan combined: * SEVERITY - a plugin that fails to load logs at WARN, and the scan matched error|fatal only. * ORDER - the scan is the last thing in the script, after the probes, so even at a matching severity a boot defect was reported as a probe failure first. Measured on the specimen (run 34084559243): the pre-fix pattern matches ZERO lines in that boot window, after which the job probed every auth and CRUD route against a server with no auth and failed on a probe, naming nothing. A boot-load failure and an auth regression have different owners and produced the same job output. Adds a boot gate between sections 2 and 3 - the same shape the audience-posture assertion already uses, which fails before the behaviour probes for the same reason. Section 4 is NOT hoisted: it stays after the probes and keeps catching what they provoke. The predicate is severity-blind and keys on the sentence: a unit of the composition did not arrive. Widening to WARN was rejected against a measured healthy baseline - pack run 34276056630 boots healthily while emitting `Console dist not found` behind the same warn glyph the specimen uses. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_012GKcPZbMoGq7WPzKLfRBTU
1 parent efd6b43 commit 64a42b9

3 files changed

Lines changed: 519 additions & 8 deletions

File tree

Lines changed: 378 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,378 @@
1+
// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license.
2+
//
3+
// Pins the BOOT-ATTRIBUTION contract of `scripts/publish-smoke.sh` — the half
4+
// that decides whether a run blames the boot or blames a probe.
5+
//
6+
// ## What was measured
7+
//
8+
// Registry canary run `34084559243`, job `101626009369`. The entire defect was
9+
// one line, at boot:
10+
//
11+
// ⚠ AuthPlugin failed to load: The requested module '@better-auth/core/db'
12+
// does not provide an export named 'createLocalAccountIssuer'
13+
//
14+
// The run did not stop there. It probed every auth and CRUD route against a
15+
// server with no auth, and exited 1 on `GET /auth/get-session … got 404`. Two
16+
// properties of the log scan combined to produce that, and fixing either one
17+
// alone leaves the other:
18+
//
19+
// * SEVERITY — a plugin that fails to load logs at WARN, and the scan matched
20+
// `error|fatal` only. Measured against the specimen's own boot window, the
21+
// pre-fix pattern matches ZERO lines; `OLD_PATTERN_HITS` below is that
22+
// number, and it is the regression this file exists to hold at 0-is-wrong.
23+
// * ORDER — section 4 (log scan) is the LAST thing in the script, after
24+
// section 3 (probes), so even at a matching severity a boot defect is
25+
// reported as a probe failure first.
26+
//
27+
// The cost is not a false green — CI went red either way. It is OWNERSHIP: a
28+
// boot-load failure and a genuine auth regression have different owners and
29+
// produced the same job output.
30+
//
31+
// ## Why the predicate is not "warn", and how it was chosen
32+
//
33+
// The obvious repair — widen the severity set to WARN — is the wrong one, and
34+
// the healthy baseline is what says so rather than an opinion. `HEALTHY_BOOT`
35+
// below is the verbatim boot window of pack run `34276056630` (job
36+
// `102229481940`), a run whose auth and CRUD probes were ALL green and whose
37+
// banner reads `Plugins: 34 loaded` with `Auth` in the roster. It carries
38+
//
39+
// ⚠ Console dist not found — install `@object-ui/console` …
40+
//
41+
// — a warn-shaped line, with the SAME `⚠` glyph as the specimen, in a boot that
42+
// is completely healthy. Registry mode adds a second one (`[MetadataPlugin]
43+
// artifact … predates this runtime's spec`, normal for a published artifact).
44+
// A canary that reds on either gets ignored, and then nobody reads it when the
45+
// real boot breaks.
46+
//
47+
// So the predicate keys on the SENTENCE, not the level: *a unit of the
48+
// composition did not arrive*. Its two legs are asserted separately below
49+
// because they buy different things — leg A names the owner, leg B survives a
50+
// rewording — and a change that quietly drops one would otherwise still pass on
51+
// the specimen.
52+
//
53+
// ## Why these are executed assertions and not greps
54+
//
55+
// The pattern and the scrubber are read out of the script by SOURCING it, the
56+
// same mechanism the sibling collision test uses: a grep assertion also passes
57+
// against a version that names the behaviour only in a comment. The one
58+
// deliberate exception is ORDER_OK, which is a byte-offset comparison on the
59+
// file — order-in-file is the property under test and it lives BELOW the
60+
// sourcing guard, where sourcing cannot reach it. What that assertion can see
61+
// is that the gate is invoked before the probes; what it cannot see is whether
62+
// the gate does anything, which is what every other assertion here is for.
63+
64+
import { describe, it, expect } from 'vitest';
65+
import { execFileSync } from 'node:child_process';
66+
import fs from 'node:fs';
67+
import os from 'node:os';
68+
import path from 'node:path';
69+
import { fileURLToPath } from 'node:url';
70+
71+
const HERE = path.dirname(fileURLToPath(import.meta.url));
72+
const SCRIPT = path.resolve(HERE, '..', '..', '..', 'scripts', 'publish-smoke.sh');
73+
74+
function have(bin: string): boolean {
75+
try {
76+
execFileSync('sh', ['-c', `command -v ${bin}`], { stdio: 'ignore' });
77+
return true;
78+
} catch {
79+
return false;
80+
}
81+
}
82+
83+
// No ports, no network, no `/proc` — unlike the sibling collision test this one
84+
// only needs a shell and the two text utilities the gate itself calls.
85+
const RUNNABLE = ['bash', 'grep', 'sed'].every(have);
86+
87+
/**
88+
* ESC as an ESCAPE SPELLING, never a raw byte.
89+
*
90+
* A literal U+001B in this file would make `grep` treat the whole thing as
91+
* binary and report `Binary file … matches` instead of the line, which is how a
92+
* control byte hides from the very searches that would find it
93+
* (`scripts/check-nul-bytes.mjs` is the authority). It is materialised at
94+
* runtime, into the fixture only.
95+
*/
96+
const ESC = '\u001b';
97+
98+
/**
99+
* The specimen's boot window, verbatim from job `101626009369`.
100+
*
101+
* Trimmed to the boot — everything here was written before the first probe ran,
102+
* which is the whole point: this is what the gate gets to look at.
103+
*/
104+
const SPECIMEN_BOOT = [
105+
'',
106+
'◆ Development Mode',
107+
' Loading objectstack.config.ts...',
108+
" ⚠ AuthPlugin failed to load: The requested module '@better-auth/core/db' does not provide an export named 'createLocalAccountIssuer'",
109+
'[LocalCryptoProvider] No OS_SECRET_KEY/OS_DEV_CRYPTO_KEY set — generated a new AES-256-GCM key and persisted it to /tmp/y/dev-crypto-key (mode 0600).',
110+
"[sql-driver] DATABASE_ERROR — the backend refused a read on 'sys_organization' (SQLITE_ERROR). select `id` from `sys_organization` limit 500 - no such table: sys_organization ",
111+
' ↪ secret fields: LocalCryptoProvider wired (dev) — set OS_SECRET_KEY and swap for KMS/Vault in production',
112+
'',
113+
' ✓ Server is ready',
114+
'',
115+
' Plugins: 30 loaded',
116+
'',
117+
' ⚠ Boot diagnostics — 4 warnings logged during startup:',
118+
" 2026-09-07T04:51:11.594Z WARN [MetadataPlugin] artifact '/tmp/y/dist/objectstack.json' predates this runtime's spec (authored engines.protocol floor 17.0.0, runtime spec 17.3.0) — converted 1 site(s) forward via ADR-0087 conversion 'field-required-notnull-explicit'.",
119+
' 2026-09-07T04:51:11.638Z WARN CORE: Core service missing, functionality may be degraded: auth',
120+
' 2026-09-07T04:51:11.639Z WARN System started with degraded capabilities. Missing core services: auth',
121+
' 2026-09-07T04:51:11.761Z WARN SharingServicePlugin: could not enumerate organizations — declared sharing rules were NOT seeded per organization at this boot; seeding retries on the next boot and on organization creation',
122+
' run with --log-level debug to watch the boot stream live',
123+
'',
124+
].join('\n');
125+
126+
/**
127+
* A HEALTHY boot window, verbatim from pack run `34276056630` / job
128+
* `102229481940` — every auth and CRUD probe in that run was green.
129+
*
130+
* ⚠ The `⚠ Console dist not found` line is the reason this fixture is here and
131+
* not paraphrased. It is warn-shaped, glyph-prefixed exactly like the specimen,
132+
* and completely benign. Any predicate that reds on this fixture is a canary
133+
* that cries wolf, and `HEALTHY_WARN_LINES` below refuses to let it pass as a
134+
* vacuous green.
135+
*/
136+
const HEALTHY_BOOT = [
137+
'',
138+
'◆ Development Mode',
139+
' Loading objectstack.config.ts...',
140+
'[LocalCryptoProvider] No OS_SECRET_KEY/OS_DEV_CRYPTO_KEY set — generated a new AES-256-GCM key and persisted it to /tmp/x/dev-crypto-key (mode 0600).',
141+
' ⚠ Console dist not found — install `@object-ui/console` (already built) or run `pnpm --filter @object-ui/console build` in the objectui workspace',
142+
'[sql-driver] while creating table "sys_metadata_commit": declared field \'id\' asks for storage the platform\'s own \'id\' column does not provide — maxLength: 64 (the column is 255).',
143+
'[sql-driver] DATABASE_ERROR — the backend refused a raw statement (SQLITE_ERROR). statement: SELECT "tenant_id" FROM "_objectstack_sequences" WHERE 1 = 0 - no such table: _objectstack_sequences',
144+
' ↪ secret fields: LocalCryptoProvider wired (dev) — set OS_SECRET_KEY and swap for KMS/Vault in production',
145+
'',
146+
' ✓ Server is ready',
147+
'',
148+
' Plugins: 34 loaded',
149+
' ObjectQL, SqlDriver, HonoServer, Metadata, PlatformObjects, Auth, Security, Audit, RestAPI, SettingsServicePlugin, SharingServicePlugin, AnalyticsServicePlugin',
150+
'',
151+
].join('\n');
152+
153+
/**
154+
* Every benign `failed to load` in the tree, plus the two near-misses that make
155+
* the legs' boundaries real rather than asserted.
156+
*
157+
* All of these are degradations of a plugin that DID load — a locale bundle, a
158+
* metadata row, an optional transport dependency — which is why a bare
159+
* `failed to load` grep is not the predicate. The last two are the sharp cases:
160+
* `[i18n] … could not be loaded` says in its own text that it is "not a boot
161+
* failure", and `Service '…' not provided — using in-memory fallback` is the
162+
* kernel's warn for a core service that WAS covered — the sibling of leg B's
163+
* line, and the one it must not match.
164+
*/
165+
const BENIGN_BOOT = [
166+
' Loading objectstack.config.ts...',
167+
"SettingsServicePlugin: failed to load translations for 'fr': ENOENT: no such file or directory",
168+
"[platform-objects] failed to load setup-bundle translations for 'de': ENOENT",
169+
'[webhook-auto-enqueuer] failed to load sys_webhook_subscription',
170+
'Loader FileSystemLoader failed to load object:accounts',
171+
"[MarketplaceInstallLocal] failed to load app_crm translations for 'ja': ENOENT",
172+
'SmtpTransport: failed to load `nodemailer` — SMTP delivery is unavailable.',
173+
'[i18n] @objectstack/i18n-files was requested but could not be loaded (declared-not-installed).',
174+
' Unchanged: this boot serves i18n from the kernel in-memory fallback, so what follows',
175+
' is why the file-based service is absent — not a boot failure.',
176+
"Service 'cache' not provided — using in-memory fallback",
177+
' ✓ Server is ready',
178+
'',
179+
].join('\n');
180+
181+
/** The other two load-failure emit sites on the CLI's boot path (leg A2, A3). */
182+
const OTHER_SITES = [
183+
" ✗ Failed to load plugin: Cannot find module '@acme/plugin-thing'",
184+
'[Capability:audit] failed to load @objectstack/plugin-audit: boom',
185+
'',
186+
].join('\n');
187+
188+
const NONSENSE = ['the quick brown fox', 'lorem ipsum dolor sit amet', '1234567890', ''].join('\n');
189+
190+
/**
191+
* The specimen with ANSI landing INSIDE the matched span — `chalk.bold` on the
192+
* plugin name, under a logger that colorizes without a TTY.
193+
*
194+
* ⚠ Deliberately mid-span rather than wrapped around the whole line. Decoration
195+
* at the EDGES leaves `AuthPlugin failed to load:` contiguous, so an unanchored
196+
* pattern matches it even unscrubbed and a test built on that shape proves
197+
* nothing about the scrubber. This shape splits the span, and the measured
198+
* consequence is asserted below: without scrubbing the run still detects a
199+
* failed boot (leg B survives) but LOSES THE PLUGIN'S NAME — which is the one
200+
* thing this card is about.
201+
*/
202+
const DECORATED_BOOT = SPECIMEN_BOOT.replace(
203+
'⚠ AuthPlugin failed to load:',
204+
`⚠ ${ESC}[1mAuthPlugin${ESC}[22m failed to load:`,
205+
);
206+
207+
/** The pre-fix section-4 pattern, transcribed from `main` for the before/after. */
208+
const OLD_ERROR_PATTERN =
209+
'^\\[(error|fatal)\\]|"level":"(error|fatal)"|^\\S+Z ERROR |Failed to register OIDC discovery routes';
210+
211+
/**
212+
* Source the real script and run the real helpers over the fixtures, reporting
213+
* one `KEY=VALUE` line per measurement.
214+
*
215+
* `set +e +o pipefail` after the source for the reason the sibling documents:
216+
* the script's own `set -euo pipefail` comes with it, and several steps here are
217+
* EXPECTED to exit non-zero — a `grep` that matches nothing is the pass
218+
* condition for three of them. The harness's own exit status is not a
219+
* measurement; every measurement is a printed line and the assertions grade
220+
* those.
221+
*/
222+
function runHarness(): Record<string, string> {
223+
const dir = fs.mkdtempSync(path.join(os.tmpdir(), 'publish-smoke-boot-'));
224+
const write = (name: string, body: string): string => {
225+
const p = path.join(dir, name);
226+
fs.writeFileSync(p, body);
227+
return p;
228+
};
229+
const fixtures = {
230+
SPECIMEN: write('specimen.log', SPECIMEN_BOOT),
231+
HEALTHY: write('healthy.log', HEALTHY_BOOT),
232+
BENIGN: write('benign.log', BENIGN_BOOT),
233+
OTHER: write('other.log', OTHER_SITES),
234+
NONSENSE: write('nonsense.log', NONSENSE),
235+
DECORATED: write('decorated.log', DECORATED_BOOT),
236+
};
237+
238+
const harness = path.join(dir, 'harness.sh');
239+
fs.writeFileSync(
240+
harness,
241+
[
242+
'#!/usr/bin/env bash',
243+
'set -u',
244+
`export SCRATCH=${JSON.stringify(dir)}`,
245+
`source ${JSON.stringify(SCRIPT)}`,
246+
'set +e +u +o pipefail',
247+
'echo "SOURCED=ok"',
248+
// The pattern and the scrubber both have to EXIST as the script's own
249+
// seams. A rename that inlined either would otherwise leave this file
250+
// measuring nothing while staying green.
251+
'echo "HAS_PATTERN=$([ -n "${SMOKE_BOOT_FAILURE_PATTERN:-}" ] && echo yes || echo no)"',
252+
'echo "HAS_SCRUB=$(type -t smoke_scrub_ansi)"',
253+
'echo "HAS_LINES=$(type -t smoke_boot_failure_lines)"',
254+
// verdict <KEY> <fixture> — scrub, then run the REAL matcher.
255+
'verdict() {',
256+
// The scrub target is derived from SCRATCH and the KEY, never from `$src`:
257+
// an empty `$2` under `set +u` would otherwise make it `.scrubbed` in the
258+
// harness's inherited cwd — which is `packages/spec` under vitest, i.e. a
259+
// stray file inside the repo rather than a loud failure.
260+
' local key=$1 src=$2 out st',
261+
' if [ -z "$src" ]; then echo "${key}_STATUS=BADARGS"; return; fi',
262+
' local scrubbed="$SCRATCH/$key.scrubbed"',
263+
' smoke_scrub_ansi "$src" "$scrubbed"',
264+
' out=$(smoke_boot_failure_lines "$scrubbed"); st=$?',
265+
' echo "${key}_STATUS=$st"',
266+
' echo "${key}_HITS=$(printf %s "$out" | grep -c . )"',
267+
' echo "${key}_FIRST=$(printf %s "$out" | head -1 | tr -d "\\n")"',
268+
'}',
269+
...Object.entries(fixtures).map(([k, p]) => `verdict ${k} ${JSON.stringify(p)}`),
270+
// BEFORE: the pre-fix pattern over the specimen's own boot window.
271+
`OLD=${JSON.stringify(OLD_ERROR_PATTERN)}`,
272+
`echo "OLD_PATTERN_HITS=$(grep -cE "$OLD" ${JSON.stringify(fixtures.SPECIMEN)})"`,
273+
// Decoration: what is lost when the scrubber does not run.
274+
`echo "DECOR_UNSCRUBBED_NAMES_PLUGIN=$(grep -cE "$SMOKE_BOOT_FAILURE_PATTERN" ${JSON.stringify(fixtures.DECORATED)} )"`,
275+
// Vacuity guard: the healthy fixture really does carry warn-shaped lines.
276+
`echo "HEALTHY_WARN_LINES=$(grep -c '⚠' ${JSON.stringify(fixtures.HEALTHY)})"`,
277+
'exit 0',
278+
].join('\n'),
279+
{ mode: 0o755 },
280+
);
281+
282+
const out = execFileSync('bash', [harness], { encoding: 'utf8', timeout: 60_000 });
283+
const parsed: Record<string, string> = {};
284+
for (const line of out.split('\n')) {
285+
const m = /^([A-Z_]+)=(.*)$/.exec(line);
286+
if (m) parsed[m[1]] = m[2];
287+
}
288+
return parsed;
289+
}
290+
291+
describe.skipIf(!RUNNABLE)('[#16793] publish-smoke.sh judges the BOOT before it probes', () => {
292+
const r = RUNNABLE ? runHarness() : ({} as Record<string, string>);
293+
294+
it('sources cleanly and exposes the boot-failure seams', () => {
295+
expect(r.SOURCED).toBe('ok');
296+
expect(r.HAS_PATTERN, 'SMOKE_BOOT_FAILURE_PATTERN is not defined by the script').toBe('yes');
297+
expect(r.HAS_SCRUB).toBe('function');
298+
expect(r.HAS_LINES).toBe('function');
299+
});
300+
301+
it('BEFORE: the error-only scan is blind to the specimen — 0 hits in its boot window', () => {
302+
// The severity half of the defect, as a number. If this ever becomes
303+
// non-zero the pre-fix scan would have caught the specimen after all, and
304+
// the argument in this file's header needs re-measuring, not patching.
305+
expect(r.OLD_PATTERN_HITS).toBe('0');
306+
});
307+
308+
it('AFTER: the specimen fails at boot, and the failure NAMES the plugin', () => {
309+
expect(r.SPECIMEN_STATUS).toBe('0');
310+
// Attribution is the deliverable. A generic "the boot looks wrong" is the
311+
// same unowned red the card was filed about.
312+
expect(r.SPECIMEN_FIRST).toContain('AuthPlugin');
313+
expect(r.SPECIMEN_FIRST).toContain('failed to load');
314+
expect(r.SPECIMEN_FIRST).toContain('createLocalAccountIssuer');
315+
});
316+
317+
it('leg B fires on the kernel verdict alone, so a reworded cause still reds', () => {
318+
// Three hits, not one: the load site (A1) plus BOTH kernel lines (B). The
319+
// count is asserted because it is what proves leg B is live — drop it and
320+
// the specimen still passes on A1 alone, and the next differently-worded
321+
// boot defect goes back to being a probe failure.
322+
expect(r.SPECIMEN_HITS).toBe('3');
323+
});
324+
325+
it('FIRING CONTROL: a healthy boot still passes, warn lines and all', () => {
326+
// Verbatim from a run whose probes were all green. A fix that reds here is
327+
// worse than the defect: a canary that cries wolf stops being read.
328+
expect(r.HEALTHY_STATUS).toBe('1');
329+
expect(r.HEALTHY_HITS).toBe('0');
330+
// …and the fixture is not vacuously clean — it carries the same `⚠` glyph
331+
// the specimen does.
332+
expect(Number(r.HEALTHY_WARN_LINES)).toBeGreaterThan(0);
333+
});
334+
335+
it('the benign `failed to load` family is NOT a boot failure', () => {
336+
expect(r.BENIGN_STATUS).toBe('1');
337+
expect(r.BENIGN_HITS).toBe('0');
338+
});
339+
340+
it('nonsense control: no fixture-independent match', () => {
341+
expect(r.NONSENSE_STATUS).toBe('1');
342+
expect(r.NONSENSE_HITS).toBe('0');
343+
});
344+
345+
it('the other two load-failure sites on the boot path are covered', () => {
346+
expect(r.OTHER_STATUS).toBe('0');
347+
expect(r.OTHER_HITS).toBe('2');
348+
});
349+
350+
it('DECORATION CONTROL: scrubbing is what keeps the plugin NAMED', () => {
351+
// Scrubbed: identical to the undecorated specimen, name included.
352+
expect(r.DECORATED_STATUS).toBe('0');
353+
expect(r.DECORATED_HITS).toBe('3');
354+
expect(r.DECORATED_FIRST).toContain('AuthPlugin');
355+
// Unscrubbed, the same input yields 2 — the two kernel lines. The one that
356+
// is lost is precisely the one carrying the plugin's name, which is the
357+
// measured reason the gate scrubs first rather than trusting NO_COLOR.
358+
expect(r.DECOR_UNSCRUBBED_NAMES_PLUGIN).toBe('2');
359+
});
360+
361+
it('ORDER: the gate is invoked before the probes, and section 4 stays put', () => {
362+
// A text assertion, deliberately, and the header says why: the gate runs
363+
// below the sourcing guard where sourcing cannot reach it, and ORDER is the
364+
// property. It grades position only — every other test here grades
365+
// behaviour.
366+
const src = fs.readFileSync(SCRIPT, 'utf8');
367+
const gate = src.indexOf('if smoke_boot_failure_lines "$BOOT_LOG"; then');
368+
const probes = src.indexOf('# ── 3. probes ');
369+
const scan = src.indexOf('# ── 4. log scan ');
370+
expect(gate, 'the boot gate is not invoked at all').toBeGreaterThan(-1);
371+
expect(probes).toBeGreaterThan(-1);
372+
expect(scan).toBeGreaterThan(-1);
373+
expect(gate, 'the boot gate must run BEFORE the probes').toBeLessThan(probes);
374+
// Section 4 was NOT hoisted: moving it forward would drop the probe-window
375+
// errors it exists to catch, which is a different regression.
376+
expect(scan, 'section 4 must still run after the probes').toBeGreaterThan(probes);
377+
});
378+
});

packages/spec/vitest.repo-tests.json

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@
1111
"scripts/gen-sdui-manifest-write-target.test.ts",
1212
"scripts/liveness/evidence.test.ts",
1313
"scripts/liveness/proof-registry.test.ts",
14+
"scripts/publish-smoke-boot-failure.test.ts",
1415
"scripts/publish-smoke-port-collision.test.ts",
1516
"scripts/query-pointer-row.test.ts",
1617
"scripts/references-banner.test.ts",

0 commit comments

Comments
 (0)