The goal here is to get a list that people can use to label runnables in order of urgency.

Using a pretty ugly patch, I've come up with this list: 1. PVsync::Msg_Notify This one will be hard to fix since it applies to whichever tab is in the foreground at the time it runs. #2. SelectorCacheKeyDeleter http://searchfox.org/mozilla-central/rev/790b2cb423ea1ecb5746722d51633caec9bab95a/dom/base/nsDocument.cpp#1241 #3. PCompositorBridge::Msg_DidComposite This one should be easier than Vsync to fix. The layers ID is part of the message, so we should be able to look this up when the message is received. We'll have to put a lock around sTabChildren though. #4. PCompositable::Msg___delete__ This doesn't seem to do very much. We might be able to get away with assigning it to no DocGroup (i.e., the SystemGroup, which doesn't exist yet). #5. nsHtml5SVGLoadDispatcher #6. LogMessageRunnable http://searchfox.org/mozilla-central/rev/790b2cb423ea1ecb5746722d51633caec9bab95a/xpcom/base/nsConsoleService.cpp#164 #7. NS_ProxyRelease/NS_ReleaseOnMainThread This could be tricky since it seems like it depends on what we're releasing. Some destructors might touch content and need to be in a certain DocGroup. #8. IDecodingTask::NotifyDecodeComplete / IDecodingTask::NotifyProgress http://searchfox.org/mozilla-central/rev/790b2cb423ea1ecb5746722d51633caec9bab95a/image/IDecodingTask.cpp#86 http://searchfox.org/mozilla-central/rev/790b2cb423ea1ecb5746722d51633caec9bab95a/image/IDecodingTask.cpp#53 #9. StorageNotifierRunnable http://searchfox.org/mozilla-central/rev/790b2cb423ea1ecb5746722d51633caec9bab95a/dom/storage/Storage.cpp#234 #10. PAPZ::Msg_RequestContentRepaint I think we can get the right TabChild via the APZChild's mController->mBrowser (assuming it's a ContentProcessController). I'll stop there for now.

This first patch just adds a bunch of runnable names.

This patch gives some somewhat generic names to a few dispatch sites where we would otherwise have nothing. We should remove these calls as we get better names for the runnables they're dispatching.

This patch allows us to "see through" a ThrottledEventQueue to get the name of the runnable inside it.

I've decided that we should have a standard way of naming runnables. For most runnables, let's name them according to their C++ class name, excluding namespaces unless the name is otherwise too general. For functions, we'll use the name of the function, including the class name but excluding namespaces. If you're okay with this, I'll update the wiki page on Quantum DOM.

The name of a setTimeout runnable will be the filename and line number of the script. This is bad if we want to report these to telemetry. So I've added an "anonymize" option to the nsITimer name callback.

The IPC message name is used as the runnable name for IPC runnables. When the name is "???", this is pretty ambiguous. I'd rather use a name that makes it clear that it's an IPC runnable.

Comment on attachment 8828163 [details] [diff] [review] anonymize nsITimer names Review of attachment 8828163 [details] [diff] [review]: ----------------------------------------------------------------- ::: dom/base/Timeout.cpp @@ +71,2 @@ > { > + if (aAnonymize) { Please add a brief comment here about filenames being sensitive. ::: xpcom/threads/nsTimerImpl.cpp @@ +547,5 @@ > if (mName.is<NameString>()) { > name = mName.as<NameString>(); > > } else if (mName.is<NameFunc>()) { > + mName.as<NameFunc>()(mITimer, false, mClosure, buf, buflen); I would write: > mName.as<NameFunc>()(mITimer, /* anonymize = */ false, mClosure, buf, buflen); Some people would insist on a two-value enum, but I won't. @@ +658,5 @@ > aName.Assign(mName.as<NameString>()); > } else if (mName.is<NameFunc>()) { > static const size_t buflen = 1024; > char buf[buflen]; > + mName.as<NameFunc>()(mITimer, true, mClosure, buf, buflen); Ditto.

Comment on attachment 8828164 [details] [diff] [review] change default IPC message name Review of attachment 8828164 [details] [diff] [review]: ----------------------------------------------------------------- ::: ipc/ipdl/ipdl.py @@ +219,5 @@ > return "%s::%s";""" % (protocol, msg, protocol, msg) > > print >>ipc_msgtype_name, """ > default: > + return "<unknown msg name>"; Could this be even clearer? Perhaps "<unknown IPC runnable msg name>"?

This is the hacky patch I used to find the filename and line number of many unlabeled dispatch sites.

(In reply to Bill McCloskey (:billm) from comment #1) > #4. PCompositable::Msg___delete__ > This doesn't seem to do very much. We might be able to get away with > assigning it to no DocGroup (i.e., the SystemGroup, which doesn't exist yet). PCompositable is removed in bug 1323957 > > #5. nsHtml5SVGLoadDispatcher > > #6. LogMessageRunnable > http://searchfox.org/mozilla-central/rev/ > 790b2cb423ea1ecb5746722d51633caec9bab95a/xpcom/base/nsConsoleService.cpp#164 > > #7. NS_ProxyRelease/NS_ReleaseOnMainThread > This could be tricky since it seems like it depends on what we're releasing. > Some destructors might touch content and need to be in a certain DocGroup. > > #8. IDecodingTask::NotifyDecodeComplete / IDecodingTask::NotifyProgress > http://searchfox.org/mozilla-central/rev/ > 790b2cb423ea1ecb5746722d51633caec9bab95a/image/IDecodingTask.cpp#86 > http://searchfox.org/mozilla-central/rev/ > 790b2cb423ea1ecb5746722d51633caec9bab95a/image/IDecodingTask.cpp#53 > > #9. StorageNotifierRunnable > http://searchfox.org/mozilla-central/rev/ > 790b2cb423ea1ecb5746722d51633caec9bab95a/dom/storage/Storage.cpp#234 > > #10. PAPZ::Msg_RequestContentRepaint > I think we can get the right TabChild via the APZChild's > mController->mBrowser (assuming it's a ContentProcessController). > > I'll stop there for now.

Comment on attachment 8828164 [details] [diff] [review] change default IPC message name Review of attachment 8828164 [details] [diff] [review]: ----------------------------------------------------------------- Like njn said maybe we can make it even more clearer. Consider that the default name is also used else where, I'd use "<unknown IPC msg name>".

This patch counts the number of times a runnable has run as well as how long it took. Benjamin, the histogram keys here are the names of runnables. They should be names of IPC messages and C++ runnable classes and methods. We want to collect this data so that we can compile a list of the runnables that run most often. We'll use this list to focus effort on these runnables when labeling them with DocGroups for Quantum DOM.

Comment on attachment 8828160 [details] [diff] [review] ThrottledEventQueue naming Review of attachment 8828160 [details] [diff] [review]: ----------------------------------------------------------------- ::: xpcom/threads/ThrottledEventQueue.cpp @@ +75,5 @@ > return NS_OK; > } > + > + NS_IMETHODIMP > + GetName(nsACString& aName) Looking at this I'm surprised we don't need to specify `overrides` here and on Run().

Just FYI, I added the concept of a SystemGroup in bug 1332494 and used it for the LogMessageRunnable.

Comment on attachment 8828159 [details] [diff] [review] give names to a few generic dispatch sites Review of attachment 8828159 [details] [diff] [review]: ----------------------------------------------------------------- ::: xpcom/threads/nsTimerImpl.cpp @@ +678,5 @@ > case CallbackType::Observer: > if (nsCOMPtr<nsINamed> named = do_QueryInterface(mCallback.o)) { > named->GetName(aName); > + } else { > + aName.AssignLiteral("Anonymous interface timer"); Nit: Perhaps call this "Anonymous observer timer" even though the distinction may not necessarily matter?

Comment on attachment 8828163 [details] [diff] [review] anonymize nsITimer names Review of attachment 8828163 [details] [diff] [review]: ----------------------------------------------------------------- ::: dom/base/Timeout.cpp @@ +71,3 @@ > { > + if (aAnonymize) { > + snprintf(aBuf, aLen, "setTimeout/Interval"); Drive-by: If you move this block below the declaration of |timeout|, you can use |timeout->mIsInterval| to check which one you have.

Comment on attachment 8828162 [details] [diff] [review] new naming scheme for runnables Review of attachment 8828162 [details] [diff] [review]: ----------------------------------------------------------------- Nice, this does look much better!

Comment on attachment 8828160 [details] [diff] [review] ThrottledEventQueue naming Review of attachment 8828160 [details] [diff] [review]: ----------------------------------------------------------------- ::: xpcom/threads/ThrottledEventQueue.cpp @@ +118,5 @@ > MOZ_ASSERT(!mExecutor); > MOZ_ASSERT(mShutdownStarted); > } > > + NS_IMETHODIMP Why is this NS_IMETHODIMP? Shouldn't it just be nsresult? Is it actually defined in an IDL interface somewhere? I think it should be clear this cannot get called outside of the private details of ThrottledEventQueue since we have the "must not be empty" requirement. We can't guarantee that if its not the ExecutorRunnable making the call. A comment to that effect would be nice as well. ::: xpcom/threads/nsEventQueue.cpp @@ +46,5 @@ > +{ > + MOZ_ASSERT(aEvent); > + *aEvent = nullptr; > + > + MOZ_RELEASE_ASSERT(!IsEmpty()); Actually, I'm curious what actually guarantees this in the patch. It seems ThrottledEventQueue calls into this without checking the length of the queue.

Comment on attachment 8828211 [details] [diff] [review] telemetry for runnable times I read through nsINamed, and I want to see if this is *always* correct, or only for C++-things: "should be a compile-time literal" We don't want key names to ever expose private/browsing data. If these are always class names or other compiled-in data, this is perfectly fine, data-r=me If there is any uncertainty about whether that's the case, please ping me and let's talk. I did not review any code.

(In reply to Ben Kelly [:bkelly] from comment #19) > Comment on attachment 8828160 [details] [diff] [review] > ThrottledEventQueue naming > > Review of attachment 8828160 [details] [diff] [review]: > ----------------------------------------------------------------- > > ::: xpcom/threads/ThrottledEventQueue.cpp > @@ +118,5 @@ > > MOZ_ASSERT(!mExecutor); > > MOZ_ASSERT(mShutdownStarted); > > } > > > > + NS_IMETHODIMP > > Why is this NS_IMETHODIMP? Shouldn't it just be nsresult? Is it actually > defined in an IDL interface somewhere? Yes, it should be nsresult. > I think it should be clear this cannot get called outside of the private > details of ThrottledEventQueue since we have the "must not be empty" > requirement. We can't guarantee that if its not the ExecutorRunnable making > the call. A comment to that effect would be nice as well. OK. > ::: xpcom/threads/nsEventQueue.cpp > @@ +46,5 @@ > > +{ > > + MOZ_ASSERT(aEvent); > > + *aEvent = nullptr; > > + > > + MOZ_RELEASE_ASSERT(!IsEmpty()); > > Actually, I'm curious what actually guarantees this in the patch. It seems > ThrottledEventQueue calls into this without checking the length of the queue. Well, it relies on people not calling GetName on a ThrottledEventQueue runnable before it's been dispatched or after it's been run. We already have a similar condition on the Run method. I can make this check for empty if you prefer though. Then it could just return "Empty ThrottledEventQueue runnable" or something.

(In reply to Bill McCloskey (:billm) from comment #21) > (In reply to Ben Kelly [:bkelly] from comment #19) > > Comment on attachment 8828160 [details] [diff] [review] > > ThrottledEventQueue naming > > > > Review of attachment 8828160 [details] [diff] [review]: > > ----------------------------------------------------------------- > > > > ::: xpcom/threads/ThrottledEventQueue.cpp > > @@ +118,5 @@ > > > MOZ_ASSERT(!mExecutor); > > > MOZ_ASSERT(mShutdownStarted); > > > } > > > > > > + NS_IMETHODIMP > > > > Why is this NS_IMETHODIMP? Shouldn't it just be nsresult? Is it actually > > defined in an IDL interface somewhere? > > Yes, it should be nsresult. > > > I think it should be clear this cannot get called outside of the private > > details of ThrottledEventQueue since we have the "must not be empty" > > requirement. We can't guarantee that if its not the ExecutorRunnable making > > the call. A comment to that effect would be nice as well. > > OK. > > > ::: xpcom/threads/nsEventQueue.cpp > > @@ +46,5 @@ > > > +{ > > > + MOZ_ASSERT(aEvent); > > > + *aEvent = nullptr; > > > + > > > + MOZ_RELEASE_ASSERT(!IsEmpty()); > > > > Actually, I'm curious what actually guarantees this in the patch. It seems > > ThrottledEventQueue calls into this without checking the length of the queue. > > Well, it relies on people not calling GetName on a ThrottledEventQueue > runnable before it's been dispatched or after it's been run. We already have > a similar condition on the Run method. I can make this check for empty if > you prefer though. Then it could just return "Empty ThrottledEventQueue > runnable" or something. Ah, I thought I deleted that comment. Anyway, I think it would make sense for nsEventQueue::PeakEvent() return a nullptr event if the queue is empty. But I convinced myself the current patch is ok. Just might be confusing if someone tries to use it in a different context.

(In reply to Benjamin Smedberg [:bsmedberg] from comment #20) > Comment on attachment 8828211 [details] [diff] [review] > telemetry for runnable times > > I read through nsINamed, and I want to see if this is *always* correct, or > only for C++-things: "should be a compile-time literal" > > We don't want key names to ever expose private/browsing data. If these are > always class names or other compiled-in data, this is perfectly fine, > data-r=me > > If there is any uncertainty about whether that's the case, please ping me > and let's talk. Well, I can say for certain the currently the code only returns compile-time constants. However, the interface does allow for arbitrary strings, so people could make mistakes in the future. How much assurance do you think we need? I can think of three options: 1. Leave it the way it is, but with a comment on the |name| property in nsINamed. 2. Change the |name| property to something like telemetryName so people are aware that it can be used in telemetry. 3. Change the interface so that only const char* can be returned. This should work now, but it might make it harder to do certain things in the future. It also might be a source of bugs if people make mistakes and return a stack buffer or something.

See previous comment.

I think it should be ok to add a comment to the `name` in nsINamed making clear that this must only be build data. Let's be ultra-clear in that comment though.

We could ensure compile-time constants with something like: %{C++ // Whatever the precise syntax is and the args for nsDependentCString. template<size_t N> void SetName(const char (&aName)[N]) { SetName(nsDependentCString(aName, N)); } protected: virtual void SetName(nsACString& aName) = 0; public: %} This is a little gross, but there is at least precedent for it: https://dxr.mozilla.org/mozilla-central/search?q=protected%3A+ext%3Aidl&redirect=false

Comment on attachment 8828211 [details] [diff] [review] telemetry for runnable times Review of attachment 8828211 [details] [diff] [review]: ----------------------------------------------------------------- ::: xpcom/threads/nsThread.cpp @@ +1242,4 @@ > if (MAIN_THREAD == mIsMainThread) { > HangMonitor::NotifyActivity(); > + > + nsCString name; Given that these names are #ifdef'ed out on beta or release, perhaps we should only collect these probes on Aurora and Nightly. r=me with that fixed.

Comment on attachment 8828159 [details] [diff] [review] give names to a few generic dispatch sites Review of attachment 8828159 [details] [diff] [review]: ----------------------------------------------------------------- ::: xpcom/threads/AbstractThread.cpp @@ +60,5 @@ > > + if (nsCOMPtr<nsINamed> named = do_QueryInterface(r)) { > + named->SetName("XPCOMThreadWrapper"); > + } > + Oh, I've done something similar and is landed in bug 1314833, FYI: https://hg.mozilla.org/mozilla-central/file/8ab1b5ce5bbc/xpcom/threads/AbstractThread.cpp#l175

(In reply to Bevis Tseng[:bevistseng][:btseng] from comment #28) > Oh, I've done something similar and is landed in bug 1314833, FYI: > https://hg.mozilla.org/mozilla-central/file/8ab1b5ce5bbc/xpcom/threads/ > AbstractThread.cpp#l175 Thanks! I'll take that part out of my patch.

Pushed by wmccloskey@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/be72b7763910 Add more runnable names (r=ehsan) https://hg.mozilla.org/integration/mozilla-inbound/rev/2810212347fd Give runnable names to some generic dispatch sites (r=ehsan) https://hg.mozilla.org/integration/mozilla-inbound/rev/8b751230fa23 Name each runnable from the ThrottledEventQueue queue (r=bkelly) https://hg.mozilla.org/integration/mozilla-inbound/rev/c76432c9954e New naming scheme for runnables (r=ehsan) https://hg.mozilla.org/integration/mozilla-inbound/rev/3a5b5b9ecace Anonymize nsITimer runnable names (r=njn) https://hg.mozilla.org/integration/mozilla-inbound/rev/600c0b9026c2 Change default IPC message name to make it clearer (r=kanru) https://hg.mozilla.org/integration/mozilla-inbound/rev/8bf7f0e27c6c Measure runnable times keyed by name for telemetry (r=ehsan,bsmedberg)

I had to back these out for causing Win7 VM debug dt5 runs to fail like https://treeherder.mozilla.org/logviewer.html#?job_id=71655985&repo=mozilla-inbound https://hg.mozilla.org/integration/mozilla-inbound/rev/6abcbe944f8f36edf1f710c9ab32dec6b371d392

(In reply to Wes Kocher (:KWierso) from comment #31) > I had to back these out for causing Win7 VM debug dt5 runs to fail like > https://treeherder.mozilla.org/logviewer.html#?job_id=71655985&repo=mozilla- > inbound > > https://hg.mozilla.org/integration/mozilla-inbound/rev/ > 6abcbe944f8f36edf1f710c9ab32dec6b371d392 See bug 1333597 for the log spam details.

Pushed by wmccloskey@mozilla.com: https://hg.mozilla.org/integration/mozilla-inbound/rev/e402c75016e0 Add more runnable names (r=ehsan) https://hg.mozilla.org/integration/mozilla-inbound/rev/28998c282974 Give runnable names to some generic dispatch sites (r=ehsan) https://hg.mozilla.org/integration/mozilla-inbound/rev/ea5f76e45be0 Name each runnable from the ThrottledEventQueue queue (r=bkelly) https://hg.mozilla.org/integration/mozilla-inbound/rev/ea9be6b31ed0 New naming scheme for runnables (r=ehsan) https://hg.mozilla.org/integration/mozilla-inbound/rev/181f7c8d957d Anonymize nsITimer runnable names (r=njn) https://hg.mozilla.org/integration/mozilla-inbound/rev/4ef27d3ca122 Change default IPC message name to make it clearer (r=kanru) https://hg.mozilla.org/integration/mozilla-inbound/rev/f0248c53cef7 Measure runnable times keyed by name for telemetry (r=ehsan,bsmedberg)

Bug 1333624 was causing the log spam. I worked around it.

https://hg.mozilla.org/mozilla-central/rev/e402c75016e0 https://hg.mozilla.org/mozilla-central/rev/28998c282974 https://hg.mozilla.org/mozilla-central/rev/ea5f76e45be0 https://hg.mozilla.org/mozilla-central/rev/ea9be6b31ed0 https://hg.mozilla.org/mozilla-central/rev/181f7c8d957d https://hg.mozilla.org/mozilla-central/rev/4ef27d3ca122 https://hg.mozilla.org/mozilla-central/rev/f0248c53cef7

I filed bug 1333984 to analyze the telemetry data from this bug. I also filed a bunch of bugs for the runnables in comment 1. They all block the labeling bug (bug 1321812).