diff --git a/README.md b/README.md index c36ba1c..b77b357 100644 --- a/README.md +++ b/README.md @@ -309,8 +309,29 @@ real-time clock Rockbox writes `/.scrobbler-timeless.log` with every timestamp set to zero; those are counted and reported but never submitted, because scrobbling them would mean inventing when they happened. -The log is renamed rather than deleted once accepted. If Last.fm quietly -dropped something, the evidence is still on the device. +### Nothing played is thrown away + +Two separate obligations, because a play that happened and never reached +Last.fm is gone for good. + +**The original is renamed, never deleted.** If Last.fm quietly dropped +something, the evidence is still on the device as `playback.log..submitted`. + +**Anything not submitted is written back** into a live log for the next run: + +| Outcome | What happens to it | +| ------------------------------ | ----------------------------------------- | +| Accepted by Last.fm | dropped from the live log | +| Not in the mirror yet | written back, tried again next run | +| In a batch that failed | written back, tried again next run | +| Nothing accepted at all | logs left completely untouched | +| A skip, or no usable timestamp | not retained — neither can ever be submitted, and the original still has it | + +The batch boundary matters: submission is recorded as each batch is accepted, +so a failure partway through knows exactly what got through and writes back +only the remainder. No duplicates, no losses. + +A file `ffprobe` cannot read costs one unidentified play, not the run. `check_fat32.py` reports paths a FAT32 device will not accept — reserved characters, trailing dots and spaces, over-long components and paths, and names diff --git a/tests/test_submit_scrobbles.py b/tests/test_submit_scrobbles.py index ae48c7b..2e98b8f 100644 --- a/tests/test_submit_scrobbles.py +++ b/tests/test_submit_scrobbles.py @@ -1,4 +1,5 @@ import json +import subprocess import sys from pathlib import Path @@ -238,12 +239,12 @@ def test_a_short_play_is_a_skip_not_a_scrobble(tmp_path, monkeypatch): fraction, so the two never disagree about what counted as a play.""" monkeypatch.setattr(Path, "is_file", lambda self: True) - played, skipped, unresolved, timeless = submit_scrobbles.plays_from_playback_log( + result = submit_scrobbles.plays_from_playback_log( PLAYBACK_LOG, "/Music", "/mnt/mirror", runner=tags_of() ) - assert skipped == 1 - assert [entry["timestamp"] for entry in played] == ["1700000300"] + assert result.skipped == 1 + assert [entry["timestamp"] for entry in result.played] == ["1700000300"] def test_a_zero_timestamp_is_refused(tmp_path, monkeypatch): @@ -251,11 +252,11 @@ def test_a_zero_timestamp_is_refused(tmp_path, monkeypatch): those would mean inventing when they happened.""" monkeypatch.setattr(Path, "is_file", lambda self: True) - _, _, _, timeless = submit_scrobbles.plays_from_playback_log( + result = submit_scrobbles.plays_from_playback_log( PLAYBACK_LOG, "/Music", "/mnt/mirror", runner=tags_of() ) - assert timeless == 1 + assert result.timeless == 1 def test_tags_come_from_the_mirror(tmp_path, monkeypatch): @@ -263,9 +264,9 @@ def test_tags_come_from_the_mirror(tmp_path, monkeypatch): plugin exists. Off the mirror the tags are free.""" monkeypatch.setattr(Path, "is_file", lambda self: True) - played, _, _, _ = submit_scrobbles.plays_from_playback_log( + played = submit_scrobbles.plays_from_playback_log( PLAYBACK_LOG, "/Music", "/mnt/mirror", runner=tags_of() - ) + ).played assert played[0]["artist"] == "Pendulum" assert played[0]["album"] == "Immersion" @@ -276,14 +277,16 @@ def test_tags_come_from_the_mirror(tmp_path, monkeypatch): def test_a_track_missing_from_the_mirror_is_counted_not_guessed(monkeypatch): monkeypatch.setattr(Path, "is_file", lambda self: False) - played, _, unresolved, _ = submit_scrobbles.plays_from_playback_log( + result = submit_scrobbles.plays_from_playback_log( PLAYBACK_LOG, "/Music", "/mnt/mirror", runner=tags_of() ) - assert played == [] + assert result.played == [] # One: the skip and the clockless entry are filtered before the file is # looked for, since neither would be submitted either way. - assert unresolved == 1 + assert result.unresolved == 1 + # And that one play is kept, so a later run can try it again. + assert len(result.retain) == 1 def test_playback_logs_are_found_including_rotations(tmp_path): @@ -309,3 +312,126 @@ def test_without_a_mirror_it_says_what_is_needed(tmp_path, capsys): submit_scrobbles.main([str(device)], transport=fake_transport([])) assert "pass --mirror" in capsys.readouterr().err + + +MIRROR = "/mnt/mirror" + + +def stub_ffprobe(monkeypatch, **tags): + """Answer for anything under the mirror without invoking ffprobe.""" + monkeypatch.setattr(submit_scrobbles, "_ffprobe", tags_of(**tags)) + + +def only_mirror_files_exist(monkeypatch, resolvable=None): + """Make the mirror's files appear to exist, and nothing else. + + Patching is_file wholesale makes the device directory look like a log file, + which sends main() down the .scrobbler.log path instead. + """ + real = Path.is_file + + def patched(self): + text = str(self) + if text.startswith(MIRROR): + return resolvable is None or text == resolvable + return real(self) + + monkeypatch.setattr(Path, "is_file", patched) + + +def playback_device(tmp_path, log=PLAYBACK_LOG): + device = tmp_path / "IPOD" + (device / ".rockbox").mkdir(parents=True) + (device / ".rockbox" / "playback.log").write_text(log) + return device + + +def test_a_failed_submission_keeps_every_log(tmp_path, monkeypatch): + """Nothing got through, so nothing may be set aside.""" + only_mirror_files_exist(monkeypatch) + stub_ffprobe(monkeypatch) + monkeypatch.setattr(submit_scrobbles, "load_session", lambda: "sk") + device = playback_device(tmp_path) + transport = fake_transport([{"error": 29, "message": "Rate limit"}]) + + code = submit_scrobbles.main( + [str(device), "--mirror", MIRROR, "--api-key", "k", "--api-secret", "s"], + transport=transport, + ) + + assert code == 1 + assert (device / ".rockbox" / "playback.log").is_file() + assert not list((device / ".rockbox").glob("*.submitted")) + + +def test_an_unmatched_play_is_written_back_not_lost(tmp_path, monkeypatch, capsys): + """A track the mirror does not yet hold is still a play that happened. It + is kept so a later run, after the file has been copied, can submit it.""" + monkeypatch.setattr(submit_scrobbles, "load_session", lambda: "sk") + # Only the first track resolves; the rest are absent from the mirror. + only_mirror_files_exist(monkeypatch, f"{MIRROR}/Pendulum/Immersion/01.mp3") + stub_ffprobe(monkeypatch) + log = ( + "1700000300:180000:245000:/Music/Pendulum/Immersion/01.mp3\n" + "1700000400:180000:245000:/Music/Missing/Album/09.mp3\n" + ) + device = playback_device(tmp_path, log) + transport = fake_transport([{"scrobbles": {"@attr": {"accepted": 1, "ignored": 0}}}]) + + code = submit_scrobbles.main( + [str(device), "--mirror", MIRROR, "--api-key", "k", "--api-secret", "s"], + transport=transport, + ) + + assert code == 0 + rockbox = device / ".rockbox" + # The original is preserved untouched... + assert list(rockbox.glob("playback.log.*.submitted")) + # ...and the unmatched play is back in a live log for the next attempt. + written = (rockbox / "playback.log").read_text() + assert "Missing/Album/09.mp3" in written + assert "Pendulum/Immersion/01.mp3" not in written + + +def test_the_original_is_renamed_rather_than_deleted(tmp_path, monkeypatch): + """If Last.fm quietly dropped something, the evidence stays on the device.""" + only_mirror_files_exist(monkeypatch) + stub_ffprobe(monkeypatch) + monkeypatch.setattr(submit_scrobbles, "load_session", lambda: "sk") + device = playback_device(tmp_path) + transport = fake_transport([{"scrobbles": {"@attr": {"accepted": 1, "ignored": 0}}}]) + + submit_scrobbles.main( + [str(device), "--mirror", MIRROR, "--api-key", "k", "--api-secret", "s"], + transport=transport, + ) + + aside = list((device / ".rockbox").glob("playback.log.*.submitted")) + assert len(aside) == 1 + assert PLAYBACK_LOG.splitlines()[0] in aside[0].read_text() + + +def test_keep_leaves_everything_alone(tmp_path, monkeypatch): + only_mirror_files_exist(monkeypatch) + stub_ffprobe(monkeypatch) + monkeypatch.setattr(submit_scrobbles, "load_session", lambda: "sk") + device = playback_device(tmp_path) + transport = fake_transport([{"scrobbles": {"@attr": {"accepted": 1, "ignored": 0}}}]) + + submit_scrobbles.main( + [str(device), "--mirror", MIRROR, "--keep", + "--api-key", "k", "--api-secret", "s"], + transport=transport, + ) + + assert (device / ".rockbox" / "playback.log").read_text() == PLAYBACK_LOG + assert not list((device / ".rockbox").glob("*.submitted")) + + +def test_a_file_ffprobe_cannot_read_does_not_abandon_the_rest(monkeypatch): + """CalledProcessError is not an OSError, so one bad file used to take the + whole submission with it.""" + def broken(path): + raise subprocess.CalledProcessError(1, "ffprobe") + + assert submit_scrobbles.read_tags(Path("/mnt/mirror/x.mp3"), runner=broken) == {} diff --git a/tools/submit_scrobbles.py b/tools/submit_scrobbles.py index 71d4840..aba0bb1 100755 --- a/tools/submit_scrobbles.py +++ b/tools/submit_scrobbles.py @@ -14,11 +14,13 @@ import argparse import hashlib import json import os +import subprocess import sys import time import urllib.error import urllib.parse import urllib.request +from dataclasses import dataclass from pathlib import Path API_ROOT = "https://ws.audioscrobbler.com/2.0/" @@ -124,11 +126,16 @@ def device_to_local(path, device_prefix, mirror): def read_tags(path, runner=None): - """Return the tags of a local file, via ffprobe.""" + """Return the tags of a local file, via ffprobe. Empty if it cannot be read. + + A file ffprobe chokes on is one play left unidentified, not a reason to + abandon the rest -- and CalledProcessError is not an OSError, so catching + the obvious things is not enough. + """ runner = runner or _ffprobe try: payload = json.loads(runner(path)) - except (OSError, ValueError): + except (OSError, ValueError, subprocess.SubprocessError): return {} return { key.lower(): value @@ -137,8 +144,6 @@ def read_tags(path, runner=None): def _ffprobe(path): - import subprocess - return subprocess.run( ["ffprobe", "-v", "error", "-show_entries", "format_tags", "-of", "json", str(path)], @@ -146,28 +151,58 @@ def _ffprobe(path): ).stdout +@dataclass +class Conversion: + """What a playback log turned into, and what must not be thrown away. + + `retain` holds the raw lines of plays that were real but could not be + submitted -- a track absent from the mirror, usually because the sync had + not copied it yet. Those are written back so a later run can try again. + Skips and clockless entries are not retained: neither can ever be + submitted, and the untouched original is set aside regardless. + """ + + played: list + skipped: int = 0 + unresolved: int = 0 + timeless: int = 0 + retain: list = None + + def __post_init__(self): + if self.retain is None: + self.retain = [] + + def plays_from_playback_log(text, device_prefix, mirror, runner=None): - """Return submittable entries, plus counts of what was left out. + """Return the conversion of a playback log. Skips are decided by the same fraction the on-device plugin uses, so the two never disagree about what counted as a play. """ - played, skipped, unresolved, timeless = [], 0, 0, 0 - for stamp, elapsed, length, device_path in parse_playback_log(text): + result = Conversion(played=[]) + for line in text.splitlines(): + parsed = parse_playback_log(line) + if not parsed: + continue + stamp, elapsed, length, device_path = parsed[0] if stamp < EARLIEST_PLAUSIBLE: - timeless += 1 + result.timeless += 1 continue if length > 0 and elapsed < length * LISTENED_FRACTION: - skipped += 1 + result.skipped += 1 continue local = device_to_local(device_path, device_prefix, mirror) tags = read_tags(local, runner) if local and local.is_file() else {} artist = tags.get("artist") or tags.get("album_artist") or "" title = tags.get("title") or "" if not artist or not title: - unresolved += 1 + # A real play of a track this run could not identify. Kept, so a + # later run -- after the file has been copied, or the tags fixed -- + # can submit it rather than the play being lost. + result.unresolved += 1 + result.retain.append(line) continue - played.append( + result.played.append( { "artist": artist, "track": title, @@ -176,10 +211,11 @@ def plays_from_playback_log(text, device_prefix, mirror, runner=None): "duration": str(length // 1000) if length > 0 else "", "timestamp": str(stamp), "mbid": tags.get("musicbrainz_trackid", ""), + "line": line, } ) - played.sort(key=lambda entry: int(entry["timestamp"])) - return played, skipped, unresolved, timeless + result.played.sort(key=lambda entry: int(entry["timestamp"])) + return result def find_playback_logs(device): @@ -259,7 +295,7 @@ def batch_params(entries): return params -def submit(entries, key, secret, session, transport, delay=1.0): +def submit(entries, key, secret, session, transport, delay=1.0, on_sent=None): """Submit every entry. Returns how many the service accepted. Batches are counted as they succeed rather than at the end, so a failure @@ -275,6 +311,8 @@ def submit(entries, key, secret, session, transport, delay=1.0): block = payload.get("scrobbles", {}) summary = block.get("@attr", block) accepted += int(summary.get("accepted", len(chunk))) + if on_sent is not None: + on_sent(chunk) ignored = int(summary.get("ignored", 0)) if ignored: print(f" {ignored} of {len(chunk)} ignored by Last.fm", file=sys.stderr) @@ -324,6 +362,7 @@ def main(argv=None, transport=http_post): log = target if target.is_file() else find_log(target) logs = [] + conversion = None if log is not None: played, skipped, timeless = parse_log( log.read_text(encoding="utf-8", errors="replace") @@ -341,8 +380,12 @@ def main(argv=None, transport=http_post): text = "\n".join( path.read_text(encoding="utf-8", errors="replace") for path in logs ) - played, skipped, unresolved, timeless = plays_from_playback_log( - text, args.device_prefix, args.mirror + conversion = plays_from_playback_log(text, args.device_prefix, args.mirror) + played = conversion.played + skipped, unresolved, timeless = ( + conversion.skipped, + conversion.unresolved, + conversion.timeless, ) print( f"{len(logs)} playback log(s): {len(played)} listened, {skipped} skipped", @@ -350,8 +393,8 @@ def main(argv=None, transport=http_post): ) if unresolved: print( - f" {unresolved} could not be matched to a file in the mirror" - " and were left out", + f" {unresolved} could not be matched to a file in the mirror." + " Those plays are kept for a later run rather than discarded.", file=sys.stderr, ) else: @@ -388,22 +431,66 @@ def main(argv=None, transport=http_post): session = authorise(args.api_key, args.api_secret, transport) save_session(session) + # Recorded as each batch is accepted, so a failure partway through knows + # exactly what got through and what did not. + sent = [] try: - accepted = submit(played, args.api_key, args.api_secret, session, transport) + accepted = submit( + played, args.api_key, args.api_secret, session, transport, + on_sent=sent.extend, + ) except LastfmError as error: - print(f"submission failed: {error}", file=sys.stderr) + print(f"submission failed after {len(sent)} scrobbles: {error}", file=sys.stderr) + keep_history(logs, played, sent, conversion, args.keep) return 1 print(f"{accepted} scrobbles accepted", file=sys.stderr) - if not args.keep and accepted: - # Renamed rather than deleted: if Last.fm quietly dropped something, - # the evidence is still on the device. - for path in logs: - aside = path.with_name(f"{path.name}.{played[-1]['timestamp']}.submitted") - path.rename(aside) - print(f"log moved to {aside.name}", file=sys.stderr) + keep_history(logs, played, sent, conversion, args.keep) return 0 +def keep_history(logs, played, sent, conversion, keep): + """Set the logs aside, writing back anything still owed a submission. + + Two separate obligations. The original is preserved untouched, renamed + rather than deleted, so a play is never lost to a mistake here. And any + play that was not submitted -- unmatched, or in a batch that failed -- is + written back into a live log, so the next run tries it again instead of it + quietly vanishing with the rest. + """ + if keep or not logs: + if keep: + print("logs left in place", file=sys.stderr) + return + + submitted = {id(entry) for entry in sent} + # A .scrobbler.log was converted by the on-device plugin and carries no + # per-line record, so there is nothing to write back for it -- only the + # rename below, which loses nothing. + pending = list(conversion.retain) if conversion is not None else [] + pending += [ + entry["line"] for entry in played + if "line" in entry and id(entry) not in submitted + ] + + if not sent: + print("nothing was accepted; logs left untouched", file=sys.stderr) + return + + stamp = played[-1]["timestamp"] if played else "0" + for path in logs: + path.rename(path.with_name(f"{path.name}.{stamp}.submitted")) + + if pending: + live = logs[0].with_name("playback.log") + live.write_text("\n".join(pending) + "\n", encoding="utf-8") + print( + f"{len(pending)} plays not submitted were written back to" + f" {live.name} for the next run", + file=sys.stderr, + ) + print(f"{len(logs)} log(s) set aside as .submitted", file=sys.stderr) + + if __name__ == "__main__": sys.exit(main())