415498 - Some errors not displayed in Error Console when using addEventListener

Status: VERIFIED FIXED

(Core :: XPConnect, defect, P2)

Description

[Sylvain Pasche]

Attachment: testcase

Some errors like NS_ERROR_DOM_WRONG_DOCUMENT_ERR or NS_ERROR_DOM_BAD_URI are not displayed in the Error Console when they happen in a handler registered from addEventListener.

I first saw this issue when trying to use XMLHttpRequest on a script accessed through file:// (it was throwing NS_ERROR_DOM_BAD_URI for security reasons). The attached testcase uses a DOM error (NS_ERROR_DOM_WRONG_DOCUMENT_ERR), so that it can be run anywhere.

Regression range:

http://bonsai.mozilla.org/cvsquery.cgi?treeid=default&module=PhoenixTinderbox&branch=HEAD&branchtype=match&dir=&file=&filetype=match&who=&whotype=match&sortby=Date&hours=2&date=explicit&mindate=2007-10-24+04%3A00%3A00&maxdate=2007-10-25+04%3A00%3A00&cvsroot=%2Fcvsroot

I guess this is a regression from bug 393627

Comment 1

[Sergey Yanovich]

Looks like it's a duplicate of bug 405769

Comment 2

[Sylvain Pasche]

(In reply to comment #1)
> Looks like it's a duplicate of bug 405769

Yes, that should be somewhat related. However bug 405769 is about unreported exceptions in chrome code, while this bug is for the ones in content code. I think the latter is more important to be addressed as it has a far greater exposure.

Comment 3

[Sergey Yanovich]

It is a broader xpconnect issue. Bug 393627 switched from filtering out a few bad codes to filtering in a few good codes. However, the list of good codes is more tricky to maintain.

My $.02 is that we need context-aware approach instead of filters, but that is a good amount of work. This whole issue is low profile, because it concerns developers only. The developers can usually build an executable with custom workaround. F.e., I have bug 393627 reverted in my builds, and suppress js console polluters with a special return value.

Sylvain, if you badly need those DOM errors logged, you can look at the patch for bug 401735. Adding a few lines to js/src/xpconnect/src/xpcwrappedjsclass.cpp
 should be fairly easy.

Comment 4

[Nickolay_Ponomarev]

Web developers aren't expected to build their own Firefox. We shouldn't regress error reporting, it makes debugging very frustrating. Asking for blocking-1.9

Comment 5

[Sergey Yanovich]

(In reply to comment #4)
> Web developers aren't expected to build their own Firefox. We shouldn't regress
> error reporting, it makes debugging very frustrating. Asking for blocking-1.9

There are 2^31 possible error codes, most coming from native C++. All but a dozen of them get blocked in xpconnect now. If we don't want to regress error reporting in wide sense, we need to change the way xpconnect qualifies errors for logging. Namely, we need to switch from error code based solution to context-aware solution.

Comment 6

[Johnny Stenback (:jst)]

Blake, any thoughts on what, if anything, we should do here for Firefox 3?

Comment 7

[Sylvain Pasche]

note that the testcase is not working any more because of bug 418755

Comment 8

[Jonas Sicking (:sicking) No longer reading bugmail consistently]

Reverting dependency as bug 405769 is likely where the initial fix would be.

So I'm starting to think that we need to either fully revert the patch in bug 393627, or just restore logging when the exception is coming from content code.

Comment 9

[Jonas Sicking (:sicking) No longer reading bugmail consistently]

Jst says it's ok to leave this for RC if we really need to. It is a web facing issue though so it'd be really good to have fixed for beta5

Comment 10

[Blake Kaplan (:mrbkap) (inactive)]

Attachment: Updated testcase

The previous testcase doesn't work anymore since we allow a node to be adopted with appendChild if it isn't already in a document.

Comment 11

[Sylvain Pasche]

Thanks for updating. A small note: the comment should mention NS_ERROR_DOM_HIERARCHY_REQUEST_ERR instead of NS_ERROR_DOM_WRONG_DOCUMENT_ERR

Comment 12

[Blake Kaplan (:mrbkap) (inactive)]

Attachment: Proposed fix

This fixes this bug by reporting xpconnect exceptions from event handlers. I've tried to minimize the possibility of duplicate reports. The idea here is that once an exception has been reported to the console, we don't have to deal with it anymore, so we remove it from the "Pending" exception field.

Comment 13

[Blake Kaplan (:mrbkap) (inactive)]

Attachment: Updated to comments

Comment 14

[Johnny Stenback (:jst)]

Comment on attachment 307618 [details] [diff] [review]
Updated to comments

+        xpc->GetPendingException(getter_AddRefs(e));
+        nsresult e_result;
+        if (e && NS_SUCCEEDED(e->GetResult(&e_result)) && result == e_result) {

You don't need the result check here now that you do the QI to nsIJSEventListener above.

r+sr=jst with that removed.

Comment 15

[Sergey Yanovich]

With this patch, the following error will be reported from event listener, but not from a js component or chrome:

        var doc = document.implementation.createDocument(null, 'DOC', null);
        doc.documentElement.appendChild(doc);

IMHO, it is a misleading practice.

Comment 16

[Sergey Yanovich]

Attachment: alternative proposed fix (more general)

The idea behind patch for bug 393627 was, that we shouldn't log dumb error code console, but when there is extra info, it should log it. XPConnect errors clearly represent a type of extra info. With this patch these errors will be logged, while no messages dumped en masse by 393627 is expected to reappear.

Comment 18

[Sergey Yanovich]

Comment on attachment 307692 [details] [diff] [review]
alternative proposed fix (more general)

I have built 1.9b4 with attachment 307692 [details] [diff] [review]. The browser passes test from attachment 307596 [details]:

Error: [Exception... "Node cannot be inserted at the specified point in the hierarchy"  code: "3" nsresult: "0x80530003 (NS_ERROR_DOM_HIERARCHY_REQUEST_ERR)"  location: "https://bugzilla.mozilla.org/attachment.cgi?id=307596 Line: 5"]
Source File: https://bugzilla.mozilla.org/attachment.cgi?id=307596
Line: 5

It also does everything, I was asking in bug 405769.

Comment 20

[Johnny Stenback (:jst)]

Comment on attachment 307692 [details] [diff] [review]
alternative proposed fix (more general)

There's no really good fix for this problem that I know of so far. More special casing of specific error codes won't really help much IMO, and only moves the problem around. I'd rather see us make a good effort at always reporting errors that web developers trigger, and treat JS components, whose development settings are obviously different have a way to turn on errors in JS components. Blake has thoughts on how to do that. sr- based on that.

Comment 21

[Sylvain Pasche]

I tried to convert the testcase into a mochitest, but I wasn't successful.

If I try to do something raising an exception, the mochitest will abort early (even if I disable the SimpleTest onerror handler) so I can't check if the console service received the exception. I there trick to get this working? (I also had plenty of "ASSERTION: XPConnect is being called on a scope without a 'Components' property!" assertions in my debug build when trying this).

Otherwise I can try with a chrome test.

Comment 22

[Sergey Yanovich]

(In reply to comment #20)
> (From update of attachment 307692 [details] [diff] [review])
> There's no really good fix for this problem that I know of so far. More special
> casing of specific error codes won't really help much IMO, and only moves the
> problem around. I'd rather see us make a good effort at always reporting errors
> that web developers trigger, and treat JS components, whose development
> settings are obviously different have a way to turn on errors in JS components.
> Blake has thoughts on how to do that. sr- based on that.
> 

I won't argue with the verdict itself, but the underlying conclusions are not fully correct.

My patch doesn't special case error codes. Additional 'switch' statement is added to 'xpc_xpc_IsReportableErrorCode' to prevent regressions, when errors, suppressed before bug 393627, would start to appear in console.

In turn, Blake's patch special cases event listeners. It is not a problem, if it is the only xpconnect code, web content may run. Otherwise, we will need to add similar checks to other places. That patch slightly degrades performance by adding extra NS_FAILED to nsEventListenerManager::HandleEventSubType(). And the patch adds an undocumented invariant to nsIEventListenerManager::HandleEvent(), that it should log errors from xpconnect handlers.

It's my first patch to a module requiring sr, and I understand now, that I shouldn't have been raising sr? until I have Blake's answer for r?.

Comment 23

[Jonas Sicking (:sicking) No longer reading bugmail consistently]

There are definitely more XPCOM interfaces that web content can implement. Off the top of my head there is:

UserDataHandler
XPathNSResolver
NodeFilter

I do think that the best fix would be to always report when an error bubbles up from content code into XPConnect. Not sure how doable it is to write such a patch cleanly though.

Comment 24

[Sergey Yanovich]

(In reply to comment #23)
> I do think that the best fix would be to always report when an error bubbles up
> from content code into XPConnect. Not sure how doable it is to write such a
> patch cleanly though.
> 

My patch does exactly this. I check whether the exception comes from xpconnect, and pass this info to xpc_IsErrorReportable(), where pure js and xpconnect exceptions are treated differently.

Comment 25

[Sylvain Pasche]

Attachment: chrome test

I could get this working when using a chrome test. For completeness I also check that error is reported with a document using window.onload (this works before this bug).

By the way attachment 307618 [details] [diff] [review] bitrotted a bit: nsIXPConnect's previous uuid changed since then.

Comment 26

[Sergey Yanovich]

Comment on attachment 308322 [details] [diff] [review]
chrome test


Sylvain, you didn't seem to have test_bug415498.html in your patch, but you add it to _TEST_FILES var in Makefile.in.

Comment 27

[Sylvain Pasche]

Thanks for noticing Sergey, I forgot to remove that file from Makefile.in  (that was from my previous tests when using a non-chrome mochitest). I'll update the patch.

Comment 28

[Sylvain Pasche]

Attachment: chrome test, v2

Comment 29

[Sergey Yanovich]

Blake, Johnny, Jonas,

I am still hoping to get attachment 307692 [details] [diff] [review] into trunk in time for Firefox 3. We have here a patch and a test, and the patch passes the test, and the patch doesn't affect non-error line of execution, so performance impact should be neglectable.

If there are any questions requiring answers, my nick or #developers is 'yanychar'.

Comment 30

[Jonas Sicking (:sicking) No longer reading bugmail consistently]

It doesn't look like this patch uses the principal of the throwing script to see if it should be reported or not, which is what I think is the right solution. I.e. if it's chrome script then don't report it, otherwise do report it.

Comment 31

[Sergey Yanovich]

Jonas, thank you spending your time on this. I understand the pressure all reviewer are experiencing as release approach. I am keeping to raise this issues, only because it is critically important for js module debugging. No errors in js xpcom modules are logged as things are now.

(In reply to comment #30)
> It doesn't look like this patch uses the principal of the throwing script to
> see if it should be reported or not, which is what I think is the right
> solution. I.e. if it's chrome script then don't report it, otherwise do report
> it.

Plain chrome code has a different path of execution on exception, and doesn't seem to hit xpc_IsErrorReportable() at all. This is exactly the thing Sylvain checks in the second part of his patch, IIUC. My patch is only hit from js modules or xpconnect wrapped content/chrome scripts (event listeners and other callbacks that can be implemented in js).

My patch does a bit different thing: it checks that the exception is popping up from xpconnect, as opposed to 'throw Components.results.NS_ERROR_*;' from js. And then only logs if it is popping.

The patch is a fix for regression introduced in bug 393627, which aimed to stop logging 'throw Components.results.NS_ERROR_*;' type of exceptions, but as side-effect also suppressed exceptions resulting from all failures in XPCOM calls. Again this paragraph applies only to xpconnect wrapped js code (js modules, callbacks), because all exceptions in normal (lacking better word) js code (be it chrome or content) are still logged.

Comment 32

[Matthew Gertner]

Based on my experience writing chrome and component JS in Firefox 3, I suspect this regression will be met with dismay by extension developers. I can't comment on content JS since I haven't been writing any, but if the error reporting regression is similar then the reaction is likely to be the same but the audience much larger.

In a nutshell, XPCOM errors in JS aren't reported at all anymore. So I've been forced to add dump() statements and the like in order to find errors in code that used to be reported automatically. This makes the develop/test/debug cycle much more time-consuming.

In my opinion, fixing this for FF3 is a must. Sergey's patch looks reasonable to me.

Comment 34

[Sylvain Pasche]

Now that we're talking about chrome errors, it may be useful to update the automated test to check that too. For now it is only checking content errors, which passes with Blake's patch.
(I guess the documents could be reloaded in a <browser> without a type="content" attribute to simulate that).

Comment 35

[timeless]

Comment on attachment 307692 [details] [diff] [review]
alternative proposed fix (more general)

first, I'm not a fan of 307618, the split between the getPendingException and the setPendingException bothers me.

+                if (NS_LIKELY( isWrapped ))
this doesn't match the whitespace conventions for the file. And please don't use tabs.

if you were going to do something like this (and i don't think you should), then I'd rather something like this:
     switch(code)
     {
         case NS_ERROR_XPC_JS_THREW_NULL:
         case NS_ERROR_XPC_JS_THREW_JS_OBJECT:
         case NS_ERROR_XPC_JS_THREW_NATIVE_OBJECT:
         case NS_ERROR_XPC_JS_THREW_STRING:
         case NS_ERROR_XPC_JS_THREW_NUMBER:
         case NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS:
         case NS_ERROR_XPC_JAVASCRIPT_ERROR:
             return JS_TRUE;
+        case NS_ERROR_FACTORY_REGISTER_AGAIN:
+        case NS_BASE_STREAM_WOULD_BLOCK:
+            if (isWrapped)
+                return JS_FALSE;
+            break;
+        default:
+            if (isWrapped && NS_FAILED(code))
+                return JS_TRUE;
     }

personally, I believe we should back out bug 393627 - which I believe is an unacceptable API change, especially this late into a product cycle. The benefits of the patch are minor and the harm to our platform is fairly major. People can and should be able to live with some small amount of noise in the Error Console. If they can't, then they clearly can't visit any Google site.

my console is currently filled with:
Error: %36
Source file: https://mail.google.com/mail/?ui=2&view=js&name=js&ids=1dgpb0bm4mmnf
Line: 254
and:
Warning: Empty string passed to getElementById().
(I have no idea who's causing that one, and if people hadn't broken this, I might investigate that.)

What follows are two approaches which I believe should be complete.
The first would be to take one of our *very* precious bits from xpidl and tag methods as "error expected". nsISupports.QueryInterface would get such a tag (so would a number of necko interfaces). Callers would be expected to rethrow the exception if they don't want to handle it.

I don't believe this is ideal. As it costs an expensive tag bit in xpidl.

An alternative approach is to allow consumers to register interfaces with the exceptionManager to get a callback before the exception is returned:

interface nsIExceptionManagerFilter {
void registerFilter(in nsIIDRef iid, in nsISupports filter);
void unregisterFilter(in nsIIDRef iid, in nsISupports filter);
}
when an exception for a method of nsIIDRef is triggered, the filter is called:

here's a draft concept using nsIObserver:
filter.nsIObserver.observe(details.nsIWritablePropertyBag2, "exception-filter", reserved=null);
calling:
details.nsIPropertyBag2.setPropertyAsBool("handled", true)
- will suppress the warning.
details.nsIPropertyBag2.getPropertyAsACString("interfaceName")
- will return the interface pretty name or return ""
details.nsIPropertyBag2.getPropertyAsACString("interfaceAsId")
- will return the interface name in this form: "{625cfd1e-da1e-4417-9ee9-dbc8e0b3fd79}"
details.nsIPropertyBag2.getPropertyAsInterface("IID",Components.interfaces.nsIJSIID)
- will return the interface as a nsIJSIID (there doesn't seem to be any easy way to store an IID directly)
details.nsIPropertyBag2.getPropertyAsACString("method")
- will return the method that was called
details.nsIPropertyBag2.getPropertyAsUint32("nsresult")
- will return the nsresult value
details.nsIPropertyBag2.getPropertyAsInterface("exception",Components.interfaces.nsIException)
- will return the exception object (other interfaces may or may not work)
details.nsIPropertyBag2.getPropertyAsInterface("calleePrincipal",Components.interfaces.nsIPrincipal)
- will return the principals for the callee
details.nsIPropertyBag2.getPropertyAsInterface("callerPrincipal",Components.interfaces.nsIPrincipal)
- will return the principals for the caller

Implementations would be advised to try not to need to call methods to figure out what they want to do. So the nsISupports.QueryInterface implementation would immediately call details.nsIWritablePropertyBag2.setPropertyAsBool("handled", true)
without ever checking anything.

here's an alternative which uses a custom interface:
interface nsIExceptionFilter {
  boolean shouldReportException(in IIDRef iid, in long methodIndex, in nsresult result, in ACString interfaceName, in ACString methodName, in nsIException exception, in nsISupports calleePrincipal, in nsISupports callerPrincipal);
}

callee/caller are arguably needed for people who decide their exceptions only matter for boundary conditions.
For a given thread, while an exception is being filtered, the exception filter will not call additional filters, i.e. if a filter triggers an exception, it will be reported immediately. Handlers which are not nsIClassInfo.THREADSAFE will only be called on the thread from which they registered. Proxies that are detectable will be rejected (this is especially targeted at the ProxyObjectManager's proxyObjects), and if possible the proxyObjectManager will refuse to proxy while the filter is running (by throwing an exception anytime a method is called from that thread on a proxy).

I think this is actually relatively easy to implement. It would of course add overhead to any exceptions that try to cross the js/xpconnect boundary. But, we could probably change the consoleService to use be called via this hook, which might improve error reporting.

Comment 36

[Sergey Yanovich]

(In reply to comment #35)
> (From update of attachment 307692 [details] [diff] [review] )
> +                if (NS_LIKELY( isWrapped ))
> this doesn't match the whitespace conventions for the file. And please don't
> use tabs.

This will be fixed. Did my best to avoid this type of convention violation. 

I'll probably add vim:: line to prevent such things in the future. Is that acceptable?

> if you were going to do something like this (and i don't think you should),
> then I'd rather something like this:
>      switch(code)
>      {
>          case NS_ERROR_XPC_JS_THREW_NULL:
>          case NS_ERROR_XPC_JS_THREW_JS_OBJECT:
>          case NS_ERROR_XPC_JS_THREW_NATIVE_OBJECT:
>          case NS_ERROR_XPC_JS_THREW_STRING:
>          case NS_ERROR_XPC_JS_THREW_NUMBER:
>          case NS_ERROR_XPC_JAVASCRIPT_ERROR_WITH_DETAILS:
>          case NS_ERROR_XPC_JAVASCRIPT_ERROR:
>              return JS_TRUE;
> +        case NS_ERROR_FACTORY_REGISTER_AGAIN:
> +        case NS_BASE_STREAM_WOULD_BLOCK:
> +            if (isWrapped)
> +                return JS_FALSE;
> +            break;
> +        default:
> +            if (isWrapped && NS_FAILED(code))
> +                return JS_TRUE;
>      }

IIUC if 'case' translates into 'if' so 'isWrapped' check outside 'switch' should be a bit faster. But I am fine with either variant.

> personally, I believe we should back out bug 393627 - which I believe is an
> unacceptable API change, especially this late into a product cycle. The
> benefits of the patch are minor and the harm to our platform is fairly major.
> People can and should be able to live with some small amount of noise in the
> Error Console. If they can't, then they clearly can't visit any Google site.

Backing out bug 393627 was my first idea, but I wasn't sold :) But I understand intention to suppress C.results error codes. Either option is fine for me again.

> What follows are two approaches which I believe should be complete.
> The first would be to take one of our *very* precious bits from xpidl and tag
> methods as "error expected". nsISupports.QueryInterface would get such a tag
> (so would a number of necko interfaces). Callers would be expected to rethrow
> the exception if they don't want to handle it.
>
> [details folded]
>
> I think this is actually relatively easy to implement. It would of course add
> overhead to any exceptions that try to cross the js/xpconnect boundary. But, we
> could probably change the consoleService to use be called via this hook, which
> might improve error reporting.
> 

I agree that we all will benefit from better error reporting. But at the moment we have no error reporting at all. Taking into consideration pre-release urge, taking a small non-regressing patch (attachment 307692 [details] [diff] [review]) seem a right thing to do. Once fixed, error reporting can be gradually improved in less urgent environment of Mozilla 2.

Josh, can I hope to get r+ from you on my patch?

Comment 37

[Mike Shaver (:shaver -- probably not reading bugmail closely)]

I think we want this for beta5 -- going to be a lot harder for ext devs to get their bugs sorted out without reliable error reporting. :(

Comment 38

[Sergey Yanovich]

Blake, ping.

Comment 39

[Johnny Stenback (:jst)]

Ben will be looking into what we want to do about this as neither Blake nor myself have had time to look at this in depth yet.

Comment 40

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

Attachment: Opt-in exceptions, v1

Ok, so here's our basic problem: Some folks think that throwing exceptions is a perfectly valid way to communicate with C++, others try to avoid any unhandled exceptions and want to know if any make it back to C++. There is no way to consolidate those opinions, and we've argued back and forth about it many times already. A functional Components.resultCode might make this situation better, but that's been broken for far too long to hope we'll see it fixed in the next week.

So after talking with lots of people about this here's my plan:

1. Some exceptions should *always* be logged.
   - Exceptions that XPConnect generates itself (like "No such method"
     exceptions and the like.
   - Unhandled exceptions in event handlers, callbacks, etc. Those are
     usually implemented as a simple anonymous function and passed as
     [function]-annotated arguments in idl.
2. Special-casing certain exceptions is uncool. Some folks agree that
   throwing a failure nsresult should exempt it from the console, others
   disagree.
3. The only way to please everyone is to allow the behavior to be changed
   at runtime. Normal users don't benefit from console spam so the
   default behavior is to suppress all other (see 1) error messages that
   cross from JS to C++.

This patch enforces 1, eliminates special-cased exceptions a in 2, and adds two ways to activate full error logging for developers for 3. You can use an environment variable to catch errors at component registration (hardly ever necessary I'd hope) or a preference to handle everything else.

I'm not really all that happy about this patch, but as jst has pointed out, all of our options kinda suck at this point.

Comment 41

[Sergey Yanovich]

(In reply to comment #40)
> Ok, so here's our basic problem: Some folks think that throwing exceptions is a
> perfectly valid way to communicate with C++, others try to avoid any unhandled
> exceptions and want to know if any make it back to C++. There is no way to
> consolidate those opinions, and we've argued back and forth about it many times
> already. A functional Components.resultCode might make this situation better,
> but that's been broken for far too long to hope we'll see it fixed in the next
> week.

There is a difference between throwing an exception, and allowing an unhandled exception to return to C++.

With this patch and reportAllJSExceptions set to true, junk NS_ERROR_FAILUREs from nsIHandlerService::getTypeFromExtension reappear in the console. They have been hidden since bug 393627.

I am not a "normal" user, but I also rightfully object console noise. When I am searching console output for a cause of failure, I am much more happier to see a single report, than to scroll through a thousand messages, generated in the normal path of execution.

> 1. Some exceptions should *always* be logged.
>    - Exceptions that XPConnect generates itself (like "No such method"
>      exceptions and the like.
>    - Unhandled exceptions in event handlers, callbacks, etc. Those are
>      usually implemented as a simple anonymous function and passed as
>      [function]-annotated arguments in idl.

We have 2 ways to create a JS exception: by throw, and by xpconnect error. The latter case should always be reported, the former produces console noise and is subject to discussion.

Ben, could you comment on my attachment 307692 [details] [diff] [review]? It may be a better default behavior (your 1.). It can also be expanded to address 'throw' (your 3.) at run-time.

Comment 42

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

Attachment: Opt-in exceptions, v2

Ok, this is the new one. I'll comment a bit more in a sec, just wanted to get this posted before I have to run.

Comment 43

[Sylvain Pasche]

I wrote a chrome test some times ago. Do you want to include it in your patch or should it be reviewed separately? I did not check how it behaves with your new patch. It is not complete, there could be tests for chrome and/or the new reportAllJSExceptions property.

Comment 44

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

(In reply to comment #41)
> There is a difference between throwing an exception, and allowing an unhandled
> exception to return to C++.

Perhaps my language was misleading, but we never report exceptions when they are thrown. We're only talking about when uncaught exceptions make it back to C++.

> I am not a "normal" user, but I also rightfully object console noise.

If it was simple to tell the difference between "noise" and "errors" then we wouldn't be in this situation to begin with :)

> When I am searching console output for a cause of failure, I am much
> more happier to see a single report, than to scroll through a thousand
> messages, generated in the normal path of execution.

As are we all. If you want to filter the console or remove duplicates then you should probably install an extension or file another bug. The code we're discussing is only concerned with reporting a single exception - it has no idea how many have passed before or how many are on the way.

> Ben, could you comment on my attachment 307692 [details] [diff] [review]?

We're not going to blindly ignore some exception for two reasons:

1. Your proposal makes a completely arbitrary distinction between throwing "wrapped" exceptions and primitives.
2. We have lots of code in JS that throws nsresults, and most of it was written back when uncaught exceptions were guaranteed to show up in the console. We will miss bugs if we continue to ignore those errors (as we are currently missing some).

So this latest patch works like before in that xpconnect and [function] method exceptions are always reported. That should take care of the majority (if not all) of the content->chrome exceptions sicking was talking about in comment 23.

This patch now causes all exceptions (primitive and otherwise) to be reported if we have unwound to the base of the JS stack (the first -> below), and we will no longer report exceptions if another JS frame is on the stack (the third -> below) assuming that the C++ in the middle may handle the exception. We will continue to report all exceptions if the preference/environment variable is set to aid debugging.

Stack:  C++ -> JS -> C++ -> JS

Incidentally, this takes care of most of the nsIHandlerService errors.

Comment 45

[Sergey Yanovich]

I agree that we need "dom.reportAllJSExceptions" pref, but I still think, we can fine-tune default behavior. I'll upload an updated patch shortly.

Comments on attachement (id=314218)
-JSBool xpc_IsReportableErrorCode(nsresult code)
-{

xpc_IsReportableErrorCode was guarding against weird error codes since the beginning of time :). Its removal will open console doors to exotic NS_ERROR_FACTORY_REGISTER_AGAIN and NS_BASE_STREAM_WOULD_BLOCK. 

+    // Always want to report forced exceptions or exceptions that we set
+    // ourselves (no such method, etc.).
+    PRBool reportable = aForceReport || xpc_exception;
+

This check is wrong for 2 reasons:
First, xpc_exception is not a boolean value. This is a minor problem.

Second, a valid xpconnect exception may be hidden in a wrapper behind pending JS exception. This is the same thing, that you are checking with aForceReport.

+        while((fp = JS_FrameIterator(cx, &fp)))
+        {
+            if(!JS_IsNativeFrame(cx, fp))
+            {
+                onlyNativeStackFrames = PR_FALSE;
+                break;
+            }
+        }
+        reportable = onlyNativeStackFrames;
+    }

I doubt this will ever set 'reportable' to true: JS context of the main chrome window or default command line handler will almost always be the top frame.

+        // May also want to check if we're moving from content->chrome and force
+        // a report in that case.
+

We are never hitting this path from chrome. Chrome JS executes directly in the context of the window. So it is not wrapped in xpconnect, and exceptions from there are logged directly from JS.

(In reply to comment #44)
> 1. Your proposal makes a completely arbitrary distinction between throwing
> "wrapped" exceptions and primitives.

This is not true. With that patch, all possible execution paths in JSValToXPCException end up reporting an error to console, *except* when we have a thrown nsresult (like in "throw Components.results.NS_ERROR_FAILURE;"). This is exactly the objective of bug 393627.

> 2. We have lots of code in JS that throws nsresults, and most of it was written
> back when uncaught exceptions were guaranteed to show up in the console. We
> will miss bugs if we continue to ignore those errors (as we are currently
> missing some).

I agree with this. This is why we need "dom.reportAllJSExceptions" pref.

> So this latest patch works like before in that xpconnect and [function] method
> exceptions are always reported.

I spent a bunch of time inside js/src with gdb to find out, that these two cases are, in fact, one. When a callback function is passed from JS, a xpconnect wrapper is created. This is the reason, why the patch for bug 393627 affects event listeners.

Comment 46

[Sergey Yanovich]

Attachment 314218 [details] [diff] also regresses bug 401735.

Comment 47

[Sergey Yanovich]

Attachment: aggregate fix

This patch does the following:
1. Reverts changes to js/src/xpconnect/src/xpcwrappedjsclass.cpp by bug 393627.

2. Adds preference and envvar from attachment 314218 [details] [diff] [review].

3. Checks that the exception being considered is a plain nsresult error value (and not a wrapped xpconnect exception).

4. Unconditionally logs exception, if it is *not* a plain nsresult. Logs plain nsresult, if 'dom.reportAllJSExceptions' or the envvar is set to true.

5. Adds Sylvain's test from attachment 308393 [details] [diff] [review].

Some additional information:
* the patch passes the test;
* cases handled by aForceReport parameters from attachment 314218 [details] [diff] [review] are handled by always logging wrapped xpconnect exceptions.
* check for JS frame hierarchy is not included on the assumption from comment 45. This can be easily restored, if need be.

Comment 48

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

Attachment: Opt-in exceptions, v3

(In reply to comment #45)
> xpc_IsReportableErrorCode was guarding against weird error codes since the
> beginning of time :). 

My understanding was that we were slowly removing those errors. We may need to add this back regardless, but in my own testing I only ever see those errors on a fresh profile (yay fastload) so I don't think it's that big of a deal.

> First, xpc_exception is not a boolean value. This is a minor problem.

That's not a problem at all, I'm testing to see if it is null.

> Second, a valid xpconnect exception may be hidden in a wrapper behind pending
> JS exception. This is the same thing, that you are checking with aForceReport.

Interesting. I was talking about exceptions set on the XPCContext, but you're right, there are others that we probably want too. I can fix that really easily.

> I doubt this will ever set 'reportable' to true

Testing wins over doubts, and my testing has shown that this does indeed work as expected.

> JS context of the main chrome window or default command line handler will
> almost always be the top frame.

Actually, in all of the cases where I'm currently hitting this code that isn't true. And as I've said, in those cases we do *not* want to report the error. We hope that code in the middle will handle the exception appropriately. We only want to report uncaught exceptions that make it all the way back past the base JS frame.

> We are never hitting this path from chrome.

I think you're confused. This call happens right after we've just crossed back from JS -> C++. It can happen in both chrome and content security contexts.

> This is not true. With that patch, all possible execution paths in
> JSValToXPCException end up reporting an error to console, *except* when we have
> a thrown nsresult (like in "throw Components.results.NS_ERROR_FAILURE;")

With attachment 307692 [details] [diff] [review] (which I was commenting on) you were only reporting "wrapped" errors and ignoring all others. Your latest patch, attachment 314319 [details] [diff] [review], does only ignore nsresults. Again, both solutions are completely arbitrary.

> I agree with this. This is why we need "dom.reportAllJSExceptions" pref.

I think we can do better for default behavior by only reporting exceptions at the base JS frame. That has the effect of possibly hiding the true location of an inner JS exception, and so the pref can be used to reveal that information. This keeps the "noise" down for regular users and doesn't require developers to go out of their way to see serious errors. It's not perfect for everyone, but I believe it is the best compromise we can manage at this point.

> I spent a bunch of time inside js/src with gdb to find out, that these two
> cases are, in fact, one. When a callback function is passed from JS, a
> xpconnect wrapper is created. This is the reason, why the patch for bug 393627
> affects event listeners.

Well, maybe we're confusing terms. Before I was saying "xpconnect errors" to mean "exceptions on the XPCContext", so that wouldn't be true. Now I'm expanding that definition to include any errors within XPConnect's range of error codes, so it's still not true :) There are several cases where xpcconvert will not assign an XPConnect error code to an exception.

Anyway, this patch now grabs all the errors in XPConnect's range and also ignores NS_NOINTERFACE messages because jst and sicking say that GetInterface is just as special as QueryInterface... I hate adding that check here, but time is short.

I'm going to do tests as a separate patch if we need it because we already have some tests for this stuff that we might be able to expand. Not sure, I haven't looked yet.

Comment 49

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

Comment on attachment 314319 [details] [diff] [review]
aggregate fix

Yeah, we've decided not to ignore simple nsresults, see previous comment.

Comment 50

[Sergey Yanovich]

(In reply to comment #48)
> Actually, in all of the cases where I'm currently hitting this code that isn't
> true. And as I've said, in those cases we do *not* want to report the error. We
> hope that code in the middle will handle the exception appropriately. We only
> want to report uncaught exceptions that make it all the way back past the base
> JS frame.

If it almost always evaluate to false, it makes sense to drop it. This cycle may affect Ts. Since exceptions are routinely used in normal path of executions, we probably want their handling to be as fast as possible.

> > We are never hitting this path from chrome.
> 
> I think you're confused. This call happens right after we've just crossed back
> from JS -> C++. It can happen in both chrome and content security contexts.

I am not confused. Chrome code is run in the context of the window, so chrome exceptions are handled differently in spidermonkey. F.e., "throw Components.results.NS_ERROR_FAILURE;" has always been reported from chrome, though it is suppressed in xpconnect wrapped JS since bug 393627 landed.

> > This is not true. With that patch, all possible execution paths in
> > JSValToXPCException end up reporting an error to console, *except* when we have
> > a thrown nsresult (like in "throw Components.results.NS_ERROR_FAILURE;")
> 
> With attachment 307692 [details] [diff] [review] (which I was commenting on) you were only reporting
> "wrapped" errors and ignoring all others. Your latest patch, attachment 314319 [details] [diff] [review],
> does only ignore nsresults. Again, both solutions are completely arbitrary.

Both variants do exactly the same thing by default. The first case used some help from xpc_IsErrorReportable(), the second didn't. And their behavior was matching the goal stated in bug 393627. The latter patch ignores thrown nsresults by default, and report them, when 'dom.reportAllJSErrors' is set to true. All other exceptions are always reported by it.

Your patch treats thrown nsresults in *exactly* the same manner. In addition, it extends this treatment to exceptions, which contain valuable data, when a ready nsIException object is stored not in xpconnect, but in a JS exception wrapper object. Failure to log this type of exceptions is exactly the behavior, for which this bug is filed. And to fix that, your patch checks type of the caller, and logs by default, if the caller is a function.

Comparing these two approaches, I just don't understand the sense, that you put in the word 'arbitrary' in this situation.
 
(In reply to comment #49)
> Yeah, we've decided not to ignore simple nsresults, see previous comment.

So be it. The new pref is enough for me, actually. I am using a custom unit test framework (xpunit), which among other things listens to JS console. The framework checks an accounting xul app, so error tolerance is zero. The whole code builds with -Werror, and there should be no runtime errors/test failures. Both false positives and false negatives are a real pain. So I clearly feel the difference between signal and noise.

With the new pref, I can do any handling, I want, inside my own code.

Comment 51

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

Attachment: Final patch

Ok, cool, I think we finally have a solution that will work for most folks. This is the final patch and it now includes Sylvain's chrome tests. Unfortunately the other tests I was hoping to use haven't been updated much since 1999 and are not part of the build currently :(

Comment 52

[Johnny Stenback (:jst)]

Comment on attachment 314723 [details] [diff] [review]
Final patch

r+sr=jst!

Comment 53

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

Comment on attachment 314723 [details] [diff] [review]
Final patch

This restores some error messages that have been lost for a long time. It doesn't change any exception propagation so there should be almost no risk of regressions.

Comment 54

[Mike Beltzner [:beltzner, not reading bugmail]]

Comment on attachment 314723 [details] [diff] [review]
Final patch

a1.9=beltzner

Comment 55

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

Fixed on trunk. I'll file some followups on the new errors we're now seeing in the console on startup.

Comment 56

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

Bug 428358 and bug 428362 were filed.

Comment 57

[Sergey Yanovich]

As bug 428362 shows, a simple setTimeout was enough to turn logging off. This bug is worth 'relnote' keyword and some comments to extension developers in release notes.

Comment 58

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

Thanks Sergey, you're absolutely correct and I forgot to add the needed keywords.

Comment 59

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

Filed bug 428402 as well.

Comment 60

[Masayuki Nakano [:masayuki] (he/him)(JST, +0900)(away 4/27 - 5/6)]

The test failed on Linux after my checked-in, but before that backed-out, the test is passed. Isn't there a random failure bug?

> *** 27 INFO Running chrome://mochikit/content/chrome/content/events/test/test_bug415498.xul...
> *** 28 INFO PASS | One error message should be reported
> *** 29 INFO PASS | message should be about NS_ERROR_DOM_HIERARCHY_REQUEST_ERR exception
> *** 30 ERROR FAIL | One error message should be reported | got 2, expected 1 | chrome://mochikit/content/chrome/content/events/test/test_bug415498.xul
> 
> *** 31 ERROR FAIL | message should be about NS_ERROR_DOM_HIERARCHY_REQUEST_ERR exception | Didn't expect -1, but got it. | chrome://mochikit/content/chrome/content/events/test/test_bug415498.xul
> 
> *** 32 INFO PASS | Some other exception was thrown than what we expected!

Comment 61

[Sylvain Pasche]

The test listens for console messages and makes assertions about how many it received. The test could fail if something else raised an exception while the test is running.
Two things could be done:
1) Add more logging information to see what unexpected exception is caught during the test
2) Filter the exceptions to discard the ones with nsIScriptError::sourceName not matching the document being loaded

Comment 62

[Sylvain Pasche]

Attachment: log exception for debugging

Apparently the nsIScriptError::sourceName property is empty for the second exception, so I can't do the filtering based on this.
Logging the exception should give more information about what's happening.

Comment 63

[Serge Gautherie (:sgautherie)]

Ben,
I filed bug 428537 to track revealed errors/exceptions ;-)

***

Masayuki, Sylvain,
May I suggest to move your new issue to a separate bug ?
(and make it block bug 428537)
Then, request approval for your patch.

***

Obviously, the patch had the desired effect ;->

V.Fixed.

Comment 64

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

(In reply to comment #63)
> I filed bug 428537 to track revealed errors/exceptions

Thanks, but I really don't see any need to open a tracking bug for them. I only mentioned those bugs in comments here for the curious. Those bugs exist independently of whether or not we report them.

Comment 65

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

Attachment: Fix random test failure [checked in]

I think this should fix up our test failure. Sicking?

Comment 66

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

Comment on attachment 315143 [details] [diff] [review]
Fix random test failure [checked in]

Landed the fix for randomly failing tests.

Comment 67

[Serge Gautherie (:sgautherie)]

(In reply to comment #64)
> (In reply to comment #63)
> > I filed bug 428537 to track revealed errors/exceptions
> 
> Thanks, but I really don't see any need to open a tracking bug for them. I only
> mentioned those bugs in comments here for the curious. Those bugs exist
> independently of whether or not we report them.

I agree with you:
the "tracking" bug is mainly "for the curious";
as a side effect, it could allow to get an estimate of what we were missing,
or notice regressions (in this unlikely event).

Comment 68

[pal-moz]

http://forums.mozillazine.org/viewtopic.php?p=3336715#3336715
is
bug 428600 ? or bug 395228 ?

Comment 69

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

Adding late-compat keyword here as well. This won't actually break any extensions (the only difference is whether or not we report errors that already existed), but the evang folks might want to make some noise about this change all the same.

Comment 70

[Mike Shaver (:shaver -- probably not reading bugmail closely)]

Yeah, for sure.  Thanks for the note.

Comment 71

[Eric Shepherd [:sheppy]]

Documented here:

http://developer.mozilla.org/en/docs/Exception_logging_in_JavaScript

Comment 72

[Sylvain Pasche]

I saw something very similar recently: bug 502718.