Append the cause() stacks to the main stack trace

[voxpelli]

Some Error:s support a cause() method that when called returns the error that caused it. Examples are VError, https://github.com/davepacheco/node-verror, and restify v2.0, https://github.com/mcavage/node-restify.

The cause() is useful when errors are wrapped by using something like VError as one can then preserve the full stack traces by appending the stack traces of the cause() to that of the original error.

This is something that eg. Bunyan does https://github.com/trentm/node-bunyan/blob/cbfaa9a7bd86c658dbb8333c894191d23b65be33/lib/bunyan.js#L1111 and this method is inspired by its implementation.

Bunyan in turn was inspired by extsprintf: https://github.com/davepacheco/node-extsprintf/blob/accc9f2774189a416f294546ed03b626eec3f80c/lib/extsprintf.js#L165

Currently when someone uses eg. VError to wrap errors (something suggested in eg. this article from Joyent) the stack traces from Mocha can be fairly useless and it won't point on the actual cause of the issue but just at the last point that wraps it. This would fix that.

[voxpelli]

The noted failure here seems to be unrelated to my PR, seems to be Travis tests that are failing on Node 6.x for some unknown reason

[boneskull]

@voxpelli thanks. restarted the build; looks like it was a network fart

[boneskull]

@voxpelli

Currently when someone uses eg. VError to wrap errors (something suggested in eg. this article from Joyent) the stack traces from Mocha can be fairly useless and it won't point on the actual cause of the issue but just at the last point that wraps it. This would fix that.

Can you show an example of this? Also, does the behavior differ when using --full-trace?

[voxpelli]

@boneskull If I run this code (just for the sake of showing the output – in reality the errors would be thrown from different places of course):

throw new VError(new VError(new Error('First one'), 'Second one'), 'Third one');

Then this will be the output when running Mocha normally:

Stack trace – Update: Deleted the erroneous stack trace

I haven't checked the --full-trace and haven't done anything specifically in regards to it. I'll check that now.

[voxpelli]

@boneskull I now added the --full-trace related code so now a standard stack trace looks like:

1) Experimental React Render render should render a basic template:
   VError: Third one: Second one: First one
    at Object.e [as helloworld] (index.js:59:11)
    at ExperimentalReact.render (index.js:68:34)
    at Context.it (test/render.spec.js:45:25)
   Caused by: VError: Second one: First one
    at Object.e [as helloworld] (index.js:59:22)
    at ExperimentalReact.render (index.js:68:34)
    at Context.it (test/render.spec.js:45:25)
   Caused by: Error: First one
    at Object.e [as helloworld] (index.js:59:33)
    at ExperimentalReact.render (index.js:68:34)
    at Context.it (test/render.spec.js:45:25)

And a full trace looks like:

1) Experimental React Render render should render a basic template:
   VError: Third one: Second one: First one
    at Object.e [as helloworld] (/Users/foo/Sites/test/index.js:59:11)
    at ExperimentalReact.render (/Users/foo/Sites/test/index.js:68:34)
    at Context.it (/Users/foo/Sites/test/test/render.spec.js:45:25)
    at callFn (/Users/foo/Sites/test/node_modules/mocha/lib/runnable.js:330:21)
    at Test.Runnable.run (/Users/foo/Sites/test/node_modules/mocha/lib/runnable.js:323:7)
    at Runner.runTest (/Users/foo/Sites/test/node_modules/mocha/lib/runner.js:434:10)
    at /Users/foo/Sites/test/node_modules/mocha/lib/runner.js:540:12
    at next (/Users/foo/Sites/test/node_modules/mocha/lib/runner.js:354:14)
    at /Users/foo/Sites/test/node_modules/mocha/lib/runner.js:364:7
    at next (/Users/foo/Sites/test/node_modules/mocha/lib/runner.js:290:14)
    at Immediate.<anonymous> (/Users/foo/Sites/test/node_modules/mocha/lib/runner.js:332:5)
    at runCallback (timers.js:566:20)
    at tryOnImmediate (timers.js:546:5)
    at processImmediate [as _immediateCallback] (timers.js:525:5)
   Caused by: VError: Second one: First one
    at Object.e [as helloworld] (/Users/foo/Sites/test/index.js:59:22)
    at ExperimentalReact.render (/Users/foo/Sites/test/index.js:68:34)
    at Context.it (/Users/foo/Sites/test/test/render.spec.js:45:25)
    at callFn (/Users/foo/Sites/test/node_modules/mocha/lib/runnable.js:330:21)
    at Test.Runnable.run (/Users/foo/Sites/test/node_modules/mocha/lib/runnable.js:323:7)
    at Runner.runTest (/Users/foo/Sites/test/node_modules/mocha/lib/runner.js:434:10)
    at /Users/foo/Sites/test/node_modules/mocha/lib/runner.js:540:12
    at next (/Users/foo/Sites/test/node_modules/mocha/lib/runner.js:354:14)
    at /Users/foo/Sites/test/node_modules/mocha/lib/runner.js:364:7
    at next (/Users/foo/Sites/test/node_modules/mocha/lib/runner.js:290:14)
    at Immediate.<anonymous> (/Users/foo/Sites/test/node_modules/mocha/lib/runner.js:332:5)
    at runCallback (timers.js:566:20)
    at tryOnImmediate (timers.js:546:5)
    at processImmediate [as _immediateCallback] (timers.js:525:5)
   Caused by: Error: First one
    at Object.e [as helloworld] (/Users/foo/Sites/test/index.js:59:33)
    at ExperimentalReact.render (/Users/foo/Sites/test/index.js:68:34)
    at Context.it (/Users/foo/Sites/test/test/render.spec.js:45:25)
    at callFn (/Users/foo/Sites/test/node_modules/mocha/lib/runnable.js:330:21)
    at Test.Runnable.run (/Users/foo/Sites/test/node_modules/mocha/lib/runnable.js:323:7)
    at Runner.runTest (/Users/foo/Sites/test/node_modules/mocha/lib/runner.js:434:10)
    at /Users/foo/Sites/test/node_modules/mocha/lib/runner.js:540:12
    at next (/Users/foo/Sites/test/node_modules/mocha/lib/runner.js:354:14)
    at /Users/foo/Sites/test/node_modules/mocha/lib/runner.js:364:7
    at next (/Users/foo/Sites/test/node_modules/mocha/lib/runner.js:290:14)
    at Immediate.<anonymous> (/Users/foo/Sites/test/node_modules/mocha/lib/runner.js:332:5)
    at runCallback (timers.js:566:20)
    at tryOnImmediate (timers.js:546:5)
    at processImmediate [as _immediateCallback] (timers.js:525:5)

I can squash the commits before merge if you want – just wanted my changes to be clear to you.

[boneskull]

we cannot expect err to be defined, nor can we expect it to be non-null

[voxpelli]

@boneskull Generally I would agree, but since the lines above and below where getFullErrorStack() gets called already accesses err.message, err.inspect, err.actual etc. I think we can safely assume that at this stage the err is defined and is a non-null value, else that code would be broken as well

[boneskull]

hmm, must be that we won't add a non-object error to the list. looking into that.

I hadn't noticed err.inspect here, which sets a precedent for this PR anyway.

[boneskull]

@voxpelli Thanks. After reading the material and code you referenced, I'm not too terribly enthusiastic about adding this:

• Adding module-specific hooks for a custom error implementation is sort of a slippery slope
• It's a breaking change; Mocha will exhibit undefined behavior when it encounters an exception which uses cause() in a non-verror/restify manner
• Concerned about bloat; this probably belongs in an extension/plugin/addon

I may be able to suggest a decent workaround. Are you dealing mainly with uncaught errors, or are these failing assertions?

Completely subjective opinion: if I found myself suggesting a similar PR, I'd have to question the rationale to wrap Errors in this fashion, simply due to concerns about interoperability. Fundamentally, it's about the full stack trace not being where it's "supposed" to be.

Would appreciate another maintainer's take. cc @mochajs/core

[voxpelli]

@boneskull Thanks for getting back!

Following up on your points:

• I wouldn't suggest this if it was just VError that implemented it. I agree that adding support for specific modules into Mocha is not a good idea. The cause() on the other hand seems to be a useful pattern that more than one tool supports and which more tools could have use for when there are wider supports among tools like eg. Mocha.
• I can see how this is a breaking change, so it can't really be a default until next major version, but could maybe be an opt-in before that, like --full-trace. (Although adding more such opt-ins adds bloat of course)
• I agree that this adds bloat. There are already specific support for error extensions like err.inspect(), err.actual, err.expected, err.showDiff though so this wouldn't be the first one of its kind. One way to manage all these error extensions could be to split out the error presentation into a separate file. That could have additional side benefits of making the error presentation reusable elsewhere (could even be useful by other modules).

About interoperability: In async code you have no possibility of a full stack trace, but if you wrap your errors and have each step of the async chain add its own context to the error, with the previous error as its cause(), then you can get close to a full stack trace through the combined stack trace. So it's not about "the full stack trace not being where it's supposed to be", but about there being no full stack trace unless one helps creating one.

In async code when eg. getting an error like myserver: failed to start up: failed to load configuration: failed to connect to database server: failed to connect to 127.0.0.1 port 1234: connect ECONNREFUSED is much more useful than just connect ECONNREFUSED or myserver: failed to start up and the combined stack trace of each error step gives something much closer to a full synchronous stack trace than any individual stack trace in the async chain could on its own.

I would be open to look into alternative ways to explore .cause() support in Mocha if you have some thoughts. For me these has been uncaught errors where I would have been aided by getting the full stack trace rather than just the stack trace of the last step.

[boneskull]

there's some other stuff in the works about assertion / mocha interop. the gist of it is that adding support for random properties is not something we want to do; instead assertion libs should have a single place to supply freeform data.

this is also very old and the CLA hasn't been signed.