Enhance register unpacking and sensor reading with improved error han…

…dling 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

@@ -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, ...]:

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)
+                await asyncio.sleep(2)

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):

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
+    assert wrr.called