Force 10 second cache expiry for everything.

Workaround for Spotify's use of max-age=0 for the me/playlists endpoint.

1. ~7.7 seconds
INFO     2019-12-03 23:47:16,030 Logged into Spotify Web API as kingosticks4
INFO     2019-12-03 23:47:23,659 Refreshed 68 playlists
INFO     2019-12-03 23:47:23,659 Refresh Playlists took 7628ms
INFO     2019-12-03 23:47:23,659 Starting Mopidy core

2. real	0m0.057s
INFO     2019-12-03 23:47:26,070 playlists.as_list() took 1ms
INFO     2019-12-03 23:47:26,073 playlists.as_list() took 1ms

2. real	0m0.223s
INFO     2019-12-03 23:47:27,668 playlists.as_list() took 212ms

3. real	0m0.837s

3. real	0m0.470s

Author: kingosticks

mopidy_spotify/playlists.py

@@ -25,10 +25,7 @@ def as_list(self):
             return list(self._get_flattened_playlist_refs())
 
     def _get_flattened_playlist_refs(self):
-        if self._backend._web_client is None:
-            return
-
-        if self._backend._web_client.user_id is None:
+        if not self._backend._web_client.logged_in:
             return
 
         web_client = self._backend._web_client
@@ -41,9 +38,6 @@ def _get_flattened_playlist_refs(self):
 
     def get_items(self, uri):
         with utils.time_logger(f"playlist.get_items({uri})", logging.INFO):
-            if not self._loaded:
-                return []
-
             return self._get_playlist(uri, as_items=True)
 
     def lookup(self, uri):
@@ -60,14 +54,17 @@ def _get_playlist(self, uri, as_items=False):
         )
 
     def refresh(self):
+        if not self._backend._web_client.logged_in:
+            return
+
         with utils.time_logger("Refresh Playlists", logging.INFO):
             _sp_links.clear()
-            with self._backend._web_client.refresh_playlists():
-                count = 0
-                for playlist_ref in self._get_flattened_playlist_refs():
-                    self._get_playlist(playlist_ref.uri)
-                    count = count + 1
-                logger.info(f"Refreshed {count} playlists")
+            self._backend._web_client.clear_cache()
+            count = 0
+            for playlist_ref in self._get_flattened_playlist_refs():
+                self._get_playlist(playlist_ref.uri)
+                count = count + 1
+            logger.info(f"Refreshed {count} playlists")
 
         self._loaded = True
 
@@ -82,7 +79,7 @@ def save(self, playlist):
 
 
 def playlist_lookup(session, web_client, uri, bitrate, as_items=False):
-    if web_client is None or web_client.user_id is None:
+    if web_client is None or not web_client.logged_in:
         return
 
     logger.debug(f'Fetching Spotify playlist "{uri}"')

mopidy_spotify/web.py

@@ -6,7 +6,6 @@
 import re
 import time
 import urllib.parse
-from contextlib import contextmanager
 from datetime import datetime
 
 import requests
@@ -74,9 +73,10 @@ def get(self, path, cache=None, *args, **kwargs):
 
         _trace(f"Get '{path}'")
 
+        ignore_expiry = kwargs.pop("ignore_expiry", False)
         if cache is not None and path in cache:
             cached_result = cache.get(path)
-            if not cached_result.expired:
+            if cached_result.still_valid(ignore_expiry):
                 return cached_result
             kwargs.setdefault("headers", {}).update(cached_result.etag_headers)
 
@@ -260,6 +260,7 @@ def _parse_retry_after(self, response):
 
 class WebResponse(dict):
     def __init__(self, url, data, expires=0.0, etag=None, status_code=400):
+        self._from_cache = False
         self.url = url
         self._expires = expires
         self._etag = etag
@@ -315,13 +316,24 @@ def _parse_etag(response):
             if etag and len(etag.groups()) == 2:
                 return etag.groups()[1]
 
-    @property
-    def expired(self):
-        status_str = {True: "expired", False: "fresh"}
-        result = self._expires < time.time()
-        _trace(f"Cached data {status_str[result]} for {self}")
+    def still_valid(self, ignore_expiry=False):
+        if ignore_expiry:
+            result = True
+            status = "forced"
+        elif self._expires >= time.time():
+            result = True
+            status = "fresh"
+        else:
+            result = False
+            status = "expired"
+        self._from_cache = result
+        _trace("Cached data %s for %s", status, self)
         return result
 
+    @property
+    def status_unchanged(self):
+        return self._from_cache or 304 == self._status_code
+
     @property
     def status_ok(self):
         return self._status_code >= 200 and self._status_code < 400
@@ -334,6 +346,7 @@ def etag_headers(self):
             return {}
 
     def updated(self, response):
+        self._from_cache = False
         if self._etag is None:
             return False
         elif self.url != response.url:
@@ -349,6 +362,7 @@ def updated(self, response):
         _trace(f"ETag match for {self} {response}")
         self._expires = response._expires
         self._etag = response._etag
+        self._status_code = response._status_code
         return True
 
     def __str__(self):
@@ -358,6 +372,10 @@ def __str__(self):
             f"[ETag: {self._etag}]"
         )
 
+    def increase_expiry(self, delta_seconds):
+        if self.status_ok and not self._from_cache:
+            self._expires += delta_seconds
+
 
 class SpotifyOAuthClient(OAuthClient):
 
@@ -368,6 +386,7 @@ class SpotifyOAuthClient(OAuthClient):
     PLAYLIST_FIELDS = (
         f"name,owner.id,type,uri,snapshot_id,tracks({TRACK_FIELDS}),"
     )
+    DEFAULT_EXTRA_EXPIRY = 10
 
     def __init__(self, client_id, client_secret, proxy_config):
         super(SpotifyOAuthClient, self).__init__(
@@ -379,11 +398,17 @@ def __init__(self, client_id, client_secret, proxy_config):
         )
         self.user_id = None
         self._cache = {}
+        self._extra_expiry = self.DEFAULT_EXTRA_EXPIRY
+
+    def get_one(self, path, *args, **kwargs):
+        logger.debug(f'Fetching page "{path}"')
+        result = self.get(path, cache=self._cache, *args, **kwargs)
+        result.increase_expiry(self._extra_expiry)
+        return result
 
     def get_all(self, path, *args, **kwargs):
         while path is not None:
-            logger.debug(f'Fetching page "{path}"')
-            result = self.get(path, *args, **kwargs)
+            result = self.get_one(path, *args, **kwargs)
             path = result.get("next")
             yield result
 
@@ -396,11 +421,13 @@ def login(self):
             logger.info(f"Logged into Spotify Web API as {self.user_id}")
             return True
 
+    @property
+    def logged_in(self):
+        return self.user_id is not None
+
     def get_user_playlists(self):
         with utils.time_logger("get_user_playlists"):
-            pages = self.get_all(
-                "me/playlists", cache=self._cache, params={"limit": 50}
-            )
+            pages = self.get_all("me/playlists", params={"limit": 50})
             for page in pages:
                 for playlist in page.get("items", []):
                     yield playlist
@@ -416,17 +443,16 @@ def get_playlist(self, uri):
             logger.error(exc)
             return {}
 
-        playlist = self.get(
+        playlist = self.get_one(
             f"playlists/{parsed.id}",
-            cache=self._cache,
             params={"fields": self.PLAYLIST_FIELDS, "market": "from_token"},
         )
 
         tracks_path = playlist.get("tracks", {}).get("next")
         track_pages = self.get_all(
             tracks_path,
-            cache=self._cache,
             params={"fields": self.TRACK_FIELDS, "market": "from_token"},
+            ignore_expiry=playlist.status_unchanged,
         )
 
         more_tracks = []
@@ -440,14 +466,8 @@ def get_playlist(self, uri):
 
         return playlist
 
-    @contextmanager
-    def refresh_playlists(self, extra_expiry=None):
+    def clear_cache(self, extra_expiry=None):
         self._cache.clear()
-        old_extra_expiry = self._extra_expiry
-        if extra_expiry is not None:
-            self._extra_expiry = extra_expiry
-        yield
-        self._extra_expiry = old_extra_expiry
 
 
 WebLink = collections.namedtuple("WebLink", ["uri", "type", "id", "owner"])

tests/test_backend.py

@@ -186,6 +186,7 @@ def test_on_start_refreshes_playlists(spotify_mock, web_mock, config, caplog):
     client_mock = web_mock.SpotifyOAuthClient.return_value
     client_mock.get_user_playlists.assert_called_once()
     assert "Refreshed 0 playlists" in caplog.text
+    assert backend.playlists._loaded
 
 
 def test_on_start_doesnt_refresh_playlists_if_not_allowed(

tests/test_playlists.py

@@ -55,7 +55,7 @@ def test_is_a_playlists_provider(provider):
 
 
 def test_as_list_when_not_logged_in(web_client_mock, provider):
-    web_client_mock.user_id = None
+    web_client_mock.logged_in = False
 
     result = provider.as_list()
 
@@ -70,15 +70,15 @@ def test_as_list_when_offline(web_client_mock, provider):
     assert len(result) == 0
 
 
-def test_as_list_blocked_when_not_loaded(provider):
+def test_as_list_when_not_loaded(provider):
     provider._loaded = False
 
     result = provider.as_list()
 
     assert len(result) == 0
 
 
-def test_as_list_when_playlist_wont_translate(provider, caplog):
+def test_as_list_when_playlist_wont_translate(provider):
     result = provider.as_list()
 
     assert len(result) == 2
@@ -104,20 +104,34 @@ def test_get_items_when_playlist_without_tracks(provider):
 
     assert len(result) == 0
 
-    assert result == []
 
+def test_get_items_when_not_logged_in(web_client_mock, provider):
+    web_client_mock.logged_in = False
 
-def test_get_items_blocked_when_not_loaded(provider):
+    assert provider.get_items("spotify:user:alice:playlist:foo") is None
+
+
+def test_get_items_when_offline(web_client_mock, provider, caplog):
+    web_client_mock.get_playlist.side_effect = None
+    web_client_mock.get_playlist.return_value = {}
+
+    assert provider.get_items("spotify:user:alice:playlist:foo") is None
+    assert (
+        "Failed to lookup Spotify playlist URI "
+        "spotify:user:alice:playlist:foo" in caplog.text
+    )
+
+
+def test_get_items_when_not_loaded(provider):
     provider._loaded = False
 
     result = provider.get_items("spotify:user:alice:playlist:foo")
 
-    assert len(result) == 0
-
-    assert result == []
+    assert len(result) == 1
+    assert result[0] == Ref.track(uri="spotify:track:abc", name="ABC 123")
 
 
-def test_get_items_when_playlist_wont_translate(provider, caplog):
+def test_get_items_when_playlist_wont_translate(provider):
     assert provider.get_items("spotify:user:alice:playlist:malformed") is None
 
 
@@ -141,7 +155,18 @@ def test_refresh_loads_all_playlists(provider, web_client_mock):
     web_client_mock.get_playlist.assert_has_calls(expected_calls)
 
 
-def test_refresh_when_not_loaded(provider, web_client_mock):
+def test_refresh_when_not_logged_in(provider, web_client_mock):
+    provider._loaded = False
+    web_client_mock.logged_in = False
+
+    provider.refresh()
+
+    web_client_mock.get_user_playlists.assert_not_called()
+    web_client_mock.get_playlist.assert_not_called()
+    assert not provider._loaded
+
+
+def test_refresh_sets_loaded(provider, web_client_mock):
     provider._loaded = False
 
     provider.refresh()
@@ -157,13 +182,13 @@ def test_refresh_counts_playlists(provider, caplog):
     assert "Refreshed 2 playlists" in caplog.text
 
 
-def test_refresh_clears_link_cache(provider):
-    playlists._sp_links = {"bar": "foobar", "bar2": "foofoo"}
+def test_refresh_clears_caches(provider, web_client_mock):
+    playlists._sp_links = {"bar": "foobar"}
 
     provider.refresh()
 
-    assert len(playlists._sp_links) == 1
-    assert list(playlists._sp_links.keys()) == ["spotify:track:abc"]
+    assert "bar" not in playlists._sp_links
+    web_client_mock.clear_cache.assert_called_once()
 
 
 def test_lookup(provider):
@@ -174,6 +199,14 @@ def test_lookup(provider):
     assert playlist.tracks[0].bitrate == 160
 
 
+def test_lookup_when_not_logged_in(web_client_mock, provider):
+    web_client_mock.logged_in = False
+
+    playlist = provider.lookup("spotify:user:alice:playlist:foo")
+
+    assert playlist is None
+
+
 def test_lookup_when_not_loaded(provider):
     provider._loaded = False
 
@@ -218,7 +251,7 @@ def test_playlist_lookup_stores_track_link(
     )
 
     session_mock.get_link.assert_called_once_with("spotify:track:abc")
-    assert len(playlists._sp_links) == 1
+    assert {"spotify:track:abc": sp_track_mock.link} == playlists._sp_links
 
 
 @pytest.mark.parametrize(