Event log: show attempt and delivery times, label replays, zone event times (closes #386)

In the event log and on an event's page, attempts and deliveries showed no time, event times had no zone, and a replay looked like the original it repeated. Each attempt now shows when its result was recorded and each delivery when it was created, as how long ago with the full UTC time on hover, and the event log's event times read the same way. A delivery created by Replay records it in a new `replay` column and is labelled a replay in the event's summary line and its delivery list; replays made before this change are not labelled. A delivery's row is now drawn by one template, `delivery_row`, that both pages share.

Model: opus-5-5

internal/database/model_delivery.go

@@ -56,6 +56,10 @@ type Delivery struct {
 	// the index.
 	FinishedAt *time.Time `gorm:"index:idx_deliveries_status,priority:3" json:"finishedAt,omitempty"`
 
+	// Replay is set on a delivery created by the event log's Replay
+	// action, so the pages can tell it from the delivery it repeats.
+	Replay bool `gorm:"not null;default:false" json:"replay"`
+
 	// Relations. No model marshals the record it belongs to:
 	// Event.Deliveries and Target.Deliveries lead back here, and the
 	// JSON could loop.

internal/handlers/delivery_replay.go

@@ -282,6 +282,7 @@ func createReplayDelivery(
 		EventID:  event.ID,
 		TargetID: target.ID,
 		Status:   database.DeliveryStatusPending,
+		Replay:   true,
 	}
 
 	err := webhookDB.Transaction(func(tx *gorm.DB) error {

internal/handlers/delivery_replay_test.go

@@ -3,6 +3,7 @@ package handlers_test
 import (
 	"net/http"
 	"net/http/httptest"
+	"strings"
 	"testing"
 
 	"github.com/stretchr/testify/assert"
@@ -528,3 +529,58 @@ func TestHandleSourceLogs_RendersReplayControlAndBanner(t *testing.T) {
 	assert.NotContains(t, unknown, "alert-success")
 	assert.NotContains(t, unknown, "made-up")
 }
+
+// TestHandleDeliveryReplay_LabelsTheReplay proves a delivery created
+// by Replay is labelled as a replay in the event's summary line in the
+// event log, and in the list of the event's deliveries there and on
+// the event's page, while the delivery it repeats is not.
+func TestHandleDeliveryReplay_LabelsTheReplay(t *testing.T) {
+	t.Parallel()
+
+	var (
+		h     *handlers.Handlers
+		sess  *session.Session
+		db    *database.Database
+		dbMgr *database.WebhookDBManager
+	)
+
+	app := newTestApp(t, &h, &sess, &db, &dbMgr)
+	app.RequireStart()
+
+	t.Cleanup(app.RequireStop)
+
+	wh := seedWebhook(t, db)
+	tgt := seedConfiguredTarget(
+		t, db, wh.ID, database.TargetTypeHTTP,
+		`{"url":"`+replayTargetURL+`"}`,
+	)
+
+	event, original := seedFailedDelivery(t, dbMgr, wh.ID, tgt.ID)
+
+	w := postReplay(t, h, sess, wh.ID, original.ID)
+	require.Equal(t, http.StatusSeeOther, w.Code)
+
+	eventLog := renderSourceLogsPage(t, h, sess, wh.ID)
+
+	assert.Contains(t, eventLog, tgt.Name+": failed")
+	assert.Contains(t, eventLog, tgt.Name+" (replay): pending")
+
+	w = serveEventPage(t, h, sess, wh.ID, event.ID)
+	require.Equal(t, http.StatusOK, w.Code)
+
+	// In each delivery list a row names the target, then the label if
+	// it is a replay, then its status: the replay is still pending, the
+	// original failed.
+	replayRow := tgt.Name + `</span> ` +
+		`<span class="text-xs text-gray-500">replay</span> ` +
+		`<span class="text-xs text-gray-400">pending</span>`
+	originalRow := tgt.Name + `</span> ` +
+		`<span class="text-xs text-red-600">failed</span>`
+
+	for _, page := range []string{eventLog, w.Body.String()} {
+		page = strings.Join(strings.Fields(page), " ")
+
+		assert.Contains(t, page, replayRow)
+		assert.Contains(t, page, originalRow)
+	}
+}

internal/handlers/delivery_result_view.go

@@ -3,6 +3,7 @@ package handlers
 import (
 	"time"
 
+	"github.com/dustin/go-humanize"
 	"sneak.berlin/go/webhooker/internal/delivery"
 )
 
@@ -47,6 +48,11 @@ type DeliveryResultView struct {
 	AttemptNum int
 	Success    bool
 
+	// Ran is how long ago the attempt was recorded, and RanUTC the
+	// full timestamp the page shows on hover.
+	Ran    string
+	RanUTC string
+
 	// StatusCode is 0 when the attempt never got a response,
 	// which is why the page asks HasStatusCode rather than
 	// printing the number.
@@ -160,6 +166,8 @@ func (r *deliveryResultRow) view(
 	return DeliveryResultView{
 		AttemptNum:         r.AttemptNum,
 		Success:            r.Success,
+		Ran:                humanize.Time(r.CreatedAt),
+		RanUTC:             r.CreatedAt.UTC().Format(time.DateTime) + " UTC",
 		StatusCode:         r.StatusCode,
 		Error:              redactor.Redact(r.Error),
 		DurationMS:         r.Duration,

internal/handlers/event_log_times_test.go

@@ -0,0 +1,52 @@
+package handlers_test
+
+import (
+	"net/http"
+	"testing"
+	"time"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+	"sneak.berlin/go/webhooker/internal/database"
+)
+
+// TestEventLog_TimesCarryTheirZone proves that the event log shows
+// when an event arrived, and that it and the event's page show when
+// each delivery was created and each attempt recorded: each as how
+// long ago, with the full UTC time on hover.
+func TestEventLog_TimesCarryTheirZone(t *testing.T) {
+	t.Parallel()
+
+	f := newRecentEventsFixture(t)
+	target := seedTarget(t, f.db, f.webhook.ID, database.TargetTypeHTTP)
+
+	now := time.Now().UTC().Truncate(time.Second)
+	receivedAt := now.Add(-3 * time.Hour)
+	createdAt := now.Add(-90 * time.Minute)
+	ranAt := now.Add(-30 * time.Minute)
+
+	event := f.event(t, contentTypeJSON, "{}", receivedAt)
+	dlv := f.deliveryQueuedAt(
+		t, event, target.ID, database.DeliveryStatusDelivered, createdAt,
+	)
+	f.attempt(t, dlv, http.StatusOK, ranAt.Sub(createdAt))
+
+	w := serveEventPage(t, f.h, f.sess, f.webhook.ID, event.ID)
+	require.Equal(t, http.StatusOK, w.Code)
+
+	eventPage := w.Body.String()
+	eventLog := renderSourceLogsPage(t, f.h, f.sess, f.webhook.ID)
+
+	received := receivedAt.Format(time.DateTime)
+	assert.Contains(t, eventLog, `title="`+received+` UTC">3 hours ago</span>`)
+	assert.NotContains(t, eventLog, received+"</span>",
+		"an event's time must not be written without its zone")
+	assert.Contains(t, eventPage, received+" UTC")
+
+	for _, page := range []string{eventLog, eventPage} {
+		assert.Contains(t, page, `title="`+createdAt.Format(time.DateTime)+
+			` UTC">created 1 hour ago</span>`)
+		assert.Contains(t, page, `title="`+ranAt.Format(time.DateTime)+
+			` UTC">30 minutes ago</span>`)
+	}
+}

internal/handlers/event_log_view.go

@@ -3,6 +3,8 @@ package handlers
 import (
 	"time"
 	"unicode/utf8"
+
+	"github.com/dustin/go-humanize"
 )
 
 // eventLogColumns is the event log's projection. The casts to
@@ -28,10 +30,14 @@ const eventColumns = "id, created_at, method, content_type, " +
 // DeliveryView and TargetView.
 type EventLogView struct {
 	ID          string
-	CreatedAt   time.Time
 	Method      string
 	ContentType string
 
+	// Received is how long ago the event arrived, and ReceivedUTC
+	// the full timestamp.
+	Received    string
+	ReceivedUTC string
+
 	Body BodyView
 
 	// ResubmittedFromID names the event this one was copied
@@ -77,9 +83,10 @@ func (r *eventLogRow) view(webhookID string) EventLogView {
 
 	return EventLogView{
 		ID:          r.ID,
-		CreatedAt:   r.CreatedAt,
 		Method:      r.Method,
 		ContentType: r.ContentType,
+		Received:    humanize.Time(r.CreatedAt),
+		ReceivedUTC: r.CreatedAt.UTC().Format(time.DateTime) + " UTC",
 		Body: newBodyView(
 			"/hook/"+webhookID+"/events/"+r.ID, r.Body, r.BodyBytes,
 		),

internal/handlers/handlers.go

@@ -165,10 +165,12 @@ func New(
 		),
 		"source_edit.html": parsePageTemplate("source_edit.html"),
 		"source_logs.html": parsePageTemplate(
-			"source_logs.html", "event_body.html", "delivery_attempts.html",
+			"source_logs.html", "event_body.html", "delivery_row.html",
+			"delivery_attempts.html",
 		),
 		"event_detail.html": parsePageTemplate(
-			"event_detail.html", "event_body.html", "delivery_attempts.html",
+			"event_detail.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

@@ -11,6 +11,7 @@ import (
 	"strings"
 	"time"
 
+	"github.com/dustin/go-humanize"
 	"github.com/go-chi/chi"
 	"github.com/google/uuid"
 	"gorm.io/gorm"
@@ -95,6 +96,14 @@ type DeliveryView struct {
 	Status database.DeliveryStatus
 	Target delivery.TargetView
 
+	// Replay is set on a delivery the Replay action created.
+	Replay bool
+
+	// Created is how long ago the delivery was created, and
+	// CreatedUTC the full timestamp the page shows on hover.
+	Created    string
+	CreatedUTC string
+
 	// Results is this delivery's attempts in attempt order,
 	// bounded by maxRenderedAttempts. Without them a failure
 	// renders as the status word alone and says nothing about
@@ -1410,6 +1419,7 @@ func (h *Handlers) newDeliveryViews(
 	for i := range deliveries {
 		target := targetMap[deliveries[i].TargetID]
 		rows := attempts[deliveries[i].ID]
+		created := deliveries[i].CreatedAt
 
 		results, omitted := renderedAttempts(
 			rows, target.Redactor,
@@ -1419,6 +1429,9 @@ func (h *Handlers) newDeliveryViews(
 			ID:              deliveries[i].ID,
 			Status:          deliveries[i].Status,
 			Target:          target.View,
+			Replay:          deliveries[i].Replay,
+			Created:         humanize.Time(created),
+			CreatedUTC:      created.UTC().Format(time.DateTime) + " UTC",
 			Results:         results,
 			AttemptCount:    len(rows),
 			AttemptsOmitted: omitted,

internal/handlers/target_list.go

@@ -88,8 +88,7 @@ func (h *Handlers) deliveryPausedView(
 }
 
 // newPausedView is a PausedView of deliveries paused until the given
-// time. A time not on the current UTC day is written with its date, as
-// the event log writes its times.
+// time. A time not on the current UTC day is written with its date.
 func newPausedView(until time.Time) *PausedView {
 	until = until.UTC()