Disconnected from spotify

Every now an then mopidy gives the following error and stops working:

1:02:59ERROR    2022-02-20 21:02:59,584 [1131:SpotifyEventLoop] spotify.session
  Spotify connection error: <ErrorType.UNABLE_TO_CONTACT_SERVER: 8>
INFO     2022-02-20 21:02:59,585 [1131:SpotifyEventLoop] mopidy_spotify.backend
  Disconnected from Spotify

Restarting mopidy helps for some time.
I have several raspberries and sometimes one device is affected and sometimes the other device. So I don’t believe it is (only) the ap.spotify.com problem mentionend here (Spotify login error: <ErrorType.UNABLE_TO_CONTACT_SERVER: 8>)

Is there a way to make mopidy more robust? Like reconnecting again after Disconnecting?

I’ve never hit this issue (uptime on my main pi-based Mopidy server is 233 days) so it’s likely an issue within your network/WiFi/internet connection or possibly with the particular Spotify server you were assigned when you connected - some of them go through periods of instability.

Even so, Libspotify already has support for tracking connection state (hence the log message) and it should be automatically logging back in again (see example at Intermittent connection, search, and playback issues · Issue #197 · mopidy/mopidy-spotify · GitHub). I wonder why that isn’t happening in your case. Perhaps a debug log would give us a clue.

Thanks for the quick reply. Strangely I have another pi with same SW running in the same network without problems.
I didn’t hit the disconnection problem again but instead encountered some exceptions which lead to the same result (not working system) in the end. Problem is that mopidy doesn’t recover. I enabled logging and added them as attachment. Would be so nice if you can have a look. Thx.

I hit the disconnected issue again. After this an exception occurs:
(tried to log more detailed information. but the raspi had trouble to handle this amount of data)

16:26:25INFO     2022-03-15 16:26:25,084 [1040:MainThread] mopidy.commands
  Starting Mopidy backends: FileBackend, M3UBackend, StreamBackend, SpotifyBackend

16:26:25INFO     2022-03-15 16:26:25,221 [1040:Audio-2] mopidy.audio.actor
  Audio output set to "volume volume=0.3 ! alsasink device=hw:0,0"

16:38:17ERROR    2022-03-15 16:38:17,643 [1040:SpotifyBackend-6] mopidy_spotify.web
  OAuth token refresh failed: invalid_grant Grant has been revoked.

16:38:17ERROR    2022-03-15 16:38:17,644 [1040:SpotifyBackend-6] mopidy_spotify.web
  Failed to load Spotify user profile
INFO     2022-03-15 16:38:17,645 [1040:MainThread] mopidy.commands
  Starting Mopidy core

16:38:17INFO     2022-03-15 16:38:17,683 [1040:MainThread] mopidy.commands
  Starting Mopidy frontends: HttpFrontend

16:38:17INFO     2022-03-15 16:38:17,690 [1040:HttpFrontend-11] mopidy.http.actor
  HTTP server running at [::ffff:127.0.0.1]:6680

16:38:17INFO     2022-03-15 16:38:17,690 [1040:MainThread] mopidy.commands
  Starting GLib mainloop

16:38:17INFO     2022-03-15 16:38:17,902 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

16:38:17INFO     2022-03-15 16:38:17,903 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

19:41:26INFO     2022-03-15 19:41:26,241 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

19:41:26INFO     2022-03-15 19:41:26,242 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:10:04INFO     2022-03-15 20:10:03,931 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode
INFO     2022-03-15 20:10:03,933 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:10:04INFO     2022-03-15 20:10:04,715 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:10:04INFO     2022-03-15 20:10:04,716 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:10:15INFO     2022-03-15 20:10:15,517 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:10:15INFO     2022-03-15 20:10:15,518 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:10:21INFO     2022-03-15 20:10:21,691 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:10:21INFO     2022-03-15 20:10:21,692 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:10:38INFO     2022-03-15 20:10:38,540 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:10:38INFO     2022-03-15 20:10:38,541 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:10:55INFO     2022-03-15 20:10:55,917 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:10:55INFO     2022-03-15 20:10:55,922 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:10:56ERROR    2022-03-15 20:10:56,010 [1040:SpotifyEventLoop] spotify.session
  Spotify connection error: <ErrorType.UNABLE_TO_CONTACT_SERVER: 8>

20:10:56INFO     2022-03-15 20:10:56,011 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Disconnected from Spotify

20:11:07INFO     2022-03-15 20:11:07,181 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:11:07INFO     2022-03-15 20:11:07,182 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:11:07ERROR    2022-03-15 20:11:07,263 [1040:SpotifyEventLoop] spotify.session
  Spotify connection error: <ErrorType.UNABLE_TO_CONTACT_SERVER: 8>

20:11:07INFO     2022-03-15 20:11:07,264 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Disconnected from Spotify

20:11:13INFO     2022-03-15 20:11:13,625 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:11:13INFO     2022-03-15 20:11:13,626 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:15:07INFO     2022-03-15 20:15:07,186 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:15:07INFO     2022-03-15 20:15:07,189 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:31:44INFO     2022-03-15 20:31:44,867 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:31:44INFO     2022-03-15 20:31:44,868 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:40:10INFO     2022-03-15 20:40:10,844 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:40:10INFO     2022-03-15 20:40:10,847 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:41:50INFO     2022-03-15 20:41:50,515 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:41:50INFO     2022-03-15 20:41:50,516 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:42:12INFO     2022-03-15 20:42:12,457 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:42:12INFO     2022-03-15 20:42:12,461 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:43:16INFO     2022-03-15 20:43:16,226 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:43:16INFO     2022-03-15 20:43:16,226 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:43:33INFO     2022-03-15 20:43:33,407 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:43:33INFO     2022-03-15 20:43:33,408 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:49:27INFO     2022-03-15 20:49:27,437 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:49:27INFO     2022-03-15 20:49:27,438 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:49:56INFO     2022-03-15 20:49:56,127 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:49:56INFO     2022-03-15 20:49:56,129 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:50:13INFO     2022-03-15 20:50:13,062 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:50:13INFO     2022-03-15 20:50:13,063 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:50:19INFO     2022-03-15 20:50:19,566 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:50:19INFO     2022-03-15 20:50:19,567 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:50:30INFO     2022-03-15 20:50:30,983 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Logged in to Spotify in online mode

20:50:30INFO     2022-03-15 20:50:30,984 [1040:SpotifyBackend-6] mopidy_spotify.backend
  Spotify private session activated

20:50:47ERROR    2022-03-15 20:50:47,010 [1040:SpotifyEventLoop] spotify.session
  Spotify connection error: <ErrorType.UNABLE_TO_CONTACT_SERVER: 8>
INFO     2022-03-15 20:50:47,012 [1040:SpotifyEventLoop] mopidy_spotify.backend
  Disconnected from Spotify

20:50:48ERROR    2022-03-15 20:50:48,714 [1040:Core-9] mopidy.core.library
  SpotifyBackend backend caused an exception.
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/mopidy/core/library.py", line 17, in _backend_error_handling
    yield
  File "/usr/lib/python3/dist-packages/mopidy/core/library.py", line 114, in _browse
    result = backend.library.browse(uri).get()
  File "/usr/lib/python3/dist-packages/pykka/_threading.py", line 45, in get
    _compat.reraise(*self._data['exc_info'])
  File "/usr/lib/python3/dist-packages/pykka/_compat/__init__.py", line 29, in reraise
    raise value
  File "/usr/lib/python3/dist-packages/pykka/_actor.py", line 193, in _actor_loop
    response = self._handle_receive(envelope.message)
  File "/usr/lib/python3/dist-packages/pykka/_actor.py", line 299, in _handle_receive
    return callee(*message.args, **message.kwargs)
  File "/usr/lib/python3/dist-packages/mopidy_spotify/library.py", line 22, in browse
    uri=uri,
  File "/usr/lib/python3/dist-packages/mopidy_spotify/browse.py", line 61, in browse
    return _browse_album(session, uri, config)
  File "/usr/lib/python3/dist-packages/mopidy_spotify/browse.py", line 98, in _browse_album
    sp_album_browser.load(config["timeout"])
  File "/usr/lib/python3/dist-packages/spotify/album.py", line 273, in load
    return utils.load(self._session, self, timeout=timeout)
  File "/usr/lib/python3/dist-packages/spotify/utils.py", line 224, in load
    % session.connection.state
spotify.error.Error: Session must be logged in and online to load objects: <ConnectionState.DISCONNECTED: 2>

20:50:49ERROR    2022-03-15 20:50:49,957 [1040:Core-9] mopidy.core.library
  SpotifyBackend backend caused an exception.
Traceback (most recent call last):
  File "/usr/lib/python3/dist-packages/mopidy/core/library.py", line 17, in _backend_error_handling
    yield
  File "/usr/lib/python3/dist-packages/mopidy/core/library.py", line 114, in _browse
    result = backend.library.browse(uri).get()
  File "/usr/lib/python3/dist-packages/pykka/_threading.py", line 45, in get
    _compat.reraise(*self._data['exc_info'])
  File "/usr/lib/python3/dist-packages/pykka/_compat/__init__.py", line 29, in reraise
    raise value
  File "/usr/lib/python3/dist-packages/pykka/_actor.py", line 193, in _actor_loop
    response = self._handle_receive(envelope.message)
  File "/usr/lib/python3/dist-packages/pykka/_actor.py", line 299, in _handle_receive
    return callee(*message.args, **message.kwargs)
  File "/usr/lib/python3/dist-packages/mopidy_spotify/library.py", line 22, in browse
    uri=uri,
  File "/usr/lib/python3/dist-packages/mopidy_spotify/browse.py", line 61, in browse
    return _browse_album(session, uri, config)
  File "/usr/lib/python3/dist-packages/mopidy_spotify/browse.py", line 98, in _browse_album
    sp_album_browser.load(config["timeout"])
  File "/usr/lib/python3/dist-packages/spotify/album.py", line 273, in load
    return utils.load(self._session, self, timeout=timeout)
  File "/usr/lib/python3/dist-packages/spotify/utils.py", line 224, in load
    % session.connection.state
spotify.error.Error: Session must be logged in and online to load objects: <ConnectionState.DISCONNECTED: 2>

Thanks for the log. You can see the connection to Spotify going down and then libspotify reconnects a few seconds later each time. So it is handling this situation the best it can. We need to find the reason reason for the connection going down so much and it must be something outside of Mopidy at the system-level.

You say the other system doesn’t have these connection issues. Is that system exactly the same? Same network? Wired - try a different network cable? Wireless - move it somewhere else?

The exception you got at the end of the log is a result of trying to use Mopidy-Spotidy during one of these periods of the network going down. We handle this gracefully in most places but we missed this one. I’ve raised Backend exception when browsing albums · Issue #332 · mopidy/mopidy-spotify · GitHub

Thanks! This is great. The connection is wireless. I saw the same behavior now also with the other device too. My guess is that the network is simply unreliable or the endpoint (spotify) is. I hope that once that issue #332 is fixed also the system works more reliable and can recover.