captureStackTrace lost when inheriting from WError

[DonutEspresso]

With 1.7.0, I noticed that the WError constructor is no longer invoking Error.captureStackTrace directly. It looks like it now defers that to VError:

https://github.com/joyent/node-verror/commit/08fa8939cc744dfce40ef1f1b9cad0d454b4b2ce#diff-7b7b65fd47508bd81ac1df9c099cc171L222

The result is that arguments.callee from the VError ctor's perspective only removes stack frames up to each of the internal sub type ctors (WError, SError, MultiError). restify-errors, which inherits directly from WError, was relying on WError's direct usage of arguments.callee to remove the ctor stack frames, so with 1.7.0 we've started seeing extra frames in our stacks.

It's an easy fix from our side to call captureStackTrace ourselves, and probably something we should have always been doing, but worth noting in case other modules were depending on this implicit behavior. I do notice that this legacy behavior (calling Error.captureStackTrace) only seems to affect WError. I'm not sure whether or not this is technically a breaking change, since inheritance in JS really doesn't guarantee you anything...!

[davepacheco]

@DonutEspresso Thanks for the heads-up. The specific extra frame you see is for the WError constructor, I assume? VError and WError already allow you to specify a "constructorOpt" option to omit frames up to that one, and I'm assuming you're not currently using that (i.e., to skip your own constructors)? What do you think about having WError and SError pass themselves as the "constructorOpt" argument to the VError constructor if the user didn't specify one?

Sorry for the issue.

[DonutEspresso]

No problem - the extra frames are minor in the grand scheme of things.

The extra frame(s) are actually coming from our end. Our own ctors were calling WError.apply(args), and expecting WError's call to captureStackTrace to remove our ctor frames. But since that's deferred to VError now, arguments.callee (from VError) points to WError, which means it removes only WError's ctor frame but not restify-error's ctor frames.

I believe this is only an issue if you're inheriting from WError like we were. We wanted to be able to support all of WError's native signatures (including extsprintf) in addition to our own signatures, which made it hairy for us to try and deconstruct user input args and safely add constructorOpt. The fix was to call captureStackTrace ourselves, which is what we probably should have been doing anyway.

Thinking about this more, I don't know if our use case would be better served by some new mechanism that would allow us to create custom ctors that inherit from VError. While the new release adds the ability to create typed errors in-situ, I think there may also be some value in having a pre-defined set of ctors for a clearly defined set of things (e.g., http error codes). Were it any other object it would be fine, but Error objects tend to have all sorts of gotchas when it comes to inheritance.

[davepacheco]

Thanks for the details. It's supposed to be fully supported to create custom classes that inherit from VError and friends -- there's even an example and test case. It's certainly fine if you want to do the captureStackTrace yourself, but I don't think you should have to in order to do that.

You're saying that previously when you inherited from WError, the captureStackTrace call elided a frame for WError itself, so then maybe the fix is that WError should supply a default value of "constructorOpt" of "arguments.callee" to achieve the same thing (without callers having to do anything special, and without having to duplicate the captureStackTrace call)?

[DonutEspresso]

Oh absolutely - to be clear the inheritance works fine! It's more that Error object itself often has these edge cases (captureStackTrace, name vs displayName, etc.) that aren't immediately straightforward, and the boilerplate adds up. It's what we were trying to solve with restify-error's makeConstructor method, which goes HttpError (restify-error ctor) -> WError -> VError.

But I believe you're right - if WError and the other ctors that depend on VError were to pass constructorOpt: arguments.callee as the default value into VError, that'd definitely net us the desired behavior. That should pass our own HttpError ctor as the constructorOpt, eliding all intermediate frames up to that point.

[davepacheco]

I didn't think that through. arguments.callee in this case will be WError itself, which is already what it's doing. That change makes no difference. WError.caller works, but breaks callers instantiating a WError directly. The old version of this code was using this.constructor, which I believe will always be the most specific class, which I think is the right thing here.

I'm using this program to test:

var mod_verror = require('./lib/verror');
var mod_util = require('util');

function MyError()
{
        mod_verror.WError.apply(this, Array.prototype.slice.call(arguments));
}

mod_util.inherits(MyError, mod_verror.WError);

function one()
{
        two();
}

function two()
{
        console.error(new Error('an Error').stack);
        console.error(new mod_verror.VError('a VError').stack);
        console.error(new mod_verror.WError('a WError').stack);
        console.error(new MyError('a MyError').stack);
}

one();

On the latest version, this produces:

Error: an Error
    at two (/home/dap/node-verror/issue-39.js:19:16)
    at one (/home/dap/node-verror/issue-39.js:14:2)
    at Object.<anonymous> (/home/dap/node-verror/issue-39.js:25:1)
    at Module._compile (module.js:460:26)
    at Object.Module._extensions..js (module.js:478:10)
    at Module.load (module.js:355:32)
    at Function.Module._load (module.js:310:12)
    at Function.Module.runMain (module.js:501:10)
    at startup (node.js:129:16)
    at node.js:814:3
VError: a VError
    at two (/home/dap/node-verror/issue-39.js:20:16)
    at one (/home/dap/node-verror/issue-39.js:14:2)
    at Object.<anonymous> (/home/dap/node-verror/issue-39.js:25:1)
    at Module._compile (module.js:460:26)
    at Object.Module._extensions..js (module.js:478:10)
    at Module.load (module.js:355:32)
    at Function.Module._load (module.js:310:12)
    at Function.Module.runMain (module.js:501:10)
    at startup (node.js:129:16)
    at node.js:814:3
WError: a WError
    at two (/home/dap/node-verror/issue-39.js:21:16)
    at one (/home/dap/node-verror/issue-39.js:14:2)
    at Object.<anonymous> (/home/dap/node-verror/issue-39.js:25:1)
    at Module._compile (module.js:460:26)
    at Object.Module._extensions..js (module.js:478:10)
    at Module.load (module.js:355:32)
    at Function.Module._load (module.js:310:12)
    at Function.Module.runMain (module.js:501:10)
    at startup (node.js:129:16)
    at node.js:814:3
WError: a MyError
    at new MyError (/home/dap/node-verror/issue-39.js:6:20)
    at two (/home/dap/node-verror/issue-39.js:22:16)
    at one (/home/dap/node-verror/issue-39.js:14:2)
    at Object.<anonymous> (/home/dap/node-verror/issue-39.js:25:1)
    at Module._compile (module.js:460:26)
    at Object.Module._extensions..js (module.js:478:10)
    at Module.load (module.js:355:32)
    at Function.Module._load (module.js:310:12)
    at Function.Module.runMain (module.js:501:10)
    at startup (node.js:129:16)

The first three look fine, but the MyError stack has the extra frame for the MyError constructor.

Prior to #10 (on b1c7bf701c232eb0039da2321291636c6815e061), this produced:

Error: an Error
    at two (/home/dap/node-verror-test/issue-39.js:19:16)
    at one (/home/dap/node-verror-test/issue-39.js:14:2)
    at Object.<anonymous> (/home/dap/node-verror-test/issue-39.js:25:1)
    at Module._compile (module.js:460:26)
    at Object.Module._extensions..js (module.js:478:10)
    at Module.load (module.js:355:32)
    at Function.Module._load (module.js:310:12)
    at Function.Module.runMain (module.js:501:10)
    at startup (node.js:129:16)
    at node.js:814:3
VError: a VError
    at two (/home/dap/node-verror-test/issue-39.js:20:16)
    at one (/home/dap/node-verror-test/issue-39.js:14:2)
    at Object.<anonymous> (/home/dap/node-verror-test/issue-39.js:25:1)
    at Module._compile (module.js:460:26)
    at Object.Module._extensions..js (module.js:478:10)
    at Module.load (module.js:355:32)
    at Function.Module._load (module.js:310:12)
    at Function.Module.runMain (module.js:501:10)
    at startup (node.js:129:16)
    at node.js:814:3
WError: a WError
    at two (/home/dap/node-verror-test/issue-39.js:21:16)
    at one (/home/dap/node-verror-test/issue-39.js:14:2)
    at Object.<anonymous> (/home/dap/node-verror-test/issue-39.js:25:1)
    at Module._compile (module.js:460:26)
    at Object.Module._extensions..js (module.js:478:10)
    at Module.load (module.js:355:32)
    at Function.Module._load (module.js:310:12)
    at Function.Module.runMain (module.js:501:10)
    at startup (node.js:129:16)
    at node.js:814:3
WError: a MyError
    at two (/home/dap/node-verror-test/issue-39.js:22:16)
    at one (/home/dap/node-verror-test/issue-39.js:14:2)
    at Object.<anonymous> (/home/dap/node-verror-test/issue-39.js:25:1)
    at Module._compile (module.js:460:26)
    at Object.Module._extensions..js (module.js:478:10)
    at Module.load (module.js:355:32)
    at Function.Module._load (module.js:310:12)
    at Function.Module.runMain (module.js:501:10)
    at startup (node.js:129:16)
    at node.js:814:3

Although interestingly enough, with VError this always produced the extra frame because VError always used arguments.callee.

With my latest changes, this now produces the expected output for all four stacks:

Error: an Error
    at two (/home/dap/node-verror/issue-39.js:19:16)
    at one (/home/dap/node-verror/issue-39.js:14:2)
    at Object.<anonymous> (/home/dap/node-verror/issue-39.js:25:1)
    at Module._compile (module.js:460:26)
    at Object.Module._extensions..js (module.js:478:10)
    at Module.load (module.js:355:32)
    at Function.Module._load (module.js:310:12)
    at Function.Module.runMain (module.js:501:10)
    at startup (node.js:129:16)
    at node.js:814:3
VError: a VError
    at two (/home/dap/node-verror/issue-39.js:20:16)
    at one (/home/dap/node-verror/issue-39.js:14:2)
    at Object.<anonymous> (/home/dap/node-verror/issue-39.js:25:1)
    at Module._compile (module.js:460:26)
    at Object.Module._extensions..js (module.js:478:10)
    at Module.load (module.js:355:32)
    at Function.Module._load (module.js:310:12)
    at Function.Module.runMain (module.js:501:10)
    at startup (node.js:129:16)
    at node.js:814:3
WError: a WError
    at two (/home/dap/node-verror/issue-39.js:21:16)
    at one (/home/dap/node-verror/issue-39.js:14:2)
    at Object.<anonymous> (/home/dap/node-verror/issue-39.js:25:1)
    at Module._compile (module.js:460:26)
    at Object.Module._extensions..js (module.js:478:10)
    at Module.load (module.js:355:32)
    at Function.Module._load (module.js:310:12)
    at Function.Module.runMain (module.js:501:10)
    at startup (node.js:129:16)
    at node.js:814:3
WError: a MyError
    at two (/home/dap/node-verror/issue-39.js:22:16)
    at one (/home/dap/node-verror/issue-39.js:14:2)
    at Object.<anonymous> (/home/dap/node-verror/issue-39.js:25:1)
    at Module._compile (module.js:460:26)
    at Object.Module._extensions..js (module.js:478:10)
    at Module.load (module.js:355:32)
    at Function.Module._load (module.js:310:12)
    at Function.Module.runMain (module.js:501:10)
    at startup (node.js:129:16)
    at node.js:814:3

and I've added a test case for it. I've got the change out for code review now: https://cr.joyent.us/300

I'd appreciate your feedback.

[DonutEspresso]

D'oh! Brain fart - for some reason I was thinking arguments.callee was the invoking function (when it's actually the current fn), when really we want to be able to jump multiple frames back to the original constructor. I applied your patch locally, it looks good and our unit tests are passing again. Thanks for the incredibly quick turn around! 👍

[davepacheco]

Fixed in 1.8.1.