diff --git a/.gitignore b/.gitignore index 8dad5e02e..6cf4137e2 100644 --- a/.gitignore +++ b/.gitignore @@ -9,6 +9,7 @@ __pycache__ .idea tests/__pycache__ .coverage +.python-version .vscode venv .venv diff --git a/CHANGELOG.md b/CHANGELOG.md index f56938429..02d1f74c5 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,7 +1,8 @@ # Changelog -## Ongoing +## v0.44.4 +- PR [#255](https://github.com/plugwise/python-plugwise-usb/pull/255): Improve enery-logs reset process, enable use of a button in Plugwise_usb beta - PR [#261](https://github.com/plugwise/python-plugwise-usb/pull/261): Sense: bugfix parsing of humidity value as an unsigned int - PR #263 Maintenance chores and re-instatement of ruff, deprecate pre-commit cloud runs (just leveraging renovate) - PR #264 Maintenance chores Rework Github Actions workflow diff --git a/plugwise_usb/__init__.py b/plugwise_usb/__init__.py index 2061ca32c..e3cc2c6b3 100644 --- a/plugwise_usb/__init__.py +++ b/plugwise_usb/__init__.py @@ -14,7 +14,6 @@ from .api import NodeEvent, PlugwiseNode, StickEvent from .connection import StickController -from .constants import DEFAULT_CONS_INTERVAL, NO_PRODUCTION_INTERVAL from .exceptions import MessageError, NodeError, StickError, SubscriptionError from .network import StickNetwork @@ -177,22 +176,6 @@ def port(self, port: str) -> None: self._port = port - async def energy_reset_request(self, mac: str) -> bool: - """Send an energy-reset request to a Node.""" - _LOGGER.debug("Resetting energy logs for %s", mac) - try: - await self._network.energy_reset_request(mac) - except (MessageError, NodeError) as exc: - raise NodeError(f"{exc}") from exc - - # Follow up by an energy-intervals (re)set - if result := await self.set_energy_intervals( - mac, DEFAULT_CONS_INTERVAL, NO_PRODUCTION_INTERVAL - ): - return result - - return False - async def set_energy_intervals( self, mac: str, cons_interval: int, prod_interval: int ) -> bool: diff --git a/plugwise_usb/api.py b/plugwise_usb/api.py index 4f1140f4e..528617978 100644 --- a/plugwise_usb/api.py +++ b/plugwise_usb/api.py @@ -41,6 +41,7 @@ class NodeFeature(str, Enum): AVAILABLE = "available" BATTERY = "battery" + CIRCLE = "circle" CIRCLEPLUS = "circleplus" ENERGY = "energy" HUMIDITY = "humidity" @@ -78,13 +79,14 @@ class NodeType(Enum): PUSHING_FEATURES = ( NodeFeature.AVAILABLE, NodeFeature.BATTERY, + NodeFeature.CIRCLE, + NodeFeature.CIRCLEPLUS, NodeFeature.HUMIDITY, NodeFeature.MOTION, NodeFeature.MOTION_CONFIG, NodeFeature.TEMPERATURE, NodeFeature.SENSE, NodeFeature.SWITCH, - NodeFeature.CIRCLEPLUS, ) diff --git a/plugwise_usb/network/__init__.py b/plugwise_usb/network/__init__.py index 8006dfa40..e9262803d 100644 --- a/plugwise_usb/network/__init__.py +++ b/plugwise_usb/network/__init__.py @@ -6,7 +6,7 @@ from asyncio import Task, create_task, gather, sleep from collections.abc import Callable, Coroutine -from datetime import UTC, datetime, timedelta +from datetime import datetime, timedelta import logging from typing import Any @@ -15,11 +15,7 @@ from ..constants import ENERGY_NODE_TYPES, UTF8 from ..exceptions import CacheError, MessageError, NodeError, StickError, StickTimeout from ..helpers.util import validate_mac -from ..messages.requests import ( - CircleClockSetRequest, - CircleMeasureIntervalRequest, - NodePingRequest, -) +from ..messages.requests import CircleMeasureIntervalRequest, NodePingRequest from ..messages.responses import ( NODE_AWAKE_RESPONSE_ID, NODE_JOIN_ID, @@ -524,25 +520,6 @@ async def stop(self) -> None: # endregion - async def energy_reset_request(self, mac: str) -> None: - """Send an energy-reset to a Node.""" - self._validate_energy_node(mac) - node_protocols = self._nodes[mac].node_protocols - request = CircleClockSetRequest( - self._controller.send, - bytes(mac, UTF8), - datetime.now(tz=UTC), - node_protocols.max, - True, - ) - if (response := await request.send()) is None: - raise NodeError(f"Energy-reset for {mac} failed") - - if response.ack_id != NodeResponseType.CLOCK_ACCEPTED: - raise MessageError( - f"Unexpected NodeResponseType {response.ack_id!r} received as response to CircleClockSetRequest" - ) - async def set_energy_intervals( self, mac: str, consumption: int, production: int ) -> None: diff --git a/plugwise_usb/nodes/circle.py b/plugwise_usb/nodes/circle.py index be90c9d0f..4e9976137 100644 --- a/plugwise_usb/nodes/circle.py +++ b/plugwise_usb/nodes/circle.py @@ -23,16 +23,19 @@ ) from ..connection import StickController from ..constants import ( + DEFAULT_CONS_INTERVAL, MAX_TIME_DRIFT, MINIMAL_POWER_UPDATE, + NO_PRODUCTION_INTERVAL, PULSES_PER_KW_SECOND, SECOND_IN_NANOSECONDS, ) -from ..exceptions import FeatureError, NodeError +from ..exceptions import FeatureError, MessageError, NodeError from ..messages.requests import ( CircleClockGetRequest, CircleClockSetRequest, CircleEnergyLogsRequest, + CircleMeasureIntervalRequest, CirclePowerUsageRequest, CircleRelayInitStateRequest, CircleRelaySwitchRequest, @@ -46,7 +49,6 @@ from .helpers.pulses import PulseLogRecord, calc_log_address from .node import PlugwiseBaseNode -CACHE_CURRENT_LOG_ADDRESS = "current_log_address" CACHE_CALIBRATION_GAIN_A = "calibration_gain_a" CACHE_CALIBRATION_GAIN_B = "calibration_gain_b" CACHE_CALIBRATION_NOISE = "calibration_noise" @@ -98,6 +100,7 @@ def __init__( self._energy_counters = EnergyCounters(mac) self._retrieve_energy_logs_task: None | Task[None] = None self._last_energy_log_requested: bool = False + self._last_collected_energy_timestamp: datetime | None = None self._group_member: list[int] = [] @@ -233,6 +236,7 @@ async def _calibration_load_from_cache(self) -> bool: cal_gain_b, cal_noise, cal_tot, + load_from_cache=True, ) if result: _LOGGER.debug( @@ -251,6 +255,7 @@ async def _calibration_update_state( gain_b: float | None, off_noise: float | None, off_tot: float | None, + load_from_cache: bool = False, ) -> bool: """Process new energy calibration settings. Returns True if successful.""" if gain_a is None or gain_b is None or off_noise is None or off_tot is None: @@ -260,8 +265,7 @@ async def _calibration_update_state( ) # Forward calibration config to energy collection self._energy_counters.calibration = self._calibration - - if self._cache_enabled: + if self._cache_enabled and not load_from_cache: self._set_cache(CACHE_CALIBRATION_GAIN_A, gain_a) self._set_cache(CACHE_CALIBRATION_GAIN_B, gain_b) self._set_cache(CACHE_CALIBRATION_NOISE, off_noise) @@ -430,27 +434,78 @@ async def energy_update(self) -> EnergyStatistics | None: # noqa: PLR0911 PLR09 ) return None + async def _get_initial_energy_logs(self) -> None: + """Collect initial energy logs from the last 10 log addresses.""" + if self._current_log_address is None: + return + + _LOGGER.debug( + "Start collecting initial energy logs from the last 10 log addresses for node %s.", + self._mac_in_str, + ) + total_addresses = 11 + log_address = self._current_log_address + prev_address_timestamp: datetime | None = None + while total_addresses > 0: + if not await self.energy_log_update(log_address): + # Handle case with None-data in all address slots + _LOGGER.debug( + "Energy None-data collected from log address %s, stopping collection", + log_address, + ) + break + + # Check if the most recent timestamp of an earlier address is recent + # (within 2/4 * log_interval plus 5 mins margin) + log_interval = self.energy_consumption_interval + factor = 2 if self.energy_production_interval is not None else 4 + + if log_interval is not None: + max_gap_minutes = (factor * log_interval) + 5 + if log_address == self._current_log_address: + if ( + self._last_collected_energy_timestamp is not None + and ( + datetime.now(tz=UTC) - self._last_collected_energy_timestamp + ).total_seconds() + // 60 + > max_gap_minutes + ): + _LOGGER.debug( + "Energy data collected from the current log address is outdated, stopping collection" + ) + break + elif ( + prev_address_timestamp is not None + and self._last_collected_energy_timestamp is not None + and ( + prev_address_timestamp - self._last_collected_energy_timestamp + ).total_seconds() + // 60 + > max_gap_minutes + ): + _LOGGER.debug( + "Collected energy data is outdated, stopping collection" + ) + break + + if self._last_collected_energy_timestamp is not None: + prev_address_timestamp = self._last_collected_energy_timestamp + + log_address, _ = calc_log_address(log_address, 1, -4) + total_addresses -= 1 + + if self._cache_enabled: + await self._energy_log_records_save_to_cache() + async def get_missing_energy_logs(self) -> None: """Task to retrieve missing energy logs.""" self._energy_counters.update() if self._current_log_address is None: - return None + return if (missing_addresses := self._energy_counters.log_addresses_missing) is None: - _LOGGER.debug( - "Start with initial energy request for the last 10 log addresses for node %s.", - self._mac_in_str, - ) - total_addresses = 11 - log_address = self._current_log_address - while total_addresses > 0: - await self.energy_log_update(log_address) - log_address, _ = calc_log_address(log_address, 1, -4) - total_addresses -= 1 - - if self._cache_enabled: - await self._energy_log_records_save_to_cache() - + await self._get_initial_energy_logs() return _LOGGER.debug("Task created to get missing logs of %s", self._mac_in_str) @@ -475,6 +530,7 @@ async def energy_log_update(self, address: int | None) -> bool: """Request energy log statistics from node. Returns true if successful.""" if address is None: return False + _LOGGER.debug( "Request of energy log at address %s for node %s", str(address), @@ -496,6 +552,7 @@ async def energy_log_update(self, address: int | None) -> bool: # Forward historical energy log information to energy counters # Each response message contains 4 log counters (slots) of the # energy pulses collected during the previous hour of given timestamp + last_energy_timestamp_collected = False for _slot in range(4, 0, -1): log_timestamp, log_pulses = response.log_data[_slot] _LOGGER.debug( @@ -511,12 +568,26 @@ async def energy_log_update(self, address: int | None) -> bool: import_only=True, ): energy_record_update = True + if not last_energy_timestamp_collected: + # Collect the timestamp of the most recent response + self._last_collected_energy_timestamp = log_timestamp.replace( + tzinfo=UTC + ) + _LOGGER.debug( + "Setting last_collected_energy_timestamp to %s", + self._last_collected_energy_timestamp, + ) + last_energy_timestamp_collected = True self._energy_counters.update() if energy_record_update: + _LOGGER.debug( + "Saving energy record update to cache for %s", self._mac_in_str + ) await self.save_cache() + return True - return True + return False async def _energy_log_records_load_from_cache(self) -> bool: """Load energy_log_record from cache.""" @@ -526,6 +597,10 @@ async def _energy_log_records_load_from_cache(self) -> bool: ) return False restored_logs: dict[int, list[int]] = {} + if cache_data == "": + _LOGGER.debug("Cache-record is empty") + return False + log_data = cache_data.split("|") for log_record in log_data: log_fields = log_record.split(":") @@ -557,7 +632,9 @@ async def _energy_log_records_load_from_cache(self) -> bool: # Create task to retrieve remaining (missing) logs if self._energy_counters.log_addresses_missing is None: + _LOGGER.debug("Cache | missing log addresses is None") return False + if len(self._energy_counters.log_addresses_missing) > 0: if self._retrieve_energy_logs_task is not None: if not self._retrieve_energy_logs_task.done(): @@ -565,13 +642,16 @@ async def _energy_log_records_load_from_cache(self) -> bool: self._retrieve_energy_logs_task = create_task( self.get_missing_energy_logs() ) + _LOGGER.debug("Cache | creating tasks to obtain missing energy logs") return False + return True async def _energy_log_records_save_to_cache(self) -> None: """Save currently collected energy logs to cached file.""" if not self._cache_enabled: return + logs: dict[int, dict[int, PulseLogRecord]] = ( self._energy_counters.get_pulse_logs() ) @@ -585,6 +665,8 @@ async def _energy_log_records_save_to_cache(self) -> None: cached_logs += f"-{log.timestamp.month}-{log.timestamp.day}" cached_logs += f"-{log.timestamp.hour}-{log.timestamp.minute}" cached_logs += f"-{log.timestamp.second}:{log.pulses}" + + _LOGGER.debug("Saving energy logrecords to cache for %s", self._mac_in_str) self._set_cache(CACHE_ENERGY_COLLECTION, cached_logs) async def _energy_log_record_update_state( @@ -609,7 +691,7 @@ async def _energy_log_record_update_state( if (cached_logs := self._get_cache(CACHE_ENERGY_COLLECTION)) is not None: if log_cache_record not in cached_logs: _LOGGER.debug( - "Add logrecord (%s, %s) to log cache of %s", + "Adding logrecord (%s, %s) to cache of %s", str(address), str(slot), self._mac_in_str, @@ -619,10 +701,16 @@ async def _energy_log_record_update_state( ) return True + _LOGGER.debug( + "Energy logrecord already present for %s, ignoring", self._mac_in_str + ) return False _LOGGER.debug( - "No existing energy collection log cached for %s", self._mac_in_str + "Cache is empty, adding new logrecord (%s, %s) for %s", + str(address), + str(slot), + self._mac_in_str, ) self._set_cache(CACHE_ENERGY_COLLECTION, log_cache_record) return True @@ -637,7 +725,7 @@ async def set_relay(self, state: bool) -> bool: if self._relay_lock.state: _LOGGER.debug("Relay switch blocked, relay is locked") - return not state + return self._relay_state.state _LOGGER.debug("Switching relay to %s", state) request = CircleRelaySwitchRequest(self._send, self._mac_in_bytes, state) @@ -690,7 +778,7 @@ async def _relay_load_from_cache(self) -> bool: cached_relay_lock, ) relay_lock = cached_relay_lock == "True" - await self._relay_update_lock(relay_lock) + await self._relay_update_lock(relay_lock, load_from_cache=True) else: # Set to initial state False when not present in cache await self._relay_update_lock(False) @@ -716,9 +804,12 @@ async def _relay_update_state( await self.publish_feature_update_to_subscribers( NodeFeature.RELAY, self._relay_state ) + _LOGGER.debug("Saving relay state update to cache for %s", self._mac_in_str) await self.save_cache() - async def _relay_update_lock(self, state: bool) -> None: + async def _relay_update_lock( + self, state: bool, load_from_cache: bool = False + ) -> None: """Process relay lock update.""" state_update = False if state: @@ -735,7 +826,11 @@ async def _relay_update_lock(self, state: bool) -> None: await self.publish_feature_update_to_subscribers( NodeFeature.RELAY_LOCK, self._relay_lock ) - await self.save_cache() + if not load_from_cache: + _LOGGER.debug( + "Saving relay lock state update to cache for %s", self._mac_in_str + ) + await self.save_cache() async def clock_synchronize(self) -> bool: """Synchronize clock. Returns true if successful.""" @@ -792,6 +887,7 @@ async def load(self) -> bool: self._setup_protocol( CIRCLE_FIRMWARE_SUPPORT, ( + NodeFeature.CIRCLE, NodeFeature.RELAY, NodeFeature.RELAY_INIT, NodeFeature.RELAY_LOCK, @@ -833,6 +929,7 @@ async def load(self) -> bool: self._setup_protocol( CIRCLE_FIRMWARE_SUPPORT, ( + NodeFeature.CIRCLE, NodeFeature.RELAY, NodeFeature.RELAY_INIT, NodeFeature.RELAY_LOCK, @@ -948,16 +1045,6 @@ async def node_info_update( await self._relay_update_state( node_info.relay_state, timestamp=node_info.timestamp ) - if ( - self._get_cache(CACHE_CURRENT_LOG_ADDRESS) is None - and node_info.current_logaddress_pointer - ): - self._set_cache( - CACHE_CURRENT_LOG_ADDRESS, - node_info.current_logaddress_pointer, - ) - await self.save_cache() - if self._current_log_address is not None and ( self._current_log_address > node_info.current_logaddress_pointer or self._current_log_address == 1 @@ -972,28 +1059,9 @@ async def node_info_update( if self._current_log_address != node_info.current_logaddress_pointer: self._current_log_address = node_info.current_logaddress_pointer - self._set_cache( - CACHE_CURRENT_LOG_ADDRESS, node_info.current_logaddress_pointer - ) - await self.save_cache() return self._node_info - async def _node_info_load_from_cache(self) -> bool: - """Load node info settings from cache.""" - if ( - current_log_address := self._get_cache(CACHE_CURRENT_LOG_ADDRESS) - ) is not None: - self._current_log_address = int(current_log_address) - _LOGGER.debug( - "circle._node_info_load_from_cache | current_log_address=%s", - self._current_log_address, - ) - return True - - _LOGGER.debug("circle._node_info_load_from_cache | current_log_address=None") - return False - # pylint: disable=too-many-arguments async def update_node_details( self, node_info: NodeInfoResponse | None = None @@ -1097,6 +1165,9 @@ async def _relay_init_update_state(self, state: bool) -> None: await self.publish_feature_update_to_subscribers( NodeFeature.RELAY_INIT, self._relay_config ) + _LOGGER.debug( + "Saving relay_init state update to cachefor %s", self._mac_in_str + ) await self.save_cache() @raise_calibration_missing @@ -1203,3 +1274,69 @@ async def get_state(self, features: tuple[NodeFeature]) -> dict[NodeFeature, Any states[NodeFeature.AVAILABLE] = self.available_state return states + + async def energy_reset_request(self) -> None: + """Send an energy-reset to a Node.""" + if self._node_protocols is None: + raise NodeError("Unable to energy-reset when protocol version is unknown") + + request = CircleClockSetRequest( + self._send, + self._mac_in_bytes, + datetime.now(tz=UTC), + self._node_protocols.max, + True, + ) + if (response := await request.send()) is None: + raise NodeError(f"Energy-reset for {self._mac_in_str} failed") + + if response.ack_id != NodeResponseType.CLOCK_ACCEPTED: + raise MessageError( + f"Unexpected NodeResponseType {response.ack_id!r} received as response to CircleClockSetRequest" + ) + + _LOGGER.warning("Energy reset for Node %s successful", self._mac_in_str) + + # Follow up by an energy-intervals (re)set + interval_request = CircleMeasureIntervalRequest( + self._send, + self._mac_in_bytes, + DEFAULT_CONS_INTERVAL, + NO_PRODUCTION_INTERVAL, + ) + if (interval_response := await interval_request.send()) is None: + raise NodeError("No response for CircleMeasureIntervalRequest") + + if ( + interval_response.response_type + != NodeResponseType.POWER_LOG_INTERVAL_ACCEPTED + ): + raise MessageError( + f"Unknown NodeResponseType '{interval_response.response_type.name}' received" + ) + _LOGGER.warning("Resetting energy intervals to default (= consumption only)") + + # Clear the cached energy_collection + if self._cache_enabled: + self._set_cache(CACHE_ENERGY_COLLECTION, "") + _LOGGER.warning( + "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") + + # Request a NodeInfo update + if await self.node_info_update() is None: + _LOGGER.warning( + "Node info update failed after energy-reset for %s", + self._mac_in_str, + ) + else: + _LOGGER.warning( + "Node info update after energy-reset successful for %s", + self._mac_in_str, + ) diff --git a/plugwise_usb/nodes/helpers/counter.py b/plugwise_usb/nodes/helpers/counter.py index c55aa46bd..2caf6828d 100644 --- a/plugwise_usb/nodes/helpers/counter.py +++ b/plugwise_usb/nodes/helpers/counter.py @@ -103,6 +103,10 @@ def add_pulse_stats( ) self.update() + def reset_pulse_collection(self) -> None: + """Reset the related pulse collection.""" + self._pulse_collection.reset() + @property def energy_statistics(self) -> EnergyStatistics: """Return collection with energy statistics.""" diff --git a/plugwise_usb/nodes/helpers/firmware.py b/plugwise_usb/nodes/helpers/firmware.py index c2df3b4d0..1379b04c6 100644 --- a/plugwise_usb/nodes/helpers/firmware.py +++ b/plugwise_usb/nodes/helpers/firmware.py @@ -155,6 +155,8 @@ class SupportedVersions(NamedTuple): FEATURE_SUPPORTED_AT_FIRMWARE: Final = { NodeFeature.BATTERY: 2.0, + NodeFeature.CIRCLE: 2.0, + NodeFeature.CIRCLEPLUS: 2.0, NodeFeature.INFO: 2.0, NodeFeature.SENSE: 2.0, NodeFeature.TEMPERATURE: 2.0, @@ -167,7 +169,6 @@ class SupportedVersions(NamedTuple): NodeFeature.MOTION: 2.0, NodeFeature.MOTION_CONFIG: 2.0, NodeFeature.SWITCH: 2.0, - NodeFeature.CIRCLEPLUS: 2.0, } # endregion diff --git a/plugwise_usb/nodes/helpers/pulses.py b/plugwise_usb/nodes/helpers/pulses.py index dda31cd02..338ed70d9 100644 --- a/plugwise_usb/nodes/helpers/pulses.py +++ b/plugwise_usb/nodes/helpers/pulses.py @@ -163,6 +163,13 @@ def pulse_counter_reset(self) -> bool: """Return a pulse_counter reset.""" return self._cons_pulsecounter_reset or self._prod_pulsecounter_reset + def reset(self) -> None: + """Reset PulseCollection after an energy-logs reset.""" + # Keep mac, wipe every other attribute. + fresh_state = PulseCollection(self._mac).__dict__ + self.__dict__.clear() # remove *all* existing keys first + self.__dict__.update(fresh_state) + def collected_pulses( self, from_timestamp: datetime, is_consumption: bool ) -> tuple[int | None, datetime | None]: @@ -409,6 +416,7 @@ def add_empty_log(self, address: int, slot: int) -> None: ): self._last_empty_log_slot = slot recalculate = True + if recalculate: self.recalculate_missing_log_addresses() @@ -510,9 +518,6 @@ def _update_log_direction( or double slots containing consumption and production data. Single slots containing production data only is NOT supported/tested. """ - if self._logs is None: - return - prev_timestamp = self._check_prev_production(address, slot, timestamp) next_timestamp = self._check_next_production(address, slot, timestamp) if self._first_prev_log_processed and self._first_next_log_processed: @@ -526,6 +531,9 @@ def _check_prev_production( self, address: int, slot: int, timestamp: datetime ) -> datetime | None: """Check the previous slot for production pulses.""" + if self._logs is None: + return + prev_address, prev_slot = calc_log_address(address, slot, -1) if self._log_exists(prev_address, prev_slot): prev_timestamp = self._logs[prev_address][prev_slot].timestamp @@ -554,6 +562,9 @@ def _check_next_production( self, address: int, slot: int, timestamp: datetime ) -> datetime | None: """Check the next slot for production pulses.""" + if self._logs is None: + return + next_address, next_slot = calc_log_address(address, slot, 1) if self._log_exists(next_address, next_slot): next_timestamp = self._logs[next_address][next_slot].timestamp @@ -823,7 +834,7 @@ def _first_log_reference( ) return (self._first_log_production_address, self._first_log_production_slot) - def _logs_missing(self, from_timestamp: datetime) -> list[int] | None: # noqa: PLR0911 PLR0912 + def _logs_missing(self, from_timestamp: datetime) -> list[int] | None: # noqa: PLR0911 PLR0912 PLR0915 """Calculate list of missing log addresses.""" if self._logs is None: self._log_addresses_missing = None @@ -854,7 +865,7 @@ def _logs_missing(self, from_timestamp: datetime) -> list[int] | None: # noqa: missing = [] _LOGGER.debug( - "_logs_missing | %s | first_address=%s, last_address=%s, from_timestamp=%s", + "_logs_missing | %s | checking in range: first_address=%s, last_address=%s, from_timestamp=%s", self._mac, first_address, last_address, @@ -878,19 +889,34 @@ def _logs_missing(self, from_timestamp: datetime) -> list[int] | None: # noqa: # Power consumption logging, so we need at least 4 logs. return None - # Collect any missing address in current range + # Collect any missing address in current range, within MAX_LOG_HOURS timeframe + # The max_count-guarding has been added for when an outdated logrecord is present in the cache, + # this will result in the unwanted collection of missing logs outside the MAX_LOG_HOURS timeframe address = last_address slot = last_slot - while not (address == first_address and slot == first_slot): + count = 0 + max_count = MAX_LOG_HOURS + if self._log_production: + max_count = ( + 2 * max_count + ) # this requires production_interval == consumption_interval + + while not ( + (address == first_address and slot == first_slot) or count > max_count + ): address, slot = calc_log_address(address, slot, -1) if address in missing: continue + if not self._log_exists(address, slot): missing.append(address) continue + if self._logs[address][slot].timestamp <= from_timestamp: break + count += 1 + # return missing logs in range first if len(missing) > 0: _LOGGER.debug( @@ -926,17 +952,29 @@ def _logs_missing(self, from_timestamp: datetime) -> list[int] | None: # noqa: return None # We have an suspected interval, so try to calculate missing log addresses prior to first collected log + _LOGGER.debug( + "_logs_missing | %s | checking before range with log_interval=%s", + self._mac, + log_interval, + ) calculated_timestamp = self._logs[first_address][ first_slot ].timestamp - timedelta(minutes=log_interval) + _LOGGER.debug( + "_logs_missing | %s | first_empty_log_address=%s", + self._mac, + self._first_empty_log_address, + ) while from_timestamp < calculated_timestamp: if ( address == self._first_empty_log_address and slot == self._first_empty_log_slot ): break + if address not in missing: missing.append(address) + calculated_timestamp -= timedelta(minutes=log_interval) address, slot = calc_log_address(address, slot, -1) diff --git a/plugwise_usb/nodes/node.py b/plugwise_usb/nodes/node.py index 91c7fb797..a8096c829 100644 --- a/plugwise_usb/nodes/node.py +++ b/plugwise_usb/nodes/node.py @@ -51,6 +51,7 @@ CACHE_NODE_TYPE = "node_type" CACHE_HARDWARE = "hardware" CACHE_NODE_INFO_TIMESTAMP = "node_info_timestamp" +CACHE_RELAY = "relay" class PlugwiseBaseNode(FeaturePublisher, ABC): @@ -456,25 +457,31 @@ async def node_info_update( _LOGGER.debug("No response for node_info_update() for %s", self.mac) await self._available_update_state(False) return self._node_info + await self._available_update_state(True, node_info.timestamp) await self.update_node_details(node_info) return self._node_info async def _node_info_load_from_cache(self) -> bool: """Load node info settings from cache.""" + if self._available: + # Skip loading this data from cache when the Node is available + return True + firmware = self._get_cache_as_datetime(CACHE_FIRMWARE) hardware = self._get_cache(CACHE_HARDWARE) - timestamp = self._get_cache_as_datetime(CACHE_NODE_INFO_TIMESTAMP) node_type: NodeType | None = None if (node_type_str := self._get_cache(CACHE_NODE_TYPE)) is not None: node_type = NodeType(int(node_type_str)) + relay_state = self._get_cache(CACHE_RELAY) == "True" + timestamp = self._get_cache_as_datetime(CACHE_NODE_INFO_TIMESTAMP) node_info = NodeInfoMessage( + current_logaddress_pointer=None, firmware=firmware, hardware=hardware, node_type=node_type, + relay_state=relay_state, timestamp=timestamp, - relay_state=None, - current_logaddress_pointer=None, ) return await self.update_node_details(node_info) @@ -510,6 +517,7 @@ async def update_node_details( complete &= self._update_node_details_hardware(node_info.hardware) complete &= self._update_node_details_timestamp(node_info.timestamp) + _LOGGER.debug("Saving Node calibration update to cache for %s", self.mac) await self.save_cache() if node_info.timestamp is not None and node_info.timestamp > datetime.now( tz=UTC @@ -639,6 +647,7 @@ async def unload(self) -> None: return if self._cache_save_task is not None and not self._cache_save_task.done(): await self._cache_save_task + _LOGGER.debug("Writing cache to disk while unloading for %s", self.mac) await self.save_cache(trigger_only=False, full_write=True) def _get_cache(self, setting: str) -> str | None: diff --git a/pyproject.toml b/pyproject.toml index 0a9ec6544..29155a6f0 100644 --- a/pyproject.toml +++ b/pyproject.toml @@ -4,7 +4,7 @@ build-backend = "setuptools.build_meta" [project] name = "plugwise_usb" -version = "0.44.3" +version = "0.44.4" license = "MIT" keywords = ["home", "automation", "plugwise", "module", "usb"] classifiers = [ diff --git a/tests/test_usb.py b/tests/test_usb.py index 831ed4e83..e861175cf 100644 --- a/tests/test_usb.py +++ b/tests/test_usb.py @@ -2156,12 +2156,11 @@ async def load_callback(event: pw_api.NodeEvent, mac: str) -> None: # type: ign ) assert not test_scan.cache_enabled node_info = pw_api.NodeInfoMessage( + current_logaddress_pointer=None, firmware=dt(2011, 6, 27, 8, 55, 44, tzinfo=UTC), hardware="080007", node_type=None, - timestamp=None, relay_state=None, - current_logaddress_pointer=None, ) await test_scan.update_node_details(node_info) assert await test_scan.load() @@ -2261,12 +2260,11 @@ async def load_callback(event: pw_api.NodeEvent, mac: str) -> None: # type: ign "1298347650AFBECD", 1, mock_stick_controller, load_callback ) node_info = pw_api.NodeInfoMessage( + current_logaddress_pointer=None, firmware=dt(2011, 6, 27, 8, 55, 44, tzinfo=UTC), hardware="080007", node_type=None, - timestamp=None, relay_state=None, - current_logaddress_pointer=None, ) await test_scan.update_node_details(node_info) test_scan.cache_enabled = True @@ -2338,12 +2336,11 @@ async def load_callback(event: pw_api.NodeEvent, mac: str) -> None: # type: ign ) ) node_info = pw_api.NodeInfoMessage( + current_logaddress_pointer=None, firmware=dt(2011, 6, 27, 9, 4, 10, tzinfo=UTC), hardware="070051", node_type=None, - timestamp=None, relay_state=None, - current_logaddress_pointer=None, ) await test_switch.update_node_details(node_info) assert await test_switch.load() @@ -2356,12 +2353,11 @@ async def load_callback(event: pw_api.NodeEvent, mac: str) -> None: # type: ign "1298347650AFBECD", 1, mock_stick_controller, load_callback ) node_info = pw_api.NodeInfoMessage( + current_logaddress_pointer=None, firmware=dt(2011, 6, 27, 9, 4, 10, tzinfo=UTC), hardware="070051", node_type=None, - timestamp=None, relay_state=None, - current_logaddress_pointer=None, ) await test_switch.update_node_details(node_info) test_switch.cache_enabled = True @@ -2488,12 +2484,12 @@ async def test_node_discovery_and_load( # noqa: PLR0915 assert sorted(state[pw_api.NodeFeature.INFO].features) == sorted( ( pw_api.NodeFeature.AVAILABLE, + pw_api.NodeFeature.CIRCLEPLUS, pw_api.NodeFeature.INFO, pw_api.NodeFeature.PING, pw_api.NodeFeature.RELAY, pw_api.NodeFeature.RELAY_LOCK, pw_api.NodeFeature.ENERGY, - pw_api.NodeFeature.CIRCLEPLUS, pw_api.NodeFeature.POWER, ) ) @@ -2540,6 +2536,7 @@ async def test_node_discovery_and_load( # noqa: PLR0915 assert sorted(state[pw_api.NodeFeature.INFO].features) == sorted( ( pw_api.NodeFeature.AVAILABLE, + pw_api.NodeFeature.CIRCLE, pw_api.NodeFeature.INFO, pw_api.NodeFeature.PING, pw_api.NodeFeature.RELAY,