diff --git a/README.md b/README.md index 1f455e2..c36ba1c 100644 --- a/README.md +++ b/README.md @@ -286,8 +286,18 @@ The unmount is the point of doing this in a script. FAT32 has no journal and the device is reached through disk mode, so an interrupted write is corruption that needs `fsck.vfat` from another machine. -`submit_scrobbles.py` sends the Rockbox scrobbler log to Last.fm and sets it -aside. Rockbox writes `/.scrobbler.log` in AUDIOSCROBBLER 1.1 format, one +`submit_scrobbles.py` sends what was played to Last.fm and sets the logs aside. + +It reads **Rockbox's own `playback.log`**, which core Rockbox writes whenever +"play log" is enabled, with no plugin running. Each line is +`timestamp:elapsed_ms:length_ms:path` — a path and nothing else, which is why +the on-device scrobbler plugin exists at all: reading tags back off the player +is slow. Off the mirror it is free, so `--mirror` lets the conversion happen +here and the plugin never has to be run. A play counts as listened at half the +track's length, the same fraction the plugin uses, so the two cannot disagree +about what a play was. + +It still reads a `.scrobbler.log` if the plugin has been run and left one. Rockbox writes `/.scrobbler.log` in AUDIOSCROBBLER 1.1 format, one tab-separated line per track rated `L` for listened or `S` for skipped; only the listened ones are sent. It runs **before** the copy, since the plays already happened and a failed transfer is no reason to lose them. diff --git a/tests/test_submit_scrobbles.py b/tests/test_submit_scrobbles.py index d91e8b5..ae48c7b 100644 --- a/tests/test_submit_scrobbles.py +++ b/tests/test_submit_scrobbles.py @@ -187,3 +187,125 @@ def test_write_credentials_are_required(tmp_path, capsys, monkeypatch): assert code == 2 assert "LASTFM_API_SECRET" in capsys.readouterr().err + + +PLAYBACK_LOG = """1700000300:180000:245000:/Music/Pendulum/Immersion/01.mp3 +1700000200:9000:180000:/Music/Green Day/Dookie/07.mp3 +0:180000:245000:/Music/No/Clock/track.mp3 +malformed line without colons +""" + + +def tags_of(artist="Pendulum", title="Watercolour", album="Immersion", track="1/11"): + def runner(path): + return json.dumps( + {"format": {"tags": {"ARTIST": artist, "TITLE": title, + "ALBUM": album, "track": track}}} + ) + + return runner + + +def test_the_playback_log_format_is_four_fields(): + """timestamp:elapsed_ms:length_ms:path, written by Rockbox core.""" + plays = submit_scrobbles.parse_playback_log(PLAYBACK_LOG) + + assert len(plays) == 3 # the malformed line is dropped + assert plays[0] == (1700000300, 180000, 245000, "/Music/Pendulum/Immersion/01.mp3") + + +def test_a_device_path_maps_onto_the_mirror(): + assert submit_scrobbles.device_to_local( + "/Music/Pendulum/Immersion/01.mp3", "/Music", "/mnt/mirror" + ) == Path("/mnt/mirror/Pendulum/Immersion/01.mp3") + + +def test_a_path_outside_the_prefix_is_not_mapped(): + """Something played from elsewhere on the card is not in the mirror.""" + assert submit_scrobbles.device_to_local( + "/Podcasts/episode.mp3", "/Music", "/mnt/mirror" + ) is None + + +def test_a_path_at_the_card_root_maps_straight_across(): + assert submit_scrobbles.device_to_local( + "/Pendulum/Immersion/01.mp3", "/", "/mnt/mirror" + ) == Path("/mnt/mirror/Pendulum/Immersion/01.mp3") + + +def test_a_short_play_is_a_skip_not_a_scrobble(tmp_path, monkeypatch): + """Nine seconds of a three minute track. The on-device plugin uses the same + 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( + PLAYBACK_LOG, "/Music", "/mnt/mirror", runner=tags_of() + ) + + assert skipped == 1 + assert [entry["timestamp"] for entry in played] == ["1700000300"] + + +def test_a_zero_timestamp_is_refused(tmp_path, monkeypatch): + """Without a real-time clock Rockbox logs ticks, not dates. Scrobbling + those would mean inventing when they happened.""" + monkeypatch.setattr(Path, "is_file", lambda self: True) + + _, _, _, timeless = submit_scrobbles.plays_from_playback_log( + PLAYBACK_LOG, "/Music", "/mnt/mirror", runner=tags_of() + ) + + assert timeless == 1 + + +def test_tags_come_from_the_mirror(tmp_path, monkeypatch): + """The log carries only a path -- which is precisely why the on-device + plugin exists. Off the mirror the tags are free.""" + monkeypatch.setattr(Path, "is_file", lambda self: True) + + played, _, _, _ = submit_scrobbles.plays_from_playback_log( + PLAYBACK_LOG, "/Music", "/mnt/mirror", runner=tags_of() + ) + + assert played[0]["artist"] == "Pendulum" + assert played[0]["album"] == "Immersion" + assert played[0]["trackNumber"] == "1" # "1/11" -> "1" + assert played[0]["duration"] == "245" # milliseconds -> seconds + + +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( + PLAYBACK_LOG, "/Music", "/mnt/mirror", runner=tags_of() + ) + + assert 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 + + +def test_playback_logs_are_found_including_rotations(tmp_path): + """Rockbox rotates the log once it passes half a megabyte.""" + rockbox = tmp_path / ".rockbox" + rockbox.mkdir() + for name in ("playback.log", "playback_0001.log", "playback_0002.log"): + (rockbox / name).write_text("1700000000:1:1:/Music/a.mp3\n") + (rockbox / "empty.log").write_text("") + + found = submit_scrobbles.find_playback_logs(tmp_path) + + assert [path.name for path in found] == [ + "playback.log", "playback_0001.log", "playback_0002.log" + ] + + +def test_without_a_mirror_it_says_what_is_needed(tmp_path, capsys): + device = tmp_path / "IPOD" + (device / ".rockbox").mkdir(parents=True) + (device / ".rockbox" / "playback.log").write_text("1700000000:1:1:/Music/a.mp3\n") + + submit_scrobbles.main([str(device)], transport=fake_transport([])) + + assert "pass --mirror" in capsys.readouterr().err diff --git a/tools/submit_scrobbles.py b/tools/submit_scrobbles.py index 3468852..71d4840 100755 --- a/tools/submit_scrobbles.py +++ b/tools/submit_scrobbles.py @@ -31,6 +31,21 @@ BATCH = 50 # scrobble. LOG_NAMES = (".scrobbler.log", ".scrobbler-timeless.log") +# Rockbox core writes this whenever "play log" is on, with no plugin running: +# timestamp:elapsed_ms:length_ms:/Music/Artist/Album/Track.mp3 +# It is rotated once it grows past half a megabyte. Converting it needs tags, +# which is why the on-device plugin exists -- reading them back off the player +# is slow. Off the mirror it is free, so the plugin can be skipped entirely. +PLAYBACK_LOG_NAMES = ("playback.log", "playback_*.log") + +# The plugin counts a track as listened at savepct of its length, defaulting to +# fifty. Same rule here, or the two disagree about what a play is. +LISTENED_FRACTION = 0.5 + +# Below this a timestamp is not a wall-clock time. Without a real-time clock +# Rockbox logs ticks in milliseconds instead, which is not a date. +EARLIEST_PLAUSIBLE = 1_000_000_000 + SESSION_FILE = Path( os.getenv("XDG_CONFIG_HOME", Path.home() / ".config") ) / "music-mirror" / "lastfm.json" @@ -83,6 +98,98 @@ def parse_log(text): return played, skipped, timeless +def parse_playback_log(text): + """Return (timestamp, elapsed_ms, length_ms, path) for each logged play.""" + plays = [] + for line in text.splitlines(): + fields = line.strip().split(":", 3) + if len(fields) != 4: + continue + stamp, elapsed, length, path = fields + try: + plays.append((int(stamp), int(elapsed), int(length), path)) + except ValueError: + continue + return plays + + +def device_to_local(path, device_prefix, mirror): + """Map a path as the player sees it onto the mirror it was copied from.""" + prefix = "/" + device_prefix.strip("/") + if prefix != "/": + if not path.startswith(prefix + "/"): + return None + path = path[len(prefix) :] + return Path(mirror) / path.lstrip("/") + + +def read_tags(path, runner=None): + """Return the tags of a local file, via ffprobe.""" + runner = runner or _ffprobe + try: + payload = json.loads(runner(path)) + except (OSError, ValueError): + return {} + return { + key.lower(): value + for key, value in (payload.get("format", {}).get("tags") or {}).items() + } + + +def _ffprobe(path): + import subprocess + + return subprocess.run( + ["ffprobe", "-v", "error", "-show_entries", "format_tags", + "-of", "json", str(path)], + capture_output=True, text=True, check=True, + ).stdout + + +def plays_from_playback_log(text, device_prefix, mirror, runner=None): + """Return submittable entries, plus counts of what was left out. + + 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): + if stamp < EARLIEST_PLAUSIBLE: + timeless += 1 + continue + if length > 0 and elapsed < length * LISTENED_FRACTION: + 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 + continue + played.append( + { + "artist": artist, + "track": title, + "album": tags.get("album", ""), + "trackNumber": (tags.get("track") or "").split("/")[0], + "duration": str(length // 1000) if length > 0 else "", + "timestamp": str(stamp), + "mbid": tags.get("musicbrainz_trackid", ""), + } + ) + played.sort(key=lambda entry: int(entry["timestamp"])) + return played, skipped, unresolved, timeless + + +def find_playback_logs(device): + """Return every playback log on a device, oldest first.""" + found = [] + for pattern in PLAYBACK_LOG_NAMES: + found.extend(sorted(Path(device).glob(f".rockbox/{pattern}"))) + return [path for path in found if path.is_file() and path.stat().st_size] + + def sign(params, secret): """Return Last.fm's method signature for a set of parameters. @@ -193,6 +300,18 @@ def find_log(device): def main(argv=None, transport=http_post): parser = argparse.ArgumentParser(description=__doc__) parser.add_argument("device", help="the mounted device, or a scrobbler log file") + parser.add_argument( + "--mirror", + help="the mirror the device was copied from. Given this, Rockbox's own" + " playback.log is converted here rather than needing the on-device" + " plugin run first", + ) + parser.add_argument( + "--device-prefix", + default="/Music", + help="where the music sits on the device, stripped when mapping a logged" + " path back onto the mirror", + ) parser.add_argument("--api-key", default=os.getenv("LASTFM_API_KEY")) parser.add_argument("--api-secret", default=os.getenv("LASTFM_API_SECRET")) parser.add_argument("--dry-run", action="store_true", help="parse and report only") @@ -203,12 +322,46 @@ def main(argv=None, transport=http_post): target = Path(args.device) log = target if target.is_file() else find_log(target) - if log is None: - print("no scrobbler log to submit", file=sys.stderr) + logs = [] + + if log is not None: + played, skipped, timeless = parse_log( + log.read_text(encoding="utf-8", errors="replace") + ) + unresolved = 0 + logs = [log] + print(f"{log}: {len(played)} listened, {skipped} skipped", file=sys.stderr) + elif args.mirror: + # No plugin has been run, but the core log is there. Tags come off the + # mirror, which is the only reason the plugin was needed at all. + logs = find_playback_logs(target) + if not logs: + print("no scrobbler log to submit", file=sys.stderr) + return 0 + 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 + ) + print( + f"{len(logs)} playback log(s): {len(played)} listened, {skipped} skipped", + file=sys.stderr, + ) + if unresolved: + print( + f" {unresolved} could not be matched to a file in the mirror" + " and were left out", + file=sys.stderr, + ) + else: + print( + "no scrobbler log to submit. Rockbox's own playback.log can be used" + " instead -- pass --mirror so tags can be read from it.", + file=sys.stderr, + ) return 0 - played, skipped, timeless = parse_log(log.read_text(encoding="utf-8", errors="replace")) - print(f"{log}: {len(played)} listened, {skipped} skipped", file=sys.stderr) if timeless: print( f" {timeless} entries have no timestamp, so this target has no clock." @@ -245,9 +398,10 @@ def main(argv=None, transport=http_post): if not args.keep and accepted: # Renamed rather than deleted: if Last.fm quietly dropped something, # the evidence is still on the device. - aside = log.with_name(f"{log.name}.{played[-1]['timestamp']}.submitted") - log.rename(aside) - print(f"log moved to {aside.name}", file=sys.stderr) + 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) return 0 diff --git a/tools/sync-to-ipod.sh b/tools/sync-to-ipod.sh index 206293d..97690db 100755 --- a/tools/sync-to-ipod.sh +++ b/tools/sync-to-ipod.sh @@ -158,7 +158,11 @@ if $scrobble; then else scrobble_options=() $dry_run && scrobble_options+=(--dry-run) - python3 "$here/submit_scrobbles.py" "${scrobble_options[@]}" "$destination" || + # --mirror lets it convert Rockbox's own playback.log, so the on-device + # scrobbler plugin never has to be run. The device root, not the music + # directory: the logs live in .rockbox. + python3 "$here/submit_scrobbles.py" "${scrobble_options[@]}" \ + --mirror "$mirror" --device-prefix "$device_prefix" "$mounted_on" || die "submitting scrobbles failed; nothing has been copied" fi fi