1398672 - Add test for better logging of exceptions/rejections from async event listeners

Status: REOPENED

(WebExtensions :: Developer Tools, defect, P3)

Description

[pea3nut]

Attachment: demo

User Agent: Mozilla/5.0 (Windows NT 10.0; WOW64; rv:52.0) Gecko/20100101 Firefox/52.0
Build ID: 20170802111520

Steps to reproduce:

// background script
chrome.browserAction.onClicked.addListener(async function(){
    //will be ignored in firefox, but chrome will throw an error to the global
    throw new Error('onClicked error!');
});


Actual results:

The event listener added in the WebExtensions background script, if the listener is an async function, the async function throws' error will be ignored


Expected results:

throw an error to the global, like chrome

Comment 1

[Kris Maglione [:kmag]]

When you throw an error within an async function, it turns into a rejected promise. Eventually, that shows up in the console as an unhandled rejection, but it's not a top-level error.

Comment 2

[pea3nut]

But it should not be displayed nothing in the console. and, why I can find error in promise executor?

// background script
chrome.browserAction.onClicked.addListener(async function(tab){
    console.log('onClicked start','async function');
    throw new Error('onClicked error in async function!');//will ignore
    console.log('onClickesssd end','async function');
});
chrome.browserAction.onClicked.addListener(function(tab){
    new Promise(function(){
        console.log('onClicked start','promise');
        throw new Error('onClicked error in promise!');//will show in browser console
        console.log('onClickesssd end','promise');
    });
});


output in console when I clicked browserAction button:

> onClicked start async function
> onClicked start promise
> Error: onClicked error in promise!

Comment 3

[pea3nut]

But it doesn't show any message when reel has some error fired in async-function. It makes many troubles in developing.

I don't try...catch this error or capture the rejected Promise, but got nothing message when error fired. Is that reasonable?

Comment 5

[Oriol Brufau [:Oriol]]

(In reply to Kris Maglione [:kmag] (long backlog; ping on IRC if you're blocked) from comment #1)
> Eventually, that shows up in the console as an unhandled rejection,

This is what I would want, but does not happen for me.

Comment 6

[Oriol Brufau [:Oriol]]

I'm reopening this bug, since the initial reason given to close it is factually false, and no new reason has been provided.
The rejected promise does NOT show up in the console as an unhandled rejection. This makes debugging very difficult.

Comment 7

[Luca Greco [:rpl] [:luca] [:lgreco]]

Needinfo-ed Tomislav to double-check if this is still happening after the recent rewrite of those internals.

Comment 8

[Oriol Brufau [:Oriol]]

Testing STR from bug 1442427, at some point uncaught exception: Object started appearing in the console, which was an improvement but not much useful either.
But then it was fixed in https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=0b523c5b6c4fc4117d16e3e17a9fe1de5e8967a5&tochange=ab07de86ac04c12998b9c7748db6fe67a285a345
Now I get TypeError: can't access property "error", browser.browserAction2 is undefined as expected.
But adding some test could be nice, to avoid regressions.

Comment 9

[Tomislav Jovanovic :zombie]

Thanks for checking Oriol. Agree about tests, though that makes it a P3.

Comment 10

[Myeongjun Go]

Hello Tomislav.
Could I ask about this issue?
According to the contents,
Does test case cover TypeError: can't access property "error", browser.browserAction2 is undefined?
So, Could you tell the properly test case location?

Comment 11

[Luca Greco [:rpl] [:luca] [:lgreco]]

See Comment 10 (it seems that the comment was meant to be a needinfo)

Comment 12

[Tomislav Jovanovic :zombie]

Could I ask about this issue?

Sure! If you're new to contributing to Mozilla, please take a look at https://wiki.mozilla.org/WebExtensions/Contribution_Onramp
And feel free to ask if you get stuck, using a needinfo as Luca did above.

Does test case cover TypeError: can't access property "error", browser.browserAction2 is undefined?

Yes, I guess the test could also include that check.

So, Could you tell the properly test case location?

I guess we can add a test to this file https://searchfox.org/mozilla-central/source/toolkit/components/extensions/test/xpcshell/test_ext_error_location.js

Comment 13

[Deepika Karanji]

Hello!
Can I work on this issue?
This is my second contribution though, so if this is open only for first timers, please let me know!

Comment 14

[Caitlin Neiman [:caitmuenster]]

Hey Deepika, welcome! Yes, please feel free to work on this bug. :) In case it's helpful, you might want to take a look at our WebExtensions-specific onboarding documentation https://wiki.mozilla.org/WebExtensions/Contribution_Onramp on how to get started. We recommend that you set up your development environment and verify that you can run tests before you change any code.

Comment 15

[Deepika Karanji]

Thanks, I have everything setup.
I tried to download the attachment linked by the reporter to reproduce the bug, but Firefox keeps preventing the installation of the unsigned add-on. What am I doing wrong?

Comment 16

[Oriol Brufau [:Oriol]]

You should be able to install it as a temporary add-on in about:debugging#/runtime/this-firefox.
Or you can also allow non-signed add-ons by setting xpinstall.signatures.required=false in about:config.

Comment 17

[Deepika Karanji]

Hi,
Apologies for the late update.

I have installed the extension, I tried running the given script in Comment 1 in the console, but I am getting this:

ReferenceError: chrome is not defined

I guessed that I haven't imported some chrome class or module for Firefox, and found this link: https://discourse.mozilla.org/t/chrome-is-not-defined/20938/14, where the folks say that I am supposed to install webextension-polyfill and add some code to the extension. Is this something that I should be doing to get the attached extension to work?

Comment 18

[Luca Greco [:rpl] [:luca] [:lgreco]]

(In reply to Deepika Karanji from comment #17)

Hi,
Apologies for the late update.

Hi,
Tomislav is away for a couple of days, and so I'm going to reply to this needinfo in the meantime.

I have installed the extension, I tried running the given script in Comment 1 in the console, but I am getting this:

ReferenceError: chrome is not defined

I guessed that I haven't imported some chrome class or module for Firefox, and found this link: https://discourse.mozilla.org/t/chrome-is-not-defined/20938/14, where the folks say that I am supposed to install webextension-polyfill and add some code to the extension. Is this something that I should be doing to get the attached extension to work?

The extension attached already contains the code in comment 1 (the reason why you get chrome is not defined is that the code snippet in comment 1 is meant to run in an extension page, e.g. in the background page as in the attached example, I suggest you to unpack the xpi file, which is basically a zip file, and look to the files into it and to the doc pages on MDN if you need more context about how the extensions work, have a good understanding about that is an important part of being able to fix a bug related to the extensions).

To reproduce the issue you should just need to:

• start Firefox
• install the attached extension
• open about:debugging in a new tab and click debug on that extension to open a devtools toolbox attached to that extension
• click the browser action that the extension has added to the Firefox toolbar

Comment 19

[Deepika Karanji]

Thank you, that was super helpful!

I followed the steps to reproduce the bug, and when I clicked on the extension (Browser Action button) in the last step, I got this in my console:

Unchecked lastError value: Error: Message manager disconnected 5 index.js:1780
onClicked start 6 background.js:2:13

This is what I found in background.js. As indicated, the error message was ignored

chrome.browserAction.onClicked.addListener(async function(tab){
    console.log('onClicked start');
    throw new Error('onClicked error!');//will ignore
    console.log('onClicked end');
});

However, I did not get the error that Oriol mentioned in their comment #8 : https://bugzilla.mozilla.org/show_bug.cgi?id=1398672#c8

Has something changed?
How is this bug different from Bug #1442427?
Also a little more information about what kind of test I should be writing would be helpful. Thanks!

Comment 20

[Luca Greco [:rpl] [:luca] [:lgreco]]

(In reply to Deepika Karanji from comment #19)

Thank you, that was super helpful!
...
However, I did not get the error that Oriol mentioned in their comment #8 : https://bugzilla.mozilla.org/show_bug.cgi?id=1398672#c8

Has something changed?

yes, over the last few months many parts of the WebExtensions framework internals is being changed to make it compatible with Fission (codename of the project that is introducing "Site Isolation" into Firefox), and so more changes are likely to have been landed between Oriol's comment and now.

How is this bug different from Bug #1442427?

Bug #1442427 was about the error not being logged, which has been fixed in the meantime and so it has been closed as a duplicate of this bug, which is about introducing an explicitly regression test (to make sure that the expected behavior doesn't regress again, which may have happened already in the meantime if the error isn't being logged anymore again).

Also a little more information about what kind of test I should be writing would be helpful. Thanks!

I'm routing the needinfo back to Tomislav, because he is back and he actively working of the changes needed to make the WebExtension framework internals compatible with Fission.

Comment 21

[Tomislav Jovanovic :zombie]

Sorry for the slow reply Deepika, but I had to investigate what's actually going on here, and it turns out this is actually not a good first bug, at least in the short term.

It seems this was (partially) regressed in bug 1588839, from this mozregression pushlog:
https://hg.mozilla.org/integration/autoland/pushloghtml?fromchange=ae020aef580f046a2e5277b726c3e2d4f50734e1&tochange=aa4e0207b45fbab40ab0d310b67630c6aced6859

The exception is still reported to the browser console (where Oriol probably saw it), but not to the devtools console when inspecting the extension. I'm not sure what are the requirements for it to show up there, but it probably has something to do with preserving the innerWindowId somewhere.

To make things even more complicated, we have a few other error handling and reporting bugs in progress.

I'm leaving a ni? for myself to look into this some more, and taking "good first bug" flag of temporarily.

Comment 22

[max]

Impact of this issue is not limited to logger, exceptions are ignored by event listeners as well

var windowOrSelf = typeof window === "undefined" ? self : window;
windowOrSelf.addEventListener(
    "error", e => console.error("error", e));
windowOrSelf.addEventListener(
    "unhandledrejection", e => console.error("unhandledrejection", e));

unhandledrejection listener may be used to notify user that something weird happened with add-on by e.g. adding badge to the browser action icon. Currently it requires adding as listener a synchronous wrapper that calls asynchronous event handler for user actions.