Show an event's entrypoint and request headers in the event log and on its page (closes #389)

The receiver stored each event's request headers and entrypoint, but no page showed them, so with several entrypoints the operator could not tell which sender sent an event. An expanded event in the event log, and the event's own page, now show the entrypoint by its description ("Entrypoint" without one, "deleted entrypoint" once deleted), never its URL, and the headers as one escaped block, sorted, whitespace kept. A resubmitted copy says the request it copies arrived there. The event log reads at most 32 KiB of headers per event, the body's limit, and links to the event's page beyond it. Both pages share one template, `event_request.html`.

Model: opus-5-5

internal/handlers/event_detail.go

@@ -1,6 +1,7 @@
 package handlers
 
 import (
+	"math"
 	"net/http"
 
 	"github.com/go-chi/chi"
@@ -59,8 +60,9 @@ func (h *Handlers) HandleEventDetail() http.HandlerFunc {
 			return
 		}
 
+		// The page shows every request header.
 		views, ok := h.eventLogViews(
-			w, r, webhookDB, webhook.ID, rows, targets,
+			w, r, webhookDB, webhook.ID, rows, targets, math.MaxInt,
 		)
 		if !ok {
 			return

internal/handlers/event_log_view.go

@@ -1,10 +1,15 @@
 package handlers
 
 import (
+	"encoding/json"
+	"net/http"
+	"slices"
+	"strings"
 	"time"
 	"unicode/utf8"
 
 	"github.com/dustin/go-humanize"
+	"sneak.berlin/go/webhooker/internal/database"
 )
 
 // eventLogColumns is the event log's projection. The casts to
@@ -12,16 +17,20 @@ import (
 // bytes rather than characters, so the cap bounds the page in
 // bytes whatever the payload's encoding. Cutting in SQLite
 // rather than in Go is the point of the projection — an
-// oversized body never becomes a Go string at all.
+// oversized body or set of request headers never becomes a Go
+// string at all.
 const eventLogColumns = "id, created_at, method, content_type, " +
-	"resubmitted_from_id, " +
+	"resubmitted_from_id, entrypoint_id, " +
+	"substr(cast(headers as blob), 1, ?) AS headers, " +
+	"length(cast(headers as blob)) AS headers_bytes, " +
 	"substr(cast(body as blob), 1, ?) AS body, " +
 	"length(cast(body as blob)) AS body_bytes"
 
 // eventColumns is eventLogColumns for the event's own page, which
-// shows the whole body.
+// shows the whole body and every request header.
 const eventColumns = "id, created_at, method, content_type, " +
-	"resubmitted_from_id, " +
+	"resubmitted_from_id, entrypoint_id, headers, " +
+	"length(cast(headers as blob)) AS headers_bytes, " +
 	"cast(body as blob) AS body, " +
 	"length(cast(body as blob)) AS body_bytes"
 
@@ -40,6 +49,22 @@ type EventLogView struct {
 
 	Body BodyView
 
+	// Entrypoint names the entrypoint the event arrived at. A
+	// resubmitted copy, even a copy of a copy, did not arrive; it
+	// names the one the request it copies arrived at. The name is
+	// the entrypoint's description, "Entrypoint" when it has none,
+	// or "deleted entrypoint", never its URL, which is the
+	// entrypoint's secret.
+	Entrypoint string
+
+	// Headers is the event's request headers as text, one
+	// "Name: value" line per value, sorted by name. HeadersCut
+	// reports headers left out because they hold more than
+	// maxRenderedBodyBytes, stored or as text; only the event log
+	// leaves them out.
+	Headers    string
+	HeadersCut bool
+
 	// ResubmittedFromID names the event this one was copied
 	// from, empty for an event that arrived on the receiver.
 	ResubmittedFromID string
@@ -60,27 +85,35 @@ func (v EventLogView) ResubmittedFrom() bool {
 }
 
 // eventLogRow is one row of the event log projection, or of
-// eventColumns. In the event log its body column arrives
-// already cut to the cap by SQLite, with the true size beside
-// it.
+// eventColumns. In the event log its headers and body columns
+// arrive already cut to the cap by SQLite, each with its true
+// size beside it.
 type eventLogRow struct {
 	ID                string
 	CreatedAt         time.Time
 	Method            string
 	ContentType       string
 	ResubmittedFromID *string
+	EntrypointID      string
+	Headers           string
+	HeadersBytes      int64
 	Body              []byte
 	BodyBytes         int64
 }
 
 // view projects a loaded row of the webhook's events for
-// rendering.
-func (r *eventLogRow) view(webhookID string) EventLogView {
+// rendering. It shows the request headers when the row holds them
+// whole and their text holds at most maxHeaderBytes.
+func (r *eventLogRow) view(
+	webhookID string, maxHeaderBytes int,
+) EventLogView {
 	var from string
 	if r.ResubmittedFromID != nil {
 		from = *r.ResubmittedFromID
 	}
 
+	headers, fit := requestHeaderLines(r.Headers, maxHeaderBytes)
+
 	return EventLogView{
 		ID:          r.ID,
 		Method:      r.Method,
@@ -90,10 +123,83 @@ func (r *eventLogRow) view(webhookID string) EventLogView {
 		Body: newBodyView(
 			"/hook/"+webhookID+"/events/"+r.ID, r.Body, r.BodyBytes,
 		),
+		Headers:           strings.Join(headers, "\n"),
+		HeadersCut:        !fit || r.HeadersBytes > int64(len(r.Headers)),
 		ResubmittedFromID: from,
 	}
 }
 
+// requestHeaderLines turns an event's stored request headers, the
+// JSON the receiver writes, into one "Name: value" line per value,
+// sorted by name. Headers that do not parse, as when the event log
+// has cut them, show as none. It reports false, with no lines, when
+// the lines, each with the newline that follows it, would hold more
+// than maxBytes: a header sent many times is stored with its name
+// once but shown with it on every line.
+func requestHeaderLines(headersJSON string, maxBytes int) ([]string, bool) {
+	var headers http.Header
+
+	if json.Unmarshal([]byte(headersJSON), &headers) != nil {
+		return nil, true
+	}
+
+	names := make([]string, 0, len(headers))
+	for name := range headers {
+		names = append(names, name)
+	}
+
+	slices.Sort(names)
+
+	var lines []string
+
+	size := 0
+
+	for _, name := range names {
+		for _, value := range headers[name] {
+			line := name + ": " + value
+
+			size += len(line) + len("\n")
+			if size > maxBytes {
+				return nil, false
+			}
+
+			lines = append(lines, line)
+		}
+	}
+
+	return lines, true
+}
+
+// entrypointNames maps each of the webhook's entrypoints to the name
+// an event that arrived at it shows: its description, or "Entrypoint"
+// when it has none, as the webhook page names it. A deleted
+// entrypoint is left out.
+func (h *Handlers) entrypointNames(
+	webhookID string,
+) (map[string]string, error) {
+	var entrypoints []database.Entrypoint
+
+	err := h.db.DB().Where(
+		"webhook_id = ?", webhookID,
+	).Find(&entrypoints).Error
+	if err != nil {
+		return nil, err
+	}
+
+	names := make(map[string]string, len(entrypoints))
+
+	for i := range entrypoints {
+		name := entrypoints[i].Description
+		if name == "" {
+			name = "Entrypoint"
+		}
+
+		names[entrypoints[i].ID] = name
+	}
+
+	return names, nil
+}
+
 // trimPartialRune drops a trailing UTF-8 sequence that the
 // byte-wise cut left incomplete, so a multi-byte rune severed
 // at the cap does not surface as a mojibake tail.

internal/handlers/event_request_test.go

@@ -0,0 +1,332 @@
+package handlers_test
+
+import (
+	"encoding/json"
+	"net/http"
+	"slices"
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/google/uuid"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"gorm.io/gorm/clause"
+	"sneak.berlin/go/webhooker/internal/database"
+)
+
+// arrivedAt is how a page names the entrypoint an event arrived at.
+func arrivedAt(name string) string {
+	return `Arrived at <span class="text-gray-900">` + name + `</span>`
+}
+
+// copiedRequestArrivedAt is how a page names, for a resubmitted copy,
+// the entrypoint the request it copies arrived at.
+func copiedRequestArrivedAt(name string) string {
+	return `The request it copies arrived at <span class="text-gray-900">` +
+		name + `</span>`
+}
+
+// headerBox is how a page shows an event's request header lines: as
+// one block of text in a single box.
+func headerBox(lines ...string) string {
+	return `<pre class="rounded-md border border-gray-200 bg-white p-2 ` +
+		`text-xs text-gray-700 overflow-x-auto whitespace-pre-wrap ` +
+		`break-all">` + strings.Join(lines, "\n") + `</pre>`
+}
+
+// showHeadersLink is the event log's link to an event's own page for
+// request headers it leaves out.
+func showHeadersLink(webhookID, eventID string) string {
+	return `<a href="/hook/` + webhookID + `/events/` + eventID +
+		`" class="btn-small">Show the request headers</a>`
+}
+
+// entrypoint records one of the fixture webhook's entrypoints.
+func (f *recentEventsFixture) entrypoint(
+	t *testing.T, description string,
+) *database.Entrypoint {
+	t.Helper()
+
+	ep := &database.Entrypoint{
+		WebhookID:   f.webhook.ID,
+		Path:        uuid.NewString(),
+		Description: description,
+		Active:      true,
+	}
+
+	require.NoError(t, f.db.DB().Omit(clause.Associations).Create(ep).Error)
+
+	return ep
+}
+
+// eventAt records an event that arrived at the entrypoint with the
+// given request headers, stored as JSON as the receiver stores them.
+func (f *recentEventsFixture) eventAt(
+	t *testing.T,
+	ep *database.Entrypoint,
+	headersJSON string,
+	receivedAt time.Time,
+) *database.Event {
+	t.Helper()
+
+	event := &database.Event{
+		WebhookID:    f.webhook.ID,
+		EntrypointID: ep.ID,
+		Method:       http.MethodPost,
+		Headers:      headersJSON,
+		Body:         "{}",
+		BodyBytes:    2,
+		ContentType:  contentTypeJSON,
+	}
+	event.CreatedAt = receivedAt
+
+	require.NoError(t, f.webhookDB.Omit(
+		clause.Associations,
+	).Create(event).Error)
+
+	return event
+}
+
+// TestEventRequest_EachEventShowsItsOwnEntrypointAndHeaders proves two
+// events that arrived at two entrypoints each show their own
+// entrypoint and request headers, in the event log and on their own
+// pages, with the headers sorted by name, escaped and keeping their
+// whitespace, and never the entrypoint's URL.
+func TestEventRequest_EachEventShowsItsOwnEntrypointAndHeaders(
+	t *testing.T,
+) {
+	t.Parallel()
+
+	f := newRecentEventsFixture(t)
+	billing := f.entrypoint(t, "Billing sender")
+	unnamed := f.entrypoint(t, "")
+
+	// Stored in reverse name order.
+	older := f.eventAt(t, billing,
+		`{"X-Shop-Event":["order.created"],`+
+			`"User-Agent":["shop/1  build\t7"],"Accept":["*/*"]}`,
+		time.Now().Add(-time.Minute))
+	newer := f.eventAt(t, unnamed,
+		`{"X-Shop-Event":["order.paid"],"X-Note":["<b>hi</b>"]}`,
+		time.Now())
+
+	olderShows := func(t *testing.T, page string) {
+		t.Helper()
+
+		assert.Contains(t, page, arrivedAt("Billing sender"))
+		assert.Contains(t, page, headerBox(
+			"Accept: */*",
+			"User-Agent: shop/1  build\t7",
+			"X-Shop-Event: order.created",
+		), "headers are sorted by name")
+		assert.NotContains(t, page, "order.paid")
+		assert.NotContains(t, page, billing.Path)
+	}
+
+	newerShows := func(t *testing.T, page string) {
+		t.Helper()
+
+		assert.Contains(t, page, arrivedAt("Entrypoint"))
+		assert.Contains(t, page, headerBox(
+			"X-Note: &lt;b&gt;hi&lt;/b&gt;",
+			"X-Shop-Event: order.paid",
+		))
+		assert.NotContains(t, page, "<b>hi</b>")
+		assert.NotContains(t, page, "order.created")
+		assert.NotContains(t, page, unnamed.Path)
+	}
+
+	// The log lists the newer event first, so everything between
+	// the two events' first mentions belongs to the newer one.
+	_, rest, found := strings.Cut(renderSourceLogsPage(
+		t, f.h, f.sess, f.webhook.ID,
+	), newer.ID)
+	require.True(t, found)
+
+	newerPart, olderPart, found := strings.Cut(rest, older.ID)
+	require.True(t, found)
+
+	newerShows(t, newerPart)
+	olderShows(t, olderPart)
+
+	w := serveEventPage(t, f.h, f.sess, f.webhook.ID, newer.ID)
+	require.Equal(t, http.StatusOK, w.Code)
+	newerShows(t, w.Body.String())
+
+	w = serveEventPage(t, f.h, f.sess, f.webhook.ID, older.ID)
+	require.Equal(t, http.StatusOK, w.Code)
+	olderShows(t, w.Body.String())
+}
+
+// TestEventRequest_DeletedEntrypoint proves an event whose entrypoint
+// has since been deleted says so in the event log and on its own page.
+func TestEventRequest_DeletedEntrypoint(t *testing.T) {
+	t.Parallel()
+
+	f := newRecentEventsFixture(t)
+	ep := f.entrypoint(t, "Retired sender")
+	event := f.eventAt(t, ep, `{}`, time.Now())
+
+	require.NoError(t, f.db.DB().Delete(ep).Error)
+
+	page := renderSourceLogsPage(t, f.h, f.sess, f.webhook.ID)
+	assert.Contains(t, page, arrivedAt("deleted entrypoint"))
+	assert.NotContains(t, page, "Retired sender")
+
+	w := serveEventPage(t, f.h, f.sess, f.webhook.ID, event.ID)
+	require.Equal(t, http.StatusOK, w.Code)
+	assert.Contains(t, w.Body.String(), arrivedAt("deleted entrypoint"))
+	assert.NotContains(t, w.Body.String(), "Retired sender")
+}
+
+// TestEventRequest_ResubmittedCopy proves a resubmitted copy and a copy
+// of that copy each say the request they copy arrived at the
+// entrypoint, in the event log and on their own pages, and never that
+// they did.
+func TestEventRequest_ResubmittedCopy(t *testing.T) {
+	t.Parallel()
+
+	f := newRecentEventsFixture(t)
+	ep := f.entrypoint(t, "Billing sender")
+	original := f.eventAt(t, ep, `{}`, time.Now().Add(-2*time.Minute))
+	copied := f.eventAt(t, ep, `{}`, time.Now().Add(-time.Minute))
+	copyOfCopy := f.eventAt(t, ep, `{}`, time.Now())
+
+	require.NoError(t, f.webhookDB.Model(copied).Update(
+		"resubmitted_from_id", original.ID,
+	).Error)
+	require.NoError(t, f.webhookDB.Model(copyOfCopy).Update(
+		"resubmitted_from_id", copied.ID,
+	).Error)
+
+	// The log lists the newest event first, and each event's Resubmit
+	// form comes before its entrypoint, so cutting the page at the
+	// copy's and the original's forms leaves each event's entrypoint
+	// in its own part.
+	copyOfCopyPart, rest, found := strings.Cut(
+		renderSourceLogsPage(t, f.h, f.sess, f.webhook.ID),
+		"/events/"+copied.ID+"/resubmit",
+	)
+	require.True(t, found)
+
+	copyPart, originalPart, found := strings.Cut(
+		rest, "/events/"+original.ID+"/resubmit",
+	)
+	require.True(t, found)
+
+	for _, part := range []string{copyOfCopyPart, copyPart} {
+		assert.Contains(t, part, copiedRequestArrivedAt("Billing sender"))
+		assert.NotContains(t, part, arrivedAt("Billing sender"))
+	}
+
+	assert.Contains(t, originalPart, arrivedAt("Billing sender"))
+	assert.NotContains(t, originalPart,
+		copiedRequestArrivedAt("Billing sender"))
+
+	for _, event := range []*database.Event{copied, copyOfCopy} {
+		w := serveEventPage(t, f.h, f.sess, f.webhook.ID, event.ID)
+		require.Equal(t, http.StatusOK, w.Code)
+		assert.Contains(t, w.Body.String(),
+			copiedRequestArrivedAt("Billing sender"))
+		assert.NotContains(t, w.Body.String(), arrivedAt("Billing sender"))
+	}
+}
+
+// TestEventRequest_HeadersOverTheLimit proves the event log leaves out
+// request headers that hold more than it shows of a body, whether
+// stored or as lines, and links to the event's own page, which shows
+// them all.
+func TestEventRequest_HeadersOverTheLimit(t *testing.T) {
+	t.Parallel()
+
+	// The receiver stores each "<" as six bytes of JSON, so this
+	// header is over the limit stored but not as a line.
+	const lessThans = bodyCap/6 + 1
+
+	// A header sent many times is stored with its name once, and
+	// shown with it on every line.
+	repeatedName := "X-Repeated-" + strings.Repeat("r", 1000)
+
+	tests := map[string]struct {
+		headers http.Header
+		line    string
+	}{
+		"stored": {
+			headers: http.Header{"X-Long": {strings.Repeat("<", lessThans)}},
+			line:    "X-Long: " + strings.Repeat("&lt;", lessThans),
+		},
+		"as lines": {
+			headers: http.Header{repeatedName: slices.Repeat([]string{""}, 41)},
+			line:    repeatedName + ": ",
+		},
+	}
+
+	for name, tc := range tests {
+		t.Run(name, func(t *testing.T) {
+			t.Parallel()
+
+			headersJSON, err := json.Marshal(tc.headers)
+			require.NoError(t, err)
+
+			f := newRecentEventsFixture(t)
+			ep := f.entrypoint(t, "Billing sender")
+			event := f.eventAt(t, ep, string(headersJSON), time.Now())
+
+			page := renderSourceLogsPage(t, f.h, f.sess, f.webhook.ID)
+			assert.Contains(t, page, showHeadersLink(f.webhook.ID, event.ID))
+			assert.NotContains(t, page, tc.line)
+			assert.Less(t, len(page), 4*bodyCap)
+
+			w := serveEventPage(t, f.h, f.sess, f.webhook.ID, event.ID)
+			require.Equal(t, http.StatusOK, w.Code)
+			assert.Contains(t, w.Body.String(), tc.line)
+			assert.NotContains(t, w.Body.String(), "Show the request headers")
+		})
+	}
+}
+
+// TestEventRequest_ManyShortHeaderLines proves that for many short
+// request header lines the event log writes no more than its limit,
+// apart from escaping: lines that fill the limit show as one block of
+// text, and one line more is left out with a link to the event's own
+// page.
+func TestEventRequest_ManyShortHeaderLines(t *testing.T) {
+	t.Parallel()
+
+	// Each "A: " line and the newline after it hold four bytes, so
+	// this many lines fill the limit exactly. Each line in its own
+	// element would make the page many times the limit.
+	const fill = bodyCap / len("A: \n")
+
+	tests := map[string]struct {
+		lines int
+		shown bool
+	}{
+		"filling the limit":  {lines: fill, shown: true},
+		"one over the limit": {lines: fill + 1, shown: false},
+	}
+
+	for name, tc := range tests {
+		t.Run(name, func(t *testing.T) {
+			t.Parallel()
+
+			headersJSON, err := json.Marshal(http.Header{
+				"A": slices.Repeat([]string{""}, tc.lines),
+			})
+			require.NoError(t, err)
+
+			f := newRecentEventsFixture(t)
+			ep := f.entrypoint(t, "Billing sender")
+			event := f.eventAt(t, ep, string(headersJSON), time.Now())
+
+			page := renderSourceLogsPage(t, f.h, f.sess, f.webhook.ID)
+			box := headerBox(slices.Repeat([]string{"A: "}, tc.lines)...)
+			link := showHeadersLink(f.webhook.ID, event.ID)
+
+			assert.Equal(t, tc.shown, strings.Contains(page, box))
+			assert.Equal(t, !tc.shown, strings.Contains(page, link))
+			assert.Less(t, len(page), 4*bodyCap)
+		})
+	}
+}

internal/handlers/handlers.go

@@ -167,12 +167,12 @@ func New(
 		),
 		"source_edit.html": parsePageTemplate("source_edit.html"),
 		"source_logs.html": parsePageTemplate(
-			"source_logs.html", "event_body.html", "delivery_row.html",
-			"delivery_attempts.html",
+			"source_logs.html", "event_request.html", "event_body.html",
+			"delivery_row.html", "delivery_attempts.html",
 		),
 		"event_detail.html": parsePageTemplate(
-			"event_detail.html", "event_body.html", "delivery_row.html",
-			"delivery_attempts.html",
+			"event_detail.html", "event_request.html", "event_body.html",
+			"delivery_row.html", "delivery_attempts.html",
 		),
 		"target_edit.html": parsePageTemplate("target_edit.html"),
 		"error.html":       parsePageTemplate("error.html"),

internal/handlers/source_management.go

@@ -1231,13 +1231,17 @@ func (h *Handlers) loadEventsWithDeliveries(
 
 	result, ok := h.eventLogViews(
 		w, r, webhookDB, webhook.ID, rows, targetMap,
+		maxRenderedBodyBytes,
 	)
 
 	return result, totalEvents, ok
 }
 
 // eventLogViews projects loaded events for rendering, each with
-// its deliveries and how many times it has been resubmitted. Like
+// its deliveries, how many times it has been resubmitted and the
+// entrypoint it arrived at (for a resubmitted copy, the one the
+// request it copies arrived at), and with its request headers only
+// when their text holds at most maxHeaderBytes. Like
 // loadEventsWithDeliveries, it reports false once it has answered
 // the request with an error.
 func (h *Handlers) eventLogViews(
@@ -1247,6 +1251,7 @@ func (h *Handlers) eventLogViews(
 	webhookID string,
 	rows []eventLogRow,
 	targetMap map[string]eventLogTarget,
+	maxHeaderBytes int,
 ) ([]EventLogView, bool) {
 	result := make([]EventLogView, len(rows))
 	eventDeliveries := make([][]database.Delivery, len(rows))
@@ -1256,7 +1261,7 @@ func (h *Handlers) eventLogViews(
 	eventIDs := make([]string, len(rows))
 
 	for i := range rows {
-		result[i] = rows[i].view(webhookID)
+		result[i] = rows[i].view(webhookID, maxHeaderBytes)
 		eventIDs[i] = rows[i].ID
 
 		webhookDB.Where(
@@ -1290,11 +1295,25 @@ func (h *Handlers) eventLogViews(
 		return nil, false
 	}
 
+	entrypoints, err := h.entrypointNames(webhookID)
+	if err != nil {
+		h.serverError(w, r, "failed to load entrypoints", err)
+
+		return nil, false
+	}
+
 	for i := range rows {
 		result[i].Deliveries = h.newDeliveryViews(
 			eventDeliveries[i], targetMap, attempts,
 		)
 		result[i].ResubmitCount = resubmits[rows[i].ID]
+
+		name, ok := entrypoints[rows[i].EntrypointID]
+		if !ok {
+			name = "deleted entrypoint"
+		}
+
+		result[i].Entrypoint = name
 	}
 
 	return result, true
@@ -1315,7 +1334,7 @@ func loadEventLogRows(
 	var rows []eventLogRow
 
 	webhookDB.Model(&database.Event{}).Select(
-		eventLogColumns, maxRenderedBodyBytes,
+		eventLogColumns, maxRenderedBodyBytes, maxRenderedBodyBytes,
 	).Where(
 		"webhook_id = ?", webhookID,
 	).Order("created_at DESC").Limit(recentEventLimit).Find(&rows)