Bug 317926

I downgraded kmix to 4.10.1 and left all of KDE 4.10.2, but kmix start still delayed.
So maybe this problem somewhere in other KDE 4.10.2 components outside kmix.

Impossible to start any application from kickoff or from desktop until kmix not stared.

This is message from .xsession-errors with menubar style "Title bar button"

ESC[31mbool DBusMenuExporterDBus::AboutToShow(int)ESC[0m: Condition failed: menu

Bug still in 4.10.3.

Can confirm this under 4.10.3, too.

Confirming. Chakra Linux KDE 4.10.3..

This also happens when I use the plasma-widget-menubar in KDE 4.10.3

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

Git commit f2291ba1d062500aa0461f787a3801273f518aa1 by Christian Esken.
Committed on 22/05/2013 at 01:22.
Pushed by esken into branch 'master'.

Change MPRIS backend to asynchronous communication

M  +2    -1    backends/mixer_alsa9.cpp
M  +5    -0    backends/mixer_backend.cpp
M  +93   -5    backends/mixer_mpris2.cpp
M  +3    -1    backends/mixer_mpris2.h
M  +1    -1    core/version.h
M  +1    -1    gui/viewdockareapopup.cpp

http://commits.kde.org/kmix/f2291ba1d062500aa0461f787a3801273f518aa1

This is a call for testers: If you are able to compile KMix from trunk and run it, please do so and report back.

-----
Background information: Quite likely the issue originates from the MPRIS2 support available since KMix in KDE4.10. I now changed the MPRIS2 backend to use asynchronous communication that might fix the issue.

kmix-4.10.3 built in Fedora with patch "[PATCH 1/8] MPRIS2 backend now does a asynchonous DBUS instrospection", I also applied patch from Comment 9 except changes to gui/viewdockareapopup.cpp.
But nothing changed after applying patches, desktop freezed until kmix not started.

Here more messages from log before kmix start:

QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/Master_0" 
QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/Headphone_0" 
QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/Speaker_0" 
QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/PCM_0" 
QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/Mic_Boost_0" 
QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/IEC958_0" 
QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/Capture_0" 
QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/Auto_Mute_Mode_0_penum" 
QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/Digital_0" 
Attaching Media Players 
plasma-desktop(2469)/plasma StatusNotifierItemSource::refreshCallback: DBusMenu disabled for this application 

Here delay follows, and when kmix started this messages appeared

bool DBusMenuExporterDBus::AboutToShow(int): Condition failed: menu 
bool DBusMenuExporterDBus::AboutToShow(int): Condition failed: menu 
bool DBusMenuExporterDBus::AboutToShow(int): Condition failed: menu 
bool DBusMenuExporterDBus::AboutToShow(int): Condition failed: menu

kmix-4.10.3 with the patch might not be enough. Test can only be done with KMix from trunk.

Git commit ffcbcf4ad7f2ae8b4ae146c2c940b82fa58fb7a1 by Christian Esken.
Committed on 22/05/2013 at 02:50.
Pushed by esken into branch 'master'.

Temporarily enable polling mode for MPRIS2 backend. Currently required for properly processing changes from players.

M  +4    -1    backends/mixer_mpris2.h

http://commits.kde.org/kmix/ffcbcf4ad7f2ae8b4ae146c2c940b82fa58fb7a1

Delay also in KDE 4.10.4 .

(In reply to comment #9)
> Git commit f2291ba1d062500aa0461f787a3801273f518aa1 by Christian Esken.
> Committed on 22/05/2013 at 01:22.
> Pushed by esken into branch 'master'.
> 
> Change MPRIS backend to asynchronous communication
> 
> M  +2    -1    backends/mixer_alsa9.cpp
> M  +5    -0    backends/mixer_backend.cpp
> M  +93   -5    backends/mixer_mpris2.cpp
> M  +3    -1    backends/mixer_mpris2.h
> M  +1    -1    core/version.h
> M  +1    -1    gui/viewdockareapopup.cpp
> 
> http://commits.kde.org/kmix/f2291ba1d062500aa0461f787a3801273f518aa1

This code is still synchronous. You must *not* use waitForFinished() if you really want your code to be asynchronous. The same applies to any method that returns QDBusReply and all QDBusConnection::call*() methods.

Thanks Lamarque. Looks like you are absolutely right. 
I re-read the API docs. it should definitely be a bit more specific in documentation of waitForFinished(), but I understand it now, especially after also consulting the DBUS specification.
Doing it proper is tricky, but I can probably only do it like this:
 - Register a "Listener" for the DBUS reply. Return and to NEVER coldplug MPRIS devices.
 - "Hotplug" the MPRIS device once the DBUS reply comes in.

Actually I have no confirmed information how to go to full asynchronous operation correctly:
- Is it enough to do everything like now, but in a separate thread?
 - Or do I have to wire each and every DBUS call to a specific SLOT? The latter would really suck^H^H^H^H be highly inconvenient.

Lamarque (or anybody else): Do you have any insight in this?
I have implemented the former ("in a separate Thread"), but am not sure whether this is THE solution.

Also this asynchronous communication has the problem that I cannot easily do volume restoring in kmixctrl. Well, I could wait a some time until everything is hopefully there, but that again would need some extra coding. Luckily we do not have any asynchronous backends that do volume restoring (MPRIS2 and PA both skip restore).

Created attachment 81050 [details]
Move most DBUS commonication of the MPRIS2 backend to its own Thread

+/**
+ * Add a MPRIS control asynchronously. The concept works like this:
+ * 1) Queue a command
+ * 2) A different thread picks up the command, and executes all DBUS communication synchronously.
+ * 3) When that thread has everything collected (stream name, metadata, volume, ...), it emits plugged()
+ * 4) The GUI thread gets the plugged() signal, as it is connected to its slot notifyToReconfigureControls()
+ *
+ * It is supposed to work better, as the GUI thread is free to communicate and not locked. Well, that is the idea.
+ * I am not sure whether it actually works better than before.
+ *
+ */

(In reply to comment #17)
> Actually I have no confirmed information how to go to full asynchronous
> operation correctly:
> - Is it enough to do everything like now, but in a separate thread?

Well, that it is enough to prevent blocking the kded module, which is the main goal here. Just  to clarify: threaded program is not exactly the same as asynchronous program, you can even use both at the same time, although that is not usually done. 

>  - Or do I have to wire each and every DBUS call to a specific SLOT? The
> latter would really suck^H^H^H^H be highly inconvenient.

That is how you use the asynchronous Qt dbus api.

> Also this asynchronous communication has the problem that I cannot easily do
> volume restoring in kmixctrl. Well, I could wait a some time until
> everything is hopefully there, but that again would need some extra coding.
> Luckily we do not have any asynchronous backends that do volume restoring
> (MPRIS2 and PA both skip restore).

What you must do is prevent your kded module from blocking the entire kded daemon when processing a dbus call. You can do that by using QThread instead of the asynchronous Qt dbus api like you did. Just keep in mind that you cannot use QThread if your module uses a graphical class (inherited from QWidget) because QWidget objects must always belong to the main thread (the one that run the kded module in this case).

Lamarque, thanks for your input. I also received some more input, mainly from apachelogger. He convinced me that even the "thread"  solution might still hang MPRIS2 hotplugging - if only a single target application hangs. So I changed to a more or less fully asynchronous solution. I'll commit this in  a second to KDE trunk.

Git commit b3b8844690216b3af547775f549c192927022657 by Christian Esken.
Committed on 15/07/2013 at 22:26.
Pushed by esken into branch 'master'.

Change MPRSI2 backend to operate nearly completely asynchronously. The still synchronous parts will be converted in the next step.

M  +126  -140  backends/mixer_mpris2.cpp
M  +80   -21   backends/mixer_mpris2.h

http://commits.kde.org/kmix/b3b8844690216b3af547775f549c192927022657

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

Git commit 6e7fb0b5ea8fb399dca5c85b51c3389d7be9b96f by Christian Esken.
Committed on 17/07/2013 at 21:35.
Pushed by esken into branch 'master'.

Fixes for memory leaks, unitialized values. Also do error checks before evaluating DBUS reply.

M  +77   -49   backends/mixer_mpris2.cpp
M  +1    -0    backends/mixer_mpris2.h
M  +4    -0    core/mixdevice.cpp
M  +5    -1    core/mixdevice.h

http://commits.kde.org/kmix/6e7fb0b5ea8fb399dca5c85b51c3389d7be9b96f

Here with KDE 4.10.97, kmix always hang on startup but only on my laptop, not sure what is happeining...

http://quickgit.kde.org/?p=kde-workspace.git&a=commit&h=9ff94e7999e26aa91b2017dfd44270eb2dbb766f

Workaround for KDE 4.11 release.

Fixed in KMxi 4.4 / KDE4.11.

This is still not fixed for me in KDE 4.11. I am still getting a delayed startup where kmix hangs for 10-20 seconds.

This is true for me as well. The bug appeared to be gone in 4.10.90~97 but after updating to 4.11, I got the problem again.

Reopened based on recent comments.

I have seen Cédric's workaround patch, but I do not know what that means for a real fix within KMix. What is the root cause? Can I do anything to fix it?
As far as I see the only synchronous DBUS call in use is "ListNames".

I will try to switch to qmenumodel (gio menumodel from Gnome/Unity)for KDE 5, so, maybe this will be fixed automatically... ;)

I found something suspicious during code review, namely a fix for bug 315383. The author added in fact an unobtrusive synchronous DBUS call via "mad->playerIfc->property("Volume")". See https://projects.kde.org/projects/kde/kdemultimedia/kmix/repository/revisions/0247b50cffa6962e1863316b855c48b290103b45

As we know now, Async DBUS calls are evil, so I will refactor it.

(In reply to comment #32)
> I found something suspicious during code review, namely a fix for bug
> 315383. The author added in fact an unobtrusive synchronous DBUS call via
> "mad->playerIfc->property("Volume")". See
> https://projects.kde.org/projects/kde/kdemultimedia/kmix/repository/
> revisions/0247b50cffa6962e1863316b855c48b290103b45
> 
> As we know now, Async DBUS calls are evil, so I will refactor it.

Oops, typo. I meant: "Sync DBUS calls are evil" (tm)

Git commit 0f7a603e1d327f76dbd6a62d08315b1956794d42 by Christian Esken.
Committed on 20/12/2013 at 10:17.
Pushed by esken into branch 'master'.

Configuration menu is now using Tabs to provide a more standard,
  convenient and pleasing layout
 Sound Menu: Play button reflects playback status and shows either
  "Play" or "Pause"
 Bugfixes and Features (CCBUGS, as most bugs are already closed). Hint: Some
bugs might have actually been alreay fixed ibn KDE4.11 or KDE4.12.

Bug ID	Severity	Summary
Related: bug 20, bug 315383, bug 299477, bug 256854, bug 304144, bug 296951, bug 303608, bug 214854, bug 319600
applet
volume control
position.

M  +9    -5    CMakeLists.txt
M  +41   -20   ChangeLog
M  +5    -1    apps/KMixApp.cpp
M  +167  -238  apps/kmix.cpp
M  +8    -13   apps/kmix.h
M  +3    -0    apps/kmixctrl.cpp
M  +3    -0    apps/kmixd.cpp
M  +18   -12   backends/mixer_backend.cpp
M  +1    -0    backends/mixer_backend.h
M  +229  -150  backends/mixer_mpris2.cpp
M  +23   -6    backends/mixer_mpris2.h
M  +8    -2    backends/mixer_oss.cpp
M  +1    -1    backends/mixer_pulse.cpp
M  +9    -9    core/ControlManager.cpp
M  +102  -15   core/GlobalConfig.cpp
M  +105  -47   core/GlobalConfig.h
M  +65   -31   core/kmixdevicemanager.cpp
M  +9    -4    core/mixdevice.cpp
M  +4    -12   core/mixdevice.h
M  +6    -4    core/mixer.cpp
M  +16   -10   core/mixertoolbox.cpp
M  +1    -1    core/version.h
M  +17   -3    core/volume.cpp
M  +9    -8    core/volume.h
M  +19   -6    gui/dialogchoosebackends.cpp
M  +1    -1    gui/dialogchoosebackends.h
M  +9    -2    gui/dialogviewconfiguration.cpp
M  +37   -10   gui/guiprofile.cpp
M  +27   -24   gui/guiprofile.h
M  +93   -118  gui/kmixdockwidget.cpp
M  +3    -4    gui/kmixdockwidget.h
M  +13   -11   gui/kmixerwidget.cpp
M  +296  -91   gui/kmixprefdlg.cpp
M  +82   -32   gui/kmixprefdlg.h
M  +87   -38   gui/mdwslider.cpp
M  +4    -2    gui/mdwslider.h
M  +69   -42   gui/viewbase.cpp
M  +1    -0    gui/viewbase.h
M  +25   -30   gui/viewdockareapopup.cpp
M  +1    -1    gui/viewdockareapopup.h
M  +4    -4    gui/viewsliders.cpp
M  +1    -1    gui/volumesliderextradata.h

http://commits.kde.org/kmix/0f7a603e1d327f76dbd6a62d08315b1956794d42

 @ Joseph Yasi and Sindre Wetjen and anybody else who can run KMix from trunk: If you are still affected by the bug, please upgrade to trunk with the changes I just committed. Try it and give feedback.

I just tried kmix from trunk. The delay is still happening with the menubar style set to "Titlebar button".

@Joseph Yasi : And you are sure tbhe delay is still KMix related? Can you disable KMix Autostart AND also KMixD (KMix Service) and try again?

Yes. I just disabled KMix autostart, and KMixD, and there is no delay on login to KDE. I've noticed with KMix the delay seems to be related to the menu export. Menus in other applications do not appear until KMix finally finished launching. With KMix disabled, menus appear immediately after login.

Thanks for the feedback, Joseph. But as far as I understand I can not do anything, as it is menu related, and the only proposed application "fix" was to wait for new menu model in KDE 5. I am moving this ticket to the "waiting room" for now.

Confirming bug in Fedora 20 - KDE 4.11.5
I disabled all KDE daemons and enabling them a few per time. I found out it is a KMim problem
https://bugzilla.redhat.com/show_bug.cgi?id=1059699

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

Disabling kmixD makes it go away. What is kmixD good for and what is it doing during startup.

@Søren Holm: KMixD is a background service, that one can use to control the volume via DBUS, independent on if the KMix GUI is running or not.
KMixD is a KDE service, and what maybe happening is that KMixD deadlocks with a different KDE service (KMixD wait for A, and A wait for KMixD. Or some more complicated scenario).
As workaround I added now a small delay. It may work or it may not. If somebody has access to KDE trunk, please test.

Change reference: http://quickgit.kde.org/?p=kmix.git&a=blobdiff&h=d21d5a63af494bcdb2d3c67b6e96d5dd1197c1bd&hp=94f2b018df3351ad902bc7b32ce6ba2efb8087c3&hb=69aa3baf266b5e0952737dd203d7d2735e6d374b&f=apps%2Fkmixd.cpp

Most relevant change:
  QTimer::singleShot( 3000, this, SLOT(delayedInitialization()));

I can say that the bug is still present in kmix-4.14.1 (I'm on Fedora 20 3.16.6-200 x86_64, all through the official F20 updates channel)

Is there a fix or workaround short of disabling KMixD for this bug yet?
It's still present in 4.14.3

I can't find any documentation on kmixd, so I don't know if I disable for good what I'll miss or disturb

Git commit 91284ff2561ba9627dfe47d21593f472df9ffa8e by Christian Esken.
Committed on 06/01/2015 at 22:29.
Pushed by esken into branch 'master'.

Add a Lock to avoid duplicate initializiation, which may help with some
startup issues (delays, lockups). Not likely a solutin for all, but
please test. Also some ceanups, less logging and fixing a small memleak.
Related: bug 318986, bug 339272, bug 339525

M  +1    -0    CMakeLists.txt
M  +122  -59   apps/KMixApp.cpp
M  +7    -10   apps/KMixApp.h
M  +2    -7    apps/kmix.cpp
M  +1    -0    apps/main.cpp
M  +1    -1    backends/mixer_mpris2.cpp
M  +4    -4    backends/mixer_pulse.cpp
M  +4    -2    core/GlobalConfig.cpp
M  +13   -0    core/GlobalConfig.h
M  +2    -1    core/mixdevice.cpp
M  +2    -2    core/mixer.cpp
M  +14   -7    gui/kmixprefdlg.cpp
M  +2    -2    gui/viewbase.cpp

http://commits.kde.org/kmix/91284ff2561ba9627dfe47d21593f472df9ffa8e

Confirming on KDE 4.14.6

(In reply to nucleo from comment #0)
> After update from KDE 4.10.1 to 4.10.2 kmix appeared in systemtray with 20
> seconds delay after KDE start but only if appmenu-qt configured to "Title
> bar button".
> 
> Reproducible: Always
> 
> Steps to Reproduce:
> 1. Set menubar style to "Title bar button".
> 2. Restart KDE.
> Actual Results:  
> kmix appeared in systemtary with 20 second delay after KDE started.
> 
> Expected Results:  
> No delay.
> 
> No delay if set menubar style to "In application".
> In KDE 4.10.1 with "Title bar button" kmix started without delay.
> appmenu-qt-0.2.6 installed.
> Delay happens with and without installed pulseaudio.

(In reply to nucleo from comment #11)
> kmix-4.10.3 built in Fedora with patch "[PATCH 1/8] MPRIS2 backend now does
> a asynchonous DBUS instrospection", I also applied patch from Comment 9
> except changes to gui/viewdockareapopup.cpp.
> But nothing changed after applying patches, desktop freezed until kmix not
> started.
> 
> Here more messages from log before kmix start:
> 
> QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/Master_0" 
> QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/Headphone_0" 
> QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/Speaker_0" 
> QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/PCM_0" 
> QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/Mic_Boost_0" 
> QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/IEC958_0" 
> QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/Capture_0" 
> QDBusConnection for control created
> "/Mixers/ALSA__HDA_Intel_1/Auto_Mute_Mode_0_penum" 
> QDBusConnection for control created "/Mixers/ALSA__HDA_Intel_1/Digital_0" 
> Attaching Media Players 
> plasma-desktop(2469)/plasma StatusNotifierItemSource::refreshCallback:
> DBusMenu disabled for this application 
> 
> Here delay follows, and when kmix started this messages appeared
> 
> bool DBusMenuExporterDBus::AboutToShow(int): Condition failed: menu 
> bool DBusMenuExporterDBus::AboutToShow(int): Condition failed: menu 
> bool DBusMenuExporterDBus::AboutToShow(int): Condition failed: menu 
> bool DBusMenuExporterDBus::AboutToShow(int): Condition failed: menu

(In reply to modellbaukeller from comment #5)
> Can confirm this under 4.10.3, too.

(In reply to Alex Tsi from comment #6)
> Confirming. Chakra Linux KDE 4.10.3..

(In reply to Sindre Wetjen from comment #7)
> This also happens when I use the plasma-widget-menubar in KDE 4.10.3

(In reply to Christian Esken from comment #8)
> *** Bug 318036 has been marked as a duplicate of this bug. ***

(In reply to Christian Esken from comment #10)
> This is a call for testers: If you are able to compile KMix from trunk and
> run it, please do so and report back.
> 
> -----
> Background information: Quite likely the issue originates from the MPRIS2
> support available since KMix in KDE4.10. I now changed the MPRIS2 backend to
> use asynchronous communication that might fix the issue.

(In reply to Christian Esken from comment #43)
> @Søren Holm: KMixD is a background service, that one can use to control the
> volume via DBUS, independent on if the KMix GUI is running or not.
> KMixD is a KDE service, and what maybe happening is that KMixD deadlocks
> with a different KDE service (KMixD wait for A, and A wait for KMixD. Or
> some more complicated scenario).
> As workaround I added now a small delay. It may work or it may not. If
> somebody has access to KDE trunk, please test.
> 
> Change reference:
> http://quickgit.kde.org/?p=kmix.
> git&a=blobdiff&h=d21d5a63af494bcdb2d3c67b6e96d5dd1197c1bd&hp=94f2b018df3351ad
> 902bc7b32ce6ba2efb8087c3&hb=69aa3baf266b5e0952737dd203d7d2735e6d374b&f=apps%2
> Fkmixd.cpp
> 
> Most relevant change:
>   QTimer::singleShot( 3000, this, SLOT(delayedInitialization()));

(In reply to nucleo from comment #1)
> I downgraded kmix to 4.10.1 and left all of KDE 4.10.2, but kmix start still
> delayed.
> So maybe this problem somewhere in other KDE 4.10.2 components outside kmix.

(In reply to nucleo from comment #2)
> Impossible to start any application from kickoff or from desktop until kmix
> not stared.

(In reply to panagiotis from comment #57)
> (In reply to nucleo from comment #2)
> > Impossible to start any application from kickoff or from desktop until kmix
> > not stared.

(In reply to nucleo from comment #4)
> Bug still in 4.10.3.

Reported for KDE4.
Please confirm if still a problem with current KMix and Plasma 5.
See also bug 318986 for startup delay issues related to PulseAudio.

(In reply to Jonathan Marten from comment #60)
> Reported for KDE4.
> Please confirm if still a problem with current KMix and Plasma 5.
> See also bug 318986 for startup delay issues related to PulseAudio.

I am not experiencing this problem on Plasma 5

Dear Bug Submitter,

This bug has been in NEEDSINFO status with no change for at least
15 days. Please provide the requested information as soon as
possible and set the bug status as REPORTED. Due to regular bug
tracker maintenance, if the bug is still in NEEDSINFO status with
no change in 30 days the bug will be closed as RESOLVED > WORKSFORME
due to lack of needed information.

For more information about our bug triaging procedures please read the
wiki located here:
https://community.kde.org/Guidelines_and_HOWTOs/Bug_triaging

If you have already provided the requested information, please
mark the bug as REPORTED so that the KDE team knows that the bug is
ready to be confirmed.

Thank you for helping us make KDE software even better for everyone!

This bug has been in NEEDSINFO status with no change for at least
30 days. The bug is now closed as RESOLVED > WORKSFORME
due to lack of needed information.

For more information about our bug triaging procedures please read the
wiki located here:
https://community.kde.org/Guidelines_and_HOWTOs/Bug_triaging

Thank you for helping us make KDE software even better for everyone!