551604 - Exceptions raised from require() don't include much stack traceback information

Status: RESOLVED FIXED

(Add-on SDK Graveyard :: General, defect, P2)

Description

[Atul Varma [:atul]]

This is because require() uses Cu.evalInSandbox(), which creates a brand-new JS Context to execute the code in. Hence any Error objects, at the very least, have no associated stack information for the frames above the evalInSandbox() call. Not sure about what nsIException objects come with.

Actually fixing this could be nontrivial because we'd have to paste together two potentially different stack tracebacks, e.g. the 'stack' property of an Error() object and the nsIException of an XPCOM traceback.

Bug 550368 is related to this.

Comment 1

[Myk Melez [:myk] [@mykmelez]]

Is there a platform change that would make it easier for us to fix this?

Comment 2

[Atul Varma [:atul]]

It looks like nsIExceptions don't include information about frames above the evalInSandbox() either. Here's a simple example:

> exports.raiseNsIExceptionInSandbox = function(test) {
>   var systemPrincipal = Cc["@mozilla.org/systemprincipal;1"]
>                          .createInstance(Ci.nsIPrincipal);
> 
>   var code = ('Components.classes["@mozilla.org/systemprincipal;1"]' +
>               '.createInstance(Components.interfaces.nsIIOService);');
> 
>   var sandbox = Cu.Sandbox(systemPrincipal);
>   // This will fail with Cr.NS_ERROR_XPC_CI_RETURNED_FAILURE
>   Cu.evalInSandbox(code, sandbox);
> };

Comment 3

[Atul Varma [:atul]]

Probably, Myk--it might be useful to set up a meeting with the JS team and/or the xpconnect folks to figure out a better solution for all this traceback hackery. 

Right now, as can be seen from the traceback.js module in jetpack-core and all the "try { ... } catch (e) { console.exception(e); }" code we'll have to wrap callbacks in for all our low-level Jetpack API modules, it's a bit of a hassle to get real tracebacks on all exceptions. And even these measures fail if the exception thrown is a string rather than an actual Error instance or an nsIException.

One option may be to use the JS debug API to trap all exceptions when they're thrown and keep track of the tracebacks, and there might be others too.

Comment 4

[Myk Melez [:myk] [@mykmelez]]

The Add-on SDK is no longer a Mozilla Labs experiment and has become a big enough project to warrant its own Bugzilla product, so the "Add-on SDK" product has been created for it, and I am moving its bugs to that product.

To filter bugmail related to this change, filter on the word "looptid".

Comment 5

[Myk Melez [:myk] [@mykmelez]]

Irakli: do you think this will be addressed when we move to sandboxes that share compartments, or will exceptions in them still not generate unified stack traces, because the sandboxes don't share scopes?

Comment 6

[Irakli Gozalishvili [:irakli] [:gozala] [@gozala]]

I guess that's a question better asked to Gabor, as he's working on compartment merging and alternative sandboxes. I don't know if lost of stack traces is associated with cross compartement calls or cross sandbox call.

Comment 7

[Myk Melez [:myk] [@mykmelez]]

Gabor: any thoughts on the question in comment 5?

Comment 8

[Gabor Krizsanits (INACTIVE)]

I don't think it will be addressed... If there is an example I can try in xpcshell with my current version where compartments are merged already. But if you require a module that has chrome access from a module that doesn't (or the other way around) they will end up in different compartment even after the fix, so we will get back to this problem anyway, and this will have to be addressed in some cases. I will try to look into this area as well during the week.

Comment 9

[Gabor Krizsanits (INACTIVE)]

I digged into this today and it looks like a new stack is created for each sandbox, regardless if they share compartments or not. I think I have an idea how to fix the problem so I assign this issue to myself.

Comment 10

[Gabor Krizsanits (INACTIVE)]

This is more difficult than I thought... The previous (outer) context has it's frame chain in a saved state, and this way I cannot enumerate it. If I try to restore frame chain it is crashing, and could not find a way to get any information from it while inside an evalinsandbox call chain. I will try to consult with someone who understand stack more than me.

Comment 11

[Brian Warner [:warner :bwarner]]

It might be sufficient to just get the stack up to the act of loading the child module, rather than trying to include the entire parent module's stack as well. For example:

 parent.js:
  L1: function one() { require("child"); }
  L2: one();

 child.js:
  L1: function two() { throw("oops"); }
  L2: two();

The "complete" stack would show: [load(parent), parent:2, parent:1:one(), load(child), child:2, child:1:two()].

But developers could get by with just: [load(child), child:2, child:1:two()].

And currently we get nothing at all.

(I need this information to make the traceback in bug 679591 more useful)

Comment 12

[Gabor Krizsanits (INACTIVE)]

(In reply to Brian Warner [:warner :bwarner] from comment #11)
> But developers could get by with just: [load(child), child:2, child:1:two()].
> 
> And currently we get nothing at all.

Ok. So the reason why it's working like this is that to check if there is any catch block around a possible uncaught exception, the code flow traversing back to the top of the call stack, 'returning' each function and when the uncaught exception is reported to the user the stack is empty... 

The only way to fix this is to store the call stack (as a string for example, like the one you get for using the debugger command) and then passing that string all around if there were nested contexts, and in the end returning it some way to the user (dump or extra argument in a catch block etc.) This would make probably exceptions way too expensive in general... So maybe this could be enabled by setting some flag somewhere maybe if it's really needed (on some xpc debug related component).

So I played around with it and it turned out relatively hard to do this, since setting (and resetting) exception on a context is used all over the place for various reasons, so I would have to cherry pick the important ones where we need to generate/store this string, and then probably cherry pick another couple of dozens places where I have to propagate this string, while we are heading back to the top of the call stack (passing it between contexts)

> (I need this information to make the traceback in bug 679591 more useful)

So I just checked the mentioned bug and it seems like you found some workaround there. I'm not sure that I can fix this issue at platform level in a way that will be accepted, since there is a conceptual problem here, and I doubt that people will be happy for me hacking my way around it.

Comment 13

[Wes Kocher (:KWierso) (Not reading bugmail; email directly if needed)]

(Pushing all open bugs to the --- milestone for the new triage system)

Comment 14

[Ben Bucksch (:BenB)]

This is a *serious* hindrance for Jetpack development, and makes it quite painful, because normally the source of the error is in my app code, but I only see the stack in the module, and if I use that module enough, I don't have any idea whatsoever where my bug is. In other cases, I got the very strange

Traceback (most recent call last):
File "resource://jid1-lfgggmozt30u9w/api-utils/lib/cuddlefish.js", line 190, in require
   let module, manifest = this.manifest[base], requirer = this.modules[base];
TypeError: this.manifest is undefined
console: [JavaScript Warning: "reference to undefined property this.manifest" {file: "resource://jid1-lfgggmozt30u9w/api-utils/lib/cuddlefish.js" line: 190}]

when I made some random mistake while implementing a module. This is very misleading.

Could you please give this high priority?

Comment 15

[Ben Bucksch (:BenB)]

> This is a *serious* hindrance for Jetpack development, and makes it quite painful

2 months later, and it still is painful and urgent. It means that development is 20 times slower: With stack, I can often fix problems in 1-2 minutes. Without, it often takes half an hour or more.

How can I help to fix this?

Comment 16

[Dave Townsend [:mossop]]

Gabor, do you have any update here or would it be better for Eddy to take a look at this point?

Comment 17

[Gabor Krizsanits (INACTIVE)]

(In reply to Dave Townsend (:Mossop) from comment #16)
> Gabor, do you have any update here or would it be better for Eddy to take a
> look at this point?

Yeah Eddy would be a better candidate for this imo. Actually I think there were a few patches landed in this area, so sandboxes should not act like black blocks regards of the stack any longer. If that is the case this shouldn't be that difficult to implement now. Eddy do you have some time to look into this?

Comment 18

[Dave Townsend [:mossop]]

Eddy?

Comment 19

[Eddy Bruel [:ejpbruel]]

(In reply to Dave Townsend (:Mossop) from comment #18)
> Eddy?

I know, I'm as shocked as you are.

Comment 20

[Eddy Bruel [:ejpbruel]]

(In reply to Dave Townsend (:Mossop) from comment #18)
> Eddy?

On a serious note, I don't currently have time for this, but I expect to learn a lot about how stacks work in SpiderMonkey in the process of implementing Harmony modules. I can take this bug once I'm a bit more familiar with that part of the code. Does that sound ok to you?

Comment 21

[Gabor Krizsanits (INACTIVE)]

If I get the css features done and all my pending patches to land sooner than that then I'll just take this task back.

Comment 22

[Eddy Bruel [:ejpbruel]]

(In reply to Gabor Krizsanits [:krizsa :gabor] from comment #21)
> If I get the css features done and all my pending patches to land sooner
> than that then I'll just take this task back.

Well, *excuse* me for not dropping everything I'm working on and looking at your bug this instant, mister Krizsanits :-P

I'm fine with taking this bug, it just could take a while before I get to it. I leave it up to you if you want to wait that long or give it a shot yourself. In any case, I might be able to help out with explaining some stuff by the time you get to it.

Comment 23

[Gabor Krizsanits (INACTIVE)]

(In reply to Eddy Bruel [:ejpbruel] from comment #22)
> (In reply to Gabor Krizsanits [:krizsa :gabor] from comment #21)
> Well, *excuse* me for not dropping everything I'm working on and looking at
> your bug this instant, mister Krizsanits :-P

Bahhh... I accept no excuses ;)

> 
> I'm fine with taking this bug, it just could take a while before I get to
> it. I leave it up to you if you want to wait that long or give it a shot
> yourself. In any case, I might be able to help out with explaining some
> stuff by the time you get to it.

Sounds good to me.

Comment 24

[Jeff Griffiths (:canuckistani) (:⚡︎)]

If it helps, I personally see this bug as being pretty important as the lack of a file name and line number for syntax errors in modules or content scripts makes debugging these things incredibly frustrating.

The workarounds ( for posterity ) are either:

1. download Komodo Edit or another editor that does syntax checking, and open the file in that editor
or 
2: compile spidermonkey and run js -C <file> ( more info here: http://is.gd/8xyDxH )

Comment 25

[Eddy Bruel [:ejpbruel]]

(In reply to Jeff Griffiths (:canuckistani) from comment #24)
> If it helps, I personally see this bug as being pretty important as the lack
> of a file name and line number for syntax errors in modules or content
> scripts makes debugging these things incredibly frustrating.
> 
> The workarounds ( for posterity ) are either:
> 
> 1. download Komodo Edit or another editor that does syntax checking, and
> open the file in that editor
> or 
> 2: compile spidermonkey and run js -C <file> ( more info here:
> http://is.gd/8xyDxH )

I'll talk to Jason Orendorff when I get a chance. He knows a lot about this stuff. Maybe he has some ideas.

Comment 26

[David Creswick]

Attachment: Pointer to Github pull request: https://github.com/mozilla/addon-sdk/pull/528

Here's a temporary solution I've been using for a while.

Comment 27

[Ben Bucksch (:BenB)]

wow, +1

Comment 28

[Irakli Gozalishvili [:irakli] [:gozala] [@gozala]]

Attachment: Pointer to Github pull request: https://github.com/mozilla/addon-sdk/pull/670#discussion_r2284106

Pointer to Github pull-request

Comment 29

[[github robot]]

Commit pushed to master at https://github.com/mozilla/addon-sdk

https://github.com/mozilla/addon-sdk/commit/87aa0bf5f77746849ac65d7f01d44349076ca272
Merge pull request #670 from Gozala/bug/stack@551604

Bug 551604 - Improve stack traces from modules r=@erikvold