AsyncSerialServer running into Exceptions after some hours

[joachim-bl]

I have an AsyncSerialServer running as a modbus slave. The master is a PLC that updates registers of the modbus slave every 10 seconds. Everything works fine, but after about 6+ hours it stops working and bloats the log file with this Exception:

26-01-19 05:35:28 asyncio                   ERROR    Exception in callback SerialTransport.intern_read_ready()
handle: <Handle SerialTransport.intern_read_ready()>
Traceback (most recent call last):
  File "/usr/lib/python3.13/asyncio/events.py", line 89, in _run
    self._context.run(self._callback, *self._args)
    ~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/venvPi/lib/python3.13/site-packages/pymodbus/transport/serialtransport.py", line 134, in intern_read_ready
    self.intern_protocol.data_received(data)  # type: ignore[attr-defined]
    ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^^^^^
  File "/home/venvPi/lib/python3.13/site-packages/pymodbus/transport/transport.py", line 305, in data_received
    self.datagram_received(data, None)
    ~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^
  File "/home/venvPi/lib/python3.13/site-packages/pymodbus/transport/transport.py", line 332, in datagram_received
    cut = self.callback_data(self.recv_buffer, addr=addr)
  File "/home/venvPi/lib/python3.13/site-packages/pymodbus/server/requesthandler.py", line 61, in callback_data
    used_len = super().callback_data(data, addr)
  File "/home/venvPi/lib/python3.13/site-packages/pymodbus/transaction/transaction.py", line 229, in callback_data
    used_len, pdu = self.framer.handleFrame(self.trace_packet(False, data), self.request_dev_id, self.request_transaction_id)
                    ~~~~~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "/home/venvPi/lib/python3.13/site-packages/pymodbus/framer/base.py", line 87, in handleFrame
    if (pdu := self.decoder.decode(frame_data)) is None:
               ~~~~~~~~~~~~~~~~~~~^^^^^^^^^^^^
  File "/home/venvPi/lib/python3.13/site-packages/pymodbus/pdu/decoders.py", line 73, in decode
    pdu.decode(frame[1:])
    ~~~~~~~~~~^^^^^^^^^^^
  File "/home/venvPi/lib/python3.13/site-packages/pymodbus/pdu/register_message.py", line 258, in decode
    self.registers.append(struct.unpack(">H", data[idx : idx + 2])[0])
                          ~~~~~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^
struct.error: unpack requires a buffer of 2 bytes

The code is running on a Raspberry pi zero V.1 on the serial port /dev/serial0. I use pymodbus version 3.11.4. Does anybody know what causes this Exception? How can I bring back my server (slave) into a working mode after such an exception?

[janiversen]

Please run the server with activated (using the pymodbus call) so we can see what is being received.

It looks as if the clients sends a 1 byte package, which also could be noise on the line.

[joachim-bl]

I wonder why bad data would prevent the slave from listening anymore, should it not recover? BTW: I run version 3.11.4 which is marked as latest stable version.

If I set logging level to DEBUG, I get hundreds of these messages per second:
26-01-19 18:44:02 pymodbus.logging DEBUG Frame check failed, possible garbage after frame, testing..

[joachim-bl]

I was waiting for the device to run into the above error, but at the moment it is running and reading data correctly. I attached a log file, showing the current situation (data transfer is correct), but it is full of errors in the background that a device id 16 or 5 does not exist which is strange. I set up the service as a slave with just one device context with the id of 15. Device 16 and 5 are other RS485 devices in the network and to my understanding this software server should ignore them and only listen to 15?
Here is my code that sets up the slave context:

mycontext = ModbusDeviceContext(
            di=ModbusSequentialDataBlock(0, [0] * 100),  # Discrete Inputs
            co=ModbusSequentialDataBlock(0, [0] * 100),  # Coils
            hr=ModbusSequentialDataBlock(0, [0] * 100),  # Holding Registers
            ir=ModbusSequentialDataBlock(0, [0] * 100),  # Input Registers
        )
	global global_context
	global_context = ModbusServerContext(devices={15: mycontext}, single=False)
	args.framer = FramerType.RTU
	args.port = '/dev/serial0'
	args.baudrate = 9600

raspi_service.log.zip

[janiversen]

Well the server do ignore them, but informs that they are being received and ignored. This is valuable information because on a point-to-point line it is most likely a configuration error.

Seems you are trying to use the server on a multipoint line, which is not supported, please see the documentation.

If the stack trace was run while connected to a multipoint line, then it is a known problem, which cannot be solved in software only (hence it is not supported).

[joachim-bl]

My setup is like this:

There is only one master and x slaves involved. I am not an expert in RS485 networking, but this seems to me a very basic setup. Concerning the error message, I understand that a slave reads all communication and filters out what is addressed to him, but I would not expect the slave to throw an error when he encounters a package with a device id that he is not meant to handle. This is not an error, it is something that is very normal, isn´t it?

I checked my master and found that he was polling one device (16) every 100ms, I changed that to 10seconds and this seems to work, at least there was no interruption tonight!

So, am I right in thinking that all the >>>extra: unexpected data in the logs is just data that is send to other devices in the network? If yes: why then is it 'unexpected'?

And one last question: is it possible to get hold of these exceptions thrown in pymodbus in my own code? I wrapped everything in try-except, but I never receive anything, I only see it in the logs.

[janiversen]

That is a multipoint setup (múltiple slaves), which as stated in the documentation are not supported.

The reason being that the start/end of each message cannot be detected correctly in a pure software solution, hardware directly connected to the rs485 is needed to the detect the 3char silence that defines the start/end.

[joachim-bl]

Ok. Thanks anyway for looking into this!

[janiversen]

Based on your input, we are working on a solution that will allow limited multipoint setup support.

It will work if the baud rate <= 19200 and the rs485 cabling is of good quality (meaning no noise on the line, causing malicious bytes).

This will be available in version 3.12 which are just around the corner.

[janiversen]

you can follow the progress on #2846.

[joachim-bl]

That is very good news, looking forward to it! For now I restart my service every 4 hours and i reboot every night, that seems to work so far. If the detection of the end is a problem, in my scenario it would be no problem to poll each device in sequence with a time gap of maybe 1sec between switching to the next device.

[janiversen]

once #2846 is merged, you can test your app. How long a delay you need between messages really depend on how your RS485 connector collects data, which are normally in the micro-second range.

Remark: you can control the timing between polls, but you cannot control how fast your devices respond :-)