1909883 - Opening a Chromium CI Console spends 400ms on the parent process, processing NS_ReleaseOnMainThread runnables from a visited links query

Status: RESOLVED FIXED

(Core :: SQLite and Embedded Database Bindings, defect, P2)

Description

[Mayank Bansal]

Go to https://ci.chromium.org/p/chromium/g/main/console?limit=50000

Profile: https://share.firefox.dev/3WFruic

Maybe spend less time? I dont know whats the correct component for this - i dont understand the profile. Please reclassify appropriately.
cc: acresky, mstange, rjesup

Comment 1

[Mayank Bansal]

On a reload of the page, there is no activity on the parent process.

Comment 2

[Markus Stange [:mstange]]

One aspect of this profile is similar to the one in bug 1907701: There is a high number of runnables (22000) in the busy 360ms window. And the per-runnable overhead of the our native Windows event loop implementation is really high - it basically enforces a 10 microsecond gap between the processing of each individual runnable Run() call.

What's different from the profile in bug 1907701 is the source of these runnables. In this profile they're the runnables from NS_ReleaseOnMainThread("StatementData::mParamsArray", mParamsArray.forget());

The mozStorage work appears to be initiated by a BaseHistory::StartPendingVisitedQueries task.

Marco, is Places the right spot for this bug? Also, would you expect 22000 runnables from a visited links query?

Comment 3

[Marco Bonardo [:mak] (Away 10-21 August)]

Unfortunately today don't have enough time to do a full analysis of the problem, but I think it's in large part related to Bug 1594368.
We're querying URLs for their visited status one by one, and notifying back, we should instead run and notify in batches.
I'm not sure if 22000 runnables is normal, it is "normal" if we're running 22000 queries for 22000 links. To avoid that we should fix that batch bug.

The other thing we should investigate is whether we can avoid this main-thread proxy release.

The reasoning about XPConnect may not apply to specific cases, if we can detect those case we can avoid the proxy release. Alternatively instead of doing async execution we could do sync execution on the helper thread, then it would be trivial to detect binding happened on the helper thread, store that info in BindingParams, and BindingParamsArray could use that info to avoid the proxy release.
But all of this may not be necessary. Bug 874814 introduced this proxyrelease because of XPCVariant being passed into Storage, though one year later in Bug 1005991 I converted those XPCVariant into Storage Variant, that should be thread-safe.

So, it may be sufficient to MOZ_DIAGNOSTIC_ASSERT that we don't have an XPCVariant, and remove the proxyrelease?

This is just by code inspection, it will require more investigation and testing.

I'm moving this to Storage because the high number of link visited queries is already tracked in bug 1594368, so I'd like to keep this about the proxy release investigation.
Not clearing ni? as I'd like to return to this in the next weeks, unless someone beats me to it (feel free to).

Comment 4

[Mayank Bansal]

(In reply to Marco Bonardo [:mak] (away Aug 5-12, Aug 19-21) from comment #3)

Unfortunately today don't have enough time to do a full analysis of the problem, but I think it's in large part related to Bug 1594368.
We're querying URLs for their visited status one by one, and notifying back, we should instead run and notify in batches.
I'm not sure if 22000 runnables is normal, it is "normal" if we're running 22000 queries for 22000 links. To avoid that we should fix that batch bug.

The URL will load 50,000 "build statuses" from different configurations of chromium. So 22,000 links seem plausible. You can change the number at the end of the URL to load that big a page (with probably an upper limit).

https://ci.chromium.org/p/chromium/g/main/console?limit=5 : https://share.firefox.dev/46o0x5D
https://ci.chromium.org/p/chromium/g/main/console?limit=50 : https://share.firefox.dev/3y3adpH
https://ci.chromium.org/p/chromium/g/main/console?limit=500: https://share.firefox.dev/4fipOlU
https://ci.chromium.org/p/chromium/g/main/console?limit=5000: https://share.firefox.dev/3LHUkrC
https://ci.chromium.org/p/chromium/g/main/console?limit=50000 (original URL): https://share.firefox.dev/4d8UXGy
https://ci.chromium.org/p/chromium/g/main/console?limit=500000 : https://share.firefox.dev/3WooSDM
https://ci.chromium.org/p/chromium/g/main/console?limit=5000000: https://share.firefox.dev/3WG85O5
https://ci.chromium.org/p/chromium/g/main/console?limit=50000000 : https://share.firefox.dev/3LCm6pH

In the larger profiles, there is also this network-y bit in the content process that may be optimized? https://share.firefox.dev/3LFq3d7

Comment 5

[Andrew Sutherland [:asuth] (he/him)]

(In reply to Marco Bonardo [:mak] (away Aug 5-12, Aug 19-21) from comment #3)

The other thing we should investigate is whether we can avoid this main-thread proxy release.

Yes, I think this should be safe.

So, it may be sufficient to MOZ_DIAGNOSTIC_ASSERT that we don't have an XPCVariant, and remove the proxyrelease?

Yeah, this seems like a reasonable check and not too bad given that it's got an explicit IID and this would only be on nightly and early beta. That said, I think we could also remove that check after a fairly short time since we explicitly normalize all passed nsIVariants to the variant class you created. I also would probably be fine without the check since I think the fuzzers that browse the web would detect this with owning thread checks that should exist on XPCVariant.

Comment 6

[Mayank Bansal]

Attachment: Too Many Links_Testcase.html

Profile: https://share.firefox.dev/3yfFB47

Comment 7

[Bas Schouten (:bas.schouten)]

Fwiw, when the event loop system was designed there was a conversation on this and its performance was tested at 15000. The current semantics of NS_ReleaseOnMainThread aren't great for that. I wonder whether we should change them slightly to automatically batch. This could reduce runnable overhead significantly for all callers here and in other places or the future.

Comment 8

[Bas Schouten (:bas.schouten)]

It would also avoid a bunch of memory churn and fragmentation by avoiding the allocation and release of such a large amount of runnables. My current thinking here is to make ProxyRelease work a little smarted by having a threadsafe thread_local list of objects, that is appended to when a runnable is already scheduled, rather than a new runnable being created.

When the target thread gets to the runnable, it would swap the list for a clean one, and go do the releases. Any subsequent ProxyRelease calls would append to the new list. As far as I can tell this would remove a footgun for the future and lead to better performance in most scenarios at a limited cost to complexity.

Comment 9

[Bas Schouten (:bas.schouten)]

(This would also fix bug 1907701)

Comment 10

[Emilio Cobos Álvarez [:emilio]]

Comment 8 sounds good to me fwiw (though if we avoid the release altogether that is even better, if a bit less general). Hopefully nobody is relying on the current timing details...

FWIW the style system has a somewhat similar use case (here)...

Comment 11

[Bas Schouten (:bas.schouten)]

Turns out that when you address the proxy release here it still leaves a load of AsyncExecuteStatements::notifyCompleteOnCallingThread runnables. So it doesn't really fix the issue.

Comment 12

[Bas Schouten (:bas.schouten)]

I have moved both of these into a special type of FastTask, I can confirm that reduces the time spent from 300ms to 50ms on my machine, however those 50ms are now a jank (because we're not checking the native event loop in the meanwhile). I'll experiment with pausing every 25ms when running fast tasks.

Comment 13

[Marco Bonardo [:mak] (Away 10-21 August)]

(In reply to Bas Schouten (:bas.schouten) from comment #11)

Turns out that when you address the proxy release here it still leaves a load of AsyncExecuteStatements::notifyCompleteOnCallingThread runnables. So it doesn't really fix the issue.

yes, we must address both. As I said in this specific case we can completely avoid the proxyrelease, even without underlying changes (that may still be a good idea for other cases). Though the notifyComplete will require batching from Bug 1594368, afaict.

Comment 14

[Bas Schouten (:bas.schouten)]

The Performance Impact Calculator has determined this bug's performance impact to be low. If you'd like to request re-triage, you can reset the Performance Impact flag to "?" or needinfo the triage sheriff.

Platforms: [x] Windows [x] macOS [x] Linux [x] Android
Websites affected: Rare
Resource impact: Some
[x] Able to reproduce locally

Comment 15

[Marco Bonardo [:mak] (Away 10-21 August)]

The ProxyRelease runnables should be gone.
I'll later look at the batching problem in bug 1594368, though it may involve some additional complexity due to caching statements that bind a variable number of parameters.

Comment 16

[Mayank Bansal]

Seems much better now with the fix from bug 1594368.
Profile from latest Nightly:
Profile opening the link in comment #0: https://share.firefox.dev/40ptg9q
Profile opening a larger URL :https://share.firefox.dev/48s8vvE
Profile of the testcase: https://share.firefox.dev/3Uuhuqh

Comment 17

[Marco Bonardo [:mak] (Away 10-21 August)]

I think in "normal" cases this is fine in Nightly for today.
There's still some jank in the extreme case (150k links) of Too Many Links_Testcase.html, mostly spent on destructors, building hashSet, IPC.
If someone can identify low hanging fruits in a new profile it'd probably be better to have a new bug in Core :: Performance with the new profile, rather than keeping this around, especially since the original report in comment 0 looks fixed.

Comment 18

[Marco Bonardo [:mak] (Away 10-21 August)]

I'm marking as resolved based on the original test case, and the work done in dependencies.
As suggested, if you can identify additional improvements in the profile, it may be better to file a new bug in the appropriate component or in Core :: Performance for further analysis.