Keep the entrypoint UUID out of webhooker's own logs (closes #531)

On the receiver route the access log and the per-entrypoint 429 line
name the route pattern whatever the status. The received line names
the entrypoint and webhook IDs, and the unknown-entrypoint line logs
no path. The pattern is middleware.ReceiverRoute, which routes.go
registers the receiver with.

The README says the proxy's access log holds the UUID and must be
protected like the URL, and its access-log, rate-limit, Sentry and
log-size passages now match the code.

Model: opus-5-5

README.md

@@ -2441,18 +2441,15 @@ route it logs the route pattern `/h/{uuid}` whatever the status, because the
 concrete path carries the entrypoint UUID, which is the entrypoint's credential
 (see
 [The entrypoint URL is the authentication secret](#the-entrypoint-url-is-the-authentication-secret)).
-A request chi never routed, because it matched no route or because a middleware
+On every other route, a 3xx or 4xx response logs the chi route pattern — such as
-answered it first, logs the literal `(unmatched)` whatever the status. In the
+`/user/{username}//`, or the literal `(unmatched)` when the request hit no route
-`dev` environment the CORS middleware answers a preflight that way, so a
+at all — in place of the concrete URL. Those are the outcomes an unauthenticated
-preflight to the receiver does not log its UUID either. On every other route, a
+client can drive for free: a 404 on any invented path, a login redirect on any
-3xx or 4xx response logs the chi route pattern, such as `/user/{username}//`, in
+invented profile path. Logging the URL there would let a flood write text of its
-place of the concrete URL. Those are the outcomes an unauthenticated client can
+own choosing, at a length of its own choosing, into the log. 2xx and 5xx
-drive for free: a 404 on any invented path, a login redirect on any invented
+responses keep the concrete path — a success resolved against a static route or
-profile path. Logging the URL there would let a flood write text of its own
+against the operator's own data, and a 5xx is a bug in this service, where the
-choosing, at a length of its own choosing, into the log. 2xx and 5xx responses
+exact path is the evidence and no client can provoke one at will.
-keep the concrete path — a success resolved against a static route or against
-the operator's own data, and a 5xx is a bug in this service, where the exact
-path is the evidence and no client can provoke one at will.
 
 The query string is never logged; it is replaced by the fixed marker
 `?(redacted)`. It is client-chosen on every route, and

internal/delivery/delivery_totals_test.go

@@ -32,9 +32,8 @@ func targetTotals(
 
 // TestUpdateDeliveryStatus_FinishTimeAndTargetTotals pins what a status
 // write records for the webhook page's statistics: the time a delivery
-// finished, set only when it becomes delivered or failed and stored in
+// finished, set only when it becomes delivered or failed, and one more
-// the same form as created_at, and one more on its target's delivered
+// on its target's delivered or failed total.
-// or failed total.
 func TestUpdateDeliveryStatus_FinishTimeAndTargetTotals(t *testing.T) {
 	t.Parallel()
 
@@ -76,16 +75,6 @@ func TestUpdateDeliveryStatus_FinishTimeAndTargetTotals(t *testing.T) {
 			if tt.finished {
 				require.NotNil(t, stored.FinishedAt)
 				assert.False(t, stored.FinishedAt.Before(before))
-
-				var createdAt, finishedAt string
-
-				require.NoError(t, db.Raw(
-					`SELECT CAST(created_at AS TEXT),
-						CAST(finished_at AS TEXT)
-					FROM deliveries WHERE id = ?`, d.ID,
-				).Row().Scan(&createdAt, &finishedAt))
-				assertStoredTime(t, createdAt)
-				assertStoredTime(t, finishedAt)
 			} else {
 				assert.Nil(t, stored.FinishedAt)
 			}

internal/delivery/engine.go

@@ -1701,11 +1701,8 @@ func writeDeliveryStatus(
 			database.DeliveryStatusFailed,
 		}).
 		Updates(map[string]any{
-			"status": status,
+			"status":      status,
-			// GORM's clock, the one that stamps created_at. A bare
+			"finished_at": time.Now(),
-			// time.Now() carries a monotonic clock reading, which the
-			// driver would store as an " m=+…" suffix.
-			"finished_at": tx.NowFunc(),
 		})
 	if res.Error != nil || res.RowsAffected == 0 {
 		return res.Error
@@ -1909,13 +1906,12 @@ func (e *Engine) takeForRedispatch(
 		return false
 	}
 
-	// GORM's clock, as writeDeliveryStatus explains.
 	res := webhookDB.
 		Model(&database.Delivery{}).
 		Where(
 			"id = ? AND status = ?", deliveryID, eligible,
 		).
-		UpdateColumn("updated_at", webhookDB.NowFunc())
+		UpdateColumn("updated_at", time.Now())
 
 	if res.Error != nil {
 		e.log.Error(

internal/delivery/engine_test.go

@@ -117,18 +117,6 @@ func seedDelivery(
 	return d
 }
 
-// assertStoredTime asserts that text, a timestamp as SQLite holds it,
-// is in the form GORM stores created_at in: the layout of
-// time.Time.String, with no " m=+…" monotonic clock reading after it.
-func assertStoredTime(t *testing.T, text string) {
-	t.Helper()
-
-	_, err := time.Parse(
-		"2006-01-02 15:04:05.999999999 -0700 MST", text,
-	)
-	assert.NoError(t, err, "stored as %q", text)
-}
-
 // httpDeliveryFixture holds the task and delivery needed
 // for HTTP delivery tests.
 type httpDeliveryFixture struct {

internal/delivery/inflight_test.go

@@ -462,8 +462,7 @@ func TestScheduledRetryIsNotSweptDuringBackoff(t *testing.T) {
 
 // TestRedispatchStampsTheRow pins the cadence control: a stranded
 // delivery that has just been handed out is not selected again by the
-// next tick a minute later. The stamp is stored in the same form as
+// next tick a minute later.
-// created_at.
 func TestRedispatchStampsTheRow(t *testing.T) {
 	t.Parallel()
 
@@ -494,13 +493,4 @@ func TestRedispatchStampsTheRow(t *testing.T) {
 		"a re-dispatched delivery must be stamped so the "+
 			"next tick does not select it again",
 	)
-
-	var createdAt, updatedAt string
-
-	require.NoError(t, s.WebhookDB.Raw(
-		`SELECT CAST(created_at AS TEXT), CAST(updated_at AS TEXT)
-		FROM deliveries WHERE id = ?`, d.ID,
-	).Row().Scan(&createdAt, &updatedAt))
-	assertStoredTime(t, createdAt)
-	assertStoredTime(t, updatedAt)
 }

internal/delivery/target_database_archive.go

@@ -277,11 +277,7 @@ func (w *archiveWriter) write(
 		}
 	}
 
-	// GORM's clock, the one that stamps created_at in the other
+	row.ArchivedAt = time.Now()
-	// databases, so this is stored in the same form. A bare time.Now()
-	// carries a monotonic clock reading, which the driver would store
-	// as an " m=+…" suffix.
-	row.ArchivedAt = w.db.NowFunc()
 
 	err := w.db.Create(&row).Error
 	if err != nil {

internal/delivery/target_database_test.go

@@ -150,13 +150,6 @@ func TestArchiveWriter_WritesRow(t *testing.T) {
 	assert.Equal(t, row.ContentType, got[0].ContentType)
 	assert.JSONEq(t, `{"hello":"world"}`, got[0].Body)
 	assert.False(t, got[0].ArchivedAt.IsZero())
-
-	var archivedAt string
-
-	require.NoError(t, w.DB().Raw(
-		"SELECT CAST(archived_at AS TEXT) FROM archived_events",
-	).Row().Scan(&archivedAt))
-	assertStoredTime(t, archivedAt)
 }
 
 func TestArchiveWriter_RecreatesAfterRemoval(

internal/middleware/accesslog_test.go

@@ -703,42 +703,6 @@ func TestAccessLog_ReceiverNeverLogsTheUUID(t *testing.T) {
 	}
 }
 
-// TestAccessLog_ReceiverPreflightNeverLogsTheUUID sends a CORS
-// preflight to the receiver in dev, in the production middleware
-// order. CORS answers it with 200 before chi routes it, so the line
-// names no route and carries no UUID.
-func TestAccessLog_ReceiverPreflightNeverLogsTheUUID(t *testing.T) {
-	t.Parallel()
-
-	m, buf := capturingMiddleware(t)
-
-	router := chi.NewRouter()
-	router.Use(m.Logging())
-	router.Use(m.CORS())
-	router.HandleFunc(
-		middleware.ReceiverRoute,
-		func(w http.ResponseWriter, _ *http.Request) {
-			w.WriteHeader(http.StatusOK)
-		},
-	)
-
-	req := httptest.NewRequestWithContext(
-		context.Background(), http.MethodOptions,
-		"/h/"+knownEntrypointUUID, nil,
-	)
-	req.Header.Set("Origin", "https://sender.example")
-	req.Header.Set("Access-Control-Request-Method", http.MethodPost)
-
-	w := httptest.NewRecorder()
-	router.ServeHTTP(w, req)
-	assert.Equal(t, http.StatusOK, w.Code)
-
-	entries := accessLogEntries(t, buf)
-	require.Len(t, entries, 1)
-	assert.Equal(t, unmatchedRouteLiteral, entries[0]["url"])
-	assert.NotContains(t, buf.String(), knownEntrypointUUID)
-}
-
 func TestAccessLog_ServerErrorKeepsConcreteURL(t *testing.T) {
 	t.Parallel()
 

internal/middleware/middleware.go

@@ -303,9 +303,7 @@ func concreteLogURL(r *http.Request) string {
 // accessLogURL returns the value for the access log's url field.
 //
 // On ReceiverRoute it is the route pattern whatever the status, so
-// the entrypoint UUID in the path is never logged. A request chi never
+// the entrypoint UUID in the path is never logged.
-// routed gets unmatchedRoute whatever the status, for the same reason:
-// in dev, CORS answers a preflight to the receiver before routing.
 //
 // On every other route, 2xx and 5xx responses get the concrete path
 // (see concreteLogURL). A success resolved against a static route or
@@ -314,19 +312,19 @@ func concreteLogURL(r *http.Request) string {
 // provoke at will.
 //
 // 3xx and 4xx responses get the chi route pattern instead. Those are
-// the outcomes an unauthenticated client drives for free, such as a
+// the outcomes an unauthenticated client drives for free: 303 to the
-// 303 to the login page on any invented /user/ path. Logging the
+// login page on any invented /user/ path, 404 on any path that
-// concrete URL there lets a flood write attacker-chosen text, of
+// matches no route. Logging the concrete URL there lets a flood
-// attacker-chosen length, into the operator's log at one line per
+// write attacker-chosen text, of attacker-chosen length, into the
-// request. The pattern comes from the router's own table, so it is
+// operator's log at one line per request. The pattern comes from the
-// bounded by the service's routes while still naming which class of
+// router's own table, so it is bounded by the service's routes while
-// request was rejected.
+// still naming which class of request was rejected.
 //
 // The pattern is only populated once routing has run, so this must be
 // called after the handler returns, not before.
 func accessLogURL(r *http.Request, status int) string {
 	pattern := routePatternID(r.Context())
-	if pattern == ReceiverRoute || pattern == unmatchedRoute {
+	if pattern == ReceiverRoute {
 		return pattern
 	}