From 7d5a2d2e99b1655311522c6219cf89a39b14617d Mon Sep 17 00:00:00 2001 From: maslyankov Date: Thu, 23 Jan 2025 18:42:41 +0200 Subject: [PATCH] Enhance register unpacking and sensor reading with improved error handling and logging - Added logging for suspicious register values (0xFFFF) and large unpacked values. - Improved error handling during unpacking of register values, including specific warnings for single and double register unpacking failures. - Introduced a mapping of register addresses to sensors for better tracking and debugging. - Enhanced performance logging for register reads, including warnings for slow reads and multiple consecutive timeouts. - Updated debug logging to provide more context on register requests and responses. These changes aim to improve the robustness and reliability of the sensor reading process. --- src/sunsynk/helpers.py | 53 +++++++++++-- src/sunsynk/solarmansunsynk.py | 2 +- src/sunsynk/sunsynk.py | 92 +++++++++++++++++++++-- src/tests/sunsynk/test_solarmansunsynk.py | 2 +- 4 files changed, 133 insertions(+), 16 deletions(-) diff --git a/src/sunsynk/helpers.py b/src/sunsynk/helpers.py index e1c27b6d..a38b5c2a 100644 --- a/src/sunsynk/helpers.py +++ b/src/sunsynk/helpers.py @@ -3,6 +3,7 @@ import logging import math import struct +import struct from typing import Any _LOGGER = logging.getLogger(__name__) @@ -44,13 +45,51 @@ def unpack_value(regs: RegType, signed: bool = True) -> int: Returns: Unpacked integer value """ - if len(regs) == 1: - fmt = "h" if signed else "H" - return struct.unpack(fmt, struct.pack("H", regs[0]))[0] - if len(regs) == 2: - fmt = "i" if signed else "I" - return struct.unpack(fmt, struct.pack("2H", regs[0], regs[1]))[0] - raise ValueError(f"Unsupported number of registers: {len(regs)}") + try: + # Log suspicious register values (all bits set) + for reg in regs: + if reg == 0xFFFF: + _LOGGER.warning( + "Suspicious register value detected: 0xFFFF (all bits set)" + ) + + if len(regs) == 1: + fmt = "h" if signed else "H" + try: + return struct.unpack(fmt, struct.pack("H", regs[0]))[0] + except struct.error as e: + _LOGGER.warning( + "Error unpacking single register %s: %s", hex(regs[0]), str(e) + ) + raise + + if len(regs) == 2: + fmt = "i" if signed else "I" + try: + val = struct.unpack(fmt, struct.pack("2H", regs[0], regs[1]))[0] + # Log potentially anomalous large values + if abs(val) > 0x7FFFFFFF: + _LOGGER.warning( + "Very large value detected: %s (registers: %s)", + val, + [hex(r) for r in regs], + ) + return val + except struct.error as e: + _LOGGER.warning( + "Error unpacking double register %s,%s: %s", + hex(regs[0]), + hex(regs[1]), + str(e), + ) + raise + + raise ValueError(f"Unsupported number of registers: {len(regs)}") + except Exception as e: + _LOGGER.error( + "Failed to unpack registers %s: %s", [hex(r) for r in regs], str(e) + ) + raise def ensure_tuple(val: Any) -> tuple[int, ...]: diff --git a/src/sunsynk/solarmansunsynk.py b/src/sunsynk/solarmansunsynk.py index 42a2ff41..ba54a1fd 100644 --- a/src/sunsynk/solarmansunsynk.py +++ b/src/sunsynk/solarmansunsynk.py @@ -98,4 +98,4 @@ async def read_holding_registers(self, start: int, length: int) -> Sequence[int] await self.disconnect() if attempt >= RETRY_ATTEMPTS: raise IOError(f"Failed to read register {start}") from err - await asyncio.sleep(2) \ No newline at end of file + await asyncio.sleep(2) diff --git a/src/sunsynk/sunsynk.py b/src/sunsynk/sunsynk.py index 4feaf543..331f0f8c 100644 --- a/src/sunsynk/sunsynk.py +++ b/src/sunsynk/sunsynk.py @@ -3,18 +3,29 @@ import asyncio import logging import time -from typing import Iterable, Sequence, TypedDict +from typing import Iterable, Sequence, TypedDict, Union import attrs from sunsynk.helpers import hex_str, patch_bitmask from sunsynk.rwsensors import RWSensor -from sunsynk.sensors import Sensor, ValType +from sunsynk.sensors import ( + BinarySensor, + EnumSensor, + InverterStateSensor, + SDStatusSensor, + Sensor, + ValType, +) from sunsynk.state import InverterState, group_sensors, register_map _LOGGER = logging.getLogger(__name__) +class RegisterReadError(Exception): + """Exception raised when there are errors reading registers.""" + + @attrs.define class Sunsynk: """Sunsync Modbus class.""" @@ -75,12 +86,19 @@ async def read_holding_registers(self, start: int, length: int) -> Sequence[int] async def read_sensors(self, sensors: Iterable[Sensor]) -> None: """Read a list of sensors - Sunsynk supports function code 0x03.""" + # pylint: disable=too-many-locals,too-many-branches # Check if state is ok & tracking the sensors being read assert self.state is not None for sen in sensors: if sen not in self.state.values: _LOGGER.warning("sensor %s not being tracked", sen.id) + # Create a map of register addresses to their corresponding sensors + reg_to_sensor: dict[int, Union[Sensor, None]] = {} + for sensor in sensors: + for addr in sensor.address: + reg_to_sensor[addr] = sensor + new_regs: dict[int, int] = {} errs: list[str] = [] groups = group_sensors( @@ -92,19 +110,39 @@ async def read_sensors(self, sensors: Iterable[Sensor]) -> None: glen = grp[-1] - grp[0] + 1 try: perf = time.perf_counter() + _LOGGER.debug("Starting read of %s registers from %s", glen, grp[0]) + r_r = await asyncio.wait_for( self.read_holding_registers(grp[0], glen), timeout=self.timeout + 1 ) perf = time.perf_counter() - perf + + # Log performance metrics _LOGGER.debug( "Time taken to fetch %s registers starting at %s : %ss", glen, grp[0], f"{perf:.2f}", ) + + # Check for potential communication issues based on timing + if perf > self.timeout * 0.8: # If taking more than 80% of timeout + _LOGGER.warning( + "Slow register read detected: %ss for %s registers from %s", + f"{perf:.2f}", + glen, + grp[0], + ) + except asyncio.TimeoutError: errs.append(f"timeout reading {glen} registers from {grp[0]}") self.timeouts += 1 + # Log consecutive timeouts + if self.timeouts > 3: + _LOGGER.error( + "Multiple consecutive timeouts detected: %s. Consider checking connection.", + self.timeouts, + ) continue except Exception as err: # pylint: disable=broad-except errs.append( @@ -117,21 +155,61 @@ async def read_sensors(self, sensors: Iterable[Sensor]) -> None: if len(r_r) != glen: _LOGGER.warning( - "Did not complete read, only read %s/%s", len(r_r), glen + "Did not complete read, only read %s/%s registers. This may cause value spikes.", + len(r_r), + glen, ) + # Log register values for debugging _LOGGER.debug( "Request registers: %s glen=%d. Response %s len=%d. regs=%s", grp, glen, - r_r, + [hex(r) for r in r_r], # Convert to hex for better debugging len(r_r), - regs, + { + k: hex(v) for k, v in regs.items() + }, # Convert to hex for better debugging ) - self.state.update(new_regs) + # Check for potentially invalid register values + for reg_addr, reg_val in regs.items(): + maybe_sensor: Union[Sensor, None] = reg_to_sensor.get(reg_addr) + if maybe_sensor is None: + continue + + current_sensor: Sensor = maybe_sensor + if reg_val == 0xFFFF: + _LOGGER.warning( + "Potentially invalid register value detected: addr=%s value=0xFFFF sensor=%s", + reg_addr, + current_sensor.name, + ) + # Only check zeros for status/enum type sensors + elif reg_val == 0 and any( + isinstance(current_sensor, t) + for t in ( + BinarySensor, + EnumSensor, + InverterStateSensor, + SDStatusSensor, + ) + ): + _LOGGER.debug( + "Zero value detected in status sensor: addr=%s sensor=%s", + reg_addr, + current_sensor.name, + ) + if errs: - raise IOError("; ".join(errs)) + _LOGGER.warning("Errors during sensor read: %s", ", ".join(errs)) + raise RegisterReadError(", ".join(errs)) + + # Reset timeout counter if successful + if not errs: + self.timeouts = 0 + + self.state.update(new_regs) class SunsynkInitParameters(TypedDict): diff --git a/src/tests/sunsynk/test_solarmansunsynk.py b/src/tests/sunsynk/test_solarmansunsynk.py index c3923854..d255c86e 100644 --- a/src/tests/sunsynk/test_solarmansunsynk.py +++ b/src/tests/sunsynk/test_solarmansunsynk.py @@ -42,4 +42,4 @@ async def test_uss_sensor(connect: Any) -> None: wrr = ss.client.write_multiple_holding_registers = AsyncMock() assert not wrr.called await ss.write_register(address=1, value=2) - assert wrr.called \ No newline at end of file + assert wrr.called