Skip to content

feat: structured logging - #24

Open
ErRusso wants to merge 10 commits into
napi-bindings:mainfrom
ErRusso:feature/structured-logging
Open

ErRusso wants to merge 10 commits into
napi-bindings:mainfrom
ErRusso:feature/structured-logging

Conversation

@ErRusso

@ErRusso ErRusso commented Oct 14, 2026

Copy link
Copy Markdown
Contributor

Logging Implementation Review

I’d appreciate feedback on whether the current logging implementation is sufficient or whether we should adopt an existing logging library.

Changes Made

  • Added src/logger.ts with a Logger class supporting info, warn, error, and debug levels.
  • Updated cli.ts to use the logger for all user-facing output (7 replacements).
  • Updated build.ts to use the logger for build status messages (4 replacements).

Benefits

  • Consistent log level prefixes: [INFO], [WARN], [ERROR], and [DEBUG].
  • Debug mode with structured JSON output.
  • Backward-compatible changes with no intended impact on existing behavior.

Questions for Review

  • Is the current lightweight logger sufficient for the project's needs, or are there gaps we should address?
  • Would adopting an existing library such as Pino, Winston, debug, or Consola provide meaningful benefits over maintaining our own implementation?

Replace console.log() calls with structured logger methods (info, warn, error)
that provide consistent formatting with log level prefixes. Add support for
debug mode to output additional structured data.

- create src/logger.ts with Logger class supporting info/warn/error/debug levels
- update cli.ts to use logger for all user-facing output
- update build.ts to use logger for build status messages
Replace console.log() calls with structured logger methods (info, warn, error)
that provide consistent formatting with log level prefixes. Add support for
debug mode to output additional structured data.

- create src/logger.ts with Logger class supporting info/warn/error/debug levels
- update cli.ts to use logger for all user-facing output (7 replacements)
- update build.ts to use logger for build status messages (4 replacements)

@NickNaso NickNaso left a comment •

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

src/logger.ts:44: The default stdout and stderr sinks call process.stdout.write(line) and process.stderr.write(line) without a trailing newline, so records are never newline-terminated and consecutive records run together on one line.
Failure scenario: Running marmotta rebuild --json writes {"level":"info","message":"Removed ..."}{"level":"info","message":"Addon built: ..."} on a single line, so any JSON Lines consumer fails to parse it. Text mode is also broken: [INFO] x[INFO] y, and --version prints with no final newline, so the shell prompt lands on the same line. I reproduced both with dist/logger.js.

src/logger.ts:87: In text mode, formatTextMessage replaces every newline with a space, which collapses multi-line output into one long line: the help text, the version list from list, and the usage that follows an unknown-command error.
Failure scenario: marmotta --help now prints the whole usage block as a single line (confirmed with od). marmotta list prints [INFO] 0.13.0 0.14.0 instead of one version per line, which breaks scripts like marmotta list | while read v. marmotta foo prints the full usage text squashed into one error line.

src/cli.ts:65: parseArgs runs, and can throw, before logger.setFormat is called, so --json is ignored for every argument-parsing error and those errors are written as text.
Failure scenario: marmotta build --bogus --json or marmotta build --json --target (missing value) writes [ERROR] marmotta [CLI_ARGUMENT_ERROR]: ... as plain text to stderr (reproduced). A CI consumer expecting JSON Lines gets an unparseable line in exactly the failure case it most needs to read.

src/cli.ts:46: --json is only recognized after the command token, but the README says it works with any command, so a leading --json is treated as the command name.
Failure scenario: marmotta --json build fails with [ERROR] marmotta [CLI_COMMAND_ERROR]: Unknown command: --json ... in text format (reproduced). marmotta --json --version fails with Unknown option: --version.

src/toolchain.ts:124: Zig and tar child processes still run with stdio: 'inherit', so their raw output goes straight to stdout and stderr in --json mode and breaks the README promise that every record is valid JSON Lines.
Failure scenario: marmotta build --json on a source with a compiler warning or error mixes zig cc diagnostics (plain text) into the output. JSON.parse on each stdout or stderr line in CI throws on the first non-JSON line.

src/cli.ts:74: Text-mode output now carries [INFO] and [ERROR] prefixes even when --json is not passed. This is an undocumented breaking change to --version, --help, list, and error output.
Failure scenario: Scripts that read the version with marmotta --version now get [INFO] marmotta 0.6.0. Tooling that matched ^marmotta [CODE]: on stderr no longer matches; the PR rewrote the MARMOTTA_HOME test regex to fit the new format instead of keeping the old one.

src/logger.ts:45: Replacing console.log and console.error with raw process.stdout.write and process.stderr.write loses Console's built-in handling that ignores stream errors, so a write to a closed pipe emits an 'error' event that nothing handles.
Failure scenario: marmotta list --json | head -0 or a CI log reader that closes the pipe early can crash the process with an unhandled EPIPE error event. The previous console.* calls silently ignored this.

src/logger.ts:30: The serialization fallback calls String(data), which itself throws for null-prototype objects and for objects with a throwing toString, so the logger throws instead of degrading. formatTextData at line 19 has the same problem.
Failure scenario: const o = Object.create(null); o.self = o; logger.info('x', o) throws TypeError: Cannot convert object to primitive value (reproduced). Inside the main().catch handler this would replace the real error report with a crash.

src/logger.ts:89: In text mode the data payload is discarded for info, warn and error unless debug mode is on, while JSON mode always includes it, so the two formats carry different information.
Failure scenario: logger.error('compile failed', { code: 'TOOLCHAIN_COMMAND_FAILED' }) without --debug prints only [ERROR] compile failed (reproduced), silently dropping the error context that the same call puts in a JSON record.

src/cli.ts:66: The --debug flag (documented as 'compile without optimizations', for build and rebuild) now also switches on verbose logging, coupling two unrelated concerns.
Failure scenario: You cannot get debug logs from an optimized -O2 build, and every unoptimized -O0 -g build also turns on verbose data dumps. On list or install, --debug now has a hidden logging meaning that the README does not mention.

src/cli.ts:117: Structured JSON error records embed the error code and message in a single formatted string instead of passing code and exitCode as data, and list emits versions as one string joined with newlines.
Failure scenario: A CI consumer of --json has to regex marmotta [(\w+)]: out of message to get the error code, and has to split message on newlines to get the versions. This defeats the purpose of structured output even though the logger already supports a data field.

src/logger.ts:77: if (!message) return; silently drops any record with an empty message, including its data payload and error-level records.
Failure scenario: logger.error('', { code }) or logger.info(String(value)) where the value is empty emits nothing at all on stdout or stderr. A diagnostic disappears with no trace, even in JSON mode where an empty message is still a valid record.

src/logger.ts:28: Circular-data handling reimplements safe serialization with a lossy fallback (String(data) gives '[object Object]') instead of using node:util inspect or a WeakSet-based circular replacer for JSON.stringify.
Failure scenario: Any context object with one circular reference loses its entire payload in JSON mode (the test even asserts '[object Object]'), which throws away all the useful fields. util.inspect or a circular-safe replacer would keep them.

src/build.ts:18: logFormat is added to BuildOptions even though nothing in build.ts reads it; it is a CLI-only concern, and type LogFormat is imported in cli.ts but never used.
Failure scenario: Every build, clean and configure call now carries an unused presentation option and build.ts has an unused type import, which couples the build API to CLI output settings. Keeping it in ParsedArgs would do the same job.

test/cli.test.js:268: The new JSON Lines tests only exercise single-record commands and call JSON.parse on the whole stream, so they pass even though records are not newline-terminated. No test covers multi-record output, text-mode help layout, or --json combined with argument errors.
Failure scenario: The missing newline, the collapsed --help output, and the text-format argument errors all ship with green CI. A test running rebuild --json and parsing stdout.split('\n') would have caught the newline bug.

You can consider the possibility to use yoctocolors or pino

@NickNaso NickNaso changed the title Feature/structured logging feat: structured logging Oct 15, 2026
Replace the hand-rolled serialization with pino, which gives newline-
terminated JSON Lines, circular-safe records, and standard level handling
while keeping the plain-text output byte-compatible with the console calls
it replaced:

- text mode writes messages unchanged (no [INFO]/[ERROR] prefixes, multi-
  line help and list output preserved) and passes data through util.inspect
- --json emits {"level":"info","time":...,"message":...} records through
  pino, with warn/error on stderr, and ignores errors from closed pipes
- MARMOTTA_LOG sets the minimum level, decoupling verbosity from --debug
- --json is resolved from the raw arguments before parsing and is accepted
  before or after the command, so argument errors honor the requested format
- errors carry code and exitCode as structured data; list emits one record
  per version in JSON mode
- drop the unused logFormat BuildOptions field
zig and tar previously inherited the terminal, so their raw diagnostics were
mixed into --json output and broke the JSON Lines promise. In JSON mode their
stdout and stderr are now piped, split into lines, and re-emitted as info and
warn records carrying the command name; text mode keeps inheriting stdio.
Add tests for newline-terminated multi-record output, argument errors under
--json, leading --json, multi-line help, circular/null-prototype context,
empty messages, level gating and invalid MARMOTTA_LOG values, and restore the
plain-text MARMOTTA_HOME and --version expectations. Document the JSON record
shape, child-output capture, and MARMOTTA_LOG in the README.
Dynamic import of a raw Windows path ("D:\...") is rejected as a URL scheme,
so the MARMOTTA_LOG test now imports a file:// URL and compares stderr without
assuming a newline style.
@NickNaso

Copy link
Copy Markdown
Member

This PR solves #2

@NickNaso NickNaso mentioned this pull request Oct 19, 2026

@NickNaso NickNaso left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Review: pino-backed logger and --json output (PR #24)

Thanks for this. Moving to pino and capturing toolchain output as JSON records is a good direction, and the comments explain the reasoning well. Most of my concerns come from one design choice: command output now goes through the level-filtered logger. Items 1–3 change what the CLI prints or which exit code it returns, so I'd like those fixed before merge. The rest are smaller fixes or cleanups.

Must fix

1. MARMOTTA_LOG can suppress command output and the final error line

src/cli.ts:84 (also lines 88, 105, 112–115, 124 and the main().catch handler at line 132)

The help text, the version string, list output, the install/remove confirmations and the final error line all go through logger.info / logger.error. The level filter therefore applies to them too, but these lines are the command's result, not diagnostics.

  • MARMOTTA_LOG=warn marmotta --version prints nothing and exits 0. That breaks the scripts the README says keep working.
  • MARMOTTA_LOG=silent marmotta build on a broken project exits 1 and prints no error, in both text and JSON modes.

Suggestion: command results and the final error should bypass level filtering. In text mode, write them straight to stdout/stderr. In JSON mode, emit them as records that are always printed. Keep MARMOTTA_LOG for diagnostic output only.

2. Zig compiler errors are logged at warn and can be filtered out

src/toolchain.ts:164

forwardLines(child.stderr, (line) => logger.warn(line, { command }));

In --json mode every stderr line is re-emitted at warn, compiler errors included. With MARMOTTA_LOG=error marmotta build --json, a syntax error drops all of Zig's error: ... lines and leaves only the generic zig exited with code 1 record. Text mode still shows them because stdio is inherited, so the two modes disagree.

Suggestion: don't apply level filtering to child-process output, or at least don't give it a level that can hide it. Tagging the records with stream: 'stderr' (next to command) is clearer than reusing warn.

3. -v / --version silently skips the requested command

src/cli.ts:48

--version is now accepted at any position and wins over the command. marmotta build -v (someone expecting "verbose") or marmotta remove 0.13.0 --version prints marmotta 0.6.0 and exits 0 without building or removing anything. CI then reports success. Before this PR these invocations failed with Unknown option: -v (exit 2).

Suggestion: honour --version only when there is no command, or reject the combination with a CliArgumentError.

Should fix

4. Custom sinks get differently terminated lines in each format

src/logger.ts:141-142

function sinkDestination(sink: LogSink): DestinationStream {
  return { write: (line: string) => void sink(line) };
}

In JSON mode pino passes newline-terminated lines to the sink. In text mode the sink gets lines without a terminator. So no sink works in both formats:

  • new Logger({ stdout: (l) => console.log(l) }) puts blank lines between JSON records.
  • new Logger({ stdout: (l) => process.stdout.write(l) }) runs text records together on one line.

Suggestion: strip the trailing \n before calling the sink, so that LogSink always receives a single line without a terminator, and document that contract on the type.

5. Level validation accepts inherited property names

src/logger.ts:83 (with the levelValues definition at line 18)

const value = levelValues[this.requestedLevel];

pino.levels.values is a plain object, so MARMOTTA_LOG=constructor (or __proto__, toString, …) resolves to a prototype member and passes validation. minLevel then becomes a function. The levelValues[level] < this.minLevel check compares against NaN and is always false, so every record is emitted, debug included. No warning appears, and the bogus name is passed to pino.

Suggestion:

const value = Object.hasOwn(levelValues, this.requestedLevel) ? levelValues[this.requestedLevel] : undefined;
if (typeof value === 'number') { /* ... */ }

6. Empty MARMOTTA_LOG should count as unset

src/logger.ts:51

this.requestedLevel = (options.level ?? process.env.MARMOTTA_LOG ?? 'info').toLowerCase();

?? treats an empty string as a value. So MARMOTTA_LOG= (common in CI jobs that export optional variables) prints ignoring invalid MARMOTTA_LOG value "" to stderr on every run. MARMOTTA_HOME and MARMOTTA_ZIG_DIR use if (!value) and treat empty as unset, so for consistency use || here (or trim and check for empty).

7. Tests don't scrub MARMOTTA_LOG from the environment

test/cli.test.js:15

if (['MARMOTTA_HOME', 'MARMOTTA_ZIG_DIR', 'ZIG_GLOBAL_CACHE_DIR'].includes(name.toUpperCase())) delete process.env[name];

CLI output now depends on MARMOTTA_LOG, but the scrub list doesn't include it. A developer with MARMOTTA_LOG=warn exported will see the help, --version and JSON help tests fail. Please add 'MARMOTTA_LOG' to the list.

Nice to have

8. Make list --json return structured data

src/cli.ts:114

else if (logger.format === 'json') for (const version of versions) logger.info(version);

Each version becomes a free-text message. A consumer can't tell version records apart from other info records (such as No Zig versions installed by Marmotta.) without parsing messages. A single record such as logger.info('Installed Zig versions', { versions }) is machine-readable and also removes this format branch.

More generally, logger.format === 'json' checks now appear in cli.ts (here and in the error handler) and in toolchain.ts. It would be cleaner if the logger owned the record shape and callers always passed a message plus structured data.

9. forwardLines could use node:readline

src/toolchain.ts:125

The function handles line splitting, CRLF stripping and flushing the trailing partial line by hand. readline.createInterface({ input: stream, crlfDelay: Infinity }) does all of that, so you'd only keep the empty-line filter. That removes about 25 lines of buffer logic that would otherwise need their own tests.

10. Unknown-command error in JSON mode includes the whole usage text

src/cli.ts:128

throw new CliCommandError(`Unknown command: ${parsed.command}\n\n${usage}`);

marmotta foo --json emits one error record whose message holds about 30 lines of help text, which floods CI log viewers. Append the usage only in text mode, or carry it as a separate field so the JSON message stays Unknown command: foo.

Address the second review round on the structured logging change:

- command results (help, version, list, confirmations, build results) and the
  final error now go through an unfiltered output()/failure() path, so
  MARMOTTA_LOG can no longer hide them; MARMOTTA_LOG filters diagnostics only
- zig/tar output is re-emitted through output() instead of warn(), so compiler
  errors survive MARMOTTA_LOG=error, and records carry command and stream
- --version combined with a command is rejected with CLI_ARGUMENT_ERROR
  instead of printing the version and skipping the requested work
- custom sinks receive one unterminated line per call in both formats
- level validation uses Object.hasOwn, rejecting inherited names such as
  "constructor" that would otherwise disable the gate
- empty or whitespace-only MARMOTTA_LOG counts as unset
- list --json emits a single structured record with data.versions
- unknown-command JSON messages no longer embed the usage block
- child output lines are split with node:readline instead of a manual buffer
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants