Skip to content

connection_lost() tears down the worker loop before notifying the application, so disconnect() races the teardown #745

Description

@jetliuzhe

Summary

All the current work on ThreadsafeProxy teardown (#722, #727, #730, #739, #740, #741)
makes the failure graceful — return an awaitable, swallow the RuntimeError, log a
warning. None of it addresses why the proxy is being used against a dead loop in the first
place, which is an ordering problem one layer up in uart.py.

Gateway.connection_lost() resolves connection_done — which triggers
EventLoopThread.force_stop() — before it notifies the application that the connection
was lost:

def connection_lost(self, exc):                           # uart.py:67
    ...
    if self._connection_done_future:
        self._connection_done_future.set_result(exc)      # :82  -> fires the :148 callback -> force_stop()
        self._connection_done_future = None
    ...
    self._api.connection_lost(exc)                        # :89  -> only now does the app find out
connection_done.add_done_callback(lambda _: thread.force_stop())   # :148

So the teardown of the loop is already in flight while :89 is still propagating upward
through EZSP.connection_lost → ControllerApplication.connection_lost → the
application's listener. By the time the application unwinds and calls
await self._ezsp.disconnect(), it is racing that teardown — and disconnect() has to go
through the proxy bound to exactly the loop being torn down.

Making the proxy fail gracefully turns a hang into a no-op, which is a real improvement,
but the disconnect still does not actually run. Flipping the order — notify the
application first, resolve connection_done after — would let the normal cleanup path
complete before the loop goes away, and would make the proxy's disconnected branches a
genuine edge case rather than the common path.

This hazard is in fact already documented a few lines above, for a different future
(uart.py:74-77):

# XXX: The startup reset future must be resolved with an error *before* the
# "connection done" future is completed: the secondary thread has an attached
# callback to stop itself, which will cause the a future to propagate a
# `CancelledError` into the active event loop, breaking everything!

That is the same mechanism — "the secondary thread has an attached callback to stop
itself" — recognised for _startup_reset_future but not for the application notification
at :89, which is also downstream of the same set_result at :82. Given that comment,
I may well be missing a constraint that forces the current order.

I am also fairly confident this is the original bug behind
home-assistant/core#88202 (2023), whose workaround zigpy/zha#628 removed in January
2026 on the assumption that "the underlying bellows issue has been resolved" — while the
PR author notes in the same thread that the original issue was never actually found.
uart.py has been heavily refactored since 2023 (407 → 151 lines), but this ordering has
survived every refactor untouched
: the force_stop done-callback sat at :404 in
Feb 2023 (95c1bee) and sits at :148 today, with set_result(exc) still ahead of the
application notification in both.

Versions

reproduced on also verified present in
bellows 0.49.0 1.0.0 (uart.py byte-identical; thread.py ThreadsafeProxy unchanged)
zigpy 1.2.2 2.1.0
zha 1.1.1 2.1.0 (CONF_USE_THREAD declared at application/const.py:76, zero references)
homeassistant 2026.4.1 dev (only components/zha/radio_manager.py:210 sets it, on the start_radio=False probe app)

Coordinator: EFR32MG24 NCP reached over a raw TCP byte bridge (socket://<ip>:6638).
The bridge does no ASH framing, so nothing on my side interferes with the protocol.

All line numbers in this issue are from bellows 1.0.0 / dev.

What the application then hits

When the application unwinds and calls EZSP.disconnect():

async def disconnect(self):                  # ezsp/__init__.py:231
    self.stop_ezsp()
    if self._gw:
        await self._gw.disconnect()          # _gw is ThreadsafeProxy(gateway, worker_loop)

ThreadsafeProxy.func_wrapper (thread.py:96-107) then dispatches to the worker loop.
Depending on exactly how far force_stop() has progressed, there are three outcomes:

worker loop state is_closed() run_coroutine_threadsafe result tracked in
closed True not reached returns bare None → await None → TypeError #722, #730
closed mid-dispatch False then closes raises RuntimeError exception at caller #740, #741
stopped, not yet closed False does not raise future never resolves → unbounded hang not covered

The third row is the one I hit, and it is the worst of the three because it is completely
silent — no exception, no log line, no retry. force_stop() schedules loop.stop();
loop.close() only happens afterwards in _thread_main's finally, so there is a real
window where the loop is unusable but reports is_closed() == False.

Self-contained reproduction of that window (Python 3.14, no bellows import required):

import asyncio, threading, time, contextlib

loop = asyncio.new_event_loop()
threading.Thread(target=lambda: (asyncio.set_event_loop(loop), loop.run_forever()),
                 daemon=True).start()
time.sleep(0.3)

loop.call_soon_threadsafe(loop.stop)          # what force_stop() does
time.sleep(0.3)
print("is_closed:", loop.is_closed())         # False -> the guard lets it through

async def victim(): return "ran"

fut = asyncio.run_coroutine_threadsafe(victim(), loop)   # does NOT raise
try:
    print("got:", fut.result(timeout=3))
except TimeoutError:
    print("HANG: never resolves; caller has no timeout")

with contextlib.suppress(Exception):
    loop.close()
try:
    asyncio.run_coroutine_threadsafe(victim(), loop)
except RuntimeError as e:
    print("after close:", e)
is_closed: False
HANG: never resolves; caller has no timeout
after close: Event loop is closed

I have also left this as a comment on #741, since that PR states it closes out the last
members of this family and this variant slips past both its is_closed() check and its
except RuntimeError.

Evidence

The hang leaves a distinctive trace when the loop is finally closed and the un-run
coroutine is garbage collected:

WARNING (bellows.thread_0) [py.warnings] /usr/local/lib/python3.14/asyncio/base_events.py:744:
RuntimeWarning: coroutine 'SerialProtocol.disconnect' was never awaited
  self._ready.clear()

base_events.py:744 is inside BaseEventLoop.close(): the coroutine object was still
unwrapped when the loop was closed.

To be precise, this warning on its own does not distinguish the hang from the
RuntimeError variant — in both cases call() has already constructed the coroutine and
it is later collected unused (my reproduction above emits it on both paths). What
identifies the hang in my case is what came with it: no exception anywhere, no
Retrying in … from config_entries, and ss -tn showing zero connection attempts from
the host for the full 90 s I sampled. The RuntimeError and TypeError variants both
surface an exception to the caller; this one surfaced nothing at all.

The TypeError variant has been reported by users as "NoneType errors", e.g.
home-assistant/core#147509 (SLZB-06 Ethernet coordinator), and is already tracked in #722.

Why USB coordinators appear unaffected

The code path is identical, but a USB serial device essentially never raises
connection_lost during normal operation, so this path is not exercised. Network
coordinators hit it on every disconnect — cable, reboot, power loss, DHCP change.

Reproduction

  1. EZSP coordinator over socket://, use_thread left at its default (True).
  2. Cut power to the coordinator (do not close the TCP connection gracefully — a hard
    power cut is the harsher and more realistic case).
  3. Frequently — but not always — the application never reconnects. In Home Assistant the
    config entry never leaves unload; no retries are scheduled and, in the hang variant,
    nothing is logged at all.

Across the reboots I logged before finding the cause, the coordinator came back on its own
5 times out of 9. I would not read too much into the exact ratio (small sample, and I was
not controlling for which of the three variants fired), but it matches the intermittency
described in #88202 and reported by SLZB-06 users.

Verification that use_thread=False still fixes it

With use_thread=False, _connect() runs on the caller's loop, so
ThreadsafeProxy._obj_loop is the main loop, :100 (loop == curr_loop) is hit first,
and :102/:107 are unreachable. EventLoopThread is never created, so there is no
force_stop() at all.

Measured on the setup above (power cut, nothing touched by hand):

event t delta
power cut 17:59:15 —
connection loss detected, first retry scheduled 17:59:34 19 s
backoff Retrying in 5 s / 10 s 17:59:34 / :45 —
coordinator back up ≈17:59:50 —
application reconnected on its own ≈17:59:58 ≈43 s total

No never awaited warning, no failed unload. Same test with the default
use_thread=True is what produced the trace quoted above.

Suggested fix

The minimal change is ordering: notify the application before the
connection_done future is resolved, so the teardown callback at :148 cannot run
until the upper layers have finished with the proxy — extending the invariant that the
XXX comment quoted above already applies to _startup_reset_future.

To be clear about what I am not proposing: removing the UART thread outright was
already tried in #598 and reverted in #604, because serial-port read notifications depend
on the event loop and any loop slowdown stalls radio traffic. That reasoning is sound and
I am not asking to revisit it — the bug here is the teardown ordering, which is
orthogonal to whether the thread exists.

Alternatives, if the ordering is load-bearing for something I have missed:

  • Have EZSP.disconnect() short-circuit when the gateway's loop is no longer usable,
    instead of awaiting through the proxy — at minimum, ThreadsafeProxy.func_wrapper
    should not return a bare None from a coroutine call site (:105), since that turns
    into a confusing TypeError at the await.
  • Give the run_coroutine_threadsafe path at :107 a timeout so a dead loop degrades
    to an error rather than an unbounded hang.
  • Failing all of the above, restore the use_thread=False default for socket://
    device paths that zigpy/zha#628 removed. Note this is narrower than Remove UART thread #598: Revert "Remove UART thread (#598)" #604's
    objection is specifically about serial fd read notifications, which does not apply to
    a TCP transport with kernel-side buffering. It is not free either — it moves ASH ACK
    timing onto the main loop, which is the same failure mode described in Prevent task cancellation from propagating to ASH #628's comments
    about the 2026.1.0 VAD CPU regression — but as a fallback it is strictly better than the
    current unbounded hang.

Happy to test any patch against the reproduction above.

Activity

  1. zigpy-review-bot commented on Aug 22, 2026

    @zigpy-review-bot
    Collaborator

    Checked this against dev. The ordering you describe is real and your line numbers are right, but I do not think the proposed swap would fix the race — and I think the reason is worth writing down, because it also explains why the symptom is fixable elsewhere.

    The notification at :89 is itself an asynchronous cross-thread dispatch, so it does not serialize anything. In the use_thread=True path, Gateway._api is not the EZSP object — uart.connect() wraps it as ThreadsafeProxy(api, <main loop>) before handing it to _connect(). EZSP.connection_lost is a plain def, so self._api.connection_lost(exc) goes through ThreadsafeProxy.func_wrapper, finds loop != curr_loop, and does loop.call_soon_threadsafe(check_result_wrapper) — it queues the notification on the main loop and returns immediately. Meanwhile connection_done was created on the worker loop inside _connect(), so its done-callback (thread.force_stop()) runs one worker-loop iteration after set_result. Flipping :82 and :89 therefore only changes which of two callbacks is enqueued first on two different loops; the application still has to cross threads and unwind through EZSP.connection_lost → ControllerApplication.connection_lost → listener_event → the config-entry reload before anything reaches await self._ezsp.disconnect(), and the teardown is in flight throughout. The XXX comment above is a genuinely different case: _startup_reset_future is resolved synchronously on the same loop, so its ordering relative to set_result is real.

    The good news is that nothing is actually skipped. By the time force_stop() has run, connection_lost has already been through zigpy's SerialProtocol, which clears _transport and sets the disconnected event. Gateway.disconnect() is SerialProtocol.disconnect() = close() + wait_until_closed(), and both are no-ops in that state. So "the disconnect does not actually run" costs nothing concrete — the only thing that mattered is that the call must neither hang nor raise, which is what makes this fixable in the proxy rather than in the ordering.

    The variant you found is the one that made it unfixable in practice, and that is now closed. Your stopped-but-not-yet-closed row is fixed on #741 (7fb32e7): force_stop() publishes an explicit stopping flag before it schedules anything, and the proxy treats it exactly like a closed loop, so the caller gets a resolved None and a log line instead of an unbounded silent wait. With that, all three rows of your table degrade to "warn and continue" and the reload can proceed to reconnect. There is a named residual on that PR — a force_stop() landing between the proxy's flag check and its dispatch — which I would rather close explicitly than leave implied.

    I verified the environment claims too: CONF_USE_THREAD is set to False in exactly one place in HA dev — components/zha/radio_manager.py:210, on the start_radio=False probe application — and the zha library only declares the constant without ever reading it, so every real ZHA connection does run through the worker thread. That matches your reading.

    What I have deliberately not done is change the teardown trigger, because that is a design call rather than a bug fix: making the worker loop outlive the application's cleanup means force_stop() can no longer hang off connection_done, and something else has to guarantee the thread is eventually stopped when the application never disconnects. The same goes for restoring use_thread=False for socket:// paths — with the #598 / #604 history behind it, that is the maintainers' call, not something I would push. If they want either explored, the fastest way to get me on it is to re-mention me here with what they want built.

    What I checked
    • bellows/uart.py:132-148 and :67-89 on dev; bellows/ezsp/__init__.py:164-166, 228-232, 331-334; bellows/thread.py ThreadsafeProxy.func_wrapper; zigpy/serial.py SerialProtocol.{connection_lost,close,disconnect,wait_until_closed} (zigpy 2.1.0).
    • EZSP.connection_lost is sync, so the proxy takes the call_soon_threadsafe branch — the notification is queued, never awaited.
    • connection_done is created inside _connect(), which runs on the worker loop, so force_stop() is dispatched by that loop.
    • CONF_USE_THREAD: bellows/config/__init__.py:36 defaults it to True; bellows/zigbee/application.py:189 reads it; ha-core dev sets it False only at components/zha/radio_manager.py:210; the zha library declares it at zha/application/const.py:76 with no reader.
    • The hang itself was reproduced directly against bellows.thread before fixing it, and is pinned by a test that fails with TimeoutError on the unpatched code.
  2. jetliuzhe commented on Aug 22, 2026

    @jetliuzhe
    Author

    Thanks — you are right about the ordering, and I verified the specific reason before accepting it.

    uart.py:138 wraps the application object before it ever reaches _connect():

    api = ThreadsafeProxy(api, asyncio.get_event_loop())

    so Gateway._api is a proxy bound to the main loop, and EZSP.connection_lost is a plain
    def (ezsp/__init__.py:331). The call at :89 therefore takes the
    call_soon_threadsafe branch — it queues the notification and returns immediately. Swapping
    :82 and :89 only reorders two callbacks on two different loops. I had read :138 while
    tracing EventLoopThread/force_stop and did not register what it meant for _api.

    Your second point corrects something I overstated. Gateway.connection_lost calls
    super().connection_lost(exc) first (uart.py:69), so by the time anything reaches
    disconnect(), SerialProtocol.connection_lost has already cleared _transport and set
    _disconnected_event — close() is a no-op and wait_until_closed() returns immediately.
    "The disconnect never actually runs" costs nothing concrete; the only thing that mattered was
    that the call must neither hang nor raise. So the useful half of what I filed was the variant
    in the #741 comment, not the fix I proposed here. Feel free to close this issue, or keep it
    for the teardown-trigger design question if that is worth tracking separately.

    Hardware results

    I have a physical EZSP-over-TCP gateway, so I ran the fix on it. Environment:
    homeassistant 2026.4.1, zigpy 1.2.2, bellows 0.49.0, zha 1.1.1, use_thread left at its
    default (True, confirmed by the presence of the bellows.thread_ worker in /proc).

    First, the failure does occur on real hardware, unpatched. I captured it once, with both
    signatures in the same incident:

    13:47:22 WARNING (MainThread) [zigpy.application] Failed to disconnect from radio
    Traceback (most recent call last):
      File ".../zigpy/application.py", line 577, in shutdown
        await self.disconnect()
      File ".../bellows/zigbee/application.py", line 614, in disconnect
        await self._ezsp.disconnect()
      File ".../bellows/ezsp/__init__.py", line 224, in disconnect
        await self._gw.disconnect()
    TypeError: 'NoneType' object can't be awaited
    13:48:13 WARNING (bellows.thread_0) [py.warnings] .../asyncio/base_events.py:744:
             RuntimeWarning: coroutine 'SerialProtocol.disconnect' was never awaited
    

    ZHA did not recover: no reconnect attempts and no TCP connection attempts from the host for
    the 60 s I sampled, and the config entry never left unload.

    Second, and this is the part I want to be straight about: my A/B came back negative.
    I applied #741 (both thread.py and uart.py — patching only thread.py leaves
    loop_thread=None and the new check inert) and ran matched arms, changing nothing but the
    two files:

    arm gateway power cuts wedged recovery
    patched 15 0 5–11 s
    unpatched 10 0 5–11 s

    Both arms are clean, so this does not validate the fix — I could not construct a red
    baseline with power cuts, and the patch's new disconnected branch was never reached during
    them (zero Attempted to use a closed event loop lines across all 15 cuts).

    It was reached in the other patched cycles: during 15 API-triggered disconnects and 3
    firmware-reboot cycles the log shows four

    WARNING (MainThread) [bellows.thread] Attempted to use a closed event loop
    

    lines, and each time the caller carried on and the entry reloaded — which is at least
    evidence that the disconnected path behaves as designed when it is exercised, rather than
    merely never being hit. Across all of those cycles there was no never awaited and no
    NoneType anywhere.

    The one incident I did capture was not a clean power cut. It happened when an
    API-triggered disconnect overlapped a Home Assistant restart — i.e. under concurrent load,
    which lines up with the 2026.1.0 VAD account in zigpy/zha#628. A gateway that simply
    disappears and comes back does not seem to be enough to lose the race on its own here.

    Two caveats on my own numbers, for whatever they are worth to you: the pre-existing failure
    rate I had been working from (roughly 1/3 to 1/2) came from n=3 and n=9 samples taken on an
    older build of my own firmware that had two of its own network bugs, both since fixed. Those
    bugs could plausibly have produced "Zigbee does not come back after a reboot" independently
    of anything in bellows, so I would not lean on those rates. And 25 power cuts is not enough
    to put a useful bound on a rare race.

    Happy to re-run against a build that makes the race more likely if you have one, or to leave
    a longer soak running.

  3. TheJulianJES commented on Aug 22, 2026

    @TheJulianJES
    Contributor

    @zigpy-review-bot Check above. (Also consider latest commits in related PR.)

  4. zigpy-review-bot commented on Aug 22, 2026

    @zigpy-review-bot
    Collaborator

    Checked the hardware results against the code — the #741 arm below is its current head, 7fb32e7. The negative A/B has a mechanical explanation, and it is not a sample-size problem: your power cuts never reached the code the PR changes, and your own logs say so.

    On a socket:// transport a hard power cut produces no FIN — the TCP connection just stalls — so Gateway.connection_lost never fires. The loss surfaces the other way instead: ASH exhausts its ACK retries → AshProtocol._enter_failed_state (ash.py:717) → Gateway.error_received (uart.py:46) → self._api.enter_failed_state(code) → EZSP.connection_lost (ezsp/__init__.py:331) → ControllerApplication.connection_lost → HA's handle_connection_lost schedules the entry reload. That route never touches _connection_done_future, so the force_stop() done-callback at uart.py:148 never runs at all: the worker loop is still fully alive when the reload's EZSP.disconnect() dispatches through the proxy, and the disconnect simply works. None of the three rows of your table can occur.

    Which is exactly what you measured — zero Attempted to use a closed event loop across all 15 patched cuts, but four during the API-triggered disconnects and firmware reboots, i.e. the events where the socket really does close and Gateway.connection_lost really does fire.

    I verified this on real bellows rather than by reading it: bellows.uart.connect() against a local TCP server, then each loss event, on both builds.

    build loss event await proxy.disconnect()
    dev transport close (FIN) TypeError: 'NoneType' object can't be awaited — your field trace, first try
    dev ASH failed state clean — force_stop() never ran, worker loop still open
    #741 transport close clean, resolves
    #741 ASH failed state clean, unchanged

    So the fix is not invalidated by that experiment; it was not exercised by it. And the one incident you did capture — TypeError at ezsp/__init__.py:224 — is the already-closed row, which is precisely what #741's first commits fix.

    How to get a red baseline

    Stop cutting power. Close the TCP connection from the bridge side instead: kill the bridge process, or ss -K the socket on the gateway. That fires connection_lost on the transport, and on unpatched dev it reproduced your exact field failure first try (row 1) with no timing luck involved.

    That buys you the TypeError row deterministically. The hang row needs one more thing, because the window really is tiny: measured against EventLoopThread here, force_stop() → loop.is_closed() is min 0.33 ms, median 1.0 ms, max 3.3 ms (n=20). A reload-driven disconnect arrives tens of milliseconds later, so it lands after the close — that is why the field failure is normally the TypeError, and why your one hang needed a disconnect issued concurrently with the loss (the API disconnect overlapping the HA restart). To take the lottery out of it, widen the window:

    # bellows/thread.py, in EventLoopThread._thread_main's `finally`, before loop.close()
    time.sleep(2)   # hold the loop stopped-but-not-closed

    With that, plus the transport-close event above:

    Both confirmed here. If you want a soak that carries information, that is the arm to soak — the widening changes only the odds of landing in the window, not what is being tested.

    One thing your power-cut path shows in passing: on the ASH-failure route, the ordering you proposed in this issue is what already happens — the application's disconnect() completes on a live worker loop and the teardown follows it, because closing the transport is what finally resolves connection_done. I checked that it does not leak the thread (worker threads 1 → 0 across disconnect()). So that ordering is fine where it occurs; it is the transport-close route that does not get it, and the proxy-side guard is what covers that route.

    Whether to close this or keep it for the teardown-trigger design question is a maintainer's call — not something I will act on either way.

    What I checked
    • Routing read on 7fb32e7 and dev: ash.py:696/717 (_enter_failed_state on NAK/ACK-timeout exhaustion) and ash.py:606 (error frame) → uart.py:46 Gateway.error_received → _api.enter_failed_state → ezsp/__init__.py:336,331 → ControllerApplication.connection_lost (zigpy/application.py:952). uart.py:82 (_connection_done_future.set_result) is only on Gateway.connection_lost, i.e. the transport route.
    • zigpy's watchdog takes the same shortcut (zigpy/application.py:946, "Treat the watchdog failure as a disconnect" → self.connection_lost(e)); bellows sets _watchdog_period = 10 (bellows/zigbee/application.py:86). HA: components/zha/helpers.py:685 → async_schedule_reload → unload → app.shutdown() (zigpy/application.py:602) → disconnect() → EZSP.disconnect().
    • The four-row table is a probe driving real bellows.uart.connect(..., use_thread=True) over asyncio.start_server on 127.0.0.1, with a stub EZSP-shaped API object; loss event A closes the server side of the socket, loss event B calls Gateway.error_received(ERROR_EXCEEDED_MAXIMUM_ACK_TIMEOUT_COUNT) on the worker loop. Then await proxy.disconnect() — the call EZSP.disconnect() makes. On dev, event A raised TypeError and left worker_loop_closed=True; event B left worker_loop_closed=False and returned cleanly.
    • Window measurement: 20 iterations of start → force_stop() → poll to loop.is_closed(), on an otherwise idle machine; Python 3.14.5.
    • Thread-leak check: after event B, threading.enumerate() shows one bellows.thread worker; after await proxy.disconnect(), zero, with stopping=True and self.loop is None.
  5. jetliuzhe commented on Aug 23, 2026

    @jetliuzhe
    Author

    Ran the experiment you described. It reproduces deterministically, and #741 fixes it.

    First, a correction to my last comment that is worth more than the numbers: my power-cut A/B could not have tested this patch, and not only for the reason you gave. When I went to re-run it today there was no bellows.thread_ worker in /proc at all — my own workaround, zha.zigpy_config.use_thread: false, was active in configuration.yaml. Without the worker thread the race is structurally impossible, so the arms were guaranteed to agree. I cannot now reconstruct whether that workaround was active for the whole of the run I reported, so please treat those numbers as withdrawn rather than merely uninformative. Flagging it because it is an easy trap for anyone else trying to reproduce this: the workaround that makes the bug go away also makes the test vacuous, and the fastest check is the thread fingerprint, not the config file.

    Setup

    bellows 0.49.0, zigpy 1.2.2, zha 1.1.1, HA 2026.4.1, physical EZSP-over-TCP gateway. Worker thread confirmed present in /proc for every trial.

    Loss event: closed the TCP connection from the bridge side (the gateway has an API to drop a client), which is the transport-close route you pointed at.

    Window widened per your recipe — time.sleep(2) in EventLoopThread._thread_main's finally, before loop.close() — in both arms, so the comparison is controlled.

    I applied #741 (7fb32e7) on top of 0.49.0. One hunk needed hand-application: force_stop() differs between 0.49.0 and dev, so self.stopping = True was inserted manually at the top. The rest applied cleanly, and the patched arm is confirmed to be running the new code by the presence of Attempted to use an event loop that is shutting down, which exists only on the PR.

    Each trial restarts HA first, so trials are independent. (My first pass did not, and once the first trial wedged there was no client left to disconnect — three "trials" were really one.)

    Results

    arm valid trials wedged never awaited guard fired recovery
    0.49.0 + widening 6 6 6 0 never (>120 s, every trial)
    #741 + widening 8 0 0 8 ~54 s

    Guard messages across the patched arm: 16 × Attempted to use an event loop that is shutting down, 12 × Attempted to use a closed event loop. The new branch is being exercised, not merely present.

    Worth being precise about "recovery": the patch turns never into about a minute, not into instant. Most of that is HA's config-entry retry backoff, not bellows.

    Two things I did not expect

    1. What hangs is the reconnect, not the disconnect.

    Every wedge in the unpatched arm hangs on connect-path coroutines:

    coroutine 'Gateway.reset' was never awaited              (4)
    coroutine 'Gateway.wait_for_startup_reset' was never awaited  (3)
    

    Zero SerialProtocol.disconnect. The discussion here and on #741 is framed around disconnect(), and that is where I found it originally, but in these runs the disconnect completes and it is the re-connect that gets dispatched into the stopping loop and never runs. That is the mechanism that leaves the entry stuck: the setup coroutine never finishes and never fails, so nothing retries.

    2. The two signatures have opposite consequences, which distorts any measurement of this bug.

    signature what HA does
    TypeError: 'NoneType' object can't be awaited logged, entry marked not-ready, retried after 5 s → recovers
    coroutine ... was never awaited (the hang) nothing at all — zero retries, permanent wedge

    In the unpatched wedges: Retrying in count 0, not ready count 0, across all four captured logs. Completely silent.

    So counting "did it wedge" misses every TypeError event, and reading the log for errors misses every hang — the dangerous one is the quiet one. I think this is why field reports of this are so inconsistent.

    One correction to the widening recipe

    The sleep(2) does not only widen the stopped-but-not-closed window. It also reliably lands EventLoopThread.start() in its early-return branch, so the caller reuses the stopped loop. I checked both arms in isolation (no device, just bellows.thread):

    arm start() reuses the stopped loop await proxy.<coro>()
    0.49.0 + widening yes hangs
    #741 + widening yes returns None immediately

    I first read that as a second defect the PR leaves open, and I was wrong: the comment you added in start() says exactly this is intended, and because self.stopping = False sits after the early return, stopping stays True and the proxy rejects instead of hanging. So the widened experiment exercises both paths and the patch covers both — but anyone repeating it should know the widening is doing two things, not one.

    Applicability

    On this hardware the transport-close route is not exotic — it fires on every gateway firmware update, every Zigbee-chip restart, and any deliberate client drop. So this is a routine event, not a corner case, which fits the original TypeError I captured in the field better than the power-cut theory I was working from.

    Happy to run a longer soak, or the same arms without the widening if a rare-event count is useful.

  6. TheJulianJES commented on Aug 23, 2026

    @TheJulianJES
    Contributor

    @zigpy-review-bot Check the above comment. Anything further to fix/PR?

  7. zigpy-review-bot commented on Aug 23, 2026

    @zigpy-review-bot
    Collaborator

    Checked it against 7fb32e7 and dev. The widened A/B holds up, and thanks for withdrawing the power-cut numbers rather than letting them stand — the thread fingerprint really is the right check, and it is worth saying that use_thread: false is not just a workaround but the one setting that makes the experiment vacuous.

    One of your two "did not expect" items does not carry over to bellows, though — and going after it turned up a fourth outcome that is not in your table.

    The reconnect cannot be dispatched into the stopping loop. uart.connect() constructs a fresh EventLoopThread() on every call (uart.py:139, identical in 0.49.0), and nothing else in bellows holds one — so start()'s early-return branch is unreachable from bellows: a reconnect always gets a brand-new loop on a brand-new thread. It is reachable in your isolation arm, because that restarts a single EventLoopThread instance, which bellows never does. Your widened scenario over a real TCP transport (close from the server side, sleep(2) before loop.close()), both arms:

    arm disconnect reconnect
    dev hangs; coroutine 'SerialProtocol.disconnect' was never awaited OK, 3 ms
    #741 OK, immediate — Attempted to use an event loop that is shutting down OK, 7 ms

    So it is still the disconnect that hangs. What makes it present as the reconnect is where that hang sits in HA: inside shutdown() (zigpy/application.py:602), i.e. inside the unload — so the entry never finishes unloading, setup never runs, and nothing schedules a retry. That is your "zero retries, permanent wedge, completely silent" signature; only the attribution moves, not the conclusion.

    Two rows are still open after #741 — both pre-existing, neither introduced by it, and both requiring a disconnect issued concurrently with the loss, which is exactly the incident you captured in the field (an API disconnect overlapping an HA restart):

    • force_stop() landing between the proxy's stopping check and its run_coroutine_threadsafe dispatch — the hang row again, through a window of a few microseconds. This is the residual named on the PR; I reproduced it by forcing that interleaving.
    • force_stop() landing immediately after the dispatch — cancel_tasks_and_stop_loop cancels every task on the loop, including the one just created, so the caller gets a bare CancelledError out of await proxy.disconnect(). That is a fourth outcome, absent from your three-row table: zigpy/application.py:603 catches Exception, not BaseException, so it escapes shutdown() instead of being logged as "Failed to disconnect from radio" and continuing.

    Both close with one change to bellows/thread.py, which I have prototyped and verified locally but not pushed: EventLoopThread tracks the futures it hands the worker loop and the worker thread resolves any the loop never ran on its way out — so no dispatch can wait forever, whatever the interleaving — and the proxy translates a teardown cancellation into the same disconnected result it already returns for a closed or stopping loop. With it, both forced interleavings return cleanly, the widened cycle is unchanged, and pytest tests/ is 451 passed.

    On your offer of more hardware time: I do not think another soak buys anything for #741. The remaining two rows are microsecond interleavings that cannot be landed on demand from outside the process — they need the interleaving forced in-process, which is a unit test, not a device. Your widened arms already cover the part hardware can answer.

    Whether the follow-up lands as commits on #741 or as its own PR is a maintainer's call. Re-mention me here or on #741 and I will push it.

    What I checked
    • Worktree at 7fb32e7 with origin/dev's bellows/{thread,uart}.py swapped in for the dev arm; Python 3.14.5, zigpy 2.1.0, pytest tests/ green on both arms.
    • Reachability of start()'s reuse branch: EventLoopThread is referenced only at uart.py:9 (import) and uart.py:139 (construction inside connect()), on dev and on 0.49.0 alike — every connect() gets a fresh instance whose self.loop is None, so the branch cannot be entered from bellows.
    • Cycle probe: real bellows.uart.connect(..., use_thread=True) against asyncio.start_server on 127.0.0.1 with a stub EZSP-shaped API; loss event = server-side close of the client socket; then await proxy.disconnect() and a fresh uart.connect(), both under asyncio.wait_for. Widening applied by wrapping the worker loop's close() with time.sleep(2), in both arms.
    • Residual row 1: run_coroutine_threadsafe patched to call force_stop() and sleep 50 ms between the proxy's flag check and the dispatch → dev and 7fb32e7 both hang; with the prototype the call returns once the worker thread exits.
    • Residual row 2 (the CancelledError): same hook, but force_stop() fires immediately after the dispatch, with no transport loss at all and stopping == False at the check → CancelledError propagates out of await proxy.disconnect() on 7fb32e7; the prototype returns None with a warning instead.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    Fields

    Priority

    None yet

    Size

    None yet

    Area

    None yet

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions