2001853 - Using Powershell to send mouseclicks to enable/disable UBlock 10000 times takes 10 minutes. Lots of time spent in listeners. glean, and GC. Also makes permanent slowdown/memory increase, and block all networking.

Status: NEW

(WebExtensions :: General, defect, P5)

Description

[Mayank Bansal]

Attachment: key.ps1

Use Nightly and installe Ublock Origin.
Enable all the possible filter lists from its UI and maybe some more.
Use attached powershell script to enable/disable the extension from about:addons 10000 times.

Profiles
10000: https://share.firefox.dev/4ofi9bo
1000: https://share.firefox.dev/48ugKJ4
Not sure why these two look different.

Observations:

1. Takes a long time in parent-pocess and webextension process.
2. Once the processing is done, the parent-process gets a permanent memory increase that doesnt go down. Attaching the memory report for reference. Parent-process takes ~1.2GB.
3. Opening/closing tabs becomes slightly slower permanently.
4. Closing the browser takes a long time (10s+). Profile indicates some unregistering preferences at the very end. Focussed profile: https://share.firefox.dev/4ii7Ulc
5. 5% time spent in Ion: listener (resource://gre/modules/Extension.sys.mjs:3831:24) . Combine this with the previous observations, maybe some of the observers are not getting cleaned up and accumulating till shutdown?
6. Lots of time in Glean. Maybe around allocating memory?
7. It is not possible to capture a Gecko profilefor this, because even for low N (100), the browser gets into a state where no network activity happens. So the browser is effectively dead. No profile will get captured/symbolicated. I have ublock put on setting that allows network activity even if all filters are not loaded, so even if ublock is incompletely loaded it should not effect networking.

Comment 1

[Mayank Bansal]

Attachment: memory-report.json.gz

Comment 2

[Mayank Bansal]

Attachment: log.txt-main.7484.moz_log

networking log for N=100. Once the processing was over, i tried to open YT. But there was absolutely no network activity.

Comment 3

[Mayank Bansal]

Attachment: about:support

Comment 4

[BugBot [:suhaib / :marco]]

The severity field is not set for this bug.
:bas.schouten, could you have a look please?

For more information, please visit BugBot documentation.

Comment 5

[Bas Schouten (:bas.schouten)]

I think this is the right component. Setting perf impact to none as this is an artificial test case.

Comment 6

[Rob Wu [:robwu]]

This is indeed a very artificial situation, but as it is essentially a benchmark, it can reveal points of improvement in our internals.

Enabling/starting an extension is not free, so it is not too surprising for it to be costly when repeated thousands of times in short succession.

Comment 7

[Mayank Bansal]

Attachment: WIP: Bug 2001853 - Track the number of blocking webRequest listeners instead of counting them on every registration. r?#webextensions-reviewers

HttpObserverManager.addOrRemove() built an Array from every listener Map to
find out whether any listener has blockingAllowed, and it runs on every
addListener/removeListener/setDNRHandlingEnabled call. Keep a count instead.

In a profile of an extension being repeatedly enabled and disabled,
addOrRemove() is ~60% of non-idle parent process CPU during the busiest
phase, and ~90% of that is the Array.from() walk.

Comment 8

[Phabricator Automation]

Comment on attachment 9619749 [details]
WIP: Bug 2001853 - Track the number of blocking webRequest listeners instead of counting them on every registration. r?#webextensions-reviewers

Revision D315253 was moved to bug 2059363. Setting attachment 9619749 [details] to obsolete.