diff --git a/tools/service_tui/app/m5_client.py b/tools/service_tui/app/m5_client.py index 6d132d0..3e8a339 100644 --- a/tools/service_tui/app/m5_client.py +++ b/tools/service_tui/app/m5_client.py @@ -120,10 +120,16 @@ class M5Client: Вернуть None если не найден — M5 опционален. """ port = None - loop = asyncio.get_running_loop() started = time.monotonic() for attempt in range(1, _AUTO_CONNECT_ATTEMPTS + 1): - port = await loop.run_in_executor(None, _find_m5_port) + # Намеренно НЕ run_in_executor: serial.tools.list_ports.comports() + # параллельно с WaitingScreen._poll_usb() (главный поток, тоже + # comports() — resolve_serial_port() для целевой платы) — два + # потока одновременно дёргают нативное перечисление USB-устройств + # (SetupDiGetClassDevs на Windows и т.п.), что подвешивало детект + # целевой платы целиком. comports() сам по себе быстрый (мс), не + # стоит того чтобы уводить его в отдельный поток и вводить гонку. + port = _find_m5_port() if port is not None: elapsed = time.monotonic() - started logger.info( @@ -140,7 +146,7 @@ class M5Client: await asyncio.sleep(_AUTO_CONNECT_RETRY_DELAY_S) if port is None: elapsed = time.monotonic() - started - visible = await loop.run_in_executor(None, _describe_visible_ports) + visible = _describe_visible_ports() logger.info( "M5StampPLC не найден за %.1fс (%d попыток, ищем %04X:%04X). " "Видимые порты: %s", @@ -209,8 +215,22 @@ class M5Client: # ── Low-level I/O ─────────────────────────────────────────────────────── def _send_recv(self, cmd: dict) -> Optional[dict]: - """Отправить команду, прочитать ответ (blocking).""" + """ + Отправить команду, прочитать ответ (blocking). + + Протокол без корреляции запрос↔ответ: одна команда — одна строка + ответа, без ID. Если предыдущий вызов истёк по таймауту (readline() + не дождался ответа за _READLINE_TIMEOUT_S), а M5 всё-таки прислал + его чуть позже — этот ответ остаётся непрочитанным в буфере порта, и + следующий вызов читает ЕГО вместо ответа на свою собственную команду + (см. историю багфикса: KeyError('id') в can_recv() из-за того, что + читался застрявший {"ok": true} от предыдущего can_send()). Сброс + входного буфера перед каждой командой устраняет этот десинк ценой + узкого окна гонки (если M5 успеет что-то прислать между reset и + write) — гораздо безопаснее, чем читать ответ на чужую команду. + """ assert self._ser is not None + self._ser.reset_input_buffer() line = json.dumps(cmd, separators=(",", ":")) + "\n" self._ser.write(line.encode("utf-8")) self._ser.flush() @@ -283,8 +303,12 @@ class M5Client: :return: {"id": int, "data": list[int]} или None при таймауте/ошибке. """ resp = await self._cmd({"cmd": "can_recv", "timeout_ms": timeout_ms}) - if resp and resp.get("ok") is True: + if resp and resp.get("ok") is True and "id" in resp and "data" in resp: return {"id": resp["id"], "data": resp["data"]} + if resp and resp.get("ok") is True: + logger.warning( + "can_recv: ok=true, но ответ без id/data (не тот ответ?): %r", resp + ) return None @staticmethod diff --git a/tools/service_tui/app/screens/diag/__init__.py b/tools/service_tui/app/screens/diag/__init__.py index 27cc051..e078264 100644 --- a/tools/service_tui/app/screens/diag/__init__.py +++ b/tools/service_tui/app/screens/diag/__init__.py @@ -244,7 +244,8 @@ class DiagScreen(Screen, ConnectionWatcherMixin): if event.type == OrchestratorEventType.SUMMARY: break except Exception as exc: - logger.error("run_worker error: %s", exc) + logger.error("run_worker error: %s", exc, exc_info=True) + self._update_progress(done, total, f"⚠ Ошибка прогона тестов: {exc}") finally: self._tests_running = False self._set_run_buttons(enabled=True) diff --git a/tools/service_tui/docs/DEV_ARCH.md b/tools/service_tui/docs/DEV_ARCH.md index 6171da5..815d593 100644 --- a/tools/service_tui/docs/DEV_ARCH.md +++ b/tools/service_tui/docs/DEV_ARCH.md @@ -216,6 +216,28 @@ flowchart TD агента (новые команды, смена формата ответа) — сверяться напрямую через `grep` по `tools/hil/m5/agent.py`, а не полагаться только на документацию. +**Протокол без корреляции запрос↔ответ — известный риск десинка.** Каждый +вызов `M5Client._send_recv()` пишет одну JSON-команду и читает ровно одну +строку ответа с фиксированным таймаутом (`_READLINE_TIMEOUT_S = 0.5`), без +ID запроса в сообщении. Если M5 не успел ответить в это окно (устройство и +так временами «тормозит» — см. заметку выше про boot-баннер MicroPython), а +ответ всё же приходит чуть позже, он остаётся непрочитанным в буфере порта. +Следующий вызов — уже ДРУГОЙ команды — читает этот протухший ответ вместо +своего. Конкретный воспроизведённый случай на живом стенде: `can_send()` +отвечает `{"ok": true}` (без `id`); если этот ответ протух и его подобрал +следующий `can_recv()`, `resp.get("ok") is True` — правда, а `resp["id"]` — +`KeyError`, роняющее `_run_worker` в `diag/__init__.py` («зависший» статус +CAN на экране, крах отдавал только `str(exc)` без traceback, что сильно +затруднило диагностику — теперь `exc_info=True`). Фикс — `reset_input_buffer()` +перед КАЖДОЙ командой в `_send_recv()` (не только один раз при открытии +порта): протухший ответ на предыдущую команду отбрасывается, следующий +`readline()` может прочитать только ответ на команду, которую мы вот-вот +отправим. Плюс defense-in-depth в `can_recv()` — не доверять форме ответа +только по `ok: true`, проверять наличие `id`/`data` явно. Если в будущем +протокол агента усложнится (несколько команд в полёте одновременно и т.п.), +этого узкого фикса будет недостаточно — понадобится настоящая корреляция +запрос↔ответ (ID в каждом сообщении). + --- ## 6. Мониторинг соединения и разрыв сессии @@ -578,6 +600,8 @@ M5 не детектится синхронно в момент перехода **Побочный эффект и его фикс:** пока `connect()` ретраит `ping` (до ~12с в худшем случае), `WaitingScreen` уже физически детектировал плату, но `ServiceApp` ещё не переключил экран — на месте секунд на 10 виден статичный (не крутящийся) спиннер, что выглядит как зависание. Причина — `_poll_usb()` в `waiting.py` останавливал разом все таймеры экрана, включая спиннер, в момент детекта. Исправлено: `_stop_detect_polling()` останавливает только опрос USB и меняет подсказку на «Плата найдена, подключаемся...», спиннер продолжает крутиться до фактического `switch_screen()` (весь набор таймеров глушится только в `on_unmount()`). +**Регрессия и её фикс (детект целевой платы переставал работать целиком):** первая версия фонового детекта M5 заворачивала `_find_m5_port()`/`comports()`-скан в `loop.run_in_executor(...)` — то есть гоняла его в отдельном потоке. При этом `WaitingScreen._poll_usb()` в главном потоке параллельно дёргает `Flasher.detect_cdc()` → `resolve_serial_port()` → тот же `serial.tools.list_ports.comports()`. До фонового M5-детекта `comports()` вызывался только из одного потока за раз; с ним — сразу из двух. Нативное перечисление USB-устройств (`SetupDiGetClassDevs` на Windows и аналоги на других ОС) не гарантированно потокобезопасно при таком параллельном доступе — это вешало детект целевой платы целиком (`WaitingScreen` зависал навсегда, независимо от M5). Исправлено: `_find_m5_port()`/`_describe_visible_ports()` в `M5Client.auto_connect()` больше не уходят в executor — `comports()` сам по себе быстрый (мс), гонять его в отдельном потоке не было необходимости, а вот держать все вызовы `comports()` в одном потоке (главном, event loop) — обязательно. Открытие/чтение уже резолвленного M5-порта (`_open()`/`_cmd()`) по-прежнему в executor — это другой системный вызов (открытие конкретного файла/хендла, не сканирование дерева устройств), конфликта с `comports()` не даёт. + --- ## 11. Версионирование firmware