Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Excessive CPU usage #3230

Open
AlanGriffiths opened this issue Feb 13, 2024 · 15 comments
Open

Excessive CPU usage #3230

AlanGriffiths opened this issue Feb 13, 2024 · 15 comments
Labels
triaged Triage into JIRA to plan it in

Comments

@AlanGriffiths
Copy link
Collaborator

AlanGriffiths commented Feb 13, 2024 •
edited
Loading

There's intermittent high CPU usage of Miriway, seen across stable (Mir 2.16.3) beta and edge (Mir/main)

So far, I've only seen it when docked to evdi (DisplayLink) outputs. And there's another report against Miracle-mw

At first it seemed very consistent when switching between versions, but I've now been running for over a week without problems with the version I first saw it on.

[Original report]
There's a big difference in CPU usage between miriway/{stable, beta} and miriway/edge when docked using DisplayLink and my usual collection of comms and development apps open on various workspaces.

With stable, miriway-shell idles at around 1%CPU, (with spikes up to around 100%)
With edge, miriway-shell idles at around 35%CPU, (with spikes up to around 190%)

Likely to be Mir as the difference is between Mir/2.16.3 and Mir/main
@Saviq
Copy link
Collaborator

Saviq commented Feb 13, 2024

Looking at the diff the only two that feel like they could be it?:

Alternatively, dependency changes? Could rebuild https://launchpad.net/~mir-team/+snap/miriway-beta as a data point.

@AlanGriffiths
Copy link
Collaborator Author

I don't know why you'd pick those. In particular, #3203 was cherry-picked into 2.16.3.

There are a lot that could have an effect. These look plausible:

@AlanGriffiths
Copy link
Collaborator Author

AlanGriffiths commented Feb 13, 2024 •
edited
Loading

Could rebuild https://launchpad.net/~mir-team/+snap/miriway-beta as a data point.

Yeah, seems like a long shot, but worth confirming. (Odd that this doesn't show any builds - edge does)

OTOH, I've installed the rebuilt beta and now have the high CPU usage again.

@AlanGriffiths
Copy link
Collaborator Author

I have also tried #3231 (which shows the same symptom).

I've also tried killall yambar - which on the first attempt appeared to mitigate the behaviour, but I couldn't then reproduce.

Attempting to kill swaybg doesn't help - it restarts (or Miriway restarts it)

@AlanGriffiths
Copy link
Collaborator Author

And now I'm on stable with the same symptom.

Update: while I was writing the previous sentence, usage suddenly dropped to 1.7% and stayed in single digits.

@AlanGriffiths
Copy link
Collaborator Author

And now, on edge/pr88 I see the same thing - a few minutes of high CPU followed by a drop to something sane.

When I reported this, the problem was persistent beyond a few minutes.

It now seems that regardless of the channel there is a chance of getting into this "high CPU" mode, and a chance of getting out of it again. Maybe the difference between stable and other branches is luck, or a change in the odds.

(There is nothing in the logs to suggest what Miriway is doing with the CPU)

@RAOF
Copy link
Contributor

RAOF commented Feb 15, 2024

Have you tried attaching perf record during a period of high CPU use too see what is eating CPU?

@AlanGriffiths
Copy link
Collaborator Author

Have you tried attaching perf record during a period of high CPU use too see what is eating CPU?

No, not "got serious" yet. So far just working on reproducing (and hoping it was a recent change that could be spotted).

@AlanGriffiths
Copy link
Collaborator Author

Compositing seems to be "the thing"...

   5.89%  Mir/Comp       [kernel.kallsyms]            [k] 0xffffffffb24a5067
   5.77%  Mir/Comp       libc.so.6                    [.] 0x000000000017d9a7
   3.72%  Mir/Comp       libc.so.6                    [.] 0x000000000017d997
   3.59%  Mir/Comp       [kernel.kallsyms]            [k] 0xffffffffb17e7b90
   3.33%  Mir/Comp       [drm]                        [k] drm_clflush_page
   3.08%  Mir/Comp       libc.so.6                    [.] 0x000000000017d970
   2.96%  Mir/Comp       [kernel.kallsyms]            [k] 0xffffffffb251cc9b
   2.55%  Mir/Comp       libc.so.6                    [.] 0x000000000017d960
   2.49%  Mir/Comp       [kernel.kallsyms]            [k] 0xffffffffb17bbc89
   2.04%  Mir/Comp       libc.so.6                    [.] 0x000000000017d94d
   1.80%  Mir/Comp       libc.so.6                    [.] 0x000000000017d956
   1.59%  Mir/Comp       [kernel.kallsyms]            [k] 0xffffffffb2601591
   1.58%  Mir/Comp       [kernel.kallsyms]            [k] 0xffffffffb2601149
   1.34%  Mir/Comp       [kernel.kallsyms]            [k] 0xffffffffb26011f7
   1.33%  Mir/Comp       [kernel.kallsyms]            [k] 0xffffffffb2601578
   1.28%  Mir/Comp       [kernel.kallsyms]            [k] 0xffffffffb17905a4
   1.10%  Mir/Comp       [kernel.kallsyms]            [k] 0xffffffffb181ba98
   0.94%  Mir/Comp       [kernel.kallsyms]            [k] 0xffffffffb2517f3e
   0.88%  Mir/Comp       libc.so.6                    [.] 0x000000000017d946
   0.85%  Mir/Comp       libc.so.6                    [.] 0x000000000017d93f
   0.71%  Mir/Comp       [drm]                        [k] drm_gem_put_pages
   0.67%  Mir/Comp       libc.so.6                    [.] 0x000000000017d923
   0.65%  Mir/Comp       [kernel.kallsyms]            [k] 0xffffffffb26011c6
   0.64%  Mir/Comp       libc.so.6                    [.] 0x000000000017d92a
   0.56%  Mir/Comp       [kernel.kallsyms]            [k] 0xffffffffb1818b2a
   0.39%  Mir/Comp       [evdi]                       [k] evdi_gem_fault
   0.38%  Mir/Comp       [i915]                       [k] fw_domains_get_with_fallback
   0.36%  miriway-shell  [kernel.kallsyms]            [k] 0xffffffffb251cc2b
...

@mattkae mattkae mentioned this issue Feb 22, 2024
Open
@AlanGriffiths
Copy link
Collaborator Author

Or maybe not. I had high CPU again...

Samples: 39K of event 'cycles:P', Event count (approx.): 40956573981
Overhead  Command          Shared Object                                              Symbol
  70.62%  Mir/Input Reade  /snap/miriway/3011/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x471dd            d [.] miral::Window::application() const                                                                   ◆
  13.87%  Mir/Input Reade  /snap/miriway/3011/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50bfd            d [.] 0x0000000000050bfd                                                                                   ▒
  11.41%  Mir/Input Reade  /snap/miriway/3011/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50bc5            d [.] 0x0000000000050bc5                                                                                   ▒
   0.79%  Mir/Input Reade  /snap/miriway/3011/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b19            d [.] 0x0000000000050b19                                                                                   ▒
   0.75%  Mir/Input Reade  /snap/miriway/3011/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b04            d [.] 0x0000000000050b04                                                                                   ▒
   0.52%  Mir/Input Reade  /snap/miriway/3011/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b40            d [.] 0x0000000000050b40                                                                                   ▒
   0.50%  Mir/Input Reade  /snap/miriway/3011/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b96            d [.] 0x0000000000050b96

@AlanGriffiths
Copy link
Collaborator Author

Maybe there are two high CPU modes. I have just seen:

Samples: 29K of event 'cycles:P', Event count (approx.): 22326713788
Overhead  Command        Shared Object
   5.35%  Mir/Comp       /snap/core24/184/usr/lib/x86_64-linux-gnu/libc.so.6
   4.16%  Mir/Comp       [kernel.kallsyms]
   3.79%  Mir/Comp       /snap/core24/184/usr/lib/x86_64-linux-gnu/libc.so.6
   3.49%  Mir/Comp       /lib/modules/6.5.0-18-generic/kernel/drivers/gpu/drm/drm.ko
   3.18%  Mir/Comp       [kernel.kallsyms]
   2.89%  Mir/Comp       [kernel.kallsyms]
   1.99%  Mir/Comp       /snap/core24/184/usr/lib/x86_64-linux-gnu/libc.so.6
   1.86%  Mir/Comp       [kernel.kallsyms]
   1.62%  Mir/Comp       [kernel.kallsyms]
   1.60%  Mir/Comp       [kernel.kallsyms]
   1.49%  Mir/Comp       [kernel.kallsyms]
   1.49%  Mir/Comp       /snap/core24/184/usr/lib/x86_64-linux-gnu/libc.so.6
   1.34%  Mir/Comp       [kernel.kallsyms]
   1.30%  Mir/Comp       /lib/modules/6.5.0-18-generic/kernel/drivers/gpu/drm/i915/i915.ko
   1.26%  Mir/Comp       /snap/core24/184/usr/lib/x86_64-linux-gnu/libc.so.6
   1.15%  Mir/Comp       /snap/core24/184/usr/lib/x86_64-linux-gnu/libc.so.6
   1.02%  Mir/Comp       [kernel.kallsyms]
   1.02%  Mir/Comp       [kernel.kallsyms]
   0.93%  Mir/Comp       /snap/core24/184/usr/lib/x86_64-linux-gnu/libc.so.6
   0.92%  Mir/Comp       [kernel.kallsyms]
   0.82%  Mir/Comp       /snap/core24/184/usr/lib/x86_64-linux-gnu/libc.so.6
   0.74%  Mir/Comp       [kernel.kallsyms]
   0.62%  miriway-shell  [kernel.kallsyms]

Which look more like the first of the two profiles above

@AlanGriffiths AlanGriffiths added the triaged Triage into JIRA to plan it in label Feb 26, 2024
@AlanGriffiths AlanGriffiths mentioned this issue Feb 26, 2024
Open
@AlanGriffiths
Copy link
Collaborator Author

AlanGriffiths commented Feb 27, 2024 •
edited
Loading

OK, as discussed on #3066 (comment) this is (where I've seen it) mostly a problem with compositing on the DisplayLink driver being CPU intensive.

For my purposes (software development rather than gaming or video playback) an effective mitigation is to add composite-delay=60 to the .config.

@AlanGriffiths AlanGriffiths mentioned this issue Feb 29, 2024
Closed
@AlanGriffiths
Copy link
Collaborator Author

OK, there are two modes. With the compositing mitigation in place I again got:

Samples: 39K of event 'cycles:P', Event count (approx.): 42343509567
Overhead  Command          Shared Object                                              Symbol
  62.78%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x471f6            d [.] miral::Window::application()
  29.23%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50bfd            d [.] 0x0000000000050bfd
   1.65%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b2a            d [.] 0x0000000000050b2a
   1.63%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50ba3            d [.] 0x0000000000050ba3
   1.56%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b40            d [.] 0x0000000000050b40
   1.46%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b62            d [.] 0x0000000000050b62
   1.18%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b0a            d [.] 0x0000000000050b0a
   0.31%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b19            d [.] 0x0000000000050b19
   0.07%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b04            d [.] 0x0000000000050b04
   0.04%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50c04            d [.] 0x0000000000050c04
   0.01%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b47            d [.] 0x0000000000050b47
   0.01%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8f601149 ! [k] 0xffffffff8f601149
   0.01%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8f6011f7 ! [k] 0xffffffff8f6011f7
   0.01%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b0f            d [.] 0x0000000000050b0f
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8f51cc9b ! [k] 0xffffffff8f51cc9b
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e604000 ! [k] 0xffffffff8e604000
   0.00%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b2f            d [.] 0x0000000000050b2f
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e571a37 ! [k] 0xffffffff8e571a37
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e4bb564 ! [k] 0xffffffff8e4bb564
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e5c0875 ! [k] 0xffffffff8e5c0875
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8f600eb0 ! [k] 0xffffffff8f600eb0
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e58e17b ! [k] 0xffffffff8e58e17b
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e4a0475 ! [k] 0xffffffff8e4a0475
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e565335 ! [k] 0xffffffff8e565335
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e551815 ! [k] 0xffffffff8e551815
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8f6011c9 ! [k] 0xffffffff8f6011c9
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e5ec409 ! [k] 0xffffffff8e5ec409
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e5428fa ! [k] 0xffffffff8e5428fa
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8f517f3e ! [k] 0xffffffff8f517f3e
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e5f04cf ! [k] 0xffffffff8e5f04cf
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e57128b ! [k] 0xffffffff8e57128b
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e5327dd ! [k] 0xffffffff8e5327dd
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e5eee40 ! [k] 0xffffffff8e5eee40
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e5327d9 ! [k] 0xffffffff8e5327d9
   0.00%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b1e            d [.] 0x0000000000050b1e
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e5428de ! [k] 0xffffffff8e5428de
   0.00%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50b69            d [.] 0x0000000000050b69
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e54b9c9 ! [k] 0xffffffff8e54b9c9
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e76c0dd ! [k] 0xffffffff8e76c0dd
   0.00%  Mir/Input Reade  /snap/miriway/3180/usr/lib/x86_64-linux-gnu/libmiral.so.7  0x50bb0            d [.] 0x0000000000050bb0
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8f601578 ! [k] 0xffffffff8f601578
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e771fce ! [k] 0xffffffff8e771fce
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e5c648e ! [k] 0xffffffff8e5c648e
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e4bb566 ! [k] 0xffffffff8e4bb566
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e45e671 ! [k] 0xffffffff8e45e671
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e45e67b ! [k] 0xffffffff8e45e67b
   0.00%  Mir/Input Reade  [kernel.kallsyms]                                          0xffffffff8e4ac136 ! [k] 0xffffffff8e4ac136

@AlanGriffiths
Copy link
Collaborator Author

I've tried switching back to GNOME for a while, and that definitely doesn't use as much CPU when using DisplayLink.

@AlanGriffiths
Copy link
Collaborator Author

A (new) manifestation:

After upgrading to 24.04, "DisplayLink 6.0", and using "Miriway 129-mir2.17.0 (4052)" running yambar bumps the miriway-shell CPU usage from around 3-4% to around 30-40%.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
triaged Triage into JIRA to plan it in
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@Saviq @RAOF @AlanGriffiths