|
| 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