Web API related MPRIS commands stop working after one hour

[hifiberry]

Still using the old 0.2.10 version with MPRIS. There is a process polling information on several MPRIS services (not just spotifyd) that polls every few second.
Changing the polling interval doesn't seem to have an effect on the time that the MPRIS interface stops working. It seems that spotifyd MPRIS is responsive only for about 1 hours.
Changing the polling interval doesn't change anything, it seems that the problem always happens after one hour.

[mainrs]

To clarify: you have written (or use) a process that makes every x seconds a call over dbus and asks spotifyd about some information? What exactly are you pulling each time?

An hour sounds like the interval an access token would have before it becomes invalid. Spotifyd uses them to retrieve Metadata information as well as do some other functionality (like next and previous calls).

Some more information would help :) is there a particular reason why you didn't update to a newer release? v0.2.16 (the lastest) moves away from the spotify web API for some of the dbus commands like next and previous. Those would work without token then.

[hifiberry]

I wasn't aware that there is a new release with a working MPRIS implementation available. I will have a look at the 0.2.16 version.

An expired access token would explain why this stops after 1 hour.

[hifiberry]

I'm pulling full metadata and playback state.
It's used here:
https://github.com/hifiberry/audiocontrol2

[mainrs]

I started re-writing the whole MPris implementation at #324. I hadn’t enough time to implement everything though. The token should refresh itself after it expired. There might be a bug in the refresh logic then. I am currently not at home but can do some testing on the weekend 😄

[hifiberry]

Just tried 0.2.16, it immediately crashes:

Sep 30 06:54:51 CX50-Office spotifyd[4737]: 06:54:51 [WARN] Unhandled dbus message: (Signal, Some("/org/freedesktop/DBus"), Some("org.freedesktop.DBus"), Some("NameAcquired"))
Sep 30 06:54:51 CX50-Office spotifyd[4737]: 06:54:51 [ERROR] Caught panic with message: called Result::unwrap() on an Err value: Error(BlockingClientInFutureContext, "https://api.spotify.com/v1/me/player")

[hifiberry]

Is there any other way to access metadata AND control the player locally without using MPRIS?

[mainrs]

Is there any other way to access metadata AND control the player locally without using MPRIS?

Based on the commands user send to me it looks like it only crashes on properties access. You should be fine when you only use control commands like previous, next, pause, play and stop. There is a work around. Spotifyd exposes a TRACK_ID environment variable. You can set the onevent hook via the cli or config file, pointing to a shell script. It gets called each time a song changes. There is a wiki entry with a script that fires a notification based on that.

[hifiberry]

The crash shown above happens directly when starting spotifyd 0.2.16. I have disabled the process that polls MPRIS data. However, there are multiple other MPRIS-enabled players running at the same time. Right now I can't use MPRIS with the new release at all, not even for next/pause/...
The only way to locally use next/pause/play right now is MPRIS - correct?

[mainrs]

Yes, correct. Out of interest, does it work if you disable other MPRIS players and only use spotifyd? Because v0.2.16 starts without problems on my machine IIRC.

[hifiberry]

Ok, I could isolate the crash to the Bluez MPRIS proxy:
https://github.com/Vudentz/BlueZ/blob/master/tools/mpris-proxy.c

If I stop this one, Spotifyd doesn't crash immediately.

However, trying to access metadata via MPRIS crashes spotifyd. Therefore the old 0.2.10 release seems to be the most stable at the moment.

[mainrs]

Thanks for the investigation! The metadata access is still a problem that I am currently tackling down :)

[hifiberry]

Ok, seem that I have to wait for 0.2.17 then ;-)

[hifiberry]

Just compiled the latest 0.2.18 release from "releases".
It says it is 0.2.17 and still crashes:

/usr/bin/spotifyd -V
spotifyd 0.2.17

07:50:20 [WARN] Unhandled dbus message: (Signal, Some("/org/freedesktop/DBus"), Some("org.freedesktop.DBus"), Some("NameAcquired"))
07:50:20 [WARN] Unhandled dbus message: (Signal, Some("/org/freedesktop/DBus"), Some("org.freedesktop.DBus"), Some("NameAcquired"))
07:50:20 [ERROR] Caught panic with message: called Result::unwrap() on an Err value: Error(BlockingClientInFutureContext, "https://api.spotify.com/v1/me/player")

I'll check the current github repo and see if this work, maybe it's a packaging error

[mainrs]

I definitely changed the version in the Cargo file. Probably a packaging error.

[hifiberry]

Yes, looks like a packaging error. Just cloned the current Git repo and compiled, now version is 0.2.18 and it seems to work :-)
Affected is at least the .tar.gz file in the 0.2.18 release, I din't check the other files

[mainrs]

I messed up a little bit during pushing and therefore had to delete a branch. That might have messed up with the Github Actions. The binaries should be fine as the code gets cloned directly from the branch

[mainrs]

I'll close the issue then. Thanks for your patience.

[hifiberry]

Ok, my message was not clear. While MPRIS itself is working on the 0.2.18 release, the problem still exists. After 1 hour the daemon stops answering MPRIS requests.

[mainrs]

Ah got you. I’ll reopen this one then. I didn’t write the refresh logic code but I can see if I can spare some time this weekend to debug it.
Just to clarify , it stops responding to web api calls like metadata, doesn’t it? Next and previous still work, do they?

[hifiberry]

Not sure if it is happening when music is playing (didn't check this), but it definitely happens if nothing is playing.

[mainrs]

Sorry to bother you again, but I think you missed my edit:

Just to clarify, it stops responding to web api calls like metadata, doesn’t it? Next and previous still work, do they?

qdbus org.mpris.MediaPlayer2.spotifyd /org/mpris/MediaPlayer2 org.mpris.MediaPlayer2.Player.Next

This will send the next command for example.

Because if even those methods fail (which don’t use the web api) it’s another problem and not an api token related one.

[hifiberry]

Just checking for some feedback. Is there any work in progress on this?

[mainrs]

No not really, I didn't have much time left the past few months. I wanted to merge outstanding PRs today in the evening. This specific issue hasn't been tackled down, sadly.

[hifiberry]

Was there already some work on using the metadata directly from libspotify instead of polling these from the Web API?

[mainrs]

I don't think so, no. I did introduce an environment flag that can be used to set a custom CLIENT_SECRET to avoid hitting the rate limit, but that was just a hotfix if at all.

[hifiberry]

Ok, thanks. I'm using the CLIENT_SECRET already

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[woodruffw]

Just another datapoint: I can confirm that this is still present on 0.3.0.

The origin of the MPRIS requests doesn't seem to matter; both playerctl and dbus-send stop working after about an hour. In my case, none of the MPRIS commands (not even PlayPause) work until some external activity happens, like starting another Spotify Connect client and connecting it to spotifyd.

Edit: I can also confirm that the problem persists even when explicitly setting SPOTIFYD_CLIENT_ID with a custom client ID that I know works. But I'm not 100% sure that was the correct environment variable to set.

[mkoreneff]

I also experience the same dbus issue after about an hour of inactivity.
Using python interface.GetAll('org.mpris.MediaPlayer2.Player')
I receive ERROR:dbus.proxies:Introspect error on :1.247:/org/mpris/MediaPlayer2: dbus.exceptions.DBusException: org.freedesktop.DBus.Error.NoReply: Did not receive a reply. Possible causes include: the remote application did not send a reply, the message bus security policy blocked the reply, the reply timeout expired, or the network connection was broken.
In journalctl I can see spotifyd[493]: Couldn't fetch metadata from spotify: Err(Unauthorized)

Once an external client connects to spotifyd as a listening device, the dbus issues seem to be resolved.

$ spotifyd -V
spotifyd 0.3.2
$ uname -a
Linux q35-arch 5.11.13-arch1-1 #1 SMP PREEMPT Sat, 10 Apr 2021 20:47:14 +0000 x86_64 GNU/Linux

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[woodruffw]

I'll attempt to repro this with the latest spotifyd this evening.

Edit: can confirm that this bug still exists. MPRIS commands are not recognized by the daemon after about an hour of interaction-free listening. Using another client (the Spotify iOS app) to change the play state causes MPRIS to resume working.

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[elken]

Still hitting this with 0.3.5

[eladyn]

@elken If I'm not mistaken, this issue should have been fixed provided the daemon isn't idle (not playing anything) for longer than an hour. Are you also running into this with playback active?

[elken]

Correct, it'll stop playing music after a song ~ an hour. I think I have an idea, so this may be a PEBCAK.

[elken]

Seems like this one's a PEBCAK; it was gpg-agent. Sorry for the noise!