MeshCore worker can deadlock in _recover_connection(): meshcore.disconnect() has no timeout #16

Open
opened 2026-10-05 06:09:14 +02:00 by adam · 0 comments
Owner

Symptom

On a serial deployment (Heltec V3 / CP2102), the MeshCore worker can deadlock during health-check recovery. The Bridge Coordinator keeps reporting MESHCORE: disconnected every minute, but the worker thread is stuck and never attempts another reconnect. Only a container restart recovers it.

Observed twice within ~16h on the same deployment:

  • Run 1: deadlock after ~26h uptime, stuck ~14h
  • Run 2 (after restart): deadlock after 3 minutes of uptime

Reproduction

Not deterministic. Trigger seems to be a "stale" health-check, which fires every 3-5 min on Heltec V3 because events are sparse.

Representative log before hang

… WARNING - MeshCore connection appears stale
… WARNING - MeshCore health check failed, attempting recovery
… WARNING - Starting MeshCore recovery (attempt 1/10)
… INFO    - Component meshcore: connected -> disconnected
# (worker is silent from here. Coordinator keeps printing "MESHCORE: disconnected" indefinitely.)

In successful recoveries the next line is INFO - Waiting Xs before MeshCore reconnection (meshcore_worker.py:880). That line never appears in a hang.

Root cause (proposed)

meshcore_worker.py:870-877 cleanup has no timeout:

if self.meshcore:
    try:
        await self.meshcore.stop_auto_message_fetching()
        await self.meshcore.disconnect()       # blocks if serial I/O is stuck
    except Exception as e:
        self.logger.debug(f"Error stopping old MeshCore connection: {e}")

If the serial transport in the meshcore lib has a pending read, disconnect() awaits it forever. The whole _recover_connection() coroutine is then frozen before await asyncio.sleep(delay) and _setup_connection(). The status loop is a separate task, so it keeps logging — masking the deadlock.

Suggested fix

Wrap cleanup in asyncio.wait_for with a short timeout and force-drop the reference:

if self.meshcore:
    for coro, label in [
        (self.meshcore.stop_auto_message_fetching, "stop_auto_fetch"),
        (self.meshcore.disconnect, "disconnect"),
    ]:
        try:
            await asyncio.wait_for(coro(), timeout=5.0)
        except (asyncio.TimeoutError, Exception) as e:
            self.logger.warning(f"Timeout/error during {label}: {e}")
    self.meshcore = None

Environment

  • Bridge commit: bbc8584 (Merge PR #17, current main)
  • Companion: Heltec V3, firmware v1.15.0-dee3e26 (USB serial via CP2102)
  • MESHCORE_CONNECTION=serial, MESHCORE_ADDRESS=/dev/ttyUSB0, baudrate 115200
  • Docker on Raspberry Pi 5 (Debian aarch64)

Workaround

docker restart meshcore-mqtt-bridge — reliable, but needs a watchdog.

## Symptom On a serial deployment (Heltec V3 / CP2102), the MeshCore worker can deadlock during health-check recovery. The Bridge Coordinator keeps reporting `MESHCORE: disconnected` every minute, but the worker thread is stuck and never attempts another reconnect. Only a container restart recovers it. Observed twice within ~16h on the same deployment: - Run 1: deadlock after ~26h uptime, stuck ~14h - Run 2 (after restart): deadlock after **3 minutes** of uptime ## Reproduction Not deterministic. Trigger seems to be a "stale" health-check, which fires every 3-5 min on Heltec V3 because events are sparse. ## Representative log before hang ``` … WARNING - MeshCore connection appears stale … WARNING - MeshCore health check failed, attempting recovery … WARNING - Starting MeshCore recovery (attempt 1/10) … INFO - Component meshcore: connected -> disconnected # (worker is silent from here. Coordinator keeps printing "MESHCORE: disconnected" indefinitely.) ``` In successful recoveries the next line is `INFO - Waiting Xs before MeshCore reconnection` (meshcore_worker.py:880). That line never appears in a hang. ## Root cause (proposed) `meshcore_worker.py:870-877` cleanup has no timeout: ```python if self.meshcore: try: await self.meshcore.stop_auto_message_fetching() await self.meshcore.disconnect() # blocks if serial I/O is stuck except Exception as e: self.logger.debug(f"Error stopping old MeshCore connection: {e}") ``` If the serial transport in the `meshcore` lib has a pending read, `disconnect()` awaits it forever. The whole `_recover_connection()` coroutine is then frozen before `await asyncio.sleep(delay)` and `_setup_connection()`. The status loop is a separate task, so it keeps logging — masking the deadlock. ## Suggested fix Wrap cleanup in `asyncio.wait_for` with a short timeout and force-drop the reference: ```python if self.meshcore: for coro, label in [ (self.meshcore.stop_auto_message_fetching, "stop_auto_fetch"), (self.meshcore.disconnect, "disconnect"), ]: try: await asyncio.wait_for(coro(), timeout=5.0) except (asyncio.TimeoutError, Exception) as e: self.logger.warning(f"Timeout/error during {label}: {e}") self.meshcore = None ``` ## Environment - Bridge commit: `bbc8584` (Merge PR #17, current main) - Companion: Heltec V3, firmware `v1.15.0-dee3e26` (USB serial via CP2102) - `MESHCORE_CONNECTION=serial`, `MESHCORE_ADDRESS=/dev/ttyUSB0`, baudrate 115200 - Docker on Raspberry Pi 5 (Debian aarch64) ## Workaround `docker restart meshcore-mqtt-bridge` — reliable, but needs a watchdog. <!-- github-sync-id:4516941876 -->
Sign in to join this conversation.
No labels
1 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: adam/meshcore-mqtt#16