| 123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220221222223224225226227228229230231232233234235236237238239240241242243244245246247248249250251252253254255256257258259260261262263264265266267268269270271272273274275276277278279280281282283284285286287288289290291292293294295296297298299300301302303304305306307308309310311312313314315316317318319320321322323324325326327328329330331 |
- """Letting go of a paho client must never block the thread that let it go.
- #3068: a printer that had been offline 38 hours still answered on 8883. The
- connection watchdog rebuilt its session, which ended in paho's `loop_stop()`
- -- set a terminate flag, then `join()` the network thread with no timeout. The
- network thread was parked in `reconnect()`'s TLS handshake, where it cannot
- read that flag, so the join never returned. The join was running on the asyncio
- thread: the process stayed up, `/health` stopped being answered, and Docker's
- `restart: unless-stopped` never fired because nothing had exited.
- Four call paths reach that join from the event loop -- the connection watchdog,
- the queue dispatch deadline, `check_staleness()` on an ordinary status poll,
- and `disconnect()` from the printer routes. They all funnel through the two
- places tested here. The relay and smart-plug services had the same join on
- their shutdown path and now share the same teardown.
- """
- import asyncio
- import threading
- import time
- from unittest.mock import MagicMock, patch
- import pytest
- from backend.app.services.bambu_mqtt import BambuMQTTClient
- from backend.app.utils.paho_teardown import retire_paho_client
- class WedgedPahoClient:
- """A paho client whose network thread will not stop.
- `loop_stop()` blocks until `release()` is called, which is what a real one
- does while its thread sits in `do_handshake()` against a printer that
- answers TCP and then goes quiet.
- """
- def __init__(self):
- self.released = threading.Event()
- self.disconnect_called = threading.Event()
- self.loop_stop_returned = threading.Event()
- self.on_connect = "sentinel"
- self.on_disconnect = "sentinel"
- self.on_subscribe = "sentinel"
- self.on_message = "sentinel"
- def disconnect(self):
- self.disconnect_called.set()
- def loop_stop(self):
- self.released.wait(timeout=10)
- self.loop_stop_returned.set()
- def release(self):
- self.released.set()
- @pytest.fixture
- def client():
- return BambuMQTTClient(
- ip_address="192.168.1.100",
- serial_number="00M09A123456789",
- access_code="12345678",
- )
- class TestRetiringAClient:
- def test_it_returns_while_the_old_client_is_still_stopping(self):
- wedged = WedgedPahoClient()
- try:
- started = time.monotonic()
- retire_paho_client(wedged, "00M09A123456789")
- elapsed = time.monotonic() - started
- assert elapsed < 2.0, f"retirement blocked the caller for {elapsed:.2f}s (#3068)"
- assert not wedged.loop_stop_returned.is_set(), "loop_stop was joined, not handed off"
- finally:
- wedged.release()
- def test_the_callbacks_are_detached_before_the_caller_moves_on(self):
- # Blocking until the network thread was gone is what used to guarantee
- # a client we had let go of could no longer touch our state. With the
- # teardown detached, a zombie that finishes its handshake would
- # auto-reconnect and set connected=True behind its replacement's back,
- # so the detach has to happen inline.
- wedged = WedgedPahoClient()
- try:
- retire_paho_client(wedged, "00M09A123456789")
- assert wedged.on_connect is None
- assert wedged.on_disconnect is None
- assert wedged.on_subscribe is None
- assert wedged.on_message is None
- finally:
- wedged.release()
- def test_the_old_session_is_still_disconnected_and_stopped(self):
- # disconnect() is what stops paho's auto-reconnect, and with it the
- # chance of an unacked project_file replaying onto a revived session
- # (#1136). Handing it off must not mean skipping it.
- wedged = WedgedPahoClient()
- assert wedged.disconnect_called.wait(timeout=0) is False
- retire_paho_client(wedged, "00M09A123456789")
- assert wedged.disconnect_called.wait(timeout=5), "the old client was never disconnected"
- wedged.release()
- assert wedged.loop_stop_returned.wait(timeout=5), "the old client's loop was never stopped"
- def test_a_client_that_raises_on_teardown_is_still_let_go(self):
- exploding = MagicMock()
- exploding.disconnect.side_effect = RuntimeError("socket already gone")
- exploding.loop_stop.side_effect = RuntimeError("no thread")
- retire_paho_client(exploding, "00M09A123456789")
- deadline = time.monotonic() + 5
- while time.monotonic() < deadline and not exploding.loop_stop.called:
- time.sleep(0.01)
- assert exploding.loop_stop.called
- def test_the_retirement_thread_is_named_for_the_printer(self):
- # A support bundle's thread dump is how the next one of these gets
- # recognised; an anonymous Thread-7 says nothing.
- wedged = WedgedPahoClient()
- try:
- retire_paho_client(wedged, "00M09A123456789")
- names = [t.name for t in threading.enumerate()]
- assert "mqtt-retire-00M09A123456789" in names
- finally:
- wedged.release()
- class TestHardReset:
- def test_it_does_not_wait_for_the_old_network_thread(self, client):
- wedged = WedgedPahoClient()
- client._client = wedged
- client._loop = None # no rebuild, so only the teardown is measured
- try:
- started = time.monotonic()
- client._hard_reset_client()
- elapsed = time.monotonic() - started
- assert elapsed < 2.0, f"_hard_reset_client blocked for {elapsed:.2f}s (#3068)"
- assert client._client is None
- finally:
- wedged.release()
- def test_the_replacement_gets_a_fresh_client_id(self, client):
- # The #1136 property: the new session must not inherit paho's QoS 1
- # queue, which is what a new client_id buys.
- wedged = WedgedPahoClient()
- client._client = wedged
- client._loop = MagicMock()
- with patch("backend.app.services.bambu_mqtt.mqtt.Client") as MockClient:
- MockClient.return_value = MagicMock()
- try:
- client._hard_reset_client()
- finally:
- wedged.release()
- assert MockClient.call_count == 1
- new_id = MockClient.call_args.kwargs["client_id"]
- assert client.serial_number in new_id
- assert client._client is MockClient.return_value
- @pytest.mark.asyncio
- async def test_a_wedged_printer_does_not_stall_the_event_loop(self, client):
- # The reported failure, end to end: force_reconnect_stale_session is
- # what the connection watchdog and the queue dispatch deadline both
- # call, from a coroutine. A heartbeat has to keep ticking through it.
- wedged = WedgedPahoClient()
- client._client = wedged
- ticks = 0
- async def heartbeat():
- nonlocal ticks
- while True:
- await asyncio.sleep(0.02)
- ticks += 1
- beat = asyncio.create_task(heartbeat())
- try:
- with patch("backend.app.services.bambu_mqtt.mqtt.Client") as MockClient:
- MockClient.return_value = MagicMock()
- started = time.monotonic()
- client.force_reconnect_stale_session("offline for 900s, port still answering")
- elapsed = time.monotonic() - started
- await asyncio.sleep(0.1)
- finally:
- beat.cancel()
- wedged.release()
- try:
- await beat
- except asyncio.CancelledError:
- pass
- assert elapsed < 2.0, f"the forced reconnect held the event loop for {elapsed:.2f}s (#3068)"
- assert ticks > 0, "the event loop made no progress while the old client was stopping"
- assert client.state.connected is False
- class TestDisconnect:
- def test_it_does_not_wait_for_the_old_network_thread(self, client):
- # Reached from PUT/DELETE /printers/{id} and POST
- # /printers/{id}/disconnect, all on the asyncio thread.
- wedged = WedgedPahoClient()
- client._client = wedged
- client.state.connected = True
- try:
- started = time.monotonic()
- client.disconnect()
- elapsed = time.monotonic() - started
- assert elapsed < 2.0, f"disconnect() blocked for {elapsed:.2f}s (#3068)"
- assert client._client is None
- assert client.state.connected is False
- finally:
- wedged.release()
- def test_the_disconnect_callback_still_gets_its_window(self, client):
- # The callback that releases the timeout fires on paho's thread, so it
- # has to run before the retirement detaches it -- otherwise every
- # caller with a non-zero timeout waits the timeout out in full.
- class AnsweringClient(WedgedPahoClient):
- def disconnect(self):
- super().disconnect()
- if self.on_disconnect is not None:
- self.on_disconnect(self, None)
- answering = AnsweringClient()
- answering.on_disconnect = client._on_disconnect # as connect() wires it
- client._client = answering
- try:
- started = time.monotonic()
- client.disconnect(timeout=5)
- elapsed = time.monotonic() - started
- assert elapsed < 2.0, (
- f"disconnect(timeout=5) took {elapsed:.2f}s — the callback was detached "
- "before it could report the disconnect"
- )
- assert client._disconnection_event.is_set()
- finally:
- answering.release()
- def test_disconnecting_twice_is_harmless(self, client):
- wedged = WedgedPahoClient()
- client._client = wedged
- try:
- client.disconnect()
- client.disconnect()
- assert client._client is None
- finally:
- wedged.release()
- class TestTheOtherMqttServices:
- """The relay and the smart-plug service tear their brokers down the same
- way, at shutdown. A wedged broker there does not stop request serving --
- nothing is being served by then -- but it does stop the process exiting,
- which leaves the container to be killed rather than stopped."""
- @pytest.mark.asyncio
- async def test_the_relay_does_not_wait_for_its_network_thread(self):
- from backend.app.services.mqtt_relay import MQTTRelayService
- wedged = WedgedPahoClient()
- service = MQTTRelayService()
- service.client = wedged
- service.connected = True
- try:
- started = time.monotonic()
- await service.disconnect()
- elapsed = time.monotonic() - started
- assert elapsed < 2.0, f"relay shutdown blocked for {elapsed:.2f}s (#3068)"
- assert service.client is None
- # Only the retirement detaches callbacks, so this proves it ran
- # rather than the service's except-block swallowing it.
- assert wedged.on_disconnect is None
- finally:
- wedged.release()
- @pytest.mark.asyncio
- async def test_the_smart_plug_service_does_not_wait_for_its_network_thread(self):
- from backend.app.services.mqtt_smart_plug import MQTTSmartPlugService
- wedged = WedgedPahoClient()
- service = MQTTSmartPlugService()
- service.client = wedged
- service.connected = True
- try:
- started = time.monotonic()
- await service.disconnect()
- elapsed = time.monotonic() - started
- assert elapsed < 2.0, f"smart-plug shutdown blocked for {elapsed:.2f}s (#3068)"
- assert service.client is None
- # Only the retirement detaches callbacks, so this proves it ran
- # rather than the service's except-block swallowing it.
- assert wedged.on_disconnect is None
- finally:
- wedged.release()
- class TestDisconnectStaysQuiet:
- def test_a_hand_disconnected_printer_is_not_announced_as_offline(self, client):
- # paho's disconnect callback used to land during the join, but
- # `_on_disconnect` suppresses itself for a clean disconnect of a
- # printer that reported in the last 10s, so a healthy printer
- # disconnected on purpose never broadcast one. Announcing it here
- # instead would reach the connected→disconnected edge and notify the
- # user their printer went offline a minute later (#1752).
- seen = []
- client.on_state_change = seen.append
- client._last_message_time = time.time()
- wedged = WedgedPahoClient()
- client._client = wedged
- client.state.connected = True
- try:
- client.disconnect()
- finally:
- wedged.release()
- assert seen == [], "disconnecting a printer by hand announced it as offline"
- assert client.state.connected is False
|