Expose an API to track DOM Promise which are left uncaught

RESOLVED FIXED in Firefox 40

Status

()

defect
RESOLVED FIXED
5 years ago
4 months ago

People

(Reporter: Yoric, Assigned: Yoric)

Tracking

(Blocks 2 bugs)

unspecified
mozilla40
Points:
---
Dependency tree / graph
Bug Flags:
in-testsuite +

Firefox Tracking Flags

(firefox40 fixed)

Details

Attachments

(1 attachment, 12 obsolete attachments)

46.65 KB, patch
Yoric
: review+
Details | Diff | Splinter Review
No description provided.
Posted patch Possible API (obsolete) — Splinter Review
If this seems ok to you, I can start looking at how to implement this.
Attachment #8505639 - Flags: feedback?(bzbarsky)
Component: General → DOM
Product: Add-on SDK → Core
Summary: Expose DOM Promise which are left uncaught → Expose an API to track DOM Promise which are left uncaught
Comment on attachment 8505639 [details] [diff] [review]
Possible API

Per offline discussion, looks like a good start.
Attachment #8505639 - Flags: feedback?(bzbarsky) → feedback+
Blocks: 939636
No longer blocks: 856878
Posted patch Implementation (obsolete) — Splinter Review
Here we go for a v1.
A few changes since our conversations:
- there is no reason to keep the promise ID only for these callbacks, so I moved it to PromiseDebugging;
- I feel that the data argument passed to callbacks is better served by using PromiseDebugging inspect the Promise itself and decide what to capture.

Note the comments in PromiseDebugging.webidl for an oddity: I have found a case in which `onConsumed` is called without `onLeftUncaught` being called.
Attachment #8505639 - Attachment is obsolete: true
Attachment #8506960 - Flags: review?(bzbarsky)
Comment on attachment 8506960 [details] [diff] [review]
Implementation

I'm sorry for the horrible lag on this review.  :(

>+++ b/dom/promise/Promise.cpp
> NS_IMPL_CYCLE_COLLECTION_UNLINK_BEGIN(Promise)
>+tmp->mResult = JS::UndefinedValue();

Please indent by 2.

> Promise::AppendCallbacks(PromiseCallback* aResolveCallback,
>+    // Note that we may not have had the opportunity to call
>+    // RunResolveTask() yet, so we may never have called

If RunResolveTask hasn't happened, our mState won't be PromiseState::Rejected, right?  So I don't think we need to worry about this case.

>@@ -1140,58 +1106,28 @@ Promise::RunResolveTask(JS::Handle<JS::V
>-    mFeature = new PromiseReportRejectFeature(this);

We can remove the PromiseReportRejectFeature class altogether, right?

>+++ b/dom/promise/Promise.h
>+  bool IsLastInChain() {

Please make that a const method.

>+++ b/dom/promise/PromiseDebugging.cpp
>+    sIDPrefix.Append(NS_LITERAL_STRING("."));

  sIDPrefix.Append('.');

>+PromiseDebugging::AddUncaughtRejectionObserver(GlobalObject&,
>+                                              UncaughtRejectionObserver& aObserver)

The indentation here is weird.  Tabs or something?

>+  nsRefPtr<UncaughtRejectionObserver> observer = &aObserver;
>+  observers.AppendElement(observer.forget());

You can just do:

  observers.AppendElement(&aObserver);

>+PromiseDebugging::RemoveUncaughtRejectionObserver(GlobalObject&,
>+  for (size_t i = 0; i < observers.Length(); ++i) {

Why not just:

  observers.RemoveElement(&aObserver);

?

>+PromiseDebugging::FlushUncaughtRejections()

>+  AutoJSAPI api;

This seems to be unused.

>+      observers[j]->OnLeftUncaught(*promise, rv);

So this looks like it will possibly notify OnConsumed for promises for which we never notified OnLeftUncaught (because they stopped being last between calling AddUncaughtRejection and this function being called), right?

Ideally we'd flag a promise at the point when we call OnLeftUncaught on it and only do OnConsumed for the ones that actually did OnLeftUncaught.

r=me with the above bits fixed.

We still need to actually have devtools add such an observer to replace the reporting we have right now that this patch is removing, right?
Attachment #8506960 - Flags: review?(bzbarsky) → review+
(In reply to Boris Zbarsky [:bz] from comment #4)
> We still need to actually have devtools add such an observer to replace the
> reporting we have right now that this patch is removing, right?

Right. Nick, do you feel we need to do that immediately or that we can afford to land this patch first? If this does not involve delving too deep into devtools code, I can add that observer, but I'll need some guidance.
Flags: needinfo?(nfitzgerald)
If we don't integrate this new hook w/ devtools, and land now, can we leave the old mechanism and only remove that once devtools uses the new hook? If so, then +1 to landing now. If not, then I think we should also do the devtools integration here.

This API is the stream of "unhandled rejected promise" and "oops, nevermind, that promise got handled now" events, right?

I think what we would want to do is (with links to code to modify and/or crib from):

1. Create a new listener service for these events in the server.

   http://dxr.mozilla.org/mozilla-central/source/toolkit/devtools/server/actors/webconsole.js#530
   http://dxr.mozilla.org/mozilla-central/source/toolkit/devtools/webconsole/utils.js#1384

2. When the frontend attaches to the server, tell it to start the new listener service:

   http://dxr.mozilla.org/mozilla-central/source/browser/devtools/webconsole/webconsole.js#4981

3. When the frontend gets unhandled-promise-rejection events, output a message to the console:

   http://dxr.mozilla.org/mozilla-central/source/browser/devtools/webconsole/webconsole.js#4942
   http://dxr.mozilla.org/mozilla-central/source/browser/devtools/webconsole/webconsole.js#1345
   http://dxr.mozilla.org/mozilla-central/source/browser/devtools/webconsole/webconsole.js#2054

4. When the frontend gets a nevermind-promise-was-handled, find the corresponding unhandled-promise-rejection message's dom node and make it faded out and strike-through'd. We don't do anything like this now, so you'll have to implement more machinery for this part yourself.
Flags: needinfo?(nfitzgerald)
Posted patch 1. Implementation, v2 (obsolete) — Splinter Review
Applied feedback, rebased.
Attachment #8506960 - Attachment is obsolete: true
Attachment #8515234 - Flags: review+
(In reply to Nick Fitzgerald [:fitzgen] from comment #6)
> If we don't integrate this new hook w/ devtools, and land now, can we leave
> the old mechanism and only remove that once devtools uses the new hook? If
> so, then +1 to landing now. If not, then I think we should also do the
> devtools integration here.
> 
> This API is the stream of "unhandled rejected promise" and "oops, nevermind,
> that promise got handled now" events, right?
> 
> I think what we would want to do is (with links to code to modify and/or
> crib from):
> [...]

That sound was my internal scope creep alert. I suspect that if I go and perform those changes, some people might be unhappy because my other Q4 priorities will go unfulfilled.

I'll find a way to put both mechanisms.
(that is, the stream and the old behavior)

I'll then proceed with the testsuite and I'll let you handle the devtools part.

Is that ok with you, Nick?
Flags: needinfo?(nfitzgerald)
Maybe me, maybe someone else, sometime in the future...

Sounds good to me.
Flags: needinfo?(nfitzgerald)
Posted patch 1. Implementation, v3 (obsolete) — Splinter Review
I realize that I had forgotten to attach the tests.
Attachment #8515234 - Attachment is obsolete: true
Attachment #8515319 - Flags: review+
Boris?
Flags: needinfo?(bzbarsky)
Planning to get to this this afternoon; I was out on Monday and most of Tuesday.
Flags: needinfo?(bzbarsky)
Comment on attachment 8515286 [details] [diff] [review]
2. Keeping in place the old mechanism until we have a replacement

r=me.  Thank you for doing this, and sorry for the long weekend lag.  :(
Attachment #8515286 - Flags: review?(bzbarsky) → review+
Posted patch Implementation (obsolete) — Splinter Review
Folded the patch, fixed trivial issues.
Attachment #8515286 - Attachment is obsolete: true
Attachment #8515319 - Attachment is obsolete: true
Attachment #8525505 - Flags: review+
I have been tracking the pdf.js bustage for a few days.
Apparently, it crashes between the time we dispatch the instance of `FlushRejections` and the time we execute it. Neither `Cancel()` nor the `WorkerFeature` I have added experimentally gets executed.

Still investigating.
Additionally, even if I patch PromiseDebugging to not add Promise to the array of uncaught rejections, we manage to execute FlushRejections, but we still crash:

16:00:36 WARNING - PROCESS-CRASH | chrome://mochitests/content/browser/browser/extensions/pdfjs/test/browser_pdfjs_navigation.js | application crashed [@ nsTArrayInfallibleResult nsTArray_base<nsTArrayInfallibleAllocator, nsTArray_CopyWithMemutils>::SwapArrayElements<nsTArrayInfallibleAllocator>(nsTArray_base<nsTArrayInfallibleAllocator, nsTArray_CopyWithMemutils>&, unsigned long, unsigned long)]

https://treeherder.mozilla.org/ui/logviewer.html#?job_id=3358207&repo=try

Note that this array is an empty arrays.

In other words, it seems rather clear to me that there is a problem with the way we use CycleCollectedJSRuntime. Perhaps we fail to initialize it, perhaps we use it after it is initialized, or perhaps we need to declare some cycles.

Any suggestion, Boris?
Flags: needinfo?(bzbarsky)
Look at WorkerThreadPrimaryRunnable::Run.  WorkerJSRuntime goes out of scope before ScheduleDeletion is called, so your CycleCollectedJSRuntime is null here.
This makes sense, although I'm not sure where how you link this to ScheduleDeletion. In other words, CycleCollectedJSRuntime is clearly not the right data structure for me. However, I believe that we do not have any kind of TLS for heap-allocated stuff, nor do I see how we could implement one.

Option 1: If CycleCollectedJSRuntime is `null`, give up. Unfortunately, we will lose error reports. Probably not that bad, but still rather unsatisfying.
Option 2: Attach the data to WorkerPrivate instead of CycleCollectedJSRuntime.
Option 3: Attach it to the Runtime.
Option 4: Add yet another object for the purpose of storing the data.

I think that the least bad options are 1 and 2.

Any preference, Boris? Kyle?
(In reply to David Rajchenbach-Teller [:Yoric] (away until November 17th - use "needinfo") from comment #23)
> This makes sense, although I'm not sure where how you link this to
> ScheduleDeletion.

From the stack you're crashing at.

> Option 1: If CycleCollectedJSRuntime is `null`, give up. Unfortunately, we
> will lose error reports. Probably not that bad, but still rather
> unsatisfying.
> Option 2: Attach the data to WorkerPrivate instead of
> CycleCollectedJSRuntime.
> Option 3: Attach it to the Runtime.
> Option 4: Add yet another object for the purpose of storing the data.
> 
> I think that the least bad options are 1 and 2.
> 
> Any preference, Boris? Kyle?

Option 2 is the best, I think.
CycleCollectedJSRuntime really should be the right data structure, since once that's gone we won't be able to properly manage the lifetime of UncaughtRejectionObserver (since that's a cycle-collected object).  In other words, if any of this stuff outlives the CycleCollectedJSRuntime, we have a serious problem as far as I can see.  For example, calling Release on an UncaughtRejectionObserver will crash after CycleCollectedJSRuntime is gone, as far as I can tell (via calling NS_CycleCollectorSuspect3 which touches sCollectorData which is nulled out in nsCycleCollector_forgetJSRuntime called from ~CycleCollectedJSRuntime).

I assume ScheduleDeletion is relevant in that it calls ClearMainEventQueue, which will process runnables.  And if the runnable that calls FlushUncaughtRejections is one of the pending runnables, we'll process it after we kill off the CycleCollectedJSRuntime.

So I think the only reasonable options are comment 23 option 1 and making sure that our FlushRejections runnable keeps the CycleCollectedJSRuntime alive while it's alive.  Kyle, is that the sort of thing that adding a feature for the lifetime of that runnable would do?
Flags: needinfo?(bzbarsky) → needinfo?(khuey)
Actually, in my latest versions, FlushRejections::DispatchNeeded() creates a WorkerFeature when it is called the first time. In this test, according to the logs, the WorkerFeature is never even notified before the crash.
Let's talk about this in person in PDX next week.
This is what I attempted to fix the issue.

STR:
- launch the tests of browser/extensions/pdfjs/test in RELEASE (part of mochitest-browser-chrome-2);
- almost-perma orange, although not always in the same test;

As we discussed, the call to `worker->AddFeature` in `FlushRejections::ThreadInit` returns `false`.
Attachment #8532655 - Flags: feedback?(khuey)
Kyle, this is a blocker for a big ongoing refactoring. Can you suggest a solution?
Flags: needinfo?(khuey)
I discussed this with bent today and we think that AddFeature should probably only be rejecting calls once we get to the Killing state.  Can you make that change and see if it fixes your patch?  If so, I'll write up a patch and audit the relevant code to see if there are any other issues.
Flags: needinfo?(khuey) → needinfo?(dteller)
Works for me.
Flags: needinfo?(dteller)
I spun that off to bug 1119360.
No longer depends on: 1119360
Flags: needinfo?(khuey)
What's the status of this bug?
(In reply to Boris Zbarsky [:bz] from comment #35)
> Blocked on bug 1119360, no?

Heh, wondered if it was still a hard dependency.

But I may ask for the status of that bug as well.
Comment on attachment 8532655 [details] [diff] [review]
Attempting to block shutdown with a WorkerFeature

We moved fixing this off to the other bug.
Attachment #8532655 - Flags: feedback?(khuey)
After investigating the test failures, I've changed my mind, and don't think we should allow WorkerFeatures to be added in the close handler.

So let's recap the requirements here.  Do we need to be able to check for uncaught rejections after we have GCd everything?  Or only after we've stopped processing events?
Flags: needinfo?(dteller)
The latter should be fine.  We want to check after there is no chance of anyone calling catch() on promises, but no more event processing should be able to guarantee that, right?
(In reply to Not doing reviews right now from comment #39)
> The latter should be fine.  We want to check after there is no chance of
> anyone calling catch() on promises, but no more event processing should be
> able to guarantee that, right?

It should, yes.  In that case we can hook in somewhere in http://hg.mozilla.org/mozilla-central/annotate/a9aff724afc7/dom/workers/WorkerPrivate.cpp#l4689.
Yes, "no more event processing" looks correct. Do workers have an equivalent of `onbeforeunload`, or `onunload`? If so, we'll need to triple-check that we get them correctly.

Patching `DoRunLoop` to integrate Promise seems a little weird, but I can work with that.
Flags: needinfo?(dteller)
It's a little weird, yes, but the existing primitive (WorkerFeature) is used for "I want to do some async stuff" more than "I want to block shutdown", and having to change all of the uses of it to handle the case where you can't do any more async stuff seems worse than hardcoding this in somewhere.

Promises already have interesting interactions with the event loops anyways.

The close handler is the worker equivalent of onunload.
Posted patch 1. Implementation, v3 (obsolete) — Splinter Review
Unbitrotten.
Attachment #8525938 - Attachment is obsolete: true
Attachment #8576621 - Flags: review+
Posted patch 2. Flushing durint shutdown (obsolete) — Splinter Review
Attachment #8532655 - Attachment is obsolete: true
Comment on attachment 8576622 [details] [diff] [review]
2. Flushing durint shutdown

A big part of that patch is removing a dependency from CycleCollectedJSRuntime towards DOM Promise, as this dependency doesn't build anymore.

Since bz is not taking reviews, Kyle, it's your turn.
Attachment #8576622 - Flags: review?(khuey)
Comment on attachment 8576622 [details] [diff] [review]
2. Flushing durint shutdown

Review of attachment 8576622 [details] [diff] [review]:
-----------------------------------------------------------------

r- for the DOM_PROMISE_DEPRECATED_REPORTING issue, but it looks pretty good.

::: dom/promise/Promise.h
@@ +32,2 @@
>  #include "mozilla/dom/workers/bindings/WorkerFeature.h"
> +#endif // defined(DOM_PROMISE_DEPRECATED_REPORTING)

I don't really understand what's going on here, since this is a duplicate of what's immediately below it.

::: xpcom/base/CycleCollectedJSRuntime.h
@@ +298,5 @@
> +  // from xpcom to dom/promise, but they can really only have a single concrete
> +  // type.
> +  nsTArray<nsCOMPtr<nsISupports /* Promise */>> mUncaughtRejections;
> +  nsTArray<nsCOMPtr<nsISupports /* Promise */ >> mConsumedRejections;
> +  nsTArray<nsRefPtr<nsISupports /* UncaughtRejectionObserver */ >> mUncaughtRejectionObservers;

Why isn't this one nsCOMPtr too?
Attachment #8576622 - Flags: review?(khuey) → review-
(In reply to Kyle Huey [:khuey] (khuey@mozilla.com) from comment #46)
> I don't really understand what's going on here, since this is a duplicate of
> what's immediately below it.

Ah, right, merge error. Fixed.

> 
> ::: xpcom/base/CycleCollectedJSRuntime.h
> @@ +298,5 @@
> > +  // from xpcom to dom/promise, but they can really only have a single concrete
> > +  // type.
> > +  nsTArray<nsCOMPtr<nsISupports /* Promise */>> mUncaughtRejections;
> > +  nsTArray<nsCOMPtr<nsISupports /* Promise */ >> mConsumedRejections;
> > +  nsTArray<nsRefPtr<nsISupports /* UncaughtRejectionObserver */ >> mUncaughtRejectionObservers;
> 
> Why isn't this one nsCOMPtr too?

Well, I cannot QI to UncaughtRejectionObserver, I assume because the class has been generated from a "callback interface" by webidl, so making it a nsCOMPtr doesn't very useful. I can change that if you prefer.
/r/6033 - Bug 1083361 - Exposing a PromiseDebugging API to monitor uncaught DOM Promise;r=bz
/r/6035 - Bug 1083361 - Handling Promise rejections that arrive during worker shutdown;r=khuey
/r/6037 - Bug 1083361 - Applied feedback;r=khuey

Pull down these commits:

hg pull review -r 583de7bcfb1693625ddf2b48e3392470393df44e
Attachment #8583782 - Flags: review?(khuey)
Comment on attachment 8583782 [details]
MozReview Request: bz://1083361/Yoric

/r/6033 - Bug 1083361 - Exposing a PromiseDebugging API to monitor uncaught DOM Promise;r=bz
/r/6035 - Bug 1083361 - Handling Promise rejections that arrive during worker shutdown;r=khuey
/r/6037 - Bug 1083361 - Applied feedback;r=khuey

Pull down these commits:

hg pull review -r 583de7bcfb1693625ddf2b48e3392470393df44e
https://reviewboard.mozilla.org/r/6035/#review5289

::: dom/promise/PromiseDebugging.h
(Diff revision 1)
> +}

Does this actually build on all platforms?  Forward declarations in anonymous namespaces didn't work a couple years ago.

::: dom/promise/PromiseDebugging.cpp
(Diff revision 1)
> -  NS_IMETHOD Run()
> +  static void FlushSync() {

nit: \n between functions

::: dom/promise/PromiseDebugging.cpp
(Diff revision 1)
> +  NS_IMETHOD Run() {

here too

::: dom/promise/PromiseDebugging.cpp
(Diff revision 1)
> +

nit: extraneous \n being added.

::: xpcom/base/CycleCollectedJSRuntime.h
(Diff revision 1)
> +  nsTArray<nsRefPtr<nsISupports /* UncaughtRejectionObserver */ >> mUncaughtRejectionObservers;

It should be nsCOMPtr<nsISupports>, like the others.

::: dom/promise/PromiseDebugging.cpp
(Diff revision 1)
> +

nit: extraneous \n

::: dom/webidl/PromiseDebugging.webidl
(Diff revision 1)
> -  static void removeUncaughtRejectionObserver(UncaughtRejectionObserver o);
> +  static boolean removeUncaughtRejectionObserver(UncaughtRejectionObserver o);

Is the return value here actually being used?
https://reviewboard.mozilla.org/r/6035/#review5717

> Is the return value here actually being used?

Yes, in tests.

> Does this actually build on all platforms?  Forward declarations in anonymous namespaces didn't work a couple years ago.

Ah, you're right, this doesn't build on all platforms. I've moved the class out of the anonymous namespace.
Posted patch promise.diff (obsolete) — Splinter Review
Posted patch Merged patchSplinter Review
Try: https://treeherder.mozilla.org/#/jobs?repo=try&revision=cec42b4f4017
Attachment #8576621 - Attachment is obsolete: true
Attachment #8576622 - Attachment is obsolete: true
Attachment #8583782 - Attachment is obsolete: true
Attachment #8591003 - Attachment is obsolete: true
Attachment #8583782 - Flags: review?(khuey)
Attachment #8591004 - Flags: review+
Awesome.  So now we need to switch the devtools UI to this new setup and then we can remove the GC-dependent old setup?  David, do you know whether there's a bug tracking that work?
Flags: needinfo?(dteller)
https://hg.mozilla.org/mozilla-central/rev/331d71cabe1e
Status: NEW → RESOLVED
Closed: 4 years ago
Flags: in-testsuite+
Resolution: --- → FIXED
Target Milestone: --- → mozilla40
(weird, this needinfo doesn't show up in my dashboard)

I do not have plans to work on the debugger side at the moment – I'm not familiar with that code, and I'm already working on several high-priority features/refactorings about:performance. Nick, could you handle this (or find someone to do it)?
Flags: needinfo?(dteller) → needinfo?(nfitzgerald)
(In reply to David Rajchenbach-Teller [:Yoric] (use "needinfo") from comment #57)
> (weird, this needinfo doesn't show up in my dashboard)
> 
> I do not have plans to work on the debugger side at the moment – I'm not
> familiar with that code, and I'm already working on several high-priority
> features/refactorings about:performance. Nick, could you handle this (or
> find someone to do it)?

What is the scope of the devtools UI changes required here? Is this to show the "x promise was rejected and uncaught" message in the console, and then gray it out or strike it out or hide it if the promise rejection is later handled? Or is this pause on uncaught rejection in the debugger?
Flags: needinfo?(nfitzgerald)
Well, the scope is filing both, implementing the former to begin with :)
Depends on: 1157714
Component: DOM → DOM: Core & HTML
You need to log in before you can comment on or make changes to this bug.