fix: connection drop and logging issues

Author: sidey79

main.py

@@ -156,6 +156,12 @@ def signal_handler(sig, frame):
             # Endlosschleife, wenn kein Timeout gesetzt ist
             while True:
                 time.sleep(1)
+                if not controller.is_running:
+                    logger.error("Controller threads are dead. Exiting...")
+                    break
+            
+            controller.disconnect()
+            sys.exit(1)
 
     except SignalduinoConnectionError as e:
         # Wird ausgelöst, wenn die Verbindung beim Start fehlschlägt (z.B. falscher Port, Gerät nicht angeschlossen)

sd_protocols/message_unsynced.py

@@ -45,6 +45,7 @@ def demodulate_mu(self, msg_data: Dict[str, Any], msg_type: str = "MU") -> List[
         mu_protocols = self.get_keys('clockabs')
 
         for pid in mu_protocols:
+            self._logging(f"MU checking PID {pid}", 5)
             # Prepare working copy of raw_data and patterns
             # (Perl does this per protocol iteration because filterfunc might modify them)
             current_raw_data = raw_data
@@ -94,6 +95,7 @@ def demodulate_mu(self, msg_data: Dict[str, Any], msg_type: str = "MU") -> List[
 
             # Check one, zero, float
             for key in ['one', 'zero', 'float']:
+                # print(f"DEBUG: Checking {key} for PID {pid}")
                 prop_val = self.get_property(pid, key)
                 if not prop_val:
                     continue
@@ -200,13 +202,16 @@ def demodulate_mu(self, msg_data: Dict[str, Any], msg_type: str = "MU") -> List[
             regex_pattern = f"(?:{re.escape(start_str)})((?:{signal_group_inner}){{{length_min},}}{reconstruct_part})"
 
             try:
+                # print(f"DEBUG: Compiling regex for {pid}: {regex_pattern[:50]}...")
                 matcher = re.compile(regex_pattern)
             except re.error as e:
                 self._logging(f"MU Demod: Invalid regex for {pid}: {e}", 3)
                 continue
 
             # Perl iterates with /g
+            # print(f"DEBUG: Executing finditer for {pid}")
             for match in matcher.finditer(current_raw_data):
+                # print(f"DEBUG: Match found for {pid}")
                 data_part = match.group(1)
 
                 # Check length max

sd_protocols/pattern_utils.py

@@ -87,6 +87,18 @@ def pattern_exists(search_pattern: List[float], pattern_list: Dict[str, float],
     # 2. Generate cartesian product of candidates
     # This gives us all possible assignments of Pattern IDs to the Unique Search Values
     # e.g. search=[1, -1], candidates(1)=['0'], candidates(-1)=['1'] -> product=[['0', '1']]
+    
+    # Check for explosion risk
+    total_combinations = 1
+    for c in candidates_list:
+        total_combinations *= len(c)
+        
+    if total_combinations > 10000:
+        if debug_callback:
+            debug_callback(f"Too many combinations: {total_combinations}. Aborting pattern match.")
+        print(f"DEBUG: Too many combinations: {total_combinations} for {search_pattern}")
+        return -1
+
     product = cartesian_product(candidates_list)
 
     if debug_callback:

signalduino/constants.py

@@ -10,7 +10,7 @@
 SDUINO_WRITEQUEUE_NEXT = 0.3
 SDUINO_WRITEQUEUE_TIMEOUT = 2
 
-SDUINO_STATUS_HEARTBEAT_INTERVAL = 600.0 # 10 minutes
+SDUINO_STATUS_HEARTBEAT_INTERVAL = 10.0 # 10 seconds
 
 SDUINO_DISPATCH_VERBOSE = 5
 SDUINO_MC_DISPATCH_VERBOSE = 5

signalduino/controller.py

@@ -3,6 +3,7 @@
 import queue
 import re
 import threading
+import time
 import os # NEU: Import für Umgebungsvariablen
 from datetime import datetime, timedelta, timezone
 from typing import Any, Callable, List, Optional, Pattern
@@ -50,6 +51,8 @@ def __init__(
         self._writer_thread: Optional[threading.Thread] = None
 
         self._heartbeat_timer: Optional[threading.Timer] = None # NEU: Heartbeat Timer initialisieren
+        self._init_timer_xq: Optional[threading.Timer] = None
+        self._init_timer_start: Optional[threading.Timer] = None
 
         self._stop_event = threading.Event()
         self._raw_message_queue: queue.Queue[str] = queue.Queue()
@@ -59,6 +62,9 @@ def __init__(
 
         self.init_retry_count = 0
         self.init_reset_flag = False
+        
+        self._keep_alive = False
+        self._monitor_thread: Optional[threading.Thread] = None
 
     def connect(self) -> None:
         """Opens the transport and starts the worker threads."""
@@ -83,13 +89,33 @@ def connect(self) -> None:
         self._writer_thread = threading.Thread(target=self._writer_loop, name="sd-writer")
         self._writer_thread.start()
 
-    def disconnect(self) -> None:
+        self._keep_alive = True
+        if not self._monitor_thread or not self._monitor_thread.is_alive():
+            self._monitor_thread = threading.Thread(target=self._monitor_loop, name="sd-monitor", daemon=True)
+            self._monitor_thread.start()
+
+    @property
+    def is_running(self) -> bool:
+        """Checks if the controller is running and threads are alive."""
+        if self._stop_event.is_set():
+            return False
+        
+        # If threads are initialized, they must be alive
+        if self._reader_thread and not self._reader_thread.is_alive():
+            return False
+        if self._parser_thread and not self._parser_thread.is_alive():
+            return False
+        if self._writer_thread and not self._writer_thread.is_alive():
+            return False
+            
+        return True
+
+    def disconnect(self, reconnect: bool = False) -> None:
         """Stops the worker threads and closes the transport."""
-        if not self.transport.is_open:
-            self.logger.warning("disconnect() called but transport is not open.")
-            return
+        if not reconnect:
+            self._keep_alive = False
 
-        self.logger.info("Disconnecting...")
+        self.logger.info("Disconnecting... (reconnect=%s)", reconnect)
         self._stop_event.set()
 
         # NEU: MQTT Publisher stoppen
@@ -100,6 +126,14 @@ def disconnect(self) -> None:
             self._heartbeat_timer.cancel()
             self._heartbeat_timer = None
 
+        if self._init_timer_xq:
+            self._init_timer_xq.cancel()
+            self._init_timer_xq = None
+
+        if self._init_timer_start:
+            self._init_timer_start.cancel()
+            self._init_timer_start = None
+
         # Wake up threads that might be waiting on queues
         self._raw_message_queue.put("")
         self._write_queue.put(QueuedCommand("", 0))
@@ -111,29 +145,60 @@ def disconnect(self) -> None:
         if self._writer_thread:
             self._writer_thread.join(timeout=1)
 
-        self.transport.close()
+        try:
+            self.transport.close()
+        except Exception as e:
+            self.logger.warning("Error closing transport: %s", e)
         self.logger.info("Transport closed.")
 
+    def _monitor_loop(self) -> None:
+        """Monitors connection state and reconnects if enabled."""
+        self.logger.info("Monitor loop started.")
+        while True:
+            time.sleep(5)
+            if self._keep_alive and not self.is_running:
+                self.logger.warning("Connection lost. Attempting auto-reconnect...")
+                try:
+                    # Ensure everything is stopped before reconnecting
+                    self.disconnect(reconnect=True)
+                    time.sleep(2)
+                    self.connect()
+                    # Trigger init sequence
+                    self.initialize()
+                except Exception as e:
+                    self.logger.error("Auto-reconnect failed: %s", e)
+
     def initialize(self) -> None:
         """Starts the initialization process."""
         self.logger.info("Initializing device...")
         self.init_retry_count = 0
         self.init_reset_flag = False
 
+        if self._stop_event.is_set():
+            self.logger.warning("initialize called but stop event is set.")
+            return
+
         # Schedule Disable Receiver (XQ) and wait briefly
-        threading.Timer(SDUINO_INIT_WAIT_XQ, self._send_xq).start()
+        self._init_timer_xq = threading.Timer(SDUINO_INIT_WAIT_XQ, self._send_xq)
+        self._init_timer_xq.start()
 
         # Schedule StartInit (Get Version)
-        threading.Timer(SDUINO_INIT_WAIT, self._start_init).start()
+        self._init_timer_start = threading.Timer(SDUINO_INIT_WAIT, self._start_init)
+        self._init_timer_start.start()
 
     def _send_xq(self) -> None:
+        if self._stop_event.is_set():
+            return
         try:
             self.logger.debug("Sending XQ to disable receiver during init")
             self.commands.disable_receiver()
         except Exception as e:
             self.logger.warning("Failed to send XQ: %s", e)
 
     def _start_init(self) -> None:
+        if self._stop_event.is_set():
+            return
+
         self.logger.info("StartInit, get version, retry = %d", self.init_retry_count)
 
         if self.init_retry_count == 0:
@@ -160,6 +225,9 @@ def _start_init(self) -> None:
         self._check_version_resp(response)
 
     def _check_version_resp(self, msg: Optional[str]) -> None:
+        if self._stop_event.is_set():
+            return
+
         if msg:
             self.logger.info("Initialized %s", msg.strip())
             self.init_reset_flag = False
@@ -263,6 +331,8 @@ def _parser_loop(self) -> None:
             except queue.Empty:
                 continue
             except Exception:
+                import traceback
+                traceback.print_exc()
                 if not self._stop_event.is_set():
                     self.logger.exception("Unhandled exception in parser loop")
         self.logger.debug("Parser loop finished.")
@@ -422,7 +492,7 @@ def _publish_status_heartbeat(self) -> None:
         try:
             # 1. Heartbeat/Alive message (Retain: True)
             self.mqtt_publisher.publish_simple("status/alive", "online", retain=True)
-            self.logger.debug("Published heartbeat status.")
+            self.logger.info("Heartbeat executed. Status: alive")
 
             # 2. Status data (version, ram, uptime)
             # Fetch data from device (non-blocking call, runs in timer thread)
@@ -443,6 +513,13 @@ def _publish_status_heartbeat(self) -> None:
             except Exception as e:
                 self.logger.warning("Could not get free RAM for heartbeat: %s", e)
                 status_data["free_ram"] = "error"
+                # NEU: Wenn Heartbeat wegen Verbindungsfehler fehlschlägt, überprüfen und Disconnect initiieren.
+                # Dies ist der erste Schritt zur Selbstheilung / Reconnect-Vorbereitung.
+                if not self.transport.is_open and not self._stop_event.is_set():
+                    self.logger.error(
+                        "Heartbeat failed: Transport is closed. Triggering disconnect to stop worker threads."
+                    )
+                    self.disconnect(reconnect=True) # Stoppt Threads, setzt self._stop_event, erlaubt Reconnect
 
             # Uptime
             try:
@@ -455,6 +532,12 @@ def _publish_status_heartbeat(self) -> None:
             except Exception as e:
                 self.logger.warning("Could not get uptime for heartbeat: %s", e)
                 status_data["uptime"] = "error"
+                # NEU: Auch hier prüfen und Disconnect initiieren, falls Verbindung noch nicht bemerkt wurde
+                if not self.transport.is_open and not self._stop_event.is_set():
+                    self.logger.error(
+                        "Heartbeat failed: Transport is closed. Triggering disconnect to stop worker threads."
+                    )
+                    self.disconnect(reconnect=True) # Stoppt Threads, setzt self._stop_event, erlaubt Reconnect
 
             # Publish all collected data to a single status/data topic
             if status_data:

signalduino/parser/__init__.py

@@ -26,6 +26,7 @@ def __init__(
     ):
         self.protocols = protocols or SDProtocols()
         self.logger = logger or logging.getLogger(__name__)
+        self.protocols.register_log_callback(self._log_adapter)
         self.rfmode = rfmode
         self.ms_parser = MSParser(self.protocols, self.logger)
         self.mu_parser = MUParser(self.protocols, self.logger)
@@ -47,6 +48,20 @@ def parse_line(self, line: str) -> List[DecodedMessage]:
 
         return list(parser.parse(frame))
 
+    def _log_adapter(self, message: str, level: int):
+        """Adapts SDProtocols custom log levels to python logging."""
+        # FHEM levels: 1=Error, 2=Warn, 3=Info, 4=More Info, 5=Debug
+        if level <= 1:
+            self.logger.error(message)
+        elif level == 2:
+            self.logger.warning(message)
+        elif level == 3:
+            self.logger.info(message)
+        elif level == 4:
+            self.logger.debug(message) # or info? keeping debug for now
+        else:
+            self.logger.debug(message)
+
     def _select_parser(self, message_type: str | None):
         if not message_type:
             return None

signalduino/transport.py

@@ -84,7 +84,7 @@ def readline(self, timeout: Optional[float] = None) -> Optional[str]:
 class TCPTransport(BaseTransport):
     """TCP transport talking to firmware via sockets."""
 
-    def __init__(self, host: str, port: int, read_timeout: float = 0.5):
+    def __init__(self, host: str, port: int, read_timeout: float = 10.0):
         self.host = host
         self.port = port
         self.read_timeout = read_timeout