diff --git a/go.mod b/go.mod index d301134a8..cf6bd0a19 100644 --- a/go.mod +++ b/go.mod @@ -196,7 +196,6 @@ require ( github.com/spf13/afero v1.15.0 // indirect github.com/spf13/cast v1.10.0 // indirect github.com/spf13/pflag v1.0.10 // indirect - github.com/stretchr/objx v0.5.3 // indirect github.com/subosito/gotenv v1.6.0 // indirect github.com/tklauser/go-sysconf v0.4.0 // indirect github.com/tklauser/numcpus v0.12.0 // indirect diff --git a/internal/alert/evaluator.go b/internal/alert/evaluator.go index 92386e960..dd43d26c6 100644 --- a/internal/alert/evaluator.go +++ b/internal/alert/evaluator.go @@ -1,90 +1,150 @@ +// Package alert tracks delivery health per destination: consecutive-failure +// counting, alert thresholds, and retry exhaustion. It is a pure tracker — it +// returns signals as data and performs no side effects outside its own state. +// Acting on the signals (operator events, auto-disable, replay dedup) is the +// caller's job. package alert import ( - "sort" + "context" + "fmt" ) -// AlertEvaluator determines when alerts should be triggered -type AlertEvaluator interface { - // ShouldAlert determines if an alert should be sent and returns the alert level - ShouldAlert(failures int) (level int, shouldAlert bool) +// Attempt is the tracker's input: the identity and outcome of one delivery +// attempt, nothing more. +type Attempt struct { + TenantID string + DestinationID string + AttemptID string + Number int // 1-indexed attempt number + Success bool + EligibleForRetry bool } -type thresholdPair struct { - percentage int - failures int +// Evaluation is the tracker's verdict on one attempt: one field per signal +// kind, nil/false when that kind has nothing to report. An attempt can carry +// several signals at once. Zero value = nothing to report (success, or a +// failure that crossed no threshold and exhausted no retries). +type Evaluation struct { + // ConsecutiveFailure is non-nil when this attempt's consecutive-failure + // count crossed an alert threshold. + ConsecutiveFailure *ConsecutiveFailureSignal + // RetriesExhausted reports that this attempt exceeded the retry budget for + // a retry-eligible event. + RetriesExhausted bool } -type alertEvaluator struct { - thresholds []thresholdPair // sorted pairs of percentage and failure counts - autoDisableFailureCount int +// ConsecutiveFailureSignal reports a crossed consecutive-failure threshold. +type ConsecutiveFailureSignal struct { + Failures int // current consecutive-failure count + Max int // configured 100%-threshold failure count + Level int // crossed threshold's percentage (e.g. 50/70/90/100) } -// NewAlertEvaluator creates a new alert evaluator -func NewAlertEvaluator(thresholds []int, autoDisableFailureCount int) AlertEvaluator { - // Create pairs of percentage thresholds and their corresponding failure counts - finalThresholds := make([]thresholdPair, 0, len(thresholds)) +// Option configures an evaluator. +type Option func(*Evaluator) - // Convert percentages to failure counts - for _, percentage := range thresholds { - // Skip invalid percentages - if percentage <= 0 || percentage > 100 { - continue - } - // Ceiling division: (a + b - 1) / b - failures := (int(autoDisableFailureCount)*int(percentage) + 99) / 100 - finalThresholds = append(finalThresholds, thresholdPair{ - percentage: percentage, - failures: failures, - }) +// WithAutoDisableFailureCount sets the consecutive-failure count that means +// 100% — the denominator for threshold math. +func WithAutoDisableFailureCount(count int) Option { + return func(e *Evaluator) { + e.autoDisableFailureCount = count } +} - sort.Slice(finalThresholds, func(i, j int) bool { return finalThresholds[i].failures < finalThresholds[j].failures }) +// WithAlertThresholds sets the percentage thresholds at which alerts fire. +func WithAlertThresholds(thresholds []int) Option { + return func(e *Evaluator) { + e.alertThresholds = thresholds + } +} - // Check if we need to add 100 - needsAutoDisable := true - if len(finalThresholds) > 0 && finalThresholds[len(finalThresholds)-1].percentage == 100 { - needsAutoDisable = false +// WithConsecutiveFailureEnabled toggles consecutive-failure tracking. When set +// to false the evaluator never tracks failures or crosses thresholds. +// Defaults to true. +func WithConsecutiveFailureEnabled(enabled bool) Option { + return func(e *Evaluator) { + e.consecutiveFailureEnabled = enabled } +} - // Auto-include 100% threshold if not present - if needsAutoDisable { - finalThresholds = append(finalThresholds, thresholdPair{ - percentage: 100, - failures: autoDisableFailureCount, - }) +// WithExhaustedRetriesEnabled toggles the retry-exhaustion signal. Defaults to +// true. +func WithExhaustedRetriesEnabled(enabled bool) Option { + return func(e *Evaluator) { + e.exhaustedRetriesEnabled = enabled } +} + +// Evaluator evaluates delivery attempts against the destination's failure +// history and returns the resulting signals as data. +type Evaluator struct { + store AlertStore + thresholds thresholdEvaluator + + autoDisableFailureCount int + alertThresholds []int + retryMaxLimit int + + consecutiveFailureEnabled bool + exhaustedRetriesEnabled bool +} - return &alertEvaluator{ - thresholds: finalThresholds, - autoDisableFailureCount: autoDisableFailureCount, +// NewEvaluator creates a new alert evaluator on the given store. +func NewEvaluator(store AlertStore, retryMaxLimit int, opts ...Option) *Evaluator { + e := &Evaluator{ + store: store, + retryMaxLimit: retryMaxLimit, + alertThresholds: []int{50, 70, 90, 100}, // default thresholds + consecutiveFailureEnabled: true, + exhaustedRetriesEnabled: true, } + + for _, opt := range opts { + opt(e) + } + + e.thresholds = newThresholdEvaluator(e.alertThresholds, e.autoDisableFailureCount) + + return e } -func (e *alertEvaluator) ShouldAlert(failures int) (int, bool) { - // If no thresholds configured, never alert - if len(e.thresholds) == 0 { - return 0, false +func (e *Evaluator) Evaluate(ctx context.Context, attempt Attempt) (Evaluation, error) { + if attempt.Success { + // Nothing is tracked when consecutive-failure tracking is disabled, so + // there is no count to reset. + if !e.consecutiveFailureEnabled { + return Evaluation{}, nil + } + if err := e.store.ResetConsecutiveFailureCount(ctx, attempt.TenantID, attempt.DestinationID); err != nil { + return Evaluation{}, err + } + return Evaluation{}, nil } - // Get current alert level - // Iterate from highest to lowest threshold - for i := len(e.thresholds) - 1; i >= 0; i-- { - threshold := e.thresholds[i] - - // For the 100% threshold (auto-disable), use >= to ensure we don't miss it - // if concurrent processing causes us to skip over the exact count. - // For other thresholds, use exact match to avoid duplicate alerts. - if threshold.percentage == 100 { - if failures >= threshold.failures { - return threshold.percentage, true - } - } else { - if failures == threshold.failures { - return threshold.percentage, true + var eval Evaluation + + if e.consecutiveFailureEnabled { + count, err := e.store.IncrementConsecutiveFailureCount(ctx, attempt.TenantID, attempt.DestinationID, attempt.AttemptID) + if err != nil { + return Evaluation{}, fmt.Errorf("failed to track consecutive failures: %w", err) + } + if level, crossed := e.thresholds.shouldAlert(count); crossed { + eval.ConsecutiveFailure = &ConsecutiveFailureSignal{ + Failures: count, + Max: e.autoDisableFailureCount, + Level: level, } } } - return 0, false + // Exhausted retries check (independent of consecutive failure thresholds). + // Attempt is 1-indexed: with retryMaxLimit=10, attempt 11 is the final one. + // Skip if retryMaxLimit=0 (retries disabled — no exhausted state to report) + // or if the exhausted-retries signal is disabled. + if e.exhaustedRetriesEnabled && e.retryMaxLimit > 0 && attempt.EligibleForRetry && attempt.Number > e.retryMaxLimit { + eval.RetriesExhausted = true + } + + return eval, nil } diff --git a/internal/alert/evaluator_test.go b/internal/alert/evaluator_test.go new file mode 100644 index 000000000..2a6998836 --- /dev/null +++ b/internal/alert/evaluator_test.go @@ -0,0 +1,299 @@ +package alert_test + +import ( + "context" + "fmt" + "testing" + + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" + + "github.com/hookdeck/outpost/internal/alert" + "github.com/hookdeck/outpost/internal/util/testutil" +) + +func failedAttempt(destID, tenantID, attemptID string) alert.Attempt { + return alert.Attempt{ + TenantID: tenantID, + DestinationID: destID, + AttemptID: attemptID, + Number: 1, + Success: false, + } +} + +func successAttempt(destID, tenantID string) alert.Attempt { + return alert.Attempt{ + TenantID: tenantID, + DestinationID: destID, + AttemptID: "att_success", + Number: 1, + Success: true, + } +} + +// crossedLevels runs failed attempts (attempt IDs att_..att_) and +// collects the threshold levels crossed, in order. +func crossedLevels(t *testing.T, ctx context.Context, e *alert.Evaluator, destID, tenantID string, from, to int) []int { + t.Helper() + var levels []int + for i := from; i <= to; i++ { + eval, err := e.Evaluate(ctx, failedAttempt(destID, tenantID, fmt.Sprintf("att_%d", i))) + require.NoError(t, err) + if sig := eval.ConsecutiveFailure; sig != nil { + levels = append(levels, sig.Level) + } + } + return levels +} + +func TestEvaluator_ThresholdCrossings(t *testing.T) { + t.Parallel() + ctx := context.Background() + redisClient := testutil.CreateTestRedisClient(t) + + e := alert.NewEvaluator( + alert.NewRedisAlertStore(redisClient, ""), + 10, + alert.WithAutoDisableFailureCount(20), + alert.WithAlertThresholds([]int{50, 66, 90, 100}), + ) + + levels := crossedLevels(t, ctx, e, "dest_1", "tenant_1", 1, 20) + assert.Equal(t, []int{50, 66, 90, 100}, levels, "each configured threshold crosses exactly once on the way to 100%") +} + +func TestEvaluator_AboveMaxKeepsCrossing(t *testing.T) { + // Past the 100% count, every further failure reports the 100% threshold + // (>= match), so the caller keeps disabling/alerting. + t.Parallel() + ctx := context.Background() + redisClient := testutil.CreateTestRedisClient(t) + + e := alert.NewEvaluator( + alert.NewRedisAlertStore(redisClient, ""), + 10, + alert.WithAutoDisableFailureCount(20), + alert.WithAlertThresholds([]int{50, 70, 90, 100}), + ) + + levels := crossedLevels(t, ctx, e, "dest_above", "tenant_above", 1, 25) + assert.Equal(t, []int{50, 70, 90, 100, 100, 100, 100, 100, 100}, levels) +} + +func TestEvaluator_CountAndMaxFailures(t *testing.T) { + t.Parallel() + ctx := context.Background() + redisClient := testutil.CreateTestRedisClient(t) + + e := alert.NewEvaluator( + alert.NewRedisAlertStore(redisClient, ""), + 10, + alert.WithAutoDisableFailureCount(4), + alert.WithAlertThresholds([]int{50, 100}), + ) + + eval, err := e.Evaluate(ctx, failedAttempt("dest_cm", "tenant_cm", "att_1")) + require.NoError(t, err) + assert.Nil(t, eval.ConsecutiveFailure, "1/4 crosses nothing") + + eval, err = e.Evaluate(ctx, failedAttempt("dest_cm", "tenant_cm", "att_2")) + require.NoError(t, err) + require.NotNil(t, eval.ConsecutiveFailure, "2/4 = 50%") + assert.Equal(t, alert.ConsecutiveFailureSignal{Failures: 2, Max: 4, Level: 50}, *eval.ConsecutiveFailure) +} + +func TestEvaluator_SuccessResets(t *testing.T) { + t.Parallel() + ctx := context.Background() + redisClient := testutil.CreateTestRedisClient(t) + + e := alert.NewEvaluator( + alert.NewRedisAlertStore(redisClient, ""), + 10, + alert.WithAutoDisableFailureCount(20), + alert.WithAlertThresholds([]int{50, 66, 90, 100}), + ) + + levels := crossedLevels(t, ctx, e, "dest_reset", "tenant_reset", 1, 14) + require.Equal(t, []int{50, 66}, levels) + + eval, err := e.Evaluate(ctx, successAttempt("dest_reset", "tenant_reset")) + require.NoError(t, err) + assert.Equal(t, alert.Evaluation{}, eval, "success reports nothing") + + // The count restarts: the same thresholds cross again. + levels = crossedLevels(t, ctx, e, "dest_reset", "tenant_reset", 15, 28) + assert.Equal(t, []int{50, 66}, levels) +} + +func TestEvaluator_ReplayedAttemptDoesNotDoubleCount(t *testing.T) { + // Counting is idempotent per attempt ID. A replayed attempt reports the + // same verdict again — replay dedup of downstream effects is the delivery + // layer's job, not the tracker's. + t.Parallel() + ctx := context.Background() + redisClient := testutil.CreateTestRedisClient(t) + + e := alert.NewEvaluator( + alert.NewRedisAlertStore(redisClient, ""), + 10, + alert.WithAutoDisableFailureCount(2), + alert.WithAlertThresholds([]int{50, 100}), + ) + + first, err := e.Evaluate(ctx, failedAttempt("dest_replay", "tenant_replay", "att_1")) + require.NoError(t, err) + require.NotNil(t, first.ConsecutiveFailure) + require.Equal(t, alert.ConsecutiveFailureSignal{Failures: 1, Max: 2, Level: 50}, *first.ConsecutiveFailure) + + replay, err := e.Evaluate(ctx, failedAttempt("dest_replay", "tenant_replay", "att_1")) + require.NoError(t, err) + assert.Equal(t, first, replay, "replay reports the same verdict without double-counting") +} + +func TestEvaluator_RetriesExhausted(t *testing.T) { + t.Parallel() + ctx := context.Background() + redisClient := testutil.CreateTestRedisClient(t) + + retryMaxLimit := 3 + e := alert.NewEvaluator( + alert.NewRedisAlertStore(redisClient, ""), + retryMaxLimit, + alert.WithAutoDisableFailureCount(100), // high so cf thresholds don't interfere + ) + + // Attempts 1-3: within retry budget. + for i := 1; i <= 3; i++ { + a := failedAttempt("dest_er", "tenant_er", fmt.Sprintf("att_%d", i)) + a.Number = i + a.EligibleForRetry = true + eval, err := e.Evaluate(ctx, a) + require.NoError(t, err) + assert.False(t, eval.RetriesExhausted, "attempt %d is within the retry budget", i) + } + + // Attempt 4: exceeds retryMaxLimit=3. + a := failedAttempt("dest_er", "tenant_er", "att_4") + a.Number = 4 + a.EligibleForRetry = true + eval, err := e.Evaluate(ctx, a) + require.NoError(t, err) + assert.True(t, eval.RetriesExhausted) +} + +func TestEvaluator_RetriesExhausted_NotEligible(t *testing.T) { + t.Parallel() + ctx := context.Background() + redisClient := testutil.CreateTestRedisClient(t) + + e := alert.NewEvaluator( + alert.NewRedisAlertStore(redisClient, ""), + 3, + alert.WithAutoDisableFailureCount(100), + ) + + a := failedAttempt("dest_ne", "tenant_ne", "att_4") + a.Number = 4 + a.EligibleForRetry = false + eval, err := e.Evaluate(ctx, a) + require.NoError(t, err) + assert.False(t, eval.RetriesExhausted, "no exhaustion when the event is not eligible for retry") +} + +func TestEvaluator_RetriesExhausted_RetriesDisabled(t *testing.T) { + // retryMaxLimit=0 means retries are disabled — there is no exhausted state. + t.Parallel() + ctx := context.Background() + redisClient := testutil.CreateTestRedisClient(t) + + e := alert.NewEvaluator( + alert.NewRedisAlertStore(redisClient, ""), + 0, + alert.WithAutoDisableFailureCount(100), + ) + + a := failedAttempt("dest_rd", "tenant_rd", "att_1") + a.Number = 5 + a.EligibleForRetry = true + eval, err := e.Evaluate(ctx, a) + require.NoError(t, err) + assert.False(t, eval.RetriesExhausted) +} + +func TestEvaluator_ConsecutiveFailure_Disabled(t *testing.T) { + // With consecutive-failure tracking disabled, failures never count and + // never cross thresholds. + t.Parallel() + ctx := context.Background() + redisClient := testutil.CreateTestRedisClient(t) + + e := alert.NewEvaluator( + alert.NewRedisAlertStore(redisClient, ""), + 10, + alert.WithAutoDisableFailureCount(5), + alert.WithConsecutiveFailureEnabled(false), + ) + + for i := 1; i <= 10; i++ { + eval, err := e.Evaluate(ctx, failedAttempt("dest_cf_off", "tenant_cf_off", fmt.Sprintf("att_%d", i))) + require.NoError(t, err) + assert.Nil(t, eval.ConsecutiveFailure) + } + + // Success has nothing to reset and reports nothing. + eval, err := e.Evaluate(ctx, successAttempt("dest_cf_off", "tenant_cf_off")) + require.NoError(t, err) + assert.Equal(t, alert.Evaluation{}, eval) +} + +func TestEvaluator_ExhaustedRetries_Disabled(t *testing.T) { + t.Parallel() + ctx := context.Background() + redisClient := testutil.CreateTestRedisClient(t) + + e := alert.NewEvaluator( + alert.NewRedisAlertStore(redisClient, ""), + 3, + alert.WithAutoDisableFailureCount(100), + alert.WithExhaustedRetriesEnabled(false), + ) + + a := failedAttempt("dest_er_off", "tenant_er_off", "att_4") + a.Number = 4 + a.EligibleForRetry = true + eval, err := e.Evaluate(ctx, a) + require.NoError(t, err) + assert.False(t, eval.RetriesExhausted, "no exhaustion signal when disabled") +} + +func TestEvaluator_Gates_Independent(t *testing.T) { + // Consecutive-failure tracking off, exhausted-retries on: exhaustion still + // fires while the count stays silent. + t.Parallel() + ctx := context.Background() + redisClient := testutil.CreateTestRedisClient(t) + + e := alert.NewEvaluator( + alert.NewRedisAlertStore(redisClient, ""), + 3, + alert.WithAutoDisableFailureCount(5), + alert.WithConsecutiveFailureEnabled(false), + alert.WithExhaustedRetriesEnabled(true), + ) + + var exhausted int + for i := 1; i <= 6; i++ { + a := failedAttempt("dest_mix", "tenant_mix", fmt.Sprintf("att_%d", i)) + a.Number = i + a.EligibleForRetry = true + eval, err := e.Evaluate(ctx, a) + require.NoError(t, err) + assert.Nil(t, eval.ConsecutiveFailure, "consecutive_failure stays silent when its gate is off") + if eval.RetriesExhausted { + exhausted++ + } + } + assert.Greater(t, exhausted, 0, "exhausted_retries still fires when its gate is on") +} diff --git a/internal/alert/monitor.go b/internal/alert/monitor.go deleted file mode 100644 index 4d9f45a22..000000000 --- a/internal/alert/monitor.go +++ /dev/null @@ -1,333 +0,0 @@ -package alert - -import ( - "context" - "fmt" - "time" - - "github.com/hookdeck/outpost/internal/idempotence" - "github.com/hookdeck/outpost/internal/logging" - "github.com/hookdeck/outpost/internal/models" - "github.com/hookdeck/outpost/internal/opevents" - "github.com/redis/go-redis/v9" - "go.uber.org/zap" -) - -// AlertEmitter is the interface for emitting alert events. Satisfied by opevents.Emitter. -type AlertEmitter interface { - Emit(ctx context.Context, topic string, tenantID string, data any) error -} - -// DestinationDisabler handles disabling destinations. -type DestinationDisabler interface { - DisableDestination(ctx context.Context, tenantID, destinationID string) error -} - -// AlertMonitor is the main interface for handling delivery attempt alerts -type AlertMonitor interface { - HandleAttempt(ctx context.Context, attempt DeliveryAttempt) error -} - -// AlertOption is a function that configures an AlertConfig -type AlertOption func(*alertMonitor) - -// WithAutoDisableFailureCount sets the number of consecutive failures before auto-disabling -func WithAutoDisableFailureCount(count int) AlertOption { - return func(c *alertMonitor) { - c.autoDisableFailureCount = count - } -} - -// WithAlertThresholds sets the percentage thresholds at which to send alerts -func WithAlertThresholds(thresholds []int) AlertOption { - return func(c *alertMonitor) { - c.alertThresholds = thresholds - } -} - -// WithStore sets the alert store for the monitor -func WithStore(store AlertStore) AlertOption { - return func(m *alertMonitor) { - m.store = store - } -} - -// WithEvaluator sets the alert evaluator for the monitor -func WithEvaluator(evaluator AlertEvaluator) AlertOption { - return func(m *alertMonitor) { - m.evaluator = evaluator - } -} - -// WithDisabler sets the destination disabler for the monitor. -// When set, destinations are auto-disabled at the 100% failure threshold. -func WithDisabler(disabler DestinationDisabler) AlertOption { - return func(m *alertMonitor) { - m.disabler = disabler - } -} - -// WithLogger sets the logger for the monitor -func WithLogger(logger *logging.Logger) AlertOption { - return func(m *alertMonitor) { - m.logger = logger - } -} - -// WithDeploymentID sets the deployment ID for the monitor -func WithDeploymentID(deploymentID string) AlertOption { - return func(m *alertMonitor) { - m.deploymentID = deploymentID - } -} - -// WithExhaustedRetriesIdempotence sets the idempotence instance for -// exhausted_retries suppression. When set, only the first exhaustion per -// destination within the TTL window emits an alert. -func WithExhaustedRetriesIdempotence(idemp idempotence.Idempotence) AlertOption { - return func(m *alertMonitor) { - m.exhaustedRetryIdemp = idemp - } -} - -// WithConsecutiveFailureEnabled toggles consecutive-failure alerting. When set -// to false the monitor never tracks or alerts on consecutive failures (and -// therefore never auto-disables). Defaults to true. -func WithConsecutiveFailureEnabled(enabled bool) AlertOption { - return func(m *alertMonitor) { - m.consecutiveFailureEnabled = enabled - } -} - -// WithExhaustedRetriesEnabled toggles exhausted_retries alerting. When set to -// false the monitor never emits exhausted_retries alerts. Defaults to true. -func WithExhaustedRetriesEnabled(enabled bool) AlertOption { - return func(m *alertMonitor) { - m.exhaustedRetriesEnabled = enabled - } -} - -// DeliveryAttempt represents a single delivery attempt -type DeliveryAttempt struct { - Event *models.Event - Destination *AlertDestination - Attempt *models.Attempt -} - -type alertMonitor struct { - logger *logging.Logger - store AlertStore - evaluator AlertEvaluator - emitter AlertEmitter - disabler DestinationDisabler - deploymentID string - - autoDisableFailureCount int - alertThresholds []int - retryMaxLimit int - exhaustedRetryIdemp idempotence.Idempotence - - consecutiveFailureEnabled bool - exhaustedRetriesEnabled bool -} - -// NewAlertMonitor creates a new alert monitor. Emitter and retryMaxLimit are -// required — callers that don't need alerts should pass nil AlertMonitor to -// consumers instead. -func NewAlertMonitor(logger *logging.Logger, redisClient redis.Cmdable, emitter AlertEmitter, retryMaxLimit int, opts ...AlertOption) AlertMonitor { - if emitter == nil { - panic("alert: NewAlertMonitor requires a non-nil emitter") - } - alertMonitor := &alertMonitor{ - logger: logger, - emitter: emitter, - retryMaxLimit: retryMaxLimit, - alertThresholds: []int{50, 70, 90, 100}, // default thresholds - consecutiveFailureEnabled: true, - exhaustedRetriesEnabled: true, - } - - for _, opt := range opts { - opt(alertMonitor) - } - - if alertMonitor.store == nil { - alertMonitor.store = NewRedisAlertStore(redisClient, alertMonitor.deploymentID) - } - - if alertMonitor.evaluator == nil { - alertMonitor.evaluator = NewAlertEvaluator(alertMonitor.alertThresholds, alertMonitor.autoDisableFailureCount) - } - - return alertMonitor -} - -func (m *alertMonitor) HandleAttempt(ctx context.Context, attempt DeliveryAttempt) error { - if attempt.Attempt.Status == models.AttemptStatusSuccess { - // Nothing is tracked when consecutive-failure alerting is disabled, so - // there is no count to reset. - if !m.consecutiveFailureEnabled { - return nil - } - return m.store.ResetConsecutiveFailureCount(ctx, attempt.Destination.TenantID, attempt.Destination.ID) - } - - if m.consecutiveFailureEnabled { - // A replayed attempt that already completed evaluation skips the rest of - // the pipeline (exhausted-retries check and the evaluated mark), matching - // the original single-pass behavior. - done, err := m.handleConsecutiveFailure(ctx, attempt) - if err != nil { - return err - } - if done { - return nil - } - } - - // Exhausted retries check (independent of consecutive failure thresholds). - // Attempt is 1-indexed: with retryMaxLimit=10, attempt 11 is the final one. - // Skip if retryMaxLimit=0 (retries disabled — no exhausted state to report) - // or if exhausted-retries alerting is disabled. - if m.exhaustedRetriesEnabled && m.retryMaxLimit > 0 && attempt.Event.EligibleForRetry && attempt.Attempt.AttemptNumber > m.retryMaxLimit { - erData := ExhaustedRetriesData{ - TenantID: attempt.Destination.TenantID, - Event: attempt.Event, - Attempt: attempt.Attempt, - Destination: attempt.Destination, - } - - emitFn := func(ctx context.Context) error { - if err := m.emitter.Emit(ctx, opevents.TopicAlertExhaustedRetries, attempt.Destination.TenantID, erData); err != nil { - return err - } - m.logger.Ctx(ctx).Audit("alert sent", - zap.String("topic", opevents.TopicAlertExhaustedRetries), - zap.String("attempt_id", attempt.Attempt.ID), - zap.String("event_id", attempt.Event.ID), - zap.String("tenant_id", attempt.Destination.TenantID), - zap.String("destination_id", attempt.Destination.ID), - zap.String("destination_type", attempt.Destination.Type), - ) - return nil - } - - if m.exhaustedRetryIdemp != nil { - key := "opevents:exhausted:" + attempt.Event.ID + ":" + attempt.Destination.ID - if err := m.exhaustedRetryIdemp.Exec(ctx, key, emitFn); err != nil { - return fmt.Errorf("failed to emit exhausted retries alert: %w", err) - } - } else { - if err := emitFn(ctx); err != nil { - return fmt.Errorf("failed to emit exhausted retries alert: %w", err) - } - } - } - - // Mark the attempt fully evaluated so replays skip re-emitting alerts. Only - // relevant when consecutive-failure tracking ran — it is the consumer of the - // evaluated mark (the replay short-circuit above). - // Non-fatal: on failure the attempt simply re-evaluates on replay, which - // matches the previous behavior (emit/disable are idempotent-by-design). - if m.consecutiveFailureEnabled { - if err := m.store.MarkAttemptEvaluated(ctx, attempt.Destination.TenantID, attempt.Destination.ID, attempt.Attempt.ID); err != nil { - m.logger.Ctx(ctx).Warn("failed to mark attempt evaluated", - zap.Error(err), - zap.String("attempt_id", attempt.Attempt.ID), - zap.String("tenant_id", attempt.Destination.TenantID), - zap.String("destination_id", attempt.Destination.ID), - ) - } - } - - return nil -} - -// handleConsecutiveFailure runs consecutive-failure tracking, alerting and -// auto-disable for a failed attempt. It returns done=true when the attempt is a -// replay that already completed evaluation, signalling the caller to stop -// processing (skip the exhausted-retries check and the evaluated mark). -func (m *alertMonitor) handleConsecutiveFailure(ctx context.Context, attempt DeliveryAttempt) (done bool, err error) { - res, err := m.store.IncrementConsecutiveFailureCount(ctx, attempt.Destination.TenantID, attempt.Destination.ID, attempt.Attempt.ID) - if err != nil { - return false, fmt.Errorf("failed to get alert state: %w", err) - } - - // Replayed attempt (MQ redelivery, producer re-publish) that already - // completed a full evaluation — skip re-emitting alerts. Attempts that - // were counted but never marked evaluated (eval failed mid-way and the - // message was nacked) fall through and re-run as recovery. - if !res.NewlyCounted && res.AlreadyEvaluated { - m.logger.Ctx(ctx).Debug("skipping replayed attempt: already evaluated", - zap.String("attempt_id", attempt.Attempt.ID), - zap.String("tenant_id", attempt.Destination.TenantID), - zap.String("destination_id", attempt.Destination.ID), - ) - return true, nil - } - - count := res.Count - level, shouldAlert := m.evaluator.ShouldAlert(count) - if !shouldAlert { - return false, nil - } - - // At 100% threshold, disable the destination and emit disabled alert. - // Both operations are idempotent on replay: DisableDestination is a no-op - // if already disabled, and consumers deduplicate events by ID. - if level == 100 && m.disabler != nil { - if err := m.disabler.DisableDestination(ctx, attempt.Destination.TenantID, attempt.Destination.ID); err != nil { - return false, fmt.Errorf("failed to disable destination: %w", err) - } - - now := time.Now() - attempt.Destination.DisabledAt = &now - - m.logger.Ctx(ctx).Audit("destination disabled", - zap.String("attempt_id", attempt.Attempt.ID), - zap.String("event_id", attempt.Event.ID), - zap.String("tenant_id", attempt.Destination.TenantID), - zap.String("destination_id", attempt.Destination.ID), - zap.String("destination_type", attempt.Destination.Type), - ) - - disabledData := DestinationDisabledData{ - TenantID: attempt.Destination.TenantID, - Destination: attempt.Destination, - DisabledAt: now, - Reason: "consecutive_failure", - Event: attempt.Event, - Attempt: attempt.Attempt, - } - if err := m.emitter.Emit(ctx, opevents.TopicAlertDestinationDisabled, attempt.Destination.TenantID, disabledData); err != nil { - return false, fmt.Errorf("failed to emit destination disabled alert: %w", err) - } - } - - // Emit consecutive failure alert - cfData := ConsecutiveFailureData{ - TenantID: attempt.Destination.TenantID, - Event: attempt.Event, - Attempt: attempt.Attempt, - Destination: attempt.Destination, - ConsecutiveFailures: ConsecutiveFailures{ - Current: count, - Max: m.autoDisableFailureCount, - Threshold: level, - }, - } - if err := m.emitter.Emit(ctx, opevents.TopicAlertConsecutiveFailure, attempt.Destination.TenantID, cfData); err != nil { - return false, fmt.Errorf("failed to emit consecutive failure alert: %w", err) - } - - m.logger.Ctx(ctx).Audit("alert sent", - zap.String("topic", opevents.TopicAlertConsecutiveFailure), - zap.String("attempt_id", attempt.Attempt.ID), - zap.String("event_id", attempt.Event.ID), - zap.String("tenant_id", attempt.Destination.TenantID), - zap.String("destination_id", attempt.Destination.ID), - zap.String("destination_type", attempt.Destination.Type), - ) - - return false, nil -} diff --git a/internal/alert/monitor_test.go b/internal/alert/monitor_test.go deleted file mode 100644 index a412f6eb6..000000000 --- a/internal/alert/monitor_test.go +++ /dev/null @@ -1,734 +0,0 @@ -package alert_test - -import ( - "context" - "fmt" - "testing" - "time" - - "github.com/stretchr/testify/assert" - "github.com/stretchr/testify/mock" - "github.com/stretchr/testify/require" - - "github.com/hookdeck/outpost/internal/alert" - "github.com/hookdeck/outpost/internal/idempotence" - "github.com/hookdeck/outpost/internal/models" - "github.com/hookdeck/outpost/internal/util/testutil" -) - -type mockAlertEmitter struct { - mock.Mock -} - -func (m *mockAlertEmitter) Emit(ctx context.Context, topic string, tenantID string, data any) error { - args := m.Called(ctx, topic, tenantID, data) - return args.Error(0) -} - -type mockDestinationDisabler struct { - mock.Mock -} - -func (m *mockDestinationDisabler) DisableDestination(ctx context.Context, tenantID, destinationID string) error { - args := m.Called(ctx, tenantID, destinationID) - return args.Error(0) -} - -func TestAlertMonitor_ConsecutiveFailures_MaxFailures(t *testing.T) { - t.Parallel() - ctx := context.Background() - logger := testutil.CreateTestLogger(t) - redisClient := testutil.CreateTestRedisClient(t) - emitter := &mockAlertEmitter{} - emitter.On("Emit", mock.Anything, mock.Anything, mock.Anything, mock.Anything).Return(nil) - disabler := &mockDestinationDisabler{} - disabler.On("DisableDestination", mock.Anything, mock.Anything, mock.Anything).Return(nil) - - monitor := alert.NewAlertMonitor( - logger, - redisClient, - emitter, - 10, - alert.WithDisabler(disabler), - alert.WithAutoDisableFailureCount(20), - alert.WithAlertThresholds([]int{50, 66, 90, 100}), - ) - - dest := &alert.AlertDestination{ID: "dest_1", TenantID: "tenant_1"} - event := &models.Event{Topic: "test.event"} - - for i := 1; i <= 20; i++ { - attempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: fmt.Sprintf("att_%d", i), - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - } - - // Verify cf alerts at correct thresholds - cfCalls := countEmitCalls(emitter, "alert.destination.consecutive_failure") - require.Equal(t, 4, cfCalls, "Should emit 4 cf alerts (50%, 66%, 90%, 100%)") - - // Verify disabled alert emitted once at 100% - disabledCalls := countEmitCalls(emitter, "alert.destination.disabled") - require.Equal(t, 1, disabledCalls, "Should emit 1 disabled alert at 100%") - - // Verify disabled alert data - for _, call := range emitter.Calls { - if call.Arguments.Get(1) == "alert.destination.disabled" { - data := call.Arguments.Get(3).(alert.DestinationDisabledData) - assert.Equal(t, dest.ID, data.Destination.ID) - assert.Equal(t, "consecutive_failure", data.Reason) - assert.NotNil(t, data.Destination.DisabledAt) - } - } - - // Verify destination was disabled exactly once - disabler.AssertNumberOfCalls(t, "DisableDestination", 1) -} - -func TestAlertMonitor_ConsecutiveFailures_Reset(t *testing.T) { - t.Parallel() - ctx := context.Background() - logger := testutil.CreateTestLogger(t) - redisClient := testutil.CreateTestRedisClient(t) - emitter := &mockAlertEmitter{} - emitter.On("Emit", mock.Anything, mock.Anything, mock.Anything, mock.Anything).Return(nil) - - monitor := alert.NewAlertMonitor( - logger, - redisClient, - emitter, - 10, - alert.WithAutoDisableFailureCount(20), - alert.WithAlertThresholds([]int{50, 66, 90, 100}), - ) - - dest := &alert.AlertDestination{ID: "dest_1", TenantID: "tenant_1"} - event := &models.Event{Topic: "test.event"} - - // Send 14 failures (triggers 50% and 66%) - for i := 1; i <= 14; i++ { - failedAttempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: fmt.Sprintf("att_%d", i), - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - require.NoError(t, monitor.HandleAttempt(ctx, failedAttempt)) - } - - cfCalls := countEmitCalls(emitter, "alert.destination.consecutive_failure") - require.Equal(t, 2, cfCalls) - - // Send a success to reset - successAttempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{Status: models.AttemptStatusSuccess}, - } - require.NoError(t, monitor.HandleAttempt(ctx, successAttempt)) - - emitter.Calls = nil - - // Send 14 more failures (new IDs) - for i := 15; i <= 28; i++ { - failedAttempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: fmt.Sprintf("att_%d", i), - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - require.NoError(t, monitor.HandleAttempt(ctx, failedAttempt)) - } - - cfCalls = countEmitCalls(emitter, "alert.destination.consecutive_failure") - require.Equal(t, 2, cfCalls) -} - -func TestAlertMonitor_ConsecutiveFailures_AboveThreshold(t *testing.T) { - t.Parallel() - ctx := context.Background() - logger := testutil.CreateTestLogger(t) - redisClient := testutil.CreateTestRedisClient(t) - emitter := &mockAlertEmitter{} - emitter.On("Emit", mock.Anything, mock.Anything, mock.Anything, mock.Anything).Return(nil) - disabler := &mockDestinationDisabler{} - disabler.On("DisableDestination", mock.Anything, mock.Anything, mock.Anything).Return(nil) - - monitor := alert.NewAlertMonitor( - logger, - redisClient, - emitter, - 10, - alert.WithDisabler(disabler), - alert.WithAutoDisableFailureCount(20), - alert.WithAlertThresholds([]int{50, 70, 90, 100}), - ) - - dest := &alert.AlertDestination{ID: "dest_above", TenantID: "tenant_above"} - event := &models.Event{Topic: "test.event"} - - for i := 1; i <= 25; i++ { - attempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: fmt.Sprintf("att_%d", i), - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - } - - // 4 at thresholds + 5 above = 9 cf alerts - cfCalls := countEmitCalls(emitter, "alert.destination.consecutive_failure") - require.Equal(t, 9, cfCalls) - - // 6 disabled alerts (failures 20-25) - disabledCalls := countEmitCalls(emitter, "alert.destination.disabled") - require.Equal(t, 6, disabledCalls) - - // 6 disable calls - disabler.AssertNumberOfCalls(t, "DisableDestination", 6) -} - -func TestAlertMonitor_NoDisabler(t *testing.T) { - // Without a disabler, 100% threshold still emits cf alert but no disable/disabled alert - t.Parallel() - ctx := context.Background() - logger := testutil.CreateTestLogger(t) - redisClient := testutil.CreateTestRedisClient(t) - emitter := &mockAlertEmitter{} - emitter.On("Emit", mock.Anything, mock.Anything, mock.Anything, mock.Anything).Return(nil) - - monitor := alert.NewAlertMonitor( - logger, - redisClient, - emitter, - 10, - alert.WithAutoDisableFailureCount(10), - alert.WithAlertThresholds([]int{50, 100}), - ) - - dest := &alert.AlertDestination{ID: "dest_no_disable", TenantID: "tenant_1"} - event := &models.Event{Topic: "test.event"} - - for i := 1; i <= 10; i++ { - attempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: fmt.Sprintf("att_%d", i), - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - } - - cfCalls := countEmitCalls(emitter, "alert.destination.consecutive_failure") - require.Equal(t, 2, cfCalls, "Should emit cf at 50% and 100%") - - disabledCalls := countEmitCalls(emitter, "alert.destination.disabled") - require.Equal(t, 0, disabledCalls, "No disabled alert without disabler") -} - -func TestAlertMonitor_ExhaustedRetries(t *testing.T) { - t.Parallel() - ctx := context.Background() - logger := testutil.CreateTestLogger(t) - redisClient := testutil.CreateTestRedisClient(t) - emitter := &mockAlertEmitter{} - emitter.On("Emit", mock.Anything, mock.Anything, mock.Anything, mock.Anything).Return(nil) - - retryMaxLimit := 3 - monitor := alert.NewAlertMonitor( - logger, - redisClient, - emitter, - retryMaxLimit, - alert.WithAutoDisableFailureCount(100), // high so cf thresholds don't interfere - ) - - dest := &alert.AlertDestination{ID: "dest_er", TenantID: "tenant_er"} - event := &models.Event{Topic: "test.event", EligibleForRetry: true} - - // Attempts 1-3: within retry budget, no exhausted_retries - for i := 1; i <= 3; i++ { - attempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: fmt.Sprintf("att_%d", i), - AttemptNumber: i, - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - } - - erCalls := countEmitCalls(emitter, "alert.attempt.exhausted_retries") - require.Equal(t, 0, erCalls, "No exhausted_retries within retry budget") - - // Attempt 4: exceeds retryMaxLimit=3, should emit exhausted_retries - attempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: "att_4", - AttemptNumber: 4, - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - - erCalls = countEmitCalls(emitter, "alert.attempt.exhausted_retries") - require.Equal(t, 1, erCalls, "Should emit exhausted_retries when attempt exceeds retry limit") - - // Verify data shape - for _, call := range emitter.Calls { - if call.Arguments.Get(1) == "alert.attempt.exhausted_retries" { - data := call.Arguments.Get(3).(alert.ExhaustedRetriesData) - assert.Equal(t, dest.ID, data.Destination.ID) - assert.Equal(t, dest.TenantID, data.TenantID) - assert.Equal(t, event.Topic, data.Event.Topic) - assert.Equal(t, 4, data.Attempt.AttemptNumber) - } - } -} - -func TestAlertMonitor_ExhaustedRetries_NotEligible(t *testing.T) { - // Events not eligible for retry should not emit exhausted_retries - t.Parallel() - ctx := context.Background() - logger := testutil.CreateTestLogger(t) - redisClient := testutil.CreateTestRedisClient(t) - emitter := &mockAlertEmitter{} - emitter.On("Emit", mock.Anything, mock.Anything, mock.Anything, mock.Anything).Return(nil) - - monitor := alert.NewAlertMonitor( - logger, - redisClient, - emitter, - 3, - alert.WithAutoDisableFailureCount(100), - ) - - dest := &alert.AlertDestination{ID: "dest_ne", TenantID: "tenant_ne"} - event := &models.Event{Topic: "test.event", EligibleForRetry: false} - - // Attempt 4 exceeds limit but event is not eligible for retry - attempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: "att_4", - AttemptNumber: 4, - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - - erCalls := countEmitCalls(emitter, "alert.attempt.exhausted_retries") - require.Equal(t, 0, erCalls, "No exhausted_retries when event not eligible for retry") -} - -func TestAlertMonitor_ExhaustedRetries_WindowSuppression(t *testing.T) { - // With idempotence, replaying the same exhausted event is suppressed within the window - t.Parallel() - ctx := context.Background() - logger := testutil.CreateTestLogger(t) - redisClient := testutil.CreateTestRedisClient(t) - emitter := &mockAlertEmitter{} - emitter.On("Emit", mock.Anything, mock.Anything, mock.Anything, mock.Anything).Return(nil) - - exhaustedIdemp := idempotence.New(redisClient, - idempotence.WithSuccessfulTTL(10*time.Second), - ) - - monitor := alert.NewAlertMonitor( - logger, - redisClient, - emitter, - 3, - alert.WithAutoDisableFailureCount(100), - alert.WithExhaustedRetriesIdempotence(exhaustedIdemp), - ) - - dest := &alert.AlertDestination{ID: "dest_ws", TenantID: "tenant_ws"} - event := &models.Event{ID: "evt_ws_1", Topic: "test.event", EligibleForRetry: true} - attempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: "att_exhaust_1", - AttemptNumber: 4, - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - - // Same event+destination replayed twice — second should be suppressed - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - - erCalls := countEmitCalls(emitter, "alert.attempt.exhausted_retries") - require.Equal(t, 1, erCalls, "Replay of the same event+destination should be suppressed by window") -} - -func TestAlertMonitor_ExhaustedRetries_PerEvent(t *testing.T) { - // Each distinct event exhausting retries on the same destination should emit its own alert - t.Parallel() - ctx := context.Background() - logger := testutil.CreateTestLogger(t) - redisClient := testutil.CreateTestRedisClient(t) - emitter := &mockAlertEmitter{} - emitter.On("Emit", mock.Anything, mock.Anything, mock.Anything, mock.Anything).Return(nil) - - exhaustedIdemp := idempotence.New(redisClient, - idempotence.WithSuccessfulTTL(10*time.Second), - ) - - monitor := alert.NewAlertMonitor( - logger, - redisClient, - emitter, - 3, - alert.WithAutoDisableFailureCount(100), - alert.WithExhaustedRetriesIdempotence(exhaustedIdemp), - ) - - dest := &alert.AlertDestination{ID: "dest_pe", TenantID: "tenant_pe"} - - // Two distinct events both exhaust retries on the same destination - for i := 1; i <= 2; i++ { - attempt := alert.DeliveryAttempt{ - Event: &models.Event{ - ID: fmt.Sprintf("evt_pe_%d", i), - Topic: "test.event", - EligibleForRetry: true, - }, - Destination: dest, - Attempt: &models.Attempt{ - ID: fmt.Sprintf("att_pe_%d", i), - AttemptNumber: 4, - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - } - - erCalls := countEmitCalls(emitter, "alert.attempt.exhausted_retries") - require.Equal(t, 2, erCalls, "Each distinct event exhausting retries should emit its own alert") -} - -func TestAlertMonitor_ExhaustedRetries_EmitFailureRetryClearsWindow(t *testing.T) { - // When emit fails, idempotence clears the key so replay can retry - t.Parallel() - ctx := context.Background() - logger := testutil.CreateTestLogger(t) - redisClient := testutil.CreateTestRedisClient(t) - emitter := &mockAlertEmitter{} - // CF alerts always succeed - emitter.On("Emit", mock.Anything, "alert.destination.consecutive_failure", mock.Anything, mock.Anything).Return(nil) - // Exhausted retries: fail first, succeed second - emitter.On("Emit", mock.Anything, "alert.attempt.exhausted_retries", mock.Anything, mock.Anything).Return(fmt.Errorf("emit failed")).Once() - emitter.On("Emit", mock.Anything, "alert.attempt.exhausted_retries", mock.Anything, mock.Anything).Return(nil).Once() - - exhaustedIdemp := idempotence.New(redisClient, - idempotence.WithSuccessfulTTL(10*time.Second), - ) - - monitor := alert.NewAlertMonitor( - logger, - redisClient, - emitter, - 3, - alert.WithAutoDisableFailureCount(100), - alert.WithExhaustedRetriesIdempotence(exhaustedIdemp), - ) - - dest := &alert.AlertDestination{ID: "dest_ef", TenantID: "tenant_ef"} - event := &models.Event{ID: "evt_1", Topic: "test.event", EligibleForRetry: true} - - attempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: "att_exhaust_1", - AttemptNumber: 4, - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - - // First call: emit fails, HandleAttempt returns error (entry would be nacked) - err := monitor.HandleAttempt(ctx, attempt) - require.Error(t, err, "Should return error when emit fails") - - // Replay: emit succeeds (idempotence key was cleared on failure) - err = monitor.HandleAttempt(ctx, attempt) - require.NoError(t, err, "Replay should succeed after emit failure") - - // 2 total calls: 1 failed + 1 succeeded. The key point is that the - // second call was NOT suppressed — idempotence cleared the key on failure. - erCalls := countEmitCalls(emitter, "alert.attempt.exhausted_retries") - require.Equal(t, 2, erCalls, "Should have 2 emit attempts (1 failed + 1 succeeded)") -} - -func TestAlertMonitor_ReplayedAttempt_SkipsEvaluation(t *testing.T) { - t.Parallel() - ctx := context.Background() - logger := testutil.CreateTestLogger(t) - redisClient := testutil.CreateTestRedisClient(t) - emitter := &mockAlertEmitter{} - emitter.On("Emit", mock.Anything, mock.Anything, mock.Anything, mock.Anything).Return(nil) - - monitor := alert.NewAlertMonitor( - logger, - redisClient, - emitter, - 10, - alert.WithAutoDisableFailureCount(2), - alert.WithAlertThresholds([]int{50, 100}), - ) - - dest := &alert.AlertDestination{ID: "dest_replay", TenantID: "tenant_replay"} - event := &models.Event{Topic: "test.event"} - attempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: "att_replay_1", - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - - // First delivery: count=1 → 50% threshold → emits - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - require.Equal(t, 1, countEmitCalls(emitter, "alert.destination.consecutive_failure")) - - // Replay (MQ redelivery / producer re-publish): fully evaluated → skipped - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - assert.Equal(t, 1, countEmitCalls(emitter, "alert.destination.consecutive_failure"), - "replayed attempt should not re-emit the alert") -} - -func TestAlertMonitor_ReplayedAttempt_PartialFailureRetries(t *testing.T) { - // When evaluation fails after the attempt was counted (e.g. emit error), - // the message is nacked and redelivered — the replay must re-run the - // evaluation, not skip it, or alerts would be silently dropped. - t.Parallel() - ctx := context.Background() - logger := testutil.CreateTestLogger(t) - redisClient := testutil.CreateTestRedisClient(t) - emitter := &mockAlertEmitter{} - emitter.On("Emit", mock.Anything, "alert.destination.consecutive_failure", mock.Anything, mock.Anything).Return(fmt.Errorf("emit failed")).Once() - emitter.On("Emit", mock.Anything, "alert.destination.consecutive_failure", mock.Anything, mock.Anything).Return(nil) - - monitor := alert.NewAlertMonitor( - logger, - redisClient, - emitter, - 10, - alert.WithAutoDisableFailureCount(2), - alert.WithAlertThresholds([]int{50, 100}), - ) - - dest := &alert.AlertDestination{ID: "dest_partial", TenantID: "tenant_partial"} - event := &models.Event{Topic: "test.event"} - attempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: "att_partial_1", - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - - // First delivery: counted, but emit fails → error (entry would be nacked) - require.Error(t, monitor.HandleAttempt(ctx, attempt)) - - // Replay: not marked evaluated → re-runs and emits successfully - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - assert.Equal(t, 2, countEmitCalls(emitter, "alert.destination.consecutive_failure"), - "replay after partial failure should re-run evaluation") - - // Second replay: now fully evaluated → skipped - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - assert.Equal(t, 2, countEmitCalls(emitter, "alert.destination.consecutive_failure")) -} - -func countEmitCalls(emitter *mockAlertEmitter, topic string) int { - count := 0 - for _, call := range emitter.Calls { - if call.Method == "Emit" && call.Arguments.Get(1) == topic { - count++ - } - } - return count -} - -func TestAlertMonitor_ConsecutiveFailures_GateDisabled(t *testing.T) { - // With consecutive-failure alerting disabled, failures never emit cf/disabled - // alerts and never auto-disable, even past the threshold. - t.Parallel() - ctx := context.Background() - logger := testutil.CreateTestLogger(t) - redisClient := testutil.CreateTestRedisClient(t) - emitter := &mockAlertEmitter{} - emitter.On("Emit", mock.Anything, mock.Anything, mock.Anything, mock.Anything).Return(nil) - disabler := &mockDestinationDisabler{} - disabler.On("DisableDestination", mock.Anything, mock.Anything, mock.Anything).Return(nil) - - monitor := alert.NewAlertMonitor( - logger, - redisClient, - emitter, - 10, - alert.WithDisabler(disabler), - alert.WithAutoDisableFailureCount(5), - alert.WithConsecutiveFailureEnabled(false), - ) - - dest := &alert.AlertDestination{ID: "dest_cf_off", TenantID: "tenant_cf_off"} - event := &models.Event{Topic: "test.event"} - - // Well past the threshold of 5. - for i := 1; i <= 10; i++ { - attempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: fmt.Sprintf("att_%d", i), - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - } - - require.Equal(t, 0, countEmitCalls(emitter, "alert.destination.consecutive_failure"), - "no consecutive_failure alerts when gate disabled") - require.Equal(t, 0, countEmitCalls(emitter, "alert.destination.disabled"), - "no disabled alerts when gate disabled") - disabler.AssertNotCalled(t, "DisableDestination", mock.Anything, mock.Anything, mock.Anything) -} - -func TestAlertMonitor_ExhaustedRetries_GateDisabled(t *testing.T) { - // With exhausted-retries alerting disabled, exceeding the retry limit emits - // nothing, even though retries are enabled and the event is eligible. - t.Parallel() - ctx := context.Background() - logger := testutil.CreateTestLogger(t) - redisClient := testutil.CreateTestRedisClient(t) - emitter := &mockAlertEmitter{} - emitter.On("Emit", mock.Anything, mock.Anything, mock.Anything, mock.Anything).Return(nil) - - monitor := alert.NewAlertMonitor( - logger, - redisClient, - emitter, - 3, - alert.WithAutoDisableFailureCount(100), - alert.WithExhaustedRetriesEnabled(false), - ) - - dest := &alert.AlertDestination{ID: "dest_er_off", TenantID: "tenant_er_off"} - event := &models.Event{Topic: "test.event", EligibleForRetry: true} - - attempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: "att_4", - AttemptNumber: 4, - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - - require.Equal(t, 0, countEmitCalls(emitter, "alert.attempt.exhausted_retries"), - "no exhausted_retries alerts when gate disabled") -} - -func TestAlertMonitor_Gates_Independent(t *testing.T) { - // Consecutive-failure gate off but exhausted-retries gate on: exhausted_retries - // still fires while consecutive_failure stays silent. - t.Parallel() - ctx := context.Background() - logger := testutil.CreateTestLogger(t) - redisClient := testutil.CreateTestRedisClient(t) - emitter := &mockAlertEmitter{} - emitter.On("Emit", mock.Anything, mock.Anything, mock.Anything, mock.Anything).Return(nil) - - monitor := alert.NewAlertMonitor( - logger, - redisClient, - emitter, - 3, - alert.WithAutoDisableFailureCount(5), - alert.WithConsecutiveFailureEnabled(false), - alert.WithExhaustedRetriesEnabled(true), - ) - - dest := &alert.AlertDestination{ID: "dest_mix", TenantID: "tenant_mix"} - event := &models.Event{Topic: "test.event", EligibleForRetry: true} - - // Enough failures to cross the cf threshold, with the last one exceeding the - // retry limit so exhausted_retries is eligible. - for i := 1; i <= 6; i++ { - attempt := alert.DeliveryAttempt{ - Event: event, - Destination: dest, - Attempt: &models.Attempt{ - ID: fmt.Sprintf("att_%d", i), - AttemptNumber: i, - Status: "failed", - Code: "500", - Time: time.Now(), - }, - } - require.NoError(t, monitor.HandleAttempt(ctx, attempt)) - } - - require.Equal(t, 0, countEmitCalls(emitter, "alert.destination.consecutive_failure"), - "consecutive_failure stays silent when its gate is off") - require.Greater(t, countEmitCalls(emitter, "alert.attempt.exhausted_retries"), 0, - "exhausted_retries still fires when its gate is on") -} diff --git a/internal/alert/notifier.go b/internal/alert/notifier.go deleted file mode 100644 index 0b0629e7d..000000000 --- a/internal/alert/notifier.go +++ /dev/null @@ -1,65 +0,0 @@ -package alert - -import ( - "time" - - "github.com/hookdeck/outpost/internal/models" -) - -// AlertDestination is the destination data included in alert event payloads. -type AlertDestination struct { - ID string `json:"id" redis:"id"` - TenantID string `json:"tenant_id" redis:"-"` - Type string `json:"type" redis:"type"` - Topics models.Topics `json:"topics" redis:"-"` - Config models.Config `json:"config" redis:"-"` - CreatedAt time.Time `json:"created_at" redis:"created_at"` - DisabledAt *time.Time `json:"disabled_at" redis:"disabled_at"` -} - -// AlertDestinationFromDestination converts a models.Destination to an AlertDestination. -func AlertDestinationFromDestination(d *models.Destination) *AlertDestination { - return &AlertDestination{ - ID: d.ID, - TenantID: d.TenantID, - Type: d.Type, - Topics: d.Topics, - Config: d.Config, - CreatedAt: d.CreatedAt, - DisabledAt: d.DisabledAt, - } -} - -// ConsecutiveFailures represents the nested consecutive failure state. -type ConsecutiveFailures struct { - Current int `json:"current"` - Max int `json:"max"` - Threshold int `json:"threshold"` -} - -// DestinationDisabledData is the data payload for alert.destination.disabled events. -type DestinationDisabledData struct { - TenantID string `json:"tenant_id"` - Destination *AlertDestination `json:"destination"` - DisabledAt time.Time `json:"disabled_at"` - Reason string `json:"reason"` - Event *models.Event `json:"event"` - Attempt *models.Attempt `json:"attempt"` -} - -// ConsecutiveFailureData is the data payload for alert.destination.consecutive_failure events. -type ConsecutiveFailureData struct { - TenantID string `json:"tenant_id"` - Event *models.Event `json:"event"` - Attempt *models.Attempt `json:"attempt"` - Destination *AlertDestination `json:"destination"` - ConsecutiveFailures ConsecutiveFailures `json:"consecutive_failures"` -} - -// ExhaustedRetriesData is the data payload for alert.attempt.exhausted_retries events. -type ExhaustedRetriesData struct { - TenantID string `json:"tenant_id"` - Event *models.Event `json:"event"` - Attempt *models.Attempt `json:"attempt"` - Destination *AlertDestination `json:"destination"` -} diff --git a/internal/alert/store.go b/internal/alert/store.go index 4324c99c2..2b19974d0 100644 --- a/internal/alert/store.go +++ b/internal/alert/store.go @@ -9,27 +9,18 @@ import ( ) const ( - keyPrefixAlert = "alert" // Base prefix for all alert keys - keyFailures = "cf" // Set for consecutive failure attempt IDs - keyEvaluated = "cfeval" // Set for fully evaluated attempt IDs + keyPrefixAlert = "alert" // Base prefix for all alert keys + keyFailures = "cf" // Set for consecutive failure attempt IDs alertKeyTTL = 24 * time.Hour ) -// FailureCountResult reports the state of consecutive-failure tracking -// after recording an attempt. -type FailureCountResult struct { - Count int // current consecutive failure count - NewlyCounted bool // attempt was not previously counted (first delivery of this attempt) - AlreadyEvaluated bool // attempt was fully evaluated before (marked via MarkAttemptEvaluated) -} - -// AlertStore manages alert-related data persistence +// AlertStore persists the tracker's own state: the consecutive-failure count +// per destination. type AlertStore interface { - IncrementConsecutiveFailureCount(ctx context.Context, tenantID, destinationID, attemptID string) (FailureCountResult, error) - // MarkAttemptEvaluated records that an attempt's alert evaluation fully - // completed, so replays (MQ redelivery, producer re-publish) can skip - // re-evaluating it. - MarkAttemptEvaluated(ctx context.Context, tenantID, destinationID, attemptID string) error + // IncrementConsecutiveFailureCount records a failed attempt and returns the + // destination's current consecutive-failure count. Recording is idempotent + // per attempt ID, so replays never double-count. + IncrementConsecutiveFailureCount(ctx context.Context, tenantID, destinationID, attemptID string) (int, error) ResetConsecutiveFailureCount(ctx context.Context, tenantID, destinationID string) error } @@ -46,60 +37,32 @@ func NewRedisAlertStore(client redis.Cmdable, deploymentID string) AlertStore { } } -func (s *redisAlertStore) IncrementConsecutiveFailureCount(ctx context.Context, tenantID, destinationID, attemptID string) (FailureCountResult, error) { +func (s *redisAlertStore) IncrementConsecutiveFailureCount(ctx context.Context, tenantID, destinationID, attemptID string) (int, error) { key := s.getFailuresKey(tenantID, destinationID) // Use a transaction to ensure atomicity between SADD, SCARD, and EXPIRE operations. // SADD is idempotent — adding the same attemptID on replay is a no-op, // preventing double-counting when messages are redelivered. pipe := s.client.TxPipeline() - saddCmd := pipe.SAdd(ctx, key, attemptID) + pipe.SAdd(ctx, key, attemptID) scardCmd := pipe.SCard(ctx, key) - evaluatedCmd := pipe.SIsMember(ctx, s.getEvaluatedKey(tenantID, destinationID), attemptID) pipe.Expire(ctx, key, alertKeyTTL) _, err := pipe.Exec(ctx) if err != nil { - return FailureCountResult{}, fmt.Errorf("failed to execute consecutive failure count transaction: %w", err) - } - - added, err := saddCmd.Result() - if err != nil { - return FailureCountResult{}, fmt.Errorf("failed to record attempt: %w", err) + return 0, fmt.Errorf("failed to execute consecutive failure count transaction: %w", err) } count, err := scardCmd.Result() if err != nil { - return FailureCountResult{}, fmt.Errorf("failed to get consecutive failure count: %w", err) + return 0, fmt.Errorf("failed to get consecutive failure count: %w", err) } - evaluated, err := evaluatedCmd.Result() - if err != nil { - return FailureCountResult{}, fmt.Errorf("failed to check evaluated state: %w", err) - } - - return FailureCountResult{ - Count: int(count), - NewlyCounted: added == 1, - AlreadyEvaluated: evaluated, - }, nil -} - -func (s *redisAlertStore) MarkAttemptEvaluated(ctx context.Context, tenantID, destinationID, attemptID string) error { - key := s.getEvaluatedKey(tenantID, destinationID) - - pipe := s.client.TxPipeline() - pipe.SAdd(ctx, key, attemptID) - pipe.Expire(ctx, key, alertKeyTTL) - - if _, err := pipe.Exec(ctx); err != nil { - return fmt.Errorf("failed to mark attempt evaluated: %w", err) - } - return nil + return int(count), nil } func (s *redisAlertStore) ResetConsecutiveFailureCount(ctx context.Context, tenantID, destinationID string) error { - return s.client.Del(ctx, s.getFailuresKey(tenantID, destinationID), s.getEvaluatedKey(tenantID, destinationID)).Err() + return s.client.Del(ctx, s.getFailuresKey(tenantID, destinationID)).Err() } func (s *redisAlertStore) deploymentPrefix() string { @@ -112,7 +75,3 @@ func (s *redisAlertStore) deploymentPrefix() string { func (s *redisAlertStore) getFailuresKey(tenantID, destinationID string) string { return fmt.Sprintf("%s%s:%s:%s:%s", s.deploymentPrefix(), keyPrefixAlert, tenantID, destinationID, keyFailures) } - -func (s *redisAlertStore) getEvaluatedKey(tenantID, destinationID string) string { - return fmt.Sprintf("%s%s:%s:%s:%s", s.deploymentPrefix(), keyPrefixAlert, tenantID, destinationID, keyEvaluated) -} diff --git a/internal/alert/store_test.go b/internal/alert/store_test.go index 4bd78df49..2cc168a9c 100644 --- a/internal/alert/store_test.go +++ b/internal/alert/store_test.go @@ -19,16 +19,14 @@ func TestRedisAlertStore(t *testing.T) { store := alert.NewRedisAlertStore(redisClient, "") // First increment - res, err := store.IncrementConsecutiveFailureCount(context.Background(), "tenant_1", "dest_1", "att_1") + count, err := store.IncrementConsecutiveFailureCount(context.Background(), "tenant_1", "dest_1", "att_1") require.NoError(t, err) - assert.Equal(t, 1, res.Count) - assert.True(t, res.NewlyCounted) + assert.Equal(t, 1, count) // Second increment (different attempt) - res, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_1", "dest_1", "att_2") + count, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_1", "dest_1", "att_2") require.NoError(t, err) - assert.Equal(t, 2, res.Count) - assert.True(t, res.NewlyCounted) + assert.Equal(t, 2, count) }) t.Run("reset consecutive failures", func(t *testing.T) { @@ -37,18 +35,18 @@ func TestRedisAlertStore(t *testing.T) { store := alert.NewRedisAlertStore(redisClient, "") // Set up initial failures - res, err := store.IncrementConsecutiveFailureCount(context.Background(), "tenant_2", "dest_2", "att_1") + count, err := store.IncrementConsecutiveFailureCount(context.Background(), "tenant_2", "dest_2", "att_1") require.NoError(t, err) - assert.Equal(t, 1, res.Count) + assert.Equal(t, 1, count) // Reset failures err = store.ResetConsecutiveFailureCount(context.Background(), "tenant_2", "dest_2") require.NoError(t, err) // Verify counter is reset by incrementing again - res, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_2", "dest_2", "att_2") + count, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_2", "dest_2", "att_2") require.NoError(t, err) - assert.Equal(t, 1, res.Count) + assert.Equal(t, 1, count) }) t.Run("idempotent on replay", func(t *testing.T) { @@ -57,79 +55,24 @@ func TestRedisAlertStore(t *testing.T) { store := alert.NewRedisAlertStore(redisClient, "") // First call - res, err := store.IncrementConsecutiveFailureCount(context.Background(), "tenant_3", "dest_3", "att_1") + count, err := store.IncrementConsecutiveFailureCount(context.Background(), "tenant_3", "dest_3", "att_1") require.NoError(t, err) - assert.Equal(t, 1, res.Count) - assert.True(t, res.NewlyCounted) + assert.Equal(t, 1, count) // Replay same attempt — count should not change - res, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_3", "dest_3", "att_1") + count, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_3", "dest_3", "att_1") require.NoError(t, err) - assert.Equal(t, 1, res.Count, "replaying the same attemptID should not increment the count") - assert.False(t, res.NewlyCounted, "replayed attemptID should not be newly counted") + assert.Equal(t, 1, count, "replaying the same attemptID should not increment the count") // Different attempt should still increment - res, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_3", "dest_3", "att_2") + count, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_3", "dest_3", "att_2") require.NoError(t, err) - assert.Equal(t, 2, res.Count) - assert.True(t, res.NewlyCounted) + assert.Equal(t, 2, count) // Replay the second attempt — count should not change - res, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_3", "dest_3", "att_2") + count, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_3", "dest_3", "att_2") require.NoError(t, err) - assert.Equal(t, 2, res.Count, "replaying the same attemptID should not increment the count") - assert.False(t, res.NewlyCounted) - }) - - t.Run("mark attempt evaluated", func(t *testing.T) { - t.Parallel() - redisClient := testutil.CreateTestRedisClient(t) - store := alert.NewRedisAlertStore(redisClient, "") - - // Counted but not yet evaluated - res, err := store.IncrementConsecutiveFailureCount(context.Background(), "tenant_4", "dest_4", "att_1") - require.NoError(t, err) - assert.False(t, res.AlreadyEvaluated, "attempt should not be evaluated before MarkAttemptEvaluated") - - // Replay before marking — still not evaluated (partial-failure recovery path) - res, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_4", "dest_4", "att_1") - require.NoError(t, err) - assert.False(t, res.NewlyCounted) - assert.False(t, res.AlreadyEvaluated) - - // Mark evaluated - err = store.MarkAttemptEvaluated(context.Background(), "tenant_4", "dest_4", "att_1") - require.NoError(t, err) - - // Replay after marking — evaluated - res, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_4", "dest_4", "att_1") - require.NoError(t, err) - assert.False(t, res.NewlyCounted) - assert.True(t, res.AlreadyEvaluated, "attempt should be evaluated after MarkAttemptEvaluated") - - // Other attempts unaffected - res, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_4", "dest_4", "att_2") - require.NoError(t, err) - assert.True(t, res.NewlyCounted) - assert.False(t, res.AlreadyEvaluated) - }) - - t.Run("reset clears evaluated markers", func(t *testing.T) { - t.Parallel() - redisClient := testutil.CreateTestRedisClient(t) - store := alert.NewRedisAlertStore(redisClient, "") - - _, err := store.IncrementConsecutiveFailureCount(context.Background(), "tenant_5", "dest_5", "att_1") - require.NoError(t, err) - require.NoError(t, store.MarkAttemptEvaluated(context.Background(), "tenant_5", "dest_5", "att_1")) - - err = store.ResetConsecutiveFailureCount(context.Background(), "tenant_5", "dest_5") - require.NoError(t, err) - - res, err := store.IncrementConsecutiveFailureCount(context.Background(), "tenant_5", "dest_5", "att_1") - require.NoError(t, err) - assert.True(t, res.NewlyCounted) - assert.False(t, res.AlreadyEvaluated, "reset should clear evaluated markers") + assert.Equal(t, 2, count, "replaying the same attemptID should not increment the count") }) } @@ -140,23 +83,23 @@ func TestRedisAlertStore_WithDeploymentID(t *testing.T) { store := alert.NewRedisAlertStore(redisClient, "dp_test_001") // Test increment with deployment ID - res, err := store.IncrementConsecutiveFailureCount(context.Background(), "tenant_1", "dest_1", "att_1") + count, err := store.IncrementConsecutiveFailureCount(context.Background(), "tenant_1", "dest_1", "att_1") require.NoError(t, err) - assert.Equal(t, 1, res.Count) + assert.Equal(t, 1, count) // Second increment - res, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_1", "dest_1", "att_2") + count, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_1", "dest_1", "att_2") require.NoError(t, err) - assert.Equal(t, 2, res.Count) + assert.Equal(t, 2, count) // Test reset with deployment ID err = store.ResetConsecutiveFailureCount(context.Background(), "tenant_1", "dest_1") require.NoError(t, err) // Verify counter is reset - res, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_1", "dest_1", "att_3") + count, err = store.IncrementConsecutiveFailureCount(context.Background(), "tenant_1", "dest_1", "att_3") require.NoError(t, err) - assert.Equal(t, 1, res.Count) + assert.Equal(t, 1, count) } func TestAlertStoreTenantIsolation(t *testing.T) { @@ -174,35 +117,29 @@ func TestAlertStoreTenantIsolation(t *testing.T) { tenantB := "tenant_b" // Increment for tenant A. - resA, err := store.IncrementConsecutiveFailureCount(context.Background(), tenantA, destinationID, "att_1") + countA, err := store.IncrementConsecutiveFailureCount(context.Background(), tenantA, destinationID, "att_1") require.NoError(t, err) - assert.Equal(t, 1, resA.Count) + assert.Equal(t, 1, countA) - resA, err = store.IncrementConsecutiveFailureCount(context.Background(), tenantA, destinationID, "att_2") + countA, err = store.IncrementConsecutiveFailureCount(context.Background(), tenantA, destinationID, "att_2") require.NoError(t, err) - assert.Equal(t, 2, resA.Count) + assert.Equal(t, 2, countA) // Tenant B uses the same destination id but must have its own counter. - resB, err := store.IncrementConsecutiveFailureCount(context.Background(), tenantB, destinationID, "att_1") + countB, err := store.IncrementConsecutiveFailureCount(context.Background(), tenantB, destinationID, "att_1") require.NoError(t, err) - assert.Equal(t, 1, resB.Count, "tenant B should not inherit tenant A's failure count") - - // Evaluated markers are tenant-scoped too. - require.NoError(t, store.MarkAttemptEvaluated(context.Background(), tenantA, destinationID, "att_1")) - resB, err = store.IncrementConsecutiveFailureCount(context.Background(), tenantB, destinationID, "att_1") - require.NoError(t, err) - assert.False(t, resB.AlreadyEvaluated, "tenant B should not see tenant A's evaluated marker") + assert.Equal(t, 1, countB, "tenant B should not inherit tenant A's failure count") // Resetting tenant A must not clear tenant B's counter. require.NoError(t, store.ResetConsecutiveFailureCount(context.Background(), tenantA, destinationID)) - resA, err = store.IncrementConsecutiveFailureCount(context.Background(), tenantA, destinationID, "att_3") + countA, err = store.IncrementConsecutiveFailureCount(context.Background(), tenantA, destinationID, "att_3") require.NoError(t, err) - assert.Equal(t, 1, resA.Count, "tenant A should be reset") + assert.Equal(t, 1, countA, "tenant A should be reset") - resB, err = store.IncrementConsecutiveFailureCount(context.Background(), tenantB, destinationID, "att_2") + countB, err = store.IncrementConsecutiveFailureCount(context.Background(), tenantB, destinationID, "att_2") require.NoError(t, err) - assert.Equal(t, 2, resB.Count, "tenant B should be unaffected by tenant A reset") + assert.Equal(t, 2, countB, "tenant B should be unaffected by tenant A reset") } func TestAlertStoreIsolation(t *testing.T) { @@ -219,41 +156,35 @@ func TestAlertStoreIsolation(t *testing.T) { destinationID := "dest_shared" // Increment in store1 - res1, err := store1.IncrementConsecutiveFailureCount(context.Background(), tenantID, destinationID, "att_1") + count1, err := store1.IncrementConsecutiveFailureCount(context.Background(), tenantID, destinationID, "att_1") require.NoError(t, err) - assert.Equal(t, 1, res1.Count) + assert.Equal(t, 1, count1) - res1, err = store1.IncrementConsecutiveFailureCount(context.Background(), tenantID, destinationID, "att_2") + count1, err = store1.IncrementConsecutiveFailureCount(context.Background(), tenantID, destinationID, "att_2") require.NoError(t, err) - assert.Equal(t, 2, res1.Count) + assert.Equal(t, 2, count1) // Increment in store2 - should start at 1 (isolated from store1) - res2, err := store2.IncrementConsecutiveFailureCount(context.Background(), tenantID, destinationID, "att_1") - require.NoError(t, err) - assert.Equal(t, 1, res2.Count, "Store 2 should have its own counter") - - // Evaluated markers are isolated too - require.NoError(t, store1.MarkAttemptEvaluated(context.Background(), tenantID, destinationID, "att_1")) - res2, err = store2.IncrementConsecutiveFailureCount(context.Background(), tenantID, destinationID, "att_1") + count2, err := store2.IncrementConsecutiveFailureCount(context.Background(), tenantID, destinationID, "att_1") require.NoError(t, err) - assert.False(t, res2.AlreadyEvaluated, "Store 2 should not see store 1's evaluated marker") + assert.Equal(t, 1, count2, "Store 2 should have its own counter") // Increment store1 again - should continue from 2 - res1, err = store1.IncrementConsecutiveFailureCount(context.Background(), tenantID, destinationID, "att_3") + count1, err = store1.IncrementConsecutiveFailureCount(context.Background(), tenantID, destinationID, "att_3") require.NoError(t, err) - assert.Equal(t, 3, res1.Count, "Store 1 counter should be unaffected by store 2") + assert.Equal(t, 3, count1, "Store 1 counter should be unaffected by store 2") // Reset store1 - should not affect store2 err = store1.ResetConsecutiveFailureCount(context.Background(), tenantID, destinationID) require.NoError(t, err) // Verify store1 is reset - res1, err = store1.IncrementConsecutiveFailureCount(context.Background(), tenantID, destinationID, "att_4") + count1, err = store1.IncrementConsecutiveFailureCount(context.Background(), tenantID, destinationID, "att_4") require.NoError(t, err) - assert.Equal(t, 1, res1.Count, "Store 1 should be reset") + assert.Equal(t, 1, count1, "Store 1 should be reset") // Verify store2 is unaffected - res2, err = store2.IncrementConsecutiveFailureCount(context.Background(), tenantID, destinationID, "att_2") + count2, err = store2.IncrementConsecutiveFailureCount(context.Background(), tenantID, destinationID, "att_2") require.NoError(t, err) - assert.Equal(t, 2, res2.Count, "Store 2 should be unaffected by store 1 reset") + assert.Equal(t, 2, count2, "Store 2 should be unaffected by store 1 reset") } diff --git a/internal/alert/threshold.go b/internal/alert/threshold.go new file mode 100644 index 000000000..4df4429e2 --- /dev/null +++ b/internal/alert/threshold.go @@ -0,0 +1,88 @@ +package alert + +import ( + "sort" +) + +type thresholdPair struct { + percentage int + failures int +} + +// thresholdEvaluator maps a consecutive-failure count to the alert threshold +// it crosses, if any. +type thresholdEvaluator struct { + thresholds []thresholdPair // sorted pairs of percentage and failure counts + autoDisableFailureCount int +} + +// newThresholdEvaluator converts percentage thresholds into failure counts +// against the auto-disable count (the 100% denominator), always including the +// 100% threshold. +func newThresholdEvaluator(thresholds []int, autoDisableFailureCount int) thresholdEvaluator { + // Create pairs of percentage thresholds and their corresponding failure counts + finalThresholds := make([]thresholdPair, 0, len(thresholds)) + + // Convert percentages to failure counts + for _, percentage := range thresholds { + // Skip invalid percentages + if percentage <= 0 || percentage > 100 { + continue + } + // Ceiling division: (a + b - 1) / b + failures := (int(autoDisableFailureCount)*int(percentage) + 99) / 100 + finalThresholds = append(finalThresholds, thresholdPair{ + percentage: percentage, + failures: failures, + }) + } + + sort.Slice(finalThresholds, func(i, j int) bool { return finalThresholds[i].failures < finalThresholds[j].failures }) + + // Check if we need to add 100 + needsAutoDisable := true + if len(finalThresholds) > 0 && finalThresholds[len(finalThresholds)-1].percentage == 100 { + needsAutoDisable = false + } + + // Auto-include 100% threshold if not present + if needsAutoDisable { + finalThresholds = append(finalThresholds, thresholdPair{ + percentage: 100, + failures: autoDisableFailureCount, + }) + } + + return thresholdEvaluator{ + thresholds: finalThresholds, + autoDisableFailureCount: autoDisableFailureCount, + } +} + +func (e thresholdEvaluator) shouldAlert(failures int) (int, bool) { + // If no thresholds configured, never alert + if len(e.thresholds) == 0 { + return 0, false + } + + // Get current alert level + // Iterate from highest to lowest threshold + for i := len(e.thresholds) - 1; i >= 0; i-- { + threshold := e.thresholds[i] + + // For the 100% threshold (auto-disable), use >= to ensure we don't miss it + // if concurrent processing causes us to skip over the exact count. + // For other thresholds, use exact match to avoid duplicate alerts. + if threshold.percentage == 100 { + if failures >= threshold.failures { + return threshold.percentage, true + } + } else { + if failures == threshold.failures { + return threshold.percentage, true + } + } + } + + return 0, false +} diff --git a/internal/apirouter/destination_handlers.go b/internal/apirouter/destination_handlers.go index 18b90a9ff..450ab0936 100644 --- a/internal/apirouter/destination_handlers.go +++ b/internal/apirouter/destination_handlers.go @@ -15,6 +15,7 @@ import ( "github.com/hookdeck/outpost/internal/idgen" "github.com/hookdeck/outpost/internal/logging" "github.com/hookdeck/outpost/internal/models" + "github.com/hookdeck/outpost/internal/opevents" "github.com/hookdeck/outpost/internal/telemetry" "github.com/hookdeck/outpost/internal/tenantstore" "github.com/hookdeck/outpost/internal/util/maputil" @@ -24,16 +25,7 @@ import ( // SubscriptionEmitter emits operator events for subscription changes. // Satisfied by opevents.Emitter. type SubscriptionEmitter interface { - Emit(ctx context.Context, topic string, tenantID string, data any) error -} - -// TenantSubscriptionUpdatedData is the data payload for tenant.subscription.updated events. -type TenantSubscriptionUpdatedData struct { - TenantID string `json:"tenant_id"` - Topics []string `json:"topics"` - PreviousTopics []string `json:"previous_topics"` - DestinationsCount int `json:"destinations_count"` - PreviousDestinationsCount int `json:"previous_destinations_count"` + Emit(ctx context.Context, ev opevents.Event) error } type DestinationHandlers struct { @@ -572,14 +564,13 @@ func (h *DestinationHandlers) emitSubscriptionUpdateIfChanged(ctx context.Contex return } - data := TenantSubscriptionUpdatedData{ + if err := h.emitter.Emit(ctx, opevents.TenantSubscriptionUpdatedEvent(opevents.TenantSubscriptionUpdatedData{ TenantID: tenantID, Topics: tenant.Topics, PreviousTopics: prev.topics, DestinationsCount: tenant.DestinationsCount, PreviousDestinationsCount: prev.destinationsCount, - } - if err := h.emitter.Emit(ctx, "tenant.subscription.updated", tenantID, data); err != nil { + })); err != nil { h.logger.Ctx(ctx).Error("failed to emit subscription update", zap.Error(err)) } } diff --git a/internal/apirouter/destination_handlers_test.go b/internal/apirouter/destination_handlers_test.go index ff90ed8e2..893e5400d 100644 --- a/internal/apirouter/destination_handlers_test.go +++ b/internal/apirouter/destination_handlers_test.go @@ -7,9 +7,9 @@ import ( "testing" "time" - "github.com/hookdeck/outpost/internal/apirouter" "github.com/hookdeck/outpost/internal/destregistry" "github.com/hookdeck/outpost/internal/models" + "github.com/hookdeck/outpost/internal/opevents" "github.com/hookdeck/outpost/internal/tenantstore" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" @@ -1279,7 +1279,7 @@ func TestAPI_SubscriptionUpdated(t *testing.T) { assert.Equal(t, "tenant.subscription.updated", call.topic) assert.Equal(t, "t1", call.tenantID) - data := call.data.(apirouter.TenantSubscriptionUpdatedData) + data := call.data.(opevents.TenantSubscriptionUpdatedData) assert.Equal(t, 1, data.DestinationsCount) assert.Equal(t, 0, data.PreviousDestinationsCount) }) @@ -1295,7 +1295,7 @@ func TestAPI_SubscriptionUpdated(t *testing.T) { require.Equal(t, http.StatusOK, resp.Code) require.Len(t, h.subscriptionEmitter.calls, 1) - data := h.subscriptionEmitter.calls[0].data.(apirouter.TenantSubscriptionUpdatedData) + data := h.subscriptionEmitter.calls[0].data.(opevents.TenantSubscriptionUpdatedData) assert.Equal(t, 0, data.DestinationsCount) assert.Equal(t, 1, data.PreviousDestinationsCount) }) @@ -1315,7 +1315,7 @@ func TestAPI_SubscriptionUpdated(t *testing.T) { require.Equal(t, http.StatusOK, resp.Code) require.Len(t, h.subscriptionEmitter.calls, 1) - data := h.subscriptionEmitter.calls[0].data.(apirouter.TenantSubscriptionUpdatedData) + data := h.subscriptionEmitter.calls[0].data.(opevents.TenantSubscriptionUpdatedData) assert.Contains(t, data.Topics, "user.deleted") assert.Contains(t, data.PreviousTopics, "user.created") }) diff --git a/internal/apirouter/router_test.go b/internal/apirouter/router_test.go index 4d0427888..3569966c2 100644 --- a/internal/apirouter/router_test.go +++ b/internal/apirouter/router_test.go @@ -16,6 +16,7 @@ import ( "github.com/hookdeck/outpost/internal/logging" "github.com/hookdeck/outpost/internal/logstore" "github.com/hookdeck/outpost/internal/models" + "github.com/hookdeck/outpost/internal/opevents" "github.com/hookdeck/outpost/internal/portal" "github.com/hookdeck/outpost/internal/publishmq" "github.com/hookdeck/outpost/internal/telemetry" @@ -244,8 +245,8 @@ type emitCall struct { data any } -func (m *mockSubscriptionEmitter) Emit(_ context.Context, topic string, tenantID string, data any) error { - m.calls = append(m.calls, emitCall{topic: topic, tenantID: tenantID, data: data}) +func (m *mockSubscriptionEmitter) Emit(_ context.Context, ev opevents.Event) error { + m.calls = append(m.calls, emitCall{topic: ev.Topic, tenantID: ev.TenantID, data: ev.Data}) return nil } diff --git a/internal/idempotence/idempotence.go b/internal/idempotence/idempotence.go index 564697641..425a4562a 100644 --- a/internal/idempotence/idempotence.go +++ b/internal/idempotence/idempotence.go @@ -19,8 +19,20 @@ const ( var ErrConflict = errors.New("conflict") +// Idempotence deduplicates work by key. Exec is the packaged form: it claims +// the key, runs the callback, and marks the key processed — for work that +// completes within one call. Processed and MarkProcessed expose the check and +// mark phases separately, for callers whose work spans a boundary Exec can't +// wrap (e.g. the effects finish on another goroutine); such callers get no +// in-flight conflict detection — concurrent duplicates both run, so their +// effects must tolerate duplication. type Idempotence interface { Exec(ctx context.Context, key string, exec func(context.Context) error) error + // Processed reports whether key was marked processed (by MarkProcessed or + // a successful Exec) within the SuccessfulTTL window. + Processed(ctx context.Context, key string) (bool, error) + // MarkProcessed marks key processed for the SuccessfulTTL window. + MarkProcessed(ctx context.Context, key string) error } type IdempotenceImpl struct { @@ -151,6 +163,23 @@ func (i *IdempotenceImpl) Exec(ctx context.Context, key string, exec func(contex return nil } +func (i *IdempotenceImpl) Processed(ctx context.Context, key string) (bool, error) { + status, err := i.getIdempotencyStatus(ctx, i.prefixKey(key)) + if err != nil { + if errors.Is(err, redis.Nil) { + return false, nil + } + return false, err + } + // A "processing" claim from an in-flight Exec does not count as processed: + // the caller re-runs, which split-phase users must tolerate anyway. + return status == StatusProcessed, nil +} + +func (i *IdempotenceImpl) MarkProcessed(ctx context.Context, key string) error { + return i.markProcessedIdempotency(ctx, i.prefixKey(key)) +} + func (i *IdempotenceImpl) checkIdempotency(ctx context.Context, idempotencyKey string) (bool, error) { idempotentValue, err := i.redisClient.SetNX(ctx, idempotencyKey, StatusProcessing, i.options.Timeout).Result() if err != nil { diff --git a/internal/idempotence/idempotence_test.go b/internal/idempotence/idempotence_test.go index 269bcb361..ac0ff2de0 100644 --- a/internal/idempotence/idempotence_test.go +++ b/internal/idempotence/idempotence_test.go @@ -5,6 +5,7 @@ import ( "errors" "log" "strconv" + "sync/atomic" "testing" "time" @@ -17,7 +18,9 @@ import ( "github.com/stretchr/testify/require" ) -func setupCountExec(_ *testing.T, ctx context.Context, timeout time.Duration, ex func() error) (exec func(context.Context) error, countexec func(count *int), cleanup func()) { +// The counter is atomic: countexec increments it from its own goroutine while +// the test body reads it. +func setupCountExec(_ *testing.T, ctx context.Context, timeout time.Duration, ex func() error) (exec func(context.Context) error, countexec func(count *atomic.Int64), cleanup func()) { execchan := make(chan struct{}, 10) // buffered to prevent blocking senders exec = func(_ context.Context) error { time.Sleep(timeout) @@ -30,11 +33,11 @@ func setupCountExec(_ *testing.T, ctx context.Context, timeout time.Duration, ex cleanup = func() { // no-op: let channel be garbage collected } - countexec = func(count *int) { + countexec = func(count *atomic.Int64) { for { select { case <-execchan: - *count++ + count.Add(1) case <-ctx.Done(): return } @@ -66,10 +69,10 @@ func TestIdempotence_Success(t *testing.T) { i.Exec(ctx, "2", exec) // 2nd exec }() // Assert - count := 0 + var count atomic.Int64 go countexec(&count) <-ctx.Done() - assert.Equal(t, 2, count, "should execute twice") + assert.EqualValues(t, 2, count.Load(), "should execute twice") }) t.Run("when 2nd exec is within processing window", func(t *testing.T) { @@ -91,13 +94,13 @@ func TestIdempotence_Success(t *testing.T) { }() // Assert - wait for 2nd exec to complete // Note: idempotence waits for full timeout (1s) when it detects a concurrent operation - count := 0 + var count atomic.Int64 go countexec(&count) select { case err := <-errchan: time.Sleep(50 * time.Millisecond) // let countexec collect assert.Nil(t, err, "should not return error") - assert.Equal(t, 1, count, "should execute once") + assert.EqualValues(t, 1, count.Load(), "should execute once") case <-time.After(2 * time.Second): require.Fail(t, "timeout waiting for 2nd exec") } @@ -121,13 +124,13 @@ func TestIdempotence_Success(t *testing.T) { errchan <- i.Exec(ctx, key, exec) // 2nd exec }() // Assert - wait for 2nd exec to complete - count := 0 + var count atomic.Int64 go countexec(&count) select { case err := <-errchan: time.Sleep(50 * time.Millisecond) // let countexec collect assert.Nil(t, err, "should not return error") - assert.Equal(t, 1, count, "should execute once") + assert.EqualValues(t, 1, count.Load(), "should execute once") case <-time.After(2 * time.Second): require.Fail(t, "timeout waiting for 2nd exec") } @@ -183,6 +186,114 @@ func TestIdempotence_WithDeploymentID(t *testing.T) { }) } +func TestIdempotence_SplitPhase(t *testing.T) { + t.Parallel() + + i := idempotence.New(testutil.CreateTestRedisClient(t), + idempotence.WithTimeout(1*time.Second), + idempotence.WithSuccessfulTTL(24*time.Hour), + ) + + t.Run("unseen key is not processed", func(t *testing.T) { + t.Parallel() + ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second) + defer cancel() + + processed, err := i.Processed(ctx, testutil.RandomString(5)) + require.NoError(t, err) + assert.False(t, processed) + }) + + t.Run("MarkProcessed makes the key processed", func(t *testing.T) { + t.Parallel() + ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second) + defer cancel() + + key := testutil.RandomString(5) + require.NoError(t, i.MarkProcessed(ctx, key)) + + processed, err := i.Processed(ctx, key) + require.NoError(t, err) + assert.True(t, processed) + }) + + t.Run("successful Exec marks the key processed", func(t *testing.T) { + t.Parallel() + ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second) + defer cancel() + + key := testutil.RandomString(5) + require.NoError(t, i.Exec(ctx, key, func(ctx context.Context) error { return nil })) + + processed, err := i.Processed(ctx, key) + require.NoError(t, err) + assert.True(t, processed) + }) + + t.Run("MarkProcessed makes Exec skip", func(t *testing.T) { + t.Parallel() + ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second) + defer cancel() + + key := testutil.RandomString(5) + require.NoError(t, i.MarkProcessed(ctx, key)) + + executed := false + require.NoError(t, i.Exec(ctx, key, func(ctx context.Context) error { + executed = true + return nil + })) + assert.False(t, executed, "Exec should skip a key marked processed") + }) + + t.Run("in-flight Exec claim does not count as processed", func(t *testing.T) { + t.Parallel() + ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second) + defer cancel() + + key := testutil.RandomString(5) + entered := make(chan struct{}) + release := make(chan struct{}) + done := make(chan error, 1) + go func() { + done <- i.Exec(ctx, key, func(ctx context.Context) error { + close(entered) + <-release + return nil + }) + }() + + <-entered + processed, err := i.Processed(ctx, key) + require.NoError(t, err) + assert.False(t, processed, "a processing claim is not processed") + + close(release) + require.NoError(t, <-done) + }) + + t.Run("deployment IDs scope split-phase keys", func(t *testing.T) { + t.Parallel() + ctx, cancel := context.WithTimeout(context.Background(), 2*time.Second) + defer cancel() + + redisClient := testutil.CreateTestRedisClient(t) + iA := idempotence.New(redisClient, idempotence.WithDeploymentID("dp_a")) + iB := idempotence.New(redisClient, idempotence.WithDeploymentID("dp_b")) + + key := testutil.RandomString(5) + require.NoError(t, iA.MarkProcessed(ctx, key)) + + processed, err := iB.Processed(ctx, key) + require.NoError(t, err) + assert.False(t, processed, "marks must not leak across deployments") + + processed, err = iA.Processed(ctx, key) + require.NoError(t, err) + assert.True(t, processed) + }) +} + func TestIdempotenceIsolation(t *testing.T) { t.Parallel() @@ -284,13 +395,13 @@ func TestIdempotence_Failure(t *testing.T) { case <-time.After(2 * time.Second): require.Fail(t, "timeout waiting for err2") } - count := 0 + var count atomic.Int64 go countexec(&count) time.Sleep(50 * time.Millisecond) // let countexec collect cancel() // stop countexec assert.Equal(t, errExec, err1, "first execution should return exec error") assert.Equal(t, idempotence.ErrConflict, err2, "second execution should return conflict error") - assert.Equal(t, 1, count, "should execute once") + assert.EqualValues(t, 1, count.Load(), "should execute once") }) t.Run("when 2nd exec is after 1st exec completion", func(t *testing.T) { @@ -323,13 +434,13 @@ func TestIdempotence_Failure(t *testing.T) { require.Fail(t, "timeout waiting for err2") } // Assert - count := 0 + var count atomic.Int64 go countexec(&count) time.Sleep(50 * time.Millisecond) // let countexec collect cancel() // stop countexec assert.Equal(t, errExec, err1, "first execution should return exec error") assert.Equal(t, errExec, err2, "second execution should return exec error") - assert.Equal(t, 2, count, "should execute twice") + assert.EqualValues(t, 2, count.Load(), "should execute twice") }) } diff --git a/internal/logmq/batchprocessor.go b/internal/logmq/batchprocessor.go index 6874f1423..53018225f 100644 --- a/internal/logmq/batchprocessor.go +++ b/internal/logmq/batchprocessor.go @@ -3,12 +3,14 @@ package logmq import ( "context" "errors" + "sync" "time" "github.com/hookdeck/outpost/internal/alert" "github.com/hookdeck/outpost/internal/logging" "github.com/hookdeck/outpost/internal/models" "github.com/hookdeck/outpost/internal/mqs" + "github.com/hookdeck/outpost/internal/opevents" "github.com/mikestefanello/batcher" "go.uber.org/zap" ) @@ -22,33 +24,198 @@ type LogStore interface { InsertMany(ctx context.Context, entries []*models.LogEntry) error } -// AlertMonitor evaluates delivery attempts for alert conditions. -type AlertMonitor interface { - HandleAttempt(ctx context.Context, attempt alert.DeliveryAttempt) error +// AlertEvaluator evaluates one delivery attempt against the destination's +// failure history and returns the tracker's verdict as data. Acting on the +// verdict (opevents, auto-disable, replay dedup) is owned by the batch +// processor. +type AlertEvaluator interface { + Evaluate(ctx context.Context, attempt alert.Attempt) (alert.Evaluation, error) } -// BatchProcessorConfig configures the batch processor. +// DestinationDisabler disables destinations that hit the auto-disable +// threshold. +type DestinationDisabler interface { + DisableDestination(ctx context.Context, tenantID, destinationID string) error +} + +// ReplayGate is the split-phase idempotence pair the pipeline uses as the +// per-attempt replay gate: Processed is checked before eval, MarkProcessed +// lands after delivery. Split-phase means no in-flight conflict detection — +// concurrent duplicates both run and may both emit (tolerated: opevents are +// at-least-once). Satisfied by idempotence.Idempotence. +type ReplayGate interface { + Processed(ctx context.Context, key string) (bool, error) + MarkProcessed(ctx context.Context, key string) error +} + +// SuppressionWindow wraps one send in a keyed dedup window: within the window +// the send is skipped and counts as delivered. Satisfied by +// idempotence.Idempotence. +type SuppressionWindow interface { + Exec(ctx context.Context, key string, exec func(context.Context) error) error +} + +// AlertPipeline groups the post-persist alert pipeline: evaluate the attempt, +// act on the verdict (disable, opevents), and dedup replays. +type AlertPipeline struct { + // Evaluator is the alert tracker. Nil disables the pipeline entirely. + Evaluator AlertEvaluator + // Emitter delivers the operator events. Required when Evaluator is set. + Emitter opevents.Emitter + // Disabler auto-disables a destination when the 100% threshold is crossed. + // Nil disables auto-disable. + Disabler DestinationDisabler + // ProcessedIdemp is the per-attempt replay gate: a replay of a fully + // processed failed attempt is skipped instead of re-counting/re-alerting. + // Required when Evaluator is set. + ProcessedIdemp ReplayGate + // ExhaustedIdemp is the per-(event,destination) suppression window for + // exhausted-retries alerts. Nil means no suppression (alert on every + // exhaustion). + ExhaustedIdemp SuppressionWindow +} + +// BatchProcessorConfig configures the batch processor. The pool fields are +// test-only overrides: zero means "derive from ItemCountThreshold" (see the +// derive* functions), which is how production always runs — no extra knobs. type BatchProcessorConfig struct { ItemCountThreshold int DelayThreshold time.Duration + // PostprocessShards is the postprocess pool's shard count — the eval + // parallelism across destinations (same destination always evaluates + // serially). Zero derives from ItemCountThreshold. + PostprocessShards int + // PostprocessShardQueueDepth bounds each shard's queue; a full shard + // blocks the batch loop (backpressure). Zero derives. + PostprocessShardQueueDepth int + // DeliveryConcurrency is the opevent delivery pool's worker count. + // Zero derives from ItemCountThreshold. + DeliveryConcurrency int + // DeliveryQueueDepth bounds the delivery queue; a full queue blocks the + // postprocess pool's workers (backpressure). Zero means 2× concurrency. + DeliveryQueueDepth int +} + +// Pool sizing derives from ItemCountThreshold (LOG_BATCH_SIZE), which doubles +// as the operator's throughput declaration: batches are sized to roughly one +// second of traffic, so LogBatchSize ≈ entries/second. The heuristic is wrong +// only in the cheap direction — an oversized batch buys idle shards (parked +// goroutines) and deeper-but-bounded queues. +// +// The safety bound behind all of it: a fetched message must reach its +// terminal state within the broker's visibility window (~60s), or it +// redelivers while still held. In-flight is bounded (a full queue blocks its +// producer, all the way back to the consumer fetch), so worst-case ack +// latency is +// +// held/drain ≈ (2×batch + 3×workers) / (workers/emitTimeout) +// +// which the derived values keep under the window with margin (~17s vs ~60s +// until the worker cap binds; see sizing_test.go) even with every send at +// emitTimeout. +const ( + // evalsPerShardPerSec is the eval throughput one shard sustains: an eval + // is ~2ms of Redis ops (≈500/s), halved for headroom because the disable + // path also writes the DB inside the ordered lane. + evalsPerShardPerSec = 250 + // minPostprocessShards keeps small deployments' eval lane comfortably + // ahead of intake; a shard costs one parked goroutine + one channel. + minPostprocessShards = 8 + // maxPostprocessShards marks where shard count stops being the + // bottleneck: 64 shards claim >16k evals/s through one Redis and one + // intake consumer — horizontal-scale territory. + maxPostprocessShards = 64 + + minDeliveryConcurrency = 10 + // maxDeliveryConcurrency caps the derived worker count (reached at + // LOG_BATCH_SIZE ≈ 1640). With the cap, a timeout-pinned sink stays + // visibility-safe up to LOG_BATCH_SIZE ≈ 37k (see sizing_test.go); + // deployments past that scale horizontally. + maxDeliveryConcurrency = 8192 +) + +// derivePostprocessShards sizes eval parallelism to intake: shards × +// evalsPerShardPerSec must cover LogBatchSize entries/second, so the ordered +// lane is never the pipeline's bottleneck. +func derivePostprocessShards(batchSize int) int { + return clamp(batchSize/evalsPerShardPerSec, minPostprocessShards, maxPostprocessShards) +} + +// derivePostprocessShardQueueDepth spreads one full batch across the shard +// queues (depth × shards ≈ LogBatchSize): dispatching a batch never blocks +// while the pipeline is healthy, so batch N+1's persist never waits on a +// merely-busy (vs stuck) stage. A stuck shard still backpressures — depth is +// finite. +func derivePostprocessShardQueueDepth(batchSize, shards int) int { + return max(1, (batchSize+shards-1)/shards) +} + +// deriveDeliveryConcurrency sizes the pool for full line rate at the worst +// send latency the emit timeout accepts: workers = rate × latency = +// LogBatchSize/s × emitTimeout. A sink may run at the timeout's edge +// indefinitely without the pipeline falling behind; past the timeout, sends +// fail into nack/redelivery, which no worker count can (or should) mask. +// Events-per-attempt doesn't factor in: a worker fans an attempt's sends out +// concurrently, so it is occupied ~one send latency regardless of K. +func deriveDeliveryConcurrency(batchSize int) int { + return clamp(batchSize*int(emitTimeout/time.Second), minDeliveryConcurrency, maxDeliveryConcurrency) +} + +func clamp(v, lo, hi int) int { + return min(max(v, lo), hi) } // BatchProcessor batches log entries and writes them to the log store. type BatchProcessor struct { - ctx context.Context - logger *logging.Logger - logStore LogStore - alertMonitor AlertMonitor - batcher *batcher.Batcher[*mqs.Message] + ctx context.Context + logger *logging.Logger + logStore LogStore + alerts AlertPipeline + batcher *batcher.Batcher[*mqs.Message] + // Both pools are nil in persist-only mode (no Evaluator — the pipeline + // then just inserts and acks; production always wires an Evaluator). + postprocessPool *postprocessPool // stage 1: ordered eval + disable + plan + deliveryPool *deliveryPool // stage 2: unordered opevent delivery + shutdownOnce sync.Once } // NewBatchProcessor creates a new batch processor for log entries. -func NewBatchProcessor(ctx context.Context, logger *logging.Logger, logStore LogStore, alertMonitor AlertMonitor, cfg BatchProcessorConfig) (*BatchProcessor, error) { +func NewBatchProcessor(ctx context.Context, logger *logging.Logger, logStore LogStore, alerts AlertPipeline, cfg BatchProcessorConfig) (*BatchProcessor, error) { + if alerts.Evaluator != nil { + if alerts.Emitter == nil { + return nil, errors.New("logmq: AlertPipeline requires an Emitter when Evaluator is set") + } + if alerts.ProcessedIdemp == nil { + return nil, errors.New("logmq: AlertPipeline requires a ProcessedIdemp when Evaluator is set") + } + } bp := &BatchProcessor{ - ctx: ctx, - logger: logger, - logStore: logStore, - alertMonitor: alertMonitor, + ctx: ctx, + logger: logger, + logStore: logStore, + alerts: alerts, + } + + if alerts.Evaluator != nil { + concurrency := cfg.DeliveryConcurrency + if concurrency <= 0 { + concurrency = deriveDeliveryConcurrency(cfg.ItemCountThreshold) + } + queueDepth := cfg.DeliveryQueueDepth + if queueDepth <= 0 { + queueDepth = 2 * concurrency + } + bp.deliveryPool = newDeliveryPool(ctx, logger, alerts, concurrency, queueDepth) + + shards := cfg.PostprocessShards + if shards <= 0 { + shards = derivePostprocessShards(cfg.ItemCountThreshold) + } + shardDepth := cfg.PostprocessShardQueueDepth + if shardDepth <= 0 { + shardDepth = derivePostprocessShardQueueDepth(cfg.ItemCountThreshold, shards) + } + bp.postprocessPool = newPostprocessPool(ctx, logger, alerts, bp.deliveryPool, shards, shardDepth) } b, err := batcher.NewBatcher(batcher.Config[*mqs.Message]{ @@ -72,9 +239,21 @@ func (bp *BatchProcessor) Add(ctx context.Context, msg *mqs.Message) error { return nil } -// Shutdown gracefully shuts down the batch processor. +// Shutdown gracefully shuts down the batch processor, upstream first so each +// stage drains with no concurrent producers: the batcher (flushes pending +// batches, which may still dispatch), then the postprocess pool (draining workers +// may still enqueue deliveries), then the delivery pool. Every in-flight +// message reaches a terminal state before Shutdown returns. Idempotent. func (bp *BatchProcessor) Shutdown() { - bp.batcher.Shutdown() + bp.shutdownOnce.Do(func() { + bp.batcher.Shutdown() + if bp.postprocessPool != nil { + bp.postprocessPool.shutdown() + } + if bp.deliveryPool != nil { + bp.deliveryPool.shutdown() + } + }) } // processBatch processes a batch of messages. @@ -167,9 +346,11 @@ func (bp *BatchProcessor) processBatch(_ string, msgs []*mqs.Message) { zap.Int("count", len(validMsgs)), zap.Int64("insert_duration_ms", time.Since(insertStart).Milliseconds())) - // Per-entry alert evaluation after successful persistence + // Hand each persisted entry to the postprocess pool — enqueue-and-return + // (unless its shard queue is full), so persistence throughput never waits + // on eval or delivery. for i, entry := range entries { - if bp.alertMonitor == nil { + if bp.alerts.Evaluator == nil { validMsgs[i].Ack() continue } @@ -183,23 +364,18 @@ func (bp *BatchProcessor) processBatch(_ string, msgs []*mqs.Message) { continue } - da := alert.DeliveryAttempt{ - Event: entry.Event, - Destination: alert.AlertDestinationFromDestination(entry.Destination), - Attempt: entry.Attempt, - } - if err := bp.alertMonitor.HandleAttempt(bp.ctx, da); err != nil { - logger.Error("alert evaluation failed", - zap.Error(err), - zap.String("attempt_id", entry.Attempt.ID), - zap.String("event_id", entry.Event.ID), - zap.String("destination_id", entry.Destination.ID)) - // Nack so the message is redelivered. InsertMany is idempotent - // (upsert by attempt ID), so redelivery won't produce duplicate log entries. - validMsgs[i].Nack() - continue - } - - validMsgs[i].Ack() + bp.postprocessPool.dispatch(entry, validMsgs[i]) } } + +// processedKey is the per-attempt replay gate key. Format is stable — changing +// it re-processes in-window replays. +func processedKey(attemptID string) string { + return "logmq:processed:" + attemptID +} + +// exhaustedRetriesKey is the per-(event,destination) suppression key for +// exhausted-retries alerts. Format is stable — changing it resets live windows. +func exhaustedRetriesKey(eventID, destinationID string) string { + return "opevents:exhausted:" + eventID + ":" + destinationID +} diff --git a/internal/logmq/batchprocessor_test.go b/internal/logmq/batchprocessor_test.go index fa300a4b7..bcfddf0e7 100644 --- a/internal/logmq/batchprocessor_test.go +++ b/internal/logmq/batchprocessor_test.go @@ -4,15 +4,18 @@ import ( "context" "encoding/json" "sync" + "sync/atomic" "testing" "time" "errors" "github.com/hookdeck/outpost/internal/alert" + "github.com/hookdeck/outpost/internal/idempotence" "github.com/hookdeck/outpost/internal/logmq" "github.com/hookdeck/outpost/internal/models" "github.com/hookdeck/outpost/internal/mqs" + "github.com/hookdeck/outpost/internal/opevents" "github.com/hookdeck/outpost/internal/util/testutil" "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" @@ -44,14 +47,15 @@ func (m *mockLogStore) getInserted() (events []*models.Event, attempts []*models return events, attempts } -// mockQueueMessage implements mqs.QueueMessage for testing. +// mockQueueMessage implements mqs.QueueMessage for testing. Terminal state is +// atomic: acks/nacks land on pool-worker goroutines. type mockQueueMessage struct { - acked bool - nacked bool + acked atomic.Bool + nacked atomic.Bool } -func (m *mockQueueMessage) Ack() { m.acked = true } -func (m *mockQueueMessage) Nack() { m.nacked = true } +func (m *mockQueueMessage) Ack() { m.acked.Store(true) } +func (m *mockQueueMessage) Nack() { m.nacked.Store(true) } func newMockMessage(entry models.LogEntry) (*mockQueueMessage, *mqs.Message) { body, _ := json.Marshal(entry) @@ -79,7 +83,7 @@ func TestBatchProcessor_ValidEntry(t *testing.T) { logger := testutil.CreateTestLogger(t) logStore := &mockLogStore{} - bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, nil, logmq.BatchProcessorConfig{ + bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, logmq.AlertPipeline{}, logmq.BatchProcessorConfig{ ItemCountThreshold: 1, DelayThreshold: 1 * time.Second, }) @@ -100,8 +104,8 @@ func TestBatchProcessor_ValidEntry(t *testing.T) { // Wait for batch to process time.Sleep(200 * time.Millisecond) - assert.True(t, mock.acked, "valid message should be acked") - assert.False(t, mock.nacked, "valid message should not be nacked") + assert.True(t, mock.acked.Load(), "valid message should be acked") + assert.False(t, mock.nacked.Load(), "valid message should not be nacked") events, attempts := logStore.getInserted() assert.Len(t, events, 1) @@ -113,7 +117,7 @@ func TestBatchProcessor_InvalidEntry_MissingEvent(t *testing.T) { logger := testutil.CreateTestLogger(t) logStore := &mockLogStore{} - bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, nil, logmq.BatchProcessorConfig{ + bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, logmq.AlertPipeline{}, logmq.BatchProcessorConfig{ ItemCountThreshold: 1, DelayThreshold: 1 * time.Second, }) @@ -133,8 +137,8 @@ func TestBatchProcessor_InvalidEntry_MissingEvent(t *testing.T) { // Wait for batch to process time.Sleep(200 * time.Millisecond) - assert.False(t, mock.acked, "invalid message should not be acked") - assert.True(t, mock.nacked, "invalid message should be nacked") + assert.False(t, mock.acked.Load(), "invalid message should not be acked") + assert.True(t, mock.nacked.Load(), "invalid message should be nacked") events, attempts := logStore.getInserted() assert.Empty(t, events, "no events should be inserted for invalid entry") @@ -146,7 +150,7 @@ func TestBatchProcessor_InvalidEntry_MissingAttempt(t *testing.T) { logger := testutil.CreateTestLogger(t) logStore := &mockLogStore{} - bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, nil, logmq.BatchProcessorConfig{ + bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, logmq.AlertPipeline{}, logmq.BatchProcessorConfig{ ItemCountThreshold: 1, DelayThreshold: 1 * time.Second, }) @@ -166,8 +170,8 @@ func TestBatchProcessor_InvalidEntry_MissingAttempt(t *testing.T) { // Wait for batch to process time.Sleep(200 * time.Millisecond) - assert.False(t, mock.acked, "invalid message should not be acked") - assert.True(t, mock.nacked, "invalid message should be nacked") + assert.False(t, mock.acked.Load(), "invalid message should not be acked") + assert.True(t, mock.nacked.Load(), "invalid message should be nacked") events, attempts := logStore.getInserted() assert.Empty(t, events, "no events should be inserted for invalid entry") @@ -179,7 +183,7 @@ func TestBatchProcessor_InvalidEntry_DoesNotBlockBatch(t *testing.T) { logger := testutil.CreateTestLogger(t) logStore := &mockLogStore{} - bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, nil, logmq.BatchProcessorConfig{ + bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, logmq.AlertPipeline{}, logmq.BatchProcessorConfig{ ItemCountThreshold: 3, // Wait for 3 messages before processing DelayThreshold: 1 * time.Second, }) @@ -212,16 +216,16 @@ func TestBatchProcessor_InvalidEntry_DoesNotBlockBatch(t *testing.T) { time.Sleep(200 * time.Millisecond) // Valid messages should be acked - assert.True(t, mock1.acked, "valid message 1 should be acked") - assert.False(t, mock1.nacked, "valid message 1 should not be nacked") + assert.True(t, mock1.acked.Load(), "valid message 1 should be acked") + assert.False(t, mock1.nacked.Load(), "valid message 1 should not be nacked") // Invalid message should be nacked - assert.False(t, mock2.acked, "invalid message should not be acked") - assert.True(t, mock2.nacked, "invalid message should be nacked") + assert.False(t, mock2.acked.Load(), "invalid message should not be acked") + assert.True(t, mock2.nacked.Load(), "invalid message should be nacked") // Valid message 2 should be acked (not blocked by invalid message) - assert.True(t, mock3.acked, "valid message 2 should be acked") - assert.False(t, mock3.nacked, "valid message 2 should not be nacked") + assert.True(t, mock3.acked.Load(), "valid message 2 should be acked") + assert.False(t, mock3.nacked.Load(), "valid message 2 should not be nacked") // Only valid entries should be inserted events, attempts := logStore.getInserted() @@ -233,9 +237,9 @@ func TestBatchProcessor_DuplicateMessages(t *testing.T) { ctx := context.Background() logger := testutil.CreateTestLogger(t) logStore := &mockLogStore{} - alertMon := &mockAlertMonitor{} + alertMon := &mockAlertEvaluator{} - bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, alertMon, logmq.BatchProcessorConfig{ + bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, testAlertPipeline(t, alertMon), logmq.BatchProcessorConfig{ ItemCountThreshold: 3, // Wait for 3 messages before processing DelayThreshold: 1 * time.Second, }) @@ -265,12 +269,12 @@ func TestBatchProcessor_DuplicateMessages(t *testing.T) { time.Sleep(200 * time.Millisecond) // All copies acked, none nacked - assert.True(t, mock1.acked, "kept copy should be acked") - assert.False(t, mock1.nacked) - assert.True(t, mock2.acked, "duplicate copy should be acked") - assert.False(t, mock2.nacked) - assert.True(t, mock3.acked, "distinct message should be acked") - assert.False(t, mock3.nacked) + assert.True(t, mock1.acked.Load(), "kept copy should be acked") + assert.False(t, mock1.nacked.Load()) + assert.True(t, mock2.acked.Load(), "duplicate copy should be acked") + assert.False(t, mock2.nacked.Load()) + assert.True(t, mock3.acked.Load(), "distinct message should be acked") + assert.False(t, mock3.nacked.Load()) // Duplicate inserted once _, attempts := logStore.getInserted() @@ -288,7 +292,7 @@ func TestBatchProcessor_MalformedJSON(t *testing.T) { logger := testutil.CreateTestLogger(t) logStore := &mockLogStore{} - bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, nil, logmq.BatchProcessorConfig{ + bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, logmq.AlertPipeline{}, logmq.BatchProcessorConfig{ ItemCountThreshold: 1, DelayThreshold: 1 * time.Second, }) @@ -302,41 +306,55 @@ func TestBatchProcessor_MalformedJSON(t *testing.T) { // Wait for batch to process time.Sleep(200 * time.Millisecond) - assert.False(t, mock.acked, "malformed message should not be acked") - assert.True(t, mock.nacked, "malformed message should be nacked") + assert.False(t, mock.acked.Load(), "malformed message should not be acked") + assert.True(t, mock.nacked.Load(), "malformed message should be nacked") events, attempts := logStore.getInserted() assert.Empty(t, events) assert.Empty(t, attempts) } -// mockAlertMonitor records HandleAttempt calls and returns a configurable error. -type mockAlertMonitor struct { +// mockAlertEvaluator records Evaluate calls and returns a configurable error. +type mockAlertEvaluator struct { mu sync.Mutex - calls []alert.DeliveryAttempt + calls []alert.Attempt returnErr error } -func (m *mockAlertMonitor) HandleAttempt(ctx context.Context, attempt alert.DeliveryAttempt) error { +func (m *mockAlertEvaluator) Evaluate(ctx context.Context, attempt alert.Attempt) (alert.Evaluation, error) { m.mu.Lock() defer m.mu.Unlock() m.calls = append(m.calls, attempt) - return m.returnErr + if m.returnErr != nil { + return alert.Evaluation{}, m.returnErr + } + return alert.Evaluation{}, nil } -func (m *mockAlertMonitor) getCalls() []alert.DeliveryAttempt { +func (m *mockAlertEvaluator) getCalls() []alert.Attempt { m.mu.Lock() defer m.mu.Unlock() - return append([]alert.DeliveryAttempt(nil), m.calls...) + return append([]alert.Attempt(nil), m.calls...) +} + +// testAlertPipeline wraps an evaluator with the required delivery deps: a +// noop-sink emitter and a real (miniredis-backed) processed gate. +func testAlertPipeline(t *testing.T, evaluator logmq.AlertEvaluator) logmq.AlertPipeline { + t.Helper() + return logmq.AlertPipeline{ + Evaluator: evaluator, + Emitter: opevents.NewEmitter(&opevents.NoopSink{}, "test-deploy", []string{"*"}), + ProcessedIdemp: idempotence.New(testutil.CreateTestRedisClient(t)), + } } -func TestBatchProcessor_AlertMonitor_WithDestination(t *testing.T) { +func TestBatchProcessor_AlertEvaluator_WithDestination(t *testing.T) { ctx := context.Background() logger := testutil.CreateTestLogger(t) logStore := &mockLogStore{} - alertMon := &mockAlertMonitor{} + alertMon := &mockAlertEvaluator{} - bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, alertMon, logmq.BatchProcessorConfig{ + bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, testAlertPipeline(t, alertMon), logmq.BatchProcessorConfig{ ItemCountThreshold: 1, DelayThreshold: 1 * time.Second, }) @@ -357,21 +375,21 @@ func TestBatchProcessor_AlertMonitor_WithDestination(t *testing.T) { time.Sleep(200 * time.Millisecond) - assert.True(t, mock.acked, "should be acked when alert monitor succeeds") - assert.False(t, mock.nacked) + assert.True(t, mock.acked.Load(), "should be acked when alert evaluation succeeds") + assert.False(t, mock.nacked.Load()) calls := alertMon.getCalls() - require.Len(t, calls, 1, "alert monitor should have been called once") - assert.Equal(t, dest.ID, calls[0].Destination.ID) + require.Len(t, calls, 1, "alert evaluator should have been called once") + assert.Equal(t, dest.ID, calls[0].DestinationID) } -func TestBatchProcessor_AlertMonitor_NilDestination(t *testing.T) { +func TestBatchProcessor_AlertEvaluator_NilDestination(t *testing.T) { ctx := context.Background() logger := testutil.CreateTestLogger(t) logStore := &mockLogStore{} - alertMon := &mockAlertMonitor{} + alertMon := &mockAlertEvaluator{} - bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, alertMon, logmq.BatchProcessorConfig{ + bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, testAlertPipeline(t, alertMon), logmq.BatchProcessorConfig{ ItemCountThreshold: 1, DelayThreshold: 1 * time.Second, }) @@ -391,18 +409,18 @@ func TestBatchProcessor_AlertMonitor_NilDestination(t *testing.T) { time.Sleep(200 * time.Millisecond) - assert.True(t, mock.acked, "should be acked even without destination (migration grace)") - assert.False(t, mock.nacked) - assert.Empty(t, alertMon.getCalls(), "alert monitor should not be called without destination") + assert.True(t, mock.acked.Load(), "should be acked even without destination (migration grace)") + assert.False(t, mock.nacked.Load()) + assert.Empty(t, alertMon.getCalls(), "alert evaluator should not be called without destination") } -func TestBatchProcessor_AlertMonitor_Error(t *testing.T) { +func TestBatchProcessor_AlertEvaluator_Error(t *testing.T) { ctx := context.Background() logger := testutil.CreateTestLogger(t) logStore := &mockLogStore{} - alertMon := &mockAlertMonitor{returnErr: errors.New("alert failed")} + alertMon := &mockAlertEvaluator{returnErr: errors.New("alert failed")} - bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, alertMon, logmq.BatchProcessorConfig{ + bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, testAlertPipeline(t, alertMon), logmq.BatchProcessorConfig{ ItemCountThreshold: 1, DelayThreshold: 1 * time.Second, }) @@ -423,8 +441,8 @@ func TestBatchProcessor_AlertMonitor_Error(t *testing.T) { time.Sleep(200 * time.Millisecond) - assert.False(t, mock.acked, "should not be acked when alert monitor fails") - assert.True(t, mock.nacked, "should be nacked when alert monitor fails") + assert.False(t, mock.acked.Load(), "should not be acked when alert evaluation fails") + assert.True(t, mock.nacked.Load(), "should be nacked when alert evaluation fails") // Entry was still persisted to logstore events, _ := logStore.getInserted() diff --git a/internal/logmq/characterization_acknowledgement_test.go b/internal/logmq/characterization_acknowledgement_test.go new file mode 100644 index 000000000..749355339 --- /dev/null +++ b/internal/logmq/characterization_acknowledgement_test.go @@ -0,0 +1,99 @@ +package logmq_test + +// Acknowledgement (exactly-once terminal state). Cross-cutting: every message +// ends in exactly one terminal state (ack XOR nack), the correct one per the +// routing table, and one message's failure must not disturb another's ack. + +import ( + "testing" + + "github.com/hookdeck/outpost/internal/models" + "github.com/hookdeck/outpost/internal/mqs" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// One batch with a success, a failure that alerts, an in-batch duplicate, an +// unparseable body, and an entry whose emit is injected to fail. Every message +// has exactly one terminal state (the correct one); the emit-fail nack does not +// disturb the others' acks. +func TestCharacterization_MixedBatchAccounting(t *testing.T) { + t.Parallel() + // 6 messages total: success, alert-failure, dup(x2), unparseable, emit-fail. + // thresholds[50,100] with max=2 so a single failure (count 1) emits a cf alert. + emitFailAttemptID := "att_emit_fail" + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 6}, + alert: alertConfig{ + autoDisableCount: 2, + thresholds: []int{50, 100}, + }, + doubles: doublesConfig{ + sinkFailOn: map[string]bool{emitFailAttemptID: true}, + }, + }) + + tenant := "tenant_c1" + destSuccess := "dest_c1_success" + destAlert := "dest_c1_alert" + destDup := "dest_c1_dup" + destFail := "dest_c1_fail" + + // 1. success + cmSuccess, msgSuccess := newCountingMessage(makeEntry(destSuccess, tenant, "att_success", models.AttemptStatusSuccess)) + // 2. failure that alerts (count 1 = 50%) + cmAlert, msgAlert := newCountingMessage(makeEntry(destAlert, tenant, "att_alert", models.AttemptStatusFailed)) + // 3. in-batch duplicate (byte-identical, success → no alert) + dupEntry := makeEntry(destDup, tenant, "att_dup", models.AttemptStatusSuccess) + cmDupKeep, msgDupKeep := newCountingMessage(dupEntry) + cmDupCopy, msgDupCopy := newCountingMessage(dupEntry) + // 4. unparseable body + cmInvalid, msgInvalid := newRawMessage([]byte("not valid json")) + // 5. emit-fail entry (failure → cf emit injected to fail) + cmEmitFail, msgEmitFail := newCountingMessage(makeEntry(destFail, tenant, emitFailAttemptID, models.AttemptStatusFailed)) + + for _, msg := range []*mqs.Message{msgSuccess, msgAlert, msgDupKeep, msgDupCopy, msgInvalid, msgEmitFail} { + h.add(msg) + } + all := []*countingMessage{cmSuccess, cmAlert, cmDupKeep, cmDupCopy, cmInvalid, cmEmitFail} + h.waitTerminal(all) + + // Exactly one terminal state per message. + for _, m := range all { + m.requireTerminalOnce(t) + } + + // Success / dup(both) / alert → ack. + cmSuccess.requireAcked(t) + cmAlert.requireAcked(t) + cmDupKeep.requireAcked(t) + cmDupCopy.requireAcked(t) + // Invalid / emit-fail → nack. + cmInvalid.requireNacked(t) + cmEmitFail.requireNacked(t) + + // Only the alerting destination produced a (successful) record. + assert.Equal(t, []string{topicCF}, topics(h.sink.forDest(destAlert))) + assert.Empty(t, h.sink.forDest(destFail), "emit-fail destination produced no recorded event") + assert.Len(t, h.sink.snapshot(), 1, "exactly one event delivered to the sink") +} + +// A single failed attempt below any threshold (count 1) → persisted, acked, +// zero sink records (the "nothing to deliver" fast path: mark + ack, no +// delivery task). +func TestCharacterization_BelowThresholdNoAlert(t *testing.T) { + t.Parallel() + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 1}, + alert: alertConfig{withDisabler: true}, + }) + + destA, tenant := "dest_c2", "tenant_c2" + cm, msg := newCountingMessage(makeEntry(destA, tenant, "att_1", models.AttemptStatusFailed)) + h.add(msg) + h.waitTerminal([]*countingMessage{cm}) + + cm.requireAcked(t) + assert.Empty(t, h.sink.snapshot(), "count 1 is below the 50%% threshold (5)") + require.Len(t, h.listAttempt(destA), 1, "attempt persisted") +} diff --git a/internal/logmq/characterization_decoupling_test.go b/internal/logmq/characterization_decoupling_test.go new file mode 100644 index 000000000..c6eb8f07f --- /dev/null +++ b/internal/logmq/characterization_decoupling_test.go @@ -0,0 +1,123 @@ +package logmq_test + +// Decoupling: persistence and alert eval must not be blocked by slow opevent +// delivery. Delivery runs on an unordered pool, so a slow sink stalls only +// the messages that owe events, never the batch loop. + +import ( + "fmt" + "testing" + "time" + + "github.com/hookdeck/outpost/internal/models" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// A batch-1 attempt whose alert delivery hangs must not delay batch 2's +// persistence or ack. (If sends ran serially in the batch loop, batch 2 would +// wait on batch 1's sink call.) +func TestCharacterization_SlowDeliveryDoesNotBlockPersistence(t *testing.T) { + t.Parallel() + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 1}, + // max=2, thresholds[50,100] → a single failure (count 1 = 50%) alerts. + alert: alertConfig{autoDisableCount: 2, thresholds: []int{50, 100}}, + doubles: doublesConfig{ + sinkBlockOn: map[string]bool{"att_slow": true}, + }, + }) + + tenant := "tenant_d1" + + // Batch 1: alerting failure whose send blocks. + cmSlow, msgSlow := newCountingMessage(makeEntry("dest_d1_slow", tenant, "att_slow", models.AttemptStatusFailed)) + h.add(msgSlow) + + // Wait until the delivery is actually blocked inside the sink. + require.Eventually(t, func() bool { return h.sink.inflightSends() >= 1 }, + 5*time.Second, 5*time.Millisecond, "the slow delivery should reach the sink") + + // Batch 2: a plain success — persists and acks while batch 1's send hangs. + cmOK, msgOK := newCountingMessage(makeEntry("dest_d1_ok", tenant, "att_ok", models.AttemptStatusSuccess)) + h.add(msgOK) + h.waitTerminal([]*countingMessage{cmOK}) + cmOK.requireAcked(t) + require.Len(t, h.listAttempt("dest_d1_ok"), 1, "batch 2 persisted while batch 1's delivery hangs") + + // The slow message is still in flight: persisted but no terminal state. + require.Len(t, h.listAttempt("dest_d1_slow"), 1, "the slow attempt itself persisted immediately") + assert.EqualValues(t, 0, cmSlow.acks()+cmSlow.nacks(), "the slow message stays un-acked until its delivery completes") + + // Release the sink: the blocked delivery completes and acks. + h.sink.release() + h.waitTerminal([]*countingMessage{cmSlow}) + cmSlow.requireAcked(t) + assert.Equal(t, []string{topicCF}, topics(h.sink.forDest("dest_d1_slow"))) +} + +// A hot destination's alerting attempts deliver in parallel — one slow send +// doesn't serialize the destination's other sends (the old per-dest serial +// loop did exactly that). +func TestCharacterization_HotDestinationDeliversInParallel(t *testing.T) { + t.Parallel() + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 3}, + // max=100 with thresholds 1/2/3% → counts 1, 2 and 3 each cross one + // threshold, so all three attempts alert. + alert: alertConfig{autoDisableCount: 100, thresholds: []int{1, 2, 3}}, + doubles: doublesConfig{ + sinkBlockOn: map[string]bool{topicCF: true}, // every cf send blocks + }, + }) + + destA, tenant := "dest_d2", "tenant_d2" + msgs := make([]*countingMessage, 0, 3) + for i := 1; i <= 3; i++ { + cm, msg := newCountingMessage(makeEntry(destA, tenant, fmt.Sprintf("att_%d", i), models.AttemptStatusFailed)) + msgs = append(msgs, cm) + h.add(msg) + } + + // All three sends block in the sink AT THE SAME TIME — same destination, + // different workers. + require.Eventually(t, func() bool { return h.sink.inflightSends() >= 3 }, + 5*time.Second, 5*time.Millisecond, "the destination's deliveries should run concurrently") + + h.sink.release() + h.waitTerminal(msgs) + for _, m := range msgs { + m.requireAcked(t) + } + assert.GreaterOrEqual(t, h.sink.maxInflightSends(), int32(3)) + assert.ElementsMatch(t, []string{"att_1", "att_2", "att_3"}, attemptIDs(h.sink.forDest(destA))) +} + +// Shutdown drains the delivery pool: every enqueued delivery reaches its +// terminal state before Shutdown returns. +func TestCharacterization_ShutdownDrainsDeliveries(t *testing.T) { + t.Parallel() + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 1}, + alert: alertConfig{autoDisableCount: 2, thresholds: []int{50, 100}}, + doubles: doublesConfig{ + sinkBlockOn: map[string]bool{"att_drain": true}, + }, + }) + + cm, msg := newCountingMessage(makeEntry("dest_d3", "tenant_d3", "att_drain", models.AttemptStatusFailed)) + h.add(msg) + require.Eventually(t, func() bool { return h.sink.inflightSends() >= 1 }, + 5*time.Second, 5*time.Millisecond) + + // Release while Shutdown is waiting on the drain. + go func() { + time.Sleep(50 * time.Millisecond) + h.sink.release() + }() + h.bp.Shutdown() + + // Shutdown returned → the delivery completed and acked. + cm.requireAcked(t) + assert.Equal(t, []string{topicCF}, topics(h.sink.forDest("dest_d3"))) +} diff --git a/internal/logmq/characterization_harness_test.go b/internal/logmq/characterization_harness_test.go new file mode 100644 index 000000000..98c87e958 --- /dev/null +++ b/internal/logmq/characterization_harness_test.go @@ -0,0 +1,493 @@ +package logmq_test + +// Characterization suite for the logmq post-persist pipeline. +// +// These tests pin the CURRENT behavior of BatchProcessor.processBatch wired to +// the REAL alert evaluator, REAL in-memory log store, REAL opevents emitter and a +// miniredis-backed alert store. The only doubles are at the external boundary: +// - recordingSink (opevents.Sink): records emitted operator events, can +// inject Send failures. +// - recordingDisabler (logmq.DestinationDisabler): records disable calls. +// - countingMessage (mqs.QueueMessage): counts ack/nack for exactly-once. +// +// Observable oracles (assert ONLY on these): +// - sink.records (ordered list of {topic, destID, attemptID}) +// - per-message ack/nack counters (exactly-once terminal state) +// - logStore.ListAttempt / ListEvent +// +// Per-destination order only — never assert global cross-destination order. +// +// Files in this suite (concern → file): +// - characterization_harness_test.go shared setup, doubles, helpers +// - characterization_ordering_test.go eval ordering & counting +// - characterization_idempotency_test.go replay / idempotency +// - characterization_acknowledgement_test.go ack/nack exactly-once +// - characterization_validation_test.go intake (parse / dedup / persist) +// - characterization_decoupling_test.go persistence decoupled from delivery +// - characterization_postprocess_test.go sharded eval: order & parallelism + +import ( + "context" + "encoding/json" + "fmt" + "sync" + "sync/atomic" + "testing" + "time" + + "github.com/hookdeck/outpost/internal/alert" + "github.com/hookdeck/outpost/internal/idempotence" + "github.com/hookdeck/outpost/internal/logmq" + "github.com/hookdeck/outpost/internal/logstore/driver" + "github.com/hookdeck/outpost/internal/logstore/memlogstore" + "github.com/hookdeck/outpost/internal/models" + "github.com/hookdeck/outpost/internal/mqs" + "github.com/hookdeck/outpost/internal/opevents" + "github.com/hookdeck/outpost/internal/util/testutil" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// ============================== Boundary doubles ============================== + +type sinkRecord struct { + topic string + destID string + attemptID string +} + +// recordingSink implements opevents.Sink. It records each emitted event, can +// inject Send errors keyed by attemptID or topic, and can block matching sends +// until release() — simulating a slow sink. It also tracks how many sends run +// concurrently. Injected-failure events are NOT recorded (so records reflect +// only successfully delivered events). +type recordingSink struct { + mu sync.Mutex + records []sinkRecord + failOn map[string]bool // key by attemptID or topic + + blockOn map[string]bool // block these sends (by attemptID or topic)... + blockCh chan struct{} // ...until this closes (via release) + releaseOnce sync.Once + + inflight atomic.Int32 + maxInflight atomic.Int32 +} + +func (s *recordingSink) Init(ctx context.Context) error { return nil } +func (s *recordingSink) Close() error { return nil } + +func (s *recordingSink) Send(ctx context.Context, event *opevents.OperatorEvent) error { + cur := s.inflight.Add(1) + defer s.inflight.Add(-1) + for { + max := s.maxInflight.Load() + if cur <= max || s.maxInflight.CompareAndSwap(max, cur) { + break + } + } + + // All three alert payloads (consecutive_failure / disabled / exhausted) + // carry a destination with an id and an attempt with an id. + var payload struct { + Destination struct { + ID string `json:"id"` + } `json:"destination"` + Attempt struct { + ID string `json:"id"` + } `json:"attempt"` + } + _ = json.Unmarshal(event.Data, &payload) + destID := payload.Destination.ID + attemptID := payload.Attempt.ID + + // Block outside the lock so a blocked send doesn't serialize the others. + if s.blockCh != nil && (s.blockOn[attemptID] || s.blockOn[event.Topic]) { + <-s.blockCh + } + + s.mu.Lock() + defer s.mu.Unlock() + if s.failOn[attemptID] || s.failOn[event.Topic] { + return fmt.Errorf("injected send failure topic=%s attempt=%s", event.Topic, attemptID) + } + s.records = append(s.records, sinkRecord{topic: event.Topic, destID: destID, attemptID: attemptID}) + return nil +} + +// release unblocks every blocked (and future) matching send. +func (s *recordingSink) release() { + s.releaseOnce.Do(func() { close(s.blockCh) }) +} + +func (s *recordingSink) inflightSends() int32 { return s.inflight.Load() } +func (s *recordingSink) maxInflightSends() int32 { return s.maxInflight.Load() } + +func (s *recordingSink) snapshot() []sinkRecord { + s.mu.Lock() + defer s.mu.Unlock() + return append([]sinkRecord(nil), s.records...) +} + +// forDest returns the records for a single destination, in arrival order. +func (s *recordingSink) forDest(destID string) []sinkRecord { + out := []sinkRecord{} + for _, r := range s.snapshot() { + if r.destID == destID { + out = append(out, r) + } + } + return out +} + +// blockingEvaluator wraps the real evaluator and blocks Evaluate for matching +// attempt IDs until release() — simulating a slow eval (e.g. a Redis hiccup). +// It counts inner Evaluate calls so tests can assert an eval did NOT run yet. +type blockingEvaluator struct { + inner logmq.AlertEvaluator + blockOn map[string]bool // block these evals (by attemptID)... + blockCh chan struct{} // ...until this closes (via release) + releaseOnce sync.Once + + blocked atomic.Int32 // evals that reached the block + entered atomic.Int32 // evals that reached the inner evaluator +} + +func (e *blockingEvaluator) Evaluate(ctx context.Context, attempt alert.Attempt) (alert.Evaluation, error) { + if e.blockOn[attempt.AttemptID] { + e.blocked.Add(1) + <-e.blockCh + } + e.entered.Add(1) + return e.inner.Evaluate(ctx, attempt) +} + +// release unblocks every blocked (and future) matching eval. +func (e *blockingEvaluator) release() { + e.releaseOnce.Do(func() { close(e.blockCh) }) +} + +func (e *blockingEvaluator) blockedEvals() int32 { return e.blocked.Load() } +func (e *blockingEvaluator) enteredEvals() int32 { return e.entered.Load() } + +type disableRecord struct { + tenantID string + destinationID string +} + +// recordingDisabler implements logmq.DestinationDisabler. +type recordingDisabler struct { + mu sync.Mutex + disabled []disableRecord +} + +func (d *recordingDisabler) DisableDestination(ctx context.Context, tenantID, destinationID string) error { + d.mu.Lock() + defer d.mu.Unlock() + d.disabled = append(d.disabled, disableRecord{tenantID: tenantID, destinationID: destinationID}) + return nil +} + +func (d *recordingDisabler) snapshot() []disableRecord { + d.mu.Lock() + defer d.mu.Unlock() + return append([]disableRecord(nil), d.disabled...) +} + +// countingMessage implements mqs.QueueMessage with integer counters so tests can +// assert exactly-once terminal state (ack==1, nack==0 or vice versa). +type countingMessage struct { + ack atomic.Int32 + nack atomic.Int32 +} + +func (m *countingMessage) Ack() { m.ack.Add(1) } +func (m *countingMessage) Nack() { m.nack.Add(1) } + +func (m *countingMessage) acks() int32 { return m.ack.Load() } +func (m *countingMessage) nacks() int32 { return m.nack.Load() } + +// requireAcked asserts the message reached exactly one terminal state: a single +// ack and no nack. +func (m *countingMessage) requireAcked(t *testing.T) { + t.Helper() + assert.Equal(t, int32(1), m.acks(), "expected exactly one ack") + assert.Equal(t, int32(0), m.nacks(), "expected no nack") +} + +// requireNacked asserts the message reached exactly one terminal state: a single +// nack and no ack. +func (m *countingMessage) requireNacked(t *testing.T) { + t.Helper() + assert.Equal(t, int32(1), m.nacks(), "expected exactly one nack") + assert.Equal(t, int32(0), m.acks(), "expected no ack") +} + +// requireTerminalOnce asserts exactly one terminal state (ack OR nack), without +// constraining which. Use when the terminal kind is asserted separately. +func (m *countingMessage) requireTerminalOnce(t *testing.T) { + t.Helper() + assert.Equal(t, int32(1), m.acks()+m.nacks(), "expected exactly one terminal state") +} + +// failingLogStore always errors on InsertMany. Used only for the InsertMany-error case. +type failingLogStore struct { + err error +} + +func (f *failingLogStore) InsertMany(ctx context.Context, entries []*models.LogEntry) error { + return f.err +} + +// ============================== Harness ============================== + +// harnessConfig groups knobs by concern: batcher + alert + delivery configure +// the REAL pipeline components; doubles tweaks the behavior of the test doubles. +type harnessConfig struct { + batcher batcherConfig // real BatchProcessor + alert alertConfig // real alert.Evaluator + postprocess postprocessConfig // real postprocess pool + delivery deliveryConfig // real delivery pool + doubles doublesConfig // test-double behavior +} + +// postprocessConfig drives the real postprocess pool. Zero values fall back to +// the BatchProcessor defaults. +type postprocessConfig struct { + // shards is set by tests that pick destinations by shard (see shardOf). + shards int +} + +// deliveryConfig drives the real delivery pool. Zero values fall back to the +// BatchProcessor defaults. +type deliveryConfig struct { + // concurrency 1 serializes delivery — used by tests whose semantics need + // deterministic delivery order (e.g. the exhausted suppression window, + // where concurrent Execs on one key hit the conflict path). + concurrency int +} + +// batcherConfig drives the real BatchProcessor flush behavior. +type batcherConfig struct { + itemCount int // flush when this many messages buffered + delay time.Duration // ...or flush after this long (default 100ms) +} + +// alertConfig drives the real alert.Evaluator. Zero values fall back to defaults +// (thresholds [50,70,90,100], autoDisableCount 10, retryMaxLimit 10). +type alertConfig struct { + thresholds []int + autoDisableCount int + retryMaxLimit int + withDisabler bool // attach the recordingDisabler to the pipeline +} + +// doublesConfig controls test-double behavior. Zero values = passthrough: the +// sink injects no failures, blocks nothing, and the harness uses a real +// memlogstore. +type doublesConfig struct { + sinkFailOn map[string]bool // make sink.Send fail for these attemptIDs/topics + sinkBlockOn map[string]bool // block sink.Send for these attemptIDs/topics until h.sink.release() + evalBlockOn map[string]bool // block Evaluate for these attemptIDs until h.eval.release() + logStore logmq.LogStore // override the store (e.g. failingLogStore); nil = memlogstore + idemp idempotence.Idempotence // exhausted-retries suppression; nil = unsuppressed +} + +type harness struct { + t *testing.T + ctx context.Context + bp *logmq.BatchProcessor + sink *recordingSink + eval *blockingEvaluator // nil unless doubles.evalBlockOn was set + disabler *recordingDisabler + store driver.LogStore // nil when logStore was overridden with a non-memlogstore +} + +func newHarness(t *testing.T, cfg harnessConfig) *harness { + t.Helper() + ctx := context.Background() + logger := testutil.CreateTestLogger(t) + redisClient := testutil.CreateTestRedisClient(t) + + sink := &recordingSink{failOn: cfg.doubles.sinkFailOn, blockOn: cfg.doubles.sinkBlockOn} + if sink.blockOn != nil { + sink.blockCh = make(chan struct{}) + } + disabler := &recordingDisabler{} + + // NOTE: opevents.NewEmitter returns a NOOP emitter when topics is nil/empty. + // To accept all topics we must pass []string{"*"} (NOT nil). + emitter := opevents.NewEmitter(sink, "test-deploy", []string{"*"}) + + thresholds := cfg.alert.thresholds + if thresholds == nil { + thresholds = []int{50, 70, 90, 100} + } + autoDisableCount := cfg.alert.autoDisableCount + if autoDisableCount == 0 { + autoDisableCount = 10 + } + retryMaxLimit := cfg.alert.retryMaxLimit + if retryMaxLimit == 0 { + retryMaxLimit = 10 + } + var evaluator logmq.AlertEvaluator = alert.NewEvaluator(alert.NewRedisAlertStore(redisClient, ""), retryMaxLimit, + alert.WithAutoDisableFailureCount(autoDisableCount), + alert.WithAlertThresholds(thresholds), + ) + var evalDouble *blockingEvaluator + if cfg.doubles.evalBlockOn != nil { + evalDouble = &blockingEvaluator{ + inner: evaluator, + blockOn: cfg.doubles.evalBlockOn, + blockCh: make(chan struct{}), + } + evaluator = evalDouble + } + + var logStore logmq.LogStore + var store driver.LogStore + if cfg.doubles.logStore != nil { + logStore = cfg.doubles.logStore + } else { + store = memlogstore.NewLogStore() + logStore = store + } + + delay := cfg.batcher.delay + if delay == 0 { + delay = 100 * time.Millisecond + } + // The suite wires the REAL processed gate (per-attempt replay dedup) over + // the same miniredis. No exhausted suppression window by default (emit on + // every exhaustion); delivery tests opt in via doubles.idemp. The disabler + // attaches to the pipeline when alert.withDisabler is set. + pipeline := logmq.AlertPipeline{ + Evaluator: evaluator, + Emitter: emitter, + ProcessedIdemp: idempotence.New(redisClient), + ExhaustedIdemp: cfg.doubles.idemp, + } + if cfg.alert.withDisabler { + pipeline.Disabler = disabler + } + bp, err := logmq.NewBatchProcessor(ctx, logger, logStore, pipeline, logmq.BatchProcessorConfig{ + ItemCountThreshold: cfg.batcher.itemCount, + DelayThreshold: delay, + PostprocessShards: cfg.postprocess.shards, + DeliveryConcurrency: cfg.delivery.concurrency, + }) + require.NoError(t, err) + t.Cleanup(bp.Shutdown) + // LIFO: releases run BEFORE bp.Shutdown, so a test that never released its + // blocked sends/evals can't deadlock the drain. + if sink.blockCh != nil { + t.Cleanup(sink.release) + } + if evalDouble != nil { + t.Cleanup(evalDouble.release) + } + + return &harness{t: t, ctx: ctx, bp: bp, sink: sink, eval: evalDouble, disabler: disabler, store: store} +} + +// makeEntry builds a LogEntry with event+attempt+destination all populated. +// AttemptNumber defaults to 1 so memlogstore persists the event (it only inserts +// the event when AttemptNumber <= 1), which lets ListAttempt link the record. +func makeEntry(destID, tenantID, attemptID, status string) models.LogEntry { + return makeEntryFull(destID, tenantID, attemptID, status, 1, true) +} + +func makeEntryFull(destID, tenantID, attemptID, status string, attemptNumber int, eligibleForRetry bool) models.LogEntry { + event := testutil.EventFactory.Any( + testutil.EventFactory.WithTenantID(tenantID), + testutil.EventFactory.WithEligibleForRetry(eligibleForRetry), + testutil.EventFactory.WithMatchedDestinationIDs([]string{destID}), + ) + attempt := testutil.AttemptFactory.Any( + testutil.AttemptFactory.WithID(attemptID), + testutil.AttemptFactory.WithTenantID(tenantID), + testutil.AttemptFactory.WithEventID(event.ID), + testutil.AttemptFactory.WithDestinationID(destID), + testutil.AttemptFactory.WithStatus(status), + testutil.AttemptFactory.WithAttemptNumber(attemptNumber), + ) + dest := testutil.DestinationFactory.Any( + testutil.DestinationFactory.WithID(destID), + testutil.DestinationFactory.WithTenantID(tenantID), + ) + return models.LogEntry{Event: &event, Attempt: &attempt, Destination: &dest} +} + +func newCountingMessage(entry models.LogEntry) (*countingMessage, *mqs.Message) { + body, _ := json.Marshal(entry) + cm := &countingMessage{} + return cm, &mqs.Message{QueueMessage: cm, Body: body, LoggableID: "test-msg"} +} + +func newRawMessage(body []byte) (*countingMessage, *mqs.Message) { + cm := &countingMessage{} + return cm, &mqs.Message{QueueMessage: cm, Body: body, LoggableID: "test-msg"} +} + +// add pushes a message into the batcher. +func (h *harness) add(msg *mqs.Message) { + require.NoError(h.t, h.bp.Add(h.ctx, msg)) +} + +// waitTerminal blocks until every message has reached exactly one terminal state. +func (h *harness) waitTerminal(msgs []*countingMessage) { + h.t.Helper() + require.Eventually(h.t, func() bool { + for _, m := range msgs { + if m.acks()+m.nacks() == 0 { + return false + } + } + return true + }, 5*time.Second, 5*time.Millisecond, "all messages should reach a terminal state") +} + +// listAttempt returns the persisted attempt records for a destination. +func (h *harness) listAttempt(destID string) []*driver.AttemptRecord { + resp, err := h.store.ListAttempt(h.ctx, driver.ListAttemptRequest{DestinationIDs: []string{destID}}) + require.NoError(h.t, err) + return resp.Data +} + +// topics extracts the topic sequence from a record slice. +func topics(recs []sinkRecord) []string { + out := make([]string, len(recs)) + for i, r := range recs { + out[i] = r.topic + } + return out +} + +// attemptIDs extracts the attemptID sequence from a record slice. +func attemptIDs(recs []sinkRecord) []string { + out := make([]string, len(recs)) + for i, r := range recs { + out[i] = r.attemptID + } + return out +} + +// topicsForAttempt extracts one attempt's topics. WHICH topics an attempt +// emitted is guaranteed; arrival order is not — an attempt's sends run +// concurrently, so assert with ElementsMatch. +func topicsForAttempt(recs []sinkRecord, attemptID string) []string { + out := []string{} + for _, r := range recs { + if r.attemptID == attemptID { + out = append(out, r.topic) + } + } + return out +} + +const ( + topicCF = opevents.TopicAlertConsecutiveFailure + topicDisabled = opevents.TopicAlertDestinationDisabled + topicExhaust = opevents.TopicAlertExhaustedRetries +) diff --git a/internal/logmq/characterization_idempotency_test.go b/internal/logmq/characterization_idempotency_test.go new file mode 100644 index 000000000..c5c44f27d --- /dev/null +++ b/internal/logmq/characterization_idempotency_test.go @@ -0,0 +1,120 @@ +package logmq_test + +// Replay / idempotency. The pipeline holds the logmq message un-acked until +// delivery completes and relies on redelivery for durability, so the same attempt is +// legitimately processed more than once. These tests pin that a replay does not +// double-count, double-alert, or double-persist. + +import ( + "testing" + + "github.com/hookdeck/outpost/internal/models" + "github.com/stretchr/testify/require" +) + +// Same failed attempt ID delivered twice (second in a later batch) → count +// incremented once, exactly ONE alert record total, both messages acked, +// persisted once. +func TestCharacterization_ReplaySameAttempt(t *testing.T) { + t.Parallel() + // max=2, thresholds[50,100] → count 1 = 50% (single cf alert, no disable). + // itemCountThreshold=1 → each Add is its own batch (so the replay takes the + // cross-batch path, not in-batch dedup). + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 1}, + alert: alertConfig{ + autoDisableCount: 2, + thresholds: []int{50, 100}, + }, + }) + + destA, tenant := "dest_b1", "tenant_b1" + entry := makeEntry(destA, tenant, "att_replay", models.AttemptStatusFailed) + + cm1, msg1 := newCountingMessage(entry) + h.add(msg1) + h.waitTerminal([]*countingMessage{cm1}) + + cm2, msg2 := newCountingMessage(entry) + h.add(msg2) + h.waitTerminal([]*countingMessage{cm2}) + + recs := h.sink.forDest(destA) + require.Equal(t, []string{topicCF}, topics(recs), "exactly one alert across both deliveries") + + cm1.requireAcked(t) + cm2.requireAcked(t) + + // Persisted once (idempotent upsert by attempt ID). + require.Len(t, h.listAttempt(destA), 1) +} + +// A stale replay of an old failed attempt arriving AFTER a success reset is +// skipped by the per-attempt processed gate — it must not re-count toward the +// fresh streak. The gate must survive the reset: if the reset also cleared +// the replay markers, the stale replay would re-count and could re-alert. +func TestCharacterization_StaleReplayAfterReset_Skipped(t *testing.T) { + t.Parallel() + // max=2, thresholds[100] → an alert fires only at count 2. If the stale + // replay re-counted, att_fresh would be count 2 → alert. It must not. + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 1}, + alert: alertConfig{ + autoDisableCount: 2, + thresholds: []int{100}, + }, + }) + + destA, tenant := "dest_sr", "tenant_sr" + stale := makeEntry(destA, tenant, "att_stale", models.AttemptStatusFailed) + + // Fail (count 1, below threshold), then success (reset). + cm1, msg1 := newCountingMessage(stale) + h.add(msg1) + h.waitTerminal([]*countingMessage{cm1}) + + cm2, msg2 := newCountingMessage(makeEntry(destA, tenant, "att_ok", models.AttemptStatusSuccess)) + h.add(msg2) + h.waitTerminal([]*countingMessage{cm2}) + + // Stale replay of the old failed attempt: skipped by the processed gate. + cm3, msg3 := newCountingMessage(stale) + h.add(msg3) + h.waitTerminal([]*countingMessage{cm3}) + + // A fresh failure starts a new streak at count 1 — no alert. + cm4, msg4 := newCountingMessage(makeEntry(destA, tenant, "att_fresh", models.AttemptStatusFailed)) + h.add(msg4) + h.waitTerminal([]*countingMessage{cm4}) + + require.Empty(t, h.sink.forDest(destA), "stale replay must not count toward the fresh streak") + cm3.requireAcked(t) + cm4.requireAcked(t) +} + +// retryMaxLimit=3; dest A attempt EligibleForRetry=true, AttemptNumber=4 → +// exactly one exhausted_retries record; acked. Run WITHOUT the idempotence window +// (single pipeline-level check; negatives live in the alert package tests). +func TestCharacterization_ExhaustedRetries(t *testing.T) { + t.Parallel() + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 1}, + alert: alertConfig{ + retryMaxLimit: 3, + // High auto-disable count so the cf threshold (count 1) never fires here. + autoDisableCount: 100, + }, + }) + + destA, tenant := "dest_b3", "tenant_b3" + entry := makeEntryFull(destA, tenant, "att_exhaust", models.AttemptStatusFailed, 4, true) + + cm, msg := newCountingMessage(entry) + h.add(msg) + h.waitTerminal([]*countingMessage{cm}) + + recs := h.sink.forDest(destA) + require.Equal(t, []string{topicExhaust}, topics(recs)) + + cm.requireAcked(t) +} diff --git a/internal/logmq/characterization_ordering_test.go b/internal/logmq/characterization_ordering_test.go new file mode 100644 index 000000000..51e069528 --- /dev/null +++ b/internal/logmq/characterization_ordering_test.go @@ -0,0 +1,211 @@ +package logmq_test + +// Ordering & counting. The reason this suite exists: processing order changes +// the alert outcome, and per-destination EVAL order must be preserved. Eval +// order is asserted through content — WHICH attempts alerted (counts 5,7,9,10) +// proves the evaluator saw a destination's attempts in add order. Sink ARRIVAL +// order is intentionally unordered — across attempts (unordered delivery pool) +// and within an attempt (concurrent sends) — so no assertion constrains it; +// WHICH events an attempt emitted still is (topicsForAttempt + ElementsMatch). + +import ( + "fmt" + "testing" + "time" + + "github.com/hookdeck/outpost/internal/models" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// 10 failed attempts in order → cf at counts 5,7,9,10; disabled at 10; disabler +// recorded the destination; all messages acked. +func TestCharacterization_ThresholdsThenDisable(t *testing.T) { + t.Parallel() + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 10}, + alert: alertConfig{withDisabler: true}, + }) + + destA, tenant := "dest_a1", "tenant_a1" + msgs := make([]*countingMessage, 0, 10) + for i := 1; i <= 10; i++ { + cm, msg := newCountingMessage(makeEntry(destA, tenant, fmt.Sprintf("att_%d", i), models.AttemptStatusFailed)) + msgs = append(msgs, cm) + h.add(msg) + } + h.waitTerminal(msgs) + + recs := h.sink.forDest(destA) + // cf at 5,7,9,10 (4 records) plus disabled at 10 (1 record) = 5 records. + // Which attempts alerted proves eval order; arrival order is unordered. + require.ElementsMatch(t, []string{"att_5", "att_7", "att_9", "att_10", "att_10"}, attemptIDs(recs)) + require.ElementsMatch(t, []string{topicCF, topicCF, topicCF, topicDisabled, topicCF}, topics(recs)) + // Attempt 10 emits both the disabled and cf events; arrival order is + // unconstrained (concurrent sends). + require.ElementsMatch(t, []string{topicDisabled, topicCF}, topicsForAttempt(recs, "att_10")) + + disabled := h.disabler.snapshot() + require.Len(t, disabled, 1) + assert.Equal(t, disableRecord{tenantID: tenant, destinationID: destA}, disabled[0]) + + for _, m := range msgs { + m.requireAcked(t) + } +} + +// Keystone: 5 failures, 1 success (reset), 5 failures → 50% alert at the 5th +// failure, then a SECOND 50% alert at the post-reset 5th failure (not a +// continuation to 70%). Eval order drives the outcome; this fails loudly if +// eval reorders a destination's attempts (the alerting attempt IDs change). +func TestCharacterization_SuccessResetsConsecutiveCount(t *testing.T) { + t.Parallel() + // 11 messages in a single batch; the in-batch serial loop preserves add order. + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 11}, + alert: alertConfig{withDisabler: true}, + }) + + destA, tenant := "dest_a2", "tenant_a2" + msgs := make([]*countingMessage, 0, 11) + add := func(entry models.LogEntry) { + cm, msg := newCountingMessage(entry) + msgs = append(msgs, cm) + h.add(msg) + } + for i := 1; i <= 5; i++ { + add(makeEntry(destA, tenant, fmt.Sprintf("fail_pre_%d", i), models.AttemptStatusFailed)) + } + add(makeEntry(destA, tenant, "success_1", models.AttemptStatusSuccess)) + for i := 1; i <= 5; i++ { + add(makeEntry(destA, tenant, fmt.Sprintf("fail_post_%d", i), models.AttemptStatusFailed)) + } + h.waitTerminal(msgs) + + recs := h.sink.forDest(destA) + // Two cf alerts, both at the 50% threshold (count 5), separated by the reset. + require.Equal(t, []string{topicCF, topicCF}, topics(recs)) + require.ElementsMatch(t, []string{"fail_pre_5", "fail_post_5"}, attemptIDs(recs)) + + // No disable: count never reached 10. + assert.Empty(t, h.disabler.snapshot()) + for _, m := range msgs { + m.requireAcked(t) + } +} + +// One batch interleaving dest A and dest B, each reaching its thresholds → each +// destination's records match its own expected content; neither the A-vs-B +// interleaving nor per-dest arrival order is constrained (guards the sharded +// eval pool + unordered delivery). +func TestCharacterization_TwoDestinationsInterleaved(t *testing.T) { + t.Parallel() + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 20}, + alert: alertConfig{withDisabler: true}, + }) + + destA, destB := "dest_a3", "dest_b3" + tenant := "tenant_a3" + msgs := make([]*countingMessage, 0, 20) + add := func(destID, attemptID string) { + cm, msg := newCountingMessage(makeEntry(destID, tenant, attemptID, models.AttemptStatusFailed)) + msgs = append(msgs, cm) + h.add(msg) + } + // Interleave A and B failures. + for i := 1; i <= 10; i++ { + add(destA, fmt.Sprintf("a_%d", i)) + add(destB, fmt.Sprintf("b_%d", i)) + } + h.waitTerminal(msgs) + + wantTopics := []string{topicCF, topicCF, topicCF, topicDisabled, topicCF} + recsA, recsB := h.sink.forDest(destA), h.sink.forDest(destB) + assert.ElementsMatch(t, wantTopics, topics(recsA), "dest A records") + assert.ElementsMatch(t, wantTopics, topics(recsB), "dest B records") + assert.ElementsMatch(t, []string{"a_5", "a_7", "a_9", "a_10", "a_10"}, attemptIDs(recsA)) + assert.ElementsMatch(t, []string{"b_5", "b_7", "b_9", "b_10", "b_10"}, attemptIDs(recsB)) + assert.ElementsMatch(t, []string{topicDisabled, topicCF}, topicsForAttempt(recsA, "a_10")) + assert.ElementsMatch(t, []string{topicDisabled, topicCF}, topicsForAttempt(recsB, "b_10")) + + disabled := h.disabler.snapshot() + require.Len(t, disabled, 2) + gotDisabled := map[string]bool{} + for _, d := range disabled { + gotDisabled[d.destinationID] = true + } + assert.True(t, gotDisabled[destA] && gotDisabled[destB]) + + for _, m := range msgs { + m.requireAcked(t) + } +} + +// 10 failures with distinct attempt IDs → the thresholds fire on exactly the +// 5th/7th/9th/10th attempts ADDED. If eval reordered a destination's attempts, +// different attempt IDs would carry the alerts (guards single-destination eval +// reordering; arrival order at the sink is unconstrained). +func TestCharacterization_EvalOrderDrivesAlerts(t *testing.T) { + t.Parallel() + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 10}, + alert: alertConfig{withDisabler: true}, + }) + + destA, tenant := "dest_a4", "tenant_a4" + msgs := make([]*countingMessage, 0, 10) + for i := 1; i <= 10; i++ { + cm, msg := newCountingMessage(makeEntry(destA, tenant, fmt.Sprintf("att_%02d", i), models.AttemptStatusFailed)) + msgs = append(msgs, cm) + h.add(msg) + } + h.waitTerminal(msgs) + + recs := h.sink.forDest(destA) + // Records are emitted at counts 5,7,9 (cf), 10 (disabled + cf). + require.ElementsMatch(t, []string{"att_05", "att_07", "att_09", "att_10", "att_10"}, attemptIDs(recs)) + assert.ElementsMatch(t, []string{topicDisabled, topicCF}, topicsForAttempt(recs, "att_10")) +} + +// Dest A split across TWO batches (6 failures, then 4) → count continues +// across batches; alerts land at 5,7,9,10 (proven by which attempts carry +// them). This is the discriminator against any design that scopes eval state +// or ordering to a single batch. +func TestCharacterization_CountContinuesAcrossBatches(t *testing.T) { + t.Parallel() + // itemCount=6 flushes the first batch by count; the second batch of 4 flushes + // via the delay ticker. + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 6, delay: 80 * time.Millisecond}, + alert: alertConfig{withDisabler: true}, + }) + + destA, tenant := "dest_a5", "tenant_a5" + + batch1 := make([]*countingMessage, 0, 6) + for i := 1; i <= 6; i++ { + cm, msg := newCountingMessage(makeEntry(destA, tenant, fmt.Sprintf("att_%02d", i), models.AttemptStatusFailed)) + batch1 = append(batch1, cm) + h.add(msg) + } + h.waitTerminal(batch1) + + batch2 := make([]*countingMessage, 0, 4) + for i := 7; i <= 10; i++ { + cm, msg := newCountingMessage(makeEntry(destA, tenant, fmt.Sprintf("att_%02d", i), models.AttemptStatusFailed)) + batch2 = append(batch2, cm) + h.add(msg) + } + h.waitTerminal(batch2) + + recs := h.sink.forDest(destA) + require.ElementsMatch(t, []string{topicCF, topicCF, topicCF, topicDisabled, topicCF}, topics(recs)) + require.ElementsMatch(t, []string{"att_05", "att_07", "att_09", "att_10", "att_10"}, attemptIDs(recs)) + require.ElementsMatch(t, []string{topicDisabled, topicCF}, topicsForAttempt(recs, "att_10")) + + require.Len(t, h.disabler.snapshot(), 1) + for _, m := range append(batch1, batch2...) { + m.requireAcked(t) + } +} diff --git a/internal/logmq/characterization_postprocess_test.go b/internal/logmq/characterization_postprocess_test.go new file mode 100644 index 000000000..9889ea15a --- /dev/null +++ b/internal/logmq/characterization_postprocess_test.go @@ -0,0 +1,184 @@ +package logmq_test + +// Postprocess pool: eval runs off the batch loop on per-destination +// shards. These tests pin the two sides of that contract — a slow eval never +// blocks persistence, and sharding keeps the ordering the counter depends on: +// same destination serial, different destinations (on different shards) +// concurrent. + +import ( + "fmt" + "hash/fnv" + "testing" + "time" + + "github.com/hookdeck/outpost/internal/models" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// shardOf mirrors the pool's shard mapping (fnv-1a(destID) % shards) so tests +// can pick destinations that do or don't share a shard. Keep in sync with +// shardIndex in postprocesspool.go. +func shardOf(destID string, shards int) int { + h := fnv.New32a() + _, _ = h.Write([]byte(destID)) + return int(h.Sum32() % uint32(shards)) +} + +// destOnOtherShard returns a destination ID that maps to a different shard +// than destID. +func destOnOtherShard(t *testing.T, destID string, shards int) string { + t.Helper() + for i := range 100 { + candidate := fmt.Sprintf("%s_other_%d", destID, i) + if shardOf(candidate, shards) != shardOf(destID, shards) { + return candidate + } + } + t.Fatal("no destination on another shard found") + return "" +} + +// A batch-1 attempt whose EVAL hangs must not delay batch 2's persistence. +// (If eval ran serially in the batch loop, a Redis hiccup on one attempt's +// eval would stall every following batch.) Both messages share a +// destination, so this holds even for the blocked shard: persistence is +// decoupled from eval entirely, not just across shards. +func TestCharacterization_SlowEvalDoesNotBlockPersistence(t *testing.T) { + t.Parallel() + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 1}, + // max=2, thresholds[50,100] → a single failure (count 1 = 50%) alerts. + alert: alertConfig{autoDisableCount: 2, thresholds: []int{50, 100}}, + doubles: doublesConfig{ + evalBlockOn: map[string]bool{"att_pp1_1": true}, + }, + }) + + dest, tenant := "dest_pp1", "tenant_pp1" + + // Batch 1: a failure whose eval blocks. + cmSlow, msgSlow := newCountingMessage(makeEntry(dest, tenant, "att_pp1_1", models.AttemptStatusFailed)) + h.add(msgSlow) + require.Eventually(t, func() bool { return h.eval.blockedEvals() >= 1 }, + 5*time.Second, 5*time.Millisecond, "the slow eval should reach the block") + + // Batch 2: same destination — persists while batch 1's eval hangs. + cmNext, msgNext := newCountingMessage(makeEntry(dest, tenant, "att_pp1_2", models.AttemptStatusSuccess)) + h.add(msgNext) + require.Eventually(t, func() bool { return len(h.listAttempt(dest)) == 2 }, + 5*time.Second, 5*time.Millisecond, "batch 2 persisted while batch 1's eval hangs") + assert.EqualValues(t, 0, h.eval.enteredEvals(), "no eval completed yet — persistence didn't wait for it") + assert.EqualValues(t, 0, cmSlow.acks()+cmSlow.nacks()+cmNext.acks()+cmNext.nacks(), + "both messages stay un-acked behind the blocked shard") + + // Release: the shard drains in order — failure alerts, success resets. + h.eval.release() + h.waitTerminal([]*countingMessage{cmSlow, cmNext}) + cmSlow.requireAcked(t) + cmNext.requireAcked(t) + assert.Equal(t, []string{topicCF}, topics(h.sink.forDest(dest))) +} + +// Destinations on different shards evaluate concurrently: a blocked eval on +// one destination doesn't stall another's eval or ack. +func TestCharacterization_CrossShardEvalsRunInParallel(t *testing.T) { + t.Parallel() + const shards = 4 + destA := "dest_pp2" + destB := destOnOtherShard(t, destA, shards) + + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 2}, + alert: alertConfig{autoDisableCount: 2, thresholds: []int{50, 100}}, + postprocess: postprocessConfig{shards: shards}, + doubles: doublesConfig{ + evalBlockOn: map[string]bool{"att_pp2_a": true}, + }, + }) + + tenant := "tenant_pp2" + cmA, msgA := newCountingMessage(makeEntry(destA, tenant, "att_pp2_a", models.AttemptStatusFailed)) + cmB, msgB := newCountingMessage(makeEntry(destB, tenant, "att_pp2_b", models.AttemptStatusFailed)) + h.add(msgA) + h.add(msgB) + + // B's shard is unaffected by A's blocked eval: B evals, alerts and acks. + h.waitTerminal([]*countingMessage{cmB}) + cmB.requireAcked(t) + assert.Equal(t, []string{topicCF}, topics(h.sink.forDest(destB))) + assert.EqualValues(t, 0, cmA.acks()+cmA.nacks(), "A stays blocked in eval") + + h.eval.release() + h.waitTerminal([]*countingMessage{cmA}) + cmA.requireAcked(t) + assert.Equal(t, []string{topicCF}, topics(h.sink.forDest(destA))) +} + +// One destination's evals stay serial: while an attempt's eval is blocked, the +// destination's next attempt must not start evaluating (same shard FIFO). This +// is the ordering the failure counter depends on. +func TestCharacterization_SameDestEvalStaysSerial(t *testing.T) { + t.Parallel() + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 1}, + alert: alertConfig{autoDisableCount: 2, thresholds: []int{50, 100}}, + doubles: doublesConfig{ + evalBlockOn: map[string]bool{"att_pp3_1": true}, + }, + }) + + dest, tenant := "dest_pp3", "tenant_pp3" + cm1, msg1 := newCountingMessage(makeEntry(dest, tenant, "att_pp3_1", models.AttemptStatusFailed)) + h.add(msg1) + require.Eventually(t, func() bool { return h.eval.blockedEvals() >= 1 }, + 5*time.Second, 5*time.Millisecond) + + cm2, msg2 := newCountingMessage(makeEntry(dest, tenant, "att_pp3_2", models.AttemptStatusFailed)) + h.add(msg2) + require.Eventually(t, func() bool { return len(h.listAttempt(dest)) == 2 }, + 5*time.Second, 5*time.Millisecond) + + // att_pp3_2 queued behind the blocked eval: it never reaches the evaluator. + require.Never(t, func() bool { return h.eval.enteredEvals() > 0 }, + 300*time.Millisecond, 20*time.Millisecond, "the second eval must wait for the first") + + // Release: both evals run in attempt order — counts 1 (50%) then 2 (100%). + h.eval.release() + h.waitTerminal([]*countingMessage{cm1, cm2}) + cm1.requireAcked(t) + cm2.requireAcked(t) + recs := h.sink.forDest(dest) + assert.ElementsMatch(t, []string{"att_pp3_1", "att_pp3_2"}, attemptIDs(recs)) + assert.ElementsMatch(t, []string{topicCF, topicCF}, topics(recs)) +} + +// Shutdown drains the postprocess pool: every dispatched task reaches its +// terminal state before Shutdown returns. +func TestCharacterization_ShutdownDrainsPostprocess(t *testing.T) { + t.Parallel() + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 1}, + alert: alertConfig{autoDisableCount: 2, thresholds: []int{50, 100}}, + doubles: doublesConfig{ + evalBlockOn: map[string]bool{"att_pp4": true}, + }, + }) + + cm, msg := newCountingMessage(makeEntry("dest_pp4", "tenant_pp4", "att_pp4", models.AttemptStatusFailed)) + h.add(msg) + require.Eventually(t, func() bool { return h.eval.blockedEvals() >= 1 }, + 5*time.Second, 5*time.Millisecond) + + // Release while Shutdown is waiting on the drain. + go func() { + time.Sleep(50 * time.Millisecond) + h.eval.release() + }() + h.bp.Shutdown() + + // Shutdown returned → the eval ran, the alert delivered and the msg acked. + cm.requireAcked(t) + assert.Equal(t, []string{topicCF}, topics(h.sink.forDest("dest_pp4"))) +} diff --git a/internal/logmq/characterization_validation_test.go b/internal/logmq/characterization_validation_test.go new file mode 100644 index 000000000..ed3d7d3cb --- /dev/null +++ b/internal/logmq/characterization_validation_test.go @@ -0,0 +1,65 @@ +package logmq_test + +// Intake / validation. The front of the pipeline: in-batch dedup and the +// nack-all-on-persist-failure path. Both are concurrency-relevant, so they are +// pinned here even though some intake routing is also covered by batchprocessor_test.go. + +import ( + "fmt" + "testing" + + "github.com/hookdeck/outpost/internal/models" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +// Two messages with identical Attempt.ID in one batch → persisted once +// (ListAttempt shows 1), both messages acked (the kept entry and the duplicate +// copy), total nack==0. +func TestCharacterization_InBatchDuplicate(t *testing.T) { + t.Parallel() + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 2}, + alert: alertConfig{withDisabler: true}, + }) + + destA, tenant := "dest_04", "tenant_04" + entry := makeEntry(destA, tenant, "att_dup", models.AttemptStatusSuccess) + cm1, msg1 := newCountingMessage(entry) + cm2, msg2 := newCountingMessage(entry) + h.add(msg1) + h.add(msg2) + h.waitTerminal([]*countingMessage{cm1, cm2}) + + require.Len(t, h.listAttempt(destA), 1, "duplicate persisted once") + + // Both the kept entry and the duplicate copy are acked; neither nacked. + cm1.requireAcked(t) + cm2.requireAcked(t) +} + +// InsertMany returns error → all messages nacked, nothing persisted, zero sink +// records (eval never ran). +func TestCharacterization_InsertManyErrorNacksAll(t *testing.T) { + t.Parallel() + failing := &failingLogStore{err: fmt.Errorf("insert boom")} + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 3}, + alert: alertConfig{withDisabler: true}, + doubles: doublesConfig{logStore: failing}, + }) + + destA, tenant := "dest_05", "tenant_05" + msgs := make([]*countingMessage, 0, 3) + for i := 1; i <= 3; i++ { + cm, msg := newCountingMessage(makeEntry(destA, tenant, fmt.Sprintf("att_%d", i), models.AttemptStatusFailed)) + msgs = append(msgs, cm) + h.add(msg) + } + h.waitTerminal(msgs) + + for _, m := range msgs { + m.requireNacked(t) + } + assert.Empty(t, h.sink.snapshot(), "no events emitted when persistence fails") +} diff --git a/internal/logmq/delivery_suppression_test.go b/internal/logmq/delivery_suppression_test.go new file mode 100644 index 000000000..4dfc25fc1 --- /dev/null +++ b/internal/logmq/delivery_suppression_test.go @@ -0,0 +1,154 @@ +package logmq_test + +// Delivery-layer exhausted-retries suppression: the delivery worker wraps the +// keyed exhausted event in an idempotence window. These tests exercise that +// path (the characterization suite wires no idempotence, so it doesn't cover +// it). + +import ( + "testing" + "time" + + "github.com/hookdeck/outpost/internal/idempotence" + "github.com/hookdeck/outpost/internal/models" + "github.com/hookdeck/outpost/internal/util/testutil" + "github.com/stretchr/testify/assert" +) + +// makeExhaustedEntry builds a failed attempt past the retry limit for a fixed +// event+destination, so its exhausted-retries suppression key is deterministic. +// cf alerting is kept quiet by the callers' high thresholds/auto-disable count. +func makeExhaustedEntry(destID, tenantID, eventID, attemptID string, attemptNumber int) models.LogEntry { + event := testutil.EventFactory.Any( + testutil.EventFactory.WithID(eventID), + testutil.EventFactory.WithTenantID(tenantID), + testutil.EventFactory.WithEligibleForRetry(true), + testutil.EventFactory.WithMatchedDestinationIDs([]string{destID}), + ) + attempt := testutil.AttemptFactory.Any( + testutil.AttemptFactory.WithID(attemptID), + testutil.AttemptFactory.WithTenantID(tenantID), + testutil.AttemptFactory.WithEventID(event.ID), + testutil.AttemptFactory.WithDestinationID(destID), + testutil.AttemptFactory.WithStatus(models.AttemptStatusFailed), + testutil.AttemptFactory.WithAttemptNumber(attemptNumber), + ) + dest := testutil.DestinationFactory.Any( + testutil.DestinationFactory.WithID(destID), + testutil.DestinationFactory.WithTenantID(tenantID), + ) + return models.LogEntry{Event: &event, Attempt: &attempt, Destination: &dest} +} + +// exhaustedAlertConfig keeps consecutive-failure alerting silent (threshold 100%, +// high auto-disable count) so only exhausted-retries events fire. +func exhaustedAlertConfig() alertConfig { + return alertConfig{thresholds: []int{100}, autoDisableCount: 100, retryMaxLimit: 3} +} + +// Two exhaustions of the same event+destination within the window → only the +// first delivers; the second is suppressed by the idempotence key. +func TestDelivery_ExhaustedRetries_WindowSuppression(t *testing.T) { + t.Parallel() + idemp := idempotence.New(testutil.CreateTestRedisClient(t), idempotence.WithSuccessfulTTL(10*time.Second)) + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 2}, + alert: exhaustedAlertConfig(), + // Serial delivery: concurrent Execs on the same window key would hit + // the in-flight conflict path (sleep + ErrConflict) instead of the + // suppression this test pins. + delivery: deliveryConfig{concurrency: 1}, + doubles: doublesConfig{idemp: idemp}, + }) + + dest, tenant, eventID := "dest_ws", "tenant_ws", "evt_ws" + cm1, msg1 := newCountingMessage(makeExhaustedEntry(dest, tenant, eventID, "att_ws_1", 4)) + cm2, msg2 := newCountingMessage(makeExhaustedEntry(dest, tenant, eventID, "att_ws_2", 5)) + h.add(msg1) + h.add(msg2) + h.waitTerminal([]*countingMessage{cm1, cm2}) + + cm1.requireAcked(t) + cm2.requireAcked(t) + assert.Equal(t, []string{topicExhaust}, topics(h.sink.forDest(dest)), + "second exhaustion of the same event+destination is suppressed within the window") +} + +// With no suppression window (idemp nil == WindowSeconds 0), every exhaustion of +// the same event+destination delivers — the key is present but there's no +// idempotence to enforce it. +func TestDelivery_ExhaustedRetries_NoWindowEmitsEvery(t *testing.T) { + t.Parallel() + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 2}, + alert: exhaustedAlertConfig(), + // doubles.idemp left nil → no suppression window. + }) + + dest, tenant, eventID := "dest_nw", "tenant_nw", "evt_nw" + cm1, msg1 := newCountingMessage(makeExhaustedEntry(dest, tenant, eventID, "att_nw_1", 4)) + cm2, msg2 := newCountingMessage(makeExhaustedEntry(dest, tenant, eventID, "att_nw_2", 5)) + h.add(msg1) + h.add(msg2) + h.waitTerminal([]*countingMessage{cm1, cm2}) + + cm1.requireAcked(t) + cm2.requireAcked(t) + assert.Equal(t, []string{topicExhaust, topicExhaust}, topics(h.sink.forDest(dest)), + "with no window, every exhaustion of the same event+destination delivers") +} + +// Distinct events exhausting on the same destination carry distinct keys → each +// delivers its own alert. +func TestDelivery_ExhaustedRetries_PerEvent(t *testing.T) { + t.Parallel() + idemp := idempotence.New(testutil.CreateTestRedisClient(t), idempotence.WithSuccessfulTTL(10*time.Second)) + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 2}, + alert: exhaustedAlertConfig(), + doubles: doublesConfig{idemp: idemp}, + }) + + dest, tenant := "dest_pe", "tenant_pe" + cm1, msg1 := newCountingMessage(makeExhaustedEntry(dest, tenant, "evt_pe_1", "att_pe_1", 4)) + cm2, msg2 := newCountingMessage(makeExhaustedEntry(dest, tenant, "evt_pe_2", "att_pe_2", 4)) + h.add(msg1) + h.add(msg2) + h.waitTerminal([]*countingMessage{cm1, cm2}) + + cm1.requireAcked(t) + cm2.requireAcked(t) + assert.Equal(t, []string{topicExhaust, topicExhaust}, topics(h.sink.forDest(dest)), + "each distinct event exhausting retries delivers its own alert") +} + +// Emit failure clears the window key, so a later exhaustion of the same +// event+destination re-delivers instead of being suppressed. +func TestDelivery_ExhaustedRetries_EmitFailureClearsWindow(t *testing.T) { + t.Parallel() + idemp := idempotence.New(testutil.CreateTestRedisClient(t), idempotence.WithSuccessfulTTL(10*time.Second)) + h := newHarness(t, harnessConfig{ + batcher: batcherConfig{itemCount: 2}, + alert: exhaustedAlertConfig(), + // Serial delivery: the fail-then-retry sequence on one window key + // needs deterministic delivery order. + delivery: deliveryConfig{concurrency: 1}, + doubles: doublesConfig{ + idemp: idemp, + sinkFailOn: map[string]bool{"att_fail": true}, // first exhausted emit fails + }, + }) + + dest, tenant, eventID := "dest_ef", "tenant_ef", "evt_ef" + cmFail, msgFail := newCountingMessage(makeExhaustedEntry(dest, tenant, eventID, "att_fail", 4)) + cmOK, msgOK := newCountingMessage(makeExhaustedEntry(dest, tenant, eventID, "att_ok", 5)) + h.add(msgFail) + h.add(msgOK) + h.waitTerminal([]*countingMessage{cmFail, cmOK}) + + // The failed emit nacks; the retry (key cleared on failure) delivers and acks. + cmFail.requireNacked(t) + cmOK.requireAcked(t) + assert.Equal(t, []string{topicExhaust}, topics(h.sink.forDest(dest)), + "retry after emit failure re-delivers because the window key was cleared") +} diff --git a/internal/logmq/deliverypool.go b/internal/logmq/deliverypool.go new file mode 100644 index 000000000..d228bcd1c --- /dev/null +++ b/internal/logmq/deliverypool.go @@ -0,0 +1,166 @@ +package logmq + +import ( + "context" + "sync" + "time" + + "github.com/hookdeck/outpost/internal/logging" + "github.com/hookdeck/outpost/internal/models" + "github.com/hookdeck/outpost/internal/mqs" + "github.com/hookdeck/outpost/internal/opevents" + "go.uber.org/zap" + "golang.org/x/sync/errgroup" +) + +// emitTimeout caps a single sink send. It is the system's definition of the +// worst ACCEPTABLE send latency: the delivery pool is sized to sustain full +// line rate at exactly this latency (see deriveDeliveryConcurrency), so a +// sink can run this slow indefinitely without falling behind. Anything slower +// fails into the nack/redelivery path — no worker count makes a +// beyond-timeout sink work, so sizing stops here. +const emitTimeout = 5 * time.Second + +// delivery is one attempt's owed operator events plus the message whose +// terminal state (ack/nack) they decide. Events are fully built before enqueue +// — post-disable, so the payload carries the destination's latest state — and +// one worker owns the whole delivery: its child send goroutines each read one +// event, and the entry is read-only from here on. +type delivery struct { + // events: disabled, consecutive_failure, exhausted_retries. Sent + // concurrently — no arrival-order guarantee within the attempt. + events []deliveryEvent + // entry supplies the audit-log fields. + entry *models.LogEntry + // msg is acked (all events delivered) or nacked (any failure) by the worker. + msg *mqs.Message + // processedKey is the per-attempt replay gate key, marked before ack. + processedKey string +} + +type deliveryEvent struct { + event opevents.Event + // suppressKey is the exhausted-retries suppression window key; "" = no + // window (emit unconditionally). + suppressKey string +} + +// deliveryPool delivers operator events on a fixed set of workers, unordered +// across attempts. It exists so the slow part of the alert pipeline (the sink +// call) never blocks the batch loop: eval hands a delivery off and moves on; +// the worker finishes the attempt's gate mark and terminal state. +type deliveryPool struct { + ctx context.Context + logger *logging.Logger + emitter opevents.Emitter + processedIdemp ReplayGate + exhaustedIdemp SuppressionWindow + + queue chan delivery + wg sync.WaitGroup +} + +func newDeliveryPool(ctx context.Context, logger *logging.Logger, alerts AlertPipeline, concurrency, queueDepth int) *deliveryPool { + p := &deliveryPool{ + ctx: ctx, + logger: logger, + emitter: alerts.Emitter, + processedIdemp: alerts.ProcessedIdemp, + exhaustedIdemp: alerts.ExhaustedIdemp, + queue: make(chan delivery, queueDepth), + } + p.wg.Add(concurrency) + for range concurrency { + go p.worker() + } + return p +} + +// enqueue hands a delivery to the pool. It blocks while the queue is full — +// the backpressure path: it stalls the postprocess workers, whose shard queues +// then fill and stall the batch loop, the batcher, and finally the broker +// fetch, so excess backlog stays in the broker instead of in memory. +func (p *deliveryPool) enqueue(d delivery) { + p.queue <- d +} + +// shutdown stops intake and drains: every enqueued delivery reaches a terminal +// state before shutdown returns. The caller must guarantee no concurrent +// enqueues (the postprocess pool — the only producer — is drained first). +func (p *deliveryPool) shutdown() { + close(p.queue) + p.wg.Wait() +} + +func (p *deliveryPool) worker() { + defer p.wg.Done() + for d := range p.queue { + p.process(d) + } +} + +// process emits the attempt's events concurrently, then marks the replay gate +// and acks. The worker still owns the whole attempt — the fan-out is child +// goroutines inside it, so the shared ack needs no fan-in protocol — but the +// worker is occupied ~one send latency instead of K× it, which is what lets +// the pool's sizing ignore how many events an attempt owes. Arrival order +// within an attempt is not guaranteed. Any failure nacks with nothing marked, +// so redelivery re-runs the attempt in full — events already sent may go out +// again (at-least-once). +func (p *deliveryPool) process(d delivery) { + ctx := p.ctx + g, gctx := errgroup.WithContext(ctx) + for _, de := range d.events { + g.Go(func() error { + sendCtx, cancel := context.WithTimeout(gctx, emitTimeout) + defer cancel() + if err := p.send(sendCtx, de, d.entry); err != nil { + p.logger.Ctx(ctx).Error("opevent delivery failed", + zap.Error(err), + zap.String("topic", de.event.Topic), + zap.String("attempt_id", d.entry.Attempt.ID), + zap.String("event_id", d.entry.Event.ID), + zap.String("destination_id", d.entry.Destination.ID)) + return err + } + return nil + }) + } + if g.Wait() != nil { + d.msg.Nack() + return + } + + if err := p.processedIdemp.MarkProcessed(ctx, d.processedKey); err != nil { + p.logger.Ctx(ctx).Error("failed to mark attempt processed", + zap.Error(err), + zap.String("attempt_id", d.entry.Attempt.ID), + zap.String("destination_id", d.entry.Destination.ID)) + d.msg.Nack() + return + } + d.msg.Ack() +} + +// send emits one event and audits the send, inside the event's suppression +// window when it has one. A suppressed duplicate (Exec skips the emit) counts +// as delivered and is not audited. +func (p *deliveryPool) send(ctx context.Context, de deliveryEvent, entry *models.LogEntry) error { + emit := func(ctx context.Context) error { + if err := p.emitter.Emit(ctx, de.event); err != nil { + return err + } + p.logger.Ctx(ctx).Audit("opevent delivered", + zap.String("topic", de.event.Topic), + zap.String("attempt_id", entry.Attempt.ID), + zap.String("event_id", entry.Event.ID), + zap.String("tenant_id", de.event.TenantID), + zap.String("destination_id", entry.Destination.ID), + zap.String("destination_type", entry.Destination.Type)) + return nil + } + if de.suppressKey == "" { + return emit(ctx) + } + return p.exhaustedIdemp.Exec(ctx, de.suppressKey, emit) +} diff --git a/internal/logmq/postprocesspool.go b/internal/logmq/postprocesspool.go new file mode 100644 index 000000000..f6d15e8f3 --- /dev/null +++ b/internal/logmq/postprocesspool.go @@ -0,0 +1,239 @@ +package logmq + +import ( + "context" + "fmt" + "hash/fnv" + "sync" + "time" + + "github.com/hookdeck/outpost/internal/alert" + "github.com/hookdeck/outpost/internal/logging" + "github.com/hookdeck/outpost/internal/models" + "github.com/hookdeck/outpost/internal/mqs" + "github.com/hookdeck/outpost/internal/opevents" + "go.uber.org/zap" +) + +// postprocessTask is one persisted entry awaiting alert evaluation, plus the message +// whose terminal state the pipeline decides. +type postprocessTask struct { + entry *models.LogEntry + msg *mqs.Message +} + +// postprocessPool runs the ordered half of the alert pipeline — evaluate, disable, +// plan — off the batch loop, so a slow eval never blocks persistence of the +// next batch. Tasks are sharded by destination (hash(destID) % N): one worker +// owns each shard's FIFO, which keeps per-destination eval order (and thus +// failure counting) exactly as serial processing had it, while different +// destinations evaluate concurrently. Delivery of the planned events is stage +// 2 (deliveryPool). +type postprocessPool struct { + ctx context.Context + logger *logging.Logger + alerts AlertPipeline + pool *deliveryPool + + shards []chan postprocessTask + wg sync.WaitGroup +} + +func newPostprocessPool(ctx context.Context, logger *logging.Logger, alerts AlertPipeline, pool *deliveryPool, shardCount, queueDepth int) *postprocessPool { + ap := &postprocessPool{ + ctx: ctx, + logger: logger, + alerts: alerts, + pool: pool, + shards: make([]chan postprocessTask, shardCount), + } + ap.wg.Add(shardCount) + for i := range ap.shards { + ap.shards[i] = make(chan postprocessTask, queueDepth) + go ap.worker(ap.shards[i]) + } + return ap +} + +// dispatch routes the entry to its destination's shard. It blocks while that +// shard's queue is full — the backpressure path: it stalls the batch loop, +// which stalls the batcher, which stops draining the broker. A full shard +// head-of-line blocks the dispatch of other shards' entries in the same batch; +// accepted for simplicity (the queues drain in Redis time, ~ms). +func (ap *postprocessPool) dispatch(entry *models.LogEntry, msg *mqs.Message) { + ap.shards[shardIndex(entry.Destination.ID, len(ap.shards))] <- postprocessTask{entry: entry, msg: msg} +} + +// shardIndex maps a destination to its shard. Same destination → same shard → +// serial eval; the mapping is stable for the process lifetime. +func shardIndex(destinationID string, shardCount int) int { + h := fnv.New32a() + _, _ = h.Write([]byte(destinationID)) + return int(h.Sum32() % uint32(shardCount)) +} + +// shutdown stops intake and drains every shard: each queued task reaches eval +// (and, when it owes events, the delivery queue) before shutdown returns. The +// caller must guarantee no concurrent dispatches (the batcher is shut down +// first) and must shut the delivery pool down after (draining workers still +// enqueue into it). +func (ap *postprocessPool) shutdown() { + for _, shard := range ap.shards { + close(shard) + } + ap.wg.Wait() +} + +func (ap *postprocessPool) worker(shard chan postprocessTask) { + defer ap.wg.Done() + for task := range shard { + ap.evalAndDispatch(ap.ctx, task.entry, task.msg) + } +} + +// evalAndDispatch runs the alert pipeline for one persisted entry and owns the +// message's terminal state: evaluate the attempt, act on the verdict (disable, +// plan the operator events), then hand delivery to the pool. +// +// A failed attempt runs inside the per-attempt processed gate, so a replay +// (MQ redelivery, producer re-publish) of a fully processed attempt is skipped +// instead of re-counting or re-alerting. The check runs BEFORE eval — a stale +// replay arriving after a success reset must not count toward the fresh +// streak. The mark lands only after the attempt's events are delivered (in the +// pool worker; inline here when there are none) — a nacked attempt re-runs in +// full on redelivery (counting stays correct: the store is idempotent per +// attempt ID). A success just resets the tracker — idempotent, so it needs no +// gate (and gating it would cost one Redis key per successful attempt). +func (ap *postprocessPool) evalAndDispatch(ctx context.Context, entry *models.LogEntry, msg *mqs.Message) { + attempt := alert.Attempt{ + TenantID: entry.Destination.TenantID, + DestinationID: entry.Destination.ID, + AttemptID: entry.Attempt.ID, + Number: entry.Attempt.AttemptNumber, + Success: entry.Attempt.Status == models.AttemptStatusSuccess, + EligibleForRetry: entry.Event.EligibleForRetry, + } + + if attempt.Success { + if _, err := ap.alerts.Evaluator.Evaluate(ctx, attempt); err != nil { + ap.nackAlertFailure(ctx, err, entry, msg) + return + } + msg.Ack() + return + } + + key := processedKey(attempt.AttemptID) + processed, err := ap.alerts.ProcessedIdemp.Processed(ctx, key) + if err != nil { + ap.nackAlertFailure(ctx, err, entry, msg) + return + } + if processed { + msg.Ack() + return + } + + eval, err := ap.alerts.Evaluator.Evaluate(ctx, attempt) + if err != nil { + ap.nackAlertFailure(ctx, err, entry, msg) + return + } + + events, err := ap.plan(ctx, eval, entry) + if err != nil { + ap.nackAlertFailure(ctx, err, entry, msg) + return + } + + // Common case: nothing to deliver — the attempt is fully processed here. + if len(events) == 0 { + if err := ap.alerts.ProcessedIdemp.MarkProcessed(ctx, key); err != nil { + ap.nackAlertFailure(ctx, err, entry, msg) + return + } + msg.Ack() + return + } + + // Blocks while the delivery queue is full (backpressure). The worker owns + // the message's terminal state from here. + ap.pool.enqueue(delivery{ + events: events, + entry: entry, + msg: msg, + processedKey: key, + }) +} + +// nackAlertFailure logs an alert-pipeline failure and nacks. InsertMany is +// idempotent (upsert by attempt ID) and a failed attempt is never marked +// processed, so redelivery re-evaluates and re-emits — events already sent may +// go out again (at-least-once). +func (ap *postprocessPool) nackAlertFailure(ctx context.Context, err error, entry *models.LogEntry, msg *mqs.Message) { + ap.logger.Ctx(ctx).Error("alert processing failed", + zap.Error(err), + zap.String("attempt_id", entry.Attempt.ID), + zap.String("event_id", entry.Event.ID), + zap.String("destination_id", entry.Destination.ID)) + msg.Nack() +} + +// plan acts on an evaluation and builds the operator events owed for this +// attempt — disabled, consecutive_failure, exhausted_retries. The delivery +// worker sends them concurrently, so slice order carries no meaning. +// The disable (a DB write) happens here, in the ordered +// lane: it's an action, not a notification, and it must precede event +// construction so the payloads carry the destination's latest state +// (disabled). The events are complete at return — workers share no mutable +// state with the eval side. +func (ap *postprocessPool) plan(ctx context.Context, eval alert.Evaluation, entry *models.LogEntry) ([]deliveryEvent, error) { + if eval.ConsecutiveFailure == nil && !eval.RetriesExhausted { + return nil, nil + } + + dest := opevents.NewAlertDestination(entry.Destination) + var events []deliveryEvent + + if cf := eval.ConsecutiveFailure; cf != nil { + if cf.Level == 100 && ap.alerts.Disabler != nil { + // Disable converges on replay: re-disabling rewrites DisabledAt, + // but the end state is the same. + if err := ap.alerts.Disabler.DisableDestination(ctx, dest.TenantID, dest.ID); err != nil { + return nil, fmt.Errorf("failed to disable destination: %w", err) + } + + // The payload carries the destination's latest state: disabled. + now := time.Now() + dest.DisabledAt = &now + + ap.logger.Ctx(ctx).Audit("destination disabled", + zap.String("attempt_id", entry.Attempt.ID), + zap.String("event_id", entry.Event.ID), + zap.String("tenant_id", dest.TenantID), + zap.String("destination_id", dest.ID), + zap.String("destination_type", dest.Type)) + + events = append(events, deliveryEvent{ + event: opevents.DestinationDisabledEvent(dest, entry.Event, entry.Attempt, now), + }) + } + + events = append(events, deliveryEvent{ + event: opevents.ConsecutiveFailureEvent(dest, entry.Event, entry.Attempt, + cf.Failures, cf.Max, cf.Level), + }) + } + + if eval.RetriesExhausted { + de := deliveryEvent{ + event: opevents.ExhaustedRetriesEvent(dest, entry.Event, entry.Attempt), + } + if ap.alerts.ExhaustedIdemp != nil { + de.suppressKey = exhaustedRetriesKey(entry.Event.ID, dest.ID) + } + events = append(events, de) + } + + return events, nil +} diff --git a/internal/logmq/sizing_test.go b/internal/logmq/sizing_test.go new file mode 100644 index 000000000..86ccd4262 --- /dev/null +++ b/internal/logmq/sizing_test.go @@ -0,0 +1,74 @@ +package logmq + +// White-box: pins the pool-sizing derivation. The formulas encode +// the operating contract — line rate at any send latency the emit timeout +// accepts, one batch of queue slack, visibility-safe ack latency — so a +// change here is a behavior change, not a refactor. + +import ( + "testing" + + "github.com/stretchr/testify/assert" +) + +func TestDerivePostprocessShards(t *testing.T) { + t.Parallel() + // shards × 250 evals/s must cover LogBatchSize entries/s. + assert.Equal(t, 8, derivePostprocessShards(0), "floor: tests and tiny deployments") + assert.Equal(t, 8, derivePostprocessShards(1000), "default batch: 1000/250=4, floored to 8") + assert.Equal(t, 16, derivePostprocessShards(4000)) + assert.Equal(t, 64, derivePostprocessShards(20000), "20000/250=80, capped: past 64 the wall is Redis/intake") +} + +func TestDerivePostprocessShardQueueDepth(t *testing.T) { + t.Parallel() + // depth × shards ≈ one full batch, so a healthy dispatch never blocks. + assert.Equal(t, 125, derivePostprocessShardQueueDepth(1000, 8)) + assert.Equal(t, 313, derivePostprocessShardQueueDepth(20000, 64), "ceil(20000/64)") + assert.Equal(t, 1, derivePostprocessShardQueueDepth(0, 8), "floor: never an unbuffered shard") +} + +func TestDeriveDeliveryConcurrency(t *testing.T) { + t.Parallel() + // workers = rate × worst accepted latency = LogBatchSize/s × emitTimeout. + assert.Equal(t, 10, deriveDeliveryConcurrency(0), "floor") + assert.Equal(t, 10, deriveDeliveryConcurrency(2), "small test batches stay at the floor") + assert.Equal(t, 5000, deriveDeliveryConcurrency(1000), "1000/s sustained with every send at the 5s timeout") + assert.Equal(t, 8192, deriveDeliveryConcurrency(20000), "capped: horizontal-scale territory") +} + +// The visibility invariant the sizes must satisfy: everything fetched reaches +// a terminal state within the broker's ~60s window even with every send at +// emitTimeout. held ≈ 2×batch (batcher + shard queues) + 3×W (delivery queue +// 2W + in-hand W); drain = W/emitTimeout, so +// +// sojourn = 10×batch/W + 3×emitTimeout +// +// Below the worker cap (batch ≤ 1638) W = 5×batch and sojourn is a constant +// 17s. Above it W is pinned at 8192 and sojourn grows with batch, crossing +// 60s at batch ≈ 37k — the single-instance envelope's edge. Past that, an +// operator needs horizontal scale (or a longer visibility window), not a +// bigger pool; the second subtest documents that boundary rather than +// pretending the formula covers it. +func TestDerivedSizingRespectsVisibility(t *testing.T) { + t.Parallel() + const visibilityBudgetSecs = 60.0 + emitSecs := emitTimeout.Seconds() + sojourn := func(batch int) float64 { + w := deriveDeliveryConcurrency(batch) + held := float64(2*batch + 3*w) + return held / (float64(w) / emitSecs) + } + + t.Run("within envelope", func(t *testing.T) { + for _, batch := range []int{1, 100, 1000, 5000, 20000, 36000} { + assert.LessOrEqualf(t, sojourn(batch), visibilityBudgetSecs, + "batch=%d: worst-case ack latency %.1fs must fit the visibility window", batch, sojourn(batch)) + } + }) + + t.Run("envelope edge", func(t *testing.T) { + assert.Greater(t, sojourn(50000), visibilityBudgetSecs, + "past ~37k the capped pool can no longer make a timeout-pinned sink visibility-safe — horizontal-scale territory, by design") + }) +} diff --git a/internal/opevents/emitter.go b/internal/opevents/emitter.go index 69d496faa..ad225b9fb 100644 --- a/internal/opevents/emitter.go +++ b/internal/opevents/emitter.go @@ -15,9 +15,17 @@ const ( backoffFactor = 2 ) +// Event is a request to emit an operator event. Callers (alert eval, apirouter) +// build it and hand it to Emit, which owns envelope construction and delivery. +type Event struct { + Topic string + TenantID string + Data any +} + // Emitter is the interface for emitting operator events. type Emitter interface { - Emit(ctx context.Context, topic string, tenantID string, data any) error + Emit(ctx context.Context, ev Event) error } // emitter is the default Emitter implementation. @@ -54,23 +62,23 @@ func NewEmitter(sink Sink, deploymentID string, topics []string) Emitter { } } -func (e *emitter) Emit(ctx context.Context, topic string, tenantID string, data any) error { +func (e *emitter) Emit(ctx context.Context, ev Event) error { // Topic filtering: nil filter means accept all ("*") - if e.topicFilter != nil && !e.topicFilter[topic] { + if e.topicFilter != nil && !e.topicFilter[ev.Topic] { return nil } - rawData, err := json.Marshal(data) + rawData, err := json.Marshal(ev.Data) if err != nil { return fmt.Errorf("opevents: failed to marshal data: %w", err) } event := &OperatorEvent{ ID: idgen.String(), - Topic: topic, + Topic: ev.Topic, Time: time.Now(), DeploymentID: e.deploymentID, - TenantID: tenantID, + TenantID: ev.TenantID, Data: rawData, } @@ -104,6 +112,6 @@ func (e *emitter) sendWithRetry(ctx context.Context, event *OperatorEvent) error // noopEmitter discards all events. Used when operator events are disabled. type noopEmitter struct{} -func (e *noopEmitter) Emit(ctx context.Context, topic string, tenantID string, data any) error { +func (e *noopEmitter) Emit(ctx context.Context, ev Event) error { return nil } diff --git a/internal/opevents/emitter_test.go b/internal/opevents/emitter_test.go index 8d6ce1646..f716c6a9d 100644 --- a/internal/opevents/emitter_test.go +++ b/internal/opevents/emitter_test.go @@ -51,7 +51,7 @@ func TestEmitter_Emit(t *testing.T) { sink := &mockSink{} em := opevents.NewEmitter(sink, "deploy-1", []string{"*"}) - err := em.Emit(context.Background(), "any.topic", "tenant-1", map[string]string{"key": "val"}) + err := em.Emit(context.Background(), opevents.Event{Topic: "any.topic", TenantID: "tenant-1", Data: map[string]string{"key": "val"}}) require.NoError(t, err) events := sink.sentEvents() @@ -69,7 +69,7 @@ func TestEmitter_Emit(t *testing.T) { opevents.TopicTenantSubscriptionUpdated, }) - err := em.Emit(context.Background(), opevents.TopicAlertConsecutiveFailure, "t1", "data") + err := em.Emit(context.Background(), opevents.Event{Topic: opevents.TopicAlertConsecutiveFailure, TenantID: "t1", Data: "data"}) require.NoError(t, err) assert.Len(t, sink.sentEvents(), 1) }) @@ -79,7 +79,7 @@ func TestEmitter_Emit(t *testing.T) { sink := &mockSink{} em := opevents.NewEmitter(sink, "", []string{opevents.TopicAlertConsecutiveFailure}) - err := em.Emit(context.Background(), opevents.TopicTenantSubscriptionUpdated, "t1", "data") + err := em.Emit(context.Background(), opevents.Event{Topic: opevents.TopicTenantSubscriptionUpdated, TenantID: "t1", Data: "data"}) require.NoError(t, err) assert.Empty(t, sink.sentEvents()) }) @@ -93,7 +93,7 @@ func TestEmitter_Emit(t *testing.T) { Count int `json:"count"` } - err := em.Emit(context.Background(), "test.topic", "tenant-42", payload{Count: 7}) + err := em.Emit(context.Background(), opevents.Event{Topic: "test.topic", TenantID: "tenant-42", Data: payload{Count: 7}}) require.NoError(t, err) events := sink.sentEvents() @@ -116,7 +116,7 @@ func TestEmitter_Emit(t *testing.T) { sink := &mockSink{} em := opevents.NewEmitter(sink, "", []string{"*"}) - err := em.Emit(context.Background(), "t", "tenant", "data") + err := em.Emit(context.Background(), opevents.Event{Topic: "t", TenantID: "tenant", Data: "data"}) require.NoError(t, err) events := sink.sentEvents() @@ -134,7 +134,7 @@ func TestEmitter_Emit(t *testing.T) { sink := &mockSink{} em := opevents.NewEmitter(sink, "", []string{}) - err := em.Emit(context.Background(), "any.topic", "t1", "data") + err := em.Emit(context.Background(), opevents.Event{Topic: "any.topic", TenantID: "t1", Data: "data"}) require.NoError(t, err) assert.Empty(t, sink.sentEvents(), "noop emitter should not send events") }) @@ -150,7 +150,7 @@ func TestEmitter_Emit(t *testing.T) { } em := opevents.NewEmitter(sink, "", []string{"*"}) - err := em.Emit(context.Background(), "t", "t1", "data") + err := em.Emit(context.Background(), opevents.Event{Topic: "t", TenantID: "t1", Data: "data"}) require.NoError(t, err) assert.Len(t, sink.sentEvents(), 1) }) @@ -166,7 +166,7 @@ func TestEmitter_Emit(t *testing.T) { } em := opevents.NewEmitter(sink, "", []string{"*"}) - err := em.Emit(context.Background(), "t", "t1", "data") + err := em.Emit(context.Background(), opevents.Event{Topic: "t", TenantID: "t1", Data: "data"}) require.Error(t, err) assert.Contains(t, err.Error(), "fail-3") assert.Empty(t, sink.sentEvents()) @@ -182,7 +182,7 @@ func TestEmitter_Emit(t *testing.T) { } em := opevents.NewEmitter(sink, "", []string{"*"}) - err := em.Emit(ctx, "t", "t1", "data") + err := em.Emit(ctx, opevents.Event{Topic: "t", TenantID: "t1", Data: "data"}) require.Error(t, err) }) } diff --git a/internal/opevents/payloads.go b/internal/opevents/payloads.go new file mode 100644 index 000000000..b632246c0 --- /dev/null +++ b/internal/opevents/payloads.go @@ -0,0 +1,137 @@ +package opevents + +import ( + "time" + + "github.com/hookdeck/outpost/internal/models" +) + +// Operator-event payloads: the wire contract for each topic. The typed +// constructors below are the only way these events are built, keeping topic, +// tenant, and payload shape in one place. + +// TenantSubscriptionUpdatedData is the data payload for +// tenant.subscription.updated events. +type TenantSubscriptionUpdatedData struct { + TenantID string `json:"tenant_id"` + Topics []string `json:"topics"` + PreviousTopics []string `json:"previous_topics"` + DestinationsCount int `json:"destinations_count"` + PreviousDestinationsCount int `json:"previous_destinations_count"` +} + +// TenantSubscriptionUpdatedEvent builds the tenant.subscription.updated event. +func TenantSubscriptionUpdatedEvent(data TenantSubscriptionUpdatedData) Event { + return Event{ + Topic: TopicTenantSubscriptionUpdated, + TenantID: data.TenantID, + Data: data, + } +} + +// AlertDestination is the destination projection included in alert payloads. +type AlertDestination struct { + ID string `json:"id"` + TenantID string `json:"tenant_id"` + Type string `json:"type"` + Topics models.Topics `json:"topics"` + Config models.Config `json:"config"` + CreatedAt time.Time `json:"created_at"` + DisabledAt *time.Time `json:"disabled_at"` +} + +// NewAlertDestination projects a models.Destination into the payload shape. +func NewAlertDestination(d *models.Destination) *AlertDestination { + return &AlertDestination{ + ID: d.ID, + TenantID: d.TenantID, + Type: d.Type, + Topics: d.Topics, + Config: d.Config, + CreatedAt: d.CreatedAt, + DisabledAt: d.DisabledAt, + } +} + +// ConsecutiveFailures represents the nested consecutive failure state. +type ConsecutiveFailures struct { + Current int `json:"current"` + Max int `json:"max"` + Threshold int `json:"threshold"` +} + +// DestinationDisabledData is the data payload for alert.destination.disabled events. +type DestinationDisabledData struct { + TenantID string `json:"tenant_id"` + Destination *AlertDestination `json:"destination"` + DisabledAt time.Time `json:"disabled_at"` + Reason string `json:"reason"` + Event *models.Event `json:"event"` + Attempt *models.Attempt `json:"attempt"` +} + +// ConsecutiveFailureData is the data payload for alert.destination.consecutive_failure events. +type ConsecutiveFailureData struct { + TenantID string `json:"tenant_id"` + Event *models.Event `json:"event"` + Attempt *models.Attempt `json:"attempt"` + Destination *AlertDestination `json:"destination"` + ConsecutiveFailures ConsecutiveFailures `json:"consecutive_failures"` +} + +// ExhaustedRetriesData is the data payload for alert.attempt.exhausted_retries events. +type ExhaustedRetriesData struct { + TenantID string `json:"tenant_id"` + Event *models.Event `json:"event"` + Attempt *models.Attempt `json:"attempt"` + Destination *AlertDestination `json:"destination"` +} + +// ConsecutiveFailureEvent builds the alert.destination.consecutive_failure event. +func ConsecutiveFailureEvent(dest *AlertDestination, event *models.Event, attempt *models.Attempt, current, max, threshold int) Event { + return Event{ + Topic: TopicAlertConsecutiveFailure, + TenantID: dest.TenantID, + Data: ConsecutiveFailureData{ + TenantID: dest.TenantID, + Event: event, + Attempt: attempt, + Destination: dest, + ConsecutiveFailures: ConsecutiveFailures{ + Current: current, + Max: max, + Threshold: threshold, + }, + }, + } +} + +// DestinationDisabledEvent builds the alert.destination.disabled event. +func DestinationDisabledEvent(dest *AlertDestination, event *models.Event, attempt *models.Attempt, disabledAt time.Time) Event { + return Event{ + Topic: TopicAlertDestinationDisabled, + TenantID: dest.TenantID, + Data: DestinationDisabledData{ + TenantID: dest.TenantID, + Destination: dest, + DisabledAt: disabledAt, + Reason: "consecutive_failure", + Event: event, + Attempt: attempt, + }, + } +} + +// ExhaustedRetriesEvent builds the alert.attempt.exhausted_retries event. +func ExhaustedRetriesEvent(dest *AlertDestination, event *models.Event, attempt *models.Attempt) Event { + return Event{ + Topic: TopicAlertExhaustedRetries, + TenantID: dest.TenantID, + Data: ExhaustedRetriesData{ + TenantID: dest.TenantID, + Event: event, + Attempt: attempt, + Destination: dest, + }, + } +} diff --git a/internal/services/builder.go b/internal/services/builder.go index e187d82c2..55214b7bb 100644 --- a/internal/services/builder.go +++ b/internal/services/builder.go @@ -364,11 +364,17 @@ func (b *ServiceBuilder) BuildLogWorker(baseRouter *gin.Engine) error { return fmt.Errorf("failed to resolve alert config: %w", err) } - var disabler alert.DestinationDisabler + var disabler logmq.DestinationDisabler if alertSettings.AutoDisableDestination { disabler = newDestinationDisabler(svc.tenantStore) } + // Per-attempt replay gate: a replay of a fully processed failed attempt is + // skipped. The default 24h TTL matches the alert store's failure-set TTL. + processedIdemp := idempotence.New(svc.redisClient, + idempotence.WithDeploymentID(b.cfg.DeploymentID), + ) + // Build a suppression window only when exhausted-retries alerting is enabled // with a positive window. A zero window means "alert on every exhaustion" // (no suppression), so we leave the idempotence instance nil. @@ -380,17 +386,12 @@ func (b *ServiceBuilder) BuildLogWorker(baseRouter *gin.Engine) error { ) } _, retryMaxLimit := b.cfg.GetRetryBackoff() - alertMonitor := alert.NewAlertMonitor( - b.logger, - svc.redisClient, - emitter, + alertEvaluator := alert.NewEvaluator( + alert.NewRedisAlertStore(svc.redisClient, b.cfg.DeploymentID), retryMaxLimit, - alert.WithDisabler(disabler), - alert.WithExhaustedRetriesIdempotence(exhaustedRetriesIdemp), alert.WithConsecutiveFailureEnabled(alertSettings.ConsecutiveFailure.Enabled), alert.WithAutoDisableFailureCount(alertSettings.ConsecutiveFailure.Count), alert.WithExhaustedRetriesEnabled(alertSettings.ExhaustedRetries.Enabled), - alert.WithDeploymentID(b.cfg.DeploymentID), ) // Create batcher for batching log writes @@ -408,7 +409,13 @@ func (b *ServiceBuilder) BuildLogWorker(baseRouter *gin.Engine) error { } b.logger.Debug("creating log batcher") - batchProcessor, err := logmq.NewBatchProcessor(b.ctx, b.logger, svc.logStore, alertMonitor, logmq.BatchProcessorConfig{ + batchProcessor, err := logmq.NewBatchProcessor(b.ctx, b.logger, svc.logStore, logmq.AlertPipeline{ + Evaluator: alertEvaluator, + Emitter: emitter, + Disabler: disabler, + ProcessedIdemp: processedIdemp, + ExhaustedIdemp: exhaustedRetriesIdemp, + }, logmq.BatchProcessorConfig{ ItemCountThreshold: batcherCfg.ItemCountThreshold, DelayThreshold: batcherCfg.DelayThreshold, }) @@ -449,12 +456,12 @@ func (b *ServiceBuilder) BuildLogWorker(baseRouter *gin.Engine) error { return nil } -// destinationDisabler implements alert.DestinationDisabler by setting DisabledAt on the destination. +// destinationDisabler implements logmq.DestinationDisabler by setting DisabledAt on the destination. type destinationDisabler struct { tenantStore tenantstore.TenantStore } -func newDestinationDisabler(tenantStore tenantstore.TenantStore) alert.DestinationDisabler { +func newDestinationDisabler(tenantStore tenantstore.TenantStore) logmq.DestinationDisabler { return &destinationDisabler{tenantStore: tenantStore} }