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
38 changes: 38 additions & 0 deletions .changeset/serve-boot-log-visibility.md
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,38 @@
---
'@objectstack/cli': patch
---

**`os dev` / `os serve` stop swallowing every plugin boot-phase log line — the
boot-quiet window buffers instead of discarding (#4012).**

`serve` blanks stdout while the kernel boots so the startup banner is readable,
and dropped what it intercepted. `ObjectLogger` routes `debug`/`info`/`warn` to
**stdout** — only `error`/`fatal` go to stderr — so that one line swallowed
every boot-phase `logger.warn` any plugin emits: the ADR-0110 D5
`[action-governance]` inventory, the automation engine's binding warnings,
every degraded-boot notice. `os dev` spawns `serve` with inherited stdio, so a
single drain blinded both entrypoints at every log level, and it inverted the
flag's own promise — the default is `warn` precisely "so flow/hook execution
failures surface (ADR-0032)". Data-phase logging was unaffected, which is why
the hole survived: `--log-level debug` printed thousands of lines with none
from boot.

- The intercepted bytes now land in a line-oriented, bounded `BootLogCapture`
that classifies each line against `ObjectLogger`'s pretty/text/json
renderings and retains only records at `warn` or above, so buffer size tracks
a boot's warnings rather than its chattiness. The startup chatter the window
exists to hide is still dropped.
- Retained records replay under the banner, beside the automation and seed
summaries that exist for exactly this reason — and on the two exits that
never reach the banner: `OS_MIGRATE_AND_EXIT` (a deploy pipeline must not
lose a degraded-boot warning) and serve's error path, where a boot that died
is when its warnings matter most.
- `--verbose` / `--log-level debug|info` no longer open the window at all.
Buffering a stream the operator explicitly asked to watch would be the flag
defeating itself.

On `examples/app-todo`, `os serve` went from 25 lines with zero WARN among them
to surfacing five boot warnings, including the `[action-governance]` line
naming all eight unbound actions. This closes the loop the D5 inventory
changeset left open: the inventory was already emitted correctly and is now
visible on the platform's own dev loop.
88 changes: 69 additions & 19 deletions packages/cli/src/commands/serve.ts
Original file line numberDiff line numberDiff line change
Expand Up@@ -15,6 +15,7 @@ import { PLATFORM_CAPABILITY_TOKENS } from '@objectstack/spec/kernel';
import { missingProviderMessage } from '../utils/capability-preflight.js';
import { resolveObjectStackHome } from '@objectstack/runtime';
import { LOG_LEVELS, resolveLogLevel, readLogLevelEnv } from '../utils/log-level.js';
import { BootLogCapture, isVerboseBootLevel } from '../utils/boot-log-capture.js';
import { redactConnectionUrl, describeDriverConnection } from '../utils/connection-display.js';
import {
printHeader,
Expand All@@ -24,6 +25,7 @@ import {
printStep,
printInfo,
printServerReady,
printBootDiagnostics,
type AutomationReadySummary,
type SeedSourceSummary,
} from '../utils/format.js';
Expand DownExpand Up@@ -176,7 +178,7 @@ export default class Serve extends Command {
options: ['minimal', 'default', 'full'],
}),
'log-level': Flags.string({
description: 'Kernel logger level. Defaults to $OS_LOG_LEVEL / $LOG_LEVEL, else `warn` so flow/hook execution failures surface (ADR-0032). Use `silent` to fully quiet the runtime.',
description: 'Kernel logger level. Defaults to $OS_LOG_LEVEL / $LOG_LEVEL, else `warn` so flow/hook execution failures surface (ADR-0032). Boot-phase warnings are replayed under the startup banner; `debug`/`info` stream the whole boot live instead. Use `silent` to fully quiet the runtime.',
options: [...LOG_LEVELS],
}),
verbose: Flags.boolean({ char: 'v', description: 'Verbose output — shortcut for --log-level debug.' }),
Expand DownExpand Up@@ -554,11 +556,35 @@ export default class Serve extends Command {
let resolvedDriverLabel: string | undefined;
let resolvedDatabaseUrl: string | undefined;

// Resolve the kernel logger level up front. It decides more than the
// logger's own threshold: it decides whether the boot-quiet window below
// runs at all, so it has to be known BEFORE the window opens rather than
// at the `new Runtime(...)` call further down.
const bootLogLevel = resolveLogLevel({
verbose: flags.verbose,
flag: flags['log-level'],
envLevel: readLogLevelEnv(),
});
// `--verbose` / `--log-level debug|info` asks to watch the boot happen.
// Blanking stdout through it would be the flag defeating itself, so at
// those levels the window never opens and boot output streams live — the
// banner just prints at the end of it (#4012).
const verboseBoot = isVerboseBootLevel(bootLogLevel);

// Save original console/stdout methods — we'll suppress noise during boot
const originalConsoleLog = console.log;
const originalConsoleDebug = console.debug;
const origStdoutWrite = process.stdout.write.bind(process.stdout);
let bootQuiet = false;
// Everything the quiet window intercepts lands here instead of being
// dropped on the floor, so boot-phase `logger.warn` survives to be
// replayed under the banner (#4012).
const bootLogs = new BootLogCapture();
/** Diagnostics to replay, or `undefined` when the boot had nothing to say. */
const collectBootDiagnostics = () => {
const lines = bootLogs.diagnostics();
return lines.length > 0 ? { lines, dropped: bootLogs.droppedCount } : undefined;
};

const restoreOutput = () => {
bootQuiet = false;
Expand All@@ -568,19 +594,34 @@ export default class Serve extends Command {
};

try {
// ── Suppress ALL runtime noise during boot ────────────────────
// ── Hold back runtime noise during boot ───────────────────────
// Multiple sources write to stdout during startup:
// • Pino-pretty (direct process.stdout.write)
// • ObjectLogger browser fallback (console.log)
// • SchemaRegistry (console.log)
// We capture stdout entirely, then restore after runtime.start().
bootQuiet = true;
process.stdout.write = (chunk: any, ...rest: any[]) => {
if (bootQuiet) return true; // swallow
return (origStdoutWrite as any)(chunk, ...rest);
};
console.log = (...args: any[]) => { if (!bootQuiet) originalConsoleLog(...args); };
console.debug = (...args: any[]) => { if (!bootQuiet) originalConsoleDebug(...args); };
// We intercept stdout entirely, then restore after runtime.start().
//
// Intercepted is not discarded (#4012): `ObjectLogger` routes `warn` to
// stdout — only `error`/`fatal` go to stderr — so dropping these bytes
// dropped every boot-phase warning a plugin logged, on both `os serve`
// and `os dev` (which inherits this child's stdio), at every log level.
// The chatter still never reaches the banner; the kernel-logger records
// among it are buffered and replayed once the banner has printed.
bootQuiet = !verboseBoot;
if (!verboseBoot) {
process.stdout.write = (chunk: any, ...rest: any[]) => {
if (bootQuiet) {
bootLogs.write(chunk, typeof rest[0] === 'string' ? rest[0] : undefined);
// Honor the write callback so a caller awaiting drain still resumes.
const cb = rest.find((a) => typeof a === 'function');
if (cb) cb();
return true;
}
return (origStdoutWrite as any)(chunk, ...rest);
};
console.log = (...args: any[]) => { if (!bootQuiet) originalConsoleLog(...args); };
console.debug = (...args: any[]) => { if (!bootQuiet) originalConsoleDebug(...args); };
}

// Load configuration
// --prebuilt: load as native ESM (no esbuild, no bundle-require) —
Expand DownExpand Up@@ -784,18 +825,13 @@ export default class Serve extends Command {
// Import ObjectStack runtime
const { Runtime } = await import('@objectstack/runtime');

// Resolve the kernel logger level. Honors --verbose / --log-level and
// The kernel logger level. Honors --verbose / --log-level and
// $OS_LOG_LEVEL / $LOG_LEVEL, defaulting to `warn` so flow/hook
// execution failures surface even when the CLI manages its own output
// (ADR-0032 "fail loudly"; see #1533). `--log-level silent` restores the
// old fully-quiet behavior.
const loggerConfig = {
level: resolveLogLevel({
verbose: flags.verbose,
flag: flags['log-level'],
envLevel: readLogLevelEnv(),
}),
};
// fully-quiet behavior. Resolved above the boot-quiet window, which
// keys off it too (#4012).
const loggerConfig = { level: bootLogLevel };

// Cluster wiring: env-driven driver selection (mirrors OS_DATABASE_URL).
// The remote driver self-registers on import; import it dynamically so it
Expand DownExpand Up@@ -2391,6 +2427,11 @@ export default class Serve extends Command {
// never accept a request — shutdown immediately so the deploy
// pipeline can move on.
if (process.env.OS_MIGRATE_AND_EXIT === '1') {
// This path exits before the banner, so it has to replay the boot
// diagnostics itself — a deploy pipeline is precisely where a
// degraded-boot warning must not vanish (#4012).
const migrateDiagnostics = collectBootDiagnostics();
if (migrateDiagnostics) printBootDiagnostics(migrateDiagnostics);
console.log(chalk.green(`✓ Migration complete (${loadedPlugins.length} plugins started against ${resolvedDatabaseUrl ? redactConnectionUrl(resolvedDatabaseUrl) : 'configured DB'})`));
try {
await kernel.shutdown();
Expand DownExpand Up@@ -2469,6 +2510,11 @@ export default class Serve extends Command {
seededAdmin,
automation: automationSummary,
seeds: seedSummary,
// #4012 — every boot-phase `logger.warn` the quiet window intercepted,
// replayed here. Without this the window is a drain: the ADR-0110 D5
// `[action-governance]` inventory, degraded-boot notices and flow
// binding failures all reached stdout and none reached a terminal.
bootDiagnostics: collectBootDiagnostics(),
// #3167 — surface the default-on MCP endpoint in the dev loop, where an
// AI client can connect to operate the running app. Same decision point
// that auto-loads the plugin + gates the route, so the banner never
Expand DownExpand Up@@ -2512,6 +2558,10 @@ export default class Serve extends Command {
restoreOutput();
console.log('');
printError(error.message || String(error));
// A boot that died is when its warnings matter most, and the banner that
// would normally carry them never printed (#4012).
const diagnostics = collectBootDiagnostics();
if (diagnostics) printBootDiagnostics(diagnostics);
if (process.env.DEBUG) console.error(chalk.dim(error.stack));
this.exit(1);
}
Expand Down
Loading
Loading