diff --git a/.gitignore b/.gitignore index a8ee76db..dc5462ad 100644 --- a/.gitignore +++ b/.gitignore @@ -23,3 +23,4 @@ package-lock.json .cursor/ .aider* .continue/ +.serena/ diff --git a/custom_components/keymaster/autolock/__init__.py b/custom_components/keymaster/autolock/__init__.py new file mode 100644 index 00000000..c9370f3e --- /dev/null +++ b/custom_components/keymaster/autolock/__init__.py @@ -0,0 +1,24 @@ +"""Autolock timer subsystem. + +Layered design: + store.py — Persistence. Owns the asyncio.Lock; atomic store ops. + scheduler.py — Single async_call_later wrapper with awaitable cancel. + timer.py — Orchestration. Explicit state machine. The public API. + +Public surface (importable from this package): + AutolockTimer, TimerEntry, TimerState — orchestration + types + TimerStore — persistence (one per coordinator) + TIMER_STORAGE_VERSION, TIMER_STORAGE_KEY — Store wiring +""" + +from .store import TIMER_STORAGE_KEY, TIMER_STORAGE_VERSION, TimerEntry, TimerStore +from .timer import AutolockTimer, TimerState + +__all__ = [ + "TIMER_STORAGE_KEY", + "TIMER_STORAGE_VERSION", + "AutolockTimer", + "TimerEntry", + "TimerState", + "TimerStore", +] diff --git a/custom_components/keymaster/autolock/scheduler.py b/custom_components/keymaster/autolock/scheduler.py new file mode 100644 index 00000000..816fcf58 --- /dev/null +++ b/custom_components/keymaster/autolock/scheduler.py @@ -0,0 +1,93 @@ +"""Single-shot scheduled callback wrapper with awaitable cancellation. + +Wraps `async_call_later` so callers can `await scheduled.cancel()` and +be guaranteed that any in-flight execution of the callback has either +completed or been cancelled before the await returns. This is what +makes higher-layer cancel safe — without this, racing a cancellation +against an already-running callback would let the callback's mutations +land after the caller assumed it was stopped. +""" + +from __future__ import annotations + +import asyncio +from collections.abc import Awaitable, Callable +from datetime import datetime as dt +import logging + +from homeassistant.core import HomeAssistant +from homeassistant.helpers.event import async_call_later + +_LOGGER: logging.Logger = logging.getLogger(__name__) + + +class ScheduledFire: + """A single-shot scheduled async callback. + + Instances are use-once: either the callback fires (and the instance + becomes `done`) or `cancel()` is called (and the instance becomes + `cancelled`). Either way, no further state transitions occur. + """ + + def __init__( + self, + hass: HomeAssistant, + delay: float, + action: Callable[[dt], Awaitable[None]], + ) -> None: + """Schedule `action` to run after `delay` seconds. + + Negative `delay` is honored as "fire on the next event-loop tick". + """ + self._hass = hass + self._action = action + self._task: asyncio.Task[None] | None = None + self._cancelled = False + self._done = False + + async def _run(now: dt) -> None: + self._task = asyncio.current_task() + try: + await self._action(now) + finally: + self._task = None + self._done = True + + self._unsub: Callable[[], None] | None = async_call_later( + hass=hass, delay=max(delay, 0), action=_run + ) + + async def cancel(self) -> None: + """Cancel the scheduled callback and wait for any in-flight run. + + Idempotent. After this returns, the action is guaranteed to have + either completed (if it had already started) or been prevented + from starting (if `async_call_later` hadn't fired yet). + """ + if self._cancelled: + return + self._cancelled = True + if self._unsub is not None: + self._unsub() + self._unsub = None + task = self._task + if task is not None and not task.done(): + try: + await task + except asyncio.CancelledError: + # CancelledError inherits from BaseException; catch explicitly + # so it doesn't propagate and cancel our caller (cancel()'s + # contract is to not re-raise from in-flight failures). + _LOGGER.debug("[ScheduledFire] In-flight callback cancelled") + except Exception: + _LOGGER.exception("[ScheduledFire] In-flight callback raised during cancel") + + @property + def cancelled(self) -> bool: + """Whether cancel() has been called.""" + return self._cancelled + + @property + def done(self) -> bool: + """Whether the callback finished executing.""" + return self._done diff --git a/custom_components/keymaster/autolock/store.py b/custom_components/keymaster/autolock/store.py new file mode 100644 index 00000000..111eb989 --- /dev/null +++ b/custom_components/keymaster/autolock/store.py @@ -0,0 +1,154 @@ +"""Persistent autolock timer store. + +One TimerStore instance per coordinator. Owns an asyncio.Lock so +concurrent operations from different timers (which all write to the +same disk store) can't interleave their load+modify+save sequences. + +The on-disk shape is `{timer_id: {"end_time": iso, "duration": int}}`. +""" + +from __future__ import annotations + +import asyncio +from collections.abc import Mapping +from dataclasses import dataclass +from datetime import datetime as dt +import logging +from typing import TypedDict + +from custom_components.keymaster.const import DOMAIN +from homeassistant.core import HomeAssistant +from homeassistant.helpers.storage import Store +from homeassistant.util import dt as dt_util + +TIMER_STORAGE_VERSION = 1 +TIMER_STORAGE_KEY = f"{DOMAIN}.timers" + +_LOGGER: logging.Logger = logging.getLogger(__name__) + + +class _TimerStoreEntryDict(TypedDict): + """Persisted shape for a single timer entry.""" + + end_time: str + duration: int + + +@dataclass(frozen=True) +class TimerEntry: + """A typed, validated timer entry. + + `end_time` must be timezone-aware and `duration` non-negative; + enforced in `__post_init__` so all construction paths (parsed from + disk, built by callers) carry the same guarantees. + """ + + end_time: dt + duration: int + + def __post_init__(self) -> None: + """Validate the entry on construction (see class docstring).""" + if self.end_time.tzinfo is None: + raise ValueError("TimerEntry.end_time must be timezone-aware") + if self.duration < 0: + raise ValueError(f"TimerEntry.duration must be non-negative, got {self.duration}") + + +class TimerStore: + """Atomic persistence layer for autolock timers. + + All public methods are async and acquire a shared lock so concurrent + operations from different AutolockTimer instances writing to the + same disk store can't lose updates. + """ + + def __init__(self, hass: HomeAssistant) -> None: + """Initialize with a fresh asyncio.Lock and the HA Store handle.""" + self._store: Store[dict[str, _TimerStoreEntryDict]] = Store( + hass, TIMER_STORAGE_VERSION, TIMER_STORAGE_KEY + ) + self._lock = asyncio.Lock() + + async def read(self, timer_id: str) -> TimerEntry | None: + """Return the entry for `timer_id`, or None if absent or invalid. + + Invalid (corrupt) entries are removed as a side effect so a + subsequent read returns None cleanly. + """ + async with self._lock: + data = await self._store.async_load() or {} + raw = data.get(timer_id) + if raw is None: + return None + entry = self._parse(timer_id, raw) + if entry is None: + # Corrupt — remove inline so callers don't see it again + del data[timer_id] + await self._store.async_save(data) + return entry + + async def write(self, timer_id: str, entry: TimerEntry) -> None: + """Persist `entry` under `timer_id`, replacing any prior value.""" + async with self._lock: + data = await self._store.async_load() or {} + data[timer_id] = { + "end_time": entry.end_time.isoformat(), + "duration": entry.duration, + } + await self._store.async_save(data) + + async def remove(self, timer_id: str) -> None: + """Remove the entry for `timer_id` if present. Idempotent.""" + async with self._lock: + data = await self._store.async_load() or {} + if timer_id in data: + del data[timer_id] + await self._store.async_save(data) + + @staticmethod + def _parse(timer_id: str, raw: object) -> TimerEntry | None: + """Parse a raw store entry into a TimerEntry, or None if invalid. + + `raw` is `object` (not the TypedDict) because legacy or manually- + edited stores may contain anything; we defensively type-check + rather than trust the on-disk shape. + """ + if not isinstance(raw, Mapping): + _LOGGER.warning( + "[TimerStore] %s: persisted entry is not a mapping (%s); treating as absent", + timer_id, + type(raw).__name__, + ) + return None + try: + end_time = dt.fromisoformat(raw["end_time"]) + except (KeyError, TypeError, ValueError): + _LOGGER.warning( + "[TimerStore] %s: invalid persisted end_time, treating as absent", + timer_id, + ) + return None + if end_time.tzinfo is None: + # Legacy/manually-edited entries may be naive. Interpret them + # as already-UTC (we always write UTC) — `dt_util.as_utc` + # would assume local/default tz, which is wrong for our data. + end_time = end_time.replace(tzinfo=dt_util.UTC) + try: + duration = int(raw.get("duration", 0)) + except (TypeError, ValueError): + _LOGGER.warning( + "[TimerStore] %s: invalid persisted duration, treating as absent", + timer_id, + ) + return None + try: + return TimerEntry(end_time=end_time, duration=duration) + except ValueError as exc: + # TimerEntry.__post_init__ enforces non-negative duration and + # tz-aware end_time; surface those as recoverable, not crashes. + _LOGGER.warning( + "[TimerStore] %s: invalid persisted entry (%s); treating as absent", + timer_id, + exc, + ) + return None diff --git a/custom_components/keymaster/autolock/timer.py b/custom_components/keymaster/autolock/timer.py new file mode 100644 index 00000000..c74e1418 --- /dev/null +++ b/custom_components/keymaster/autolock/timer.py @@ -0,0 +1,236 @@ +"""Autolock timer orchestration with explicit state machine. + +The timer is owned by the coordinator and lives across config-entry +reloads. It does NOT capture a kmlock reference; instead it takes a +`get_kmlock` closure that resolves the live kmlock at fire time, so a +reload that replaces the kmlock instance does not orphan in-flight +actions. + +State machine (recover() must be the first transition, from FRESH only): + + FRESH ── recover() (no entry) ─────────> DONE + FRESH ── recover() (active entry) ─────> ACTIVE + FRESH ── recover() (expired entry) ────> ACTIVE → fire → see below + + ACTIVE ── start() ─────────────────────> ACTIVE (re-arm) + ACTIVE ── cancel() ────────────────────> DONE + ACTIVE ── fire (success) ──────────────> DONE + ACTIVE ── fire (action raised) ────────> ACTIVE (entry re-persisted; + is_running=False) + ACTIVE ── fire (kmlock missing) ───────> DONE (entry removed) + + DONE ── start() ─────────────────────> ACTIVE + DONE ── cancel() ────────────────────> DONE (idempotent) + +Invariants: + 1. The store entry mirrors the most recent ACTIVE state. cancel() and + successful fire remove it; start() and recover() (active) write it. + 2. cancel() awaits any in-flight callback before returning. After + cancel() returns, no further action firing can happen. + 3. The action snapshot is the live kmlock from `get_kmlock()` — never + a captured reference. Reload swaps kmlocks transparently. +""" + +from __future__ import annotations + +from collections.abc import Awaitable, Callable +from datetime import datetime as dt, timedelta +from enum import Enum +import logging + +from custom_components.keymaster.autolock.scheduler import ScheduledFire +from custom_components.keymaster.autolock.store import TimerEntry, TimerStore +from custom_components.keymaster.lock import KeymasterLock +from homeassistant.core import HomeAssistant +from homeassistant.util import dt as dt_util + +_LOGGER: logging.Logger = logging.getLogger(__name__) + + +class TimerState(Enum): + """Explicit lifecycle states (see module docstring for transitions).""" + + FRESH = "fresh" + ACTIVE = "active" + DONE = "done" + + +class AutolockTimer: + """One persistent autolock timer, keyed by `timer_id`. + + Owned by the coordinator. The same instance is reused across config- + entry reloads — the kmlock is resolved indirectly via `get_kmlock()`. + """ + + def __init__( + self, + hass: HomeAssistant, + store: TimerStore, + timer_id: str, + get_kmlock: Callable[[], KeymasterLock | None], + action: Callable[[KeymasterLock, dt], Awaitable[None]], + ) -> None: + """Construct the timer in the FRESH state. + + Call `recover()` once before any other method to load any + persisted state from a prior process. + """ + self._hass = hass + self._store = store + self._timer_id = timer_id + self._get_kmlock = get_kmlock + self._action = action + self._state = TimerState.FRESH + self._entry: TimerEntry | None = None + self._scheduled: ScheduledFire | None = None + + # ------------------------------------------------------------------ + # Public API + # ------------------------------------------------------------------ + + async def recover(self) -> None: + """Load any persisted entry left over from a prior process. + + - No entry: stay DONE (idle). + - Active entry: move to ACTIVE, schedule the remaining delay. + - Expired entry: fire the action immediately. On success → DONE. + On failure → re-persist for retry on next restart. + """ + if self._state != TimerState.FRESH: + raise RuntimeError(f"recover() requires FRESH state, got {self._state}") + entry = await self._store.read(self._timer_id) + if entry is None: + self._state = TimerState.DONE + return + if entry.end_time <= dt_util.utcnow(): + # Set state to ACTIVE before firing so _fire's success and + # failure paths leave a usable post-recover state. + self._entry = entry + self._state = TimerState.ACTIVE + await self._fire(now=dt_util.utcnow(), entry=entry) + return + self._entry = entry + self._schedule_remaining() + self._state = TimerState.ACTIVE + + async def start(self, duration: int) -> None: + """Start (or restart) the timer for `duration` seconds.""" + if self._state == TimerState.FRESH: + raise RuntimeError("start() requires recover() to have been called first") + if self._scheduled is not None: + await self._scheduled.cancel() + self._scheduled = None + end_time = dt_util.utcnow() + timedelta(seconds=duration) + self._entry = TimerEntry(end_time=end_time, duration=duration) + await self._store.write(self._timer_id, self._entry) + self._schedule_remaining() + self._state = TimerState.ACTIVE + _LOGGER.debug( + "[AutolockTimer] %s: started, fires at %s (%ss)", + self._timer_id, + end_time, + duration, + ) + + async def cancel(self) -> None: + """Cancel the timer. Idempotent. Awaits in-flight callback.""" + if self._scheduled is not None: + await self._scheduled.cancel() + self._scheduled = None + if self._state == TimerState.ACTIVE: + self._entry = None + await self._store.remove(self._timer_id) + self._state = TimerState.DONE + _LOGGER.debug("[AutolockTimer] %s: cancelled", self._timer_id) + + # ------------------------------------------------------------------ + # Read-only properties + # ------------------------------------------------------------------ + + @property + def state(self) -> TimerState: + """Current lifecycle state.""" + return self._state + + @property + def is_running(self) -> bool: + """True if a callback is currently scheduled to fire. + + Tied to the ScheduledFire's done flag (not just `_state`) so an + action that ran but left the entry persisted (failure replay + path) reports False — callers can then issue a fresh `start()` + to re-arm without conflict. + """ + return ( + self._state == TimerState.ACTIVE + and self._scheduled is not None + and not self._scheduled.done + ) + + @property + def end_time(self) -> dt | None: + """When the timer will fire, or None if not active.""" + return self._entry.end_time if self.is_running and self._entry else None + + @property + def duration(self) -> int | None: + """Original total duration in seconds, or None if not active.""" + return self._entry.duration if self.is_running and self._entry else None + + @property + def remaining_seconds(self) -> int | None: + """Seconds until the timer fires, or None if not active.""" + if not self.is_running or self._entry is None: + return None + return round((self._entry.end_time - dt_util.utcnow()).total_seconds()) + + # ------------------------------------------------------------------ + # Internals + # ------------------------------------------------------------------ + + def _schedule_remaining(self) -> None: + """(Re)create the ScheduledFire from the current `_entry`.""" + assert self._entry is not None + delay = (self._entry.end_time - dt_util.utcnow()).total_seconds() + + async def fire(now: dt) -> None: + assert self._entry is not None + await self._fire(now=now, entry=self._entry) + + self._scheduled = ScheduledFire(self._hass, delay, fire) + + async def _fire(self, now: dt, entry: TimerEntry) -> None: + """Fire the action against the live kmlock; clean up on success. + + Three outcomes: + - kmlock missing: terminal. Clear state + remove entry so it + can't replay forever on subsequent restarts. + - action raises: keep the entry persisted so recovery on the + next restart retries it. State stays ACTIVE; is_running + reports False because the ScheduledFire has finished. + - action succeeds: entry retired, state DONE. + """ + kmlock = self._get_kmlock() + if kmlock is None: + _LOGGER.warning( + "[AutolockTimer] %s: kmlock no longer present; clearing timer", + self._timer_id, + ) + self._entry = None + await self._store.remove(self._timer_id) + self._state = TimerState.DONE + return + try: + await self._action(kmlock, now) + except Exception: + _LOGGER.exception( + "[AutolockTimer] %s: action raised; entry preserved for restart retry", + self._timer_id, + ) + # Re-persist for replay on next recover(). + await self._store.write(self._timer_id, entry) + return + self._entry = None + await self._store.remove(self._timer_id) + self._state = TimerState.DONE + _LOGGER.debug("[AutolockTimer] %s: fired and cleared", self._timer_id) diff --git a/custom_components/keymaster/coordinator.py b/custom_components/keymaster/coordinator.py index 58769fe7..9e8a6274 100644 --- a/custom_components/keymaster/coordinator.py +++ b/custom_components/keymaster/coordinator.py @@ -27,12 +27,13 @@ STATE_OPEN, ) from homeassistant.core import CoreState, Event, EventStateChangedData, HomeAssistant -from homeassistant.helpers import device_registry as dr, entity_registry as er +from homeassistant.helpers import device_registry as dr, entity_registry as er, sun from homeassistant.helpers.event import async_call_later, async_track_state_change_event from homeassistant.helpers.storage import Store from homeassistant.helpers.update_coordinator import DataUpdateCoordinator from homeassistant.util import slugify +from .autolock import AutolockTimer, TimerStore from .const import ( ATTR_ACTION_CODE, ATTR_ACTION_TEXT, @@ -44,6 +45,8 @@ BACKOFF_INITIAL_SECONDS, BACKOFF_MAX_SECONDS, DAY_NAMES, + DEFAULT_AUTOLOCK_MIN_DAY, + DEFAULT_AUTOLOCK_MIN_NIGHT, DOMAIN, EVENT_KEYMASTER_CODE_SLOT_RESET, EVENT_KEYMASTER_LOCK_STATE_CHANGED, @@ -56,11 +59,7 @@ ) from .exceptions import ProviderNotConfiguredError from .helpers import ( - TIMER_STORAGE_KEY, - TIMER_STORAGE_VERSION, - KeymasterTimer, Throttle, - TimerStoreEntry, call_hass_service, delete_code_slot_entities, dismiss_persistent_notification, @@ -78,6 +77,11 @@ _LOGGER: logging.Logger = logging.getLogger(__name__) +# Notification id suffixes shared between the create-sites and the +# dismiss-on-success loop in _lock_locked. Single source of truth so +# new ids can't be added in one place and silently missed in the other. +AUTOLOCK_NOTIFICATION_SUFFIXES: tuple[str, ...] = ("door_open", "door_closed", "failed") + STORAGE_VERSION = 1 STORAGE_KEY = f"{DOMAIN}.locks" @@ -119,9 +123,7 @@ def __init__(self, hass: HomeAssistant) -> None: config_entry=None, ) self._store: Store[dict[str, Any]] = Store(hass, STORAGE_VERSION, STORAGE_KEY) - self._timer_store: Store[dict[str, TimerStoreEntry]] = Store( - hass, TIMER_STORAGE_VERSION, TIMER_STORAGE_KEY - ) + self._timer_store = TimerStore(hass) async def initial_setup(self) -> None: """Trigger the initial async_setup.""" @@ -675,7 +677,7 @@ async def _lock_unlocked( code_slot_num = 0 if kmlock.autolock_enabled and kmlock.autolock_timer: - await kmlock.autolock_timer.start() + await kmlock.autolock_timer.start(duration=self.autolock_duration_seconds(kmlock)) self.async_set_updated_data(dict(self.kmlocks)) if kmlock.lock_notifications: @@ -801,16 +803,22 @@ async def _lock_locked( action_code, ) - # Dismiss retry lock notifications now that the lock has succeeded + # Dismiss autolock-related notifications. Each dismissal is + # wrapped so a transient failure (e.g. HA not yet started) can't + # abort the rest of this handler. notification_slug = slugify(kmlock.lock_name).lower() - await dismiss_persistent_notification( - hass=self.hass, - notification_id=f"{notification_slug}_autolock_door_open", - ) - await dismiss_persistent_notification( - hass=self.hass, - notification_id=f"{notification_slug}_autolock_door_closed", - ) + for suffix in AUTOLOCK_NOTIFICATION_SUFFIXES: + try: + await dismiss_persistent_notification( + hass=self.hass, + notification_id=f"{notification_slug}_autolock_{suffix}", + ) + except Exception: + _LOGGER.exception( + "[lock_locked] %s: failed to dismiss %s notification", + kmlock.lock_name, + suffix, + ) if kmlock.autolock_timer: await kmlock.autolock_timer.cancel() @@ -902,13 +910,29 @@ async def _lock_lock(self, kmlock: KeymasterLock) -> None: _LOGGER.debug("[lock_lock] %s: Locking", kmlock.lock_name) kmlock.pending_retry_lock = False target: MutableMapping[str, Any] = {ATTR_ENTITY_ID: kmlock.lock_entity_id} + # raise_on_missing so ServiceNotFound (e.g. lock entity removed or + # renamed) propagates up to _timer_triggered's notification path, + # rather than being swallowed and silently retiring the autolock. await call_hass_service( hass=self.hass, domain=LOCK_DOMAIN, service=SERVICE_LOCK, target=dict(target), + raise_on_missing=True, ) + def autolock_duration_seconds(self, kmlock: KeymasterLock) -> int: + """Compute the autolock duration for a kmlock based on time of day. + + Sun.is_up determines whether to use the day or night minute setting, + defaulting if the kmlock has no value configured. + """ + if sun.is_up(self.hass): + minutes = kmlock.autolock_min_day or DEFAULT_AUTOLOCK_MIN_DAY + else: + minutes = kmlock.autolock_min_night or DEFAULT_AUTOLOCK_MIN_NIGHT + return int(minutes) * 60 + async def _setup_timers(self) -> None: for kmlock in self.kmlocks.values(): if not isinstance(kmlock, KeymasterLock): @@ -916,21 +940,32 @@ async def _setup_timers(self) -> None: await self._setup_timer(kmlock) async def _setup_timer(self, kmlock: KeymasterLock) -> None: + """Construct the AutolockTimer for this kmlock if absent, then recover. + + The AutolockTimer captures kmlock only via a get_kmlock closure + that resolves through `self.kmlocks[id]` at fire time, so a + config-entry reload that replaces the kmlock instance is picked + up transparently — the action runs against the live replacement. + """ if not isinstance(kmlock, KeymasterLock): return + if kmlock.autolock_timer is not None: + return + entry_id = kmlock.keymaster_config_entry_id - if not hasattr(kmlock, "autolock_timer") or not kmlock.autolock_timer: - kmlock.autolock_timer = KeymasterTimer() - if not kmlock.autolock_timer.is_setup: - await kmlock.autolock_timer.setup( - hass=self.hass, - kmlock=kmlock, - call_action=functools.partial(self._timer_triggered, kmlock), - timer_id=f"{kmlock.keymaster_config_entry_id}_autolock", - store=self._timer_store, - ) - if kmlock.autolock_timer.is_running: - self.async_set_updated_data(dict(self.kmlocks)) + def get_kmlock(eid: str = entry_id) -> KeymasterLock | None: + return self.kmlocks.get(eid) + + kmlock.autolock_timer = AutolockTimer( + hass=self.hass, + store=self._timer_store, + timer_id=f"{entry_id}_autolock", + get_kmlock=get_kmlock, + action=self._timer_triggered, + ) + await kmlock.autolock_timer.recover() + if kmlock.autolock_timer.is_running: + self.async_set_updated_data(dict(self.kmlocks)) async def _timer_triggered(self, kmlock: KeymasterLock, _: dt) -> None: _LOGGER.debug("[timer_triggered] %s", kmlock.lock_name) @@ -942,8 +977,25 @@ async def _timer_triggered(self, kmlock: KeymasterLock, _: dt) -> None: message=f"Unable to lock {kmlock.lock_name} as the sensor indicates the door is currently opened. The operation will be automatically retried when the door is closed.", notification_id=f"{slugify(kmlock.lock_name).lower()}_autolock_door_open", ) - else: + return + try: await self._lock_lock(kmlock=kmlock) + except Exception: + # AutolockTimer preserves the store entry for replay on next + # restart, but the user has no UI signal otherwise. Surface + # a notification so they can act before that. + _LOGGER.exception("[timer_triggered] %s: autolock action failed", kmlock.lock_name) + await send_persistent_notification( + hass=self.hass, + title=f"Autolock failed for {kmlock.lock_name}", + message=( + f"Autolock for {kmlock.lock_name} could not lock the door. " + "Check the lock's connection and lock it manually if needed. " + "The operation will be retried on next Home Assistant restart." + ), + notification_id=f"{slugify(kmlock.lock_name).lower()}_autolock_failed", + ) + raise async def _update_door_and_lock_state(self, trigger_actions_if_changed: bool = False) -> None: # _LOGGER.debug("[update_door_and_lock_state] Running") @@ -1076,7 +1128,6 @@ async def _update_lock(self, new: KeymasterLock) -> bool: ): return False await KeymasterCoordinator._unsubscribe_listeners(old) - # _LOGGER.debug("[update_lock] %s: old: %s", new.lock_name, old) del_code_slots: list[int] = [ old.starting_code_slot + i for i in range(old.number_of_code_slots) ] @@ -1087,40 +1138,18 @@ async def _update_lock(self, new: KeymasterLock) -> bool: if code_slot_num in del_code_slots: del_code_slots.remove(code_slot_num) - new.lock_state = old.lock_state - new.door_state = old.door_state - new.autolock_enabled = old.autolock_enabled - new.autolock_min_day = old.autolock_min_day - new.autolock_min_night = old.autolock_min_night - new.retry_lock = old.retry_lock - for code_slot_num, new_kmslot in new.code_slots.items(): - if code_slot_num not in old.code_slots: - continue - old_kmslot: KeymasterCodeSlot = old.code_slots[code_slot_num] - new_kmslot.enabled = old_kmslot.enabled - new_kmslot.name = old_kmslot.name - new_kmslot.pin = old_kmslot.pin - new_kmslot.override_parent = old_kmslot.override_parent - new_kmslot.notifications = old_kmslot.notifications - new_kmslot.accesslimit_count_enabled = old_kmslot.accesslimit_count_enabled - new_kmslot.accesslimit_count = old_kmslot.accesslimit_count - new_kmslot.accesslimit_date_range_enabled = old_kmslot.accesslimit_date_range_enabled - new_kmslot.accesslimit_date_range_start = old_kmslot.accesslimit_date_range_start - new_kmslot.accesslimit_date_range_end = old_kmslot.accesslimit_date_range_end - new_kmslot.accesslimit_day_of_week_enabled = old_kmslot.accesslimit_day_of_week_enabled - if not new_kmslot.accesslimit_day_of_week: - continue - for dow_num, new_dow in new_kmslot.accesslimit_day_of_week.items(): - if not old_kmslot.accesslimit_day_of_week: - continue - old_dow: KeymasterCodeSlotDayOfWeek = old_kmslot.accesslimit_day_of_week[dow_num] - new_dow.dow_enabled = old_dow.dow_enabled - new_dow.limit_by_time = old_dow.limit_by_time - new_dow.include_exclude = old_dow.include_exclude - new_dow.time_start = old_dow.time_start - new_dow.time_end = old_dow.time_end + # Carry user/runtime state from old → new (lock state, autolock + # config, retry state, code slots + DOW). Owned by KeymasterLock + # so the field-by-field copy lives next to the field declarations. + new.inherit_state_from(old) + + # Transfer the timer to new. The get_kmlock closure resolves + # through self.kmlocks[id] (updated below), so the action fires + # against the live kmlock without needing to rebind the timer. + new.autolock_timer = old.autolock_timer + old.autolock_timer = None + self.kmlocks[new.keymaster_config_entry_id] = new - # _LOGGER.debug("[update_lock] %s: new: %s", new.lock_name, new) _LOGGER.debug("[update_lock] Code slot entities to delete: %s", del_code_slots) for code_slot_num in del_code_slots: await delete_code_slot_entities( @@ -1131,7 +1160,11 @@ async def _update_lock(self, new: KeymasterLock) -> bool: await self._rebuild_lock_relationships() await self._update_door_and_lock_state() await self._update_listeners(self.kmlocks[new.keymaster_config_entry_id]) - await self._setup_timer(self.kmlocks[new.keymaster_config_entry_id]) + # Construct the timer if old didn't have one (defensive — should be + # rare since add_lock sets one up, but a half-initialized old + # instance might not). + if new.autolock_timer is None: + await self._setup_timer(new) await self.async_refresh() return True diff --git a/custom_components/keymaster/helpers.py b/custom_components/keymaster/helpers.py index 1314118e..fb3984ff 100644 --- a/custom_components/keymaster/helpers.py +++ b/custom_components/keymaster/helpers.py @@ -2,35 +2,21 @@ from __future__ import annotations -from collections.abc import Callable, MutableMapping -from datetime import datetime as dt, timedelta +from collections.abc import MutableMapping import logging import time -from typing import TYPE_CHECKING, Any, TypedDict +from typing import TYPE_CHECKING, Any from homeassistant.components import persistent_notification from homeassistant.components.script import DOMAIN as SCRIPT_DOMAIN from homeassistant.core import HomeAssistant, callback from homeassistant.exceptions import ServiceNotFound -from homeassistant.helpers import entity_registry as er, sun -from homeassistant.helpers.event import async_call_later -from homeassistant.helpers.storage import Store -from homeassistant.util import dt as dt_util, slugify +from homeassistant.helpers import entity_registry as er +from homeassistant.util import slugify -from .const import DEFAULT_AUTOLOCK_MIN_DAY, DEFAULT_AUTOLOCK_MIN_NIGHT, DOMAIN +from .const import DOMAIN from .providers import is_platform_supported -TIMER_STORAGE_VERSION = 1 -TIMER_STORAGE_KEY = f"{DOMAIN}.timers" - - -class TimerStoreEntry(TypedDict): - """Persisted state for a single autolock timer.""" - - end_time: str - duration: int - - if TYPE_CHECKING: from .lock import KeymasterLock @@ -62,178 +48,6 @@ def reset(self, func_name: str, key: str) -> None: self._cooldowns[func_name].pop(key, None) -class KeymasterTimer: - """Persistent auto-lock timer backed by HA Store. - - The timer persists its end_time to disk so it survives HA restarts. - On setup(), if a persisted timer is found: - - expired → fire the action immediately and clean up - - active → resume with the remaining time - - absent → idle (no timer was running) - """ - - def __init__(self) -> None: - """Initialize the keymaster Timer.""" - self.hass: HomeAssistant | None = None - self._unsub_events: list[Callable] = [] - self._kmlock: KeymasterLock | None = None - self._call_action: Callable | None = None - self._end_time: dt | None = None - self._duration: int | None = None - self._timer_id: str | None = None - self._store: Store[dict[str, TimerStoreEntry]] | None = None - - async def setup( - self, - hass: HomeAssistant, - kmlock: KeymasterLock, - call_action: Callable, - timer_id: str, - store: Store[dict[str, TimerStoreEntry]], - ) -> None: - """Set up the timer and recover any persisted state.""" - self.hass = hass - self._kmlock = kmlock - self._call_action = call_action - self._timer_id = timer_id - self._store = store - - # Recover persisted timer - data = await store.async_load() or {} - timer_data = data.get(timer_id) - if timer_data: - try: - end_time = dt.fromisoformat(timer_data["end_time"]) - except (KeyError, TypeError, ValueError): - _LOGGER.warning( - "[KeymasterTimer] %s: Invalid persisted timer data, removing", - timer_id, - ) - await self._remove_from_store() - return - duration = timer_data.get("duration", 0) - if end_time <= dt_util.utcnow(): - _LOGGER.debug( - "[KeymasterTimer] %s: Persisted timer expired during downtime, firing", - timer_id, - ) - await self._remove_from_store() - hass.async_create_task(call_action(dt_util.utcnow())) - else: - _LOGGER.debug( - "[KeymasterTimer] %s: Resuming persisted timer, ending %s", - timer_id, - end_time, - ) - await self._resume(end_time, duration) - - async def start(self) -> bool: - """Start a timer.""" - if not self.hass or not self._kmlock or not self._call_action: - _LOGGER.error("[KeymasterTimer] Cannot start timer as timer not setup") - return False - - # Cancel any existing timer - self._cancel_callbacks() - - if sun.is_up(self.hass): - delay: int = (self._kmlock.autolock_min_day or DEFAULT_AUTOLOCK_MIN_DAY) * 60 - else: - delay = (self._kmlock.autolock_min_night or DEFAULT_AUTOLOCK_MIN_NIGHT) * 60 - self._duration = int(delay) - self._end_time = dt_util.utcnow() + timedelta(seconds=delay) - _LOGGER.debug( - "[KeymasterTimer] Starting auto-lock timer for %s seconds. Ending %s", - int(delay), - self._end_time, - ) - self._schedule_callbacks(delay) - await self._persist_to_store() - return True - - async def cancel(self, timer_elapsed: dt | None = None) -> None: - """Cancel a timer.""" - if timer_elapsed: - _LOGGER.debug("[KeymasterTimer] Timer elapsed") - else: - _LOGGER.debug("[KeymasterTimer] Cancelling auto-lock timer") - self._cancel_callbacks() - self._end_time = None - self._duration = None - await self._remove_from_store() - - def _schedule_callbacks(self, delay: float) -> None: - """Schedule a single callback that fires the action then cleans up.""" - - async def _on_expired(now: dt) -> None: - """Fire the action and clean up timer state.""" - if self._call_action: - await self._call_action(now) - await self.cancel(timer_elapsed=now) - - self._unsub_events.append(async_call_later(hass=self.hass, delay=delay, action=_on_expired)) - - def _cancel_callbacks(self) -> None: - """Unsubscribe all pending callbacks.""" - for unsub in self._unsub_events: - unsub() - self._unsub_events = [] - - async def _resume(self, end_time: dt, duration: int) -> None: - """Resume a timer from a persisted end_time.""" - remaining = (end_time - dt_util.utcnow()).total_seconds() - self._end_time = end_time - self._duration = duration - self._schedule_callbacks(remaining) - - async def _persist_to_store(self) -> None: - """Write current timer state to the store.""" - if not self._store or not self._timer_id or not self._end_time: - return - data = await self._store.async_load() or {} - data[self._timer_id] = { - "end_time": self._end_time.isoformat(), - "duration": self._duration, - } - await self._store.async_save(data) - - async def _remove_from_store(self) -> None: - """Remove this timer's entry from the store.""" - if not self._store or not self._timer_id: - return - data = await self._store.async_load() or {} - if self._timer_id in data: - del data[self._timer_id] - await self._store.async_save(data) - - @property - def is_running(self) -> bool: - """Return if the timer is running.""" - return self._end_time is not None and self._end_time > dt_util.utcnow() - - @property - def is_setup(self) -> bool: - """Return if the timer has been initially setup.""" - return bool(self.hass and self._kmlock and self._call_action) - - @property - def end_time(self) -> dt | None: - """Returns when the timer will end.""" - return self._end_time if self.is_running else None - - @property - def remaining_seconds(self) -> int | None: - """Return the seconds until the timer ends.""" - if not self.is_running: - return None - return round((self._end_time - dt_util.utcnow()).total_seconds()) - - @property - def duration(self) -> int | None: - """Return the total timer duration in seconds.""" - return self._duration if self.is_running else None - - @callback def async_has_supported_provider( hass: HomeAssistant, @@ -341,8 +155,17 @@ async def call_hass_service( service: str, service_data: dict[str, Any] | None = None, target: dict[str, Any] | None = None, + *, + raise_on_missing: bool = False, ) -> None: - """Call a hass service and log a failure on an error.""" + """Call a hass service and log a failure on an error. + + If `raise_on_missing` is True, a `ServiceNotFound` (e.g. the lock + entity was removed/renamed) propagates to the caller instead of + being swallowed with a warning. Safety-critical callers (autolock) + set this so the failure surfaces to user notifications rather than + silently retiring the timer as if the action had succeeded. + """ _LOGGER.debug( "[call_hass_service] service: %s.%s, target: %s, service_data: %s", domain, @@ -354,6 +177,8 @@ async def call_hass_service( try: await hass.services.async_call(domain, service, service_data=service_data, target=target) except ServiceNotFound: + if raise_on_missing: + raise _LOGGER.warning("Action Not Found: %s.%s", domain, service) diff --git a/custom_components/keymaster/lock.py b/custom_components/keymaster/lock.py index 0301479e..2881aa5a 100644 --- a/custom_components/keymaster/lock.py +++ b/custom_components/keymaster/lock.py @@ -5,14 +5,17 @@ from collections.abc import Callable, MutableMapping from dataclasses import dataclass, field from datetime import datetime as dt, time as dt_time +import logging from typing import TYPE_CHECKING from .const import Synced -from .helpers import KeymasterTimer if TYPE_CHECKING: + from .autolock import AutolockTimer from .providers import BaseLockProvider +_LOGGER: logging.Logger = logging.getLogger(__name__) + @dataclass class KeymasterCodeSlotDayOfWeek: @@ -26,6 +29,18 @@ class KeymasterCodeSlotDayOfWeek: time_start: dt_time | None = None time_end: dt_time | None = None + def inherit_state_from(self, old: KeymasterCodeSlotDayOfWeek) -> None: + """Carry the user-configurable state of `old` into `self`. + + Structural identity (`day_of_week_num`, `day_of_week_name`) is + intentionally NOT inherited — those belong to `self`. + """ + self.dow_enabled = old.dow_enabled + self.limit_by_time = old.limit_by_time + self.include_exclude = old.include_exclude + self.time_start = old.time_start + self.time_end = old.time_end + @dataclass class KeymasterCodeSlot: @@ -47,6 +62,35 @@ class KeymasterCodeSlot: accesslimit_day_of_week_enabled: bool = False accesslimit_day_of_week: MutableMapping[int, KeymasterCodeSlotDayOfWeek] | None = None + def inherit_state_from(self, old: KeymasterCodeSlot) -> None: + """Carry user state from `old` into `self`. + + Structural identity (`number`) and runtime-only fields (`active`, + `synced`) are intentionally NOT inherited — they belong to the + new instance's lifecycle. + + For `accesslimit_day_of_week`, only DOW keys present on both + sides are inherited; keys present only on one side are left + alone (kept on `self`, dropped from `old`). + """ + self.enabled = old.enabled + self.name = old.name + self.pin = old.pin + self.override_parent = old.override_parent + self.notifications = old.notifications + self.accesslimit_count_enabled = old.accesslimit_count_enabled + self.accesslimit_count = old.accesslimit_count + self.accesslimit_date_range_enabled = old.accesslimit_date_range_enabled + self.accesslimit_date_range_start = old.accesslimit_date_range_start + self.accesslimit_date_range_end = old.accesslimit_date_range_end + self.accesslimit_day_of_week_enabled = old.accesslimit_day_of_week_enabled + if not self.accesslimit_day_of_week or not old.accesslimit_day_of_week: + return + for dow_num, new_dow in self.accesslimit_day_of_week.items(): + old_dow = old.accesslimit_day_of_week.get(dow_num) + if old_dow is not None: + new_dow.inherit_state_from(old_dow) + @dataclass class KeymasterLock: @@ -73,7 +117,7 @@ class KeymasterLock: autolock_enabled: bool = False autolock_min_day: int | None = None autolock_min_night: int | None = None - autolock_timer: KeymasterTimer | None = None + autolock_timer: AutolockTimer | None = None retry_lock: bool = False pending_retry_lock: bool = False parent_name: str | None = None @@ -84,6 +128,44 @@ class KeymasterLock: # Transient runtime-only field; excluded from persistence (init=False). masked_code_slots: set[int] = field(default_factory=set, init=False, repr=False) + def inherit_state_from(self, old: KeymasterLock) -> None: + """Carry user/runtime state from a previous instance into this one. + + Used during config-entry reload: the new instance is constructed + fresh from config, but user-owned state (autolock config, current + lock/door state, code-slot contents, in-flight retry) must + survive the swap. + """ + self.lock_state = old.lock_state + self.door_state = old.door_state + self.autolock_enabled = old.autolock_enabled + self.autolock_min_day = old.autolock_min_day + self.autolock_min_night = old.autolock_min_night + self.retry_lock = old.retry_lock + self.pending_retry_lock = old.pending_retry_lock + if not self.code_slots or not old.code_slots: + # Log loudly: silent code-slot loss would drop the user's + # PINs/schedules without any signal until they notice codes + # have stopped working. + if not self.code_slots and old.code_slots: + _LOGGER.error( + "[KeymasterLock] %s: replacement has no code_slots; " + "dropping %d configured slot(s) from the previous instance", + self.lock_name, + len(old.code_slots), + ) + elif self.code_slots and not old.code_slots: + _LOGGER.warning( + "[KeymasterLock] %s: previous instance had no code_slots; " + "replacement keeps its defaults", + self.lock_name, + ) + return + for code_slot_num, new_slot in self.code_slots.items(): + old_slot = old.code_slots.get(code_slot_num) + if old_slot is not None: + new_slot.inherit_state_from(old_slot) + keymasterlock_type_lookup: MutableMapping[str, type] = { "lock_name": str, @@ -105,7 +187,7 @@ class KeymasterLock: "autolock_enabled": bool, "autolock_min_day": int, "autolock_min_night": int, - # "autolock_timer": KeymasterTimer, + # "autolock_timer": AutolockTimer, "retry_lock": bool, "pending_retry_lock": bool, "parent_name": str, diff --git a/custom_components/keymaster/switch.py b/custom_components/keymaster/switch.py index b7bc9b43..b310f225 100644 --- a/custom_components/keymaster/switch.py +++ b/custom_components/keymaster/switch.py @@ -298,7 +298,9 @@ async def async_turn_on(self, **_: Any) -> None: and self._kmlock.autolock_timer and not self._kmlock.autolock_timer.is_running ): - await self._kmlock.autolock_timer.start() + await self._kmlock.autolock_timer.start( + duration=self.coordinator.autolock_duration_seconds(self._kmlock) + ) self.coordinator.async_set_updated_data(dict(self.coordinator.kmlocks)) if ( self._property.endswith(".enabled") diff --git a/tests/autolock/__init__.py b/tests/autolock/__init__.py new file mode 100644 index 00000000..db005dd6 --- /dev/null +++ b/tests/autolock/__init__.py @@ -0,0 +1 @@ +"""Tests for the autolock subsystem.""" diff --git a/tests/autolock/test_scheduler.py b/tests/autolock/test_scheduler.py new file mode 100644 index 00000000..4b5f94c8 --- /dev/null +++ b/tests/autolock/test_scheduler.py @@ -0,0 +1,165 @@ +"""Tests for the ScheduledFire callback wrapper.""" + +from __future__ import annotations + +import asyncio +from datetime import datetime as dt +from unittest.mock import patch + +import pytest + +from custom_components.keymaster.autolock.scheduler import ScheduledFire +from homeassistant.util import dt as dt_util + + +async def test_fires_after_delay(hass): + """The action runs once when the scheduled delay elapses.""" + fired = [] + + async def action(now: dt) -> None: + fired.append(now) + + # Capture the unsub callable so we can drive `async_call_later` ourselves + with patch( + "custom_components.keymaster.autolock.scheduler.async_call_later" + ) as mock_call_later: + scheduled = ScheduledFire(hass, delay=10, action=action) + captured_action = mock_call_later.call_args.kwargs["action"] + + now = dt_util.utcnow() + await captured_action(now) + assert fired == [now] + assert scheduled.done + + +async def test_cancel_before_fire_prevents_action(hass): + """Cancelling before the callback fires unsubscribes it cleanly.""" + fired = False + + async def action(now: dt) -> None: + nonlocal fired + fired = True + + with patch( + "custom_components.keymaster.autolock.scheduler.async_call_later" + ) as mock_call_later: + unsub_called = False + + def fake_unsub() -> None: + nonlocal unsub_called + unsub_called = True + + mock_call_later.return_value = fake_unsub + scheduled = ScheduledFire(hass, delay=10, action=action) + + await scheduled.cancel() + assert scheduled.cancelled + assert unsub_called + assert not fired + + +async def test_cancel_awaits_in_flight_action(hass): + """If the callback is already running, cancel() awaits its completion.""" + action_started = asyncio.Event() + action_release = asyncio.Event() + action_completed = False + + async def slow_action(now: dt) -> None: + nonlocal action_completed + action_started.set() + await action_release.wait() + action_completed = True + + with patch( + "custom_components.keymaster.autolock.scheduler.async_call_later" + ) as mock_call_later: + scheduled = ScheduledFire(hass, delay=10, action=slow_action) + captured_action = mock_call_later.call_args.kwargs["action"] + + # Drive the callback so it's mid-execution when cancel runs + fire_task = asyncio.create_task(captured_action(dt_util.utcnow())) + await action_started.wait() + assert not action_completed + + cancel_task = asyncio.create_task(scheduled.cancel()) + await asyncio.sleep(0) + assert not cancel_task.done(), "cancel must wait for in-flight action" + + action_release.set() + await asyncio.gather(fire_task, cancel_task) + assert action_completed + + +async def test_cancel_is_idempotent(hass): + """Calling cancel() repeatedly is safe and stays cancelled.""" + + async def action(now: dt) -> None: + pass + + with patch("custom_components.keymaster.autolock.scheduler.async_call_later"): + scheduled = ScheduledFire(hass, delay=10, action=action) + + await scheduled.cancel() + await scheduled.cancel() + assert scheduled.cancelled + + +async def test_cancel_swallows_action_exception(hass, caplog): + """If the in-flight action raises, cancel() logs and proceeds.""" + + async def failing_action(now: dt) -> None: + raise RuntimeError("boom") + + with patch( + "custom_components.keymaster.autolock.scheduler.async_call_later" + ) as mock_call_later: + scheduled = ScheduledFire(hass, delay=10, action=failing_action) + captured_action = mock_call_later.call_args.kwargs["action"] + + fire_task = asyncio.create_task(captured_action(dt_util.utcnow())) + # Let the action raise + with pytest.raises(RuntimeError): + await fire_task + # cancel should not re-raise even though the task ended exceptionally + await scheduled.cancel() + + +async def test_cancel_swallows_in_flight_cancelled_error(hass): + """cancel() must not re-raise CancelledError from the in-flight task. + + asyncio.CancelledError inherits from BaseException, so a bare + `except Exception` would let it escape and cancel the caller — + violating cancel()'s contract of never re-raising in-flight failures. + """ + + async def cancellable_action(now: dt) -> None: + await asyncio.sleep(60) # ensure we're mid-await when cancelled + + with patch( + "custom_components.keymaster.autolock.scheduler.async_call_later" + ) as mock_call_later: + scheduled = ScheduledFire(hass, delay=10, action=cancellable_action) + captured_action = mock_call_later.call_args.kwargs["action"] + + fire_task = asyncio.create_task(captured_action(dt_util.utcnow())) + await asyncio.sleep(0) # let it start + fire_task.cancel() + # cancel() must not re-raise even though fire_task ended with CancelledError + await scheduled.cancel() + + +async def test_negative_delay_clamped_to_zero(hass): + """Clamp negative delay to zero. + + A negative delay (e.g. recovery for an already-expired timer) + schedules with delay=0 instead of crashing async_call_later. + """ + + async def action(now: dt) -> None: + pass + + with patch( + "custom_components.keymaster.autolock.scheduler.async_call_later" + ) as mock_call_later: + ScheduledFire(hass, delay=-5, action=action) + assert mock_call_later.call_args.kwargs["delay"] == 0 diff --git a/tests/autolock/test_store.py b/tests/autolock/test_store.py new file mode 100644 index 00000000..653fcb18 --- /dev/null +++ b/tests/autolock/test_store.py @@ -0,0 +1,160 @@ +"""Tests for the TimerStore persistence layer.""" + +from __future__ import annotations + +import asyncio +from datetime import datetime as dt, timedelta +from unittest.mock import AsyncMock + +import pytest + +from custom_components.keymaster.autolock.store import TimerEntry, TimerStore +from homeassistant.util import dt as dt_util + + +@pytest.fixture +def store(hass): + """Provide a TimerStore wired to a real HA Store.""" + return TimerStore(hass) + + +@pytest.fixture +def entry() -> TimerEntry: + """Provide a fresh-in-the-future entry.""" + return TimerEntry(end_time=dt_util.utcnow() + timedelta(minutes=5), duration=300) + + +async def test_read_absent_returns_none(store): + """Reading a missing timer_id yields None without raising.""" + assert await store.read("missing") is None + + +async def test_write_then_read_roundtrips(store, entry): + """write() persists, read() returns the same entry.""" + await store.write("t1", entry) + loaded = await store.read("t1") + assert loaded is not None + assert loaded.end_time == entry.end_time + assert loaded.duration == entry.duration + + +async def test_remove_deletes_entry(store, entry): + """remove() purges the entry; subsequent read() returns None.""" + await store.write("t1", entry) + await store.remove("t1") + assert await store.read("t1") is None + + +async def test_remove_absent_is_noop(store): + """remove() on a missing timer_id is a silent noop.""" + await store.remove("never-existed") # must not raise + + +async def test_write_overwrites_existing(store, entry): + """A second write() under the same timer_id replaces the prior value.""" + await store.write("t1", entry) + later = TimerEntry(end_time=entry.end_time + timedelta(minutes=10), duration=900) + await store.write("t1", later) + loaded = await store.read("t1") + assert loaded == later + + +async def test_multiple_timer_ids_isolated(store, entry): + """Operations on one timer_id don't affect another.""" + other = TimerEntry(end_time=entry.end_time + timedelta(minutes=10), duration=42) + await store.write("a", entry) + await store.write("b", other) + assert await store.read("a") == entry + assert await store.read("b") == other + await store.remove("a") + assert await store.read("a") is None + assert await store.read("b") == other + + +async def test_non_mapping_entry_is_removed_on_read(store): + """Persisted entry that's not a dict (e.g. legacy list/string) is pruned. + + Regression: `_parse` previously called `.get()` on `raw` unconditionally, + so a non-mapping value would AttributeError and break recovery. + """ + await store._store.async_save({"weird": ["unexpected", "list"]}) + assert await store.read("weird") is None + raw = await store._store.async_load() or {} + assert "weird" not in raw + + +async def test_negative_duration_entry_is_removed_on_read(store): + """A persisted entry with a negative duration is pruned. + + Regression: TimerEntry's __post_init__ raises ValueError for negative + duration, but `_parse` didn't catch it — would crash recovery. + """ + future = (dt_util.utcnow() + timedelta(minutes=5)).isoformat() + await store._store.async_save({"bad": {"end_time": future, "duration": -1}}) + assert await store.read("bad") is None + raw = await store._store.async_load() or {} + assert "bad" not in raw + + +async def test_corrupt_entry_is_removed_on_read(hass, store, entry): + """Corrupt entries are pruned so callers see them as absent.""" + # Plant a malformed entry by going around the public API + await store._store.async_save({"corrupt": {"end_time": "not-a-date", "duration": 5}}) + assert await store.read("corrupt") is None + # Confirm it was removed + raw = await store._store.async_load() or {} + assert "corrupt" not in raw + + +async def test_naive_end_time_interpreted_as_utc(store): + """Naive on-disk datetimes are interpreted as UTC, not local time. + + Regression: an earlier version used `dt_util.as_utc()` which converts + from local/default-zone, so the loaded value would be wrong on any + non-UTC HA install. The fix uses `replace(tzinfo=UTC)` to interpret + the stored value as already-UTC. Compare loaded value against the + same instant treated as UTC — equality (not just tz-awareness) is + what catches the regression. + """ + # Specific UTC instant: 2030-01-01 12:34:56Z + known_utc = dt(2030, 1, 1, 12, 34, 56, tzinfo=dt_util.UTC) + naive_iso = known_utc.replace(tzinfo=None).isoformat() + await store._store.async_save({"legacy": {"end_time": naive_iso, "duration": 300}}) + + loaded = await store.read("legacy") + assert loaded is not None + assert loaded.end_time.tzinfo is not None + # The load must produce the SAME UTC instant — `as_utc` would have + # shifted it by the local UTC offset on non-UTC test hosts. + assert loaded.end_time == known_utc + + +async def test_concurrent_writes_serialized_by_lock(hass, store): + """Two concurrent writes must serialize — neither overwrites the other. + + Without the shared lock, both would load the empty dict, each set + their own key, and the later async_save would clobber the earlier. + """ + e1 = TimerEntry(end_time=dt_util.utcnow() + timedelta(minutes=5), duration=300) + e2 = TimerEntry(end_time=dt_util.utcnow() + timedelta(minutes=10), duration=600) + + # Make load yield so the writes have a chance to interleave + real_load = store._store.async_load + real_save = store._store.async_save + save_calls = [] + + async def slow_load(): + await asyncio.sleep(0) + return await real_load() + + async def tracking_save(data): + save_calls.append(dict(data)) + await real_save(data) + + store._store.async_load = AsyncMock(side_effect=slow_load) + store._store.async_save = AsyncMock(side_effect=tracking_save) + + await asyncio.gather(store.write("a", e1), store.write("b", e2)) + + final = await store._store.async_load() or {} + assert "a" in final and "b" in final, f"expected both keys, got {final}" diff --git a/tests/autolock/test_timer.py b/tests/autolock/test_timer.py new file mode 100644 index 00000000..e5414fd5 --- /dev/null +++ b/tests/autolock/test_timer.py @@ -0,0 +1,389 @@ +"""Tests for AutolockTimer orchestration + state machine. + +Each named scenario maps to one of the races identified during the +PR #601 review iterations. The redesign addresses each by construction +rather than by patching the old code. +""" + +from __future__ import annotations + +import asyncio +from datetime import datetime as dt, timedelta +from unittest.mock import AsyncMock, patch + +import pytest + +from custom_components.keymaster.autolock.store import TimerEntry, TimerStore +from custom_components.keymaster.autolock.timer import AutolockTimer, TimerState +from custom_components.keymaster.lock import KeymasterLock +from homeassistant.util import dt as dt_util + + +@pytest.fixture +def store(hass) -> TimerStore: + """Provide a TimerStore wired to a real HA Store.""" + return TimerStore(hass) + + +@pytest.fixture +def kmlock() -> KeymasterLock: + """Provide a fresh KeymasterLock.""" + return KeymasterLock( + lock_name="test_lock", + lock_entity_id="lock.test", + keymaster_config_entry_id="entry_1", + ) + + +def make_timer( + hass, + store: TimerStore, + *, + timer_id: str = "t1", + kmlock: KeymasterLock | None = None, + action: AsyncMock | None = None, +) -> tuple[AutolockTimer, AsyncMock, dict]: + """Build an AutolockTimer with a tracked action and mutable kmlock slot. + + Returns (timer, action_mock, slot) where `slot["kmlock"]` is the + indirect kmlock the timer resolves at fire time. Mutating + `slot["kmlock"] = other` simulates a config-entry reload. + """ + if action is None: + action = AsyncMock() + slot: dict = {"kmlock": kmlock} + timer = AutolockTimer( + hass=hass, + store=store, + timer_id=timer_id, + get_kmlock=lambda: slot["kmlock"], + action=action, + ) + return timer, action, slot + + +# ---------------------------------------------------------------------- +# State machine basics +# ---------------------------------------------------------------------- + + +async def test_constructed_in_fresh_state(hass, store, kmlock): + """A new instance is FRESH and not running.""" + timer, _, _ = make_timer(hass, store, kmlock=kmlock) + assert timer.state == TimerState.FRESH + assert not timer.is_running + assert timer.end_time is None + + +async def test_start_before_recover_raises(hass, store, kmlock): + """Forbid start() before recover(). + + The FRESH→ACTIVE transition requires recover() so the timer always + sees any persisted prior state. + """ + timer, _, _ = make_timer(hass, store, kmlock=kmlock) + with pytest.raises(RuntimeError, match="recover"): + await timer.start(duration=300) + + +async def test_recover_with_no_entry_goes_to_done(hass, store, kmlock): + """Recovering with an empty store leaves the timer in DONE.""" + timer, action, _ = make_timer(hass, store, kmlock=kmlock) + await timer.recover() + assert timer.state == TimerState.DONE + assert action.await_count == 0 + + +async def test_recover_resumes_active_entry(hass, store, kmlock): + """Recovering an active entry transitions to ACTIVE and schedules.""" + end_time = dt_util.utcnow() + timedelta(minutes=5) + await store.write("t1", TimerEntry(end_time=end_time, duration=300)) + timer, action, _ = make_timer(hass, store, kmlock=kmlock) + await timer.recover() + assert timer.state == TimerState.ACTIVE + assert timer.is_running + assert timer.end_time == end_time + assert timer.duration == 300 + assert action.await_count == 0 + + +async def test_recover_fires_expired_entry(hass, store, kmlock): + """An entry whose end_time is in the past fires the action immediately.""" + expired = dt_util.utcnow() - timedelta(minutes=5) + await store.write("t1", TimerEntry(end_time=expired, duration=300)) + timer, action, _ = make_timer(hass, store, kmlock=kmlock) + await timer.recover() + assert action.await_count == 1 + assert timer.state == TimerState.DONE + assert await store.read("t1") is None + + +# ---------------------------------------------------------------------- +# Start / cancel +# ---------------------------------------------------------------------- + + +async def test_start_writes_entry_and_schedules(hass, store, kmlock): + """start() persists the entry and schedules the callback.""" + timer, _, _ = make_timer(hass, store, kmlock=kmlock) + await timer.recover() + await timer.start(duration=300) + assert timer.state == TimerState.ACTIVE + assert timer.is_running + persisted = await store.read("t1") + assert persisted is not None + assert persisted.duration == 300 + + +async def test_start_replaces_prior_schedule(hass, store, kmlock): + """Calling start() while ACTIVE cancels the prior schedule and replaces it.""" + timer, _, _ = make_timer(hass, store, kmlock=kmlock) + await timer.recover() + await timer.start(duration=300) + first_end = timer.end_time + await asyncio.sleep(0) + await timer.start(duration=600) + assert timer.duration == 600 + assert timer.end_time != first_end + + +async def test_cancel_clears_state_and_store(hass, store, kmlock): + """cancel() clears in-memory state AND removes the store entry.""" + timer, action, _ = make_timer(hass, store, kmlock=kmlock) + await timer.recover() + await timer.start(duration=300) + await timer.cancel() + assert timer.state == TimerState.DONE + assert not timer.is_running + assert await store.read("t1") is None + assert action.await_count == 0 + + +async def test_cancel_idempotent(hass, store, kmlock): + """cancel() is safe to call repeatedly.""" + timer, _, _ = make_timer(hass, store, kmlock=kmlock) + await timer.recover() + await timer.cancel() + await timer.cancel() # must not raise + assert timer.state == TimerState.DONE + + +# ---------------------------------------------------------------------- +# The races that motivated the redesign +# ---------------------------------------------------------------------- + + +async def test_action_resolves_live_kmlock_at_fire_time(hass, store, kmlock): + """Resolve the LIVE kmlock at fire time, not the captured one. + + A reload between start() and fire-time must NOT cause the action to + run against the OLD kmlock. The indirect get_kmlock closure resolves + the live one at fire time. + + This was the original PR #601 concern: functools.partial captured the + kmlock by reference and mutations landed on the orphaned old instance. + """ + captured_kmlocks: list[KeymasterLock] = [] + + async def action(km: KeymasterLock, _now: dt) -> None: + captured_kmlocks.append(km) + + new_kmlock = KeymasterLock( + lock_name="test_lock", + lock_entity_id="lock.test", + keymaster_config_entry_id="entry_1", + ) + timer, _, slot = make_timer(hass, store, kmlock=kmlock, action=AsyncMock(wraps=action)) + await timer.recover() + + # Drive the callback manually via patched async_call_later so we control timing + with patch( + "custom_components.keymaster.autolock.scheduler.async_call_later" + ) as mock_call_later: + await timer.start(duration=300) + captured_callback = mock_call_later.call_args.kwargs["action"] + + # Simulate a reload between start() and fire + slot["kmlock"] = new_kmlock + + await captured_callback(dt_util.utcnow()) + assert len(captured_kmlocks) == 1 + assert captured_kmlocks[0] is new_kmlock + # Original kmlock was NEVER touched (compare by identity, not equality — + # KeymasterLock is a dataclass so == compares field values) + assert captured_kmlocks[0] is not kmlock + + +async def test_cancel_awaits_in_flight_action(hass, store, kmlock): + """Cancellation awaits an in-flight action. + + Otherwise mutations the action makes after cancel() returns could + land on stale state (or worse, conflict with the cancel itself). + """ + action_started = asyncio.Event() + action_release = asyncio.Event() + action_completed = False + + async def slow_action(km: KeymasterLock, _now: dt) -> None: + nonlocal action_completed + action_started.set() + await action_release.wait() + action_completed = True + + timer, _, _ = make_timer(hass, store, kmlock=kmlock, action=AsyncMock(wraps=slow_action)) + await timer.recover() + + with patch( + "custom_components.keymaster.autolock.scheduler.async_call_later" + ) as mock_call_later: + await timer.start(duration=300) + captured_callback = mock_call_later.call_args.kwargs["action"] + + fire_task = asyncio.create_task(captured_callback(dt_util.utcnow())) + await action_started.wait() + cancel_task = asyncio.create_task(timer.cancel()) + await asyncio.sleep(0) + assert not cancel_task.done(), "cancel must wait for in-flight action" + + action_release.set() + await asyncio.gather(fire_task, cancel_task) + assert action_completed + + +async def test_action_failure_preserves_entry_for_replay(hass, store, kmlock): + """Preserve store entry on action failure for replay on next restart. + + If the action raises, the entry stays so the timer replays on the + next HA restart. The lock didn't actually lock; we prefer 'fire + again later' over 'silently lose the autolock'. + + is_running must report False after the failed fire so callers can + issue a fresh start() to re-arm — the ScheduledFire is `done` even + though the timer state is still ACTIVE for entry-presence reasons. + """ + + async def failing_action(km: KeymasterLock, _now: dt) -> None: + raise RuntimeError("lock service unavailable") + + timer, _, _ = make_timer(hass, store, kmlock=kmlock, action=AsyncMock(wraps=failing_action)) + await timer.recover() + + with patch( + "custom_components.keymaster.autolock.scheduler.async_call_later" + ) as mock_call_later: + await timer.start(duration=300) + captured_callback = mock_call_later.call_args.kwargs["action"] + + await captured_callback(dt_util.utcnow()) + + persisted = await store.read("t1") + assert persisted is not None, "entry must be preserved on action failure" + assert not timer.is_running, "is_running must be False after fire completes" + + +async def test_start_after_in_process_action_failure_rearms(hass, store, kmlock): + """A failed in-process fire leaves the timer rearmable via start(). + + After in-process action failure: state stays ACTIVE, entry is preserved, + is_running=False (the ScheduledFire is done). A subsequent start() must + cancel any lingering scheduled handle and re-arm cleanly without raising. + """ + + async def failing_action(km: KeymasterLock, _now: dt) -> None: + raise RuntimeError("lock service unavailable") + + timer, _, _ = make_timer(hass, store, kmlock=kmlock, action=AsyncMock(wraps=failing_action)) + await timer.recover() + + with patch( + "custom_components.keymaster.autolock.scheduler.async_call_later" + ) as mock_call_later: + await timer.start(duration=300) + captured_callback = mock_call_later.call_args.kwargs["action"] + + await captured_callback(dt_util.utcnow()) # action raises + + assert timer.state == TimerState.ACTIVE + assert not timer.is_running + + # New start() must succeed and re-arm + await timer.start(duration=600) + assert timer.is_running + assert timer.duration == 600 + + +async def test_recovery_action_failure_preserves_entry(hass, store, kmlock): + """Recovery-fire action failure also preserves the entry. + + Same contract as the in-process firing path: action failure leaves + the entry on disk so the next restart retries. The timer must also + leave FRESH (otherwise a subsequent start() would raise) — verify + state transitions to ACTIVE with no scheduled callback, and that + start() can re-arm cleanly. + """ + expired = dt_util.utcnow() - timedelta(minutes=5) + await store.write("t1", TimerEntry(end_time=expired, duration=300)) + + async def failing_action(km: KeymasterLock, _now: dt) -> None: + raise RuntimeError("lock service unavailable") + + timer, _, _ = make_timer(hass, store, kmlock=kmlock, action=AsyncMock(wraps=failing_action)) + await timer.recover() + + # Post-recover state: ACTIVE (entry preserved) but is_running=False + # (no scheduled callback). A fresh start() must be possible. + assert timer.state == TimerState.ACTIVE + assert not timer.is_running + await timer.start(duration=300) # must not raise + + persisted = await store.read("t1") + assert persisted is not None + + +async def test_action_with_missing_kmlock_clears_state_terminally(hass, store, caplog): + """Treat missing kmlock at fire time as terminal: clean up, don't loop. + + If the kmlock was deleted before fire time, skip the action AND + clear the persisted entry + transition to DONE — otherwise the + timer would stay ACTIVE with an expired end_time, replaying + forever on subsequent restarts. + """ + action = AsyncMock() + timer, _, slot = make_timer(hass, store, kmlock=None, action=action) + await timer.recover() + + with patch( + "custom_components.keymaster.autolock.scheduler.async_call_later" + ) as mock_call_later: + slot["kmlock"] = KeymasterLock( + lock_name="x", lock_entity_id="lock.x", keymaster_config_entry_id="x" + ) + await timer.start(duration=300) + captured_callback = mock_call_later.call_args.kwargs["action"] + + slot["kmlock"] = None # kmlock vanished before fire + await captured_callback(dt_util.utcnow()) + + assert action.await_count == 0 + assert timer.state == TimerState.DONE + assert not timer.is_running + assert await store.read("t1") is None, "entry must be cleared so it can't replay" + + +async def test_cross_timer_writes_dont_clobber(hass, store, kmlock): + """Cross-timer concurrent writes don't clobber each other. + + Two timers writing to the same TimerStore concurrently must both end + up persisted. The shared lock inside TimerStore is what makes this + safe — without it, last-writer wins. + + (This complements the dedicated TimerStore test; here we exercise it + through the AutolockTimer surface to cover the integration.) + """ + timer_a, _, _ = make_timer(hass, store, timer_id="a", kmlock=kmlock) + timer_b, _, _ = make_timer(hass, store, timer_id="b", kmlock=kmlock) + await timer_a.recover() + await timer_b.recover() + await asyncio.gather(timer_a.start(duration=300), timer_b.start(duration=600)) + assert await store.read("a") is not None + assert await store.read("b") is not None diff --git a/tests/test_coordinator.py b/tests/test_coordinator.py index 533f5a0b..0c7a24a5 100644 --- a/tests/test_coordinator.py +++ b/tests/test_coordinator.py @@ -1009,7 +1009,8 @@ async def test_lock_locked_already_locked_clears_pending_retry( await mock_coordinator._lock_locked(mock_kmlock, source="manual") assert mock_kmlock.pending_retry_lock is False - assert mock_dismiss.call_count == 2 + # door_open + door_closed + autolock_failed dismissed on lock success + assert mock_dismiss.call_count == 3 async def test_lock_locked_throttled(self, mock_coordinator, mock_kmlock): """Test _lock_locked respects throttling.""" @@ -1065,10 +1066,13 @@ async def test_lock_unlocked_starts_autolock_timer(self, mock_coordinator, mock_ mock_kmlock.code_slots = {} mock_coordinator._throttle = Mock() mock_coordinator._throttle.is_allowed = Mock(return_value=True) + # Coordinator now computes the duration before calling start(); + # bypass the sun.is_up + autolock_min_* lookup here. + mock_coordinator.autolock_duration_seconds = Mock(return_value=300) await mock_coordinator._lock_unlocked(mock_kmlock, source="manual") - mock_kmlock.autolock_timer.start.assert_called_once() + mock_kmlock.autolock_timer.start.assert_called_once_with(duration=300) mock_coordinator.async_set_updated_data.assert_called_once() async def test_lock_unlocked_no_autolock_no_data_update(self, mock_coordinator, mock_kmlock): @@ -1183,7 +1187,7 @@ async def test_door_closed_retry_lock_sends_notifications(self, mock_coordinator assert "closed" in mock_send.call_args.kwargs["message"].lower() async def test_lock_locked_dismisses_retry_notifications(self, mock_coordinator, mock_kmlock): - """Test _lock_locked dismisses both retry lock persistent notifications.""" + """Test _lock_locked dismisses all autolock-related persistent notifications.""" mock_coordinator._throttle = Mock() mock_coordinator._throttle.is_allowed = Mock(return_value=True) @@ -1193,12 +1197,13 @@ async def test_lock_locked_dismisses_retry_notifications(self, mock_coordinator, ) as mock_dismiss: await mock_coordinator._lock_locked(mock_kmlock, source="manual") - assert mock_dismiss.call_count == 2 notification_ids = [ call.kwargs["notification_id"] for call in mock_dismiss.call_args_list ] + # door_open + door_closed + autolock_failed all dismissed on success assert any("_autolock_door_open" in nid for nid in notification_ids) assert any("_autolock_door_closed" in nid for nid in notification_ids) + assert any("_autolock_failed" in nid for nid in notification_ids) async def test_timer_triggered_open_door_sends_notification( self, mock_coordinator, mock_kmlock @@ -1228,6 +1233,34 @@ async def test_timer_triggered_closed_door_locks(self, mock_coordinator, mock_km mock_coordinator._lock_lock.assert_called_once_with(kmlock=mock_kmlock) + async def test_timer_triggered_action_failure_notifies_and_reraises( + self, mock_coordinator, mock_kmlock + ): + """Surface a persistent notification AND re-raise on action failure. + + When _lock_lock raises, _timer_triggered must surface a notification + so the user sees the failure (no UI signal otherwise until next HA + restart) AND re-raise so AutolockTimer._fire enters its + preserve-entry branch (otherwise the timer silently retires the + store entry, losing replay-on-restart). + """ + mock_kmlock.retry_lock = True + mock_kmlock.door_state = STATE_CLOSED + mock_coordinator._lock_lock = AsyncMock(side_effect=RuntimeError("lock unavailable")) + + with ( + patch( + "custom_components.keymaster.coordinator.send_persistent_notification", + new=AsyncMock(), + ) as mock_send, + pytest.raises(RuntimeError, match="lock unavailable"), + ): + await mock_coordinator._timer_triggered(mock_kmlock, dt.now()) + + mock_send.assert_called_once() + notification_id = mock_send.call_args.kwargs["notification_id"] + assert "_autolock_failed" in notification_id + async def test_rapid_unlock_lock_unlock_not_throttled(self, mock_coordinator, mock_kmlock): """Test unlock→lock→unlock within throttle window still starts the timer. @@ -1243,6 +1276,7 @@ async def test_rapid_unlock_lock_unlock_not_throttled(self, mock_coordinator, mo mock_kmlock.lock_notifications = False mock_kmlock.code_slots = {} mock_kmlock.pending_retry_lock = False + mock_coordinator.autolock_duration_seconds = Mock(return_value=300) # Use a real Throttle with a long cooldown to force the race mock_coordinator._throttle = Throttle() @@ -1312,62 +1346,125 @@ def mock_coordinator(self, hass): coordinator._initial_setup_done_event.set() return coordinator - async def test_setup_timer_passes_timer_id_and_store(self, mock_coordinator): - """Test _setup_timer passes timer_id and store to timer.setup().""" + async def test_setup_timer_constructs_with_correct_args(self, mock_coordinator): + """Wire AutolockTimer with the right args + call recover(). + + Asserts timer_id, store, action, and get_kmlock closure resolution. + """ kmlock = KeymasterLock( lock_name="test_lock", lock_entity_id="lock.test", keymaster_config_entry_id="test_entry_123", ) + # Pre-populate self.kmlocks so the get_kmlock closure can resolve + mock_coordinator.kmlocks["test_entry_123"] = kmlock mock_timer = AsyncMock() - mock_timer.is_setup = False mock_timer.is_running = False with patch( - "custom_components.keymaster.coordinator.KeymasterTimer", + "custom_components.keymaster.coordinator.AutolockTimer", return_value=mock_timer, - ): + ) as mock_cls: await mock_coordinator._setup_timer(kmlock) - mock_timer.setup.assert_called_once() - call_kwargs = mock_timer.setup.call_args.kwargs + mock_cls.assert_called_once() + call_kwargs = mock_cls.call_args.kwargs assert call_kwargs["timer_id"] == "test_entry_123_autolock" assert call_kwargs["store"] is mock_coordinator._timer_store + # Bound methods compare equal but aren't `is` (each access binds anew) + assert call_kwargs["action"] == mock_coordinator._timer_triggered + # get_kmlock closure resolves the live kmlock from the dict + assert call_kwargs["get_kmlock"]() is kmlock + mock_timer.recover.assert_awaited_once() + assert kmlock.autolock_timer is mock_timer async def test_setup_timer_pushes_data_when_timer_resumed(self, mock_coordinator): - """Test _setup_timer pushes data to entities when timer resumes from persistence.""" + """Push a coordinator update when recovery leaves the timer running. + + If recover() leaves the timer ACTIVE (a persisted entry was found), + _setup_timer pushes data so entities reflect the resumed state. + """ kmlock = KeymasterLock( lock_name="test_lock", lock_entity_id="lock.test", keymaster_config_entry_id="test_entry_123", ) + mock_coordinator.kmlocks["test_entry_123"] = kmlock mock_timer = AsyncMock() - mock_timer.is_setup = False - mock_timer.is_running = True # Timer resumed from store + mock_timer.is_running = True with patch( - "custom_components.keymaster.coordinator.KeymasterTimer", + "custom_components.keymaster.coordinator.AutolockTimer", return_value=mock_timer, ): await mock_coordinator._setup_timer(kmlock) mock_coordinator.async_set_updated_data.assert_called_once() - async def test_setup_timer_skips_if_already_setup(self, mock_coordinator): - """Test _setup_timer does not call setup() again if timer is already set up.""" + async def test_setup_timer_skips_if_already_attached(self, mock_coordinator): + """Noop if the kmlock already has a timer. + + Covers _update_lock transferring the timer from old → new: the + replacement kmlock keeps the existing timer instance. _setup_timer + must not construct a new one or call recover() (which would raise + from non-FRESH state). + """ kmlock = KeymasterLock( lock_name="test_lock", lock_entity_id="lock.test", keymaster_config_entry_id="test_entry_123", ) - kmlock.autolock_timer = Mock() - kmlock.autolock_timer.is_setup = True + existing_timer = AsyncMock() + kmlock.autolock_timer = existing_timer + + with patch("custom_components.keymaster.coordinator.AutolockTimer") as mock_cls: + await mock_coordinator._setup_timer(kmlock) + + mock_cls.assert_not_called() + existing_timer.recover.assert_not_called() + assert kmlock.autolock_timer is existing_timer + + async def test_setup_timer_get_kmlock_resolves_replacement_after_reload(self, mock_coordinator): + """get_kmlock resolves the live kmlock after reload swaps it. + + The closure resolves through self.kmlocks, so a config-entry + reload that swaps the kmlock instance is visible to the timer at + fire time. This is the structural fix for the "action mutates + orphaned kmlock" race that drove the redesign. + """ + old_kmlock = KeymasterLock( + lock_name="test_lock", + lock_entity_id="lock.test", + keymaster_config_entry_id="entry_1", + ) + new_kmlock = KeymasterLock( + lock_name="test_lock", + lock_entity_id="lock.test", + keymaster_config_entry_id="entry_1", + ) + mock_coordinator.kmlocks["entry_1"] = old_kmlock + + captured_get_kmlock = None + + def capture(*args, **kwargs): + nonlocal captured_get_kmlock + captured_get_kmlock = kwargs["get_kmlock"] + timer = AsyncMock() + timer.is_running = False + return timer - await mock_coordinator._setup_timer(kmlock) + with patch( + "custom_components.keymaster.coordinator.AutolockTimer", + side_effect=capture, + ): + await mock_coordinator._setup_timer(old_kmlock) - kmlock.autolock_timer.setup.assert_not_called() + assert captured_get_kmlock() is old_kmlock + # Simulate reload: swap the kmlock in the coordinator's dict + mock_coordinator.kmlocks["entry_1"] = new_kmlock + assert captured_get_kmlock() is new_kmlock # ============================================================================ diff --git a/tests/test_helpers.py b/tests/test_helpers.py index bd7cece3..38588092 100644 --- a/tests/test_helpers.py +++ b/tests/test_helpers.py @@ -1,13 +1,9 @@ """Test keymaster helpers.""" -from datetime import timedelta -from unittest.mock import AsyncMock, MagicMock, patch - -import pytest +from unittest.mock import MagicMock, patch from custom_components.keymaster.const import DOMAIN from custom_components.keymaster.helpers import ( - KeymasterTimer, Throttle, async_has_supported_provider, call_hass_service, @@ -16,9 +12,8 @@ send_manual_notification, send_persistent_notification, ) -from custom_components.keymaster.lock import KeymasterLock from homeassistant.helpers import entity_registry as er -from homeassistant.util import dt as dt_util, slugify +from homeassistant.util import slugify # Test Throttle class @@ -184,249 +179,6 @@ async def test_delete_code_slot_entities(hass): assert True -@pytest.fixture -def mock_store(): - """Create a mock Store that behaves like an empty HA Store.""" - store = AsyncMock() - store.async_load = AsyncMock(return_value={}) - store.async_save = AsyncMock() - return store - - -# KeymasterTimer tests -async def test_keymaster_timer_init(): - """Test KeymasterTimer initialization.""" - timer = KeymasterTimer() - assert timer.hass is None - assert timer._unsub_events == [] - assert timer._kmlock is None - assert timer._call_action is None - assert timer._end_time is None - assert timer._duration is None - assert not timer.is_setup - assert not timer.is_running - - -async def test_keymaster_timer_setup(hass): - """Test KeymasterTimer setup.""" - timer = KeymasterTimer() - - # Create a mock lock - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - kmlock.autolock_min_day = 5 - kmlock.autolock_min_night = 10 - - # Create a mock callback - async def mock_callback(*args): - pass - - store = AsyncMock() - store.async_load = AsyncMock(return_value={}) - store.async_save = AsyncMock() - await timer.setup(hass, kmlock, mock_callback, timer_id="test_timer", store=store) - - assert timer.hass is hass - assert timer._kmlock is kmlock - assert timer._call_action is mock_callback - assert timer.is_setup - - -async def test_keymaster_timer_start_not_setup(hass, caplog): - """Test starting timer when not setup.""" - timer = KeymasterTimer() - - result = await timer.start() - - assert result is False - assert "[KeymasterTimer] Cannot start timer as timer not setup" in caplog.text - - -async def test_keymaster_timer_start_day(hass): - """Test starting timer during day.""" - timer = KeymasterTimer() - - # Create a mock lock - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - kmlock.autolock_min_day = 5 - kmlock.autolock_min_night = 10 - - # Create a mock callback - async def mock_callback(*args): - pass - - store = AsyncMock() - store.async_load = AsyncMock(return_value={}) - store.async_save = AsyncMock() - await timer.setup(hass, kmlock, mock_callback, timer_id="test_timer", store=store) - - # Mock sun.is_up to return True (daytime) - with patch("custom_components.keymaster.helpers.sun.is_up", return_value=True): - result = await timer.start() - - assert result is True - assert timer._end_time is not None - assert timer._duration == 5 * 60 - assert len(timer._unsub_events) == 1 - assert timer.is_running - assert timer._end_time is not None # Should still be set after checking is_running - - -async def test_keymaster_timer_start_night(hass): - """Test starting timer during night.""" - timer = KeymasterTimer() - - # Create a mock lock - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - kmlock.autolock_min_day = 5 - kmlock.autolock_min_night = 10 - - # Create a mock callback - async def mock_callback(*args): - pass - - store = AsyncMock() - store.async_load = AsyncMock(return_value={}) - store.async_save = AsyncMock() - await timer.setup(hass, kmlock, mock_callback, timer_id="test_timer", store=store) - - # Mock sun.is_up to return False (nighttime) - with patch("custom_components.keymaster.helpers.sun.is_up", return_value=False): - result = await timer.start() - - assert result is True - assert timer._end_time is not None - assert timer._duration == 10 * 60 - assert len(timer._unsub_events) == 1 - assert timer.is_running - assert timer._end_time is not None # Should still be set after checking is_running - - -async def test_keymaster_timer_restart(hass): - """Test restarting an already running timer.""" - timer = KeymasterTimer() - - # Create a mock lock - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - kmlock.autolock_min_day = 5 - - # Create a mock callback - async def mock_callback(*args): - pass - - store = AsyncMock() - store.async_load = AsyncMock(return_value={}) - store.async_save = AsyncMock() - await timer.setup(hass, kmlock, mock_callback, timer_id="test_timer", store=store) - - # Start timer first time - with patch("custom_components.keymaster.helpers.sun.is_up", return_value=True): - result1 = await timer.start() - - assert result1 is True - assert len(timer._unsub_events) == 1 - - # Start timer again - should cancel previous and restart - with patch("custom_components.keymaster.helpers.sun.is_up", return_value=True): - result2 = await timer.start() - - assert result2 is True - assert len(timer._unsub_events) == 1 # Old callback cancelled, new one added - - -async def test_keymaster_timer_cancel(hass): - """Test cancelling a timer.""" - timer = KeymasterTimer() - - # Create a mock lock - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - kmlock.autolock_min_day = 5 - - # Create a mock callback - async def mock_callback(*args): - pass - - store = AsyncMock() - store.async_load = AsyncMock(return_value={}) - store.async_save = AsyncMock() - await timer.setup(hass, kmlock, mock_callback, timer_id="test_timer", store=store) - - # Start timer - with patch("custom_components.keymaster.helpers.sun.is_up", return_value=True): - await timer.start() - - assert timer._end_time is not None - assert timer._duration is not None - assert timer.is_running - - # Cancel timer - await timer.cancel() - - assert not timer.is_running - assert timer._end_time is None - assert timer._duration is None - assert timer._unsub_events == [] - - -async def test_keymaster_timer_properties(hass): - """Test KeymasterTimer properties.""" - timer = KeymasterTimer() - - # Create a mock lock - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - kmlock.autolock_min_day = 5 - - # Create a mock callback - async def mock_callback(*args): - pass - - store = AsyncMock() - store.async_load = AsyncMock(return_value={}) - store.async_save = AsyncMock() - await timer.setup(hass, kmlock, mock_callback, timer_id="test_timer", store=store) - - # Before starting - assert timer.is_setup - assert not timer.is_running - assert timer.end_time is None - assert timer.remaining_seconds is None - assert timer.duration is None - - # Start timer - with patch("custom_components.keymaster.helpers.sun.is_up", return_value=True): - await timer.start() - - # After starting - assert timer.is_running - assert timer.end_time is not None - assert timer.remaining_seconds is not None - assert timer.remaining_seconds > 0 # Time remaining (positive because end_time is in future) - assert timer.duration == 5 * 60 # 5 minutes in seconds - - async def test_delete_code_slot_entities_removes_all(hass): """Test that delete_code_slot_entities attempts to remove all expected entities.""" config_entry_id = "entry_123" @@ -476,211 +228,6 @@ async def test_delete_code_slot_entities_handles_errors(hass): assert mock_registry.async_remove.call_count == 47 -async def test_keymaster_timer_cancel_elapsed(hass): - """Test cancelling a timer that has elapsed.""" - timer = KeymasterTimer() - - # Create a mock lock - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - kmlock.autolock_min_day = 5 - - async def mock_callback(*args): - pass - - store = AsyncMock() - store.async_load = AsyncMock(return_value={}) - store.async_save = AsyncMock() - await timer.setup(hass, kmlock, mock_callback, timer_id="test_timer", store=store) - - # Start timer - with patch("custom_components.keymaster.helpers.sun.is_up", return_value=True): - await timer.start() - - # Cancel with timer_elapsed parameter (simulating callback after timer ends) - await timer.cancel(timer_elapsed=dt_util.utcnow()) - - assert not timer.is_running - assert timer._end_time is None - - -async def test_keymaster_timer_expired_properties_are_pure(hass): - """Test all property reads on an expired timer return correct values without side effects.""" - timer = KeymasterTimer() - - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - - async def mock_callback(*args): - pass - - store = AsyncMock() - store.async_load = AsyncMock(return_value={}) - store.async_save = AsyncMock() - await timer.setup(hass, kmlock, mock_callback, timer_id="test_timer", store=store) - - unsub = MagicMock() - timer._end_time = dt_util.utcnow() - timedelta(seconds=1) - timer._duration = 300 - timer._unsub_events = [unsub] - - # Properties return "not running" values - assert timer.is_running is False - assert timer.end_time is None - assert timer.remaining_seconds is None - assert timer.duration is None - assert timer.is_setup is True - - # But internal state is untouched — only the scheduled callback cleans up - unsub.assert_not_called() - assert timer._end_time is not None - assert timer._duration == 300 - assert len(timer._unsub_events) == 1 - - -async def test_keymaster_timer_setup_recovers_expired_timer(hass, mock_store): - """Test setup() fires action immediately when persisted timer has expired (issue #594).""" - timer = KeymasterTimer() - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - - expired_end_time = (dt_util.utcnow() - timedelta(minutes=5)).isoformat() - mock_store.async_load = AsyncMock( - return_value={"test_timer": {"end_time": expired_end_time, "duration": 300}} - ) - - action_called = False - - async def mock_action(*args): - nonlocal action_called - action_called = True - - await timer.setup(hass, kmlock, mock_action, timer_id="test_timer", store=mock_store) - await hass.async_block_till_done() - - # Expired timer should have fired the action - assert action_called is True - - # Expired timer should be cleaned from store - mock_store.async_save.assert_called() - saved_data = mock_store.async_save.call_args[0][0] - assert "test_timer" not in saved_data - - # Timer should not be running (it was expired, not resumed) - assert not timer.is_running - - -async def test_keymaster_timer_setup_resumes_active_timer(hass, mock_store): - """Test setup() resumes timer when persisted timer is still active.""" - timer = KeymasterTimer() - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - - future_end_time = (dt_util.utcnow() + timedelta(minutes=5)).isoformat() - mock_store.async_load = AsyncMock( - return_value={"test_timer": {"end_time": future_end_time, "duration": 600}} - ) - - async def mock_action(*args): - pass - - await timer.setup(hass, kmlock, mock_action, timer_id="test_timer", store=mock_store) - - # Timer should be running with the persisted end_time - assert timer.is_running - assert timer._duration == 600 - assert len(timer._unsub_events) == 1 - - -async def test_keymaster_timer_setup_no_persisted_timer(hass, mock_store): - """Test setup() does nothing when no persisted timer exists.""" - timer = KeymasterTimer() - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - - async def mock_action(*args): - pass - - await timer.setup(hass, kmlock, mock_action, timer_id="test_timer", store=mock_store) - - # Timer should be set up but not running - assert timer.is_setup - assert not timer.is_running - - -async def test_keymaster_timer_start_persists_to_store(hass, mock_store): - """Test start() persists end_time to the store.""" - timer = KeymasterTimer() - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - kmlock.autolock_min_day = 5 - - async def mock_action(*args): - pass - - await timer.setup(hass, kmlock, mock_action, timer_id="test_timer", store=mock_store) - - with patch("custom_components.keymaster.helpers.sun.is_up", return_value=True): - await timer.start() - - # Store should have been written with the timer data - mock_store.async_save.assert_called() - saved_data = mock_store.async_save.call_args[0][0] - assert "test_timer" in saved_data - assert "end_time" in saved_data["test_timer"] - assert saved_data["test_timer"]["duration"] == 300 - - -async def test_keymaster_timer_cancel_removes_from_store(hass, mock_store): - """Test cancel() removes the timer from the store.""" - timer = KeymasterTimer() - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - kmlock.autolock_min_day = 5 - - async def mock_action(*args): - pass - - await timer.setup(hass, kmlock, mock_action, timer_id="test_timer", store=mock_store) - - with patch("custom_components.keymaster.helpers.sun.is_up", return_value=True): - await timer.start() - - mock_store.async_save.reset_mock() - # Simulate store has the timer data - mock_store.async_load = AsyncMock( - return_value={"test_timer": {"end_time": timer._end_time.isoformat(), "duration": 300}} - ) - - await timer.cancel() - - assert not timer.is_running - mock_store.async_save.assert_called() - saved_data = mock_store.async_save.call_args[0][0] - assert "test_timer" not in saved_data - - def test_async_has_supported_provider_with_entity_id(hass): """Test async_has_supported_provider with entity_id parameter.""" with patch( @@ -699,225 +246,6 @@ def test_async_has_supported_provider_no_args(hass): assert result is False -async def test_keymaster_timer_setup_invalid_end_time_format(hass, mock_store): - """Test setup() handles corrupt end_time string in persisted data.""" - timer = KeymasterTimer() - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - - mock_store.async_load = AsyncMock( - return_value={"test_timer": {"end_time": "not-a-date", "duration": 300}} - ) - - action_called = False - - async def mock_action(*args): - nonlocal action_called - action_called = True - - await timer.setup(hass, kmlock, mock_action, timer_id="test_timer", store=mock_store) - - # Action should NOT have fired - assert action_called is False - # Timer should not be running - assert not timer.is_running - # Invalid entry should be removed from store - mock_store.async_save.assert_called() - saved_data = mock_store.async_save.call_args[0][0] - assert "test_timer" not in saved_data - - -async def test_keymaster_timer_setup_missing_end_time_key(hass, mock_store): - """Test setup() handles persisted data with missing end_time key.""" - timer = KeymasterTimer() - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - - # end_time key is missing entirely - mock_store.async_load = AsyncMock(return_value={"test_timer": {"duration": 300}}) - - async def mock_action(*args): - pass - - await timer.setup(hass, kmlock, mock_action, timer_id="test_timer", store=mock_store) - - assert not timer.is_running - # Invalid entry should be removed from store - mock_store.async_save.assert_called() - saved_data = mock_store.async_save.call_args[0][0] - assert "test_timer" not in saved_data - - -async def test_keymaster_timer_setup_null_end_time(hass, mock_store): - """Test setup() handles persisted data with None end_time.""" - timer = KeymasterTimer() - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - - mock_store.async_load = AsyncMock( - return_value={"test_timer": {"end_time": None, "duration": 300}} - ) - - async def mock_action(*args): - pass - - await timer.setup(hass, kmlock, mock_action, timer_id="test_timer", store=mock_store) - - assert not timer.is_running - mock_store.async_save.assert_called() - saved_data = mock_store.async_save.call_args[0][0] - assert "test_timer" not in saved_data - - -async def test_keymaster_timer_persist_skipped_without_store(hass): - """Test _persist_to_store is a no-op when store is not set.""" - timer = KeymasterTimer() - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - - async def mock_action(*args): - pass - - # Setup without a store (pass None) - timer.hass = hass - timer._kmlock = kmlock - timer._call_action = mock_action - timer._timer_id = "test_timer" - timer._store = None - timer._end_time = dt_util.utcnow() + timedelta(minutes=5) - - # Should not raise - await timer._persist_to_store() - - -async def test_keymaster_timer_remove_from_store_missing_key(hass, mock_store): - """Test _remove_from_store is a no-op when timer_id is not in the store.""" - timer = KeymasterTimer() - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - - # Store has data but NOT our timer_id - mock_store.async_load = AsyncMock( - return_value={"other_timer": {"end_time": "2026-01-01T00:00:00", "duration": 300}} - ) - - async def mock_action(*args): - pass - - await timer.setup(hass, kmlock, mock_action, timer_id="test_timer", store=mock_store) - - mock_store.async_save.reset_mock() - - # Manually call _remove_from_store - await timer._remove_from_store() - - # Should not have saved (no changes needed) - mock_store.async_save.assert_not_called() - - -async def test_keymaster_timer_setup_duration_missing_defaults_to_zero(hass, mock_store): - """Test setup() defaults duration to 0 when missing from persisted data.""" - timer = KeymasterTimer() - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - - future_end_time = (dt_util.utcnow() + timedelta(minutes=5)).isoformat() - mock_store.async_load = AsyncMock(return_value={"test_timer": {"end_time": future_end_time}}) - - async def mock_action(*args): - pass - - await timer.setup(hass, kmlock, mock_action, timer_id="test_timer", store=mock_store) - - assert timer.is_running - assert timer._duration == 0 - - -async def test_keymaster_timer_on_expired_callback(hass, mock_store): - """Test the _on_expired callback fires the action then cancels the timer.""" - timer = KeymasterTimer() - kmlock = KeymasterLock( - lock_name="test_lock", - lock_entity_id="lock.test_lock", - keymaster_config_entry_id="test_entry", - ) - kmlock.autolock_min_day = 5 - - action_called_with = None - - async def mock_action(now): - nonlocal action_called_with - action_called_with = now - - await timer.setup(hass, kmlock, mock_action, timer_id="test_timer", store=mock_store) - - with patch("custom_components.keymaster.helpers.sun.is_up", return_value=True): - await timer.start() - - assert len(timer._unsub_events) == 1 - - # Simulate store having the timer data for cancel's _remove_from_store - mock_store.async_load = AsyncMock( - return_value={"test_timer": {"end_time": timer._end_time.isoformat(), "duration": 300}} - ) - - # Grab the callback that was passed to async_call_later and invoke it directly - with patch("custom_components.keymaster.helpers.async_call_later") as mock_call_later: - # Re-start to capture the callback - await timer.start() - callback_fn = mock_call_later.call_args[1]["action"] - - # Fire the callback - now = dt_util.utcnow() - await callback_fn(now) - - # Action should have been called - assert action_called_with == now - # Timer should be cleaned up - assert not timer.is_running - assert timer._end_time is None - assert timer._duration is None - - -async def test_keymaster_timer_remove_from_store_no_store(hass): - """Test _remove_from_store is a no-op when store is None.""" - timer = KeymasterTimer() - timer._timer_id = "test_timer" - timer._store = None - - # Should not raise - await timer._remove_from_store() - - -async def test_keymaster_timer_remove_from_store_no_timer_id(hass, mock_store): - """Test _remove_from_store is a no-op when timer_id is None.""" - timer = KeymasterTimer() - timer._store = mock_store - timer._timer_id = None - - # Should not raise - await timer._remove_from_store() - mock_store.async_load.assert_not_called() - - def test_throttle_reset_existing_func_missing_key(): """Test reset() with existing func_name but non-existent key is a safe no-op.""" throttle = Throttle() diff --git a/tests/test_switch.py b/tests/test_switch.py index 94e69ea6..db113fb7 100644 --- a/tests/test_switch.py +++ b/tests/test_switch.py @@ -243,7 +243,13 @@ async def test_switch_autolock_starts_timer_when_lock_unlocked( assert entity._attr_is_on is True assert kmlock.autolock_enabled is True + # Switch must pass an explicit duration kwarg (computed via the + # coordinator) — the new AutolockTimer.start() requires it. kmlock.autolock_timer.start.assert_called_once() + call_kwargs = kmlock.autolock_timer.start.call_args.kwargs + assert "duration" in call_kwargs, f"start() must pass duration=, got {call_kwargs}" + assert isinstance(call_kwargs["duration"], int) + assert call_kwargs["duration"] > 0 async def test_switch_autolock_does_not_start_timer_when_lock_locked(