diff --git a/README.md b/README.md index c04e4f4..53aad27 100644 --- a/README.md +++ b/README.md @@ -174,6 +174,7 @@ Run `marmotta --help` or `npx marmotta --help` for the built-in usage summary. | `-o, --output-dir ` | `build`, `rebuild`, `clean` | Override `outputDir`. Relative paths are resolved from the project directory. | | `--target ` | `build`, `rebuild` | Zig target triple used for cross-compilation. | | `--debug` | `build`, `rebuild` | Compile without optimization and include debug information (`-O0 -g` instead of `-O2`). | +| `--json` | Any command | Emit machine-readable JSON Lines instead of plain text. Recognized before or after the command. | | `-h, --help` | Any command | Show help. | | `-v, --version` | Top-level command | Show the Marmotta version. | @@ -183,8 +184,37 @@ For example, request a build for ARM64 macOS: npx marmotta build --target aarch64-macos ``` +Use `--json` in CI when another process needs to consume Marmotta's output; see [Logging](#logging) for the record format and the `MARMOTTA_LOG` variable. + Use a target triple supported by Zig for the intended target. Cross-compilation does not run the resulting addon on the host; load it on a compatible target system. +### Logging + +By default Marmotta writes plain text: command results on stdout and errors on stderr, with no level prefixes, so scripts that read `marmotta --version` or `marmotta list` keep working unchanged. + +Pass `--json` when another process needs to consume the output, as in CI. The flag is recognized before or after the command, and each record is one JSON object on its own line (JSON Lines): + +```sh +npx marmotta build --json +npx marmotta --json list +``` + +```json +{"level":"info","time":1730000000000,"message":"Addon built: /project/build/hello.node"} +{"level":"info","time":1730000000001,"data":{"versions":["0.13.0","0.14.0"]},"message":"Installed Zig versions"} +{"level":"error","time":1730000000002,"data":{"code":"CLI_ARGUMENT_ERROR","exitCode":2},"message":"Unknown option: --bogus"} +``` + +- `level` is a string such as `info`, `warn`, or `error`. Informational records go to stdout; warnings and errors go to stderr. +- `message` is the human-readable text, and `data` carries the record's structured context when there is any, such as the error `code` and `exitCode`, the installed `versions`, or a child process's `command` and `stream`. +- Command results, such as help, the version, `list`, confirmations and error messages, are always printed. Output from the Zig and `tar` child processes is captured and re-emitted as records tagged with `command` and `stream`, so every line printed in `--json` mode is valid JSON and compiler errors are never hidden. Lines from the child's stderr are `warn` records on stderr; lines from its stdout are `info` records on stdout. Lines keep their order within each stream, but the order between a child's stdout and stderr lines is not preserved. +- Set `MARMOTTA_LOG` to the minimum level for diagnostic records: `trace`, `debug`, `info`, `warn`, `error`, `fatal`, or `silent`. The default is `info`, which hides `debug` records: which Zig is used, where Zig is downloaded from, and each Zig or `tar` command line. An unrecognized value is ignored with a warning. + +`MARMOTTA_LOG` filters diagnostics only; it never hides a command's result or its final error. It applies to both formats and does not change the shape of the output. + +`--version` is a top-level request and cannot be combined with a command, so `marmotta build --version` fails with an argument error instead of printing the version and skipping the build. + + ## Zig toolchain Without a `zigVersion` pin, Marmotta uses `zig` from `PATH` when available, then a locally managed version, and otherwise downloads the latest stable Zig release for the supported host platform into the Marmotta home directory (see [Marmotta home directory](#marmotta-home-directory)). If `zigVersion` is set, Marmotta ignores `PATH` and selects that exact managed version, downloading it if necessary. If the pinned version is not available for the host platform, the command fails instead of falling back to another version. If the download index includes a checksum, Marmotta verifies the downloaded archive. If `MARMOTTA_ZIG_DIR` is set, Marmotta uses only that Zig and never downloads one (see [Existing Zig installation](#existing-zig-installation)). diff --git a/package-lock.json b/package-lock.json index 601a2bd..4fbfd77 100644 --- a/package-lock.json +++ b/package-lock.json @@ -9,7 +9,8 @@ "version": "0.6.0", "license": "Apache-2.0", "dependencies": { - "node-api-headers": "^1.3.0" + "node-api-headers": "^1.3.0", + "pino": "^10.4.0" }, "bin": { "marmotta": "dist/cli.js" @@ -22,6 +23,12 @@ "node": ">=20" } }, + "node_modules/@pinojs/redact": { + "version": "0.4.0", + "resolved": "https://registry.npmjs.org/@pinojs/redact/-/redact-0.4.0.tgz", + "integrity": "sha512-k2ENnmBugE/rzQfEcdWHcCY+/FM3VLzH9cYEsbdsoqrvzAKRhUZeRNhAZvB8OitQJ1TBed3yqWtdjzS6wJKBwg==", + "license": "MIT" + }, "node_modules/@types/node": { "version": "22.20.4", "resolved": "https://registry.npmjs.org/@types/node/-/node-22.20.4.tgz", @@ -32,12 +39,134 @@ "undici-types": "~6.21.0" } }, + "node_modules/atomic-sleep": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/atomic-sleep/-/atomic-sleep-1.0.0.tgz", + "integrity": "sha512-kNOjDqAh7px0XWNI+4QbzoiR/nTkHAWNud2uvnJquD1/x5a7EQZMJT0AczqK0Qn67oY/TTQ1LbUKajZpp3I9tQ==", + "license": "MIT", + "engines": { + "node": ">=8.0.0" + } + }, "node_modules/node-api-headers": { "version": "1.9.0", "resolved": "https://registry.npmjs.org/node-api-headers/-/node-api-headers-1.9.0.tgz", "integrity": "sha512-2oNILP4jXwRB4ywnYKjVk1YyJ96n2D4EOVJO6S3oYZ5PtbJrw3Yt9TpAuX3nBLMuzn74rnfGQrv13pS9vC+YiA==", "license": "MIT" }, + "node_modules/on-exit-leak-free": { + "version": "2.1.2", + "resolved": "https://registry.npmjs.org/on-exit-leak-free/-/on-exit-leak-free-2.1.2.tgz", + "integrity": "sha512-0eJJY6hXLGf1udHwfNftBqH+g73EU4B504nZeKpz1sYRKafAghwxEJunB2O7rDZkL4PGfsMVnTXZ2EjibbqcsA==", + "license": "MIT", + "engines": { + "node": ">=14.0.0" + } + }, + "node_modules/pino": { + "version": "10.4.0", + "resolved": "https://registry.npmjs.org/pino/-/pino-10.4.0.tgz", + "integrity": "sha512-bk1ZMTwG/Vymx+zPoa28MhNzucFvXJWp3csrSuxuHPSMeUettaCoQ5Jvg07mtC4JGNpcfTwz41oVCnNgBK9+vA==", + "license": "MIT", + "dependencies": { + "@pinojs/redact": "^0.4.0", + "atomic-sleep": "^1.0.0", + "on-exit-leak-free": "^2.1.0", + "pino-abstract-transport": "^3.0.0", + "pino-std-serializers": "^7.0.0", + "process-warning": "^5.0.0", + "quick-format-unescaped": "^4.0.3", + "real-require": "^1.0.0", + "safe-stable-stringify": "^2.3.1", + "sonic-boom": "^4.0.1", + "thread-stream": "^4.0.0" + }, + "bin": { + "pino": "bin.js" + } + }, + "node_modules/pino-abstract-transport": { + "version": "3.0.0", + "resolved": "https://registry.npmjs.org/pino-abstract-transport/-/pino-abstract-transport-3.0.0.tgz", + "integrity": "sha512-wlfUczU+n7Hy/Ha5j9a/gZNy7We5+cXp8YL+X+PG8S0KXxw7n/JXA3c46Y0zQznIJ83URJiwy7Lh56WLokNuxg==", + "license": "MIT", + "dependencies": { + "split2": "^4.0.0" + } + }, + "node_modules/pino-std-serializers": { + "version": "7.1.0", + "resolved": "https://registry.npmjs.org/pino-std-serializers/-/pino-std-serializers-7.1.0.tgz", + "integrity": "sha512-BndPH67/JxGExRgiX1dX0w1FvZck5Wa4aal9198SrRhZjH3GxKQUKIBnYJTdj2HDN3UQAS06HlfcSbQj2OHmaw==", + "license": "MIT" + }, + "node_modules/process-warning": { + "version": "5.1.1", + "resolved": "https://registry.npmjs.org/process-warning/-/process-warning-5.1.1.tgz", + "integrity": "sha512-oCkNVj4OKnKEcocVBcDfiIugN1/cE6rgfT3nCtzeqZPA8+rIxMaQ0xXzIkGP8Gj2qUaP1UR7uhJ1VD8lUCpzCg==", + "funding": [ + { + "type": "github", + "url": "https://github.com/sponsors/fastify" + }, + { + "type": "opencollective", + "url": "https://opencollective.com/fastify" + } + ], + "license": "MIT" + }, + "node_modules/quick-format-unescaped": { + "version": "4.0.4", + "resolved": "https://registry.npmjs.org/quick-format-unescaped/-/quick-format-unescaped-4.0.4.tgz", + "integrity": "sha512-tYC1Q1hgyRuHgloV/YXs2w15unPVh8qfu/qCTfhTYamaw7fyhumKa2yGpdSo87vY32rIclj+4fWYQXUMs9EHvg==", + "license": "MIT" + }, + "node_modules/real-require": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/real-require/-/real-require-1.0.0.tgz", + "integrity": "sha512-P4nbQYQfePJxRSmY+v/KINxVucm4NF3p3s7pJveMTtom52FR4YGltUQLB8idDXwDDWW+eYrWDFbuzUnjoWHF7g==", + "license": "MIT" + }, + "node_modules/safe-stable-stringify": { + "version": "2.5.0", + "resolved": "https://registry.npmjs.org/safe-stable-stringify/-/safe-stable-stringify-2.5.0.tgz", + "integrity": "sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==", + "license": "MIT", + "engines": { + "node": ">=10" + } + }, + "node_modules/sonic-boom": { + "version": "4.2.1", + "resolved": "https://registry.npmjs.org/sonic-boom/-/sonic-boom-4.2.1.tgz", + "integrity": "sha512-w6AxtubXa2wTXAUsZMMWERrsIRAdrK0Sc+FUytWvYAhBJLyuI4llrMIC1DtlNSdI99EI86KZum2MMq3EAZlF9Q==", + "license": "MIT", + "dependencies": { + "atomic-sleep": "^1.0.0" + } + }, + "node_modules/split2": { + "version": "4.2.0", + "resolved": "https://registry.npmjs.org/split2/-/split2-4.2.0.tgz", + "integrity": "sha512-UcjcJOWknrNkF6PLX83qcHM6KHgVKNkV62Y8a5uYDVv9ydGQVwAHMKqHdJje1VTWpljG0WYpCDhrCdAOYH4TWg==", + "license": "ISC", + "engines": { + "node": ">= 10.x" + } + }, + "node_modules/thread-stream": { + "version": "4.2.0", + "resolved": "https://registry.npmjs.org/thread-stream/-/thread-stream-4.2.0.tgz", + "integrity": "sha512-e2zZ96wSChazBsbENf/Pcm/4swHt2cEKQ92rhUjkL9GCKiTDJIaTBenjE/m9DXi0QBmTMDkFDdOomUy20A1tDQ==", + "license": "MIT", + "dependencies": { + "real-require": "^1.0.0" + }, + "engines": { + "node": ">=20" + } + }, "node_modules/typescript": { "version": "5.9.3", "resolved": "https://registry.npmjs.org/typescript/-/typescript-5.9.3.tgz", diff --git a/package.json b/package.json index 249f750..b2b7f19 100644 --- a/package.json +++ b/package.json @@ -50,7 +50,8 @@ "node": ">=20" }, "dependencies": { - "node-api-headers": "^1.3.0" + "node-api-headers": "^1.3.0", + "pino": "^10.4.0" }, "devDependencies": { "@types/node": "^22.15.0", diff --git a/src/build.ts b/src/build.ts index 3235349..36ba6f2 100644 --- a/src/build.ts +++ b/src/build.ts @@ -4,6 +4,7 @@ import { dirname, extname, join, resolve } from 'node:path'; import { loadProject, type ProjectConfig } from './project.js'; import { createBuildDirectory, ensureZig, runZig } from './toolchain.js'; import { hostImportsSource, readDefSymbols } from './windows-host.js'; +import { logger } from './logger.js'; const require = createRequire(import.meta.url); type NodeApiHeaders = { include_dir: string; def_paths: { node_api_def: string } }; @@ -33,7 +34,7 @@ async function compile(config: ProjectConfig, options: BuildOptions, cleanOnly: const output = join(outputDir, `${config.name}.node`); if (cleanOnly) { await rm(output, { force: true }); - console.log(`Removed ${output}`); + logger.output(`Removed ${output}`); return; } @@ -82,7 +83,7 @@ async function compile(config: ProjectConfig, options: BuildOptions, cleanOnly: await mkdir(dirname(output), { recursive: true }); await runZig(zig, args, options.directory); - console.log(`Addon built: ${output}`); + logger.output(`Addon built: ${output}`); } finally { await rm(temporaryDir, { recursive: true, force: true }); } @@ -91,7 +92,7 @@ async function compile(config: ProjectConfig, options: BuildOptions, cleanOnly: export async function configure(options: BuildOptions): Promise { const config = await loadProject(options.directory, { target: options.target }); await ensureZig(config.zigVersion); - console.log(`Configuration ready: ${config.name} (${config.sources.length} sources)`); + logger.output(`Configuration ready: ${config.name} (${config.sources.length} sources)`); return config; } diff --git a/src/cli.ts b/src/cli.ts index b6e229c..783aaed 100644 --- a/src/cli.ts +++ b/src/cli.ts @@ -3,6 +3,7 @@ import { resolve } from 'node:path'; import { build, clean, configure, type BuildOptions } from './build.js'; import { CliArgumentError, CliCommandError, normalizeError } from './errors.js'; import { ensureZig, listZigVersions, removeZigVersion } from './toolchain.js'; +import { logger } from './logger.js'; const usage = `Marmotta - build tool for Node.js addons with Zig @@ -22,50 +23,111 @@ Options: -o, --output-dir directory where .node is generated --target Zig target, e.g. aarch64-macos or x86_64-windows --debug compile without optimizations + --json output machine-readable JSON lines -h, --help show this help -v, --version show the version Environment: MARMOTTA_HOME absolute path that replaces ~/.marmotta as Marmotta's root directory - MARMOTTA_ZIG_DIR absolute path of an existing Zig installation to use instead of downloading Zig`; + MARMOTTA_ZIG_DIR absolute path of an existing Zig installation to use instead of downloading Zig + MARMOTTA_LOG minimum log level: trace, debug, info (default), warn, error, fatal, silent`; -type ParsedArgs = { command: string; positional: string[]; options: BuildOptions; help: boolean }; +type ParsedArgs = { + command: string; + positional: string[]; + options: BuildOptions; + help: boolean; + version: boolean; + json: boolean; + /** The first argument error. main() throws it once the output format is applied. */ + error?: Error; +}; +// Errors that are followed by the usage block in text mode, marked where they are thrown. +const usageErrors = new WeakSet(); + +function withUsage(error: E): E { + usageErrors.add(error); + return error; +} + +// Flags are recognized before or after the command, so `marmotta --json build` and +// `marmotta build --json` behave the same. The first positional token names the command. +// Parsing continues past the first error, so a later --json still selects the format that error +// is reported in. function parseArgs(argv: string[]): ParsedArgs { - const [command = 'help', ...tokens] = argv; const options: BuildOptions = { directory: process.cwd() }; - const positional: string[] = []; - let help = command === 'help' || command === '--help' || command === '-h'; + const positionals: string[] = []; + let help = false; + let version = false; + let json = false; + let commandOption = false; + let error: Error | undefined; + const fail = (failure: Error) => { + error ??= failure; + }; - for (let index = 0; index < tokens.length; index += 1) { - const token = tokens[index]; + for (let index = 0; index < argv.length; index += 1) { + const token = argv[index]; if (token === '-h' || token === '--help') help = true; - else if (token === '--debug') options.debug = true; - else if (token === '-C' || token === '--directory' || token === '-o' || token === '--output-dir' || token === '--target') { - const value = tokens[index + 1]; + else if (token === '-v' || token === '--version') version = true; + else if (token === '--json') json = true; + else if (token === '--debug') { + options.debug = true; + commandOption = true; + } else if (token === '-C' || token === '--directory' || token === '-o' || token === '--output-dir' || token === '--target') { + commandOption = true; + const value = argv[index + 1]; if (!value || value.startsWith('-')) { - throw new CliArgumentError(`Missing value for ${token}`); + fail(new CliArgumentError(`Missing value for ${token}`)); + continue; } index += 1; if (token === '-C' || token === '--directory') options.directory = resolve(value); else if (token === '-o' || token === '--output-dir') options.outputDir = value; else options.target = value; } else if (token.startsWith('-')) { - throw new CliArgumentError(`Unknown option: ${token}`); - } else positional.push(token); + fail(new CliArgumentError(`Unknown option: ${token}`)); + } else positionals.push(token); } - return { command, positional, options, help }; + const [command, ...rest] = positionals; + // --version is a top-level request. Combining it with a command would print the version and + // silently skip the requested work, so reject the combination instead. + if (version && command !== undefined && command !== 'help') { + fail(new CliArgumentError('--version cannot be combined with a command')); + } + // Command options without a command would otherwise fall through to help and exit 0, so a + // script that forgot the command would pass without doing anything. + if (command === undefined && commandOption && !help && !version) { + fail(withUsage(new CliCommandError('Missing command'))); + } + return { + command: command ?? 'help', + positional: rest, + options, + // No positional token means help, unless the user asked for --version instead. + help: help || command === 'help' || (command === undefined && !version), + version, + json, + error, + }; } async function main(): Promise { const parsed = parseArgs(process.argv.slice(2)); + // The format is applied before any argument error is thrown, so that error and an invalid + // MARMOTTA_LOG warning are both reported in the requested format. + logger.setFormat(parsed.json ? 'json' : 'text'); + logger.checkLevel(); + if (parsed.error) throw parsed.error; + if (parsed.help) { - console.log(usage); + logger.output(usage); return; } - if (parsed.command === '--version' || parsed.command === '-v') { - console.log('marmotta 0.6.0'); + if (parsed.version) { + logger.output('marmotta 0.6.0'); return; } @@ -85,11 +147,14 @@ async function main(): Promise { break; case 'install': await ensureZig(); - console.log('Zig toolchain is ready.'); + logger.output('Zig toolchain is ready.'); break; case 'list': { const versions = await listZigVersions(); - console.log(versions.length > 0 ? versions.join('\n') : 'No Zig versions installed by Marmotta.'); + logger.output(versions.length > 0 ? 'Installed Zig versions' : 'No Zig versions installed by Marmotta.', { + data: { versions }, + text: versions.length > 0 ? versions.join('\n') : undefined, + }); break; } case 'remove': { @@ -98,16 +163,20 @@ async function main(): Promise { throw new CliArgumentError('Specify the Zig version to remove.'); } await removeZigVersion(version); - console.log(`Removed Zig version ${version}.`); + logger.output(`Removed Zig version ${version}.`); break; } default: - throw new CliCommandError(`Unknown command: ${parsed.command}\n\n${usage}`); + throw withUsage(new CliCommandError(`Unknown command: ${parsed.command}`)); } } main().catch((error: unknown) => { const normalized = normalizeError(error); - console.error(`marmotta [${normalized.code}]: ${normalized.message}`); + // Text mode keeps the historical "marmotta [CODE]: message" line and appends the usage block for + // errors marked with withUsage(); the JSON record omits it so its message stays a single line. + const base = `marmotta [${normalized.code}]: ${normalized.message}`; + const text = usageErrors.has(normalized) ? `${base}\n\n${usage}` : base; + logger.failure(normalized.message, { code: normalized.code, exitCode: normalized.exitCode }, text); process.exitCode = normalized.exitCode; }); diff --git a/src/logger.ts b/src/logger.ts new file mode 100644 index 0000000..ea68453 --- /dev/null +++ b/src/logger.ts @@ -0,0 +1,200 @@ +import { inspect } from 'node:util'; +import pino, { type DestinationStream, type Logger as PinoLogger } from 'pino'; + +export type LogFormat = 'text' | 'json'; +export type LogLevel = 'info' | 'warn' | 'error' | 'debug'; + +/** + * Receives one record per call, without a trailing newline, in both text and JSON mode, so the + * same sink works for either format. + */ +type LogSink = (line: string) => void; + +export interface LoggerOptions { + format?: LogFormat; + /** Lowest level that produces output. Defaults to MARMOTTA_LOG, or "info" when unset or invalid. */ + level?: string; + stdout?: LogSink; + stderr?: LogSink; +} + +export interface OutputOptions { + /** Structured context merged into the JSON record. Ignored in text mode. */ + data?: unknown; + /** Text written instead of the message in text mode, for results that render differently. */ + text?: string; + /** Level of the record, which also picks the stream: warn and error go to stderr. Defaults to "info". */ + level?: LogLevel; +} + +// pino's level scale also drives the plain-text gate. "silent" is accepted by pino but is not part +// of its value table. +function levelValue(level: string): number | undefined { + if (level === 'silent') return Infinity; + // Object.hasOwn rejects inherited names such as "constructor" or "__proto__", which would + // otherwise resolve to prototype members and silently disable the gate. + return Object.hasOwn(pino.levels.values, level) ? pino.levels.values[level] : undefined; +} + +function isStderrLevel(level: LogLevel): boolean { + return level === 'warn' || level === 'error'; +} + +// inspect handles circular references, prototypes and throwing accessors without failing, which +// keeps the plain-text payload best-effort even for context that JSON cannot represent. +function formatTextData(data: unknown): string { + try { + return inspect(data, { depth: null, colors: false, breakLength: 100 }); + } catch { + return '[unserializable data]'; + } +} + +type JsonLoggers = { + /** Gated by the requested level, like the plain-text diagnostics. */ + diagnostics: PinoLogger; + /** Shares the destination but is never gated, for command output. */ + output: PinoLogger; +}; + +export class Logger { + private readonly requestedLevel: string; + private readonly level: string; + private readonly minLevel: number; + private readonly stdoutSink: LogSink; + private readonly stderrSink: LogSink; + private readonly customSinks: boolean; + private logFormat: LogFormat; + private levelChecked = false; + private json?: JsonLoggers; + + constructor(options: LoggerOptions = {}) { + this.logFormat = options.format ?? 'text'; + this.customSinks = options.stdout !== undefined || options.stderr !== undefined; + // console.* appends the newline, keeps multi-line messages intact and passes them through + // unchanged, and silently absorbs errors from closed pipes, so text output stays + // byte-compatible with the plain console usage this logger replaces. + this.stdoutSink = options.stdout ?? ((line) => console.log(line)); + this.stderrSink = options.stderr ?? ((line) => console.error(line)); + // Empty or whitespace-only counts as unset, matching MARMOTTA_HOME and MARMOTTA_ZIG_DIR. + const requested = (options.level ?? process.env.MARMOTTA_LOG ?? '').trim(); + this.requestedLevel = requested === '' ? 'info' : requested.toLowerCase(); + const value = levelValue(this.requestedLevel); + this.level = value === undefined ? 'info' : this.requestedLevel; + this.minLevel = value ?? levelValue('info')!; + } + + get format(): LogFormat { + return this.logFormat; + } + + /** Child process output must be captured and re-emitted as records in JSON mode. */ + get capturesChildOutput(): boolean { + return this.logFormat === 'json'; + } + + setFormat(format: LogFormat): void { + if (format !== 'text' && format !== 'json') { + throw new TypeError(`Unsupported log format: ${String(format)}`); + } + this.logFormat = format; + } + + /** + * Warns, once, when the requested level was not recognized and "info" is used instead. Call it + * after the output format is final, so the warning is written in that format. + */ + checkLevel(): void { + if (this.levelChecked) return; + this.levelChecked = true; + if (this.level === this.requestedLevel) return; + this.warn(`marmotta: ignoring invalid MARMOTTA_LOG value ${JSON.stringify(this.requestedLevel)}; using "info"`); + } + + info(message: string, data?: unknown): void { + this.log('info', message, data); + } + + warn(message: string, data?: unknown): void { + this.log('warn', message, data); + } + + error(message: string, data?: unknown): void { + this.log('error', message, data); + } + + debug(message: string, data?: unknown): void { + this.log('debug', message, data); + } + + /** + * Writes a command result. Level filtering never applies: MARMOTTA_LOG controls diagnostics, not + * the command's own output, so `--version`, `list`, confirmations and compiler output stay + * visible even when MARMOTTA_LOG is set to "error" or "silent". + */ + output(message: string, options: OutputOptions = {}): void { + const { data, text, level = 'info' } = options; + if (this.logFormat === 'json') this.writeJson(this.jsonLoggers().output, level, message, data); + else (isStderrLevel(level) ? this.stderrSink : this.stdoutSink)(text ?? message); + } + + /** Writes the final CLI error; it is always printed, on stderr. */ + failure(message: string, data?: unknown, text?: string): void { + this.output(message, { data, text, level: 'error' }); + } + + private log(level: LogLevel, message: string, data?: unknown): void { + if (this.logFormat === 'json') { + this.writeJson(this.jsonLoggers().diagnostics, level, message, data); + return; + } + if (levelValue(level)! < this.minLevel) return; + const line = data === undefined ? message : `${message}\n${formatTextData(data)}`; + (isStderrLevel(level) ? this.stderrSink : this.stdoutSink)(line); + } + + // pino serializes circular context as "[Circular]" instead of dropping the payload. + private writeJson(target: PinoLogger, level: LogLevel, message: string, data?: unknown): void { + if (data === undefined) target[level](message); + else target[level]({ data }, message); + } + + // Both loggers write through one multistream that sends warn and above to stderr and everything + // else to stdout; dedupe keeps a warn or error record off stdout. + private jsonLoggers(): JsonLoggers { + if (this.json) return this.json; + const stdout = this.customSinks ? sinkDestination(this.stdoutSink) : standardDestination(1); + const stderr = this.customSinks ? sinkDestination(this.stderrSink) : standardDestination(2); + const destination = pino.multistream([ + { level: 'trace', stream: stdout }, + { level: 'warn', stream: stderr }, + ], { dedupe: true }); + const diagnostics = pino({ + level: this.level, + messageKey: 'message', + formatters: { + level: (label: string) => ({ level: label }), + bindings: () => ({}), + }, + }, destination); + this.json = { diagnostics, output: diagnostics.child({}, { level: 'trace' }) }; + return this.json; + } +} + +function standardDestination(fd: 1 | 2): DestinationStream { + const destination = pino.destination({ dest: fd, sync: true }); + // A downstream reader such as `head` can close the pipe early; console.* would silently absorb + // the write error, and the logger must not crash the process where console would not. + destination.on('error', () => {}); + return destination; +} + +function sinkDestination(sink: LogSink): DestinationStream { + // pino terminates JSON records with a newline; the sink contract is one unterminated line per + // call, so strip it before handing the line over. + return { write: (line: string) => void sink(line.replace(/\n$/, '')) }; +} + +// Default logger instance for use throughout the application +export const logger = new Logger(); diff --git a/src/toolchain.ts b/src/toolchain.ts index f8141ed..9f1714c 100644 --- a/src/toolchain.ts +++ b/src/toolchain.ts @@ -4,6 +4,8 @@ import { constants } from 'node:fs'; import { access, chmod, mkdtemp, mkdir, readdir, rename, rm, writeFile } from 'node:fs/promises'; import { homedir } from 'node:os'; import { basename, isAbsolute, join, resolve, win32 } from 'node:path'; +import { createInterface } from 'node:readline'; +import { logger } from './logger.js'; import { MarmottaDirectoryFailedError, MarmottaHomeInvalidError, @@ -119,9 +121,44 @@ function prepareZigCache(command: ZigCommand): Promise { return prepared; } +// Re-emits a captured child stream one line at a time. readline handles CRLF and the trailing +// partial line at end of stream; empty lines are dropped so they do not become blank records. +function forwardLines(stream: NodeJS.ReadableStream | null, emit: (line: string) => void): void { + if (!stream) return; + const lines = createInterface({ input: stream, crlfDelay: Infinity, terminal: false }); + lines.on('line', (line) => { + if (line.length > 0) emit(line); + }); + // A stream error is reported by the child's own close event; swallowing it here only prevents an + // unhandled 'error' event from crashing the process while the output was being reformatted. + stream.on('error', () => {}); +} + function run(executable: string, args: string[], options: { cwd?: string; env?: NodeJS.ProcessEnv } = {}): Promise { return new Promise((resolve, reject) => { - const child = spawn(executable, args, { cwd: options.cwd, env: options.env, stdio: 'inherit' }); + // JSON output promises one JSON object per line, so raw zig/tar output cannot inherit the + // terminal in that mode: it is captured and re-emitted as records instead. Text mode keeps the + // live, streaming output users expect from a build. + const capture = logger.capturesChildOutput; + logger.debug(`Running ${basename(executable)}`, { executable, args, cwd: options.cwd ?? process.cwd() }); + const child = spawn(executable, args, { + cwd: options.cwd, + env: options.env, + stdio: capture ? ['inherit', 'pipe', 'pipe'] : 'inherit', + }); + if (capture) { + const command = basename(executable); + // Child output is a command result, not a diagnostic: it bypasses MARMOTTA_LOG so compiler + // errors cannot be filtered out, and `stream` identifies which pipe it came from. stderr + // carries Zig's and tar's warnings and errors, so its records are "warn" records on stderr; + // the final failure record is the one with level "error". Each pipe keeps its own line + // order, but two pipes cannot keep the order between them: Zig and tar write their + // diagnostics to stderr only, so a note and the error it refers to stay together. + forwardLines(child.stdout, (line) => + logger.output(line, { data: { command, stream: 'stdout' } })); + forwardLines(child.stderr, (line) => + logger.output(line, { data: { command, stream: 'stderr' }, level: 'warn' })); + } child.once('error', (cause: Error) => { reject(new ToolchainSpawnFailedError(basename(executable), { cause })); }); @@ -224,6 +261,7 @@ async function downloadZig(requestedVersion?: string): Promise<{ version: string throw new ZigInstallFailedError(`No Zig ${version} package available for ${platformKey()}.`); } + logger.debug(`Downloading Zig ${version}`, { url: artifact.tarball }); let archiveResponse: Response; try { archiveResponse = await fetch(artifact.tarball); @@ -313,12 +351,19 @@ export async function ensureZig(version?: string): Promise { const home = marmottaHome(); const zigDirectory = configuredZigDirectory(); const zig = zigDirectory === undefined ? await findZig(home, version) : await configuredZig(zigDirectory); - return withZigEnvironment(home, zig); + const command = withZigEnvironment(home, zig); + logger.debug(`Using Zig: ${command.executable}`, { + executable: command.executable, + home: home.path, + cacheDirectory: command.cacheDirectory, + }); + return command; } export async function listZigVersions(): Promise { const root = zigRoot(marmottaHome()); + logger.debug(`Reading Zig versions in ${root}`); try { return (await readdir(root, { withFileTypes: true })) .filter((entry) => entry.isDirectory() && !entry.name.startsWith('.')) diff --git a/test/cli.test.js b/test/cli.test.js index 5413117..d4655f9 100644 --- a/test/cli.test.js +++ b/test/cli.test.js @@ -12,7 +12,7 @@ const cli = fileURLToPath(new URL('../dist/cli.js', import.meta.url)); // Every CLI process inherits this environment: run it with Marmotta's defaults, not the developer's own settings. // node --test runs each file in its own process, and Windows variable names are case-insensitive. for (const name of Object.keys(process.env)) { - if (['MARMOTTA_HOME', 'MARMOTTA_ZIG_DIR', 'ZIG_GLOBAL_CACHE_DIR'].includes(name.toUpperCase())) delete process.env[name]; + if (['MARMOTTA_HOME', 'MARMOTTA_ZIG_DIR', 'ZIG_GLOBAL_CACHE_DIR', 'MARMOTTA_LOG'].includes(name.toUpperCase())) delete process.env[name]; } const zigAvailable = spawnSync('zig', ['version'], { stdio: 'ignore' }).status === 0; @@ -48,6 +48,24 @@ test('reports an unknown command with an error code', () => { assert.equal(result.status, 2); assert.match(result.stderr, /CLI_COMMAND_ERROR/); assert.match(result.stderr, /Unknown command/); + assert.match(result.stderr, /Usage: marmotta /); +}); + +test('rejects command options given without a command', () => { + for (const args of [['--debug'], ['-C', '.'], ['--target', 'x86_64-linux'], ['--json', '-o', 'build']]) { + const result = spawnSync(process.execPath, [cli, ...args], { encoding: 'utf8' }); + assert.equal(result.status, 2, args.join(' ')); + assert.equal(result.stdout.length, 0, args.join(' ')); + assert.match(result.stderr, /CLI_COMMAND_ERROR/, args.join(' ')); + assert.match(result.stderr, /Missing command/, args.join(' ')); + } + + const text = spawnSync(process.execPath, [cli, '--debug'], { encoding: 'utf8' }); + assert.match(text.stderr, /Usage: marmotta /); + // --json alone only selects the format, so it still shows help. + const json = spawnSync(process.execPath, [cli, '--json'], { encoding: 'utf8' }); + assert.equal(json.status, 0, json.stderr); + assert.match(JSON.parse(json.stdout).message, /^Marmotta - build tool/); }); test('classifies invalid options as argument errors', () => { @@ -56,9 +74,7 @@ test('classifies invalid options as argument errors', () => { assert.match(result.stderr, /CLI_ARGUMENT_ERROR/); }); -test('builds and loads a C Node-API addon with Zig', { skip: !zigAvailable }, async () => { - const directory = await mkdtemp(join(tmpdir(), 'marmotta-addon-')); - const source = `#include +const addonSource = `#include #include static napi_value Method(napi_env env, napi_callback_info info) { @@ -80,6 +96,10 @@ static napi_value Initialize(napi_env env, napi_value exports) { NAPI_MODULE(NODE_GYP_MODULE_NAME, Initialize) `; +test('builds and loads a C Node-API addon with Zig', { skip: !zigAvailable }, async () => { + const directory = await mkdtemp(join(tmpdir(), 'marmotta-addon-')); + const source = addonSource; + try { await mkdir(join(directory, 'build')); await writeFile(join(directory, 'hello.c'), source); @@ -260,6 +280,213 @@ NAPI_MODULE_INIT() { } }); +test('supports JSON Lines output for CI consumers', () => { + const help = spawnSync(process.execPath, [cli, '--help', '--json'], { encoding: 'utf8' }); + assert.equal(help.status, 0, help.stderr || help.stdout); + assert.equal(help.stderr.length, 0); + assert.ok(help.stdout.endsWith('\n'), 'JSON records must be newline-terminated'); + + const lines = help.stdout.split('\n').filter((line) => line.length > 0); + assert.equal(lines.length, 1); + const entry = JSON.parse(lines[0]); + assert.equal(entry.level, 'info'); + assert.equal(typeof entry.message, 'string'); +}); + +test('recognizes --json before the command', () => { + const result = spawnSync(process.execPath, [cli, '--json', 'unknown-command'], { encoding: 'utf8' }); + assert.equal(result.status, 2); + assert.equal(result.stdout.length, 0); + + const entry = JSON.parse(result.stderr); + assert.equal(entry.level, 'error'); + assert.equal(entry.message, 'Unknown command: unknown-command'); + assert.doesNotMatch(entry.message, /Usage:/, 'the usage block must not flood the JSON message'); +}); + +test('reports CLI errors as structured JSON Lines', () => { + const result = spawnSync(process.execPath, [cli, 'unknown-command', '--json'], { + encoding: 'utf8', + }); + assert.equal(result.status, 2); + assert.equal(result.stdout.length, 0); + + const entry = JSON.parse(result.stderr); + assert.equal(entry.level, 'error'); + assert.equal(entry.message, 'Unknown command: unknown-command'); + assert.equal(entry.data.code, 'CLI_COMMAND_ERROR'); + assert.equal(entry.data.exitCode, 2); +}); + +test('reports argument errors as structured JSON Lines', () => { + for (const args of [['build', '--bogus', '--json'], ['build', '--json', '--target']]) { + const result = spawnSync(process.execPath, [cli, ...args], { encoding: 'utf8' }); + assert.equal(result.status, 2, args.join(' ')); + assert.equal(result.stdout.length, 0, args.join(' ')); + + const entry = JSON.parse(result.stderr); + assert.equal(entry.level, 'error', args.join(' ')); + assert.equal(entry.data.code, 'CLI_ARGUMENT_ERROR', args.join(' ')); + } +}); + +test('does not let MARMOTTA_LOG hide command output', () => { + for (const level of ['warn', 'silent']) { + const env = { ...process.env, MARMOTTA_LOG: level }; + const version = spawnSync(process.execPath, [cli, '--version'], { encoding: 'utf8', env }); + assert.equal(version.status, 0, level); + assert.equal(version.stdout, 'marmotta 0.6.0\n', level); + + const help = spawnSync(process.execPath, [cli, '--help'], { encoding: 'utf8', env }); + assert.equal(help.status, 0, level); + assert.match(help.stdout, /^Marmotta - build tool/, level); + } +}); + +test('still reports the final error when MARMOTTA_LOG hides diagnostics', () => { + const env = { ...process.env, MARMOTTA_HOME: 'relative/marmotta-home', MARMOTTA_LOG: 'silent' }; + + const text = spawnSync(process.execPath, [cli, 'list'], { encoding: 'utf8', env }); + assert.equal(text.status, 2); + assert.match(text.stderr, /^marmotta \[MARMOTTA_HOME_INVALID\]:/); + + const json = spawnSync(process.execPath, [cli, 'list', '--json'], { encoding: 'utf8', env }); + assert.equal(json.status, 2); + const entry = JSON.parse(json.stderr); + assert.equal(entry.level, 'error'); + assert.equal(entry.data.code, 'MARMOTTA_HOME_INVALID'); +}); + +test('MARMOTTA_LOG=debug shows diagnostics that the default level hides', async () => { + const home = await mkdtemp(join(tmpdir(), 'marmotta-debug-')); + try { + const run = (level) => spawnSync(process.execPath, [cli, 'list', '--json'], { + encoding: 'utf8', + env: level === undefined ? { ...process.env, MARMOTTA_HOME: home } : { ...process.env, MARMOTTA_HOME: home, MARMOTTA_LOG: level }, + }); + const levels = (result) => result.stdout.split('\n').filter((line) => line.length > 0).map((line) => JSON.parse(line).level); + + const quiet = run(undefined); + assert.equal(quiet.status, 0, quiet.stderr); + assert.deepEqual(levels(quiet), ['info']); + + const loud = run('debug'); + assert.equal(loud.status, 0, loud.stderr); + assert.deepEqual(levels(loud), ['debug', 'info']); + } finally { + await rm(home, { recursive: true, force: true }); + } +}); + +test('warns about an invalid MARMOTTA_LOG value in the requested format', () => { + const env = { ...process.env, MARMOTTA_LOG: 'bogus' }; + const json = spawnSync(process.execPath, [cli, '--version', '--json'], { encoding: 'utf8', env }); + assert.equal(json.status, 0, json.stderr); + assert.equal(JSON.parse(json.stdout).message, 'marmotta 0.6.0'); + const warning = JSON.parse(json.stderr); + assert.equal(warning.level, 'warn'); + assert.match(warning.message, /ignoring invalid MARMOTTA_LOG value "bogus"/); + + const text = spawnSync(process.execPath, [cli, '--version'], { encoding: 'utf8', env }); + assert.equal(text.stdout, 'marmotta 0.6.0\n'); + assert.match(text.stderr, /^marmotta: ignoring invalid MARMOTTA_LOG value "bogus"/); +}); + +test('rejects --version combined with a command', () => { + for (const args of [['build', '--version'], ['remove', '0.13.0', '-v'], ['--json', 'build', '--version']]) { + const result = spawnSync(process.execPath, [cli, ...args], { encoding: 'utf8' }); + assert.equal(result.status, 2, args.join(' ')); + assert.match(result.stderr, /CLI_ARGUMENT_ERROR/, args.join(' ')); + assert.match(result.stderr, /--version cannot be combined with a command/, args.join(' ')); + } +}); + +test('lists installed Zig versions as structured data in JSON mode', async () => { + const home = await mkdtemp(join(tmpdir(), 'marmotta-list-')); + try { + await mkdir(join(home, 'toolchains', 'zig', '0.13.0'), { recursive: true }); + await mkdir(join(home, 'toolchains', 'zig', '0.14.0'), { recursive: true }); + const env = { ...process.env, MARMOTTA_HOME: home }; + + const json = spawnSync(process.execPath, [cli, 'list', '--json'], { encoding: 'utf8', env }); + assert.equal(json.status, 0, json.stderr); + const entry = JSON.parse(json.stdout); + assert.equal(entry.message, 'Installed Zig versions'); + assert.deepEqual(entry.data.versions, ['0.13.0', '0.14.0']); + + const text = spawnSync(process.execPath, [cli, 'list'], { encoding: 'utf8', env }); + assert.equal(text.status, 0, text.stderr); + assert.equal(text.stdout, '0.13.0\n0.14.0\n'); + } finally { + await rm(home, { recursive: true, force: true }); + } +}); + +test('keeps Zig compiler errors in --json output when MARMOTTA_LOG=error', { skip: !zigAvailable }, async () => { + const directory = await mkdtemp(join(tmpdir(), 'marmotta-json-errors-')); + try { + await writeFile(join(directory, 'hello.c'), '#include \n\nint broken(void) { return missing_symbol; }\n'); + await writeFile(join(directory, 'marmotta.config.json'), JSON.stringify({ name: 'hello' })); + + const result = spawnSync(process.execPath, [cli, 'build', '-C', directory, '--json'], { + encoding: 'utf8', + maxBuffer: 16 * 1024 * 1024, + env: { ...process.env, MARMOTTA_LOG: 'error' }, + }); + assert.equal(result.status, 1, result.stdout || result.stderr); + + const entries = result.stderr.split('\n').filter((line) => line.length > 0).map((line) => JSON.parse(line)); + const compilerEntries = entries.filter((entry) => entry.data?.command === 'zig' && entry.data?.stream === 'stderr'); + assert.ok(compilerEntries.length > 0, 'Zig compiler output must survive MARMOTTA_LOG=error'); + assert.ok(compilerEntries.every((entry) => entry.level === 'warn'), 'stderr records must not claim level info'); + assert.ok(entries.some((entry) => entry.data?.code === 'TOOLCHAIN_COMMAND_FAILED')); + } finally { + await rm(directory, { recursive: true, force: true }); + } +}); + +test('keeps the plain text output for --version and --help', () => { + const version = spawnSync(process.execPath, [cli, '--version'], { encoding: 'utf8' }); + assert.equal(version.status, 0, version.stderr); + assert.equal(version.stdout, 'marmotta 0.6.0\n'); + assert.equal(version.stderr.length, 0); + + const help = spawnSync(process.execPath, [cli, '--help'], { encoding: 'utf8' }); + assert.equal(help.status, 0, help.stderr); + const lines = help.stdout.split('\n'); + assert.ok(lines.length > 10, 'help must not be collapsed onto a single line'); + assert.equal(lines[0], 'Marmotta - build tool for Node.js addons with Zig'); +}); + +test('emits one JSON record per line for a multi-step build', { skip: !zigAvailable }, async () => { + const directory = await mkdtemp(join(tmpdir(), 'marmotta-json-lines-')); + try { + await writeFile(join(directory, 'hello.c'), addonSource); + await writeFile(join(directory, 'marmotta.config.json'), JSON.stringify({ name: 'hello' })); + + const result = spawnSync(process.execPath, [cli, 'rebuild', '-C', directory, '--json'], { + encoding: 'utf8', + maxBuffer: 16 * 1024 * 1024, + }); + assert.equal(result.status, 0, result.stderr || result.stdout); + assert.ok(result.stdout.endsWith('\n'), 'stdout must end with a newline'); + + const lines = result.stdout.split('\n'); + assert.equal(lines.at(-1), ''); + const entries = lines.slice(0, -1).map((line) => JSON.parse(line)); + assert.ok(entries.length >= 2, `expected several records, got ${entries.length}`); + assert.ok(entries.every((entry) => typeof entry.level === 'string' && typeof entry.message === 'string')); + assert.ok(entries.some((entry) => /Removed/.test(entry.message))); + assert.ok(entries.some((entry) => /Addon built/.test(entry.message))); + + for (const line of result.stderr.split('\n').filter((line) => line.length > 0)) { + assert.doesNotThrow(() => JSON.parse(line), `stderr line is not JSON: ${line}`); + } + } finally { + await rm(directory, { recursive: true, force: true }); + } +}); + test('reports an invalid MARMOTTA_HOME without breaking help', () => { const env = { ...process.env, MARMOTTA_HOME: 'relative/marmotta-home' }; const help = spawnSync(process.execPath, [cli, '--help'], { encoding: 'utf8', env }); diff --git a/test/logger.test.js b/test/logger.test.js new file mode 100644 index 0000000..b0662d0 --- /dev/null +++ b/test/logger.test.js @@ -0,0 +1,215 @@ +import assert from 'node:assert/strict'; +import { spawnSync } from 'node:child_process'; +import { test } from 'node:test'; +import { Logger } from '../dist/logger.js'; + +function capture(format = 'json', level = 'info') { + const stdout = []; + const stderr = []; + return { + logger: new Logger({ + format, + level, + stdout: (line) => stdout.push(line), + stderr: (line) => stderr.push(line), + }), + stdout, + stderr, + }; +} + +// Each sink call is one complete record: JSON records parse directly, without splitting on newlines. +function records(chunks) { + return chunks.map((chunk) => JSON.parse(chunk)); +} + +test('writes one JSON record per call to the matching stream', () => { + const { logger, stdout, stderr } = capture(); + + logger.info('first record'); + logger.info('second record', { addon: 'hello.node' }); + logger.warn('cache miss'); + logger.error('compile failed', { code: 'TOOLCHAIN_COMMAND_FAILED' }); + + assert.equal(stdout.length, 2); + assert.equal(stderr.length, 2); + for (const chunk of [...stdout, ...stderr]) assert.ok(!chunk.endsWith('\n'), JSON.stringify(chunk)); + + const [first, second] = records(stdout); + assert.equal(first.level, 'info'); + assert.equal(first.message, 'first record'); + assert.equal(typeof first.time, 'number'); + assert.deepEqual(second.data, { addon: 'hello.node' }); + + const [warned, failed] = records(stderr); + assert.equal(warned.level, 'warn'); + assert.equal(warned.message, 'cache miss'); + assert.equal(failed.level, 'error'); + assert.deepEqual(failed.data, { code: 'TOOLCHAIN_COMMAND_FAILED' }); +}); + +test('keeps text output plain, multi-line, and includes the data payload', () => { + const { logger, stdout, stderr } = capture('text'); + + logger.info('marmotta 0.6.0'); + logger.info('Commands:\n build\n clean'); + logger.warn('careful', { code: 'SOMETHING' }); + + assert.deepEqual(stdout, ['marmotta 0.6.0', 'Commands:\n build\n clean']); + assert.match(stderr[0], /^careful\n/); + assert.match(stderr[0], /code: 'SOMETHING'/); +}); + +test('uses the same sink contract in both formats', () => { + const lines = []; + const sink = (line) => lines.push(line); + + new Logger({ format: 'json', stdout: sink }).info('json record'); + new Logger({ format: 'text', stdout: sink }).info('text record'); + + assert.equal(lines.length, 2); + assert.equal(JSON.parse(lines[0]).message, 'json record'); + assert.equal(lines[1], 'text record'); + for (const line of lines) assert.ok(!line.endsWith('\n'), JSON.stringify(line)); +}); + +test('never filters command output with the level', () => { + const json = capture('json', 'error'); + json.logger.output('marmotta 0.6.0'); + json.logger.output('compiler error', { data: { command: 'zig', stream: 'stderr' }, level: 'warn' }); + json.logger.info('hidden'); + json.logger.debug('hidden'); + assert.deepEqual(records(json.stdout).map((record) => record.message), ['marmotta 0.6.0']); + assert.deepEqual(records(json.stderr).map((record) => [record.level, record.message]), [['warn', 'compiler error']]); + + const text = capture('text', 'error'); + text.logger.output('marmotta 0.6.0'); + text.logger.info('hidden'); + assert.deepEqual(text.stdout, ['marmotta 0.6.0']); +}); + +test('emits records for empty messages instead of dropping them', () => { + const json = capture(); + json.logger.info(''); + json.logger.error('', { code: 'SOMETHING' }); + assert.equal(records(json.stdout)[0].message, ''); + assert.deepEqual(records(json.stderr)[0].data, { code: 'SOMETHING' }); + + const text = capture('text'); + text.logger.info(''); + assert.deepEqual(text.stdout, ['']); +}); + +test('keeps JSON records valid when context is circular', () => { + const { logger, stdout } = capture(); + const context = { addon: 'hello.node' }; + context.self = context; + + logger.info('context', context); + + const [record] = records(stdout); + assert.equal(record.data.self, '[Circular]'); + assert.equal(record.data.addon, 'hello.node'); +}); + +test('does not throw on null-prototype objects in either format', () => { + const context = Object.create(null); + context.self = context; + + const json = capture(); + assert.doesNotThrow(() => json.logger.info('null-prototype', context)); + assert.equal(records(json.stdout)[0].data.self, '[Circular]'); + + const text = capture('text'); + assert.doesNotThrow(() => text.logger.info('null-prototype', context)); + assert.match(text.stdout[0], /self/); +}); + +test('debug records are hidden until the level allows them', () => { + const quiet = capture(); + quiet.logger.debug('hidden'); + assert.deepEqual(quiet.stdout, []); + assert.deepEqual(quiet.stderr, []); + + const loud = capture('json', 'debug'); + loud.logger.debug('visible'); + assert.equal(records(loud.stdout)[0].message, 'visible'); + + const text = capture('text', 'warn'); + text.logger.info('hidden'); + text.logger.warn('shown'); + assert.deepEqual(text.stdout, []); + assert.deepEqual(text.stderr, ['shown']); +}); + +test('routes warn and error records to stderr only', () => { + const { logger, stdout, stderr } = capture('json', 'trace'); + logger.debug('debug record'); + logger.output('result'); + logger.warn('warning'); + logger.failure('failed', { code: 'SOMETHING' }); + + assert.deepEqual(records(stdout).map((record) => record.level), ['debug', 'info']); + assert.deepEqual(records(stderr).map((record) => record.level), ['warn', 'error']); +}); + +test('falls back to info for an invalid MARMOTTA_LOG value', () => { + const { logger, stdout, stderr } = capture('json', 'bogus'); + logger.info('visible'); + logger.debug('hidden'); + assert.deepEqual(stderr, [], 'the warning is written only by checkLevel()'); + + logger.checkLevel(); + logger.checkLevel(); + assert.equal(stderr.length, 1, 'the warning is written once'); + assert.equal(records(stderr)[0].level, 'warn'); + assert.match(records(stderr)[0].message, /ignoring invalid MARMOTTA_LOG value "bogus"/); + assert.equal(records(stdout).length, 1); +}); + +test('rejects inherited property names as levels', () => { + for (const level of ['constructor', '__proto__', 'toString']) { + const { logger, stdout, stderr } = capture('json', level); + logger.checkLevel(); + logger.info('visible'); + logger.debug('hidden'); + + assert.match(stderr[0], /ignoring invalid MARMOTTA_LOG value/, level); + assert.equal(records(stdout).length, 1, level); + } +}); + +test('treats an empty level as unset', () => { + const { logger, stdout, stderr } = capture('json', ''); + logger.checkLevel(); + logger.info('visible'); + logger.debug('hidden'); + + assert.deepEqual(stderr, []); + assert.equal(records(stdout).length, 1); +}); + +test('accepts silent as a level that hides every diagnostic but not command output', () => { + for (const format of ['json', 'text']) { + const { logger, stdout, stderr } = capture(format, 'silent'); + logger.checkLevel(); + logger.error('hidden'); + logger.output('result'); + + assert.deepEqual(stderr, [], format); + assert.equal(stdout.length, 1, format); + } +}); + +test('MARMOTTA_LOG configures the default logger level', () => { + // A file:// URL imports correctly on Windows, where "D:\..." is read as a URL scheme. + const moduleUrl = new URL('../dist/logger.js', import.meta.url).href; + const script = `import(${JSON.stringify(moduleUrl)}).then(({ logger }) => { logger.info('hidden'); logger.error('shown'); });`; + const result = spawnSync(process.execPath, ['-e', script], { + encoding: 'utf8', + env: { ...process.env, MARMOTTA_LOG: 'error' }, + }); + + assert.equal(result.stdout, ''); + assert.equal(result.stderr.trim(), 'shown'); +});