mirror of
https://github.com/navidrome/navidrome.git
synced 2026-07-30 08:46:16 -04:00
* 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.
270 lines
9.8 KiB
Go
270 lines
9.8 KiB
Go
package model
|
|
|
|
import (
|
|
"strings"
|
|
|
|
"github.com/navidrome/navidrome/log"
|
|
. "github.com/onsi/ginkgo/v2"
|
|
. "github.com/onsi/gomega"
|
|
"github.com/sirupsen/logrus"
|
|
"github.com/sirupsen/logrus/hooks/test"
|
|
)
|
|
|
|
var _ = Describe("ParseLyrics", func() {
|
|
DescribeTable("known suffix routes to the matching parser",
|
|
func(suffix, contents string, wantSynced bool, wantFirst string) {
|
|
list, err := ParseLyrics(GinkgoT().Context(), suffix, "eng", []byte(contents))
|
|
Expect(err).ToNot(HaveOccurred())
|
|
Expect(list).To(HaveLen(1))
|
|
Expect(list[0].Synced).To(Equal(wantSynced))
|
|
Expect(list[0].Line[0].Value).To(Equal(wantFirst))
|
|
},
|
|
Entry(".lrc", ".lrc", "[00:01.00]lrc line", true, "lrc line"),
|
|
Entry(".txt plain", ".txt", "plain line", false, "plain line"),
|
|
Entry(".srt", ".srt", "1\n00:00:01,000 --> 00:00:02,000\nsrt line\n", true, "srt line"),
|
|
Entry(".ttml", ".ttml", `<tt xmlns="http://www.w3.org/ns/ttml"><body><div><p begin="00:00.000" end="00:01.000">ttml line</p></div></body></tt>`, true, "ttml line"),
|
|
Entry(".yaml", ".yaml", "version: \"1.0\"\nmetadata:\n language: eng\nlines:\n - text: yaml line\n start_ms: 1000\n", true, "yaml line"),
|
|
)
|
|
|
|
It("empty suffix content-sniffs (TTML)", func() {
|
|
ttml := `<tt xmlns="http://www.w3.org/ns/ttml"><body><div><p begin="00:00.000" end="00:01.000">auto ttml</p></div></body></tt>`
|
|
list, err := ParseLyrics(GinkgoT().Context(), "", "eng", []byte(ttml))
|
|
Expect(err).ToNot(HaveOccurred())
|
|
Expect(list).To(HaveLen(1))
|
|
Expect(list[0].Line[0].Value).To(Equal("auto ttml"))
|
|
})
|
|
|
|
It("empty suffix content-sniffs (YAML)", func() {
|
|
yaml := "version: \"1.0\"\nmetadata:\n language: eng\nlines:\n - text: auto yaml\n start_ms: 1000\n"
|
|
list, err := ParseLyrics(GinkgoT().Context(), "auto", "eng", []byte(yaml))
|
|
Expect(err).ToNot(HaveOccurred())
|
|
Expect(list).To(HaveLen(1))
|
|
Expect(list[0].Line[0].Value).To(Equal("auto yaml"))
|
|
})
|
|
|
|
It("falls back to plain text when a known suffix fails to parse structurally", func() {
|
|
list, err := ParseLyrics(GinkgoT().Context(), ".srt", "eng", []byte("not actually an srt file"))
|
|
Expect(err).ToNot(HaveOccurred())
|
|
Expect(list).To(HaveLen(1))
|
|
Expect(list[0].Synced).To(BeFalse())
|
|
Expect(list[0].Line[0].Value).To(Equal("not actually an srt file"))
|
|
})
|
|
|
|
Describe("logging on parser probe failures", func() {
|
|
var hook *test.Hook
|
|
|
|
BeforeEach(func() {
|
|
prevLevel := log.CurrentLevel()
|
|
l, h := test.NewNullLogger()
|
|
hook = h
|
|
// Swap the logger before raising the level: SetLevel also forces the
|
|
// current default logger to logrus.TraceLevel, and the null logger would
|
|
// otherwise stay at Info and drop Trace entries before the hook sees them.
|
|
prevLogger := log.SetDefaultLogger(l)
|
|
log.SetLevel(log.LevelTrace)
|
|
DeferCleanup(func() {
|
|
log.SetDefaultLogger(prevLogger)
|
|
log.SetLevel(prevLevel)
|
|
})
|
|
})
|
|
|
|
// This is the source of the full-scan log spam: embedded lyrics are parsed
|
|
// with an empty suffix (sniff mode), so every plain-text lyric fails the
|
|
// YAML/SRT/TTML probes on its way to the plain-text fallback. A probe miss
|
|
// during sniffing is expected control flow, not a warning.
|
|
It("logs sniff probe misses at trace only, with file attribution", func() {
|
|
ctx := log.NewContext(GinkgoT().Context(), "file", "/music/song.mp3")
|
|
list, err := ParseLyrics(ctx, "", "eng", []byte("Just a plain\nlyric line\n"))
|
|
|
|
Expect(err).ToNot(HaveOccurred())
|
|
Expect(list).To(HaveLen(1))
|
|
Expect(list[0].Line[0].Value).To(Equal("Just a plain"))
|
|
entries := hook.AllEntries()
|
|
Expect(entries).ToNot(BeEmpty(), "probe misses should be observable at trace")
|
|
for _, e := range entries {
|
|
Expect(e.Level).To(Equal(logrus.TraceLevel),
|
|
"sniff-mode probe misses must not be logged above Trace")
|
|
Expect(e.Data).To(HaveKeyWithValue("file", "/music/song.mp3"))
|
|
}
|
|
})
|
|
|
|
// A specific suffix means the user declared the format, so a structural
|
|
// failure is worth surfacing loudly — and it must name the file.
|
|
It("warns and names the file when a requested suffix fails to parse", func() {
|
|
ctx := log.NewContext(GinkgoT().Context(), "file", "/music/song.yaml")
|
|
list, err := ParseLyrics(ctx, ".yaml", "eng", []byte("not: [valid, yaml\n"))
|
|
|
|
Expect(err).ToNot(HaveOccurred())
|
|
Expect(list).To(HaveLen(1)) // still falls back to plain text
|
|
entry := hook.LastEntry()
|
|
Expect(entry).ToNot(BeNil())
|
|
Expect(entry.Level).To(Equal(logrus.WarnLevel))
|
|
Expect(entry.Data).To(HaveKeyWithValue("file", "/music/song.yaml"))
|
|
})
|
|
})
|
|
})
|
|
|
|
var _ = Describe("ParseLyrics content-sniffing", func() {
|
|
It("should parse embedded TTML with the tag language as the default", func() {
|
|
content := `<tt xmlns="http://www.w3.org/ns/ttml" xmlns:ttm="http://www.w3.org/ns/ttml#metadata">
|
|
<head>
|
|
<metadata>
|
|
<ttm:agent xml:id="lead" ttm:type="person">
|
|
<ttm:name>Lead Vocal</ttm:name>
|
|
</ttm:agent>
|
|
</metadata>
|
|
</head>
|
|
<body>
|
|
<div>
|
|
<p begin="00:00:01.000" end="00:00:03.000">
|
|
<span begin="00:00:01.000" end="00:00:02.000" ttm:agent="lead">Hello </span><span begin="00:00:02.000" end="00:00:03.000" ttm:agent="lead">world</span>
|
|
</p>
|
|
</div>
|
|
</body>
|
|
</tt>`
|
|
|
|
list, err := ParseLyrics(GinkgoT().Context(), "", "ENG", []byte(content))
|
|
|
|
// ParseLyrics's job is to detect TTML and apply the tag language as the
|
|
// default; the parser's cue/agent details are covered in lyrics_ttml_test.go.
|
|
Expect(err).ToNot(HaveOccurred())
|
|
Expect(list).To(HaveLen(1))
|
|
Expect(list[0].Kind).To(Equal("main"))
|
|
Expect(list[0].Lang).To(Equal("eng"))
|
|
Expect(list[0].Synced).To(BeTrue())
|
|
Expect(list[0].Line[0].Value).To(Equal("Hello world"))
|
|
})
|
|
|
|
It("should preserve embedded TTML translation and pronunciation tracks", func() {
|
|
content := `<tt xmlns="http://www.w3.org/ns/ttml" xmlns:itunes="http://music.apple.com/lyric-ttml-internal">
|
|
<head>
|
|
<metadata>
|
|
<iTunesMetadata xmlns="http://music.apple.com/lyric-ttml-internal">
|
|
<translations>
|
|
<translation xml:lang="es">
|
|
<text for="L1">Hola</text>
|
|
</translation>
|
|
</translations>
|
|
<transliterations>
|
|
<transliteration xml:lang="ja-Latn">
|
|
<text for="L1"><span begin="00:00:01.000" end="00:00:01.300" xmlns="http://www.w3.org/ns/ttml">ko</span><span begin="00:00:01.300" end="00:00:01.600" xmlns="http://www.w3.org/ns/ttml">nni</span></text>
|
|
</transliteration>
|
|
</transliterations>
|
|
</iTunesMetadata>
|
|
</metadata>
|
|
</head>
|
|
<body xml:lang="ja">
|
|
<div>
|
|
<p begin="00:00:01.000" end="00:00:02.000" itunes:key="L1">こんにちは</p>
|
|
</div>
|
|
</body>
|
|
</tt>`
|
|
|
|
list, err := ParseLyrics(GinkgoT().Context(), "", "eng", []byte(content))
|
|
|
|
Expect(err).ToNot(HaveOccurred())
|
|
Expect(list).To(HaveLen(3))
|
|
Expect(list[0].Kind).To(Equal("main"))
|
|
Expect(list[0].Lang).To(Equal("ja"))
|
|
Expect(list[0].Line[0].Value).To(Equal("こんにちは"))
|
|
Expect(list[1].Kind).To(Equal("translation"))
|
|
Expect(list[1].Lang).To(Equal("es"))
|
|
Expect(list[1].Line[0].Value).To(Equal("Hola"))
|
|
Expect(list[2].Kind).To(Equal("pronunciation"))
|
|
Expect(list[2].Lang).To(Equal("ja-latn"))
|
|
Expect(list[2].Line[0].Value).To(Equal("konni"))
|
|
Expect(list[2].Line[0].Cue).To(HaveLen(2))
|
|
})
|
|
|
|
It("should parse embedded SRT with the tag language", func() {
|
|
content := `1
|
|
00:00:18,800 --> 00:00:22,800
|
|
We're from subtitles
|
|
|
|
2
|
|
00:00:22,801 --> 00:00:26,000
|
|
Another subtitle line`
|
|
|
|
list, err := ParseLyrics(GinkgoT().Context(), "", "POR", []byte(content))
|
|
|
|
Expect(err).ToNot(HaveOccurred())
|
|
Expect(list).To(Equal(LyricList{
|
|
{
|
|
Lang: "por",
|
|
Line: []Line{
|
|
{
|
|
Start: new(int64(18800)),
|
|
End: new(int64(22800)),
|
|
Value: "We're from subtitles",
|
|
},
|
|
{
|
|
Start: new(int64(22801)),
|
|
End: new(int64(26000)),
|
|
Value: "Another subtitle line",
|
|
},
|
|
},
|
|
Synced: true,
|
|
},
|
|
}))
|
|
})
|
|
|
|
It("should parse embedded SRT blocks separated by whitespace-only blank lines", func() {
|
|
content := "1\n00:00:01,000 --> 00:00:02,000\nFirst subtitle\n \n2\n00:00:03,000 --> 00:00:04,000\nSecond subtitle"
|
|
|
|
list, err := ParseLyrics(GinkgoT().Context(), "", "eng", []byte(content))
|
|
|
|
Expect(err).ToNot(HaveOccurred())
|
|
Expect(list).To(HaveLen(1))
|
|
Expect(list[0].Line).To(Equal([]Line{
|
|
{Start: new(int64(1000)), End: new(int64(2000)), Value: "First subtitle"},
|
|
{Start: new(int64(3000)), End: new(int64(4000)), Value: "Second subtitle"},
|
|
}))
|
|
})
|
|
|
|
It("should keep embedded enhanced LRC cues", func() {
|
|
content := "[00:01.00]<00:01.00>Lead <00:01.50>words"
|
|
|
|
list, err := ParseLyrics(GinkgoT().Context(), "", "eng", []byte(content))
|
|
|
|
Expect(err).ToNot(HaveOccurred())
|
|
Expect(list).To(HaveLen(1))
|
|
Expect(list[0].Lang).To(Equal("eng"))
|
|
Expect(list[0].Synced).To(BeTrue())
|
|
Expect(list[0].Line[0].Value).To(Equal("Lead words"))
|
|
Expect(list[0].Line[0].Cue).To(HaveLen(2))
|
|
})
|
|
|
|
It("should fall back to plain lyrics when embedded TTML is invalid", func() {
|
|
content := `<tt xmlns="http://www.w3.org/ns/ttml">
|
|
<body>
|
|
<p begin="not-a-time">Broken</p>
|
|
</body>
|
|
</tt>`
|
|
|
|
list, err := ParseLyrics(GinkgoT().Context(), "", "eng", []byte(content))
|
|
|
|
Expect(err).ToNot(HaveOccurred())
|
|
Expect(list).To(HaveLen(1))
|
|
Expect(list[0].Lang).To(Equal("eng"))
|
|
Expect(list[0].Synced).To(BeFalse())
|
|
Expect(list[0].Line).ToNot(BeEmpty())
|
|
values := make([]string, 0, len(list[0].Line))
|
|
for _, line := range list[0].Line {
|
|
values = append(values, line.Value)
|
|
}
|
|
Expect(strings.Join(values, "\n")).To(ContainSubstring("Broken"))
|
|
})
|
|
|
|
It("detects a Lyricsfile YAML payload via content-sniffing", func() {
|
|
yaml := "version: \"1.0\"\nmetadata:\n title: Song\n language: eng\nlines:\n - text: sniffed yaml line\n start_ms: 1000\n"
|
|
|
|
list, err := ParseLyrics(GinkgoT().Context(), "", "eng", []byte(yaml))
|
|
|
|
Expect(err).ToNot(HaveOccurred())
|
|
Expect(list).To(HaveLen(1))
|
|
Expect(list[0].Synced).To(BeTrue())
|
|
Expect(list[0].Line).To(HaveLen(1))
|
|
Expect(list[0].Line[0].Value).To(Equal("sniffed yaml line"))
|
|
})
|
|
})
|