navidrome/core/artwork/gate_test.go

Ignoring revisions in .git-blame-ignore-revs. Click here to bypass and see the normal blame view.

56 lines
2 KiB
Go
Raw Permalink Normal View History

fix(artwork): ramp the external circuit breaker back up instead of closing on one answer (#5961) * fix(artwork): ramp the external circuit breaker back up instead of closing on one answer The breaker went straight from open to fully closed on a single non-transient response, so recovery was a burst: the agent resumed at the limiter's full rate until five consecutive failures reopened it. A not-found counted as that response, and a provider that is blocking still answers the occasional request, so the cycle never settled. Observed on a production library over 100 minutes with apple-music blocked. Of 232 responses, 228 were 403 and 4 were not-found, and those four closed the breaker four times. Each close was followed by another open 1 to 3 seconds later, with about five requests in between: 00:59:05 closed -> 00:59:06 opened 01:23:13 closed -> 01:23:16 opened 01:41:21 closed -> 01:41:24 opened Closing now needs breakerRecoveries consecutive answers, one per probe interval, and any failure discards the count. A not-found still counts, because the provider did answer, but it can no longer close the breaker by itself. Unrelated to the plugin loading in the rest of this PR; it came out of investigating why iTunes kept returning 403 while the breaker was open. * fix(artwork): count only current-episode probes toward breaker recovery The worker drains concurrently, so when the breaker opens there are already calls past allow(), queued in the rate limiter or waiting on a response. Their answers arrive after the open and reached the recovery counter, so breakerRecoveries of them closed the breaker with no probe interval elapsed at all: the burst the ramp exists to prevent. allow() now returns the open episode a call was admitted under, zero when the breaker was closed, and only an answer whose generation matches the current episode counts. The generation also invalidates a probe whose answer lands after the breaker closed and reopened, which a plain probe flag would credit to the wrong episode. The token never crosses the gateFunc seam: allow and record are both called inside Worker.gate, so passthroughGate, tracingGate and offlineGate are untouched. The regression test needs no fake clock. The race is an ordering, not a duration, so it is reproduced by calling allow and record in the order concurrency produces, which is deterministic where a goroutine-based test would pass on a lucky schedule. Found by Codex. * test(artwork): move the breaker ordering spec into the Ginkgo suite The ordering regression does not need a fake clock, so it does not need the plain testing.T runner either. That runner is only used here because testing/synctest requires it; every other spec belongs in the Ginkgo suite. The three specs left in worker_timing_test.go all drive the fake clock.
2026-08-15 10:36:14 -04:00
package artwork
import (
"errors"
"time"
fix(artwork): ramp the external circuit breaker back up instead of closing on one answer (#5961) * fix(artwork): ramp the external circuit breaker back up instead of closing on one answer The breaker went straight from open to fully closed on a single non-transient response, so recovery was a burst: the agent resumed at the limiter's full rate until five consecutive failures reopened it. A not-found counted as that response, and a provider that is blocking still answers the occasional request, so the cycle never settled. Observed on a production library over 100 minutes with apple-music blocked. Of 232 responses, 228 were 403 and 4 were not-found, and those four closed the breaker four times. Each close was followed by another open 1 to 3 seconds later, with about five requests in between: 00:59:05 closed -> 00:59:06 opened 01:23:13 closed -> 01:23:16 opened 01:41:21 closed -> 01:41:24 opened Closing now needs breakerRecoveries consecutive answers, one per probe interval, and any failure discards the count. A not-found still counts, because the provider did answer, but it can no longer close the breaker by itself. Unrelated to the plugin loading in the rest of this PR; it came out of investigating why iTunes kept returning 403 while the breaker was open. * fix(artwork): count only current-episode probes toward breaker recovery The worker drains concurrently, so when the breaker opens there are already calls past allow(), queued in the rate limiter or waiting on a response. Their answers arrive after the open and reached the recovery counter, so breakerRecoveries of them closed the breaker with no probe interval elapsed at all: the burst the ramp exists to prevent. allow() now returns the open episode a call was admitted under, zero when the breaker was closed, and only an answer whose generation matches the current episode counts. The generation also invalidates a probe whose answer lands after the breaker closed and reopened, which a plain probe flag would credit to the wrong episode. The token never crosses the gateFunc seam: allow and record are both called inside Worker.gate, so passthroughGate, tracingGate and offlineGate are untouched. The regression test needs no fake clock. The race is an ordering, not a duration, so it is reproduced by calling allow and record in the order concurrency produces, which is deterministic where a goroutine-based test would pass on a lucky schedule. Found by Codex. * test(artwork): move the breaker ordering spec into the Ginkgo suite The ordering regression does not need a fake clock, so it does not need the plain testing.T runner either. That runner is only used here because testing/synctest requires it; every other spec belongs in the Ginkgo suite. The three specs left in worker_timing_test.go all drive the fake clock.
2026-08-15 10:36:14 -04:00
"github.com/navidrome/navidrome/core/agents"
fix(artwork): ramp the external circuit breaker back up instead of closing on one answer (#5961) * fix(artwork): ramp the external circuit breaker back up instead of closing on one answer The breaker went straight from open to fully closed on a single non-transient response, so recovery was a burst: the agent resumed at the limiter's full rate until five consecutive failures reopened it. A not-found counted as that response, and a provider that is blocking still answers the occasional request, so the cycle never settled. Observed on a production library over 100 minutes with apple-music blocked. Of 232 responses, 228 were 403 and 4 were not-found, and those four closed the breaker four times. Each close was followed by another open 1 to 3 seconds later, with about five requests in between: 00:59:05 closed -> 00:59:06 opened 01:23:13 closed -> 01:23:16 opened 01:41:21 closed -> 01:41:24 opened Closing now needs breakerRecoveries consecutive answers, one per probe interval, and any failure discards the count. A not-found still counts, because the provider did answer, but it can no longer close the breaker by itself. Unrelated to the plugin loading in the rest of this PR; it came out of investigating why iTunes kept returning 403 while the breaker was open. * fix(artwork): count only current-episode probes toward breaker recovery The worker drains concurrently, so when the breaker opens there are already calls past allow(), queued in the rate limiter or waiting on a response. Their answers arrive after the open and reached the recovery counter, so breakerRecoveries of them closed the breaker with no probe interval elapsed at all: the burst the ramp exists to prevent. allow() now returns the open episode a call was admitted under, zero when the breaker was closed, and only an answer whose generation matches the current episode counts. The generation also invalidates a probe whose answer lands after the breaker closed and reopened, which a plain probe flag would credit to the wrong episode. The token never crosses the gateFunc seam: allow and record are both called inside Worker.gate, so passthroughGate, tracingGate and offlineGate are untouched. The regression test needs no fake clock. The race is an ordering, not a duration, so it is reproduced by calling allow and record in the order concurrency produces, which is deterministic where a goroutine-based test would pass on a lucky schedule. Found by Codex. * test(artwork): move the breaker ordering spec into the Ginkgo suite The ordering regression does not need a fake clock, so it does not need the plain testing.T runner either. That runner is only used here because testing/synctest requires it; every other spec belongs in the Ginkgo suite. The three specs left in worker_timing_test.go all drive the fake clock.
2026-08-15 10:36:14 -04:00
. "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega"
)
// allowed drops the generation token when a caller only cares about admission.
func allowed(b *breaker) bool { ok, _ := b.allow(); return ok }
var _ = Describe("breaker", func() {
// The worker drains concurrently, so when the breaker opens there are already calls past
// allow(), queued in the rate limiter or waiting on a response. Their answers arrive
// afterwards. Counting those as recovery closes the breaker with no probe interval elapsed,
// which is the burst the ramp exists to prevent. No clock is involved: the race is an
// ordering, so it is reproduced by making the calls in the order concurrency produces.
It("ignores answers from calls admitted before it opened", func() {
b := newBreaker()
// A batch clears allow() while the breaker is still closed.
for range breakerThreshold + breakerRecoveries {
ok, gen := b.allow()
Expect(ok).To(BeTrue())
Expect(gen).To(BeZero(), "admitted with the breaker closed, so not a probe")
}
// The fast failures in that batch open it.
for range breakerThreshold {
b.record("agentA", 0, errors.New("blocked"))
}
Expect(allowed(b)).To(BeFalse(), "breaker is open")
// The slower answers from the same batch land now.
for range breakerRecoveries {
b.record("agentA", 0, nil)
}
Expect(allowed(b)).To(BeFalse(),
"answers from calls admitted before the breaker opened must not close it")
})
It("opens at once when a provider asks to retry later, honoring its delay", func() {
b := newBreaker()
Expect(allowed(b)).To(BeTrue(), "starts closed")
// A single explicit back-off opens the breaker without reaching the failure threshold.
b.record("agentA", 0, &agents.RetryLaterError{RetryIn: 5 * time.Second})
Expect(allowed(b)).To(BeFalse(), "an explicit back-off opens the breaker immediately")
Expect(b.probeAfter).To(Equal(5*time.Second), "the provider's delay drives the probe interval")
})
fix(artwork): ramp the external circuit breaker back up instead of closing on one answer (#5961) * fix(artwork): ramp the external circuit breaker back up instead of closing on one answer The breaker went straight from open to fully closed on a single non-transient response, so recovery was a burst: the agent resumed at the limiter's full rate until five consecutive failures reopened it. A not-found counted as that response, and a provider that is blocking still answers the occasional request, so the cycle never settled. Observed on a production library over 100 minutes with apple-music blocked. Of 232 responses, 228 were 403 and 4 were not-found, and those four closed the breaker four times. Each close was followed by another open 1 to 3 seconds later, with about five requests in between: 00:59:05 closed -> 00:59:06 opened 01:23:13 closed -> 01:23:16 opened 01:41:21 closed -> 01:41:24 opened Closing now needs breakerRecoveries consecutive answers, one per probe interval, and any failure discards the count. A not-found still counts, because the provider did answer, but it can no longer close the breaker by itself. Unrelated to the plugin loading in the rest of this PR; it came out of investigating why iTunes kept returning 403 while the breaker was open. * fix(artwork): count only current-episode probes toward breaker recovery The worker drains concurrently, so when the breaker opens there are already calls past allow(), queued in the rate limiter or waiting on a response. Their answers arrive after the open and reached the recovery counter, so breakerRecoveries of them closed the breaker with no probe interval elapsed at all: the burst the ramp exists to prevent. allow() now returns the open episode a call was admitted under, zero when the breaker was closed, and only an answer whose generation matches the current episode counts. The generation also invalidates a probe whose answer lands after the breaker closed and reopened, which a plain probe flag would credit to the wrong episode. The token never crosses the gateFunc seam: allow and record are both called inside Worker.gate, so passthroughGate, tracingGate and offlineGate are untouched. The regression test needs no fake clock. The race is an ordering, not a duration, so it is reproduced by calling allow and record in the order concurrency produces, which is deterministic where a goroutine-based test would pass on a lucky schedule. Found by Codex. * test(artwork): move the breaker ordering spec into the Ginkgo suite The ordering regression does not need a fake clock, so it does not need the plain testing.T runner either. That runner is only used here because testing/synctest requires it; every other spec belongs in the Ginkgo suite. The three specs left in worker_timing_test.go all drive the fake clock.
2026-08-15 10:36:14 -04:00
})