screen-locker/screen_locker/_status.py
Krzysztof kuhy Rudnicki e5db25468d
Some checks are pending
pre-commit / pre-commit (push) Waiting to run
Tests / test (3.10) (push) Waiting to run
Tests / test (3.11) (push) Waiting to run
Tests / test (3.12) (push) Waiting to run
Tests / lock-popup-safety (push) Waiting to run
release-apk / release (APK) (push) Waiting to run
Re-arm the locker, and make a disarmed enforcer impossible to miss
The screen locker stopped locking on 2026-08-04 and nobody could tell. Not a
logic bug: every predicate worked the whole time. systemd logged

  timers.target: Found ordering cycle: early-bird-workout-check.timer/start
    after graphical-session.target/start after basic.target/start after
    timers.target/start - after early-bird-workout-check.timer
  timers.target: Job early-bird-workout-check.timer/start deleted to break
    ordering cycle starting with timers.target/start

and left the timer disabled. A timer that is WantedBy=timers.target must not be
ordered After= a target that itself comes after timers.target; systemd resolves
that loop by deleting the job, which is an absence, and absences page nobody.

That timer is the ONLY thing that closes the early-bird window. Each morning a
run inside the window banked early_bird_pending.json, logged "will re-check at
08:30", and exited 0. The re-check never came, so the marker stood all day,
every day, for thirteen days.

It stayed invisible because logging.basicConfig was called only in the
--sync-only branch, never for --production -- the mode systemd actually runs.
Journal proof: zero INFO lines from workout-locker.service since June. Every
early exit logged at INFO into a logger with no handler. Meanwhile the healthy
15-minute sync kept the system looking alive.

The 2026-08-15 Python split is NOT implicated: it was pure code motion, and
basicConfig already sat in that branch before it.

Fixes:

* Drop the After= that closes the cycle; Persistent=true so a machine asleep at
  08:30 still re-checks after resume.
* Add workout-locker.timer (*:00,30). The service is WantedBy=
  graphical-session.target, i.e. one decision per login, so the 08-16 -> 08-17
  day and ISO-week rollover inside one long session was never re-evaluated.
* arm.sh: install units, enable timers, verify -- one command, because
  re-arming was a four-command sequence that was easy to half-do, and
  `systemctl enable` returns 0 while systemd deletes the timer job.
* check_enforcement_armed.py asks systemd what it actually scheduled (enabled
  AND has a next trigger) and fails loudly otherwise. Wired as ExecStartPost on
  workout-sync.service, so a disarmed locker marks that unit failed every 15
  minutes instead of scrolling past. install_systemd.sh now fails on it too.

Logging (the reason this went unnoticed, so treated as a defect in its own
right):

* basicConfig for every mode, never one branch.
* Every enforcement-abandoning exit records a decision instead of an invisible
  INFO: one greppable line -- DECISION lock=no reason=early_bird_window_active
  weekly=0/5 -- at WARNING, since per CLAUDE.md an INFO explanation of a
  non-action is a silent failure with extra steps. The enforced case is logged
  too: "no line at all" was the outage's whole signature.
* A durable JSONL trail outside the repo (~/.local/share/screen_locker/), so
  "when did this last actually enforce?" survives journal rotation. --status
  and --sync-only record lock=n/a; "did not decide" must never look like
  "decided not to lock".
* check_silent_failures.py now also catches sys.exit(0) that explains nothing.
  Verified both directions: it flags 3/3 exits in the pre-fix _auto_upgrade.py
  and passes the repo clean.

Sync noise: four records replayed as WARNINGs every cycle (~384/day), which is
how the actionable lines got tuned out. manual_workout:2026-08-15 is an empty
stub ({date, kind, type}) -- no workout to recover, and that day's credit was
already counted under a different sync_record_id, so no credit was ever lost.
The three "collided" records are dedup working. Both now report at info; a
WARNING from this logger again means something real. 4 -> 0 per cycle.

Verified on the live system: the periodic timer fired at 16:45 and the journal
shows `DECISION lock=no reason=scheduled_skip_day weekly=0/5` -- the line that
did not exist for thirteen days. Both timers report enabled and scheduled, and
no ordering cycle recurs. Today is a scheduled skip so the machine was not
locked mid-session; enforcement resumes tomorrow 08:30. 1007 tests, 100%
coverage, all hooks green.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
Claude-Session: https://claude.ai/code/session_01F2b6ZjBcdrkSYnMujx4mWd
2026-08-17 16:47:25 +02:00

170 lines
5.8 KiB
Python

"""Non-locking status view: workout count, bonuses, RunnerUp scan trigger."""
from __future__ import annotations
from datetime import date, datetime, timedelta, timezone
import json
import logging
import sys
from typing import TYPE_CHECKING
from screen_locker._constants import EXTRA_BENEFITS_FILE
from screen_locker._decision_log import record_no_decision
from screen_locker._extra_benefits import (
current_streak,
has_extended_early_bird,
weekly_shutdown_bonus_hours,
)
from screen_locker._log_io import load_workout_log
from screen_locker._sick_tracker import load_history
from screen_locker._weekly_check import (
COUNTED_WORKOUT_TYPES,
WEEKLY_WORKOUT_MINIMUM,
count_weekly_workouts,
)
if TYPE_CHECKING:
from pathlib import Path
from screen_locker.screen_lock import ScreenLocker
_logger = logging.getLogger(__name__)
def _load_extra_benefits() -> dict:
"""Load extra_benefits_state.json, returning {} on any error."""
if not EXTRA_BENEFITS_FILE.exists():
return {}
try:
return json.loads(EXTRA_BENEFITS_FILE.read_text())
except (OSError, ValueError) as exc:
_logger.warning(
"Could not read extra-benefits state from %s: %s — the status view "
"will show a 0 streak and no bonus hours, which may be wrong",
EXTRA_BENEFITS_FILE,
exc,
)
return {}
def _print_day_line(d: date, entries: list[dict], sick_days: set[str]) -> bool:
"""Print one day's status line(s). Returns True if any workout counted.
A day may hold several workouts — each is printed on its own line.
"""
label = d.strftime("%a %b %d")
if not entries:
if d.isoformat() in sick_days:
print(f" {label} ✗ sick_day")
else:
print(f" {label} — no entry")
return False
any_counted = False
for entry in entries:
wtype = entry.get("workout_data", {}).get("type", "?")
src = entry.get("workout_data", {}).get("source", "")
counted = wtype in COUNTED_WORKOUT_TYPES
any_counted = any_counted or counted
src_str = f" ({src[:45]})" if src else ""
mark = "✓" if counted else "✗"
print(f" {label} {mark} {wtype}{src_str}")
return any_counted
def run_status(locker: ScreenLocker) -> None:
"""Print weekly workout status, run RunnerUp scan, apply bonus, then exit."""
today = datetime.now(tz=timezone.utc).astimezone().date()
monday = today - timedelta(days=today.weekday())
log_file: Path = locker.log_file
log_data = load_workout_log(log_file)
sick_days = set(load_history().sick_days)
print("=== Weekly Workout Status ===")
# Per-day breakdown
for i in range(7):
d = monday + timedelta(days=i)
if d > today:
break
_print_day_line(d, log_data.get(d.isoformat(), []), sick_days)
print()
# The weekly total, per the anti-gaming rule (each verified workout counts
# individually, manual counts once/day) — NOT a per-day checkmark count,
# which would undercount a day holding two verified workouts.
before_count = count_weekly_workouts(log_file)
# RunnerUp scan
n_filled = locker._scan_and_fill_week_runnerup(log_file)
if n_filled > 0:
print(f" Auto-filled {n_filled} workout(s) from RunnerUp exports.")
after_count = count_weekly_workouts(log_file)
bonus = max(0, after_count - max(WEEKLY_WORKOUT_MINIMUM, before_count))
if bonus > 0:
ok = locker._adjust_shutdown_time_by(bonus)
if ok:
print(f" +{bonus}h shutdown bonus applied.")
else:
print(f" +{bonus}h shutdown bonus pending (config write failed).")
else:
print(" No new workouts found via RunnerUp scan.")
after_count = before_count
print()
# Extra benefits summary
bonus_hours = weekly_shutdown_bonus_hours(EXTRA_BENEFITS_FILE)
streak = current_streak(EXTRA_BENEFITS_FILE)
eb_ext = has_extended_early_bird(EXTRA_BENEFITS_FILE)
eb_str = "Yes — until 09:00" if eb_ext else "No"
# Heat skips this month
this_month = datetime.now(tz=timezone.utc).astimezone().date().strftime("%Y-%m")
heat_entries = [
(d, entry)
for d, entries in log_data.items()
if d.startswith(this_month)
for entry in entries
if isinstance(entry, dict)
and entry.get("workout_data", {}).get("type") == "heat_skip"
]
if heat_entries:
last_date, last_e = max(heat_entries, key=lambda de: de[0])
last_temp = last_e.get("workout_data", {}).get("temperature_celsius", "?")
heat_str = f"{len(heat_entries)} (last: {last_date}, {last_temp}°C)"
else:
heat_str = "0"
print(f" Shutdown bonus (this wk): {bonus_hours}h")
print(f" Streak (5+ wks) : {streak}")
print(f" Early-bird extended : {eb_str}")
print(f" Heat skips (month) : {heat_str}")
print()
remaining = max(0, WEEKLY_WORKOUT_MINIMUM - after_count)
extra = max(0, after_count - WEEKLY_WORKOUT_MINIMUM)
if remaining > 0:
print(
f" Need {remaining} more to reach the minimum ({WEEKLY_WORKOUT_MINIMUM})."
)
elif extra > 0:
print(f" {after_count}/{WEEKLY_WORKOUT_MINIMUM} — {extra} above minimum!")
else:
print(
f" Weekly minimum met exactly"
f" ({WEEKLY_WORKOUT_MINIMUM}/{WEEKLY_WORKOUT_MINIMUM})."
)
# Shutdown config
cfg = locker._read_shutdown_config()
if cfg:
_mw, _ts, _morning = cfg
print(f" Shutdown tonight : {_mw:02d}:00")
# --status is a read-out, not an enforcement run; make that explicit so the
# journal never reads as though the locker evaluated and declined to lock.
record_no_decision("--status")
sys.exit(0)