` + strings.Join(lines, "\n") + `` +} + +// 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 `Show the request headers` +} + +// 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":["hi"]}`, + 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: <b>hi</b>", + "X-Shop-Event: order.paid", + )) + assert.NotContains(t, page, "hi") + 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("<", 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) + }) + } +} diff --git a/internal/handlers/handlers.go b/internal/handlers/handlers.go index f132349..2b689e6 100644 --- a/internal/handlers/handlers.go +++ b/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"), diff --git a/internal/handlers/source_management.go b/internal/handlers/source_management.go index e8130d3..845580a 100644 --- a/internal/handlers/source_management.go +++ b/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) diff --git a/templates/event_detail.html b/templates/event_detail.html index 3756cad..30756cb 100644 --- a/templates/event_detail.html +++ b/templates/event_detail.html @@ -50,6 +50,15 @@ +
The request it copies arrived at {{.Entrypoint}}
+ {{else}} +Arrived at {{.Entrypoint}}
+ {{end}} + {{if .HeadersCut}} +The request headers are larger than the event log shows. Show the request headers
+ {{else if .Headers}} +Request headers
+{{.Headers}}
+ {{else}}
+ No request headers.
+ {{end}} +