JasonLG1979 / gnome-shell-extension-mpris-indicator-button

A full featured MPRIS indicator button extension for GNOME Shell 3.38+
https://extensions.gnome.org/extension/1379/mpris-indicator-button/
GNU General Public License v3.0
159 stars 21 forks source link

Possibly misbehaving with the mpd-mpris service #49

Closed guihkx closed 3 years ago

guihkx commented 3 years ago

Describe the bug

I'm using this service/daemon called mpd-mpris, which implements the MPRIS protocol for the Music Player Daemon (MPD).

It works almost perfectly with this extension. There are two issues I'm experiencing right now:

  1. Upon restarting the mpd-mpris daemon, some playback flags are randomly enabled/disabled in MPD (for example: shuffle mode, random mode, single mode).
  2. If I leave a song playing on MPD; Then lock my screen (Super+L); Then unlock it, MPD's volume will be set to zero, for some odd reason.

Initially, I thought this was an issue with the mpd-mpris daemon (and I reported it to their developer), but if I actually disable this extension, I'm unable to reproduce these two bugs!

Since it's not clear if this is a bug with mpd-mpris or this extension, @natsukagami (the creator of mpd-mpris) suggested me to report it here, and it's also willing to help on a possible fix.

Steps To Reproduce:

Note: This needs both MPD and mpd-mpris set up.

The first issue can be reproduced by either:

  1. Keep restarting mpd-mpris daemon: Some playblack flags will be randomly enabled/disabled. Here's a video I recorded showing this behavior.
  2. Disable this extension temporarily; Then run the mpd-mpris service (and make sure to not have any playback flags enabled in MPD. You can use ncmpcpp to check which flags are enabled); Then re-enable this extension. Playblack flags will be randomly set/unset each time you do this.

The second issue:

  1. Run mpd-mpris like normal
  2. Lock your session: Super+L
  3. Unlock it
  4. MPD's Volume will be set to zero

Expected behavior

System Details (please complete the following information):

guihkx commented 3 years ago

I dug a little into this extension's code and came across these two methods:

https://github.com/JasonLG1979/gnome-shell-extension-mpris-indicator-button/blob/4701612ac980ee183efbe293e26ccc4be88f22af/mprisindicatorbutton%40JasonLG1979.github.io/dbus.js#L1878

https://github.com/JasonLG1979/gnome-shell-extension-mpris-indicator-button/blob/4701612ac980ee183efbe293e26ccc4be88f22af/mprisindicatorbutton%40JasonLG1979.github.io/dbus.js#L1804

If I understand correctly, they're used to determine if a player has a valid interface for volume/shuffle/loop controls.

When called, they will first store the current value of the property, then change it to something else, then restore its initial value. By doing so, this extension is able to determine exactly what controls the current player supports, and will add it (or hide it) on its GNOME Shell widget. For example, if I were to delete this line that calls _testVolume():

https://github.com/JasonLG1979/gnome-shell-extension-mpris-indicator-button/blob/4701612ac980ee183efbe293e26ccc4be88f22af/mprisindicatorbutton%40JasonLG1979.github.io/dbus.js#L1663

Then the volume slider would not be shown in the widget.

So, back to the main issue: For some reason that I'm not aware of, while in the process of switching/toggling values for these properties, either this extension or mpd-mpris will sometimes get confused and do not update these values in the proper order.

Example:

  1. Extension asks mpd-mpris for the current volume state
  2. mpd-mpris replies with 0.5 (example)
  3. Extension stores that value
  4. Extension asks mpd-mpris to set the volume to 0.0
  5. Extension asks mpd-mpris to set the volume back to 0.5

I don't know who's at fault here, but sometimes mpd-mpris will set the volume to 0.5 first, then only later set the volume to 0.0.

A temporary, ugly hack I found for now, is to merely update these properties with their own current values, instead of replacing the initial value with something else, then restoring that initial value later. The patch:

Click here to expand ```diff diff --git a/mprisindicatorbutton@JasonLG1979.github.io/dbus.js b/mprisindicatorbutton@JasonLG1979.github.io/dbus.js index e8a66f9..581fc69 100644 --- a/mprisindicatorbutton@JasonLG1979.github.io/dbus.js +++ b/mprisindicatorbutton@JasonLG1979.github.io/dbus.js @@ -1816,14 +1816,10 @@ const MprisProxyHandler = GObject.registerClass({ } else { if (this._playerProxy.Shuffle !== null) { let initialShuffle = this._playerProxy.Shuffle || false; - this._playerProxy.Shuffle = !initialShuffle; this._playerProxy.Shuffle = initialShuffle; } if (this._playerProxy.LoopStatus !== null) { let initialLoopStatus = this._playerProxy.LoopStatus || 'None'; - this._playerProxy.LoopStatus = initialLoopStatus === 'None' ? 'Playlist' - : initialLoopStatus === 'Playlist' ? 'Track' - : 'None'; this._playerProxy.LoopStatus = initialLoopStatus; } } @@ -1883,11 +1879,6 @@ const MprisProxyHandler = GObject.registerClass({ // remains hidden since it's pointless to show a widget that doesn't do anything... if (this._playerProxy.Volume) { let initialVolume = this._playerProxy.Volume || 0.0; - this._playerProxy.Volume = initialVolume <= 0.0 - ? 0.1 - : initialVolume >= 1.0 - ? 0.9 - : Math.min(initialVolume - 0.1, 0.0); this._playerProxy.Volume = initialVolume; } } ```

Obviously, I haven't tested with other players beside MPD / mpd-mpris, so it's likely that it will break something. But hey, works for me™ and I'm happy for now. :)

JasonLG1979 commented 3 years ago

Your assumptions are correct as far as the purpose of those methods, to check if those properties actually work. Unfortunately there's really no other way to do it as a lot of players "lie" and expose non-functional properties. If I had to guess mpd-mpris exposes their mpris interface before it's actually fully functional. If it were actually fully functional when initially exposed testing the properties would work and be invisible to the user because it would happen so fast.

JasonLG1979 commented 3 years ago

However Your example is not correct. If the initial reported value was 0.5 the extension would set the volume to 0.4 and then back to 0.5.

JasonLG1979 commented 3 years ago

Again though that should happen in a matter of milliseconds if not microseconds when the interface is initially exposed. The user should not notice it at all.

guihkx commented 3 years ago

However Your example is not correct. If the initial reported value was 0.5 the extension would set the volume to 0.4 and then back to 0.5.

Indeed, you're right! Bad example on my part. :p

Again though that should happen in a matter of milliseconds if not microseconds when the interface is initially exposed. The user should not notice it at all.

Yes, I can confirm that I'm unable to notice these changes (when they actually work), the issue is that sometimes flags are wrongfully flipped / volume is set to zero. :(

If I had to guess mpd-mpris exposes their mpris interface before it's actually fully functional

I'm not sure about this one. I can reproduce this consistently after disabling/enabling this extension (while keeping the mpd-mpris service always running)

JasonLG1979 commented 3 years ago

I'm not sure about this one. I can reproduce this consistently after disabling/enabling this extension (while keeping the mpd-mpris service always running)

Is something playing while you toggle the extension? And what is your audio setup? Is MPD running on the same machine? Is it going though pulseaudio? And if so does MPD use pulseaudio for volume control? I ask because with pulseaudio you can't change the volume of a sink if it doesn't exist/isn't open. So for example if you start a player and aren't playing anything yet you can't change the volume because the sink hasn't been opened yet. Gstreamer gets around this by basically faking it and caching any volume changes until the sink is actually opened and then it applies the volume.

JasonLG1979 commented 3 years ago

Yes, I can confirm that I'm unable to notice these changes (when they actually work), the issue is that sometimes flags are wrongfully flipped / volume is set to zero. :(

Whatever the values are set to is what was reported to the extension when it 1st queried the property. If for example the volume is set to zero then that's what the player said the volume was. I don't know what to tell you? Sounds to me like mpd-mpris is reporting bogus values for those properties for whatever reason?

guihkx commented 3 years ago

Is something playing while you toggle the extension?

Yes, every time I tested this there was music playing in MPD.

And what is your audio setup? Is MPD running on the same machine? Is it going though pulseaudio? And if so does MPD use pulseaudio for volume control? I ask because with pulseaudio you can't change the volume of a sink if it doesn't exist/isn't open.

Yes, the MPD server is running in the same machine I use both ncmpcpp and mpd-mpris to control it.

Yes, I am using the PulseAudio backend in MPD. My config file looks like this (pretty standard):

~/.config/mpd/mpd.conf:

bind_to_address "0.0.0.0"

db_file "~/.config/mpd/database"
log_file "~/.config/mpd/log"

# Optional
music_directory    "/run/media/gui/SEAGATE/Multimedia/Music"
playlist_directory "~/.config/mpd/playlists"
pid_file           "~/.config/mpd/pid"
state_file         "~/.config/mpd/state"
sticker_file       "~/.config/mpd/sticker.sql"

audio_output {
    type   "pulse"
    name   "Music Player Daemon"
}
audio_output {
    type   "fifo"
    name   "Visualizer feed"
    path   "/tmp/mpd.fifo"
    format "44100:16:2"
}
audio_output {
    type      "httpd"
    name      "MPD HTTP Stream"
    encoder   "vorbis" # optional
    port      "8000"
    bitrate   "128"
    format    "44100:16:1"
    always_on "no"
    tags      "yes"
}

Whatever the values are set to is what was reported to the extension when it 1st queried the property. If for example the volume is set to zero then that's what the player said the volume was. I don't know what to tell you? Sounds to me like mpd-mpris is reporting bogus values for those properties for whatever reason?

That could be it, yes... I will try adding a few log() lines to observe what values mpd-mpris is giving me. Thanks

guihkx commented 3 years ago

I've reverted my previous patch and blindly added a couple of log() calls in some places I thought they'd be useful. Because the logging can get too overwhelming, for the time being I'll be looking only for the volume issue and ignore the Shuffle/LoopStatus issue.

diff --git a/mprisindicatorbutton@JasonLG1979.github.io/dbus.js b/mprisindicatorbutton@JasonLG1979.github.io/dbus.js
index e8a66f9..5ca8f8b 100644
--- a/mprisindicatorbutton@JasonLG1979.github.io/dbus.js
+++ b/mprisindicatorbutton@JasonLG1979.github.io/dbus.js
@@ -1653,6 +1653,7 @@ const MprisProxyHandler = GObject.registerClass({
                 this._updateLoopStatus();
             }
             if (props.includes('Volume')) {
+                log(`Signal received (g-properties-changed): Calling _updateVolume()`);
                 this._updateVolume();
             }
         });
@@ -1817,6 +1818,7 @@ const MprisProxyHandler = GObject.registerClass({
             if (this._playerProxy.Shuffle !== null) {
                 let initialShuffle = this._playerProxy.Shuffle || false;
                 this._playerProxy.Shuffle = !initialShuffle;
+                log(`_testShuffleLoopStatus(): initialShuffle = ${initialShuffle}`);
                 this._playerProxy.Shuffle = initialShuffle;
             }
             if (this._playerProxy.LoopStatus !== null) {
@@ -1824,6 +1826,7 @@ const MprisProxyHandler = GObject.registerClass({
                 this._playerProxy.LoopStatus = initialLoopStatus === 'None' ? 'Playlist'
                     : initialLoopStatus === 'Playlist' ? 'Track'
                     : 'None';
+                log(`_testShuffleLoopStatus(): initialLoopStatus = ${initialLoopStatus}`);
                 this._playerProxy.LoopStatus = initialLoopStatus;
             }
         }
@@ -1883,6 +1886,7 @@ const MprisProxyHandler = GObject.registerClass({
         // remains hidden since it's pointless to show a widget that doesn't do anything...
         if (this._playerProxy.Volume) {
             let initialVolume = this._playerProxy.Volume || 0.0;
+            log(`_testVolume(): initialVolume = ${initialVolume}`);
             this._playerProxy.Volume = initialVolume <= 0.0
                 ? 0.1
                 : initialVolume >= 1.0
@@ -1894,6 +1898,7 @@ const MprisProxyHandler = GObject.registerClass({

     _updateVolume() {
         let newVolume = this._playerProxy.Volume ? Math.max(0.0, Math.min(Math.round(this._playerProxy.Volume * 100) / 100, 1.0)) : 0.0;
+        log(`_updateVolume(): currentVolume: ${this._playerProxy.Volume}, newVolume: ${newVolume}`);
         if (this._volume !== newVolume) {
             this._volume = newVolume;
             this.notify('volume');

After disabling/enabling the extension a couple of times (and making sure MPD was actively playing music), I got this in the system journal:

dec 10 18:30:55 arch gnome-shell[765]: _testShuffleLoopStatus(): initialShuffle = false
dec 10 18:30:55 arch gnome-shell[765]: _testShuffleLoopStatus(): initialLoopStatus = None
dec 10 18:30:55 arch gnome-shell[765]: _testVolume(): initialVolume = 0.4
dec 10 18:30:55 arch gnome-shell[765]: Signal received (g-properties-changed): Calling _updateVolume()
dec 10 18:30:55 arch gnome-shell[765]: _updateVolume(): currentVolume: 0.4, newVolume: 0.4
dec 10 18:30:55 arch gnome-shell[765]: Signal received (g-properties-changed): Calling _updateVolume()
dec 10 18:30:55 arch gnome-shell[765]: _updateVolume(): currentVolume: 0, newVolume: 0

I don't understand why the first call to both _testVolume() and _updateVolume() are reporting the correct initial volume (0.4), but the next call to _updateVolume() reports 0... And like I said before, this behavior is arbitrary: sometimes the volume does not get zero'd and flags are properly flipped back. :S

Just for completeness sake, this is what the log looks like when everything works:

dec 10 18:34:17 arch gnome-shell[765]: _testShuffleLoopStatus(): initialShuffle = false
dec 10 18:34:17 arch gnome-shell[765]: _testShuffleLoopStatus(): initialLoopStatus = None
dec 10 18:34:17 arch gnome-shell[765]: _testVolume(): initialVolume = 0.4
dec 10 18:34:17 arch gnome-shell[765]: Signal received (g-properties-changed): Calling _updateVolume()
dec 10 18:34:17 arch gnome-shell[765]: _updateVolume(): currentVolume: 0, newVolume: 0
dec 10 18:34:17 arch gnome-shell[765]: Signal received (g-properties-changed): Calling _updateVolume()
dec 10 18:34:17 arch gnome-shell[765]: _updateVolume(): currentVolume: 0.4, newVolume: 0.4

Any ideas? @natsukagami

JasonLG1979 commented 3 years ago

It looks 2 issues. A synchronicity problem (aka a race condition) combined with mpd-mpris not reporting the correct volume value for the 1st volume change.

I say that because the logs should show that the initial volume was 0.4 then it should show a change to 0.5 and back to 0.4.

What I see is that:

  1. When setting the volume to 0.5 mpd-mpris signals a volume change to 0.0. I don't know what's going on there?

  2. Sometimes property change signals are sent out of order. Dbus messages are guaranteed to be received in the order that you send them so that leads me to believe that mpd-mpris is doing something asynchronous and not being careful to make sure to respond to property changes in the order in which they are received. They need to either handle things synchronously or use some kind of ordered queue.

v4rakh commented 3 years ago

Hi.

I am also experiencing the first issue. With this indicator extension enabled, restarting Cantata (has an own mpris) or using mpdris2 and just restarting it, will reproducibly enable the repeat mode for me. Sometimes even repeat and single repeat at the same time.

This does btw not happen when extension is turned off and I just use GNOME's default mpris integration in the default notification menu (or however they call it).

JasonLG1979 commented 3 years ago

@v4rakh the only way to know if a mpris property like repeat actually exists and is functional is to toggle it and see if there is a corresponding property changed signal. That's just how mpris and more widely DBus works.

If I had to guess neither is actually waiting for mpd to respond before initializing their mpris interfaces. The mpris interface is just about the last thing that should be initialized, they should at least wait until they have all the info needed for the interface to be actually functional. Again it's a race condition. They're putting the cart before the horse so to speak or maybe next to the horse in the case of trying to do interdependent things asynchronously without flow control.

v4rakh commented 3 years ago

Okay, that's unfortunate, so nothing we can do to fix this (mis)behavior.

JasonLG1979 commented 3 years ago

@v4rakh well that depends on if my hunch is correct. If you would do a simple test for me? Disable the extension and start Cantata and then enable the extension. Does that stop the unintended behavior?

v4rakh commented 3 years ago

No, when re-enabling the extension, it directly enables repeat mode.

Edit: Also, when I quit Cantata and re-open, it doesn't remember last known played track if extension enabled. Instead it's entirely in stopped state and not in 'last known track stopped state'. Without the extension, when I quit Cantata and re-open then it still knows the last played track, but it's exactly stopped at this positon and 'Play' would start this last known track from the beginning. I guess that's a similar problem probing functionality?

Btw this also happens regardless of the mpris implementation I use (the one integrated with Cantata and the standalone one mpdris2).

JasonLG1979 commented 3 years ago

No, when re-enabling the extension, it directly enables repeat mode.

It's probably the same issue as @guihkx is having with volume. They're not making sure to handle things in order.

Also, when I quit Cantata and re-open, it doesn't remember last known played track if extension enabled. Instead it's entirely in stopped state and not in 'last known track stopped state'. Without the extension, when I quit Cantata and re-open then it still knows the last played track, but it's exactly stopped at this positon and 'Play' would start this last known track from the beginning. I guess that's a similar problem probing functionality?

That's weird. The extension doesn't flip any switches when an mpris interface is taken down (a player quits).

I'd file a bug with both Cantata and mpdris2. Most other players that try to expose repeat, shuffle and volume do it right.

JasonLG1979 commented 3 years ago

Closing this as not my bug.