Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Serialize err.cause in a nice way when possible #78

Merged
merged 4 commits into from
Nov 24, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
113 changes: 113 additions & 0 deletions lib/err-helpers.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,113 @@
'use strict'

// **************************************************************
// * Code initially copied/adapted from "pony-cause" npm module *
// * Please upstream improvements there *
// **************************************************************

/**
* @param {Error|{ cause?: unknown|(()=>err)}} err
* @returns {Error|undefined}
*/
const getErrorCause = (err) => {
if (!err) return

/** @type {unknown} */
// @ts-ignore
const cause = err.cause

// VError / NError style causes
if (typeof cause === 'function') {
// @ts-ignore
const causeResult = err.cause()

return causeResult instanceof Error
? causeResult
: undefined
} else {
return cause instanceof Error
? cause
: undefined
}
}

/**
* Internal method that keeps a track of which error we have already added, to avoid circular recursion
*
* @private
* @param {Error} err
* @param {Set<Error>} seen
* @returns {string}
*/
const _stackWithCauses = (err, seen) => {
if (!(err instanceof Error)) return ''

const stack = err.stack || ''

// Ensure we don't go circular or crazily deep
if (seen.has(err)) {
return stack + '\ncauses have become circular...'
}

const cause = getErrorCause(err)

if (cause) {
seen.add(err)
return (stack + '\ncaused by: ' + _stackWithCauses(cause, seen))
} else {
return stack
}
}

/**
* @param {Error} err
* @returns {string}
*/
const stackWithCauses = (err) => _stackWithCauses(err, new Set())

/**
* Internal method that keeps a track of which error we have already added, to avoid circular recursion
*
* @private
* @param {Error} err
* @param {Set<Error>} seen
* @param {boolean} [skip]
* @returns {string}
*/
const _messageWithCauses = (err, seen, skip) => {
if (!(err instanceof Error)) return ''

const message = skip ? '' : (err.message || '')

// Ensure we don't go circular or crazily deep
if (seen.has(err)) {
return message + ': ...'
}

const cause = getErrorCause(err)

if (cause) {
seen.add(err)

// @ts-ignore
const skipIfVErrorStyleCause = typeof err.cause === 'function'

return (message +
(skipIfVErrorStyleCause ? '' : ': ') +
_messageWithCauses(cause, seen, skipIfVErrorStyleCause))
} else {
return message
}
}

/**
* @param {Error} err
* @returns {string}
*/
const messageWithCauses = (err) => _messageWithCauses(err, new Set())

module.exports = {
getErrorCause,
stackWithCauses,
messageWithCauses
}
8 changes: 5 additions & 3 deletions lib/err.js
Original file line number Diff line number Diff line change
Expand Up @@ -2,6 +2,8 @@

module.exports = errSerializer

const { messageWithCauses, stackWithCauses } = require('./err-helpers')

const { toString } = Object.prototype
const seen = Symbol('circular-ref-tag')
const rawSymbol = Symbol('pino-raw-err-ref')
Expand Down Expand Up @@ -46,12 +48,12 @@ function errSerializer (err) {
_err.type = toString.call(err.constructor) === '[object Function]'
? err.constructor.name
: err.name
_err.message = err.message
_err.stack = err.stack
_err.message = messageWithCauses(err)
_err.stack = stackWithCauses(err)
for (const key in err) {
if (_err[key] === undefined) {
const val = err[key]
if (val instanceof Error) {
if (val instanceof Error && key !== 'cause') {
/* eslint-disable no-prototype-builtins */
if (!val.hasOwnProperty(seen)) {
_err[key] = errSerializer(val)
Expand Down
32 changes: 32 additions & 0 deletions test/err.test.js
Original file line number Diff line number Diff line change
Expand Up @@ -46,6 +46,38 @@ test('serializes nested errors', function (t) {
t.match(serialized.inner.stack, /err\.test\.js:/)
})

test('serializes error causes', function (t) {
t.plan(6)
const err = Error('foo')
err.cause = Error('bar')
err.cause.cause = Error('abc')
const serialized = serializer(err)
t.is(serialized.type, 'Error')
t.is(serialized.message, 'foo: bar: abc')
Copy link
Member

Choose a reason for hiding this comment

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

Why is the message a concatenation of the three errors? Can you show an example of the full serialized error?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

It's because all three describe the error that has happened, but at three different levels. An example:

If err consists of thrown and wrapped errors in these three steps:

  1. ENOENT, stat '/nonexistent'
  2. Failed to open cache
  3. Can't cache example.com/robots.txt

Then when someone does:

pino.warn(err, 'robots.txt lookup failed');

It will log:

{
  "message": "Can't cache example.com/robots.txt: Failed to open cache: ENOENT, stat '/nonexistent'"
  "stack": `Error: Can't cache example.com/robots.txt
    at Object.<anonymous> (/examples/fullStack.js:5:12)
caused by: Error: Failed to open cache:
    at Object.<anonymous> (/examples/fullStack.js:3:12)
caused by: Error: ENOENT, stat '/nonexistent'
    at Object.<anonymous> (/examples/fs.js:4:15)`
}

Copy link
Contributor Author

Choose a reason for hiding this comment

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

So the idea is that the top most error should only describe the error on its abstraction level, not on any of the lower levels, but rather refer to the error causes for adding those description at those levels.

This makes it easy to distinguish between Can't cache example.com/robots.txt errors caused by Failed to open cache if there's also another reason going around that's maybe Malformed cache file content.

Here's a real life example: https://github.com/dependency-check-team/dependency-check/blob/c0537d04452098208132c6633277374dc9ad0a8d/lib/resolve-target.js#L40-L43

Copy link
Member

Choose a reason for hiding this comment

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

Okay. My biggest concern was that I thought I was using the standard error serializer from this package and that this change in message shape would break me. But it seems I'm not using it. Still, this will be a semver major change unless it serializes like:

{
  "message": "three",
  "stack": "...",
  "cause": {
    "message": "two",
    "stack": "...",
    "cause": {
      "message": "one",
      "stack": "..."
    }
  }
}

Copy link
Contributor Author

Choose a reason for hiding this comment

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

If we keep the nested cause and only extend stack, then I think we can make it a minor, then follow up with message + removing redundant cause in a major?

Thoughts @jsumners @mcollina?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Thinking a bit more about this, I think safest would be to simply make this a major change and make all changes at once

t.match(serialized.stack, /err\.test\.js:/)
t.match(serialized.stack, /Error: foo/)
t.match(serialized.stack, /Error: bar/)
t.match(serialized.stack, /Error: abc/)
})

test('serializes error causes with VError support', function (t) {
t.plan(6)
// Fake VError-style setyp
const err = Error('foo: bar')
err.cause = () => {
const err = Error('bar')
err.cause = Error('abc')
return err
}
const serialized = serializer(err)
t.is(serialized.type, 'Error')
t.is(serialized.message, 'foo: bar: abc')
t.match(serialized.stack, /err\.test\.js:/)
t.match(serialized.stack, /Error: foo/)
t.match(serialized.stack, /Error: bar/)
t.match(serialized.stack, /Error: abc/)
})

test('prevents infinite recursion', function (t) {
t.plan(4)
const err = Error('foo')
Expand Down