feat: more robust connect and initalisation

sidey79 · sidey79 · commit c593e9c464ff · 2025-12-06T01:11:19.000Z
diff --git a/main.py b/main.py
@@ -26,6 +26,8 @@ def initialize_logging(log_level_str: str):
             logging.StreamHandler(sys.stdout)
         ]
     )
+    # Setze den Level auch auf den Root-Logger, falls basicConfig ihn nicht korrekt gesetzt hat (z.B. bei wiederholtem Aufruf)
+    logging.getLogger().setLevel(level)
 
 # Initialisiere das Logging mit dem LOG_LEVEL aus der Umgebungsvariable (falls vorhanden)
 initialize_logging(os.environ.get("LOG_LEVEL", "INFO"))
@@ -86,6 +88,8 @@ def main():
     # Logging Einstellung
     parser.add_argument("--log-level", default=DEFAULT_LOG_LEVEL, choices=["DEBUG", "INFO", "WARNING", "ERROR", "CRITICAL"], help=f"Logging Level. Standard: {DEFAULT_LOG_LEVEL}")
     
+    parser.add_argument("--timeout", type=int, default=None, help="Beendet das Programm nach N Sekunden (optional)")
+    
     args = parser.parse_args()
 
     # Logging Level anpassen (aus CLI oder ENV Default)
@@ -129,28 +133,28 @@ def signal_handler(sig, frame):
     try:
         logger.info("Verbinde zum Signalduino...")
         controller.connect()
-        logger.info("Verbunden! Drücke Ctrl+C zum Beenden.")
+        logger.info("Verbunden! Starte Initialisierung...")
+        
+        # Starte Initialisierung, welche die Versionsabfrage inkl. Retry-Logik durchführt
+        controller.initialize()
+        logger.info("Initialisierung abgeschlossen! Drücke Ctrl+C zum Beenden.")
         
-        # Sende Versionsabfrage zum Test
-        logger.info("Sende Versionsabfrage (V)...")
-        # Perl regex: 'V\s.*SIGNAL(?:duino|ESP|STM).*(?:\s\d\d:\d\d:\d\d)'
-        version_pattern = re.compile(
-            r"V\s.*SIGNAL(?:duino|ESP|STM).*", re.IGNORECASE
-        )
-        version = controller.send_command(
-            "V",
-            expect_response=True,
-            timeout=15.0,  # Erhöhe den Timeout für den initialen V-Befehl
-            response_pattern=version_pattern,
-        )
-        if version:
-            logger.info(f"Signalduino Version: {version.strip()}")
-        else:
-            logger.warning("Keine Antwort auf Versionsabfrage erhalten.")
-
         # Hauptschleife
-        while True:
-            time.sleep(1)
+        if args.timeout is not None:
+            logger.info(f"Programm wird nach {args.timeout} Sekunden beendet.")
+            start_time = time.time()
+            # Der `while` Block mit `time.sleep(0.1)` wird verwendet, um auf das Timeout zu warten,
+            # während das Controller-Thread im Hintergrund Nachrichten verarbeitet.
+            while (time.time() - start_time) < args.timeout:
+                time.sleep(0.1)
+            # Timeout erreicht, Controller trennen (signal_handler wird nicht aufgerufen)
+            logger.info("Timeout erreicht. Programm wird beendet.")
+            controller.disconnect()
+            sys.exit(0)
+        else:
+            # Endlosschleife, wenn kein Timeout gesetzt ist
+            while True:
+                time.sleep(1)
 
     except Exception as e:
         logger.error(f"Ein Fehler ist aufgetreten: {e}", exc_info=True)
diff --git a/signalduino/controller.py b/signalduino/controller.py
@@ -6,7 +6,12 @@
 from datetime import datetime, timedelta, timezone
 from typing import Any, Callable, List, Literal, Optional, Pattern
 
-from .constants import SDUINO_CMD_TIMEOUT
+from .constants import (
+    SDUINO_CMD_TIMEOUT,
+    SDUINO_INIT_MAXRETRY,
+    SDUINO_INIT_WAIT,
+    SDUINO_INIT_WAIT_XQ,
+)
 from .exceptions import SignalduinoCommandTimeout, SignalduinoConnectionError
 from .mqtt import MqttPublisher # NEU: MQTT-Import
 from .parser import SignalParser
@@ -46,6 +51,9 @@ def __init__(
         self._pending_responses: List[PendingResponse] = []
         self._pending_responses_lock = threading.Lock()
 
+        self.init_retry_count = 0
+        self.init_reset_flag = False
+
     def connect(self) -> None:
         """Opens the transport and starts the worker threads."""
         if self.transport.is_open:
@@ -96,6 +104,92 @@ def disconnect(self) -> None:
         self.transport.close()
         self.logger.info("Transport closed.")
 
+    def initialize(self) -> None:
+        """Starts the initialization process."""
+        self.logger.info("Initializing device...")
+        self.init_retry_count = 0
+        self.init_reset_flag = False
+
+        # Schedule Disable Receiver (XQ) and wait briefly
+        threading.Timer(SDUINO_INIT_WAIT_XQ, self._send_xq).start()
+        
+        # Schedule StartInit (Get Version)
+        threading.Timer(SDUINO_INIT_WAIT, self._start_init).start()
+
+    def _send_xq(self) -> None:
+        try:
+            self.logger.debug("Sending XQ to disable receiver during init")
+            self.send_command("XQ", expect_response=False)
+        except Exception as e:
+            self.logger.warning("Failed to send XQ: %s", e)
+
+    def _start_init(self) -> None:
+        self.logger.info("StartInit, get version, retry = %d", self.init_retry_count)
+
+        if self.init_retry_count == 0:
+            # First attempt: XQ is sent via a separate timer in initialize(), no blocking wait here.
+            pass
+
+        if self.init_retry_count >= SDUINO_INIT_MAXRETRY:
+            if not self.init_reset_flag:
+                self.logger.warning("StartInit, retry count reached. Resetting device.")
+                self.init_reset_flag = True
+                self._reset_device()
+            else:
+                self.logger.error("StartInit, retry count reached after reset. Closing device.")
+                self.disconnect()
+            return
+
+        response = None
+        try:
+            # Perl Regex: 'V\s.*SIGNAL(?:duino|ESP|STM).*(?:\s\d\d:\d\d:\d\d)'
+            version_pattern = re.compile(r"V\s.*SIGNAL(?:duino|ESP|STM).*", re.IGNORECASE)
+            # Use a short timeout here to speed up failed attempts
+            response = self.send_command(
+                "V",
+                expect_response=True,
+                timeout=2.0, # Shorter timeout for retries
+                response_pattern=version_pattern,
+            )
+        except Exception as e:
+            self.logger.debug("StartInit: Exception during version check: %s", e)
+
+        self._check_version_resp(response)
+
+    def _check_version_resp(self, msg: Optional[str]) -> None:
+        if msg:
+            self.logger.info("Initialized %s", msg.strip())
+            self.init_reset_flag = False
+            self.init_retry_count = 0
+
+            # Enable Receiver XE
+            try:
+                self.logger.info("Enabling receiver (XE)")
+                self.send_command("XE", expect_response=False)
+            except Exception as e:
+                self.logger.warning("Failed to enable receiver: %s", e)
+
+            # Check for CC1101
+            if "cc1101" in msg.lower():
+                self.logger.info("CC1101 detected")
+                # Here we could query ccconf and ccpatable like in Perl
+        else:
+            self.logger.warning("StartInit: No valid version response.")
+            self.init_retry_count += 1
+            # Retry initialization
+            self._start_init()
+
+    def _reset_device(self) -> None:
+        self.logger.info("Resetting device...")
+        try:
+            self.disconnect()
+            # Wait briefly to ensure port is released/device resets
+            threading.Event().wait(2.0)
+            self.connect()
+            self.initialize()
+        except Exception as e:
+            self.logger.error("Failed to reset device: %s", e)
+
     def _reader_loop(self) -> None:
         """Continuously reads from the transport and puts lines into a queue."""
         self.logger.debug("Reader loop started.")
@@ -123,10 +217,17 @@ def _parser_loop(self) -> None:
                 if not raw_line or self._stop_event.is_set():
                     continue
 
-                if self._handle_as_command_response(raw_line.strip()):
+                line_data = raw_line.strip()
+                
+                if self._handle_as_command_response(line_data):
+                    continue
+
+                if line_data.startswith("XQ") or line_data.startswith("XR"):
+                    # Abfangen der Receiver-Statusmeldungen XQ/XR (wie in Perl /^XQ/ und /^XR/)
+                    self.logger.debug("Found receiver status: %s", line_data)
                     continue
 
-                decoded_messages = self.parser.parse_line(raw_line)
+                decoded_messages = self.parser.parse_line(line_data)
                 for message in decoded_messages:
                     if self.mqtt_publisher:
                         try:
@@ -228,7 +329,7 @@ def set_message_type_enabled(
             raise ValueError(f"Invalid message type: {message_type}")
 
         verb = "E" if enabled else "D"
-        noun = message_type  # S, U, or C
+        noun = message_type[-1]  # S, U, or C
         command = f"C{verb}{noun}"
         self.send_command(command)
 
diff --git a/tests/test_controller.py b/tests/test_controller.py
@@ -141,4 +141,60 @@ def readline_side_effect():
     try:
         callback_mock.assert_called_once_with(decoded_msg)
     finally:
+        controller.disconnect()
+
+
+def test_initialize_retry_logic(mock_transport, mock_parser):
+    """Test the retry logic during initialization."""
+    controller = SignalduinoController(transport=mock_transport, parser=mock_parser)
+    controller.connect()
+
+    # Mock send_command to fail initially and then succeed
+    call_count = 0
+
+    def side_effect(*args, **kwargs):
+        nonlocal call_count
+        call_count += 1
+        payload = kwargs.get("payload") or args[0] if args else None
+        
+        if payload == "XQ":
+            return None
+        if payload == "V":
+            if call_count <= 2:  # Fail first attempt (XQ is 1st call)
+                raise SignalduinoCommandTimeout("Timeout")
+            return "V 3.5.0-dev SIGNALduino"
+        return None
+
+    controller.send_command = Mock(side_effect=side_effect)
+
+    # Use very short intervals for testing by patching the imported constants in the controller module
+    import signalduino.controller
+    
+    original_wait = signalduino.controller.SDUINO_INIT_WAIT
+    original_wait_xq = signalduino.controller.SDUINO_INIT_WAIT_XQ
+    
+    signalduino.controller.SDUINO_INIT_WAIT = 0.1
+    signalduino.controller.SDUINO_INIT_WAIT_XQ = 0.05
+
+    try:
+        controller.initialize()
+        time.sleep(1.5)  # Wait for timers and retries
+
+        # Verify calls:
+        # 1. XQ
+        # 2. V (fails)
+        # 3. V (retry, succeeds)
+        # 4. XE (enabled after success)
+        
+        # Note: Depending on timing and implementation details, call count might vary slighty
+        # but we expect at least XQ, failed V, successful V, XE.
+        
+        calls = [c.kwargs.get('payload') or c.args[0] for c in controller.send_command.call_args_list]
+        assert "XQ" in calls
+        assert calls.count("V") >= 2
+        assert "XE" in calls
+
+    finally:
+        signalduino.controller.SDUINO_INIT_WAIT = original_wait
+        signalduino.controller.SDUINO_INIT_WAIT_XQ = original_wait_xq
         controller.disconnect()
