search

wills106 / homeassistant-solax-modbus

SolaX Power Modbus custom_component for Home Assistant (Supports some Ginlong Solis, Growatt, Sofar Solar, TIGO TSI & Qcells Q.Volt Hyb)
315 stars 98 forks source link

[Bug]: pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request #801

Open sonypsx opened 6 months ago

sonypsx commented 6 months ago

Describe the bug

Hello,

first of all: Really nice work! Go on with this wonderful piece of software! Excellent work!

Facts: Im running this system now quite for a while (since Oct. 2023) without any flaws. I got all the data i was looking for and i STILL get them, but ... Since About 3 -4 releases ago of HA my logfile is growing very fast. The entries which i have pasted in the detailed error.log are repeating every 2 seconds. So its almost impossible to read anything else there.

What i tried to resolve the problem so far: Reboot the Waveshare Delete the integration and readded Reboot the whole HA System (Runs on Raspberry Pi4/4GB Addition hint: a friend of mine runs HA in x86 VM (also with the same Solax Inverter) and is getting the very same error in the logs. Our two systems are not connected!

As far as i know none of the FW Versions are changed since the problem appeared!

Integration Version

2024.03.1

Homeassistant core version

2024.3.0

Inverter brand

Solax X3-Hybrid-G4

Plugin used

plugin_solax.py

Serial prefix

H34A12

Inverter firmware versions

ARM 2.03 , DSP 2.07

Connection Method

Waveshare RS485 TO ETH (B)

Dongle firmware

Waveshare V1. 486

Detailed Error Log

2024-03-10 21:43:39.945 ERROR (MainThread) [pymodbus.logging] General exception: unpack requires a buffer of 4 bytes 2024-03-10 21:43:39.945 ERROR (MainThread) [homeassistant] Error doing job: Fatal error: protocol.data_received() call failed. Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 1017, in _read_ready__data_received self._protocol.data_received(data) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 307, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 341, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/pymodbus/client/base.py", line 186, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/base.py", line 139, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, **kwargs) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/socket_framer.py", line 141, in frameProcessIncomingPacket self._process(callback, tid) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/socket_framer.py", line 148, in _process raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request 2024-03-10 21:43:40.547 ERROR (MainThread) [pymodbus.logging] General exception: unpack requires a buffer of 4 bytes 2024-03-10 21:43:40.547 ERROR (MainThread) [homeassistant] Error doing job: Fatal error: protocol.data_received() call failed. Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 1017, in _read_ready__data_received self._protocol.data_received(data) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 307, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 341, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/pymodbus/client/base.py", line 186, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/base.py", line 139, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, **kwargs) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/socket_framer.py", line 141, in frameProcessIncomingPacket self._process(callback, tid) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/socket_framer.py", line 148, in _process raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request 2024-03-10 21:43:41.146 ERROR (MainThread) [pymodbus.logging] General exception: unpack requires a buffer of 4 bytes 2024-03-10 21:43:41.147 ERROR (MainThread) [homeassistant] Error doing job: Fatal error: protocol.data_received() call failed. Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 1017, in _read_ready__data_received self._protocol.data_received(data) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 307, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 341, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/pymodbus/client/base.py", line 186, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/base.py", line 139, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, **kwargs) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/socket_framer.py", line 141, in frameProcessIncomingPacket self._process(callback, tid) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/socket_framer.py", line 148, in _process raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request

Additional context

No response

tsunami-ad commented 6 months ago

I have an issue too after upgrading home assistant core to 2024.3.0 The solax integration doesnt finds any devices or entities.. before updationg, it worked fine.

chirs-51 commented 6 months ago

i get the same bug after som hours / days its stops working after restart it's Work again just with a growatt sph 3600

sonypsx commented 6 months ago

After the last Core Update (2024.3.1) its getting worse! Only a few entities are visibe now. The errors which i described above are gone but now i have new erros: 2024-03-14 21:24:31.950 WARNING (MainThread) [asyncio] socket.send() raised exception. 2024-03-14 21:24:36.953 WARNING (MainThread) [asyncio] socket.send() raised exception. 2024-03-14 21:24:41.954 WARNING (MainThread) [asyncio] socket.send() raised exception. 2024-03-14 21:24:46.955 WARNING (MainThread) [asyncio] socket.send() raised exception. 2024-03-14 21:27:01.964 WARNING (MainThread) [asyncio] socket.send() raised exception. 2024-03-14 21:27:06.966 WARNING (MainThread) [asyncio] socket.send() raised exception. 2024-03-14 21:27:11.968 WARNING (MainThread) [asyncio] socket.send() raised exception. 2024-03-14 21:27:16.969 WARNING (MainThread) [asyncio] socket.send() raised exception.

Just to mention: my friend which also runs HA and Solax Modbus integration is having the same issues. So i can exclude a local hardware problem.

sonypsx commented 6 months ago

Small Update: i reverted to Core 2024.3.0 -> entities are visible again, but of course the Logentries which mentioned in my first post are back.

tsunami-ad commented 6 months ago

I've disconnected the solax ethernet cable from the router and connected again. Looks like it's working again..

wills106 commented 6 months ago

I have just released 2024.03.2 which forces pyModbus to v3.6.6 v3.6.5 and v3.6.6 have quite a few fixes for various communication related issues by the look. I'm not getting any of these errors people are encounting so I don't know how much of an improvement v3.6.6 will make.

Edit: I would also recommend downloading the update through HACS removing the integration from the Integration page, restarting HA and adding it in again. To ensure there isn't any left over configuration prior to 2024.03.1 stored in the cache.

sonypsx commented 6 months ago

Hello Wills, thanks for the update, did all what: .) remove config -> restart .) delete the integration via HACS -> restart .) add the new one-> restart .) add config

I now have at least values with Core 2024.03.0 and core 2024.03.1 However those loglines are still here with bother core versions!

`2024-03-16 21:05:52.910 ERROR (MainThread) [homeassistant] Error doing job: Fatal error: protocol.data_received() call failed. Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 1017, in _read_readydata_received self._protocol.data_received(data) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 303, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 337, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/pymodbus/client/base.py", line 201, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/base.py", line 139, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, **kwargs) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/socket_framer.py", line 106, in frameProcessIncomingPacket raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request 2024-03-16 21:05:53.916 ERROR (MainThread) [pymodbus.logging] General exception: unpack requires a buffer of 4 bytes 2024-03-16 21:05:53.917 ERROR (MainThread) [homeassistant] Error doing job: Fatal error: protocol.data_received() call failed. Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 1017, in _read_readydata_received self._protocol.data_received(data) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 303, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 337, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/pymodbus/client/base.py", line 201, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/base.py", line 139, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, **kwargs) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/socket_framer.py", line 106, in frameProcessIncomingPacket raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request

`

sonypsx commented 6 months ago

Update: Just installed 2024.03.3 the hard way - e.g. restarts and removing and so on -> Logentries are still here! Gladly the values too!

sonypsx commented 6 months ago

Update: 2024.03.6 -> still the same logentries...

sonypsx commented 6 months ago

Update: Core: 2024.3.3 Frontend: 20240307.0 Solax ModBus: 2024.03.6

-> still the same logentries... Any chance to get rid of that? I also recognized that from time to time i got no data of some or all entities from Solax Modbus, most of the time they come back by itself. Only sometimes i have to restart. If it helps, i have a full backup with from february and a second Raspberry, so i could fire this one up and crosscheck if i have not those logentries - this would proof there is nothing wrong with my RS485 and Solax hardware.

Regards sonypsx

dolce08 commented 6 months ago

Same issue with a Solis Inverter since HA core 2024.3.1

Inverter: Solis RHI-6K-48ES-5G Integration Version: 2024.3.7 HA version: 2024.3.3 Connection method: LAN (DLS-L)

I also receive the error 'Modbus Error: [Input/Output] ERROR: No response received after 3 retries' when attempting RTC sync

sonypsx commented 6 months ago

Update: Integration Version: 2024.3.7 HA Core: 2024.3.3

Loglines repeating: 2024-03-27 08:38:35.092 ERROR (MainThread) [pymodbus.logging] General exception: unpack requires a buffer of 4 bytes 2024-03-27 08:38:35.092 ERROR (MainThread) [homeassistant] Error doing job: Fatal error: protocol.data_received() call failed. Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 1017, in _read_ready__data_received self._protocol.data_received(data) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 303, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 337, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/pymodbus/client/base.py", line 201, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/base.py", line 139, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, **kwargs) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/socket_framer.py", line 106, in frameProcessIncomingPacket raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request

wills106 commented 6 months ago

'Modbus Error: [Input/Output] ERROR: No response received after 3 retries' when attempting RTC sync

Try 2024.03.8b1 those errors should be gone now.

sonypsx commented 6 months ago

Still the same with all recent Updates done. Modbus Integration 2024.03.8 HA Core: 2024.3.3

sonypsx commented 5 months ago

Update: Still the same issue: Modbus Integration 2024.04.2 HA Core: 2024.4.2

litinoveweedle commented 5 months ago

There is/was some error in underlying pymodbus at least use by HA. I think that multiple other recent issue starting to appear from HA 2023.3.0 were probably cause by this:

https://github.com/home-assistant/core/pull/115279

wills106 commented 5 months ago

Do you have anything else connected to the Modbus bus which could be causing communication errors. Or are you running a very long cable between the Inverter and Waveshare?

Have you tried the Bus conflict option mentioned here

dolce08 commented 5 months ago

FYI the latest home assistant 2024.4.3 update has resolved all modbus error messages I was receiving.

wills106 commented 5 months ago

It seems like there has been a whole host of issues with pyModbus on HA https://github.com/home-assistant/core/issues/115236

pyModbus has been updated to v3.6.7

I have just released 2024.04.3 making v3.6.7 the minimum.

sonypsx commented 5 months ago

Everything up2date again - still the same About the cablelength: around 2m long so not pretty short (from working to not working i did not change the cable) I only have the Inverter on that cable connection so not much to disconnect. But reading that there is a quite huge problem with pyModBus, i still didn't lost hope to get this solved.

dolce08 commented 5 months ago

They are continuing to make updates to pyModbus. This issue details non standard implementation of modbus, which I remember reading is the case for some inverter brands https://github.com/home-assistant/core/issues/115489

wills106 commented 5 months ago

I have just released 2024.04.4b1 pushing pyModbus to v3.6.8

sonypsx commented 5 months ago

I have just released 2024.04.4b1 pushing pyModbus to v3.6.8

I just tried out your new beta release still no luck! Loglines are still the same.

wills106 commented 5 months ago

@sonypsx Can you confirm your definitely on v3.6.8 and HA isn't reverting back to an older version. You can check version here

sonypsx commented 5 months ago

@sonypsx Can you confirm your definitely on v3.6.8 and HA isn't reverting back to an older version. You can check version here

homeassistant:/config# pip show pymodbus Name: pymodbus Version: 3.6.8 Summary: A fully featured modbus protocol stack in python Home-page: Author: Galen Collins, Jan Iversen Author-email: License: BSD-3-Clause Location: /usr/local/lib/python3.12/site-packages Requires: Required-by: pystiebeleltron homeassistant:/config#

Yep confirmed - i am on 3.6.8 Thats my current running HA: Core 2024.4.3 Supervisor 2024.04.0 Operating System Frontend 20240404.2

Yours is at: 2024.04.4b1 as you suggested ...

Just rechecked loglines - yes still there

anton4 commented 5 months ago

Other HA modbus integrations are also having the same issues. Here's an example of Sungrow integration - image

More info here - https://github.com/mkaiser/Sungrow-SHx-Inverter-Modbus-Home-Assistant/issues/274 It should all be related to modbus changes made in HomeAssistant 2024.4 version

wills106 commented 4 months ago

@sonypsx is this resolved now?

sonypsx commented 4 months ago

@sonypsx is this resolved now? @wills106

Core 2024.5.4 Supervisor 2024.05.1 Frontend 20240501.1 Solax ModBus 2024.5.4

Sadly still there: 2024-05-21 20:23:48.476 ERROR (MainThread) [pymodbus.logging] General exception: unpack requires a buffer of 4 bytes 2024-05-21 20:23:48.477 ERROR (MainThread) [homeassistant] Error doing job: Fatal error: protocol.data_received() call failed. Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 1017, in _read_ready__data_received self._protocol.data_received(data) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 302, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 336, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/pymodbus/client/base.py", line 207, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/base.py", line 139, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, **kwargs) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/socket_framer.py", line 112, in frameProcessIncomingPacket raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request

wills106 commented 4 months ago

Does it mention which register it's failing to decode?

You might be missing a register in the version of your Inverter.

sonypsx commented 4 months ago

Does it mention which register it's failing to decode?

You might be missing a register in the version of your Inverter.

I wrote earlier that it worked with HA 202403x that error started with HA202404. So it shouldn't have anything to do with the registers.

X3012.0 von SolaX Power Firmware: DSP v1.39 ARM v1.38 Hardware: Gen4 if you lead me how to get that Info about the registers i could do it. In the logs sadly there is no info.

sonypsx commented 3 months ago

Small Update... While HA 2024.06.0 was quite a bugtrap ;) with HA 2024.06.1 and Solax ModBus 2024.05.7 its again the same story:

Traceback (most recent call last): File "/usr/local/lib/python3.12/asyncio/selector_events.py", line 1017, in _read_ready__data_received self._protocol.data_received(data) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 302, in data_received self.datagram_received(data, None) File "/usr/local/lib/python3.12/site-packages/pymodbus/transport/transport.py", line 336, in datagram_received cut = self.callback_data(self.recv_buffer, addr=addr) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ File "/usr/local/lib/python3.12/site-packages/pymodbus/client/base.py", line 207, in callback_data self.framer.processIncomingPacket(data, self._handle_response, slave=0) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/base.py", line 139, in processIncomingPacket self.frameProcessIncomingPacket(single, callback, slave, **kwargs) File "/usr/local/lib/python3.12/site-packages/pymodbus/framer/socket_framer.py", line 112, in frameProcessIncomingPacket raise ModbusIOException("Unable to decode request") pymodbus.exceptions.ModbusIOException: Modbus Error: [Input/Output] Unable to decode request 2024-06-08 20:56:47.119 ERROR (MainThread) [pymodbus.logging] General exception: unpack requires a buffer of 4 bytes 2024-06-08 20:56:47.119 ERROR (MainThread) [homeassistant] Error doing job: Fatal error: protocol.data_received() call failed. (None)

Anything i can do to get/give more details -> appricated!