pino-pretty icon indicating copy to clipboard operation
pino-pretty copied to clipboard

Support structure for error log object used by pino@7

Open mojavelinux opened this issue 2 years ago • 6 comments

pino@7 now stores a logged error object on the err key instead of fusing it into the top-level of the log object. However, pino-pretty only checks for the old structure (log.type === 'Error' && log.stack). I'd like to request that pino-pretty add support for the new structure that pino@7 uses so users don't have to implement custom handlers to achieve the error object formatting as before.

Here's an example of this scenario when using pino@7:

const pino = require('pino')
const pinoPretty = require('pino-pretty')

const logger = pino({ base: undefined }, pinoPretty({ destination: 2, colorize: true }))

try {
  const obj = Object.defineProperty({}, 'foo', { value: 'bar' })
  obj.foo = 'baz'
} catch (err) {
  logger.error(err)
}

Here's the output we'd like to see:

[1637306767116] ERROR: Cannot assign to read only property 'foo' of object '#<Object>'
    TypeError: Cannot assign to read only property 'foo' of object '#<Object>'
        at Object.<anonymous> (/tmp/pino-lab/index.js:10:11)
        ...

Here's the output we currently see:

[1637306825642] ERROR: Cannot assign to read only property 'foo' of object '#<Object>'
    err: {
      "type": "TypeError",
      "message": "Cannot assign to read only property 'foo' of object '#<Object>'",
      "stack":
          TypeError: Cannot assign to read only property 'foo' of object '#<Object>'
              at Object.<anonymous> (/tmp/pino-lab/index.js:10:11)
              ...
    }

mojavelinux avatar Nov 19 '21 07:11 mojavelinux

Would you like to send a Pull Request to address this issue? Remember to add unit tests.

mcollina avatar Nov 19 '21 07:11 mcollina

Here's the logic I propose using:

    ...
    let err
    // pino@7+ stores error on err key
    if ((log.type === 'Error' && (err = log).stack) || ((err = log.err) && err.stack)) {
      const prettifiedErrorLog = prettifyErrorLog({
        log: err,
        errorLikeKeys: errorLikeObjectKeys,
        errorProperties: errorProps,
        ident: IDENT,
        eol: EOL
      })
      line += prettifiedErrorLog
    } ...

We could take this a step further and support all the errorLikeObjectKeys.

mojavelinux avatar Nov 19 '21 07:11 mojavelinux

Would you like to send a Pull Request to address this issue?

Absolutely. I only submit an issue if I am prepared to submit a PR to implement it.

mojavelinux avatar Nov 19 '21 07:11 mojavelinux

While working on the tests for this change, I noticed that when singleLine is true, the formatted message (with or without the new code in place) is missing an newline:

[1637309450761] ERROR: Cannot assign to read only property 'foo' of object '#<Object>'    TypeError: Cannot assign to read only property 'foo' of object '#<Object>'
        at Object.<anonymous> (/tmp/pino-lab/index.js:10:11)

mojavelinux avatar Nov 19 '21 08:11 mojavelinux

It appears as though this change has some rippling affects in the assumptions made by the tests. The tests seem to want to apply custom formatting to error-like object keys that sit at the top level (just like it does for keys nested deeper in the structure). However, there's no way I can see that we can tell the difference between an error logged using logger.error(err) and an error passed in the log object using logger.error({ err }).

There are two proposals I have to reconcile this dilemma.

Proposal 1: Treat the err key as special and only allow custom formatting for any other error-like key, such as error. This is what I have done in the PR I submitted. See #268.

Proposal 2: Add an option to control whether error-like keys at the top level are formatted using prettifyErrorLog. This would allow us to retain the existing behavior out of the box (for those who may be relying on it), or to switch to a uniform approach for formatting an error object (attached to an error-like key at the top level). The name I propose for this is prettifyError.

At the moment, I think we're sort of stuck in the middle of the road. On the one hand, the automatic error object formatting that used to work prior to pino@7 no longer does (e.g., logger.error(err)). However, that change seemed to open up a new way of formatting the error-like keys at the top level that are blocking us for restoring that behavior implicitly.

mojavelinux avatar Nov 19 '21 09:11 mojavelinux

Drop support for the old style (top level) error properties and we'll release a new major.

jsumners avatar Nov 19 '21 12:11 jsumners