895340 - nsIObserverService should report JS exceptions thrown in observers

Status: RESOLVED FIXED

(Core :: XPConnect, defect)

Description

[David Teller [:Yoric] - still alive but not very active]

Attachment: Trivial test case

Consider the (very frequent) following scenario:
- some JS code registers an observer |obs| with the nsIObserverService;
- for some reason, typically some dynamic type error, |obs| raises a JavaScript error;
- nothing is displayed anywhere.

This kind of scenario regularly costs me hours until I can guess which of the observers has raised the error that I'm tracking.

By default, we should display the error and its JS stack.

Comment 1

[David Teller [:Yoric] - still alive but not very active]

Re-filing this to XPConnect, without certainty.

Comment 2

[Boris Zbarsky [:bzbarsky]]

XPConnect can't solve this: it assumes that we want to propagate the exception transparently, but of course observers can't work like that.

What should happen here, presumably, is for the observer service to push a null JSContext on the stack before starting to invoke observers, if I understand the setup correctly.  Bobby, does that sound right?

Comment 3

[Mark Hammond [:markh] [:mhammond]]

I'm confused about this - I could have sworn I've seen exactly the same thing.  However, if I take your example, paste it into a "browser" scratchpad in Nightly, fix the order of the args to addObserver (handler is 1st arg, topic is second) and run it while the "browser console" is open, sure enough, I see in the console:

[11:46:57.398] [Exception... "'Error: Will you report me?' when calling method: [nsIObserver::observe]"  nsresult: "0x8057001c (NS_ERROR_XPC_JS_THREW_JS_OBJECT)"  location: "JS frame :: Scratchpad/2 :: <TOP_LEVEL> :: line 7"  data: no] @ Scratchpad/2:7

So color me confused, but it seems this might be INVALID?

Comment 4

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

That's weird. If I put the code in browser.js (after fixing the argument order), it ignores the error.

I think I might have a fix for this. I need to check tryserver though.

Comment 5

[Mark Hammond [:markh] [:mhammond]]

Gavin and I were chatting in IRC - it looks like running it from the scratchpad or the browser console does report the error, but almost all other contexts do not.  Strange...

Comment 6

[Bobby Holley (:bholley)]

(In reply to Boris Zbarsky (:bz) from comment #2)
> XPConnect can't solve this: it assumes that we want to propagate the
> exception transparently, but of course observers can't work like that.
> 
> What should happen here, presumably, is for the observer service to push a
> null JSContext on the stack before starting to invoke observers, if I
> understand the setup correctly.  Bobby, does that sound right?

Assuming that we want the observers to be invoked as system code, rather than with the privileges of the code triggering the notification. I'm a bit surprised it doesn't do that already.

Comment 7

[David Teller [:Yoric] - still alive but not very active]

bsmedberg mentioned on dev-platform (at https://groups.google.com/d/msg/mozilla.dev.platform/dgKzmj3i1M4/sq3xkJk4D5IJ ) the existence of a sort-of-workaround, which may be useful for anyone encountering this bug:

« I argued against fixing bug 415498 at the time, and because it was so contentious, there is an "out": if you set MOZ_REPORT_ALL_JS_EXCEPTIONS you will get the old behavior (and the possibility of some false-positives). You can also call nsIXPConnect.setReportAllJSExceptions to set this at runtime. »

Comment 8

[:Gavin Sharp [email: [e-mail]]]

(In reply to David Rajchenbach Teller [:Yoric] from comment #7)
> « I argued against fixing bug 415498 at the time, and because it was so
> contentious, there is an "out": if you set MOZ_REPORT_ALL_JS_EXCEPTIONS you
> will get the old behavior (and the possibility of some false-positives). You
> can also call nsIXPConnect.setReportAllJSExceptions to set this at runtime. »

FWIW that didn't help me (I set the dom.report_all_js_exceptions pref rather than an environment variable, but they control the same switch AFAICT). I still didn't see the exception reported when running the code from the JS Shell, so I think there are at least two different underlying causes of this more general symptom.

Comment 9

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

There are two issues here. The one that bsmedberg pointed out is a general problem with interleaving JS and C++ code. If the JS code throws an exception, should it be reported on the console, or should it be passed to C++ via an error code? The solution people came up with is to report only certain exceptions, based on the nsresult that they get translated to. Nobody really likes this solution, but there aren't any better ideas, and it seems to work okay. The dom.report_all_js_exceptions pref just tells xpconnect to report all exceptions regardless of the nsresult code.

In our case, the exception getting thrown *should* be reported based on its nsresult. The fact that it's not being reported is a bug. That's why dom.report_all_js_exceptions doesn't work--it would only help if the exception was being filtered out based on its nsresult.

The bug is a regression from bug 455436. I'm working on a fix for that, but it's failing a couple tests right now.

Comment 10

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

Attachment: error-reporter-hack

This bug took a lot of bugzilla/hg spelunking, so I'll try to summarize.

As I said in the previous comment, prior to bug 455436 we would have reported this exception. The idea was supposed to be that all JS exceptions, except for a few matching certain nsresult codes, should be reported to the error console.

The goal of bug 455436 seems to have been to allow workers to customize error reporting more than what was then possible. I haven't had a chance to talk to bent about it, though, so I'm making some educated guesses. The crucial change was here:
  http://hg.mozilla.org/mozilla-central/rev/3aec0eec68a1#l6.120

Prior to that change, an error occurring during wrapped JS execution would be reported by the code in nsXPCWrappedJSClass::CheckForException. It would print out one of these messages:
  ************************************************************
  * Call to xpconnect wrapped JSObject produced this error:  *
  * ...                                                      *
  ************************************************************
and it would put something similar in the error console. It would not invoke any window.onError handlers.

I think the change was made because workers wanted to report these errors using their own custom error reporter. For normal browser JSContexts, that means we now report them using NS_ScriptErrorReporter. I'm guessing bent ran into a problem here, because NS_ScriptErrorReporter *does* invoke window.onError. So he added code to the beginning of that function to skip reporting the error if there's any JS code on the stack. That way he avoided breaking code that didn't expect window.onError to be called. The unfortunate side effect is that we no longer report to the error console either.

At first I tried changing nsXPCWrappedJSClass::CheckForException so that it doesn't call the JSContext's error reporter if it's NS_ScriptErrorReporter. That restores the previous behavior for browser JSContexts. However, that caused some mochitests to fail. As an example, the test_sanityException2.html test expects window.onError to be called when an exception is thrown inside XPCWrappedJS code when no other JS is on the stack. Prior to bug 455436, we never would have called window.onError. However, that test didn't exist back then.

It seems like a good idea to call window.onError when there's no JS on the stack. So I came up with this patch. The error reporter has the option to tell xpconnect that it's ignoring the error. In that case, xpconnect can print the error to the error console.

Ben, if this is wrong, can you correct me?

Comment 11

[Bobby Holley (:bholley)]

Comment on attachment 778657 [details] [diff] [review]
error-reporter-hack

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

This all seems ok I guess, and kudos to billm for diving in. IMO it's just another deck chair on a titanic that we can't save without redesigning our whole mechanism here (which I have plans for in the medium-term), which is why I'm not personally volunteering to put out any of these individual fires. But I certainly won't stand in your way. :-)

::: js/xpconnect/idl/nsIXPConnect.idl
@@ +626,1 @@
>                                        in JSContextPtr aJSContext);

This needs an IID rev.

::: js/xpconnect/src/XPCWrappedJSClass.cpp
@@ +1024,5 @@
> +                JS_GetErrorReporter(cx) != xpcWrappedJSErrorReporter)
> +            {
> +                // If the error reporter ignores the error, it will call
> +                // xpc->MarkErrorUnreported().
> +                xpcc->ClearUnreportedError();

So the idea is that we just leave the old bit on the context until we're about to check it again here, in which case we clear it? That's kind of yucky, but ok I guess...

Comment 12

[Ben Turner (not reading bugmail, use the needinfo flag!)]

(In reply to Bill McCloskey (:billm) from comment #10)

This is mostly right, with a few exceptions. There are two main things I remember fixing:

1. We used to always report exceptions every time we crossed from JS back into C++ with an exception set. That made the console kinda useless since browser JS sometimes tried to throw an exception that it expected to be handled in the C++ caller. The compromise we agreed on way back when was to only report JS exceptions if there was no other JS on the stack. So we don't report here:

  C++ -> JS -> C++ -> JS-that-throws

And we do report here:

  C++ -> JS-that-throws

Setting the environment variable or the report_all_js_exceptions pref of course would report the first case too.

2. The change to make XPConnect respect JS error reporters came because XPConnect just used to always set its own error reporter on the context before calling anything. That broke workers and any custom error reporters.

This stuff about calling window.onerror was never an issue that I addressed specifically. Any change to that behavior was likely accidental.

Comment 13

[Ben Turner (not reading bugmail, use the needinfo flag!)]

Comment on attachment 778657 [details] [diff] [review]
error-reporter-hack

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

This looks fine to me, I guess. Workers don't use XPConnect any longer so they won't be affected by this. If bholley has finished merging all the different main thread error reporters (DOM, JS component loader, xpcshell... maybe others?) and none of them need this opt-out behavior then maybe you don't need this and you could just always report...

Comment 14

[Bobby Holley (:bholley)]

(In reply to ben turner [:bent] from comment #13)
> Comment on attachment 778657 [details] [diff] [review]
> error-reporter-hack
> 
> Review of attachment 778657 [details] [diff] [review]:
> -----------------------------------------------------------------
> 
> This looks fine to me, I guess. Workers don't use XPConnect any longer so
> they won't be affected by this. If bholley has finished merging all the
> different main thread error reporters (DOM, JS component loader, xpcshell...
> maybe others?)

We still have a distinction between DOM (NS_ScriptErrorReporter) and non-DOM (xpc::SystemErrorReporter), but everything else has been flattened I think.

Comment 15

[Bill McCloskey [inactive unless it's an emergency] (:billm)]

https://hg.mozilla.org/integration/mozilla-inbound/rev/64462ec4cef3

Comment 16

[Justin Dolske [:Dolske]]

(In reply to ben turner [:bent] from comment #12)

> 1. We used to always report exceptions every time we crossed from JS back
> into C++ with an exception set. That made the console kinda useless since
> browser JS sometimes tried to throw an exception that it expected to be
> handled in the C++ caller. 

Would it be useful (and/or possible, wise :) to allow such callers to opt-in to a silencing mechanism? I think this pattern is fairly uncommon, so maybe we can just make it go away?

EG:

  ...
  if (blah) {
    var e = Components.Exception("blah" Cr.NS_SOME_PARTICULAR_CODE);
    e.unloggedException = true;
    throw e;
  }

Comment 17

[Ryan VanderMeulen [:RyanVM]]

https://hg.mozilla.org/mozilla-central/rev/64462ec4cef3