Closed Bug 996060 Opened 10 years ago Closed 5 years ago

Save a stack for thrown values that are not error objects

Categories

(Core :: JavaScript Engine, defect, P2)

x86
Windows 7
defect

Tracking

()

RESOLVED FIXED

People

(Reporter: jujjyl, Assigned: bhackett1024)

References

(Blocks 1 open bug)

Details

(Keywords: parity-chrome, Whiteboard: [polish-backlog][gaming-tools][v8api])

Attachments

(4 files, 7 obsolete files)

599 bytes, text/html
Details
31.61 KB, patch
Details | Diff | Splinter Review
47 bytes, text/x-phabricator-request
Details | Review
47 bytes, text/x-phabricator-request
Details | Review
1. Visit the test page https://dl.dropboxusercontent.com/u/40949268/emcc/bugs/throw_exception_no_sourcemaps/throw_exception_no_sourcemaps.html

2. After the spinning circle disappears, open the web console.

Observed:

The web console prints "uncaught exception: 5247032" without any file:line info.

Expected:

The web console prints something like the following:

https://dl.dropboxusercontent.com/u/40949268/emcc/bugs/throw_exception_no_sourcemaps/expected_output.png

The source code in the link is effectively of this form:

try { 
    ...
    throw 5247032; // throw_exception_no_sourcemaps.js, line 1732
    ...
} catch(e) { // catch and re-throw:
  ...
  throw e; // throw_exception_no_sourcemaps.js, line 9318
  ...
}

The test page is intentionally a more "meaty" example to illustrate the importance of getting as much info as possible regarding the exception, since it comes from an Emscripten-compiled codebase.
Whiteboard: [parity-chrome]
Thanks for the bug report. I would like to determine where the bug is (in which part of our code), and the test case is too big/complex for that purpose. Can you please attach a minimal test-case which shows the bug? (Very) minimal tests are most helpful. Thanks!

Also see bug 814497.
You maybe interested in my addon: http://davidbruant.github.io/usefulStackTrace/
Happy to answer questions (send me an email diectly not on Bugzilla)
A minimal testcase. Please do check the larger testcase as well, since it represents a "real-world" example!
Thanks David, I downloaded the addon and tried it on the minimal testcase above, but I was not able to get it print information. I had the checkbox in Settings dialog checked, and had the web console window open while reloading the page.

Also to note, here's a related bug item in the Emscripten bug tracker: https://github.com/kripken/emscripten/issues/2292 .
Something that is different in the Emscripten case and in the tests, is that in Emscripten we cannot do "throw new Error(...)", but must effectively throw an integer with "throw 1231143;" so that we are asm.js-compatible. That might be an affecting factor here?
Whiteboard: [parity-chrome] → [parity-chrome][polish-backlog]
Priority: -- → P2
Whiteboard: [parity-chrome][polish-backlog] → [parity-chrome][polish-backlog][gaming-tools]
FWIW, in chrome code, doing:

throw new Error("Foo")

also doesn't provide a stack trace in the browser console, which you can test by just running that code in the browser console. Doing that in the web console also doesn't work.

However, the trivial testcase:

http://jsbin.com/yunayuzawo/edit?html,js,output

*does* have a stack.

If you use today's nightly on anything other than OS X, and open the browser console, on startup an error was created by CustomizableUI because the loop code tries to create a widget in the hidden window, which fails. I believe that code might be using console.error, but either way, there is no stack trace there either. I'm changing this in bug 1229474 to actually throw an exception before we get to that point, but that doesn't provide a stack trace, either.

Jordan, any chance someone can look at this based on these steps?
Flags: needinfo?(jsantell)
This is on our radar for games debugging, so hopefully get to it soon -- discussion with bgrins/tromey in IRC with some possible solutions I believe
Flags: needinfo?(jsantell) → needinfo?(bgrinstead)
(In reply to Jordan Santell [:jsantell] [@jsantell] (Please needinfo) from comment #7)
> This is on our radar for games debugging, so hopefully get to it soon --
> discussion with bgrins/tromey in IRC with some possible solutions I believe

Regarding Comment 6, the console evaluation is using the debugger's executeInGlobalWithBindings which returns a 'throw' property if it threw: https://dxr.mozilla.org/mozilla-central/source/devtools/server/actors/webconsole.js#861.  error.unsafeDereference() does actually have a stack so seems like maybe a bug in createValueGrip.  Still, this console evaluation case seems like a different bug.

Tom, do you have any idea what's going on with the stack when re-throwing the exception as in https://bug996060.bmoattachments.org/attachment.cgi?id=8406265?
Flags: needinfo?(bgrinstead) → needinfo?(ttromey)
See Also: → 1230194
The uncaught exception winds up passing through this code:

https://dxr.mozilla.org/mozilla-central/source/js/src/jsexn.cpp#932

See the comment there - it seems that this is already known to be incorrect.

That doesn't really help though.

It seems tricky and/or weird to try to associate a stack with this
exception, as it is just an integer.  Maybe it could be done "on the side"
somehow, say by capturing the stack at the most recent "throw".  (Though
this has wrong semantics for re-throwing, so ...)  I don't really know, though.
Maybe Nick has an idea; and he was talking about this bug today anyway.
Flags: needinfo?(ttromey) → needinfo?(nfitzgerald)
Ugh. I didn't realize that this was not for thrown error objects but for thrown primitives (and I supppose any non-Error?). Caching a SavedFrame stack "on the side" seems sane to me (given the context) but invalidation seems difficult. Yes, it would have funky semantics for re-throws, but we're off in the sticks here.

Not sure what kind of performance implications capturing a SavedFrame stack on every (non-error object) throw would have on code in the wild or benchmarks. Throws are already fairly slow, so maybe it doesn't matter too much...
Flags: needinfo?(nfitzgerald)
I just realized that I've been thinking in terms of Ion and capturing a stack when remat'ing frames due to a throw, but shu tells me that by the time SM sees that asm.js code did a throw, the asm.js code is already unwound. I think we would need to make some changes in odin or something...

+CC luke, shu
Summary: Console does not show a call stack for thrown exceptions. (incl. chained re-thrown exceptions) → Console does not show a call stack for thrown values that are not error objects
Luke, any idea how we might be able to capture a stack when code emitted by odin throws?
Flags: needinfo?(luke)
Error.stack works and shows the full JS call stack in asm.js.  (Of course, you have to do it by calling from asm.js through an FFI into normal JS so you have access to Error.stack.)
Flags: needinfo?(luke)
So the misunderstanding was that I thought `throw 12345` was in asm.js code, but it is just normal js on top of an asm.js stack.

After talking with luke and shu on irc, we've boiled it down to something like this:

* Add some kind of flag to enable this stack capturing only when devtools is open
* inside JSContext::setPendingException:
  * if the flag is set and the thrown value is not an error object:
    * capture the current stack and save it on the runtime

Then, when creating error messages for uncaught exceptions, check for a stack on the runtime. I'm not sure where this happens yet.
It might be worth seeing if we can get by without a flag and see what benchmarks say...
SpiderNode wants this, and I think not only when devtools are watching.
Component: Developer Tools: Console → JavaScript Engine
Product: Firefox → Core
Summary: Console does not show a call stack for thrown values that are not error objects → Save a stack for thrown values that are not error objects
This commit captures the JS stack in `JSContext::setPendingException` and
exposes a new JSAPI function for getting the stack:
`JS::GetPendingExceptionStack`. This stack is cleared out when the pending
exception is cleared.

Questions:

* The pending exception lives on the cx, but I put this on the rt because my
  understanding is that we are trying to get rid of cx and we shouldn't add
  anything new there. However, in this case it is a bit funky because
  JS_GetPendingException takes a cx but JS::GetPendingExceptionStack takes an
  rt. Is putting this stack on the rt the correct decision?

* For simplicity/laziness I just made JSRuntime::pendingExceptionStack
  public. Should we make it private and add getters and all that so that it can
  only be reset or changed in JSContext::{set,clear}PendingException? Or do you
  feel that is overkill?
Attachment #8750543 - Flags: review?(sphink)
Comment on attachment 8750543 [details] [diff] [review]
Save a stack on JSContext::setPendingException

Ehsan: does this work for your needs in SpiderNode?
Attachment #8750543 - Flags: feedback?(ehsan)
Comment on attachment 8750543 [details] [diff] [review]
Save a stack on JSContext::setPendingException

Review of attachment 8750543 [details] [diff] [review]:
-----------------------------------------------------------------

Sorry to be a bother, but I'd prefer this to be on the cx for now. I know we're moving away from the cx, but I'd rather not have an intermediate state where some pending exception data is on the runtime and some is on the cx. (Plus I imagine this does pretty funky stuff atm if you have multiple contexts, which is not yet disallowed.) I think it'd be better to put it on the cx for now and move them over together.

One thing that makes me nervous is that this is duplicating information in the case of throwing an Error object, and it seems possible for the information to get out of sync. I wonder if this should only be saved for primitives? (Or at the very least, skipped for things like JS_GENERATOR_CLOSING etc.) But maybe that would make it too weird to retrieve through an API, if it has to dig it out of different places.

I expected to see compartment wrapping when retrieving the stack. Don't you need to store it in _unwrappedPendingExceptionStack and then wrap it in GetPendingExceptionStack?

Other than those, it looks good, modulo possible perf results.
Attachment #8750543 - Flags: review?(sphink)
Comment on attachment 8750543 [details] [diff] [review]
Save a stack on JSContext::setPendingException

Yes, this is mostly what I need (moving it to JSContext is fine too.)

One question though, are we guaranteed to always have a full stack trace available here?  That would be great for SpiderNode, but Boris was worried about performance concerns on the mailing list.  If we only capture the top frame that's fine too, but I'd like to know which alternative are we planning to go forward with.

Thanks!!
Attachment #8750543 - Flags: feedback?(ehsan) → feedback+
This addresses review comments and changes the JSAPI function signature a little
as well (s/rt/cx/ but also bool return with stackp out param now).

About to run octane a few times, will report back. Would like to avoid re-using
the Error object's stack unless octane results say we have to (that stack could
be from quite far away, and ideally we would be able to give both stacks out as
requested).
Attachment #8754074 - Flags: review?(sphink)
Attachment #8750543 - Attachment is obsolete: true
(In reply to :Ehsan Akhgari (busy, don't ask for review please) from comment #21)
> Comment on attachment 8750543 [details] [diff] [review]
> Save a stack on JSContext::setPendingException
> 
> Yes, this is mostly what I need (moving it to JSContext is fine too.)
> 
> One question though, are we guaranteed to always have a full stack trace
> available here?

Unless Octane says otherwise, yes. And it will always be the stack at JSContext::setPendingException time, which roughly correlates to `throw` statements. And this is different from `e.stack` when `e` is a caught `Error` object, as that stack is captured when `e` was allocated, which may have been a completely different time/stack than the `throw`. We can also add a JSAPI to get an error's stack, if we don't already have one somewhere.

> That would be great for SpiderNode, but Boris was worried
> about performance concerns on the mailing list.

We will let Octane decide :)
Attached image Octane results (obsolete) —
10 runs with and 10 runs without the patch.

Higher is better, and this says that we are actually /faster/ with this patch, which is clearly untrue, so I think we are well within the noise here.

Not the most scientific, but I think we should Ship It!
Comment on attachment 8754074 [details] [diff] [review]
Save a stack on JSContext::setPendingException

Review of attachment 8754074 [details] [diff] [review]:
-----------------------------------------------------------------

Yep, I'm fine with this if perf allows. And thanks for the description of Error.stack vs this stack. This seems useful all of the time, then.
Attachment #8754074 - Flags: review?(sphink) → review+
This commit captures the JS stack in `JSContext::setPendingException` and
exposes a new JSAPI function for getting the stack:
`JS::GetPendingExceptionStack`. This stack is cleared out when the pending
exception is cleared.
Comment on attachment 8754126 [details] [diff] [review]
Save a stack on JSContext::setPendingException; r=sfink

This updated version makes JSContext::setPendingException take a HandleValue, which was easier than I feared.
Attachment #8754126 - Flags: review?(sphink)
Attachment #8754074 - Attachment is obsolete: true
Comment on attachment 8754126 [details] [diff] [review]
Save a stack on JSContext::setPendingException; r=sfink

Review of attachment 8754126 [details] [diff] [review]:
-----------------------------------------------------------------

::: js/src/vm/Interpreter.cpp
@@ +3633,5 @@
>           * be necessary, but it seems clearer.  And it points out a FIXME:
>           * 350509, due to Igor Bukanov.
>           */
> +        RootedValue v(cx, rval);
> +        cx->setPendingException(v);

Use rootValue0 here. Yeah, it's weird.
Attachment #8754126 - Flags: review?(sphink) → review+
Comment on attachment 8754127 [details] [diff] [review]
Part 2: Add a testing function and jit test for pending exception's stacks; r=sfink

Review of attachment 8754127 [details] [diff] [review]:
-----------------------------------------------------------------

r=me, though it seems like there ought to be a more clever way of surfacing this. Dunno what it might be.

I'd also be tempted to duplicate the test, but this time throw an Error object allocated somewhere else and check both stacks. For documentation, if nothing else.
Attachment #8754127 - Flags: review?(sphink) → review+
Ok, this version fixes the issues seen in the try push with two new changes:

* Don't even attempt to capture a stack when we are throwing OOM

* Add JS::ExceptionStackBehavior to control whether a particular
  setExceptionStack call will capture a stack or not. This was necessary to
  avoid horrible loops of clearing and re-setting exceptions that caused
  timeouts. I know that we discussed the Real Fix for this, but I'd like to put
  it off for the moment. I think that is fair, since this patch series gives us
  strictly more info then we have without it, even if we could do a better job
  with respect to temporarily clearing and re-setting exceptions.

Hopefully this is the last iteration of this patch you will have to review!
Thanks for your patience :)
Attachment #8754904 - Flags: review?(sphink)
Attachment #8754126 - Attachment is obsolete: true
Now with error-created-at-a-distance-from-the-throw and an assertion that the
pending exception stack is not the same as the thrown error's stack.
Attachment #8754905 - Flags: review+
Attachment #8754127 - Attachment is obsolete: true
Comment on attachment 8754904 [details] [diff] [review]
Save a stack on JSContext::setPendingException

Review of attachment 8754904 [details] [diff] [review]:
-----------------------------------------------------------------

::: js/src/jsapi.h
@@ +5466,5 @@
> +namespace JS {
> +
> +enum class ExceptionStackBehavior: bool {
> +    // Capture the current JS stack when setting the exception. It may be
> +    // retreived by JS::GetPendingExceptionStack.

i before e except after c... :-)

@@ +5470,5 @@
> +    // retreived by JS::GetPendingExceptionStack.
> +    Capture,
> +    // Do not capture any stack.
> +    DoNotCapture
> +};

I almost wonder if this should be ExceptionBehavior::CaptureStack and ExceptionBehavior::DoNotCaptureStack. I don't know how likely it is that we'd want other flags, but it doesn't seem out of the realm of possibility. And on first reading, I didn't associate the "Stack" part with "DoNotCapture", and worried that somehow you're requesting that it not capture the exception at all.

But it's a minor thing, and I'm not sure. Up to you.

@@ +5482,5 @@
>  JS_GetPendingException(JSContext* cx, JS::MutableHandleValue vp);
>  
>  extern JS_PUBLIC_API(void)
> +JS_SetPendingException(JSContext* cx, JS::HandleValue v,
> +                       JS::ExceptionStackBehavior behavior = JS::ExceptionStackBehavior::Capture);

All current Gecko callers are ok with capturing the stack, then?

@@ +5996,5 @@
> +/**
> + * Get the SavedFrame stack object captured when the pending exception was set
> + * on the JSContext. This fuzzily correlates with a `throw` statement in JS,
> + * although arbitrary JSAPI consumers or VM code may also set pending exceptions
> + * via `JS_SetPendingException`.

I wonder if 'fuzzily correlates' is too scary? Would it be fair to say this?:

This will correspond to a 'throw' statement in JS, or the state at which JS_SetPendingException is called by VM code or a JSAPI consumer.

@@ +5999,5 @@
> + * although arbitrary JSAPI consumers or VM code may also set pending exceptions
> + * via `JS_SetPendingException`.
> + *
> + * This is not the same stack as `e.stack` when `e` is an `Error` object. (That
> + * would be JS::ExceptionStackOrNull).

Can you expand on this a little, by saying that e.stack is the stack from the point at which the Error object is created?

@@ +6004,5 @@
> + *
> + * Note that it is possible that `stackp` is null with a `true` return value if
> + * either there is no pending exception (and hence no stack for the pending
> + * exception) or if the exception was set on the `cx` when there was no JS on
> + * the stack.

"...(and therefore the stack is correctly empty)", maybe?

Also, with the new ExceptionStackBehavior, aren't there additional cases here? OOM, and whatever other situations you use DoNotCapture for?
Attachment #8754904 - Flags: review?(sphink) → review+
(In reply to Steve Fink [:sfink] [:s:] from comment #36)
> Comment on attachment 8754904 [details] [diff] [review]
> Save a stack on JSContext::setPendingException
> 
> Review of attachment 8754904 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> ::: js/src/jsapi.h
> @@ +5466,5 @@
> > +namespace JS {
> > +
> > +enum class ExceptionStackBehavior: bool {
> > +    // Capture the current JS stack when setting the exception. It may be
> > +    // retreived by JS::GetPendingExceptionStack.
> 
> i before e except after c... :-)
> 
> @@ +5470,5 @@
> > +    // retreived by JS::GetPendingExceptionStack.
> > +    Capture,
> > +    // Do not capture any stack.
> > +    DoNotCapture
> > +};
> 
> I almost wonder if this should be ExceptionBehavior::CaptureStack and
> ExceptionBehavior::DoNotCaptureStack. I don't know how likely it is that
> we'd want other flags, but it doesn't seem out of the realm of possibility.
> And on first reading, I didn't associate the "Stack" part with
> "DoNotCapture", and worried that somehow you're requesting that it not
> capture the exception at all.
> 
> But it's a minor thing, and I'm not sure. Up to you.
> 
> @@ +5482,5 @@
> >  JS_GetPendingException(JSContext* cx, JS::MutableHandleValue vp);
> >  
> >  extern JS_PUBLIC_API(void)
> > +JS_SetPendingException(JSContext* cx, JS::HandleValue v,
> > +                       JS::ExceptionStackBehavior behavior = JS::ExceptionStackBehavior::Capture);
> 
> All current Gecko callers are ok with capturing the stack, then?

We will find out -- I just added some mochitests to the try push :)
SM(cgc) passed the backout without errors.
Whiteboard: [parity-chrome][polish-backlog][gaming-tools] → [parity-chrome][polish-backlog][gaming-tools][v8api]
This patch needs a bit of reworking to handle the fairly common unset-do-stuff-and-then-reset-pending-exception pattern that crops up throughout spidermonkey, but I don't have the cycles at the moment.
Flags: needinfo?(nfitzgerald)
See Also: → 1315183
Now, when FireBug is dead, we really need this to be fixed!
Sorry for the noise, but with lack of this feature, it is pointless to develop and debug a web application with Firefox. That's why I use Chrome for that. e.g. Angular.
Dev team should sort their priorities! This should be P1
(In reply to :Gijs (he/him) from comment #6)
> FWIW, in chrome code, doing:
> 
> throw new Error("Foo")
> 
> also doesn't provide a stack trace in the browser console, which you can
> test by just running that code in the browser console.

That is no longer true today - I'm on chrome 66.0.3359.117 and it does show a stack trace back to the location where the error is thrown, even when the thrown value is not an error object.
Duplicate of 686587
Mass bug change to replace various 'parity' whiteboard flags with the new canonical keywords. (See bug 1443764 comment 13.)
Keywords: parity-chrome
Whiteboard: [parity-chrome][polish-backlog][gaming-tools][v8api] → [polish-backlog][gaming-tools][v8api]
The leave-open keyword is there and there is no activity for 6 months.
:sdetar, maybe it's time to close this bug?
Flags: needinfo?(sdetar)
Jason, this bug still has the leave-open keyword, but seemed to be marked as a duplicate bug.  Should we close it?
Flags: needinfo?(sdetar) → needinfo?(jorendorff)
It looks like Nick is the best person to decide what to do with this.
Flags: needinfo?(jorendorff) → needinfo?(nfitzgerald)
It looks like the other bug was duped to this one, so removing ni.
Flags: needinfo?(nfitzgerald)
Blocks: dbg-stacks
Assignee: nobody → bhackett1024
Attached patch patchSplinter Review

Working patch with DOM changes and so forth to allow the stack for 'throw 3' to show up in the console. I started with Nick's patch and changed most of the internal interfaces so that spidermonkey can save and restore stacks explicitly if it needs to remove and then restore the pending exception. I think this is done, except for a new test. Known limitations:

  • Workers will need some additional handling, but the devtools console doesn't report stacks for worker exceptions as is, so the two seem like they could be fixed together in followup.

  • When a non-error value is caught and then rethrown from JS, the stack for the later throw is reported. This could happen for an explicit 'try { ... } catch (e) { throw e; }' which seems fine (and would be hard to fix), but it can also happen due to how 'try { ... } finally { ... }' and 'for (... of ...) { ... }' are compiled by the frontend. It would be good to fix the latter two but since this requires modifying bytecode generation I think it would be better to do in followup.

Attachment #8754098 - Attachment is obsolete: true
Attachment #8754904 - Attachment is obsolete: true
Attachment #8754905 - Attachment is obsolete: true
Pushed by bhackett@mozilla.com:
https://hg.mozilla.org/integration/mozilla-inbound/rev/36c7e4619a29
Part 1 - Include stack in JSContext exception information, r=sfink.
https://hg.mozilla.org/integration/mozilla-inbound/rev/8e21496aa97b
Part 2 - Use JS engine stack if necessary when reporting errors, r=bz.
https://hg.mozilla.org/integration/mozilla-inbound/rev/ad5283f158e7
Part 3 - Add JSAPI test for stacks saved when throwing.
https://hg.mozilla.org/integration/mozilla-inbound/rev/7d16d7014ed3
Part 4 - Add mochitest for console stacks from non-exception errors.
Status: NEW → RESOLVED
Closed: 5 years ago
Keywords: leave-open
Resolution: --- → FIXED
You need to log in before you can comment on or make changes to this bug.

Attachment

General

Creator:
Created:
Updated:
Size: