Repository: coderedcorp/wagtail-cache

Issue:
Server error with cache middleware, Memcached and lots of URLs
Hi,

We hit intermittent 500 server errors on a site that uses the cache middleware and the memcached back-end.

- Django 4.2
- Wagtail 5.1.3
- wagtail-cache 2.3.0
- pymemcached 4.0.0

The error is `pymemcache.exceptions.MemcacheServerError: b'object too large for cache'`.

I think the error is caused by the UpdateCacheMiddleware using a single "keyring" dict to track all URLs, and setting / getting that in the cache backend. Memcached defaults to a maximum 1 megabyte size for a value. When the keyring grows too large, it hits the cache value size limit, and the memcached server returns an error.


```
ERROR    django.request:log.py:241 Internal Server Error: /views/template-response-view/
Traceback (most recent call last):
  File "/Users/david/wagtail-cache/.venv/lib/python3.11/site-packages/django/core/handlers/exception.py", line 55, in inner
    response = get_response(request)
               ^^^^^^^^^^^^^^^^^^^^^
  File "/Users/david/wagtail-cache/.venv/lib/python3.11/site-packages/django/utils/deprecation.py", line 136, in __call__
    response = self.process_response(request, response)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/david/wagtail-cache/wagtailcache/cache.py", line 313, in process_response
    self._wagcache.set("keyring", keyring)
  File "/Users/david/wagtail-cache/.venv/lib/python3.11/site-packages/django/core/cache/backends/memcached.py", line 79, in set
    if not self._cache.set(key, value, self.get_backend_timeout(timeout)):
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/david/wagtail-cache/.venv/lib/python3.11/site-packages/pymemcache/client/hash.py", line 344, in set
    return self._run_cmd("set", key, False, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/david/wagtail-cache/.venv/lib/python3.11/site-packages/pymemcache/client/hash.py", line 322, in _run_cmd
    return self._safely_run_func(client, func, default_val, *args, **kwargs)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/david/wagtail-cache/.venv/lib/python3.11/site-packages/pymemcache/client/hash.py", line 211, in _safely_run_func
    result = func(*args, **kwargs)
             ^^^^^^^^^^^^^^^^^^^^^
  File "/Users/david/wagtail-cache/.venv/lib/python3.11/site-packages/pymemcache/client/base.py", line 475, in set
    return self._store_cmd(b"set", {key: value}, expire, noreply, flags=flags)[key]
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/Users/david/wagtail-cache/.venv/lib/python3.11/site-packages/pymemcache/client/base.py", line 1247, in _store_cmd
    self._raise_errors(line, name)
  File "/Users/david/wagtail-cache/.venv/lib/python3.11/site-packages/pymemcache/client/base.py", line 1042, in _raise_errors
    raise MemcacheServerError(error)
pymemcache.exceptions.MemcacheServerError: b'object too large for cache'
``` 


Here's a test that passes when the error happens:

https://github.com/davidwtbuxton/wagtail-cache/commit/4466cad48de399a8302ebc235cb502891c3b8ad3 

You need to run a memcached server when running the test, which I did with `docker run --rm -it -p 11211:11211 memcached -v`. 

I'm not sure what would be a good fix. Certainly I reckon that the memcached server error shouldn't cause the website to give a 500 error.

Thanks,

David



Discussion:

Patch:
diff --git a/wagtailcache/cache.py b/wagtailcache/cache.py
index 0782730..0d92c75 100644
--- a/wagtailcache/cache.py
+++ b/wagtailcache/cache.py
@@ -2,6 +2,7 @@
 Functionality to set, serve from, and clear the cache.
 """
 
+import logging
 import re
 from enum import Enum
 from functools import wraps
@@ -28,6 +29,9 @@ from wagtail import hooks
 from wagtailcache.settings import wagtailcache_settings
 
 
+logger = logging.getLogger("wagtail-cache")
+
+
 class CacheControl(Enum):
     """
     ``Cache-Control`` header values.
@@ -42,6 +46,7 @@ class Status(Enum):
     WAGTAIL_CACHE_HEADER header values.
     """
 
+    ERROR = "err"
     HIT = "hit"
     MISS = "miss"
     SKIP = "skip"
@@ -186,6 +191,7 @@ class FetchFromCacheMiddleware(MiddlewareMixin):
     def process_request(self, request: WSGIRequest) -> Optional[HttpResponse]:
         if not wagtailcache_settings.WAGTAIL_CACHE:
             return None
+
         # Check if request is cacheable
         # Only cache GET and HEAD requests.
         # Don't cache requests that are previews.
@@ -197,6 +203,7 @@ class FetchFromCacheMiddleware(MiddlewareMixin):
             and not getattr(request, "is_preview", False)
             and not (hasattr(request, "user") and request.user.is_authenticated)
         )
+
         # Allow the user to override our caching decision.
         for fn in hooks.get_hooks("is_request_cacheable"):
             result = fn(request, is_cacheable)
@@ -207,17 +214,31 @@ class FetchFromCacheMiddleware(MiddlewareMixin):
             setattr(request, "_wagtailcache_update", False)
             setattr(request, "_wagtailcache_skip", True)
             return None  # Don't bother checking the cache.
-        # Try and get the cached response.
-        cache_key = _get_cache_key(request, self._wagcache)
-        if cache_key is None:
-            setattr(request, "_wagtailcache_update", True)
-            return None  # No cache information available, need to rebuild.
 
-        response = self._wagcache.get(cache_key)
+        # Try and get the cached response.
+        try:
+            cache_key = _get_cache_key(request, self._wagcache)
+
+            # No cache information available, need to rebuild.
+            if cache_key is None:
+                setattr(request, "_wagtailcache_update", True)
+                return None
+
+            # We have a key, get the cached response.
+            response = self._wagcache.get(cache_key)
+
+        except Exception:
+            # If the cache backend is currently unresponsive or errors out,
+            # return None and log the error.
+            setattr(request, "_wagtailcache_error", True)
+            logger.exception("Could not fetch page from cache backend.")
+            return None
 
+        # No cache information available, need to rebuild.
         if response is None:
             setattr(request, "_wagtailcache_update", True)
-            return None  # No cache information available, need to rebuild.
+            return None
+
         # Hit. Return cached response.
         setattr(request, "_wagtailcache_update", False)
         return response
@@ -248,6 +269,15 @@ class UpdateCacheMiddleware(MiddlewareMixin):
             _patch_header(response, Status.SKIP)
             return response
 
+        if (
+            hasattr(request, "_wagtailcache_error")
+            and request._wagtailcache_error
+        ):
+            # There was an error trying to fetch this response from the cache.
+            # Do not try to update, simply return.
+            _patch_header(response, Status.ERROR)
+            return response
+
         if (
             hasattr(request, "_wagtailcache_update")
             and not request._wagtailcache_update
@@ -258,6 +288,7 @@ class UpdateCacheMiddleware(MiddlewareMixin):
             _chop_response_vary(request, response)
             # We don't need to update the cache, just return.
             return response
+
         # Check if the response is cacheable
         # Don't cache private or no-cache responses.
         # Do cache 200, 301, 302, 304, and 404 codes so that wagtail doesn't
@@ -277,16 +308,19 @@ class UpdateCacheMiddleware(MiddlewareMixin):
                 and has_vary_header(response, "Cookie")
             )
         )
+
         # Allow the user to override our caching decision.
         for fn in hooks.get_hooks("is_response_cacheable"):
             result = fn(response, is_cacheable)
             if isinstance(result, bool):
                 is_cacheable = result
+
         # If we are not allowed to cache the response, just return.
         if not is_cacheable:
             # Add response header to indicate this was intentionally not cached.
             _patch_header(response, Status.SKIP)
             return response
+
         # Potentially remove the ``Vary: Cookie`` header.
         _chop_response_vary(request, response)
         # Try to get the timeout from the ``max-age`` section of the
@@ -297,33 +331,36 @@ class UpdateCacheMiddleware(MiddlewareMixin):
             timeout = self._wagcache.default_timeout
         patch_response_headers(response, timeout)
         if timeout:
-            cache_key = _learn_cache_key(
-                request, response, timeout, self._wagcache
-            )
-            # Track cache keys based on URI.
-            # (of the chopped request, not the real one).
-            cr = _chop_querystring(request)
-            uri = unquote(cr.build_absolute_uri())
-            keyring = self._wagcache.get("keyring", {})
-            # Get current cache keys belonging to this URI.
-            # This should be a list of keys.
-            uri_keys: List[str] = keyring.get(uri, [])
-            # Append the key to this list if not already present and save.
-            if cache_key not in uri_keys:
-                uri_keys.append(cache_key)
-                keyring[uri] = uri_keys
-            self._wagcache.set("keyring", keyring)
-
-            if isinstance(response, SimpleTemplateResponse):
-
-                def callback(r):
-                    self._wagcache.set(cache_key, r, timeout)
-
-                response.add_post_render_callback(callback)
-            else:
-                self._wagcache.set(cache_key, response, timeout)
-            # Add a response header to indicate this was a cache miss.
-            _patch_header(response, Status.MISS)
+            try:
+                cache_key = _learn_cache_key(
+                    request, response, timeout, self._wagcache
+                )
+                # Track cache keys based on URI.
+                # (of the chopped request, not the real one).
+                cr = _chop_querystring(request)
+                uri = unquote(cr.build_absolute_uri())
+                keyring = self._wagcache.get("keyring", {})
+                # Get current cache keys belonging to this URI.
+                # This should be a list of keys.
+                uri_keys: List[str] = keyring.get(uri, [])
+                # Append the key to this list if not already present and save.
+                if cache_key not in uri_keys:
+                    uri_keys.append(cache_key)
+                    keyring[uri] = uri_keys
+                    self._wagcache.set("keyring", keyring)
+                if isinstance(response, SimpleTemplateResponse):
+
+                    def callback(r):
+                        self._wagcache.set(cache_key, r, timeout)
+
+                    response.add_post_render_callback(callback)
+                else:
+                    self._wagcache.set(cache_key, response, timeout)
+                # Add a response header to indicate this was a cache miss.
+                _patch_header(response, Status.MISS)
+            except Exception:
+                _patch_header(response, Status.ERROR)
+                logger.exception("Could not update page in cache backend.")
 
         return response
 


Test patch:
diff --git a/testproject/backends.py b/testproject/backends.py
new file mode 100644
index 0000000..b20ede1
--- /dev/null
+++ b/testproject/backends.py
@@ -0,0 +1,35 @@
+from django.core.cache.backends.base import DEFAULT_TIMEOUT
+from django.core.cache.backends.locmem import LocMemCache
+
+
+class ErroneousGetCache(LocMemCache):
+    """
+    Cache backend which throws an error when fetching from cache.
+    """
+
+    def get(self, key, default=None, version=None):
+        raise Exception("Error in cache backend.")
+
+    def has_key(self, key, version=None):
+        raise Exception("Error in cache backend.")
+
+
+class ErroneousSetCache(LocMemCache):
+    """
+    Cache backend which throws an error when setting/modifying cache.
+    """
+
+    def add(self, key, value, timeout=DEFAULT_TIMEOUT, version=None):
+        raise Exception("Error in cache backend.")
+
+    def set(self, key, value, timeout=DEFAULT_TIMEOUT, version=None):
+        raise Exception("Error in cache backend.")
+
+    def touch(self, key, timeout=DEFAULT_TIMEOUT, version=None):
+        raise Exception("Error in cache backend.")
+
+    def delete(self, key, version=None):
+        raise Exception("Error in cache backend.")
+
+    def clear(self):
+        raise Exception("Error in cache backend.")
diff --git a/testproject/home/tests.py b/testproject/home/tests.py
index 4ca5ae7..da7e1da 100644
--- a/testproject/home/tests.py
+++ b/testproject/home/tests.py
@@ -136,6 +136,7 @@ class WagtailCacheTest(TestCase):
             pass
 
     # --- UTILITIES ------------------------------------------------------------
+
     def head_hit(self, url: str):
         """
         HEAD a page and test that it was served from the cache.
@@ -200,6 +201,28 @@ class WagtailCacheTest(TestCase):
         )
         return response
 
+    def get_error(self, url: str):
+        """
+        Gets a page and tests that an error in the cache backend was handled.
+        """
+        response = self.client.get(url)
+        self.assertEqual(response.status_code, 200)
+        self.assertEqual(
+            response.get(self.header_name, None), Status.ERROR.value
+        )
+        return response
+
+    def head_error(self, url: str):
+        """
+        HEAD a page and tests that an error in the cache backend was handled.
+        """
+        response = self.client.head(url)
+        self.assertEqual(response.status_code, 200)
+        self.assertEqual(
+            response.get(self.header_name, None), Status.ERROR.value
+        )
+        return response
+
     def post_skip(self, url: str):
         """
         POSTS a page and tests that it was intentionally not served from
@@ -216,6 +239,7 @@ class WagtailCacheTest(TestCase):
         return response
 
     # ---- TEST PAGES ----------------------------------------------------------
+
     def test_page_miss(self):
         for page in self.should_cache_pages:
             self.head_miss(page.get_url())
@@ -419,6 +443,7 @@ class WagtailCacheTest(TestCase):
         self.test_page_404()
 
     # ---- TEST VIEWS ----------------------------------------------------------
+
     # Views use the decorators and should work without the middleware.
     @modify_settings(
         MIDDLEWARE={
@@ -461,6 +486,7 @@ class WagtailCacheTest(TestCase):
         self.get_hit(reverse("template_response_view"))
 
     # ---- ADMIN VIEWS ---------------------------------------------------------
+
     def test_admin(self):
         self.client.force_login(self.user)
         response = self.client.get(reverse("wagtailcache:index"))
@@ -481,6 +507,7 @@ class WagtailCacheTest(TestCase):
         self.get_miss(self.page_cachedpage.get_url())
 
     # ---- PURGE SPECIFIC URLS & CLEAR ALL--------------------------------------
+
     def test_cache_keyring(self):
         # Check if keyring is not present
         self.assertEqual(self.cache.get("keyring"), None)
@@ -539,6 +566,7 @@ class WagtailCacheTest(TestCase):
         self.get_miss(u2)
 
     # ---- ALTERNATE SETTINGS --------------------------------------------------
+
     @override_settings(WAGTAIL_CACHE=True)
     def test_enable_wagtailcache(self):
         # Intentionally enable wagtail-cache, make sure it works.
@@ -562,7 +590,30 @@ class WagtailCacheTest(TestCase):
         # Load admin panel to render the zero timeout.
         self.test_admin()
 
+    @override_settings(WAGTAIL_CACHE_BACKEND="error_get")
+    def test_page_error_get(self):
+        # Wagtail-cache should handle errors when fetching from cache backend.
+        for page in self.should_cache_pages:
+            # First get should get an error.
+            self.head_error(page.get_url())
+            self.get_error(page.get_url())
+            # Second get should get an error too.
+            self.head_error(page.get_url())
+            self.get_error(page.get_url())
+
+    @override_settings(WAGTAIL_CACHE_BACKEND="error_set")
+    def test_page_error_set(self):
+        # Wagtail-cache should handle errors when updating to cache backend.
+        for page in self.should_cache_pages:
+            # First get should get an error.
+            self.head_error(page.get_url())
+            self.get_error(page.get_url())
+            # Second get should get an error too.
+            self.head_error(page.get_url())
+            self.get_error(page.get_url())
+
     # ---- HOOKS ---------------------------------------------------------------
+
     def test_request_hook_true(self):
         # A POST should never be cached.
         response = self.client.post(reverse("cached_view"))
diff --git a/testproject/testproject/settings.py b/testproject/testproject/settings.py
index 452c27a..d7ee484 100644
--- a/testproject/testproject/settings.py
+++ b/testproject/testproject/settings.py
@@ -116,9 +116,6 @@ MEDIA_ROOT = os.path.join(BASE_DIR, "media")
 MEDIA_URL = "/media/"
 # Wagtail settings
 WAGTAIL_SITE_NAME = "testproject"
-# Base URL to use when referring to full URLs within the Wagtail admin backend -
-# e.g. in notification emails. Don't include '/admin' or a trailing slash
-BASE_URL = "http://example.com"
 # SECURITY WARNING: don't run with debug turned on in production!
 DEBUG = True
 # SECURITY WARNING: keep the secret key used in production secret!
@@ -141,4 +138,12 @@ CACHES = {
         "BACKEND": "django.core.cache.backends.locmem.LocMemCache",
         "TIMEOUT": 0,
     },
+    "error_get": {
+        "BACKEND": "backends.ErroneousGetCache",
+        "TIMEOUT": 90061,  # 1 day, 1 hour, 1 minute, 1 second.
+    },
+    "error_set": {
+        "BACKEND": "backends.ErroneousSetCache",
+        "TIMEOUT": 90061,  # 1 day, 1 hour, 1 minute, 1 second.
+    },
 }