diff --git a/apps/studio/config/locales/en_US.json b/apps/studio/config/locales/en_US.json index c09a113..bcd5cbd 100644 --- a/apps/studio/config/locales/en_US.json +++ b/apps/studio/config/locales/en_US.json @@ -356,6 +356,7 @@ "samples_dropped": "Record buffer is full; the oldest {count} samples were released (the full session is no longer complete)", "run_failed": "Run failed: {error}", "filters_saved": "Filter settings saved: {describe} (applies to the next session)", + "rail_camera_fps": "camera {fps}", "video_ended": "Video ended", "camera_disconnected": "Camera disconnected", "reset_ok": "Tracker reset", diff --git a/apps/studio/config/locales/zh_CN.json b/apps/studio/config/locales/zh_CN.json index 54d344b..993af71 100644 --- a/apps/studio/config/locales/zh_CN.json +++ b/apps/studio/config/locales/zh_CN.json @@ -356,6 +356,7 @@ "samples_dropped": "记录缓冲已达上限，最早的 {count} 个样本已被释放（全程记录不再完整）", "run_failed": "启动失败: {error}", "filters_saved": "滤波设置已保存：{describe}（下次采集生效）", + "rail_camera_fps": "摄像头 {fps}", "video_ended": "视频已结束", "camera_disconnected": "摄像机已断开", "reset_ok": "追踪器已重置", diff --git a/apps/studio/src/orisys_studio/app_window.py b/apps/studio/src/orisys_studio/app_window.py index c039080..f633515 100644 --- a/apps/studio/src/orisys_studio/app_window.py +++ b/apps/studio/src/orisys_studio/app_window.py @@ -200,6 +200,10 @@ class StudioMainWindow(QMainWindow): #: What the last frame cost to acquire and process, in milliseconds — the #: other half of the frame-rate reading. self._latest_process_ms: float | None = None + #: The capture source's own published rate and shortfall, over the same + #: window: together with the above they say who is the slow part. + self._latest_capture_fps: float = 0.0 + self._latest_capture_dropped: int = 0 #: Last coefficients file written by the calibration panel (not applied). self._last_calibration_export = "" self._depth_range_value: tuple[float, float] | None = None @@ -1365,6 +1369,13 @@ class StudioMainWindow(QMainWindow): # cannot keep up, and only this number tells the two apart. if self._latest_process_ms: fps = f"{fps} · {self._latest_process_ms:.0f} ms" + # ...and the camera's own rate settles it: a capture rate well above + # what we consumed means the frames were there and we did not take + # them (the drop counter says how many). + if self._latest_capture_fps: + fps = f"{fps} · {t('status.rail_camera_fps', fps=f'{self._latest_capture_fps:.1f}')}" + if self._latest_capture_dropped: + fps = f"{fps} (-{self._latest_capture_dropped})" detail = f"{detail} · {fps}" if detail else fps self.toolbar.set_source_summary(detail) # The full path and the replay's notes do not fit on a 30 px rail, so @@ -2120,6 +2131,8 @@ class StudioMainWindow(QMainWindow): self._last_sample_valid = None self._latest_fps = None self._latest_process_ms = None + self._latest_capture_fps = 0.0 + self._latest_capture_dropped = 0 self._depth_range_value = None self._last_depth_frame = None # The new session's store is cleared *before* the charts are attached to @@ -2207,6 +2220,8 @@ class StudioMainWindow(QMainWindow): self.arrow_panel.clear_preview(t("panels.arrow_empty")) self._latest_fps = None self._latest_process_ms = None + self._latest_capture_fps = 0.0 + self._latest_capture_dropped = 0 self._last_sample_valid = None self._last_display_fallback = None self._last_display_available = None @@ -2376,6 +2391,10 @@ class StudioMainWindow(QMainWindow): if is_new: self._latest_fps = getattr(packet, "fps", None) self._latest_process_ms = getattr(packet, "process_ms", None) + self._latest_capture_fps = float(getattr(packet, "capture_fps", 0.0) or 0.0) + self._latest_capture_dropped = int( + getattr(packet, "capture_dropped", 0) or 0 + ) # The rail carries the live telemetry (fps, validity, calibration) and # the record strip its own numbers. Both compare before repainting, so # this is safe on a 16 ms timer. diff --git a/shared/src/orisys_app_shared/acquisition/models.py b/shared/src/orisys_app_shared/acquisition/models.py index 50d7b88..1b9127b 100644 --- a/shared/src/orisys_app_shared/acquisition/models.py +++ b/shared/src/orisys_app_shared/acquisition/models.py @@ -41,6 +41,12 @@ class SdkPacket: timestamp: float fps: float process_ms: float + #: The rate the *capture source* published frames at, over the same window as + #: ``fps``. ``fps`` is what this loop consumed; when the two disagree, the + #: difference is frames the camera had and the loop did not take. + capture_fps: float = 0.0 + #: How many published frames were replaced before anyone consumed them. + capture_dropped: int = 0 normal_force: float = 0.0 shear_x: float = 0.0 shear_y: float = 0.0 diff --git a/shared/src/orisys_app_shared/acquisition/sdk_worker.py b/shared/src/orisys_app_shared/acquisition/sdk_worker.py index 5591490..b43b8a7 100644 --- a/shared/src/orisys_app_shared/acquisition/sdk_worker.py +++ b/shared/src/orisys_app_shared/acquisition/sdk_worker.py @@ -123,9 +123,7 @@ def _capture_sequence(sensor) -> Optional[int]: every call decodes the next frame, so its counter says nothing about repeats and is ignored (``None``). """ - source = getattr(sensor, "capture_source", None) - if source is None: - source = getattr(sensor, "_capture_source", None) + source = _capture_source(sensor) if source is None or not bool(getattr(source, "running", False)): return None status = getattr(source, "status", None) @@ -135,6 +133,28 @@ def _capture_sequence(sensor) -> Optional[int]: return None +def _capture_dropped(sensor) -> Optional[int]: + """Frames the capture source published that nobody took in time. + + The SDK's background reader counts one of these every time it replaces a + frame that was never consumed, so this is the consumer's shortfall — the + number that says "the camera had it and we did not take it". + """ + source = _capture_source(sensor) + status = getattr(source, "status", None) if source is not None else None + try: + return int(getattr(status, "dropped_frames")) + except (TypeError, ValueError): + return None + + +def _capture_source(sensor): + source = getattr(sensor, "capture_source", None) + if source is None: + source = getattr(sensor, "_capture_source", None) + return source + + def process_chain(sensor) -> tuple[Optional[np.ndarray], str]: """Run the live processing chain for one already-read frame. @@ -714,6 +734,13 @@ class SdkAcquisitionWorker(RecordSinkMixin): #: When that frame arrived, and how far apart this device's frames are #: meant to be: the wait below never steps over the next frame's arrival. last_frame_at = 0.0 + #: ``(collection time, published sequence)`` over the same window as + #: ``frame_times``. The sequence advances whenever the *capture source* + #: publishes, whether or not this loop takes the frame, so comparing the + #: two rates says whether a low frame rate is the camera's or ours. + source_times: list[tuple[float, int]] = [] + source_dropped = 0 + last_source_seq: Optional[int] = None frame_period = 1.0 / max(1.0, float(mode.fps or 30.0)) # Per-session monotonic frame index: the join key shared by the video, # the CSV and the calibration records. @@ -748,6 +775,17 @@ class SdkAcquisitionWorker(RecordSinkMixin): # without a background reader (a video file) decodes a new frame # per call, so it has no repeat marker and is left alone. delivered = _capture_sequence(sensor) + if delivered is not None and delivered != last_source_seq: + # Bookkeeping per *published* frame, not per poll: this branch + # is entered many times while waiting, and a list comprehension + # on every one of them starves the capture thread of the GIL + # (measured: the fake camera's own 30 fps dropped to 8). + last_source_seq = delivered + source_times.append((t0, delivered)) + source_cutoff = t0 - FPS_WINDOW_S + source_times = [ + item for item in source_times if item[0] >= source_cutoff + ] if delivered is not None and delivered == last_delivered: # Wait for the next frame, but never *past* the moment it is # due: sleeping a whole timer tick before looking again is how @@ -820,6 +858,17 @@ class SdkAcquisitionWorker(RecordSinkMixin): # number that says whether the loop can still keep up with the # device, which the frame rate alone cannot. t_done = time.perf_counter() + # What the capture source published over the window, so a rate + # below the camera's own can be attributed instead of guessed. + capture_fps = 0.0 + if len(source_times) > 1: + source_span = source_times[-1][0] - source_times[0][0] + published = source_times[-1][1] - source_times[0][1] + if source_span > 0.0: + capture_fps = max(0.0, published / source_span) + taken = _capture_dropped(sensor) + if taken is not None: + source_dropped = taken invalid_reason = forces.get("invalid_reason") or compute_error raw_frame = _ensure_bgr(raw) # The frame the chain above actually consumed, kept as the @@ -842,6 +891,8 @@ class SdkAcquisitionWorker(RecordSinkMixin): ), fps=fps, process_ms=(t_done - t0) * 1000.0, + capture_fps=capture_fps, + capture_dropped=source_dropped, normal_force=forces["normal_force"], shear_x=forces["shear_x"], shear_y=forces["shear_y"], diff --git a/shared/tests/test_worker_frame_rate.py b/shared/tests/test_worker_frame_rate.py index 14fc06c..18bcf8d 100644 --- a/shared/tests/test_worker_frame_rate.py +++ b/shared/tests/test_worker_frame_rate.py @@ -38,7 +38,9 @@ class _CaptureSource: The real one is a thread too: the sequence advances whether or not the consumer asks for a frame, which is exactly why an unchanged sequence means - "no new frame" rather than "the consumer has not called yet". + "no new frame" rather than "the consumer has not called yet". It also counts + a drop whenever it replaces a frame nobody took, like + ``orisys.capture.source.CaptureSource._background_loop`` does. """ def __init__(self, period_s: float = FRAME_PERIOD_S) -> None: @@ -46,6 +48,7 @@ class _CaptureSource: self.running = True self._period = float(period_s) self._stop = threading.Event() + self._taken_seq = 0 self._thread = threading.Thread(target=self._publish, daemon=True) self._thread.start() @@ -53,14 +56,25 @@ class _CaptureSource: while not self._stop.is_set(): if self._stop.wait(timeout=self._period): return + # Replacing a frame that was never consumed is a drop on our side. + if self.status.last_seq > self._taken_seq: + self.status.dropped_frames += 1 self.status.last_seq += 1 + def take(self) -> None: + self._taken_seq = self.status.last_seq + def close(self) -> None: self.running = False self._stop.set() self._thread.join(timeout=1.0) +#: Per-frame processing cost the fake device charges, so a test can make the +#: pipeline slower than the camera (the real box chain costs ~10 ms at 480p). +PROCESS_COST_S = 0.0 + + class _Info: """The channel names the worker reads off ``sensor.info``.""" @@ -105,7 +119,11 @@ class _Sensor: def get_img(self): # ``read_latest``: hand back the newest frame immediately, the same one - # again when nothing new has arrived. + # again when nothing new has arrived. A test can make this cost time, so + # the loop can be put under a pipeline slower than the camera. + if PROCESS_COST_S > 0: + time.sleep(PROCESS_COST_S) + self.capture_source.take() return self.frame def disconnect(self): @@ -211,6 +229,42 @@ def test_the_reported_rate_is_the_delivered_rate(): assert abs(settled[-1] - measured) < 0.25 * measured, (settled[-1], measured) +def test_the_camera_s_own_rate_is_reported_next_to_ours(monkeypatch): + """A low frame rate must be attributable, not just visible. + + With a pipeline that fits the frame period the two rates agree. With one that + does not, the *camera's* rate stays at 30 while ours falls and the source + counts the frames nobody took — which is the whole difference between "the + camera is slow" and "we are slow". + """ + packets, _ = _collect(duration_s=1.5) + assert packets, "the loop emitted nothing at all" + camera = [float(packet.capture_fps) for packet in packets if packet.capture_fps] + assert camera, "no packet carried the capture source's own rate" + assert 28.0 <= camera[-1] <= 31.0, f"the fake camera publishes at 30 fps, got {camera[-1]}" + assert packets[-1].capture_dropped == 0, ( + f"the loop dropped {packets[-1].capture_dropped} frames while keeping up" + ) + + # Now make the pipeline three times slower than the camera's own period. + monkeypatch.setattr(sys.modules[__name__], "PROCESS_COST_S", 0.06) + slow, _ = _collect(duration_s=2.0) + try: + assert slow, "the loop emitted nothing at all" + ours = _rate(slow) + assert ours < 22.0, f"a 60 ms pipeline still kept up at {ours:.1f} fps" + assert 28.0 <= float(slow[-1].capture_fps) <= 31.0, ( + "the camera's rate was reported as slow too: " + f"{slow[-1].capture_fps}" + ) + assert slow[-1].capture_dropped > 5, ( + "the loop fell behind without recording a single dropped frame: " + f"{slow[-1].capture_dropped}" + ) + finally: + monkeypatch.setattr(sys.modules[__name__], "PROCESS_COST_S", 0.0) + + def test_a_file_source_runs_on_the_video_s_own_timeline(): """A pass over a video is stamped with the video's time, not the wall clock.""" from orisys_app_shared.acquisition.sdk_worker import SdkAcquisitionWorker