Long (temporal) stack traces about q HOT 12 CLOSED

Yes, however, it would still be good to show the asynchronous boundaries in the stack trace.

It might be useful to model this with chains of exceptions, or exception-like objects.

One thought I considered (and clearly, you have also) is that we might use Error.captureStackTrace to bless deferred objects with .stack getters. We can then construct an error chain as we propagate through. The .stack might also be useful for producing a waterfall diagram with expandable stack traces.

The feature would obviously have to be detected so we can fall back to a less inspectable version of Q at run time.

from q.

I think I have a vague idea what you mean, but could you give an example of a stack trace that still shows asynchronous boundaries?

By instrumenting when with the following lines:

var error = {};
Error.captureStackTrace(error, when);
console.log("stack trace", error.stack);

I manage to get the following two stack traces:

stack trace [object Object]
    at makePromise.then (c:\Users\Domenic\Programming\test\node_modules\q\q.js:270:12)
    at doYAsync (c:\Users\Domenic\Programming\test\test.js:10:23)
    at doZAsync (c:\Users\Domenic\Programming\test\test.js:16:12)
    at Object.<anonymous> (c:\Users\Domenic\Programming\test\test.js:19:1)
    at Module._compile (module.js:441:26)
    at Object..js (module.js:459:10)
    at Module.load (module.js:348:31)
    at Function._load (module.js:308:12)
    at Array.0 (module.js:479:10)
    at EventEmitter._tickCallback (node.js:192:40)
stack trace [object Object]
    at Object.end (c:\Users\Domenic\Programming\test\node_modules\q\q.js:885:5)
    at makePromise.end (c:\Users\Domenic\Programming\test\node_modules\q\q.js:289:34)
    at Object.<anonymous> (c:\Users\Domenic\Programming\test\test.js:19:12)
    at Module._compile (module.js:441:26)
    at Object..js (module.js:459:10)
    at Module.load (module.js:348:31)
    at Function._load (module.js:308:12)
    at Array.0 (module.js:479:10)
    at EventEmitter._tickCallback (node.js:192:40)

So the information is at least there and accessible (and we can use Error.prepareStackTrace to restructure it as necessary). The trick will be associating it with promises as they propagate through the system, and then putting it all together at an appropriate time.

As far as I can tell we'd want this information in two places:

• In a scenario using .end() as above.
• As a replacement for rejectionReason.stack inside rejection handlers, e.g. for live debugging.

For the latter case I mean that if we replaced the above doZAsync with

function doZAsync() {
    return doYAsync().fail(function (err) {
        console.log(err.stack);
    });
}

It would output something like

Error: boo!
    at c:\Users\Domenic\Programming\test\test.js:11:15
    at doYAsync (c:\Users\Domenic\Programming\test\test.js:10:xx)

from q.

Error: boo!
    at c:\Users\Domenic\Programming\test\test.js:11:15
From previous event:
    at doYAsync (c:\Users\Domenic\Programming\test\test.js:10:xx)
    at doZAsync (c:\Users\Domenic\Programming\test\test.js:16:xx)
    at c:\Users\Domenic\Programming\test\test.js:19:xx

Where there is some delimiter separating the stack traces from each event, indicating that the program yielded between those frames. This is a good hint that there was an opportunity for other code to run in between.

At this point you’re way ahead of me. My thought was that we could get away with just instrumenting deferreds since that’s where everything ultimately comes from. Even when calls defer before yielding. I’m not 100% sure on what the right approach is.

from q.

This issue might also involve or solve another lingering issue: It’s really nice when programmers have the foresight to rewrite errors at interface boundaries. So, if you’re using the FS module, you would get an error message related to what you were attempting to do, rather what the FS module was attempting to do with the operating system. Something like, "Failed to read such and such file" instead of "File descriptor not opened for read". The problem is that usually you lose some insight at these boundaries. It strikes me that exceptions should inherently support chaining, so you can both have a friendly face and the ability to dig deeper into the issue by expanding the next error in the chain.

from q.

Really like the async boundaries idea now that I get it :).

My thought was that we could get away with just instrumenting deferreds since that’s where everything ultimately comes from. Even when calls defer before yielding.

Ooh, thanks for the tip. Yeah, I was just getting to the point of trying to figure out which seams I need to insert myself into.

It strikes me that exceptions should inherently support chaining, so you can both have a friendly face and the ability to dig deeper into the issue by expanding the next error in the chain.

Agreed. Cf. Exception.InnerException in .NET.

from q.

Maybe this will help,
https://github.com/johnjbarton/LongMueller

from q.

LongMueller will certainly help! Thanks.

from q.

How do you use LongMueller? I can't find any docs

from q.

Sorry, I was really just offering the source as inspiration. You can see an example of Cause.js on my fork of Q
https://github.com/johnjbarton/q/blob/master/q.js
However, to be clear, this was done just at the end of my experiment with Q so I'm unsure how well the stacks work in routine practice.

from q.

What should the following output?

var Q = require("q");

function doXAsync() {
    return Q.resolve(5);
}

function doYAsync() {
    return doXAsync().then(function doXAsyncCallback() {
        return Q.delay(10).then(function delayCallback() {
            return { foo: "bar" };
        }).get("bar").then(function getBarCallback() {
            throw new Error("boo!");
        });
    });
}

function doZAsync() {
    return doYAsync();
}

doZAsync()
    .end();

I've got

Error: boo!
    at getBarCallback (C:\Users\ddenicola\SkyDrive\Programming\Work in Progress\q with stack traces playground\test.js:14:19)
From previous event:
    at doYAsync (C:\Users\ddenicola\SkyDrive\Programming\Work in Progress\q with stack traces playground\test.js:10:23)
    at doZAsync (C:\Users\ddenicola\SkyDrive\Programming\Work in Progress\q with stack traces playground\test.js:20:12)
    at Object.<anonymous> (C:\Users\ddenicola\SkyDrive\Programming\Work in Progress\q with stack traces playground\test.js:27:1)

right now but feel like doXAsyncCallback and maybe delayCallback should appear in the trace.

from q.

I agree that we should trace all the functions that were visited in preparation, but don’t sweat blood over it. I think this is already useful.

from q.

Landed in v0.8.5

from q.