Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
46 changes: 46 additions & 0 deletions .changeset/degraded-boot-stderr-premise.md
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,46 @@
---
'@objectstack/types': patch
'@objectstack/objectql': patch
'@objectstack/runtime': patch
'@objectstack/cli': patch
---

**Correct the stale premise left behind by #4012: the degraded-boot stderr copy
survives the operator's LOG LEVEL, not `os serve`'s boot-quiet window.**

`emitDegradedBootBanner` writes the `OS_ALLOW_DRIVER_CONNECT_FAILURE` banner to
stderr in addition to `logger.warn`, and every comment and test name explaining
why cited the same reason: `os serve` swallowed all of stdout while the kernel
booted, and `Logger` routes `warn` to stdout. #4012 fixed that — the boot window
now buffers and replays `warn`-and-above — which retires the *stated*
justification for a duplicate that is nonetheless still load-bearing:

`Logger.write()` returns before touching a stream when the record is below
`config.level`, so at `--log-level error`, `fatal` or `silent` the banner's
`logger.warn` reaches **no** stream at all. A production host at `error` is
exactly the deployment this escape hatch exists for, and exactly where a
logger-only banner would vanish. Removing the stderr copy on the strength of
#4012 would therefore have been a regression — so this documents the reason that
is still true, in the places someone would read before deleting it:
`degraded-boot.ts`, the engine's emit site, and all three parity tests
(objectql, runtime, service-datasource), which are renamed off "which `os serve`
boot-quiet cannot swallow" to "which the operator log level cannot filter away".

The objectql parity test now proves the claim instead of asserting around it: it
drives a **real** `ObjectLogger` at `level: 'error'` and requires the banner on
stderr *and* nothing on stdout. Set the level to `warn` and it fails — so the
test is pinned to the level filter rather than passing for any reason.

Also corrected in the same sweep, all comment-only, all previously overstating
what #4012 had not yet fixed:

- the automation wiring summary (`format.ts`, `serve.ts`, its test) claimed the
boot window swallowed the engine's binding warnings. Its real justification is
stronger and unchanged: a flow that silently fails to arm emits **no** log line
at any level, so binding state has to be read off the live engine — absence of
a warning was never evidence of a bound flow.
- the seed summary (`seed-summary.ts`, `format.ts`, its test) and `AppPlugin`'s
seed-outcome note attributed the silence to the boot window; the operative
gate is that `SeedLoader`'s result logs are `info`, under the default `warn`.

No behavior changes.
15 changes: 8 additions & 7 deletions packages/cli/src/commands/serve-automation-summary.test.ts
Original file line numberDiff line numberDiff line change
Expand Up@@ -2,13 +2,14 @@
//
// Startup-banner automation summary (2026-07-17 third-party eval).
//
// Flow registration and trigger binding happen entirely inside serve's
// boot-quiet stdout window, so the automation engine's own logs never reach
// the terminal — a project whose flows silently failed to arm looked exactly
// like one whose flows armed fine. `collectAutomationSummary` gathers the
// live binding facts after stdout is restored so the banner can answer
// "did my flows actually arm?" — including the three silent author mistakes:
// engine not enabled, trigger not registered, and objectName mismatch.
// A project whose flows silently failed to arm looks exactly like one whose
// flows armed fine: the failure modes below emit no log line to go looking for,
// and the engine's own binding narration is `info`, under the default `warn`
// level. So the banner reads live binding STATE off the engine rather than
// scraping output. `collectAutomationSummary` gathers those facts after
// runtime.start() so the banner can answer "did my flows actually arm?" —
// including the three silent author mistakes: engine not enabled, trigger not
// registered, and objectName mismatch.

import { describe, it, expect } from 'vitest';
import { collectAutomationSummary } from './serve.js';
Expand Down
23 changes: 12 additions & 11 deletions packages/cli/src/commands/serve.ts
Original file line numberDiff line numberDiff line change
Expand Up@@ -2471,21 +2471,22 @@ export default class Serve extends Command {
} catch { /* auth service not present — nothing to show */ }

// ── Automation wiring summary (2026-07-17 third-party eval) ─────
// Flow registration + trigger binding happen entirely inside the
// boot-quiet stdout window above, so the engine's own info/warn logs
// never reach the terminal. Collect the live binding state here (after
// restore) and surface it in the banner: declared-but-engine-missing,
// unbound triggered flows, and bound-but-dead (unknown object) flows.
// A flow that silently failed to arm logs nothing at all, so no amount of
// log plumbing answers "did my flows arm?" — the binding STATE has to be
// read off the live engine. Collect it here (after restore) and surface it
// in the banner: declared-but-engine-missing, unbound triggered flows, and
// bound-but-dead (unknown object) flows.
const automationSummary = collectAutomationSummary(
kernel,
Array.isArray((config as any)?.flows) ? (config as any).flows.length : 0,
);

// ── Seed outcome summary (#3415/#3430) ─────────────────────────
// Seeds run inside the boot-quiet window too, and SeedLoader's own
// logs sit under the default warn level — a fixture could lose 90%
// of its rows, or a marketplace package rehydrate onto a fresh DB
// with zero rows, all with zero terminal signal. AppPlugin and the
// SeedLoader's own result logs are `info`, under the default warn
// level — a fixture could lose 90% of its rows, or a marketplace
// package rehydrate onto a fresh DB with zero rows, all with zero
// terminal signal. (The boot-quiet window hid them at every level on
// top of that until #4012.) AppPlugin and the
// marketplace rehydrate/heal path stash a per-source entry on the
// kernel; print them here, loudly when rows dropped or an install
// came up empty.
Expand DownExpand Up@@ -2624,8 +2625,8 @@ export function describeRegisteredDriver(kernel: any): { label: string; url: str

/**
* Collect the automation wiring facts for the startup banner (2026-07-17
* third-party eval: flow registration/binding logs fall inside the boot-quiet
* stdout window, so the banner is the one channel a developer reliably sees).
* third-party eval: a flow that failed to arm emits no log line to find, so the
* banner reads the binding state off the engine instead).
*
* Every probe is feature-detected so an older `@objectstack/service-automation`
* (without `getTriggerBindingAudit` / extended runtime states) degrades to the
Expand Down
6 changes: 4 additions & 2 deletions packages/cli/src/utils/format.seed-summary.test.ts
Original file line numberDiff line numberDiff line change
Expand Up@@ -5,8 +5,10 @@ import { printServerReady, type ServerReadyOptions, type SeedSourceSummary } fro

/**
* #3415/#3430 — the boot banner is the ONE place a developer reliably sees seed
* outcomes (SeedLoader's own logs are level-filtered and swallowed by the serve
* boot-quiet window). Assert the Seeds line prints per source, screams on
* outcomes: SeedLoader's own result logs are `info`, under the default `warn`
* level. (They were additionally swallowed by the serve boot-quiet window at
* every level until framework#4012; the level gate is what still hides them.)
* Assert the Seeds line prints per source, screams on
* rejections AND empty marketplace installs, marks fresh-DB heals, and stays
* silent when nothing was seeded.
*/
Expand Down
21 changes: 12 additions & 9 deletions packages/cli/src/utils/format.ts
Original file line numberDiff line numberDiff line change
Expand Up@@ -294,18 +294,21 @@ export interface ServerReadyOptions {
*/
seededAdmin?: { email: string; password: string };
/**
* Automation wiring summary (2026-07-17 third-party eval). The boot-quiet
* stdout window swallows every info/warn the automation engine logs while
* binding flows to triggers, so the banner is the ONE reliable place a
* developer can see whether their record-change / schedule flows actually
* armed. Collected from the live engine after runtime.start().
* Automation wiring summary (2026-07-17 third-party eval). The engine's own
* `info` narration while binding flows to triggers sits under the default
* `warn` level and never prints, and a flow that armed logs nothing either
* way — so a log line is the wrong instrument here regardless. This reports
* live binding STATE, read off the engine after runtime.start(), which is
* what "did my flows actually arm?" actually asks. (Boot-phase warnings the
* engine does emit now reach the terminal too — see {@link BootDiagnostics},
* #4012 — but absence of a warning was never evidence of a bound flow.)
*/
automation?: AutomationReadySummary;
/**
* Per-source seed outcomes for this boot (#3415/#3430). Seeds run inside the
* boot-quiet stdout window and SeedLoader's own logs sit under the default
* warn level, so without this line a fixture can silently lose most of its
* rows (the showcase shipped 1 of 5 projects for weeks) and a marketplace
* Per-source seed outcomes for this boot (#3415/#3430). SeedLoader's own
* logs sit under the default warn level (and the boot-quiet window hid them
* at every level until #4012), so without this line a fixture can silently
* lose most of its rows (the showcase shipped 1 of 5 projects for weeks) and a marketplace
* package can rehydrate onto a fresh DB with zero rows. Each config app and
* each rehydrated/healed marketplace package contributes one entry;
* rejections and empty installs are loud, a clean seed prints one dim line.
Expand Down
33 changes: 26 additions & 7 deletions packages/objectql/src/engine-driver-connect-failfast.test.ts
Original file line numberDiff line numberDiff line change
Expand Up@@ -8,6 +8,7 @@
// OS_ALLOW_DRIVER_CONNECT_FAILURE.

import { describe, it, expect, beforeEach, afterEach } from 'vitest';
import { ObjectLogger } from '@objectstack/core';
import { ObjectQL } from './engine.js';
import { DriverConnectError } from './driver-connect-errors.js';

Expand DownExpand Up@@ -138,28 +139,46 @@ describe('ObjectQL.init() — driver connect fail-fast (framework#3741)', () =>
expect(warned).toContain('sql');
});

it('repeats the degraded banner on stderr, which `os serve` boot-quiet cannot swallow', async () => {
// `os serve` replaces process.stdout.write for the whole boot, and Logger
// sends `warn` to stdout — so a logger-only banner is invisible in exactly
// the deployment this flag exists for.
it('repeats the degraded banner on stderr, which the operator log level cannot filter away', async () => {
// The banner's `logger.warn` is dropped OUTRIGHT at `error`/`fatal`/`silent`
// — `Logger.write()` returns before touching a stream — and a production
// host at `error` is exactly the deployment this flag exists for. The stderr
// copy is what survives that.
//
// This used to be justified by `os serve`'s boot-quiet stdout capture
// instead; that swallowed the banner at EVERY level until framework#4012
// fixed it. Pinning the level filter keeps the test tied to the reason that
// is still true.
process.env[ENV] = '1';
const written: string[] = [];
const realWrite = process.stderr.write;
const onStdout: string[] = [];
const realErrWrite = process.stderr.write;
const realOutWrite = process.stdout.write;
(process.stderr as { write: unknown }).write = (chunk: any) => {
written.push(String(chunk));
return true;
};
(process.stdout as { write: unknown }).write = (chunk: any) => {
onStdout.push(String(chunk));
return true;
};
try {
const engine = new ObjectQL({
logger: { debug() {}, info() {}, warn() {}, error() {} },
// A REAL logger, silenced the way a production host silences it.
logger: new ObjectLogger({ level: 'error' }),
} as any);
engine.registerDriver(fails('sql', 'down'), true);
await engine.init();
} finally {
(process.stderr as { write: unknown }).write = realWrite;
(process.stderr as { write: unknown }).write = realErrWrite;
(process.stdout as { write: unknown }).write = realOutWrite;
}

expect(written.join('')).toContain('DEGRADED BOOT');
// The half that makes this a real pin: at `error` the logger emitted
// NOTHING, so stderr is the only channel that carried the banner. Drop the
// helper and this deployment goes silent.
expect(onStdout.join('')).not.toContain('DEGRADED BOOT');
});

it('treats a falsy opt-in value as off — still fail-fast', async () => {
Expand Down
7 changes: 5 additions & 2 deletions packages/objectql/src/engine.ts
Original file line numberDiff line numberDiff line change
Expand Up@@ -2050,8 +2050,11 @@ export class ObjectQL implements IDataEngine {
`the DDL, so those objects may have no tables even after the database comes back. Unset ` +
`OS_ALLOW_DRIVER_CONNECT_FAILURE to restore fail-fast boot.`;
this.logger.warn(banner, { failedDrivers });
// …and again on a channel the host cannot silence — see the helper's note
// on `os serve`'s boot-quiet stdout capture.
// …and again on a channel the operator's log level cannot filter away: the
// line above is dropped outright at `error`/`fatal`/`silent`, which is a
// normal production setting and precisely where this flag gets used. See
// the helper's note — the duplication is deliberate, and it is NOT about
// `os serve`'s boot-quiet window (that swallowed it too until #4012).
emitDegradedBootBanner(banner);
}

Expand Down
11 changes: 7 additions & 4 deletions packages/runtime/src/app-plugin.ts
Original file line numberDiff line numberDiff line change
Expand Up@@ -932,10 +932,13 @@ export class AppPlugin implements Plugin {
const totalRefsDropped = result.summary.totalReferencesDropped ?? 0;
// #3415/#3430: stash a per-source outcome on the kernel so
// the CLI boot banner can print a Seeds line. The logs below
// never reach `os dev` output — info is under the default
// warn level, and the serve boot-quiet window swallows stdout
// — so without this a fixture can lose most of its rows with
// no signal at all. One labelled entry per config app.
// are `info`, which sits under the default `warn` level, so
// they never reach `os dev` output — without this a fixture
// can lose most of its rows with no signal at all. (The
// serve boot-quiet window used to swallow them on top of
// that, at every level; framework#4012 fixed that half, but
// the level gate below is what still hides these.) One
// labelled entry per config app.
recordSeedOutcome(ctx, {
source: String(appId),
inserted: totalInserted,
Expand Down
7 changes: 6 additions & 1 deletion packages/runtime/src/degraded-boot-parity.test.ts
Original file line numberDiff line numberDiff line change
Expand Up@@ -135,7 +135,12 @@ describe('degraded-boot parity between the two connect paths (framework#3826)',
});
}

it('announces the degraded state on stderr, which `os serve` boot-quiet cannot swallow', async () => {
// Parity with the engine-side pin in
// `objectql/src/engine-driver-connect-failfast.test.ts`: the stderr copy
// survives the operator's LOG LEVEL (`warn` is dropped outright at
// `error`/`fatal`/`silent`), not `os serve`'s boot-quiet window — that
// swallowed the banner at every level until framework#4012 fixed it.
it('announces the degraded state on stderr, which the operator log level cannot filter away', async () => {
process.env[ENV] = '1';
const written: string[] = [];
const realWrite = process.stderr.write;
Expand Down
11 changes: 6 additions & 5 deletions packages/runtime/src/seed-summary.ts
Original file line numberDiff line numberDiff line change
Expand Up@@ -3,11 +3,12 @@
/**
* Boot-time seed outcome accumulator (#3415, extended #3430).
*
* Seeds run inside the CLI's boot-quiet stdout window and SeedLoader's own
* result logs sit under the default `warn` level, so `os dev` shows NOTHING
* about how seeding actually went — a fixture can silently lose most of its
* rows, a marketplace package can rehydrate onto a fresh DB with zero rows,
* and a partial row-level failure leaves no signal at all.
* SeedLoader's own result logs sit under the default `warn` level, so `os dev`
* shows NOTHING about how seeding actually went — a fixture can silently lose
* most of its rows, a marketplace package can rehydrate onto a fresh DB with
* zero rows, and a partial row-level failure leaves no signal at all. (Seeds
* also run inside the CLI's boot-quiet window, which hid them at every level
* until framework#4012; the level gate is what still hides them.)
*
* Every seeding producer (AppPlugin's inline config-app seed, the
* marketplace rehydrate/heal path) records a per-source outcome on the
Expand Down
Original file line numberDiff line numberDiff line change
Expand Up@@ -321,7 +321,11 @@ describe('DatasourceConnectionService.connect', () => {
expect(warned).toContain('visit');
});

it('repeats the degraded banner on stderr, which `os serve` boot-quiet cannot swallow', async () => {
// The stderr copy survives the operator's LOG LEVEL — `warn` is dropped
// outright at `error`/`fatal`/`silent` — not `os serve`'s boot-quiet
// window, which swallowed it at every level until framework#4012 fixed
// that. Same pin as the engine-side and runtime-side parity tests.
it('repeats the degraded banner on stderr, which the operator log level cannot filter away', async () => {
process.env[ENV] = '1';
const written: string[] = [];
const realWrite = process.stderr.write;
Expand Down
21 changes: 15 additions & 6 deletions packages/types/src/degraded-boot.ts
Original file line numberDiff line numberDiff line change
Expand Up@@ -22,12 +22,21 @@
* silence.
*
* `OS_ALLOW_DRIVER_CONNECT_FAILURE` only justifies itself if the state it opts
* into is impossible to miss — and a logger-only banner is missable: `os serve`
* swallows ALL of stdout while the kernel boots (its "boot-quiet" capture), and
* `Logger` routes `warn` to stdout, so the one message that matters would be
* invisible in exactly the situation it exists for. Writing to stderr as well
* is the same belt-and-braces the kernel already uses for plugin startup
* failures.
* into is impossible to miss — and a logger-only banner is missable, because
* the logger answers to a level the operator sets. `Logger.write()` returns
* before emitting anything when the record is below `config.level`, so at
* `--log-level error`, `fatal`, or `silent` this `warn` never reaches ANY
* stream. A production host running at `error` is exactly the deployment this
* flag exists for, and is exactly where the banner would vanish. Writing to
* stderr as well is the same belt-and-braces the kernel already uses for
* plugin startup failures.
*
* A second reason used to be load-bearing and no longer is: `os serve` blanked
* ALL of stdout while the kernel booted, and `Logger` routes `warn` to stdout,
* so a boot-phase banner was swallowed at every level. That was framework#4012
* and is fixed — the boot window buffers and replays `warn`-and-above instead
* of discarding it. Do not re-derive this helper's necessity from the
* boot-quiet capture; the level filter is what keeps it alive.
*
* Best-effort and never throws: falls back to `console.error`, then to silence
* on runtimes that have neither (the logger still carries the structured
Expand Down
Loading