navidrome/server/subsonic/media_retrieval_test.go
Deluan Quintão 01b7c86f90
fix(scanner): stop logging expected lyrics sniff misses as warnings (#5702)
* fix(scanner): stop logging expected lyrics sniff misses as warnings

During a scan, embedded lyrics are parsed with an empty suffix, which puts
ParseLyrics into content-sniffing mode: it tries the TTML, SRT and Lyricsfile
YAML parsers in turn before falling back to plain text. Every plain-text or LRC
lyric therefore fails the structured probes on its way to the fallback, and each
failure was logged at warning level with no indication of which file triggered
it, flooding the scan log with benign "Error parsing lyrics, falling back to
plain text" messages.

A probe rejecting content it does not own during sniffing is expected control
flow, so it is now logged at trace instead. A parse failure under an explicitly
requested suffix (e.g. a malformed .yaml/.srt/.ttml sidecar) still warns, since
the user declared that format. ParseLyrics gains ctx and path parameters so any
warning names the offending file and carries request context where available;
all call sites are updated accordingly.

Also fixes a test-isolation bug in the new logging spec: the BeforeEach swapped
the process-global default logger via SetDefaultLogger but only restored the log
level on cleanup, leaking the null logger and its hook into later specs in the
shared model suite.

* test: use spec-scoped contexts instead of context.Background in lyrics tests

Replace context.Background() with GinkgoT().Context() (and b.Context() in the
parse benchmarks) across the lyrics-related tests, so contexts are cancelled
when each spec ends. The embeddedLyrics fixture in core/lyrics is now a
hand-written literal like its sibling fixtures, removing the construction-time
ParseLyrics call that could not use a spec-scoped context.

* refactor(model): attach lyrics parse log attribution via context

Narrow ParseLyrics back to (ctx, suffix, lang, contents), dropping the path
parameter added by the previous commit. Attribution now uses the codebase's
existing idiom: callers that know the source attach it with log.NewContext
(e.g. "file" for the media file or sidecar), and the plugin adapter tags both
the plugin name and the track, fixing probe-miss logs that misattributed
plugin-returned content to the file's own tags. This removes three adjacent
string parameters that were easy to swap silently, and the "" placeholder most
call sites had to pass.

Also hardens the logging spec from the previous commit: the null test logger is
now swapped in before raising the level (SetLevel forces the current default
logger to trace, so the old order left the null logger at info and trace
entries never reached the hook), the sniff test now asserts probe misses are
observable at trace with file attribution instead of only asserting the absence
of warnings, and cleanup restores the actual previous logger — via a new return
value on log.SetDefaultLogger — instead of a bare logrus.New() that would
discard hooks configured on the process-wide logger.

* refactor(lyrics): hoist attributed log contexts out of loops

Address review feedback on #5702: build the log-attributed context once per
operation instead of per iteration, and reuse it on the surrounding log calls
so the error/trace lines around ParseLyrics carry the same attribution fields.
In fromExternalFile the sidecar path now rides the context for all log lines
in the function, replacing the repeated explicit "path" field.

* style(model): pass lyrics parse errors as final log arguments

Per the project logging convention, errors go as the last argument (the log
package normalizes them via its error case) instead of a keyed "error" pair,
which stores the raw error value and bypasses that handling. Flagged by review
on #5702; the keyed form was inherited from the original warning line.
2026-07-02 09:46:57 -04:00

238 lines
7.4 KiB
Go

package subsonic
import (
"bytes"
"cmp"
"context"
"encoding/json"
"errors"
"io"
"net/http/httptest"
"path/filepath"
"slices"
"time"
"github.com/navidrome/navidrome/conf"
"github.com/navidrome/navidrome/conf/configtest"
"github.com/navidrome/navidrome/core/artwork"
"github.com/navidrome/navidrome/core/lyrics"
"github.com/navidrome/navidrome/model"
"github.com/navidrome/navidrome/tests"
. "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega"
)
var _ = Describe("MediaRetrievalController", func() {
var router *Router
var ds model.DataStore
mockRepo := &mockedMediaFile{MockMediaFileRepo: tests.MockMediaFileRepo{}}
var artwork *fakeArtwork
var w *httptest.ResponseRecorder
BeforeEach(func() {
ds = &tests.MockDataStore{
MockedMediaFile: mockRepo,
}
artwork = &fakeArtwork{data: "image data"}
router = New(ds, artwork, nil, nil, nil, nil, nil, nil, nil, nil, nil, nil, nil, lyrics.NewLyrics(ds, nil), nil, nil)
w = httptest.NewRecorder()
DeferCleanup(configtest.SetupConfig())
conf.Server.LyricsPriority = "embedded,.lrc"
})
Describe("GetCoverArt", func() {
It("should return data for that id", func() {
r := newGetRequest("id=34", "size=128", "square=true")
_, err := router.GetCoverArt(w, r)
Expect(err).ToNot(HaveOccurred())
Expect(artwork.recvSize).To(Equal(128))
Expect(artwork.recvSquare).To(BeTrue())
Expect(w.Body.String()).To(Equal(artwork.data))
})
It("should return placeholder if id parameter is missing (mimicking Subsonic)", func() {
r := newGetRequest() // No id parameter
_, err := router.GetCoverArt(w, r)
Expect(err).To(BeNil())
Expect(artwork.recvId).To(BeEmpty())
Expect(w.Body.String()).To(Equal(artwork.data))
})
It("should fail when the file is not found", func() {
artwork.err = model.ErrNotFound
r := newGetRequest("id=34", "size=128", "square=true")
_, err := router.GetCoverArt(w, r)
Expect(err).To(MatchError("Artwork not found"))
})
It("should fail when there is an unknown error", func() {
artwork.err = errors.New("weird error")
r := newGetRequest("id=34", "size=128")
_, err := router.GetCoverArt(w, r)
Expect(err).To(MatchError("weird error"))
})
When("client disconnects (context is cancelled)", func() {
It("should not call the service if cancelled before the call", func() {
ctx, cancel := context.WithCancel(GinkgoT().Context())
r := newGetRequest("id=34", "size=128", "square=true")
r = r.WithContext(ctx)
cancel()
_, err := router.GetCoverArt(w, r)
Expect(err).ToNot(HaveOccurred())
Expect(artwork.recvId).To(Equal(""))
Expect(artwork.recvSize).To(Equal(0))
Expect(artwork.recvSquare).To(BeFalse())
Expect(w.Body.String()).To(BeEmpty())
})
It("should not return data if cancelled during the call", func() {
ctx, cancel := context.WithCancel(GinkgoT().Context())
defer cancel()
r := newGetRequest("id=34", "size=128", "square=true")
r = r.WithContext(ctx)
artwork.ctxCancelFunc = cancel
_, err := router.GetCoverArt(w, r)
Expect(err).ToNot(HaveOccurred())
Expect(artwork.recvId).To(Equal("34"))
Expect(artwork.recvSize).To(Equal(128))
Expect(artwork.recvSquare).To(BeTrue())
Expect(w.Body.String()).To(BeEmpty())
})
})
})
Describe("GetLyrics", func() {
It("should return data for given artist & title", func() {
r := newGetRequest("artist=Rick+Astley", "title=Never+Gonna+Give+You+Up")
lyricsList, _ := model.ParseLyrics(GinkgoT().Context(), ".lrc", "eng", []byte("[00:18.80]We're no strangers to love\n[00:22.80]You know the rules and so do I"))
lyrics, _ := lyricsList.Main()
lyricsJson, err := json.Marshal(model.LyricList{
lyrics,
})
Expect(err).ToNot(HaveOccurred())
mockRepo.SetData(model.MediaFiles{
{
ID: "1",
Artist: "Rick Astley",
Title: "Never Gonna Give You Up",
Lyrics: string(lyricsJson),
},
})
response, err := router.GetLyrics(r)
Expect(err).ToNot(HaveOccurred())
Expect(response.Lyrics.Artist).To(Equal("Rick Astley"))
Expect(response.Lyrics.Title).To(Equal("Never Gonna Give You Up"))
Expect(response.Lyrics.Value).To(Equal("We're no strangers to love\nYou know the rules and so do I\n"))
})
It("should surface the main-kind track when translation tracks are present", func() {
r := newGetRequest("artist=Rick+Astley", "title=Never+Gonna+Give+You+Up")
start := int64(0)
lyricsJSON, err := json.Marshal(model.LyricList{
{Kind: model.LyricKindTranslation, Lang: "por", Line: []model.Line{{Start: &start, Value: "Nunca vou te decepcionar"}}},
{Kind: model.LyricKindMain, Lang: "eng", Line: []model.Line{{Start: &start, Value: "Never gonna let you down"}}},
})
Expect(err).ToNot(HaveOccurred())
mockRepo.SetData(model.MediaFiles{
{
ID: "1",
Artist: "Rick Astley",
Title: "Never Gonna Give You Up",
Lyrics: string(lyricsJSON),
},
})
response, err := router.GetLyrics(r)
Expect(err).ToNot(HaveOccurred())
Expect(response.Lyrics.Value).To(Equal("Never gonna let you down\n"))
})
It("should return empty subsonic response if the record corresponding to the given artist & title is not found", func() {
r := newGetRequest("artist=Dheeraj", "title=Rinkiya+Ke+Papa")
mockRepo.SetData(model.MediaFiles{})
response, err := router.GetLyrics(r)
Expect(err).ToNot(HaveOccurred())
Expect(response.Lyrics.Artist).To(Equal(""))
Expect(response.Lyrics.Title).To(Equal(""))
Expect(response.Lyrics.Value).To(Equal(""))
})
It("should return lyric file when finding mediafile with no embedded lyrics but present on filesystem", func() {
r := newGetRequest("artist=Rick+Astley", "title=Never+Gonna+Give+You+Up")
fixturesDir, err := filepath.Abs("tests/fixtures")
Expect(err).ToNot(HaveOccurred())
mockRepo.SetData(model.MediaFiles{
{
LibraryPath: fixturesDir,
Path: "test.mp3",
ID: "1",
Artist: "Rick Astley",
Title: "Never Gonna Give You Up",
},
})
response, err := router.GetLyrics(r)
Expect(err).ToNot(HaveOccurred())
Expect(response.Lyrics.Artist).To(Equal("Rick Astley"))
Expect(response.Lyrics.Title).To(Equal("Never Gonna Give You Up"))
Expect(response.Lyrics.Value).To(Equal("We're no strangers to love\nYou know the rules and so do I\n"))
})
})
})
type fakeArtwork struct {
artwork.Artwork
data string
err error
ctxCancelFunc func()
recvId string
recvSize int
recvSquare bool
}
func (c *fakeArtwork) GetOrPlaceholder(_ context.Context, id string, size int, square bool) (io.ReadCloser, time.Time, error) {
if c.err != nil {
return nil, time.Time{}, c.err
}
c.recvId = id
c.recvSize = size
c.recvSquare = square
if c.ctxCancelFunc != nil {
c.ctxCancelFunc()
return nil, time.Time{}, context.Canceled
}
return io.NopCloser(bytes.NewReader([]byte(c.data))), time.Time{}, nil
}
type mockedMediaFile struct {
tests.MockMediaFileRepo
}
func (m *mockedMediaFile) GetAll(opts ...model.QueryOptions) (model.MediaFiles, error) {
data, err := m.MockMediaFileRepo.GetAll(opts...)
if err != nil {
return nil, err
}
if len(opts) == 0 || opts[0].Sort != "lyrics, updated_at" {
return data, nil
}
result := slices.Clone(data)
slices.SortFunc(result, func(a, b model.MediaFile) int {
diff := cmp.Or(
cmp.Compare(a.Lyrics, b.Lyrics),
cmp.Compare(a.UpdatedAt.Unix(), b.UpdatedAt.Unix()),
)
if opts[0].Order == "desc" {
return -diff
}
return diff
})
return result, nil
}