Skip to content

fix(autolock): honor cancel() during pre-run and cleared-entry races#674

Open
sckissel wants to merge 1 commit into
FutureTense:mainfrom
sckissel:fix/autolock-cancel-race
Open

fix(autolock): honor cancel() during pre-run and cleared-entry races#674
sckissel wants to merge 1 commit into
FutureTense:mainfrom
sckissel:fix/autolock-cancel-race

Conversation

@sckissel

@sckissel sckissel commented Jul 7, 2026

Copy link
Copy Markdown

Fixes #671

Summary

AutolockTimer raises AssertionError at timer.py:185 when cancel() interleaves with an async_call_later dispatch. The module docstring in timer.py declares:

cancel() awaits any in-flight callback before returning. After cancel() returns, no further action firing can happen.

...but the implementation had two windows where that invariant could be violated in practice, producing repeated tracebacks (192 occurrences over ~2 weeks on the reporter's install) plus follow-up "Task exception was never retrieved" warnings at task GC.

Root cause

Window 1 — scheduler-level. ScheduledFire.cancel() sets _cancelled=True and calls _unsub(), but if the underlying HA TimerHandle has already fired at the loop level, that unsub is a no-op. If cancel() arrives before _run executes its first line (self._task = asyncio.current_task()), cancel() reads _task as None, returns without awaiting anything, and _run still invokes _action after cancel() has returned.

Window 2 — timer-level. Even when the scheduler cancel is observed correctly, the fire closure in _schedule_remaining hard-asserts self._entry is not None. _entry can legitimately be None by the time fire runs — e.g. a start() that awaited store.write() yielded to a racing cancel() that cleared _entry, or a reload path that swapped state without going through ScheduledFire.cancel. The assert then crashes the task.

Fix

Two minimal defensive guards that restore the documented invariant:

  • scheduler.py::_run — short-circuit if _cancelled is already set before running the action. Closes window 1 directly.
  • timer.py::_schedule_remaining.fire — replace the assert with a debug-logged bail. _fire (with the store cleanup + state transitions) does not need to run if _entry has already been cleared; the cancel path has already handled those transitions. Belt-and-suspenders defense against any future code path that clears _entry without going through ScheduledFire.cancel.

Regression tests

  • tests/autolock/test_scheduler.py::test_cancel_wins_race_when_run_not_yet_started — models the "TimerHandle already fired, unsub is a no-op" state, cancels, then invokes the captured _run; asserts the action never fires and scheduled.done is set.
  • tests/autolock/test_timer.py::test_fire_closure_bails_when_entry_cleared_race — clears _entry without touching _cancelled on the scheduler (bypassing the scheduler-level guard) and directly invokes the captured callback; asserts no AssertionError and no action call.

Both existing tests (test_cancel_before_fire_prevents_action, test_cancel_awaits_in_flight_action, test_cancel_is_idempotent, test_cancel_swallows_action_exception, test_cancel_swallows_in_flight_cancelled_error) exercise paths where _task gets set before cancel() reads it, so their behavior is unchanged by the _cancelled short-circuit — they still pass through _run's existing flow.

Notes

  • Diff is 99 lines total across 4 files (+2 changes to production code, +2 new tests).
  • No public API changes; no behavior change on any path that was previously succeeding.
  • I don't have a Windows-ARM64 build toolchain to run the HA test suite locally (numpy/grpcio/cryptography have no ARM64 wheels for Python 3.14 on Windows and would need MSVC to build). CI should confirm.

…ces (FutureTense#671)

`AutolockTimer` was raising `AssertionError` at `timer.py:185` when a
`cancel()` interleaved with an `async_call_later` dispatch. The module
docstring documents the invariant "after cancel() returns, no further
action firing can happen", but the implementation had two windows where
that invariant could be violated in practice:

1. `ScheduledFire.cancel()` sets `_cancelled=True` and calls `_unsub()`,
   but if the underlying HA `TimerHandle` has already fired, the unsub
   is a no-op. If cancel arrives before `_run` executes its first line
   (`self._task = asyncio.current_task()`), `cancel()` sees `_task is
   None`, returns without awaiting anything, and `_run` still invokes
   `_action` after cancel() has returned.

2. Even when the scheduler-level cancel is observed correctly, the
   `fire` closure in `_schedule_remaining` was hard-asserting
   `self._entry is not None`. `_entry` can legitimately be `None` by
   the time `fire` runs — e.g. a `start()` that awaited `store.write()`
   yielded to a racing `cancel()` that cleared `_entry`, or a reload
   path that swapped state without going through
   `ScheduledFire.cancel`. The assert crashed the task and produced
   ~190 log tracebacks over ~2 weeks on the reporter's install plus a
   "Task exception was never retrieved" warning on task GC.

Fixes:

- `scheduler.py::_run`: short-circuit if `_cancelled` is already set
  before running the action. This closes window (1) directly and
  matches the invariant advertised by the module docstring.
- `timer.py::_schedule_remaining.fire`: replace the assert with a
  debug-logged bail. `_fire` (with the store cleanup + state
  transitions) does not need to run if `_entry` has already been
  cleared — the cancel path has already handled those transitions.
  Belt-and-suspenders defense in case any future code path clears
  `_entry` without going through `ScheduledFire.cancel`.

Regression tests:

- `tests/autolock/test_scheduler.py::test_cancel_wins_race_when_run_not_yet_started`
  models the "TimerHandle already fired, unsub is a no-op" state,
  cancels, then invokes the captured `_run` — asserts the action
  never fires.
- `tests/autolock/test_timer.py::test_fire_closure_bails_when_entry_cleared_race`
  clears `_entry` without touching `_cancelled` on the scheduler
  (bypassing the scheduler-level guard) and directly invokes the
  captured callback — asserts no `AssertionError` and no action call.

Fixes FutureTense#671
@github-actions github-actions Bot added the bugfix Fixes a bug label Jul 7, 2026

@tykeal tykeal left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Walkthrough

This PR closes the AssertionError reported in #671 by making ScheduledFire/AutolockTimer honor cancel() in two race windows. The primary fix is scheduler-level: _run now short-circuits when _cancelled is already set, so a cancel that lands after the HA TimerHandle was dispatched but before _run's first statement no longer lets a stale action fire. A secondary, defensive fix replaces the hard assert self._entry is not None in the timer's fire closure with a debug-logged bail.

The change is correct and closes the primary race. Verified locally: tests/autolock/test_scheduler.py + tests/autolock/test_timer.py26 passed (Python 3.13). No blockers.

Changes

  • custom_components/keymaster/autolock/scheduler.py_run guards on self._cancelled at entry; on hit, sets _done = True and returns without invoking _action.
  • custom_components/keymaster/autolock/timer.py_schedule_remaining.fire snapshots self._entry into a local and, if None, logs at debug and returns instead of asserting.
  • tests/autolock/test_scheduler.pytest_cancel_wins_race_when_run_not_yet_started models the no-op-unsub / _task is None state and asserts the action does not fire post-cancel.
  • tests/autolock/test_timer.pytest_fire_closure_bails_when_entry_cleared_race clears _entry without cancelling the scheduler and asserts no AssertionError / no action call.

Review Comments

custom_components/keymaster/autolock/scheduler.py

[Analysis — not an issue] The guard genuinely closes window 1, not just narrows it. cancel() sets _cancelled = True synchronously before its first await, and _run reads it on its first line with no intervening await before self._task = asyncio.current_task(). Because the loop is cooperative single-threaded, the check→task-assignment region is atomic: either _run observes the flag and bails, or cancel() observes a non-None _task and awaits it. No remaining interleaving lets a stale action fire. This is the real fix for #671 — the timer.py:185 assert was merely the symptom of _run reaching fire after _entry had been cleared by cancel().

[NITPICK] The bail sets self._done = True while _cancelled is also True, so an instance can now report both cancelled and done. This is consistent with the existing cancel-after-start path (the finally sets _done = True there too), so it is not a behavior bug — but the class docstring's "either... or..." wording (lines 27-29) no longer describes it precisely. Consider clarifying:

    Instances are use-once: either the callback fires (and the instance
    becomes `done`) or `cancel()` is called (and the instance becomes
    `cancelled`). A cancelled instance may additionally report `done`
    once its `_run` slice observes the flag and short-circuits (or after
    an in-flight run completes). Either way, no further state
    transitions occur.

custom_components/keymaster/autolock/timer.py

[Analysis] Snapshotting entry = self._entry into a local and passing it to _fire (rather than re-reading self._entry) is a strict improvement — it removes a read-after-await on shared state. Correct.

[SUGGESTION] Under the current code this guard is defensive-only: the sole non-_fire path that clears _entry is cancel() (line 137), which always await self._scheduled.cancel()s first (line 134) — so _cancelled is set and the scheduler-level guard already prevents fire from running. No presently-reachable path clears _entry without cancelling the scheduler. The PR description acknowledges this ("belt-and-suspenders"), which is fine; consider tightening the inline comment so a future reader is not misled into thinking the race is live today:

            # Defensive: no current code path clears `_entry` without
            # first cancelling the scheduler (which the `_run` guard
            # already catches), but a future reload/replace path might.
            # Bail cleanly instead of asserting; the cancel path owns
            # store cleanup and lifecycle transitions.
            entry = self._entry

tests/autolock/test_timer.py

[NITPICK] The captured callable is ScheduledFire._run (passed to async_call_later as action=_run), not the fire closure — the variable name fire_closure is misleading despite the clarifying comment. Rename for accuracy:

        await timer.start(duration=300)
        run_wrapper = mock_call_later.call_args.kwargs["action"]

...and correspondingly await run_wrapper(dt_util.utcnow()) at the invocation site.

[SUGGESTION] Both new tests depend on mock_call_later.call_args.kwargs["action"], which couples them to async_call_later being invoked with action as a keyword. If that call ever becomes positional the tests fail obscurely rather than at the behavior under test. Low priority given these are targeted regression tests, but a helper that resolves the scheduled callback from either args/kwargs would harden them.

CI Status

  • Autolabel PR — pass.
  • No test/lint/type-check job reported in gh pr checks; CI did not validate the suite for this PR. Ran the two affected test modules locally: 26 passed (Python 3.13). Recommend confirming ruff/mypy/full tox in CI before merge.

Verdict: Correct, minimal, and well-targeted. 0 blockers, 2 suggestions, 2 nitpicks.

@codecov-commenter

codecov-commenter commented Jul 7, 2026

Copy link
Copy Markdown

⚠️ Please install the 'codecov app svg image' to ensure uploads and comments are reliably processed by Codecov.

Codecov Report

✅ All modified and coverable lines are covered by tests.
✅ Project coverage is 92.22%. Comparing base (cdb4922) to head (010520e).
⚠️ Report is 188 commits behind head on main.
❗ Your organization needs to install the Codecov GitHub app to enable full functionality.

Additional details and impacted files
@@            Coverage Diff             @@
##             main     #674      +/-   ##
==========================================
+ Coverage   84.14%   92.22%   +8.07%     
==========================================
  Files          10       41      +31     
  Lines         801     4822    +4021     
  Branches        0       30      +30     
==========================================
+ Hits          674     4447    +3773     
- Misses        127      375     +248     
Flag Coverage Δ
python 92.07% <100.00%> (?)

Flags with carried forward coverage won't be shown. Click here to find out more.

☔ View full report in Codecov by Harness.
📢 Have feedback on the report? Share it here.

🚀 New features to boost your workflow:
  • ❄️ Test Analytics: Detect flaky tests, report on failures, and find test suite problems.
  • 📦 JS Bundle Analysis: Save yourself from yourself by tracking and limiting bundle sizes in JS merges.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

bugfix Fixes a bug

Projects

None yet

Development

Successfully merging this pull request may close these issues.

ISSUE: Autolock race between cancel() and dispatched fire callback (AssertionError at timer.py:185)

3 participants