From 8035f9b7d3ded27893a1d6ee41cd7dff85a76e9d Mon Sep 17 00:00:00 2001 From: hulk Date: Mon, 12 Oct 2026 16:14:18 +0800 Subject: [PATCH] GUI v0.2.9: fix chronic-lag root cause (log trim crash on PySide6 6.11) + 5 hardening fixes - log trim used instance-level enum access (removed in PySide6 6.11), crashed --- AGENTS.md | 31 +++++ GUI/README.md | 13 +++ GUI/_diag_latency.py | 232 +++++++++++++++++++++++++++++++++++++ GUI/_diag_latency_buggy.py | 225 +++++++++++++++++++++++++++++++++++ GUI/app_fluent.py | 47 +++++--- GUI/filmforge_rs485.py | 13 ++- GUI/selftest_gui.py | 52 +++++++++ 7 files changed, 597 insertions(+), 16 deletions(-) create mode 100644 GUI/_diag_latency.py create mode 100644 GUI/_diag_latency_buggy.py diff --git a/AGENTS.md b/AGENTS.md index 38e05c8..5023e26 100644 --- a/AGENTS.md +++ b/AGENTS.md @@ -160,9 +160,40 @@ （app+window 两级 setWindowIcon，_icon_path() 兼容源码态与 _MEIPASS 打包态）、 Windows 任务栏独立标识 AppUserModelID "hulk.FilmForgeGUI"。README"无应用 图标"遗留项关闭。 + - v0.2.8：**慢性卡顿修复**——`_log()` 手工 cursor 裁剪（`cursor.Start`/ + `BlockUnderCursor` 实例级枚举访问）在 PySide6 6.11 上必然抛 AttributeError， + 日志超 500 行（100ms 上报 ≈50s）后每个 100ms tick 异常中止 `_tick` 后半段： + 应答超时清理失效（pending 永不清 → "停止"点击被幂等去重永久拦截，实拍状态栏 + "M2S0 应答中,已忽略重复发送"）、RX 队列积压 ratchet（帧处理滞后 54ms→均值 + 1037ms/峰值 2701ms，日志/chip/曲线显示滞后数秒，"停止 5s 后才见命令发出"实为 + 日志显示积压，TX 本身 5~166ms 即出）、日志无限增长、CPU +30%。改原生 + `setMaximumBlockCount(500)` 环形裁剪；selftest 新增"500 行封顶/封顶后可追加/ + 最新行在末尾"3 条回归。离屏 A/B 实测（GUI/_diag_latency_buggy.py，假固件 + 100ms 上报+定时点击）：buggy 组 5.5 分钟异常 2241 次、修复组全程漂移 ≤15ms/ + 零异常/零积压。v0.2.7 exe（2026-10-10 打包）内嵌同版本 PySide6 6.11.2， + 同带此 bug，需重新打包生效。 + - v0.2.9：**整体审查修复 5 项**——①CSV 写失败（磁盘满/记录盘被拔）自动停记录 + 并提示，不再沿 _tick 帧处理路径抛 OSError 中止主循环（与 v0.2.8 日志裁剪同款 + 失效管道）；②故障标记 faults 封顶 1000 条（曾是唯一无上限缓冲：NTC 抖动时 + 10 条/s 无限增长，且 _draw_faults 每 paint 全量扫描）；③串口写超时单独捕获 + SerialTimeoutException——只丢该条命令、链路保留，不再按 OSError 当"设备拔出" + 关端口断链（适配器停滞曾迫使手动重连）；④日志自动滚动仅在贴底时跟随（上报 + 运行时可上翻历史，不再被拽回底部）；⑤冻结视图切片右缘同样二分（暂停时长不再 + 增加 render 成本）。selftest 新增 7 项回归（封顶/滚动跟随/CSV 失败自停/冻结 + 切片）共 59 项全过。整体审查报告（2026-10-12）其余 P3 遗留：selftest 未覆盖 + _tick 主循环（超时清理/丢失判定）、"全部"窗口全量切片有 MAX_SAMPLES 兜底、 + _last_set 单槽位罕见误补偿（8s 自愈）、build_exe remove_stale 无提示强杀 + 运行实例、M888 后固定 2s 重查可能早于固件就绪、_danger_reset 把去重忽略记成 + "已下发"。协议建议的 300ms×3 自动重发维持不做（设计决策，用户拍板）。 - selftest 全过（累计新增 15 项回归用例，含窗口图标非空检查）；exe 已本地 打包冒烟，Gitea 发布待用户确认后执行。 遗留见其 README"已知事项"：USB-RS485 适配器更换。 +- [x] **GUI 慢性卡顿修复（根因已定位并修复 v0.2.8，待真机确认）**： + 根因/机理/实测数据见上方 v0.2.8 条目（`cursor.Start` 实例级枚举访问在 + PySide6 6.11 必抛 → tick 异常中止 → 应答超时清理失效 + RX 积压 ratchet + + 日志无限增长）。复现/验证脚本：`GUI/_diag_latency.py`（修复基线）/ + `GUI/_diag_latency_buggy.py`（带 bug 对照，假固件 100ms 上报+定时点击）。 + 遗留：待真机长时间运行确认 + 重新打包 exe。 - [ ] **LED 引脚确认**：FilmForge 自制板 LED 引脚未定（当前沿用模板默认 PA15， 仅为构建占位），按原理图修改。 - [ ] **delay_10us 校准**：M4@168MHz 系数为估算值（/300000），需实测修正。 diff --git a/GUI/README.md b/GUI/README.md index 1275958..b02c515 100644 --- a/GUI/README.md +++ b/GUI/README.md @@ -75,6 +75,19 @@ python publish_gitea.py release/FilmForge-GUI-v<版本>-win64.zip --replace --in 才返回（Windows 串口"字节间隔超时"150ms 因帧间隔更短永不触发，100ms 上报时 ≈2.5s 一批），表现为曲线/命令全部 3 秒一卡、一股脑一大坨。已改为 `read(in_waiting or 1)`，延迟回到 ≤150ms 量级（v0.2.2，真机实测确认）。 +- **日志裁剪走原生 `setMaximumBlockCount(500)`**：手工 `textCursor` 裁剪用了 + `cursor.Start`/`cursor.BlockUnderCursor` 实例级枚举访问，PySide6 6.11 已移除 + （类上仍在），必然抛 AttributeError——日志超 500 行（100ms 上报 ≈50s）后每个 + 100ms tick 在 `_log` 处异常中止：`_tick` 后半段（应答超时清理/连接状态机/统计 + 节流）永不执行（pending 永不清 → "停止"点击被幂等去重永久拦截）、RX 队列积压 + ratchet（帧处理滞后涨到 1~2.7s，日志/chip/曲线显示全面滞后）、日志无限增长。 + v0.2.8 改原生环形裁剪修复（离屏 A/B 实测：修复后 6 分钟漂移 ≤15ms、零异常、 + 零积压；selftest 新增 3 条回归用例）。 +- **日志自动滚动仅在贴底时跟随**：上报运行时可上翻查看历史（每行强制滚底会抢 + 滚动条）；CSV 写失败（磁盘满/记录盘被拔）自动停止记录并提示——`_csv_write` 在 + `_tick` 帧处理路径上，未捕获异常会中止主循环（v0.2.8 日志裁剪同款教训）；故障 + 标记封顶 1000 条；冻结视图切片右缘二分（暂停时长不增加渲染成本）；串口写超时 + 只丢该条命令、链路保留（不按设备拔出断链）。均 v0.2.9。 - Fluent 控件自定义样式必须走 `setCustomStyleSheet`（覆盖 hover/pressed/disabled）， 直接 `setStyleSheet` 会在切主题时被库重刷（DLPilot 同款坑）；标题字号走 QFont。 - 图表刷新双节流：数据到达即重绘（≤10Hz）+ 0.5s 时间轴推进；“全部”窗口超 4000 点 diff --git a/GUI/_diag_latency.py b/GUI/_diag_latency.py new file mode 100644 index 0000000..df3631e --- /dev/null +++ b/GUI/_diag_latency.py @@ -0,0 +1,232 @@ +#!/usr/bin/env python3 +# -*- coding: utf-8 -*- +"""诊断 v2: 干净基线 — 旁路 app_fluent._log 的坏裁剪(cursor.Start 在 PySide6 +6.11.2 上抛 AttributeError), 用 Qt 原生 setMaximumBlockCount 替代, 其余不动源码。 +目的: 验证 100ms 持续上报数分钟下, 修复裁剪后 点击->TX 是否仍瞬时、事件循环 +是否仍流畅(对照 buggy 版的 tick 中止 + 队列积压)。""" +import ctypes +import gc +import os +import sys +import threading +import time + +os.environ.setdefault("QT_QPA_PLATFORM", "offscreen") +sys.path.insert(0, os.path.dirname(os.path.abspath(__file__))) + +import filmforge_rs485 as ff + + +class FakeSerial: + """模拟 CH34x + 固件: M2S 控制周期温度帧, M2S0 回 ok 并停流。""" + + def __init__(self, *a, **kw): + self._buf = bytearray() + self._lock = threading.Lock() + self._alive = True + self.write_log = [] # [(time, cmd_bytes)] + self.report_ms = 0 + self._next_tx = 0.0 + self._th = threading.Thread(target=self._fw, daemon=True) + self._th.start() + FakeSerial.last = self + + def _fw(self): + while self._alive: + now = time.time() + if self.report_ms and now >= self._next_tx: + self._push(self._frame("34.6")) + self._next_tx = now + self.report_ms / 1000.0 + time.sleep(0.002) + + @staticmethod + def _frame(payload, type_code=0xF0): + body = bytes([type_code, len(payload)]) + payload.encode("ascii") + return bytes([0xB5]) + body + bytes([ff.sum_crc(body)]) + + def _push(self, b): + with self._lock: + self._buf += b + + @property + def in_waiting(self): + with self._lock: + return len(self._buf) + + def read(self, n): + deadline = time.time() + 0.15 + while True: + with self._lock: + if self._buf: + out = bytes(self._buf[:n]) + del self._buf[:n] + return out + if time.time() >= deadline: + return b"" + time.sleep(0.004) + + def write(self, data): + self.write_log.append((time.time(), bytes(data))) + cmd = bytes(data[3:-1]).decode("ascii", "replace").strip() + threading.Timer(0.05, lambda: self._on_cmd(cmd)).start() + return len(data) + + def _on_cmd(self, cmd): + if cmd.startswith("M2S"): + try: + ms = int(cmd[3:]) + except ValueError: + ms = 0 + self.report_ms = ms + self._next_tx = time.time() + ms / 1000.0 + self._push(self._frame("ok")) + elif cmd in ("M1", "M2", "M3", "M4", "M999"): + self._push(self._frame({"M1": "34.6", "M2": "OFF", "M3": "OFF", + "M4": "35.0", "M999": "v41.0.0.1"}[cmd])) + else: + self._push(self._frame("ok")) + + def close(self): + self._alive = False + try: + self._th.join(timeout=0.5) + except Exception: + pass + + +ff.serial.Serial = FakeSerial + +from PySide6.QtCore import QTimer +from PySide6.QtWidgets import QApplication + +app = QApplication([]) +import app_fluent + +# ---- 测试侧修复: 旁路坏裁剪(原生上限 500 行, 语义等同原意图) ---- +window = app_fluent.App(0) +window.txt_log.setMaximumBlockCount(500) # blockCount 永不 >500, 坏分支不触发 +window.show() +fake = None +exception_count = [0] + +# ---- 指标 ---- +stats = {"paint": [0, 0.0, 0.0], "tick": [0, 0.0, 0.0], + "gc": [0, 0.0, 0.0], "drift": [], "qmax": [0], "click": []} + +_orig_paint = app_fluent.TemperatureChart.paintEvent +def timed_paint(self, ev): + t0 = time.perf_counter() + _orig_paint(self, ev) + dt = time.perf_counter() - t0 + s = stats["paint"]; s[0] += 1; s[1] += dt; s[2] = max(s[2], dt) +app_fluent.TemperatureChart.paintEvent = timed_paint + +_orig_tick = app_fluent.App._tick +def timed_tick(self): + t0 = time.perf_counter() + try: + _orig_tick(self) + except Exception as e: + exception_count[0] += 1 + if exception_count[0] <= 3: + print("TICK EXCEPTION:", e, flush=True) + dt = time.perf_counter() - t0 + s = stats["tick"]; s[0] += 1; s[1] += dt; s[2] = max(s[2], dt) +app_fluent.App._tick = timed_tick + +_gc_t = [0.0] +def gc_cb(phase, info): + if phase == "start": + _gc_t[0] = time.perf_counter() + else: + dt = time.perf_counter() - _gc_t[0] + s = stats["gc"]; s[0] += 1; s[1] += dt; s[2] = max(s[2], dt) +gc.callbacks.append(gc_cb) + +probe = {"expect": None} +def probe_fire(): + now = time.time() + if probe["expect"] is None: + probe["expect"] = now + 0.02 + return + stats["drift"].append((now, now - probe["expect"])) + probe["expect"] += 0.02 + if now - probe["expect"] > 0.5: + probe["expect"] = now + 0.02 +pt = QTimer(); pt.timeout.connect(probe_fire); pt.start(20) + +CLICK_PERIOD = 30 +click = {"expect": None, "n": 0} + +def do_click_stop(): + now = time.time() + drift_ms = (now - click["expect"]) * 1000 if click["expect"] else 0.0 + q0 = window._rx_q.qsize() + window._send_set("M2S0", "report", ("OFF", None)) # "停止"按钮真实路径 + click["n"] += 1 + stats["click"].append(dict(n=click["n"], t=now, drift_ms=drift_ms, + qsize=q0, pending=len(window._pending), + samples=len(window.samples_t), + logblk=window.txt_log.blockCount())) + QTimer.singleShot(3000, do_click_restart) + +def do_click_restart(): + window._send_set("M2S100", "report", ("ON", 100)) + click["expect"] = time.time() + CLICK_PERIOD + QTimer.singleShot(CLICK_PERIOD * 1000, do_click_stop) + +def start(): + global fake + window.link.open("COMFAKE", 115200) + def wait_conn(): + if window.link.is_connected(): + fake = FakeSerial.last + click["expect"] = time.time() + 15 + QTimer.singleShot(15000, do_click_stop) + print("[t0] connected; stop-clicks every %ds from +15s" % CLICK_PERIOD, + flush=True) + else: + QTimer.singleShot(200, wait_conn) + QTimer.singleShot(200, wait_conn) +QTimer.singleShot(100, start) + +t_start = time.time() +DURATION = float(sys.argv[1]) if len(sys.argv) > 1 else 320.0 +INTERVAL = float(sys.argv[2]) if len(sys.argv) > 2 else 40.0 + +def monitor(): + while time.time() - t_start < DURATION: + time.sleep(INTERVAL) + el = time.time() - t_start + recent = [d for t, d in stats["drift"] if t >= time.time() - INTERVAL] + rmax = max(recent) * 1000 if recent else 0 + stats["qmax"][0] = max(stats["qmax"][0], window._rx_q.qsize()) + print(f"[{el:6.1f}s] cpu={time.process_time():7.2f}s " + f"samples={len(window.samples_t):6d} q={window._rx_q.qsize():4d} " + f"(max {stats['qmax'][0]:4d}) logblk={window.txt_log.blockCount():4d} " + f"paint(n={stats['paint'][0]:5d} max={stats['paint'][2]*1000:6.1f}ms) " + f"tick_max={stats['tick'][2]*1000:6.1f}ms " + f"gc_max={stats['gc'][2]*1000:5.1f}ms drift_max={rmax:7.1f}ms " + f"exc={exception_count[0]}", flush=True) + print("==== CLICK 明细 ====", flush=True) + for c in stats["click"]: + tx = next((t for t, d in FakeSerial.last.write_log + if d[3:-1].decode("ascii", "replace") == "M2S0" + and c["t"] <= t <= c["t"] + 2.0), None) + total = (tx - c["t"]) * 1000 if tx else -1 + print(f"click#{c['n']} t=+{c['t']-t_start:6.1f}s 调度漂移={c['drift_ms']:8.1f}ms " + f"click->TX={total:7.1f}ms q={c['qsize']:4d} pending={c['pending']} " + f"samples={c['samples']:6d} logblk={c['logblk']}", flush=True) + ds = sorted(d for _t, d in stats["drift"]) + if ds: + print(f"drift: n={len(ds)} p50={ds[len(ds)//2]*1000:.1f}ms " + f"p99={ds[int(len(ds)*0.99)]*1000:.1f}ms max={ds[-1]*1000:.1f}ms " + f">500ms次数={sum(1 for d in ds if d>0.5)}", flush=True) + print(f"paint total={stats['paint'][1]:.2f}s max={stats['paint'][2]*1000:.1f}ms | " + f"tick total={stats['tick'][1]:.2f}s max={stats['tick'][2]*1000:.1f}ms | " + f"gc total={stats['gc'][1]:.2f}s max={stats['gc'][2]*1000:.1f}ms " + f"n={stats['gc'][0]} | exceptions={exception_count[0]}", flush=True) + os._exit(0) + +threading.Thread(target=monitor, daemon=True).start() +app.exec() diff --git a/GUI/_diag_latency_buggy.py b/GUI/_diag_latency_buggy.py new file mode 100644 index 0000000..61867ed --- /dev/null +++ b/GUI/_diag_latency_buggy.py @@ -0,0 +1,225 @@ +#!/usr/bin/env python3 +# -*- coding: utf-8 -*- +"""诊断 v2b: BUGGY 对照组 — 不加裁剪修复, 复现 PySide6 6.11.2 上 +_log 裁剪 AttributeError 触发后的行为: tick 中止 / RX 处理滞后 ratchet / +事件循环漂移 / 点击->TX。指标同 v2, 另增帧处理年龄(frame_age)。""" +import gc +import os +import sys +import threading +import time + +os.environ.setdefault("QT_QPA_PLATFORM", "offscreen") +sys.path.insert(0, os.path.dirname(os.path.abspath(__file__))) + +import filmforge_rs485 as ff + + +class FakeSerial: + def __init__(self, *a, **kw): + self._buf = bytearray() + self._lock = threading.Lock() + self._alive = True + self.write_log = [] + self.report_ms = 0 + self._next_tx = 0.0 + self._th = threading.Thread(target=self._fw, daemon=True) + self._th.start() + FakeSerial.last = self + + def _fw(self): + while self._alive: + now = time.time() + if self.report_ms and now >= self._next_tx: + self._push(self._frame("34.6")) + self._next_tx = now + self.report_ms / 1000.0 + time.sleep(0.002) + + @staticmethod + def _frame(payload, type_code=0xF0): + body = bytes([type_code, len(payload)]) + payload.encode("ascii") + return bytes([0xB5]) + body + bytes([ff.sum_crc(body)]) + + def _push(self, b): + with self._lock: + self._buf += b + + @property + def in_waiting(self): + with self._lock: + return len(self._buf) + + def read(self, n): + deadline = time.time() + 0.15 + while True: + with self._lock: + if self._buf: + out = bytes(self._buf[:n]) + del self._buf[:n] + return out + if time.time() >= deadline: + return b"" + time.sleep(0.004) + + def write(self, data): + self.write_log.append((time.time(), bytes(data))) + cmd = bytes(data[3:-1]).decode("ascii", "replace").strip() + threading.Timer(0.05, lambda: self._on_cmd(cmd)).start() + return len(data) + + def _on_cmd(self, cmd): + if cmd.startswith("M2S"): + try: + ms = int(cmd[3:]) + except ValueError: + ms = 0 + self.report_ms = ms + self._next_tx = time.time() + ms / 1000.0 + self._push(self._frame("ok")) + elif cmd in ("M1", "M2", "M3", "M4", "M999"): + self._push(self._frame({"M1": "34.6", "M2": "OFF", "M3": "OFF", + "M4": "35.0", "M999": "v41.0.0.1"}[cmd])) + else: + self._push(self._frame("ok")) + + def close(self): + self._alive = False + try: + self._th.join(timeout=0.5) + except Exception: + pass + + +ff.serial.Serial = FakeSerial + +from PySide6.QtCore import QTimer +from PySide6.QtWidgets import QApplication + +app = QApplication([]) +import app_fluent + +# 注意: 不打 setMaximumBlockCount 补丁 —— 原样复现 bug +window = app_fluent.App(0) +window.show() +fake = None +exception_count = [0] + +stats = {"tick": [0, 0.0, 0.0], "gc": [0, 0.0, 0.0], "drift": [], + "qmax": [0], "click": [], "age": [0, 0.0, 0.0]} # age: n,total,max + +_orig_tick = app_fluent.App._tick +def timed_tick(self): + t0 = time.perf_counter() + try: + _orig_tick(self) + except Exception as e: + exception_count[0] += 1 + if exception_count[0] <= 3: + print("TICK EXCEPTION:", type(e).__name__, e, flush=True) + dt = time.perf_counter() - t0 + s = stats["tick"]; s[0] += 1; s[1] += dt; s[2] = max(s[2], dt) +app_fluent.App._tick = timed_tick + +_orig_handle = app_fluent.App._handle_frame +def timed_handle(self, fr, t_rx): + _orig_handle(self, fr, t_rx) + age = time.time() - t_rx # 帧从收到到被主线程处理的滞后 + s = stats["age"]; s[0] += 1; s[1] += age; s[2] = max(s[2], age) +app_fluent.App._handle_frame = timed_handle + +_gc_t = [0.0] +def gc_cb(phase, info): + if phase == "start": + _gc_t[0] = time.perf_counter() + else: + dt = time.perf_counter() - _gc_t[0] + s = stats["gc"]; s[0] += 1; s[1] += dt; s[2] = max(s[2], dt) +gc.callbacks.append(gc_cb) + +probe = {"expect": None} +def probe_fire(): + now = time.time() + if probe["expect"] is None: + probe["expect"] = now + 0.02 + return + stats["drift"].append((now, now - probe["expect"])) + probe["expect"] += 0.02 + if now - probe["expect"] > 0.5: + probe["expect"] = now + 0.02 +pt = QTimer(); pt.timeout.connect(probe_fire); pt.start(20) + +CLICK_PERIOD = 30 +click = {"expect": None, "n": 0} + +def do_click_stop(): + now = time.time() + drift_ms = (now - click["expect"]) * 1000 if click["expect"] else 0.0 + q0 = window._rx_q.qsize() + window._send_set("M2S0", "report", ("OFF", None)) + click["n"] += 1 + stats["click"].append(dict(n=click["n"], t=now, drift_ms=drift_ms, + qsize=q0, pending=len(window._pending), + samples=len(window.samples_t), + logblk=window.txt_log.blockCount())) + QTimer.singleShot(3000, do_click_restart) + +def do_click_restart(): + window._send_set("M2S100", "report", ("ON", 100)) + click["expect"] = time.time() + CLICK_PERIOD + QTimer.singleShot(CLICK_PERIOD * 1000, do_click_stop) + +def start(): + global fake + window.link.open("COMFAKE", 115200) + def wait_conn(): + if window.link.is_connected(): + fake = FakeSerial.last + click["expect"] = time.time() + 15 + QTimer.singleShot(15000, do_click_stop) + print("[t0] connected; stop-clicks every %ds from +15s (BUGGY mode)" + % CLICK_PERIOD, flush=True) + else: + QTimer.singleShot(200, wait_conn) + QTimer.singleShot(200, wait_conn) +QTimer.singleShot(100, start) + +t_start = time.time() +DURATION = float(sys.argv[1]) if len(sys.argv) > 1 else 320.0 +INTERVAL = float(sys.argv[2]) if len(sys.argv) > 2 else 40.0 + +def monitor(): + while time.time() - t_start < DURATION: + time.sleep(INTERVAL) + el = time.time() - t_start + recent = [d for t, d in stats["drift"] if t >= time.time() - INTERVAL] + rmax = max(recent) * 1000 if recent else 0 + stats["qmax"][0] = max(stats["qmax"][0], window._rx_q.qsize()) + n, tot, mx = stats["age"] + print(f"[{el:6.1f}s] cpu={time.process_time():7.2f}s " + f"samples={len(window.samples_t):6d} q={window._rx_q.qsize():5d} " + f"(max {stats['qmax'][0]:5d}) logblk={window.txt_log.blockCount():5d} " + f"frame_age avg={tot/max(n,1)*1000:7.1f}ms max={mx*1000:8.1f}ms " + f"tick_max={stats['tick'][2]*1000:6.1f}ms drift_max={rmax:8.1f}ms " + f"exc={exception_count[0]}", flush=True) + print("==== CLICK 明细 ====", flush=True) + for c in stats["click"]: + tx = next((t for t, d in FakeSerial.last.write_log + if d[3:-1].decode("ascii", "replace") == "M2S0" + and c["t"] <= t <= c["t"] + 2.0), None) + total = (tx - c["t"]) * 1000 if tx else -1 + print(f"click#{c['n']} t=+{c['t']-t_start:6.1f}s 调度漂移={c['drift_ms']:8.1f}ms " + f"click->TX={total:7.1f}ms q={c['qsize']:5d} pending={c['pending']} " + f"samples={c['samples']:6d} logblk={c['logblk']}", flush=True) + ds = sorted(d for _t, d in stats["drift"]) + if ds: + print(f"drift: n={len(ds)} p50={ds[len(ds)//2]*1000:.1f}ms " + f"p99={ds[int(len(ds)*0.99)]*1000:.1f}ms max={ds[-1]*1000:.1f}ms " + f">500ms次数={sum(1 for d in ds if d>0.5)}", flush=True) + n, tot, mx = stats["age"] + print(f"frame_age avg={tot/max(n,1)*1000:.1f}ms max={mx*1000:.1f}ms | " + f"exceptions={exception_count[0]} | tick n={stats['tick'][0]} " + f"max={stats['tick'][2]*1000:.1f}ms", flush=True) + os._exit(0) + +threading.Thread(target=monitor, daemon=True).start() +app.exec() diff --git a/GUI/app_fluent.py b/GUI/app_fluent.py index ce253bb..efb2792 100644 --- a/GUI/app_fluent.py +++ b/GUI/app_fluent.py @@ -60,7 +60,7 @@ import config import filmforge_rs485 as ff APP_NAME = "FilmForge" -APP_VERSION = "0.2.7" +APP_VERSION = "0.2.9" REPO_URL = "https://gitea.hulk.wang/hulk/FilmForge" MONO = QFont("Consolas", 10) CHIP_IDLE = "#666666" @@ -69,6 +69,7 @@ CHIP_ERR = "#D9534F" CHIP_WARN = "#E8833A" PENDING_TIMEOUT = 1.2 # 应答超时(秒): 协议建议 300ms 重发, 监视台不自动重发只提示 RESPONSE_FRESH = 0.5 # 应答新鲜度: 该窗口内的温度帧优先按“查询应答”派发 +MAX_FAULTS = 1000 # 故障标记内存上限(条): NTC 抖动场景防无限增长 CHART_COLORS_DARK = dict(bg="#242424", grid="#3a3a3a", text="#c9c9c9", measured="#00c8d7", target=CHIP_WARN, fault=CHIP_ERR) @@ -133,7 +134,7 @@ class TemperatureChart(QWidget): ts, vs = self._samples_t, self._samples_v if not ts: return [], [] - lo, hi = 0, len(ts) # 二分找左边界(留一点前文保证连线) + lo, hi = 0, len(ts) # 左边界二分(留一点前文保证连线) while lo < hi: m = (lo + hi) // 2 if ts[m] < t0: @@ -141,7 +142,14 @@ class TemperatureChart(QWidget): else: hi = m lo = max(lo - 1, 0) - t_out, v_out = ts[lo:], vs[lo:] + end, hi = lo, len(ts) # 右边界二分: 暂停(冻结)后不切冻结尾后新样本 + while end < hi: + m = (end + hi) // 2 + if ts[m] <= t1: + end = m + 1 + else: + hi = m + t_out, v_out = ts[lo:end], vs[lo:end] if len(t_out) > 4000: stride = math.ceil(len(t_out) / 4000) gt, gv = [], [] @@ -674,6 +682,9 @@ class App(QMainWindow): self.txt_log.setFont(MONO) self.txt_log.setLineWrapMode(QPlainTextEdit.NoWrap) self.txt_log.setMinimumHeight(200) + # 裁剪走原生环形上限: 手工 cursor 裁剪在 PySide6 6.11 上抛 AttributeError + # (实例级枚举访问已移除), 曾致每 tick 异常中止 + 日志无限增长 + 显示滞后 + self.txt_log.setMaximumBlockCount(500) body.addWidget(self.txt_log) self._log(f"帧格式: D5 01 LEN <命令> CRC / B5 TYPE LEN CRC; " f"响应超时建议 {ff.REPLY_TIMEOUT * 1000:.0f}ms 重发") @@ -959,6 +970,8 @@ class App(QMainWindow): self.samples_t.append(t) self.samples_v.append(float("nan")) self.faults.append((t, code)) + if len(self.faults) > MAX_FAULTS: # 封顶: 抖动场景不无限增长(_draw_faults 按 paint 全量扫描) + del self.faults[:len(self.faults) - MAX_FAULTS] self.lbl_temp.setText("—.— ℃") self._csv_write(t, code, ok=False) self.chart.update() @@ -1266,9 +1279,19 @@ class App(QMainWindow): target = f"{self.target_hist[-1][1]:g}" if self.target_hist else "" heater = self.heater_state or "" sensor = self.sensor_state or ("OK" if ok else "") - self._csv.write(f"{time.strftime('%Y-%m-%d %H:%M:%S', time.localtime(t))}," - f"{t - self._csv_t0:.3f},{temp_text},{target},{heater},{sensor}\n") - self._csv.flush() + try: + self._csv.write(f"{time.strftime('%Y-%m-%d %H:%M:%S', time.localtime(t))}," + f"{t - self._csv_t0:.3f},{temp_text},{target},{heater},{sensor}\n") + self._csv.flush() + except OSError as e: + # 写失败(磁盘满/记录盘被拔): 自动停记录。本函数在 _tick 帧处理路径上, + # 未捕获异常会中止整段消费(与 v0.2.8 日志裁剪同款失效管道, 勿回退) + self._csv.close() + self._csv = None + self.btn_csv.setText("开始记录") + self.lbl_csv.setText(f"记录失败已停止: {e}") + self._log(f"⚠ CSV 记录失败已停止: {e}") + return self._csv_count += 1 self.lbl_csv.setText(f"记录中({self._csv_count} 行) → " f"{os.path.basename(self._csv_path)}") @@ -1279,15 +1302,11 @@ class App(QMainWindow): # ================= 日志 ================= def _log(self, line): - self.txt_log.appendPlainText(time.strftime("%H:%M:%S ") + line) - if self.txt_log.blockCount() > 500: - cursor = self.txt_log.textCursor() - cursor.movePosition(cursor.Start) - cursor.select(cursor.BlockUnderCursor) - cursor.removeSelectedText() - cursor.deleteChar() sb = self.txt_log.verticalScrollBar() - sb.setValue(sb.maximum()) + at_bottom = sb.value() >= sb.maximum() - 4 + self.txt_log.appendPlainText(time.strftime("%H:%M:%S ") + line) + if at_bottom: # 仅原本贴底时跟随, 不抢用户上翻看历史 + sb.setValue(sb.maximum()) def _clear_log(self): self.txt_log.clear() diff --git a/GUI/filmforge_rs485.py b/GUI/filmforge_rs485.py index 48e7d9b..919f72c 100644 --- a/GUI/filmforge_rs485.py +++ b/GUI/filmforge_rs485.py @@ -347,8 +347,17 @@ class FF485: pass if item is not None: cmd, frame = item - self.ser.write(frame) - self.on_event(f'→ {cmd} [{frame.hex(" ").upper()}]') + sent = False + try: + self.ser.write(frame) + sent = True + except serial.SerialTimeoutException: + # 写超时(适配器停滞): 只丢这条命令, 链路保留。 + # 勿并入下方 OSError——瞬时停滞曾被当成"设备拔出" + # 关端口断链, 迫使用户手动重连(适配器换向本就不稳) + self.on_event(f'✕ {cmd} 写超时未发出, 链路保留(可重发)') + if sent: + self.on_event(f'→ {cmd} [{frame.hex(" ").upper()}]') # 按到达量读取, 不攒大块: 固定 read(256) 在持续帧流下要攒满 # 256 字节才返回(win32 字节间隔超时 150ms 因帧间隔更短永不 # 触发, 100ms 上报 ≈ 2.5s 一批), 表现为曲线/命令全按 3s 一卡 diff --git a/GUI/selftest_gui.py b/GUI/selftest_gui.py index 8c0fdc1..555a3d1 100644 --- a/GUI/selftest_gui.py +++ b/GUI/selftest_gui.py @@ -227,5 +227,57 @@ with open(window._csv_path, encoding='utf-8-sig') as f: check('CSV 表头+2 行', len(lines), 3) check('CSV 故障行', lines[2].split(',')[2], 'SHRT') +# 6) 日志环形裁剪回归: 写满 500 行后封顶, 继续追加不抛异常、不无限增长。 +# (手工 cursor 裁剪用 cursor.Start/BlockUnderCursor 实例级枚举访问, +# PySide6 6.11 上必然抛 AttributeError → 每 tick 异常中止, v0.2.8 改原生裁剪) +for i in range(600): + window._log(f'日志压力行 {i}') +check('日志 500 行封顶', window.txt_log.blockCount() <= 500, True) +window._log('封顶后追加行') +check('封顶后可继续追加', window.txt_log.blockCount() <= 500, True) +check('封顶后最新行在末尾', + window.txt_log.toPlainText().splitlines()[-1].endswith('封顶后追加行'), True) + +# 7) v0.2.9 回归: 故障标记封顶 / 滚动条跟随 / CSV 写失败自停 / 冻结切片右边界 +t_end = time.time() +for i in range(app_fluent.MAX_FAULTS + 50): + window._record_fault(t_end + i * 0.01, ff.SENSOR_OPEN) +check('故障标记封顶', len(window.faults), app_fluent.MAX_FAULTS) + +sb = window.txt_log.verticalScrollBar() +sb.setValue(0) +window._log('上翻后新行') +check('上翻时不抢滚动条', sb.value() <= 1, True) +sb.setValue(sb.maximum()) +window._log('贴底跟随行') +check('贴底时跟随滚动', abs(sb.value() - sb.maximum()) <= 4, True) + + +class _BoomFile: + """模拟写坏盘: write/flush 必抛 OSError(磁盘满/记录盘被拔)""" + def write(self, *_a): + raise OSError(28, '模拟磁盘满') + def flush(self): + raise OSError(28, '模拟磁盘满') + def close(self): + pass + + +window._csv = _BoomFile() +window._csv_path = 'dummy.csv' +window._add_sample(time.time(), 25.0) +check('CSV 写失败自动停止记录', window._csv is None, True) +check('CSV 失败后按钮复位', window.btn_csv.text(), '开始记录') + +c = window.chart +c._samples_t, c._samples_v = [1.0, 2.0, 3.0, 4.0], [1, 2, 3, 4] +c._frozen_at = 2.5 +ts, _vs = c._visible(0, 2.5) +check('冻结切片不含冻结尾后样本', ts, [1.0, 2.0]) +c._frozen_at = None +ts, _vs = c._visible(0, 99) +check('实时切片完整', ts, [1.0, 2.0, 3.0, 4.0]) +c._samples_t, c._samples_v = window.samples_t, window.samples_v + print('RESULT:', 'FAIL:' + ','.join(fails) if fails else 'ALL PASS') sys.exit(1 if fails else 0)