Skip to content

Server not handling garbage byte after frame #2664

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Closed
brherger opened this issue May 9, 2025 · 4 comments · Fixed by #2665
Closed

Server not handling garbage byte after frame #2664

brherger opened this issue May 9, 2025 · 4 comments · Fixed by #2665

Comments

@brherger
Copy link
Contributor

brherger commented May 9, 2025

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
Copy link
Collaborator

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

brherger pushed a commit to brherger/pymodbus that referenced this issue May 9, 2025
ensure unpacking of proper length during decoding (pymodbus-dev#2664)
d4a474c
@brherger
Copy link
Contributor Author

brherger commented May 9, 2025

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
Copy link
Collaborator

side response: in the test framework

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

@janiversen
Copy link
Collaborator

Verified bug on v3.9.2 and on dev.

This was referenced May 9, 2025
Closed
Merged
janiversen added a commit that referenced this issue May 9, 2025
@brherger @janiversen
ensure unpacking of proper length during decoding (#2664) (#2665)
ef44d0f 
Co-authored-by: Beau Herger <[email protected]>
Co-authored-by: jan iversen <[email protected]>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
2 participants
@janiversen @brherger