Open Bug 1550923 Opened 5 years ago Updated 2 years ago

JavaScript Error: "2147500037" in basic open/close browser mochitest with no actionable information to debug or diagnose the root cause

Categories

(Core :: JavaScript Engine, defect, P3)

defect

Tracking

()

People

(Reporter: kats, Unassigned)

References

Details

Add the following test as a browser mochitest:

add_task(async function test_main() {
  let win = await BrowserTestUtils.openNewBrowserWindow();
  await BrowserTestUtils.closeWindow(win);
  SimpleTest.ok(true, "yay");
})

Expected: passes with no errors.

Actual:

 0:07.75 TEST_START: gfx/layers/apz/test/mochitest/browser_simple.js
 0:07.75 INFO Entering test bound test_main
 0:08.07 INFO Console message: [JavaScript Error: "2147500037" {file: "resource:///modules/ContentSearch.jsm" line: 364}]
_processEventQueue/this._currentEventPromise<@resource:///modules/ContentSearch.jsm:364:12
async*_processEventQueue@resource:///modules/ContentSearch.jsm:369:7
receiveMessage@resource:///modules/ContentSearch.jsm:184:10
receiveMessage@resource:///modules/BrowserGlue.jsm:591:30
MessageListener.receiveMessage*init@resource:///modules/BrowserGlue.jsm:606:19
BG__beforeUIStartup@resource:///modules/BrowserGlue.jsm:1075:15
BG_observe@resource:///modules/BrowserGlue.jsm:759:14

 0:08.07 INFO Console message: [JavaScript Error: "2147500037" {file: "resource:///modules/ContentSearch.jsm" line: 364}]
_processEventQueue/this._currentEventPromise<@resource:///modules/ContentSearch.jsm:364:12
async*_processEventQueue@resource:///modules/ContentSearch.jsm:369:7
receiveMessage@resource:///modules/ContentSearch.jsm:184:10
receiveMessage@resource:///modules/BrowserGlue.jsm:591:30
MessageListener.receiveMessage*init@resource:///modules/BrowserGlue.jsm:606:19
BG__beforeUIStartup@resource:///modules/BrowserGlue.jsm:1075:15
BG_observe@resource:///modules/BrowserGlue.jsm:759:14

 0:08.18 GECKO(27434) JavaScript error: , line 0: uncaught exception: 2147500037
 0:08.17 INFO Console message: [JavaScript Error: "uncaught exception: 2147500037"]
 0:08.31 PASS yay - 
 0:08.31 FAIL A promise chain failed to handle a rejection: 2147500037 - stack: (No stack available.)
Rejection date: Fri May 10 2019 21:32:57 GMT-0400 (Eastern Daylight Time) - false == true - JS frame :: resource://testing-common/PromiseTestUtils.jsm :: assertNoUncaughtRejections :: line 257
Stack trace:
resource://testing-common/PromiseTestUtils.jsm:assertNoUncaughtRejections:257
chrome://mochikit/content/browser-test.js:Tester_execTest/<:1140
chrome://mochikit/content/browser-test.js:Tester_execTest:1144
chrome://mochikit/content/browser-test.js:nextTest/<:1005
chrome://mochikit/content/tests/SimpleTest/SimpleTest.js:SimpleTest.waitForFocus/waitForFocusInner/focusedOrLoaded/<:803
 0:08.31 INFO Leaving test bound test_main
 0:08.32 GECKO(27434) MEMORY STAT vsizeMaxContiguous not supported in this build configuration.
 0:08.32 GECKO(27434) MEMORY STAT | vsize 2815MB | residentFast 313MB | heapAllocated 131MB
 0:08.32 TEST_END: Test OK. Subtests passed 1/2. Unexpected 1

Even though this is not fission-specific, it is blocking my attempts to add some browser mochitests for fission-related codepaths which in turn is slowing down fission-related fixes. I need to use the BrowserTestUtils.openNewBrowserWindow API to open a fission-enabled window.

Fission Milestone: --- → ?
Depends on: 1550467

I've just been trying this on my MacBook Pro 10.14 and I can't reproduce this. I have tried both opt and debug artefact builds using latest mozilla-central (revision fa3cfee27619ddc9bcbcf70555bda4eb1e815146).

I added a new file (browser/components/search/test/browser/browser_window.js) as a browser chrome mochitest and pasted the test in, then built and ran it and also tried it with --verify

Could you take another look please?

It would probably help to know which event type it is trying to process here: https://searchfox.org/mozilla-central/rev/8308eb7ea14318f53b55f3289c2bb9b712265318/browser/modules/ContentSearch.jsm#362

Although now I look at it a bit more, I don't see why that would cause an uncaught error - seeing as there's a try/catch around it that is obviously handling it.

Flags: needinfo?(kats)

I'm able to 100% consistently reproduce on Linux, opt non-artifact build (mozconfig is here) using mozilla-central revision 7c1fce459b7aa (which is from Friday). Just to be sure I did a fresh checkout on that rev and used the same steps you described (pasted the test to browser/components/test/browser/browser/browser_window.js and ran it).

You're right that it looks like any exceptions should be getting caught, so maybe the stack that's getting dumped is just a red herring and the real error is somewhere else? At any rate the message type that's causing the stack dump is a Message with the msg.data.type being GetState for the first one and GetStrings for the second one.

I can debug a bit more later today.

So the exception that's getting logged here seems to be getting thrown from this line and is indeed getting caught just fine. If I comment out the handler on this line obviously the exceptions don't fire, but I still get the "promise chain failed to handle a rejection" error. So yeah, it looks like the ContentSearch error is a red herring, and the real error is not really logged (coming from JavaScript error: , line 0: uncaught exception 2147500037). How does one go about debugging this? I'm not so familiar with debugging JS errors in the browser front end that are buried in the middle of a nest of promise chains.

Flags: needinfo?(kats)
Blocks: 1550467
No longer depends on: 1550467

I tried using rr to try and find out what's going on but really I'm just flailing about and I shouldn't be. I'm going to move this into the JS component because I think the JS engine or something thereabout should be doing a better job of giving me actionable information.

Javascript engine folks: summary here is that I have a reproducible scenario where I run a simple browser-chrome mochitest and it fails due to a JavaScript error: , line 0: uncaught exception 2147500037 as best I can tell, but I have no idea what the root cause is because there's no stack, JS line number, or any other sort of useful information. Help on how to debug this would be much appreciated.

Component: Search → JavaScript Engine
Product: Firefox → Core
Summary: JavaScript Error: "2147500037" {file: "resource:///modules/ContentSearch.jsm" line: 364} in basic open/close browser mochitest → JavaScript Error: "2147500037" in basic open/close browser mochitest with no actionable information to debug or diagnose the root cause

(In reply to Mark Banner (:standard8) from comment #2)

I have tried both opt and debug artefact builds using latest mozilla-central (revision fa3cfee27619ddc9bcbcf70555bda4eb1e815146).

Also for the record I rebuilt at latest m-c tip (hg rev cb5734727c0a) and it still happens for me (still Linux opt build).

I see this error when I run ./mach test browser/components/sessionstore/test/browser_354894_perwindowpb.js on a local m-c build (non-artifact) b0645d43f221 on Mac OSX 10.14.4.

It doesn't make the run fail right away, but it does after a while. Please take a look at https://gist.github.com/mikedeboer/0f472b598e9bb738d8c48e5bc7584351 for more details.

So something is throwing Cr.NS_ERROR_FAILURE (2147500037) here, with no stack to be found.

Shouldn't bug 1543751 have helped here by always capturing a stack, even when throwing a primitive?

OK, so this turned out to be the SearchService init that threw this error, due to the build system not correctly processing this change:

addons.webextension.amazondotcom@search.mozilla.org ERROR Loading extension 'amazondotcom@search.mozilla.org': Loading locale file _locales/de/messages.json: Error: Error while loading 'file:///Users/mikedeboer/Projects/mozilla-central/obj-x86_64-apple-darwin18.5.0/dist/NightlyDebug.app/Contents/Resources/browser/chrome/browser/search-extensions/amazondotcom/_locales/de/messages.json' (NS_ERROR_FILE_NOT_FOUND)

So a clobber will fix this - I confirmed this on my machine. Bug 1552120 has been filed to fix the incremental build/ symlink issue.

For future reference, how did you track that down?

...And is there a way to reproduce the situation where an error is reported, but with no useful stack, and it's super hard to track down? This is frustrating—the engine already does a ton of work to make sure error information and async stacks are propagated. Maybe there is just a place in xpconnect where an error is printed but the extra information isn't.

Flags: needinfo?(mdeboer)
Priority: -- → P1
No longer blocks: 1550467
Depends on: 1553283

I think we caught the issue because the previous lines in the the test log showed the files had been removed, and we guessed a bit.

What I've just done is to take another look at the search service which is a Javascript XPCOM component. If search initialisation fails, then we currently effectively do this (actual code):

throw Cr.NS_ERROR_FAILURE

I've just tried swapping it to:

throw Components.Exception("Search initialisation failed", Cr.NS_ERROR_FAILURE);

and now in the test output I get:

 0:09.71 GECKO(30429) JavaScript error: resource://gre/modules/SearchService.jsm, line 1711: NS_ERROR_FAILURE: Search initialisation failed
 0:09.71 INFO Console message: [JavaScript Error: "NS_ERROR_FAILURE: Search initialisation failed" {file: "resource://gre/modules/SearchService.jsm" line: 1711}]

Bug 1536556 is soon going to land that will add linting to pick up the obvious cases for these, but it wouldn't be able to pick up this case.

I'll fix these in bug 1553283... leaving this for any js engine investigation.

Flags: needinfo?(mdeboer)

(In reply to Kartikaya Gupta (email:kats@mozilla.com) from comment #1)

Even though this is not fission-specific, it is blocking my attempts to add some browser mochitests for fission-related codepaths which in turn is slowing down fission-related fixes. I need to use the BrowserTestUtils.openNewBrowserWindow API to open a fission-enabled window.

:kats, is this still a blocker for fission fixes or not?

Flags: needinfo?(kats)

Not any more, no. As Mike pointed out in comment 10 a clobber build fixed the problem.

Flags: needinfo?(kats)
Fission Milestone: ? → ---

Jason, should we close this bug based on comment 10? I changed the priority 3 for now since we are not working on it.

Flags: needinfo?(jorendorff)
Priority: P1 → P3

The remaining bug here is that if JS code throws a number, at least in some places, no stack is printed to the console.

It's uncertain where the bug belongs. Maybe XPConnect. P3 is fine.

Flags: needinfo?(jorendorff)
Severity: normal → S3
You need to log in before you can comment on or make changes to this bug.