mirror of
https://github.com/kuhyx/screen-locker.git
synced 2026-11-10 23:07:13 +01:00
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
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
202 lines
7.8 KiB
Python
Executable File
202 lines
7.8 KiB
Python
Executable File
#!/usr/bin/env python3
|
|
"""Pre-commit hook: ban silent failures.
|
|
|
|
A caught exception that is swallowed (not re-raised) must say WHY in the log,
|
|
loudly. Otherwise the failure is invisible: the caller sees a bland ``None`` /
|
|
``[]`` / early return and cannot tell "nothing to do" from "it broke". That is
|
|
not hypothetical — the PC's workout sync silently did nothing for weeks because
|
|
a missing token returned ``[]`` and a real error only logged at ``INFO``.
|
|
|
|
The rule: every ``except`` handler must either
|
|
|
|
* re-``raise`` (the failure is someone else's problem), or
|
|
* log at ``warning`` / ``error`` / ``exception`` / ``critical`` with the reason.
|
|
|
|
``debug`` / ``info`` do not count — an invisible log is a silent failure with
|
|
extra steps. ruff's ``S110`` only catches ``except: pass``; this catches the
|
|
far more common ``except: log.info(...); return []``.
|
|
|
|
There is deliberately no escape hatch (per-line lint suppressions are banned
|
|
repo-wide too): if a failure is truly benign, say so at ``warning`` and move on.
|
|
"""
|
|
|
|
from __future__ import annotations
|
|
|
|
import ast
|
|
import logging
|
|
from pathlib import Path
|
|
import sys
|
|
|
|
_logger = logging.getLogger(__name__)
|
|
|
|
# Log levels loud enough that a human actually sees the failure.
|
|
_LOUD_LOG_METHODS = frozenset({"warning", "error", "exception", "critical"})
|
|
|
|
|
|
def _is_loud_log_call(node: ast.AST) -> bool:
|
|
"""Return True if ``node`` is a ``<something>.warning(...)``-style call."""
|
|
return (
|
|
isinstance(node, ast.Call)
|
|
and isinstance(node.func, ast.Attribute)
|
|
and node.func.attr in _LOUD_LOG_METHODS
|
|
)
|
|
|
|
|
|
def _handler_is_loud(handler: ast.ExceptHandler) -> bool:
|
|
"""Return True if the handler re-raises or logs loudly about the failure."""
|
|
return any(
|
|
isinstance(node, ast.Raise) or _is_loud_log_call(node)
|
|
for node in ast.walk(handler)
|
|
)
|
|
|
|
|
|
def _is_silent_exit(node: ast.AST) -> bool:
|
|
"""Return True if ``node`` is a bare ``sys.exit(0)`` / ``exit(0)`` call."""
|
|
if not isinstance(node, ast.Call):
|
|
return False
|
|
func = node.func
|
|
is_exit = (isinstance(func, ast.Attribute) and func.attr == "exit") or (
|
|
isinstance(func, ast.Name) and func.id == "exit"
|
|
)
|
|
if not is_exit or len(node.args) != 1:
|
|
return False
|
|
arg = node.args[0]
|
|
return isinstance(arg, ast.Constant) and arg.value == 0
|
|
|
|
|
|
def _find_silent_exits(tree: ast.AST) -> list[ast.Call]:
|
|
"""Return every ``sys.exit(0)`` not preceded by a loud explanation.
|
|
|
|
A process that exits 0 has declared success, so nothing downstream will ever
|
|
flag it — which is precisely how the screen locker stopped enforcing for
|
|
thirteen days in 2026-08 while every unit reported ``0/SUCCESS``. Each such
|
|
exit abandons the work the process was started to do, so it must say why at
|
|
a level a human actually sees.
|
|
|
|
The check is per-enclosing-block: an exit is considered explained when a
|
|
loud log call or a ``record_decision(...)``-style helper appears in the same
|
|
body. That keeps it cheap and, more importantly, keeps it free of an escape
|
|
hatch -- there is no comment that silences it.
|
|
"""
|
|
offenders: dict[int, ast.Call] = {}
|
|
for block in ast.walk(tree):
|
|
for body_attr in ("body", "orelse", "finalbody"):
|
|
statements = getattr(block, body_attr, None)
|
|
if not isinstance(statements, list):
|
|
continue
|
|
for index, statement in enumerate(statements):
|
|
exits = [
|
|
inner for inner in ast.walk(statement) if _is_silent_exit(inner)
|
|
]
|
|
if not exits:
|
|
continue
|
|
# Scope the search to the exit's OWN statement plus the ones
|
|
# directly before it in the same body. Scanning the whole
|
|
# enclosing body was useless: a sibling method's warning() call
|
|
# elsewhere in the class marked every exit "explained", which is
|
|
# how the original _auto_upgrade.py passed this check while
|
|
# containing exactly the bug it is meant to catch.
|
|
scope = [*statements[:index], statement]
|
|
explained = any(
|
|
_is_loud_log_call(inner) or _is_explaining_call(inner)
|
|
for candidate in scope
|
|
for inner in ast.walk(candidate)
|
|
)
|
|
if explained:
|
|
continue
|
|
for call in exits:
|
|
offenders.setdefault(call.lineno, call)
|
|
return [call for _, call in sorted(offenders.items())]
|
|
|
|
|
|
# Helpers that record the reason for stopping. Calling one counts as speaking
|
|
# up, the same as logging loudly.
|
|
_EXPLAINING_CALLS = frozenset(
|
|
{
|
|
"record_decision",
|
|
"record_no_decision",
|
|
"_record_decision",
|
|
"_record_skip",
|
|
"_skip",
|
|
}
|
|
)
|
|
|
|
# Deliberately NOT relaxed to accept `info`. An INFO line beside sys.exit(0)
|
|
# is structurally indistinguishable from the bug this check exists to catch --
|
|
# the 2026-08 outage looked exactly like `_logger.info(...); sys.exit(0)`. Since
|
|
# the AST cannot tell "finished my job" from "abandoned enforcement", the rule
|
|
# stays strict and the handful of genuine completion exits record themselves
|
|
# through _EXPLAINING_CALLS instead. A check that cannot distinguish must fail
|
|
# closed, not open.
|
|
|
|
|
|
def _is_explaining_call(node: ast.AST) -> bool:
|
|
"""Return True if ``node`` calls a helper that records why work stopped."""
|
|
if not isinstance(node, ast.Call):
|
|
return False
|
|
func = node.func
|
|
if isinstance(func, ast.Attribute):
|
|
return func.attr in _EXPLAINING_CALLS
|
|
return isinstance(func, ast.Name) and func.id in _EXPLAINING_CALLS
|
|
|
|
|
|
def _handler_label(handler: ast.ExceptHandler) -> str:
|
|
"""Return a readable name for what the handler catches."""
|
|
if handler.type is None:
|
|
return "except:"
|
|
return f"except {ast.unparse(handler.type)}:"
|
|
|
|
|
|
def _check_source(path: Path, source: str) -> list[str]:
|
|
"""Return one message per silently-swallowing except handler in ``source``."""
|
|
try:
|
|
tree = ast.parse(source, filename=str(path))
|
|
except SyntaxError as exc:
|
|
_logger.warning(
|
|
"Could not parse %s (%s at line %s) — reporting it as a problem "
|
|
"rather than skipping it, since its handlers cannot be checked",
|
|
path,
|
|
exc.msg,
|
|
exc.lineno,
|
|
)
|
|
return [f"{path}:{exc.lineno}: could not parse ({exc.msg})"]
|
|
problems = [
|
|
f"{path}:{node.lineno}: {_handler_label(node)} swallows the error without "
|
|
f"logging why — re-raise, or log at warning/error/exception/critical"
|
|
for node in ast.walk(tree)
|
|
if isinstance(node, ast.ExceptHandler) and not _handler_is_loud(node)
|
|
]
|
|
problems.extend(
|
|
f"{path}:{node.lineno}: sys.exit(0) abandons the work this process was "
|
|
f"started for without saying why — log at warning/error, or record the "
|
|
f"reason (see screen_locker._decision_log.record_decision)"
|
|
for node in _find_silent_exits(tree)
|
|
)
|
|
return problems
|
|
|
|
|
|
def main() -> int:
|
|
"""Return 1 if any file swallows an exception silently, else 0."""
|
|
problems: list[str] = []
|
|
for filename in sys.argv[1:]:
|
|
path = Path(filename)
|
|
try:
|
|
source = path.read_text(encoding="utf-8", errors="replace")
|
|
except OSError as exc:
|
|
_logger.warning(
|
|
"Could not read %s (%s) — reporting it as a problem rather than "
|
|
"skipping it, since its handlers cannot be checked",
|
|
path,
|
|
exc,
|
|
)
|
|
problems.append(f"{path}: could not read ({exc})")
|
|
continue
|
|
problems.extend(_check_source(path, source))
|
|
for problem in problems:
|
|
sys.stdout.write(f"{problem}\n")
|
|
return 1 if problems else 0
|
|
|
|
|
|
if __name__ == "__main__":
|
|
sys.exit(main())
|