Modbus RTU does not seem to retry - Pymodbus: hub1: Modbus Error: [Input/Output] Modbus Error: [Invalid Message] No response received, expected at least 4 bytes (0 received)

[cgernert]

The problem

Scan interval is 15 seconds (default). In a time frame from 30 min to 2 h, modbus sporadically misses single replies. Strangely, Modbus does not seem to retry and only requests again 15 seconds (scan interval) later, in the next run.

I have two devices (slave 1 and slave 2) in series. Tested with Waveshare USB FT232RL and now CH343G, but the result is the same.

What version of Home Assistant Core has the issue?

2023.2.5

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

homeassistant.components.modbus

Link to integration documentation on our website

https://www.home-assistant.io/integrations/modbus/

Diagnostics information

log.txt

Example YAML snippet

modbus:
  - name: hub1
    type: serial
    baudrate: 9600
    bytesize: 8
    method: rtu
    parity: N
    port: /dev/ttyACM0
    stopbits: 1
    retry_on_empty: true
    retries: 10
    close_comm_on_error: false
    message_wait_milliseconds: 50
    delay: 1
    timeout: 1
    sensors: !include modbus_sensor.yaml
...
- name: sdm630_phase_1_power_w
  #name: SDM630 P1 WZ SZ EZ
  slave: 1
  address: 12
  input_type: input
  count: 2
  precision: 3
  scale: 1
  data_type: float32
  unit_of_measurement: W
  device_class: power
- name: sdm630_phase_2_power_w
  #name: SDM630 P2 AZ
  slave: 1
  address: 14
  input_type: input
  count: 2
  precision: 3
  scale: 1
  data_type: float32
  unit_of_measurement: W
  device_class: power
- name: sdm630_phase_3_power_w
  #name: SDM630 P3 KÜ HR
  slave: 1
  address: 16
  input_type: input
  count: 2
  precision: 3
  scale: 1
  data_type: float32
  unit_of_measurement: W
  device_class: power
- name: sdm630_total_system_power_w
  slave: 1
  address: 52
  input_type: input
  count: 2
  precision: 3
  scale: 1
  data_type: float32
  unit_of_measurement: W
  device_class: power
- name: sdm630_import_wh_since_last_reset
  slave: 1  
  address: 72
  input_type: input
  count: 2
  precision: 2
  data_type: float32
  unit_of_measurement: kWh
  device_class: energy
- name: sdm630_2_phase_1_power_w
  #name: SDM630 P1 WZ SZ EZ
  unique_id: sdm630_2_phase_1_power_w
  slave: 2
  address: 12
  input_type: input
  count: 2
  precision: 3
  scale: 1
  data_type: float32
  unit_of_measurement: W
  device_class: power

Anything in the logs that might be useful for us?

2023-02-26 19:03:11.609 DEBUG (SyncWorker_1) [pymodbus.transaction] Current transaction state - TRANSACTION_COMPLETE
2023-02-26 19:03:11.610 DEBUG (SyncWorker_1) [pymodbus.transaction] Running transaction 4825
2023-02-26 19:03:11.610 DEBUG (SyncWorker_1) [pymodbus.transaction] SEND: 0x1 0x4 0x0 0xc 0x0 0x2 0xb1 0xc8
2023-02-26 19:03:11.611 DEBUG (SyncWorker_1) [pymodbus.framer.rtu_framer] Changing state to IDLE - Last Frame End - 1677434578.174977, Current Time stamp - 1677434591.610909
2023-02-26 19:03:11.611 DEBUG (SyncWorker_1) [pymodbus.client.base] New Transaction state "SENDING"
2023-02-26 19:03:11.613 DEBUG (SyncWorker_1) [pymodbus.transaction] Changing transaction state from "SENDING" to "WAITING FOR REPLY"
2023-02-26 19:03:11.667 DEBUG (SyncWorker_1) [pymodbus.transaction] Changing transaction state from "WAITING FOR REPLY" to "PROCESSING REPLY"
2023-02-26 19:03:11.668 DEBUG (SyncWorker_1) [pymodbus.transaction] RECV: 0x1 0x4 0x4 0x43 0xc9 0xaa 0x46 0xc1 0x6c
2023-02-26 19:03:11.668 DEBUG (SyncWorker_1) [pymodbus.framer.rtu_framer] Getting Frame - 0x4 0x4 0x43 0xc9 0xaa 0x46
2023-02-26 19:03:11.668 DEBUG (SyncWorker_1) [pymodbus.factory] Factory Response[ReadInputRegistersResponse': 4]
2023-02-26 19:03:11.669 DEBUG (SyncWorker_1) [pymodbus.framer.rtu_framer] Frame advanced, resetting header!!
2023-02-26 19:03:11.669 DEBUG (SyncWorker_1) [pymodbus.transaction] Adding transaction 1
2023-02-26 19:03:11.669 DEBUG (SyncWorker_1) [pymodbus.framer.rtu_framer] Frame - [b'\x01\x04\x04C\xc9\xaaF\xc1l'] not ready
2023-02-26 19:03:11.669 DEBUG (SyncWorker_1) [pymodbus.transaction] Getting transaction 1
2023-02-26 19:03:11.670 DEBUG (SyncWorker_1) [pymodbus.transaction] Changing transaction state from "PROCESSING REPLY" to "TRANSACTION_COMPLETE"
2023-02-26 19:03:12.659 DEBUG (SyncWorker_9) [pymodbus.transaction] Current transaction state - TRANSACTION_COMPLETE
2023-02-26 19:03:12.659 DEBUG (SyncWorker_9) [pymodbus.transaction] Running transaction 4826
2023-02-26 19:03:12.659 DEBUG (SyncWorker_9) [pymodbus.transaction] SEND: 0x1 0x4 0x0 0xe 0x0 0x2 0x10 0x8
2023-02-26 19:03:12.660 DEBUG (SyncWorker_9) [pymodbus.framer.rtu_framer] Changing state to IDLE - Last Frame End - 1677434591.667448, Current Time stamp - 1677434592.660163
2023-02-26 19:03:12.660 DEBUG (SyncWorker_9) [pymodbus.client.base] New Transaction state "SENDING"
2023-02-26 19:03:12.661 DEBUG (SyncWorker_9) [pymodbus.transaction] Changing transaction state from "SENDING" to "WAITING FOR REPLY"
2023-02-26 19:03:14.665 DEBUG (SyncWorker_9) [pymodbus.transaction] Transaction failed. (Modbus Error: [Invalid Message] No response received, expected at least 4 bytes (0 received)) 
2023-02-26 19:03:14.666 DEBUG (SyncWorker_9) [pymodbus.framer.rtu_framer] Frame - [b''] not ready
2023-02-26 19:03:14.666 DEBUG (SyncWorker_9) [pymodbus.transaction] Getting transaction 1
2023-02-26 19:03:14.666 DEBUG (SyncWorker_9) [pymodbus.transaction] Changing transaction state from "PROCESSING REPLY" to "TRANSACTION_COMPLETE"
2023-02-26 19:03:14.666 ERROR (SyncWorker_9) [homeassistant.components.modbus.modbus] Pymodbus: hub1: Modbus Error: [Input/Output] Modbus Error: [Invalid Message] No response received, expected at least 4 bytes (0 received)
2023-02-26 19:03:14.736 DEBUG (SyncWorker_3) [pymodbus.transaction] Current transaction state - TRANSACTION_COMPLETE
2023-02-26 19:03:14.737 DEBUG (SyncWorker_3) [pymodbus.transaction] Running transaction 4827
2023-02-26 19:03:14.737 DEBUG (SyncWorker_3) [pymodbus.transaction] SEND: 0x1 0x4 0x0 0x10 0x0 0x2 0x70 0xe
2023-02-26 19:03:14.738 DEBUG (SyncWorker_3) [pymodbus.framer.rtu_framer] Changing state to IDLE - Last Frame End - 1677434594.665427, Current Time stamp - 1677434594.73794
2023-02-26 19:03:14.738 DEBUG (SyncWorker_3) [pymodbus.client.base] New Transaction state "SENDING"
2023-02-26 19:03:14.740 DEBUG (SyncWorker_3) [pymodbus.transaction] Changing transaction state from "SENDING" to "WAITING FOR REPLY"
2023-02-26 19:03:14.792 DEBUG (SyncWorker_3) [pymodbus.transaction] Changing transaction state from "WAITING FOR REPLY" to "PROCESSING REPLY"
2023-02-26 19:03:14.792 DEBUG (SyncWorker_3) [pymodbus.transaction] RECV: 0x1 0x4 0x4 0x42 0xe1 0xd9 0xf1 0x25 0xde
2023-02-26 19:03:14.792 DEBUG (SyncWorker_3) [pymodbus.transaction] Got response!!!
2023-02-26 19:03:14.793 DEBUG (SyncWorker_3) [pymodbus.framer.rtu_framer] Getting Frame - 0x4 0x4 0x42 0xe1 0xd9 0xf1
2023-02-26 19:03:14.793 DEBUG (SyncWorker_3) [pymodbus.factory] Factory Response[ReadInputRegistersResponse': 4]
2023-02-26 19:03:14.793 DEBUG (SyncWorker_3) [pymodbus.framer.rtu_framer] Frame advanced, resetting header!!
2023-02-26 19:03:14.794 DEBUG (SyncWorker_3) [pymodbus.transaction] Adding transaction 1
2023-02-26 19:03:14.794 DEBUG (SyncWorker_3) [pymodbus.framer.rtu_framer] Frame - [b'\x01\x04\x04B\xe1\xd9\xf1%\xde'] not ready
2023-02-26 19:03:14.794 DEBUG (SyncWorker_3) [pymodbus.transaction] Getting transaction 1
2023-02-26 19:03:14.794 DEBUG (SyncWorker_3) [pymodbus.transaction] Changing transaction state from "PROCESSING REPLY" to "TRANSACTION_COMPLETE"

... NEXT TRY FOR 0x1 0x4 0x0 0xe 0x0 0x2 0x10 0x8 ~ 15 SECS LATER ...

2023-02-26 19:03:27.660 DEBUG (SyncWorker_1) [pymodbus.transaction] Current transaction state - TRANSACTION_COMPLETE
2023-02-26 19:03:27.661 DEBUG (SyncWorker_1) [pymodbus.transaction] Running transaction 4832
2023-02-26 19:03:27.661 DEBUG (SyncWorker_1) [pymodbus.transaction] SEND: 0x1 0x4 0x0 0xe 0x0 0x2 0x10 0x8
2023-02-26 19:03:27.661 DEBUG (SyncWorker_1) [pymodbus.framer.rtu_framer] Changing state to IDLE - Last Frame End - 1677434606.65926, Current Time stamp - 1677434607.661781
2023-02-26 19:03:27.662 DEBUG (SyncWorker_1) [pymodbus.client.base] New Transaction state "SENDING"
2023-02-26 19:03:27.664 DEBUG (SyncWorker_1) [pymodbus.transaction] Changing transaction state from "SENDING" to "WAITING FOR REPLY"
2023-02-26 19:03:27.716 DEBUG (SyncWorker_1) [pymodbus.transaction] Changing transaction state from "WAITING FOR REPLY" to "PROCESSING REPLY"
2023-02-26 19:03:27.717 DEBUG (SyncWorker_1) [pymodbus.transaction] RECV: 0x1 0x4 0x4 0x42 0x20 0x52 0x62 0x52 0xbf
2023-02-26 19:03:27.717 DEBUG (SyncWorker_1) [pymodbus.framer.rtu_framer] Getting Frame - 0x4 0x4 0x42 0x20 0x52 0x62
2023-02-26 19:03:27.718 DEBUG (SyncWorker_1) [pymodbus.factory] Factory Response[ReadInputRegistersResponse': 4]
2023-02-26 19:03:27.718 DEBUG (SyncWorker_1) [pymodbus.framer.rtu_framer] Frame advanced, resetting header!!
2023-02-26 19:03:27.718 DEBUG (SyncWorker_1) [pymodbus.transaction] Adding transaction 1
2023-02-26 19:03:27.718 DEBUG (SyncWorker_1) [pymodbus.framer.rtu_framer] Frame - [b'\x01\x04\x04B RbR\xbf'] not ready
2023-02-26 19:03:27.719 DEBUG (SyncWorker_1) [pymodbus.transaction] Getting transaction 1
2023-02-26 19:03:27.719 DEBUG (SyncWorker_1) [pymodbus.transaction] Changing transaction state from "PROCESSING REPLY" to "TRANSACTION_COMPLETE"

Additional information

[home-assistant[bot]]

Hey there @adamchengtkc, @janiversen, @vzahradnik, mind taking a look at this issue as it has been labeled with an integration (modbus) you are listed as a code owner for? Thanks!

Code owner commands

Code owners of modbus can trigger bot actions by commenting:

• @home-assistant close Closes the issue.
• @home-assistant rename Awesome new title Renames the issue.
• @home-assistant reopen Reopen the issue.
• @home-assistant unassign modbus Removes the current integration label and assignees on the issue, add the integration domain after the command.

_{^{(message by CodeOwnersMention)}}

---

modbus documentation modbus source _{^{(message by IssueLinks)}}

[janiversen]

This is probably a problem in the underlying library pymodbus, we simply pass the parameters.

[cgernert]

OK, sorry about that. Found the issue on their repo: https://github.com/pymodbus-dev/pymodbus/issues/1331

Oh, you are there, too. Did not see that one coming 😁

[chx0003]

Hi, I see that the issue was solved in the pymodbus code, but the error is still happening in HA 2023.3.6 Was the solution already ported to HA? Thanks and Regards

[chx0003]

Just updated to HA 2023.4.2 and the error is still there. It happens (at least in my case) once an hour, almost like a clock. At least an answer would be nice, to know if anybody is following this open issue.

[thrhymes]

i have the same problem missing out on a lot of data from my solar charge controller. suspected a defect solar charge controller...

i use the battery-charge-state and solar power to switch on and off my inverter and this totally messes up my automations and nearly killed my batteries

[cgernert]

Be patient, the fix will be included in pymodbus version 3.3

[jara1]

Hi, thanks to @cgernert and @janiversen it's already fixed in pymodbus v3.2.0, is there plan to integrate this version in HA?

[janiversen]

That is a question you should ask in HA, but since that is also me I will answer.

Short answer is no, for a couple of reasons 3.2.0 are defunct, and the current release is 3.2.2. Version 3.3 is due in June, and that is planned to be integrated in HA. I am not sure it is worth the pain to bump library 2 times within a very short period of time

[jara1]

Thanks for answer. I'm OK with June. I was just curious when it will be.

[RogMoe]

If relevant; I'm experiencing the same issue. I've got 2 Eastron electric meters and get the same error a few times a day.

`Logger: homeassistant.components.modbus.modbus Source: components/modbus/modbus.py:403 Integration: Modbus (documentation, issues) First occurred: 14:47:03 (4 occurrences) Last logged: 16:40:48

Pymodbus: eastron: Modbus Error: [Input/Output] Modbus Error: [Invalid Message] No response received, expected at least 4 bytes (0 received)`

[alex0411]

Hi, the version 3.3.0 of pymodbus was released. Could you integrate this version in HA to get rid of this error: https://pymodbus.readthedocs.io/en/latest/changelog.html#version-3-3-0 Thanks a lot!

[janiversen]

No I cannot, because pymodbus v3.3.0 have a problem that would cause a lot of users in HA to have trouble.

We do not bump a library version until it has matured a bit to avoid child problems.

And just fyi. I am one of the main maintainer of both the HA modbus integration and pymodbus.

And finally it seems you did not test v3.3.0 because it does not help on this problem v3.4.0 will help.

[chx0003]

So, just to be clear, is the parameter retry_on_empty totally useless in the version in production right now? The previous version of the library was working ok (at least in my case) and it seems that a lot of people is afected by this issue reported back in February. Solving it is not a priority ATM? Thanks and Regards

[janiversen]

@alex0411 Just looked a bit deeper into your comments. The changes in pymodbus v3.3.0 is in the async part, so changing to v3.3.0 will not solve your problem!!

What needs to happen is:

1. update the modbus integration to use pymodbus v3.3.x
2. change the modbus integration to use async calls (which now works in pymodbus)
3. Update the configuration of the modbus integration to reflect the new possibilities/limitations.

As I believe, you can imagine, this is not a small task.

[chx0003]

You could also downgrade modbus integration to the previous version, that one didn't present this issue and downgrading is probably a "smaller task" that upgrading.

[janiversen]

Sure that would solve this problem, but reintroduce the problems the upgrade solved, so it is a non-starter.

I only upgrade the integration when there are real benefits to be hands, and not just because a new version is available. This attitude have caused som harder discussions with developers of non-core integrations.

What you could do is take the old version that works for you and install is as a custom_component (just add a version number in the manifest).

[chx0003]

Sure that would solve this problem, but reintroduce the problems the upgrade solved, so it is a non-starter.

I only upgrade the integration when there are real benefits to be hands, and not just because a new version is available. This attitude have caused som harder discussions with developers of non-core integrations.

What you could do is take the old version that works for you and install is as a custom_component (just add a version number in the manifest).

Thanks for the tip, I didn't know I could do that. I will try to copy the old version of modbus to the custom_components folder of HA and if that superseeds the current version used by HA it should solve the problem. I'll report back when it's done.

[chx0003]

Reporting back: success!

I had to go back to version 2.5.3 of modbus component (extracted from HA 2023.1.7) and the error is gone.

Also noticed that after v2.5.3, you've implemented v3.1.1 and v3.1.3 in HA, both of them have this issue, but are updated to support python3.7 and above, so I don't know how much longer v2.5.3 will work with the coming versions of HA.

According to the changelogs of PyModbus, v3.2.0 addresses especifically the issue being reported here. "Forward retry_on_empty and retries by calling transaction (1401)"(https://pymodbus.readthedocs.io/en/latest/changelog.html#version-3-2-0)

So as suggested in previous comments, applying that version or newer to HA should solve the issue, shouldn't it?

[janiversen]

Could be you are welcome to test it, now you have a custom component

[chx0003]

Yes, I have the v2.5.3 of modbus working as a custom component, but how can I test v3.2.0 of PyModbus as a custom component of HA? The versions that I've seen ported to HA are only v2.5.3, v3.1.1 and v3.1.3 How can I port a different version of PyModbus to work with HA? Thanks for your help

[janiversen]

update the manifest and hope there are no software changes needed.

[chx0003]

I hope I've understood correctly what you meant.

Here is what I did: -Took modbus component folder from the last HA release (2023.5.4) -Placed that folder inside the custom_components folder of my HA host -Manually edited the file manifest.json from that folder adding the line: "version": "3.2.0", and changing the line "requirements": ["pymodbus==3.1.3"] to "requirements": ["pymodbus==3.2.0"] -Restarted HA

The result is that the issue reported here is gone and no other errors show for modbus! Plus, I believe that now I'm using v3.2.0 of PyModbus called from a custom component of HA. The only downside that I see with this solution is that the custom component won't be updated automatically when you update the modbus component in HA.

After this test, could you update the manifest file included in the modbus component of HA to use at least v3.2.0 of PyModbus?

Thanks and Regards

[janiversen]

No I cannot due to other errors, but you have a solution.

[chx0003]

Yes, I do. Thanks

[alex0411]

Hi, the usage of the custom component and update to 3.2.0 also solved my issue. Thanks

[hattmann]

Hi chx0003, thanyk you very much, your fix solved my issues completly!

[janiversen]

Please be aware the next release of HA will upgrade the modbus integration to use pymodbus version 3.3.1

We specifically skipped version 3.2.0 because of some errors that affects the integration severely (of course depending on the configuration).