🐛 | Spotify / gstreamer throws error 'Resource not found'

[GreenhouseCH]

Version

2.8.0

Branch

master

OS

Rasberry Pi 64 bit

Pi model

4

Hardware

With Rfid Reader & Hifiberry

What happened?

After booting the PhonieBox, I do hear the startup sound.
Playing local files (e.g. mp3 or wav or flac) works flawlessly via the Iris interface.

Playing songs/playlists from Spotify however does not work anymore (it did the last time the system was started up). After re-initiating a connection to Spotify (token regeneration), the error persists. It does not matter if I play a spotify song via Iris or via the RFID Card. The error is always the same: Mopidy gets the prompt, but gstreamer fails to play.

mpd runs as root (as per /etc/mpd.conf)

Logs

Output from daemon.log:

Aug  7 00:06:20 PhonieBox mopidy[12978]: ERROR    [MainThread] mopidy.audio.gst GStreamer error: Resource not found.
Aug  7 00:06:20 PhonieBox mopidy[12978]: DEBUG    [MainThread] mopidy.audio.gst Got ERROR bus message: error=GLib.Error('Resource not found.', 'gst-resource-error-quark', 3) debug='audio/spotify/src/spotifyaudiosrc/imp.rs(307): <gstspotify::spotifyaudiosrc::imp::SpotifyAudioSrc as gstreamer_base::subclass::push_src::PushSrcImpl>::create (): /GstPlayBin:playbin0/GstURIDecodeBin:uridecodebin0/GstSpotifyAudioSrc:source:\ntrack is not available'
Aug  7 00:06:20 PhonieBox mopidy[12978]: DEBUG    [MainThread] mopidy.audio.gst Changing state to GST_STATE_NULL: result=GST_STATE_CHANGE_SUCCESS

Additionally, the log shows lots of entries with "New MPD connection", which I don't know if they add anything to the discussion here.

Aug  7 00:06:06 PhonieBox mopidy[12978]: DEBUG    [MpdSession-892] mopidy_mpd.network Client most likely disconnected.
Aug  7 00:06:06 PhonieBox mopidy[12978]: DEBUG    [MpdSession-892] pykka Unregistered MpdSession (urn:uuid:545f514a-fb6c-428c-b426-726a0ad5f253)
Aug  7 00:06:06 PhonieBox mopidy[12978]: DEBUG    [MpdSession-892] pykka Stopped MpdSession (urn:uuid:545f514a-fb6c-428c-b426-726a0ad5f253)
Aug  7 00:06:06 PhonieBox mopidy[12978]: DEBUG    [MpdSession-892] mopidy_mpd.network Already stopping: Actor is shutting down.
Aug  7 00:06:06 PhonieBox mopidy[12978]: DEBUG    [MainThread] pykka Registered MpdSession (urn:uuid:548ad54c-f926-4bd7-801b-d30101059945)
Aug  7 00:06:06 PhonieBox mopidy[12978]: DEBUG    [MainThread] pykka Starting MpdSession (urn:uuid:548ad54c-f926-4bd7-801b-d30101059945)
Aug  7 00:06:06 PhonieBox mopidy[12978]: INFO     [MpdSession-893] mopidy_mpd.session New MPD connection from [::ffff:127.0.0.1]:59128
Aug  7 00:06:06 PhonieBox mopidy[12978]: DEBUG    [MpdSession-893] mopidy_mpd.session Request from [::ffff:127.0.0.1]:59128: command_list_ok_begin
Aug  7 00:06:06 PhonieBox mopidy[12978]: DEBUG    [MpdSession-893] mopidy_mpd.session Request from [::ffff:127.0.0.1]:59128: status
Aug  7 00:06:06 PhonieBox mopidy[12978]: DEBUG    [MpdSession-893] mopidy_mpd.session Request from [::ffff:127.0.0.1]:59128: currentsong
Aug  7 00:06:06 PhonieBox mopidy[12978]: DEBUG    [MpdSession-893] mopidy_mpd.session Request from [::ffff:127.0.0.1]:59128: command_list_end
Aug  7 00:06:06 PhonieBox mopidy[12978]: DEBUG    [MpdSession-893] mopidy_mpd.session Response to [::ffff:127.0.0.1]:59128:
Aug  7 00:06:06 PhonieBox mopidy[12978]:     volume: 30
Aug  7 00:06:06 PhonieBox mopidy[12978]:     repeat: 1
Aug  7 00:06:06 PhonieBox mopidy[12978]:     random: 0
Aug  7 00:06:06 PhonieBox mopidy[12978]:     single: 1
Aug  7 00:06:06 PhonieBox mopidy[12978]:     consume: 0
Aug  7 00:06:06 PhonieBox mopidy[12978]:     playlist: 0
Aug  7 00:06:06 PhonieBox mopidy[12978]:     playlistlength: 0
Aug  7 00:06:06 PhonieBox mopidy[12978]:     xfade: 0
Aug  7 00:06:06 PhonieBox mopidy[12978]:     state: stop
Aug  7 00:06:06 PhonieBox mopidy[12978]:     list_OK
Aug  7 00:06:06 PhonieBox mopidy[12978]:     list_OK
Aug  7 00:06:06 PhonieBox mopidy[12978]:     OK

Configuration

mpd.conf:

[local]
enabled = true
media_dir = /home/pi/RPi-Jukebox-RFID/shared/audiofolders
excluded_file_extensions =
.conf
.jpg
.txt
placeholder

[file]
#enabled = true
metadata_timeout = 1

[m3u]
playlists_dir = /home/pi/RPi-Jukebox-RFID/playlists
default_encoding = UTF-8
default_extension = .m3u

[audio]
output = alsasink
mixer_volume = 30

[mpd]
hostname = 0.0.0.0

[http]
hostname = 0.0.0.0

[iris]
country = DE
locale = de_DE

[spotify]
enabled = true
username = some.name
password = some.password
client_id = some-id
client_secret = some-secret
#bitrate = 160
#volume_normalization = true
#private_session = false
#timeout = 10
#allow_cache = true
#allow_network = true
#allow_playlists = true
#search_album_count = 20
#search_artist_count = 10
#search_track_count = 50
#toplist_countries =

[logging]
verbosity = 4

More info

No response

[bold-gman]

I see the same issue with my two boxes. They worked fine yesterday, but Spotify streams don't work today. Local files play okay.

[shruxx]

Same issue here. Yesterday it worked, now nothing plays anymore via Spotify.

[s-martin]

Spotify changed something in their API, already under investigation in librespot, see issue in mopidy-spotify (which is used by Phoniebox): mopidy/mopidy-spotify#418

[GreenhouseCH]

True - thanks, @s-martin , and apologies for blaming RPi-Jukebox-RFID. :-)
Here's the bug issue: [https://github.com/librespot-org/librespot/issues/1527]
There seems to be a fix for raspotify, Developers of librespot however think this problem is only temporary.

[TommyTaif]

I tried the workaround from @GreenhouseCH 's link, which works fine for me.

The mentioned fix is:

Adding 0.0.0.0 apresolve.spotify.com to /etc/hosts.

[bold-gman]

Adding 0.0.0.0 apresolve.spotify.com to /etc/hosts.

Can confirm, works after a reboot, for now at least.

[GreenhouseCH]

Yes, works (at least temporarily)!

[chieftuscan]

Amazing, I was also having this problem. thanks for the fix.

[mmschlecht]

Is there any procedure which need to be performed in order to resolve the issue? Locally on my box I mean.