diff --git a/dali/driver/serial.py b/dali/driver/serial.py index 2c5c729..dc33878 100644 --- a/dali/driver/serial.py +++ b/dali/driver/serial.py @@ -660,18 +660,30 @@ async def send_dali_command( ) if confirm.error_code is not None: raise TransmissionError(confirm.error_code) + if ( + hasattr(confirm.message, "frame") + and confirm.message.frame != tx.frame + ): + # A confirmation for a different frame can only be a + # stale one for an earlier send whose confirmation + # arrived after it had already timed out: sends are + # serialised under '_tx_lock', so nothing later is in + # flight yet. Drop it and keep waiting for this frame's + # own confirmation, otherwise every subsequent send + # inherits the one-off mismatch and the stream never + # resynchronises. + _LOG.warning( + "Discarding stale LUBA confirmation for '%s' " + "while awaiting '%s'", + confirm.message, + tx, + ) + continue if hasattr(confirm.message, "frame"): - if confirm.message.frame == tx.frame: - _LOG.trace( - f"LUBA device reports message '{tx}' sent, " - f"with ID {confirm.tx_id}" - ) - else: - _LOG.error( - "Expected LUBA device to confirm transmission " - f"of message '{tx}', but got a confirmation " - f"for '{confirm.message}'" - ) + _LOG.trace( + f"LUBA device reports message '{tx}' sent, " + f"with ID {confirm.tx_id}" + ) else: _LOG.debug( f"Unable to decode message id {confirm.tx_id}, but " diff --git a/dali/tests/test_serial_driver.py b/dali/tests/test_serial_driver.py index aad20e4..1acea61 100644 --- a/dali/tests/test_serial_driver.py +++ b/dali/tests/test_serial_driver.py @@ -6,11 +6,12 @@ import pytest -from dali.address import DeviceShort, InstanceNumber +from dali.address import DeviceShort, GearShort, InstanceNumber from dali.command import NumericResponse from dali.device.general import QueryInstanceType from dali.device.helpers import check_bad_rsp from dali.driver.serial import _DALI_FRAMING_ERROR, DriverLubaRs232 +from dali.gear.general import QueryActualLevel @pytest.mark.asyncio @@ -149,6 +150,35 @@ async def test_connect_reopens_the_port_after_a_lost_transport(monkeypatch): assert driver._protocol is replacement +@pytest.mark.asyncio +async def test_send_dali_command_resyncs_after_stale_confirmation(caplog): + """A stale confirmation must not desync every following transmission. + + A weak bus can let a send's confirmation arrive after it timed out; the + next send then finds that stale confirmation queued ahead of its own. It + must be discarded and the matching one awaited, so the stream recovers + instead of every later frame inheriting the one-off mismatch. + """ + protocol = DriverLubaRs232.LubaProtocol() + protocol.transport = MagicMock() + protocol.rx_idle.set() + + command = QueryActualLevel(GearShort(0)) + stale = QueryActualLevel(GearShort(1)) + protocol._queue_tx_conf.put_nowait( + protocol.LubaMsgTxConf(tx_id=1, message=stale) + ) + protocol._queue_tx_conf.put_nowait( + protocol.LubaMsgTxConf(tx_id=2, message=command) + ) + + with caplog.at_level(logging.WARNING, logger="dali.driver"): + await protocol.send_dali_command(command) + + assert protocol._queue_tx_conf.empty() + assert any("stale LUBA confirmation" in r.getMessage() for r in caplog.records) + + @pytest.mark.asyncio async def test_reset_luba_response_drains_all(caplog): """Stale LUBA command replies must be cleared before a handshake retry."""