fix long and slow commands

src/ntfc/command_builder.py

@@ -198,7 +198,11 @@ def _build_expect_pattern(
         items = expects if regexp else [re.escape(e) for e in expects]
 
         if match_all:
-            return "".join(f"(?=.*{item})" for item in items)
+            # Anchor the lookaheads so the engine evaluates them once from
+            # the start of the buffer. Unanchored, re.search retries them
+            # at every position and each scans to the end: quadratic in
+            # the buffer size, tens of seconds on a 100 KB console dump.
+            return "^" + "".join(f"(?=.*{item})" for item in items)
         return rf"({'|'.join(items)})"
 
     def _default_prompt_pattern(self, cmd: str, flag: str = "") -> str:

src/ntfc/device/common.py

@@ -52,6 +52,7 @@ class DeviceCommon(ABC):
 
     _BUSY_LOOP_TIMEOUT = 180  # 180 sec with no data read from target
     _OUTPUT_TAIL_MAX = 4 * 1024 * 1024
+    _FLOOD_DETECT_TIME = 10  # sec of uninterrupted output after a timeout
 
     def __init__(self, conf: "CoreConfig", echo: bool = True):
         """Initialize common device."""
@@ -306,15 +307,23 @@ def _read_until_pattern_loop(  # noqa: C901
                 break
 
         # check for output flood condition.
-        # If we still get some data from dev, its possible that we stuck
-        # in some command
+        # A slow command can still be printing when the timeout expires,
+        # so keep reading until the device goes quiet. Only a device that
+        # never stops printing is flooding (stuck in some command).
         if ret == CmdStatus.TIMEOUT:
-            chunk = self._read_all(0.1)
-            if len(chunk) > 0:
+            flood_end = time.time() + self._FLOOD_DETECT_TIME
+            flood = True
+            while time.time() < flood_end:
+                chunk = self._read_all(self._read_all_sleep)
+                self._console_log(chunk)
+                if not chunk:
+                    flood = False
+                    break
+
+            if flood:
                 if not self._state_mgr.is_unhealthy():
                     self._log_device_event("fault detected: flood")
                 self._state_mgr.set_unhealthy("Flood detected")
-            self._console_log(chunk)
 
         return CmdReturn(ret, _match, output.decode("utf-8", errors="replace"))
 

tests/device/test_common.py

@@ -20,6 +20,7 @@
 
 import os
 import tempfile
+import time
 from types import SimpleNamespace
 from unittest.mock import patch
 
@@ -29,6 +30,7 @@
 from ntfc.log.handler import LogHandler
 
 g_mock_read = b""
+g_mock_read_until = None
 
 
 class DeviceMock(DeviceCommon):
@@ -44,6 +46,8 @@ def __init__(self, config):
 
     def _read(self, _=0):
         """Mock."""
+        if g_mock_read_until is not None and time.time() > g_mock_read_until:
+            return b""
         return g_mock_read
 
     def _write(self, _):
@@ -120,6 +124,7 @@ def test_device_common_send_cmd_pattern():
         config = mockdevice.return_value
 
         dev = DeviceMock(config)
+        dev._FLOOD_DETECT_TIME = 0.5
         assert dev is not None
 
         assert dev.flood is False
@@ -152,6 +157,31 @@ def test_device_common_send_cmd_pattern():
         assert ret.status == CmdStatus.TIMEOUT
 
 
+def test_device_common_slow_output_is_timeout_not_flood():
+    """Output that still arrives at the timeout but then stops is a TIMEOUT."""
+    with patch("ntfc.envconfig.EnvConfig") as mockdevice:
+
+        global g_mock_read, g_mock_read_until
+
+        config = mockdevice.return_value
+        config.read_poll_interval = 0.05
+        dev = DeviceMock(config)
+        dev._dev_is_health_priv = lambda: True
+
+        # the device keeps printing for 0.5s past the 1s command timeout
+        # and then goes quiet: a slow command, not a stuck one
+        g_mock_read = b"x" * 100
+        g_mock_read_until = time.time() + 1.5
+        try:
+            ret = dev.send_cmd_read_until_pattern(b"", b"y", 1)
+        finally:
+            g_mock_read_until = None
+
+        assert ret.status == CmdStatus.TIMEOUT
+        assert dev.flood is False
+        assert dev.dev_is_health() is True
+
+
 def test_device_common_send_cmd_fail_pattern():
 
     with patch("ntfc.envconfig.EnvConfig") as mockdevice:
@@ -160,6 +190,7 @@ def test_device_common_send_cmd_fail_pattern():
 
         config = mockdevice.return_value
         dev = DeviceMock(config)
+        dev._FLOOD_DETECT_TIME = 0.5
 
         # fail_pattern detected before success pattern → FAILED, exits early
         g_mock_read = b"ERROR: something bad"
@@ -211,6 +242,7 @@ def test_device_common_read_until_pattern():
 
         config = mockdevice.return_value
         dev = DeviceMock(config)
+        dev._FLOOD_DETECT_TIME = 0.5
 
         # success: pattern found in output
         g_mock_read = b"PASS: all tests ok"

tests/test_command_builder.py

@@ -19,6 +19,7 @@
 ############################################################################
 
 import re
+import time
 
 import pytest
 
@@ -61,11 +62,11 @@ def test_build_expect_pattern(builder: CommandBuilder) -> None:
     )
     assert (
         builder._build_expect_pattern(["aaa", "bbb"], True, False)
-        == "(?=.*aaa)(?=.*bbb)"
+        == "^(?=.*aaa)(?=.*bbb)"
     )
     assert (
         builder._build_expect_pattern(["aaa", "bbb"], True, True)
-        == "(?=.*aaa)(?=.*bbb)"
+        == "^(?=.*aaa)(?=.*bbb)"
     )
     assert (
         builder._build_expect_pattern(["aaa", "bbb"], False, True)
@@ -100,6 +101,27 @@ def test_prepare_pattern_with_expects(builder: CommandBuilder) -> None:
     assert re.search(p2, "cmd: command not found")
 
 
+def test_prepare_pattern_match_all_is_linear(builder: CommandBuilder) -> None:
+    """A match_all pattern must not scan the buffer once per position."""
+    p = builder._prepare_pattern(
+        "popen", ["Calling pclose()"], "", True, False
+    )
+    # a device dumping thousands of builtin names before the expected line
+    buf = "    ltp_some_test_case_name_padded_to_width\n" * 5000
+    assert len(buf) > 200000
+
+    t0 = time.time()
+    assert re.search(p, buf) is None
+    assert time.time() - t0 < 0.5
+
+    assert re.search(p, buf + "Calling pclose()\n")
+    assert re.search(p, buf + "popen: command not found\n")
+
+    p2 = builder._prepare_pattern("cmd", ["A", "B"], "", True, False)
+    assert re.search(p2, buf + "B\n" + buf + "A\n")
+    assert re.search(p2, buf + "A\n") is None
+
+
 def test_prepare_pattern_without_expects(builder: CommandBuilder) -> None:
     p = builder._prepare_pattern("cmd", None, "", True, False)
     assert re.search(p, "nsh> ")