Count the manual budget per workout, keep a synced twin's id, and let a logged workout outrank an expired early bird

Three faults that together locked kuhy out on 2026-09-18 with a workout
on disk and "Manual-workout budget exhausted" on the screen.

1. The football logged at 00:02 on 2026-09-13 was rekeyed to its local
   day (keeping workout_id manual:2026-09-12T14:30), published, and pulled
   straight back by the 09:40 tick as a new record: _already_ingested only
   matched sync_record_id (which a locally logged entry never carries) and
   the chokepoint re-derived the id from the corrected date, so the same
   workout landed twice. Ingest now files a synced manual under the wire
   id it arrived with and recognises an entry whose own workout_id is that
   record.

2. count_in_window counted raw manual_workout entries, so the twin took a
   second budget slot for a week (2/2) while the weekly count, which goes
   through credit_key, saw one. The budget now shares credit_key -- the
   rule the docstring says every counter must share -- and distinct
   workouts on one day still cost a slot each.

3. _check_today_state_exits returned False (full lock) from the expired
   early-bird branch before ever consulting has_logged_today, so a manual
   walk entered on the lock screen at 09:32 held for exactly one tick: the
   09:35 run locked again ("also=workout_logged_today"), and kept doing so
   every 5 minutes while the day's marker lasted, which is how a sick day
   got spent over a logged workout. The explain chain already treated the
   expired marker as non-terminal; the live ladder now falls through the
   same way.

_manual_sync.py went over the 250-line cap and is split: draft
reconstruction lives in _manual_sync_draft.py, re-exported from the
original path so patch targets are unchanged.

Replayed on the real log: count_day_credits("2026-09-13") == 1 while the
old count_in_window said 2; after the fix the status API reports
used_7d=1, exhausted=False. test_manual_rekey_dedup.py fails 3/4 on HEAD.
1334 tests, 100% coverage.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
This commit is contained in:
Krzysztof Rudnicki 2026-09-18 09:44:28 +02:00
parent 8df1ff6d09
commit 9b84af7537
6 changed files with 364 additions and 142 deletions

View File

@ -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",

View File

@ -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:<date>T<start>`` 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

View File

@ -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

View File

@ -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

View File

@ -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)

View File

@ -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,