1762223 - [GTK_USE_PORTAL] Multiple active downloads consume excessive CPU

Status: UNCONFIRMED

(Core :: Widget: Gtk, defect, P3)

Description

[andysem]

User Agent: Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:98.0) Gecko/20100101 Firefox/98.0

Steps to reproduce:

1. Have ~15 active downloads, with a total download bandwidth of ~100 Mbit/s.
2. No other activity, no clicking or other interaction with the currently open page. There are no animations on the currently open page (this was a Wikipedia page with static content in my case), no video or audio on the other tabs.

Actual results:

My Core i7 12700K is constantly loaded at 20-25% across all cores by the main Firefox process (i.e. the load is spread across all cores, each logical core is loaded by 20-25%). The content process consumes much less (around 2-3% across all cores).

Expected results:

Firefox should not consume CPU as much by merely downloading files.

Comment 1

[andysem]

Attachment: Firefox 2022-03-30 18.27 profile (small).json.gz

Comment 2

[andysem]

Attachment: about:support page

Comment 3

[BugBot [:suhaib / :marco/ :calixte]]

The Bugbug bot thinks this bug should belong to the 'Firefox::Downloads Panel' component, and is moving the bug to that component. Please correct in case you think the bot is wrong.

Comment 4

[:Gijs (he/him)]

The profile (thank you!) shows that a bunch of the CPU time goes to your "Download Manager (S3)" extension, which is responding to the progress of the download(s).

The other thing I notice in the main process is g_file_monitor_source_dispatch and other gtk bits inserting jank markers. I can't tell what's causing that because there's no Firefox code in the stack for that (apart from the event loop itself and our memory allocator functions). I don't believe any of the internal Firefox code uses file monitoring APIs (certainly I don't see the aforementioned function in code search) so I don't know why that code is running - perhaps if you have a file open/save dialog open on the same directory where files are downloading, and gtk is busy updating that view to show accurate file sizes? Maybe stransky has better ideas.

I'm not sure my diagnosis is complete, so pinging florian in case he sees anything else in this profile.

It would be useful to confirm if the issue improves at all if you disable the add-on and restart.

Finally, it's possible this is related to bug 1742797, but I don't know if that affects Linux, and I don't see much graphics stuff in the profile (perhaps the relevant settings were not enabled, I'm not sure). You could perhaps confirm/deny if you turn off browser.download.alwaysOpenPanel, restart, and then set off all these downloads without opening the downloads panel, and checking if the behaviour is any better.

Comment 5

[Martin Stránský [:stransky] (ni? me)]

Plese try to open the download on command line (by wget for instance) and compare the CPU load with Firefox.
Thanks.

Comment 6

[andysem]

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

The profile (thank you!) shows that a bunch of the CPU time goes to your "Download Manager (S3)" extension, which is responding to the progress of the download(s).

I tried disabling the addon while the downloads were in progress. It didn't make a difference. I confirmed that the addon wasn't active as its icon has disappeared in the UI and the downloads panel was not updating anymore.

The other thing I notice in the main process is g_file_monitor_source_dispatch and other gtk bits inserting jank markers. I can't tell what's causing that because there's no Firefox code in the stack for that (apart from the event loop itself and our memory allocator functions). I don't believe any of the internal Firefox code uses file monitoring APIs (certainly I don't see the aforementioned function in code search) so I don't know why that code is running - perhaps if you have a file open/save dialog open on the same directory where files are downloading, and gtk is busy updating that view to show accurate file sizes? Maybe stransky has better ideas.

No, no Open/Save dialog was open. The setup was as described in the original post - start the downloads, then watch a still Wikipedia page.

I can add that there is a fair amount of kernel time in the CPU load generated by Firefox, as shown by htop. I can't tell the exact numbers at this point, but visually it looked like around 20% of the CPU load bar lengths were red (i.e. kernel time). Combined with the call trace in the profile, which indicates most of the time spent in g_poll, my uneducated guess is that Firefox uses poll(2) (or whatever similar mechanism) inefficiently, which results in lots of system calls. I may be wrong, of course.

Finally, it's possible this is related to bug 1742797, but I don't know if that affects Linux, and I don't see much graphics stuff in the profile (perhaps the relevant settings were not enabled, I'm not sure).

FWIW, only one Firefox window was open (unlike the referenced bug). I did not click on the Downloads icon to display progress, and that panel does not open automatically on my system when I start a download.

Comment 7

[Florian Quèze [:florian]]

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

I'm not sure my diagnosis is complete, so pinging florian in case he sees anything else in this profile.

You mentioned the 2 biggest things I can see: the S3 download manager add-on, and the g_file_monitor_source_dispatch and other gtk bits.

Additionally, it seems the Socket Thread is spending about half its CPU time doing malloc calls from mozilla::net::nsHttpActivityDistributor::ObserveActivityWithArgs, but that's not really significant compared to the other 2 issues.

Finally, it's possible this is related to bug 1742797, but I don't know if that affects Linux, and I don't see much graphics stuff in the profile (perhaps the relevant settings were not enabled, I'm not sure).

I think that bug is Windows-only. Graphics stuff was recorded in the profile, but not included at upload-time. We would need to see the Compositor and Renderer threads to know if there were graphics issues.

Comment 8

[Florian Quèze [:florian]]

(In reply to andysem from comment #6)

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

The profile (thank you!) shows that a bunch of the CPU time goes to your "Download Manager (S3)" extension, which is responding to the progress of the download(s).

I tried disabling the addon while the downloads were in progress. It didn't make a difference. I confirmed that the addon wasn't active as its icon has disappeared in the UI and the downloads panel was not updating anymore.

If the issue reproduces without the add-on, it would be nice if you could capture and share a profile without it.

I can add that there is a fair amount of kernel time in the CPU load generated by Firefox, as shown by htop. I can't tell the exact numbers at this point, but visually it looked like around 20% of the CPU load bar lengths were red (i.e. kernel time).

If you would like to dig deeper into what part of Firefox uses the CPU, about:processes can help (especially if you set toolkit.aboutProcesses.showThreads to true from about:config).

Combined with the call trace in the profile, which indicates most of the time spent in g_poll, my uneducated guess is that Firefox uses poll(2) (or whatever similar mechanism) inefficiently, which results in lots of system calls. I may be wrong, of course.

Assuming you were looking at all the samples with __GI___poll on the parent process main thread, that's actually the idle time when the CPU isn't used.

Comment 9

[andysem]

(In reply to Martin Stránský [:stransky] (ni? me) from comment #5)

Plese try to open the download on command line (by wget for instance) and compare the CPU load with Firefox.

Unfortunately, I can't easily test that as I don't have large downloads available to test. The issue in Firefox was reproduced with downloads from www.gog.com, and those downloads are not available for unauthenticated clients like wget. At least, I don't know how to download them from console.

Comment 10

[Florian Quèze [:florian]]

(In reply to andysem from comment #9)

(In reply to Martin Stránský [:stransky] (ni? me) from comment #5)

Plese try to open the download on command line (by wget for instance) and compare the CPU load with Firefox.

Unfortunately, I can't easily test that as I don't have large downloads available to test.

There are large files at http://test-debit.free.fr/ (meant to be use for bandwidth tests)

Comment 11

[andysem]

(In reply to Florian Quèze [:florian] from comment #10)

(In reply to andysem from comment #9)

(In reply to Martin Stránský [:stransky] (ni? me) from comment #5)

Plese try to open the download on command line (by wget for instance) and compare the CPU load with Firefox.

Unfortunately, I can't easily test that as I don't have large downloads available to test.

There are large files at http://test-debit.free.fr/ (meant to be use for bandwidth tests)

Thanks. 16 wgets from that site consume around 4% CPU. On idle the CPU is loaded for about 2-3%.

Though I'm not sure this test is a valid comparison, as it is not https. But even with encryption, the downloads should not be consuming 20-25% CPU.

Comment 12

[andysem]

Attachment: CPU load for 16 wgets downloading in parallel

Comment 13

[andysem]

Attachment: Firefox 2022-04-01 18.27 profile (small).json.gz

Here is a profile from Forefox downloading 16 files with Download Statusbar addon disabled.

I also have a more complete profile (with hidden threads) that is larger than Bugzilla allows to attach. If needed, I can upload it somewhere (tell me where).

Comment 14

[andysem]

Attachment: CPU load for 16 downloads in Firefox

Comment 15

[:Gijs (he/him)]

(In reply to andysem from comment #13)

I also have a more complete profile (with hidden threads) that is larger than Bugzilla allows to attach. If needed, I can upload it somewhere (tell me where).

When you've got it loaded you can use the "upload local profile" button in the top right of the profiler page. Then click the "permalink" item and drop the link here. :-)

(Thanks again for all the responses so far!)

Comment 16

[andysem]

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

(In reply to andysem from comment #13)

I also have a more complete profile (with hidden threads) that is larger than Bugzilla allows to attach. If needed, I can upload it somewhere (tell me where).

When you've got it loaded you can use the "upload local profile" button in the top right of the profiler page. Then click the "permalink" item and drop the link here. :-)

Thanks, here's the link: https://share.firefox.dev/36OppJl

PS: I remember trying to upload it like this before, and it didn't work due to some error.

Comment 17

[:Gijs (he/him)]

I'm still seeing significant GTK file chooser API activity in the profile, which is confusing given comment #6 is very clear that no file picker is open. :stransky, is there any obvious explanation for this, or a MOZ_LOG type thing we can use to figure out why that's stealing CPU?

Florian, that activity still doesn't seem to be sufficient to explain using 20% CPU - can you see anything else in the profile from comment #16: https://share.firefox.dev/36OppJl ? (Most threads are hidden but even unhiding the main threads from various processes I'm not seeing much, but I'm not sure how else to look for stuff in there...)

Comment 18

[Martin Stránský [:stransky] (ni? me)]

Yes, it looks like a bug in gtk_file_chooser although I can't say which one. I see suspicions gtk_file_filter_add_custom() calls and other from the chooser.

Comment 19

[Martin Stránský [:stransky] (ni? me)]

I wonder if that comes from some Gnome component or so. Doesn't look like a part of Gtk library. Can you try a different desktop environment? Like KDE or so?
Thanks.

Comment 20

[andysem]

(In reply to Martin Stránský [:stransky] (ni? me) from comment #19)

I wonder if that comes from some Gnome component or so. Doesn't look like a part of Gtk library. Can you try a different desktop environment? Like KDE or so?

I am running KDE. The system is Kubuntu 21.10.

I have GTK_USE_PORTAL=1 environment variable to use KDE open/save file dialogs, if it matters. Though I fail to see how that matters if the dialog is not open. If it does indeed matter, that sounds like a bug in its own right.

Comment 21

[Martin Stránský [:stransky] (ni? me)]

(In reply to andysem from comment #20)

(In reply to Martin Stránský [:stransky] (ni? me) from comment #19)

I wonder if that comes from some Gnome component or so. Doesn't look like a part of Gtk library. Can you try a different desktop environment? Like KDE or so?

I am running KDE. The system is Kubuntu 21.10.

I have GTK_USE_PORTAL=1 environment variable to use KDE open/save file dialogs, if it matters. Though I fail to see how that matters if the dialog is not open. If it does indeed matter, that sounds like a bug in its own right.

I see. Can you try without GTK_USE_PORTAL?
Thanks.

Comment 22

[andysem]

Attachment: Screenshot_20220408_133205.png

Firefox has updated to 99.0 on my system, so from here on the testing is done on this version.

Without GTK_USE_PORTAL CPU load is significantly lower, though still somewhat higher than wget. See the attached screenshot for 15 downloads.

Firefox profile: https://share.firefox.dev/3umXx8r

Comment 23

[andysem]

Attachment: Screenshot_20220408_134203.png

For consistency, here's an updated profile from Firefox 99.0 with GTK_USE_PORTAL: https://share.firefox.dev/3ry542r

Comment 24

[Martin Stránský [:stransky] (ni? me)]

Thanks, the stack looks differently without GTK_USE_PORTAL so I'd say it's the portal dialog which causes it.
Also can you try Gnome with GTK_USE_PORTAL set please?
Thanks.

Comment 25

[andysem]

(In reply to Martin Stránský [:stransky] (ni? me) from comment #24)

Thanks, the stack looks differently without GTK_USE_PORTAL so I'd say it's the portal dialog which causes it.
Also can you try Gnome with GTK_USE_PORTAL set please?
Thanks.

Sorry, I cannot test other DEs. This is my working machine and don't really want to mangle it by installing GNOME.

Comment 26

[Gregory Pappas [:gregp]]

Reporter, some changes have landed in Firefox 110 Beta that try to reduce CPU usage when downloading. Are you able to test Firefox 110 beta to see if this bug still reproduces there? Thank you.

Comment 27

[BugBot [:suhaib / :marco/ :calixte]]

Redirect a needinfo that is pending on an inactive user to the triage owner.
:stransky, since the bug has recent activity, could you have a look please?

For more information, please visit auto_nag documentation.

Comment 28

[andysem]

Sorry for not responding, I forgot about this.

At the moment I can't test as accessing https://beta.mozilla.org/ gives me a 503 error.

Comment 29

[andysem]

I have tested Firefox 110.0 b9 with 9 downloads from http://test-debit.free.fr/ (I can't start more downloads as the site seems to have a limit on the number of active downloads).

With portal, the CPU consumption by Firefox is roughly double than that without portal. So, it probably got much better than originally, but I'd say the problem isn't completely fixed yet.

Comment 30

[andysem]

Attachment: Firefox 110b9 without portal with 9 downloads.

Comment 31

[andysem]

Attachment: Firefox 110b9 with portal with 9 downloads.

Comment 32

[Gregory Pappas [:gregp]]

Awesome, can you also provide an updated profile similar to the one in comment 23? Thanks!

Comment 33

[andysem]

(In reply to Gregory Pappas [:gregp] from comment #32)

Awesome, can you also provide an updated profile similar to the one in comment 23? Thanks!

Here's the profile: https://share.firefox.dev/3RXs5aN