From 58f45ef75871045ea9a5ae7fb7229e4f641336be Mon Sep 17 00:00:00 2001 From: Miguel Angel Simon Sierra Date: Fri, 10 Jul 2026 01:56:08 -0400 Subject: [PATCH] feat(cli): deprecate validate, inspect, layout in favor of check MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit One stderr notice per invocation and _meta.deprecated: true in JSON mode (shared helper next to withMeta; layout owns both inspect and layout via createInspectCommand). Help descriptions gain the pointer. No behavior change; removal ships separately once migration telemetry says usage has decayed. fix(producer): route info/debug logs to stderr — the compiler's 'Localized remote media' line was landing on stdout ahead of validate's --json payload, breaking every piped consumer. Diagnostics now share stderr with warn/error; render progress uses its own channel. --- packages/cli/src/commands/inspect.test.ts | 81 ++++++++++++++++ packages/cli/src/commands/layout.test.ts | 104 +++++++++++++++++++++ packages/cli/src/commands/layout.ts | 92 ++++++++++-------- packages/cli/src/commands/validate.test.ts | 86 ++++++++++++++++- packages/cli/src/commands/validate.ts | 28 ++++-- packages/cli/src/utils/updateCheck.test.ts | 64 ++++++++++++- packages/cli/src/utils/updateCheck.ts | 27 +++++- packages/producer/src/logger.test.ts | 94 +++++++++++++------ packages/producer/src/logger.ts | 10 +- 9 files changed, 500 insertions(+), 86 deletions(-) create mode 100644 packages/cli/src/commands/inspect.test.ts create mode 100644 packages/cli/src/commands/layout.test.ts diff --git a/packages/cli/src/commands/inspect.test.ts b/packages/cli/src/commands/inspect.test.ts new file mode 100644 index 000000000..59288c7eb --- /dev/null +++ b/packages/cli/src/commands/inspect.test.ts @@ -0,0 +1,81 @@ +import type { CommandDef } from "citty"; +import { runCommand } from "citty"; +import { afterEach, describe, expect, it, vi } from "vitest"; + +// See layout.test.ts for why these two dynamic-import targets are mocked: +// resolveProject skips real filesystem resolution, and bundleToSingleHtml +// gives a fast, deterministic failure that exercises run()'s outer catch +// (the JSON failure envelope) without needing headless Chrome. +const FAKE_PROJECT = { + dir: "/fake-project", + name: "fake-project", + indexPath: "/fake-project/index.html", +}; + +vi.mock("../utils/project.js", () => ({ + resolveProject: vi.fn(() => FAKE_PROJECT), +})); + +vi.mock("@hyperframes/core/compiler", () => ({ + bundleToSingleHtml: vi.fn(async () => { + throw new Error("bundling failed (test double)"); + }), +})); + +import inspectCommand from "./inspect.js"; + +function metaDescription(command: CommandDef): string { + const meta = command.meta; + if (meta && typeof meta === "object" && "description" in meta) { + return String(meta.description ?? ""); + } + throw new Error("expected a synchronous meta object"); +} + +afterEach(() => { + vi.restoreAllMocks(); +}); + +describe("inspect command deprecation (U5)", () => { + it("is the compatibility alias for layout, sharing its deprecated description", () => { + expect(metaDescription(inspectCommand)).toContain("(deprecated, use check)"); + }); + + it("prints a one-line deprecation notice naming 'inspect' on stderr, never stdout", async () => { + const stderrWrites: string[] = []; + const stdoutWrites: string[] = []; + vi.spyOn(process.stderr, "write").mockImplementation((chunk: unknown) => { + stderrWrites.push(String(chunk)); + return true; + }); + vi.spyOn(process.stdout, "write").mockImplementation((chunk: unknown) => { + stdoutWrites.push(String(chunk)); + return true; + }); + vi.spyOn(process, "exit").mockImplementation(() => undefined as never); + vi.spyOn(console, "log").mockImplementation(() => {}); + + await runCommand(inspectCommand, { rawArgs: ["--json"] }); + + const stderrText = stderrWrites.join(""); + expect(stderrText).toContain("hyperframes inspect"); + expect(stderrText).toContain("hyperframes check"); + expect(stdoutWrites.join("")).toBe(""); + }); + + it("--json output is valid JSON with _meta.deprecated === true on failure", async () => { + vi.spyOn(process.stderr, "write").mockImplementation(() => true); + vi.spyOn(process, "exit").mockImplementation(() => undefined as never); + const logSpy = vi.spyOn(console, "log").mockImplementation(() => {}); + + await runCommand(inspectCommand, { rawArgs: ["--json"] }); + + const jsonCall = logSpy.mock.calls.find( + ([arg]) => typeof arg === "string" && arg.trim().startsWith("{"), + ); + expect(jsonCall).toBeDefined(); + const parsed = JSON.parse(String(jsonCall?.[0])); + expect(parsed.ok).toBe(false); + expect(parsed._meta.deprecated).toBe(true); + }); +}); diff --git a/packages/cli/src/commands/layout.test.ts b/packages/cli/src/commands/layout.test.ts new file mode 100644 index 000000000..bd7cdb4d7 --- /dev/null +++ b/packages/cli/src/commands/layout.test.ts @@ -0,0 +1,104 @@ +import type { CommandDef } from "citty"; +import { runCommand } from "citty"; +import { afterEach, describe, expect, it, vi } from "vitest"; + +// resolveProject and bundleToSingleHtml are both reached via a dynamic +// `await import(...)` inside layout.ts's run() / runLayoutAudit(), so +// vi.mock intercepts them the same way it would a static import. Mocking +// resolveProject skips real filesystem project resolution; mocking +// bundleToSingleHtml gives a deterministic, fast failure well before any +// real browser or network work — exercising run()'s outer catch (the JSON +// failure envelope) without needing headless Chrome. +const FAKE_PROJECT = { + dir: "/fake-project", + name: "fake-project", + indexPath: "/fake-project/index.html", +}; + +vi.mock("../utils/project.js", () => ({ + resolveProject: vi.fn(() => FAKE_PROJECT), +})); + +vi.mock("@hyperframes/core/compiler", () => ({ + bundleToSingleHtml: vi.fn(async () => { + throw new Error("bundling failed (test double)"); + }), +})); + +import { createInspectCommand } from "./layout.js"; + +/** + * citty's `meta` is `Resolvable` (object | promise | thunk). + * This file's commands always define it as a synchronous object literal, so + * narrow to that shape instead of asserting it with `as`. + */ +function metaDescription(command: CommandDef): string { + const meta = command.meta; + if (meta && typeof meta === "object" && "description" in meta) { + return String(meta.description ?? ""); + } + throw new Error("expected a synchronous meta object"); +} + +afterEach(() => { + vi.restoreAllMocks(); +}); + +describe("layout command deprecation (U5)", () => { + it("marks both the layout and inspect command names' shared description as deprecated", () => { + expect(metaDescription(createInspectCommand("layout"))).toContain("(deprecated, use check)"); + expect(metaDescription(createInspectCommand("inspect"))).toContain("(deprecated, use check)"); + }); + + it("prints a one-line deprecation notice to stderr and never to stdout", async () => { + const stderrWrites: string[] = []; + const stdoutWrites: string[] = []; + vi.spyOn(process.stderr, "write").mockImplementation((chunk: unknown) => { + stderrWrites.push(String(chunk)); + return true; + }); + vi.spyOn(process.stdout, "write").mockImplementation((chunk: unknown) => { + stdoutWrites.push(String(chunk)); + return true; + }); + vi.spyOn(process, "exit").mockImplementation(() => undefined as never); + vi.spyOn(console, "log").mockImplementation(() => {}); + + await runCommand(createInspectCommand("layout"), { rawArgs: ["--json"] }); + + const stderrText = stderrWrites.join(""); + expect(stderrText).toContain("hyperframes layout"); + expect(stderrText).toContain("hyperframes check"); + expect(stdoutWrites.join("")).toBe(""); + }); + + it("--json output is valid JSON with _meta.deprecated === true on failure", async () => { + vi.spyOn(process.stderr, "write").mockImplementation(() => true); + vi.spyOn(process, "exit").mockImplementation(() => undefined as never); + const logSpy = vi.spyOn(console, "log").mockImplementation(() => {}); + + await runCommand(createInspectCommand("layout"), { rawArgs: ["--json"] }); + + const jsonCall = logSpy.mock.calls.find( + ([arg]) => typeof arg === "string" && arg.trim().startsWith("{"), + ); + expect(jsonCall).toBeDefined(); + const parsed = JSON.parse(String(jsonCall?.[0])); + expect(parsed.ok).toBe(false); + expect(parsed._meta.deprecated).toBe(true); + }); + + it("the inspect command name produces the same _meta.deprecated === true envelope", async () => { + vi.spyOn(process.stderr, "write").mockImplementation(() => true); + vi.spyOn(process, "exit").mockImplementation(() => undefined as never); + const logSpy = vi.spyOn(console, "log").mockImplementation(() => {}); + + await runCommand(createInspectCommand("inspect"), { rawArgs: ["--json"] }); + + const jsonCall = logSpy.mock.calls.find( + ([arg]) => typeof arg === "string" && arg.trim().startsWith("{"), + ); + const parsed = JSON.parse(String(jsonCall?.[0])); + expect(parsed._meta.deprecated).toBe(true); + }); +}); diff --git a/packages/cli/src/commands/layout.ts b/packages/cli/src/commands/layout.ts index 55d2c49d2..1fb0f3a28 100644 --- a/packages/cli/src/commands/layout.ts +++ b/packages/cli/src/commands/layout.ts @@ -7,7 +7,7 @@ import { c } from "../ui/colors.js"; import { resolveProject } from "../utils/project.js"; import { normalizeErrorMessage } from "../utils/errorMessage.js"; import { serveStaticProjectHtml } from "../utils/staticProjectServer.js"; -import { withMeta } from "../utils/updateCheck.js"; +import { printDeprecationNotice, withMeta } from "../utils/updateCheck.js"; import { buildLayoutSampleTimes, buildTransitionSampleTimes, @@ -388,16 +388,19 @@ function resolveMotionSpec(specPath: string, json: boolean): MotionSpec { if (json) { console.log( JSON.stringify( - withMeta({ - schemaVersion: INSPECT_SCHEMA_VERSION, - ok: false, - error: message, - issues: [], - errorCount: 0, - warningCount: 0, - infoCount: 0, - issueCount: 0, - }), + withMeta( + { + schemaVersion: INSPECT_SCHEMA_VERSION, + ok: false, + error: message, + issues: [], + errorCount: 0, + warningCount: 0, + infoCount: 0, + issueCount: 0, + }, + { deprecated: true }, + ), null, 2, ), @@ -422,7 +425,7 @@ export function createInspectCommand(commandName: "inspect" | "layout") { meta: { name: commandName, description: - "Inspect rendered composition layout for text/container overflow, plus optional motion verification via a *.motion.json sidecar", + "Inspect rendered composition layout for text/container overflow, plus optional motion verification via a *.motion.json sidecar (deprecated, use check)", }, args: { dir: { type: "positional", description: "Project directory", required: false }, @@ -476,6 +479,7 @@ export function createInspectCommand(commandName: "inspect" | "layout") { // Pre-existing command-run branching; U1 only swapped the seek internals. // fallow-ignore-next-line complexity async run({ args }) { + printDeprecationNotice(commandName); const project = resolveProject(args.dir); const samples = Math.max(1, parseInt(args.samples as string, 10) || 9); const tolerance = Math.max(0, parseFloat(args.tolerance as string) || 2); @@ -534,25 +538,28 @@ export function createInspectCommand(commandName: "inspect" | "layout") { if (args.json) { console.log( JSON.stringify( - withMeta({ - schemaVersion: INSPECT_SCHEMA_VERSION, - duration: result.duration, - samples: result.samples, - transitionSamples: atTransitions ? result.transitionSamples : undefined, - transitionSamplesDropped: atTransitions - ? result.transitionSamplesDropped - : undefined, - tolerance, - strict, - collapseStatic, - motionSpec: motionSpec ? motionSpecPath : undefined, - motionSamples: motionSpec ? result.motionSamples : undefined, - ...summary, - totalIssueCount: limited.totalIssueCount, - truncated: limited.truncated, - ok, - issues: limited.issues, - }), + withMeta( + { + schemaVersion: INSPECT_SCHEMA_VERSION, + duration: result.duration, + samples: result.samples, + transitionSamples: atTransitions ? result.transitionSamples : undefined, + transitionSamplesDropped: atTransitions + ? result.transitionSamplesDropped + : undefined, + tolerance, + strict, + collapseStatic, + motionSpec: motionSpec ? motionSpecPath : undefined, + motionSamples: motionSpec ? result.motionSamples : undefined, + ...summary, + totalIssueCount: limited.totalIssueCount, + truncated: limited.truncated, + ok, + issues: limited.issues, + }, + { deprecated: true }, + ), null, 2, ), @@ -602,16 +609,19 @@ export function createInspectCommand(commandName: "inspect" | "layout") { if (args.json) { console.log( JSON.stringify( - withMeta({ - schemaVersion: INSPECT_SCHEMA_VERSION, - ok: false, - error: message, - issues: [], - errorCount: 0, - warningCount: 0, - infoCount: 0, - issueCount: 0, - }), + withMeta( + { + schemaVersion: INSPECT_SCHEMA_VERSION, + ok: false, + error: message, + issues: [], + errorCount: 0, + warningCount: 0, + infoCount: 0, + issueCount: 0, + }, + { deprecated: true }, + ), null, 2, ), diff --git a/packages/cli/src/commands/validate.test.ts b/packages/cli/src/commands/validate.test.ts index bd3941286..f35f3ffd8 100644 --- a/packages/cli/src/commands/validate.test.ts +++ b/packages/cli/src/commands/validate.test.ts @@ -1,4 +1,6 @@ -import { describe, expect, it, vi } from "vitest"; +import type { CommandDef } from "citty"; +import { runCommand } from "citty"; +import { afterEach, describe, expect, it, vi } from "vitest"; import { extractCompositionErrorsFromLint, navigationTimeoutHint, @@ -28,6 +30,29 @@ vi.mock("../utils/producer.js", () => ({ })), })); +// U5 deprecation tests: resolveProject and lintProject are both reached via a +// dynamic `await import(...)` inside validate.ts's run() / validateInBrowser(), +// so vi.mock intercepts them the same way it would a static import. Mocking +// resolveProject skips real filesystem project resolution; mocking lintProject +// (the first await inside validateInBrowser) gives a fast, deterministic +// failure well before any real browser or network work — exercising run()'s +// outer catch (the JSON failure envelope) without needing headless Chrome. +const FAKE_PROJECT = { + dir: "/fake-project", + name: "fake-project", + indexPath: "/fake-project/index.html", +}; + +vi.mock("../utils/project.js", () => ({ + resolveProject: vi.fn(() => FAKE_PROJECT), +})); + +vi.mock("../utils/lintProject.js", () => ({ + lintProject: vi.fn(async () => { + throw new Error("lint failed (test double)"); + }), +})); + // Regression for the validate audio-duration-probe timeout: a slow-loading // media element's duration was snapshotted once, at a fixed point in time, // and any element still mid-load was permanently misreported as unreadable. @@ -282,3 +307,62 @@ describe("navigationTimeoutHint", () => { expect(navigationTimeoutHint("some string failure", 10000)).toBeNull(); }); }); + +function metaDescription(command: CommandDef): string { + const meta = command.meta; + if (meta && typeof meta === "object" && "description" in meta) { + return String(meta.description ?? ""); + } + throw new Error("expected a synchronous meta object"); +} + +describe("validate command deprecation (U5)", () => { + afterEach(() => { + vi.restoreAllMocks(); + }); + + it("marks the command description as deprecated", async () => { + const { default: validateCommand } = await import("./validate.js"); + expect(metaDescription(validateCommand)).toContain("(deprecated, use check)"); + }); + + it("prints a one-line deprecation notice to stderr and never to stdout", async () => { + const stderrWrites: string[] = []; + const stdoutWrites: string[] = []; + vi.spyOn(process.stderr, "write").mockImplementation((chunk: unknown) => { + stderrWrites.push(String(chunk)); + return true; + }); + vi.spyOn(process.stdout, "write").mockImplementation((chunk: unknown) => { + stdoutWrites.push(String(chunk)); + return true; + }); + vi.spyOn(process, "exit").mockImplementation(() => undefined as never); + vi.spyOn(console, "log").mockImplementation(() => {}); + + const { default: validateCommand } = await import("./validate.js"); + await runCommand(validateCommand, { rawArgs: ["--json"] }); + + const stderrText = stderrWrites.join(""); + expect(stderrText).toContain("hyperframes validate"); + expect(stderrText).toContain("hyperframes check"); + expect(stdoutWrites.join("")).toBe(""); + }); + + it("--json output is valid JSON with _meta.deprecated === true on failure", async () => { + vi.spyOn(process.stderr, "write").mockImplementation(() => true); + vi.spyOn(process, "exit").mockImplementation(() => undefined as never); + const logSpy = vi.spyOn(console, "log").mockImplementation(() => {}); + + const { default: validateCommand } = await import("./validate.js"); + await runCommand(validateCommand, { rawArgs: ["--json"] }); + + const jsonCall = logSpy.mock.calls.find( + ([arg]) => typeof arg === "string" && arg.trim().startsWith("{"), + ); + expect(jsonCall).toBeDefined(); + const parsed = JSON.parse(String(jsonCall?.[0])); + expect(parsed.ok).toBe(false); + expect(parsed._meta.deprecated).toBe(true); + }); +}); diff --git a/packages/cli/src/commands/validate.ts b/packages/cli/src/commands/validate.ts index 0852dec60..823ae2367 100644 --- a/packages/cli/src/commands/validate.ts +++ b/packages/cli/src/commands/validate.ts @@ -13,7 +13,7 @@ import { normalizeErrorMessage } from "../utils/errorMessage.js"; import type { ProjectLintResult } from "../utils/lintProject.js"; import { resolveCompositionViewportFromHtml } from "../utils/compositionViewport.js"; import { c } from "../ui/colors.js"; -import { withMeta } from "../utils/updateCheck.js"; +import { printDeprecationNotice, withMeta } from "../utils/updateCheck.js"; import { resolveCliChromeGpuMode, seekCompositionTimeline, @@ -514,13 +514,16 @@ function emitJsonReport( ): void { console.log( JSON.stringify( - withMeta({ - ok: errors.length === 0, - errors, - warnings, - contrast, - contrastFailures: contrastFailures.length, - }), + withMeta( + { + ok: errors.length === 0, + errors, + warnings, + contrast, + contrastFailures: contrastFailures.length, + }, + { deprecated: true }, + ), null, 2, ), @@ -567,7 +570,11 @@ function emitTextReport( function emitFailureReport(message: string, asJson: boolean): void { if (asJson) { console.log( - JSON.stringify(withMeta({ ok: false, error: message, errors: [], warnings: [] }), null, 2), + JSON.stringify( + withMeta({ ok: false, error: message, errors: [], warnings: [] }, { deprecated: true }), + null, + 2, + ), ); return; } @@ -577,7 +584,7 @@ function emitFailureReport(message: string, asJson: boolean): void { export default defineCommand({ meta: { name: "validate", - description: `Load a composition in headless Chrome and report console errors + description: `Load a composition in headless Chrome and report console errors (deprecated, use check) Examples: hyperframes validate @@ -602,6 +609,7 @@ Examples: }, }, async run({ args }) { + printDeprecationNotice("validate"); const project = resolveProject(args.dir); const timeout = parseInt(args.timeout as string, 10) || 3000; const useContrast = args.contrast ?? true; diff --git a/packages/cli/src/utils/updateCheck.test.ts b/packages/cli/src/utils/updateCheck.test.ts index 1de5d35bc..9a9daf28c 100644 --- a/packages/cli/src/utils/updateCheck.test.ts +++ b/packages/cli/src/utils/updateCheck.test.ts @@ -1,5 +1,5 @@ import { afterEach, describe, expect, it, vi } from "vitest"; -import { isSafeVersion } from "./updateCheck.js"; +import { isSafeVersion, printDeprecationNotice, withMeta } from "./updateCheck.js"; describe("isSafeVersion", () => { it("accepts strict semver, incl. prerelease/build metadata", () => { @@ -150,6 +150,68 @@ async function checkWith(registryVersion: unknown): Promise<{ } } +/** + * U5: validate/inspect/layout are deprecated in favor of `check`. withMeta's + * optional `{ deprecated: true }` is the single place that adds `_meta.deprecated` + * to a --json envelope; every other command (check, lint, ...) calls withMeta + * with no second argument and must never see the key at all — not even `false`. + */ +describe("withMeta — deprecated flag", () => { + it("omits _meta.deprecated entirely when no options are passed (check/lint et al.)", () => { + const wrapped = withMeta({ ok: true }); + expect("deprecated" in wrapped._meta).toBe(false); + }); + + it("omits _meta.deprecated when options.deprecated is false", () => { + const wrapped = withMeta({ ok: true }, { deprecated: false }); + expect("deprecated" in wrapped._meta).toBe(false); + }); + + it("sets _meta.deprecated === true when requested (validate/inspect/layout)", () => { + const wrapped = withMeta({ ok: true }, { deprecated: true }); + expect(wrapped._meta.deprecated).toBe(true); + }); + + it("preserves the rest of the _meta envelope alongside the deprecated flag", () => { + const wrapped = withMeta({ ok: true }, { deprecated: true }); + expect(wrapped._meta.version).toEqual(expect.any(String)); + expect(typeof wrapped._meta.updateAvailable).toBe("boolean"); + }); +}); + +/** + * The stderr-only deprecation notice: printed once per invocation, never on + * stdout, so --json output stays pure JSON while humans still see the notice. + */ +describe("printDeprecationNotice", () => { + it("writes exactly one line to stderr, never stdout", () => { + const stderrWrites: string[] = []; + const stdoutWrites: string[] = []; + const origErrWrite = process.stderr.write.bind(process.stderr); + const origOutWrite = process.stdout.write.bind(process.stdout); + process.stderr.write = ((chunk: unknown) => { + stderrWrites.push(String(chunk)); + return true; + }) as typeof process.stderr.write; + process.stdout.write = ((chunk: unknown) => { + stdoutWrites.push(String(chunk)); + return true; + }) as typeof process.stdout.write; + + try { + printDeprecationNotice("validate"); + } finally { + process.stderr.write = origErrWrite; + process.stdout.write = origOutWrite; + } + + expect(stdoutWrites).toEqual([]); + expect(stderrWrites).toHaveLength(1); + expect(stderrWrites[0]).toContain("hyperframes validate"); + expect(stderrWrites[0]).toContain("hyperframes check"); + }); +}); + describe("checkForUpdate — registry boundary guard", () => { afterEach(() => { vi.doUnmock("../telemetry/config.js"); diff --git a/packages/cli/src/utils/updateCheck.ts b/packages/cli/src/utils/updateCheck.ts index caaab0920..6a58fad52 100644 --- a/packages/cli/src/utils/updateCheck.ts +++ b/packages/cli/src/utils/updateCheck.ts @@ -40,6 +40,8 @@ export interface UpdateMeta { version: string; latestVersion?: string; updateAvailable: boolean; + /** Present (and true) only for commands superseded by `check`; absent otherwise. */ + deprecated?: boolean; } /** @@ -130,9 +132,30 @@ export function getUpdateMeta(): UpdateMeta { /** * Wrap a JSON payload with the _meta version envelope. * Use this in all --json command outputs for consistent agent-friendly metadata. + * + * Pass `{ deprecated: true }` from a command superseded by `check` (validate, + * inspect, layout) to add `_meta.deprecated: true`; every other call site is + * unaffected — the key is only ever added, never set to `false`. */ -export function withMeta(data: T): T & { _meta: UpdateMeta } { - return { ...data, _meta: getUpdateMeta() }; +export function withMeta( + data: T, + options?: { deprecated?: boolean }, +): T & { _meta: UpdateMeta } { + const meta = getUpdateMeta(); + if (options?.deprecated) meta.deprecated = true; + return { ...data, _meta: meta }; +} + +/** + * One-line deprecation notice for a command superseded by `check`. Always + * writes to stderr (never stdout), so a --json invocation's stdout stays + * pure, parseable JSON. Call once per invocation, before the command's own + * output. + */ +export function printDeprecationNotice(command: string): void { + process.stderr.write( + `'hyperframes ${command}' is deprecated and will be removed in a future release. Use 'hyperframes check' instead.\n`, + ); } /** diff --git a/packages/producer/src/logger.test.ts b/packages/producer/src/logger.test.ts index f4d1f66c9..8e767d36f 100644 --- a/packages/producer/src/logger.test.ts +++ b/packages/producer/src/logger.test.ts @@ -1,13 +1,13 @@ -import { afterEach, beforeEach, describe, expect, it, mock } from "bun:test"; +import { afterEach, beforeEach, describe, expect, it, vi } from "vitest"; import { createConsoleLogger, defaultLogger } from "./logger.js"; import type { LogLevel, ProducerLogger } from "./logger.js"; describe("createConsoleLogger", () => { - // We capture calls to console.{log,warn,error} via `mock` so we can + // We capture calls to console.{log,warn,error} via `vi.fn` so we can // assert what would have been printed without polluting test output. - let logSpy: ReturnType; - let warnSpy: ReturnType; - let errorSpy: ReturnType; + let logSpy: ReturnType; + let warnSpy: ReturnType; + let errorSpy: ReturnType; let origLog: typeof console.log; let origWarn: typeof console.warn; let origError: typeof console.error; @@ -16,9 +16,9 @@ describe("createConsoleLogger", () => { origLog = console.log; origWarn = console.warn; origError = console.error; - logSpy = mock(() => {}); - warnSpy = mock(() => {}); - errorSpy = mock(() => {}); + logSpy = vi.fn(); + warnSpy = vi.fn(); + errorSpy = vi.fn(); console.log = logSpy as unknown as typeof console.log; console.warn = warnSpy as unknown as typeof console.warn; console.error = errorSpy as unknown as typeof console.error; @@ -30,6 +30,43 @@ describe("createConsoleLogger", () => { console.error = origError; }); + // All four levels are stderr-bound (console.error/console.warn); console.log + // (stdout) must never be touched, since producer runs inside CLI commands + // whose stdout is a machine-readable contract (e.g. `validate --json`). + describe("stdout/stderr routing", () => { + it("info and debug write to console.error (stderr), never console.log (stdout)", () => { + const log = createConsoleLogger("debug"); + log.info("info-msg"); + log.debug("debug-msg"); + + expect(logSpy).not.toHaveBeenCalled(); + expect(errorSpy.mock.calls.map((c) => c[0])).toEqual([ + "[INFO] info-msg", + "[DEBUG] debug-msg", + ]); + }); + + it("warn and error keep their pre-existing channels (console.warn / console.error)", () => { + const log = createConsoleLogger("debug"); + log.warn("warn-msg"); + log.error("error-msg"); + + expect(logSpy).not.toHaveBeenCalled(); + expect(warnSpy.mock.calls[0]?.[0]).toBe("[WARN] warn-msg"); + expect(errorSpy.mock.calls[0]?.[0]).toBe("[ERROR] error-msg"); + }); + + it("console.log is never called at any level", () => { + const log = createConsoleLogger("debug"); + log.debug("d"); + log.info("i"); + log.warn("w"); + log.error("e"); + + expect(logSpy).not.toHaveBeenCalled(); + }); + }); + describe("level filtering", () => { it("level=info drops debug, keeps info/warn/error", () => { const log = createConsoleLogger("info"); @@ -38,12 +75,12 @@ describe("createConsoleLogger", () => { log.warn("warn-msg"); log.error("error-msg"); - expect(logSpy.mock.calls.length).toBe(1); - expect(logSpy.mock.calls[0]?.[0]).toBe("[INFO] info-msg"); + // info + error both route to console.error now (info: stderr routing, error: always stderr). + expect(errorSpy.mock.calls.length).toBe(2); + expect(errorSpy.mock.calls[0]?.[0]).toBe("[INFO] info-msg"); + expect(errorSpy.mock.calls[1]?.[0]).toBe("[ERROR] error-msg"); expect(warnSpy.mock.calls.length).toBe(1); expect(warnSpy.mock.calls[0]?.[0]).toBe("[WARN] warn-msg"); - expect(errorSpy.mock.calls.length).toBe(1); - expect(errorSpy.mock.calls[0]?.[0]).toBe("[ERROR] error-msg"); }); it("level=debug keeps all four levels", () => { @@ -53,12 +90,12 @@ describe("createConsoleLogger", () => { log.warn("w"); log.error("e"); - // info + debug both go to console.log - expect(logSpy.mock.calls.length).toBe(2); - expect(logSpy.mock.calls[0]?.[0]).toBe("[DEBUG] d"); - expect(logSpy.mock.calls[1]?.[0]).toBe("[INFO] i"); + // debug + info + error all go to console.error + expect(errorSpy.mock.calls.length).toBe(3); + expect(errorSpy.mock.calls[0]?.[0]).toBe("[DEBUG] d"); + expect(errorSpy.mock.calls[1]?.[0]).toBe("[INFO] i"); + expect(errorSpy.mock.calls[2]?.[0]).toBe("[ERROR] e"); expect(warnSpy.mock.calls.length).toBe(1); - expect(errorSpy.mock.calls.length).toBe(1); }); it("level=warn drops info and debug, keeps warn/error", () => { @@ -68,9 +105,9 @@ describe("createConsoleLogger", () => { log.warn("w"); log.error("e"); - expect(logSpy.mock.calls.length).toBe(0); - expect(warnSpy.mock.calls.length).toBe(1); expect(errorSpy.mock.calls.length).toBe(1); + expect(errorSpy.mock.calls[0]?.[0]).toBe("[ERROR] e"); + expect(warnSpy.mock.calls.length).toBe(1); }); it("level=error drops everything except error", () => { @@ -80,7 +117,6 @@ describe("createConsoleLogger", () => { log.warn("w"); log.error("e"); - expect(logSpy.mock.calls.length).toBe(0); expect(warnSpy.mock.calls.length).toBe(0); expect(errorSpy.mock.calls.length).toBe(1); }); @@ -90,8 +126,8 @@ describe("createConsoleLogger", () => { log.debug("d"); log.info("i"); - expect(logSpy.mock.calls.length).toBe(1); - expect(logSpy.mock.calls[0]?.[0]).toBe("[INFO] i"); + expect(errorSpy.mock.calls.length).toBe(1); + expect(errorSpy.mock.calls[0]?.[0]).toBe("[INFO] i"); }); }); @@ -100,14 +136,14 @@ describe("createConsoleLogger", () => { const log = createConsoleLogger("info"); log.info("hello", { a: 1, b: "two" }); - expect(logSpy.mock.calls[0]?.[0]).toBe('[INFO] hello {"a":1,"b":"two"}'); + expect(errorSpy.mock.calls[0]?.[0]).toBe('[INFO] hello {"a":1,"b":"two"}'); }); it("emits message only when meta is omitted", () => { const log = createConsoleLogger("info"); log.info("plain"); - expect(logSpy.mock.calls[0]?.[0]).toBe("[INFO] plain"); + expect(errorSpy.mock.calls[0]?.[0]).toBe("[INFO] plain"); }); it("does not invoke JSON.stringify when level is filtered out", () => { @@ -123,7 +159,7 @@ describe("createConsoleLogger", () => { }; // Should not throw — debug is below the info threshold. log.debug("trap", trap as unknown as Record); - expect(logSpy.mock.calls.length).toBe(0); + expect(errorSpy.mock.calls.length).toBe(0); }); }); @@ -185,7 +221,7 @@ describe("createConsoleLogger", () => { } expect(buildCount).toBe(0); - expect(logSpy.mock.calls.length).toBe(0); + expect(errorSpy.mock.calls.length).toBe(0); }); it("call-site gate runs the meta builder when debug is enabled", () => { @@ -203,7 +239,7 @@ describe("createConsoleLogger", () => { } expect(buildCount).toBe(5); - expect(logSpy.mock.calls.length).toBe(5); + expect(errorSpy.mock.calls.length).toBe(5); }); it("custom logger without isLevelEnabled falls back to running the meta builder (`?? true`)", () => { @@ -242,8 +278,8 @@ describe("createConsoleLogger", () => { defaultLogger.info("default-info"); defaultLogger.debug("default-debug"); - expect(logSpy.mock.calls.length).toBe(1); - expect(logSpy.mock.calls[0]?.[0]).toBe("[INFO] default-info"); + expect(errorSpy.mock.calls.length).toBe(1); + expect(errorSpy.mock.calls[0]?.[0]).toBe("[INFO] default-info"); }); it("exposes isLevelEnabled gating debug at info threshold", () => { diff --git a/packages/producer/src/logger.ts b/packages/producer/src/logger.ts index d0fa8b77f..845d321e5 100644 --- a/packages/producer/src/logger.ts +++ b/packages/producer/src/logger.ts @@ -4,6 +4,12 @@ * Lightweight pluggable logger with zero dependencies. * Default implementation writes to console with level filtering. * + * All levels write to stderr (console.error/console.warn), never stdout — + * producer runs inside CLI commands whose stdout is a machine-readable + * contract (e.g. `validate --json`, `check --json`); an info/debug line on + * stdout would corrupt that output. There is no diagnostic use case that + * needs these lines on stdout specifically, so the whole logger is stderr-only. + * * Users can provide their own logger (e.g. Winston, Pino) by * implementing the ProducerLogger interface. */ @@ -71,12 +77,12 @@ export function createConsoleLogger(level: LogLevel = "info"): ProducerLogger { }, info(message, meta) { if (shouldLog("info")) { - console.log(`[INFO] ${message}${formatMeta(meta)}`); + console.error(`[INFO] ${message}${formatMeta(meta)}`); } }, debug(message, meta) { if (shouldLog("debug")) { - console.log(`[DEBUG] ${message}${formatMeta(meta)}`); + console.error(`[DEBUG] ${message}${formatMeta(meta)}`); } }, isLevelEnabled(msgLevel) {