fix: preserve graced pages on origin 5xx refreshes

Makefile

@@ -31,7 +31,7 @@ test-restart-docs:
 		echo "OK: README documents container restart workflow"; \
 		echo "=== Test: Restart documentation PASSED ==="
 
-test-e2e-hard: test-e2e-harness-module test-e2e-scenario-config test-hostile-static-cookie test-hostile-static-cookie-canary test-hostile-account-cookie-isolation test-hostile-set-cookie-isolation test-hostile-query-suffix test-hostile-query-suffix-canary test-hostile-accept-encoding test-hostile-accept-encoding-canary test-hostile-deflate-encoding test-hostile-deflate-encoding-canary test-5xx-not-cached test-purge-unauthorized test-post-not-cached test-hostile-post-canary test-grace-stale test-hostile-vary-star test-hostile-vary-star-canary test-hostile-authorization test-hostile-authorization-canary test-hostile-zero-ttl test-hostile-zero-ttl-canary test-hostile-invalid-expires-canary test-hostile-nonstatic-invalid-expires-canary test-hostile-surrogate-esi test-hostile-surrogate-esi-canary test-hostile-revalidate test-hostile-revalidate-canary test-hostile-unsafe-location test-hostile-unsafe-location-canary test-compose-image-rebuild
+test-e2e-hard: test-grace-5xx test-e2e-harness-module test-e2e-scenario-config test-hostile-static-cookie test-hostile-static-cookie-canary test-hostile-account-cookie-isolation test-hostile-set-cookie-isolation test-hostile-query-suffix test-hostile-query-suffix-canary test-hostile-accept-encoding test-hostile-accept-encoding-canary test-hostile-deflate-encoding test-hostile-deflate-encoding-canary test-5xx-not-cached test-purge-unauthorized test-post-not-cached test-hostile-post-canary test-grace-stale test-hostile-vary-star test-hostile-vary-star-canary test-hostile-authorization test-hostile-authorization-canary test-hostile-zero-ttl test-hostile-zero-ttl-canary test-hostile-invalid-expires-canary test-hostile-nonstatic-invalid-expires-canary test-hostile-surrogate-esi test-hostile-surrogate-esi-canary test-hostile-revalidate test-hostile-revalidate-canary test-hostile-unsafe-location test-hostile-unsafe-location-canary test-compose-image-rebuild
 
 test-compose-image-rebuild:
 	@echo "=== Test: Compose image VCL rebuild and mounted cache policy ==="
@@ -457,6 +457,11 @@ test-e2e-harness-module:
 	@echo "=== Test: E2E harness module ==="
 	@./test/e2e/assert-e2e-harness-module.sh
 
+.PHONY: test-grace-5xx
+test-grace-5xx:
+	@echo "=== Test: Origin 5xx preserves graced pages ==="
+	@IMAGE="$(IMAGE)" python3 ./test/e2e/assert-grace-5xx.py
+
 test-5xx-not-cached:
 	@echo "=== Test: Backend 5xx responses not served from cache ==="
 	@./test/e2e/run-hostile-scenario.sh 5xx

README.md

@@ -95,7 +95,7 @@ The embedded default VCL includes generated backend configuration and the shared
 - **Accept-Encoding normalisation** — normalises to `gzip` or `deflate` for text; unsets for binary assets. A deflate response is its own cache object: Varnish transcodes gzip, not deflate, so that object is not served to a gzip or identity client.
 - **Cookie stripping** — removes cookies for static assets to improve cache hit rates.
 - **Cache TTLs** — 1 day TTL with 7 day grace for static assets; 1 hour grace for other content.
-- **500 error handling** — sets TTL to 0 and 24h grace for backend 5xx errors.
+- **5xx error handling** — abandons failed background refreshes so the good cached page remains available within its existing grace window. Without a usable stale page, origin errors reach the client but are not cached; errors do not extend grace.
 - **X-Cache header** — adds `HIT`/`MISS` for cache observability.
 
 The backend address differs between modes through the adapter: Docker Compose uses `web:80`; standalone defaults to `127.0.0.1:8080`. `render-vcl` generates backend VCL from `VARNISH_BACKEND_HOST`, `VARNISH_BACKEND_PORT`, and `VARNISH_BACKEND_PROBE_PATH`.

cache-policy.vcl

@@ -216,6 +216,21 @@ sub invalidate_reference {
 }
 
 sub vcl_backend_response {
+    if (beresp.status >= 500 && beresp.status < 600) {
+        # A failed background refresh must not replace the good graced object,
+        # even when the error carries Set-Cookie or no-store headers.
+        if (bereq.is_bgfetch) {
+            return (abandon);
+        }
+
+        # With no usable stale object, deliver the origin error but never
+        # store it. The TTL belongs only to the hit-for-miss marker.
+        set beresp.uncacheable = true;
+        set beresp.ttl = 120s;
+        set beresp.grace = 0s;
+        return (deliver);
+    }
+
     # Keep the normalized cache identity on the object so a successful
     # unsafe request can invalidate every variant for this exact host and URL.
     set beresp.http.X-Varnish-Cache-Host = bereq.http.host;
@@ -328,11 +343,6 @@ sub vcl_backend_response {
         }
     }
 
-    if (beresp.status >= 500 && beresp.status < 600) {
-        set beresp.ttl = 0s;
-        set beresp.grace = 24h;
-    }
-
     # RFC 9111 §5.2.2.2, §5.2.2.8, §5.2.2.10: Stale responses must not be served
     # without origin revalidation when prohibited by must-revalidate or
     # proxy-revalidate (or s-maxage, which implies proxy-revalidate). A positive

test/e2e/assert-grace-5xx.py

@@ -0,0 +1,117 @@
+#!/usr/bin/env python3
+"""Real HTTP regression: failed refreshes must not evict a graced page."""
+import json
+import os
+from pathlib import Path
+import subprocess
+import time
+import urllib.error
+import urllib.parse
+import urllib.request
+import uuid
+
+ROOT = Path(__file__).resolve().parents[2]
+
+
+def docker(*args):
+    return subprocess.check_output(["docker", *map(str, args)], text=True).strip()
+
+
+def request(base, path):
+    try:
+        response = urllib.request.urlopen(base + path, timeout=5)
+    except urllib.error.HTTPError as error:
+        response = error
+    with response:
+        return response.status, response.headers, response.read()
+
+
+def main():
+    prefix = "grace-5xx-" + uuid.uuid4().hex[:10]
+    origin, cache = prefix + "-origin", prefix + "-cache"
+    image = os.environ.get("IMAGE", "jonbaldie/varnish:latest")
+    docker("network", "create", prefix)
+    try:
+        docker("run", "-d", "--name", origin, "--network", prefix,
+               "-p", "127.0.0.1::8080", "-v",
+               f"{ROOT}/test/e2e/fixtures/scriptable-origin.py:/origin.py:ro",
+               "python:3.13-alpine", "python", "-u", "/origin.py")
+        docker("run", "-d", "--name", cache, "--network", prefix,
+               "-p", "127.0.0.1::80", "-e", f"VARNISH_BACKEND_HOST={origin}",
+               "-e", "VARNISH_BACKEND_PORT=8080", "-e", "VARNISH_BACKEND_PROBE_PATH=/probe",
+               "-v", f"{ROOT}/cache-policy.vcl:/etc/varnish/cache-policy.vcl:ro", image)
+        def base(name, port):
+            binding = json.loads(docker("inspect", name))[0]["NetworkSettings"]["Ports"][port][0]
+            return "http://127.0.0.1:" + binding["HostPort"]
+        backend, frontend = base(origin, "8080/tcp"), base(cache, "80/tcp")
+        for _ in range(60):
+            try:
+                if request(frontend, "/ready")[0] == 200:
+                    break
+            except (OSError, urllib.error.URLError):
+                pass
+            time.sleep(0.25)
+        else:
+            raise AssertionError("Varnish never became ready")
+
+        def configure(path, status, ttl=1, **headers):
+            query = urllib.parse.urlencode({"path": path, "status": status,
+                                           "h_Cache-Control": f"max-age={ttl}", **headers})
+            assert request(backend, "/__set?" + query)[0] == 200
+
+        for status in (500, 502, 503):
+            path = f"/news-{status}"
+            configure(path, 200)
+            code, headers, body = request(frontend, path)
+            assert code == 200
+            origin_id = headers["X-Origin-N"]
+            assert request(frontend, path)[1]["X-Cache"] == "HIT"
+            # Error-only storage headers must not bypass stale preservation.
+            error_headers = ({"h_Cache-Control": "no-store"} if status == 502 else
+                             {"h_Set-Cookie": "outage=1"} if status == 503 else {})
+            configure(path, status, **error_headers)
+            time.sleep(2)
+            for attempt in range(5):
+                code, headers, actual_body = request(frontend, path)
+                print(f"origin={status} attempt={attempt} response={code} "
+                      f"cache={headers['X-Cache']} age={headers['Age']}", flush=True)
+                assert code == 200, f"{status} refresh replaced graced 200 with {code}"
+                assert headers["X-Cache"] == "HIT"
+                assert headers["X-Origin-N"] == origin_id and actual_body == body
+                assert int(headers["Age"]) >= 2
+                time.sleep(0.25)
+            # Recovery must replace the old page, not freeze it indefinitely.
+            configure(path, 200, ttl=60)
+            for _ in range(40):
+                code, headers, _ = request(frontend, path)
+                if code == 200 and headers["X-Origin-N"] != origin_id:
+                    break
+                time.sleep(0.1)
+            else:
+                raise AssertionError("recovered origin never refreshed the cached page")
+            cold = f"/cold-{status}"
+            configure(cold, status)
+            first = request(frontend, cold)
+            second = request(frontend, cold)
+            assert first[0] == second[0] == status, "cold error must reach client"
+            assert first[1]["X-Origin-N"] != second[1]["X-Origin-N"], "5xx was cached"
+        # A page that prohibits stale serving must still expose an origin 5xx.
+        path = "/must-revalidate"
+        configure(path, 200, **{"h_Cache-Control": "max-age=1, must-revalidate"})
+        assert request(frontend, path)[0] == 200
+        configure(path, 503)
+        time.sleep(2)
+        assert request(frontend, path)[0] == 503, "served stale despite must-revalidate"
+        print("OK: 500/502/503 preserve grace, recover, and are not cached on cold misses")
+    except Exception:
+        for name in (origin, cache):
+            subprocess.run(["docker", "logs", name], check=False)
+        raise
+    finally:
+        for name in (cache, origin):
+            subprocess.run(["docker", "rm", "-fv", name], check=False, stdout=subprocess.DEVNULL)
+        docker("network", "rm", prefix)
+
+
+if __name__ == "__main__":
+    main()

test/e2e/fixtures/scriptable-origin.py

@@ -0,0 +1,53 @@
+"""Scriptable origin. Query params h_<Name>=v set response headers, status=N
+sets status. POST /__set?path=/p&status=N&h_X=v overrides later responses for
+path /p (any query) until /__clear. Each response carries X-Origin-N."""
+import http.server, itertools, json, threading, urllib.parse
+
+ctr = itertools.count(1)
+overrides = {}
+lock = threading.Lock()
+
+class H(http.server.BaseHTTPRequestHandler):
+    protocol_version = "HTTP/1.1"
+
+    def any(self):
+        u = urllib.parse.urlsplit(self.path)
+        q = urllib.parse.parse_qs(u.query, keep_blank_values=True)
+        ln = int(self.headers.get("Content-Length") or 0)
+        if ln:
+            self.rfile.read(ln)
+        if u.path == "/__set":
+            with lock:
+                overrides[q["path"][0]] = q
+            return self.reply(200, {}, b"set\n")
+        if u.path == "/__clear":
+            with lock:
+                overrides.clear()
+            return self.reply(200, {}, b"clear\n")
+        with lock:
+            o = overrides.get(u.path)
+        if o:
+            q = {**q, **o}
+        n = next(ctr)
+        status = int(q.get("status", [200])[0])
+        hdrs = {k[2:].replace("_", "-"): v[0] for k, v in q.items() if k.startswith("h_")}
+        body = json.dumps({"n": n, "method": self.command, "path": self.path,
+                           "status": status,
+                           "headers": dict(self.headers)}).encode() + b"\n"
+        self.reply(status, hdrs, body, n)
+
+    def reply(self, status, hdrs, body, n=0):
+        self.send_response(status)
+        for k, v in hdrs.items():
+            self.send_header(k, v)
+        self.send_header("X-Origin-N", str(n))
+        self.send_header("Content-Type", "text/html")
+        self.send_header("Content-Length", str(len(body)))
+        self.end_headers()
+        if self.command != "HEAD":
+            self.wfile.write(body)
+
+    do_GET = do_POST = do_PUT = do_DELETE = do_HEAD = do_PURGE = any
+    def log_message(self, *a): pass
+
+http.server.ThreadingHTTPServer(("0.0.0.0", 8080), H).serve_forever()