From 657cc9369183777c337cfeb37702107b807615a6 Mon Sep 17 00:00:00 2001 From: Jean-Pierre Martineau Date: Tue, 15 Sep 2026 21:11:35 -0400 Subject: [PATCH] The companion's clock is set from this computer when it connects, if a preference asks MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A new "Set clock on connect" preference (Device group, off by default) has the interactive session write the host time to the radio once per connection — at launch, on a deferred connect, and after a reconnect, since a link drop is exactly when a board without a real-time clock may have rebooted and lost the time. The set runs in a background task off the connect path and reports only in the log, with the drift it corrected; a refused write costs a warning line, never the session. Scripted CLI runs never start the service, so a one-shot command that only reads the radio never writes its clock. The device-side step is the one the Device config screen's Sync clock action already ran inline in apply_ops; it is lifted into services/clock_sync.set_clock and the action and the service both call it. Co-Authored-By: Claude Fable 5.1 --- meshterm/context.py | 41 ++++++-- meshterm/core/preferences.py | 21 +++- meshterm/services/clock_sync.py | 170 ++++++++++++++++++++++++++++++++ meshterm/tools/config.py | 25 ++--- meshterm/ui/menu.py | 5 + tests/test_clock_sync.py | 160 ++++++++++++++++++++++++++++++ 6 files changed, 394 insertions(+), 28 deletions(-) create mode 100644 meshterm/services/clock_sync.py create mode 100644 tests/test_clock_sync.py diff --git a/meshterm/context.py b/meshterm/context.py index ad3704b..a5e052b 100644 --- a/meshterm/context.py +++ b/meshterm/context.py @@ -38,6 +38,7 @@ if TYPE_CHECKING: from .services.basemap import BasemapSource from .services.battery_service import BatteryService from .services.chat_service import ChatService + from .services.clock_sync import ClockSync from .services.courier import CourierService from .services.device_state import DeviceState from .services.event_hub import EventHub @@ -155,6 +156,7 @@ class AppContext: _chat: ChatService | None = field(default=None, init=False, repr=False) _adverts: AdvertScheduler | None = field(default=None, init=False, repr=False) _watchtower: WatchtowerService | None = field(default=None, init=False, repr=False) + _clock_sync: ClockSync | None = field(default=None, init=False, repr=False) _courier: CourierService | None = field(default=None, init=False, repr=False) _battery: BatteryService | None = field(default=None, init=False, repr=False) _devstate: DeviceState | None = field(default=None, init=False, repr=False) @@ -358,6 +360,21 @@ class AppContext: self._watchtower = WatchtowerService(self) return self._watchtower + @property + def clock_sync(self) -> ClockSync: + """Return the session's on-connect clock setter, creating it on first use. + + Created idle here; the interactive session starts it alongside the other + always-on services, and :meth:`device` tells it about each connection as it + settles. Scripted CLI runs never start it, so a one-shot command that only reads + the radio never writes its clock. + """ + if self._clock_sync is None: + from .services.clock_sync import ClockSync + + self._clock_sync = ClockSync(self) + return self._clock_sync + @property def courier(self) -> CourierService: """Return the session's store-and-forward courier, creating it on first use. @@ -515,8 +532,7 @@ class AppContext: self._active_port = None self._active_address = None await self._open(f"TCP companion {tcp_host}:{tcp_port}") - await self._remember_connected() - await self._reconcile_channels() + await self._settle_connection() return self._device # A Bluetooth endpoint (an explicit ``--ble``, a BLE profile, a device picked at @@ -549,8 +565,7 @@ class AppContext: self._active_port = None self._active_endpoint = None await self._open(f"BLE companion {ble_address}") - await self._remember_connected() - await self._reconcile_channels() + await self._settle_connection() return self._device resolution = resolve_device( @@ -568,8 +583,7 @@ class AppContext: self._active_address = None self._active_endpoint = None await self._open(f"serial port {resolution.port}") - await self._remember_connected() - await self._reconcile_channels() + await self._settle_connection() return self._device def _resolve_tcp_endpoint(self) -> tuple[str | None, int | None]: @@ -656,6 +670,19 @@ class AppContext: hardware_model=await self._hardware_model(), ) + async def _settle_connection(self) -> None: + """The steps every fresh connection gets once the link is open, in order. + + Remember the device as the default, replay its remembered channels, and hand it to + the on-connect clock setter — which returns at once and does its work in the + background, so the connection is usable the moment this returns. Each step is + best-effort on its own; none can fail the connection. + """ + await self._remember_connected() + await self._reconcile_channels() + if self._device is not None: + self.clock_sync.on_connected(self._device) + async def _reconcile_channels(self) -> None: """Replay channels remembered for this device that it isn't reporting (best-effort). @@ -792,6 +819,8 @@ class AppContext: await self._battery.aclose() if self._watchtower is not None: await self._watchtower.aclose() + if self._clock_sync is not None: + await self._clock_sync.aclose() if self._adverts is not None: await self._adverts.aclose() if self._monitor is not None: diff --git a/meshterm/core/preferences.py b/meshterm/core/preferences.py index 68dabec..90cec16 100644 --- a/meshterm/core/preferences.py +++ b/meshterm/core/preferences.py @@ -57,11 +57,12 @@ else: # pragma: no cover - exercised only on 3.10 import tomli as tomllib #: Display groups, in the order the page and the file present them. The order is the -#: order a session happens in — what MeshTerm puts on the air, how loud, what it watches -#: for, how it draws the world, what it keeps, and how it paints. Nothing sorts -#: alphabetically: a reader looking for "how long before I give up on a message" should -#: not have to know it starts with a D. +#: order a session happens in — what MeshTerm does to the radio as the link opens, what +#: it puts on the air, how loud, what it watches for, how it draws the world, what it +#: keeps, and how it paints. Nothing sorts alphabetically: a reader looking for "how long +#: before I give up on a message" should not have to know it starts with a D. GROUPS: tuple[str, ...] = ( + "Device", "Sending", "TX optimize", "Watchtower", @@ -205,6 +206,18 @@ _LOG_LEVEL_CHOICES: dict[str, str] = { #: code-level behaviour is named, never re-typed: one source, so changing it cannot leave #: the constant and the registry disagreeing about what MeshTerm does. PREFERENCES: tuple[PrefSpec, ...] = ( + # --- Device ------------------------------------------------------------------ + PrefSpec( + key="set_clock_on_connect", + label="Set clock on connect", + help="Set the device clock from this computer when it connects", + group="Device", + value_type="bool", + # Off: writing to a radio nobody asked to be written to is the owner's call. The + # set is silent (the log records it) and happens once per connection — see + # :mod:`meshterm.services.clock_sync`. + default=False, + ), # --- Sending ----------------------------------------------------------------- PrefSpec( key="trace_cooldown_s", diff --git a/meshterm/services/clock_sync.py b/meshterm/services/clock_sync.py new file mode 100644 index 0000000..ca1e1c7 --- /dev/null +++ b/meshterm/services/clock_sync.py @@ -0,0 +1,170 @@ +# SPDX-License-Identifier: Apache-2.0 +"""Set the companion's clock from this computer — by hand from Device config, or on connect. + +Most MeshCore boards carry no real-time clock: a power cycle puts them back at whatever +epoch the firmware boots with, and every message they then send is stamped in a year the +mesh does not agree on. :func:`set_clock` is the one device-side step that corrects it — +read what the radio thinks the time is, write ours, and hand back the drift that was +corrected, the fact worth keeping and the one the set destroys by succeeding. The Device +config screen's *Sync clock* action (``config sync-clock`` on the command line) calls it +and acknowledges on screen; :class:`ClockSync` calls the same function on its own, once +per connection, when the ``set_clock_on_connect`` preference asks for it (off by default — +writing to a radio that nobody asked to be written to is a choice the owner makes). + +The automatic set is a background step, not a startup step: the connect path hands the +device over and carries on, and the write happens in a task of its own so a slow or silent +firmware never holds the menu. It reports in the **log**, never on screen. + +Once per *connection*, keyed by the device object's identity like the advert scheduler's +key probe: a reconnect after a link drop is a fresh :class:`~meshterm.core.connection.Device` +and gets its own set, because a drop is exactly when the board may have rebooted and lost +its clock again. The interactive session starts the service; scripted CLI runs never do, +so a one-shot command cannot change a radio it was only asked to read. +""" + +from __future__ import annotations + +import asyncio +import time +from dataclasses import dataclass +from datetime import datetime +from typing import TYPE_CHECKING + +if TYPE_CHECKING: + from ..context import AppContext + from ..core.connection import Device + + +@dataclass(frozen=True, slots=True) +class ClockSet: + """What one clock set did. + + Attributes: + epoch: The UNIX time written to the device. + drift_s: How far the device's clock was from ours *before* the set (device minus + host, seconds), or ``None`` where the firmware would not report its clock. + """ + + epoch: int + drift_s: int | None + + @property + def set_at(self) -> datetime: + """The written instant, in this computer's local time.""" + return datetime.fromtimestamp(self.epoch).astimezone() + + @property + def stamp(self) -> str: + """The written instant as the acknowledgement and the log print it.""" + return self.set_at.strftime("%Y-%m-%d %H:%M:%S") + + +async def set_clock(device: Device) -> ClockSet: + """Set ``device``'s clock to this computer's, returning what was corrected. + + The read of the device's own clock before the write is optional — the drift is a + nicety, and a firmware that will not answer still gets its clock set. + + Args: + device: A connected device. + + Returns: + The instant written and the drift it corrected. + + Raises: + Whatever the device raises when the write itself fails. + """ + try: + before = await device.get_time() + except Exception: # noqa: BLE001 - optional read; the drift is a nicety + before = None + epoch = int(time.time()) + await device.set_time(epoch) + return ClockSet(epoch=epoch, drift_s=None if before is None else before - epoch) + + +class ClockSync: + """Owns the on-connect clock set for an interactive session. + + Interact through :meth:`start`, :meth:`stop`/:meth:`aclose`, and + :meth:`on_connected`, which the context calls as each connection settles. + """ + + def __init__(self, ctx: AppContext) -> None: + """Initialize an idle service bound to an application context. + + Args: + ctx: The shared application context, read for the preference at each + connection and for the logger. Nothing is touched until :meth:`start`. + """ + self._ctx = ctx + self._armed = False + self._task: asyncio.Task | None = None + # Identity of the device object last set, so one connection is set once even if + # the connect path reports it more than once. + self._synced: int | None = None + + @property + def active(self) -> bool: + """Whether the service is armed to act on connections.""" + return self._armed + + async def start(self) -> None: + """Arm the service, setting the clock at once if a device is already connected. + + Idempotent. The startup picker may have adopted a live connection before any + service started, so the connection that already exists counts as the first one. + """ + if self._armed: + return + self._armed = True + device = self._ctx._device + if device is not None: + self.on_connected(device) + + async def stop(self) -> None: + """Disarm, cancelling a set still in flight. Idempotent.""" + self._armed = False + task, self._task = self._task, None + if task is not None and not task.done(): + task.cancel() + try: + await task + except asyncio.CancelledError: + pass + + async def aclose(self) -> None: + """Stop at session end (an alias for :meth:`stop`).""" + await self.stop() + + def on_connected(self, device: Device) -> None: + """Note a settled connection and, if the preference asks, set its clock in the background. + + Returns at once; the set runs in its own task. A no-op while the service is not + started (scripted runs), while the preference is off, and for a device this + session has already set. + + Args: + device: The device the context just finished connecting. + """ + if not self._armed or not self._ctx.preferences.set_clock_on_connect: + return + if self._synced == id(device): + return + self._synced = id(device) + self._task = asyncio.ensure_future(self._sync(device)) + + async def _sync(self, device: Device) -> None: + """Run :func:`set_clock` and put the outcome in the log.""" + log = self._ctx.log + try: + done = await set_clock(device) + except asyncio.CancelledError: + raise + except Exception as exc: # noqa: BLE001 - best-effort; the link is not ours to break + log.warning("clock sync: could not set the device clock: %s", exc) + return + if done.drift_s is None: + log.info("clock sync: device clock set to %s (drift unknown)", done.stamp) + else: + log.info("clock sync: device clock set to %s (was %+d s off)", done.stamp, done.drift_s) diff --git a/meshterm/tools/config.py b/meshterm/tools/config.py index 9455803..0f45a49 100644 --- a/meshterm/tools/config.py +++ b/meshterm/tools/config.py @@ -29,6 +29,7 @@ from ..core.device_config import ( parse_value, settings_by_category, ) +from ..services.clock_sync import set_clock from .base import Tool, ToolResult, register if TYPE_CHECKING: # pragma: no cover - typing only @@ -306,23 +307,19 @@ async def apply_ops( elif kind == "share": report.append(await _share_contact(ctx, snapshot)) elif kind == "sync_clock": - import time as _time - from datetime import datetime - - epoch = int(_time.time()) - drift = await _try_clock(device) - await device.set_time(epoch) - stamp = datetime.fromtimestamp(epoch).astimezone().strftime("%Y-%m-%d %H:%M:%S") - ctx.ui.ack(f"[ok]✓[/ok] device clock set to [brand]{stamp}[/brand]") + # The same step the on-connect service runs in the background + # (:mod:`meshterm.services.clock_sync`); here it is acknowledged and reported. + done = await set_clock(device) + ctx.ui.ack(f"[ok]✓[/ok] device clock set to [brand]{done.stamp}[/brand]") changes += 1 report.append( _acted( "clock", changes=1, - set_at=datetime.fromtimestamp(epoch).astimezone(), + set_at=done.set_at, # What the clock was off by *before* the set: the fact worth logging, # and the one this command destroys by succeeding. - drift_s=None if drift is None else drift - epoch, + drift_s=done.drift_s, ) ) elif kind == "reboot": @@ -802,11 +799,3 @@ def _acted(key: str, **facts: Any) -> Facts: values=dict(facts), shape=SILENT, ) - - -async def _try_clock(device: Device) -> int | None: - """The device's current clock, or ``None`` where the firmware will not answer.""" - try: - return await device.get_time() - except Exception: # noqa: BLE001 - optional read; the drift is a nicety - return None diff --git a/meshterm/ui/menu.py b/meshterm/ui/menu.py index a0574df..b5c13de 100644 --- a/meshterm/ui/menu.py +++ b/meshterm/ui/menu.py @@ -399,6 +399,7 @@ async def run_menu(ctx: AppContext) -> None: # Stop history + chat recording (closing their run records), the background # advert scheduler, and the always-on event hub, even on an unexpected exit. await ctx.adverts.aclose() + await ctx.clock_sync.aclose() await ctx.monitor.aclose() await ctx.chat.aclose() await ctx.events.aclose() @@ -821,6 +822,10 @@ async def _resume_monitor(ctx: AppContext) -> None: await ctx.adverts.start() # The Watchtower only listens (rules over hub events), so it too is safe from launch. await ctx.watchtower.start() + # The clock setter acts only when a connection settles (and at once on one the startup + # picker already adopted), only when its preference is on, and only in the background; + # it never opens the radio and never touches the screen — it reports in the log. + await ctx.clock_sync.start() # The courier drains the outbox on its own paced schedule; each pass checks for a # connected device and skips quietly without one, exactly like the advert scheduler. await ctx.courier.start() diff --git a/tests/test_clock_sync.py b/tests/test_clock_sync.py new file mode 100644 index 0000000..b40fff9 --- /dev/null +++ b/tests/test_clock_sync.py @@ -0,0 +1,160 @@ +# SPDX-License-Identifier: Apache-2.0 +"""Tests for the clock set: the shared device step, and the on-connect service around it. + +One function sets the device clock for both the Device config action and the automatic +service; the service is off by default, acts once per connection in the background, and +says what it did in the log rather than on screen. +""" + +from __future__ import annotations + +import asyncio +import io +import logging +import time +from pathlib import Path + +import pytest +from rich.console import Console + +from meshterm.context import AppContext +from meshterm.core.admin_store import AdminStore +from meshterm.core.config import Settings +from meshterm.core.device_store import DeviceStore +from meshterm.core.preferences import get_spec +from meshterm.persistence.repository import Repository +from meshterm.services.clock_sync import ClockSync, set_clock + + +@pytest.fixture() +def ctx(tmp_path: Path) -> AppContext: + """A mock-backed application context, preferences at their defaults.""" + settings = Settings(config_dir=tmp_path, db_path=tmp_path / "clock.db") + context = AppContext( + console=Console(file=io.StringIO()), + settings=settings, + repo=Repository(settings.db_path), + device_store=DeviceStore(tmp_path / "devices.json"), + admin_store=AdminStore(tmp_path / "admin.json"), + mock=True, + ) + yield context + context.repo.close() + + +@pytest.fixture() +def log_lines() -> list[str]: + """Every record the app logger emits during the test (it does not propagate to root).""" + lines: list[str] = [] + + class _Collect(logging.Handler): + def emit(self, record: logging.LogRecord) -> None: + lines.append(record.getMessage()) + + handler = _Collect(level=logging.DEBUG) + logger = logging.getLogger("meshterm") + previous = logger.level + logger.setLevel(logging.DEBUG) + logger.addHandler(handler) + yield lines + logger.removeHandler(handler) + logger.setLevel(previous) + + +async def _settle() -> None: + """Let a task spawned by the service run to completion.""" + for _ in range(5): + await asyncio.sleep(0) + + +def test_the_preference_exists_and_is_off_by_default() -> None: + """Writing to a radio nobody asked to be written to is the owner's call.""" + spec = get_spec("set_clock_on_connect") + assert spec.value_type == "bool" + assert spec.default is False + assert spec.group == "Device" + + +async def test_set_clock_writes_the_host_time_and_reports_the_drift(ctx: AppContext) -> None: + """The shared step corrects a clock an hour slow and says by how much.""" + device = await ctx.device() + await device.set_time(int(time.time()) - 3600) + + done = await set_clock(device) + + assert abs(done.epoch - int(time.time())) <= 2 + assert done.drift_s is not None and -3602 <= done.drift_s <= -3598 + assert abs(await device.get_time() - int(time.time())) <= 2 + + +async def test_the_service_does_nothing_while_the_preference_is_off( + ctx: AppContext, log_lines: list[str] +) -> None: + """Off by default: a connection is noted and the clock is left alone.""" + device = await ctx.device() + await device.set_time(int(time.time()) - 3600) + service = ClockSync(ctx) + await service.start() + + service.on_connected(device) + await _settle() + + assert abs(await device.get_time() - (int(time.time()) - 3600)) <= 2 + assert not any("clock sync" in line for line in log_lines) + + +async def test_the_service_sets_the_clock_once_per_connection_and_logs_it( + ctx: AppContext, log_lines: list[str] +) -> None: + """On: the first settled connection is set in the background; the same one is not set twice.""" + ctx.preferences.set("set_clock_on_connect", True) + device = await ctx.device() + await device.set_time(int(time.time()) - 3600) + service = ClockSync(ctx) + await service.start() # a device is already connected: that counts as the first one + + await _settle() + assert abs(await device.get_time() - int(time.time())) <= 2 + said = [line for line in log_lines if line.startswith("clock sync: device clock set to")] + assert len(said) == 1 + assert "-36" in said[0] # "(was -3600 s off)", give or take the seconds the test took + + await device.set_time(int(time.time()) - 3600) + service.on_connected(device) + await _settle() + assert abs(await device.get_time() - (int(time.time()) - 3600)) <= 2 # untouched + assert len([line for line in log_lines if "device clock set to" in line]) == 1 + await service.aclose() + + +async def test_a_service_never_started_ignores_connections( + ctx: AppContext, log_lines: list[str] +) -> None: + """A scripted run never starts the service, so its connections never write the clock.""" + ctx.preferences.set("set_clock_on_connect", True) + device = await ctx.device() + await device.set_time(int(time.time()) - 3600) + + ctx.clock_sync.on_connected(device) # what the connect path does + await _settle() + + assert abs(await device.get_time() - (int(time.time()) - 3600)) <= 2 + assert not any("clock sync" in line for line in log_lines) + + +async def test_a_write_that_fails_is_logged_not_raised( + ctx: AppContext, log_lines: list[str] +) -> None: + """A firmware that refuses the write costs a warning line, never the session.""" + ctx.preferences.set("set_clock_on_connect", True) + device = await ctx.device() + + async def _refuse(epoch: int) -> None: + raise RuntimeError("no clock here") + + device.set_time = _refuse # type: ignore[method-assign] + service = ClockSync(ctx) + await service.start() + await _settle() + + assert any("could not set the device clock: no clock here" in line for line in log_lines)