diff --git a/README.md b/README.md index b77b357..fd73f1f 100644 --- a/README.md +++ b/README.md @@ -309,6 +309,47 @@ 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. +### Timestamps are local wall clock, and are corrected here + +Rockbox has no concept of a timezone. Its clock is set to local time, and it +builds log timestamps with `mktime(get_time())` — but +[its `mktime`](https://git.rockbox.org/cgit/rockbox.git/tree/firmware/libc/mktime.c) +is plain calendar arithmetic that applies no offset, so the RTC's local fields +come out as if they were UTC. The number in the log is therefore ahead of the +real instant by whatever the offset was. Last.fm stores UTC, so submitting it +raw puts every play an hour into the future for the half of the year the UK is +on BST. + +Rockbox is candid about this: its scrobbler plugin writes `#TZ/UNKNOWN` in the +log header, and the AUDIOSCROBBLER spec says a device may claim `#TZ/UTC` only +if it actually converted. The correction is the consumer's job. + +Each timestamp is decoded back into the wall-clock fields it came from and +reinterpreted in the player's zone. Doing it **per play** rather than applying +one offset to the whole log matters: a week's listening can straddle a daylight +saving change, and the two sides need different offsets. A log that declares +`#TZ/UTC` is left alone, so a client that already converted is not shifted +twice. + +The zone defaults to this machine's. Set `ROCKBOX_TIMEZONE` (or pass +`--device-timezone`) to an IANA name if the player's clock is keeping a +different one. + +Because Rockbox cannot adjust for daylight saving itself, **you have to change +the player's clock by hand twice a year**. If you forget, its times are an hour +out and no amount of zone arithmetic recovers them. The submitter reports any +play that converts to a time in the future, which is what a forgotten +adjustment looks like: + +``` + 37 plays are timestamped up to 58 minutes in the future, converting from + Europe/London. Either the player's clock is wrong or that is not the zone + it is set to. +``` + +`--dry-run` prints each play's local time beside the epoch, so the conversion +can be checked against when you actually remember listening. + ### Nothing played is thrown away Two separate obligations, because a play that happened and never reached diff --git a/tests/test_submit_scrobbles.py b/tests/test_submit_scrobbles.py index 2e98b8f..39275e8 100644 --- a/tests/test_submit_scrobbles.py +++ b/tests/test_submit_scrobbles.py @@ -1,7 +1,9 @@ import json import subprocess import sys +from datetime import datetime, timezone from pathlib import Path +from zoneinfo import ZoneInfo import pytest @@ -289,6 +291,130 @@ def test_a_track_missing_from_the_mirror_is_counted_not_guessed(monkeypatch): assert len(result.retain) == 1 +LONDON = ZoneInfo("Europe/London") + +# Rockbox builds timestamps with mktime(get_time()), and its mktime applies no +# zone at all, so the number is the RTC's local wall clock read as if it were +# UTC. Under BST that puts every play an hour ahead of when it happened. +SUMMER_LOGGED = 1787839200 # 2026-08-27 14:00 written by the device +SUMMER_TRUE = 1787835600 # the instant that actually was, 13:00 UTC +WINTER_LOGGED = 1796479200 # 2026-12-05 14:00, when London is already UTC +WINTER_TRUE = 1796479200 + + +def test_a_summer_timestamp_is_pulled_back_to_real_utc(): + """The device logged 14:00 local. That was 13:00 UTC, and UTC is what + Last.fm stores.""" + assert submit_scrobbles.device_time_to_utc(SUMMER_LOGGED, LONDON) == SUMMER_TRUE + + +def test_a_winter_timestamp_is_left_alone(): + """London keeps UTC for half the year, so there is nothing to correct and + the correction must not invent an offset anyway.""" + assert submit_scrobbles.device_time_to_utc(WINTER_LOGGED, LONDON) == WINTER_TRUE + + +def test_the_converted_time_reads_back_as_the_clock_the_device_showed(): + """The round trip, which is the property that actually matters: whatever + the player's screen said is what Last.fm should show in local time.""" + shown = datetime.fromtimestamp(SUMMER_LOGGED, timezone.utc) + corrected = submit_scrobbles.device_time_to_utc(SUMMER_LOGGED, LONDON) + + assert datetime.fromtimestamp(corrected, LONDON).strftime("%Y-%m-%d %H:%M") == ( + shown.strftime("%Y-%m-%d %H:%M") + ) + + +def test_one_log_spanning_a_clock_change_converts_each_side_separately(): + """A week's listening either side of the October change carries two + different offsets. Correcting the log by a single figure would put half of + it an hour out, which is why the offset is resolved per play.""" + before, after = 1792888200, 1792899000 # 2026-10-25, 00:30 BST and 03:30 GMT + + assert submit_scrobbles.device_time_to_utc(before, LONDON) == before - 3600 + assert submit_scrobbles.device_time_to_utc(after, LONDON) == after + + +def test_a_playback_log_is_corrected_before_submission(monkeypatch): + monkeypatch.setattr(Path, "is_file", lambda self: True) + log = f"{SUMMER_LOGGED}:180000:245000:/Music/Pendulum/Immersion/01.mp3\n" + + played = submit_scrobbles.plays_from_playback_log( + log, "/Music", "/mnt/mirror", runner=tags_of(), zone=LONDON + ).played + + assert played[0]["timestamp"] == str(SUMMER_TRUE) + + +def test_a_scrobbler_log_claiming_utc_is_not_corrected_twice(): + """The format's header exists for exactly this. A client that already did + the conversion says so, and correcting it again would break it.""" + log = LOG.replace("#TZ/UNKNOWN", "#TZ/UTC") + + played, _, _ = submit_scrobbles.parse_log(log, LONDON) + + assert [entry["timestamp"] for entry in played] == ["1700000100", "1700000300"] + + +def test_a_scrobbler_log_declaring_unknown_is_corrected(): + """Rockbox writes UNKNOWN, meaning local wall clock, so the times are ours + to fix.""" + played, _, _ = submit_scrobbles.parse_log(LOG, LONDON) + + # 1700000100 and 1700000300 are November, when London is on UTC anyway; + # the point is that the header did not exempt them from being looked at. + assert submit_scrobbles.declares_utc(LOG) is False + assert [entry["timestamp"] for entry in played] == ["1700000100", "1700000300"] + + +def test_the_system_zone_keeps_its_whole_name(monkeypatch, tmp_path): + """/etc/localtime points into the tzdata tree. Taking only the last + component gives "London", which no database holds -- and the fallback for + an unknown name is a fixed offset, which is wrong for half the year. The + region has to survive.""" + zoneinfo_dir = tmp_path / "share" / "zoneinfo" / "Europe" + zoneinfo_dir.mkdir(parents=True) + (zoneinfo_dir / "London").write_bytes(b"TZif") + monkeypatch.setattr( + submit_scrobbles.Path, + "read_text", + lambda self, **kw: (_ for _ in ()).throw(OSError), + ) + monkeypatch.setattr( + submit_scrobbles.Path, + "resolve", + lambda self: zoneinfo_dir / "London", + ) + + assert submit_scrobbles.system_zone_name() == "Europe/London" + + +def test_a_named_zone_beats_the_machine_default(): + """The player may not be in the same place as the laptop.""" + assert submit_scrobbles.device_zone("Asia/Tokyo") == ZoneInfo("Asia/Tokyo") + + +def test_plays_dated_after_now_are_reported(): + """A clock never put forward, or the wrong zone, produces plays that have + not happened yet. Last.fm cannot tell those from real ones.""" + now = 1787835600 + played = [ + {"timestamp": str(now - 60)}, + {"timestamp": str(now + 3600)}, + ] + + ahead = submit_scrobbles.future_plays(played, now=now) + + assert [entry["timestamp"] for entry in ahead] == [str(now + 3600)] + + +def test_a_clock_a_minute_fast_is_not_reported(): + """Devices drift. Only an offset large enough to be a zone error matters.""" + now = 1787835600 + + assert submit_scrobbles.future_plays([{"timestamp": str(now + 60)}], now=now) == [] + + def test_playback_logs_are_found_including_rotations(tmp_path): """Rockbox rotates the log once it passes half a megabyte.""" rockbox = tmp_path / ".rockbox" diff --git a/tools/submit_scrobbles.py b/tools/submit_scrobbles.py index aba0bb1..9c2c538 100755 --- a/tools/submit_scrobbles.py +++ b/tools/submit_scrobbles.py @@ -21,7 +21,9 @@ import urllib.error import urllib.parse import urllib.request from dataclasses import dataclass +from datetime import datetime, timezone from pathlib import Path +from zoneinfo import ZoneInfo, ZoneInfoNotFoundError API_ROOT = "https://ws.audioscrobbler.com/2.0/" @@ -48,6 +50,11 @@ LISTENED_FRACTION = 0.5 # Rockbox logs ticks in milliseconds instead, which is not a date. EARLIEST_PLAUSIBLE = 1_000_000_000 +# How far ahead of now a converted play may sit before it is reported. Some +# slack absorbs a device clock drifting by a minute or two; an hour out means +# the zone is wrong or the clock was never put forward. +FUTURE_TOLERANCE_SECONDS = 300 + SESSION_FILE = Path( os.getenv("XDG_CONFIG_HOME", Path.home() / ".config") ) / "music-mirror" / "lastfm.json" @@ -57,14 +64,117 @@ class LastfmError(Exception): """A Last.fm request that failed.""" -def parse_log(text): +def system_zone_name(): + """Return this machine's IANA zone name, or "" if nothing states it. + + The name has to come out whole. /etc/localtime is a symlink into the + tzdata tree, so the part after `zoneinfo/` is the name -- taking only the + last component yields "London", which no database has, and falls back to a + fixed offset that would then be wrong for half the year. + """ + try: + named = Path("/etc/timezone").read_text(encoding="utf-8").strip() + if named: + return named + except OSError: + pass + try: + parts = Path("/etc/localtime").resolve().parts + except OSError: + return "" + if "zoneinfo" in parts: + return "/".join(parts[len(parts) - parts[::-1].index("zoneinfo"):]) + return "" + + +def device_zone(name=None): + """Return the zone the device's clock is keeping. + + Rockbox has no concept of a timezone, so its clock is set to local wall + time and the zone has to be supplied from outside. Defaulting to this + machine's zone is right whenever the player and the laptop are in the same + place, which for a device synced by cable they are. + """ + if name: + return ZoneInfo(name) + for candidate in (os.getenv("TZ"), system_zone_name()): + if not candidate: + continue + try: + return ZoneInfo(candidate) + except (ZoneInfoNotFoundError, ValueError): + continue + # Nothing named the zone, so the offset cannot be resolved per play: this + # is today's offset applied to every timestamp, which is wrong either side + # of a daylight saving change. Still better than pretending it logged UTC. + print( + "warning: no IANA timezone found for this machine; using its current" + " offset for every play. Pass --device-timezone to fix older plays" + " across a daylight saving change.", + file=sys.stderr, + ) + return datetime.now().astimezone().tzinfo + + +def device_time_to_utc(stamp, zone): + """Return the true UTC epoch of a timestamp Rockbox wrote. + + Rockbox builds its timestamps with `mktime(get_time())`, and its mktime + (firmware/libc/mktime.c) is plain calendar arithmetic with no zone applied. + Fed the RTC's local fields it yields local-wall-clock-as-if-UTC, so the + number is ahead of real UTC by whatever the offset was. Its own scrobbler + plugin admits this by writing `#TZ/UNKNOWN`, leaving the correction here. + + Decoding the number back into those fields and reinterpreting them in the + device's zone recovers the instant, and does so per play, so a log + straddling a daylight-saving change converts each side by its own offset. + """ + fields = datetime.fromtimestamp(stamp, timezone.utc).replace(tzinfo=zone) + return int(fields.timestamp()) + + +def future_plays(played, now=None): + """Return the plays timestamped later than now, which cannot have happened. + + A device clock left on the wrong offset, or never adjusted across a + daylight-saving change, shows up here. Last.fm has no way to tell such a + scrobble from a real one, so it is worth saying out loud. + """ + now = time.time() if now is None else now + return [ + entry for entry in played + if int(entry["timestamp"]) > now + FUTURE_TOLERANCE_SECONDS + ] + + +def declares_utc(text): + """Whether an AUDIOSCROBBLER log says its timestamps are already UTC. + + The format's header carries `#TZ/UTC` or `#TZ/UNKNOWN`, and its spec is + explicit that a device may only claim UTC if it converted. Rockbox writes + UNKNOWN, meaning the times are local wall clock and want correcting; a log + from anything that claims UTC must be left alone. + """ + for line in text.splitlines(): + if not line.startswith("#"): + break + if line.strip().upper().startswith("#TZ/"): + return line.strip().upper() == "#TZ/UTC" + return False + + +def parse_log(text, zone=None): """Return the listened tracks in an AUDIOSCROBBLER log, oldest first. Fields are artist, album, title, track number, length, rating, timestamp and MusicBrainz id. Rockbox converts any tab inside a field to a space before writing, so splitting on tabs is safe. + + Timestamps are corrected from the device's local wall clock to UTC unless + the log's own header claims it did that already. """ played, skipped, timeless = [], 0, 0 + convert = zone is not None and not declares_utc(text) for line in text.splitlines(): if not line or line.startswith("#"): continue @@ -85,6 +195,8 @@ def parse_log(text): continue if not artist or not title: continue + if convert: + when = device_time_to_utc(when, zone) played.append( { "artist": artist, @@ -173,11 +285,13 @@ class Conversion: self.retain = [] -def plays_from_playback_log(text, device_prefix, mirror, runner=None): +def plays_from_playback_log(text, device_prefix, mirror, runner=None, zone=None): """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. + two never disagree about what counted as a play. Timestamps are corrected + from the device's wall clock to UTC; the core log has no header to say so, + but it is written the same way the plugin's UNKNOWN times are. """ result = Conversion(played=[]) for line in text.splitlines(): @@ -209,7 +323,9 @@ def plays_from_playback_log(text, device_prefix, mirror, runner=None): "album": tags.get("album", ""), "trackNumber": (tags.get("track") or "").split("/")[0], "duration": str(length // 1000) if length > 0 else "", - "timestamp": str(stamp), + "timestamp": str( + device_time_to_utc(stamp, zone) if zone is not None else stamp + ), "mbid": tags.get("musicbrainz_trackid", ""), "line": line, } @@ -350,6 +466,14 @@ def main(argv=None, transport=http_post): help="where the music sits on the device, stripped when mapping a logged" " path back onto the mirror", ) + parser.add_argument( + "--device-timezone", + default=os.getenv("ROCKBOX_TIMEZONE"), + help="the zone the player's clock is set to, as an IANA name such as" + " Europe/London. Rockbox keeps local wall time and cannot record an" + " offset, so its timestamps need this to become the UTC Last.fm wants." + " Defaults to this machine's zone", + ) 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") @@ -358,6 +482,12 @@ def main(argv=None, transport=http_post): ) args = parser.parse_args(argv) + try: + zone = device_zone(args.device_timezone) + except (ZoneInfoNotFoundError, ValueError) as error: + print(f"unknown timezone {args.device_timezone!r}: {error}", file=sys.stderr) + return 2 + target = Path(args.device) log = target if target.is_file() else find_log(target) logs = [] @@ -365,7 +495,7 @@ def main(argv=None, transport=http_post): conversion = None if log is not None: played, skipped, timeless = parse_log( - log.read_text(encoding="utf-8", errors="replace") + log.read_text(encoding="utf-8", errors="replace"), zone ) unresolved = 0 logs = [log] @@ -380,7 +510,9 @@ def main(argv=None, transport=http_post): text = "\n".join( path.read_text(encoding="utf-8", errors="replace") for path in logs ) - conversion = plays_from_playback_log(text, args.device_prefix, args.mirror) + conversion = plays_from_playback_log( + text, args.device_prefix, args.mirror, zone=zone + ) played = conversion.played skipped, unresolved, timeless = ( conversion.skipped, @@ -413,9 +545,24 @@ def main(argv=None, transport=http_post): ) if not played: return 0 + + ahead = future_plays(played) + if ahead: + newest = int(ahead[-1]["timestamp"]) - int(time.time()) + print( + f" {len(ahead)} plays are timestamped up to {newest // 60} minutes in" + f" the future, converting from {zone}. Either the player's clock is" + " wrong or that is not the zone it is set to.", + file=sys.stderr, + ) + if args.dry_run: for entry in played[:20]: - print(f"{entry['timestamp']}\t{entry['artist']}\t{entry['track']}") + when = datetime.fromtimestamp(int(entry["timestamp"]), zone) + print( + f"{entry['timestamp']}\t{when:%Y-%m-%d %H:%M %Z}" + f"\t{entry['artist']}\t{entry['track']}" + ) return 0 if not args.api_key or not args.api_secret: diff --git a/tools/sync-to-ipod.sh b/tools/sync-to-ipod.sh index 97690db..8da0091 100755 --- a/tools/sync-to-ipod.sh +++ b/tools/sync-to-ipod.sh @@ -41,6 +41,12 @@ Submitting scrobbles needs LASTFM_API_KEY and LASTFM_API_SECRET; it is skipped with a note when they are unset. Scrobbling is a write method and needs the secret, unlike the read-only calls elsewhere in these projects. +Rockbox has no notion of a timezone: its clock holds local wall time and its +logs record that, not UTC. Set ROCKBOX_TIMEZONE to the zone the player's clock +is keeping (an IANA name, such as Europe/London) if it differs from this +machine's, which is otherwise assumed. Getting it wrong shifts every scrobble +by the difference. + The mirror is the directory holding the artist folders. The destination is where those folders should end up on the device -- not the card root, unless that is genuinely where you want them: @@ -158,6 +164,11 @@ if $scrobble; then else scrobble_options=() $dry_run && scrobble_options+=(--dry-run) + # Rockbox keeps local wall time with no notion of a zone, so its + # timestamps are not the UTC Last.fm expects. Naming the zone the + # player's clock is set to lets them be corrected. + [ -n "${ROCKBOX_TIMEZONE:-}" ] && + scrobble_options+=(--device-timezone "$ROCKBOX_TIMEZONE") # --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.