Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

MPRIS signal PropertiesChanged is not triggered #89

Closed
mariusor opened this issue Aug 31, 2019 · 14 comments
Closed

MPRIS signal PropertiesChanged is not triggered #89

mariusor opened this issue Aug 31, 2019 · 14 comments
Labels
bug Something isn't working

Comments

@mariusor
Copy link

Hi,

I am the developer behind a generic scrobbling daemon for linux, called mpris-scrobbler and I had a bug report from a user involving ncspot[1].

The issue boiled down to ncspot's MPRIS implementation not triggering the /org/mpris/MediaPlayer2/org.freedesktop.DBus.Properties/PropertiesChanged when track or play status change.

I'm not sure if this is a problem of the underlying library or the player must enable this signal specifically, but it would be great if someone could give it a look.

Thank you.

[1] mariusor/mpris-scrobbler#66

@hrkfdn
Copy link
Owner

hrkfdn commented Aug 31, 2019

Hey,

thanks for the report. On my machine the following message is sent when the track changes:

signal time=1567286673.088128 sender=:1.84 -> destination=(null destination) serial=23 path=/org/mpris/MediaPlayer2; interface=org.freedesktop.DBus.Properties; member=PropertiesChanged
   string "org.mpris.MediaPlayer2.Player"
   array [
      dict entry(
         string "Metadata"
         variant             array [
               dict entry(
                  string "xesam:url"
                  variant                      string "spotify:track:4w5m4X0OZ2IslxNOgtntTN"
               )
               dict entry(
                  string "xesam:albumArtist"
                  variant                      array [
                        string "Freddie Gibbs"
                        string "Madlib"
                     ]
               )
               dict entry(
                  string "xesam:discNumber"
                  variant                      int32 1
               )
               dict entry(
                  string "mpris:artUrl"
                  variant                      string "https://i.scdn.co/image/e92b5ac19289be2da377082a0df648c7eb9e2dc2"
               )
               dict entry(
                  string "mpris:length"
                  variant                      uint32 182680000
               )
               dict entry(
                  string "xesam:album"
                  variant                      string "Bandana"
               )
               dict entry(
                  string "xesam:title"
                  variant                      string "Crime Pays"
               )
               dict entry(
                  string "xesam:artist"
                  variant                      array [
                        string "Freddie Gibbs"
                        string "Madlib"
                     ]
               )
               dict entry(
                  string "xesam:trackNumber"
                  variant                      uint32 4
               )
               dict entry(
                  string "mpris:trackid"
                  variant                      string "spotify:track:4w5m4X0OZ2IslxNOgtntTN"
               )
            ]
      )
      dict entry(
         string "PlaybackStatus"
         variant             string "Playing"
      )
   ]
   array [
   ]

This seems to be sufficient for the Gnome Shell notification window. Do you have any details on what is missing or incorrect?

@hrkfdn
Copy link
Owner

hrkfdn commented Aug 31, 2019

Ah, I think I found out why: the DBus message sending is triggered asynchronously for the stopped track and playback of the new track. By the time the DBus messages are formatted, the track is already playing, which results in 2 PropertiesChanged messages for the new track. This triggers the check in your scrobbler. I'll work on a fix.

@mariusor
Copy link
Author

You're right, I think I conflated the two issues the submitter to my bug had. In the ticket the signal is shown clearly in the log.

hrkfdn added a commit that referenced this issue Aug 31, 2019
as sending out PropertiesChanged events was triggered asynchronously by a
message queue, retrieving the metadata during message formatting is too late.

this resulted in two PropertiesChanged messages announcing the new track as
playing.

this should prevent such a scenario.

as discussed in #89
@hrkfdn hrkfdn added the bug Something isn't working label Aug 31, 2019
@hrkfdn
Copy link
Owner

hrkfdn commented Aug 31, 2019

Hey @mariusor. I have reworked the MPRIS behavior a little. Could you check if this fixes it?

@ghost
Copy link

ghost commented Sep 1, 2019

@hrkfdn I could, and I will, give me some time

t. original reporter

@ghost
Copy link

ghost commented Sep 1, 2019

now I'm getting

Sep 01 10:05:28 a mpris-scrobbler[1057]: DEBUG     loaded::metadata::artist: Milanku
Sep 01 10:05:28 a mpris-scrobbler[1057]: DEBUG     loaded::metadata::album_artist: Milanku
Sep 01 10:05:28 a mpris-scrobbler[1057]: DEBUG     loaded::metadata::title: Mépris
Sep 01 10:05:28 a mpris-scrobbler[1057]: DEBUG     loaded::metadata::album: Convalescence
Sep 01 10:05:28 a mpris-scrobbler[1057]: DEBUG     loaded::metadata::length: 0
Sep 01 10:05:28 a mpris-scrobbler[1057]: DEBUG     loaded::metadata::track_id: spotify:track:3N4y9BXEdS9zvcjfOiLz6W
Sep 01 10:05:28 a mpris-scrobbler[1057]: DEBUG     loaded::metadata::art_url: https://i.scdn.co/image/9dd704e8b5791382b44c0b71fe215f231cce8e2d
Sep 01 10:05:28 a mpris-scrobbler[1057]: DEBUG     loaded::metadata::timestamp: 1567321528
Sep 01 10:05:28 a mpris-scrobbler[1057]: DEBUG     loaded::playback_status: Playing
Sep 01 10:05:28 a mpris-scrobbler[1057]: DEBUG   events::invalid_mpris_properties[0x5582145530d0::0x558214546c40]: already loaded

@mariusor
Copy link
Author

mariusor commented Sep 1, 2019

Same here. :)

So there still the same behaviour. The track information is loaded properly from the Signal payload, yet the scrobbler doesn't consider it valid for a scrobble. It's probably something on my side, and I'll do a debug session later today.

The only thing that there's still not spec compliant for ncspot is that the PropertiesChanged signal is not advertised when doing introspection. It's possible - but not very probable - that this also might be an issue.

Thanx for taking the time to look into this.

@hrkfdn
Copy link
Owner

hrkfdn commented Sep 1, 2019

ncspot should now issue a Stopped PropertiesChanged signal for the old track and then once a Playing signal for the new track. At least when observing dbus using dbus-monitor. I'm uncertain as to how the track is loaded twice.

Does it maybe update the track metadata somehow else?

@mariusor
Copy link
Author

mariusor commented Sep 1, 2019

The already loaded message comes from the fact that the scrobbler tries to do some heuristics to determine for if the current PropertiesChanged message was submitted multiple times by a faulty player.

I have a long standing improvement planned for it to add these types of heuristics on a per player basis, but for now it's all done in the same piece of logic and looks like some of them are trampling over normal behaviour.

@hrkfdn
Copy link
Owner

hrkfdn commented Sep 1, 2019

Got it, thanks. If there isn't anything else that needs fixing on ncspot's side regarding this, could you close the issue? If not, let me know :)

@mariusor
Copy link
Author

mariusor commented Sep 1, 2019

Yes definitely.

I'll probably dedicate more time to make it work properly on my side with ncspot, as I have been looking for a spotify replacement for a long time. (I have an open ticket for spotifyd - another rust project to connect to the spotify API, for a similar issue with the PropertiesChanged signal :D)

I'm not sure if we can close this or not, I would say yes and I'll open a new tickcet if I get more ideas for improvement.

@hrkfdn
Copy link
Owner

hrkfdn commented Sep 1, 2019

Cool, I'll close it for now then. If you spot anything else, please let me now!

@hrkfdn hrkfdn closed this as completed Sep 1, 2019
@mariusor
Copy link
Author

mariusor commented Sep 1, 2019

So, the problem was triggered by the mpris scrobbler not reading the mpris:length value, because your MPRIS library sends it down the pipe to DBus as a uint value instead of a int64 the way the spec requires[1].

I relaxed the dbus length reading on my side, so I think everything should work properly from now on.

[1] https://www.freedesktop.org/wiki/Specifications/mpris-spec/metadata/#index2h4

@hrkfdn
Copy link
Owner

hrkfdn commented Sep 1, 2019

Oh, nice catch, thanks! I have adjusted the types as per specification.

mtshrmn pushed a commit to mtshrmn/ncspot that referenced this issue Sep 8, 2020
as sending out PropertiesChanged events was triggered asynchronously by a
message queue, retrieving the metadata during message formatting is too late.

this resulted in two PropertiesChanged messages announcing the new track as
playing.

this should prevent such a scenario.

as discussed in hrkfdn#89
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants