go.mod

@@ -4,6 +4,7 @@ go 1.26.1
 
 require (
 	github.com/99designs/basicauth-go v0.0.0-20230316000542-bf6f9cbbf0f8
+	github.com/dustin/go-humanize v1.0.1
 	github.com/getsentry/sentry-go v0.25.0
 	github.com/go-chi/chi v1.5.5
 	github.com/go-chi/cors v1.2.1
@@ -29,7 +30,6 @@ require (
 	github.com/beorn7/perks v1.0.1 // indirect
 	github.com/cespare/xxhash/v2 v2.2.0 // indirect
 	github.com/davecgh/go-spew v1.1.2-0.20180830191138-d8f796af33cc // indirect
-	github.com/dustin/go-humanize v1.0.1 // indirect
 	github.com/gorilla/securecookie v1.1.2 // indirect
 	github.com/jinzhu/inflection v1.0.0 // indirect
 	github.com/jinzhu/now v1.1.5 // indirect

internal/handlers/delivery_result_view.go

@@ -1,6 +1,8 @@
 package handlers
 
 import (
+	"time"
+
 	"sneak.berlin/go/webhooker/internal/delivery"
 )
 
@@ -25,7 +27,7 @@ const maxRenderedResponseBytes = 4096
 // cut, so an oversized stored response never becomes a Go
 // string at all.
 const deliveryResultColumns = "delivery_id, attempt_num, success, " +
-	"status_code, error, duration, " +
+	"status_code, error, duration, created_at, " +
 	"substr(cast(response_body as blob), 1, ?) AS response_body, " +
 	"length(cast(response_body as blob)) AS response_bytes"
 
@@ -106,6 +108,10 @@ type deliveryResultRow struct {
 	Duration      int64
 	ResponseBody  []byte
 	ResponseBytes int64
+
+	// CreatedAt is when the attempt's result was recorded, which
+	// is when the attempt finished.
+	CreatedAt time.Time
 }
 
 // view projects a loaded row for rendering, stripping the

internal/handlers/handlers.go

@@ -28,7 +28,7 @@ const (
 	// maxBodyShift is the bit shift for 1 MB body limit.
 	maxBodyShift = 20
 	// recentEventLimit is the number of recent events to show.
-	recentEventLimit = 20
+	recentEventLimit = 50
 	// paginationPerPage is the number of items per page.
 	paginationPerPage = 25
 

internal/handlers/recent_events.go

@@ -0,0 +1,248 @@
+package handlers
+
+import (
+	"net/http"
+	"strconv"
+	"time"
+
+	"github.com/dustin/go-humanize"
+	"gorm.io/gorm"
+	"sneak.berlin/go/webhooker/internal/database"
+)
+
+// recentEventColumns is the recent events list's projection. It
+// reads the body's size and never the body itself, for the reason
+// maxRenderedBodyBytes gives; the cast to blob makes length count
+// bytes rather than characters.
+const recentEventColumns = "id, created_at, method, content_type, " +
+	"resubmitted_from_id, length(cast(body as blob)) AS body_bytes"
+
+// RecentEventView is one row of the recent events list on a
+// webhook's page.
+type RecentEventView struct {
+	Method      string
+	ContentType string
+
+	// ResubmittedFromID names the event this one was copied from,
+	// empty for an event that arrived on the receiver.
+	ResubmittedFromID string
+
+	// Received is how long ago the event arrived, and ReceivedUTC
+	// the full timestamp the page shows on hover.
+	Received    string
+	ReceivedUTC string
+
+	// Size is the size of the stored body.
+	Size string
+
+	// ProcessingTime is how long the event's slowest delivery
+	// took; see processingTime.
+	ProcessingTime string
+
+	// Status is what the webhook's HTTP target answered, and
+	// StatusClass its colour; see targetStatus. Both are empty
+	// unless the webhook has exactly one HTTP target.
+	Status      string
+	StatusClass string
+}
+
+// recentEventRow is one row of recentEventColumns.
+type recentEventRow struct {
+	ID                string
+	CreatedAt         time.Time
+	Method            string
+	ContentType       string
+	ResubmittedFromID *string
+	BodyBytes         uint64
+}
+
+// singleHTTPTargetID returns the ID of the webhook's HTTP target
+// when it has exactly one, and "" when it has none or several.
+func singleHTTPTargetID(targets []database.Target) string {
+	id := ""
+	count := 0
+
+	for i := range targets {
+		if targets[i].Type == database.TargetTypeHTTP {
+			id = targets[i].ID
+			count++
+		}
+	}
+
+	if count != 1 {
+		return ""
+	}
+
+	return id
+}
+
+// loadRecentEvents loads the webhook's recentEventLimit newest
+// events for its page, newest first. statusTargetID is the
+// webhook's only HTTP target, or "" when the list shows no status.
+func (h *Handlers) loadRecentEvents(
+	webhookDB *gorm.DB, webhookID, statusTargetID string,
+) ([]RecentEventView, error) {
+	var rows []recentEventRow
+
+	err := webhookDB.Model(&database.Event{}).
+		Select(recentEventColumns).
+		Where("webhook_id = ?", webhookID).
+		Order("created_at DESC").
+		Limit(recentEventLimit).
+		Find(&rows).Error
+	if err != nil {
+		return nil, err
+	}
+
+	eventIDs := make([]string, len(rows))
+	for i := range rows {
+		eventIDs[i] = rows[i].ID
+	}
+
+	// Oldest first, so an event's last delivery to a target is its
+	// newest: a replay adds a delivery rather than changing the
+	// earlier one.
+	var deliveries []database.Delivery
+
+	err = webhookDB.
+		Select("id, event_id, target_id, status, created_at").
+		Where("event_id IN ?", eventIDs).
+		Order("created_at ASC").
+		Find(&deliveries).Error
+	if err != nil {
+		return nil, err
+	}
+
+	byEvent := make(map[string][]database.Delivery, len(rows))
+	deliveryIDs := make([]string, len(deliveries))
+
+	for i := range deliveries {
+		eventID := deliveries[i].EventID
+		byEvent[eventID] = append(byEvent[eventID], deliveries[i])
+		deliveryIDs[i] = deliveries[i].ID
+	}
+
+	attempts, err := h.loadDeliveryResults(webhookDB, deliveryIDs)
+	if err != nil {
+		return nil, err
+	}
+
+	views := make([]RecentEventView, len(rows))
+	for i := range rows {
+		views[i] = rows[i].view(
+			byEvent[rows[i].ID], attempts, statusTargetID,
+		)
+	}
+
+	return views, nil
+}
+
+// view projects a loaded row for rendering. deliveries is the
+// event's deliveries, oldest first, and attempts their recorded
+// attempts keyed by delivery ID.
+func (r *recentEventRow) view(
+	deliveries []database.Delivery,
+	attempts map[string][]deliveryResultRow,
+	statusTargetID string,
+) RecentEventView {
+	v := RecentEventView{
+		Method:         r.Method,
+		ContentType:    r.ContentType,
+		Received:       humanize.Time(r.CreatedAt),
+		ReceivedUTC:    r.CreatedAt.UTC().Format(time.DateTime) + " UTC",
+		Size:           humanize.Bytes(r.BodyBytes),
+		ProcessingTime: processingTime(deliveries, attempts),
+	}
+
+	if r.ResubmittedFromID != nil {
+		v.ResubmittedFromID = *r.ResubmittedFromID
+	}
+
+	if statusTargetID != "" {
+		v.Status, v.StatusClass = targetStatus(
+			deliveries, attempts, statusTargetID,
+		)
+	}
+
+	return v
+}
+
+// processingTime is how long the event's slowest delivery took,
+// from being queued to its last recorded attempt, time spent
+// waiting between retries included. A delivery is queued when its
+// event is received, or when an operator replays it, so a replay
+// is timed from the replay rather than from the event's arrival.
+// It is "in progress" while any delivery is pending or retrying,
+// and empty for an event with no deliveries.
+func processingTime(
+	deliveries []database.Delivery,
+	attempts map[string][]deliveryResultRow,
+) string {
+	if len(deliveries) == 0 {
+		return ""
+	}
+
+	var slowest time.Duration
+
+	for i := range deliveries {
+		if !deliveries[i].Status.Terminal() {
+			return "in progress"
+		}
+
+		tries := attempts[deliveries[i].ID]
+		if len(tries) == 0 {
+			continue
+		}
+
+		last := tries[len(tries)-1].CreatedAt
+		slowest = max(slowest, last.Sub(deliveries[i].CreatedAt))
+	}
+
+	return slowest.Round(time.Millisecond).String()
+}
+
+// targetStatus is what the target answered for the event, and the
+// colour to show it in: the HTTP status code of the last attempt of
+// the event's newest delivery to the target. Without a code it is
+// "no response" when that attempt failed before a response
+// arrived, the delivery's status ("pending") before any attempt,
+// and "not sent" when the event has no delivery to the target.
+func targetStatus(
+	deliveries []database.Delivery,
+	attempts map[string][]deliveryResultRow,
+	targetID string,
+) (string, string) {
+	newest := -1
+
+	for i := range deliveries {
+		if deliveries[i].TargetID == targetID {
+			newest = i
+		}
+	}
+
+	if newest < 0 {
+		return "not sent", "text-gray-400"
+	}
+
+	tries := attempts[deliveries[newest].ID]
+	if len(tries) == 0 {
+		return string(deliveries[newest].Status), "text-gray-400"
+	}
+
+	code := tries[len(tries)-1].StatusCode
+
+	switch {
+	case code == 0:
+		return "no response", "text-red-600"
+	case code >= http.StatusInternalServerError:
+		return strconv.Itoa(code), "text-red-600"
+	case code >= http.StatusBadRequest:
+		return strconv.Itoa(code), "text-yellow-600"
+	case code >= http.StatusMultipleChoices:
+		return strconv.Itoa(code), "text-gray-500"
+	case code >= http.StatusOK:
+		return strconv.Itoa(code), "text-green-600"
+	default:
+		return strconv.Itoa(code), "text-gray-500"
+	}
+}

internal/handlers/recent_events_test.go

@@ -0,0 +1,295 @@
+package handlers_test
+
+import (
+	"fmt"
+	"net/http"
+	"strings"
+	"testing"
+	"time"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"gorm.io/gorm"
+	"gorm.io/gorm/clause"
+	"sneak.berlin/go/webhooker/internal/database"
+	"sneak.berlin/go/webhooker/internal/handlers"
+	"sneak.berlin/go/webhooker/internal/session"
+)
+
+// statusTitle marks the status column's cell in a recent events
+// row; it is absent from the page when the column is not shown.
+const statusTitle = `title="HTTP status from the HTTP target"`
+
+// recentEventsFixture is one started app and a webhook whose
+// recent events list a test fills.
+type recentEventsFixture struct {
+	h         *handlers.Handlers
+	sess      *session.Session
+	db        *database.Database
+	webhook   *database.Webhook
+	webhookDB *gorm.DB
+}
+
+func newRecentEventsFixture(t *testing.T) *recentEventsFixture {
+	t.Helper()
+
+	f := &recentEventsFixture{}
+
+	var dbMgr *database.WebhookDBManager
+
+	app := newTestApp(t, &f.h, &f.sess, &f.db, &dbMgr)
+	app.RequireStart()
+
+	t.Cleanup(app.RequireStop)
+
+	f.webhook = seedWebhook(t, f.db)
+
+	webhookDB, err := dbMgr.GetDB(f.webhook.ID)
+	require.NoError(t, err)
+
+	f.webhookDB = webhookDB
+
+	return f
+}
+
+func (f *recentEventsFixture) render(t *testing.T) string {
+	t.Helper()
+
+	return renderSourceDetailPage(t, f.h, f.sess, f.webhook.ID)
+}
+
+// event records an event received at receivedAt.
+func (f *recentEventsFixture) event(
+	t *testing.T, contentType, body string, receivedAt time.Time,
+) *database.Event {
+	t.Helper()
+
+	event := &database.Event{
+		WebhookID:   f.webhook.ID,
+		Method:      http.MethodPost,
+		Body:        body,
+		ContentType: contentType,
+	}
+	event.CreatedAt = receivedAt
+
+	require.NoError(t, f.webhookDB.Omit(
+		clause.Associations,
+	).Create(event).Error)
+
+	return event
+}
+
+// delivery records a delivery of the event to the target, queued
+// when the event was received.
+func (f *recentEventsFixture) delivery(
+	t *testing.T,
+	event *database.Event,
+	targetID string,
+	status database.DeliveryStatus,
+) *database.Delivery {
+	t.Helper()
+
+	return f.deliveryQueuedAt(
+		t, event, targetID, status, event.CreatedAt,
+	)
+}
+
+// deliveryQueuedAt records a delivery of the event to the target,
+// queued at queuedAt, as a replay is.
+func (f *recentEventsFixture) deliveryQueuedAt(
+	t *testing.T,
+	event *database.Event,
+	targetID string,
+	status database.DeliveryStatus,
+	queuedAt time.Time,
+) *database.Delivery {
+	t.Helper()
+
+	dlv := &database.Delivery{
+		EventID:  event.ID,
+		TargetID: targetID,
+		Status:   status,
+	}
+	dlv.CreatedAt = queuedAt
+
+	require.NoError(t, f.webhookDB.Omit(
+		clause.Associations,
+	).Create(dlv).Error)
+
+	return dlv
+}
+
+// attempt records one attempt of the delivery that finished took
+// after the delivery was queued, with HTTP status code (0 for no
+// response).
+func (f *recentEventsFixture) attempt(
+	t *testing.T, dlv *database.Delivery, code int, took time.Duration,
+) {
+	t.Helper()
+
+	result := &database.DeliveryResult{
+		DeliveryID: dlv.ID,
+		AttemptNum: 1,
+		StatusCode: code,
+	}
+	result.CreatedAt = dlv.CreatedAt.Add(took)
+
+	require.NoError(t, f.webhookDB.Omit(
+		clause.Associations,
+	).Create(result).Error)
+}
+
+// statusCell is the status column's cell as the page renders it.
+func statusCell(class, text string) string {
+	return `<span class="font-medium ` + class + `" ` + statusTitle +
+		`>` + text + `</span>`
+}
+
+// TestHandleSourceDetail_ShowsFiftyNewestEvents proves the list
+// holds the 50 newest events, newest first, and not one more.
+func TestHandleSourceDetail_ShowsFiftyNewestEvents(t *testing.T) {
+	t.Parallel()
+
+	f := newRecentEventsFixture(t)
+	base := time.Now().Add(-time.Hour)
+
+	for i := range 51 {
+		f.event(
+			t, fmt.Sprintf("application/x-recent-%02d", i), "{}",
+			base.Add(time.Duration(i)*time.Second),
+		)
+	}
+
+	body := f.render(t)
+
+	assert.Equal(t, 50, strings.Count(body, `title="Body size"`))
+	assert.NotContains(t, body, "application/x-recent-00")
+	assert.Contains(t, body, "application/x-recent-01")
+	assert.Less(
+		t,
+		strings.Index(body, "application/x-recent-50"),
+		strings.Index(body, "application/x-recent-49"),
+	)
+}
+
+// TestHandleSourceDetail_RecentEventColumns proves a row shows its
+// time relative with the UTC timestamp on hover, its body size,
+// and its processing time once every delivery has finished.
+func TestHandleSourceDetail_RecentEventColumns(t *testing.T) {
+	t.Parallel()
+
+	f := newRecentEventsFixture(t)
+	logTarget := seedTarget(t, f.db, f.webhook.ID, database.TargetTypeLog)
+
+	receivedAt := time.Now().Add(-210 * time.Second).
+		UTC().Truncate(time.Second)
+
+	done := f.event(
+		t, contentTypeJSON, strings.Repeat("x", 2048), receivedAt,
+	)
+	f.attempt(
+		t,
+		f.delivery(t, done, logTarget.ID, database.DeliveryStatusDelivered),
+		0, 1500*time.Millisecond,
+	)
+
+	waiting := f.event(t, "text/plain", "{}", receivedAt)
+	f.delivery(t, waiting, logTarget.ID, database.DeliveryStatusPending)
+
+	body := f.render(t)
+
+	assert.Contains(
+		t, body,
+		`<span title="`+receivedAt.Format(time.DateTime)+
+			` UTC">3 minutes ago</span>`,
+	)
+	assert.Contains(t, body, `<span title="Body size">2.0 kB</span>`)
+	assert.Contains(t, body, ">1.5s</span>")
+	assert.Contains(t, body, ">in progress</span>")
+}
+
+// TestHandleSourceDetail_StatusWithSingleHTTPTarget proves that a
+// webhook with exactly one HTTP target shows, colour-coded, what
+// that target answered for each event. The log target beside it
+// does not count against "exactly one".
+func TestHandleSourceDetail_StatusWithSingleHTTPTarget(t *testing.T) {
+	t.Parallel()
+
+	f := newRecentEventsFixture(t)
+	target := seedTarget(t, f.db, f.webhook.ID, database.TargetTypeHTTP)
+	seedTarget(t, f.db, f.webhook.ID, database.TargetTypeLog)
+
+	now := time.Now()
+
+	for _, code := range []int{204, 302, 404, 503, 0} {
+		dlv := f.delivery(
+			t, f.event(t, contentTypeJSON, "{}", now), target.ID,
+			database.DeliveryStatusDelivered,
+		)
+		f.attempt(t, dlv, code, time.Second)
+	}
+
+	f.delivery(
+		t, f.event(t, contentTypeJSON, "{}", now), target.ID,
+		database.DeliveryStatusPending,
+	)
+	f.event(t, contentTypeJSON, "{}", now)
+
+	// A replay is a newer delivery, and its answer is the one shown.
+	replayed := f.event(t, contentTypeJSON, "{}", now)
+	f.attempt(t, f.delivery(
+		t, replayed, target.ID, database.DeliveryStatusFailed,
+	), 502, time.Second)
+	f.attempt(t, f.deliveryQueuedAt(
+		t, replayed, target.ID, database.DeliveryStatusDelivered,
+		now.Add(time.Minute),
+	), 200, time.Second)
+
+	body := f.render(t)
+
+	assert.Contains(t, body, statusCell("text-green-600", "204"))
+	assert.Contains(t, body, statusCell("text-gray-500", "302"))
+	assert.Contains(t, body, statusCell("text-yellow-600", "404"))
+	assert.Contains(t, body, statusCell("text-red-600", "503"))
+	assert.Contains(t, body, statusCell("text-red-600", "no response"))
+	assert.Contains(t, body, statusCell("text-gray-400", "pending"))
+	assert.Contains(t, body, statusCell("text-gray-400", "not sent"))
+	assert.Contains(t, body, statusCell("text-green-600", "200"))
+	assert.NotContains(t, body, ">502<")
+}
+
+// TestHandleSourceDetail_NoStatusWithoutSingleHTTPTarget proves the
+// status column is absent when the webhook has no HTTP target or
+// more than one.
+func TestHandleSourceDetail_NoStatusWithoutSingleHTTPTarget(
+	t *testing.T,
+) {
+	t.Parallel()
+
+	cases := map[string][]database.TargetType{
+		"none":    {database.TargetTypeLog},
+		"several": {database.TargetTypeHTTP, database.TargetTypeHTTP},
+	}
+
+	for name, types := range cases {
+		t.Run(name, func(t *testing.T) {
+			t.Parallel()
+
+			f := newRecentEventsFixture(t)
+			event := f.event(t, contentTypeJSON, "{}", time.Now())
+
+			for _, tt := range types {
+				target := seedTarget(t, f.db, f.webhook.ID, tt)
+				f.attempt(t, f.delivery(
+					t, event, target.ID,
+					database.DeliveryStatusDelivered,
+				), 200, time.Second)
+			}
+
+			body := f.render(t)
+
+			assert.Contains(t, body, `title="Body size"`)
+			assert.NotContains(t, body, statusTitle)
+		})
+	}
+}

internal/handlers/source_management.go

@@ -415,16 +415,21 @@ func (h *Handlers) renderSourceDetail(
 		"webhook_id = ?", webhook.ID,
 	).Find(&targets)
 
-	var events []database.Event
+	var events []RecentEventView
 
 	if h.dbMgr.DBExists(webhook.ID) {
 		webhookDB, dbErr := h.dbMgr.GetDB(webhook.ID)
 		if dbErr == nil {
-			webhookDB.Where(
-				"webhook_id = ?", webhook.ID,
-			).Order("created_at DESC").Limit(
-				recentEventLimit,
-			).Find(&events)
+			events, dbErr = h.loadRecentEvents(
+				webhookDB, webhook.ID, singleHTTPTargetID(targets),
+			)
+		}
+
+		if dbErr != nil {
+			h.log.Error(
+				"failed to load recent events",
+				"webhook_id", webhook.ID, "error", dbErr,
+			)
 		}
 	}
 

templates/source_detail.html

@@ -187,12 +187,24 @@
         <div class="divide-y divide-gray-100">
             {{range .Events}}
             <div class="p-4">
-                <div class="flex items-center justify-between">
-                    <div class="flex items-center gap-3">
+                <div class="flex flex-wrap items-center justify-between gap-3">
+                    <div class="flex flex-wrap items-center gap-3">
                         <span class="badge-info">{{.Method}}</span>
-                        <span class="text-sm text-gray-500">{{.ContentType}}</span>
+                        <span class="text-sm text-gray-500 break-all">{{.ContentType}}</span>
+                        {{if .ResubmittedFromID}}
+                        <span class="text-xs text-gray-500" title="This event is a copy of {{.ResubmittedFromID}}">resubmitted copy</span>
+                        {{end}}
+                    </div>
+                    <div class="flex flex-wrap items-center gap-3 text-xs text-gray-400">
+                        <span title="Body size">{{.Size}}</span>
+                        {{if .ProcessingTime}}
+                        <span title="Processing time: how long the slowest delivery took, from being queued to its last attempt">{{.ProcessingTime}}</span>
+                        {{end}}
+                        {{if .Status}}
+                        <span class="font-medium {{.StatusClass}}" title="HTTP status from the HTTP target">{{.Status}}</span>
+                        {{end}}
+                        <span title="{{.ReceivedUTC}}">{{.Received}}</span>
                     </div>
-                    <span class="text-xs text-gray-400">{{.CreatedAt.Format "2006-01-02 15:04:05 UTC"}}</span>
                 </div>
             </div>
             {{else}}