diff --git a/README.md b/README.md index 2b2f6bc..1d38ba3 100644 --- a/README.md +++ b/README.md @@ -1830,6 +1830,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. @@ -1849,7 +1850,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 @@ -1903,6 +1905,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 be4c6d6..d3fc52f 100644 --- a/internal/handlers/delivery_replay.go +++ b/internal/handlers/delivery_replay.go @@ -283,6 +283,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..5f54af6 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,48 @@ 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) + + const label = `replay` + + for _, page := range []string{eventLog, w.Body.String()} { + assert.Equal(t, 1, strings.Count(page, label)) + } +} 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/source_management.go b/internal/handlers/source_management.go index 01dcb50..06a1465 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 @@ -1430,6 +1439,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, @@ -1439,6 +1449,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/event_detail.html b/templates/event_detail.html index 14241b1..07b0377 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
@@ -67,9 +67,13 @@ {{range .Deliveries}}
- {{.Target.DisplayName}} + + {{.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}}
diff --git a/templates/source_logs.html b/templates/source_logs.html index d18ae87..4422778 100644 --- a/templates/source_logs.html +++ b/templates/source_logs.html @@ -32,10 +32,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}} @@ -67,9 +67,11 @@ {{.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}}