mirror of
https://github.com/kuhyx/screen-locker.git
synced 2026-11-10 20:27:13 +01:00
Krzysztof kuhy Rudnicki
b0d9165a79
The morning routine is started by systemd right after boot and right after
resume, so its sync ran seconds before DHCP/DNS were up. Every such run failed
outright — and said this:
Workout sync push FAILED for 6 workout(s): network error reading
screen-locker-sync/devices — a 403 here means the token lacks
contents:write on kuhyx/syncs
Both halves of that were wrong. It was not a 403, and the token was fine: the
same six workouts pushed successfully by hand minutes later on the same token,
which reports push=true on the repo. The message cost a real investigation
chasing a permissions bug that did not exist.
- _sync_retry.with_sync_retry wraps the three sync call sites in a bounded
retry (4 attempts, 2s/4s/8s backoff — ~14s, enough for the network to come
up, short enough not to drag the routine). Verified offline in a network
namespace: three retries, then an honest give-up.
- Any GitHubSyncError retries, deliberately including RepoNotFoundError.
Classifying transient vs permanent would couple us to which exception
crdt_sync chains where; a few wasted seconds on a genuinely bad token is the
cheaper mistake.
- The push failure log now reports what actually happened. The contents:write
hint survives only for RepoNotFoundError, which is the one error that
actually implicates the repo or the token.
Retry at the application layer rather than ordering the unit after
network-online.target: the same race hits on resume, where boot ordering does
not apply, and these are user units that cannot depend on a system target.
The tests' autouse no-sleep fixture patches the module-local `sleep` name
rather than `_sync_retry.time.sleep` — the latter mutates the shared time
module object and silently disabled sleep for the whole suite, breaking an
unrelated temperature timeout test.
Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
295 lines
11 KiB
Python
295 lines
11 KiB
Python
"""Tests for pushing the PC's workouts (from workout_log.json) to the sync repo."""
|
|
# pylint: disable=protected-access
|
|
|
|
from __future__ import annotations
|
|
|
|
from datetime import datetime, timezone
|
|
import json
|
|
from typing import TYPE_CHECKING
|
|
from unittest.mock import MagicMock, patch
|
|
|
|
from crdt_sync import GitHubSyncError, RepoNotFoundError
|
|
|
|
from screen_locker import _manual_push
|
|
from screen_locker._manual_push import (
|
|
PushResult,
|
|
_decode_log,
|
|
_encode_log,
|
|
_entry_wall_ms,
|
|
push_pc_workouts,
|
|
records_from_workout_log,
|
|
)
|
|
|
|
if TYPE_CHECKING:
|
|
from pathlib import Path
|
|
|
|
import pytest
|
|
|
|
_MANUAL = {
|
|
"type": "manual_workout",
|
|
"source": "table tennis at Solec",
|
|
"start_time": "18:00",
|
|
"rpe": 6,
|
|
}
|
|
_RUN = {
|
|
"type": "runnerup_verified",
|
|
"source": "Running: 9.8 km in 55 min",
|
|
"distance_km": 9.8,
|
|
}
|
|
|
|
|
|
def _write_log(log_file: Path, data: dict) -> None:
|
|
log_file.write_text(json.dumps(data))
|
|
|
|
|
|
def _entry(workout_data: dict, ts: str, workout_id: str | None = None) -> dict:
|
|
entry: dict = {"timestamp": ts, "workout_data": workout_data}
|
|
if workout_id is not None:
|
|
entry["workout_id"] = workout_id
|
|
return entry
|
|
|
|
|
|
class TestEncodeDecodeLog:
|
|
"""The crdt log blob round-trips."""
|
|
|
|
def test_round_trips(self, tmp_path: Path) -> None:
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(
|
|
log_file, {"2026-07-13": [_entry(_RUN, "2026-07-13T10:00:00+00:00")]}
|
|
)
|
|
log = records_from_workout_log(log_file)
|
|
assert _decode_log(_encode_log(log)).keys() == log.keys()
|
|
|
|
|
|
class TestEntryWallMs:
|
|
"""The HLC clock is derived from the entry's own timestamp — stably."""
|
|
|
|
def test_uses_the_entry_timestamp(self) -> None:
|
|
expected = int(
|
|
datetime(2026, 7, 13, 12, tzinfo=timezone.utc).timestamp() * 1000
|
|
)
|
|
ms = _entry_wall_ms({"timestamp": "2026-07-13T12:00:00+00:00"}, "2026-07-13")
|
|
assert ms == expected
|
|
|
|
def test_unparsable_timestamp_falls_back_to_midnight(self) -> None:
|
|
ms = _entry_wall_ms({"timestamp": "not-a-time"}, "2026-07-13")
|
|
assert ms == _entry_wall_ms({"timestamp": "2026-07-13T00:00:00+00:00"}, "x")
|
|
|
|
def test_missing_timestamp_falls_back_to_midnight(self) -> None:
|
|
expected = int(datetime(2026, 7, 13, tzinfo=timezone.utc).timestamp() * 1000)
|
|
assert _entry_wall_ms({}, "2026-07-13") == expected
|
|
|
|
def test_fallback_is_stable_across_calls(self) -> None:
|
|
"""The fallback must not be 'now' — that would churn the repo."""
|
|
assert _entry_wall_ms({}, "2026-07-13") == _entry_wall_ms({}, "2026-07-13")
|
|
|
|
|
|
class TestRecordsFromWorkoutLog:
|
|
"""workout_log.json is the single source of truth for what gets pushed."""
|
|
|
|
def test_derives_a_record_per_counted_workout(self, tmp_path: Path) -> None:
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(
|
|
log_file,
|
|
{
|
|
"2026-07-13": [
|
|
_entry(_MANUAL, "2026-07-13T07:25:12+00:00"),
|
|
_entry(
|
|
_RUN,
|
|
"2026-07-13T23:10:00+00:00",
|
|
workout_id="runnerup_verified:2026-07-13",
|
|
),
|
|
]
|
|
},
|
|
)
|
|
log = records_from_workout_log(log_file)
|
|
assert set(log) == {"manual:2026-07-13T18:00", "runnerup_verified:2026-07-13"}
|
|
|
|
def test_payload_carries_kind_and_date(self, tmp_path: Path) -> None:
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(
|
|
log_file, {"2026-07-13": [_entry(_RUN, "2026-07-13T10:00:00+00:00")]}
|
|
)
|
|
payload, _hlc = records_from_workout_log(log_file)[
|
|
"runnerup_verified:2026-07-13"
|
|
].fields["payload"]
|
|
assert payload["kind"] == "runnerup_verified"
|
|
assert payload["date"] == "2026-07-13"
|
|
assert payload["distance_km"] == 9.8
|
|
|
|
def test_legacy_entry_without_workout_id_still_publishes(
|
|
self, tmp_path: Path
|
|
) -> None:
|
|
"""Entries predating workout_id get the id they would have had."""
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(
|
|
log_file, {"2026-07-13": [_entry(_MANUAL, "2026-07-13T07:25+00:00")]}
|
|
)
|
|
assert "manual:2026-07-13T18:00" in records_from_workout_log(log_file)
|
|
|
|
def test_uncounted_types_are_not_pushed(self, tmp_path: Path) -> None:
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(
|
|
log_file,
|
|
{"2026-07-13": [_entry({"type": "sick_day"}, "2026-07-13T07:00:00+00:00")]},
|
|
)
|
|
assert records_from_workout_log(log_file) == {}
|
|
|
|
def test_non_dict_workout_data_is_skipped(self, tmp_path: Path) -> None:
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(
|
|
log_file,
|
|
{
|
|
"2026-07-13": [
|
|
{"timestamp": "2026-07-13T07:00:00+00:00", "workout_data": "x"}
|
|
]
|
|
},
|
|
)
|
|
assert records_from_workout_log(log_file) == {}
|
|
|
|
def test_entry_without_derivable_id_is_skipped(self, tmp_path: Path) -> None:
|
|
"""A counted type with no id can't be deduped, so it isn't synced."""
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(
|
|
log_file, {"2026-07-13": [_entry(_MANUAL, "2026-07-13T07:00:00+00:00")]}
|
|
)
|
|
with patch("screen_locker._manual_push._derive_workout_id", return_value=None):
|
|
assert records_from_workout_log(log_file) == {}
|
|
|
|
def test_is_deterministic_across_calls(self, tmp_path: Path) -> None:
|
|
"""Same log → identical records+HLCs, so a re-push is a no-op."""
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(
|
|
log_file, {"2026-07-13": [_entry(_RUN, "2026-07-13T10:00:00+00:00")]}
|
|
)
|
|
assert _encode_log(records_from_workout_log(log_file)) == _encode_log(
|
|
records_from_workout_log(log_file)
|
|
)
|
|
|
|
|
|
class TestPushPcWorkouts:
|
|
"""Every outcome is reported — never a silent no-op."""
|
|
|
|
def test_no_token_reports_why(self, tmp_path: Path) -> None:
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(
|
|
log_file, {"2026-07-13": [_entry(_RUN, "2026-07-13T10:00:00+00:00")]}
|
|
)
|
|
with patch.object(_manual_push, "read_sync_token", return_value=None):
|
|
result = push_pc_workouts(log_file)
|
|
assert result == PushResult(pushed=False, record_count=0, reason=result.reason)
|
|
assert "no sync token" in result.reason
|
|
|
|
def test_empty_log_reports_why(self, tmp_path: Path) -> None:
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(log_file, {})
|
|
with patch.object(_manual_push, "read_sync_token", return_value="t"):
|
|
result = push_pc_workouts(log_file)
|
|
assert result.pushed is False
|
|
assert result.record_count == 0
|
|
assert "no counted workouts" in result.reason
|
|
|
|
def test_sync_error_reports_why(self, tmp_path: Path) -> None:
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(
|
|
log_file, {"2026-07-13": [_entry(_RUN, "2026-07-13T10:00:00+00:00")]}
|
|
)
|
|
with (
|
|
patch.object(_manual_push, "read_sync_token", return_value="t"),
|
|
patch.object(_manual_push, "GitHubSyncClient", MagicMock()),
|
|
patch.object(
|
|
_manual_push, "sync_log", side_effect=GitHubSyncError("403 forbidden")
|
|
),
|
|
):
|
|
result = push_pc_workouts(log_file)
|
|
assert result.pushed is False
|
|
assert result.record_count == 1
|
|
assert "403 forbidden" in result.reason
|
|
|
|
def test_network_error_is_not_blamed_on_the_token(
|
|
self, tmp_path: Path, caplog: pytest.LogCaptureFixture
|
|
) -> None:
|
|
"""A network failure must not be reported as a permissions problem.
|
|
|
|
Regression guard for 2026-07-20: the morning routine runs seconds after
|
|
boot/resume, so its pushes failed with the network still down — and the
|
|
log asserted "a 403 here means the token lacks contents:write", which
|
|
sent an investigation chasing a permissions bug that did not exist.
|
|
"""
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(
|
|
log_file, {"2026-07-13": [_entry(_RUN, "2026-07-13T10:00:00+00:00")]}
|
|
)
|
|
with (
|
|
patch.object(_manual_push, "read_sync_token", return_value="t"),
|
|
patch.object(_manual_push, "GitHubSyncClient", MagicMock()),
|
|
patch.object(
|
|
_manual_push,
|
|
"sync_log",
|
|
side_effect=GitHubSyncError("network error reading x"),
|
|
),
|
|
caplog.at_level("WARNING"),
|
|
):
|
|
result = push_pc_workouts(log_file)
|
|
assert result.pushed is False
|
|
assert "network error reading x" in caplog.text
|
|
assert "contents:write" not in caplog.text
|
|
|
|
def test_repo_not_found_still_points_at_the_token(
|
|
self, tmp_path: Path, caplog: pytest.LogCaptureFixture
|
|
) -> None:
|
|
"""The permission hint survives for the error that actually implies it."""
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(
|
|
log_file, {"2026-07-13": [_entry(_RUN, "2026-07-13T10:00:00+00:00")]}
|
|
)
|
|
with (
|
|
patch.object(_manual_push, "read_sync_token", return_value="t"),
|
|
patch.object(_manual_push, "GitHubSyncClient", MagicMock()),
|
|
patch.object(
|
|
_manual_push,
|
|
"sync_log",
|
|
side_effect=RepoNotFoundError("no access"),
|
|
),
|
|
caplog.at_level("WARNING"),
|
|
):
|
|
result = push_pc_workouts(log_file)
|
|
assert result.pushed is False
|
|
assert "contents:write" in caplog.text
|
|
|
|
def test_successful_push_reports_count(self, tmp_path: Path) -> None:
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(
|
|
log_file,
|
|
{
|
|
"2026-07-13": [
|
|
_entry(_MANUAL, "2026-07-13T07:25:12+00:00"),
|
|
_entry(_RUN, "2026-07-13T23:10:00+00:00"),
|
|
]
|
|
},
|
|
)
|
|
fake_sync = MagicMock()
|
|
with (
|
|
patch.object(_manual_push, "read_sync_token", return_value="t"),
|
|
patch.object(_manual_push, "GitHubSyncClient", MagicMock()),
|
|
patch.object(_manual_push, "sync_log", fake_sync),
|
|
):
|
|
result = push_pc_workouts(log_file)
|
|
assert result == PushResult(pushed=True, record_count=2, reason="pushed")
|
|
assert fake_sync.call_count == 1
|
|
|
|
def test_pushes_runs_not_just_manuals(self, tmp_path: Path) -> None:
|
|
"""Regression: the phone must converge on the PC's runs too."""
|
|
log_file = tmp_path / "workout_log.json"
|
|
_write_log(
|
|
log_file, {"2026-07-12": [_entry(_RUN, "2026-07-12T10:00:00+00:00")]}
|
|
)
|
|
with (
|
|
patch.object(_manual_push, "read_sync_token", return_value="t"),
|
|
patch.object(_manual_push, "GitHubSyncClient", MagicMock()),
|
|
patch.object(_manual_push, "sync_log", MagicMock()) as fake_sync,
|
|
):
|
|
push_pc_workouts(log_file)
|
|
pushed = fake_sync.call_args.kwargs["local_log"]
|
|
assert "runnerup_verified:2026-07-12" in pushed
|