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.

Sign up for GitHub

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

Jump to bottom

Intermittent connection, search, and playback issues #197

Open
duanearnett opened this issue Aug 23, 2018 · 9 comments
Open

Intermittent connection, search, and playback issues #197

duanearnett opened this issue Aug 23, 2018 · 9 comments

Comments

@duanearnett
Copy link

duanearnett commented Aug 23, 2018 •
edited

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?
@kingosticks
Copy link
Member

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?

@duanearnett
Copy link
Author

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?

@kingosticks
Copy link
Member

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.

@duanearnett
Copy link
Author

@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.

@kingosticks
Copy link
Member

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 <stein.magnus@jodal.no>
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?

@duanearnett
Copy link
Author 

Package: libspotify12
Architecture: amd64
Version: 12.1.51-1
Priority: extra
Section: libs
Source: libspotify
Maintainer: Stein Magnus Jodal <stein.magnus@jodal.no>
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 <stein.magnus@jodal.no>
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.

@duanearnett
Copy link
Author

duanearnett commented Sep 6, 2018 •
edited

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...

@duanearnett
Copy link
Author

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...

@duanearnett
Copy link
Author

This has started again after a few months of working perfectly - same behavior as before on a brand new spotify account.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@duanearnett @kingosticks