Files
HW-Debug-Tools/SerialMate/ISSUE_rx_timestamp_and_lag.md
T

98 lines
5.0 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# SerialMate 接收路径问题报告(时间戳失真 + 显示延迟累积)
> 来源:FilmForge 固件联调(GD32F405 RS485,115200,M2 连续温度上报 2~10 帧/s)。
> 现象与固件侧二分验证结论一起整理,供后续修复。
> 日期:2026-10-10
>
> **【已修复 v0.1.1,2026-10-10】** 根因 1 与根因 2 的 1/2/3/4 全部落地,
> 实现与本文建议的差别:日志批量插入每行包 `<p style="margin:0">`(`<br>`
> 连接只算 1 个 block,会让 maximumBlockCount 失效);转义空格转 `&nbsp;`
> 防富文本折叠连续空格;通道缓存放 `_ch_cfg`(`_on_channel` 时重建)。
> 自检已覆盖(selftest_gui 69 项含积压折叠/到达时间戳用例),
> 端到端模拟 600 帧积压:日志 201 行、曲线 600 点全收、时间戳=到达时刻。
> 详见 AGENTS.md §7 v0.1.1。
## 现象(联调实测)
1. **时间戳挤压**:M2 以 500ms/100ms 周期上报时,日志里出现 13 帧"0.2~1ms 间隔"
挤在同一批(如 23:59:55.221~227),完全不是真实到达间隔。
2. **显示延迟累积**:命令 ack 延迟 120~160ms 才显示;长时间运行后越来越卡,
最终表现为"命令发了没反应"(实际帧在队列里排队,晚些时候才显示)。
3. **偶发"丢帧"观感**:与 2 叠加后,ack 迟迟不显示,上位机/人工判断为无响应。
固件侧已用调试串口镜像做过二分验证:**帧到达固件、固件发出响应均为 100%**,
SerialMate 显示层的时间戳与延迟失真是独立存在的第二层问题。
## 根因 1:时间戳在 GUI 消费时刻打,而非字节到达时刻(确凿)
- `link.py` `_dispatch_rx()` 后台线程解析出帧后回调 `on_frame(fr)`;
- `main.py:237` `self.link.on_frame = lambda fr: self.events.put(('frame', fr))`
—— **入队时不带时间戳**;
- `main.py:1291` `_on_frame()` 里才调 `_timestamp()` —— **消费时打戳**。
后台读线程 20ms 轮询、GUI QTimer 30ms drain,再叠加 UI 卡顿,一串积压帧的
时间戳全部落在消费瞬间,毫秒级挤在一起。**这不是到达时间,是显示时间。**
### 修复建议
时间戳统一在 link 后台线程产生(字节到达时刻),随事件入队:
```python
# link.py _dispatch_rx()
ts = time.time() # 或 time.perf_counter()
for fr in self.parser.feed(data):
if self.on_frame is not None:
self.on_frame(fr, ts) # 携带到达时刻
# raw 同理: self.on_raw(data, ts)
# main.py
self.link.on_frame = lambda fr, ts: self.events.put(('frame', fr, ts))
...
def _on_frame(self, fr, ts): # 显示时用 ts 格式化,不再调 _timestamp()
```
`on_raw` / `on_tx`(若也要求发送时刻)/ `on_status` 同理改造。
`_timestamp()` 改为接受 epoch 秒参数的纯格式化函数。
## 根因 2:接收日志无限增长 → UI 递减性卡顿 → 延迟累积(确凿)
- `_append_rx`/`_append_rx_frame` 对 `text_rx` 逐行 `appendPlainText/appendHtml`,
**无任何行数上限**。长跑后 QPlainTextEdit 文档越滚越大,排版/paint 成本上升,
30ms 的 `_drain_events` 开始处理不完,事件积压,显示延迟越拉越大。
- `_on_frame` 每帧调用 `_collect_channels()`(遍历全部通道 UI 控件读
isChecked/text/value),帧率高时放大 UI 线程占用。
### 修复建议
1. 行数上限:`self.text_rx.setMaximumBlockCount(5000)`(一行代码,先止血);
或定时(如每 5s)裁剪超量历史。
2. 批量插入:`_drain_events` 把本轮全部行拼成一个字符串/HTML 片段,**一次**
append,减少 N 次 UI 重排为 1 次。
3. 通道配置缓存:维护 `self._ch_cfg`,仅在 `_on_channel`(用户改动配置)时
重建;`_on_frame` 直接读缓存,不再每帧遍历控件。
4. 帧率自适应:积压超过阈值(如 events.qsize() > 200)时,帧日志折叠为
计数摘要("…+250 帧 (温度上报)"),保曲线、压日志。
## 排除项(验证过没有问题)
- `protocol.FrameParser`(前缀对齐 + LEN + CRC,失配丢 1 字节重同步)解析器
本身健壮,未发现丢帧逻辑缺陷;`src/selftest.py` 覆盖良好。
- `events = queue.Queue()` 无上限,不会丢事件,只会延迟。
- `link.py` 读线程 20ms 轮询 + `read(4096)`,常规速率下不会溢出驱动缓冲
(115200 下 20ms 最多 288 字节)。
## 优先级建议
1. 先做根因 2 的"1. 行数上限"(一行代码)——立刻止血卡顿。
2. 再做根因 1 的时间戳随事件携带——日志时间恢复可信。
3. 根因 2 的 2/3/4 与根因 1 的状态/tx 同步改造,作为一轮完整性优化。
## 复现方法
固件端(FilmForge,GD32F405,RS485 115200):
- `M2S500` 开启 500ms 周期温度上报(帧 `B5 F0 04 "25.6" CRC`);
- 连续观察 10 分钟以上,或把上报间隔调到 `M2S100` 加速日志增长。
预期:修复前时间戳随 UI 卡顿成批挤压、显示延迟随运行时间增大;
修复后时间戳单调且间隔≈设定周期,长时间运行无卡顿增长。