1736616 - CPU usage measurements show some CPU activity on Rust threads when they are completely idle on Linux

Status: RESOLVED FIXED

(Core :: Gecko Profiler, defect, P3)

Description

[Nazım Can Altınova [:canova]]

We've realized this when we were working on the profiler front-end to use the CPU usage for detecting idle threads.

On macOS and Windows, the Rust worker threads that belong to a thread pool are using 0 CPU when they are completely idle. But on Linux, they are never using zero CPU even though they are completely idle. This is either a bug on our side while we are measuring the CPU usage, or this is a bug with the way rust/rayon handles the thread pools on Linux (it seems to be less likely, see the last paragraph of this bug).

Here are some example profiles from Linux:
https://share.firefox.dev/3AXm0AW (look at the CPU values of a StyleThread, or any other rust thread that is idle.)
https://share.firefox.dev/3phnx2T (look at the CPU values of a WRRenderBackend thread.)

Here's an example profile from macOS:
https://share.firefox.dev/3lX8yJo (look at the CPU values of a StyleThread.)

To see the CPU usage in more detail in a profile: Go to the devtools console and call experimental.enableCPUGraphs(). You will see that CPU graph tracks will appear under the activity graph in the timeline. This is a bar graph that shows the CPU usage deltas for each sample. Even though activity graph is using the CPU usage as its height, it's doing some smoothing, so these experimental tracks would make it easier to see.

Also you can programmatically access to these values: Select a thread, open the console and write filteredThread.samples.threadCPUDelta. And filteredThread.samples.threadCPUDelta.filter(val => val === 0).length will return zero on linux but not on macOS.

Florian also shared a profile that is taken with linux perf showing that these threads are not using any CPU:
https://share.firefox.dev/2Z9eSof
So this looks more like a problem with the way we capture the CPU measurements, but can't say something for sure.

Comment 1

[BugBot [:suhaib / :marco]]

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

For more information, please visit auto_nag documentation.

Comment 2

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

My guess is that this is due to the way threads are suspended before being sampled on Linux.
See this comment for the full explanations.

Basically, the sampler thread sends a signal to the target thread, and work happens in that target thread's signal handler (to suspend the thread and wait for the sampler to do its sampling).
This seems like the most likely source of extra CPU work.

On other platforms, the sampler thread can invoke OS routines to directly suspend a target thread, without that thread having to do anything.

I'm not sure there is a possible perfect solution to this. Thoughts:

1. Is there another way to suspend a thread, that's more like Windows and macOS? I see pthread_suspend is just not implemented on Linux.
2. Could we (profiler backend and/or frontend) account for this little bit of extra activity and hide it?
3. We could measure the CPU times just before and after sampling, and discard that small work; in the worst case we may miss some real work that happens at these edges, but that should be small enough compared to the time between sampling loops.

The last point may be the easiest to prototype, it could be worth having a go. At the very least, it should confirm/eliminate my guess as the cause of this extra activity.

Comment 3

[Florian Quèze [:florian]]

(In reply to Gerald Squelart [:gerald] (he/him) from comment #2)

At the very least, it should confirm/eliminate my guess as the cause of this extra activity.

One thing worth noting is that Rust threads never have any 0 CPU sample, but C++ threads do. Given what you said above, the difference might be that C++ threads call AUTO_PROFILER_THREAD_SLEEP, but Rust threads never do. If that's the reason, then it confirms your guess.

Comment 4

[Florian Quèze [:florian]]

(In reply to Gerald Squelart [:gerald] (he/him) from comment #2)

1. Is there another way to suspend a thread, that's more like Windows and macOS? I see pthread_suspend is just not implemented on Linux.

Could this also fix the (very annoying) bug 1698748 at the same time?

Comment 5

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

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

One thing worth noting is that Rust threads never have any 0 CPU sample, but C++ threads do. Given what you said above, the difference might be that C++ threads call AUTO_PROFILER_THREAD_SLEEP, but Rust threads never do. If that's the reason, then it confirms your guess.

Good point, thank you.
Indeed, AUTO_PROFILER_THREAD_SLEEP (from C++ threads) means that the sampler doesn't even attempt to suspend and sample those sleeping C++ threads.
So another possible solution to eliminate spurious CPU work from Rust threads would be to make them call an equivalent to AUTO_PROFILER_THREAD_SLEEP. But I think we don't actually have much control over Rust event loops (usually hidden in 3rd party crates like Tokio), so that would be difficult to introduce.
With my proposal to subtract CPU work while suspending a thread for full sampling, there would be more chance to get a real zero-CPU value between sampling loops, which in turn would make the next sampling loop reuse the same sample and not even attempt to re-suspend the thread. 😁

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

(In reply to Gerald Squelart [:gerald] (he/him) from comment #2)

1. Is there another way to suspend a thread, that's more like Windows and macOS? I see pthread_suspend is just not implemented on Linux.

Could this also fix the (very annoying) bug 1698748 at the same time?

If there was another way to suspend a thread, I would probably help, yes.

But now, thinking about my proposal again, I'm less enthusiastic about what I just said above (about getting real zeroes and not sampling again) 🤔. We could have the following scenario:

1. Target thread T is poll()ing.
2. Sampler Thread S records CPU times before suspending.
3. S sends a signal to suspend T.
4. T handles the signal, S samples T, T resumes.
5. S records CPU times after suspending (so that CPU work during sampling will be ignored).
6. T's poll() returns because of the above signal, which causes some "real" work to happen! (bug 1698748 in effect).
7. At the next samping loop, S records T's CPU times, but they are not zero, so we'll do a full sampling again. 😢

It may still be a good idea to try, though it may not be 100% effective.

Comment 6

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Prototype patch in Try. Profile before -> Profile after.

Looking closely at the "after" profile, most threads now have zero CPU utilization most of the time, confirmed by selecting each and running filteredThread.samples.threadCPUDelta.filter(val => val === 0).length in the JS console.

As a nice bonus, there are many more samples taken in the same amount of time, probably because the samplers didn't waste time stack-walking the same sleeping threads.

Comment 7

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

(In reply to Nazım Can Altınova [:canova][:canaltinova on phabricator] from comment #0)

On macOS and Windows, the Rust worker threads that belong to a thread pool are using 0 CPU when they are completely idle.

Did you really see that?
Because while testing on Windows, I noticed that idle threads had no zero-CPU either!
CPU utilization was around a few tens of thousands of cycles per ms, which is in the order of 0.001% of a CPU, very low but not 0%.
Profile.

I wrote the same patch as on Linux, and it helped! Idle threads now have almost 90% of zeroes, and non-zero values were 10x smaller.
Profile.

I'll have a look at macOS next...

Comment 8

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

MacOS is working well without the patch, getting mostly zero-CPU values in idle threads. Adding that same patch as Windows&Linux didn't seem to have noticeable effect (on a small test). I'll test a bit more before deciding whether to add a patch for macOS.

Finally, looking at post-patch tests, Windows is the one left with no/few zeroes! Though values are very low, not being exactly zero means that the profiler may still do more work on those idle Rust threads.
I think I will finish the current patch and get it landed, because it's already quite useful as-is, but I'll file a follow-up to see what can be done to help further...

Comment 9

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Attachment: Bug 1736616 - Discard CPU utilization due to suspending threads - r?canaltinova

Suspending threads on some platforms may actually add CPU times to the target threads, artificially making it look like that thread did some work since the last CPU sampling.
This is especially visible on Linux, where suspending is done by sending a signal to the target thread, where the signal handler does quite a bit of work. On Windows there seems to be CPU work happening, possibly when the OS is checking whether a thread needs to be woken up.

To help with this, this patch effectively removes the CPU running times that happen during sampling:

• Thread sampling actions before: record-CPU stack ... record-CPU stack ...
  The difference between two "record-CPU" is the amount of work done, which includes "stack" sampling.
• After: record-CPU stack reset-CPU ... record-CPU stack reset-CPU ...
  Now thanks to the "reset-CPU" happening after "stack", the next "record-CPU" will only include the work done outside of the stack sampling.
  This "reset-CPU" action is done in the new platform-specific function DiscardSuspendedThreadRunningTimes.

Note that there is a small window (just before and after the actual stack sampling) where some real CPU work may be discarded as well, but it should be negligible compared to all the work that happens between sampling loops.

Comment 10

[Pulsebot]

Pushed by [e-mail]:
https://hg.mozilla.org/integration/autoland/rev/1d76ef913254
Discard CPU utilization due to suspending threads - r=canaltinova

Comment 11

[Cristina Cozmuta (:CrissCozmuta)]

https://hg.mozilla.org/mozilla-central/rev/1d76ef913254

Comment 12

[Florian Quèze [:florian]]

(In reply to Gerald Squelart [:gerald] (he/him) from comment #8)

Finally, looking at post-patch tests, Windows is the one left with no/few zeroes! Though values are very low, not being exactly zero means that the profiler may still do more work on those idle Rust threads.
I think I will finish the current patch and get it landed, because it's already quite useful as-is, but I'll file a follow-up to see what can be done to help further...

Did you file the follow-up you mentionned here? I tried to reproduce on Windows on today's nightly, and I saw lots of 0 CPU samples, so I'm a bit confused about what remains to be done.

Comment 13

[Gerald Squelart (he/him) (not at Mozilla since 2022-09-15)]

Thank you Florian for the reminder and extra information. I've filed follow-up bug 1741743 to look into this (whether we do get zeroes or not; and what to do next).