Bug 288675

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?

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).

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

I see Pulseaudio in the Stacktrace. Is it probably leaking channels?

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.

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.

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".

#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 ?? ()

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.

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.

see also bug 288619

*** Bug 288619 has been marked as a duplicate of this bug. ***

marking confirmed, enough 'me too's' and dups.

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 :)

Created attachment 66921 [details]
kmix using almost 2GB of memory and 25% CPU (on a 4 core system)

(In reply to comment #15)

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

25% CPU total on a system with 4 cores?

(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.

*** Bug 289501 has been marked as a duplicate of this bug. ***

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.

(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.

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.

*** Bug 288983 has been marked as a duplicate of this bug. ***

I can confirm it - Kubuntu 11.10-64bit, latest beta of KDE4.8.

I can confirm too on Kubuntu 11.10-64bit, KDE4.8 RC1 (4.7.95)

I can confirm using kubuntu/ppa RC1 packages. The for me: using amarok triggers that bug

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.)

*** Bug 289922 has been marked as a duplicate of this bug. ***

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

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

Please try again with the newest from branch 4.8 (or trunk). I might have just fixed that today.

*** Bug 289720 has been marked as a duplicate of this bug. ***

*** Bug 290017 has been marked as a duplicate of this bug. ***

*** Bug 290139 has been marked as a duplicate of this bug. ***

That fixed it here. Thanks!

Updated to kdemultimedia-4.7.95-2.fc16.x86_64 and associated packages and it seems fixed here as well on Fedora 16

Works for me, also fixes #285017, but creates #290197

*** Bug 289682 has been marked as a duplicate of this bug. ***

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 ?

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.

Hi,

Are there any patches that packagers could use to fix this lil' problem for those of us beta testing 4.8 ?

Created attachment 67275 [details]
Patch for Bug 288675

Patch for Bug 288675, please apply against KDE4.8 RC1

Thank you very much kind sir :)

*** Bug 289630 has been marked as a duplicate of this bug. ***

As per comment #29, this is fixed.

This seems fixed for me too. Thanks a lot!

*** Bug 285017 has been marked as a duplicate of this bug. ***