test(16.2-07): full coverage of the site cache purge

- TestSiteCachePurgeConfig: every refused configuration names its key and
  never the token; https anywhere and http to loopback are accepted
- TestSiteCachePurgeRequest: the contract request, Info and Warn lines,
  the 2 s timeout, a cancelled parent context, no token in any log line
- Postgres: category create, update and delete and post create, untouched
  update (D-03 bytes kept), failing and unreachable purges and delete each
  purge once after the commit; failed saves send none
This commit is contained in:
2026-10-10 18:35:36 +02:00
parent 09e56437fd
commit 4405feeaa7
2 changed files with 464 additions and 42 deletions

293
classes/site_cache_test.go Normal file
View File

@@ -0,0 +1,293 @@
package classes
import (
"bytes"
"context"
"encoding/json"
"io"
"log/slog"
"net/http"
"net/http/httptest"
"strconv"
"strings"
"sync"
"testing"
"time"
)
const (
purgeToken32 = "0123456789abcdef0123456789abcdef"
purgeToken40 = "site-cache-unit-token-0123456789abcdefgh"
)
// captureLogs routes slog.Default to a text handler on a buffer for the
// test and returns the buffer.
func captureLogs(t *testing.T) *syncBuffer {
t.Helper()
buf := &syncBuffer{}
prev := slog.Default()
slog.SetDefault(slog.New(slog.NewTextHandler(buf, &slog.HandlerOptions{Level: slog.LevelDebug})))
t.Cleanup(func() { slog.SetDefault(prev) })
return buf
}
type syncBuffer struct {
mu sync.Mutex
buf bytes.Buffer
}
func (b *syncBuffer) Write(p []byte) (int, error) {
b.mu.Lock()
defer b.mu.Unlock()
return b.buf.Write(p)
}
func (b *syncBuffer) lines() []string {
b.mu.Lock()
defer b.mu.Unlock()
var out []string
for _, line := range strings.Split(strings.TrimSpace(b.buf.String()), "\n") {
if line != "" {
out = append(out, line)
}
}
return out
}
func TestSiteCachePurgeConfig(t *testing.T) {
refused := []struct {
name, url, token, key string
}{
{"only the URL", "http://127.0.0.1:3016/api/__journal__/cache/purge", "", SiteCachePurgeTokenKey},
{"only the token", "", purgeToken40, SiteCachePurgeURLKey},
{"a bad scheme", "ftp://127.0.0.1/purge", purgeToken40, SiteCachePurgeURLKey},
{"no scheme", "127.0.0.1:3016/purge", purgeToken40, SiteCachePurgeURLKey},
{"no host", "http:///purge", purgeToken40, SiteCachePurgeURLKey},
{"user info", "http://user:secret@127.0.0.1/purge", purgeToken40, SiteCachePurgeURLKey},
{"a fragment", "http://127.0.0.1/purge#top", purgeToken40, SiteCachePurgeURLKey},
{"an empty fragment", "http://127.0.0.1/purge#", purgeToken40, SiteCachePurgeURLKey},
{"http to a non-loopback host", "http://example.test/purge", purgeToken40, SiteCachePurgeURLKey},
{"http to a private address", "http://10.0.0.5:3016/purge", purgeToken40, SiteCachePurgeURLKey},
{"a 31-character token", "http://127.0.0.1/purge", purgeToken32[:31], SiteCachePurgeTokenKey},
}
for _, tc := range refused {
t.Run("refuses "+tc.name, func(t *testing.T) {
p, err := NewSiteCachePurger(tc.url, tc.token)
if err == nil || p != nil {
t.Fatalf("NewSiteCachePurger(%q) = %v, %v; want an error", tc.url, p, err)
}
if !strings.Contains(err.Error(), tc.key) {
t.Fatalf("error %q does not name %s", err, tc.key)
}
if tc.token != "" && strings.Contains(err.Error(), tc.token) {
t.Fatalf("error %q carries the token", err)
}
})
}
t.Run("both empty disables the purge", func(t *testing.T) {
p, err := NewSiteCachePurger("", "")
if p != nil || err != nil {
t.Fatalf("NewSiteCachePurger(\"\", \"\") = %v, %v; want nil, nil", p, err)
}
})
accepted := []struct {
url, endpoint string
}{
{"https://cache.example.test/api/__journal__/cache/purge", "cache.example.test/api/__journal__/cache/purge"},
{"http://127.0.0.1:3016/api/__journal__/cache/purge", "127.0.0.1:3016/api/__journal__/cache/purge"},
{"http://127.9.8.7/purge", "127.9.8.7/purge"},
{"http://[::1]:3000/purge", "[::1]:3000/purge"},
{"http://localhost:3000/purge?x=1", "localhost:3000/purge"},
}
for _, tc := range accepted {
t.Run("accepts "+tc.url, func(t *testing.T) {
p, err := NewSiteCachePurger(tc.url, purgeToken32)
if err != nil || p == nil {
t.Fatalf("NewSiteCachePurger(%q) = %v, %v; want a purger", tc.url, p, err)
}
if p.Endpoint() != tc.endpoint {
t.Fatalf("Endpoint() = %q, want %q", p.Endpoint(), tc.endpoint)
}
})
}
var nilPurger *SiteCachePurger
if nilPurger.Endpoint() != "" {
t.Fatal("a nil purger has an endpoint")
}
}
// purgeHit is one request the test receiver got.
type purgeHit struct {
method, path, auth, contentType string
body map[string]string
}
func purgeReceiver(t *testing.T, handle func(w http.ResponseWriter, r *http.Request)) (*httptest.Server, func() []purgeHit) {
t.Helper()
var mu sync.Mutex
var hits []purgeHit
srv := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
raw, _ := io.ReadAll(r.Body)
var body map[string]string
_ = json.Unmarshal(raw, &body)
mu.Lock()
hits = append(hits, purgeHit{r.Method, r.URL.Path, r.Header.Get("Authorization"), r.Header.Get("Content-Type"), body})
mu.Unlock()
handle(w, r)
}))
t.Cleanup(srv.Close)
return srv, func() []purgeHit {
mu.Lock()
defer mu.Unlock()
return append([]purgeHit(nil), hits...)
}
}
func newTestPurger(t *testing.T, srv *httptest.Server) *SiteCachePurger {
t.Helper()
p, err := NewSiteCachePurger(srv.URL+"/api/__journal__/cache/purge", purgeToken40)
if err != nil {
t.Fatal(err)
}
return p
}
func assertNoToken(t *testing.T, logs *syncBuffer) {
t.Helper()
for _, line := range logs.lines() {
if strings.Contains(line, purgeToken40) || strings.Contains(line, "Bearer") || strings.Contains(line, "Authorization") {
t.Fatalf("log line carries the token or the Authorization header: %s", line)
}
}
}
func TestSiteCachePurgeRequest(t *testing.T) {
t.Run("sends the contract request and logs the purged count", func(t *testing.T) {
logs := captureLogs(t)
srv, hits := purgeReceiver(t, func(w http.ResponseWriter, _ *http.Request) {
w.Header().Set("Content-Type", "application/json")
_, _ = w.Write([]byte(`{"purged":7}`))
})
newTestPurger(t, srv).Purge(context.Background(), "category", "cordyceps")
got := hits()
if len(got) != 1 {
t.Fatalf("%d requests, want 1", len(got))
}
h := got[0]
if h.method != http.MethodPost || h.path != "/api/__journal__/cache/purge" {
t.Fatalf("request %s %s", h.method, h.path)
}
if h.auth != "Bearer "+purgeToken40 || !strings.HasPrefix(h.contentType, "application/json") {
t.Fatalf("Authorization %q, Content-Type %q", h.auth, h.contentType)
}
if len(h.body) != 2 || h.body["kind"] != "category" || h.body["slug"] != "cordyceps" {
t.Fatalf("body = %#v", h.body)
}
lines := logs.lines()
if len(lines) != 1 || !strings.Contains(lines[0], "level=INFO") || !strings.Contains(lines[0], `msg="journal: site cache purged"`) ||
!strings.Contains(lines[0], "kind=category") || !strings.Contains(lines[0], "slug=cordyceps") ||
!strings.Contains(lines[0], "status=200") || !strings.Contains(lines[0], "purged=7") {
t.Fatalf("log = %q", lines)
}
assertNoToken(t, logs)
})
t.Run("an answer without purged logs the status only", func(t *testing.T) {
logs := captureLogs(t)
srv, _ := purgeReceiver(t, func(w http.ResponseWriter, _ *http.Request) { w.WriteHeader(http.StatusNoContent) })
newTestPurger(t, srv).Purge(context.Background(), "post", "hello")
lines := logs.lines()
if len(lines) != 1 || !strings.Contains(lines[0], "level=INFO") || !strings.Contains(lines[0], "status=204") || strings.Contains(lines[0], "purged=") {
t.Fatalf("log = %q", lines)
}
})
for _, status := range []int{http.StatusInternalServerError, http.StatusUnauthorized} {
t.Run("a "+http.StatusText(status)+" answer logs one warning", func(t *testing.T) {
logs := captureLogs(t)
srv, hits := purgeReceiver(t, func(w http.ResponseWriter, _ *http.Request) { w.WriteHeader(status) })
newTestPurger(t, srv).Purge(context.Background(), "post", "hello")
if len(hits()) != 1 {
t.Fatalf("%d requests, want 1", len(hits()))
}
lines := logs.lines()
if len(lines) != 1 || !strings.Contains(lines[0], "level=WARN") || !strings.Contains(lines[0], `msg="journal: site cache purge failed"`) ||
!strings.Contains(lines[0], "kind=post") || !strings.Contains(lines[0], "slug=hello") {
t.Fatalf("log = %q", lines)
}
if !strings.Contains(lines[0], "status="+strconv.Itoa(status)) {
t.Fatalf("log %q lacks status=%d", lines[0], status)
}
assertNoToken(t, logs)
})
}
t.Run("a slow receiver is abandoned after the timeout", func(t *testing.T) {
logs := captureLogs(t)
release := make(chan struct{})
srv, _ := purgeReceiver(t, func(_ http.ResponseWriter, r *http.Request) {
select {
case <-release:
case <-r.Context().Done():
}
})
defer close(release)
start := time.Now()
newTestPurger(t, srv).Purge(context.Background(), "post", "slow")
elapsed := time.Since(start)
if elapsed < SiteCachePurgeTimeout-200*time.Millisecond || elapsed > SiteCachePurgeTimeout+1500*time.Millisecond {
t.Fatalf("Purge returned after %s, want about %s", elapsed, SiteCachePurgeTimeout)
}
lines := logs.lines()
if len(lines) != 1 || !strings.Contains(lines[0], "level=WARN") || !strings.Contains(lines[0], "error=timeout") {
t.Fatalf("log = %q", lines)
}
assertNoToken(t, logs)
})
t.Run("an unreachable receiver logs one warning without the URL's token", func(t *testing.T) {
logs := captureLogs(t)
srv, _ := purgeReceiver(t, func(http.ResponseWriter, *http.Request) {})
p := newTestPurger(t, srv)
srv.Close()
p.Purge(context.Background(), "category", "gone")
lines := logs.lines()
if len(lines) != 1 || !strings.Contains(lines[0], "level=WARN") || !strings.Contains(lines[0], "kind=category") {
t.Fatalf("log = %q", lines)
}
assertNoToken(t, logs)
})
t.Run("a cancelled parent context still sends", func(t *testing.T) {
captureLogs(t)
srv, hits := purgeReceiver(t, func(w http.ResponseWriter, _ *http.Request) { _, _ = w.Write([]byte(`{"purged":1}`)) })
ctx, cancel := context.WithCancel(context.Background())
cancel()
newTestPurger(t, srv).Purge(ctx, "post", "after-cancel")
if got := hits(); len(got) != 1 || got[0].body["slug"] != "after-cancel" {
t.Fatalf("requests = %#v, want one", got)
}
})
t.Run("a nil purger sends nothing", func(t *testing.T) {
logs := captureLogs(t)
var p *SiteCachePurger
p.Purge(context.Background(), "post", "nil")
PurgeSiteCacheAfterCommit(context.Background(), nil, nil, "post", "nil")
if lines := logs.lines(); len(lines) != 0 {
t.Fatalf("log = %q, want nothing", lines)
}
})
t.Run("outside a transaction the after-commit purge runs at once", func(t *testing.T) {
captureLogs(t)
srv, hits := purgeReceiver(t, func(w http.ResponseWriter, _ *http.Request) { _, _ = w.Write([]byte(`{"purged":2}`)) })
PurgeSiteCacheAfterCommit(context.Background(), nil, newTestPurger(t, srv), "category", "now")
if got := hits(); len(got) != 1 || got[0].body["kind"] != "category" || got[0].body["slug"] != "now" {
t.Fatalf("requests = %#v, want one", got)
}
})
}

View File

@@ -91,6 +91,12 @@ func (r *purgeReceiver) take() []purgeRequest {
return got
}
func (r *purgeReceiver) setStatus(status int) {
r.mu.Lock()
r.status = status
r.mu.Unlock()
}
func (r *purgeReceiver) setProbe(probe func() string) {
r.mu.Lock()
r.probe = probe
@@ -121,14 +127,30 @@ func (r *purgeReceiver) expectOnePurge(t *testing.T, stage, kind, slug string) p
return req
}
// TestCategoriesAdminPurgesSiteCache proves an admin update of a category
// sends one authorized purge request to the host site after the save
// transaction commits (G-16.2-2, D-19).
// TestCategoriesAdminPurgesSiteCache proves every admin write of a category
// sends one authorized purge request with kind category after the save
// transaction commits, and a failed save sends none (G-16.2-2, D-19).
func TestCategoriesAdminPurgesSiteCache(t *testing.T) {
recv := newPurgeReceiver(t)
env := newPostsEnv(t, recv.env()...)
token := env.admin(t, controllers.PermissionAccessCategories)
// The probe reads the committed row through the pool while the purge
// request is in flight: "<content>" or "missing".
recv.setProbe(func() string {
var cat models.Category
if err := env.gdb.Where("slug = ?", "purge-news").Limit(1).Find(&cat).Error; err != nil {
return "error: " + err.Error()
}
if cat.ID == 0 {
return "missing"
}
if cat.Content == nil {
return ""
}
return *cat.Content
})
rec := env.expect(t, http.StatusCreated, http.MethodPost, adminAPI(adminCategoriesPath), token, map[string]any{
"name": map[string]any{"en": "Purge news", "pl": "Wiadomości"},
"slug": map[string]any{"en": "purge-news", "pl": "wiadomosci"},
@@ -136,43 +158,71 @@ func TestCategoriesAdminPurgesSiteCache(t *testing.T) {
})
id := adminCreatedID(t, rec)
itemPath := adminAPI(fmt.Sprintf("%s/%d", adminCategoriesPath, id))
recv.take()
if req := recv.expectOnePurge(t, "create", "category", "purge-news"); req.Seen != "<p>Before</p>\n" {
t.Fatalf("create: the purge saw %q, want the committed row", req.Seen)
}
content := func() string {
var cat models.Category
if err := env.gdb.First(&cat, id).Error; err != nil {
return "error: " + err.Error()
served := func(t *testing.T) map[string]json.RawMessage {
t.Helper()
rec := env.expect(t, http.StatusOK, http.MethodGet, itemPath, token, nil)
var data map[string]json.RawMessage
if err := json.Unmarshal(adminDecode(t, rec).Data, &data); err != nil {
t.Fatal(err)
}
if cat.Content == nil {
return ""
return data
}
t.Run("update", func(t *testing.T) {
const edited = "<p>After the edit</p>\n"
body := servedBody(served(t), "name", "slug")
body["content"] = edited
env.expect(t, http.StatusOK, http.MethodPut, itemPath, token, body)
if req := recv.expectOnePurge(t, "update", "category", "purge-news"); req.Seen != edited {
t.Fatalf("the purge saw content %q, want the committed %q (purge before commit)", req.Seen, edited)
}
return *cat.Content
}
recv.setProbe(content)
})
rec = env.expect(t, http.StatusOK, http.MethodGet, itemPath, token, nil)
var served map[string]json.RawMessage
if err := json.Unmarshal(adminDecode(t, rec).Data, &served); err != nil {
t.Fatal(err)
}
const edited = "<p>After the edit</p>\n"
body := servedBody(served, "name", "slug")
body["content"] = edited
env.expect(t, http.StatusOK, http.MethodPut, itemPath, token, body)
t.Run("a failed update sends none", func(t *testing.T) {
body := servedBody(served(t), "slug")
body["name"] = map[string]any{"en": "", "pl": ""}
body["content"] = "<p>Refused</p>\n"
if rec := env.call(t, http.MethodPut, itemPath, token, body); rec.Code != http.StatusUnprocessableEntity {
t.Fatalf("update without a name = %d, want 422: %s", rec.Code, rec.Body.String())
}
if got := recv.take(); len(got) != 0 {
t.Fatalf("a failed update sent %d purge requests: %+v", len(got), got)
}
})
req := recv.expectOnePurge(t, "update", "category", "purge-news")
if req.Seen != edited {
t.Fatalf("the purge saw content %q, want the committed %q (purge before commit)", req.Seen, edited)
}
t.Run("delete", func(t *testing.T) {
env.expect(t, http.StatusOK, http.MethodDelete, itemPath, token, nil)
if req := recv.expectOnePurge(t, "delete", "category", "purge-news"); req.Seen != "missing" {
t.Fatalf("the purge saw %q, want the row already deleted", req.Seen)
}
})
}
// TestPostsAdminPurgesSiteCache proves an admin update of a post sends one
// authorized purge request with kind post after the save commits.
// TestPostsAdminPurgesSiteCache proves every admin write of a post sends one
// authorized purge request with kind post after the commit, that an
// untouched save still purges and keeps both content columns byte for byte
// (D-03), that a refused, failing or unreachable purge never changes the
// save response, and that a failed save sends none.
func TestPostsAdminPurgesSiteCache(t *testing.T) {
recv := newPurgeReceiver(t)
env := newPostsEnv(t, recv.env()...)
token := env.admin(t, controllers.PermissionAccessPosts)
recv.setProbe(func() string {
var post models.Post
if err := env.gdb.Where("slug = ?", "purge-post").Limit(1).Find(&post).Error; err != nil {
return "error: " + err.Error()
}
if post.ID == 0 {
return "missing"
}
return post.ContentHTML
})
rec := env.expect(t, http.StatusCreated, http.MethodPost, adminAPI(adminPostsPath), token, map[string]any{
"title": map[string]any{"en": "Purge post", "pl": "Wpis"},
"slug": map[string]any{"en": "purge-post", "pl": "wpis"},
@@ -180,23 +230,102 @@ func TestPostsAdminPurgesSiteCache(t *testing.T) {
"excerpt": map[string]any{"en": "Excerpt", "pl": "Wyjątek"},
})
id := adminCreatedID(t, rec)
recv.take()
itemPath := adminAPI(fmt.Sprintf("%s/%d", adminPostsPath, id))
if req := recv.expectOnePurge(t, "create", "post", "purge-post"); req.Seen != "<p>Before</p>" {
t.Fatalf("create: the purge saw %q, want the committed row", req.Seen)
}
recv.setProbe(func() string {
put := func(t *testing.T, content string) *httptest.ResponseRecorder {
t.Helper()
body := servedBody(servedForm(t, env, token, id), "title", "slug", "excerpt")
body["content"] = map[string]any{"en": content}
return env.call(t, http.MethodPut, itemPath, token, body)
}
stored := func(t *testing.T) models.Post {
t.Helper()
var post models.Post
if err := env.gdb.First(&post, id).Error; err != nil {
return "error: " + err.Error()
t.Fatal(err)
}
return post.ContentHTML
})
served := servedForm(t, env, token, id)
const edited = "<p>After the edit</p>"
body := servedBody(served, "title", "slug", "excerpt")
body["content"] = map[string]any{"en": edited}
env.expect(t, http.StatusOK, http.MethodPut, adminAPI(fmt.Sprintf("%s/%d", adminPostsPath, id)), token, body)
req := recv.expectOnePurge(t, "update", "post", "purge-post")
if req.Seen != edited {
t.Fatalf("the purge saw content_html %q, want the committed %q (purge before commit)", req.Seen, edited)
return post
}
t.Run("update", func(t *testing.T) {
const edited = "<p>After the edit</p>"
if rec := put(t, edited); rec.Code != http.StatusOK {
t.Fatalf("update = %d: %s", rec.Code, rec.Body.String())
}
if req := recv.expectOnePurge(t, "update", "post", "purge-post"); req.Seen != edited {
t.Fatalf("the purge saw content_html %q, want the committed %q (purge before commit)", req.Seen, edited)
}
})
t.Run("an untouched update purges and keeps both columns", func(t *testing.T) {
const imported = "\n<!-- imported -->\n<p onclick=\"x()\">Kept as stored</p>\n"
const importedHTML = "<p>Rendered elsewhere</p>\n"
if err := env.gdb.Model(&models.Post{}).Where("id = ?", id).Updates(map[string]any{"content": imported, "content_html": importedHTML}).Error; err != nil {
t.Fatal(err)
}
served := servedForm(t, env, token, id)
env.expect(t, http.StatusOK, http.MethodPut, itemPath, token, servedBody(served, "title", "slug", "excerpt", "content"))
recv.expectOnePurge(t, "untouched update", "post", "purge-post")
assertHostContent(t, env, id, "untouched update", imported, importedHTML)
})
t.Run("a failed save sends none", func(t *testing.T) {
// The admin lacks access_publish: FormBeforeUpdate refuses inside
// the save transaction.
body := servedBody(servedForm(t, env, token, id), "title", "slug", "excerpt")
body["published"] = true
if rec := env.call(t, http.MethodPut, itemPath, token, body); rec.Code != http.StatusForbidden {
t.Fatalf("publish without access_publish = %d, want 403: %s", rec.Code, rec.Body.String())
}
if got := recv.take(); len(got) != 0 {
t.Fatalf("a failed save sent %d purge requests: %+v", len(got), got)
}
})
t.Run("a failing purge never changes the save", func(t *testing.T) {
recv.setStatus(http.StatusInternalServerError)
defer recv.setStatus(http.StatusOK)
const edited = "<p>Saved while the site answers 500</p>"
if rec := put(t, edited); rec.Code != http.StatusOK {
t.Fatalf("update with a failing purge = %d: %s", rec.Code, rec.Body.String())
}
recv.expectOnePurge(t, "failing purge", "post", "purge-post")
if got := stored(t); got.Content != edited || got.ContentHTML != edited {
t.Fatalf("stored = %q / %q, want %q", got.Content, got.ContentHTML, edited)
}
})
t.Run("delete", func(t *testing.T) {
spare := env.expect(t, http.StatusCreated, http.MethodPost, adminAPI(adminPostsPath), token, map[string]any{
"title": map[string]any{"en": "Spare"},
"slug": map[string]any{"en": "spare-post"},
"content": map[string]any{"en": "<p>Spare</p>"},
})
spareID := adminCreatedID(t, spare)
recv.expectOnePurge(t, "spare create", "post", "spare-post")
env.expect(t, http.StatusOK, http.MethodDelete, adminAPI(fmt.Sprintf("%s/%d", adminPostsPath, spareID)), token, nil)
recv.expectOnePurge(t, "delete", "post", "spare-post")
var n int64
if err := env.gdb.Model(&models.Post{}).Where("id = ?", spareID).Count(&n).Error; err != nil || n != 0 {
t.Fatalf("spare post rows = %d (%v), want 0", n, err)
}
})
// Last: closing the receiver ends its use for this env.
t.Run("an unreachable site never changes the save", func(t *testing.T) {
recv.srv.Close()
const edited = "<p>Saved while nothing listens</p>"
if rec := put(t, edited); rec.Code != http.StatusOK {
t.Fatalf("update with no receiver = %d: %s", rec.Code, rec.Body.String())
}
if got := stored(t); got.Content != edited || got.ContentHTML != edited {
t.Fatalf("stored = %q / %q, want %q", got.Content, got.ContentHTML, edited)
}
if got := recv.take(); len(got) != 0 {
t.Fatalf("a closed receiver recorded %d requests", len(got))
}
})
}