Skip to content

Commit 5155093

Browse files
fix(cli): os verify --json writes exactly one JSON document to stdout; boot diagnostics move to stderr (#21381)
Fixes #21324 Clause-②: no `os verify --json > report.json` now leaves a file `JSON.parse` reads whole. Under `--json` the command takes the CLI's existing stdout reservation (`reserveStdoutForJson`, the route `bootSchemaStack` took for the same defect in commit 2b641dd) before it loads the config. Every write to `process.stdout`, whoever makes it, is forwarded to stderr, and the report leaves through `emitJson` on the real stdout. Nothing is silenced, and the text face is unchanged. ## Measured first: where the stdout lines came from Measured at `f39760864c` (the claim's base) on a two-object `defineStack` stack that passes the author-time rules and reaches the runtime stage. The command was `objectstack verify --json > report.json`, run through this checkout's source entry (`bin/run-dev.js`): | | before (`f39760864c`) | after (`0c2c904fea`) | |---|---|---| | verify exit | 0 | 0 | | `JSON.parse(report.json)` exit | 1, `Unexpected non-whitespace character after JSON at position 4` | 0 | | stdout lines | 349; the document starts at line 319 | 31; the document only | | stderr lines | 3 | 321; the same 3 plus the 318 that moved | A stdout-write probe attributed the 318 lines ahead of the document. The probe is a `--import` preload in the scratchpad that tags each write by its writer, and it touches no repo file. | writer | lines | passes through the kernel logger? | |---|---|---| | the kernel's `ObjectLogger` (169 INFO, 5 WARN) | 174 | yes | | the ObjectQL registry's `console.log` (`[Registry] ...`) | 143 | no | | `HonoServerPlugin`'s `console.log` on stop | 1 | no | After the fix, the same probe sees exactly one write on the real stdout: the document, from `writeStdoutDirect`. A sorted diff of the after-run's stderr against the before-run's stdout lines differs only in timestamps, ids, ports and durations. So nothing was dropped. With `--rls` (two boots; measured at `866de1d7c8`, whose `verify.ts` is byte-identical) the after-run gives exit 0, a parseable stdout of 80 lines (the document) and 653 lines on stderr. ## The route, and why not the one the claim expected The claim expected a new optional kernel-logger member on `@objectstack/verify`'s `BootOptions`, which the CLI would pass under `--json`. The measurement rules that out as the fix: - A kernel logger setting reaches 174 of the 318 lines. The registry's and Hono's `console.log` calls (144 lines) never go through it, so stdout would still not parse. - `silent` would also throw away the 5 WARN records: the missing `job` service, the analytics read-grant notice, OAuth served unencrypted on loopback, and the port fallback. - Sending `info`/`warn` to stderr from inside the logger would need a change in `packages/core` (stop clause 1). It is not needed either: the CLI already owns a seam that moves every stdout write to stderr for a `--json` run (`packages/cli/src/utils/json-stdout.ts`). That module's header records why it rejected the silent route, for the same two reasons. The reservation redirects each write as it happens. Nothing is captured and filtered afterwards, so stop clause 2 does not apply. `@objectstack/verify` is untouched and its published `BootOptions` does not move. That is why the declaration line reads `no`: this PR adds no new key to a published payload and widens no accept set. ## What changed - `packages/cli/src/commands/verify.ts` - `run()`: under `--json`, calls `reserveStdoutForJson()` before `loadConfig`. The reservation is never released, because the run is one-shot and its last act is the payload and the exit. That way a booted stack's late timers cannot land under the document. - The runtime report now goes out through `emitJson(...)` instead of `this.log(JSON.stringify(..., null, 2))`. The bytes are the same (pretty, with a trailing newline), but they now reach the real stdout and are drained before `this.exit`. The old `this.log` followed by an exit could truncate a report larger than one pipe buffer. The other two `--json` documents (the stage-1 refusal and the could-not-run envelope) already used `emitJson`. - `packages/cli/test/verify-json-stdout.test.ts` (new; integration tier, because it spawns the CLI; not an `.e2e` name, so it runs on every PR) spawns `verify --json` and `verify` on a clean stack that reaches the runtime stage, and pins four things: - stdout is byte-equal to the re-serialized document, and that document is the runtime report (`crud`, `hardFailures: 0`); - stdout carries no kernel-logger record and no registry line; - stderr carries the kernel logger's records, WARN among them, and the registry's `console.log` lines (moved, never destroyed); - the text face still writes the kernel logger's records and the registry lines to stdout, next to `verify passed`. The child is spawned with `OS_REGISTRY_LOG: 'info'`, the shipped default, written out at the call site. This package's vitest config sets `warn` for its own workers, and at `warn` the registry's writer stays quiet. - `content/docs/deployment/cli.mdx`, the `#### os verify` entry only: - the `--json` paragraph now says that stdout carries exactly one document, that everything else goes to stderr and none of it is dropped, and that without `--json` the lines stay on stdout; - the stage-1 boundary sentence now names the `defineStack` provenance refusal (`STACK_PROVENANCE_MISSING`, the 1a step of `validate`/`build` that `verify` does not run). This was carried from the contract review on #21364, item 3.2. - `.changeset/21324-verify-json-stdout.md`: `@objectstack/cli` at `patch`. ## Tests All runs are at `f9ee0ac5e8` (after `origin/main` was merged in) unless a row says otherwise. | run | result | |---|---| | `pnpm --filter @objectstack/cli exec vitest run test/verify-json-stdout.test.ts test/verify-author-time-stage.test.ts test/published-subpath-console.pin.test.ts test/published-subpath-hook-body.pin.test.ts` | 4 files, 36 tests passed | | `pnpm --filter @objectstack/cli exec vitest run --project unit` | 243 of 245 files passed. The other 2 (`published-subpath-*`) refused with "packages/cli is not built". After `pnpm --filter @objectstack/cli build`, both pass (row above). | | `pnpm --filter @objectstack/cli typecheck` | exit 0 (`tsc --noEmit`, and `check:test-typecheck` OK) | | stage-1 refusal stays one document (`verify-author-time-stage.test.ts`, the existing pin) | green, in the first row | | `OS_TEST_TIERS=nightly` `test/config-miss-stdout-purity.e2e.test.ts` (the `verify` face is a member, and the reservation is taken before `loadConfig`) | 174 of 174 passed, including both `verify` branches on both faces | | `OS_TEST_TIERS=nightly` `test/json-stdout-purity.e2e.test.ts` | 1 failed, 40 passed, the same case that fails on the base (see Acceptance notes) | The integration layer is the spawn tier. The two spawn files this diff touches or depends on ran locally (rows above). The rest of the integration tier is declared to CI. ## Ablations (fix committed first; each leg goes through `scripts/ablation-replace.mjs`, which restores and proves blob == HEAD with an empty `git diff HEAD`) `packages/cli/dist` was absent during these legs, so the spawned CLI ran `src/` through tsx, and the mutation reached the run with no rebuild. | leg | mutation | result | |---|---|---| | A | delete `if (flags.json) reserveStdoutForJson();` | 3 failed, 1 passed (the text face stays green, as predicted) | | B | report back through `this.log(JSON.stringify(..., null, 2))` | 1 failed (`Unexpected end of JSON input`: the report went to stderr), 3 passed | | C | both, which is the base behaviour | 3 failed with the card's own signature, `Unexpected non-whitespace character after JSON at position 4`; 1 passed | | D | reserve on the text face too (`if (flags.json \|\| !flags.json)`) | 1 failed (the text-face pin), 3 passed | ## Gates `node scripts/pm/dispatch-gates.mjs --repo objectstack-ai/objectstack --commands` (no paths) derived 94 commands at `f9ee0ac5e8`. All 94 were run with their exit codes recorded, and `--ran` reports `94 run, 0 NOT-MEASURED, 0 UNRUN`. Five of them first refused with exit 3 (`PREREQUISITE NOT MET`: unbuilt CLI and client-react). They were re-run after `turbo run build` for exactly the closure each gate named, and all five exited 0. Those five are `check:skill-examples`, `check:i18n`, `check:i18n-coverage`, `check:i18n-walk-parity` and `check:dual-build-cjs-loads`. `pnpm lint` (repo-wide) is CI's. The narrowed run below counts as a measurement because all three of these hold: 1. The population comes from eslint's own config. Of the 4 touched paths, the config matches the 2 `.ts` files and answers "File ignored because no matching configuration was supplied" for the `.mdx` and the `.md`. 2. `--format json` returned 4 results: `verify.ts` and `verify-json-stdout.test.ts` with 0 errors and 0 warnings, at `f9ee0ac5e8`. 3. The diff cannot change any untouched file's verdict, because `eslint.config.mjs` enables no type-aware linting (no `parserOptions.project` and no typed rules, as its own header states). ## Acceptance notes - **#21347 remains open; this PR does not carry its nightly red.** The red was reproduced at `f39760864c` with `OS_TEST_TIERS=nightly` on `packages/cli/test/json-stdout-purity.e2e.test.ts`: 1 failed, 40 passed. The failing case is `the family this contract has to hold across > is exactly the set listed here — a new member goes red until it is driven too`, with `expected [ 'meta resync', …(13) ] to deeply equal [ 'meta resync', …(12) ]`. The source-discovered family now includes `migrate audit-metadata-bodies` (it calls `bootSchemaStack(` and declares `--json`), and the file's `FAMILY` map does not list it. `os verify` is not a member of that family at all, because it boots through `@objectstack/verify`'s `bootStack`, not `bootSchemaStack`. So no case there is `verify --json`. All 13 driven members pass their three cases. Per the dispatch, that test file is not touched here. - That purity family is discovered from `bootSchemaStack(`, so it cannot see `os verify`. The new pin is what holds `verify --json` to one document. A grep over `packages/cli/src/commands` for a `--json` flag next to a kernel boot finds 15 commands: 14 reserve through `bootSchemaStack({ jsonOutput })`, and the 15th is `verify`, which now reserves too. - The ObjectQL registry prints its `[Registry] ...` housekeeping through `console.log`, at its own `OS_REGISTRY_LOG` level, outside the kernel logger. That is why a logger-level route could not have fixed this. This is an observation, not a defect, and nothing is filed. --- _Generated by [Claude Code](https://claude.ai/code/session_01VvcEokUG1tvVxkceYfR5XB)_ --------- Co-authored-by: Claude <noreply@anthropic.com>
1 parent ee75aae commit 5155093

4 files changed

Lines changed: 205 additions & 5 deletions

File tree

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,15 @@
1+
---
2+
'@objectstack/cli': patch
3+
---
4+
5+
fix(cli): `os verify --json` writes exactly one JSON document to stdout; the booted stack's log lines move to stderr (#21324)
6+
7+
Clause-②: no
8+
9+
`os verify --json > report.json` used to exit 0 and leave a file no JSON parser accepts. On a two-object stack that reaches the runtime stage, 318 lines landed on stdout ahead of the report: the kernel logger's `INFO` and `WARN` records, the ObjectQL registry's `[Registry] …` lines and the HTTP server's stop line. `JSON.parse` failed at position 4.
10+
11+
Under `--json`, stdout now carries the report and nothing else, and every other line the run writes goes to stderr. Nothing is dropped: the boot records, the warnings among them and the shutdown lines all still reach the operator, on stderr. The document is unchanged, and so is the shape of each of the three `--json` documents (the runtime report, the author-time refusal, and the could-not-run envelope).
12+
13+
`os verify` without `--json` is unchanged: the log lines stay on stdout beside the text report.
14+
15+
A script that read those log lines from `os verify --json`'s stdout now reads them from stderr.

‎content/docs/deployment/cli.mdx‎

Lines changed: 11 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1723,9 +1723,11 @@ os verify --rls --multi-tenant --json # Org-scoped boot, structured rep
17231723
same ones `os validate` reports — and the app is never booted. Advisories
17241724
(`warning` and `info` findings) never fail `os verify`; the text face counts
17251725
them, and `os validate` prints them. This stage is the rule registry, not all
1726-
of `os validate`: the package-docs lint, the capability-provider check, the
1727-
picklist-reference and view-container-name checks and `--strict` stay
1728-
`os validate`'s, so run it too.
1726+
of `os validate`: the `defineStack` provenance refusal (a config whose
1727+
default export `defineStack` did not build, `STACK_PROVENANCE_MISSING`), the
1728+
package-docs lint, the capability-provider check, the picklist-reference and
1729+
view-container-name checks and `--strict` stay `os validate`'s, so run it
1730+
too.
17291731
2. **Runtime.** Boot the app in-process and exercise it through the real HTTP
17301732
stack: for each object, a record derived from its fields is created, read
17311733
back and compared (CRUD round-trip fidelity), and a create, read or
@@ -1746,7 +1748,12 @@ The config is the one `--app` names, or the auto-detected one — see
17461748
| `0` | Both stages passed: no gating author-time finding, and no runtime failure |
17471749
| `1` | The author-time stage refused the stack (the runtime stage did not run), the runtime stage found failures, or the command could not run at all (no config found, a config that does not load, a boot failure) |
17481750
1749-
**`--json`.** What the document carries depends on where the run ended:
1751+
**`--json`.** stdout carries exactly one JSON document and nothing else, so
1752+
`os verify --json > report.json` leaves a file `JSON.parse` reads whole. Every
1753+
other line the run produces — the booted stack's log records, warnings
1754+
included, and its boot and shutdown lines — goes to stderr; none is dropped.
1755+
Without `--json`, those lines stay on stdout beside the text report. What the
1756+
document carries depends on where the run ended:
17501757
17511758
- **Refused by the author-time stage:** `{ "error": "<sentence>", "errors": [...] }`,
17521759
where `errors` carries the findings in the shape `os validate --json` carries

‎packages/cli/src/commands/verify.ts‎

Lines changed: 25 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -35,6 +35,7 @@ import {
3535
errorCodeFields,
3636
isReportedError,
3737
} from '../utils/format.js';
38+
import { reserveStdoutForJson } from '../utils/json-stdout.js';
3839

3940
/**
4041
* Should this `os verify` run boot an org-scoped (multi-tenant) stack?
@@ -132,6 +133,26 @@ export default class Verify extends Command {
132133
async run(): Promise<void> {
133134
const { flags } = await this.parse(Verify);
134135

136+
// [#21324] Under `--json`, stdout is the report's channel and nothing
137+
// else's: the payload leaves through `emitJson` (the real stdout), and
138+
// every other byte written to `process.stdout` for the rest of this run is
139+
// forwarded to stderr. Measured on a clean stack that reaches the runtime
140+
// stage, 318 lines landed on stdout ahead of the document, from three
141+
// independent writers — the kernel's `ObjectLogger` (174 lines, 5 of them
142+
// WARN: `info`/`warn` go to stdout by design, `packages/core/src/logger.ts`),
143+
// the ObjectQL registry's `console.log` (143 `[Registry] Installed
144+
// package: …` lines) and `HonoServerPlugin`'s `console.log` on stop. A
145+
// kernel logger level reaches only the first, and `silent` would throw the
146+
// degraded-boot WARN lines away with it; the stream reservation reaches all
147+
// three and destroys nothing — the route `bootSchemaStack` took for the
148+
// same defect (commit 2b641ddd4, `../utils/json-stdout.ts`).
149+
//
150+
// Taken before `loadConfig`, so nothing the run prints can precede it, and
151+
// never released: `os verify` is one-shot, its last act is the payload and
152+
// the exit, and a booted stack's late timers must not land under the
153+
// document. The text face owns stdout and takes no reservation.
154+
if (flags.json) reserveStdoutForJson();
155+
135156
try {
136157
await this.runVerification(flags);
137158
} catch (error: any) {
@@ -264,7 +285,10 @@ export default class Verify extends Command {
264285
(rls?.positionCoverage.notRun.length ?? 0);
265286

266287
if (flags.json) {
267-
this.log(JSON.stringify({ app: crud.app, config: absolutePath, multiTenant, crud, rls, hardFailures }, null, 2));
288+
// `emitJson`, not `this.log`: stdout is reserved (see `run()`), so the
289+
// report has to leave through the real stream — and awaiting the write
290+
// drains a report larger than one pipe buffer before `this.exit` below.
291+
await emitJson({ app: crud.app, config: absolutePath, multiTenant, crud, rls, hardFailures });
268292
} else {
269293
this.log(formatReport(crud));
270294
if (rls) this.log(formatRlsReport(rls));
Lines changed: 154 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,154 @@
1+
// Copyright (c) 2026 ObjectStack. Licensed under the Apache-2.0 license.
2+
3+
/**
4+
* PIN — `os verify --json` on a stack that REACHES THE RUNTIME STAGE writes
5+
* exactly one JSON document to stdout, and the boot's diagnostics are moved to
6+
* stderr rather than destroyed (#21324).
7+
*
8+
* ## The defect
9+
*
10+
* `objectstack verify --json > report.json` exited 0 and left a file no JSON
11+
* parser accepts. Measured through the real CLI on a clean stack before this
12+
* landed: 349 stdout lines, the document starting at line 319, and
13+
* `JSON.parse` failing at position 4. Every line ahead of it came from one of
14+
* three independent writers:
15+
*
16+
* - the kernel's `ObjectLogger` — 174 lines, 5 of them WARN (`info` and
17+
* `warn` go to stdout by design, `packages/core/src/logger.ts`);
18+
* - the ObjectQL registry's `console.log` — 143 `[Registry] Installed
19+
* package: …` lines;
20+
* - `HonoServerPlugin`'s `console.log` when the stack stops — 1 line.
21+
*
22+
* So a kernel logger setting could never have produced one document: two of
23+
* the three writers never pass through it.
24+
*
25+
* ## What is pinned
26+
*
27+
* - `--json`: stdout is BYTE-EQUAL to the re-serialized document — a bare
28+
* `JSON.parse`, and then nothing else on the stream, whoever wrote it —
29+
* and the document is the RUNTIME report (`crud`, `hardFailures`), so the
30+
* run really reached the stage whose boot writes the lines;
31+
* - the diagnostics are moved, never destroyed: stderr carries the kernel
32+
* logger's records, WARN among them, and the registry's `console.log`
33+
* lines. Silencing the logger would make stdout parse too, and go red here;
34+
* - the text face is unchanged: without `--json`, the kernel logger's
35+
* records still go to stdout beside the report.
36+
*
37+
* The stage-1 refusal face (`{ error, errors }`, nothing booted) is pinned by
38+
* `verify-author-time-stage.test.ts`.
39+
*
40+
* Spawned rather than run in-process: the stream a byte lands on is the
41+
* contract, and only a real process has the streams a consumer redirects.
42+
*/
43+
44+
import { describe, expect, it, beforeAll, afterAll } from 'vitest';
45+
import { spawnSync } from 'node:child_process';
46+
import { mkdtempSync, rmSync, writeFileSync } from 'node:fs';
47+
import { tmpdir } from 'node:os';
48+
import { join } from 'node:path';
49+
import { CLI, TSX, childEnv } from './helpers/serve-process.js';
50+
import { defineStackSource, linkSpec } from './helpers/define-stack-fixture.js';
51+
52+
/** A stack the author-time rules pass, so `os verify` reaches the runtime stage. */
53+
const STACK = {
54+
manifest: {
55+
id: 'com.example.verify-json-stdout',
56+
namespace: 'vj',
57+
version: '1.0.0',
58+
name: 'Verify JSON Stdout',
59+
type: 'app',
60+
engines: { protocol: '^17' },
61+
},
62+
objects: [
63+
{
64+
name: 'vj_note',
65+
label: 'Note',
66+
pluralLabel: 'Notes',
67+
sharingModel: 'private',
68+
fields: {
69+
title: { type: 'text', label: 'Title', required: true },
70+
done: { type: 'boolean', label: 'Done' },
71+
},
72+
},
73+
],
74+
};
75+
76+
/** The rendering `ObjectLogger` writes at `pretty` (the CLI's format): `<iso-ts> LEVEL …`. */
77+
const LOGGER_RECORD = /^\d{4}-\d{2}-\d{2}T[\d:.]+Z\s+(DEBUG|INFO|WARN)\b/m;
78+
const LOGGER_WARN_RECORD = /^\d{4}-\d{2}-\d{2}T[\d:.]+Z\s+WARN\b/m;
79+
80+
/** The second writer: a `console.log` in the ObjectQL registry, outside the kernel logger. */
81+
const REGISTRY_CONSOLE_LINE = '[Registry] Installed package';
82+
83+
interface Run {
84+
status: number | null;
85+
stdout: string;
86+
stderr: string;
87+
}
88+
89+
function runCli(dir: string, args: string[]): Run {
90+
// Through tsx, so the child runs this checkout's `src/` — under plain node
91+
// oclif resolves the command from `dist/`, and the pin would measure
92+
// whatever was last built.
93+
const r = spawnSync(TSX, [CLI, ...args], {
94+
cwd: dir,
95+
encoding: 'utf8',
96+
// Every spawned child under this directory declares its environment at the
97+
// call site (#11595). `OS_REGISTRY_LOG: 'info'` is the shipped default,
98+
// restated because this package's vitest config sets `warn` for its own
99+
// workers and the child would inherit it: at `warn` the registry's
100+
// `console.log` — the writer a logger-level fix cannot reach — never speaks,
101+
// and the pin would hold over one writer instead of the three an operator's
102+
// run has.
103+
env: childEnv({ NO_COLOR: '1', OS_REGISTRY_LOG: 'info' }),
104+
maxBuffer: 64 * 1024 * 1024,
105+
});
106+
return { status: r.status, stdout: r.stdout ?? '', stderr: r.stderr ?? '' };
107+
}
108+
109+
describe('os verify --json on a stack that reaches the runtime stage (#21324)', () => {
110+
let dir: string;
111+
let json: Run;
112+
let text: Run;
113+
114+
beforeAll(() => {
115+
dir = mkdtempSync(join(tmpdir(), 'os-verify-json-stdout-'));
116+
writeFileSync(join(dir, 'objectstack.config.mjs'), defineStackSource(STACK));
117+
linkSpec(dir);
118+
json = runCli(dir, ['verify', '--json']);
119+
text = runCli(dir, ['verify']);
120+
}, 360_000);
121+
122+
afterAll(() => {
123+
if (dir) rmSync(dir, { recursive: true, force: true });
124+
});
125+
126+
it('writes exactly one JSON document to stdout, and it is the runtime report', () => {
127+
expect(json.status, `os verify --json failed on a clean stack:\n${json.stdout}\n${json.stderr}`).toBe(0);
128+
// A bare parse — no extraction. Under the defect this threw at position 4.
129+
const doc = JSON.parse(json.stdout) as { crud?: unknown; hardFailures?: unknown };
130+
// And NOTHING else on the stream: a stray line after the document, or a
131+
// second document, would survive a lenient reader but not this equality.
132+
expect(json.stdout).toBe(`${JSON.stringify(doc, null, 2)}\n`);
133+
expect(doc.crud).toBeTypeOf('object');
134+
expect(doc.hardFailures).toBe(0);
135+
});
136+
137+
it('leaves no record of either writer on stdout, naming the cause separately from the parse', () => {
138+
expect(json.stdout).not.toMatch(LOGGER_RECORD);
139+
expect(json.stdout).not.toContain(REGISTRY_CONSOLE_LINE);
140+
});
141+
142+
it('moves the diagnostics to stderr instead of destroying them — WARN records included', () => {
143+
expect(json.stderr).toMatch(LOGGER_RECORD);
144+
expect(json.stderr).toMatch(LOGGER_WARN_RECORD);
145+
expect(json.stderr).toContain(REGISTRY_CONSOLE_LINE);
146+
});
147+
148+
it('leaves the text face as it was: the kernel logger still writes to stdout beside the report', () => {
149+
expect(text.status, `os verify failed on a clean stack:\n${text.stdout}\n${text.stderr}`).toBe(0);
150+
expect(text.stdout).toMatch(LOGGER_RECORD);
151+
expect(text.stdout).toContain(REGISTRY_CONSOLE_LINE);
152+
expect(text.stdout).toContain('verify passed');
153+
});
154+
});

0 commit comments

Comments
 (0)