diff --git a/screen_locker/_auto_upgrade.py b/screen_locker/_auto_upgrade.py index 8500fac..388f4ac 100644 --- a/screen_locker/_auto_upgrade.py +++ b/screen_locker/_auto_upgrade.py @@ -92,15 +92,23 @@ class AutoUpgradeMixin(_ReasonsMixin): def _check_today_state_exits(self) -> bool: """Handle early-bird and today's log states. Return True to stop startup.""" - if self._is_early_bird_pending() and not self._is_early_bird_time(): - if self._try_auto_upgrade_early_bird(): - _skip( - "early_bird_auto_upgraded", - "Auto-upgraded early_bird entry to phone_verified.", - ) - return True - return False # Expired early bird, upgrade unavailable — full lock. - if self._is_early_bird_pending(): + pending = self._is_early_bird_pending() + window_open = self._is_early_bird_time() + if pending and not window_open and self._try_auto_upgrade_early_bird(): + _skip( + "early_bird_auto_upgraded", + "Auto-upgraded early_bird entry to phone_verified.", + ) + return True + # An expired marker with nothing to upgrade is NOT a lock on its own. + # It used to `return False` right here, ahead of has_logged_today, so + # a workout logged by any other path after 08:30 never counted while + # the marker lasted: on 2026-09-18 a manual walk entered on the lock + # screen at 09:32 closed the lock, and the 09:35 tick locked again -- + # every 5 minutes, for the rest of the day -- while the explain chain + # (_compliance_state, where the expired marker is non-terminal) said + # "lock skipped". Fall through to the same ladder as any other morning. + if pending and window_open: # The ONLY thing that closes this window is # early-bird-workout-check.timer. When that timer was disabled by an # ordering cycle (2026-08-04) this branch silently deferred the lock @@ -136,7 +144,7 @@ class AutoUpgradeMixin(_ReasonsMixin): "Wake alarm earned a workout skip.", **self._other_conditions("wake_alarm_skip"), ) - elif self._is_early_bird_time(): + elif window_open: self._save_early_bird_pending() _skip( "early_bird_banked", diff --git a/screen_locker/_manual_sync.py b/screen_locker/_manual_sync.py index 9e6dcb0..bbe1233 100644 --- a/screen_locker/_manual_sync.py +++ b/screen_locker/_manual_sync.py @@ -22,11 +22,14 @@ import logging from typing import TYPE_CHECKING from screen_locker._log_io import load_workout_log -from screen_locker._log_mixin import write_signed_entry +from screen_locker._log_mixin import _entry_workout_id, write_signed_entry +from screen_locker._manual_sync_draft import ( + _draft_or_report, + is_empty_stub, + reconstruct_draft, +) from screen_locker._manual_workout import ( MANUAL_WORKOUT_SYNC_KIND, - SPORT_OTHER, - ManualWorkoutDraft, build_entry, is_budget_exhausted, validate_manual_workout, @@ -38,140 +41,31 @@ if TYPE_CHECKING: OnIngestedCallback = Callable[[dict, "list[dict]"], None] +__all__ = ["ingest_manual_records", "is_empty_stub", "reconstruct_draft"] + _logger = logging.getLogger(__name__) # Key under which the source sync record id is stored in the ingested # ``workout_data`` — makes re-ingestion of the same record idempotent. _SYNC_ID_FIELD = "sync_record_id" -# The raw user inputs every real manual workout carries. A payload holding none -# of them is a metadata stub, not a damaged workout: there is nothing to -# recover and no amount of retrying will change that. -_SUBSTANTIVE_FIELDS = frozenset( - { - "sport", - "start_time", - "end_time", - "location_name", - "transport_method", - "cost", - "rpe", - "went_well", - "to_improve", - "overall_feeling", - } -) - - -def is_empty_stub(payload: Mapping[str, object]) -> bool: - """True when ``payload`` carries no workout content at all. - - Observed in the wild as ``{"type", "kind", "date"}`` and nothing else -- - a record the phone created without ever attaching the workout. Every sync - cycle re-reported it as malformed, so a permanent, unfixable condition - produced an unbounded stream of identical warnings (four every 15 minutes), - which is how the genuinely actionable lines got lost in the noise. - """ - return not (_SUBSTANTIVE_FIELDS & set(payload)) - - -def _coerce_int(value: object) -> int: - """Coerce a JSON scalar to int; raise for a non-numeric (skips the record).""" - if isinstance(value, (int, str)): - return int(value) - raise TypeError(value) - - -def reconstruct_draft(payload: Mapping[str, object]) -> ManualWorkoutDraft | None: - """Rebuild a :class:`ManualWorkoutDraft` from a synced manual payload. - - Returns None if a required raw field is missing or mistyped, so a malformed - record is skipped rather than crashing ingestion. Only the raw user inputs - are read back — the derived fields (``source``, ``duration_minutes``, - ``type``) are recomputed by :func:`build_entry` on the PC. - """ - try: - sport = str(payload["sport"]) - activity_type_other = ( - str(payload.get("activity_type", "")) if sport == SPORT_OTHER else "" - ) - return ManualWorkoutDraft( - sport=sport, - start_time=str(payload["start_time"]), - end_time=str(payload["end_time"]), - location_name=str(payload["location_name"]), - transport_method=str(payload["transport_method"]), - cost=str(payload["cost"]), - rpe=_coerce_int(payload["rpe"]), - went_well=str(payload["went_well"]), - to_improve=str(payload["to_improve"]), - overall_feeling=str(payload["overall_feeling"]), - reservation_phone=str(payload.get("reservation_phone", "")), - techniques_practiced=str(payload.get("techniques_practiced", "")), - warm_up_minutes=str(payload.get("warm_up_minutes", "")), - pain_or_injury=str(payload.get("pain_or_injury", "none")), - matches_won=_coerce_int(payload.get("matches_won", 0)), - matches_lost=_coerce_int(payload.get("matches_lost", 0)), - sets_won=_coerce_int(payload.get("sets_won", 0)), - sets_lost=_coerce_int(payload.get("sets_lost", 0)), - racket=str(payload.get("racket", "")), - balls=str(payload.get("balls", "")), - activity_type_other=activity_type_other, - activity_details=str(payload.get("activity_details", "")), - equipment=str(payload.get("equipment", "")), - ) - except (KeyError, TypeError, ValueError) as exc: - _logger.warning( - "Synced manual workout payload is malformed (%s: %s) — SKIPPING " - "this record, so it will not be logged or counted on the PC", - type(exc).__name__, - exc, - ) - return None - - -def _draft_or_report( - record_id: str, payload: Mapping[str, object] -) -> ManualWorkoutDraft | None: - """Rebuild the draft, or report why it cannot be rebuilt and return None. - - The two failure modes are deliberately reported at different levels, because - only one of them is actionable: - - * an **empty stub** carries no workout at all (seen as ``{type, kind, - date}``) -- nothing to recover, nothing to fix, so re-reporting it at - ``warning`` on every 15-minute sync cycle only teaches the reader to - ignore this logger; - * a **malformed** payload has real workout fields that would not parse, - which means genuine credit may be going missing -- that stays loud. - """ - if is_empty_stub(payload): - _logger.info( - "Manual record %s is an empty stub (keys: %s) — no workout data to " - "ingest; skipping permanently, no credit is being lost", - record_id, - sorted(payload), - ) - return None - draft = reconstruct_draft(payload) - if draft is None: - _logger.warning( - "Manual record %s is malformed — it HAS workout fields but they " - "could not be parsed, so real credit may be lost", - record_id, - ) - return draft - def _already_ingested(logs: dict[str, list[dict]], record_id: str) -> bool: - """True if any logged entry already carries this sync record id. + """True if any logged entry already IS this sync record. - Iterates the per-day lists (a day may hold several workouts); a cheap - early-out before reconstructing the draft. The write chokepoint also dedups - by ``workout_id``, so this and that are two guards on the same idempotency. + Matches either way a record can already be here: an entry ingested from + sync carries the id in ``sync_record_id``; an entry logged on this PC + (form or CLI) and then published carries it as its own ``workout_id``, + since the publisher keys records on exactly that. Checking only the first + is how the 2026-09-13 football was re-ingested: it had been logged locally + (no ``sync_record_id``), pushed as ``manual:2026-09-12T14:30``, and pulled + back as a "new" record. A cheap early-out before reconstructing the draft; + the write chokepoint dedups by ``workout_id`` as a second guard. """ - for entries in logs.values(): + for day, entries in logs.items(): for entry in entries: + if _entry_workout_id(day, entry) == record_id: + return True workout_data = entry.get("workout_data", {}) if ( isinstance(workout_data, dict) @@ -229,6 +123,13 @@ def ingest_manual_records( continue entry = build_entry(draft) entry[_SYNC_ID_FIELD] = record_id + # The wire id IS the workout's id: the device that logged it minted + # ``manual:T`` once, and the publisher keys on the same + # id. Without this the chokepoint re-derived one from ``date`` + + # start, and when the two dates disagreed (a record whose day key was + # later corrected to the local day) the same workout landed twice + # under two ids -- and then consumed two manual-budget slots. + entry["workout_id"] = record_id result = write_signed_entry(log_file, date, entry) if not result.appended: # This is dedup working, not credit being lost: the workout is diff --git a/screen_locker/_manual_sync_draft.py b/screen_locker/_manual_sync_draft.py new file mode 100644 index 0000000..10f588a --- /dev/null +++ b/screen_locker/_manual_sync_draft.py @@ -0,0 +1,140 @@ +"""Rebuild a :class:`ManualWorkoutDraft` from a synced manual-workout payload. + +Split out of :mod:`screen_locker._manual_sync` to keep every file under the +250-line cap; that module re-exports :func:`reconstruct_draft` and +:func:`is_empty_stub`, so callers and patch targets are unchanged. + +Only the raw user inputs are read back — the derived fields (``source``, +``duration_minutes``, ``type``) are recomputed on the PC by ``build_entry``, +which is what keeps a phone from ever dictating what a workout is worth. +""" + +from __future__ import annotations + +import logging +from typing import TYPE_CHECKING + +from screen_locker._manual_workout import SPORT_OTHER, ManualWorkoutDraft + +if TYPE_CHECKING: + from collections.abc import Mapping + +_logger = logging.getLogger(__name__) + +# The raw user inputs every real manual workout carries. A payload holding none +# of them is a metadata stub, not a damaged workout: there is nothing to +# recover and no amount of retrying will change that. +_SUBSTANTIVE_FIELDS = frozenset( + { + "sport", + "start_time", + "end_time", + "location_name", + "transport_method", + "cost", + "rpe", + "went_well", + "to_improve", + "overall_feeling", + } +) + + +def is_empty_stub(payload: Mapping[str, object]) -> bool: + """True when ``payload`` carries no workout content at all. + + Observed in the wild as ``{"type", "kind", "date"}`` and nothing else -- + a record the phone created without ever attaching the workout. Every sync + cycle re-reported it as malformed, so a permanent, unfixable condition + produced an unbounded stream of identical warnings (four every 15 minutes), + which is how the genuinely actionable lines got lost in the noise. + """ + return not (_SUBSTANTIVE_FIELDS & set(payload)) + + +def _coerce_int(value: object) -> int: + """Coerce a JSON scalar to int; raise for a non-numeric (skips the record).""" + if isinstance(value, (int, str)): + return int(value) + raise TypeError(value) + + +def reconstruct_draft(payload: Mapping[str, object]) -> ManualWorkoutDraft | None: + """Rebuild a :class:`ManualWorkoutDraft` from a synced manual payload. + + Returns None if a required raw field is missing or mistyped, so a malformed + record is skipped rather than crashing ingestion. Only the raw user inputs + are read back — the derived fields (``source``, ``duration_minutes``, + ``type``) are recomputed by :func:`build_entry` on the PC. + """ + try: + sport = str(payload["sport"]) + activity_type_other = ( + str(payload.get("activity_type", "")) if sport == SPORT_OTHER else "" + ) + return ManualWorkoutDraft( + sport=sport, + start_time=str(payload["start_time"]), + end_time=str(payload["end_time"]), + location_name=str(payload["location_name"]), + transport_method=str(payload["transport_method"]), + cost=str(payload["cost"]), + rpe=_coerce_int(payload["rpe"]), + went_well=str(payload["went_well"]), + to_improve=str(payload["to_improve"]), + overall_feeling=str(payload["overall_feeling"]), + reservation_phone=str(payload.get("reservation_phone", "")), + techniques_practiced=str(payload.get("techniques_practiced", "")), + warm_up_minutes=str(payload.get("warm_up_minutes", "")), + pain_or_injury=str(payload.get("pain_or_injury", "none")), + matches_won=_coerce_int(payload.get("matches_won", 0)), + matches_lost=_coerce_int(payload.get("matches_lost", 0)), + sets_won=_coerce_int(payload.get("sets_won", 0)), + sets_lost=_coerce_int(payload.get("sets_lost", 0)), + racket=str(payload.get("racket", "")), + balls=str(payload.get("balls", "")), + activity_type_other=activity_type_other, + activity_details=str(payload.get("activity_details", "")), + equipment=str(payload.get("equipment", "")), + ) + except (KeyError, TypeError, ValueError) as exc: + _logger.warning( + "Synced manual workout payload is malformed (%s: %s) — SKIPPING " + "this record, so it will not be logged or counted on the PC", + type(exc).__name__, + exc, + ) + return None + + +def _draft_or_report( + record_id: str, payload: Mapping[str, object] +) -> ManualWorkoutDraft | None: + """Rebuild the draft, or report why it cannot be rebuilt and return None. + + The two failure modes are deliberately reported at different levels, because + only one of them is actionable: + + * an **empty stub** carries no workout at all (seen as ``{type, kind, + date}``) -- nothing to recover, nothing to fix, so re-reporting it at + ``warning`` on every 15-minute sync cycle only teaches the reader to + ignore this logger; + * a **malformed** payload has real workout fields that would not parse, + which means genuine credit may be going missing -- that stays loud. + """ + if is_empty_stub(payload): + _logger.info( + "Manual record %s is an empty stub (keys: %s) — no workout data to " + "ingest; skipping permanently, no credit is being lost", + record_id, + sorted(payload), + ) + return None + draft = reconstruct_draft(payload) + if draft is None: + _logger.warning( + "Manual record %s is malformed — it HAS workout fields but they " + "could not be parsed, so real credit may be lost", + record_id, + ) + return draft diff --git a/screen_locker/_manual_workout_types.py b/screen_locker/_manual_workout_types.py index 1e01489..4509335 100644 --- a/screen_locker/_manual_workout_types.py +++ b/screen_locker/_manual_workout_types.py @@ -21,6 +21,7 @@ from screen_locker._constants import ( ) from screen_locker._day import today_str from screen_locker._log_io import load_workout_log +from screen_locker._weekly_check import credit_key, day_workout_index if TYPE_CHECKING: from pathlib import Path @@ -63,13 +64,21 @@ def count_in_window( *, today: str | None = None, ) -> int: - """Return how many ``manual_workout`` ENTRIES fall in the trailing window. + """Return how many manual-workout CREDITS fall in the trailing window. - Counted per entry, not per day: each logged manual workout consumes its + Counted per workout, not per day: each logged manual workout consumes its own budget slot, matching how each one also earns its own weekly-count and shutdown credit (see ``screen_locker._weekly_check.COUNTED_WORKOUT_TYPES`` and ``screen_locker._workout_credit``) — the budget is the sole limiter on how many you can log, not a once-per-day collapse. + + "One workout" is decided by :func:`screen_locker._weekly_check.credit_key`, + the single rule every counter must share. This used to count raw entries + instead, so a synced copy of a workout already in the log (2026-09-13: a + manual rekeyed to its local day, then pulled back in under a fresh + workout_id) consumed a second budget slot while the weekly count, going + through ``credit_key``, correctly saw one — and the budget read exhausted + for a week over a workout that was logged once. """ today_str = today or _today_iso() today_dt = _parse_iso(today_str) @@ -81,10 +90,14 @@ def count_in_window( parsed = _parse_iso(date_str) if parsed is None or not (cutoff < parsed <= today_dt): continue - count += sum( - 1 - for entry in entries - if entry.get("workout_data", {}).get("type") == MANUAL_WORKOUT_TYPE + siblings = day_workout_index(entries) + count += len( + { + key + for index, entry in enumerate(entries) + if (key := credit_key(date_str, index, entry, siblings)) is not None + and key[0] == MANUAL_WORKOUT_TYPE + } ) return count diff --git a/screen_locker/tests/test_manual_rekey_dedup.py b/screen_locker/tests/test_manual_rekey_dedup.py new file mode 100644 index 0000000..efa971b --- /dev/null +++ b/screen_locker/tests/test_manual_rekey_dedup.py @@ -0,0 +1,136 @@ +"""A workout rekeyed to its local day is not re-ingested, and never double-budgeted. + +Regression for 2026-09-13, second act. The football logged at 00:02 local was +filed under the UTC day and then moved to ``2026-09-13`` by +``scripts/rekey_log_entry.py``, keeping its ``workout_id`` +``manual:2026-09-12T14:30``. The 09:40 tick published that entry, pulled it +straight back, and ingested it AGAIN as ``manual:2026-09-13T14:30``: + +* ``_already_ingested`` matched only ``sync_record_id``, which a locally + logged entry never carries; +* the write chokepoint re-derived the id from the payload's (now corrected) + date, so ``_is_logged_anywhere`` found no twin. + +The weekly count collapsed the pair through ``credit_key``, but the +manual-workout budget counted raw entries, so one football read as 2/2 for a +week and the lock screen hid "Log Manual Workout" over a workout logged once. +""" + +from __future__ import annotations + +import json +from typing import TYPE_CHECKING + +from screen_locker._log_mixin import write_signed_entry +from screen_locker._manual_sync import ingest_manual_records +from screen_locker._manual_workout import ( + SPORT_OTHER, + ManualWorkoutDraft, + build_entry, + build_sync_payload, + count_in_window, + is_budget_exhausted, + manual_sync_record_id, +) +from screen_locker._weekly_check import count_day_credits + +if TYPE_CHECKING: + from pathlib import Path + +UTC_DAY = "2026-09-12" +LOCAL_DAY = "2026-09-13" +TODAY = "2026-09-18" + +FOOTBALL = ManualWorkoutDraft( + sport=SPORT_OTHER, + start_time="14:30", + end_time="16:30", + location_name="Boisko stoczniowiec Płock", + transport_method="by car ~2hr", + cost="free (?)", + rpe=6, + went_well="Stamina held up for the full two hours of play", + to_improve="Look around before passing instead of passing immediately", + overall_feeling="Pretty good session, long drive but worth it once a year", + activity_type_other="football 11v11", + activity_details="We played a traditional football game 11v11 with lots of swaps", + equipment="regular football shoes, white shirt", +) +# Minted at 00:02 local, when the day key was still the UTC day. +FOOTBALL_ID = manual_sync_record_id(UTC_DAY, FOOTBALL.start_time) + + +def _log_after_rekey(log_file: Path) -> None: + """Write the log exactly as it stood after the rekey, before the 09:40 tick. + + One football under the local day, keyed on the id it was minted with. + """ + write_signed_entry( + log_file, LOCAL_DAY, {**build_entry(FOOTBALL), "workout_id": FOOTBALL_ID} + ) + + +def _published_twin() -> tuple[str, dict]: + """The record the PC pushed at 09:40: the minted id, the corrected day.""" + return FOOTBALL_ID, build_sync_payload(FOOTBALL, LOCAL_DAY) + + +class TestSyncedTwinIsNotReIngested: + """Pulling back the PC's own published entry is a no-op.""" + + def test_rekeyed_entry_is_recognised_by_its_workout_id( + self, tmp_path: Path + ) -> None: + log_file = tmp_path / "log.json" + _log_after_rekey(log_file) + + ingested = ingest_manual_records(log_file, [_published_twin()], today=LOCAL_DAY) + + assert ingested == [] + assert len(json.loads(log_file.read_text())[LOCAL_DAY]) == 1 + + def test_ingested_entry_keeps_the_wire_id(self, tmp_path: Path) -> None: + """A synced manual is filed under the id it arrived with, not a re-derived one.""" + log_file = tmp_path / "log.json" + record_id, payload = _published_twin() + + ingest_manual_records(log_file, [(record_id, payload)], today=LOCAL_DAY) + + (entry,) = json.loads(log_file.read_text())[LOCAL_DAY] + assert entry["workout_id"] == record_id + assert entry["workout_data"]["sync_record_id"] == record_id + + +class TestBudgetCountsWorkoutsNotEntries: + """The manual budget shares ``credit_key`` with the weekly count.""" + + def test_synced_copy_of_an_entry_consumes_no_second_slot( + self, tmp_path: Path + ) -> None: + """The exact pair on disk on 2026-09-13: one football, two entries.""" + log_file = tmp_path / "log.json" + _log_after_rekey(log_file) + twin = build_entry(FOOTBALL) + twin["sync_record_id"] = FOOTBALL_ID + # What the old ingest wrote: same workout under a freshly derived id. + write_signed_entry(log_file, LOCAL_DAY, twin) + entries = json.loads(log_file.read_text())[LOCAL_DAY] + assert len(entries) == 2 + + assert count_day_credits(LOCAL_DAY, entries) == 1 + assert count_in_window(log_file, 7, today=TODAY) == 1 + assert not is_budget_exhausted(log_file, today=TODAY) + + def test_two_distinct_manuals_on_one_day_both_consume_a_slot( + self, tmp_path: Path + ) -> None: + """Collapsing is for duplicates only; two real workouts still cost two.""" + log_file = tmp_path / "log.json" + _log_after_rekey(log_file) + evening = ManualWorkoutDraft( + **{**FOOTBALL.__dict__, "start_time": "19:00", "end_time": "20:00"} + ) + write_signed_entry(log_file, LOCAL_DAY, build_entry(evening)) + + assert count_in_window(log_file, 7, today=TODAY) == 2 + assert is_budget_exhausted(log_file, today=TODAY) diff --git a/screen_locker/tests/test_weekly_logic_part2.py b/screen_locker/tests/test_weekly_logic_part2.py index 3ddff59..0fc5e26 100644 --- a/screen_locker/tests/test_weekly_logic_part2.py +++ b/screen_locker/tests/test_weekly_logic_part2.py @@ -59,6 +59,30 @@ class TestCheckTodayStateExits: result = locker._check_today_state_exits() assert result is False + def test_expired_early_bird_does_not_outrank_a_logged_workout( + self, + mock_tk: MagicMock, + mock_sys_exit: MagicMock, + tmp_path: Path, + ) -> None: + """2026-09-18: a manual walk logged at 09:32 must hold after 08:30. + + The expired-marker branch used to return False (full lock) before + ``has_logged_today`` was ever consulted, so every 5-minute tick after + the walk re-locked the PC for the rest of the day. + """ + locker = self._make_locker(mock_tk, tmp_path) + with ( + patch.object(locker, "_is_early_bird_pending", return_value=True), + patch.object(locker, "_is_early_bird_time", return_value=False), + patch.object(locker, "_try_auto_upgrade_early_bird", return_value=False), + patch.object(locker, "has_logged_today", return_value=True), + patch("screen_locker._auto_upgrade.record_decision") as record, + ): + result = locker._check_today_state_exits() + assert result is True + assert record.call_args.args[0].reason == "workout_logged_today" + def test_early_bird_window_active_returns_true( self, mock_tk: MagicMock,