Merge pull request #345 from plugwise/test_bouwew

Implement energy device clock synchronization

Author: bouwew

CHANGELOG.md

@@ -1,5 +1,9 @@
 # Changelog
 
+## v0.47.0 - 2025-09-26
+
+- PR [345](https://github.com/plugwise/python-plugwise-usb/pull/345): New Feature: schedule clock synchronization every 3600 seconds
+
 ## v0.46.1 - 2025-09-25
 
 - PR [337](https://github.com/plugwise/python-plugwise-usb/pull/337): Improve node removal, remove and reset the node as executed by Source, and remove the cache-file.

plugwise_usb/nodes/circle.py

@@ -2,13 +2,14 @@
 
 from __future__ import annotations
 
-from asyncio import Task, create_task, gather
+from asyncio import CancelledError, Task, create_task, gather, sleep
 from collections.abc import Awaitable, Callable
 from dataclasses import replace
 from datetime import UTC, datetime, timedelta
 from functools import wraps
 import logging
 from math import ceil
+import random
 from typing import Any, Final, TypeVar, cast
 
 from ..api import (
@@ -74,7 +75,9 @@
 # Default firmware if not known
 DEFAULT_FIRMWARE: Final = datetime(2008, 8, 26, 15, 46, tzinfo=UTC)
 
-MAX_LOG_HOURS = DAY_IN_HOURS
+MAX_LOG_HOURS: Final = DAY_IN_HOURS
+
+CLOCK_SYNC_PERIOD: Final = 3600
 
 FuncT = TypeVar("FuncT", bound=Callable[..., Any])
 _LOGGER = logging.getLogger(__name__)
@@ -141,6 +144,8 @@ def __init__(
         """Initialize base class for Sleeping End Device."""
         super().__init__(mac, node_type, controller, loaded_callback)
 
+        # Clock
+        self._clock_synchronize_task: Task[None] | None = None
         # Relay
         self._relay_lock: RelayLock = RelayLock()
         self._relay_state: RelayState = RelayState()
@@ -852,47 +857,61 @@ async def _relay_update_lock(
                 )
                 await self.save_cache()
 
+    async def _clock_synchronize_scheduler(self) -> None:
+        """Background task: periodically synchronize the clock until cancelled."""
+        try:
+            while True:
+                await sleep(CLOCK_SYNC_PERIOD + (random.uniform(-5, 5)))
+                try:
+                    await self.clock_synchronize()
+                except Exception:
+                    _LOGGER.exception(
+                        "Clock synchronization failed for %s", self._mac_in_str
+                    )
+        except CancelledError:
+            _LOGGER.debug("Clock sync scheduler cancelled for %s", self._mac_in_str)
+            raise
+
     async def clock_synchronize(self) -> bool:
         """Synchronize clock. Returns true if successful."""
-        get_clock_request = CircleClockGetRequest(self._send, self._mac_in_bytes)
-        clock_response = await get_clock_request.send()
-        if clock_response is None or clock_response.timestamp is None:
+        request = CircleClockGetRequest(self._send, self._mac_in_bytes)
+        response = await request.send()
+        if response is None or response.timestamp is None:
             return False
-        _dt_of_circle = datetime.now(tz=UTC).replace(
-            hour=clock_response.time.hour.value,
-            minute=clock_response.time.minute.value,
-            second=clock_response.time.second.value,
+
+        dt_now = datetime.now(tz=UTC)
+        days_diff = (response.day_of_week.value - dt_now.weekday()) % 7
+        circle_timestamp: datetime = dt_now.replace(
+            day=dt_now.day + days_diff,
+            hour=response.time.value.hour,
+            minute=response.time.value.minute,
+            second=response.time.value.second,
             microsecond=0,
             tzinfo=UTC,
         )
-        clock_offset = clock_response.timestamp.replace(microsecond=0) - _dt_of_circle
-        if (clock_offset.seconds < MAX_TIME_DRIFT) or (
-            clock_offset.seconds > -(MAX_TIME_DRIFT)
-        ):
+        clock_offset = response.timestamp.replace(microsecond=0) - circle_timestamp
+        if abs(clock_offset.total_seconds()) < MAX_TIME_DRIFT:
             return True
+
         _LOGGER.info(
-            "Reset clock of node %s because time has drifted %s sec",
+            "Sync clock of node %s because time drifted %s seconds",
             self._mac_in_str,
-            str(clock_offset.seconds),
+            int(abs(clock_offset.total_seconds())),
         )
         if self._node_protocols is None:
             raise NodeError(
-                "Unable to synchronize clock en when protocol version is unknown"
+                "Unable to synchronize clock when protocol version is unknown"
             )
-        set_clock_request = CircleClockSetRequest(
+
+        set_request = CircleClockSetRequest(
             self._send,
             self._mac_in_bytes,
             datetime.now(tz=UTC),
             self._node_protocols.max,
         )
-        if (node_response := await set_clock_request.send()) is None:
-            _LOGGER.warning(
-                "Failed to (re)set the internal clock of %s",
-                self.name,
-            )
-            return False
-        if node_response.ack_id == NodeResponseType.CLOCK_ACCEPTED:
-            return True
+        if (node_response := await set_request.send()) is not None:
+            return node_response.ack_id == NodeResponseType.CLOCK_ACCEPTED
+        _LOGGER.warning("Failed to sync the clock of %s", self.name)
         return False
 
     async def load(self) -> None:
@@ -1016,6 +1035,10 @@ async def initialize(self) -> bool:
                 return False
 
         await super().initialize()
+        if self._clock_synchronize_task is None or self._clock_synchronize_task.done():
+            self._clock_synchronize_task = create_task(
+                self._clock_synchronize_scheduler()
+            )
         return True
 
     async def node_info_update(
@@ -1082,6 +1105,11 @@ async def unload(self) -> None:
         if self._cache_enabled:
             await self._energy_log_records_save_to_cache()
 
+        if self._clock_synchronize_task:
+            self._clock_synchronize_task.cancel()
+            await gather(self._clock_synchronize_task, return_exceptions=True)
+            self._clock_synchronize_task = None
+
         await super().unload()
 
     @raise_not_loaded
@@ -1318,7 +1346,7 @@ async def energy_reset_request(self) -> None:
                 f"Unexpected NodeResponseType {response.ack_id!r} received as response to CircleClockSetRequest"
             )
 
-        _LOGGER.warning("Energy reset for Node %s successful", self._mac_in_str)
+        _LOGGER.info("Energy reset for Node %s successful", self._mac_in_str)
 
         # Follow up by an energy-intervals (re)set
         interval_request = CircleMeasureIntervalRequest(
@@ -1337,20 +1365,20 @@ async def energy_reset_request(self) -> None:
             raise MessageError(
                 f"Unknown NodeResponseType '{interval_response.response_type.name}' received"
             )
-        _LOGGER.warning("Resetting energy intervals to default (= consumption only)")
+        _LOGGER.info("Resetting energy intervals to default (= consumption only)")
 
         # Clear the cached energy_collection
         if self._cache_enabled:
             self._set_cache(CACHE_ENERGY_COLLECTION, "")
-            _LOGGER.warning(
+            _LOGGER.info(
                 "Energy-collection cache cleared successfully, updating cache for %s",
                 self._mac_in_str,
             )
             await self.save_cache()
 
         # Clear PulseCollection._logs
         self._energy_counters.reset_pulse_collection()
-        _LOGGER.warning("Resetting pulse-collection")
+        _LOGGER.info("Resetting pulse-collection")
 
         # Request a NodeInfo update
         if await self.node_info_update() is None:
@@ -1359,7 +1387,7 @@ async def energy_reset_request(self) -> None:
                 self._mac_in_str,
             )
         else:
-            _LOGGER.warning(
+            _LOGGER.info(
                 "Node info update after energy-reset successful for %s",
                 self._mac_in_str,
             )

plugwise_usb/nodes/circle_plus.py

@@ -67,44 +67,61 @@ async def load(self) -> bool:
 
     async def clock_synchronize(self) -> bool:
         """Synchronize realtime clock. Returns true if successful."""
-        clock_request = CirclePlusRealTimeClockGetRequest(
-            self._send, self._mac_in_bytes
-        )
-        if (clock_response := await clock_request.send()) is None:
-            _LOGGER.debug(
-                "No response for async_realtime_clock_synchronize() for %s", self.mac
+        request = CirclePlusRealTimeClockGetRequest(self._send, self._mac_in_bytes)
+        if (response := await request.send()) is None:
+            _LOGGER.warning(
+                "No response for clock_synchronize() for %s", self._mac_in_str
             )
             await self._available_update_state(False)
             return False
-        await self._available_update_state(True, clock_response.timestamp)
+        await self._available_update_state(True, response.timestamp)
+
+        dt_now = datetime.now(tz=UTC)
+        dt_now_date = dt_now.replace(hour=0, minute=0, second=0, microsecond=0)
+        response_date = datetime(
+            response.date.value.year,
+            response.date.value.month,
+            response.date.value.day,
+            hour=0,
+            minute=0,
+            second=0,
+            microsecond=0,
+            tzinfo=UTC,
+        )
+        if dt_now_date != response_date:
+            _LOGGER.info(
+                "Sync clock of node %s because time has drifted %s days",
+                self._mac_in_str,
+                int(abs((dt_now_date - response_date).days)),
+            )
+            return await self._send_clock_set_req()
 
-        _dt_of_circle: datetime = datetime.now(tz=UTC).replace(
-            hour=clock_response.time.value.hour,
-            minute=clock_response.time.value.minute,
-            second=clock_response.time.value.second,
+        circle_plus_timestamp: datetime = dt_now.replace(
+            hour=response.time.value.hour,
+            minute=response.time.value.minute,
+            second=response.time.value.second,
             microsecond=0,
             tzinfo=UTC,
         )
-        clock_offset = clock_response.timestamp.replace(microsecond=0) - _dt_of_circle
-        if (clock_offset.seconds < MAX_TIME_DRIFT) or (
-            clock_offset.seconds > -(MAX_TIME_DRIFT)
-        ):
+        clock_offset = response.timestamp.replace(microsecond=0) - circle_plus_timestamp
+        if abs(clock_offset.total_seconds()) < MAX_TIME_DRIFT:
             return True
+
         _LOGGER.info(
-            "Reset realtime clock of node %s because time has drifted %s seconds while max drift is set to %s seconds)",
-            self._node_info.mac,
-            str(clock_offset.seconds),
-            str(MAX_TIME_DRIFT),
+            "Sync clock of node %s because time drifted %s seconds",
+            self._mac_in_str,
+            int(abs(clock_offset.total_seconds())),
         )
-        clock_set_request = CirclePlusRealTimeClockSetRequest(
+        return await self._send_clock_set_req()
+
+    async def _send_clock_set_req(self) -> bool:
+        """Send CirclePlusRealTimeClockSetRequest."""
+        set_request = CirclePlusRealTimeClockSetRequest(
             self._send, self._mac_in_bytes, datetime.now(tz=UTC)
         )
-        if (node_response := await clock_set_request.send()) is not None:
+        if (node_response := await set_request.send()) is not None:
             return node_response.ack_id == NodeResponseType.CLOCK_ACCEPTED
-        _LOGGER.warning(
-            "Failed to (re)set the internal realtime clock of %s",
-            self.name,
-        )
+        _LOGGER.warning("Failed to sync the clock of %s", self.name)
         return False
 
     @raise_not_loaded

pyproject.toml

@@ -4,7 +4,7 @@ build-backend = "setuptools.build_meta"
 
 [project]
 name            = "plugwise_usb"
-version         = "0.46.1"
+version         = "0.47.0"
 license         = "MIT"
 keywords        = ["home", "automation", "plugwise", "module", "usb"]
 classifiers     = [
@@ -540,3 +540,7 @@ testpaths = [
 ]
 asyncio_default_fixture_loop_scope = "session"
 asyncio_mode = "strict"
+# log_cli = true
+# log_cli_level = "DEBUG"
+# log_format = "%(asctime)s %(levelname)s %(message)s"
+# log_date_format = "%Y-%m-%d %H:%M:%S"