From d8c60c9b67e5fae73bb0d0466cb96f891cd8dfbb Mon Sep 17 00:00:00 2001 From: clawbot <35+clawbot@noreply.example.org> Date: Sat, 3 Oct 2026 04:12:27 +0200 Subject: [PATCH] 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 --- README.md | 8 +++- internal/database/model_delivery.go | 4 ++ internal/handlers/delivery_replay.go | 1 + internal/handlers/delivery_replay_test.go | 56 +++++++++++++++++++++++ internal/handlers/delivery_result_view.go | 8 ++++ internal/handlers/event_log_times_test.go | 52 +++++++++++++++++++++ internal/handlers/event_log_view.go | 11 ++++- internal/handlers/handlers.go | 6 ++- internal/handlers/source_management.go | 13 ++++++ internal/handlers/target_list.go | 3 +- templates/delivery_attempts.html | 1 + templates/delivery_row.html | 16 +++++++ templates/event_detail.html | 10 +--- templates/source_logs.html | 20 +++----- 14 files changed, 181 insertions(+), 28 deletions(-) create mode 100644 internal/handlers/event_log_times_test.go create mode 100644 templates/delivery_row.html diff --git a/README.md b/README.md index 5576bf9..ef36bf5 100644 --- a/README.md +++ b/README.md @@ -1831,6 +1831,7 @@ status across potentially multiple attempts. | `target_id`| UUID | Foreign key → Target | | `status` | DeliveryStatus | One of: `pending`, `delivered`, `failed`, `retrying` | | `finished_at` | timestamp | When the delivery became `delivered` or `failed` (nullable; empty while `pending` or `retrying`) | +| `replay` | boolean | Whether the delivery was created by **Replay** | **Relations:** Belongs to Event. Belongs to Target. Has many DeliveryResults. @@ -1850,7 +1851,8 @@ NEW `pending` delivery for the same event and target and hands it to the engine on the ordinary path — same retries, same SSRF guard, same circuit breaker as a first attempt. It never touches the delivery it repeats: that row's status, timestamps and recorded attempts stand as -the record of what happened. +the record of what happened. The new delivery records `replay`, and the +event log and the event's page label it a replay. What is re-sent is the stored event body, against the target's configuration **as it stands now** — the point of a replay is to @@ -1904,6 +1906,10 @@ A `database` or `log` target sends no HTTP request, so in the event log and on the event's page its attempts show no status: a successful one reads "archived" or "written to the log". +The event log and the event's page show when each attempt was recorded and +when each delivery was created, as the recent events list shows when an event +arrived: how long ago, with the full UTC time on hover. + **Relations:** Belongs to Delivery. #### EventTotals, TargetTotals and EntrypointTotals diff --git a/internal/database/model_delivery.go b/internal/database/model_delivery.go index ffaba8a..5f22557 100644 --- a/internal/database/model_delivery.go +++ b/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. diff --git a/internal/handlers/delivery_replay.go b/internal/handlers/delivery_replay.go index 4d0473a..48f7f5b 100644 --- a/internal/handlers/delivery_replay.go +++ b/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 { diff --git a/internal/handlers/delivery_replay_test.go b/internal/handlers/delivery_replay_test.go index 332aa59..2c4865a 100644 --- a/internal/handlers/delivery_replay_test.go +++ b/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 + ` ` + + `replay ` + + `pending` + originalRow := tgt.Name + ` ` + + `failed` + + for _, page := range []string{eventLog, w.Body.String()} { + page = strings.Join(strings.Fields(page), " ") + + assert.Contains(t, page, replayRow) + assert.Contains(t, page, originalRow) + } +} diff --git a/internal/handlers/delivery_result_view.go b/internal/handlers/delivery_result_view.go index 4b0e51f..f635b92 100644 --- a/internal/handlers/delivery_result_view.go +++ b/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, diff --git a/internal/handlers/event_log_times_test.go b/internal/handlers/event_log_times_test.go new file mode 100644 index 0000000..7066c95 --- /dev/null +++ b/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`) + assert.NotContains(t, eventLog, received+"", + "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`) + assert.Contains(t, page, `title="`+ranAt.Format(time.DateTime)+ + ` UTC">30 minutes ago`) + } +} diff --git a/internal/handlers/event_log_view.go b/internal/handlers/event_log_view.go index 3079493..4a3446e 100644 --- a/internal/handlers/event_log_view.go +++ b/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, ), diff --git a/internal/handlers/handlers.go b/internal/handlers/handlers.go index 151d8c4..c1d52db 100644 --- a/internal/handlers/handlers.go +++ b/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"), diff --git a/internal/handlers/source_management.go b/internal/handlers/source_management.go index 121689b..8b3fe1d 100644 --- a/internal/handlers/source_management.go +++ b/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, diff --git a/internal/handlers/target_list.go b/internal/handlers/target_list.go index 9333b2e..f6a3cad 100644 --- a/internal/handlers/target_list.go +++ b/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() diff --git a/templates/delivery_attempts.html b/templates/delivery_attempts.html index 59d3b72..835efd0 100644 --- a/templates/delivery_attempts.html +++ b/templates/delivery_attempts.html @@ -9,6 +9,7 @@