diff --git a/internal/db/migrations/0097_requeue_short_track_prints.down.sql b/internal/db/migrations/0097_requeue_short_track_prints.down.sql new file mode 100644 index 00000000..f1513b02 --- /dev/null +++ b/internal/db/migrations/0097_requeue_short_track_prints.down.sql @@ -0,0 +1,3 @@ +-- The cleared rows were failures; the workers write them again, or better. +-- Nothing to undo. +SELECT 1; diff --git a/internal/db/migrations/0097_requeue_short_track_prints.up.sql b/internal/db/migrations/0097_requeue_short_track_prints.up.sql new file mode 100644 index 00000000..55022235 --- /dev/null +++ b/internal/db/migrations/0097_requeue_short_track_prints.up.sql @@ -0,0 +1,20 @@ +-- #6178: the image's fpcalc exits 3 ("Error decoding audio frame (End of +-- file)") on every file shorter than the span it is asked for, so every track +-- under two minutes failed both prints. The failure was stored as a verdict, +-- and a verdict is not retried until the file changes. fpcalcReadToEnd now +-- keeps those prints; clear the failures so the workers take them again. + +-- The AcoustID lookup's queue takes a track with no lookup row. +DELETE FROM track_acoustid_lookups + WHERE state = 'failed' + AND detail LIKE '%Error decoding audio frame (End of file)%'; + +-- The fingerprint backfill's queue takes a track with no fingerprint row. A +-- NULL chromaprint is always a verdict (an inconclusive attempt stores +-- nothing), and on a track no longer than the span it was taken at it is this +-- failure. A track that is damaged fails again and is stamped again. +DELETE FROM track_fingerprints f + USING tracks t + WHERE f.track_id = t.id + AND f.chromaprint IS NULL + AND t.duration_ms <= f.chromaprint_length_sec * 1000; diff --git a/internal/library/fingerprint.go b/internal/library/fingerprint.go index 8b69449a..c9f5be57 100644 --- a/internal/library/fingerprint.go +++ b/internal/library/fingerprint.go @@ -264,7 +264,7 @@ func computeAudioStreamSHA256(ctx context.Context, path string) ([]byte, error) // lengthSec seconds of the file. func computeChromaprint(ctx context.Context, path string, lengthSec int32) ([]int32, error) { out, err := runFingerprintTool(ctx, "fpcalc", fpcalcArgs(path, int(lengthSec))) - if err != nil { + if err != nil && !fpcalcReadToEnd(err, out, int(lengthSec)) { return nil, err } return parseFpcalcRaw(out) @@ -276,7 +276,7 @@ func computeChromaprint(ctx context.Context, path string, lengthSec int32) ([]in // rejects as a verdict. func computeLookupFingerprint(ctx context.Context, path string) (lookupFingerprint, error) { out, err := runFingerprintTool(ctx, "fpcalc", fpcalcLookupArgs(path)) - if err != nil { + if err != nil && !fpcalcReadToEnd(err, out, lookupFingerprintLengthSec) { return lookupFingerprint{}, err } return parseFpcalcCompressed(out) @@ -289,6 +289,9 @@ func computeLookupFingerprint(ctx context.Context, path string) (lookupFingerpri // fingerprint of a damaged file is not that file's identity. Stored, it would // score against a healthy copy over whatever prefix survived, and could group // or fail to group either way. Absent is better than wrong. +// +// A tool that ran and exited non-zero returns its stdout beside the +// *toolExitError, for the one exit 3 that is not damage (fpcalcReadToEnd). func runFingerprintTool(ctx context.Context, name string, args []string) ([]byte, error) { runCtx, cancel := context.WithTimeout(ctx, fingerprintTimeout) defer cancel() @@ -311,11 +314,58 @@ func runFingerprintTool(ctx context.Context, name string, args []string) ([]byte } var exitErr *exec.ExitError if errors.As(err, &exitErr) { - return nil, fmt.Errorf("%s exited %d: %s", name, exitErr.ExitCode(), stderrTail(exitErr.Stderr)) + return out, &toolExitError{name: name, code: exitErr.ExitCode(), stderr: stderrTail(exitErr.Stderr)} } return nil, fmt.Errorf("%s: %w", name, err) } +// toolExitError is a fingerprint tool that ran and exited non-zero: a verdict +// on the file, unlike a stall or a missing tool. +type toolExitError struct { + name string + code int + stderr []byte // the tail, as stderrTail keeps it +} + +func (e *toolExitError) Error() string { + return fmt.Sprintf("%s exited %d: %s", e.name, e.code, e.stderr) +} + +// fpcalcExitPartial is fpcalc's exit for "reading failed, but here is a +// fingerprint of what I got". +const fpcalcExitPartial = 3 + +// fpcalcReadToEnd reports whether fpcalc's partial exit only means it decoded +// the whole file (#6178). The image's fpcalc 1.5.1 reports the decoder's end of +// file as "Error decoding audio frame (End of file)" and exits 3 whenever it +// reaches the end before -length, so it failed every file shorter than the +// span asked for: every track under two minutes, at any length setting. That +// print covers the whole file, so it is the file's identity. +// +// A damaged file can stop at an end of file too. Its DURATION, the length the +// container declares, is then longer than the span asked for, and it stays a +// failure. +func fpcalcReadToEnd(err error, out []byte, lengthSec int) bool { + var exitErr *toolExitError + if !errors.As(err, &exitErr) || exitErr.code != fpcalcExitPartial || + !bytes.Contains(exitErr.stderr, []byte("(End of file)")) { + return false + } + d, ok := fpcalcDuration(out) + return ok && d > 0 && d <= lengthSec +} + +// fpcalcDuration reads the DURATION= line of fpcalc's output, in whole seconds. +func fpcalcDuration(out []byte) (int, bool) { + for _, line := range strings.Split(string(out), "\n") { + if v, ok := strings.CutPrefix(strings.TrimSpace(line), "DURATION="); ok { + d, err := strconv.Atoi(v) + return d, err == nil + } + } + return 0, false +} + // stderrTail keeps the END of a failing tool's stderr. ffmpeg and fpcalc print // the actual reason last, after any banner or per-frame warnings, so a cap that // kept the head would log the noise and drop the cause. diff --git a/internal/library/fingerprint_test.go b/internal/library/fingerprint_test.go index a2bf4d56..a8ec170b 100644 --- a/internal/library/fingerprint_test.go +++ b/internal/library/fingerprint_test.go @@ -253,3 +253,45 @@ func TestFingerprintResult_InconclusiveIfEitherHalfIs(t *testing.T) { } } } + +// fpcalc 1.5.1 exits 3 with "(End of file)" on every file shorter than the +// span asked for (#6178). That print covers the whole file and is kept; a file +// whose declared length runs past the span stopped early, and is not. +func TestFpcalcReadToEnd(t *testing.T) { + eof := []byte("ERROR: Error decoding audio frame (End of file)") + out := func(sec int) []byte { return []byte(fmt.Sprintf("DURATION=%d\nFINGERPRINT=AQAB\n", sec)) } + for name, tc := range map[string]struct { + err error + out []byte + want bool + }{ + "short file read to its end": {&toolExitError{name: "fpcalc", code: 3, stderr: eof}, out(37), true}, + "exactly the span": {&toolExitError{name: "fpcalc", code: 3, stderr: eof}, out(120), true}, + "declared longer than read": {&toolExitError{name: "fpcalc", code: 3, stderr: eof}, out(150), false}, + "partial for another reason": {&toolExitError{name: "fpcalc", code: 3, stderr: []byte("ERROR: invalid data")}, out(37), false}, + "a different exit": {&toolExitError{name: "fpcalc", code: 2, stderr: eof}, out(37), false}, + "no duration printed": {&toolExitError{name: "fpcalc", code: 3, stderr: eof}, []byte("FINGERPRINT=AQAB\n"), false}, + "not a tool exit (a stall)": {fmt.Errorf("fpcalc: %w", errFingerprintTimeout), out(37), false}, + "wrapped exit is still judged": {fmt.Errorf("lookup: %w", &toolExitError{name: "fpcalc", code: 3, stderr: eof}), out(37), true}, + } { + if got := fpcalcReadToEnd(tc.err, tc.out, 120); got != tc.want { + t.Errorf("%s: fpcalcReadToEnd = %v, want %v", name, got, tc.want) + } + } +} + +// The output of a tool that exited non-zero reaches the caller, or +// fpcalcReadToEnd has nothing to read; the message is unchanged. +func TestRunFingerprintTool_KeepsOutputOnExit(t *testing.T) { + out, err := runFingerprintTool(context.Background(), "sh", + []string{"-c", "echo DURATION=37; echo 'ERROR: Error decoding audio frame (End of file)' >&2; exit 3"}) + if err == nil { + t.Fatal("exit 3 returned no error") + } + if want := "sh exited 3: ERROR: Error decoding audio frame (End of file)"; err.Error() != want { + t.Errorf("err = %q, want %q", err, want) + } + if d, ok := fpcalcDuration(out); !ok || d != 37 { + t.Errorf("output = %q, want the DURATION line kept", out) + } +}