Modbus RTU (serial) connection fails after first command in 2.5.1, (works in 2.3.0)

[HarrisonPace]

Versions

• Python: 3.8.1
• OS: Linux
• Pymodbus: 2.5.1
• Modbus Hardware (if used):
  MCU via CP2102 (USB)
  Rockwell, Siemens PLCs (FTDI Adapter)
  ESP32 over UART (FTDI Adapter)

Pymodbus Specific

• Client: rtu - sync

Description

This issue was identified as a upstream issue with pymodbus from Home Assistant's Modbus Component.
This issue emerged in Home Assistant 2021.5, when the pymodbus library was updated from 2.3.0 to 2.5.1.

In pymodbus 2.3.0 a Modbus device connected over serial worked but often produced an error on startup in Home Assistant:
Cleanup recv buffer before send: 0x4d 0xfb .

After this error occurred the Modbus client would continue to function correctly and the error would not occur again. Communication between the modbus device functioned as expected.

In pymodbus 2.5.1, serial devices do not work after after the first modbus command. The first command always works but this error is produced and all future modbus commands fail:

2021-05-11 02:10:25 DEBUG (SyncWorker_1) [pymodbus.client.sync] New Transaction state 'SENDING'
2021-05-11 02:10:25 WARNING (SyncWorker_1) [pymodbus.client.sync] Cleanup recv buffer before send: 0x4d 0xfb
2021-05-11 02:10:25 ERROR (SyncWorker_1) [homeassistant.components.modbus.modbus] Pymodbus: Modbus Error: [Input/Output] No Response received from the remote unit/Unable to decode response

Reverting back to pymodbus 2.30 fixes the issue.

It is possible this issue is related: #510

This is a significant issue, as Modbus RTU does not work after the initial command.
Testing was conducted with USB UART connections and RS485 serial connections to several microcontrollers and PLCs.

Speaking with @janiversen, (maintainer of Home Assistant Modbus Component) we identified the issue to be caused by updating to pymodbus 2.5.1.

Code and Logs

Although configuration applies to Home Assistant, I have included it for reference. NOTE: I am not using pymodbus directly, when testing.

  modbus:
  - name: Curtain Controller
    type: serial
    method: rtu
    port: /dev/serial/by-id/usb-www.freetronics.com_0003_95437313934351505191-if00
    baudrate: 9600
    stopbits: 1
    bytesize: 8
    parity: N
    timeout: 10
    switches:
      #Curtain Controller
      - name: "Bedroom Curtain - UP"
        slave: 1
        address: 0
        write_type: coil
      - name: "Bedroom Curtain - Down"
        slave: 1
        address: 1
        write_type: coil
      - name: "Bedroom Curtain - Stop"
        slave: 1
        address: 2
        write_type: coil

[janiversen]

👍 Lets hope this get solved fast and 2.5.2 are release so we can upgrade.

We want to use pymodbus async version, but once the 3.x is released.

[dhoomakethu]

@thehaxxa would you mind giving the complete logs with 2.5.1 and 2.3.0. Pymodbus 2.5.1 closes connection on encountering error. We have seen in some cases adding a small delay after an error is encountered fixes these sort of issue. There should also be kwarg which should disable disconnects after an erroneous transaction. Will try to find it.

[janiversen]

We have the possibility to add a delay between the connect() and the first request, that might help as well.

@dhoomakethu you can see how we use pymodbus here:

modbus.py.gz

If you find the kwarg, it can easily be added.

[HarrisonPace]

We have the possibility to add a delay between the connect() and the first request, that might help as well.

I can confirm the addition of delay: 2 and delay: 5 had no effect in this context.

[janiversen]

@dhoomakethu can we configure (with kwargs or similar) a delay after the error ?

[dhoomakethu]

@thehaxxa No the delay needs to be after an error is received. I will try to see if I can reproduce this issue with the limited hardware I have at my disposal.

[dhoomakethu]

@janiversen we can add additional configuration but it would be helpful if I can get some debug logs to figure out what could be going wrong. I will also take a look in to home assist modbus stack.

[janiversen]

@dhoomakethu I sure can follow you on getting debug logs, that is a supporters nightmare 😁

I am sure @thehaxxa will supply you with those, I am "just" the maintainer of code and use Modbus-tcp.

[HarrisonPace]

would you mind giving the complete logs with 2.5.1 and 2.3.0.

Unfortunately you have them, there is no logging about the Connection or RECEIVE feedback. @janiversen suggested this might be insightful in discussions with him.

I posted all the logging information I have.
I do believe it's a startup issue that may be mitigated by a delay. It would be great if this was configurable in either context.

This is the only logging I have on 2.5.1:

2021-05-11 23:51:58 DEBUG (SyncWorker_1) [pymodbus.client.sync] New Transaction state 'SENDING'
2021-05-11 23:51:58 WARNING (SyncWorker_1) [pymodbus.client.sync] Cleanup recv buffer before send: 0x4d 0xfb
2021-05-11 23:51:58 ERROR (SyncWorker_1) [homeassistant.components.modbus.modbus] Pymodbus: Modbus Error: [Input/Output] No Response received from the remote unit/Unable to decode response

and 2.3.0 has this:

2021-05-11 23:51:58 DEBUG (SyncWorker_2) [pymodbus.client.sync] New Transaction state 'SENDING'
2021-05-11 23:51:58 WARNING (SyncWorker_2) [pymodbus.client.sync] Cleanup recv buffer before send: 0x4d 0xfb
2021-05-11 23:51:58 ERROR (SyncWorker_2) [homeassistant.components.modbus.modbus] Pymodbus: Modbus Error: [Input/Output] No Response received from the remote unit/Unable to decode response

2021-05-11 23:52:00 DEBUG (SyncWorker_14) [pymodbus.client.sync] New Transaction state 'SENDING'
2021-05-11 23:52:00 WARNING (SyncWorker_14) [pymodbus.client.sync] Cleanup recv buffer before send: 0x20 0x43 0x75 0x72 0x74 0x61 0x69 0x6e 0x20 0x53 0x65 0x72 0x76 0x65 0x72 0xd 0xa 0x1 0x5 0x0 0x1 0xff 0x0 0xdd 0xfa

[janiversen]

@dhoomakethu try to simulate your rs-485 delivers garble when opened (my rs485 - rs232 used to do that), as I read the pymodbus code that would lead to a disconnect in 2.5.1 whereas 2.30 would continue

[dhoomakethu]

The connection close was introduced to mitigate some nasty bugs around retries. I thought we finally hit the nail as there was not issue's reported on this topic with 2.5.1 until today 😁 . I will try to reproduce this and see if there is anything else we can do here.

[janiversen]

@dhoomakethu without being deep into your code, allow me a suggestion:
after connect() in client mode, skip anything received until first request is sent. For server mode, you need to add "If not a valid modbus message".

After that I think disconnect() on bad messages is an excellent idea.

[janiversen]

If you want that tested I am sure @thehaxxa can help, if you send a patched python file.