Loss of ability to stream spotify through mopidy

I’ve looked through various topics regarding this, and I think my issue might be unique. I’ve been working on it for about 7 hours now and I’m at a loss.

I installed Mopidy on my Arch for the first time 2 days ago. The documentation is informative and straightforward, so I got everything configured and running quite easily. I used pacman to install mopidy, and yay to install the mpd and spotify extensions and their dependencies. Now, unexpectedly, I can no longer play spotify through mopidy. Each time I start mopidy, I see I successfully connect to the Spotify API (and my playlists populate in my music player), but I immediately get a login error message and lose communication with spotify.

Here is what I have tried:

  • Regenerate Mopidy API credentials (I’ve done this numerous times)
  • Use a different Spotify premium account
  • Run mopidy as both a system service and as an application
  • Completely remove Mopidy and all of its dependencies (even if needed by other packages), remove all pacman / yay cache, then reinstall Mopidy.
  • Clean out the cache directories that Mopidy references in its default configs
  • Restore default config file and add only the bare minimum config options required to make Spotify and MPD work.

And I still cannot figure out what’s going on. I even spun up a Debian instance on digital ocean, and it seems to be running Mopidy and Mopidy-Spotify / Mopidy-MPD without issue. I have not verified by actually playing music (requires additional configuration I need to figure out), but the errors I am seeing on my local system are not present.

Here is my /var/log/mopidy.log file:

Sep 07 13:47:56 horsehead mopidy[1807]: INFO 2020-09-07 13:47:56,180 [1807:MainThread] mopidy.commands Sep 07 13:47:56 horsehead mopidy[1807]: Starting Mopidy mixer: SoftwareMixer Sep 07 13:47:56 horsehead mopidy[1807]: INFO 2020-09-07 13:47:56,181 [1807:MainThread] mopidy.commands Sep 07 13:47:56 horsehead mopidy[1807]: Starting Mopidy audio Sep 07 13:47:56 horsehead mopidy[1807]: INFO 2020-09-07 13:47:56,183 [1807:MainThread] mopidy.commands Sep 07 13:47:56 horsehead mopidy[1807]: Starting Mopidy backends: FileBackend, M3UBackend, StreamBackend, SpotifyBackend Sep 07 13:47:56 horsehead mopidy[1807]: INFO 2020-09-07 13:47:56,196 [1807:Audio-2] mopidy.audio.actor Sep 07 13:47:56 horsehead mopidy[1807]: Audio output set to "autoaudiosink" Sep 07 13:48:06 horsehead mopidy[1807]: INFO 2020-09-07 13:48:06,917 [1807:SpotifyBackend-6] mopidy_spotify.web Sep 07 13:48:06 horsehead mopidy[1807]: Logged into Spotify Web API as 12151430380 Sep 07 13:48:26 horsehead mopidy[1807]: ERROR 2020-09-07 13:48:26,251 [1807:SpotifyEventLoop] spotify.session Sep 07 13:48:26 horsehead mopidy[1807]: Spotify login error: <ErrorType.UNABLE_TO_CONTACT_SERVER: 8> Sep 07 13:48:26 horsehead mopidy[1807]: INFO 2020-09-07 13:48:26,466 [1807:SpotifyBackend-6] mopidy_spotify.playlists Sep 07 13:48:26 horsehead mopidy[1807]: Refreshed 54 Spotify playlists Sep 07 13:48:26 horsehead mopidy[1807]: INFO 2020-09-07 13:48:26,466 [1807:MainThread] mopidy.commands Sep 07 13:48:26 horsehead mopidy[1807]: Starting Mopidy core Sep 07 13:48:26 horsehead mopidy[1807]: INFO 2020-09-07 13:48:26,472 [1807:MainThread] mopidy.commands Sep 07 13:48:26 horsehead mopidy[1807]: Starting Mopidy frontends: HttpFrontend, MpdFrontend Sep 07 13:48:26 horsehead mopidy[1807]: INFO 2020-09-07 13:48:26,473 [1807:HttpFrontend-11] mopidy.http.actor Sep 07 13:48:26 horsehead mopidy[1807]: HTTP server running at [::ffff:127.0.0.1]:6680 Sep 07 13:48:26 horsehead mopidy[1807]: INFO 2020-09-07 13:48:26,473 [1807:MainThread] mopidy_mpd.actor Sep 07 13:48:26 horsehead mopidy[1807]: MPD server running at [::ffff:127.0.0.1]:6600 Sep 07 13:48:26 horsehead mopidy[1807]: INFO 2020-09-07 13:48:26,474 [1807:MainThread] mopidy.commands Sep 07 13:48:26 horsehead mopidy[1807]: Starting GLib mainloop Sep 07 13:48:26 horsehead dbus-daemon[328]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.154' (uid=46 pid=1807 comm="/usr/bin/python /usr/bin/mopidy --config /usr/shar") Sep 07 13:48:26 horsehead dbus-daemon[328]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit dbus-org.freedesktop.Avahi.service not found. Sep 07 13:48:26 horsehead dbus-daemon[328]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.153' (uid=46 pid=1807 comm="/usr/bin/python /usr/bin/mopidy --config /usr/shar") Sep 07 13:48:26 horsehead dbus-daemon[328]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit dbus-org.freedesktop.Avahi.service not found. Sep 07 13:48:26 horsehead dbus-daemon[328]: [system] Activating via systemd: service name='org.freedesktop.Avahi' unit='dbus-org.freedesktop.Avahi.service' requested by ':1.153' (uid=46 pid=1807 comm="/usr/bin/python /usr/bin/mopidy --config /usr/shar") Sep 07 13:48:26 horsehead dbus-daemon[328]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.Avahi.service': Unit dbus-org.freedesktop.Avahi.service not found. Sep 07 13:48:27 horsehead mopidy[1807]: INFO 2020-09-07 13:48:27,878 [1807:MpdSession-13] mopidy_mpd.session Sep 07 13:48:27 horsehead mopidy[1807]: New MPD connection from [::ffff:127.0.0.1]:58166 Sep 07 13:48:44 horsehead mopidy[1807]: INFO 2020-09-07 13:48:44,160 [1807:MpdSession-14] mopidy_mpd.session Sep 07 13:48:44 horsehead mopidy[1807]: New MPD connection from [::ffff:127.0.0.1]:58170 Sep 07 13:48:45 horsehead mopidy[1807]: INFO 2020-09-07 13:48:45,347 [1807:SpotifyBackend-6] mopidy_spotify.lookup Sep 07 13:48:45 horsehead mopidy[1807]: Failed to lookup 'spotify:track:73b2P1h6d4C5vmhwuCqDYA': Session must be logged in and online to load objects: <ConnectionState.LOGGED_OUT: 0> Sep 07 13:48:45 horsehead mopidy[1807]: INFO 2020-09-07 13:48:45,349 [1807:SpotifyBackend-6] mopidy_spotify.lookup Sep 07 13:48:45 horsehead mopidy[1807]: Failed to lookup 'spotify:track:0aQXKkpgnoTgCXBRNeWGrU': Session must be logged in and online to load objects: <ConnectionState.LOGGED_OUT: 0>

This is the line where I first see a problem:

Sep 07 13:48:26 horsehead mopidy[1807]: Spotify login error: <ErrorType.UNABLE_TO_CONTACT_SERVER: 8>

** I did notice a line from my working Mopidy on my Debian VPS that is not occurring on my local machine: **

INFO 2020-09-07 17:51:35,863 [3316:SpotifyEventLoop] mopidy_spotify.backend
Logged in to Spotify in online mode

Back to my local machine, here is the output of mopidy deps:

Executable: /usr/bin/mopidy
Platform: Linux-5.8.7-arch1-1-x86_64-with-glibc2.2.5
Python: CPython 3.8.5 from /usr/lib/python3.8
Mopidy: 3.0.2 from /usr/lib/python3.8/site-packages
Pykka: 2.0.2 from /usr/lib/python3.8/site-packages
requests: 2.24.0 from /usr/lib/python3.8/site-packages
chardet: 3.0.4 from /usr/lib/python3.8/site-packages
idna: 2.10 from /usr/lib/python3.8/site-packages
urllib3: 1.25.10 from /usr/lib/python3.8/site-packages
setuptools: 50.3.0 from /usr/lib/python3.8/site-packages
tornado: 6.0.4 from /usr/lib/python3.8/site-packages
Mopidy-MPD: 3.0.0 from /usr/lib/python3.8/site-packages
Mopidy: 3.0.2 from /usr/lib/python3.8/site-packages
Pykka: 2.0.2 from /usr/lib/python3.8/site-packages
setuptools: 50.3.0 from /usr/lib/python3.8/site-packages
Mopidy-Spotify: 4.0.1 from /usr/lib/python3.8/site-packages
Mopidy: 3.0.2 from /usr/lib/python3.8/site-packages
Pykka: 2.0.2 from /usr/lib/python3.8/site-packages
pyspotify: 2.1.3 from /usr/lib/python3.8/site-packages
cffi: 1.14.2 from /usr/lib/python3.8/site-packages
pycparser: 2.20 from /usr/lib/python3.8/site-packages
setuptools: 50.3.0 from /usr/lib/python3.8/site-packages
requests: 2.24.0 from /usr/lib/python3.8/site-packages
chardet: 3.0.4 from /usr/lib/python3.8/site-packages
idna: 2.10 from /usr/lib/python3.8/site-packages
urllib3: 1.25.10 from /usr/lib/python3.8/site-packages
setuptools: 50.3.0 from /usr/lib/python3.8/site-packages
GStreamer: 1.16.2.0 from /usr/lib/python3.8/site-packages/gi
Detailed information:
Python wrapper: python-gi 3.36.1
Relevant elements:
Found:
uridecodebin
souphttpsrc
appsrc
alsasink
osssink
oss4sink
pulsesink
id3demux
id3v2mux
lamemp3enc
mpegaudioparse
mpg123audiodec
vorbisdec
vorbisenc
vorbisparse
oggdemux
oggmux
oggparse
flacdec
flacparse
shout2send
Not found:
flump3dec
mad

Here is the output of mopidyctl config:

Running “/usr/bin/mopidy --config /usr/share/mopidy/conf.d:/etc/mopidy/mopidy.conf config” as user mopidy
[core]
cache_dir = /var/cache/mopidy
config_dir = /etc/mopidy
data_dir = /var/lib/mopidy
max_tracklist_length = 10000
restore_state = false

[logging]
verbosity = 0
format = %(levelname)-8s %(asctime)s [%(process)d:%(threadName)s] %(name)s\n %(message)s
color = true
config_file = /etc/mopidy/logging.conf

[audio]
mixer = software
mixer_volume =
output = autoaudiosink
buffer_time =

[proxy]
scheme =
hostname =
port =
username =
password =

[file]
enabled = true
media_dirs =
$XDG_MUSIC_DIR|Music
~/|Home
excluded_file_extensions =
.directory
.html
.jpeg
.jpg
.log
.nfo
.pdf
.png
.txt
.zip
show_dotfiles = false
follow_symlinks = false
metadata_timeout = 1000

[http]
enabled = true
hostname = 127.0.0.1
port = 6680
zeroconf = Mopidy HTTP server on $hostname
allowed_origins =
csrf_protection = true
default_app = mopidy

[m3u]
enabled = true
base_dir =
default_encoding = latin-1
default_extension = .m3u8
playlists_dir = /var/lib/mopidy/playlists

[softwaremixer]
enabled = true

[stream]
enabled = true
protocols =
http
https
mms
rtmp
rtmps
rtsp
metadata_blacklist =
timeout = 5000

[spotify]
enabled = true
username = ********
password = ********
client_id = ********
client_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 =

[mpd]
enabled = true
hostname = 127.0.0.1
port = 6600
password =
max_connections = 20
connection_timeout = 60
zeroconf = Mopidy MPD server on $hostname
command_blacklist =
listall
listallinfo
default_playlist_scheme = m3u

I am out of ideas. Any advice on what I should look at next?

Unable to contact server sounds like you have a network problem. The Web api and the main Spotify session work differently, it’s the latter that’s responsible for track lookups and playback, and it’s that which isn’t working for you. I’d start by looking at your firewall.

Failing that, you could enable Mopidy’s debug logging to see if there are any more clues there.

I figured it out. Spotify didn’t like the DNS I was using, which I thought I had ruled out earlier, but dhcpcd was overriding resolve.conf without me realizing it.

I changed to Google’s DNS and everything works fine now.

1 Like