Cf. https://taskcluster-artifacts.net/SUzToUJzTumRHTqrmUS5Mg/0/public/logs/live_backing.log from just now on autoland.

This is getting annoying as a red herring and we should work out what it is and how to fix it / make it go away.

:jryans, do you know anything about this, from your time with PromiseTestUtils ? Where should I start looking?

I don't recall seeing this error before, but let's see what we can find...

Line 112 is:

    PromiseDebugging.addUncaughtRejectionObserver(observer);
    Promise.reject(this._ensureDOMPromiseRejectionsProcessedReason);
    Services.tm.spinEventLoopUntil(() => observed); <--
    PromiseDebugging.removeUncaughtRejectionObserver(observer);

It's not clear to me if the error means an exception occurred in the observer, or if that was just what happened to be on the stack from some random code (since it spins an event loop). Maybe start by adding a try / catch in the observer and logging any caught errors, perhaps stringifying fields to get something better than [object Object].

It looks like the stack code is a red herring. A try catch in that code does nothing, and if I take out the spinEventLoopUntil, the error still shows up for URL "" (empty string), line 0. So I suspect that the spinny event loop is just leading to the error being given the stack info for the event loop spin, but that ultimately has nothing to do with where the error is happening.

I'll see if I can track down where we're running JS without a URL and throwing an error...

Alright, I've figured this out. What's being logged is, ironically, the "marker" promise that is on PromiseTestUtils itself.

That is, PromiseTestUtils defines an _ensureDOMPromiseRejectionsProcessedReason property, which is just a plain object, which it looks for in order to ensure all uncaught promise rejections have been reported. The combination of JS/DOM code still ends up logging this to the console and stderr.

Yoric, what's supposed to happen here? Just trying to add .catch() around the rejected promise from either of the uncaught promise rejection handlers does not stop JS/DOM from logging this.

If it's difficult to make this error go away completely, I'd suggest that instead of an empty object, we make the marker promise rejection a "real" error/exception object with a descriptive string so people don't think something's wrong with their test when they see it in the console/stderr.

Isn't this a bug in https://searchfox.org/mozilla-central/source/toolkit/modules/tests/modules/PromiseTestUtils.jsm#135-145 ?

Otherwise, what code exactly is logging the error?

(In reply to David Teller [:Yoric] (please use "needinfo") from comment #4)

Isn't this a bug in https://searchfox.org/mozilla-central/source/toolkit/modules/tests/modules/PromiseTestUtils.jsm#135-145 ?

Otherwise, what code exactly is logging the error?

No, the code you linked isn't what's logging that error. I was hoping you could tell me, you know more about the internals of promise rejection accounting than I do...

Well, normally, only code that calls PromiseDebugging.addUncaughtRejectionObserver should be able to log uncaught Promise rejections. There isn't much code that does this in our tree, so I assumed it was the logging inside PromiseTestUtils.onLeftUncaught. If not... that's weird.

Could it be this? https://searchfox.org/mozilla-central/source/testing/mochitest/tests/SimpleTest/SimpleTest.js#1647-1670

(In reply to David Teller [:Yoric] (please use "needinfo") from comment #6)

Well, normally, only code that calls PromiseDebugging.addUncaughtRejectionObserver should be able to log uncaught Promise rejections. There isn't much code that does this in our tree, so I assumed it was the logging inside PromiseTestUtils.onLeftUncaught. If not... that's weird.

Could it be this? https://searchfox.org/mozilla-central/source/testing/mochitest/tests/SimpleTest/SimpleTest.js#1647-1670

It's not. The error gets reported to the console from somewhere in C++ land, an ErrorReport instance gets created, etc. Pick literally any browser mochitest (I happened to use toolkit/mozapps/extensions/test/xpinstall/browser_privatebrowsing.js in case it matters) to reproduce this yourself.

Note that the error says "uncaught exception", not "uncaught rejection". AFAICT the js engine has just started treating rejections that aren't handled like exceptions and reporting them that way.

According to searchfox, there is only one occurrence of "uncaught exception" (with this capitalization) in m-c, and it's the one in SimpleTest. Odd.

C++ stack that reports this:

xul.dll!mozilla::dom::Promise::ReportRejectedPromise(JSContext * aCx, JS::Handle<JSObject *> aPromise) Line 534	C++
xul.dll!mozilla::dom::PromiseDebugging::FlushUncaughtRejectionsInternal() Line 276	C++
xul.dll!mozilla::dom::FlushRejections::Run() Line 61	C++
xul.dll!nsThread::ProcessNextEvent(bool aResult, bool *) Line 1214	C++
xul.dll!NS_ProcessNextEvent(nsIThread * aThread, bool) Line 486	C++
xul.dll!nsThreadManager::SpinEventLoopUntilInternal(nsINestedEventLoopCondition * aCondition, bool) Line 488	C++
[External Code]	
xul.dll!XPCWrappedNative::CallMethod(XPCCallContext & ccx, XPCWrappedNative::CallMode mode) Line 1149	C++
xul.dll!XPC_WN_CallMethod(JSContext * cx, unsigned int argc, JS::Value * vp) Line 943	C++
xul.dll!js::InternalCallOrConstruct(JSContext * cx, const JS::CallArgs & args, js::MaybeConstruct construct) Line 539	C++
xul.dll!InternalCall(JSContext * cx, const js::AnyInvokeArgs & args) Line 594	C++
xul.dll!Interpret(JSContext * cx, js::RunState & state) Line 0	C++
xul.dll!js::RunScript(JSContext * cx, js::RunState & state) Line 424	C++
xul.dll!js::InternalCallOrConstruct(JSContext * cx, const JS::CallArgs & args, js::MaybeConstruct construct) Line 567	C++
xul.dll!InternalCall(JSContext * cx, const js::AnyInvokeArgs & args) Line 594	C++
xul.dll!js::Call(JSContext * cx, JS::Handle<JS::Value> fval, JS::Handle<JS::Value> thisv, const js::AnyInvokeArgs & args, JS::MutableHandle<JS::Value> rval) Line 610	C++
xul.dll!JS_CallFunctionValue(JSContext * cx, JS::Handle<JSObject *> obj, JS::Handle<JS::Value> fval, const JS::HandleValueArray & args, JS::MutableHandle<JS::Value> rval) Line 2660	C++
xul.dll!nsXPCWrappedJS::CallMethod(unsigned short methodIndex, const nsXPTMethodInfo * info, nsXPTCMiniVariant * nativeParams) Line 978	C++
xul.dll!PrepareAndDispatch(nsXPTCStubBase * self, unsigned int methodIndex, unsigned __int64 * args, unsigned __int64 * gprData, double * fprData) Line 181	C++
[External Code]	
xul.dll!nsThread::ProcessNextEvent(bool aResult, bool *) Line 1214	C++
xul.dll!NS_ProcessNextEvent(nsIThread * aThread, bool) Line 486	C++
xul.dll!mozilla::ipc::MessagePump::Run(base::MessagePump::Delegate * aDelegate) Line 88	C++
xul.dll!MessageLoop::RunHandler() Line 309	C++
xul.dll!MessageLoop::Run() Line 291	C++

JS stack:

0 ensureDOMPromiseRejectionsProcessed() ["resource://testing-common/PromiseTestUtils.jsm":112:16]
    this = [object Object]
1 nextTest() ["chrome://mochikit/content/browser-test.js":911:28]
    this = [object Object]
2 testScope/test_finish/<() ["chrome://mochikit/content/browser-test.js":1732:24]
    this = [object ChromeWindow]
3 run() ["chrome://mochikit/content/browser-test.js":1647:8]
    this = [object Object]

(Previously: see comment #3)

We take the else if branch at https://searchfox.org/mozilla-central/rev/e5327b05c822cdac24e233afa37d72c0552dbbaf/dom/promise/Promise.cpp#529-535, and the tostring of the rejection/exception value that xpconnect/js come up with is "uncaught exception: Object".

Based on hg annotate, this looks like it changed in bug 1533308. :bhackett, can we somehow avoid the sentinel promise rejection that PromiseTestUtils uses, and/or make this exception code ignore it, too?

(In reply to David Teller [:Yoric] (please use "needinfo") from comment #9)

According to searchfox, there is only one occurrence of "uncaught exception" (with this capitalization) in m-c, and it's the one in SimpleTest. Odd.

I took your word for this, but I assume you included the trailing quotes or something?

https://searchfox.org/mozilla-central/rev/e5327b05c822cdac24e233afa37d72c0552dbbaf/js/src/js.msg#185

shows up when searching for "uncaught exception

(In reply to :Gijs (he/him) from comment #10)

We take the else if branch at https://searchfox.org/mozilla-central/rev/e5327b05c822cdac24e233afa37d72c0552dbbaf/dom/promise/Promise.cpp#529-535, and the tostring of the rejection/exception value that xpconnect/js come up with is "uncaught exception: Object".

Based on hg annotate, this looks like it changed in bug 1533308. :bhackett, can we somehow avoid the sentinel promise rejection that PromiseTestUtils uses, and/or make this exception code ignore it, too?

Hi, I don't think I understand what you're asking for. Bug 1533308 fixed an issue where uncaught rejections of non-error objects were never reported anywhere; before it landed the rejections would incorrectly lead to no output at all. It's pretty unfortunate that we only produce an "Object" string instead of toString'ing the object, but calling toString can produce side effects that are visible to the page.

(In reply to Brian Hackett (:bhackett) from comment #11)

(In reply to :Gijs (he/him) from comment #10)

We take the else if branch at https://searchfox.org/mozilla-central/rev/e5327b05c822cdac24e233afa37d72c0552dbbaf/dom/promise/Promise.cpp#529-535, and the tostring of the rejection/exception value that xpconnect/js come up with is "uncaught exception: Object".

Based on hg annotate, this looks like it changed in bug 1533308. :bhackett, can we somehow avoid the sentinel promise rejection that PromiseTestUtils uses, and/or make this exception code ignore it, too?

Hi, I don't think I understand what you're asking for. Bug 1533308 fixed an issue where uncaught rejections of non-error objects were never reported anywhere; before it landed the rejections would incorrectly lead to no output at all. It's pretty unfortunate that we only produce an "Object" string instead of toString'ing the object, but calling toString can produce side effects that are visible to the page.

So there's some mechanism by which uncaught rejections are meant to be logged on a per-test basis when running mochitests, which is in PromiseTestUtils (see comment #3, and https://searchfox.org/mozilla-central/rev/05db7b82d5a4adaa8b36ec6f4fd1715f6fd7885b/toolkit/modules/tests/modules/PromiseTestUtils.jsm#21-37 and https://searchfox.org/mozilla-central/rev/05db7b82d5a4adaa8b36ec6f4fd1715f6fd7885b/toolkit/modules/tests/modules/PromiseTestUtils.jsm#227-236 ). That adds a "marker" type uncaught rejection to allow the JS uncaught rejection handlers in the test framework to know that we're done reporting. This is now showing up as an uncaught exception/rejection in every test log ever, as a result of the native promise error reporting. I want it not to show up because it is confusing, repetitive and uninformative, and potentially makes it harder to find "real" uncaught rejections that also happen in the test, as they would generate the same messages.

Some options that I can come up with from my limited knowledge of what's going on here:

• add a way to tell the cpp js-exception-reporting code in question to not log this particular object
• add a cpp API to allow the PromiseTestUtils reporting to detect that all uncaught rejections have been reported in some way that doesn't involve having a marker/special uncaught rejection
• switch away from using PromiseTestUtils and have the cpp js-exception-reporting code integrate more directly with the test utils handling (which may or may not work if rejections from other promise implementations don't trigger the same reporting mechanisms, or there isn't a good way to distinguish when promises get rejected on a per-test basis or something, or not an easy way to interface with the test harness from where the JS-internal reporting code is at).

I don't mind which we go for, I just want the logspam to go away.

Thank you!

Backed out changeset 8f30450e231c (bug 1575306) for ESlint failure at PromiseTestUtils.jsm:99:31.

Backout: https://hg.mozilla.org/integration/autoland/rev/22ced1a079e01b240690d2c20f51c6bc15a8ac4a

Push that started the failures: https://treeherder.mozilla.org/#/jobs?repo=autoland&resultStatus=pending%2Crunning%2Csuccess%2Ctestfailed%2Cbusted%2Cexception&revision=8f30450e231c3866d852e77b5bc2b6df885cbc66&selectedJob=266913863

Failure log: https://treeherder.mozilla.org/logviewer.html#/jobs?job_id=266913863&repo=autoland&lineNumber=77

https://hg.mozilla.org/mozilla-central/rev/89526353707b