Start improving high-throughput multi-camera recording path and diagnostics

.gitignore

@@ -113,3 +113,8 @@ venv.bak/
 !dlclivegui/config.py
 # uv package files
 uv.lock
+
+# profiling
+profile*.svg
+scalene*.json
+scalene*.html

dlclivegui/cameras/backends/basler_backend.py

@@ -9,7 +9,7 @@
 
 import numpy as np
 
-from ...config import BASLER_DO_LOG_TIMING, CameraTriggerSettings
+from ...config import BASLER_DO_LOG_TIMING, DEBUG_TRIGGER_LOGS, CameraTriggerSettings
 from ...utils.stats import WorkerTimingStats
 from ..base import CameraBackend, SupportLevel, register_backend
 
@@ -51,6 +51,7 @@ def __init__(self, settings):
         )
         self._camera_pixel_format: str | None = None
         self._logged_first_frame: bool = False
+        self._debug_last_acquis_stats_log: float = 0.0
 
         # Optional fast-start hint for probe workers
         # (may skip StartGrabbing and converter setup for faster capability probing; not suitable for normal capture)
@@ -638,7 +639,8 @@ def open(self) -> None:
                 pass
 
             self._camera.StartGrabbing(
-                pylon.GrabStrategy_LatestImageOnly,
+                # pylon.GrabStrategy_LatestImageOnly,
+                pylon.GrabStrategy_OneByOne,
             )
             LOG.info(
                 "[Basler] grabbing=%s max_buffers=%s",
@@ -661,7 +663,7 @@ def open(self) -> None:
         )
 
         # ----------------------------
-        # Persist stable identity into namespace (migration-safe)
+        # Persist stable identity into namespace
         # ----------------------------
         try:
             serial = device.GetSerialNumber()
@@ -722,6 +724,8 @@ def read(self) -> tuple[np.ndarray, float]:
                 grab_result.Release()
                 grab_result = None
 
+            self._debug_log_acquisition_stats(context="after frame read")
+
             if self._actual_width is None or self._actual_height is None:
                 h, w = frame.shape[:2]
                 self._actual_width = int(w)
@@ -746,6 +750,8 @@ def read(self) -> tuple[np.ndarray, float]:
 
             self._timing.note_error()
             self._timing.maybe_log()
+            self._debug_log_acquisition_stats(context=f"after frame read error: {type(exc).__name__}")
+
             raise RuntimeError("Failed to retrieve image from Basler camera.") from exc
 
     def close(self) -> None:
@@ -957,7 +963,57 @@ def _set_numeric_feature(self, name: str, value, *, strict: bool = False) -> boo
             LOG.warning("Failed to set Basler feature '%s' to '%s': %s", name, value, exc)
             return False
 
+    def _debug_log_acquisition_stats(
+        self,
+        *,
+        context: str,
+        force: bool = False,
+    ) -> None:
+        if not BASLER_DO_LOG_TIMING or not LOG.isEnabledFor(logging.DEBUG):
+            return
+
+        now = time.monotonic()
+        if not force and now - self._debug_last_acquisition_stats_log < 1.0:
+            return
+
+        self._debug_last_acquisition_stats_log = now
+        stats = self._debug_read_acquisition_stats()
+        if stats:
+            LOG.debug(
+                "[Basler] acquisition stats context=%s values=%s",
+                context,
+                stats,
+            )
+
+    def _debug_read_acquisition_stats(self) -> dict[str, int]:
+        cam = self._camera
+        if cam is None or not cam.IsGrabbing():
+            return {}
+
+        stats: dict[str, int] = {}
+        for name in ("NumReadyBuffers", "NumQueuedBuffers", "MaxNumBuffer"):
+            try:
+                stats[name] = int(getattr(cam, name).GetValue())
+            except Exception:
+                pass
+
+        try:
+            sg = cam.StreamGrabber
+            for name in (
+                "Statistic_Buffer_Underrun_Count",
+                "Statistic_Missed_Frame_Count",
+                "Statistic_Failed_Buffer_Count",
+            ):
+                stats[name] = int(getattr(sg, name).GetValue())
+        except Exception:
+            pass
+
+        return stats
+
     def _debug_trigger_nodes(self, *, context: str = "") -> None:
+        if not LOG.isEnabledFor(logging.DEBUG) or not DEBUG_TRIGGER_LOGS:
+            return
+
         names = (
             "TriggerSelector",
             "TriggerMode",

dlclivegui/cameras/backends/gentl_backend.py

@@ -12,7 +12,7 @@
 import cv2
 import numpy as np
 
-from ...config import CameraTriggerSettings
+from ...config import DEBUG_TRIGGER_LOGS, CameraTriggerSettings
 from ..base import CameraBackend, SupportLevel, register_backend
 from ..factory import DetectedCamera
 from .utils import gentl_discovery as cti_finder
@@ -199,6 +199,9 @@ def static_capabilities(cls) -> dict[str, SupportLevel]:
         }
 
     def _debug_trigger_nodes(self, node_map, *, context: str = "") -> None:
+        if not LOG.isEnabledFor(logging.DEBUG) or not DEBUG_TRIGGER_LOGS:
+            return
+
         names = (
             "TriggerMode",
             "TriggerSelector",

dlclivegui/config.py

@@ -31,6 +31,8 @@
 SINGLE_CAMERA_WORKER_DO_LOG_TIMING: bool = False
 MULTI_CAMERA_WORKER_DO_LOG_TIMING: bool = False
 REC_DO_LOG_TIMING: bool = False
+### Trigger debug logging
+DEBUG_TRIGGER_LOGS = False
 # MAIN_WINDOW_DO_LOG_TIMING: bool = False
 #### Backends
 BASLER_DO_LOG_TIMING: bool = False