Pulse/internal/notifications/queue_observability_test.go
rcourtman 76dc690840 Suppress recovery notifications when the firing never left the queue
An alert that resolved while its firing notification was still in the
grouping window or waiting in the persistent queue (alert delay pushes
activation close to resolution; quiet-hours replay defers delivery)
produced a recovery-only notification: CancelAlert dropped the queued
firing, but LastNotified had been set optimistically at dispatch, so
the resolved-notification gate believed the firing had been sent.

CancelAlert now reports whether it cancelled a firing notification that
had not been delivered (grouping window entries and pending queue rows;
mid-send rows are excluded because their delivery may still complete),
and handleAlertResolved suppresses the recovery in that case. This also
covers the quiet-hours replay bypass: a recovery only follows a deferred
firing if the replay was actually delivered.

Addresses #1553
2026-07-11 18:28:28 +01:00

119 lines
2.9 KiB
Go

package notifications
import (
"bytes"
"strings"
"testing"
"time"
"github.com/rs/zerolog"
"github.com/rs/zerolog/log"
)
func TestGetDLQLogsStructuredContextOnScanFailure(t *testing.T) {
nq, err := NewNotificationQueue(t.TempDir())
if err != nil {
t.Fatalf("NewNotificationQueue failed: %v", err)
}
t.Cleanup(func() {
_ = nq.Stop()
})
_, err = nq.db.Exec(
`INSERT INTO notification_queue (id, type, method, status, alerts, config, attempts, max_attempts, created_at, completed_at)
VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?, ?)`,
"bad-dlq-json",
"webhook",
"slack",
QueueStatusDLQ,
"{invalid-json",
"{}",
1,
3,
time.Now().Unix(),
time.Now().Unix(),
)
if err != nil {
t.Fatalf("failed to insert malformed dlq row: %v", err)
}
logOutput := captureNotificationQueueLogs(t)
notifications, err := nq.GetDLQ(5)
if err != nil {
t.Fatalf("GetDLQ returned error: %v", err)
}
if len(notifications) != 0 {
t.Fatalf("expected malformed row to be skipped, got %d notifications", len(notifications))
}
for _, expected := range []string{
`"component":"notification_queue"`,
`"action":"scan_dlq_row"`,
`"queueStatus":"dlq"`,
`"batchLimit":5`,
`"dbPath":"` + nq.dbPath + `"`,
`"message":"Failed to scan DLQ notification"`,
`"error":"failed to unmarshal alerts`,
} {
if !strings.Contains(logOutput.String(), expected) {
t.Fatalf("expected log output to include %s, got %q", expected, logOutput.String())
}
}
}
func TestCancelByAlertIdentifiersLogsStructuredContextOnAlertUnmarshalFailure(t *testing.T) {
nq, err := NewNotificationQueue(t.TempDir())
if err != nil {
t.Fatalf("NewNotificationQueue failed: %v", err)
}
t.Cleanup(func() {
_ = nq.Stop()
})
_, err = nq.db.Exec(
`INSERT INTO notification_queue (id, type, method, status, alerts, config, attempts, max_attempts, created_at)
VALUES (?, ?, ?, ?, ?, ?, ?, ?, ?)`,
"bad-cancel-json",
"email",
"smtp",
QueueStatusSending,
`{"broken":`,
"{}",
1,
3,
time.Now().Unix(),
)
if err != nil {
t.Fatalf("failed to insert malformed sending row: %v", err)
}
logOutput := captureNotificationQueueLogs(t)
if _, err := nq.CancelByAlertIdentifiers([]string{"alert-1"}); err != nil {
t.Fatalf("CancelByAlertIdentifiers returned error: %v", err)
}
for _, expected := range []string{
`"component":"notification_queue"`,
`"action":"cancel_unmarshal_alerts"`,
`"notifID":"bad-cancel-json"`,
`"message":"Failed to unmarshal alerts for cancellation check"`,
`"error":"unexpected end of JSON input"`,
} {
if !strings.Contains(logOutput.String(), expected) {
t.Fatalf("expected log output to include %s, got %q", expected, logOutput.String())
}
}
}
func captureNotificationQueueLogs(t *testing.T) *bytes.Buffer {
t.Helper()
var buf bytes.Buffer
origLogger := log.Logger
log.Logger = zerolog.New(&buf).Level(zerolog.DebugLevel).With().Timestamp().Logger()
t.Cleanup(func() {
log.Logger = origLogger
})
return &buf
}