Skip to content

feat: normalise error logging to { message, error } - #149

Merged
cuzzlor merged 5 commits into
mainfrom
fix/hoist-winston-wrapped-error
Sep 1, 2026
Merged

feat: normalise error logging to { message, error }#149
cuzzlor merged 5 commits into
mainfrom
fix/hoist-winston-wrapped-error

Conversation

@cuzzlor

@cuzzlor cuzzlor commented Sep 1, 2026

Copy link
Copy Markdown
Collaborator

However you log an error, you get the same record: { message: <the line you wrote>, error: { name, message, stack, … } }.

logger.error(new Error('boom')) //                      { level, message: 'boom',   error: { name, message, stack } }
logger.error('failed', new Error('boom')) //             { level, message: 'failed', error: { name, message, stack } }
logger.error('failed', { error: new Error('boom') }) //  { level, message: 'failed', error: { name, message, stack } }
logger.error(new Error('')) //                          { level, message: '',       error: { name, message, stack } }
logger.error(new AggregateError([inner])) //             { level, message: '',       error: { name, stack, errors: [ … ] } }

Interpolation is the deliberate exception: logger.error('failed: %s', err) passes the error as a value to interpolate, not as metadata, so it stays where the caller put it. More on that below.

The bug

An error with an empty message lost its name, stack and cause in the pretty console:

[error] 13:28:39.664 stop() threw during SIGTERM shutdown
[error] 13:28:39.666 [object Object]

Winston's single-argument hot path (winston/lib/winston/create-logger.js:78) reads:

const info = msg && msg.message && msg || { message: msg };

Whether the error becomes the record or is wrapped as { message: err } turns purely on whether its message is truthy. A truthy one takes the branch fix A in #148 handled; an empty one — a bare new Error(''), or an AggregateError whose detail is all in errors — takes the other. In the wrapped case the record is not an Error, so #148's branch never fired: the walk serialised the nested error correctly but left it under message, where prettyConsoleFormat interpolates an object and format.json emits message as an object where a log query expects a string.

Why nest rather than spread

The obvious fix was to spread the wrapped error onto the record, mirroring 2.1.0. That is wrong for both branches: it puts the error in the same namespace as level, defaultMeta and the caller's metadata, and the two overlap on name, message, stack, code, cause and errors. Whichever side wins, the other's data is dropped.

Measured with defaultMeta: { name: 'my-service' }:

Call Record, before
logger.error(new Error('boom')) { name: 'my-service', message: 'boom', stack: 'my-service: boom …' }
logger.error(new Error('')) { name: 'my-service', message: '', stack: 'Error: …' }
logger.error('failed', { error: err }) { name: 'my-service', message: 'failed', error: { name: 'Error', … } }

Both flat rows lose the error's name. The first also has its stack header rewritten to my-service: boom, because V8 formats stack lazily on first access and winston assigns defaultMeta onto the record before any format runs — which in that branch is the error itself. Only the third row survives, and it is the shape this library has always produced for a nested error. So that is the shape everything else normalises to.

Why normalise the arguments, not repair the record

A format only sees what winston has already built, and winston builds four unrelated records from an Error argument:

Call Raw info Error is
error(err) { level, …defaultMeta } — info is the error the record
error(new Error('')) { message: <live Error>, level } under message
error('failed', err) { message: 'failed boom', stack: '…', SPLAT: [err] } in SPLAT, stack copied up
error('failed', { error: err }) { message: 'failed', error: <live Error> } already right

By the time a format runs, row 1 has had level and defaultMeta assigned onto the error instance, and row 3 has had the error's message concatenated onto the caller's — recoverable, if at all, only by guessing at a trailing substring.

So createLogger rewrites the arguments instead, and winston only ever sees row 4. normalizeErrorArgs moves an Error out of the message or metadata position into { error }, keeping the caller's message — or, for an error passed alone, its own. Metadata already there is merged; nothing is dropped, and a non-plain-object in the metadata position has { error } inserted before it rather than over it.

withNormalizedErrorArgs installs the wrappers as own properties shadowing the prototype methods they call, so the rest of the winston API is untouched. child needs no wrapping: winston builds one with Object.create(logger, { write }), so the wrappers are already on its prototype chain, and this is forwarded so a wrapped method called on a child still writes through the child.

This also closes the collision above. The error is never written as the record, so winston never assigns defaultMeta onto it — error.name stays Error and the stack header is never rewritten.

serializeErrorFormat keeps handling both record shapes: it is exported for use outside createLogger, and logger.write, winston's exception handlers and the object form of log all reach it without passing through a level method.

Interpolation is left alone

Winston reads the arguments after the message as interpolation values rather than metadata once the message matches formatRegExp, and merges nothing onto the record for such a call. Rewriting logger.error('failed: %s', err) therefore produced no top-level error at all, and put a { error } wrapper where format.splat() expects the error. Those calls now pass through untouched, so the error keeps the splat position it was given and serializeErrorFormat serialises it there.

An error in the message position needed the same guard for the opposite reason: its own message can hold a token by accident — new Error('bad format: %s') — which would have winston read the { error } just added as an interpolation value and drop it. Those are handed over as { message: err }, the shape the format already nests, and one winston cannot resolve back to a record that is the error.

Migration

Bumped to 2.2.0 — 2.1.0's top-level name/message/stack is one release old, which is what makes this the cheap moment to correct it. Documented in the README's error-serialization section:

  • Read error.stack rather than stack, and adjust any omitPaths/redactPaths aimed at the old top-level keys.
  • logger.error('msg', err) no longer has the error's message concatenated onto yours, and no longer copies stack to the top of the record: message is 'msg', detail is under error.

Verification

Driven end to end through createLogger with a colliding defaultMeta, capturing what the Console transport actually printed. All five call shapes above print the same way, and error.name/error.stack are intact where they used to be overwritten:

[error] 15:33:11.557 hello          # logger.error(new Error('hello'))
 name: my-service
 error:
  name: Error
  message: hello
  stack: Error: hello …

[error] 15:33:11.558 hello          # logger.error('hello', new Error('hello'))
 name: my-service
 error:
  name: Error
  message: hello
  stack: Error: hello …
  • npm test — 143 passed (105 at 2.1.0)
  • New coverage: the argument rewriting rules directly (merge, insert, no mutation, interpolation left alone, a token in the error's own message, DOMException, the message position for log(level, …), the object form of log left to the format, inheritance through Object.create); end to end, every call shape agreeing, a child logger, metadata alongside an error, the error instance left unmutated, the error kept in the splat position; and at the format level both record shapes, level staying out of error, routing symbols, and custom serialisers
  • npm run build clean end to end — lint, tsc, rollup, attw, CJS smoke

🤖 Generated with Claude Code

`logger.error(err)` on an error whose `message` is empty loses the error's name,
stack and cause in the pretty console, which prints `[object Object]`.

Winston's single-argument hot path (`winston/lib/winston/create-logger.js:78`)
reads `msg && msg.message && msg || { message: msg }`, so the branch is decided
purely by whether the message is truthy: a truthy one makes the error the
record — the case fix A in #148 handled — and an empty one nests it as
`{ message: err }`. A bare `new Error('')` does it, and so does an
`AggregateError` whose detail is all in `errors`.

In the nested case the record is not an `Error`, so the root-error branch never
fires. The walk serialises the nested error correctly but leaves it under
`message`, where `prettyConsoleFormat` interpolates an object, and `format.json`
keeps every field but emits `message` as an object where a log query expects a
string.

`hoistWrappedError` serialises it and spreads the result onto the record before
the walk runs, so `message` is a string and `name`/`stack` are siblings whichever
branch winston took. Only `message` comes from the serialiser; every other key
the caller already set wins, so `{ message: err, requestId }` keeps its
`requestId`. Not `serializeRecord`: that lifts `level` and the routing symbols
off the error, and here they are on the record already.

The same shape can be passed deliberately rather than built by winston, and
there is no way to tell the two apart, so both are hoisted — a caller who puts
an `Error` in `message` wants it logged as an error either way.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@cuzzlor
cuzzlor requested review from mderriey and a balanced review from Copilot September 1, 2026 06:52
@cuzzlor
cuzzlor requested a review from robdmoore September 1, 2026 06:52

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

Pull request overview

Fixes serialization of errors nested under message, preserving readable error details across Winston transports.

Changes:

  • Hoists wrapped errors before recursive serialization.
  • Adds coverage for empty-message and aggregate errors.
  • Documents behavior and bumps version to 2.1.1.

Reviewed changes

Copilot reviewed 4 out of 4 changed files in this pull request and generated 1 comment.

File Description
src/serialize-error-format.ts Implements wrapped-error hoisting.
src/serialize-error-format.spec.ts Adds regression tests.
README.md Documents serialization behavior.
package.json Bumps patch version.

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

Comment thread README.md Outdated
@cuzzlor

cuzzlor commented Sep 1, 2026

Copy link
Copy Markdown
Collaborator Author

Changing my mind on this one, hold fire.

@cuzzlor cuzzlor closed this Sep 1, 2026
`logger.error(err)` put the error's fields at the top of the record. That puts
the error in the same namespace as `level`, `defaultMeta` and the caller's own
metadata, and the two overlap on `name`, `message`, `stack`, `code`, `cause` and
`errors`. Either precedence loses something real. With
`defaultMeta: { name: 'my-service' }`:

  logger.error(new Error('boom'))
  { name: 'my-service', message: 'boom', stack: 'my-service: boom\n    at …' }

The error's name is gone, and the stack header reads `my-service: boom` — V8
formats `stack` lazily on first access, and winston assigns `defaultMeta` onto
the record before any format runs, which in this branch is the error itself.

Nesting removes the overlap instead of arbitrating it. Both winston branches now
produce the shape a nested error already had, so error detail is always at
`error` and `message` is always a string:

  logger.error(new Error('boom'))         { message: 'boom', error: { name, message, stack } }
  logger.error(new Error(''))             { message: '',     error: { name, message, stack } }
  logger.error('failed', { error: err })   { message: 'failed', error: { name, message, stack } }

That last one is unchanged, and is how most callers already log an error, so
`error.stack` is now the single path to error detail however it was logged.

Two branches, one shape. `serializeRecord` carries the error's own enumerable
keys to record level — an `Error`'s intrinsic fields are non-enumerable, so its
own enumerable keys are the record side of the merge winston made — and nests
the serialised error. `hoistWrappedError` covers the other side of
`winston/lib/winston/create-logger.js:78`, where an empty message makes the
record `{ message: err }`, and nests it in the same place.

`message` is still set from the serialiser, because it is winston's slot rather
than error data: `format.printf` and `prettyConsoleFormat` interpolate it, and an
object there is the `[object Object]` this started as. A serialiser that drops
`message` yields `''`.

Minor rather than patch: 2.1.0's top-level `name`/`message`/`stack` shape is one
release old, and this is the cheapest moment to correct it. README documents the
migration.

Known and unchanged: in the whole-record branch, `defaultMeta` keys are
indistinguishable from properties the thrower attached, so they are carried to
record level *and* seen by the serialiser, and a colliding key still poisons the
nested error's `name` and stack header. Not fixable from inside a format.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@cuzzlor cuzzlor changed the title fix: hoist an error winston nested under message feat: one shape for logger.error(err), with detail under error Sep 1, 2026
@cuzzlor cuzzlor changed the title feat: one shape for logger.error(err), with detail under error feat: nest error detail under error, fixing the [object Object] log line Sep 1, 2026
`logger.error(err)` and `logger.error('failed', err)` now produce the same
record. Winston decides what to do with an `Error` argument in three separate
places and the results have nothing in common:

  logger.error(err)             the record IS the error
  logger.error(new Error(''))   { message: err } — the branch turns on a truthy message
  logger.error('failed', err)   { message: 'failed ' + err.message, stack }, error under SPLAT
  logger.error('failed', { err }) { message: 'failed', error: err }

A format only sees what winston has already built. By then the first shape has
had `level` and `defaultMeta` assigned onto the error instance, and the third has
had the error's message concatenated onto the caller's — recoverable, if at all,
only by guessing. So `createLogger` now rewrites the arguments instead, and
winston only ever sees the last shape, which needs no repair.

`normalizeErrorArgs` moves an `Error` from the message or metadata position into
`{ error }`, keeping the caller's message (or, for an error passed alone, its own)
and merging with metadata already there. Nothing is dropped: a non-plain-object
in the metadata position has `{ error }` inserted before it. Interpolation is
untouched, and an `Error` past the metadata position is a splat value, left to
`serializeErrorFormat`.

`withNormalizedErrorArgs` installs it on the level methods and `log` as own
properties, shadowing the prototype methods they call, so the rest of the winston
API is untouched. `child` needs no wrapping: winston builds a child with
`Object.create(logger, { write })`, so these own properties are already on its
prototype chain, and `this` is forwarded so a wrapped method called on a child
still writes through the child.

This closes the caveat from the previous commit. The error is never written as
the record, so winston never assigns `defaultMeta` onto it, so a colliding
`defaultMeta.name` can no longer take the error's name or — V8 formats `stack`
lazily on first access — rewrite its stack header to `my-service: boom`.

`serializeErrorFormat` keeps handling both record shapes. It is exported for use
outside `createLogger`, and `logger.write`, winston's exception handlers and the
object form of `log` all reach it without passing through a level method.

Behaviour change beyond the record shape: `logger.error('msg', err)` no longer
has the error's message concatenated onto yours and no longer copies `stack` to
the top of the record.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@cuzzlor cuzzlor changed the title feat: nest error detail under error, fixing the [object Object] log line feat: normalise every error log call to { message, error } Sep 1, 2026
@cuzzlor cuzzlor reopened this Sep 1, 2026
@cuzzlor
cuzzlor requested a balanced review from Copilot September 1, 2026 08:01

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

Pull request overview

Copilot reviewed 8 out of 8 changed files in this pull request and generated 2 comments.

Comment thread README.md Outdated
Comment thread src/normalize-error-args.ts
cuzzlor and others added 2 commits September 1, 2026 16:12
Winston reads the arguments after the message as interpolation values rather than
metadata when the message holds a `util.format` token, and merges nothing onto the
record for such a call. Normalising `logger.error('failed: %s', err)` to
`('failed: %s', { error: err })` therefore produced no top-level `error` at all,
and put a wrapper object where `format.splat()` expects the error.

Those calls are left alone now, so they keep winston's splat semantics: the error
stays in the position the caller passed it, serialized under `SPLAT` where the
format finds it. Reported by Copilot on #149.

An error in the *message* position gets the same guard for a different reason: its
own message can hold a token by accident — `new Error('bad format: %s')` — which
would have winston read the `{ error }` just added as an interpolation value and
drop it. Those go over as `{ message: err }` instead, the shape
`serializeErrorFormat` already nests, and one winston cannot resolve back to a
record that is the error.

Also from the same review: the README's `logger.error('failed', { error })`
example referenced an undeclared binding, so it could not be copied or
type-checked. Inlined `new Error('cause')` like the lines around it, and corrected
"three results" to four.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The carve-out in the previous commit left two statements overclaiming. The
README said an `Error` "always" reaches winston as `{ error }` metadata and
"never" as the record or the message, which a tokened message now contradicts on
both counts. And `normalizeErrorArgs`'s own doc introduced a four-row table as
"three different places" — the same slip Copilot caught in the README, where the
first two rows are in fact one expression resolving two ways.

Also: two `{@link serializeErrorFormat}` references in a module that imports
nothing, so neither could resolve; plain code spans instead.

`log` is skipped in the level loop. Winston declines to define a level named
`log`, so `target.log` is `Logger.prototype.log` and the block below already
wraps it with the message at index 1; the level loop would wrap it again with the
message at index 0. Both passes together happen to be idempotent for every shape
that reaches them, so this is a second pointless pass rather than a bug — but
reading the same method twice invites one. The accompanying test pins the message
position, which is the part that would actually break.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@cuzzlor cuzzlor changed the title feat: normalise every error log call to { message, error } feat: normalise error logging to { message, error } Sep 1, 2026
@cuzzlor
cuzzlor merged commit c3b9001 into main Sep 1, 2026
1 check passed
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.

3 participants