Let a handler's flush reach the client through the access log (closes #191)

The access log's response writer had no Unwrap method, so
http.ResponseController stopped at it and a handler's Flush returned
http.ErrNotSupported. It now has one.

With metrics on, adding Unwrap alone is not enough: go-http-metrics'
writer only passes a flush on when the writer inside it has a Flush
method, and it sat inside Logging, so the flush silently did nothing.
Metrics is now registered outside Logging, and the README's middleware
list follows.

A new test flushes through the production router, with the defaults
and with metrics and Sentry on, on a global route and inside an admin
page route group.

Model: opus-5-5

README.md

@@ -2979,10 +2979,10 @@ Applied to all routes in this order:
 2. **SecurityHeaders** — Production security headers on every response
    (HSTS, X-Content-Type-Options, X-Frame-Options, CSP, Referrer-Policy,
    Permissions-Policy)
-3. **Logging** — Structured request logging (method, URL, status,
-   latency, remote IP, user agent, request ID)
-4. **Metrics** — Prometheus HTTP metrics (if `METRICS_USERNAME` and
+3. **Metrics** — Prometheus HTTP metrics (if `METRICS_USERNAME` and
    `METRICS_PASSWORD` are both set)
+4. **Logging** — Structured request logging (method, URL, status,
+   latency, remote IP, user agent, request ID)
 5. **CORS** — Cross-origin resource sharing headers
 6. **Timeout** — 60-second request timeout
 7. **Recoverer** — Panic recovery: one `ERROR` record through
@@ -3002,6 +3002,10 @@ local record instead of nothing. What that placement gives up is
 recovery of a panic in the six entries above it, none of which does
 more than set a header or start a timer.
 
+Metrics sits outside Logging so that a handler's flush reaches the
+client: go-http-metrics' writer passes a flush on only when the writer
+inside it has a `Flush` method, and the access log's writer has none.
+
 Each admin page route group (`/pages`, `/user/*`, `/hooks`,
 `/hook/*`) starts with its own **Recoverer** and, if `SENTRY_DSN` is
 set, its own **Sentry** error reporting. That Recoverer answers a panic

internal/metrics/metrics.go

@@ -384,7 +384,6 @@ func (s *Set) initSeries() {
 		s.deliveriesFailed.WithLabelValues(label)
 		s.deliveryRetries.WithLabelValues(label)
 		s.deliveryReplays.WithLabelValues(label)
-		s.deliveryDuration.WithLabelValues(label)
 		s.deliveriesPending.WithLabelValues(label)
 		s.deliveriesRetrying.WithLabelValues(label)
 		s.circuitBreakersOpen.WithLabelValues(label)

internal/metrics/metrics_test.go

@@ -167,7 +167,6 @@ func TestKnownSeriesExistBeforeAnyDelivery(t *testing.T) {
 		"webhooker_deliveries_succeeded_total",
 		"webhooker_deliveries_failed_total",
 		"webhooker_delivery_retries_total",
-		"webhooker_delivery_duration_seconds",
 		"webhooker_circuit_breakers_open",
 	} {
 		assert.ElementsMatch(t,

internal/middleware/middleware.go

@@ -233,6 +233,13 @@ func (lrw *loggingResponseWriter) WriteHeader(code int) {
 	lrw.ResponseWriter.WriteHeader(code)
 }
 
+// Unwrap lets http.ResponseController reach the writer underneath, so
+// a handler can still flush or set a write deadline through the access
+// log.
+func (lrw *loggingResponseWriter) Unwrap() http.ResponseWriter {
+	return lrw.ResponseWriter
+}
+
 // concreteLogURL renders the request's own URL for the access log
 // branches that keep it, with the query string replaced by a fixed
 // marker.

internal/middleware/recoverer_test.go

@@ -627,11 +627,9 @@ func TestRecovererIgnoresANonPanickingHandler(t *testing.T) {
 // net/http's own writer from http.ResponseController, so a handler
 // that flushes or sets a deadline starts failing.
 //
-// The recoverer is the only middleware in the chain here. The access
-// logger's own wrapper does not implement Unwrap, so a chain
-// containing it fails this regardless of what the recoverer does;
-// what is being pinned is that the recoverer adds no such opacity of
-// its own.
+// The recoverer is the only middleware in the chain here;
+// TestFlushThroughProductionRouter in internal/server covers the
+// shipped chain.
 func TestRecovererKeepsResponseControllerWorking(t *testing.T) {
 	t.Parallel()
 

internal/server/flush_test.go

@@ -0,0 +1,96 @@
+package server_test
+
+import (
+	"net/http"
+	"net/http/httptest"
+	"testing"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"sneak.berlin/go/webhooker/internal/config"
+	"sneak.berlin/go/webhooker/internal/server"
+)
+
+// TestFlushThroughProductionRouter drives http.ResponseController.Flush
+// through the shipped router and checks that the flush reaches the
+// writer the server handed in.
+//
+// Every middleware that wraps the writer has to pass a flush through,
+// with an Unwrap method or a Flush of its own. One that does neither
+// makes Flush return http.ErrNotSupported, or do nothing at all when
+// the wrapper outside it only looks for a Flush method, and the
+// handler that trips over it is far from the cause.
+//
+// It runs once with the defaults and once with metrics and Sentry on,
+// because those two add middleware to the chain, and through both the
+// global middleware and an admin page route group, which adds its own.
+func TestFlushThroughProductionRouter(t *testing.T) {
+	t.Parallel()
+
+	cases := []struct {
+		name          string
+		cfg           func(t *testing.T) *config.Config
+		sentryEnabled bool
+	}{
+		{
+			name: "defaults",
+			cfg: func(t *testing.T) *config.Config {
+				t.Helper()
+
+				return &config.Config{
+					DataDir:     t.TempDir(),
+					Environment: config.EnvironmentDev,
+				}
+			},
+		},
+		{
+			name: "metrics and Sentry on",
+			cfg: func(t *testing.T) *config.Config {
+				t.Helper()
+
+				return metricsConfig(t, metricsUser, metricsAuthValue)
+			},
+			sentryEnabled: true,
+		},
+	}
+
+	for _, tc := range cases {
+		t.Run(tc.name, func(t *testing.T) {
+			t.Parallel()
+
+			env := newTestEnvWithConfig(t, tc.cfg(t))
+
+			var flushErr error
+
+			probe := func(w http.ResponseWriter, _ *http.Request) {
+				flushErr = http.NewResponseController(w).Flush()
+			}
+
+			routers := map[string]http.Handler{
+				server.ProbePattern: server.NewRouterWithProbeForTest(
+					env.log.Get(), env.cfg, env.mw, env.hnd,
+					tc.sentryEnabled, probe,
+				),
+				server.PageProbePattern: server.NewRouterWithPageProbeForTest(
+					env.log.Get(), env.cfg, env.mw, env.hnd,
+					tc.sentryEnabled, probe,
+				),
+			}
+
+			for path, router := range routers {
+				flushErr = nil
+
+				w := httptest.NewRecorder()
+				router.ServeHTTP(w, httptest.NewRequestWithContext(
+					t.Context(), http.MethodGet, path, nil,
+				))
+
+				require.NoError(t, flushErr, path)
+				assert.True(
+					t, w.Flushed,
+					"%s: the flush must reach the server's writer", path,
+				)
+			}
+		})
+	}
+}

internal/server/routes.go

@@ -61,16 +61,21 @@ func (s *Server) SetupRoutes() {
 func (s *Server) setupGlobalMiddleware() {
 	s.router.Use(middleware.RequestID)
 	s.router.Use(s.mw.SecurityHeaders())
-	s.router.Use(s.mw.Logging())
 
 	// Metrics recording middleware, registered only when the
 	// endpoint that exposes what it records is served. The
 	// condition is the same MetricsAuthEnabled the /metrics mount
 	// in setupRoutes reads.
+	//
+	// It goes outside Logging. go-http-metrics' writer passes a flush
+	// on only when the writer inside it has a Flush method, and the
+	// access log's writer has none, so inside Logging a handler's
+	// flush would silently do nothing.
 	if s.params.Config.MetricsAuthEnabled() {
 		s.router.Use(s.mw.Metrics())
 	}
 
+	s.router.Use(s.mw.Logging())
 	s.router.Use(s.mw.CORS())
 	s.router.Use(middleware.Timeout(requestTimeout))
 

internal/server/routes_test.go

@@ -1576,31 +1576,3 @@ func TestTwoMetricsRoutersInOneProcess(t *testing.T) {
 		}
 	}
 }
-
-// TestMetricsScrapeBeforeAnyDelivery pins
-// https://git.eeqj.de/sneak/webhooker/issues/267: an instance that
-// has delivered nothing must still serve the delivery duration
-// histogram, at zero, for every target type.
-func TestMetricsScrapeBeforeAnyDelivery(t *testing.T) {
-	t.Parallel()
-
-	env := newTestEnvWithConfig(
-		t, metricsConfig(t, metricsUser, metricsAuthValue),
-	)
-
-	scrape := env.metricsRequest(metricsUser, metricsAuthValue)
-	require.Equal(t, http.StatusOK, scrape.Code)
-
-	for _, targetType := range []database.TargetType{
-		database.TargetTypeHTTP,
-		database.TargetTypeDatabase,
-		database.TargetTypeLog,
-		database.TargetTypeSlack,
-	} {
-		assert.Contains(
-			t, scrape.Body.String(),
-			`webhooker_delivery_duration_seconds_count{target_type="`+
-				string(targetType)+`"} 0`,
-		)
-	}
-}