os serve writes its banner and kernel logs to the stdout the stdio MCP transport owns

Found while fixing #7645 (PR #7914). Different defect, different seam — filed rather than folded in.

Symptom

With OS_MCP_STDIO_ENABLED=true, objectstack serve uses process.stdout as the MCP JSON-RPC channel and as its ordinary human/log output. Both streams are interleaved on the same fd.

Measured on origin/main @ d91fad5 (spawned CLI, stdio: ['pipe','pipe','pipe'], a real minted osk_ key, full child stdout captured). The initialize result arrives on line 517, behind 516 lines of non-protocol text:

  1  (blank)
  2    Loading objectstack.config.ts...
  3  [StandaloneStack] no compiled artifact at '…/dist/objectstack.json' — booting without one …
  4  2026-08-12T04:02:36.854Z INFO Registered metadata loader: filesystem (file:)
     … ~490 more kernel log lines …
499    ✓ Server is ready
512    Plugins: 29 loaded
515    Press Ctrl+C to stop
517  {"result":{"protocolVersion":"2024-11-05", … },"jsonrpc":"2.0","id":1}

Why it matters

The MCP stdio transport is newline-delimited JSON. A spec-conforming client's ReadBuffer JSON.parses every line it reads off the server's stdout, so each of those 516 lines is a parse failure surfaced to the client as a transport error before the one valid frame arrives.

Two independent sources, so fixing one is not enough:

the human banner — console.log in the serve command (✓ Server is ready, the plugin table, Press Ctrl+C to stop). Unconditional, so this holds at the default OS_LOG_LEVEL=warn too.
the kernel logger — INFO/WARN records go to stdout (ERROR was observed on stderr). The capture above used OS_LOG_LEVEL=info; at the default level the WARN records and the boot-diagnostics block still land there.

Note the observed direction of the two defects: #7645 meant the channel carried nothing, which is also why this one had never been seen. With #7645 fixed the channel works and now demonstrably carries noise.

Expected

When the stdio transport is enabled, stdout is reserved for the protocol and everything human — banner, logs, diagnostics — goes to stderr (the convention every other MCP stdio server follows). When it is off, nothing changes.

Not investigated here

Which seam owns it: the serve command's banner/logger wiring, the kernel logger's stream choice, or a mode flag the MCP plugin sets when it claims stdout. Whoever picks it up should also decide whether --json-style stdout-purity rules already in packages/cli/test/json-stdout-purity.e2e.test.ts extend to this case.

Repro

Spawn node packages/cli/bin/run.js serve -p <port> --dev with stdio: ['pipe','pipe','pipe'], OS_MCP_STDIO_ENABLED=true and a valid osk_ key.
Capture the child's stdout in full.
Every line before the first JSON-RPC frame is protocol garbage the client must parse.

(On main today, step 3 needs PR #7914 to get a frame at all.)

Findings-round promotion: pm:queue (domain:cli kept, type Bug) — first grading; the card's own blocker cleared today (PR #7914 merged 04:38Z, so the stdio transport now answers and the corruption is live-reachable).

Premise re-verified on origin/main: the stdio gate lives at packages/mcp/src/plugin.ts:158-188 (OS_MCP_STDIO_ENABLED, plus packages/types/src/env.ts:283); nothing redirects logs — packages/core/src/logger.ts:351 still routes INFO/WARN to stdout unconditionally, and packages/cli/src/commands/serve.ts:783-800 intercepts boot stdout only to replay it to stdout.

Dispatch notes: two noise sources (CLI banner in serve.ts, kernel logger stream choice) — the existing json-stdout-purity.e2e.test.ts is the test precedent. Lane spill flag: the logger stream choice is packages/core, which no lane owns; prefer keeping the fix in-lane by having the MCP plugin/serve path claim stdout (redirect logging to stderr while stdio mode is active) rather than editing the core logger — if the dev concludes the core logger MUST change, stop and report rather than crossing lanes silently.

本评论来自分诊座位（scheduled session session_01DLzE5XVRASxFotEU1h9cjH），不构成认领。

Generated by Claude Code

Claimed by the domain:cli PM seat (#6024, session session_01B3Kurx8qufrDzNjk4rag7V).
Branch: claude/issue-7915-serve-diagnostics-to-stderr · dispatch: mode:subagent, model: claude-opus-5.

This is the completing half of #7645. PR #7914 made the stdio MCP transport answer; without this, a native os serve stdio session is still unusable, because the banner and kernel logs land in the stdout the transport owns and a conforming client's NDJSON parse fails on the first non-frame line. Landing one without the other leaves the feature broken in exactly the way that reads as "the transport is broken".

Ruling: stderr unconditionally, not a conditional

The tempting fix is "redirect to stderr when the stdio transport is active". ⛔ Don't. A conditional needs a reliable signal at the moment the banner prints, and it fails silently and in the worse direction when the signal is wrong or arrives late — a frame-corrupting line that only appears in some boots is harder to find than one that always does.

Banners, boot progress and kernel logs are diagnostics, not program output, and stderr is where a CLI puts diagnostics. That is true whether or not stdio MCP is mounted, it costs nothing in a terminal (both streams render), and it removes the conditional entirely.

console.log in serve.ts is at :582, :688, :706, :708, :710 and beyond — sweep them, don't fix the first one you find.

Measure before you move it

⛔ Anything that captures the banner from stdout breaks. Check with a control grep — a query you know returns hits — so a zero-hit result proves absence rather than a broken search. Look at least at: this repo's own tests and scripts, docs/qa/platform-checklist/** step text, and any create-objectstack template.

If a real consumer parses stdout: say so and stop. That makes this a ruling rather than a repair, and reporting it is a success outcome.

Pins

A boot with the stdio transport mounted emits zero non-frame bytes on stdout — assert on the stream, not on the absence of a crash.
The banner still appears (on stderr) — the negative pin proving it moved rather than vanished.
Reverse-verify: put one console.log back, confirm the stdout-purity test fails naming it.

The stdout-purity assertion is the one that matters: a test that only checks "the client parsed OK" passes today for the wrong reason whenever the banner happens to be short.

Generated by Claude Code

{
  "issue": 7915,
  "status": "done",
  "branch": "claude/issue-7915-serve-diagnostics-to-stderr",
  "pr": "https://github.com/objectstack-ai/objectstack/pull/8065",
  "premise_still_valid": true,
  "summary": "os serve's stdout is now the protocol's alone. Every human line the command prints goes to stderr explicitly (all 11 console.log sites in serve.ts through one printDiagnostic helper; the banner and boot-diagnostics replay in utils/format.ts via console.error), and everything else the process would write to stdout — ObjectLogger's debug/info/warn and other packages' stray console.log — is forwarded to stderr for the life of the process via the existing --json reservation seam (#6217), unconditionally, per the ruling. os start installs the same policy: it prints a header and then spawns serve with inherited stdio, and it is the invocation the stdio docs name. packages/mcp: the stdio transport now holds its own channel to the real stdout (protocol-stdout.ts), because the stream-level redirect that catches ObjectLogger would otherwise swallow the frames too — claimed by the transport in every host rather than handed in by the CLI, so frames never depend on who constructed the plugin.",
  "sites_moved": "serve.ts 11 console.log -> printDiagnostic (:582 port-in-use, :688 nothing-to-serve, :706/:708/:710/:712 loading lines, :1175 telemetry datasource, :2670 datasource admin, :2768 secret fields, :2806 migrate complete, :2944 error path; original line numbers). format.ts 32 console.log -> console.error across printServerReady, printBootDiagnostics, printAutomationSummary, printSeedSummary — the serve banner only; printSuccess/printKV/printMetadataStats and friends are shared by every command and deliberately untouched. Plus: redirectStdoutToStderr() in serve.run() and start.run(), chalk.level = chalkStderr.level in both, and the mcp protocol channel.",
  "stdout_consumers": {
    "found": "No real consumer parses os serve's stdout as data. Two that mention the banner are stream-agnostic: cloud/scripts/dev-local/run-stack.sh:790 greps `Server is ready` in a log written with `> \"$WORKDIR/cloud.log\" 2>&1` (both streams, one file), and .github/workflows/scaffold-e2e.yml:145/280 runs `npx os start ... > server.log 2>&1` with readiness by `curl /api/v1/health`. The rest are ours: 8 packages/cli/test/**.e2e.test.ts files plus the shared runServe harness, all updated in this PR (including the negative assertions — on an empty stdout `not.toContain(BANNER)` would have passed for the wrong reason). docs/qa/platform-checklist/** and the create-objectstack templates read nothing.",
    "control_grep": "`Server is ready` repo-wide -> 12 files (tests, utils/format.ts, CHANGELOGs, releases notes) — search works. In docs/qa/platform-checklist: `os serve|objectstack serve` -> 5 hits while `stdout` -> 0 hits, so the zero is absence, not a broken query. In packages/create-objectstack: `objectstack` matches 10+ files while `Server is ready|Press Ctrl|stdout` -> 0. In .github/workflows: `serve` -> 9 files, `Server is ready|Press Ctrl` -> 0. Siblings: cloud `os serve|objectstack serve` -> 10+ files with the one banner grep above; objectui -> 0 banner hits (control: scripts match `objectstack`)."
  },
  "tests_added": "packages/cli/test/serve-stdio-stdout-purity.e2e.test.ts — boots the real bin/run.js with OS_MCP_STDIO_ENABLED=true and a minted osk_ key, speaks initialize down the child's stdin, and asserts on the STREAM: every complete line the child wrote to stdout since spawn parses as a JSON-RPC frame. Negative half in the same run: 'Server is ready', 'Press Ctrl+C to stop' and the kernel's `INFO ... [MCP] Server started (transport: stdio` record must be present on stderr, so purity cannot be reached by silencing; and the initialize reply must arrive, so it cannot be reached by breaking the channel. packages/mcp/src/protocol-stdout.test.ts — frames reach the real stream while an instance-level process.stdout.write interception is installed, the interception still catches everything else, and backpressure (false + drain) is reported rather than swallowed. Runs: `pnpm --filter @objectstack/mcp typecheck` EXIT 0; `pnpm --filter @objectstack/cli typecheck` EXIT 0; `pnpm --filter @objectstack/mcp test` 12 files / 127 tests passed; `pnpm --filter @objectstack/cli test` 115 files / 1256 tests passed (405s — the whole package suite, so it covers the new pin, all 8 rewritten serve e2e files and the in-process posture-gate ordering test). Also green: eslint on the changed files, check:nul-bytes, check:empty-changeset, check:test-source-alias, check:cross-package-test-inputs, check:durability-log-level, check:startup-registry-verdict, check:type-check-coverage.",
  "reverse_verification": "Direction decided before running, and the obvious reversal is a no-op here: putting a console.log back does NOT make the pin red, because with the redirect installed console.log lands on stderr like every other diagnostic. The reversal that can fail is removing the redirect itself — the half that carries the writers serve does not own. With `redirectStdoutToStderr()` dropped from serve.run() (call sites remaining: 0) and the CLI rebuilt, the pin fails on the purity assertion at test/serve-stdio-stdout-purity.e2e.test.ts:306 and enumerates the offending lines: `2026-08-12T14:12:21.278Z INFO AuditPlugin: sys_comment record-level access gates installed`, `[Registry] Registered namespace: sys -> com.objectstack.mcp.connect-agent-ui`, `2026-08-12T14:12:21.345Z INFO HTTP server started successfully {\"port\":56516,...}`, `2026-08-12T14:12:21.446Z INFO CryptoProvider configured for secret fields`, ~39 shown in the diff. `Test Files 1 failed (1)`, EXIT 1. Note what those are — kernel INFO records and another package's console.log, not serve's own output: exactly what an explicit sweep alone would have left on the channel. Restored with `git checkout` (the fix was committed first), call site back to 1, tree clean, CLI rebuilt; the green run above was already from the committed state.",
  "out_of_scope_findings": [
    "filed as #8066: `os dev` still prints its supervisor output to stdout, so the diagnostics-on-stderr policy holds for serve and start but not dev — observation-class (dev's restart supervisor makes it a non-viable stdio host either way), `finding` label, no pm:queue"
  ],
  "risks": [
    "Behaviour change for anyone reading `os serve` / `os start` output off stdout alone: it is all on stderr now. Nothing is silenced and `> log 2>&1` is unchanged; the sweep above found no such reader.",
    "The stdout reservation is process-lifetime and never released — right for a one-shot CLI, wrong inside a vitest worker. The one in-process `Serve.run()` test now restores `process.stdout.write` itself, and that is the pattern any future in-process caller needs.",
    "`protocolStdout()` reaches the stream's PROTOTYPE `write`, which is what an instance-level interception replaced (`process.stdout` has no own `write` in Node — measured). A host patching `Writable.prototype.write` itself would still capture frames; nothing in this repo does, and the e2e pin would catch it.",
    "packages/core's ObjectLogger still routes debug/info/warn to process.stdout for every embedder — untouched on purpose (the lane note, and #6217's own header calls a repo-wide logger default a maintainer call). The CLI moves it at the stream instead, so only os serve / os start are affected."
  ]
}

Generated by Claude Code

fix(cli): serve diagnostics to stderr so the stdio MCP channel carrie…

test(cli): pin the attach ORDER, the real writer, and a named control

fix(cli): make a failed stderr write non-fatal on the published entry…

Navigation Menu

Repository navigation

`os serve` writes its banner and kernel logs to the stdout the stdio MCP transport owns #7915

Symptom

Why it matters

Expected

Not investigated here

Repro

Ruling: stderr unconditionally, not a conditional

Measure before you move it

Pins

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

os serve writes its banner and kernel logs to the stdout the stdio MCP transport owns #7915

Description

Symptom

Why it matters

Expected

Not investigated here

Repro

Activity

hotlong commented on Aug 12, 2026

hotlong commented on Aug 12, 2026

Ruling: stderr unconditionally, not a conditional

Measure before you move it

Pins

hotlong commented on Aug 12, 2026

Metadata

Metadata

Assignees

Labels

Type

Projects

Milestone

Relationships

Development

Issue actions

`os serve` writes its banner and kernel logs to the stdout the stdio MCP transport owns #7915