405769 - all C.results in js modules are ignored by jsconsole

Status: RESOLVED DUPLICATE of bug 415498

(Core :: XPConnect, defect)

Description

[Sergey Yanovich]

User-Agent:       Mozilla/5.0 (X11; U; Linux i686; en-US; rv:1.8.1.8) Gecko/20071004 Iceweasel/2.0.0.8 (Debian-2.0.0.8-1)
Build Identifier: cvs20071128

When a js XPCOM calls another XPCOM, and that call fails, the failure is not logged to console. See attached test case for more details.

Reproducible: Always

Steps to Reproduce:
1. cd dist/bin
2. patch -p1 < testcase.diff
3. ./firefox --jsconsole

Actual Results:  
nothing happens

Expected Results:  
NS_NOINTERFACE exception is logged

This is a follow-up of bug 393627 -> bug 401735 chain.

I understand that the chain aims at reducing console noise by hiding thrown exceptions with a registered nsresult code. However, as a by-product, it suppresses not just thrown, but *all* errors and exceptions with a registered nsresult code.

As a result, debugging js modules becomes extremely difficult.

Comment 1

[Sergey Yanovich]

Attachment: testcase

Comment 2

[Sergey Yanovich]

Attachment: proposed fix

Described functionality is really essential for me. I see several possible solutions:
1. Use a special error code for thrown exceptions that are to be ignored (this patch).
2. Use a boolean pref to suppress/log C.results exceptions.
3. A mix of 1. and 2.

Comment 3

[Sergey Yanovich]

Yet another approach:
4. Use a special flag to suppress logging when the exception is thrown (by xor), and clear this flag (again by xor) in js/src/xpconnect/src/xpcwrappedjsclass.cpp::xpc_IsReportableErrorCode().

Comment 4

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

I don't agree with this fix. There is no reason to put the error in an error-console just because we're crossing a JS/C++ boundary. We don't log errors that go between JS components, or errors that go between C++ components, we only log errors that bubble up to top level without being handled. So why should boundaries between the two languages cause logging if it is later handled.

(sorry, this is a duped comment, but i wanted to make it in the right place)

Comment 5

[Sergey Yanovich]

(In reply to comment #4)
> I don't agree with this fix. There is no reason to put the error in an
> error-console just because we're crossing a JS/C++ boundary. We don't log
> errors that go between JS components, or errors that go between C++ components,
> we only log errors that bubble up to top level without being handled. So why
> should boundaries between the two languages cause logging if it is later
> handled.

Great. We are getting closer to the subject.

Let's agree on terminology first. I understand, that an exception (or an error) is handled, if it happens inside try {} catch {}, or try {} finally {} blocks. If an exception doesn't go to either catch {} or finally {} within the JSContext, it appears in, it is unhandled.

We want the rule above NOT to apply to exceptions, that are intentionally thrown, AND that has a numeric error code.

In practice, we hide all exceptions (and errors), that just have a numeric error code, effectively ignoring whether they are thrown deliberately. Here is an example:

I believe, this should be logged (case 1):

function a() { b(); }
function b() { throw Component.result.NS_ERROR_UNEXPECTED; }

But this should not (case 2):

function a() { try { b(); } catch (e) { throw e.result; } }
function b() { throw Component.result.NS_ERROR_UNEXPECTED; }

Currently, neither case is logged, before bug 393627 both case were logged. So we have a regression.

I agree, that proposed fix doesn't address the above example properly. It just reverses the things to pre-393627 state. But handling of 393627 is not acceptable for people like me, who actively debug js components using error console. So I am ready to accept any solution that will make case 2 above be reported.

Comment 6

[Sergey Yanovich]

(In reply to comment #5)
> So I am ready to accept any solution that will make case 2 above be
> reported.

I mean case 1, sorry.

Comment 7

[Dave Townsend [:mossop]]

I don't follow why you think the above two cases are different. Both are ultimately returning the NS_ERROR_UNEXPECTED result to the caller (in case 1 a is the caller, in case 2 you haven't elaborated on the caller).

There are thousands if not millions of places in the C++ code where such a result is returned and it never goes to the error console. About the best hope is that it is dumped to the system console in debug builds using the NS_ENSURE_SUCCESS macro.

Comment 8

[Sergey Yanovich]

(In reply to comment #7)
> I don't follow why you think the above two cases are different. Both are
> ultimately returning the NS_ERROR_UNEXPECTED result to the caller (in case 1 a
> is the caller, in case 2 you haven't elaborated on the caller).

Right, they both return the same error code. But they do it in a fundamentally different fashions. Case 1 don't expect b() to fail, while case 2 does. I have no interest in seeing case 2 in the console, since I know it may fail. But I NEED to see every case 1 failure!

> There are thousands if not millions of places in the C++ code where such a
> result is returned and it never goes to the error console. About the best hope
> is that it is dumped to the system console in debug builds using the
> NS_ENSURE_SUCCESS macro.

Dave, here you are contradicting yourself. Imaging that someone would land a patch that suppressed _part_, but not _all_ of NS_ENSURE_TRUE reports. You know that something is wrong, you are sure there must be an assertion, you stare at the console and see nothing. I can't imaging anything more frustrating.

The same thing bug 393627 did to js error console.

I am developing a quite sophisticated XR app. I have a unit test suite for it. I use shell console to check for C++ assertions, and js console for js assertions.  After bug 393627 was landed js console went silent. After bug 401735 landed, I can get, what I want, if I wrap each js line of code in "try {} catch(e) {throw e.message;}", which is non-sense.

Comment 9

[Dave Townsend [:mossop]]

(In reply to comment #8)
> (In reply to comment #7)
> > I don't follow why you think the above two cases are different. Both are
> > ultimately returning the NS_ERROR_UNEXPECTED result to the caller (in case 1 a
> > is the caller, in case 2 you haven't elaborated on the caller).
> 
> Right, they both return the same error code. But they do it in a fundamentally
> different fashions. Case 1 don't expect b() to fail, while case 2 does. I have
> no interest in seeing case 2 in the console, since I know it may fail. But I
> NEED to see every case 1 failure!

No the caller behaves differently, not the method called. The method returning the error has no idea whether what it is returning will be handled or not.

> > There are thousands if not millions of places in the C++ code where such a
> > result is returned and it never goes to the error console. About the best hope
> > is that it is dumped to the system console in debug builds using the
> > NS_ENSURE_SUCCESS macro.
> 
> Dave, here you are contradicting yourself. Imaging that someone would land a
> patch that suppressed _part_, but not _all_ of NS_ENSURE_TRUE reports. You know
> that something is wrong, you are sure there must be an assertion, you stare at
> the console and see nothing. I can't imaging anything more frustrating.
> 
> The same thing bug 393627 did to js error console.

Not really I think. There are also plenty of cases in the C++ where the macros aren't used and nothing is logged. The JS error console is user facing, we should not be dumping expected error conditions to it. If your errors are not expected then is there a particular reason you are returning known error codes?

> I am developing a quite sophisticated XR app. I have a unit test suite for it.
> I use shell console to check for C++ assertions, and js console for js
> assertions.  After bug 393627 was landed js console went silent. After bug
> 401735 landed, I can get, what I want, if I wrap each js line of code in "try
> {} catch(e) {throw e.message;}", which is non-sense.

Maybe the answer here it to dump js exceptions that are currently suppressed to the debug error console.

Comment 10

[Sergey Yanovich]

(In reply to comment #9)
> No the caller behaves differently, not the method called. The method returning
> the error has no idea whether what it is returning will be handled or not.

I mean, that nothing must be logged in b() and case2-a(), but case1-a() must log an unhandled exception.

> Not really I think. There are also plenty of cases in the C++ where the macros
> aren't used and nothing is logged. The JS error console is user facing, we
> should not be dumping expected error conditions to it. If your errors are not
> expected then is there a particular reason you are returning known error codes?

Absolutely, if we don't want to see assertion, we use:
if (NS_FAILED(rv)) return rv;

, and otherwise:
NS_ENSURE_TRUE(rv, rv);

I am talking about about situations when NS_ENSURE_* selectively logs nothing. Which is what we have in js console after bug 393627.

> Maybe the answer here it to dump js exceptions that are currently suppressed to
> the debug error console.

Proposed fix is doing just that.

Comment 11

[Dave Townsend [:mossop]]

(In reply to comment #10)
> (In reply to comment #9)
> > No the caller behaves differently, not the method called. The method returning
> > the error has no idea whether what it is returning will be handled or not.
> 
> I mean, that nothing must be logged in b() and case2-a(), but case1-a() must
> log an unhandled exception.

Without knowing the caller to case 2 how can you say whether or not the exception from a() should be reported or not?
> > Maybe the answer here it to dump js exceptions that are currently suppressed to
> > the debug error console.
> 
> Proposed fix is doing just that.

Is there some other patch then, since the patch attached here does not do that.

Comment 12

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

As you say, we don't want to report an error if it happens inside a try/catch block. What if the try/catch block lives in C++? (the syntax is a bit different, but the functionality is exactly the same).

That is exactly what we're having here. The C++ code catches the error thrown from JS and handles it.

In other cases the C++ will simply pass the error through and it can be reported higher up in the call chain.

Comment 13

[Sergey Yanovich]

Comment on attachment 290520 [details] [diff] [review]
proposed fix

(In reply to comment #5)
(case 1):

> function a() { b(); }
> function b() { throw Component.result.NS_ERROR_UNEXPECTED; }
 
(case 2):
 
> function a() { try { b(); } catch (e) { throw e.result; } }
> function b() { throw Component.result.NS_ERROR_UNEXPECTED; }
 
> Currently, neither case is logged, before bug 393627 both case were logged. So
> we have a regression.

The last sentence is wrong, and seems to cause lots of confusion. I'll try to correct it and make clearer:

O - Old, as it was before bug 393627
N - Now, as it is now, after bug 401735
I - Ideal, as it can be :)

+ - exception is logged
- - exception is not logged

case1-a(): O+ N- I+
case1-b(): O+ N- I-
case2-a(): O+ N- I-
case2-b(): O+ N- I-

The table clearly shows that the current state of affairs is much closer to an ideal, than the previous one. So opposition to reverting the things is reasonable.

However, I don't give up my efforts to make the world a bit better. I noticed, that there is an   XPCOM object for exception in case1-a(), and a JS Object in all other cases. I'll try to leverage that.

Comment 14

[Sergey Yanovich]

Bug 415498 is a reduced case of this bug.

Comment 15

[Damon Sicore (:damons)]

-.  We're not doing the wrong thing here, but we decided to change what we log.  Won't block the release.

Comment 16

[Sergey Yanovich]

Please take bug 405769 comment 13 into consideration, when choosing a solution to bug 415498.

Comment 17

[John J. Barton]

(In reply to comment #5)
I want to encourage work on error handling in Firefox because currently its not good.  However the current discussion has me confused.

> I believe, this should be logged (case 1):
> 
> function a() { b(); }
> function b() { throw Component.result.NS_ERROR_UNEXPECTED; }
> 
> But this should not (case 2):
> 
> function a() { try { b(); } catch (e) { throw e.result; } }
> function b() { throw Component.result.NS_ERROR_UNEXPECTED; }

These cases both throw exception and both should result in the an unhandled exception message. The first should have a stack with a()/b(), the second should have a stack with just b(). Why won't both be reported?

Comment 18

[Sergey Yanovich]

(In reply to comment #17)
> (In reply to comment #5)
> I want to encourage work on error handling in Firefox because currently its not
> good.  However the current discussion has me confused.
> 
> > I believe, this should be logged (case 1):
> > 
> > function a() { b(); }
> > function b() { throw Component.result.NS_ERROR_UNEXPECTED; }
> > 
> > But this should not (case 2):
> > 
> > function a() { try { b(); } catch (e) { throw e.result; } }
> > function b() { throw Component.result.NS_ERROR_UNEXPECTED; }
> 
> These cases both throw exception and both should result in the an unhandled
> exception message. The first should have a stack with a()/b(), the second
> should have a stack with just b(). Why won't both be reported?

function b() case is the only way for a js component to return a non-NS_OK result. The number of js components is constantly growing, so does the the number of return logged. However bad is the practice of using using exception to convey information, it is widely popular and must be taken into account.

A compromise can be on the proposal in comment 13. Junk is hidden, but unhandled cases are still reported. I've filed a patch for that in bug 415498.

Comment 19

[John J. Barton]

I guess these samples are incomplete?

You mean:

function c() {  service.a();  }
--- xpcom ---
function a() { try { b(); } catch (e) { throw e.result; } }
function b() { throw Component.result.NS_ERROR_UNEXPECTED; }

? AND in additional xpcom (or xpconnect whatever that layer is called) has the bug that it does not pass exceptions correctly?

Only after c() can an exception be unhandled and thus cause an error in the console.  Everything else is a bug.  

I don't get comment 13 because both case 1 and 2 throw exceptions. So the ideal and only reasonable case is both show up on the console as unhandled exceptions.

Comment 20

[Sergey Yanovich]

(In reply to comment #19)
> I guess these samples are incomplete?
> 
> You mean:
> 
> function c() {  service.a();  }
> --- xpcom ---
> function a() { try { b(); } catch (e) { throw e.result; } }
> function b() { throw Component.result.NS_ERROR_UNEXPECTED; }

a() and b() are assumed to be from different modules.

If they are from the same module, similar behavior can also be achieved. We may check that exception is thrown from the top frame to hide it, and log it otherwise. But in the view of JS exception costs, it isn't worth the effort.