diff --git a/cmd/server/main.go b/cmd/server/main.go index 3dba8d3..d348fd7 100644 --- a/cmd/server/main.go +++ b/cmd/server/main.go @@ -9,6 +9,7 @@ import ( "os/signal" "strings" "sync" + "sync/atomic" "syscall" "time" @@ -235,12 +236,19 @@ func main() { logger.Error("failed to fetch users for background sync", "error", err) continue } - syncErrors := 0 + // Governing: ADR-0019, SPEC observability REQ "BG-001", REQ "BG-002" — the error + // counter is atomic (incremented from per-user goroutines) and the tick metric is + // emitted only after joining this tick's goroutines, so duration_ms measures the + // actual sync work rather than goroutine spawn time and the counter is stable. + var syncErrors atomic.Int64 + var tickWG sync.WaitGroup for _, u := range users { // Governing: SPEC graceful-shutdown REQ-WG-002 (wg.Add before spawn, defer wg.Done first) wg.Add(1) + tickWG.Add(1) go func(user *ent.User) { defer wg.Done() + defer tickWG.Done() // Governing: SPEC graceful-shutdown REQ-SEM-003, REQ-SEM-004 (semaphore acquire with ctx) select { case sem <- struct{}{}: @@ -251,15 +259,16 @@ func main() { // Governing: SPEC graceful-shutdown REQ-CTX-002 (cancelled ctx passed to service methods) if err := syncer.Sync(ctx, user); err != nil { logger.Error("background sync failed", "username", user.Username, "error", err) - syncErrors++ + syncErrors.Add(1) } }(u) } + tickWG.Wait() logger.Info("metric.background_tick", "loop", "sync", "users_processed", len(users), "duration_ms", time.Since(tickStart).Milliseconds(), - "errors", syncErrors) + "errors", int(syncErrors.Load())) } } }() @@ -291,12 +300,18 @@ func main() { logger.Error("failed to fetch users for metadata sync", "error", err) return } - metadataErrors := 0 + // Governing: ADR-0019, SPEC observability REQ "BG-001", REQ "BG-002" — atomic error + // counter and post-join emission so duration_ms measures actual tick work and the + // counter is stable (see sync loop above). + var metadataErrors atomic.Int64 + var tickWG sync.WaitGroup for _, u := range users { // Governing: SPEC graceful-shutdown REQ-WG-002 (wg.Add before spawn, defer wg.Done first) wg.Add(1) + tickWG.Add(1) go func(user *ent.User) { defer wg.Done() + defer tickWG.Done() // Governing: SPEC graceful-shutdown REQ-SEM-003, REQ-SEM-004 (semaphore acquire with ctx) select { case sem <- struct{}{}: @@ -307,15 +322,16 @@ func main() { // Governing: SPEC graceful-shutdown REQ-CTX-002 (cancelled ctx passed to service methods) if err := metadataSvc.SyncAll(ctx, user); err != nil { logger.Error("metadata sync failed", "username", user.Username, "error", err) - metadataErrors++ + metadataErrors.Add(1) } }(u) } + tickWG.Wait() logger.Info("metric.background_tick", "loop", "metadata", "users_processed", len(users), "duration_ms", time.Since(tickStart).Milliseconds(), - "errors", metadataErrors) + "errors", int(metadataErrors.Load())) } // Initial delay to let the app start up @@ -380,12 +396,18 @@ func main() { logger.Error("failed to fetch users for playlist sync", "error", err) continue } - plSyncErrors := 0 + // Governing: ADR-0019, SPEC observability REQ "BG-001", REQ "BG-002" — atomic error + // counter and post-join emission so duration_ms measures actual tick work and the + // counter is stable (see sync loop above). + var plSyncErrors atomic.Int64 + var tickWG sync.WaitGroup for _, u := range users { // Governing: SPEC graceful-shutdown REQ-WG-002 (wg.Add before spawn, defer wg.Done first) wg.Add(1) + tickWG.Add(1) go func(user *ent.User) { defer wg.Done() + defer tickWG.Done() // Governing: SPEC graceful-shutdown REQ-SEM-003, REQ-SEM-004 (semaphore acquire with ctx) select { case sem <- struct{}{}: @@ -396,15 +418,16 @@ func main() { // Governing: SPEC graceful-shutdown REQ-CTX-002 (cancelled ctx passed to service methods) if err := playlistSyncSvc.SyncAllEnabledPlaylists(ctx, user.ID); err != nil { logger.Error("playlist sync failed", "username", user.Username, "error", err) - plSyncErrors++ + plSyncErrors.Add(1) } }(u) } + tickWG.Wait() logger.Info("metric.background_tick", "loop", "playlist_sync", "users_processed", len(users), "duration_ms", time.Since(tickStart).Milliseconds(), - "errors", plSyncErrors) + "errors", int(plSyncErrors.Load())) } } }() diff --git a/internal/services/sync.go b/internal/services/sync.go index f100960..b9fd0b4 100644 --- a/internal/services/sync.go +++ b/internal/services/sync.go @@ -4,6 +4,7 @@ package services import ( "context" "encoding/json" + "errors" "fmt" "log/slog" "time" @@ -57,51 +58,98 @@ func (s *Syncer) Register(factory providers.Factory) { s.factories = append(s.factories, factory) } +// providerSyncOutcome accumulates per-provider results across the history and +// playlist phases of a full sync so metric.sync can report true per-provider +// listens, playlists, duration, and success. +// Governing: ADR-0019 (structured metrics), SPEC observability REQ "BG-003" +type providerSyncOutcome struct { + listens int + playlists int + duration time.Duration + errs []error +} + +// recordOutcome merges one phase's result for a provider into the outcomes map. +// A nil map is a no-op so syncHistory/syncPlaylists callers that do not need +// per-provider metrics (SyncProvider, SyncRecentListens, SyncPlaylists) can pass nil. +func recordOutcome(outcomes map[providers.Type]*providerSyncOutcome, pt providers.Type, listens, playlists int, d time.Duration, err error) { + if outcomes == nil { + return + } + o := outcomes[pt] + if o == nil { + o = &providerSyncOutcome{} + outcomes[pt] = o + } + o.listens += listens + o.playlists += playlists + o.duration += d + if err != nil { + o.errs = append(o.errs, err) + } +} + // Governing: ADR-0019 (structured metrics), SPEC observability REQ "BG-003" // Governing: SPEC graceful-shutdown REQ-REC-004 (ctx propagated to DB ops; cancellation leaves DB consistent) // Governing: SPEC listen-playlist-sync REQ-SYNC-010 (full sync: providers -> history -> playlists) // Governing: SPEC listen-playlist-sync REQ-SYNC-011 (history failure does not abort playlist sync) // Sync performs a full synchronization (history and playlists) for the user. +// Per-provider failures do not abort the sync (partial success is preserved), +// but they are aggregated and returned so callers and metric.sync see real failures. +// Governing: ADR-0020 (error handling and resilience) func (s *Syncer) Sync(ctx context.Context, u *ent.User) error { s.logger.Info("starting full sync", "username", u.Username) - syncStart := time.Now() refreshedUser, activeProviders, err := s.getActiveProviders(ctx, u) if err != nil { return err } - var listensSynced, playlistsSynced int - syncSuccess := true - var syncErr string + // Pre-seed outcomes so every active provider emits a metric.sync event, + // even if it supports neither history nor playlists. + outcomes := make(map[providers.Type]*providerSyncOutcome, len(activeProviders)) + for _, p := range activeProviders { + outcomes[p.Type()] = &providerSyncOutcome{} + } // 1. History - var histErr error - listensSynced, histErr = s.syncHistory(ctx, refreshedUser, activeProviders) + listensSynced, histErr := s.syncHistory(ctx, refreshedUser, activeProviders, outcomes) if histErr != nil { s.logger.Error("failed to sync history", "username", refreshedUser.Username, "error", histErr) - syncSuccess = false - syncErr = histErr.Error() } // 2. Playlists - var plErr error - playlistsSynced, plErr = s.syncPlaylists(ctx, refreshedUser, activeProviders) + playlistsSynced, plErr := s.syncPlaylists(ctx, refreshedUser, activeProviders, outcomes) if plErr != nil { s.logger.Error("failed to sync playlists", "username", refreshedUser.Username, "error", plErr) - syncSuccess = false - syncErr = plErr.Error() } - // Emit metric.sync for each active provider + // Emit one metric.sync per active provider carrying that provider's own + // listens, playlists, duration, and success — not aggregate totals. + // Governing: ADR-0019 (structured metrics), SPEC observability REQ "BG-003" for _, p := range activeProviders { + o := outcomes[p.Type()] + provErr := errors.Join(o.errs...) + errStr := "" + if provErr != nil { + errStr = provErr.Error() + } s.logger.Info("metric.sync", "provider", string(p.Type()), - "listens_synced", listensSynced, - "playlists_synced", playlistsSynced, - "duration_ms", time.Since(syncStart).Milliseconds(), - "success", syncSuccess, - "error", syncErr) + "listens_synced", o.listens, + "playlists_synced", o.playlists, + "duration_ms", o.duration.Milliseconds(), + "success", provErr == nil, + "error", errStr) + } + + // Surface aggregated per-provider errors without having blocked partial success: + // providers that succeeded have already persisted their data. + // Governing: ADR-0020, SPEC listen-playlist-sync REQ-SYNC-011 + if syncErr := errors.Join(histErr, plErr); syncErr != nil { + s.logger.Error("full sync completed with errors", "username", refreshedUser.Username, + "listens_synced", listensSynced, "playlists_synced", playlistsSynced, "error", syncErr) + return fmt.Errorf("sync completed with errors: %w", syncErr) } s.logger.Info("full sync completed", "username", refreshedUser.Username) @@ -131,13 +179,22 @@ func (s *Syncer) SyncProvider(ctx context.Context, u *ent.User, providerType pro } // 1. History - if _, err := s.syncHistory(ctx, refreshedUser, targetProviders); err != nil { - s.logger.Error("failed to sync history", "username", refreshedUser.Username, "provider", providerType, "error", err) + _, histErr := s.syncHistory(ctx, refreshedUser, targetProviders, nil) + if histErr != nil { + s.logger.Error("failed to sync history", "username", refreshedUser.Username, "provider", providerType, "error", histErr) } // 2. Playlists - if _, err := s.syncPlaylists(ctx, refreshedUser, targetProviders); err != nil { - s.logger.Error("failed to sync playlists", "username", refreshedUser.Username, "provider", providerType, "error", err) + _, plErr := s.syncPlaylists(ctx, refreshedUser, targetProviders, nil) + if plErr != nil { + s.logger.Error("failed to sync playlists", "username", refreshedUser.Username, "provider", providerType, "error", plErr) + } + + // Surface aggregated errors so callers (e.g. the manual sync task handlers) + // can report real failures instead of silently succeeding. + // Governing: ADR-0020 (error handling and resilience) + if err := errors.Join(histErr, plErr); err != nil { + return fmt.Errorf("provider sync completed with errors: %w", err) } s.logger.Info("provider sync completed", "username", refreshedUser.Username, "provider", providerType) @@ -150,7 +207,7 @@ func (s *Syncer) SyncRecentListens(ctx context.Context, u *ent.User) error { if err != nil { return err } - _, err = s.syncHistory(ctx, refreshedUser, activeProviders) + _, err = s.syncHistory(ctx, refreshedUser, activeProviders, nil) return err } @@ -160,7 +217,7 @@ func (s *Syncer) SyncPlaylists(ctx context.Context, u *ent.User) error { if err != nil { return err } - _, err = s.syncPlaylists(ctx, refreshedUser, activeProviders) + _, err = s.syncPlaylists(ctx, refreshedUser, activeProviders, nil) return err } @@ -215,8 +272,12 @@ func (s *Syncer) logEvent(ctx context.Context, u *ent.User, eventType syncevent. // Governing: SPEC listen-playlist-sync REQ-SYNC-020 (since timestamp from last listen) // Governing: SPEC listen-playlist-sync REQ-SYNC-022 (per-track errors logged, sync continues) // Governing: SPEC listen-playlist-sync REQ-SYNC-023 (notification published on new listens) -func (s *Syncer) syncHistory(ctx context.Context, u *ent.User, activeProviders []providers.Provider) (int, error) { +// Governing: ADR-0020 — per-provider failures are aggregated and returned; one +// provider failing does not prevent the remaining providers from syncing. +// outcomes may be nil when per-provider metrics are not needed. +func (s *Syncer) syncHistory(ctx context.Context, u *ent.User, activeProviders []providers.Provider, outcomes map[providers.Type]*providerSyncOutcome) (int, error) { allAdded := 0 + var errs []error for _, provider := range activeProviders { // Check if provider supports history fetching fetcher, ok := provider.(providers.HistoryFetcher) @@ -228,12 +289,16 @@ func (s *Syncer) syncHistory(ctx context.Context, u *ent.User, activeProviders [ // Check backoff state before calling provider // Governing: SPEC error-handling REQ-BACK-004, REQ-STATE-004 + // A backoff skip is deliberate throttling, not a new failure — it is not + // added to the aggregated error. backoffKey := BackoffKey{UserID: u.ID, ProviderType: provider.Type()} if skip, reason := s.backoff.ShouldSkip(backoffKey); skip { s.logger.Info("skipping provider due to backoff", "provider", providerName, "reason", reason) continue } + provStart := time.Now() + // Send sync starting notification s.bus.Publish(u.ID, events.Event{ Type: events.EventTypeNotification, @@ -318,6 +383,11 @@ func (s *Syncer) syncHistory(ctx context.Context, u *ent.User, activeProviders [ } // Log sync failed event s.logEvent(ctx, u, syncevent.EventTypeSyncFailed, providerName, fmt.Sprintf("Failed to fetch listens from %s: %v", providerName, err), nil) + // Aggregate the failure instead of swallowing it so Sync() and + // metric.sync see real failures. Remaining providers still sync. + // Governing: ADR-0020, SPEC listen-playlist-sync REQ-SYNC-011 + errs = append(errs, fmt.Errorf("%s: history sync failed: %w", providerName, err)) + recordOutcome(outcomes, provider.Type(), totalAdded, 0, time.Since(provStart), err) continue } @@ -359,13 +429,20 @@ func (s *Syncer) syncHistory(ctx context.Context, u *ent.User, activeProviders [ if err := s.updateLastSyncedAt(ctx, u, provider.Type()); err != nil { s.logger.Warn("failed to update last_synced_at", "provider", provider.Type(), "error", err) } + + recordOutcome(outcomes, provider.Type(), totalAdded, 0, time.Since(provStart), nil) } - return allAdded, nil + // Governing: ADR-0020 — aggregated per-provider errors returned via errors.Join + return allAdded, errors.Join(errs...) } // Governing: SPEC listen-playlist-sync REQ-SYNC-030 (fetch playlists from each PlaylistManager provider) -func (s *Syncer) syncPlaylists(ctx context.Context, u *ent.User, activeProviders []providers.Provider) (int, error) { +// Governing: ADR-0020 — per-provider failures are aggregated and returned; one +// provider failing does not prevent the remaining providers from syncing. +// outcomes may be nil when per-provider metrics are not needed. +func (s *Syncer) syncPlaylists(ctx context.Context, u *ent.User, activeProviders []providers.Provider, outcomes map[providers.Type]*providerSyncOutcome) (int, error) { allAdded := 0 + var errs []error for _, provider := range activeProviders { manager, ok := provider.(providers.PlaylistManager) if !ok { @@ -376,12 +453,16 @@ func (s *Syncer) syncPlaylists(ctx context.Context, u *ent.User, activeProviders // Check backoff state before calling provider // Governing: SPEC error-handling REQ-BACK-004, REQ-STATE-004 + // A backoff skip is deliberate throttling, not a new failure — it is not + // added to the aggregated error. backoffKey := BackoffKey{UserID: u.ID, ProviderType: provider.Type()} if skip, reason := s.backoff.ShouldSkip(backoffKey); skip { s.logger.Info("skipping provider due to backoff", "provider", providerName, "reason", reason) continue } + provStart := time.Now() + // Send sync starting notification s.bus.Publish(u.ID, events.Event{ Type: events.EventTypeNotification, @@ -421,6 +502,11 @@ func (s *Syncer) syncPlaylists(ctx context.Context, u *ent.User, activeProviders } // Log sync failed event s.logEvent(ctx, u, syncevent.EventTypeSyncFailed, providerName, fmt.Sprintf("Failed to fetch playlists from %s: %v", providerName, err), nil) + // Aggregate the failure instead of swallowing it so Sync() and + // metric.sync see real failures. Remaining providers still sync. + // Governing: ADR-0020, SPEC listen-playlist-sync REQ-SYNC-011 + errs = append(errs, fmt.Errorf("%s: playlist sync failed: %w", providerName, err)) + recordOutcome(outcomes, provider.Type(), 0, 0, time.Since(provStart), err) continue } @@ -435,11 +521,18 @@ func (s *Syncer) syncPlaylists(ctx context.Context, u *ent.User, activeProviders } s.logger.Info("fetched playlists", "provider", provider.Type(), "count", len(playlists)) + var provErr error + var provAdded int if len(playlists) > 0 { added, skipped, err := s.persistPlaylists(ctx, u, provider.Type(), playlists) if err != nil { s.logger.Error("failed to persist playlists", "error", err) + // Persistence failures are real sync failures too. + // Governing: ADR-0020 + provErr = fmt.Errorf("%s: failed to persist playlists: %w", providerName, err) + errs = append(errs, provErr) } + provAdded = added allAdded += added if added > 0 { @@ -467,8 +560,11 @@ func (s *Syncer) syncPlaylists(ctx context.Context, u *ent.User, activeProviders if err := s.updateLastSyncedAt(ctx, u, provider.Type()); err != nil { s.logger.Warn("failed to update last_synced_at", "provider", provider.Type(), "error", err) } + + recordOutcome(outcomes, provider.Type(), 0, provAdded, time.Since(provStart), provErr) } - return allAdded, nil + // Governing: ADR-0020 — aggregated per-provider errors returned via errors.Join + return allAdded, errors.Join(errs...) } // publishFatalNotification publishes a user-visible notification for fatal provider errors. diff --git a/internal/services/sync_error_test.go b/internal/services/sync_error_test.go index dad7f37..29c5e0b 100644 --- a/internal/services/sync_error_test.go +++ b/internal/services/sync_error_test.go @@ -1,7 +1,10 @@ package services_test import ( + "bufio" + "bytes" "context" + "encoding/json" "fmt" "io" "log/slog" @@ -76,11 +79,12 @@ func TestSyncer_ProviderError_TriggersBackoffRetriable(t *testing.T) { } syncer.Register(mockFactory(mockProv)) - // First sync — should not return error (Sync swallows per-provider errors) + // First sync — the provider failure must surface as an error (issue #326) err = syncer.Sync(context.Background(), user) - assert.NoError(t, err, "Sync should not surface per-provider errors") + assert.Error(t, err, "Sync must surface aggregated per-provider errors") - // Second sync — the provider should be skipped due to backoff + // Second sync — the provider is skipped due to backoff; a deliberate + // backoff skip is throttling, not a new failure, so no error surfaces err = syncer.Sync(context.Background(), user) assert.NoError(t, err) } @@ -112,11 +116,11 @@ func TestSyncer_ProviderError_FatalNotRetried(t *testing.T) { } syncer.Register(mockFactory(mockProv)) - // First sync — triggers fatal error + // First sync — triggers fatal error, which must surface (issue #326) err = syncer.Sync(context.Background(), user) - assert.NoError(t, err, "Sync should not surface per-provider errors") + assert.Error(t, err, "Sync must surface aggregated per-provider errors") - // Second sync — provider should be skipped due to fatal backoff + // Second sync — provider is skipped due to fatal backoff (throttling, not a new failure) err = syncer.Sync(context.Background(), user) assert.NoError(t, err) } @@ -187,7 +191,7 @@ func TestSyncer_HistoryCallbackError_DoesNotPersistPartialData(t *testing.T) { syncer.Register(mockFactory(failProv)) err = syncer.SyncRecentListens(context.Background(), user) - require.NoError(t, err) // syncHistory swallows per-provider errors + require.Error(t, err, "syncHistory must surface aggregated per-provider errors (issue #326)") // Verify no listens were persisted listens, err := client.Listen.Query().All(context.Background()) @@ -274,8 +278,8 @@ func TestSyncer_RevokedNavidromeCredentials_FatalStopsRetryAndNotifies(t *testin prov := &countingProvider{providerType: providers.TypeNavidrome, err: revokedErr} syncer.Register(mockFactory(prov)) - // First sync — hits the 401, records fatal state, notifies - require.NoError(t, syncer.Sync(context.Background(), user)) + // First sync — hits the 401, records fatal state, notifies, and surfaces the error (issue #326) + require.Error(t, syncer.Sync(context.Background(), user)) require.GreaterOrEqual(t, notifier.notifyCalls, 1, "NotifyIfNeeded must fire for a fatal error") assert.Equal(t, services.ErrorClassFatal, services.ClassifyError(notifier.lastErr), "the error reaching the notifier must classify fatal") @@ -313,10 +317,139 @@ func TestSyncer_LegacyNavidromeErrorString_FallbackClassifiesFatal(t *testing.T) prov := &countingProvider{providerType: providers.TypeNavidrome, err: legacyErr} syncer.Register(mockFactory(prov)) - require.NoError(t, syncer.Sync(context.Background(), user)) + require.Error(t, syncer.Sync(context.Background(), user), "fatal provider error must surface (issue #326)") require.GreaterOrEqual(t, notifier.notifyCalls, 1, "NotifyIfNeeded must fire via the string fallback") callsAfterFirst := prov.calls require.NoError(t, syncer.Sync(context.Background(), user)) assert.Equal(t, callsAfterFirst, prov.calls, "backoff must stop after fatal classification") } + +// metricSyncEvent mirrors the metric.sync attribute schema for log-capture assertions. +// Governing: ADR-0019 (structured metrics), SPEC observability REQ-BG-003 +type metricSyncEvent struct { + Msg string `json:"msg"` + Provider string `json:"provider"` + ListensSynced int `json:"listens_synced"` + PlaylistsSynced int `json:"playlists_synced"` + DurationMs int64 `json:"duration_ms"` + Success bool `json:"success"` + Error string `json:"error"` +} + +// captureMetricSyncEvents parses JSON log output and returns metric.sync events keyed by provider. +func captureMetricSyncEvents(t *testing.T, logs *bytes.Buffer) map[string]metricSyncEvent { + t.Helper() + events := make(map[string]metricSyncEvent) + scanner := bufio.NewScanner(logs) + for scanner.Scan() { + line := scanner.Bytes() + var ev metricSyncEvent + if err := json.Unmarshal(line, &ev); err != nil { + continue + } + if ev.Msg == "metric.sync" { + events[ev.Provider] = ev + } + } + require.NoError(t, scanner.Err()) + return events +} + +// TestSyncer_AllProvidersFail_SyncReturnsErrorAndMetricSyncFails is the issue #326 +// acceptance test: when every provider fails, Sync() returns an aggregated error +// and each provider's metric.sync event logs success=false. +// Governing: ADR-0019, ADR-0020, SPEC observability REQ-BG-003 +func TestSyncer_AllProvidersFail_SyncReturnsErrorAndMetricSyncFails(t *testing.T) { + client := enttest.Open(t, "sqlite3", "file:ent?mode=memory&cache=shared&_fk=1") + t.Cleanup(func() { client.Close() }) + + var logs bytes.Buffer + logger := slog.New(slog.NewJSONHandler(&logs, nil)) + bus := events.NewBus() + syncer := services.NewSyncer(client, &config.Config{}, logger, bus, nil) + + user, err := client.User.Create().SetUsername("testuser").Save(context.Background()) + require.NoError(t, err) + + failingSpotify := &mockProvider{ + providerType: providers.TypeSpotify, + err: fmt.Errorf("connection timeout"), + } + failingNavidrome := &mockProvider{ + providerType: providers.TypeNavidrome, + err: fmt.Errorf("connection refused"), + } + syncer.Register(mockFactory(failingSpotify)) + syncer.Register(mockFactory(failingNavidrome)) + + err = syncer.Sync(context.Background(), user) + require.Error(t, err, "Sync must return an error when every provider fails") + assert.Contains(t, err.Error(), string(providers.TypeSpotify)) + assert.Contains(t, err.Error(), string(providers.TypeNavidrome)) + + metrics := captureMetricSyncEvents(t, &logs) + require.Len(t, metrics, 2, "one metric.sync event per active provider") + for provider, ev := range metrics { + assert.False(t, ev.Success, "metric.sync for %s must log success=false", provider) + assert.NotEmpty(t, ev.Error, "metric.sync for %s must carry the error", provider) + assert.Zero(t, ev.ListensSynced, "no listens synced for failing provider %s", provider) + } +} + +// TestSyncer_PartialFailure_SurfacesErrorButPreservesPartialSuccess asserts that +// one provider failing does not prevent other providers from syncing, that the +// aggregated error still surfaces, and that metric.sync attributes each +// provider's own counts and success flag (not aggregate totals). +// Governing: ADR-0019, ADR-0020, SPEC observability REQ-BG-003, SPEC listen-playlist-sync REQ-SYNC-011 +func TestSyncer_PartialFailure_SurfacesErrorButPreservesPartialSuccess(t *testing.T) { + client := enttest.Open(t, "sqlite3", "file:ent?mode=memory&cache=shared&_fk=1") + t.Cleanup(func() { client.Close() }) + + var logs bytes.Buffer + logger := slog.New(slog.NewJSONHandler(&logs, nil)) + bus := events.NewBus() + syncer := services.NewSyncer(client, &config.Config{}, logger, bus, nil) + + user, err := client.User.Create().SetUsername("testuser").Save(context.Background()) + require.NoError(t, err) + + failingSpotify := &mockProvider{ + providerType: providers.TypeSpotify, + err: fmt.Errorf("connection timeout"), + } + workingNavidrome := &mockProvider{ + providerType: providers.TypeNavidrome, + tracks: []providers.Track{ + {ID: "t1", Name: "Track One", Artist: "Artist One", Album: "Album One", PlayedAt: time.Now()}, + {ID: "t2", Name: "Track Two", Artist: "Artist Two", Album: "Album Two", PlayedAt: time.Now().Add(-10 * time.Minute)}, + }, + } + syncer.Register(mockFactory(failingSpotify)) + syncer.Register(mockFactory(workingNavidrome)) + + err = syncer.Sync(context.Background(), user) + require.Error(t, err, "partial failure must still surface an error") + assert.Contains(t, err.Error(), string(providers.TypeSpotify)) + assert.NotContains(t, err.Error(), string(providers.TypeNavidrome), + "the healthy provider must not appear in the aggregated error") + + // Partial success preserved: the healthy provider's listens persisted + listens, err := client.Listen.Query().All(context.Background()) + require.NoError(t, err) + assert.Len(t, listens, 2, "healthy provider's listens must persist despite the other failing") + + // Per-provider metric attribution (REQ-BG-003) + metrics := captureMetricSyncEvents(t, &logs) + require.Len(t, metrics, 2, "one metric.sync event per active provider") + + spotifyEv := metrics[string(providers.TypeSpotify)] + assert.False(t, spotifyEv.Success, "failing provider must log success=false") + assert.NotEmpty(t, spotifyEv.Error) + assert.Zero(t, spotifyEv.ListensSynced) + + navidromeEv := metrics[string(providers.TypeNavidrome)] + assert.True(t, navidromeEv.Success, "healthy provider must log success=true") + assert.Empty(t, navidromeEv.Error) + assert.Equal(t, 2, navidromeEv.ListensSynced, "listens_synced must be the provider's own count") +}