Bug 452726

Summary: 100% cpu usage of kwin_wayland
Product: [Plasma] kwin Reporter: Jaime Torres <jtamate>
Component: platform-drmAssignee: KWin default assignee <kwin-bugs-null>
Status: RESOLVED FIXED    
Severity: normal CC: buddha, kde, kde, kt47uo5uvzw, michael.olbrich, msentunali, nate
Priority: NOR Keywords: wayland-only
Version: 5.25.4   
Target Milestone: ---   
Platform: unspecified   
OS: Linux   
Latest Commit: Version Fixed In: 5.26
Sentry Crash Report:
Attachments: The perf data in txt format

Description Jaime Torres 2022-04-18 09:51:09 UTC
SUMMARY
The elastic launch cursor animation for an application start makes kwin_wayland to use 100% of one cpu.
I've changed the cursor to remove the animation and this 100% cpu issue is gone.

STEPS TO REPRODUCE
1.  have two wayland sessions with two different users (for example in Ctrl+Alt+F2 and Ctrl+Alt+F3)
2.  have in the user of Ctrl+F2 firefox with several tabs and windows
3.  have configured the elastic cursor animation for notification launching an app
4. have top or similar running in the other session.
5.  launch firefox, and switch inmediately to the other session (Ctrl+Alt+F3)

OBSERVED RESULT
I get always 100% kwin_wayland cpu usage.

EXPECTED RESULT
Normal cpu usage.

SOFTWARE/OS VERSIONS
Operating System: openSUSE Tumbleweed 20220411
KDE Plasma Version: 5.24.4
KDE Frameworks Version: 5.93.0
Qt Version: 5.15.2
Kernel Version: 5.17.1-1.g47fa9ec-default (64-bit)
Graphics Platform: Wayland
Processors: 6 × AMD Phenom(tm) II X6 1100T Processor
Memory: 15.6 GiB of RAM
Graphics Processor: AMD JUNIPER

ADDITIONAL INFORMATION
Information from perf record -g -p pid  and then perf report -s srcline

Samples: 617K of event 'cycles', Event count (approx.): 343103171448
  Children      Self  Source:Line
+   93.26%    41.66%  ??:0                                                                                                                                                                                       +   +   25.04%     0.00%  ppoll+139825755533488                                                                                                                                                                      +   19.92%     0.00%  QSocketNotifier::qt_metacast+139825763225600                                                                                                                                               +   17.25%     0.00%  recvmsg+139825755533409                                                                                                                                                                    +   15.87%     0.00%  QEventDispatcherUNIXPrivate::~QEventDispatcherUNIXPrivate+139825763225600                                                                                                                  +    3.59%     0.00%  QHashData::nextNode+139825763225627                                                                                                                                                        +    3.59%     3.59%  qhash.cpp:595                                                                                                                                                                              +    3.06%     0.00%  QSocketNotifier::activated+139825763225695                                                                                                                                                 +    2.67%     0.00%  QEventDispatcherUNIX::processEvents+139825763226503                                                                                                                                        +    2.32%     0.00%  QEventDispatcherUNIX::processEvents+139825763225654                                                                                                                                        +    1.73%     1.73%  qobjectdefs_impl.h:411                                                                                                                                                                     +    1.72%     1.72%  atomic_base.h:880                                                                                                                                                                          +    1.53%     0.00%  wl_display_flush_clients+139825749340195                                                                                                                                                   +    1.53%     1.53%  wl_display_flush_clients+35                                                                                                                                                                +    1.42%     0.00%  wl_display_flush_clients+139825749340236                                                                                                                                                   +    1.42%     1.42%  wl_display_flush_clients+76                                                                                                                                                                +    1.32%     1.32%  atomic_base.h:838                                                                                                                                                                          +    1.21%     0.00%  wl_display_flush_clients+139825749340240                                                                                                                                                   +    1.21%     1.21%  wl_display_flush_clients+80                                                                                                                                                                +    1.13%     1.13%  qobject.cpp:1445                                                                                                                                                                           +    1.08%     1.08%  breezetoolsareamanager.cpp:129                                                                                                                                                             +    1.05%     0.00%  QObject::eventFilter+139825763225600                                                                                                                                                       +    1.03%     0.00%  Breeze::AppListener::eventFilter+139825675771906                                                                                                                                           +    1.03%     0.00%  QtPrivate::QSlotObject<void (KWin::DrmGpu::*)(), QtPrivate::List<>, void>::impl+139825666580482                                                                                            +    0.94%     0.94%  kcheckaccelerators.cpp:137                                                                                                                                                                 +    0.90%     0.00%  KCheckAccelerators::eventFilter+139825747832834                                                                                                                                            +    0.90%     0.90%  PlasmaQuick::ConfigView::qt_metacall+2306                                                                                                                                                  +    0.90%     0.00%  PlasmaQuick::ConfigView::qt_metacall+139824822937858                                                                                                                                       +    0.87%     0.00%  __clock_gettime+139825755533343                                                                                                                                                            +    0.85%     0.85%  recvmsg.c:35                                                                                                                                                                               +    0.84%     0.00%  QMutex::unlock+139825763225605                                                                                                                                                             +    0.82%     0.00%  QEvent::~QEvent+139825763225600                                                                                                                                                            +    0.80%     0.80%  recvmsg.c:27                                                                                                                                                                               +    0.77%     0.00%  recvmsg+139825755533316                                                                                                                                                                    +    0.70%     0.70%  qcoreapplication.cpp:1180                                                                                                                                                                  +    0.68%     0.68%  qcoreevent.h:301                                                                                                                                                                           +    0.68%     0.00%  qt_plugin_instance+139824823632658                                                                                                                                                         +    0.67%     0.67%  qt_plugin_instance+103186                                                                                                                                                                  +    0.65%     0.00%  QtPrivate::QSlotObject<void (KWin::Xwl::Xwayland::*)(), QtPrivate::List<>, void>::impl+94243826286594                                                                                      +    0.63%     0.00%  Plasma::AppletScript::uiReadyChanged+139825800749330                                                                                                                                       +    0.63%     0.63%  Plasma::AppletScript::uiReadyChanged+274                                                                                                                                                   +    0.59%     0.59%  pthread_mutex_unlock.c:367                                                                                                                                                                 +    0.57%     0.00%  Breeze::Mnemonics::eventFilter+139825675771908
Comment 1 Jaime Torres 2022-04-18 09:54:27 UTC
Created attachment 148215 [details]
The perf data in txt format
Comment 2 Marco Martin 2022-04-19 14:05:50 UTC
*** Bug 452657 has been marked as a duplicate of this bug. ***
Comment 3 kt47uo5uvzw 2022-05-01 14:29:03 UTC
Any ideas? Because I can't work with multi user logged in as the cpu and fan usage is really high then.
Comment 4 Jaime Torres 2022-05-02 13:45:12 UTC
Another workaround, apart from disabling the cursor animation, seems to be changing the window decorations to plastik. Apparently it is not affected. The maximum peaks I get so far is 20% CPU usage..
Comment 5 kt47uo5uvzw 2022-05-04 11:15:57 UTC
(In reply to Jaime Torres from comment #4)
> Another workaround, apart from disabling the cursor animation, seems to be
> changing the window decorations to plastik. Apparently it is not affected.
> The maximum peaks I get so far is 20% CPU usage..

Thanks for some ideas, but nothing helped. What can I do to help finding the bug?
Comment 6 David Edmundson 2022-06-16 10:41:50 UTC
I can reproduce a simpler case:

run glxgears on a given session
switch VT to a terminal

kwin_wayland CPU spikes
Comment 7 Michael Olbrich 2022-06-19 11:11:06 UTC
I can reproduce this as well. From what I've seen it happens when kwin is busy with something related to rendering during the VT switch. So any application with continuous frame updates will trigger this.

I've attached gdb to see if I can figure out what is going on. It seems kwin is busy looping in the event loop.
In QEventDispatcherUNIXPrivate::markPendingSocketNotifiers() pfd.revents is POLLIN for an fd for /dev/dri/card0.
I tried to single step through the code to find whatever function should handle this event but I never got anywhere outside the Qt core code.

I guess the handler of this event was in some way disabled when switching VTs but the event is still queued.

Btw, I'm running 5.25.0 right now but I've seen this with 5.24.5 as well.
Comment 8 kt47uo5uvzw 2022-08-11 09:41:10 UTC
For me it's the major bug number one. I always have to logout first before I can switch to another user and that's annoying. If I can help with some logging or testing, let me know. I don't know where to begin. Have also tried a clean reinstall. Thanks!
Comment 9 kt47uo5uvzw 2022-09-03 15:06:08 UTC
*** Bug 456304 has been marked as a duplicate of this bug. ***
Comment 10 hexchain 2022-09-03 15:16:39 UTC
(In reply to David Edmundson from comment #6)
> I can reproduce a simpler case:
> 
> run glxgears on a given session
> switch VT to a terminal
> 
> kwin_wayland CPU spikes

Can confirm this reproducer works most of the time.
Comment 11 Bug Janitor Service 2022-09-26 19:16:46 UTC
A possibly relevant merge request was started @ https://invent.kde.org/plasma/kwin/-/merge_requests/3002
Comment 12 Vlad Zahorodnii 2022-09-27 07:42:04 UTC
Git commit 1d8c9c62cffe74d60636d6840d486a50b7b82003 by Vlad Zahorodnii.
Committed on 27/09/2022 at 07:29.
Pushed by vladz into branch 'master'.

backends/drm: Fix 100% cpu usage after tty switch

The drm fd can get stuck in readable state, in which case the
QSocketNotifier will fire the activated signal as often as it can
leading to high cpu usage.

We need to read() the drm fd in order to make the socket notifier stop
firing QSocketNotifier::activated.

This change removes the m_platform->isActive() check to ensure that
drmHandleEvent() gets called, in general, it should be safe as we only
notify the outputs about completed pageflips.

M  +0    -3    src/backends/drm/drm_gpu.cpp

https://invent.kde.org/plasma/kwin/commit/1d8c9c62cffe74d60636d6840d486a50b7b82003
Comment 13 Vlad Zahorodnii 2022-09-27 07:48:09 UTC
Git commit b870ec804b23a727bc926777820107dc5f2567a0 by Vlad Zahorodnii.
Committed on 27/09/2022 at 07:48.
Pushed by vladz into branch 'Plasma/5.26'.

backends/drm: Fix 100% cpu usage after tty switch

The drm fd can get stuck in readable state, in which case the
QSocketNotifier will fire the activated signal as often as it can
leading to high cpu usage.

We need to read() the drm fd in order to make the socket notifier stop
firing QSocketNotifier::activated.

This change removes the m_platform->isActive() check to ensure that
drmHandleEvent() gets called, in general, it should be safe as we only
notify the outputs about completed pageflips.


(cherry picked from commit 1d8c9c62cffe74d60636d6840d486a50b7b82003)

M  +0    -3    src/backends/drm/drm_gpu.cpp

https://invent.kde.org/plasma/kwin/commit/b870ec804b23a727bc926777820107dc5f2567a0