Name the cause on the page for a refused form (closes #358)

The CSRF middleware answered a refused login or generator form with the
library's bare text, such as "Forbidden - origin invalid". It now answers
403 with a page that names the cause and what to do, and logs a warning
with the request ID and the library's reason. A page opened over plain
HTTP with debug off and a form from another host both fail the origin
check; the page tells them apart by the host in the Origin or Referer
header.

Model: opus-5-5

internal/handlers/csrf_refused_internal_test.go

@@ -0,0 +1,205 @@
+package handlers
+
+import (
+	"bytes"
+	"context"
+	"encoding/json"
+	"html/template"
+	"log/slog"
+	"net/http"
+	"net/http/httptest"
+	"net/url"
+	"strings"
+	"testing"
+
+	"github.com/go-chi/chi/v5/middleware"
+	"github.com/gorilla/csrf"
+
+	"sneak.berlin/go/pixa/internal/seal"
+)
+
+// refusedFormRequestID is the request ID of the requests postRefusedForm
+// sends, which the warning for a refused form must carry.
+const refusedFormRequestID = "test-request-id"
+
+// TestFormRefusedNamesCause verifies that a form the CSRF middleware refuses
+// answers 403 with a page naming the cause, and logs a warning with the
+// request ID and the middleware's reason.
+func TestFormRefusedNamesCause(t *testing.T) {
+	t.Parallel()
+
+	tests := []struct {
+		name       string
+		debug      bool
+		origin     string
+		referer    string
+		wantCause  string
+		wantReason error
+	}{
+		{
+			name:       "plain HTTP origin with debug off",
+			origin:     "http://example.com",
+			wantCause:  causePlainHTTP,
+			wantReason: csrf.ErrBadOrigin,
+		},
+		{
+			name:       "plain HTTP referer with debug off",
+			referer:    "http://example.com/",
+			wantCause:  causePlainHTTP,
+			wantReason: csrf.ErrBadReferer,
+		},
+		{
+			name:       "origin on another host",
+			origin:     "https://proxy.example.net",
+			wantCause:  causeOtherHost,
+			wantReason: csrf.ErrBadOrigin,
+		},
+		{
+			name:       "referer on another host",
+			referer:    "https://proxy.example.net/",
+			wantCause:  causeOtherHost,
+			wantReason: csrf.ErrBadReferer,
+		},
+		{
+			name:       "HTTPS origin with debug on",
+			debug:      true,
+			origin:     "https://example.com",
+			wantCause:  causeHTTPSWithDebug,
+			wantReason: csrf.ErrBadOrigin,
+		},
+		{
+			name:       "no origin or referer with debug off",
+			wantCause:  causeNoReferer,
+			wantReason: csrf.ErrNoReferer,
+		},
+		{
+			name:       "missing token",
+			debug:      true,
+			origin:     "http://example.com",
+			wantCause:  causeStaleToken,
+			wantReason: csrf.ErrNoToken,
+		},
+	}
+
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			t.Parallel()
+
+			rec, logLine := postRefusedForm(t, tt.debug, tt.origin, tt.referer,
+				nil, "")
+			checkFormRefused(t, rec, logLine, tt.wantCause, tt.wantReason)
+		})
+	}
+}
+
+// TestFormRefusedNamesCauseForForeignToken verifies that a form whose token
+// does not match its CSRF cookie answers 403 with a page naming
+// causeStaleToken, and logs a warning with the request ID and the
+// middleware's reason.
+func TestFormRefusedNamesCauseForForeignToken(t *testing.T) {
+	t.Parallel()
+
+	// The router and postRefusedForm derive their CSRF key from
+	// testSigningKey, so cookiesA is valid there and only tokenB is wrong.
+	_, router := newCSRFTestRouter(t)
+	cookiesA, _ := csrfCredentials(t, router, nil)
+	_, tokenB := csrfCredentials(t, router, nil)
+
+	rec, logLine := postRefusedForm(t, true, "http://example.com", "",
+		cookiesA, tokenB)
+	checkFormRefused(t, rec, logLine, causeStaleToken, csrf.ErrBadToken)
+}
+
+// postRefusedForm sends a POST with the given cookies to the CSRF
+// middleware built for debug. It adds the form token and the Origin and
+// Referer headers when they are not empty. It returns the response and the
+// one JSON log line the middleware wrote.
+func postRefusedForm(
+	t *testing.T, debug bool, origin, referer string,
+	cookies []*http.Cookie, token string,
+) (*httptest.ResponseRecorder, map[string]any) {
+	t.Helper()
+
+	keys, err := seal.DeriveKeys(testSigningKey)
+	if err != nil {
+		t.Fatalf("seal.DeriveKeys() error = %v", err)
+	}
+
+	var logs bytes.Buffer
+
+	log := slog.New(slog.NewJSONHandler(&logs, nil))
+	reached := http.HandlerFunc(func(_ http.ResponseWriter, _ *http.Request) {
+		t.Error("the refused form reached the handler behind the middleware")
+	})
+	srv := newCSRFProtect(keys.CSRFKey, debug, log)(reached)
+
+	form := url.Values{loginKeyField: {"x"}}
+	if token != "" {
+		form.Set(csrfTokenField, token)
+	}
+
+	ctx := context.WithValue(context.Background(),
+		middleware.RequestIDKey, refusedFormRequestID)
+	req := httptest.NewRequestWithContext(ctx, http.MethodPost,
+		"http://example.com/", strings.NewReader(form.Encode()))
+	req.Header.Set("Content-Type", "application/x-www-form-urlencoded")
+
+	for _, c := range cookies {
+		req.AddCookie(c)
+	}
+
+	if origin != "" {
+		req.Header.Set("Origin", origin)
+	}
+
+	if referer != "" {
+		req.Header.Set("Referer", referer)
+	}
+
+	rec := httptest.NewRecorder()
+	srv.ServeHTTP(rec, req)
+
+	var logLine map[string]any
+
+	err = json.Unmarshal(logs.Bytes(), &logLine)
+	if err != nil {
+		t.Fatalf("decoding log line %q: %v", logs.String(), err)
+	}
+
+	return rec, logLine
+}
+
+// checkFormRefused checks that rec is a 403 page naming wantCause and that
+// logLine is a warning carrying the request ID and wantReason.
+func checkFormRefused(
+	t *testing.T, rec *httptest.ResponseRecorder, logLine map[string]any,
+	wantCause string, wantReason error,
+) {
+	t.Helper()
+
+	if rec.Code != http.StatusForbidden {
+		t.Errorf("status = %d, want %d", rec.Code, http.StatusForbidden)
+	}
+
+	body := rec.Body.String()
+	t.Logf("body: %s", body)
+
+	if !strings.Contains(body, template.HTMLEscapeString(wantCause)) {
+		t.Errorf("page does not name the cause %q", wantCause)
+	}
+
+	t.Logf("log line: %v", logLine)
+
+	if logLine["level"] != "WARN" || logLine["msg"] != "form refused" {
+		t.Errorf("log line = %v, want a WARN \"form refused\"", logLine)
+	}
+
+	if logLine["request_id"] != refusedFormRequestID {
+		t.Errorf("logged request_id = %v, want %q",
+			logLine["request_id"], refusedFormRequestID)
+	}
+
+	if logLine["reason"] != wantReason.Error() {
+		t.Errorf("logged reason = %v, want %q", logLine["reason"], wantReason)
+	}
+}