帧率读数改为"采集时刻"的到达率,并在旁边显示每帧耗时 - What: sdk_worker 的采集循环里把帧率与时间戳的取样点从"算完之后"(t1) 改成"取到这一帧的时刻"(t0)——frame_times、SIGPkt.mono_t(实时分支)与 last_frame_mono(断线判定)都用 t0,所以 16.7 FPS 现在明确表示"帧是以这个速率到达的",而不是把流水线耗时当成帧率;process_ms 的终点从 process_chain 之后改到 read_forces_from_sensor 之后(t_done),因此它终于涵盖这一帧的**全部**开销(此前漏掉力值读取);last_frame_at 仍取 t1(compute chain 结束)作为节拍相位参考,行为不变(帧率测试仍然通过)。app_window 在 视图▸显示帧率 打开时把每帧耗时一起显示在轨道摘要里:"16.7 FPS · 58 ms",并新增 _latest_process_ms(随会话/回放清空)。tests/test_ui_smoke.py 增加一项断言:轨道同时给出速率与耗时,且没有耗时数据时仍只显示速率。 - Why: 用户看到 Studio 上方显示 16.67 fps 而不是 30,问是不是显示错了。查证结论:这个数字来自 packet.fps,是采集循环真实的"到达率",记录里的行数也是它——不是界面 bug;但它有两个缺陷让这个数字**无法单独判读**:(1) 取样点在算完之后,于是它把本机流水线耗时混进了"设备帧率";(2) 旁边没有每帧耗时,而"16.7 FPS"既可能是摄像头只给 16.7,也可能是流水线跟不上 30(实测:每帧 ≤30 ms 时循环仍能跑满 29.3 fps;40/50/60/70 ms 分别掉到 24.7/19.8/16.5/14.1 fps——16.67 恰好对应每帧约 60 ms)。本机 app 配置(365x365 拼接、dis_mode=3)在 480p 素材上 process_chain+力值读取只要 ~10 ms(上限约 100 fps),因此本次报的 16.67 不可能是这台机器上这个配置的流水线瓶颈;两种可能必须靠耗时数据区分。 - Verification: pytest shared/tests/test_worker_frame_rate.py 4 项全过(30 fps 设备仍被消费在 29.3 fps);studio 全量 90 passed(新增 1 项);ui_check 554 项检查 0 失败;真实 SDK 复测:文件源 55.4 fps 到达率、每帧 18.2 ms(含力值读取)。 - Not in this change: frames.csv 仍未记录 process_ms(下次改记录格式、加未滤波 17 列时一并加,避免连做两次版本升级);未动节拍逻辑本身。

This commit is contained in:
ykcheungab
2026-09-14 11:22:44 +08:00
parent a9f75a868d
commit 5ef4d955fb
3 changed files with 55 additions and 5 deletions
@@ -197,6 +197,9 @@ class StudioMainWindow(QMainWindow):
#: Was the most recent readout valid? ``None`` before the first sample.
self._last_sample_valid: bool | None = None
self._latest_fps: float | None = None
#: 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
#: Last coefficients file written by the calibration panel (not applied).
self._last_calibration_export = ""
self._depth_range_value: tuple[float, float] | None = None
@@ -1357,6 +1360,11 @@ class StudioMainWindow(QMainWindow):
detail = t("status.rail_video_name", name=Path(path).name)
if self._show_fps and self._latest_fps is not None:
fps = f"{self._latest_fps:.1f} FPS"
# The cost goes next to the rate because one without the other cannot
# be read: "16.7 FPS" is either a slow camera or a pipeline that
# 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"
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
@@ -2111,6 +2119,7 @@ class StudioMainWindow(QMainWindow):
self._last_display_available = None
self._last_sample_valid = None
self._latest_fps = None
self._latest_process_ms = None
self._depth_range_value = None
self._last_depth_frame = None
# The new session's store is cleared *before* the charts are attached to
@@ -2197,6 +2206,7 @@ class StudioMainWindow(QMainWindow):
if not keep_frame:
self.arrow_panel.clear_preview(t("panels.arrow_empty"))
self._latest_fps = None
self._latest_process_ms = None
self._last_sample_valid = None
self._last_display_fallback = None
self._last_display_available = None
@@ -2365,6 +2375,7 @@ class StudioMainWindow(QMainWindow):
self._render_run_image(packet)
if is_new:
self._latest_fps = getattr(packet, "fps", None)
self._latest_process_ms = getattr(packet, "process_ms", None)
# 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.
+23
View File
@@ -2105,6 +2105,29 @@ def test_the_status_bar_is_a_notice_line_not_a_state_line(make_window):
_finish(window, stuck)
def test_the_rail_reads_the_rate_and_what_it_cost(qt_app, make_window):
"""A frame rate alone cannot say whether we or the camera are the slow part.
``packet.process_ms`` is the whole per-frame cost, so the rail shows it next
to the rate: "16.7 FPS · 58 ms" means the loop cannot keep up, while
"16.7 FPS · 6 ms" means the camera is only delivering 16.7.
"""
window = make_window()
window._show_fps = True
window._latest_fps = 16.67
window._latest_process_ms = 58.4
window._refresh_status_rail()
text = window.toolbar.source_summary.text()
assert "16.7 FPS" in text, text
assert "58 ms" in text, text
# Without a measured cost the rate is still shown, on its own.
window._latest_process_ms = None
window._refresh_status_rail()
assert window.toolbar.source_summary.text().strip().endswith("FPS")
window.close()
# ------------------------------------------------------- plot settings dialog
def test_the_chart_gear_opens_the_settings_dialog(qt_app, make_window):
"""The gear is the one place the filters can be changed from the UI."""
@@ -735,6 +735,11 @@ class SdkAcquisitionWorker(RecordSinkMixin):
break
t0 = time.perf_counter()
# ``t0`` is when this frame was *collected*: the device's own rate
# and the frame's acquisition time are measured from here, not
# from the end of its processing (that would report how long the
# pipeline took, dressed up as a frame rate).
#
# ``CaptureSource.read_latest`` hands back the newest frame and,
# until the pipeline produces another one, that **same** frame
# again. Treating the repeat as a new sample doubled every
@@ -772,7 +777,7 @@ class SdkAcquisitionWorker(RecordSinkMixin):
compute_error = ""
# The frame's acquisition time, so an event that happens on this
# frame is dated when it happened rather than when it was queued.
frame_mono = max(0.0, time.perf_counter() - self._mono_t0)
frame_mono = max(0.0, t0 - self._mono_t0)
try:
# Applying new coefficients is reported separately from the
# compute chain: a rejected document is an operator error,
@@ -797,7 +802,11 @@ class SdkAcquisitionWorker(RecordSinkMixin):
chain_depth, chain_error = process_chain(sensor)
compute_error = compute_error or chain_error
t1 = time.perf_counter()
frame_times.append(t1)
# The rate is measured between *collections* (``t0``), so it is
# the rate the frames arrived at. Measuring it after the compute
# chain instead made the rail report the loop's own cost as if it
# were the device's rate.
frame_times.append(t0)
cutoff = t1 - FPS_WINDOW_S
frame_times = [t for t in frame_times if t >= cutoff]
# A *rate*, not a count: counting arrivals in a one-second window
@@ -807,6 +816,10 @@ class SdkAcquisitionWorker(RecordSinkMixin):
span = frame_times[-1] - frame_times[0] if len(frame_times) > 1 else 0.0
fps = (len(frame_times) - 1) / span if span > 0.0 else 0.0
forces = read_forces_from_sensor(sensor, config_ref=mode.config_ref)
# Everything this frame cost, including the force readout — the
# number that says whether the loop can still keep up with the
# device, which the frame rate alone cannot.
t_done = time.perf_counter()
invalid_reason = forces.get("invalid_reason") or compute_error
raw_frame = _ensure_bgr(raw)
# The frame the chain above actually consumed, kept as the
@@ -825,10 +838,10 @@ class SdkAcquisitionWorker(RecordSinkMixin):
mono_t=(
frame_id * frame_period
if is_file
else max(0.0, t1 - self._mono_t0)
else max(0.0, t0 - self._mono_t0)
),
fps=fps,
process_ms=(t1 - t0) * 1000.0,
process_ms=(t_done - t0) * 1000.0,
normal_force=forces["normal_force"],
shear_x=forces["shear_x"],
shear_y=forces["shear_y"],
@@ -857,7 +870,10 @@ class SdkAcquisitionWorker(RecordSinkMixin):
self._emit(packet)
frame_id += 1
saw_frame = True
last_frame_mono = t1
last_frame_mono = t0
# The pacing phase reference stays the end of the compute chain:
# the loop waits out the rest of the frame period from there, and
# that is the behaviour the frame-rate tests pin.
last_frame_at = t1
except Exception as exc:
self._set_end_reason("error")