Server not handling garbage byte after frame

[brherger]

Thanks for creating and maintaining this package.

We are using a ModbusSerialServer with Python 3.11 and pymodbus==3.9.2.

One of the connected clients is throwing a stray 0x0 at the end of messages occasionally. We suspect this is happening when it resets, but this is out of our control. The server does not deal with this effectively and an exception in throw.

2025-05-08 21:36:01.758 |              pymodbus.logging: 329| [  DEBUG] recv: 0xfe 0x4 0x0 0x3 0x0 0x1 0xd5 0xc5 0x0 old_data:  addr=None
2025-05-08 21:36:01.758 |              pymodbus.logging:  91| [  DEBUG] Processing: 0xfe 0x4 0x0 0x3 0x0 0x1 0xd5 0xc5 0x0
2025-05-08 21:36:01.758 |                       asyncio:  74| [  ERROR] Exception in callback <bound method SerialTransport.intern_read_ready of <pymodbus.transport.serialtransport.SerialTransport object at 0x7faf0995d0>>
handle: <Handle SerialTransport.intern_read_ready>
Traceback (most recent call last):
  File "uvloop/cbhandles.pyx", line 61, in uvloop.loop.Handle._run
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/transport/serialtransport.py", line 134, in intern_read_ready
    self.intern_protocol.data_received(data)  # type: ignore[attr-defined]
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 304, in data_received
    self.datagram_received(data, None)
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 338, in datagram_received
    cut = self.callback_data(self.recv_buffer, addr=addr)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/server/requesthandler.py", line 79, in callback_data
    used_len = super().callback_data(data, addr)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/transaction/transaction.py", line 217, in callback_data
    used_len, pdu = self.framer.processIncomingFrame(self.trace_packet(False, data))
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/framer/base.py", line 76, in processIncomingFrame
    data_len, pdu = self._processIncomingFrame(data[used_len:])
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/framer/base.py", line 97, in _processIncomingFrame
    if (result := self.decoder.decode(frame_data)) is None:
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/pdu/decoders.py", line 112, in decode
    pdu.decode(frame[1:])
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/pdu/register_message.py", line 26, in decode
    self.address, self.count = struct.unpack(">HH", data)
                               ^^^^^^^^^^^^^^^^^^^^^^^^^^
struct.error: unpack requires a buffer of 4 bytes

The "bad" message is not discarded and when the client starts polling again the buffer keeps filling up and the problem compounds to the point where the server is constantly throwing this exception as well as Frame check failed warnings and it has to be restarted.

2025-05-08 21:36:04.389 |              pymodbus.logging: 329| [  DEBUG] recv: 0xfe 0x4 0x0 0x19 0x0 0x1 0xf4 0x2 old_data: 0xfe 0x4 0x0 0x3 0x0 0x1 0xd5 0xc5 0x0 addr=None
2025-05-08 21:36:04.389 |              pymodbus.logging:  91| [  DEBUG] Processing: 0xfe 0x4 0x0 0x3 0x0 0x1 0xd5 0xc5 0x0 0xfe 0x4 0x0 0x19 0x0 0x1 0xf4 0x2
2025-05-08 21:36:04.389 |              pymodbus.logging: 123| [  DEBUG] Frame check failed, possible garbage after frame, testing..
2025-05-08 21:36:04.389 |              pymodbus.logging: 123| [  DEBUG] Frame check failed, possible garbage after frame, testing..
2025-05-08 21:36:04.389 |              pymodbus.logging: 123| [  DEBUG] Frame check failed, possible garbage after frame, testing..
2025-05-08 21:36:04.390 |              pymodbus.logging: 123| [  DEBUG] Frame check failed, possible garbage after frame, testing..
2025-05-08 21:36:04.390 |              pymodbus.logging: 123| [  DEBUG] Frame check failed, possible garbage after frame, testing..
2025-05-08 21:36:04.390 |              pymodbus.logging: 123| [  DEBUG] Frame check failed, possible garbage after frame, testing..
2025-05-08 21:36:04.390 |              pymodbus.logging: 123| [  DEBUG] Frame check failed, possible garbage after frame, testing..
...
...
2025-05-08 21:36:07.889 |              pymodbus.logging: 329| [  DEBUG] recv: 0xfe 0x4 0x0 0x3 0x0 0x1 0xd5 0xc5 old_data: 0xfe 0x4 0x0 0x3 0x0 0x1 0xd5 0xc5 0x0 0xfe 0x4 0x0 0x19 0x0 0x1 0xf4 0x2 0xfe 0x4 0x0 0x19 0x0 0x1 0xf4 0x2 0xfe 0x4 0x0 0x19 0x0 0x1 0xf4 0x2 0xfe 0x4 0x0 0x19 0x0 0x1 0xf4 0x2 0xfe 0x4 0x0 0x19 0x0 0x1 0xf4 0x2 0xfe 0x4 0x0 0x19 0x0 0x1 0xf4 0x2 0xfe 0x4 0x0 0x3 0x0 0x1 0xd5 0xc5 addr=None
2025-05-08 21:36:07.889 |              pymodbus.logging:  91| [  DEBUG] Processing: 0xfe 0x4 0x0 0x3 0x0 0x1 0xd5 0xc5 0x0 0xfe 0x4 0x0 0x19 0x0 0x1 0xf4 0x2 0xfe 0x4 0x0 0x19 0x0 0x1 0xf4 0x2 0xfe 0x4 0x0 0x19 0x0 0x1 0xf4 0x2 0xfe 0x4 0x0 0x19 0x0 0x1 0xf4 0x2 0xfe 0x4 0x0 0x19 0x0 0x1 0xf4 0x2 0xfe 0x4 0x0 0x19 0x0 0x1 0xf4 0x2 0xfe 0x4 0x0 0x3 0x0 0x1 0xd5 0xc5 0xfe 0x4 0x0 0x3 0x0 0x1 0xd5 0xc5
2025-05-08 21:36:07.889 |              pymodbus.logging: 123| [  DEBUG] Frame check failed, possible garbage after frame, testing..
...
... < many more Frame check failed messages >
...
2025-05-08 21:36:07.896 |              pymodbus.logging: 123| [  DEBUG] Frame check failed, possible garbage after frame, testing..
2025-05-08 21:36:07.896 |                       asyncio:  74| [  ERROR] Exception in callback <bound method SerialTransport.intern_read_ready of <pymodbus.transport.serialtransport.SerialTransport object at 0x7faf0995d0>>
handle: <Handle SerialTransport.intern_read_ready>
Traceback (most recent call last):
  File "uvloop/cbhandles.pyx", line 61, in uvloop.loop.Handle._run
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/transport/serialtransport.py", line 134, in intern_read_ready
    self.intern_protocol.data_received(data)  # type: ignore[attr-defined]
    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 304, in data_received
    self.datagram_received(data, None)
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/transport/transport.py", line 338, in datagram_received
    cut = self.callback_data(self.recv_buffer, addr=addr)
          ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/server/requesthandler.py", line 79, in callback_data
    used_len = super().callback_data(data, addr)
               ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/transaction/transaction.py", line 217, in callback_data
    used_len, pdu = self.framer.processIncomingFrame(self.trace_packet(False, data))
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/framer/base.py", line 76, in processIncomingFrame
    data_len, pdu = self._processIncomingFrame(data[used_len:])
                    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/framer/base.py", line 97, in _processIncomingFrame
    if (result := self.decoder.decode(frame_data)) is None:
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/pdu/decoders.py", line 112, in decode
    pdu.decode(frame[1:])
  File "/home/bamboo/peta-async/.tox/py/lib/python3.11/site-packages/pymodbus/pdu/register_message.py", line 26, in decode
    self.address, self.count = struct.unpack(">HH", data)
                               ^^^^^^^^^^^^^^^^^^^^^^^^^^
struct.error: unpack requires a buffer of 4 bytes

[janiversen]

Sounds like a bug, the frame with the 0x0 should be discarded, let me have a look.

[brherger]

Side question. Where is the best place to add a unit test for this such that raw bytes can be injected into the framer and pdu? I saw separate tests for each, but could not determine if there was an integration of both somewhere which is more inclusive. It was hoping to improve diagnosis and contribute in the future. Thanks.

[janiversen]

side response: in the test framework

Framer is responsible for delivering a pdu, so bad bytes are part of the framer.

[janiversen]

Verified bug on v3.9.2 and on dev.