Open
Bug 1503704
Opened 6 years ago
Updated 11 months ago
Very high CPU usage on fast.com
Categories
(Core :: Networking, defect, P2)
Core
Networking
Tracking
()
People
(Reporter: rowbot, Unassigned)
References
(Blocks 1 open bug)
Details
(Keywords: perf:resource-use, Whiteboard: [necko-triaged])
STR:
1) Visit https://fast.com
2) Run the speed test.
When running the speed test, my CPU usage is at 100%. This is on an Intel Core-i5 2500k. Internet speed is roughly 1 Gbps. Not sure if this is normal for my CPU, which is kind of old now or if this is a performance problem in Firefox or Windows. The profile is showing some pretty long wait times on the DNS resolver threads. Let me know if I can provide anymore information.
Profile: http://bit.ly/2yHS12C
|
Reporter | |
Comment 1•6 years ago
|
||
I should also add that this is on Windows 10 64-bit with the latest version of Nightly.
|
||
Comment 2•6 years ago
|
||
Markus, I'm looking at the profile, but it's not clear how to recognize which thread(s) is behind the load. I can see some dispatch delays on the socket thread and also on the content (main?) thread. Is that the ultimate indicator?
It's been a long time I was looking at perf-help. The new cleopatra is so pretty!!
|
||
Comment 3•6 years ago
|
||
The Gecko profiler is not well suited to debug CPU usage. It's more targeted at finding sources of jank, and for looking at how things are scheduled.
I do see though that there's a lot of activity on the parent process main thread: https://perfht.ml/2RusYr4
That's the thread that's most critical to responsiveness and should be kept as idle as possible. But it's busy running all kinds of code in response to the data that's arriving over the network, especially in these two time ranges: https://perfht.ml/2RqAl2w and https://perfht.ml/2RzomQz
In the first of those sections:
- it's telling the new tab page about icons: https://perfht.ml/2RvYxkl
- it's servicing IndexedDB requests, probably for kinto (bug 1502146): https://perfht.ml/2RsVh9b
- it's allocating + deallocating memory when processing network responses: https://perfht.ml/2RtfR9k
- there's lots of event loop and thread coordination overhead from tons of tiny events
In the second section, it's:
- notifying WebRequest listeners in extensions: https://perfht.ml/2RqQuVR
- actually I think that's all it's doing. There's just tons of messages and promise callbacks it's coordinating with the extension which it's notifying.
Oh, and the extension is uBlock origin, whose code is running in the WebExtension process, which is called "Content (5 of 5)" in this profile: https://perfht.ml/2RnRuK8
|
|
||
Comment 4•6 years ago
|
||
However, they may be more CPU usage happening on other threads which are not profiled by default. On Linux, the system "perf" profiler is a good profiler to investigate such issues.
|
|
Reporter | |
Comment 5•6 years ago
|
||
Here is a profile in a clean Fx profile: https://perfht.ml/2yKTvJQ
I still see 100% CPU usage on my end. Let me know if there are other threads you would like me to include in a profile.
|
||
Comment 6•6 years ago
|
||
Hi Vicky,
Could you find someone on your team to take a look first?
Thanks.
Flags: needinfo?(vchin)
|
||
Updated•6 years ago
|
Whiteboard: [qf]
|
||
Updated•6 years ago
|
Flags: needinfo?(vchin)
Whiteboard: [qf] → [qf:p3:resource]
|
||
Comment 7•6 years ago
|
||
|
|
||
Comment 8•6 years ago
|
||
This profile shows a number of things responsible for the CPU usage:
- The main threads of the parent process and of the content process are doing a bunch of work to handle the large number of input stream ready events. Some of this work is in JS so it's easier to look at the profile from comment 5 for the main threads:
- A lot of it seems to be "death by a thousand cuts" simply from event loop overhead + scheduling + copying + notifying.
- In the content process, the DOM API Performance.getEntriesByName shows up pretty heavily, and it seems to be spending most of its time sorting entries.
- The IPDL background thread in the parent process is using a bunch of CPU just forwarding data along to the content process.
- The IOThread uses some amount of CPU, but most of it seems to be in the kernel, not sure what's so expensive there. Could be event loop overhead again.
- The URL Classifier thread shows some serious CPU usage, mostly updating hashes, and in locking overhead.
- The Socket Thread in the parent process is showing a lot of CPU usage. I can't identify a single culprit.
- The Socket Thread in the content process is also showing a lot of CPU usage, almost completely due to event loop / runnable overhead.
- A ton of StreamTransport threads seem to be getting created (and probably destroyed) during the course of this run, both in the parent process and in the content process. The parent process goes from StreamTrans#52 all the way up to StreamTrans#260 in the window from 18.5s to 21s, that's a rate of about 80 threads being created per second. The content process goes from StreamTrans#1 all the way to StreamTrans#1363 in the window from 5.5s to 13.3s, which is a rate of 175 threads being created per second.
I think, of all the issues identified above, the large number of StreamTransport threads is the most concerning and the most actionable. If this could use a thread pool of limited size, that should help a fair amount.
We should also check if Performance.getEntriesByName really has to sort a list every time it is called.
And it would be nice to make each individual load completion cheaper, by reducing the number of copies and threads involved. It would be very nice to not have to go through the parent process's main thread for each load, but I don't know how realistic that is.
Oh, and the URL classifier thread's locking behavior might warrant investigation.
|
|
||
Comment 9•6 years ago
|
||
This is something to be analyzed and maybe split to sub-bugs. Would be good to look at this soon while we (or somebody) can reproduce.
Priority: -- → P2
Whiteboard: [qf:p3:resource] → [qf:p3:resource][necko-triaged]
|
|
Reporter | |
Comment 10•6 years ago
|
||
Hey everyone,
I happened to have this computer turned on this weekend (it's no longer my daily driver) and figured I'd check to see if there were any changes. I updated to the latest nightly and I updated my Ethernet Controller driver and Firefox's CPU usage dropped by roughly 15%, which is good, though my entire computer still reports 100% CPU usage.
I took 2 new profiles, both on clean profiles. The second profile is quite large as I ticked the option for "StreamTrans" in the Gecko Profiler since Markus brought up StreamTransport threads. I'm no expert at reading these things, but it looks like there are over 9200 StreamTransport threads in a 32 second window in the second profile. That's roughly 287 threads per second.
https://perfht.ml/2Bjt6Uq
https://perfht.ml/2Bjy8QX (StreamTrans enabled)
|
|
||
Comment 11•6 years ago
|
||
The number of stream transport threads will very likely be solved with bug 1535361. But even with that patch I still can see (in an opt build) a huge CPU load (two cores full load), so it's not a factor.
|
|
||
Updated•4 years ago
|
Blocks: necko-perf
|
||
Updated•3 years ago
|
Performance Impact: --- → P3
Keywords: perf:resource-use
Whiteboard: [qf:p3:resource][necko-triaged] → [necko-triaged]
|
||
Updated•2 years ago
|
Severity: normal → S3
|
||
Comment 12•11 months ago
|
||
Current profile: https://share.firefox.dev/49MAd5C
Threadripper, 1Gbps connection (fast.com says ~900Mbs).
CPU usage during transfer ~30-40% socket thread, 5-10% MainThread
|
||
Comment 13•11 months ago
|
||
(In reply to Markus Stange [:mstange] from comment #8)
- A ton of StreamTransport threads seem to be getting created (and probably
destroyed) during the course of this run, both in the parent process and in
the content process. The parent process goes from StreamTrans#52 all the way
up to StreamTrans#260 in the window from 18.5s to 21s, that's a rate of
about 80 threads being created per second. The content process goes from
StreamTrans#1 all the way to StreamTrans#1363 in the window from 5.5s to
13.3s, which is a rate of 175 threads being created per second.
This part of the issue may have been related to bug Bug 1667581. If we're still creating a large amount of StreamTransport threads, we should look into it - could be a similar but different issue.
See Also: → 1667581
You need to log in
before you can comment on or make changes to this bug.
Description
•