mopidy-spotify
mopidy-spotify copied to clipboard
Published
20 hours ago •
mopidy
mopidy
Intermittent connection, search, and playback issues
Mopidy and mopidy-spotify have been working well for over a year. Recently (the past few months) there have been intermittent connection and playback issues. Currently, if I can get search to work, I can playback the first minute or so of a song, playback then stops. If I queue up another song, it may wait a few minutes, but, will eventually (probably) play the first minute or so and stop.
This is on x86, ubuntu, mopidy v2.1, mopidy-spotify v3.1, using ncmpcpp as my front end if that even matters.
2018-08-23 08:21:09,692 INFO [28188:SpotifyEventLoop] mopidy_spotify.backend: Disconnected from Spotify
2018-08-23 08:23:18,130 INFO [28188:SpotifyEventLoop] mopidy_spotify.backend: Logged in to Spotify in online mode
2018-08-23 08:23:19,090 ERROR [28188:SpotifyEventLoop] spotify.session: Spotify connection error: <ErrorType.CLIENT_TOO_OLD: 9>
2018-08-23 08:23:19,091 INFO [28188:SpotifyEventLoop] mopidy_spotify.backend: Disconnected from Spotify
2018-08-23 08:25:35,269 INFO [28188:SpotifyEventLoop] mopidy_spotify.backend: Logged in to Spotify in online mode
2018-08-23 08:25:36,377 ERROR [28188:SpotifyEventLoop] spotify.session: Spotify connection error: <ErrorType.CLIENT_TOO_OLD: 9>
2018-08-23 08:25:36,377 INFO [28188:SpotifyEventLoop] mopidy_spotify.backend: Disconnected from Spotify
2018-08-23 08:27:52,222 INFO [28188:SpotifyEventLoop] mopidy_spotify.backend: Logged in to Spotify in online mode
2018-08-23 08:27:52,690 ERROR [28188:SpotifyEventLoop] spotify.session: Spotify connection error: <ErrorType.CLIENT_TOO_OLD: 9>
2018-08-23 08:27:52,690 INFO [28188:SpotifyEventLoop] mopidy_spotify.backend: Disconnected from Spotify
2018-08-23 08:30:08,331 INFO [28188:SpotifyEventLoop] mopidy_spotify.backend: Logged in to Spotify in online mode
2018-08-23 08:30:09,077 ERROR [28188:SpotifyEventLoop] spotify.session: Spotify connection error: <ErrorType.CLIENT_TOO_OLD: 9>
2018-08-23 08:30:09,077 INFO [28188:SpotifyEventLoop] mopidy_spotify.backend: Disconnected from Spotify
Is this just because libspotify is out of date and the Spotify region I'm connecting to is bouncing it? Any way I can help troubleshoot this issue? Or is there a recommended alternative?
Your conclusion seems likely but I don't know if we can do anything about it. I away at the moment without access to a machine to test if I now get this.
Are you getting this client too old message every time or just sometimes? What region are you in?
Every time now. This intermittent behavior is consistent. I’m in the southeast US. Should I hop on a VPN or something? Or do you think it’s a combination of my account and the lib?
I'm back in the UK now and I can verify that I don't see this issue. If you have access to a VPN then that should help temporarily but I guess it's only a matter of time before Spotify roll out this client version requirement across all regions and put the final nail in libspotify's coffin.
@kingosticks Tried this morning on a VPN in both London and Chicago and saw the same behavior.
2018-09-04 08:12:00,005 INFO [7480:MpdSession-24] mopidy.mpd.session: New MPD connection from [::ffff:127.0.0.1]:58486
2018-09-04 08:12:01,612 ERROR [7480:SpotifyEventLoop] spotify.session: Spotify connection error: <ErrorType.CLIENT_TOO_OLD: 9>
2018-09-04 08:12:01,613 INFO [7480:SpotifyEventLoop] mopidy_spotify.backend: Disconnected from Spotify
2018-09-04 08:12:40,506 INFO [7480:SpotifyEventLoop] mopidy_spotify.backend: Logged in to Spotify in online mode
2018-09-04 08:12:41,031 ERROR [7480:SpotifyEventLoop] spotify.session: Spotify connection error: <ErrorType.CLIENT_TOO_OLD: 9>
2018-09-04 08:12:41,031 INFO [7480:SpotifyEventLoop] mopidy_spotify.backend: Disconnected from Spotify
It will eventually reconnect for a few minutes, but then just goes back to the above logs on repeat...
Anything I can do to help here (I like my ncmpcpp setup over the spotify desktop client)? ...help to remove the dependency on libspotify? I find it unlikely and/or strange I'm the only one experiencing this behavior.
That's odd. Can you see exactly what version of libspotify you have?
$ apt-cache show libspotify*
Package: libspotify12
Architecture: amd64
Version: 12.1.51-1
Priority: extra
Section: libs
Source: libspotify
Maintainer: Stein Magnus Jodal <[email protected]>
Installed-Size: 2569
Depends: libc6 (>= 2.7)
Filename: dists/stretch/non-free/binary-amd64/libspotify12_12.1.51-1_amd64.deb
Size: 1145468
MD5sum: 15f308474632a3bf0214a3beeeaa9265
SHA1: 4be11cc82b48a752e8acf15f72d7b1b40f90a4d5
SHA256: 9ab71db7215fc278e8d2ad550b2329dde34cc25dd82c09986089240acdab7021
SHA512: a8aee48e569275198e4d91494604c7d15933e520a2deae1c8ba1cdc2941d68014bdc5eb69361e9d09516f02af188f87af0fef27bc90eb8c3501ab4a024051996
Homepage: http://developer.spotify.com/en/libspotify/
Description: Library for using the Spotify music streaming service
The libspotify C API package allows third party developers to write
applications that utilize the Spotify music streaming service.
Description-md5: c639258edb5bbb13ef7341b5abaf7ad6
If you run with debug logging you can see what Spotify access point you are assigned. I don't know if that's interesting... I'm on:
DEBUG 2018-09-04 15:37:17,534 [32477:Dummy-12] spotify.session
libspotify log message: 14:37:17.534 I [ap:1752] Connecting to AP ap.spotify.com:4070
DEBUG 2018-09-04 15:37:17,565 [32477:Dummy-12] spotify.session
libspotify log message: 14:37:17.565 I [ap:1226] Connected to AP: 104.199.65.5:4070
Anything special about your account e.g. facebook login, family membership etc?
Package: libspotify12
Architecture: amd64
Version: 12.1.51-1
Priority: extra
Section: libs
Source: libspotify
Maintainer: Stein Magnus Jodal <[email protected]>
Installed-Size: 2569
Depends: libc6 (>= 2.7)
Filename: dists/stretch/non-free/binary-amd64/libspotify12_12.1.51-1_amd64.deb
Size: 1145468
MD5sum: 15f308474632a3bf0214a3beeeaa9265
SHA1: 4be11cc82b48a752e8acf15f72d7b1b40f90a4d5
SHA256: 9ab71db7215fc278e8d2ad550b2329dde34cc25dd82c09986089240acdab7021
SHA512: a8aee48e569275198e4d91494604c7d15933e520a2deae1c8ba1cdc2941d68014bdc5eb69361e9d09516f02af188f87af0fef27bc90eb8c3501ab4a024051996
Homepage: http://developer.spotify.com/en/libspotify/
Description: Library for using the Spotify music streaming service
The libspotify C API package allows third party developers to write
applications that utilize the Spotify music streaming service.
Description-md5: c639258edb5bbb13ef7341b5abaf7ad6
Package: libspotify-dev
Architecture: amd64
Version: 12.1.51-1
Priority: extra
Section: libdevel
Source: libspotify
Maintainer: Stein Magnus Jodal <[email protected]>
Installed-Size: 1642
Depends: libspotify12 (= 12.1.51-1)
Filename: dists/stretch/non-free/binary-amd64/libspotify-dev_12.1.51-1_amd64.deb
Size: 464066
MD5sum: 455edf2d13a8234ab31d6dda27452fae
SHA1: d537c5604d4d0e64cb0aa231b02aa27168d37635
SHA256: acdd35ce4726c047683de36ea2c52b5f86c9625345d8a42ebe874c61153c2ed9
SHA512: 5e8973a2ca08b589ef70b622bcdd14caded0b9f1d0c28af7f7bd20806fc37d269d3ad7deec8da0f2a5f93efbf60cd38deb89b92dff14d8f4f38bb4130823cb94
Homepage: http://developer.spotify.com/en/libspotify/
Description: Library for using the Spotify music streaming service
This development package provides the header files and the symbolic links to
allow compilation and linking of programs that use the libraries provided in
the libspotify12 package.
Description-md5: d47de16681cf12a7bb07ed939bc01a82
DEBUG 2018-09-05 23:08:42,398 [31013:Dummy-12] spotify.session
libspotify log message: 04:08:42.398 I [ap:1226] Connected to AP: 104.199.240.132:443
Nothing special about my account I think - it is very old. I believe it was a facebook login at first because that was the only way to log in when they were in beta...I might be making that up, otherwise, everything about it is normal.
Also - I don't pretend to know anything about the inner workings of spotify or libspotify, but find it weird that my AP I'm connected to is over port :443, and not what appears to be the common :4070 Spotify port (according to my 15 seconds of Googling, and your snippet).
Here's a snippet of the logs from what looks like a connection to :80, then to :4070, not sure if this is helpful or not.
Installing the snap app of Spotify works as expected - I know thats a completely different thing, but maybe worth noting.
DEBUG 2018-09-06 08:09:15,872 [3238:Dummy-12] spotify.session
libspotify log message: 13:09:15.871 E [ap:4172] ChannelError(1, 0, playlist)
DEBUG 2018-09-06 08:09:15,872 [3238:SpotifyEventLoop] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:15,872 [3238:Dummy-12] spotify.session
libspotify log message: 13:09:15.872 E [ap:4168] ChannelError(1, 0, BAD_JOB)
DEBUG 2018-09-06 08:09:15,873 [3238:Dummy-12] spotify.session
libspotify log message: 13:09:15.873 E [ap:3915] Connection error: 102
DEBUG 2018-09-06 08:09:15,874 [3238:Dummy-12] spotify.session
libspotify log message: 13:09:15.874 I [ap:1752] Connecting to AP ap.spotify.com:80
DEBUG 2018-09-06 08:09:15,874 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.620s for new events
DEBUG 2018-09-06 08:09:15,875 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:15,875 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.617s for new events
DEBUG 2018-09-06 08:09:15,907 [3238:Dummy-12] spotify.session
libspotify log message: 13:09:15.907 I [ap:1226] Connected to AP: 104.154.127.222:80
DEBUG 2018-09-06 08:09:15,998 [3238:Dummy-12] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:16,040 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:16,086 [3238:SpotifyEventLoop] spotify.session
Credentials blob updated: 'NvhrI4VKse21cXHKgdLF8/g9k8l4VNLCxF6KpNe0Inv1hZHOw/oViNe8HsT81ze7nIsQcjXn6qcBHzqm4hpRac+Sr7y/3TgiEKxbhrnb21goKwLQ+323utyxEmslrmXxhawddLZm2AFahhgApHMspdjSu7xB9k/emvN4DxILHWXH6tBDFMAyfQMp5V2XJWr1'
DEBUG 2018-09-06 08:09:16,087 [3238:SpotifyEventLoop] spotify.session
Connection state updated
INFO 2018-09-06 08:09:16,087 [3238:SpotifyEventLoop] mopidy_spotify.backend
Logged in to Spotify in online mode
DEBUG 2018-09-06 08:09:16,087 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.451s for new events
DEBUG 2018-09-06 08:09:16,539 [3238:SpotifyEventLoop] spotify.eventloop
Timeout reached; processing events
DEBUG 2018-09-06 08:09:16,540 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 4.240s for new events
DEBUG 2018-09-06 08:09:20,781 [3238:SpotifyEventLoop] spotify.eventloop
Timeout reached; processing events
DEBUG 2018-09-06 08:09:20,782 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.072s for new events
DEBUG 2018-09-06 08:09:20,812 [3238:Dummy-12] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:20,814 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:20,815 [3238:SpotifyEventLoop] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:20,816 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.039s for new events
DEBUG 2018-09-06 08:09:20,816 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:20,817 [3238:SpotifyEventLoop] spotify.session
User info updated
DEBUG 2018-09-06 08:09:20,817 [3238:SpotifyEventLoop] spotify.session
User info updated
DEBUG 2018-09-06 08:09:20,817 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.037s for new events
DEBUG 2018-09-06 08:09:20,855 [3238:SpotifyEventLoop] spotify.eventloop
Timeout reached; processing events
DEBUG 2018-09-06 08:09:20,856 [3238:SpotifyEventLoop] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:20,858 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.019s for new events
DEBUG 2018-09-06 08:09:20,858 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:20,858 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.017s for new events
DEBUG 2018-09-06 08:09:20,876 [3238:SpotifyEventLoop] spotify.eventloop
Timeout reached; processing events
DEBUG 2018-09-06 08:09:20,876 [3238:SpotifyEventLoop] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:20,877 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 4.978s for new events
DEBUG 2018-09-06 08:09:20,877 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:20,877 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 4.976s for new events
DEBUG 2018-09-06 08:09:25,854 [3238:SpotifyEventLoop] spotify.eventloop
Timeout reached; processing events
DEBUG 2018-09-06 08:09:25,863 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.017s for new events
DEBUG 2018-09-06 08:09:25,881 [3238:SpotifyEventLoop] spotify.eventloop
Timeout reached; processing events
DEBUG 2018-09-06 08:09:25,882 [3238:SpotifyEventLoop] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:25,882 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 4.972s for new events
DEBUG 2018-09-06 08:09:25,882 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:25,883 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 4.971s for new events
DEBUG 2018-09-06 08:09:25,915 [3238:Dummy-12] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:25,916 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:25,916 [3238:SpotifyEventLoop] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:25,917 [3238:SpotifyEventLoop] spotify.playlist_container
Playlist removed at index 1
DEBUG 2018-09-06 08:09:25,917 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist "2018-21" removed from index 1
DEBUG 2018-09-06 08:09:25,917 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist "2018-21" removed from index 1
DEBUG 2018-09-06 08:09:25,918 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist "2018-21" removed from index 1
DEBUG 2018-09-06 08:09:25,918 [3238:SpotifyEventLoop] spotify.playlist_container
Playlist removed at index 0
DEBUG 2018-09-06 08:09:25,918 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist "2018-05-25" removed from index 0
DEBUG 2018-09-06 08:09:25,919 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist "2018-05-25" removed from index 0
DEBUG 2018-09-06 08:09:25,919 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist "2018-05-25" removed from index 0
DEBUG 2018-09-06 08:09:25,919 [3238:SpotifyEventLoop] spotify.playlist_container
Playlist container loaded
DEBUG 2018-09-06 08:09:25,920 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist container loaded
DEBUG 2018-09-06 08:09:25,920 [3238:SpotifyEventLoop] mopidy.listener
Sending playlists_loaded to BackendListener: {}
DEBUG 2018-09-06 08:09:25,920 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist container loaded
DEBUG 2018-09-06 08:09:25,920 [3238:Core-13] mopidy.listener
Sending playlists_loaded to CoreListener: {}
DEBUG 2018-09-06 08:09:25,921 [3238:SpotifyEventLoop] mopidy.listener
Sending playlists_loaded to BackendListener: {}
DEBUG 2018-09-06 08:09:25,922 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist container loaded
DEBUG 2018-09-06 08:09:25,922 [3238:Core-13] mopidy.listener
Sending playlists_loaded to CoreListener: {}
DEBUG 2018-09-06 08:09:25,922 [3238:SpotifyEventLoop] mopidy.listener
Sending playlists_loaded to BackendListener: {}
DEBUG 2018-09-06 08:09:25,923 [3238:Core-13] mopidy.listener
Sending playlists_loaded to CoreListener: {}
DEBUG 2018-09-06 08:09:25,923 [3238:SpotifyEventLoop] spotify.session
libspotify log message: 13:09:25.923 W [playlist:1575] Lost items added 0000000000000000000000000000000000!!!
DEBUG 2018-09-06 08:09:25,924 [3238:SpotifyEventLoop] spotify.playlist_container
Playlist added at index 0
DEBUG 2018-09-06 08:09:25,924 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist "2018-05-25" added to index 0
DEBUG 2018-09-06 08:09:25,925 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist "2018-05-25" added to index 0
DEBUG 2018-09-06 08:09:25,925 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist "2018-05-25" added to index 0
DEBUG 2018-09-06 08:09:25,925 [3238:SpotifyEventLoop] spotify.playlist_container
Playlist added at index 1
DEBUG 2018-09-06 08:09:25,926 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist "2018-21" added to index 1
DEBUG 2018-09-06 08:09:25,926 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist "2018-21" added to index 1
DEBUG 2018-09-06 08:09:25,926 [3238:SpotifyEventLoop] mopidy_spotify.playlists
Spotify playlist "2018-21" added to index 1
DEBUG 2018-09-06 08:09:25,927 [3238:SpotifyEventLoop] spotify.session
libspotify log message: 13:09:25.927 W [playlist:1575] Lost items added 47419bcbaea50d06e284ff07b8a45f3f04!!!
DEBUG 2018-09-06 08:09:25,931 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.001s for new events
DEBUG 2018-09-06 08:09:25,931 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:25,931 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.985s for new events
DEBUG 2018-09-06 08:09:25,947 [3238:Dummy-12] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:25,963 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:25,964 [3238:SpotifyEventLoop] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:25,964 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.953s for new events
DEBUG 2018-09-06 08:09:25,964 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:25,965 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.952s for new events
DEBUG 2018-09-06 08:09:26,048 [3238:Dummy-12] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:26,079 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:26,079 [3238:SpotifyEventLoop] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:26,079 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.838s for new events
DEBUG 2018-09-06 08:09:26,079 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:26,080 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.837s for new events
DEBUG 2018-09-06 08:09:26,080 [3238:Dummy-12] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:26,081 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:26,081 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.836s for new events
DEBUG 2018-09-06 08:09:26,112 [3238:Dummy-12] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:26,113 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:26,114 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.803s for new events
DEBUG 2018-09-06 08:09:26,413 [3238:Dummy-12] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:26,428 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:26,429 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.488s for new events
DEBUG 2018-09-06 08:09:26,446 [3238:Dummy-12] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:26,461 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:26,462 [3238:SpotifyEventLoop] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:26,462 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.455s for new events
DEBUG 2018-09-06 08:09:26,463 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:26,463 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.454s for new events
DEBUG 2018-09-06 08:09:26,479 [3238:Dummy-12] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:26,479 [3238:Dummy-12] spotify.session
libspotify log message: 13:09:26.479 E [ap:4172] ChannelError(8, 0, playlist)
DEBUG 2018-09-06 08:09:26,480 [3238:Dummy-12] spotify.session
libspotify log message: 13:09:26.480 E [ap:4172] ChannelError(16, 0, playlist)
DEBUG 2018-09-06 08:09:26,480 [3238:Dummy-12] spotify.session
libspotify log message: 13:09:26.480 E [ap:4168] ChannelError(16, 0, BAD_JOB)
DEBUG 2018-09-06 08:09:26,481 [3238:Dummy-12] spotify.session
libspotify log message: 13:09:26.481 E [ap:3915] Connection error: 102
DEBUG 2018-09-06 08:09:26,481 [3238:Dummy-12] spotify.session
libspotify log message: 13:09:26.481 I [ap:1752] Connecting to AP ap.spotify.com:4070
DEBUG 2018-09-06 08:09:26,495 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:26,496 [3238:SpotifyEventLoop] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:26,496 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.421s for new events
DEBUG 2018-09-06 08:09:26,497 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:26,497 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.420s for new events
DEBUG 2018-09-06 08:09:26,514 [3238:Dummy-12] spotify.session
libspotify log message: 13:09:26.514 I [ap:1226] Connected to AP: 104.154.127.129:4070
DEBUG 2018-09-06 08:09:26,611 [3238:Dummy-12] spotify.session
Notify main thread
DEBUG 2018-09-06 08:09:26,661 [3238:SpotifyEventLoop] spotify.eventloop
Notification received; processing events
DEBUG 2018-09-06 08:09:26,684 [3238:SpotifyEventLoop] spotify.session
Credentials blob updated: 'NvhrI4VKse21cXHKgdLF81sE7wUDLdB6l5MndE4DomhktFOCmmCSQDlgSlYcMJaX9AF5Q8lQcjpbgIm0aJ4Ihbb4yYdu3qlUnJrDakuctyw1NMbOi2qY+EoBgKUHKo3uNL2ir1Z6D7U2Uip0EGY4yf+8OnlNqHXXCYnJqeF/U/9/b0WQqoOz07GgqfzkS9Ue'
DEBUG 2018-09-06 08:09:26,684 [3238:SpotifyEventLoop] spotify.session
Connection state updated
INFO 2018-09-06 08:09:26,684 [3238:SpotifyEventLoop] mopidy_spotify.backend
Logged in to Spotify in online mode
DEBUG 2018-09-06 08:09:26,684 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 0.255s for new events
DEBUG 2018-09-06 08:09:26,940 [3238:SpotifyEventLoop] spotify.eventloop
Timeout reached; processing events
DEBUG 2018-09-06 08:09:26,941 [3238:SpotifyEventLoop] spotify.eventloop
Waiting 3.913s for new events
DEBUG 2018-09-06 08:09:30,453 [3238:MpdFrontend-14] mopidy.zeroconf
Zeroconf service "Mopidy MPD server on hostname" (_mpd._tcp at []:6600): Published
DEBUG 2018-09-06 08:09:30,454 [3238:MainThread] pykka
Registered MpdSession (urn:uuid:3d30ec27-bfd5-41f4-bf9f-878f6c097167)
DEBUG 2018-09-06 08:09:30,457 [3238:MpdFrontend-14] mopidy.listener
Sending stored_playlist to MpdSession: {}
DEBUG 2018-09-06 08:09:30,457 [3238:MainThread] pykka
Starting MpdSession (urn:uuid:3d30ec27-bfd5-41f4-bf9f-878f6c097167)
DEBUG 2018-09-06 08:09:30,460 [3238:MpdFrontend-14] mopidy.listener
Sending stored_playlist to MpdSession: {}
INFO 2018-09-06 08:09:30,461 [3238:MpdSession-18] mopidy.mpd.session
New MPD connection from [::ffff:127.0.0.1]:51720
INFO 2018-09-06 08:09:30,462 [3238:MainThread] mopidy.commands
Interrupted. Exiting...
Just wanted to leave an update on this issue. I created a new account and it seems to be working fine. I'll keep using the new Spotify account and see if there are any issues...
This has started again after a few months of working perfectly - same behavior as before on a brand new spotify account.