feat: convert Rockbox's playback log on the laptop, skipping the plugin

Scrobbling previously needed the on-device Last.fm plugin run by hand before
each sync, to turn Rockbox's playback log into AUDIOSCROBBLER format. Forgetting
that step means the sync submits nothing and quietly appears not to work.

Core Rockbox writes ROCKBOX_DIR/playback.log whenever "play log" is enabled,
with no plugin running at all. Each line is timestamp:elapsed_ms:length_ms:path.
The only thing missing is tags, and that is exactly why the plugin exists:
reading them back off the player is slow. Off the mirror it is free, because the
same files are already there -- so the conversion belongs on the laptop, and the
plugin can be skipped entirely.

A play counts as listened at half the track's length, matching the plugin's
savepct default, so the two cannot disagree about what a play was. A short play
is a skip. An entry with no usable timestamp is refused rather than invented,
which is the clockless case again. A path that maps to nothing in the mirror is
counted and reported instead of guessed at.

Rotated logs are picked up too; Rockbox starts a new one past half a megabyte.
All of them are renamed aside together once Last.fm has accepted the batch.

A .scrobbler.log is still read when the plugin has been run and left one.

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.

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

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
 
 

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