From 7199fcfa0b2461cf32c14ff76b0cc6c57d7a3c18 Mon Sep 17 00:00:00 2001 From: sneak Date: Sat, 3 Oct 2026 00:52:03 +0000 Subject: [PATCH] Event log: show attempt and delivery times, label replays, zone event times (closes #386) Each attempt shows when it was recorded and each delivery when it was created, in the event log and on the event's page. The event log's event times read as the recent events list does: how long ago, with the full UTC time on hover. A delivery records whether Replay created it, in a new replay column added to the delivery model in place. Such a delivery is labelled a replay in the event's summary line and in both pages' delivery lists. Both pages draw a delivery's row from one shared template. 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 @@
Attempt {{.AttemptNum}} + {{.Ran}} {{if not .Success}}failure{{else if eq $.Target.Type "database"}}archived{{else if eq $.Target.Type "log"}}written to the log{{else}}success{{end}} {{/* A database or log target sends no HTTP request, so its attempts have no status code. */}} {{if not (eq $.Target.Type "database" "log")}} diff --git a/templates/delivery_row.html b/templates/delivery_row.html new file mode 100644 index 0000000..eaa33d2 --- /dev/null +++ b/templates/delivery_row.html @@ -0,0 +1,16 @@ +{{define "delivery_row"}} + + + + {{.Target.DisplayName}} + {{if .Replay}}replay{{end}} + {{with .Paused}}waiting: target paused after repeated failures, next try no earlier than {{.Until}} ({{.Relative}}){{else}}{{.Status}}{{end}} + + + created {{.Created}} + {{.AttemptCount}} attempt{{if ne .AttemptCount 1}}s{{end}} + + +{{end}} diff --git a/templates/event_detail.html b/templates/event_detail.html index 14241b1..3756cad 100644 --- a/templates/event_detail.html +++ b/templates/event_detail.html @@ -21,7 +21,7 @@
Received
-
{{.CreatedAt.UTC.Format "2006-01-02 15:04:05"}} UTC
+
{{.ReceivedUTC}}
Method
@@ -66,13 +66,7 @@
{{range .Deliveries}}
-
- {{.Target.DisplayName}} - - {{with .Paused}}waiting: target paused after repeated failures, next try no earlier than {{.Until}} ({{.Relative}}){{else}}{{.Status}}{{end}} - {{.AttemptCount}} attempt{{if ne .AttemptCount 1}}s{{end}} - -
+ {{template "delivery_row" .}}
{{template "delivery_attempts" .}}
diff --git a/templates/source_logs.html b/templates/source_logs.html index b1fce27..a87938c 100644 --- a/templates/source_logs.html +++ b/templates/source_logs.html @@ -33,10 +33,10 @@ {{range .Deliveries}} - {{.Target.DisplayName}}: {{if .Paused}}waiting{{else}}{{.Status}}{{end}} + {{.Target.DisplayName}}{{if .Replay}} (replay){{end}}: {{if .Paused}}waiting{{else}}{{.Status}}{{end}} {{end}} - {{.CreatedAt.Format "2006-01-02 15:04:05"}} + {{.Received}} @@ -64,17 +64,11 @@ {{range .Deliveries}}
- {{if and .Status.Terminal (not .Target.Deleted)}}
-- 2.54.0