javascriptnode.jssequelize.jsstack-tracewinston

Merging stack traces in rethrown errors


I'm rethrowing here an error from Sequelize promise (Bluebird). In the first place, this was done to change error message, but as it appeared, this also produces more informative stack trace.

It is something like

sequelize.sync().catch(originalError => {
  const rethrownError = new Error(originalError.msg + ': ' + originalError.sql);
  throw rethrownError;
});

Where originalError.stack doesn't contain the line that caused the error but it holds important information that it originates in Sequelize and MySQL driver:

SequelizeDatabaseError: ER_KEY_COLUMN_DOES_NOT_EXITS: Key column 'NonExisting' doesn't exist in table
    at Query.formatError (...\node_modules\sequelize\lib\dialects\mysql\query.js:175:14)
    at Query._callback (...\node_modules\sequelize\lib\dialects\mysql\query.js:49:21)
    at Query.Sequence.end (...\node_modules\mysql\lib\protocol\sequences\Sequence.js:85:24)
    at Query.ErrorPacket (...\node_modules\mysql\lib\protocol\sequences\Query.js:94:8)
    at Protocol._parsePacket (...\node_modules\mysql\lib\protocol\Protocol.js:280:23)
    at Parser.write (...\node_modules\mysql\lib\protocol\Parser.js:74:12)
    at Protocol.write (...\node_modules\mysql\lib\protocol\Protocol.js:39:16)
    at Socket.<anonymous> (...\node_modules\mysql\lib\Connection.js:109:28)
    at emitOne (events.js:96:13)
    at Socket.emit (events.js:188:7)
    at readableAddChunk (_stream_readable.js:176:18)
    at Socket.Readable.push (_stream_readable.js:134:10)
    at TCP.onread (net.js:548:20)

rethrownError.stack contains the point of interest (the first line in the stack) but everything else is a rubbish:

Error: ER_KEY_COLUMN_DOES_NOT_EXITS: Key column 'NonExisting' doesn't exist in table
    at sequelize.sync.catch (...\app.js:59:17)
    at tryCatcher (...\node_modules\bluebird\js\release\util.js:16:23)
    at Promise._settlePromiseFromHandler (...\node_modules\bluebird\js\release\promise.js:504:31)
    at Promise._settlePromise (...\node_modules\bluebird\js\release\promise.js:561:18)
    at Promise._settlePromise0 (...\node_modules\bluebird\js\release\promise.js:606:10)
    at Promise._settlePromises (...\node_modules\bluebird\js\release\promise.js:681:18)
    at Async._drainQueue (...\node_modules\bluebird\js\release\async.js:138:16)
    at Async._drainQueues (...\node_modules\bluebird\js\release\async.js:148:10)
    at Immediate.Async.drainQueues (...\node_modules\bluebird\js\release\async.js:17:14)
    at runCallback (timers.js:637:20)
    at tryOnImmediate (timers.js:610:5)
    at processImmediate [as _immediateCallback] (timers.js:582:5)

I would like to keep the information about both of them - and to designate the link between them, not just to add as two unrelated log entries.

I've been thinking on logging them as a single error with concatenated stack, rethrownError.stack += '\n' + originalError.stack.

How should these two errors be treated? Should their stack traces be joined? Is there a convention for merging error stacks in JavaScript (Node.js in particular)?

The intention is to keep the resulting error meaningful and to not upset existing tools that parse error stack traces (namely Stacktrace.js).

The projects under consideration use Winston logger or plain console.error, so the error is stringified at some point (in the example above it was logged via unhandled rejection handler).


Solution

  • 馃毃 UPDATE 2022: Error.prototype.cause has been implemented in ES2022. In Node.js it's available since v16.9.0 (released a year earlier). Consider using the native implementation.

    Since ECMAScript 2022, new Error() lets us specify what caused it:

    try {
      // 路路路
    } catch (error) {
      throw new Error(
        `While processing ${filePath}`,
        {
          cause: error
        }
      );
    }
    

    See also: https://developer.mozilla.org/en-US/docs/Web/JavaScript/Reference/Global_Objects/Error/cause


    Original answer:

    Here is a lightweight alternative to VError: rerror (I鈥檓 the author)

    The idea is the same: Wrapping errors in errors. However it is much simpler. It has less features, but also works in the browser. It also takes into account that creating stack traces is expensive. Instead of creating stack traces and appending them to a string it creates a stack of errors internally and only creates the big stack trace if you need it (use the getter).

    Example

    function fail() {
      throw new RError({
        name: 'BAR',
        message: 'I messed up.'
      })
    }
    
    function failFurther() {
      try {
        fail()
      } catch (err) {
        throw new RError({
          name: 'FOO',
          message: 'Something went wrong.',
          cause: err
        })
      }
    }
    
    try {
      failFurther()
    } catch (err) {
      console.error(err.why)
      console.error(err.stacks)
    }
    

    Output

    FOO: Something went wrong. <- BAR: I messed up.
    Error
        at failFurther (/Users/boris/Workspace/playground/es5/index.js:98:11)
        at Object.<anonymous> (/Users/boris/Workspace/playground/es5/index.js:107:3)
        at Module._compile (module.js:556:32)
        at Object.Module._extensions..js (module.js:565:10)
        at Module.load (module.js:473:32)
        at tryModuleLoad (module.js:432:12)
        at Function.Module._load (module.js:424:3)
        at Module.runMain (module.js:590:10)
        at run (bootstrap_node.js:394:7)
    <- Error
        at fail (/Users/boris/Workspace/playground/es5/index.js:88:9)
        at failFurther (/Users/boris/Workspace/playground/es5/index.js:96:5)
        at Object.<anonymous> (/Users/boris/Workspace/playground/es5/index.js:107:3)
        at Module._compile (module.js:556:32)
        at Object.Module._extensions..js (module.js:565:10)
        at Module.load (module.js:473:32)
        at tryModuleLoad (module.js:432:12)
        at Function.Module._load (module.js:424:3)
        at Module.runMain (module.js:590:10)
    

    A recommended read: https://www.joyent.com/node-js/production/design/errors