diff --git a/apps/vertex2.py b/apps/vertex2.py index 2c45e0b..832fc87 100644 --- a/apps/vertex2.py +++ b/apps/vertex2.py @@ -7,6 +7,7 @@ import time import json import socket import threading +from collections import deque import re from urllib.parse import urlparse @@ -14,6 +15,7 @@ class Vertex2(SmartObject): def on_initialize_smart_object(self): # HASS can call initialize() again without calling terminate() first. self._stop_interrupt_listener() + self._cancel_input_5v_refresh() self._interrupt_stop = threading.Event() self._status_requested = threading.Event() self._last_logged_status = None @@ -217,9 +219,28 @@ class Vertex2(SmartObject): if sensor.get_state() != 'unavailable': sensor.set_state(state='unavailable') - def _schedule_input_5v_refresh(self): - # Device monitoring must run even when no HA input sensors are exposed. - self.run_in(self._refresh_input_5v_sensors, 0.1) + def _cancel_input_5v_refresh(self): + handle = getattr(self, '_input_5v_refresh_handle', None) + if handle is not None: + self.cancel_timer(handle, silent=True) + self._input_5v_refresh_handle = None + self._input_5v_refresh_generation = getattr(self, '_input_5v_refresh_generation', 0) + 1 + self._input_5v_failure_since = None + self._input_5v_failures = 0 + + def _schedule_input_5v_refresh(self, delay=1): + # Coalesce bursts without postponing a pending retry or starving reads. + if self._input_5v_refresh_handle is not None: + return + self._input_5v_refresh_generation += 1 + self._input_5v_refresh_handle = self.run_in( + self._on_input_5v_refresh, delay, generation=self._input_5v_refresh_generation) + + def _on_input_5v_refresh(self, kwargs): + if kwargs['generation'] != self._input_5v_refresh_generation: + return + self._input_5v_refresh_handle = None + self._refresh_input_5v_sensors() def _refresh_input_5v_sensors(self, kwargs=None): if not self._vertex2_ready(): @@ -233,11 +254,27 @@ class Vertex2(SmartObject): raise ValueError('expected an information object') except (RequestException, ValueError) as error: self._invalidate_input_5v_sensors() - self.log_warning(f'Vertex2 input +5V readback failed: {error}') + if not self._vertex2_ready(): + self._cancel_input_5v_refresh() + return + self._input_5v_failures += 1 + if self._input_5v_failure_since is None: + self._input_5v_failure_since = time.monotonic() + log = self.log_warning if self._input_5v_failures == 2 else self.log_info + log(f'Vertex2 input +5V readback failed ' + f'(attempt={self._input_5v_failures}, {type(error).__name__}): {error}') + if self._input_5v_failures == 1: + self._schedule_input_5v_refresh(delay=5) return if not self._vertex2_ready(): self._invalidate_input_5v_sensors() return + if self._input_5v_failure_since is not None: + self.log_info( + f'Vertex2 input +5V readback restored after ' + f'{time.monotonic() - self._input_5v_failure_since:.1f}s ' + f'({self._input_5v_failures} failed attempts)') + self._cancel_input_5v_refresh() states = {} for index in range(4): # Firmware uses 2 for present and 1 for absent, not boolean 1/0. @@ -442,11 +479,26 @@ class Vertex2(SmartObject): status_started = None reconfigure = True pending_interrupt_at = None + recent_lines = deque(maxlen=12) + received_bytes = 0 + interrupt_count = 0 + + def status_timeout_error(): + return OSError( + 'Vertex2 TCP status response timed out ' + f'(elapsed={time.monotonic() - status_started:.2f}s, limit=5s, ' + f'received={sorted(status)}, missing={sorted(expected - status.keys())}, ' + f'bytes={received_bytes}, interrupts={interrupt_count}, ' + f'reconfigure={reconfigure}, ' + f'recent_lines={list(recent_lines)!r}, partial_line={buffer[-256:]!r})') while not interrupt_stop.is_set() and self._vertex2_powered(): if status_started is None and self._status_requested.is_set(): self._status_requested.clear() status = {} + recent_lines.clear() + received_bytes = 0 + interrupt_count = 0 status_started = time.monotonic() request_interrupt_at = pending_interrupt_at pending_interrupt_at = None @@ -457,7 +509,7 @@ class Vertex2(SmartObject): data = connection.recv(1024) except socket.timeout: if status_started is not None and time.monotonic() - status_started > 5: - raise OSError('Vertex2 TCP status response timed out') + raise status_timeout_error() continue if interrupt_stop.is_set() or not self._vertex2_powered(): @@ -465,6 +517,7 @@ class Vertex2(SmartObject): if not data: raise OSError('Vertex2 closed the IP INTERRUPT connection') + received_bytes += len(data) buffer += data.decode('ascii', errors='ignore') if len(buffer) > 4096: raise OSError('Vertex2 TCP response exceeded buffer limit') @@ -472,7 +525,9 @@ class Vertex2(SmartObject): while '\n' in buffer: line, buffer = buffer.split('\n', 1) line = line.strip() + recent_lines.append(line[:256]) if line == 'int': + interrupt_count += 1 pending_interrupt_at = time.monotonic() self._status_requested.set() elif status_started is not None: @@ -497,7 +552,7 @@ class Vertex2(SmartObject): status_started = None if status_started is not None and time.monotonic() - status_started > 5: - raise OSError('Vertex2 TCP status response timed out') + raise status_timeout_error() except (OSError, ValueError) as error: if interrupt_stop.is_set(): @@ -557,6 +612,7 @@ class Vertex2(SmartObject): self._command_processing_handle = None def terminate(self): + self._cancel_input_5v_refresh() if getattr(self, '_input_select_config', None): self._publish_input_select('/availability', 'offline') self._stop_interrupt_listener() @@ -721,6 +777,7 @@ class Vertex2(SmartObject): ) def _suspend_vertex2(self): + self._cancel_input_5v_refresh() self._invalidate_input_5v_sensors() self._reset_no_signal_spam() self._invalidate_plus5_sensors()