From 59448e928351f5afd08ee3ce86fa46b081128c0f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Deluan=20Quint=C3=A3o?= Date: Sat, 29 Aug 2026 17:28:29 -0400 Subject: [PATCH] fix(scrobbler): back off when a provider asks us to, instead of retrying per play (#6028) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit * feat(agents): retry-later error type with optional server delay Add agents.ErrRetryLater and agents.RetryLaterError, which carries the delay requested by an external service (e.g. ListenBrainz's X-RateLimit-Reset-In). scrobbler.ErrRetryLater becomes an alias of the new sentinel, so existing errors.Is checks and the plugin error-string protocol keep working unchanged. Groundwork for honoring server-requested retry delays across scrobbling, metadata agents and artwork. Song.Equals tests moved to song_test.go to enable external test package. * fix(scrobbler): honor backoff window and server-requested retry delay ListenBrainz 429s were decoded into a typed error that classified as unrecoverable, silently discarding the scrobble (a JSON-bodied 429 was measured live). The client now maps any 429 to agents.RetryLaterError, carrying X-RateLimit-Reset-In when present (capped at 1h). Last.fm error 29 (rate limit) is now retryable like 11/16. The buffer's drain loop no longer lets wake signals bypass an active backoff window - new plays enqueue but drain only when the window closes - and the wait honors the server delay via max(backoff, retryIn). * feat(agents): skip cooling-down agents in aggregate calls When an agent reports retry-later, remember a per-agent cooldown deadline (the server-requested delay, or 1 minute when unspecified) and skip that agent in all aggregate metadata calls until it passes. A round that found no data but skipped or saw a throttled agent returns ErrRetryLater instead of ErrNotFound, so callers cannot mistake rate limiting for a definitive 'no data' answer. * feat(artwork): honor server-requested retry delay when rescheduling When an external image lookup fails with a retry-later error carrying a delay (e.g. a 429 with X-RateLimit-Reset-In), the chain trace carries the largest such hint back to the worker, which reschedules the item at max(exponential backoff, server delay) instead of backoff alone. * feat(plugins): retry-later with optional delay for scrobbler and agent plugins Scrobbler plugins can now return scrobbler(retry_later:N) to request a retry in N seconds (capped at 1h); the bare token keeps its old meaning. Metadata-agent plugins, which had no error vocabulary at all, gain the parallel agent(retry_later[:N]) token, mapped to agents.RetryLaterError so the aggregate's cooldown and the artwork worker honor plugin throttling the same way as built-in agents. * fix: address whole-branch review findings for retry-later handling Narrow the aggregate's throttled rule to the spec sentence: core.Agents returns ErrRetryLater only when no agent answered at all (all skipped-cooling or retry-later). An agent that does not implement the called method now returns an internal errUnsupported instead of ErrNotFound, so it counts as "did not run" — without that, the always-appended local agent would answer for biography, URL and images and make ErrRetryLater unreachable. Wire the consequence in core/external: a throttled round no longer stamps ExternalInfoUpdatedAt (artist and album), so the empty result is not cached for the TTL, and TopSongs maps ErrRetryLater to the same empty-200 the not-found path already produced instead of a new client-facing error. Move the Last.fm code-29 mapping into the client's central error construction so every metadata path produces RetryLaterError, and map ListenBrainz's body-level code 429 (sent with a non-429 HTTP status) the same way. Clamp server- and plugin-requested delays in seconds before scaling to a Duration, in all three parse sites: a header of 18446744074 wrapped past 2^64 and came out as a 0.29s delay. Also: extract the artwork worker's reschedule computation into retryDelay() and cover both it and the trace RetryIn wiring with tests; collapse the double regex call in mapScrobblerError; drop capabilities.ScrobblerErrorRetryLaterIn (ndpgen never emits funcs, so plugin authors could not reach it); regenerate the PDKs so MetadataAgentError reaches the Go and Rust SDKs; de-flake the cooldown tests (long RetryIn for the skip case, separate expiry spec); and cover the max() retry-delay aggregation across users in the scrobble buffer. * refactor: dedupe retry-later parsing and simplify error collection - Add agents.NewRetryLater and agents.RetryLaterFromSeconds, with a single 1h cap, replacing the parse+clamp+multiply logic and the maxRetryInSeconds constant duplicated across listenbrainz, plugins and the agent adapter. - Move HTTP header parsing to httpclient.RetryAfter, so the transport layer owns it and stays domain-agnostic; drop retryInFromHeaders from the ListenBrainz client. Covered by a new Ginkgo table in that package. - Collapse the two near-identical plugin retry_later regexes into one parseRetryLater(prefix, msg) shared by the agent and scrobbler adapters. - Fold the duplicated noteRetryIn snippet from fetchArtistImage and fetchAlbumImage into recordAgent, which already branched on the same isTransientExternal condition. - Replace the atomic.Bool + note() closure in populateArtistInfo with errgroup's own error collection; the group carries no context, so a returned error does not cancel its siblings. - Reuse recoveringScrobbler for the per-user delay test instead of a third double, and switch fakeScrobbler's mutex-guarded error to the atomic.Pointer idiom already used in the same package. * refactor(listenbrainz): keep rate-limit header parsing in the adapter The X-RateLimit-Reset-In header is ListenBrainz's own convention, not a shared one: Last.fm sends no rate-limit headers at all and reports its limit as a body code, and no other integration in tree sends Retry-After. A parser in utils/httpclient implied a uniformity across services that does not exist, so it moves back next to the only client that can know which header its service sends. * refactor(agents): collapse the retry-later sentinel and error into one type ErrRetryLater is now the zero-delay RetryLaterError rather than a separate errors.New value, so errors.Is and errors.AsType both match the sentinel and every delay-carrying variant. That removes the trap where a bare sentinel silently skipped the AsType path, and lets every consumer read the delay off the error directly: the RetryIn accessor and the two constructors are gone, with the policy cap applied where untrusted input is parsed. * refactor(agents): split the cooldown store from the per-dispatch tally The cooldown map and mutex become a cooldowns value with active/park, holding no knowledge of errors; agentAttempts records one dispatch's outcomes and owns the classification that noteAgentError used to hide behind a bool. The three dispatch loops now touch a single object: skip folds the cooldown check and the throttled flag into one call, so the store never appears in the loops. * refactor(agents): share one dispatch loop between the agent call helpers callAgentMethod and callAgentSliceMethod ran identical loops, differing only in how they test a result for emptiness: a slice cannot be compared against its zero value, so the two could not share a constraint. Both now delegate to callAgent, which takes that test as a parameter. Keeping the loop in one place matters more than the lines saved: it holds the cooldown skip, the attempt recording and the empty-dispatch verdict, and a fix applied to one copy but not the other would be silent. * test: cover the two retry-later paths a mutation could break silently Both gaps were proven, not guessed: making the artwork worker pass 0 instead of the collected hint left all 386 specs green, and replacing the default agent cooldown with 0 left the agents suite green. The worker test drives a throttled image agent through drain and asserts the persisted retry_at, and the cooldown test parks an agent that asked to be retried without naming a delay, which is what Last.fm does on every rate limit. * refactor(artwork): carry the external failure as an error, not a flag plus a trace field The retry delay was riding on ChainTrace, a diagnostic that gets persisted, while the very same signal — an external source faulted — already travelled by value as resolution.extError. That was two mechanisms for one idea, and it put control-flow state inside a serializable trace. resolution.extError and chainState.extErr become the error itself, so a caller checks err != nil for the fault and errors.AsType for the delay the provider asked for. The agent loops return that error last, per convention, and longerRetry keeps whichever failure wants the longer wait. ChainTrace goes back to holding only steps and no longer imports core/agents. * fix(artwork): check the resolve error before reading its resolution Reading res.extError before the err check was safe only because every error path in resolve returns a bare resolution{}; a future path returning a partly-filled one would have been read silently. The failure path now returns no delay explicitly. * test(artwork): assert the delay acquire reports, not just its downstream effect acquire's retry delay was only covered through the worker's persisted retry_at, one layer away from where the value is computed. Both outcomes are now pinned at the processor: a plain failure asks for nothing, a throttled provider's delay is passed through. * refactor: share the retry-seconds parse and drop the backoff deadline arithmetic The clamp-before-scaling invariant lived in two parsers and was independently re-tested in three files with the same magic number; a fix applied to one copy would have left the others wrapping a huge value down to a fraction of a second. It moves to agents.ParseRetryIn. The buffer tracked an absolute retryDeadline only to re-arm a timer that was already armed for the same instant; a backingOff flag says the same thing without the arithmetic. The plugin token regex now carries its capability in the pattern instead of capturing and comparing, so another capability's token in the same message cannot mask it. resolution.extError becomes extErr, matching its chainState counterpart. * fix(agents): keep the longer cooldown when parks overlap Calls to one agent overlap, so a short cooldown could land after a long one started and cut it short. park now keeps whichever deadline is later, matching the rule longerRetry already applies on the artwork side. No in-tree provider can currently produce two different delays for the same agent, so this is hardening rather than a fix for observed behaviour. * fix(agents): parse the retry delay at a fixed width strconv.Atoi parses into the native int, so on the 32-bit targets we ship (linux/386, windows/386, three ARM variants) a delay above MaxInt32 seconds overflowed and became unspecified instead of being capped. No provider sends a 68-year delay, so this is not user-visible, but the overflow tests asserted the cap and would have failed on those architectures, where tests never run. * fix(plugins): anchor the retry_later regex to a word boundary Prevents a superstring like useragent(retry_later) from matching the agent capability token. --- adapters/lastfm/agent.go | 3 +- adapters/lastfm/agent_test.go | 19 +++ adapters/lastfm/client.go | 11 +- adapters/listenbrainz/agent_test.go | 13 ++ adapters/listenbrainz/client.go | 17 +++ adapters/listenbrainz/client_test.go | 73 +++++++++ core/agents/agents.go | 144 +++++++++++++----- core/agents/agents_test.go | 126 ++++++++++++++- core/agents/interfaces.go | 51 ++++++- core/agents/interfaces_test.go | 47 ++++-- core/agents/song_test.go | 27 ++++ core/artwork/agent_images.go | 36 +++-- core/artwork/agent_images_test.go | 65 +++++--- core/artwork/processor.go | 32 ++-- core/artwork/processor_test.go | 57 ++++--- core/artwork/resolve.go | 49 +++--- core/artwork/resolve_test.go | 46 +++--- core/artwork/worker.go | 9 +- core/artwork/worker_soak_test.go | 2 +- core/artwork/worker_test.go | 33 ++++ core/external/provider.go | 63 +++++--- core/external/provider_similarsongs.go | 2 +- core/external/provider_topsongs_test.go | 15 ++ .../external/provider_updatealbuminfo_test.go | 22 +++ .../provider_updateartistinfo_test.go | 19 +++ core/scrobbler/buffered_scrobbler.go | 47 +++--- core/scrobbler/buffered_scrobbler_test.go | 122 ++++++++++++++- core/scrobbler/interfaces.go | 4 +- core/scrobbler/play_tracker_test.go | 37 +++-- plugins/capabilities.go | 29 +++- plugins/capabilities/metadata_agent.go | 12 ++ plugins/metadata_agent.go | 3 + plugins/metadata_agent_test.go | 26 ++++ plugins/pdk/go/metadata/metadata.go | 12 ++ plugins/pdk/go/metadata/metadata_stub.go | 12 ++ .../rust/nd-pdk-capabilities/src/metadata.rs | 5 + plugins/scrobbler_adapter.go | 5 +- plugins/scrobbler_adapter_test.go | 22 +++ 38 files changed, 1085 insertions(+), 232 deletions(-) create mode 100644 core/agents/song_test.go diff --git a/adapters/lastfm/agent.go b/adapters/lastfm/agent.go index 863868b5a..7f005db1a 100644 --- a/adapters/lastfm/agent.go +++ b/adapters/lastfm/agent.go @@ -405,7 +405,8 @@ func (l *lastfmAgent) Scrobble(ctx context.Context, userId string, s scrobbler.S log.Warn(ctx, "Last.fm client.scrobble returned error", "track", s.Title, err) return errors.Join(err, scrobbler.ErrRetryLater) } - if lfErr.Code == 11 || lfErr.Code == 16 { + // 11: service offline; 16: temporarily unavailable. Rate limiting is mapped by the client. + if lfErr.Code == 11 || lfErr.Code == 16 || errors.Is(err, scrobbler.ErrRetryLater) { return errors.Join(err, scrobbler.ErrRetryLater) } return errors.Join(err, scrobbler.ErrUnrecoverable) diff --git a/adapters/lastfm/agent_test.go b/adapters/lastfm/agent_test.go index 94024b9ab..ce81e0916 100644 --- a/adapters/lastfm/agent_test.go +++ b/adapters/lastfm/agent_test.go @@ -100,6 +100,15 @@ var _ = Describe("lastfmAgent", func() { Expect(httpClient.RequestCount).To(Equal(1)) Expect(httpClient.SavedRequest.URL.Query().Get("artist")).To(Equal("U2")) }) + + It("returns ErrRetryLater on error 29 (rate limit exceeded)", func() { + httpClient.Res = http.Response{ + Body: io.NopCloser(bytes.NewBufferString(`{"error":29,"message":"Rate limit exceeded"}`)), + StatusCode: 200, + } + _, err := agent.GetArtistBiography(ctx, "123", "U2", "") + Expect(errors.Is(err, agents.ErrRetryLater)).To(BeTrue()) + }) }) Describe("Language Fallback", func() { @@ -497,6 +506,16 @@ var _ = Describe("lastfmAgent", func() { Expect(err).To(MatchError(scrobbler.ErrRetryLater)) }) + It("returns ErrRetryLater on error 29 (rate limit exceeded)", func() { + httpClient.Res = http.Response{ + Body: io.NopCloser(bytes.NewBufferString(`{"error":29,"message":"Rate limit exceeded"}`)), + StatusCode: 200, + } + + err := agent.Scrobble(ctx, "user-1", scrobbler.Scrobble{MediaFile: *track, TimeStamp: time.Now()}) + Expect(errors.Is(err, scrobbler.ErrRetryLater)).To(BeTrue()) + }) + It("returns ErrRetryLater on http errors", func() { httpClient.Res = http.Response{ Body: io.NopCloser(bytes.NewBufferString(`internal server error`)), diff --git a/adapters/lastfm/client.go b/adapters/lastfm/client.go index 726df1360..e468aa638 100644 --- a/adapters/lastfm/client.go +++ b/adapters/lastfm/client.go @@ -5,6 +5,7 @@ import ( "crypto/md5" "encoding/hex" "encoding/json" + "errors" "fmt" "net/http" "net/url" @@ -14,11 +15,15 @@ import ( "strings" "time" + "github.com/navidrome/navidrome/core/agents" "github.com/navidrome/navidrome/log" ) const ( apiBaseUrl = "https://ws.audioscrobbler.com/2.0/" + // errCodeRateLimit is Last.fm's "rate limit exceeded"; it arrives in the body, with HTTP 200 + // and no rate-limit headers, so the body code is the only signal. + errCodeRateLimit = 29 ) type lastFMError struct { @@ -225,7 +230,11 @@ func (c *client) makeRequest(ctx context.Context, method string, params url.Valu return nil, jsonErr } if response.Error != 0 { - return &response, &lastFMError{Code: response.Error, Message: response.Message} + var err error = &lastFMError{Code: response.Error, Message: response.Message} + if response.Error == errCodeRateLimit { + err = errors.Join(err, &agents.RetryLaterError{}) + } + return &response, err } return &response, nil diff --git a/adapters/listenbrainz/agent_test.go b/adapters/listenbrainz/agent_test.go index 2c4668296..a201b7c3a 100644 --- a/adapters/listenbrainz/agent_test.go +++ b/adapters/listenbrainz/agent_test.go @@ -164,6 +164,19 @@ var _ = Describe("listenBrainzAgent", func() { err := agent.Scrobble(ctx, "user-1", sc) Expect(err).To(MatchError(scrobbler.ErrUnrecoverable)) }) + + It("keeps a 429 scrobble for retry and carries the delay", func() { + httpClient.Res = http.Response{ + StatusCode: 429, + Header: http.Header{"X-Ratelimit-Reset-In": []string{"7"}}, + Body: io.NopCloser(bytes.NewBufferString(`{"code":429,"error":"rate limited"}`)), + } + err := agent.Scrobble(ctx, "user-1", scrobbler.Scrobble{MediaFile: *track, TimeStamp: time.Now()}) + Expect(errors.Is(err, scrobbler.ErrRetryLater)).To(BeTrue()) + retry, ok := errors.AsType[*agents.RetryLaterError](err) + Expect(ok).To(BeTrue()) + Expect(retry.RetryIn).To(Equal(7 * time.Second)) + }) }) Describe("GetArtistUrl", func() { diff --git a/adapters/listenbrainz/client.go b/adapters/listenbrainz/client.go index 708f02f28..aae4fb51d 100644 --- a/adapters/listenbrainz/client.go +++ b/adapters/listenbrainz/client.go @@ -13,6 +13,7 @@ import ( "slices" "github.com/navidrome/navidrome/conf" + "github.com/navidrome/navidrome/core/agents" "github.com/navidrome/navidrome/log" ) @@ -21,6 +22,12 @@ const ( labsBase = "https://labs.api.listenbrainz.org/" ) +// retryLaterErr reads the wait ListenBrainz asked for. It sends X-RateLimit-Reset-In +// (delta-seconds) on every response, including the 429, and never Retry-After. +func retryLaterErr(h http.Header) *agents.RetryLaterError { + return &agents.RetryLaterError{RetryIn: agents.ParseRetryIn(h.Get("X-RateLimit-Reset-In"))} +} + var ( ErrorNotFound = errors.New("listenbrainz: not found") ) @@ -174,6 +181,9 @@ func (c *client) makeAuthenticatedRequest(ctx context.Context, method string, en } defer resp.Body.Close() + if resp.StatusCode == http.StatusTooManyRequests { + return nil, retryLaterErr(resp.Header) + } decoder := json.NewDecoder(resp.Body) var response listenBrainzResponse @@ -185,6 +195,10 @@ func (c *client) makeAuthenticatedRequest(ctx context.Context, method string, en return nil, jsonErr } if response.Code != 0 && response.Code != 200 { + // LB also reports rate limiting as a body code, not only as an HTTP status. + if response.Code == http.StatusTooManyRequests { + return &response, retryLaterErr(resp.Header) + } return &response, &listenBrainzError{Code: response.Code, Message: response.Error} } @@ -211,6 +225,9 @@ func (c *client) makeGenericRequest(ctx context.Context, method string, endpoint // On a 200 code, there is no code. Decode using using error message if it exists if resp.StatusCode != 200 { defer resp.Body.Close() + if resp.StatusCode == http.StatusTooManyRequests { + return nil, retryLaterErr(resp.Header) + } decoder := json.NewDecoder(resp.Body) var lbzError lbzHttpError diff --git a/adapters/listenbrainz/client_test.go b/adapters/listenbrainz/client_test.go index 319cf01ab..ec0b0ac11 100644 --- a/adapters/listenbrainz/client_test.go +++ b/adapters/listenbrainz/client_test.go @@ -4,13 +4,17 @@ import ( "bytes" "context" "encoding/json" + "errors" "fmt" "io" "net/http" "os" + "strings" + "time" "github.com/navidrome/navidrome/conf" "github.com/navidrome/navidrome/conf/configtest" + "github.com/navidrome/navidrome/core/agents" "github.com/navidrome/navidrome/tests" . "github.com/onsi/ginkgo/v2" . "github.com/onsi/gomega" @@ -461,4 +465,73 @@ var _ = Describe("client", func() { })) }) }) + + Describe("rate limiting", func() { + It("returns RetryLaterError with the header delay on 429", func() { + httpClient.Res = http.Response{ + StatusCode: 429, + Header: http.Header{"X-Ratelimit-Reset-In": []string{"3"}}, + Body: io.NopCloser(strings.NewReader(`{"code":429,"error":"You have exceeded your rate limit."}`)), + } + _, err := client.validateToken(context.Background(), "token") + Expect(errors.Is(err, agents.ErrRetryLater)).To(BeTrue()) + retry, ok := errors.AsType[*agents.RetryLaterError](err) + Expect(ok).To(BeTrue()) + Expect(retry.RetryIn).To(Equal(3 * time.Second)) + }) + + It("returns RetryLaterError with zero delay when no header is present", func() { + httpClient.Res = http.Response{ + StatusCode: 429, + Body: io.NopCloser(strings.NewReader(`{"code":429,"error":"rate limited"}`)), + } + _, err := client.validateToken(context.Background(), "token") + Expect(errors.Is(err, agents.ErrRetryLater)).To(BeTrue()) + retry, _ := errors.AsType[*agents.RetryLaterError](err) + Expect(retry.RetryIn).To(BeZero()) + }) + + DescribeTable("caps absurd header values at one hour", + func(header string) { + httpClient.Res = http.Response{ + StatusCode: 429, + Header: http.Header{"X-Ratelimit-Reset-In": []string{header}}, + Body: io.NopCloser(strings.NewReader(`{"code":429,"error":"rate limited"}`)), + } + _, err := client.validateToken(context.Background(), "token") + retry, _ := errors.AsType[*agents.RetryLaterError](err) + Expect(retry.RetryIn).To(Equal(time.Hour)) + }, + Entry("a large value", "999999"), + Entry("a huge value", "99999999999"), + // Scaling this to nanoseconds before capping wraps past 2^64, landing on ~0.29s. + Entry("a value that overflows int64 nanoseconds", "18446744074"), + ) + + It("maps a body-level 429 sent with a non-429 status", func() { + httpClient.Res = http.Response{ + StatusCode: 200, + Header: http.Header{"X-Ratelimit-Reset-In": []string{"7"}}, + Body: io.NopCloser(strings.NewReader(`{"code":429,"error":"You have exceeded your rate limit."}`)), + } + _, err := client.validateToken(context.Background(), "token") + Expect(errors.Is(err, agents.ErrRetryLater)).To(BeTrue()) + retry, ok := errors.AsType[*agents.RetryLaterError](err) + Expect(ok).To(BeTrue()) + Expect(retry.RetryIn).To(Equal(7 * time.Second)) + }) + + It("returns RetryLaterError on a 429 from makeGenericRequest", func() { + httpClient.Res = http.Response{ + StatusCode: 429, + Header: http.Header{"X-Ratelimit-Reset-In": []string{"5"}}, + Body: io.NopCloser(strings.NewReader(`{"code":429,"error":"rate limited"}`)), + } + _, err := client.getArtistUrl(context.Background(), "1") + Expect(errors.Is(err, agents.ErrRetryLater)).To(BeTrue()) + retry, ok := errors.AsType[*agents.RetryLaterError](err) + Expect(ok).To(BeTrue()) + Expect(retry.RetryIn).To(Equal(5 * time.Second)) + }) + }) }) diff --git a/core/agents/agents.go b/core/agents/agents.go index 348f7d4e7..ac623951c 100644 --- a/core/agents/agents.go +++ b/core/agents/agents.go @@ -1,9 +1,12 @@ package agents import ( + "cmp" "context" + "errors" "slices" "strings" + "sync" "time" "github.com/navidrome/navidrome/conf" @@ -22,11 +25,43 @@ type PluginLoader interface { LoadMediaAgent(name string) (Interface, bool) } +// agentCooldown is the default cooldown duration for an agent that returns a RetryLaterError without a specific +// RetryIn duration. +const agentCooldown = time.Minute + +// errUnsupported marks an agent that does not implement the requested method: it never ran, +// so it neither answered nor throttled. +var errUnsupported = errors.New("agent does not support this method") + // Agents is a meta-agent that aggregates multiple built-in and plugin agents. It tries each enabled agent in order // until one returns valid data. type Agents struct { ds model.DataStore pluginLoader PluginLoader + cooldowns cooldowns +} + +// cooldowns remembers, across dispatches, which agents asked to be left alone and until when. +type cooldowns struct { + mu sync.RWMutex + until map[string]time.Time +} + +func (c *cooldowns) active(name string) bool { + c.mu.RLock() + defer c.mu.RUnlock() + return time.Now().Before(c.until[name]) +} + +// park keeps whichever deadline is later, so a call still in flight when a longer cooldown +// starts cannot cut it short when it finally answers. +func (c *cooldowns) park(name string, d time.Duration) { + until := time.Now().Add(d) + c.mu.Lock() + defer c.mu.Unlock() + if until.After(c.until[name]) { + c.until[name] = until + } } // GetAgents returns the singleton instance of Agents @@ -41,6 +76,7 @@ func createAgents(ds model.DataStore, pluginLoader PluginLoader) *Agents { return &Agents{ ds: ds, pluginLoader: pluginLoader, + cooldowns: cooldowns{until: map[string]time.Time{}}, } } @@ -171,7 +207,7 @@ func (a *Agents) GetArtistMBID(ctx context.Context, id string, name string) (str return callAgentMethod(ctx, a, "GetArtistMBID", func(ag Interface) (string, error) { retriever, ok := ag.(ArtistMBIDRetriever) if !ok { - return "", ErrNotFound + return "", errUnsupported } return retriever.GetArtistMBID(ctx, id, name) }) @@ -188,7 +224,7 @@ func (a *Agents) GetArtistURL(ctx context.Context, id, name, mbid string) (strin return callAgentMethod(ctx, a, "GetArtistURL", func(ag Interface) (string, error) { retriever, ok := ag.(ArtistURLRetriever) if !ok { - return "", ErrNotFound + return "", errUnsupported } return retriever.GetArtistURL(ctx, id, name, mbid) }) @@ -205,7 +241,7 @@ func (a *Agents) GetArtistBiography(ctx context.Context, id, name, mbid string) return callAgentMethod(ctx, a, "GetArtistBiography", func(ag Interface) (string, error) { retriever, ok := ag.(ArtistBiographyRetriever) if !ok { - return "", ErrNotFound + return "", errUnsupported } return retriever.GetArtistBiography(ctx, id, name, mbid) }) @@ -224,7 +260,11 @@ func (a *Agents) GetSimilarArtists(ctx context.Context, id, name, mbid string, l overLimit := int(float64(limit) * conf.Server.DevExternalArtistFetchMultiplier) start := time.Now() + attempts := newAttempts(&a.cooldowns) for _, enabledAgent := range a.getEnabledAgentNames() { + if attempts.skip(enabledAgent.name) { + continue + } ag := a.getAgent(enabledAgent) if ag == nil { continue @@ -237,6 +277,7 @@ func (a *Agents) GetSimilarArtists(ctx context.Context, id, name, mbid string, l continue } similar, err := retriever.GetSimilarArtists(ctx, id, name, mbid, overLimit) + attempts.record(enabledAgent.name, err) if len(similar) > 0 && err == nil { if log.IsGreaterOrEqualTo(log.LevelTrace) { log.Debug(ctx, "Got Similar Artists", "agent", ag.AgentName(), "artist", name, "similar", similar, "elapsed", time.Since(start)) @@ -246,7 +287,7 @@ func (a *Agents) GetSimilarArtists(ctx context.Context, id, name, mbid string, l return similar, err } } - return nil, ErrNotFound + return nil, attempts.noResultErr() } func (a *Agents) GetArtistImages(ctx context.Context, id, name, mbid string) ([]ExternalImage, error) { @@ -260,7 +301,7 @@ func (a *Agents) GetArtistImages(ctx context.Context, id, name, mbid string) ([] return callAgentSliceMethod(ctx, a, "GetArtistImages", func(ag Interface) ([]ExternalImage, error) { retriever, ok := ag.(ArtistImageRetriever) if !ok { - return nil, ErrNotFound + return nil, errUnsupported } return retriever.GetArtistImages(ctx, id, name, mbid) }) @@ -281,7 +322,7 @@ func (a *Agents) GetArtistTopSongs(ctx context.Context, id, artistName, mbid str return callAgentSliceMethod(ctx, a, "GetArtistTopSongs", func(ag Interface) ([]Song, error) { retriever, ok := ag.(ArtistTopSongsRetriever) if !ok { - return nil, ErrNotFound + return nil, errUnsupported } return retriever.GetArtistTopSongs(ctx, id, artistName, mbid, overLimit) }) @@ -295,7 +336,7 @@ func (a *Agents) GetAlbumInfo(ctx context.Context, name, artist, mbid string) (* return callAgentMethod(ctx, a, "GetAlbumInfo", func(ag Interface) (*AlbumInfo, error) { retriever, ok := ag.(AlbumInfoRetriever) if !ok { - return nil, ErrNotFound + return nil, errUnsupported } return retriever.GetAlbumInfo(ctx, name, artist, mbid) }) @@ -309,7 +350,7 @@ func (a *Agents) GetAlbumImages(ctx context.Context, name, artist, mbid string) return callAgentSliceMethod(ctx, a, "GetAlbumImages", func(ag Interface) ([]ExternalImage, error) { retriever, ok := ag.(AlbumImageRetriever) if !ok { - return nil, ErrNotFound + return nil, errUnsupported } return retriever.GetAlbumImages(ctx, name, artist, mbid) }) @@ -320,7 +361,7 @@ func (a *Agents) GetSimilarSongsByTrack(ctx context.Context, id, name, artist, m return callAgentSliceMethod(ctx, a, "GetSimilarSongsByTrack", func(ag Interface) ([]Song, error) { retriever, ok := ag.(SimilarSongsByTrackRetriever) if !ok { - return nil, ErrNotFound + return nil, errUnsupported } return retriever.GetSimilarSongsByTrack(ctx, id, name, artist, mbid, count) }) @@ -331,7 +372,7 @@ func (a *Agents) GetSimilarSongsByAlbum(ctx context.Context, id, name, artist, m return callAgentSliceMethod(ctx, a, "GetSimilarSongsByAlbum", func(ag Interface) ([]Song, error) { retriever, ok := ag.(SimilarSongsByAlbumRetriever) if !ok { - return nil, ErrNotFound + return nil, errUnsupported } return retriever.GetSimilarSongsByAlbum(ctx, id, name, artist, mbid, count) }) @@ -349,16 +390,61 @@ func (a *Agents) GetSimilarSongsByArtist(ctx context.Context, id, name, mbid str return callAgentSliceMethod(ctx, a, "GetSimilarSongsByArtist", func(ag Interface) ([]Song, error) { retriever, ok := ag.(SimilarSongsByArtistRetriever) if !ok { - return nil, ErrNotFound + return nil, errUnsupported } return retriever.GetSimilarSongsByArtist(ctx, id, name, mbid, count) }) } -func callAgentMethod[T comparable](ctx context.Context, agents *Agents, methodName string, fn func(Interface) (T, error)) (T, error) { +// agentAttempts tallies what the enabled agents did in one dispatch. +type agentAttempts struct { + cooldowns *cooldowns + throttled bool + answered bool +} + +func newAttempts(c *cooldowns) agentAttempts { + return agentAttempts{cooldowns: c} +} + +// skip reports whether name is still cooling down, counting it as throttled for this dispatch. +func (t *agentAttempts) skip(name string) bool { + if !t.cooldowns.active(name) { + return false + } + t.throttled = true + return true +} + +// record files one agent's outcome, parking it when it asked to be retried later. +func (t *agentAttempts) record(name string, err error) { + switch retry, isRetryLater := errors.AsType[*RetryLaterError](err); { + case errors.Is(err, errUnsupported): + case isRetryLater: + t.cooldowns.park(name, cmp.Or(retry.RetryIn, agentCooldown)) + t.throttled = true + default: + t.answered = true + } +} + +// noResultErr tells a retryable empty dispatch (nobody answered) from a definitive miss. +func (t *agentAttempts) noResultErr() error { + if t.throttled && !t.answered { + return ErrRetryLater + } + return ErrNotFound +} + +// callAgent tries each enabled agent in order until found reports a usable result. +func callAgent[T any](ctx context.Context, agents *Agents, methodName string, fn func(Interface) (T, error), found func(T) bool) (T, error) { var zero T start := time.Now() + attempts := newAttempts(&agents.cooldowns) for _, enabledAgent := range agents.getEnabledAgentNames() { + if attempts.skip(enabledAgent.name) { + continue + } ag := agents.getAgent(enabledAgent) if ag == nil { continue @@ -367,41 +453,29 @@ func callAgentMethod[T comparable](ctx context.Context, agents *Agents, methodNa break } result, err := fn(ag) + attempts.record(enabledAgent.name, err) if err != nil { log.Trace(ctx, "Agent method call error", "method", methodName, "agent", ag.AgentName(), "error", err) continue } - if result != zero { + if found(result) { log.Debug(ctx, "Got result", "method", methodName, "agent", ag.AgentName(), "elapsed", time.Since(start)) return result, nil } } - return zero, ErrNotFound + return zero, attempts.noResultErr() +} + +func callAgentMethod[T comparable](ctx context.Context, agents *Agents, methodName string, fn func(Interface) (T, error)) (T, error) { + return callAgent(ctx, agents, methodName, fn, func(result T) bool { + var zero T + return result != zero + }) } func callAgentSliceMethod[T any](ctx context.Context, agents *Agents, methodName string, fn func(Interface) ([]T, error)) ([]T, error) { - start := time.Now() - for _, enabledAgent := range agents.getEnabledAgentNames() { - ag := agents.getAgent(enabledAgent) - if ag == nil { - continue - } - if utils.IsCtxDone(ctx) { - break - } - results, err := fn(ag) - if err != nil { - log.Trace(ctx, "Agent method call error", "method", methodName, "agent", ag.AgentName(), "error", err) - continue - } - - if len(results) > 0 { - log.Debug(ctx, "Got results", "method", methodName, "agent", ag.AgentName(), "count", len(results), "elapsed", time.Since(start)) - return results, nil - } - } - return nil, ErrNotFound + return callAgent(ctx, agents, methodName, fn, func(results []T) bool { return len(results) > 0 }) } var _ Interface = (*Agents)(nil) diff --git a/core/agents/agents_test.go b/core/agents/agents_test.go index e79b2b3c8..35ebf18d8 100644 --- a/core/agents/agents_test.go +++ b/core/agents/agents_test.go @@ -3,6 +3,7 @@ package agents import ( "context" "errors" + "time" "github.com/navidrome/navidrome/conf/configtest" "github.com/navidrome/navidrome/consts" @@ -14,6 +15,29 @@ import ( . "github.com/onsi/gomega" ) +var _ = Describe("cooldowns", func() { + // Calls to one agent overlap, so a short cooldown can land after a long one started. + It("keeps the longer deadline when a shorter park lands after it", func() { + c := cooldowns{until: map[string]time.Time{}} + + c.park("fake", time.Hour) + c.park("fake", time.Millisecond) + + time.Sleep(10 * time.Millisecond) + Expect(c.active("fake")).To(BeTrue()) + }) + + It("extends the deadline when the later park is longer", func() { + c := cooldowns{until: map[string]time.Time{}} + + c.park("fake", time.Millisecond) + c.park("fake", time.Hour) + + time.Sleep(10 * time.Millisecond) + Expect(c.active("fake")).To(BeTrue()) + }) +}) + var _ = Describe("Agents", func() { var ctx context.Context var cancel context.CancelFunc @@ -160,6 +184,102 @@ var _ = Describe("Agents", func() { }) }) + Describe("cooldown", func() { + It("skips an agent that returned RetryLaterError until the deadline", func() { + mock.Err = &RetryLaterError{RetryIn: time.Hour} + _, err := ag.GetArtistBiography(ctx, "id", "name", "mbid") + Expect(errors.Is(err, ErrRetryLater)).To(BeTrue()) + + // Immediately after: agent is skipped, not called + mock.Err = nil + calls := mock.Calls + _, err = ag.GetArtistBiography(ctx, "id", "name", "mbid") + Expect(mock.Calls).To(Equal(calls)) + Expect(errors.Is(err, ErrRetryLater)).To(BeTrue()) + }) + + // Providers that throttle without saying for how long (Last.fm sends no delay at all) + // must still be parked, or the aggregate keeps calling them on every request. + It("parks an agent that asked to be retried without a delay", func() { + mock.Err = ErrRetryLater + _, err := ag.GetArtistBiography(ctx, "id", "name", "mbid") + Expect(errors.Is(err, ErrRetryLater)).To(BeTrue()) + + mock.Err = nil + calls := mock.Calls + _, err = ag.GetArtistBiography(ctx, "id", "name", "mbid") + Expect(mock.Calls).To(Equal(calls), "the default cooldown must outlast the request") + Expect(errors.Is(err, ErrRetryLater)).To(BeTrue()) + }) + + It("calls the agent again once the cooldown expires", func() { + mock.Err = &RetryLaterError{RetryIn: 10 * time.Millisecond} + _, err := ag.GetArtistBiography(ctx, "id", "name", "mbid") + Expect(errors.Is(err, ErrRetryLater)).To(BeTrue()) + + mock.Err = nil + Eventually(func() (string, error) { + return ag.GetArtistBiography(ctx, "id", "name", "mbid") + }, 5*time.Second, 10*time.Millisecond).Should(Equal("bio")) + }) + + It("returns ErrNotFound, not ErrRetryLater, when agents failed for other reasons", func() { + mock.Err = errors.New("boom") + _, err := ag.GetArtistBiography(ctx, "id", "name", "mbid") + Expect(errors.Is(err, ErrNotFound)).To(BeTrue()) + Expect(errors.Is(err, ErrRetryLater)).To(BeFalse()) + }) + + // ErrRetryLater tells the caller "nobody answered, do not cache this". A definitive + // answer from any other agent is an answer, throttled peer or not. + It("returns ErrNotFound when another agent answered with a definitive miss", func() { + other := &mockAgent{Err: ErrNotFound} + Register("fake2", func(model.DataStore) Interface { return other }) + conf.Server.Agents = "fake,fake2" + ag = createAgents(ds, nil) + mock.Err = &RetryLaterError{RetryIn: time.Hour} + + _, err := ag.GetArtistBiography(ctx, "id", "name", "mbid") + Expect(errors.Is(err, ErrNotFound)).To(BeTrue()) + Expect(errors.Is(err, ErrRetryLater)).To(BeFalse()) + + // The cooldown was still recorded for the throttled agent + calls := mock.Calls + _, _ = ag.GetArtistBiography(ctx, "id", "name", "mbid") + Expect(mock.Calls).To(Equal(calls)) + }) + + It("returns ErrNotFound when another agent answered with an empty slice", func() { + empty := &testImageAgent{Name: "emptyImages"} + Register("emptyImages", func(model.DataStore) Interface { return empty }) + conf.Server.Agents = "fake,emptyImages" + ag = createAgents(ds, nil) + mock.Err = &RetryLaterError{RetryIn: time.Hour} + + _, err := ag.GetArtistImages(ctx, "123", "test", "mb123") + Expect(errors.Is(err, ErrNotFound)).To(BeTrue()) + Expect(errors.Is(err, ErrRetryLater)).To(BeFalse()) + }) + + It("returns ErrRetryLater from GetSimilarArtists when only cooling agents remain", func() { + mock.Err = &RetryLaterError{RetryIn: time.Hour} + _, err := ag.GetSimilarArtists(ctx, "123", "test", "mb123", 2) + Expect(errors.Is(err, ErrRetryLater)).To(BeTrue()) + }) + + It("returns ErrNotFound from GetSimilarArtists when another agent answered", func() { + other := &mockAgent{Err: ErrNotFound} + Register("fake2", func(model.DataStore) Interface { return other }) + conf.Server.Agents = "fake,fake2" + ag = createAgents(ds, nil) + mock.Err = &RetryLaterError{RetryIn: time.Hour} + + _, err := ag.GetSimilarArtists(ctx, "123", "test", "mb123", 2) + Expect(errors.Is(err, ErrNotFound)).To(BeTrue()) + Expect(errors.Is(err, ErrRetryLater)).To(BeFalse()) + }) + }) + Describe("GetArtistImages", func() { It("returns on first match", func() { Expect(ag.GetArtistImages(ctx, "123", "test", "mb123")).To(Equal([]ExternalImage{{ @@ -423,8 +543,9 @@ var _ = Describe("Agents", func() { }) type mockAgent struct { - Args []any - Err error + Args []any + Err error + Calls int } func (a *mockAgent) AgentName() string { @@ -449,6 +570,7 @@ func (a *mockAgent) GetArtistURL(_ context.Context, id, name, mbid string) (stri func (a *mockAgent) GetArtistBiography(_ context.Context, id, name, mbid string) (string, error) { a.Args = []any{id, name, mbid} + a.Calls++ if a.Err != nil { return "", a.Err } diff --git a/core/agents/interfaces.go b/core/agents/interfaces.go index 7fc5de361..9225a0442 100644 --- a/core/agents/interfaces.go +++ b/core/agents/interfaces.go @@ -3,6 +3,9 @@ package agents import ( "context" "errors" + "fmt" + "strconv" + "time" "github.com/gohugoio/hashstructure" "github.com/navidrome/navidrome/model" @@ -52,11 +55,49 @@ func (s Song) Equals(other Song) bool { return h1 == h2 } -var ( - // ErrNotFound means the provider answered and had nothing. Return the underlying error - // for a fault instead, or callers that back off on faults will treat it as definitive. - ErrNotFound = errors.New("not found") -) +// ErrNotFound means the provider answered and had nothing. Return the underlying error +// for a fault instead, or callers that back off on faults will treat it as definitive. +var ErrNotFound = errors.New("not found") + +// ErrRetryLater is the zero-delay RetryLaterError: the provider is temporarily unavailable +// or throttling us, but did not say for how long. Both errors.Is(err, ErrRetryLater) and +// errors.AsType[*RetryLaterError] match it and every delay-carrying variant. +// Treat it as immutable; build a new RetryLaterError to name a delay. +var ErrRetryLater = &RetryLaterError{} + +// RetryLaterError asks callers to back off, optionally for the delay the provider requested. +type RetryLaterError struct { + RetryIn time.Duration +} + +func (e *RetryLaterError) Error() string { + if e.RetryIn > 0 { + return fmt.Sprintf("retry later (in %s)", e.RetryIn) + } + return "retry later" +} + +func (e *RetryLaterError) Is(target error) bool { + _, ok := target.(*RetryLaterError) + return ok +} + +// MaxRetryIn caps a delay parsed from a provider, so a bogus value cannot park it indefinitely. +const MaxRetryIn = time.Hour +const maxRetryInSeconds = int(MaxRetryIn / time.Second) + +// ParseRetryIn reads a provider's delay given in seconds, from a header or a plugin token. +// Anything unparseable or non-positive means unspecified. +func ParseRetryIn(seconds string) time.Duration { + // Clamp in seconds: scaling first would wrap a huge value past int64 nanoseconds, + // turning "wait an age" into a fraction of a second. Parse at a fixed width so the + // cap holds on the 32-bit targets we ship, where a plain Atoi would overflow first. + secs, err := strconv.ParseInt(seconds, 10, 64) + if err != nil || secs <= 0 { + return 0 + } + return time.Duration(min(secs, int64(maxRetryInSeconds))) * time.Second +} // AlbumInfoRetriever provides album info (no images) type AlbumInfoRetriever interface { diff --git a/core/agents/interfaces_test.go b/core/agents/interfaces_test.go index c13710a38..6acbc545d 100644 --- a/core/agents/interfaces_test.go +++ b/core/agents/interfaces_test.go @@ -1,27 +1,42 @@ -package agents +package agents_test import ( + "errors" + "fmt" + "time" + + "github.com/navidrome/navidrome/core/agents" + "github.com/navidrome/navidrome/core/scrobbler" . "github.com/onsi/ginkgo/v2" . "github.com/onsi/gomega" ) -var _ = Describe("Song.Equals", func() { - base := Song{ID: "1", Name: "S", Artists: []Artist{{ID: "x", Name: "A"}}} - It("true for identical songs incl Artists", func() { - Expect(base.Equals(base)).To(BeTrue()) +var _ = Describe("RetryLaterError", func() { + It("matches the ErrRetryLater sentinel via errors.Is", func() { + err := &agents.RetryLaterError{RetryIn: 30 * time.Second} + Expect(errors.Is(err, agents.ErrRetryLater)).To(BeTrue()) }) - It("false when Artists differ", func() { - other := base - other.Artists = []Artist{{ID: "y", Name: "B"}} - Expect(base.Equals(other)).To(BeFalse()) + + It("matches through errors.Join and wrapping", func() { + err := fmt.Errorf("calling LB: %w", errors.Join(errors.New("http 429"), &agents.RetryLaterError{})) + Expect(errors.Is(err, agents.ErrRetryLater)).To(BeTrue()) }) - It("false when a scalar differs", func() { - other := base - other.Name = "T" - Expect(base.Equals(other)).To(BeFalse()) + + It("exposes the delay through the wrapped error", func() { + err := errors.Join(errors.New("http 429"), &agents.RetryLaterError{RetryIn: 42 * time.Second}) + retry, ok := errors.AsType[*agents.RetryLaterError](err) + Expect(ok).To(BeTrue()) + Expect(retry.RetryIn).To(Equal(42 * time.Second)) }) - It("true when both have empty Artists and equal scalars", func() { - a := Song{ID: "1", Name: "S"} - Expect(a.Equals(a)).To(BeTrue()) + + It("matches the sentinel too, reporting no delay", func() { + retry, ok := errors.AsType[*agents.RetryLaterError](agents.ErrRetryLater) + Expect(ok).To(BeTrue()) + Expect(retry.RetryIn).To(BeZero()) + }) + + It("is the same sentinel as scrobbler.ErrRetryLater", func() { + Expect(errors.Is(scrobbler.ErrRetryLater, agents.ErrRetryLater)).To(BeTrue()) + Expect(errors.Is(&agents.RetryLaterError{}, scrobbler.ErrRetryLater)).To(BeTrue()) }) }) diff --git a/core/agents/song_test.go b/core/agents/song_test.go new file mode 100644 index 000000000..c13710a38 --- /dev/null +++ b/core/agents/song_test.go @@ -0,0 +1,27 @@ +package agents + +import ( + . "github.com/onsi/ginkgo/v2" + . "github.com/onsi/gomega" +) + +var _ = Describe("Song.Equals", func() { + base := Song{ID: "1", Name: "S", Artists: []Artist{{ID: "x", Name: "A"}}} + It("true for identical songs incl Artists", func() { + Expect(base.Equals(base)).To(BeTrue()) + }) + It("false when Artists differ", func() { + other := base + other.Artists = []Artist{{ID: "y", Name: "B"}} + Expect(base.Equals(other)).To(BeFalse()) + }) + It("false when a scalar differs", func() { + other := base + other.Name = "T" + Expect(base.Equals(other)).To(BeFalse()) + }) + It("true when both have empty Artists and equal scalars", func() { + a := Song{ID: "1", Name: "S"} + Expect(a.Equals(a)).To(BeTrue()) + }) +}) diff --git a/core/artwork/agent_images.go b/core/artwork/agent_images.go index 95596dabc..985abacd7 100644 --- a/core/artwork/agent_images.go +++ b/core/artwork/agent_images.go @@ -2,6 +2,7 @@ package artwork import ( "context" + "errors" "io" "net/url" @@ -41,22 +42,36 @@ func bestImageURL(imgs []agents.ExternalImage) *url.URL { return best } -// fetchArtistImage tries each enabled artist-image agent in order. extErr is true only when no +// longerRetry keeps whichever external failure asks for the longer wait, so one provider's +// short delay cannot shorten another's. +func longerRetry(a, b error) error { + if a == nil { + return b + } + var ra, rb *agents.RetryLaterError + if errors.As(b, &rb) && (!errors.As(a, &ra) || rb.RetryIn > ra.RetryIn) { + return b + } + return a +} + +// fetchArtistImage tries each enabled artist-image agent in order. The error is non-nil only when no // agent succeeded and at least one failed transiently. -func fetchArtistImage(ctx context.Context, ag *agents.Agents, gate gateFunc, ar model.Artist) (r io.ReadCloser, agentName string, extErr bool) { +func fetchArtistImage(ctx context.Context, ag *agents.Agents, gate gateFunc, ar model.Artist) (io.ReadCloser, string, error) { // Synthetic artists would otherwise get an unrelated agent result assigned to them. switch ar.ID { case consts.UnknownArtistID, consts.VariousArtistsID: traceFrom(ctx).add(TraceStep{Candidate: externalCandidate, Outcome: OutcomeSkipped, Detail: "synthetic artist"}) - return nil, "", false + return nil, "", nil } name := externalName(ar.Name) imageAgents := ag.ArtistImageAgents() if len(imageAgents) == 0 { traceFrom(ctx).add(TraceStep{Candidate: externalCandidate, Outcome: OutcomeSkipped, Detail: "no enabled agent provides artist images"}) - return nil, "", false + return nil, "", nil } + var extErr error for _, a := range imageAgents { reader, path, err := gate(a.Name, func() (io.ReadCloser, string, error) { imgs, err := a.Retriever.GetArtistImages(ctx, ar.ID, name, ar.MbzArtistID) @@ -71,10 +86,10 @@ func fetchArtistImage(ctx context.Context, ag *agents.Agents, gate gateFunc, ar }) recordAgent(ctx, a.Name, reader, path, err) if reader != nil { - return reader, a.Name, false + return reader, a.Name, nil } if isTransientExternal(err) { - extErr = true + extErr = longerRetry(extErr, err) log.Debug(ctx, "Artwork: External artist-image lookup failed", "agent", a.Name, "artist", ar.Name, err) } } @@ -82,14 +97,15 @@ func fetchArtistImage(ctx context.Context, ag *agents.Agents, gate gateFunc, ar } // fetchAlbumImage is the album counterpart of fetchArtistImage. -func fetchAlbumImage(ctx context.Context, ag *agents.Agents, gate gateFunc, al model.Album) (r io.ReadCloser, agentName string, extErr bool) { +func fetchAlbumImage(ctx context.Context, ag *agents.Agents, gate gateFunc, al model.Album) (io.ReadCloser, string, error) { name, artist := externalName(al.Name), externalName(al.AlbumArtist) imageAgents := ag.AlbumImageAgents() if len(imageAgents) == 0 { traceFrom(ctx).add(TraceStep{Candidate: externalCandidate, Outcome: OutcomeSkipped, Detail: "no enabled agent provides album images"}) - return nil, "", false + return nil, "", nil } + var extErr error for _, a := range imageAgents { reader, path, err := gate(a.Name, func() (io.ReadCloser, string, error) { imgs, err := a.Retriever.GetAlbumImages(ctx, name, artist, al.MbzAlbumID) @@ -104,10 +120,10 @@ func fetchAlbumImage(ctx context.Context, ag *agents.Agents, gate gateFunc, al m }) recordAgent(ctx, a.Name, reader, path, err) if reader != nil { - return reader, a.Name, false + return reader, a.Name, nil } if isTransientExternal(err) { - extErr = true + extErr = longerRetry(extErr, err) log.Debug(ctx, "Artwork: External album-image lookup failed", "agent", a.Name, "album", al.Name, err) } } diff --git a/core/artwork/agent_images_test.go b/core/artwork/agent_images_test.go index 60a34352d..d0c2429b0 100644 --- a/core/artwork/agent_images_test.go +++ b/core/artwork/agent_images_test.go @@ -2,11 +2,13 @@ package artwork import ( "context" + "errors" "io" "net/http" "net/http/httptest" "strings" "sync" + "time" "github.com/navidrome/navidrome/conf" "github.com/navidrome/navidrome/conf/configtest" @@ -153,11 +155,11 @@ var _ = Describe("agent images", func() { a := &fakeImageAgent{name: "agentA", imgs: []agents.ExternalImage{img("/a", 100)}} ag := imageAgents(a) - r, name, extErr := fetchArtistImage(ctx, ag, passthroughGate, model.Artist{ID: "ar1", Name: "Artist"}) + r, name, err := fetchArtistImage(ctx, ag, passthroughGate, model.Artist{ID: "ar1", Name: "Artist"}) Expect(r).ToNot(BeNil()) defer r.Close() Expect(name).To(Equal("agentA")) - Expect(extErr).To(BeFalse()) + Expect(err).ToNot(HaveOccurred()) }) It("skips the external lookup for synthetic artists", func() { @@ -165,10 +167,10 @@ var _ = Describe("agent images", func() { ag := imageAgents(a) for _, id := range []string{consts.UnknownArtistID, consts.VariousArtistsID} { - r, name, extErr := fetchArtistImage(ctx, ag, passthroughGate, model.Artist{ID: id, Name: "Various Artists"}) + r, name, err := fetchArtistImage(ctx, ag, passthroughGate, model.Artist{ID: id, Name: "Various Artists"}) Expect(r).To(BeNil()) Expect(name).To(BeEmpty()) - Expect(extErr).To(BeFalse()) + Expect(err).ToNot(HaveOccurred()) } Expect(a.artistCalls).To(Equal(0), "synthetic artists never reach the agents") }) @@ -177,9 +179,9 @@ var _ = Describe("agent images", func() { ag := imageAgents() t := &ChainTrace{} - r, _, extErr := fetchArtistImage(withTrace(ctx, t), ag, passthroughGate, model.Artist{ID: "ar1"}) + r, _, err := fetchArtistImage(withTrace(ctx, t), ag, passthroughGate, model.Artist{ID: "ar1"}) Expect(r).To(BeNil()) - Expect(extErr).To(BeFalse()) + Expect(err).ToNot(HaveOccurred()) Expect(t.Steps()).To(Equal([]TraceStep{{Candidate: "external", Outcome: OutcomeSkipped, Detail: "no enabled agent provides artist images"}}), "a configured external token must never be silently absent from the chain") @@ -211,11 +213,11 @@ var _ = Describe("agent images", func() { b := &fakeImageAgent{name: "agentB", imgs: []agents.ExternalImage{img("/b", 50)}} ag := imageAgents(a, b) - r, name, extErr := fetchArtistImage(ctx, ag, passthroughGate, model.Artist{ID: "ar1"}) + r, name, err := fetchArtistImage(ctx, ag, passthroughGate, model.Artist{ID: "ar1"}) Expect(r).ToNot(BeNil()) defer r.Close() Expect(name).To(Equal("agentB")) - Expect(extErr).To(BeFalse(), "a later hit clears an earlier agent's error") + Expect(err).ToNot(HaveOccurred(), "a later hit clears an earlier agent's error") Expect(a.artistCalls).To(Equal(1)) Expect(b.artistCalls).To(Equal(1)) }) @@ -225,20 +227,43 @@ var _ = Describe("agent images", func() { b := &fakeImageAgent{name: "agentB", err: agents.ErrNotFound} ag := imageAgents(a, b) - r, name, extErr := fetchArtistImage(ctx, ag, passthroughGate, model.Artist{ID: "ar1"}) + r, name, err := fetchArtistImage(ctx, ag, passthroughGate, model.Artist{ID: "ar1"}) Expect(r).To(BeNil()) Expect(name).To(BeEmpty()) - Expect(extErr).To(BeFalse(), "not-found is definitive, never a transient failure") + Expect(err).ToNot(HaveOccurred(), "not-found is definitive, never a transient failure") }) - It("reports extErr when one agent fails transiently and the rest find nothing", func() { + It("reports an error when one agent fails transiently and the rest find nothing", func() { a := &fakeImageAgent{name: "agentA", err: agents.ErrNotFound} b := &fakeImageAgent{name: "agentB", err: context.DeadlineExceeded} ag := imageAgents(a, b) - r, _, extErr := fetchArtistImage(ctx, ag, passthroughGate, model.Artist{ID: "ar1"}) + r, _, err := fetchArtistImage(ctx, ag, passthroughGate, model.Artist{ID: "ar1"}) Expect(r).To(BeNil()) - Expect(extErr).To(BeTrue()) + Expect(err).To(HaveOccurred()) + }) + + // The worker reschedules on this delay, so it is only honored if the agent loop + // returns it. Two throttled agents: the longest wait is the one that must survive. + It("returns the longest retry delay the providers asked for", func() { + a := &fakeImageAgent{name: "agentA", err: &agents.RetryLaterError{RetryIn: 10 * time.Second}} + b := &fakeImageAgent{name: "agentB", err: &agents.RetryLaterError{RetryIn: 5 * time.Second}} + ag := imageAgents(a, b) + + r, _, err := fetchArtistImage(ctx, ag, passthroughGate, model.Artist{ID: "ar1"}) + Expect(r).To(BeNil()) + retry, ok := errors.AsType[*agents.RetryLaterError](err) + Expect(ok).To(BeTrue()) + Expect(retry.RetryIn).To(Equal(10 * time.Second)) + }) + + It("returns no delay when the provider did not ask for one", func() { + ag := imageAgents(&fakeImageAgent{name: "agentA", err: errors.New("boom")}) + + _, _, err := fetchArtistImage(ctx, ag, passthroughGate, model.Artist{ID: "ar1"}) + Expect(err).To(HaveOccurred()) + _, ok := errors.AsType[*agents.RetryLaterError](err) + Expect(ok).To(BeFalse(), "a plain failure must not look like a throttle") }) }) @@ -247,11 +272,11 @@ var _ = Describe("agent images", func() { a := &fakeImageAgent{name: "agentA", imgs: []agents.ExternalImage{img("/a", 100)}} ag := imageAgents(a) - r, name, extErr := fetchAlbumImage(ctx, ag, passthroughGate, model.Album{Name: "Album", AlbumArtist: "Artist"}) + r, name, err := fetchAlbumImage(ctx, ag, passthroughGate, model.Album{Name: "Album", AlbumArtist: "Artist"}) Expect(r).ToNot(BeNil()) defer r.Close() Expect(name).To(Equal("agentA")) - Expect(extErr).To(BeFalse()) + Expect(err).ToNot(HaveOccurred()) Expect(a.albumCalls).To(Equal(1)) }) @@ -259,21 +284,21 @@ var _ = Describe("agent images", func() { ag := imageAgents() t := &ChainTrace{} - r, _, extErr := fetchAlbumImage(withTrace(ctx, t), ag, passthroughGate, model.Album{Name: "Album"}) + r, _, err := fetchAlbumImage(withTrace(ctx, t), ag, passthroughGate, model.Album{Name: "Album"}) Expect(r).To(BeNil()) - Expect(extErr).To(BeFalse()) + Expect(err).ToNot(HaveOccurred()) Expect(t.Steps()).To(Equal([]TraceStep{{Candidate: "external", Outcome: OutcomeSkipped, Detail: "no enabled agent provides album images"}}), "a configured external token must never be silently absent from the chain") }) - It("reports extErr when the only agent fails transiently", func() { + It("reports an error when the only agent fails transiently", func() { a := &fakeImageAgent{name: "agentA", err: context.DeadlineExceeded} ag := imageAgents(a) - r, _, extErr := fetchAlbumImage(ctx, ag, passthroughGate, model.Album{Name: "Album"}) + r, _, err := fetchAlbumImage(ctx, ag, passthroughGate, model.Album{Name: "Album"}) Expect(r).To(BeNil()) - Expect(extErr).To(BeTrue()) + Expect(err).To(HaveOccurred()) }) }) diff --git a/core/artwork/processor.go b/core/artwork/processor.go index fdb28189a..cf2176775 100644 --- a/core/artwork/processor.go +++ b/core/artwork/processor.go @@ -16,6 +16,7 @@ import ( "github.com/navidrome/navidrome/conf" "github.com/navidrome/navidrome/consts" + "github.com/navidrome/navidrome/core/agents" "github.com/navidrome/navidrome/core/artwork/blurhash" "github.com/navidrome/navidrome/core/artwork/dominant" "github.com/navidrome/navidrome/core/artwork/thumbhash" @@ -80,7 +81,7 @@ type processor struct { // acquire resolves one queue item end to end: find an image, hash/decode/ // blurhash it, place its bytes, and persist the resulting state. -func (p *processor) acquire(ctx context.Context, item model.ArtworkQueueItem) (out outcome, got *acquired) { +func (p *processor) acquire(ctx context.Context, item model.ArtworkQueueItem) (out outcome, got *acquired, retryIn time.Duration) { repo := p.ds.Artwork(ctx) start := time.Now() defer func() { @@ -92,10 +93,13 @@ func (p *processor) acquire(ctx context.Context, item model.ArtworkQueueItem) (o if err != nil { traceStage(ctx, "resolve", err) log.Warn(ctx, "Artwork: Could not resolve item", "kind", item.ItemKind, "id", item.ItemID, err) - return outcomeFailed, nil + return outcomeFailed, nil, 0 + } + if retry, ok := errors.AsType[*agents.RetryLaterError](res.extErr); ok { + retryIn = retry.RetryIn } if res.reader == nil { - if res.extError || res.localError { + if res.extErr != nil || res.localError { // A fault is not a definitive "no image": never settle absent, keep serving old state. // A chainless resolver (playlist/radio) records no step, so leave a fallback or explain is blank. if t := traceFrom(ctx); len(t.Steps()) == 0 { @@ -106,10 +110,10 @@ func (p *processor) acquire(ctx context.Context, item model.ArtworkQueueItem) (o t.add(TraceStep{Candidate: cmp.Or(res.source, "source"), Outcome: outcome}) } log.Debug(ctx, "Artwork: No image, but a source faulted; keeping previous state", - "kind", item.ItemKind, "id", item.ItemID, "extError", res.extError, "localError", res.localError) - return outcomeFailed, nil + "kind", item.ItemKind, "id", item.ItemID, "extErr", res.extErr, "localError", res.localError) + return outcomeFailed, nil, retryIn } - return writeAbsent(ctx, repo, item), nil + return writeAbsent(ctx, repo, item), nil, 0 } defer res.reader.Close() @@ -118,7 +122,7 @@ func (p *processor) acquire(ctx context.Context, item model.ArtworkQueueItem) (o if err != nil { traceStage(ctx, "read", err) log.Warn(ctx, "Artwork: Failed to read resolved image", "kind", item.ItemKind, "id", item.ItemID, "source", res.source, err) - return outcomeFailed, nil + return outcomeFailed, nil, retryIn } log.Debug(ctx, "Artwork: Read resolved image", "kind", item.ItemKind, "id", item.ItemID, "source", res.source, "bytes", len(data), "elapsed", time.Since(readStart)) @@ -128,7 +132,7 @@ func (p *processor) acquire(ctx context.Context, item model.ArtworkQueueItem) (o if err != nil { traceStage(ctx, "hash", err) log.Warn(ctx, "Artwork: Failed to hash image", "kind", item.ItemKind, "id", item.ItemID, err) - return outcomeFailed, nil + return outcomeFailed, nil, retryIn } log.Trace(ctx, "Artwork: Hashed image", "kind", item.ItemKind, "id", item.ItemID, "hash", hash, "bytes", len(data), "elapsed", time.Since(hashStart)) @@ -152,14 +156,14 @@ func (p *processor) acquire(ctx context.Context, item model.ArtworkQueueItem) (o if err != nil { traceStage(ctx, "decode", err) log.Warn(ctx, "Artwork: Failed to decode resolved image", "kind", item.ItemKind, "id", item.ItemID, err) - return outcomeFailed, nil + return outcomeFailed, nil, retryIn } log.Debug(ctx, "Artwork: Decoded new image", "kind", item.ItemKind, "id", item.ItemID, "hash", hash, "width", art.Width, "height", art.Height, "mime", art.Mime, "elapsed", time.Since(decodeStart)) default: traceStage(ctx, "lookup", err) log.Warn(ctx, "Artwork: Failed to look up image hash", "kind", item.ItemKind, "id", item.ItemID, err) - return outcomeFailed, nil + return outcomeFailed, nil, retryIn } art.SizeBytes = int64(len(data)) @@ -167,15 +171,15 @@ func (p *processor) acquire(ctx context.Context, item model.ArtworkQueueItem) (o if err != nil { traceStage(ctx, "store", err) log.Warn(ctx, "Artwork: Failed to persist resolved image", "kind", item.ItemKind, "id", item.ItemID, err) - return outcomeFailed, nil + return outcomeFailed, nil, retryIn } got = &acquired{ia: ia, mime: art.Mime, data: data} - if res.extError { + if res.extErr != nil { log.Debug(ctx, "Artwork: Serving a lower-priority source after an external failure", "kind", item.ItemKind, "id", item.ItemID, "source", res.source) - return outcomeFoundStale, got + return outcomeFoundStale, got, retryIn } - return outcomeFound, got + return outcomeFound, got, retryIn } // persist places the bytes and commits the rows referencing them, excluding Prune for that diff --git a/core/artwork/processor_test.go b/core/artwork/processor_test.go index 0ca5a308e..554ca08dc 100644 --- a/core/artwork/processor_test.go +++ b/core/artwork/processor_test.go @@ -90,7 +90,7 @@ var _ = Describe("processor.acquire", func() { {ID: "al1", Name: "Album", FolderIDs: []string{"f1"}}, }) - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al1"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al1"}) Expect(out).To(Equal(outcomeFound)) ia, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "al1", model.ImageTypePrimary) @@ -127,7 +127,7 @@ var _ = Describe("processor.acquire", func() { {ID: "alL1", Name: "Album", FolderIDs: []string{"f1"}}, }) - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alL1"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alL1"}) Expect(out).To(Equal(outcomeFound)) Expect(lock.locks).To(BeNumerically(">", 0), "the write window must exclude prune") Expect(lock.held()).To(BeFalse(), "the window must close before acquire returns") @@ -141,7 +141,7 @@ var _ = Describe("processor.acquire", func() { {ID: "alL2", Name: "Album", FolderIDs: []string{"f1"}}, }) - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alL2"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alL2"}) Expect(out).To(Equal(outcomeAbsent)) Expect(lock.locks).To(BeZero()) }) @@ -153,7 +153,7 @@ var _ = Describe("processor.acquire", func() { }) folderRepo.result = nil - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al2"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al2"}) Expect(out).To(Equal(outcomeFound)) ia, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "al2", model.ImageTypePrimary) @@ -176,7 +176,7 @@ var _ = Describe("processor.acquire", func() { {ID: "al3", Name: "Album"}, }) - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al3"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al3"}) Expect(out).To(Equal(outcomeAbsent)) ia, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "al3", model.ImageTypePrimary) @@ -197,7 +197,7 @@ var _ = Describe("processor.acquire", func() { {ID: "al-io", Name: "Album", FolderIDs: []string{"f1"}}, }) - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al-io"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al-io"}) Expect(out).To(Equal(outcomeFailed)) _, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "al-io", model.ImageTypePrimary) @@ -222,7 +222,7 @@ var _ = Describe("processor.acquire", func() { DeferCleanup(func() { _ = os.Chmod(upload, 0o600) }) radioRepo.Data["ra-io"] = &model.Radio{ID: "ra-io", Name: "Station", UploadedImage: "ra-io.jpg"} - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "ra", ItemID: "ra-io"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "ra", ItemID: "ra-io"}) Expect(out).To(Equal(outcomeFailed)) _, err := artRepo.GetItemArtwork(model.KindRadioArtwork, "ra-io", model.ImageTypePrimary) @@ -249,7 +249,7 @@ var _ = Describe("processor.acquire", func() { radioRepo.Data["ra-tr"] = &model.Radio{ID: "ra-tr", Name: "Station", UploadedImage: "ra-tr.jpg"} trace := &ChainTrace{} - out, _ := proc.acquire(withTrace(ctx, trace), model.ArtworkQueueItem{ItemKind: "ra", ItemID: "ra-tr"}) + out, _, _ := proc.acquire(withTrace(ctx, trace), model.ArtworkQueueItem{ItemKind: "ra", ItemID: "ra-tr"}) Expect(out).To(Equal(outcomeFailed)) steps := trace.Steps() @@ -265,13 +265,26 @@ var _ = Describe("processor.acquire", func() { }) imageAgents(&fakeImageAgent{name: "failAgent", err: errors.New("agent timed out")}) - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al4"}) + out, _, retryIn := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al4"}) Expect(out).To(Equal(outcomeFailed)) + Expect(retryIn).To(BeZero(), "a plain failure asks for no particular delay") _, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "al4", model.ImageTypePrimary) Expect(err).To(MatchError(model.ErrNotFound)) }) + It("failed-on-extError: reports the delay a throttled provider asked for", func() { + conf.Server.CoverArtPriority = "external" + ds.MockedAlbum.(*tests.MockAlbumRepo).SetData(model.Albums{ + {ID: "al4r", Name: "Album"}, + }) + imageAgents(&fakeImageAgent{name: "throttled", err: &agents.RetryLaterError{RetryIn: 42 * time.Second}}) + + out, _, retryIn := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al4r"}) + Expect(out).To(Equal(outcomeFailed)) + Expect(retryIn).To(Equal(42 * time.Second)) + }) + It("found-stale: a fallback hit after a transient external failure persists state and returns outcomeFoundStale", func() { conf.Server.CoverArtPriority = "external, cover.jpg" folderRepo.result = []model.Folder{{ @@ -283,7 +296,7 @@ var _ = Describe("processor.acquire", func() { }) imageAgents(&fakeImageAgent{name: "failAgent", err: errors.New("agent timed out")}) - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alstale"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alstale"}) Expect(out).To(Equal(outcomeFoundStale)) ia, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "alstale", model.ImageTypePrimary) @@ -300,7 +313,7 @@ var _ = Describe("processor.acquire", func() { ds.MockedAlbum.(*tests.MockAlbumRepo).SetData(model.Albums{{ID: "alU", Name: "Album", FolderIDs: []string{"f1"}}}) folderRepo.result = []model.Folder{{Path: "album", ImageFiles: []string{"cover.jpg"}}} - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alU"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alU"}) Expect(out).To(Equal(outcomeFound)) ia, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "alU", model.ImageTypePrimary) @@ -320,7 +333,7 @@ var _ = Describe("processor.acquire", func() { ds.MockedAlbum.(*tests.MockAlbumRepo).SetData(model.Albums{{ID: "alE", Name: "Album", FolderIDs: []string{"f1"}}}) folderRepo.result = []model.Folder{{Path: "album", ImageFiles: []string{"cover.jpg"}}} - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alE"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alE"}) Expect(out).To(Equal(outcomeFailed)) _, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "alE", model.ImageTypePrimary) @@ -338,7 +351,7 @@ var _ = Describe("processor.acquire", func() { ds.MockedAlbum.(*tests.MockAlbumRepo).SetData(model.Albums{{ID: "alX", Name: "Album"}}) imageAgents(&fakeImageAgent{name: "deezerFake", imgs: []agents.ExternalImage{{URL: srv.URL, Size: 500}}}) - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alX"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alX"}) Expect(out).To(Equal(outcomeFailed)) _, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "alX", model.ImageTypePrimary) @@ -357,7 +370,7 @@ var _ = Describe("processor.acquire", func() { ds.MockedAlbum.(*tests.MockAlbumRepo).SetData(model.Albums{{ID: "alext", Name: "Album"}}) imageAgents(&fakeImageAgent{name: "deezerFake", imgs: []agents.ExternalImage{{URL: srv.URL, Size: 500}}}) - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alext"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alext"}) Expect(out).To(Equal(outcomeFound)) ia, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "alext", model.ImageTypePrimary) @@ -382,7 +395,7 @@ var _ = Describe("processor.acquire", func() { {ID: "al6", Name: "Album B", FolderIDs: []string{"f1"}}, }) - out1, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al5"}) + out1, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al5"}) Expect(out1).To(Equal(outcomeFound)) ia1, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "al5", model.ImageTypePrimary) Expect(err).ToNot(HaveOccurred()) @@ -392,7 +405,7 @@ var _ = Describe("processor.acquire", func() { poisoned.BlurHash = "SENTINEL" artRepo.Data[ia1.Hash] = poisoned - out2, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al6"}) + out2, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al6"}) Expect(out2).To(Equal(outcomeFound)) ia2, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "al6", model.ImageTypePrimary) Expect(err).ToNot(HaveOccurred()) @@ -422,7 +435,7 @@ var _ = Describe("processor.acquire", func() { }) folderRepo.result = []model.Folder{{Path: "album-a", ImageFiles: []string{"cover.jpg"}}} - outN, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alA"}) + outN, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alA"}) Expect(outN).To(Equal(outcomeFound)) iaA, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "alA", model.ImageTypePrimary) Expect(err).ToNot(HaveOccurred()) @@ -436,7 +449,7 @@ var _ = Describe("processor.acquire", func() { artRepo.Data[iaA.Hash] = poisoned folderRepo.result = []model.Folder{{Path: "album-b", ImageFiles: []string{"cover.jpg"}}} - outN, _ = proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alB"}) + outN, _, _ = proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alB"}) Expect(outN).To(Equal(outcomeFound)) iaB, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "alB", model.ImageTypePrimary) Expect(err).ToNot(HaveOccurred()) @@ -467,7 +480,7 @@ var _ = Describe("processor.acquire", func() { radioRepo.Data = map[string]*model.Radio{"ra1": {ID: "ra1", Name: "Radio", UploadedImage: "ra1_test.jpg"}} ds.MockedRadio = radioRepo - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "ra", ItemID: "ra1"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "ra", ItemID: "ra1"}) Expect(out).To(Equal(outcomeFailed)) _, err := artRepo.GetItemArtwork(model.KindRadioArtwork, "ra1", model.ImageTypePrimary) @@ -488,7 +501,7 @@ var _ = Describe("processor.acquire", func() { radioRepo.Data = map[string]*model.Radio{"big": {ID: "big", Name: "Radio", UploadedImage: "big_test.jpg"}} ds.MockedRadio = radioRepo - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "ra", ItemID: "big"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "ra", ItemID: "big"}) Expect(out).To(Equal(outcomeFailed)) _, err = artRepo.GetItemArtwork(model.KindRadioArtwork, "big", model.ImageTypePrimary) @@ -554,7 +567,7 @@ var _ = Describe("processor.acquire", func() { Expect(err).ToNot(HaveOccurred()) Expect(artRepo.PutImage(&model.Artwork{Hash: hash, Mime: "application/octet-stream"})).To(Succeed()) - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alM"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alM"}) Expect(out).To(Equal(outcomeFound)) upgraded, err := artRepo.GetImage(hash) @@ -574,7 +587,7 @@ var _ = Describe("processor.acquire", func() { Expect(os.WriteFile(blockedRoot, []byte("x"), 0600)).To(Succeed()) proc.store = NewImageStore(blockedRoot) - out, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al7"}) + out, _, _ := proc.acquire(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al7"}) Expect(out).To(Equal(outcomeFailed)) _, err := artRepo.GetItemArtwork(model.KindAlbumArtwork, "al7", model.ImageTypePrimary) diff --git a/core/artwork/resolve.go b/core/artwork/resolve.go index 6663679fa..e7a2d3765 100644 --- a/core/artwork/resolve.go +++ b/core/artwork/resolve.go @@ -25,9 +25,9 @@ type resolution struct { source string // model.ItemArtwork.Source value: "folder", "embedded", "external", "upload", "generated" sourcePath string // backing library/upload file (folder/upload: the image; embedded: the audio file); "" otherwise refMtime int64 // sourcePath mtime (unix-nanoseconds) at resolution; 0 when no sourcePath - // external source errored/timed out. With no reader it forces failed (never absent); - // on a hit a higher-priority external step failed—serve this, but retry later. - extError bool + // a faulted external source, carrying the provider's requested delay when it named one. + // With no reader it forces failed (never absent); on a hit, serve this but retry later. + extErr error // a local source that should have been readable wasn't. With no reader it forces failed, // so a transient I/O fault never records absent. localError bool @@ -36,14 +36,15 @@ type resolution struct { // chainState carries what a priority walk has seen so far. A hit takes extErr with it so a // transient external failure still retries; localErr is dropped, as the scanner re-lists changes. type chainState struct { - extErr, localErr bool - trace *ChainTrace // nil only where no caller attached one + extErr error + localErr bool + trace *ChainTrace // nil only where no caller attached one } // try stamps the accumulated external failure onto a hit, and records the miss otherwise. func (c *chainState) try(candidate string, res resolution, ok bool) (resolution, bool) { if ok { - res.extError = c.extErr + res.extErr = c.extErr c.record(candidate, OutcomeHit, res.sourcePath) return res, true } @@ -62,7 +63,7 @@ func (c *chainState) record(candidate string, out Outcome, detail string) { // exhausted is the outcome when no source in the chain yielded an image. func (c *chainState) exhausted() resolution { - return resolution{extError: c.extErr, localError: c.localErr} + return resolution{extErr: c.extErr, localError: c.localErr} } // externalSource holds the agents to ask and the rate limiter/circuit breaker to ask them through. @@ -181,16 +182,16 @@ func chainFetchesExternal(priority string) bool { // Album and artist fetches stop here when the resolver is local-only, rather than at each point in // the chain walk; resolvePlaylist gates the third network path, the m3u image URL, itself. -func (r *resolver) fetchExternalAlbum(ctx context.Context, al model.Album) (io.ReadCloser, string, bool) { +func (r *resolver) fetchExternalAlbum(ctx context.Context, al model.Album) (io.ReadCloser, string, error) { if r.ext == nil { - return nil, "", false + return nil, "", nil } return fetchAlbumImage(ctx, r.ext.agents, r.ext.gate, al) } -func (r *resolver) fetchExternalArtist(ctx context.Context, ar model.Artist) (io.ReadCloser, string, bool) { +func (r *resolver) fetchExternalArtist(ctx context.Context, ar model.Artist) (io.ReadCloser, string, error) { if r.ext == nil { - return nil, "", false + return nil, "", nil } return fetchArtistImage(ctx, r.ext.agents, r.ext.gate, ar) } @@ -223,10 +224,10 @@ func (r *resolver) resolveAlbum(ctx context.Context, albumID string) (resolution return res, nil } case pattern == externalCandidate: - if rd, name, isErr := r.fetchExternalAlbum(ctx, *al); rd != nil { + if rd, name, err := r.fetchExternalAlbum(ctx, *al); rd != nil { return resolution{reader: rd, source: ExternalPrefix + name}, nil - } else if isErr { - chain.extErr = true + } else if err != nil { + chain.extErr = longerRetry(chain.extErr, err) } case len(imgFiles) > 0: res, ok := resolveFolderFile(ctx, lib, imgFiles, pattern) @@ -285,10 +286,10 @@ func (r *resolver) resolveArtist(ctx context.Context, artistID string) (resoluti } switch { case pattern == externalCandidate: - if rd, name, isErr := r.fetchExternalArtist(ctx, *ar); rd != nil { + if rd, name, err := r.fetchExternalArtist(ctx, *ar); rd != nil { return resolution{reader: rd, source: ExternalPrefix + name}, nil - } else if isErr { - chain.extErr = true + } else if err != nil { + chain.extErr = longerRetry(chain.extErr, err) } case pattern == "image-folder": res, ok := resolveArtistImageFolder(ar) @@ -332,7 +333,7 @@ func (r *resolver) resolvePlaylist(ctx context.Context, playlistID string) (reso return resolution{}, err } - var extErr bool + var extErr error for _, src := range []struct{ path, source string }{ {pl.UploadedImagePath(), "upload"}, {findPlaylistSidecarPath(ctx, pl.Path), "folder"}, @@ -366,7 +367,7 @@ func (r *resolver) resolvePlaylist(ctx context.Context, playlistID string) (reso if res, ok, err := resolveExternalStep(r.ext.gate, "m3u", sf); ok { return res, nil } else if err != nil { - extErr = true + extErr = longerRetry(extErr, err) // Record it here with its detail: once album sampling adds its own steps, the processor's // empty-trace fallback no longer fires, and the error that forced the retry would be lost. traceFrom(ctx).add(TraceStep{Candidate: ExternalPrefix + "m3u", Outcome: OutcomeError, Detail: err.Error()}) @@ -389,8 +390,8 @@ func (r *resolver) resolvePlaylist(ctx context.Context, playlistID string) (reso } continue } - if res.extError { - extErr = true + if res.extErr != nil { + extErr = longerRetry(extErr, res.extErr) } if res.reader == nil { continue @@ -409,7 +410,7 @@ func (r *resolver) resolvePlaylist(ctx context.Context, playlistID string) (reso if tileErr != nil { return resolution{}, fmt.Errorf("resolvePlaylist: sampled album art failed: %w", tileErr) } - return resolution{extError: extErr}, nil + return resolution{extErr: extErr}, nil } // Grow to 4 tiles by repeating what we have. switch len(tiles) { @@ -420,9 +421,9 @@ func (r *resolver) resolvePlaylist(ctx context.Context, playlistID string) (reso } grid, err := assembleTiles(tiles) if err != nil { - return resolution{extError: extErr}, nil //nolint:nilerr // encode failure is a soft "no image", not a resolution error + return resolution{extErr: extErr}, nil //nolint:nilerr // encode failure is a soft "no image", not a resolution error } - return resolution{reader: grid, source: "generated", extError: extErr}, nil + return resolution{reader: grid, source: "generated", extErr: extErr}, nil } // resolveRadio serves only an uploaded image; there is no fallback. diff --git a/core/artwork/resolve_test.go b/core/artwork/resolve_test.go index 236e76b9b..402a11363 100644 --- a/core/artwork/resolve_test.go +++ b/core/artwork/resolve_test.go @@ -100,7 +100,7 @@ var _ = Describe("resolveItem", func() { Expect(res.source).To(Equal("embedded")) Expect(filepath.ToSlash(res.sourcePath)).To(HaveSuffix("tests/fixtures/artist/an-album/test.mp3")) Expect(res.refMtime).To(BeNumerically(">", 0)) - Expect(res.extError).To(BeFalse()) + Expect(res.extErr).ToNot(HaveOccurred()) }) It("resolves absent when the track has no cover art", func() { @@ -111,7 +111,7 @@ var _ = Describe("resolveItem", func() { res, err := newResolver(ds, ag, ffm, nil).resolve(ctx, model.ArtworkQueueItem{ItemKind: "mf", ItemID: "mf2"}) Expect(err).ToNot(HaveOccurred()) Expect(res.reader).To(BeNil()) - Expect(res.extError).To(BeFalse()) + Expect(res.extErr).ToNot(HaveOccurred()) }) It("resolves absent when media file cover art is disabled", func() { @@ -154,7 +154,7 @@ var _ = Describe("resolveItem", func() { Expect(res.source).To(Equal("folder")) Expect(filepath.ToSlash(res.sourcePath)).To(HaveSuffix("tests/fixtures/artist/an-album/cover.jpg")) Expect(res.refMtime).To(BeNumerically(">", 0)) - Expect(res.extError).To(BeFalse()) + Expect(res.extErr).ToNot(HaveOccurred()) }) It("falls back to embedded art when no folder image matches", func() { @@ -172,7 +172,7 @@ var _ = Describe("resolveItem", func() { Expect(res.refMtime).To(BeNumerically(">", 0)) }) - It("sets extError when the external source errors without being not-found", func() { + It("sets extErr when the external source errors without being not-found", func() { conf.Server.CoverArtPriority = "external" ds.MockedAlbum.(*tests.MockAlbumRepo).SetData(model.Albums{ {ID: "al3", Name: "Album"}, @@ -182,10 +182,10 @@ var _ = Describe("resolveItem", func() { res, err := newResolver(ds, ag, ffm, nil).resolve(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al3"}) Expect(err).ToNot(HaveOccurred()) Expect(res.reader).To(BeNil()) - Expect(res.extError).To(BeTrue()) + Expect(res.extErr).To(HaveOccurred()) }) - It("does not set extError when the external source reports not-found", func() { + It("does not set extErr when the external source reports not-found", func() { conf.Server.CoverArtPriority = "external" ds.MockedAlbum.(*tests.MockAlbumRepo).SetData(model.Albums{ {ID: "al4", Name: "Album"}, @@ -195,10 +195,10 @@ var _ = Describe("resolveItem", func() { res, err := newResolver(ds, ag, ffm, nil).resolve(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al4"}) Expect(err).ToNot(HaveOccurred()) Expect(res.reader).To(BeNil()) - Expect(res.extError).To(BeFalse()) + Expect(res.extErr).ToNot(HaveOccurred()) }) - It("carries extError onto a fallback folder hit after a transient external failure", func() { + It("carries extErr onto a fallback folder hit after a transient external failure", func() { conf.Server.CoverArtPriority = "external, cover.jpg" folderRepo.result = []model.Folder{{ Path: "tests/fixtures/artist/an-album", @@ -214,10 +214,10 @@ var _ = Describe("resolveItem", func() { Expect(res.reader).ToNot(BeNil()) defer res.reader.Close() Expect(res.source).To(Equal("folder")) - Expect(res.extError).To(BeTrue()) + Expect(res.extErr).To(HaveOccurred()) }) - It("does not carry extError onto a fallback folder hit after a definitive external not-found", func() { + It("does not carry extErr onto a fallback folder hit after a definitive external not-found", func() { conf.Server.CoverArtPriority = "external, cover.jpg" folderRepo.result = []model.Folder{{ Path: "tests/fixtures/artist/an-album", @@ -233,7 +233,7 @@ var _ = Describe("resolveItem", func() { Expect(res.reader).ToNot(BeNil()) defer res.reader.Close() Expect(res.source).To(Equal("folder")) - Expect(res.extError).To(BeFalse()) + Expect(res.extErr).ToNot(HaveOccurred()) }) It("routes the external step through the injected gate, keyed by agent name", func() { @@ -250,7 +250,7 @@ var _ = Describe("resolveItem", func() { res, err := newResolver(ds, ag, ffm, gate).resolve(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "al5"}) Expect(err).ToNot(HaveOccurred()) - Expect(res.extError).To(BeTrue()) + Expect(res.extErr).To(HaveOccurred()) Expect(gatedNames).To(Equal([]string{"failAgent"})) }) }) @@ -298,7 +298,7 @@ var _ = Describe("resolveItem", func() { Expect(filepath.ToSlash(res.sourcePath)).To(HaveSuffix("tests/fixtures/artist/an-album/artist.png")) }) - It("sets extError when the external source errors without being not-found", func() { + It("sets extErr when the external source errors without being not-found", func() { conf.Server.ArtistArtPriority = "external" artistRepo := tests.CreateMockArtistRepo() artistRepo.SetData(model.Artists{{ID: "ar3", Name: "Artist"}}) @@ -308,10 +308,10 @@ var _ = Describe("resolveItem", func() { res, err := newResolver(ds, ag, ffm, nil).resolve(ctx, model.ArtworkQueueItem{ItemKind: "ar", ItemID: "ar3"}) Expect(err).ToNot(HaveOccurred()) Expect(res.reader).To(BeNil()) - Expect(res.extError).To(BeTrue()) + Expect(res.extErr).To(HaveOccurred()) }) - It("does not set extError when the external source reports not-found", func() { + It("does not set extErr when the external source reports not-found", func() { conf.Server.ArtistArtPriority = "external" artistRepo := tests.CreateMockArtistRepo() artistRepo.SetData(model.Artists{{ID: "ar4", Name: "Artist"}}) @@ -321,7 +321,7 @@ var _ = Describe("resolveItem", func() { res, err := newResolver(ds, ag, ffm, nil).resolve(ctx, model.ArtworkQueueItem{ItemKind: "ar", ItemID: "ar4"}) Expect(err).ToNot(HaveOccurred()) Expect(res.reader).To(BeNil()) - Expect(res.extError).To(BeFalse()) + Expect(res.extErr).ToNot(HaveOccurred()) }) It("routes the external step through the injected gate, keyed by agent name", func() { @@ -338,7 +338,7 @@ var _ = Describe("resolveItem", func() { res, err := newResolver(ds, ag, ffm, gate).resolve(ctx, model.ArtworkQueueItem{ItemKind: "ar", ItemID: "ar5"}) Expect(err).ToNot(HaveOccurred()) - Expect(res.extError).To(BeTrue()) + Expect(res.extErr).To(HaveOccurred()) Expect(gatedNames).To(Equal([]string{"failAgent"})) }) }) @@ -516,7 +516,7 @@ var _ = Describe("resolveItem", func() { res, err := newResolver(ds, ag, ffm, gate).resolve(ctx, model.ArtworkQueueItem{ItemKind: "pl", ItemID: "ple"}) Expect(err).ToNot(HaveOccurred()) Expect(res.reader).To(BeNil()) - Expect(res.extError).To(BeTrue()) + Expect(res.extErr).To(HaveOccurred()) Expect(gatedNames).To(Equal([]string{"m3u"}), "the playlist URL fetch is gated under \"m3u\"") }) @@ -537,7 +537,7 @@ var _ = Describe("resolveItem", func() { res, err := newResolver(ds, ag, ffm, gate).resolve(withTrace(ctx, trace), model.ArtworkQueueItem{ItemKind: "pl", ItemID: "plm3u"}) Expect(err).ToNot(HaveOccurred()) - Expect(res.extError).To(BeTrue()) + Expect(res.extErr).To(HaveOccurred()) steps := trace.Steps() var m3u *TraceStep @@ -562,7 +562,7 @@ var _ = Describe("resolveItem", func() { res, err := newResolver(ds, ag, ffm, nil).resolve(ctx, model.ArtworkQueueItem{ItemKind: "pl", ItemID: "plm"}) Expect(err).ToNot(HaveOccurred()) Expect(res.reader).To(BeNil()) - Expect(res.extError).To(BeFalse()) + Expect(res.extErr).ToNot(HaveOccurred()) }) It("treats an ExternalImageURL 404 as a definitive miss and falls through to the grid", func() { @@ -582,7 +582,7 @@ var _ = Describe("resolveItem", func() { Expect(res.reader).ToNot(BeNil()) defer res.reader.Close() Expect(res.source).To(Equal("generated")) - Expect(res.extError).To(BeFalse()) + Expect(res.extErr).ToNot(HaveOccurred()) }) // A local resolver holds no agents: reaching the external branch would panic, not degrade. @@ -594,7 +594,7 @@ var _ = Describe("resolveItem", func() { res, err := newLocalResolver(ds, ffm).resolve(ctx, model.ArtworkQueueItem{ItemKind: "al", ItemID: "alx"}) Expect(err).ToNot(HaveOccurred()) Expect(res.reader).To(BeNil()) - Expect(res.extError).To(BeFalse(), "a skipped step is not a failed one") + Expect(res.extErr).ToNot(HaveOccurred(), "a skipped step is not a failed one") }) // The worker resolving the same playlist is asserted alongside, so this cannot pass vacuously. @@ -642,7 +642,7 @@ var _ = Describe("resolveItem", func() { res, err := newResolver(ds, ag, ffm, nil).resolve(ctx, model.ArtworkQueueItem{ItemKind: "pl", ItemID: "pl500"}) Expect(err).ToNot(HaveOccurred()) Expect(res.reader).To(BeNil()) - Expect(res.extError).To(BeTrue()) + Expect(res.extErr).To(HaveOccurred()) }) It("yields an empty resolution when no album has art", func() { diff --git a/core/artwork/worker.go b/core/artwork/worker.go index 0358708c0..bea478aa5 100644 --- a/core/artwork/worker.go +++ b/core/artwork/worker.go @@ -241,7 +241,7 @@ func (w *Worker) process(ctx context.Context, item model.ArtworkQueueItem) (outc item.ImageType = cmp.Or(item.ImageType, model.ImageTypePrimary) trace := &ChainTrace{} ctx = withTrace(ctx, trace) - out, got := w.proc.acquire(ctx, item) + out, got, retryIn := w.proc.acquire(ctx, item) queue := w.proc.ds.ArtworkQueue(ctx) switch out { @@ -252,7 +252,7 @@ func (w *Worker) process(ctx context.Context, item model.ArtworkQueueItem) (outc log.Warn(ctx, "Artwork: Could not delete processed queue item", "kind", item.ItemKind, "id", item.ItemID, err) } case outcomeFoundStale, outcomeFailed: - retryAt := time.Now().Add(backoff(item.Attempts)) + retryAt := time.Now().Add(retryDelay(item.Attempts, retryIn)) encoded := trace.encode("") if retryAt.Before(item.EnqueuedAt.Add(giveUpAfter)) { // A mid-flight re-enqueue reset retry_at; stale backoff must not stomp its @@ -341,3 +341,8 @@ func backoffFor(attempts int, jitter float64) time.Duration { func backoff(attempts int) time.Duration { return backoffFor(attempts, rand.Float64()*0.8-0.4) //nolint:gosec // retry jitter, not security-sensitive } + +// retryDelay is how long a failed item waits: our backoff, unless the provider asked for longer. +func retryDelay(attempts int, hint time.Duration) time.Duration { + return max(backoff(attempts), hint) +} diff --git a/core/artwork/worker_soak_test.go b/core/artwork/worker_soak_test.go index eb7346102..803cc2dfe 100644 --- a/core/artwork/worker_soak_test.go +++ b/core/artwork/worker_soak_test.go @@ -95,7 +95,7 @@ var _ = Describe("Worker soak", func() { start := time.Now() for i := range soakCycles { it := items[i%len(items)] - out, _ := proc.acquire(context.Background(), it) + out, _, _ := proc.acquire(context.Background(), it) // Read-back exercises the surfaces a caller would use after acquisition. if out == outcomeFound { diff --git a/core/artwork/worker_test.go b/core/artwork/worker_test.go index 248e400e1..b0ef665fc 100644 --- a/core/artwork/worker_test.go +++ b/core/artwork/worker_test.go @@ -245,6 +245,23 @@ var _ = Describe("Worker", func() { Expect(err).To(MatchError(model.ErrNotFound), "a timeout must never settle on absent") }) + It("reschedules past the provider's requested delay when it exceeds the backoff", func() { + conf.Server.CoverArtPriority = "external" + ds.MockedAlbum.(*tests.MockAlbumRepo).SetData(model.Albums{{ID: "al9", Name: "Album"}}) + // Well above backoff(0)'s jittered ceiling, so only the hint can produce this retry_at. + const askedFor = 90 * time.Minute + imageAgents(&fakeImageAgent{name: "throttledAgent", err: &agents.RetryLaterError{RetryIn: askedFor}}) + Expect(queueRepo.Enqueue(model.ArtworkQueueItem{ItemKind: "al", ItemID: "al9"})).To(Succeed()) + + n, err := w.drain(ctx, 2) + Expect(err).ToNot(HaveOccurred()) + Expect(n).To(Equal(1)) + + it := findQueued(queueRepo, "al", "al9") + Expect(it).ToNot(BeNil()) + Expect(it.RetryAt).To(BeTemporally("~", time.Now().Add(askedFor), time.Minute)) + }) + It("reschedules a found-stale item via MarkFailed while keeping its served state", func() { conf.Server.CoverArtPriority = "external, cover.jpg" folderRepo.result = []model.Folder{{ @@ -911,3 +928,19 @@ var _ = Describe("backoff", func() { } }) }) + +var _ = Describe("retryDelay", func() { + It("uses the backoff schedule when the provider asked for nothing", func() { + d := retryDelay(0, 0) + Expect(d).To(BeNumerically(">=", 3*time.Second)) + Expect(d).To(BeNumerically("<=", 7*time.Second)) + }) + + It("waits the provider's delay when it is longer than the backoff", func() { + Expect(retryDelay(0, time.Hour)).To(Equal(time.Hour)) + }) + + It("keeps the backoff when it is longer than the provider's delay", func() { + Expect(retryDelay(4, time.Second)).To(BeNumerically(">=", 3*time.Second)) + }) +}) diff --git a/core/external/provider.go b/core/external/provider.go index 5c46dc644..3a3f4bd46 100644 --- a/core/external/provider.go +++ b/core/external/provider.go @@ -148,7 +148,8 @@ func (e *provider) populateAlbumInfo(ctx context.Context, album auxAlbum) (auxAl start := time.Now() albumName := album.Name() info, err := e.ag.GetAlbumInfo(ctx, albumName, album.AlbumArtist, album.MbzAlbumID) - if errors.Is(err, agents.ErrNotFound) { + // Throttled joins not-found: no answer to store, and an unstamped timestamp retries next call. + if errors.Is(err, agents.ErrNotFound) || errors.Is(err, agents.ErrRetryLater) { return album, nil } if err != nil { @@ -253,28 +254,37 @@ func (e *provider) populateArtistInfo(ctx context.Context, artist auxArtist) (au start := time.Now() // Get MBID first, if it is not yet available artistName := artist.Name() + var mbidErr error if artist.MbzArtistID == "" { mbid, err := e.ag.GetArtistMBID(ctx, artist.ID, artistName) + mbidErr = err if mbid != "" && err == nil { artist.MbzArtistID = mbid } } - // Call all registered agents and collect information + // Call all registered agents and collect information. The group carries no context, so a + // returned error does not cancel the siblings; only throttling is reported back. g := errgroup.Group{} g.SetLimit(2) - g.Go(func() error { _ = e.callGetImage(ctx, e.ag, &artist); return nil }) - g.Go(func() error { e.callGetBiography(ctx, e.ag, &artist); return nil }) - g.Go(func() error { e.callGetURL(ctx, e.ag, &artist); return nil }) - g.Go(func() error { e.callGetSimilarArtists(ctx, e.ag, &artist, maxSimilarArtists, true); return nil }) - _ = g.Wait() + g.Go(func() error { return retryLaterOnly(e.callGetImage(ctx, e.ag, &artist)) }) + g.Go(func() error { return retryLaterOnly(e.callGetBiography(ctx, e.ag, &artist)) }) + g.Go(func() error { return retryLaterOnly(e.callGetURL(ctx, e.ag, &artist)) }) + g.Go(func() error { + return retryLaterOnly(e.callGetSimilarArtists(ctx, e.ag, &artist, maxSimilarArtists, true)) + }) + throttled := errors.Is(g.Wait(), agents.ErrRetryLater) || errors.Is(mbidErr, agents.ErrRetryLater) if utils.IsCtxDone(ctx) { log.Warn(ctx, "ArtistInfo update canceled", "id", artist.ID, "name", artistName, "elapsed", time.Since(start), ctx.Err()) return artist, ctx.Err() } - artist.ExternalInfoUpdatedAt = new(time.Now()) + // A throttled round keeps the previous timestamp, so the next call retries instead of + // serving an empty cache entry for the whole TTL. + if !throttled { + artist.ExternalInfoUpdatedAt = new(time.Now()) + } err := e.ds.Artist(ctx).UpdateExternalInfo(&artist.Artist) if err != nil { log.Error(ctx, "Error trying to update artist external information", "id", artist.ID, "name", artistName, @@ -334,8 +344,9 @@ func (e *provider) TopSongs(ctx context.Context, artistName, id string, count in songs, err := e.getMatchingTopSongs(ctx, e.ag, artist, count) if err != nil { switch { - case errors.Is(err, agents.ErrNotFound): - log.Trace(ctx, "TopSongs not found", "name", artistName) + // Throttled is not an answer, but the caller keeps the empty 200 it got before. + case errors.Is(err, agents.ErrNotFound), errors.Is(err, agents.ErrRetryLater): + log.Trace(ctx, "TopSongs not found", "name", artistName, err) return nil, model.ErrNotFound case errors.Is(err, context.Canceled): log.Debug(ctx, "TopSongs call canceled", err) @@ -385,22 +396,33 @@ func (e *provider) getMatchingTopSongs(ctx context.Context, agent agents.ArtistT return mfs, nil } -func (e *provider) callGetURL(ctx context.Context, agent agents.ArtistURLRetriever, artist *auxArtist) { - artisURL, err := agent.GetArtistURL(ctx, artist.ID, artist.Name(), artist.MbzArtistID) - if err != nil { - return +// retryLaterOnly discards every failure the caller does not act on, so errgroup's +// first-error slot is reserved for the throttling signal. +func retryLaterOnly(err error) error { + if errors.Is(err, agents.ErrRetryLater) { + return err } - artist.ExternalUrl = artisURL + return nil } -func (e *provider) callGetBiography(ctx context.Context, agent agents.ArtistBiographyRetriever, artist *auxArtist) { +func (e *provider) callGetURL(ctx context.Context, agent agents.ArtistURLRetriever, artist *auxArtist) error { + artisURL, err := agent.GetArtistURL(ctx, artist.ID, artist.Name(), artist.MbzArtistID) + if err != nil { + return err + } + artist.ExternalUrl = artisURL + return nil +} + +func (e *provider) callGetBiography(ctx context.Context, agent agents.ArtistBiographyRetriever, artist *auxArtist) error { bio, err := agent.GetArtistBiography(ctx, artist.ID, artist.Name(), artist.MbzArtistID) if err != nil { - return + return err } bio = str.SanitizeText(bio) bio = strings.ReplaceAll(bio, "\n", " ") artist.Biography = strings.ReplaceAll(bio, "(retry_later[:seconds])` token, which is +// all a plugin fault carries back across the WASM boundary. The capability is part of the +// pattern, so another capability's token in the same message cannot mask this one. The leading +// \b keeps a superstring like `useragent(retry_later)` from matching `agent`. +var ( + agentRetryLaterRe = retryLaterRe("agent") + scrobblerRetryLaterRe = retryLaterRe("scrobbler") +) + +func retryLaterRe(capability string) *regexp.Regexp { + return regexp.MustCompile(`\b` + capability + `\(retry_later(?::(\d+))?\)`) +} + +// parseRetryLater reports whether msg carries the capability's retry_later token, with its delay. +func parseRetryLater(re *regexp.Regexp, msg string) (*agents.RetryLaterError, bool) { + m := re.FindStringSubmatch(msg) + if m == nil { + return nil, false + } + return &agents.RetryLaterError{RetryIn: agents.ParseRetryIn(m[1])}, true +} diff --git a/plugins/capabilities/metadata_agent.go b/plugins/capabilities/metadata_agent.go index 72cb1622f..8fec7f5a8 100644 --- a/plugins/capabilities/metadata_agent.go +++ b/plugins/capabilities/metadata_agent.go @@ -224,3 +224,15 @@ type SimilarSongsResponse struct { // Songs is the list of similar songs. Songs []types.SongRef `json:"songs"` } + +// MetadataAgentError represents an error type for metadata agent operations. +type MetadataAgentError string + +const ( + // MetadataAgentErrorRetryLater indicates the provider is throttling; retry later. + // Append ":" inside the parentheses to request a specific delay. + MetadataAgentErrorRetryLater MetadataAgentError = "agent(retry_later)" +) + +// Error implements the error interface for MetadataAgentError. +func (e MetadataAgentError) Error() string { return string(e) } diff --git a/plugins/metadata_agent.go b/plugins/metadata_agent.go index 607926438..17062ba6b 100644 --- a/plugins/metadata_agent.go +++ b/plugins/metadata_agent.go @@ -56,6 +56,9 @@ func agentErr(err error) error { if errors.Is(err, errNotImplemented) || errors.Is(err, errFunctionNotFound) { return errors.Join(agents.ErrNotFound, err) } + if retryLater, ok := parseRetryLater(agentRetryLaterRe, err.Error()); ok { + return errors.Join(retryLater, err) + } return err } diff --git a/plugins/metadata_agent_test.go b/plugins/metadata_agent_test.go index 2dc67d41c..a7a0aa8b8 100644 --- a/plugins/metadata_agent_test.go +++ b/plugins/metadata_agent_test.go @@ -5,6 +5,7 @@ package plugins import ( "errors" "fmt" + "time" "github.com/navidrome/navidrome/core/agents" "github.com/navidrome/navidrome/plugins/capabilities" @@ -31,6 +32,31 @@ var _ = Describe("agentErr", func() { Entry("a non-zero exit is a fault", errors.New("plugin call exited with code 1"), false), ) + + DescribeTable("agentErr retry-later", + func(msg string, wantDelay time.Duration) { + err := agentErr(errors.New(msg)) + Expect(errors.Is(err, agents.ErrRetryLater)).To(BeTrue()) + retry, _ := errors.AsType[*agents.RetryLaterError](err) + d := retry.RetryIn + Expect(d).To(Equal(wantDelay)) + }, + Entry("bare token", "agent(retry_later)", time.Duration(0)), + Entry("with seconds", "agent(retry_later:120)", 120*time.Second), + Entry("capped at 1h", "agent(retry_later:999999)", time.Hour), + // Scaling to nanoseconds before capping wraps past 2^64, landing on ~0.29s. + Entry("capped before it can overflow", "agent(retry_later:18446744074)", time.Hour), + ) + + It("leaves other plugin errors untouched", func() { + orig := errors.New("some plugin failure") + Expect(agentErr(orig)).To(Equal(orig)) + }) + + It("does not treat a superstring token as a throttle", func() { + orig := errors.New("useragent(retry_later)") + Expect(agentErr(orig)).To(Equal(orig)) + }) }) var _ = Describe("MetadataAgent", Ordered, func() { diff --git a/plugins/pdk/go/metadata/metadata.go b/plugins/pdk/go/metadata/metadata.go index bb0ae9620..57546352e 100644 --- a/plugins/pdk/go/metadata/metadata.go +++ b/plugins/pdk/go/metadata/metadata.go @@ -18,6 +18,18 @@ type ArtistRef = types.ArtistRef // Deprecated: use types.SongRef. type SongRef = types.SongRef +// MetadataAgentError represents an error type for metadata agent operations. +type MetadataAgentError string + +const ( + // MetadataAgentErrorRetryLater indicates the provider is throttling; retry later. + // Append ":" inside the parentheses to request a specific delay. + MetadataAgentErrorRetryLater MetadataAgentError = "agent(retry_later)" +) + +// Error implements the error interface for MetadataAgentError. +func (e MetadataAgentError) Error() string { return string(e) } + // AlbumImagesResponse is the response for GetAlbumImages. type AlbumImagesResponse struct { // Images is the list of album images. diff --git a/plugins/pdk/go/metadata/metadata_stub.go b/plugins/pdk/go/metadata/metadata_stub.go index 572eba4da..f979419a9 100644 --- a/plugins/pdk/go/metadata/metadata_stub.go +++ b/plugins/pdk/go/metadata/metadata_stub.go @@ -16,6 +16,18 @@ type ArtistRef = types.ArtistRef // Deprecated: use types.SongRef. type SongRef = types.SongRef +// MetadataAgentError represents an error type for metadata agent operations. +type MetadataAgentError string + +const ( + // MetadataAgentErrorRetryLater indicates the provider is throttling; retry later. + // Append ":" inside the parentheses to request a specific delay. + MetadataAgentErrorRetryLater MetadataAgentError = "agent(retry_later)" +) + +// Error implements the error interface for MetadataAgentError. +func (e MetadataAgentError) Error() string { return string(e) } + // AlbumImagesResponse is the response for GetAlbumImages. type AlbumImagesResponse struct { // Images is the list of album images. diff --git a/plugins/pdk/rust/nd-pdk-capabilities/src/metadata.rs b/plugins/pdk/rust/nd-pdk-capabilities/src/metadata.rs index 38fcae9da..890e16954 100644 --- a/plugins/pdk/rust/nd-pdk-capabilities/src/metadata.rs +++ b/plugins/pdk/rust/nd-pdk-capabilities/src/metadata.rs @@ -24,6 +24,11 @@ pub type ArtistRef = nd_pdk_types::ArtistRef; #[deprecated(note = "use nd_pdk::types::SongRef")] pub type SongRef = nd_pdk_types::SongRef; +/// MetadataAgentError represents an error type for metadata agent operations. +pub type MetadataAgentError = &'static str; +/// MetadataAgentErrorRetryLater indicates the provider is throttling; retry later. +/// Append ":" inside the parentheses to request a specific delay. +pub const METADATA_AGENT_ERROR_RETRY_LATER: MetadataAgentError = "agent(retry_later)"; /// AlbumImagesResponse is the response for GetAlbumImages. #[derive(Debug, Clone, Default, Serialize, Deserialize)] #[serde(rename_all = "camelCase")] diff --git a/plugins/scrobbler_adapter.go b/plugins/scrobbler_adapter.go index b3203a352..721f0d3fa 100644 --- a/plugins/scrobbler_adapter.go +++ b/plugins/scrobbler_adapter.go @@ -174,11 +174,12 @@ func mapScrobblerError(err error) error { return nil } errMsg := err.Error() + retryLater, isRetryLater := parseRetryLater(scrobblerRetryLaterRe, errMsg) switch { case strings.Contains(errMsg, capabilities.ScrobblerErrorNotAuthorized.Error()): return scrobbler.ErrNotAuthorized - case strings.Contains(errMsg, capabilities.ScrobblerErrorRetryLater.Error()): - return scrobbler.ErrRetryLater + case isRetryLater: + return retryLater case strings.Contains(errMsg, capabilities.ScrobblerErrorUnrecoverable.Error()): return scrobbler.ErrUnrecoverable default: diff --git a/plugins/scrobbler_adapter_test.go b/plugins/scrobbler_adapter_test.go index 56a452742..3efd5d1b1 100644 --- a/plugins/scrobbler_adapter_test.go +++ b/plugins/scrobbler_adapter_test.go @@ -7,6 +7,7 @@ import ( "errors" "time" + "github.com/navidrome/navidrome/core/agents" "github.com/navidrome/navidrome/core/scrobbler" "github.com/navidrome/navidrome/model" "github.com/navidrome/navidrome/model/request" @@ -362,4 +363,25 @@ var _ = Describe("mapScrobblerError", func() { err := mapScrobblerError(errors.New("some unknown error")) Expect(err).To(MatchError(scrobbler.ErrUnrecoverable)) }) + + DescribeTable("mapScrobblerError retry-later", + func(msg string, wantDelay time.Duration) { + err := mapScrobblerError(errors.New(msg)) + Expect(errors.Is(err, scrobbler.ErrRetryLater)).To(BeTrue()) + retry, _ := errors.AsType[*agents.RetryLaterError](err) + d := retry.RetryIn + Expect(d).To(Equal(wantDelay)) + }, + Entry("bare token", "scrobbler(retry_later)", time.Duration(0)), + Entry("with seconds", "scrobbler(retry_later:30)", 30*time.Second), + Entry("capped at 1h", "scrobbler(retry_later:999999)", time.Hour), + // Scaling to nanoseconds before capping wraps past 2^64, landing on ~0.29s. + Entry("capped before it can overflow", "scrobbler(retry_later:18446744074)", time.Hour), + Entry("wrapped in context", "plugin xyz: scrobbler(retry_later:5)", 5*time.Second), + ) + + It("still maps unknown errors to unrecoverable", func() { + err := mapScrobblerError(errors.New("scrobbler(retry_later_garbage")) + Expect(errors.Is(err, scrobbler.ErrUnrecoverable)).To(BeTrue()) + }) })