diff --git a/coderd/notifications/enqueuer.go b/coderd/notifications/enqueuer.go index ff3af3fc5e..6027c36b39 100644 --- a/coderd/notifications/enqueuer.go +++ b/coderd/notifications/enqueuer.go @@ -73,12 +73,14 @@ func NewStoreEnqueuer(cfg codersdk.NotificationsConfig, store Store, helpers tem } // Enqueue queues a notification message for later delivery, assumes no structured input data. +// Returns the IDs of successfully enqueued messages, if any. func (s *StoreEnqueuer) Enqueue(ctx context.Context, userID, templateID uuid.UUID, labels map[string]string, createdBy string, targets ...uuid.UUID) ([]uuid.UUID, error) { return s.EnqueueWithData(ctx, userID, templateID, labels, nil, createdBy, targets...) } // Enqueue queues a notification message for later delivery. // Messages will be dequeued by a notifier later and dispatched. +// Returns the IDs of successfully enqueued messages, if any. func (s *StoreEnqueuer) EnqueueWithData(ctx context.Context, userID, templateID uuid.UUID, labels map[string]string, data map[string]any, createdBy string, targets ...uuid.UUID) ([]uuid.UUID, error) { metadata, err := s.store.FetchNewMessageMetadata(ctx, database.FetchNewMessageMetadataParams{ UserID: userID, @@ -141,14 +143,26 @@ func (s *StoreEnqueuer) EnqueueWithData(ctx context.Context, userID, templateID // // This is more efficient than fetching the user's preferences for each enqueue, and centralizes the business logic. if strings.Contains(err.Error(), ErrCannotEnqueueDisabledNotification.Error()) { - return nil, ErrCannotEnqueueDisabledNotification + s.log.Debug(ctx, "notification not enqueued", + slog.F("template_id", templateID), + slog.F("user_id", userID), + slog.F("method", method), + slog.Error(ErrCannotEnqueueDisabledNotification), + ) + continue } // If the enqueue fails due to a dedupe hash conflict, this means that a notification has already been enqueued // today with identical properties. It's far simpler to prevent duplicate sends in this central manner, rather than // having each notification enqueue handle its own logic. if database.IsUniqueViolation(err, database.UniqueNotificationMessagesDedupeHashIndex) { - return nil, ErrDuplicate + s.log.Debug(ctx, "notification not enqueued", + slog.F("template_id", templateID), + slog.F("user_id", userID), + slog.F("method", method), + slog.Error(ErrDuplicate), + ) + continue } s.log.Warn(ctx, "failed to enqueue notification", slog.F("template_id", templateID), slog.F("input", input), slog.Error(err)) diff --git a/coderd/notifications/notifications_test.go b/coderd/notifications/notifications_test.go index c3aa1fd72c..22dd78591c 100644 --- a/coderd/notifications/notifications_test.go +++ b/coderd/notifications/notifications_test.go @@ -35,6 +35,7 @@ import ( "golang.org/x/xerrors" "cdr.dev/slog" + "cdr.dev/slog/sloggers/sloghuman" "github.com/coder/quartz" "github.com/coder/serpent" @@ -1654,7 +1655,8 @@ func TestDisabledByDefaultBeforeEnqueue(t *testing.T) { ctx := dbauthz.AsNotifier(testutil.Context(t, testutil.WaitSuperLong)) store, _ := dbtestutil.NewDB(t) - logger := testutil.Logger(t) + logbuf := strings.Builder{} + logger := testutil.Logger(t).AppendSinks(sloghuman.Sink(&logbuf)).Leveled(slog.LevelDebug) cfg := defaultNotificationsConfig(database.NotificationMethodSmtp) enq, err := notifications.NewStoreEnqueuer(cfg, store, defaultHelpers(), logger.Named("enqueuer"), quartz.NewReal()) @@ -1662,10 +1664,12 @@ func TestDisabledByDefaultBeforeEnqueue(t *testing.T) { user := createSampleUser(t, store) // We want to try enqueuing a notification on a template that is disabled - // by default. We expect this to fail. + // by default. We expect this to be a no-op that produces a debug log. templateID := notifications.TemplateWorkspaceManuallyUpdated - _, err = enq.Enqueue(ctx, user.ID, templateID, map[string]string{}, "test") - require.ErrorIs(t, err, notifications.ErrCannotEnqueueDisabledNotification, "enqueuing did not fail with expected error") + notifIDs, err := enq.Enqueue(ctx, user.ID, templateID, map[string]string{}, "test") + require.NoError(t, err) + require.Contains(t, logbuf.String(), notifications.ErrCannotEnqueueDisabledNotification.Error()) + require.Empty(t, notifIDs) } // TestDisabledBeforeEnqueue ensures that notifications cannot be enqueued once a user has disabled that notification template @@ -1679,7 +1683,8 @@ func TestDisabledBeforeEnqueue(t *testing.T) { ctx := dbauthz.AsNotifier(testutil.Context(t, testutil.WaitSuperLong)) store, _ := dbtestutil.NewDB(t) - logger := testutil.Logger(t) + logbuf := strings.Builder{} + logger := testutil.Logger(t).AppendSinks(sloghuman.Sink(&logbuf)).Leveled(slog.LevelDebug) // GIVEN: an enqueuer & a sample user cfg := defaultNotificationsConfig(database.NotificationMethodSmtp) @@ -1697,9 +1702,12 @@ func TestDisabledBeforeEnqueue(t *testing.T) { require.NoError(t, err, "failed to set preferences") require.EqualValues(t, 1, n, "unexpected number of affected rows") - // THEN: enqueuing the "workspace deleted" notification should fail with an error - _, err = enq.Enqueue(ctx, user.ID, templateID, map[string]string{}, "test") - require.ErrorIs(t, err, notifications.ErrCannotEnqueueDisabledNotification, "enqueueing did not fail with expected error") + // THEN: enqueuing the "workspace deleted" notification should fail be + // a no-op that produces a debug log + notifIDs, err := enq.Enqueue(ctx, user.ID, templateID, map[string]string{}, "test") + require.NoError(t, err) + require.Contains(t, logbuf.String(), notifications.ErrCannotEnqueueDisabledNotification.Error()) + require.Empty(t, notifIDs) } // TestDisabledAfterEnqueue ensures that notifications enqueued before a notification template was disabled will not be @@ -1909,7 +1917,8 @@ func TestNotificationDuplicates(t *testing.T) { ctx := dbauthz.AsNotifier(testutil.Context(t, testutil.WaitSuperLong)) store, pubsub := dbtestutil.NewDB(t) - logger := testutil.Logger(t) + logbuf := strings.Builder{} + logger := testutil.Logger(t).AppendSinks(sloghuman.Sink(&logbuf)).Leveled(slog.LevelDebug) method := database.NotificationMethodSmtp cfg := defaultNotificationsConfig(method) @@ -1933,10 +1942,12 @@ func TestNotificationDuplicates(t *testing.T) { map[string]string{"initiator": "danny"}, "test", user.ID) require.NoError(t, err) - // WHEN: the second is enqueued, the enqueuer will reject the request. - _, err = enq.Enqueue(ctx, user.ID, notifications.TemplateWorkspaceDeleted, + // WHEN: the second is enqueued, the enqueuer will reject it as a duplicate. + ids, err := enq.Enqueue(ctx, user.ID, notifications.TemplateWorkspaceDeleted, map[string]string{"initiator": "danny"}, "test", user.ID) - require.ErrorIs(t, err, notifications.ErrDuplicate) + require.NoError(t, err) + require.Contains(t, logbuf.String(), notifications.ErrDuplicate.Error()) + require.Empty(t, ids) // THEN: when the clock is advanced 24h, the notification will be accepted. // NOTE: the time is used in the dedupe hash, so by advancing 24h we're creating a distinct notification from the one