webhooker/internal/handlers/target_paused_test.go

package handlers_test

import (
	"net/http"
	"strings"
	"testing"
	"time"

	"github.com/stretchr/testify/assert"
	"github.com/stretchr/testify/require"
	"gorm.io/gorm/clause"
	"sneak.berlin/go/webhooker/internal/database"
	"sneak.berlin/go/webhooker/internal/delivery"
	"sneak.berlin/go/webhooker/internal/handlers"
	"sneak.berlin/go/webhooker/internal/session"
)

// cooldownEnds is how the pages write the end of a paused target's
// breaker's cooldown: the time in UTC, with its date when that falls on
// another UTC day, then how long that is from now.
const cooldownEnds = `(\d{4}-\d\d-\d\d )?\d\d:\d\d:\d\d UTC ` +
	`\(\d+ seconds from now\)`

// TestPausedTarget_ShownUntilBreakerCloses takes an http target's
// circuit breaker from open through half-open to closed.
//
// Open, the target's row on the webhook page says its deliveries are
// paused and until when, and each retrying delivery says it is waiting
// and why in the event log and on the event's page, with the earliest
// it can be tried next: the later of the cooldown's end and the end of
// its own backoff, with the date when that is another UTC day.
// Half-open, the row says deliveries are held while one delivery tests
// the target, with no time, and no delivery says it is waiting. Closed,
// the pages say neither. The delivered delivery and the log target are
// shown as before throughout.
func TestPausedTarget_ShownUntilBreakerCloses(t *testing.T) {
	t.Parallel()

	var (
		h        *handlers.Handlers
		sess     *session.Session
		db       *database.Database
		dbMgr    *database.WebhookDBManager
		breakers *testCircuitBreakers
	)

	app := newTestApp(t, &h, &sess, &db, &dbMgr, &breakers)
	app.RequireStart()

	t.Cleanup(app.RequireStop)

	wh := seedWebhook(t, db)
	target := seedTarget(t, db, wh.ID, database.TargetTypeHTTP)
	seedTarget(t, db, wh.ID, database.TargetTypeLog)

	retrying := seedStoredEvent(t, dbMgr, wh.ID, `{"n":1}`)
	addDelivery(t, dbMgr, wh.ID, retrying.ID, target.ID,
		database.DeliveryStatusRetrying)

	delivered := seedStoredEvent(t, dbMgr, wh.ID, `{"n":2}`)
	addDelivery(t, dbMgr, wh.ID, delivered.ID, target.ID,
		database.DeliveryStatusDelivered)

	// This delivery's 18th attempt failed a minute ago, so its own
	// backoff ends over a day from now: long after the cooldown, and on
	// another UTC day, so the page shows the date.
	backedOff := seedStoredEvent(t, dbMgr, wh.ID, `{"n":3}`)
	backedOffID := addDelivery(t, dbMgr, wh.ID, backedOff.ID, target.ID,
		database.DeliveryStatusRetrying)

	failedAt := time.Now().Add(-time.Minute).Truncate(time.Second)
	addFailedAttempt(t, dbMgr, wh.ID, backedOffID, 18, failedAt)

	backoffEnds := failedAt.Add(delivery.Backoff(18)).UTC().
		Format("2006-01-02 15:04:05") + " UTC (1 day from now)"

	const waiting = "waiting: target paused after repeated failures, " +
		"next try no earlier than "

	breakers.Set(target.ID, delivery.CircuitOpen, 30*time.Second)

	list := targetList(t, renderSourceDetailPage(t, h, sess, wh.ID))
	assert.Regexp(t, "t-http http Active Edit Deactivate Delete "+
		"Deliveries paused: after repeated failures, until "+cooldownEnds+
		", then one waiting delivery is sent to test the target while "+
		"the others wait at least one more cooldown", list)
	assert.Equal(t, 1, strings.Count(list, "Deliveries paused"))

	log := renderSourceLogsPage(t, h, sess, wh.ID)
	assert.Equal(t, 2, strings.Count(log, "t-http: waiting"))
	assert.Contains(t, log, "t-http: delivered")
	assert.Regexp(t, waiting+cooldownEnds, log)
	assert.Contains(t, log, waiting+backoffEnds)
	// No delivery shows as retrying; the Pending link's title says it.
	assert.NotRegexp(t, `t-http: retrying|>retrying<`, log)

	page := eventPage(t, h, sess, wh.ID, retrying.ID)
	assert.Regexp(t, waiting+cooldownEnds, page)
	assert.NotContains(t, page, "retrying")

	page = eventPage(t, h, sess, wh.ID, backedOff.ID)
	assert.Contains(t, page, waiting+backoffEnds)
	assert.NotContains(t, page, "seconds from now")

	breakers.Set(target.ID, delivery.CircuitHalfOpen, 0)

	list = targetList(t, renderSourceDetailPage(t, h, sess, wh.ID))
	assert.Contains(t, list, "t-http http Active Edit Deactivate Delete "+
		"Deliveries paused: held while one delivery tests whether the "+
		"target has recovered")
	// Not the whole list: the add target form above the rows says UTC.
	assert.NotContains(t, targetRow(list, "t-http", "t-log"), "UTC")

	assertRetryingNotWaiting(t, h, sess, wh.ID, retrying, backedOff)

	breakers.Set(target.ID, delivery.CircuitClosed, 0)

	list = targetList(t, renderSourceDetailPage(t, h, sess, wh.ID))
	assert.NotContains(t, list, "Deliveries paused")

	assertRetryingNotWaiting(t, h, sess, wh.ID, retrying, backedOff)
}

// targetRow returns the row of the target named name in a targetList:
// from its name to the name of the target listed after it, next.
func targetRow(list, name, next string) string {
	_, row, _ := strings.Cut(list, name+" ")
	row, _, _ = strings.Cut(row, next+" ")

	return row
}

// assertRetryingNotWaiting checks that the event log and each event's
// page show the http target's delivery of the event as retrying, and
// none of them as waiting.
func assertRetryingNotWaiting(
	t *testing.T,
	h *handlers.Handlers,
	sess *session.Session,
	webhookID string,
	events ...*database.Event,
) {
	t.Helper()

	log := renderSourceLogsPage(t, h, sess, webhookID)
	assert.Equal(t, len(events), strings.Count(log, "t-http: retrying"))
	assert.NotContains(t, log, "waiting")

	for _, event := range events {
		page := eventPage(t, h, sess, webhookID, event.ID)
		assert.Contains(t, page, ">retrying</span>")
		assert.NotContains(t, page, "waiting")
	}
}

// addDelivery records a delivery of the event to the target, with the
// given status, in the webhook's own database, and returns its ID.
func addDelivery(
	t *testing.T,
	dbMgr *database.WebhookDBManager,
	webhookID, eventID, targetID string,
	status database.DeliveryStatus,
) string {
	t.Helper()

	webhookDB, err := dbMgr.GetDB(webhookID)
	require.NoError(t, err)

	dlv := &database.Delivery{
		EventID:  eventID,
		TargetID: targetID,
		Status:   status,
	}

	require.NoError(t, webhookDB.Omit(clause.Associations).Create(
		dlv,
	).Error)

	return dlv.ID
}

// addFailedAttempt records the delivery's failed attempt attemptNum,
// made at the given time.
func addFailedAttempt(
	t *testing.T,
	dbMgr *database.WebhookDBManager,
	webhookID, deliveryID string,
	attemptNum int,
	at time.Time,
) {
	t.Helper()

	webhookDB, err := dbMgr.GetDB(webhookID)
	require.NoError(t, err)

	require.NoError(t, webhookDB.Omit(clause.Associations).Create(
		&database.DeliveryResult{
			BaseModel:  database.BaseModel{CreatedAt: at},
			DeliveryID: deliveryID,
			AttemptNum: attemptNum,
			Error:      "connection refused",
		},
	).Error)
}

// eventPage runs the real event page handler and returns the
// rendered HTML.
func eventPage(
	t *testing.T,
	h *handlers.Handlers,
	sess *session.Session,
	webhookID, eventID string,
) string {
	t.Helper()

	w := serveEventPage(t, h, sess, webhookID, eventID)
	require.Equal(t, http.StatusOK, w.Code)

	return w.Body.String()
}