Skip to content

Commit c20b875

Browse files
authored
docs(types,objectql,runtime,cli): repoint the degraded-boot stderr copy at the reason that survived #4012 (#4106)
`emitDegradedBootBanner` writes the OS_ALLOW_DRIVER_CONNECT_FAILURE banner to stderr on top of `logger.warn`, and every comment and test name explaining why cited one reason: `os serve` swallowed all of stdout while the kernel booted, and Logger routes `warn` to stdout. #4012 fixed that, retiring the stated justification for a duplicate that is still load-bearing for a different one: `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. A production host at `error` is exactly the deployment this escape hatch exists for, and exactly where a logger-only banner vanishes. Deleting the stderr copy on the strength of #4012 would have been a regression — so the surviving reason is documented where someone would read it before deleting it: degraded-boot.ts, the engine emit site, and all three parity tests (objectql, runtime, service-datasource), 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 rather than asserting around it: it drives a real ObjectLogger at level 'error' and requires the banner on stderr AND nothing on stdout. Setting the level to 'warn' makes it fail. Same sweep, same class of stale premise, all comment-only: 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, in that a flow which silently fails to arm emits no log line at any level; and the seed summary (seed-summary.ts, format.ts, its test) plus AppPlugin's seed-outcome note attributed the silence to the boot window, where the operative gate is that SeedLoader's result logs are `info`, under the default `warn`. No behavior changes — every non-test line changed is a comment. Refs #4012
1 parent bb192c4 commit c20b875

12 files changed

Lines changed: 152 additions & 55 deletions

File tree

Lines changed: 46 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,46 @@
1+
---
2+
'@objectstack/types': patch
3+
'@objectstack/objectql': patch
4+
'@objectstack/runtime': patch
5+
'@objectstack/cli': patch
6+
---
7+
8+
**Correct the stale premise left behind by #4012: the degraded-boot stderr copy
9+
survives the operator's LOG LEVEL, not `os serve`'s boot-quiet window.**
10+
11+
`emitDegradedBootBanner` writes the `OS_ALLOW_DRIVER_CONNECT_FAILURE` banner to
12+
stderr in addition to `logger.warn`, and every comment and test name explaining
13+
why cited the same reason: `os serve` swallowed all of stdout while the kernel
14+
booted, and `Logger` routes `warn` to stdout. #4012 fixed that — the boot window
15+
now buffers and replays `warn`-and-above — which retires the *stated*
16+
justification for a duplicate that is nonetheless still load-bearing:
17+
18+
`Logger.write()` returns before touching a stream when the record is below
19+
`config.level`, so at `--log-level error`, `fatal` or `silent` the banner's
20+
`logger.warn` reaches **no** stream at all. A production host at `error` is
21+
exactly the deployment this escape hatch exists for, and exactly where a
22+
logger-only banner would vanish. Removing the stderr copy on the strength of
23+
#4012 would therefore have been a regression — so this documents the reason that
24+
is still true, in the places someone would read before deleting it:
25+
`degraded-boot.ts`, the engine's emit site, and all three parity tests
26+
(objectql, runtime, service-datasource), which are renamed off "which `os serve`
27+
boot-quiet cannot swallow" to "which the operator log level cannot filter away".
28+
29+
The objectql parity test now proves the claim instead of asserting around it: it
30+
drives a **real** `ObjectLogger` at `level: 'error'` and requires the banner on
31+
stderr *and* nothing on stdout. Set the level to `warn` and it fails — so the
32+
test is pinned to the level filter rather than passing for any reason.
33+
34+
Also corrected in the same sweep, all comment-only, all previously overstating
35+
what #4012 had not yet fixed:
36+
37+
- the automation wiring summary (`format.ts`, `serve.ts`, its test) claimed the
38+
boot window swallowed the engine's binding warnings. Its real justification is
39+
stronger and unchanged: a flow that silently fails to arm emits **no** log line
40+
at any level, so binding state has to be read off the live engine — absence of
41+
a warning was never evidence of a bound flow.
42+
- the seed summary (`seed-summary.ts`, `format.ts`, its test) and `AppPlugin`'s
43+
seed-outcome note attributed the silence to the boot window; the operative
44+
gate is that `SeedLoader`'s result logs are `info`, under the default `warn`.
45+
46+
No behavior changes.

packages/cli/src/commands/serve-automation-summary.test.ts

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

1314
import { describe, it, expect } from 'vitest';
1415
import { collectAutomationSummary } from './serve.js';

packages/cli/src/commands/serve.ts

Lines changed: 12 additions & 11 deletions
Original file line numberDiff line numberDiff line change
@@ -2471,21 +2471,22 @@ export default class Serve extends Command {
24712471
} catch { /* auth service not present — nothing to show */ }
24722472

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

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

26252626
/**
26262627
* Collect the automation wiring facts for the startup banner (2026-07-17
2627-
* third-party eval: flow registration/binding logs fall inside the boot-quiet
2628-
* stdout window, so the banner is the one channel a developer reliably sees).
2628+
* third-party eval: a flow that failed to arm emits no log line to find, so the
2629+
* banner reads the binding state off the engine instead).
26292630
*
26302631
* Every probe is feature-detected so an older `@objectstack/service-automation`
26312632
* (without `getTriggerBindingAudit` / extended runtime states) degrades to the

packages/cli/src/utils/format.seed-summary.test.ts

Lines changed: 4 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -5,8 +5,10 @@ import { printServerReady, type ServerReadyOptions, type SeedSourceSummary } fro
55

66
/**
77
* #3415/#3430 — the boot banner is the ONE place a developer reliably sees seed
8-
* outcomes (SeedLoader's own logs are level-filtered and swallowed by the serve
9-
* boot-quiet window). Assert the Seeds line prints per source, screams on
8+
* outcomes: SeedLoader's own result logs are `info`, under the default `warn`
9+
* level. (They were additionally swallowed by the serve boot-quiet window at
10+
* every level until framework#4012; the level gate is what still hides them.)
11+
* Assert the Seeds line prints per source, screams on
1012
* rejections AND empty marketplace installs, marks fresh-DB heals, and stays
1113
* silent when nothing was seeded.
1214
*/

packages/cli/src/utils/format.ts

Lines changed: 12 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -294,18 +294,21 @@ export interface ServerReadyOptions {
294294
*/
295295
seededAdmin?: { email: string; password: string };
296296
/**
297-
* Automation wiring summary (2026-07-17 third-party eval). The boot-quiet
298-
* stdout window swallows every info/warn the automation engine logs while
299-
* binding flows to triggers, so the banner is the ONE reliable place a
300-
* developer can see whether their record-change / schedule flows actually
301-
* armed. Collected from the live engine after runtime.start().
297+
* Automation wiring summary (2026-07-17 third-party eval). The engine's own
298+
* `info` narration while binding flows to triggers sits under the default
299+
* `warn` level and never prints, and a flow that armed logs nothing either
300+
* way — so a log line is the wrong instrument here regardless. This reports
301+
* live binding STATE, read off the engine after runtime.start(), which is
302+
* what "did my flows actually arm?" actually asks. (Boot-phase warnings the
303+
* engine does emit now reach the terminal too — see {@link BootDiagnostics},
304+
* #4012 — but absence of a warning was never evidence of a bound flow.)
302305
*/
303306
automation?: AutomationReadySummary;
304307
/**
305-
* Per-source seed outcomes for this boot (#3415/#3430). Seeds run inside the
306-
* boot-quiet stdout window and SeedLoader's own logs sit under the default
307-
* warn level, so without this line a fixture can silently lose most of its
308-
* rows (the showcase shipped 1 of 5 projects for weeks) and a marketplace
308+
* Per-source seed outcomes for this boot (#3415/#3430). SeedLoader's own
309+
* logs sit under the default warn level (and the boot-quiet window hid them
310+
* at every level until #4012), so without this line a fixture can silently
311+
* lose most of its rows (the showcase shipped 1 of 5 projects for weeks) and a marketplace
309312
* package can rehydrate onto a fresh DB with zero rows. Each config app and
310313
* each rehydrated/healed marketplace package contributes one entry;
311314
* rejections and empty installs are loud, a clean seed prints one dim line.

packages/objectql/src/engine-driver-connect-failfast.test.ts

Lines changed: 26 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -8,6 +8,7 @@
88
// OS_ALLOW_DRIVER_CONNECT_FAILURE.
99

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

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

141-
it('repeats the degraded banner on stderr, which `os serve` boot-quiet cannot swallow', async () => {
142-
// `os serve` replaces process.stdout.write for the whole boot, and Logger
143-
// sends `warn` to stdout — so a logger-only banner is invisible in exactly
144-
// the deployment this flag exists for.
142+
it('repeats the degraded banner on stderr, which the operator log level cannot filter away', async () => {
143+
// The banner's `logger.warn` is dropped OUTRIGHT at `error`/`fatal`/`silent`
144+
// — `Logger.write()` returns before touching a stream — and a production
145+
// host at `error` is exactly the deployment this flag exists for. The stderr
146+
// copy is what survives that.
147+
//
148+
// This used to be justified by `os serve`'s boot-quiet stdout capture
149+
// instead; that swallowed the banner at EVERY level until framework#4012
150+
// fixed it. Pinning the level filter keeps the test tied to the reason that
151+
// is still true.
145152
process.env[ENV] = '1';
146153
const written: string[] = [];
147-
const realWrite = process.stderr.write;
154+
const onStdout: string[] = [];
155+
const realErrWrite = process.stderr.write;
156+
const realOutWrite = process.stdout.write;
148157
(process.stderr as { write: unknown }).write = (chunk: any) => {
149158
written.push(String(chunk));
150159
return true;
151160
};
161+
(process.stdout as { write: unknown }).write = (chunk: any) => {
162+
onStdout.push(String(chunk));
163+
return true;
164+
};
152165
try {
153166
const engine = new ObjectQL({
154-
logger: { debug() {}, info() {}, warn() {}, error() {} },
167+
// A REAL logger, silenced the way a production host silences it.
168+
logger: new ObjectLogger({ level: 'error' }),
155169
} as any);
156170
engine.registerDriver(fails('sql', 'down'), true);
157171
await engine.init();
158172
} finally {
159-
(process.stderr as { write: unknown }).write = realWrite;
173+
(process.stderr as { write: unknown }).write = realErrWrite;
174+
(process.stdout as { write: unknown }).write = realOutWrite;
160175
}
161176

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

165184
it('treats a falsy opt-in value as off — still fail-fast', async () => {

packages/objectql/src/engine.ts

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -2050,8 +2050,11 @@ export class ObjectQL implements IDataEngine {
20502050
`the DDL, so those objects may have no tables even after the database comes back. Unset ` +
20512051
`OS_ALLOW_DRIVER_CONNECT_FAILURE to restore fail-fast boot.`;
20522052
this.logger.warn(banner, { failedDrivers });
2053-
// …and again on a channel the host cannot silence — see the helper's note
2054-
// on `os serve`'s boot-quiet stdout capture.
2053+
// …and again on a channel the operator's log level cannot filter away: the
2054+
// line above is dropped outright at `error`/`fatal`/`silent`, which is a
2055+
// normal production setting and precisely where this flag gets used. See
2056+
// the helper's note — the duplication is deliberate, and it is NOT about
2057+
// `os serve`'s boot-quiet window (that swallowed it too until #4012).
20552058
emitDegradedBootBanner(banner);
20562059
}
20572060

packages/runtime/src/app-plugin.ts

Lines changed: 7 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -932,10 +932,13 @@ export class AppPlugin implements Plugin {
932932
const totalRefsDropped = result.summary.totalReferencesDropped ?? 0;
933933
// #3415/#3430: stash a per-source outcome on the kernel so
934934
// the CLI boot banner can print a Seeds line. The logs below
935-
// never reach `os dev` output — info is under the default
936-
// warn level, and the serve boot-quiet window swallows stdout
937-
// — so without this a fixture can lose most of its rows with
938-
// no signal at all. One labelled entry per config app.
935+
// are `info`, which sits under the default `warn` level, so
936+
// they never reach `os dev` output — without this a fixture
937+
// can lose most of its rows with no signal at all. (The
938+
// serve boot-quiet window used to swallow them on top of
939+
// that, at every level; framework#4012 fixed that half, but
940+
// the level gate below is what still hides these.) One
941+
// labelled entry per config app.
939942
recordSeedOutcome(ctx, {
940943
source: String(appId),
941944
inserted: totalInserted,

packages/runtime/src/degraded-boot-parity.test.ts

Lines changed: 6 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -135,7 +135,12 @@ describe('degraded-boot parity between the two connect paths (framework#3826)',
135135
});
136136
}
137137

138-
it('announces the degraded state on stderr, which `os serve` boot-quiet cannot swallow', async () => {
138+
// Parity with the engine-side pin in
139+
// `objectql/src/engine-driver-connect-failfast.test.ts`: the stderr copy
140+
// survives the operator's LOG LEVEL (`warn` is dropped outright at
141+
// `error`/`fatal`/`silent`), not `os serve`'s boot-quiet window — that
142+
// swallowed the banner at every level until framework#4012 fixed it.
143+
it('announces the degraded state on stderr, which the operator log level cannot filter away', async () => {
139144
process.env[ENV] = '1';
140145
const written: string[] = [];
141146
const realWrite = process.stderr.write;

packages/runtime/src/seed-summary.ts

Lines changed: 6 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -3,11 +3,12 @@
33
/**
44
* Boot-time seed outcome accumulator (#3415, extended #3430).
55
*
6-
* Seeds run inside the CLI's boot-quiet stdout window and SeedLoader's own
7-
* result logs sit under the default `warn` level, so `os dev` shows NOTHING
8-
* about how seeding actually went — a fixture can silently lose most of its
9-
* rows, a marketplace package can rehydrate onto a fresh DB with zero rows,
10-
* and a partial row-level failure leaves no signal at all.
6+
* SeedLoader's own result logs sit under the default `warn` level, so `os dev`
7+
* shows NOTHING about how seeding actually went — a fixture can silently lose
8+
* most of its rows, a marketplace package can rehydrate onto a fresh DB with
9+
* zero rows, and a partial row-level failure leaves no signal at all. (Seeds
10+
* also run inside the CLI's boot-quiet window, which hid them at every level
11+
* until framework#4012; the level gate is what still hides them.)
1112
*
1213
* Every seeding producer (AppPlugin's inline config-app seed, the
1314
* marketplace rehydrate/heal path) records a per-source outcome on the

0 commit comments

Comments
 (0)