Bug 288675 - kmix uses 100% cpu
Summary: kmix uses 100% cpu
Status: RESOLVED FIXED
Alias: None
Product: kmix
Classification: Applications
Component: general (show other bugs)
Version: 3.9
Platform: Arch Linux Linux
: HI crash
Target Milestone: ---
Assignee: Christian Esken
URL:
Keywords:
: 288619 288983 289501 289630 289682 289720 289922 290017 290139 (view as bug list)
Depends on:
Blocks:
 
Reported: 2011-12-10 18:34 UTC by Timothée Ravier
Modified: 2012-04-08 10:07 UTC (History)
29 users (show)

See Also:
Latest Commit:
Version Fixed In:


Attachments
Backtrace of kmix SVN 1268585 hanging, consuming 100% CPU (9.36 KB, text/plain)
2011-12-14 06:08 UTC, Elias Probst
Details
strace kmix 3.8 after KDE start, normal operation, then 100% cpu (46.00 KB, text/plain)
2011-12-15 09:21 UTC, Max
Details
backtrace while kmix takes 100% cpu (7.48 KB, text/plain)
2011-12-19 15:19 UTC, Michael
Details
kmix using almost 2GB of memory and 25% CPU (on a 4 core system) (109.71 KB, image/png)
2011-12-20 00:20 UTC, Jorge Adriano
Details
Patch for Bug 288675 (6.76 KB, patch)
2011-12-31 12:33 UTC, Christian Esken
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Timothée Ravier 2011-12-10 18:34:54 UTC
Version:           3.9 (using Devel) 
OS:                Linux

After a random time, kmix starts taking 100% cpu.

Reproducible: Sometimes

Steps to Reproduce:
Play some music, wait. It happened at least 4 times on my Arch KDE since I switched to KDE 4.8 beta 1. Still here in beta 2.


Expected Results:  
kmix should not use 100% cpu
Comment 1 Elias Probst 2011-12-11 19:22:11 UTC
Using:
- KDE SC 4.7.90 (4.8.0 beta 2)
- Qt 4.7.2
- PulseAudio 0.9.22

It happens here only when clicking on KMix' systray icon.
Attaching strace to it shows an ever repeating output of this:

write(2, "kmix(20650) ViewBase::createDeviceWidgets: CONNECT ViewBase count  1\n", 69) = 69
write(2, "kmix(20650) ViewBase::createDeviceWidgets: CONNECT ViewBase controlschanged \"PulseAudio::Playback_Streams:1\"\n", 109) = 109
write(2, "kmix(20650) ViewBase::controlsReconfigured: ViewBase::controlsReconfigured()  \"PulseAudio::Playback_Streams:1\"  is being redrawn (mixset contains:  2 )\n", 152) = 152
write(2, "kmix(20650) ViewBase::controlsReconfigured: ViewBase::controlsReconfigured()  \"PulseAudio::Playback_Streams:1\" : Recreating widgets (mixset contains:  2 )\n", 155) = 155
write(2, "kmix(20650) ViewBase::createDeviceWidgets: CONNECT ViewBase count  1\n", 69) = 69
write(2, "kmix(20650) ViewBase::createDeviceWidgets: CONNECT ViewBase controlschanged \"PulseAudio::Playback_Streams:1\"\n", 109) = 109
write(2, "kmix(20650) ViewBase::controlsReconfigured: ViewBase::controlsReconfigured()  \"PulseAudio::Playback_Streams:1\"  is being redrawn (mixset contains:  2 )\n", 152) = 152
write(2, "kmix(20650) ViewBase::controlsReconfigured: ViewBase::controlsReconfigured()  \"PulseAudio::Playback_Streams:1\" : Recreating widgets (mixset contains:  2 )\n", 155) = 155
brk(0xa21b000)                          = 0xa21b000

At the moment when clicking on it/making it hang, there's this output on the terminal from which KMix was started:
kmix(7108) KMixDockWidget::activate: Activate at  QPoint(1658,1044)
kmix(7108) KMixDockWidget::activate: Skip default KStatusNotifierItkdebem behavior
kmix(7108) KMixDockWidget::activate: cm is NOT visible => setAssociatedWidget(_referenceWidget)
kmix(7108) KMixDockWidget::activate: moving to QSize(204, 127) 1556 917


Couldn't get any usable information using gdb so far. Are there any other known ways to reproduce this problem?
Comment 2 Timothée Ravier 2011-12-11 23:42:47 UTC
Using: (Arch Linux testing)
- KDE SC 4.7.90 (4.8.0 beta 2)
- Qt 4.7.4
- PulseAudio 1.1
- VLC 1.1.12 (not sure this is relevant)

Indeed, it seems to hapen only once you've click on the systray icon. For a while after the first click, everything works just as expected. Then suddenly, it goes wild.

I didn't choose "repoducible: always" as I haven't actively tried to reproduce the bug (yet).
Comment 3 Max 2011-12-13 17:03:33 UTC
s114-intel:~ # kmix --version
Qt: 4.7.1
KDE: 4.6.00 (4.6.0) "release 6"
KMix: 3.8

Similar problem in Opensuse 11.4, symptoms: 100% CPU on 1 core, switching after minutes to another core. When: after Login, no sound played, system sounds turned off (I think), click on tray icon has no effect whatsoever, not even in the strace. Sound is working when playing!

Strace shows only: 
brk(0x4373000)                          = 0x4373000
brk(0x4394000)                          = 0x4394000
brk(0x43b5000)                          = 0x43b5000
brk(0x43d6000)                          = 0x43d6000
brk(0x43f7000)                          = 0x43f7000
brk(0x4418000)                          = 0x4418000
brk(0x4439000)                          = 0x4439000
brk(0x445a000)                          = 0x445a000
brk(0x447b000)                          = 0x447b000
brk(0x449c000)                          = 0x449c000
...

What else can I do to find the bug?

Max
Comment 4 Christian Esken 2011-12-13 22:27:32 UTC
I see Pulseaudio in the Stacktrace. Is it probably leaking channels?
Comment 5 Colin Guthrie 2011-12-13 22:51:14 UTC
This looks like some kind of feedback loop introduced in master. I'd suggest trying to do a bisect but due to some missing headers you forgot to commit for several revisions, this is nigh on impossible (I tried a few weeks ago to do this without success) :(

I really do not have the time to support these changes. I spent a very long time trying to squeeze PA support into kmix but the constructs are really hard to work with and I really cannot spend time looking into this after a refactor in trunk. Really sorry, but I just don't have time.

As this is the default setup on pretty much all distros I really, really advise you set your system up to work with PA properly so you can test this stuff after you make changes.
Comment 6 Christian Esken 2011-12-13 23:11:10 UTC
Missing headers? Oops? Which? Lately? I haven't heard about those. I am confused now.
The problem with setting up my system properly for PA is that it doesn't work: I am trying 2 times a year and it is unfortunately always hell. So I only test from time to time. Last was (... checking ... ... ) in Mid-November, and it basically looked OK. CPU usage is better in ALSA, but I did not recognize any significant memleaks.
Comment 7 Christian Esken 2011-12-13 23:51:16 UTC
I found a way to reproduce it. When I am using "pa-cmd" and massively add streams via "play-file /Multimedia/Kennedy_berliner.ogg 0" it happens sooner or later. Stacktrace snapshot in next comment.

As far as I can understand this issue is only fixable via a major architecture change. I am thinking of a clean communication flow, e.g. via a cleanly synchronized and order-obeying Command-Queue, with commands like "add-stream for card 1" or "recreate GUI".
Comment 8 Christian Esken 2011-12-13 23:51:50 UTC
#0  0x00007f7aa909bec7 in QCoreApplication::removePostedEvents(QObject*, int) () from /usr/lib64/libQtCore.so.4
#1  0x00007f7aa82947c8 in QWidget::~QWidget() () from /usr/lib64/libQtGui.so.4
#2  0x00007f7aa9c38549 in KMenu::~KMenu() () from /usr/lib64/libkdeui.so.5
#3  0x00007f7aa90ab1b4 in QObjectPrivate::deleteChildren() () from /usr/lib64/libQtCore.so.4
#4  0x00007f7aa82947c0 in QWidget::~QWidget() () from /usr/lib64/libQtGui.so.4
#5  0x00007f7aaabdc2f1 in MixDeviceWidget::~MixDeviceWidget (this=0x2a1c370, __in_chrg=<value optimized out>)
    at /home/kde/workspace/kmix/kmix/gui/mixdevicewidget.cpp:76
#6  0x00007f7aaabe2fef in MDWSlider::~MDWSlider (this=0x2a1c370, __in_chrg=<value optimized out>) at /home/kde/workspace/kmix/kmix/gui/mdwslider.h:59
#7  0x00007f7aaabe302a in MDWSlider::~MDWSlider (this=0x2a1c370, __in_chrg=<value optimized out>) at /home/kde/workspace/kmix/kmix/gui/mdwslider.h:59
#8  0x00007f7aaabd695e in ViewBase::setMixSet (this=0x9e7ee0) at /home/kde/workspace/kmix/kmix/gui/viewbase.cpp:253
#9  0x00007f7aaabd6710 in ViewBase::controlsReconfigured (this=0x9e7ee0, mixer_ID=...) at /home/kde/workspace/kmix/kmix/gui/viewbase.cpp:217
#10 0x00007f7aaabd7c1b in ViewBase::qt_metacall (this=0x9e7ee0, _c=QMetaObject::InvokeMetaMethod, _id=3, _a=0x7fff458fe390)
    at /home/kde/workspace/kmix-BUILD/kmix/viewbase.moc:89
#11 0x00007f7aaabdb537 in ViewSliders::qt_metacall (this=0x9e7ee0, _c=QMetaObject::InvokeMetaMethod, _id=30, _a=0x7fff458fe390)
    at /home/kde/workspace/kmix-BUILD/kmix/viewsliders.moc:67
#12 0x00007f7aa90addcf in QMetaObject::activate(QObject*, QMetaObject const*, int, void**) () from /usr/lib64/libQtCore.so.4
#13 0x00007f7aaabfc429 in Mixer::controlsReconfigured (this=0x847f50, _t1=...) at /home/kde/workspace/kmix-BUILD/kmix/mixer.moc:110
#14 0x00007f7aaabfc325 in Mixer::qt_metacall (this=0x847f50, _c=QMetaObject::InvokeMetaMethod, _id=2, _a=0x7fff458fe4c0)
    at /home/kde/workspace/kmix-BUILD/kmix/mixer.moc:83
#15 0x00007f7aa90addcf in QMetaObject::activate(QObject*, QMetaObject const*, int, void**) () from /usr/lib64/libQtCore.so.4
#16 0x00007f7aaabae7a1 in Mixer_Backend::controlsReconfigured (this=0x8e4040, _t1=...) at /home/kde/workspace/kmix-BUILD/kmix/mixer_backend.moc:100
#17 0x00007f7aaabae6e8 in Mixer_Backend::qt_metacall (this=0x8e4040, _c=QMetaObject::InvokeMetaMethod, _id=1, _a=0xc3b280)
    at /home/kde/workspace/kmix-BUILD/kmix/mixer_backend.moc:80
#18 0x00007f7aa90aca4a in QObject::event(QEvent*) () from /usr/lib64/libQtCore.so.4
#19 0x00007f7aa8247d14 in QApplicationPrivate::notify_helper(QObject*, QEvent*) () from /usr/lib64/libQtGui.so.4
#20 0x00007f7aa825022a in QApplication::notify(QObject*, QEvent*) () from /usr/lib64/libQtGui.so.4
#21 0x00007f7aa9c719e6 in KApplication::notify(QObject*, QEvent*) () from /usr/lib64/libkdeui.so.5
#22 0x00007f7aa9098bdc in QCoreApplication::notifyInternal(QObject*, QEvent*) () from /usr/lib64/libQtCore.so.4
#23 0x00007f7aa909c3d5 in QCoreApplicationPrivate::sendPostedEvents(QObject*, int, QThreadData*) () from /usr/lib64/libQtCore.so.4
#24 0x00007f7aa90c3763 in ?? () from /usr/lib64/libQtCore.so.4
#25 0x00007f7aa720b7d3 in g_main_context_dispatch () from /lib64/libglib-2.0.so.0
---Type <return> to continue, or q <return> to quit---
#26 0x00007f7aa720bfb0 in ?? () from /lib64/libglib-2.0.so.0
#27 0x00007f7aa720c250 in g_main_context_iteration () from /lib64/libglib-2.0.so.0
#28 0x00007f7aa90c38ff in QEventDispatcherGlib::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib64/libQtCore.so.4
#29 0x00007f7aa82ecd8e in ?? () from /usr/lib64/libQtGui.so.4
#30 0x00007f7aa9098032 in QEventLoop::processEvents(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib64/libQtCore.so.4
#31 0x00007f7aa9098245 in QEventLoop::exec(QFlags<QEventLoop::ProcessEventsFlag>) () from /usr/lib64/libQtCore.so.4
#32 0x00007f7aa909c68b in QCoreApplication::exec() () from /usr/lib64/libQtCore.so.4
#33 0x00007f7aaabc6d98 in kdemain (argc=1, argv=0x7fff458ff478) at /home/kde/workspace/kmix/kmix/apps/main.cpp:76
#34 0x00000000004008a6 in kdeinitmain (argc=32767, argv=0x0) at /home/kde/workspace/kmix-BUILD/kmix/kmix_dummy.cpp:2
#35 0x00007fff458ff478 in ?? ()
#36 0x0000000100000000 in ?? ()
#37 0x0000000000000000 in ?? ()
Comment 9 Elias Probst 2011-12-14 06:08:43 UTC
Created attachment 66722 [details]
Backtrace of kmix SVN 1268585 hanging, consuming 100% CPU

Built kmix now from SVN (Rev 1268585) and it happened again. Attached a backtrace of kmix hanging, consuming 100% CPU.
Comment 10 Max 2011-12-15 09:21:33 UTC
Created attachment 66769 [details]
strace kmix 3.8 after KDE start, normal operation, then 100% cpu

Record the moment when kmix goes into a loop.
Comment 11 Francesco Riosa 2011-12-18 19:38:53 UTC
see also bug 288619
Comment 12 Michael 2011-12-19 15:12:38 UTC
*** Bug 288619 has been marked as a duplicate of this bug. ***
Comment 13 Rex Dieter 2011-12-19 15:15:22 UTC
marking confirmed, enough 'me too's' and dups.
Comment 14 Michael 2011-12-19 15:19:35 UTC
Created attachment 66903 [details]
backtrace while kmix takes 100% cpu

Not only does kmix use 100% of one core, its memory usage also continues to grow.

I am setting that to assigned, as enough people including me can confirm that issue.

Hopefully we can get that fixed soon :)
Comment 15 Jorge Adriano 2011-12-20 00:20:24 UTC
Created attachment 66921 [details]
kmix using almost 2GB of memory and 25% CPU (on a 4 core system)
Comment 16 Max 2011-12-21 09:28:10 UTC
(In reply to comment #15)

> kmix using almost 2GB of memory and 25% CPU

25% CPU total on a system with 4 cores?
Comment 17 Jorge Adriano 2011-12-21 10:20:14 UTC
(In reply to comment #16)
> (In reply to comment #15)
> 
> > kmix using almost 2GB of memory and 25% CPU
> 
> 25% CPU total on a system with 4 cores?

Yes.
Comment 18 Christian Esken 2011-12-22 11:40:51 UTC
*** Bug 289501 has been marked as a duplicate of this bug. ***
Comment 19 Christian Esken 2011-12-22 23:55:46 UTC
This is indeed a very bad bug, and I need to fix it fast. I see this as a  KDE4.8 showstopper, as KMix is one of the Application that is run by "every" KDE user and I fear most users will be hit by this bug sooner or later.
Comment 20 Francesco Riosa 2011-12-23 02:13:19 UTC
(In reply to comment #19)
> [...] I see this as a KDE4.8 showstopper [...]
yep we agree :)
If you cannot reproduce feel free to ask whatever you need (running kde from git here), here it seem to be triggered by many browser tab open, with a number of flash movies.
Comment 21 Myriam Schweingruber 2011-12-23 11:54:45 UTC
I can reproduce this reliably in KDE 4.7.90 on Kubuntu 11.10 either by starting Dragonplayer or Amarok: after a while it goes up to 100% CPU and stays there even after the application was closed.
Comment 22 Tommi Tervo 2011-12-23 17:24:16 UTC
*** Bug 288983 has been marked as a duplicate of this bug. ***
Comment 23 Tom Kijas 2011-12-27 23:30:41 UTC
I can confirm it - Kubuntu 11.10-64bit, latest beta of KDE4.8.
Comment 24 Andreas Roth 2011-12-28 10:13:32 UTC
I can confirm too on Kubuntu 11.10-64bit, KDE4.8 RC1 (4.7.95)
Comment 25 Robby Engelmann 2011-12-28 16:16:59 UTC
I can confirm using kubuntu/ppa RC1 packages. The for me: using amarok triggers that bug
Comment 26 S Clark 2011-12-29 04:58:01 UTC
I've also seen this triggered by flash plugin running within firefox, so it's not just KDE applications setting this off. (I usually end up "kill -HUP" the kmix process.  The problem doesn't IMMEDIATELY recur if I then restart kmix, but it does pop up again eventually - at least so far.)
Comment 27 Christian Esken 2011-12-29 16:16:56 UTC
*** Bug 289922 has been marked as a duplicate of this bug. ***
Comment 28 Christian Esken 2011-12-30 12:06:37 UTC
SVN commit 1270926 by esken:

Fix infinite loop leading to 100% CPU usage (on reconstruction a newly connected signal would be implicitely emitted ("again"), which leads to reconstruction and newly connecting the signal, and so forth).
Fixed in trunk. This MUST be committed to all affected branches!!!

 M  +33 -1     kmixerwidget.cpp  
 M  +5 -0      kmixerwidget.h  
 M  +18 -0     mdwslider.cpp  
 M  +1 -1      mdwslider.h  
 M  +1 -1      mixdevicewidget.h  
 M  +8 -11     viewbase.cpp  
 M  +3 -1      viewbase.h  


WebSVN link: http://websvn.kde.org/?view=rev&revision=1270926
Comment 29 Christian Esken 2011-12-30 12:19:05 UTC
SVN commit 1270928 by esken:

Fix infinite loop leading to 100% CPU usage and excessively allocating memory (on reconstruction a newly connected signal would be implicitely emitted ("again"), which leads to reconstruction and newly connecting the signal, and so forth).
Backport to branch 4.8. Please note that I consider this bug as a showstopper for KDE4.8 (this bug will affect most users, leads to 100% CPU usage, and possibly eat up all available memory).
Related: bug 289682

 M  +33 -1     kmixerwidget.cpp  
 M  +5 -0      kmixerwidget.h  
 M  +11 -0     mdwslider.cpp  
 M  +1 -1      mdwslider.h  
 M  +1 -1      mixdevicewidget.h  
 M  +8 -11     viewbase.cpp  
 M  +3 -1      viewbase.h  


WebSVN link: http://websvn.kde.org/?view=rev&revision=1270928
Comment 30 Christian Esken 2011-12-30 12:42:36 UTC
Please try again with the newest from branch 4.8 (or trunk). I might have just fixed that today.
Comment 31 Christian Esken 2011-12-30 12:49:55 UTC
*** Bug 289720 has been marked as a duplicate of this bug. ***
Comment 32 Christian Esken 2011-12-30 17:00:39 UTC
*** Bug 290017 has been marked as a duplicate of this bug. ***
Comment 33 Christian Esken 2011-12-30 17:01:03 UTC
*** Bug 290139 has been marked as a duplicate of this bug. ***
Comment 34 Thomas Kuther 2011-12-30 17:42:58 UTC
That fixed it here. Thanks!
Comment 35 Colin J Thomson 2011-12-30 17:51:57 UTC
Updated to kdemultimedia-4.7.95-2.fc16.x86_64 and associated packages and it seems fixed here as well on Fedora 16
Comment 36 Hrvoje Senjan 2011-12-30 18:22:08 UTC
Works for me, also fixes #285017, but creates #290197
Comment 37 Christian Esken 2011-12-30 19:22:24 UTC
*** Bug 289682 has been marked as a duplicate of this bug. ***
Comment 38 Søren Holm 2011-12-31 00:03:54 UTC
hmmm ... I did not see dbus or virtuoso-t being mensioned here. I experience that kmix using 100% cpu is related to virtuoso-t going crazy. Much dbus-traffic or whatever..... does that seem plausible ?
Comment 39 Kevin Kofler 2011-12-31 02:46:08 UTC
No, it doesn't. The infinite loop in KMix has already been identified and fixed, it has absolutely nothing to do with Virtuoso, and anyway I don't see how it could have had anything to do with it.
Comment 40 Silviu C. 2011-12-31 11:40:59 UTC
Hi,

Are there any patches that packagers could use to fix this lil' problem for those of us beta testing 4.8 ?
Comment 41 Christian Esken 2011-12-31 12:33:02 UTC
Created attachment 67275 [details]
Patch for Bug 288675

Patch for Bug 288675, please apply against KDE4.8 RC1
Comment 42 Silviu C. 2011-12-31 12:53:54 UTC
Thank you very much kind sir :)
Comment 43 Joaquin Luciano 2012-01-02 01:18:05 UTC
*** Bug 289630 has been marked as a duplicate of this bug. ***
Comment 44 Myriam Schweingruber 2012-01-02 11:32:02 UTC
As per comment #29, this is fixed.
Comment 45 Timothée Ravier 2012-01-04 19:59:57 UTC
This seems fixed for me too. Thanks a lot!
Comment 46 Colin Guthrie 2012-04-08 10:00:25 UTC
*** Bug 285017 has been marked as a duplicate of this bug. ***