diff --git a/packages/spec/scripts/publish-smoke-boot-failure.test.ts b/packages/spec/scripts/publish-smoke-boot-failure.test.ts new file mode 100644 index 0000000000..88f92dfee5 --- /dev/null +++ b/packages/spec/scripts/publish-smoke-boot-failure.test.ts @@ -0,0 +1,430 @@ +// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license. +// +// Pins the BOOT-ATTRIBUTION contract of `scripts/publish-smoke.sh` — the half +// that decides whether a run blames the boot or blames a probe. +// +// ## What was measured +// +// Registry canary run `34084559243`, job `101626009369`. The entire defect was +// one line, at boot: +// +// ⚠ AuthPlugin failed to load: The requested module '@better-auth/core/db' +// does not provide an export named 'createLocalAccountIssuer' +// +// The run did not stop there. It probed every auth and CRUD route against a +// server with no auth, and exited 1 on `GET /auth/get-session … got 404`. Two +// properties of the log scan combined to produce that, and fixing either one +// alone leaves the other: +// +// * SEVERITY — a plugin that fails to load logs at WARN, and the scan matched +// `error|fatal` only. Measured against the specimen's own boot window, the +// pre-fix pattern matches ZERO lines; `OLD_PATTERN_HITS` below is that +// number, and it is the regression this file exists to hold at 0-is-wrong. +// * ORDER — section 4 (log scan) is the LAST thing in the script, after +// section 3 (probes), so even at a matching severity a boot defect is +// reported as a probe failure first. +// +// The cost is not a false green — CI went red either way. It is OWNERSHIP: a +// boot-load failure and a genuine auth regression have different owners and +// produced the same job output. +// +// ## Why the predicate is not "warn", and how it was chosen +// +// The obvious repair — widen the severity set to WARN — is the wrong one, and +// the healthy baseline is what says so rather than an opinion. `HEALTHY_BOOT` +// below is the verbatim boot window of pack run `34276056630` (job +// `102229481940`), a run whose auth and CRUD probes were ALL green and whose +// banner reads `Plugins: 34 loaded` with `Auth` in the roster. It carries +// +// ⚠ Console dist not found — install `@object-ui/console` … +// +// — a warn-shaped line, with the SAME `⚠` glyph as the specimen, in a boot that +// is completely healthy. Registry mode adds a second one (`[MetadataPlugin] +// artifact … predates this runtime's spec`, normal for a published artifact). +// A canary that reds on either gets ignored, and then nobody reads it when the +// real boot breaks. +// +// So the predicate keys on the SENTENCE, not the level: *a unit of the +// composition did not arrive*. Its two legs are asserted separately below +// because they buy different things — leg A names the owner, leg B survives a +// rewording — and a change that quietly drops one would otherwise still pass on +// the specimen. +// +// ## Why these are executed assertions and not greps +// +// The pattern and the scrubber are read out of the script by SOURCING it, the +// same mechanism the sibling collision test uses: a grep assertion also passes +// against a version that names the behaviour only in a comment. The one +// deliberate exception is ORDER_OK, which is a byte-offset comparison on the +// file — order-in-file is the property under test and it lives BELOW the +// sourcing guard, where sourcing cannot reach it. What that assertion can see +// is that the gate is invoked before the probes; what it cannot see is whether +// the gate does anything, which is what every other assertion here is for. + +import { describe, it, expect } from 'vitest'; +import { execFileSync } from 'node:child_process'; +import fs from 'node:fs'; +import os from 'node:os'; +import path from 'node:path'; +import { fileURLToPath } from 'node:url'; + +const HERE = path.dirname(fileURLToPath(import.meta.url)); +const SCRIPT = path.resolve(HERE, '..', '..', '..', 'scripts', 'publish-smoke.sh'); + +function have(bin: string): boolean { + try { + execFileSync('sh', ['-c', `command -v ${bin}`], { stdio: 'ignore' }); + return true; + } catch { + return false; + } +} + +// No ports, no network, no `/proc` — unlike the sibling collision test this one +// only needs a shell and the two text utilities the gate itself calls. +const RUNNABLE = ['bash', 'grep', 'sed'].every(have); + +/** + * ESC as an ESCAPE SPELLING, never a raw byte. + * + * A literal U+001B in this file would make `grep` treat the whole thing as + * binary and report `Binary file … matches` instead of the line, which is how a + * control byte hides from the very searches that would find it + * (`scripts/check-nul-bytes.mjs` is the authority). It is materialised at + * runtime, into the fixture only. + */ +const ESC = '\u001b'; + +/** + * The specimen's boot window, verbatim from job `101626009369`. + * + * Trimmed to the boot — everything here was written before the first probe ran, + * which is the whole point: this is what the gate gets to look at. + */ +const SPECIMEN_BOOT = [ + '', + '◆ Development Mode', + ' Loading objectstack.config.ts...', + " ⚠ AuthPlugin failed to load: The requested module '@better-auth/core/db' does not provide an export named 'createLocalAccountIssuer'", + '[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).', + "[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 ", + ' ↪ secret fields: LocalCryptoProvider wired (dev) — set OS_SECRET_KEY and swap for KMS/Vault in production', + '', + ' ✓ Server is ready', + '', + ' Plugins: 30 loaded', + '', + ' ⚠ Boot diagnostics — 4 warnings logged during startup:', + " 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'.", + ' 2026-09-07T04:51:11.638Z WARN CORE: Core service missing, functionality may be degraded: auth', + ' 2026-09-07T04:51:11.639Z WARN System started with degraded capabilities. Missing core services: auth', + ' 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', + ' run with --log-level debug to watch the boot stream live', + '', +].join('\n'); + +/** + * A HEALTHY boot window, verbatim from pack run `34276056630` / job + * `102229481940` — every auth and CRUD probe in that run was green. + * + * ⚠ The `⚠ Console dist not found` line is the reason this fixture is here and + * not paraphrased. It is warn-shaped, glyph-prefixed exactly like the specimen, + * and completely benign. Any predicate that reds on this fixture is a canary + * that cries wolf, and `HEALTHY_WARN_LINES` below refuses to let it pass as a + * vacuous green. + */ +const HEALTHY_BOOT = [ + '', + '◆ Development Mode', + ' Loading objectstack.config.ts...', + '[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).', + ' ⚠ Console dist not found — install `@object-ui/console` (already built) or run `pnpm --filter @object-ui/console build` in the objectui workspace', + '[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).', + '[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', + ' ↪ secret fields: LocalCryptoProvider wired (dev) — set OS_SECRET_KEY and swap for KMS/Vault in production', + '', + ' ✓ Server is ready', + '', + ' Plugins: 34 loaded', + ' ObjectQL, SqlDriver, HonoServer, Metadata, PlatformObjects, Auth, Security, Audit, RestAPI, SettingsServicePlugin, SharingServicePlugin, AnalyticsServicePlugin', + '', +].join('\n'); + +/** + * A healthy REGISTRY-mode boot window. + * + * ⚠ Unlike `HEALTHY_BOOT` this one is RECONSTRUCTED, not verbatim, and the + * distinction is load-bearing so it is stated rather than glossed: it is the + * specimen's own boot window (job `101626009369`) with the four lines + * attributable to the defect removed — the `AuthPlugin failed to load` line, + * both kernel degraded-capability lines, and `SharingServicePlugin: could not + * enumerate organizations`, which only failed because the plugin that creates + * `sys_organization` never loaded. What is KEPT is the one boot warning that is + * normal for registry mode: the canary installs the LAST PUBLISHED release, so + * an artifact whose protocol floor predates the runtime's spec is expected, and + * the ADR-0087 forward conversion says so at WARN. + * + * ⭐ This fixture exists because the pack-mode one could not do this job, and + * that was MEASURED rather than foreseen: under a deliberately wrong + * `WARN|warn` predicate the firing control below stayed GREEN, because + * `HEALTHY_BOOT`'s only warn-shaped line carries the `⚠` glyph and never the + * word. A healthy boot that spells `WARN` in full is what makes "⛔ do not + * widen the severity set wholesale" a thing this file can actually catch. + */ +const HEALTHY_REGISTRY_BOOT = [ + '', + '◆ Development Mode', + ' Loading objectstack.config.ts...', + '[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).', + ' ↪ secret fields: LocalCryptoProvider wired (dev) — set OS_SECRET_KEY and swap for KMS/Vault in production', + '', + ' ✓ Server is ready', + '', + ' Plugins: 31 loaded', + '', + ' ⚠ Boot diagnostics — 1 warning logged during startup:', + " 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'.", + ' run with --log-level debug to watch the boot stream live', + '', +].join('\n'); + +/** + * Every benign `failed to load` in the tree, plus the two near-misses that make + * the legs' boundaries real rather than asserted. + * + * All of these are degradations of a plugin that DID load — a locale bundle, a + * metadata row, an optional transport dependency — which is why a bare + * `failed to load` grep is not the predicate. The last two are the sharp cases: + * `[i18n] … could not be loaded` says in its own text that it is "not a boot + * failure", and `Service '…' not provided — using in-memory fallback` is the + * kernel's warn for a core service that WAS covered — the sibling of leg B's + * line, and the one it must not match. + */ +const BENIGN_BOOT = [ + ' Loading objectstack.config.ts...', + "SettingsServicePlugin: failed to load translations for 'fr': ENOENT: no such file or directory", + "[platform-objects] failed to load setup-bundle translations for 'de': ENOENT", + '[webhook-auto-enqueuer] failed to load sys_webhook_subscription', + 'Loader FileSystemLoader failed to load object:accounts', + "[MarketplaceInstallLocal] failed to load app_crm translations for 'ja': ENOENT", + 'SmtpTransport: failed to load `nodemailer` — SMTP delivery is unavailable.', + '[i18n] @objectstack/i18n-files was requested but could not be loaded (declared-not-installed).', + ' Unchanged: this boot serves i18n from the kernel in-memory fallback, so what follows', + ' is why the file-based service is absent — not a boot failure.', + "Service 'cache' not provided — using in-memory fallback", + ' ✓ Server is ready', + '', +].join('\n'); + +/** The other two load-failure emit sites on the CLI's boot path (leg A2, A3). */ +const OTHER_SITES = [ + " ✗ Failed to load plugin: Cannot find module '@acme/plugin-thing'", + '[Capability:audit] failed to load @objectstack/plugin-audit: boom', + '', +].join('\n'); + +const NONSENSE = ['the quick brown fox', 'lorem ipsum dolor sit amet', '1234567890', ''].join('\n'); + +/** + * The specimen with ANSI landing INSIDE the matched span — `chalk.bold` on the + * plugin name, under a logger that colorizes without a TTY. + * + * ⚠ Deliberately mid-span rather than wrapped around the whole line. Decoration + * at the EDGES leaves `AuthPlugin failed to load:` contiguous, so an unanchored + * pattern matches it even unscrubbed and a test built on that shape proves + * nothing about the scrubber. This shape splits the span, and the measured + * consequence is asserted below: without scrubbing the run still detects a + * failed boot (leg B survives) but LOSES THE PLUGIN'S NAME — which is the one + * thing this card is about. + */ +const DECORATED_BOOT = SPECIMEN_BOOT.replace( + '⚠ AuthPlugin failed to load:', + `⚠ ${ESC}[1mAuthPlugin${ESC}[22m failed to load:`, +); + +/** The pre-fix section-4 pattern, transcribed from `main` for the before/after. */ +const OLD_ERROR_PATTERN = + '^\\[(error|fatal)\\]|"level":"(error|fatal)"|^\\S+Z ERROR |Failed to register OIDC discovery routes'; + +/** + * Source the real script and run the real helpers over the fixtures, reporting + * one `KEY=VALUE` line per measurement. + * + * `set +e +o pipefail` after the source for the reason the sibling documents: + * the script's own `set -euo pipefail` comes with it, and several steps here are + * EXPECTED to exit non-zero — a `grep` that matches nothing is the pass + * condition for three of them. The harness's own exit status is not a + * measurement; every measurement is a printed line and the assertions grade + * those. + */ +function runHarness(): Record { + const dir = fs.mkdtempSync(path.join(os.tmpdir(), 'publish-smoke-boot-')); + const write = (name: string, body: string): string => { + const p = path.join(dir, name); + fs.writeFileSync(p, body); + return p; + }; + const fixtures = { + SPECIMEN: write('specimen.log', SPECIMEN_BOOT), + HEALTHY: write('healthy.log', HEALTHY_BOOT), + BENIGN: write('benign.log', BENIGN_BOOT), + OTHER: write('other.log', OTHER_SITES), + NONSENSE: write('nonsense.log', NONSENSE), + DECORATED: write('decorated.log', DECORATED_BOOT), + REGISTRY: write('registry.log', HEALTHY_REGISTRY_BOOT), + }; + + const harness = path.join(dir, 'harness.sh'); + fs.writeFileSync( + harness, + [ + '#!/usr/bin/env bash', + 'set -u', + `export SCRATCH=${JSON.stringify(dir)}`, + `source ${JSON.stringify(SCRIPT)}`, + 'set +e +u +o pipefail', + 'echo "SOURCED=ok"', + // The pattern and the scrubber both have to EXIST as the script's own + // seams. A rename that inlined either would otherwise leave this file + // measuring nothing while staying green. + 'echo "HAS_PATTERN=$([ -n "${SMOKE_BOOT_FAILURE_PATTERN:-}" ] && echo yes || echo no)"', + 'echo "HAS_SCRUB=$(type -t smoke_scrub_ansi)"', + 'echo "HAS_LINES=$(type -t smoke_boot_failure_lines)"', + // verdict — scrub, then run the REAL matcher. + 'verdict() {', + // The scrub target is derived from SCRATCH and the KEY, never from `$src`: + // an empty `$2` under `set +u` would otherwise make it `.scrubbed` in the + // harness's inherited cwd — which is `packages/spec` under vitest, i.e. a + // stray file inside the repo rather than a loud failure. + ' local key=$1 src=$2 out st', + ' if [ -z "$src" ]; then echo "${key}_STATUS=BADARGS"; return; fi', + ' local scrubbed="$SCRATCH/$key.scrubbed"', + ' smoke_scrub_ansi "$src" "$scrubbed"', + ' out=$(smoke_boot_failure_lines "$scrubbed"); st=$?', + ' echo "${key}_STATUS=$st"', + ' echo "${key}_HITS=$(printf %s "$out" | grep -c . )"', + ' echo "${key}_FIRST=$(printf %s "$out" | head -1 | tr -d "\\n")"', + '}', + ...Object.entries(fixtures).map(([k, p]) => `verdict ${k} ${JSON.stringify(p)}`), + // BEFORE: the pre-fix pattern over the specimen's own boot window. + `OLD=${JSON.stringify(OLD_ERROR_PATTERN)}`, + `echo "OLD_PATTERN_HITS=$(grep -cE "$OLD" ${JSON.stringify(fixtures.SPECIMEN)})"`, + // Decoration: what is lost when the scrubber does not run. + `echo "DECOR_UNSCRUBBED_NAMES_PLUGIN=$(grep -cE "$SMOKE_BOOT_FAILURE_PATTERN" ${JSON.stringify(fixtures.DECORATED)} )"`, + // Vacuity guard: the healthy fixture really does carry warn-shaped lines. + `echo "HEALTHY_WARN_LINES=$(grep -c '⚠' ${JSON.stringify(fixtures.HEALTHY)})"`, + `echo "REGISTRY_WARN_WORDS=$(grep -c 'WARN' ${JSON.stringify(fixtures.REGISTRY)})"`, + 'exit 0', + ].join('\n'), + { mode: 0o755 }, + ); + + const out = execFileSync('bash', [harness], { encoding: 'utf8', timeout: 60_000 }); + const parsed: Record = {}; + for (const line of out.split('\n')) { + const m = /^([A-Z_]+)=(.*)$/.exec(line); + if (m) parsed[m[1]] = m[2]; + } + return parsed; +} + +describe.skipIf(!RUNNABLE)('[#16793] publish-smoke.sh judges the BOOT before it probes', () => { + const r = RUNNABLE ? runHarness() : ({} as Record); + + it('sources cleanly and exposes the boot-failure seams', () => { + expect(r.SOURCED).toBe('ok'); + expect(r.HAS_PATTERN, 'SMOKE_BOOT_FAILURE_PATTERN is not defined by the script').toBe('yes'); + expect(r.HAS_SCRUB).toBe('function'); + expect(r.HAS_LINES).toBe('function'); + }); + + it('BEFORE: the error-only scan is blind to the specimen — 0 hits in its boot window', () => { + // The severity half of the defect, as a number. If this ever becomes + // non-zero the pre-fix scan would have caught the specimen after all, and + // the argument in this file's header needs re-measuring, not patching. + expect(r.OLD_PATTERN_HITS).toBe('0'); + }); + + it('AFTER: the specimen fails at boot, and the failure NAMES the plugin', () => { + expect(r.SPECIMEN_STATUS).toBe('0'); + // Attribution is the deliverable. A generic "the boot looks wrong" is the + // same unowned red the card was filed about. + expect(r.SPECIMEN_FIRST).toContain('AuthPlugin'); + expect(r.SPECIMEN_FIRST).toContain('failed to load'); + expect(r.SPECIMEN_FIRST).toContain('createLocalAccountIssuer'); + }); + + it('leg B fires on the kernel verdict alone, so a reworded cause still reds', () => { + // Three hits, not one: the load site (A1) plus BOTH kernel lines (B). The + // count is asserted because it is what proves leg B is live — drop it and + // the specimen still passes on A1 alone, and the next differently-worded + // boot defect goes back to being a probe failure. + expect(r.SPECIMEN_HITS).toBe('3'); + }); + + it('FIRING CONTROL: a healthy boot still passes, warn lines and all', () => { + // Verbatim from a run whose probes were all green. A fix that reds here is + // worse than the defect: a canary that cries wolf stops being read. + expect(r.HEALTHY_STATUS).toBe('1'); + expect(r.HEALTHY_HITS).toBe('0'); + // …and the fixture is not vacuously clean — it carries the same `⚠` glyph + // the specimen does. + expect(Number(r.HEALTHY_WARN_LINES)).toBeGreaterThan(0); + }); + + it('FIRING CONTROL 2: a healthy REGISTRY boot passes even though it spells WARN', () => { + // The half `HEALTHY_BOOT` cannot test. Registry mode installs the last + // PUBLISHED release, so a protocol-floor conversion warning is normal there + // — and it arrives as a full `Z WARN …` line. This is the assertion + // that turns "⛔ do not widen the severity set to WARN" from advice in a + // comment into something that reddens. + expect(r.REGISTRY_STATUS).toBe('1'); + expect(r.REGISTRY_HITS).toBe('0'); + // Vacuity guard: the fixture really does contain the literal word. + expect(Number(r.REGISTRY_WARN_WORDS)).toBeGreaterThan(0); + }); + + it('the benign `failed to load` family is NOT a boot failure', () => { + expect(r.BENIGN_STATUS).toBe('1'); + expect(r.BENIGN_HITS).toBe('0'); + }); + + it('nonsense control: no fixture-independent match', () => { + expect(r.NONSENSE_STATUS).toBe('1'); + expect(r.NONSENSE_HITS).toBe('0'); + }); + + it('the other two load-failure sites on the boot path are covered', () => { + expect(r.OTHER_STATUS).toBe('0'); + expect(r.OTHER_HITS).toBe('2'); + }); + + it('DECORATION CONTROL: scrubbing is what keeps the plugin NAMED', () => { + // Scrubbed: identical to the undecorated specimen, name included. + expect(r.DECORATED_STATUS).toBe('0'); + expect(r.DECORATED_HITS).toBe('3'); + expect(r.DECORATED_FIRST).toContain('AuthPlugin'); + // Unscrubbed, the same input yields 2 — the two kernel lines. The one that + // is lost is precisely the one carrying the plugin's name, which is the + // measured reason the gate scrubs first rather than trusting NO_COLOR. + expect(r.DECOR_UNSCRUBBED_NAMES_PLUGIN).toBe('2'); + }); + + it('ORDER: the gate is invoked before the probes, and section 4 stays put', () => { + // A text assertion, deliberately, and the header says why: the gate runs + // below the sourcing guard where sourcing cannot reach it, and ORDER is the + // property. It grades position only — every other test here grades + // behaviour. + const src = fs.readFileSync(SCRIPT, 'utf8'); + const gate = src.indexOf('if smoke_boot_failure_lines "$BOOT_LOG"; then'); + const probes = src.indexOf('# ── 3. probes '); + const scan = src.indexOf('# ── 4. log scan '); + expect(gate, 'the boot gate is not invoked at all').toBeGreaterThan(-1); + expect(probes).toBeGreaterThan(-1); + expect(scan).toBeGreaterThan(-1); + expect(gate, 'the boot gate must run BEFORE the probes').toBeLessThan(probes); + // Section 4 was NOT hoisted: moving it forward would drop the probe-window + // errors it exists to catch, which is a different regression. + expect(scan, 'section 4 must still run after the probes').toBeGreaterThan(probes); + }); +}); diff --git a/packages/spec/vitest.repo-tests.json b/packages/spec/vitest.repo-tests.json index a9e5e0aef7..9e6156d2dd 100644 --- a/packages/spec/vitest.repo-tests.json +++ b/packages/spec/vitest.repo-tests.json @@ -11,6 +11,7 @@ "scripts/gen-sdui-manifest-write-target.test.ts", "scripts/liveness/evidence.test.ts", "scripts/liveness/proof-registry.test.ts", + "scripts/publish-smoke-boot-failure.test.ts", "scripts/publish-smoke-port-collision.test.ts", "scripts/query-pointer-row.test.ts", "scripts/references-banner.test.ts", diff --git a/scripts/publish-smoke.sh b/scripts/publish-smoke.sh index 496ed6e17d..bd4a22ceea 100644 --- a/scripts/publish-smoke.sh +++ b/scripts/publish-smoke.sh @@ -471,6 +471,99 @@ smoke_wait_for_own_server() { fail "dev server published port $bound but never answered there within $((timeout * 2))s" } +# ── what counts as an error line, and what counts as a FAILED BOOT ────────── +# +# Two patterns, two windows, two different questions. Spelled here, above the +# sourcing guard, so both are driven by the tests instead of grepped for — the +# same reason `smoke_dev_server_argv` is a function (see its note above). +# +# SMOKE_ERROR_LOG_PATTERN — "did anything log at error level?", asked of the +# WHOLE log after the probes (section 4). Unchanged in content from the inline +# expression it replaces. Three error formats coexist: ConsoleLogger +# `[error] …`, JsonLogger `"level":"error"`, and timestamped ` ERROR …`. +# The trailing `Failed to register OIDC discovery routes` is a special case left +# from #3091 and is deliberately KEPT: nothing below generalises it. +SMOKE_ERROR_LOG_PATTERN='^\[(error|fatal)\]|"level":"(error|fatal)"|^\S+Z ERROR |Failed to register OIDC discovery routes' + +# SMOKE_BOOT_FAILURE_PATTERN — "did the composition this run installed actually +# ARRIVE?", asked of the boot window BEFORE the probes. +# +# The gate this pattern feeds exists because a boot-load failure and an auth +# regression are different owners that used to produce the same job output. In +# run 34084559243 the whole defect was one WARN line at boot — +# +# ⚠ AuthPlugin failed to load: The requested module '@better-auth/core/db' +# does not provide an export named 'createLocalAccountIssuer' +# +# — after which the run probed every auth and CRUD route against a server with +# no auth and failed on a probe, naming nothing. +# +# ⛔ The severity is NOT the predicate. Widening the error scan to WARN is the +# obvious repair and it is the wrong one: warn is where this repo deliberately +# puts functional degradation (AGENTS.md → "Degradation log levels"), so a +# healthy boot HAS warn lines and a canary that reds on them gets ignored. +# MEASURED, rather than assumed — the warn-shaped lines a healthy boot emits: +# +# pack mode, run 34276056630 (all auth+CRUD probes green, `Plugins: 34 +# loaded`, and no boot-diagnostics block at all, i.e. zero structured warns): +# ⚠ Console dist not found — install `@object-ui/console` … +# registry mode, run 34084559243 (the broken boot; this is the one of its four +# boot warnings that is normal for registry mode — a published artifact +# legitimately predates the runtime's spec): +# Z WARN [MetadataPlugin] artifact … predates this runtime's spec … +# +# Both are healthy, and the first even carries the same `⚠` glyph as the +# specimen — so `⚠`, `warn`, and "a plugin word appears" are all disqualified as +# predicates. So is a bare `failed to load` grep: it matches the benign +# content-load degradations of plugins that DID load (`SettingsServicePlugin: +# failed to load translations for 'fr'`, `[platform-objects] failed to load … +# translations`, `Loader … failed to load :`). +# +# The predicate is instead: A UNIT OF THE COMPOSITION DID NOT ARRIVE. Two legs, +# answering two different halves of that: +# +# A. the load site names the unit that failed — this is what gives the run an +# OWNER to report. One alternative per real emit site in the CLI's boot +# path (`packages/cli/src/commands/serve.ts`): +# A1 `⚠ AuthPlugin failed to load: ` (:3917, warn) +# A2 `✗ Failed to load plugin: ` (:3958, error TEXT +# but not error LEVEL, +# so section 4 misses +# this one too) +# A3 `[Capability:] failed to load : …` (:4338, ditto) +# A1 carries a tail guard — "load" must not be followed by another WORD — +# and that guard is the whole difference between `AuthPlugin failed to +# load: …` and `SettingsServicePlugin: failed to load translations …`. +# A2/A3 need no such guard: their subjects are already unambiguous. +# +# B. the KERNEL's own verdict that it booted without a declared core service +# (`packages/core/src/kernel.ts` :354/:370). This leg is the answer to "the +# next boot defect will be worded differently": it never reads the cause at +# all, so it fires whatever the load site said — or said nothing. It is by +# construction never benign, because a core service that DID get a fallback +# takes the sibling warn `Service '…' not provided — using in-memory +# fallback`, which this pattern deliberately does not match. +# +# ⚠ Deliberately UNANCHORED. These lines arrive behind a ` ⚠ ` glyph, or a +# `Z WARN ` logger prefix, or indented inside the boot-diagnostics summary +# block — and a pattern that assumed one of those spellings is exactly how the +# scan below already missed a decorated `ERROR` once (the NO_COLOR note in +# section 2). The gate scrubs ANSI before matching, for that same reason. +SMOKE_BOOT_FAILURE_PATTERN='[[:alnum:]_]+Plugin failed to (load|start)[[:space:]]*($|[^[:alnum:][:space:]])|[Ff]ailed to load plugin|\[Capability:[^]]+\] failed to load|System started with degraded capabilities|CORE: Core service missing' + +# Strip ANSI SGR sequences: $1 -> $2. Both windows scrub before matching, so a +# colorized line cannot slip past either one. +smoke_scrub_ansi() { + sed -e $'s/\x1b\\[[0-9;]*m//g' "$1" > "$2" +} + +# Print the boot-failure lines in $1 (ALREADY scrubbed), with line numbers. +# Status 0 when at least one matched, so `if smoke_boot_failure_lines …; then` +# reads as "the boot failed". +smoke_boot_failure_lines() { + grep -nE "$SMOKE_BOOT_FAILURE_PATTERN" "$1" +} + # Sourcing this file defines the helpers above and runs nothing. `${BASH_SOURCE[0]}` # differs from `$0` exactly when the file is sourced, which is how the collision # test drives the real functions instead of grepping for them — a grep passes @@ -762,6 +855,35 @@ if [ "$BOUND_PORT" != "$SMOKE_PORT" ]; then fi BASE_URL="http://localhost:$BOUND_PORT" +# ── boot gate — BETWEEN 2 and 3, and that position is the point ───────────── +# Nothing has been probed yet, so `$SERVER_LOG` right here IS the boot window. +# +# This is the same refusal the audience-posture assertion in section 3 makes, +# applied to the case it missed: fail BEFORE the behaviour probes, which would +# otherwise report the real defect as a cheerful downstream 4xx. A server that +# came up without its auth plugin answers every auth probe honestly — 404, no +# auth here — and that answer is indistinguishable from an auth regression, +# which has a different owner. So the boot is judged on its own before anything +# is asked of it. +# +# ⛔ This is NOT section 4 moved forward. Section 4 stays where it is and keeps +# scanning the whole log after the probes; hoisting it would drop the +# probe-window errors it exists to catch. What runs here is the boot-failure +# predicate (see SMOKE_BOOT_FAILURE_PATTERN) — which is severity-blind, and so +# closes the WARN half — plus the error-level scan against the boot window +# only, which costs nothing (such a line already fails the run in section 4) +# and buys the same attribution for an error-level boot failure. +log "Checking the boot for a composition that did not load" +BOOT_LOG="$SMOKE_ROOT/server.boot.log" +smoke_scrub_ansi "$SERVER_LOG" "$BOOT_LOG" +if smoke_boot_failure_lines "$BOOT_LOG"; then + fail "the server booted WITHOUT part of the composition (see the line(s) above, which name it). Every probe below would run against a server missing that capability and report the absence as a behaviour failure — a different owner. Fix the boot, then re-run." +fi +if grep -nE "$SMOKE_ERROR_LOG_PATTERN" "$BOOT_LOG"; then + fail "error-level log lines during BOOT, before any probe ran (see above)" +fi +echo " ok — the boot log names no failed plugin, capability or core service" + # ── 3. probes ─────────────────────────────────────────────────────────────── COOKIES_USER="$SMOKE_ROOT/cookies-user.txt" COOKIES_ADMIN="$SMOKE_ROOT/cookies-admin.txt" @@ -972,16 +1094,26 @@ probe "DELETE /data/$NOTE_OBJECT/$RECORD_ID (delete)" 200 \ -X DELETE "$BASE_URL/api/v1/data/$NOTE_OBJECT/$RECORD_ID" # ── 4. log scan ───────────────────────────────────────────────────────────── -# The #3091 breakage announced itself at startup ("Failed to register OIDC -# discovery routes") and would have been caught by ANY error-level line. -# Three error formats coexist: ConsoleLogger `[error] …`, JsonLogger -# `"level":"error"`, and timestamped ` ERROR …` (better-auth's logger and -# the auth plugin's startup reporting). ANSI codes are stripped first — -# belt-and-braces with NO_COLOR above, so a colorized ERROR can't slip through. +# What is left for this section to catch, now that the boot gate above runs +# first: everything the PROBES provoked. The whole log is re-scanned rather +# than just the probe window, so nothing depends on slicing it correctly — the +# boot half simply cannot reach here any more, having already failed. +# +# ⚠ The premise this section was written on no longer holds on its own. It read: +# "the #3091 breakage announced itself at startup … and would have been caught +# by ANY error-level line". True of #3091, which logged at error level — and the +# reason it did not generalise is the boot gate's whole subject: a startup +# breakage that logs at WARN is invisible here, and even at a matching severity +# arrives AFTER the probes have already blamed something else. Startup is now +# judged above; this scan is no longer the thing standing between a boot defect +# and a misattributed probe failure. +# +# ANSI codes are stripped first — belt-and-braces with NO_COLOR in section 2, so +# a colorized ERROR can't slip through (it did, once). log "Scanning server log for error-level output" SCRUBBED_LOG="$SMOKE_ROOT/server.scrubbed.log" -sed -e $'s/\x1b\\[[0-9;]*m//g' "$SERVER_LOG" > "$SCRUBBED_LOG" -if grep -nE '^\[(error|fatal)\]|"level":"(error|fatal)"|^\S+Z ERROR |Failed to register OIDC discovery routes' "$SCRUBBED_LOG"; then +smoke_scrub_ansi "$SERVER_LOG" "$SCRUBBED_LOG" +if grep -nE "$SMOKE_ERROR_LOG_PATTERN" "$SCRUBBED_LOG"; then fail "error-level log lines during the smoke (see above)" fi echo " ok — no error/fatal log lines"