Periodic Modbus Connection Failure

[lazy-pete]

Describe the bug

Over the last week I have had regular overnight failures of the Solax Modbus Connection.

This occurred with 2024.3.7 and also after downgrading to 2024.02.06 (oldest I could find in HACS).

It seems to fail to connect to my Elfin EW11 ip address and therefore the Waveshare RS485 Modbus module.

Reloading the integration does not rectify the situation, but restarting Home Assistant does, so I don’t think it’s an actual networking issue.

from a day or so ago (I restarted before collecting logs this morning)

Logger: pymodbus.logging Source: custom_components/solax_modbus/init.py:388 integration: SolaX Inverter Modbus (documentation, issues) First occurred: 25 March 2024 at 23:48:14 (61 occurrences) Last logged: 03:27:55

Failed to connect Failed to connect [Errno 113] Connect call failed ('192.168.1.25', 502)

Any suggestions ?

Integration Version

2024.3.7

Homeassistant core version

2024.3.3

Inverter brand

Solis

Plugin used

plugin_solis.py

Serial prefix

60310

Connection Method

Waveshare Adapter, Elfin EW11

Detailed Error Log

No response

Additional context

No response

[adamj89]

+1, same issue here.

[adamj89]

To be more specific, it freezes as soon as the night charge begins (tried changing the time and the problem occurs each time)

[rmu1987]

I also had connection Failures on my Sofar Solar inverter, after upgrading from 2024.3.6 to 2024.3.7.

Downgrading to 2024.3.6 solved the issue.

[wills106]

Try 2024.03.8b1

[lazy-pete]

Logs from last night on 2024.02.06 - will try beta as above

2024-03-27 07:28:41.992 WARNING (SyncWorker_2) [homeassistant.loader] We found a custom integration solax_modbus which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant 2024-03-27 07:29:09.215 ERROR (MainThread) [homeassistant.helpers.event] Error while processing template: Template<template=({{0}}{{ states('number.solax_timed_charge_start_hours') | round(0) }}:{{ states('number.solax_timed_charge_start_minutes') | round(0) }}) renders=2> ValueError: Template error: round got invalid input 'unknown' when rendering template '{{0}}{{ states('number.solax_timed_charge_start_hours') | round(0) }}:{{ states('number.solax_timed_charge_start_minutes') | round(0) }}' but no default was specified homeassistant.exceptions.TemplateError: ValueError: Template error: round got invalid input 'unknown' when rendering template '{{0}}{{ states('number.solax_timed_charge_start_hours') | round(0) }}:{{ states('number.solax_timed_charge_start_minutes') | round(0) }}' but no default was specified 2024-03-27 07:29:09.217 ERROR (MainThread) [homeassistant.components.template.template_entity] TemplateError('ValueError: Template error: round got invalid input 'unknown' when rendering template '{{0}}{{ states('number.solax_timed_charge_start_hours') | round(0) }}:{{ states('number.solax_timed_charge_start_minutes') | round(0) }}' but no default was specified') while processing template 'Template<template=({{0}}{{ states('number.solax_timed_charge_start_hours') | round(0) }}:{{ states('number.solax_timed_charge_start_minutes') | round(0) }}) renders=4>' for attribute '_attr_native_value' in entity 'sensor.charge_start_time' 2024-03-27 07:29:09.218 ERROR (MainThread) [homeassistant.helpers.event] Error while processing template: Template<template=({{0}}{{ states('number.solax_timed_charge_end_hours') | round(0) }}:{{ states('number.solax_timed_charge_end_minutes') | round(0) }}) renders=2> ValueError: Template error: round got invalid input 'unknown' when rendering template '{{0}}{{ states('number.solax_timed_charge_end_hours') | round(0) }}:{{ states('number.solax_timed_charge_end_minutes') | round(0) }}' but no default was specified homeassistant.exceptions.TemplateError: ValueError: Template error: round got invalid input 'unknown' when rendering template '{{0}}{{ states('number.solax_timed_charge_end_hours') | round(0) }}:{{ states('number.solax_timed_charge_end_minutes') | round(0) }}' but no default was specified 2024-03-27 07:29:09.220 ERROR (MainThread) [homeassistant.components.template.template_entity] TemplateError('ValueError: Template error: round got invalid input 'unknown' when rendering template '{{0}}{{ states('number.solax_timed_charge_end_hours') | round(0) }}:{{ states('number.solax_timed_charge_end_minutes') | round(0) }}' but no default was specified') while processing template 'Template<template=({{0}}{{ states('number.solax_timed_charge_end_hours') | round(0) }}:{{ states('number.solax_timed_charge_end_minutes') | round(0) }}) renders=4>' for attribute '_attr_native_value' in entity 'sensor.charge_end_time_set' File "/config/custom_components/solax_modbus/button.py", line 91, in async_press File "/config/custom_components/solax_modbus/init.py", line 458, in async_write_registers_multi 2024-03-29 19:25:05.107 WARNING (MainThread) [custom_components.solax_modbus.plugin_solis] Solis: attempt to read serialnumber failed at 0x80ec File "/config/custom_components/solax_modbus/plugin_solis.py", line 60, in async_read_serialnr File "/config/custom_components/solax_modbus/init.py", line 376, in async_read_input_registers 2024-03-29 19:25:05.110 WARNING (MainThread) [custom_components.solax_modbus.plugin_solis] Solis: reading serial number from address 0x80ec failed; other address may succeed 2024-03-29 19:25:05.110 ERROR (MainThread) [custom_components.solax_modbus.plugin_solis] Solis: cannot find serial number, even not for other Inverter 2024-03-29 19:25:05.110 ERROR (MainThread) [custom_components.solax_modbus.plugin_solis] unrecognized Solis inverter type - serial number : unknown 2024-03-29 19:41:05.086 WARNING (MainThread) [custom_components.solax_modbus.plugin_solis] Solis: attempt to read serialnumber failed at 0x80ec File "/config/custom_components/solax_modbus/plugin_solis.py", line 60, in async_read_serialnr File "/config/custom_components/solax_modbus/init.py", line 376, in async_read_input_registers 2024-03-29 19:41:05.087 WARNING (MainThread) [custom_components.solax_modbus.plugin_solis] Solis: reading serial number from address 0x80ec failed; other address may succeed 2024-03-29 19:41:05.087 ERROR (MainThread) [custom_components.solax_modbus.plugin_solis] Solis: cannot find serial number, even not for other Inverter 2024-03-29 19:41:05.087 ERROR (MainThread) [custom_components.solax_modbus.plugin_solis] unrecognized Solis inverter type -

[chronvas]

I have the same issue, seems something going on with Modbus library using: "version": "2024.03.8"

2024-04-01 WARNING (MainThread) [pymodbus.logging] Failed to connect 
2024-04-01 ERROR (MainThread) [homeassistant] Error doing job: Future exception was never retrieved
pymodbus.exceptions.ConnectionException: Modbus Error: [Connection] Client is not connected

and

Logger: custom_components.solax_modbus
Source: custom_components/solax_modbus/__init__.py:470
integration: SolaX Inverter Modbus (documentation, issues)
First occurred: 6:53:11 PM (2 occurrences)
Last logged: 6:59:14 PM

Unable to connect to Inverter at 10.0.0.5:502

and

Logger: pymodbus.logging
Source: custom_components/solax_modbus/__init__.py:461
integration: SolaX Inverter Modbus (documentation, issues)
First occurred: 6:53:11 PM (2 occurrences)
Last logged: 6:59:14 PM

Failed to connect

The error goes away after a HA restart, then it works ok for a couple of hours, but eventually fails and stops I also have the Elfin EW11 wireless, I doubt that this is the issue since it used to work fine so far, unless the Elfin gives up some times and returns an error, and pymodbus can't recover from that, maybe? not sure

[lazy-pete]

Still getting nightly dropouts.

I’m trying an automation to restart HA when a dropout is detected meantime.

[chronvas]

@lazy-pete that might end up into a loop if it always fails after a restart for some reason, watch out for that. Have you tried if it is possible to restart just the solax-modbus integration?

[adamj89]

My workaround is to do a nightly reboot of HA, scheduled around 5 minutes after night charge begins. Reloading the integration alone doesn't work.

[lazy-pete]

Hi - yes, just reloading the integration doesn’t work.

I use an automation template from another issue thread here, which uses an unavailable status of 15mins for one of the entities. That would reload the integration but not fix the problem.

Restarting home Assistant has always worked so I’m hoping 15mins is long enough for the rebooted setup to be all up and running.

Cheers,

Pete

On Tue, 2 Apr 2024 at 11:14, Adam Jackson @.***> wrote:

My workaround is to do a nightly reboot of HA, scheduled around 5 minutes after night charge begins. Reloading the integration alone doesn't work.

— Reply to this email directly, view it on GitHub https://github.com/wills106/homeassistant-solax-modbus/issues/822#issuecomment-2031609540, or unsubscribe https://github.com/notifications/unsubscribe-auth/AHMEIQ2MVVDTVRTDTIMSGYTY3KAH5AVCNFSM6AAAAABFKTOOHWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDAMZRGYYDSNJUGA . You are receiving this because you were mentioned.Message ID: @.***>

[fbf2201]

For me the last version that works flawlessly without freezing values is 2024.02.5. (I didn't try all the betas of 2024.02.6 thow) My inverter is a Solis RAI-3K-48ES-5G connected with the device's WiFi and Modbus RTU over TCP. I roughly tried to find something specific in the logs during that moment the values froze, but I couldn't find anything that seemed to be helpful. But I have to admit I'm not a programming expert. ;-) Maybe someone has an idea what to look for? (or maybe somewhere else?) I tried all the new nonbeta versions after that, but all freeze after a while. I always have to go back by copying the 2024.02.5 files back to the solax_modbus folder.

Bye, Frank

[chronvas]

I've updated to the latest "2024.04.1"

The errors have slightly changed

Logger: pymodbus.logging
Source: runner.py:188
First occurred: 10:49:24 AM (9 occurrences)
Last logged: 11:09:57 AM

and

Failed to connect

Logger: homeassistant
Source: /usr/src/homeassistant/homeassistant/runner.py:145
First occurred: 10:48:46 AM (18 occurrences)
Last logged: 11:21:37 AM

Error doing job: Future exception was never retrieved
pymodbus.exceptions.ConnectionException: Modbus Error: [Connection] Client is not connected

[lazy-pete]

Hi - I’m still getting periodic dropouts with this, but failing to set up an automatic restart when it does so. It’s becoming a pain having to check messages / dashboards regularly to catch it.

The most obvious sign from my dashboards that the Solax service has stopped is a growing drift between the sensor.solis_RTc time and the local sensor.date_time_iso entity.

I’m wondering if there’s a way to set up an automation that would use the HA Core restart service to trigger if the drift between the two times grew to 15 mins.

Any template experts with an idea ?

Cheers,

Pete

On Wed, 3 Apr 2024 at 11:33, Vasileios Chroniadis @.***> wrote:

I've updated to the latest "2024.04.1"

The errors have slightly changed

Logger: pymodbus.logging Source: runner.py:188 First occurred: 10:49:24 AM (9 occurrences) Last logged: 11:09:57 AM

Failed to connect

Logger: homeassistant Source: /usr/src/homeassistant/homeassistant/runner.py:145 First occurred: 10:48:46 AM (18 occurrences) Last logged: 11:21:37 AM

Error doing job: Future exception was never retrieved pymodbus.exceptions.ConnectionException: Modbus Error: [Connection] Client is not connected

— Reply to this email directly, view it on GitHub https://github.com/wills106/homeassistant-solax-modbus/issues/822#issuecomment-2034198122, or unsubscribe https://github.com/notifications/unsubscribe-auth/AHMEIQ6JXFKSSP63KRRW6QTY3PLG7AVCNFSM6AAAAABFKTOOHWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDAMZUGE4TQMJSGI . You are receiving this because you were mentioned.Message ID: @.***>

[chronvas]

I have re-added the integration and it seems to work fine for the last 24 hours I am using it.

Core 2024.3.3
Supervisor 2024.03.1
Operating System 12.1
Frontend 20240307.0
solax_modbus version 2024.04.1

Latest HA core update 2024.4.x brings some changes to modbus, so a bit reluctant to update core atm

2nd day update: no problem so far, I have this in the logs

Logger: homeassistant
Source: /usr/src/homeassistant/homeassistant/runner.py:145
First occurred: 9:05:51 AM (2 occurrences)
Last logged: 9:47:34 AM

Error doing job: Future exception was never retrieved
pymodbus.exceptions.ConnectionException: Modbus Error: [Connection] Client is not connected

but the integration works fine, seems that it has recovered from this error

[viking2010]

Great integration, but I'm also suffering with a similar issue. I'm seeing 10's of thousands of these errors which are similar to the one listed by the op. 92440 occurrences in 21 hours! I'm using a Solis Hybrid inverter with the integration with the S2-WL-ST adaptor which is plugged in via LAN cable rather than WiFi. Apart from the errors, I see no issues with the data I'm pulling in, so can only think it's from something I'm not showing on any dashboards.

Logger: pymodbus.logging Source: runner.py:188 First occurred: 08:21:58 (92440 occurrences) Last logged: 13:45:42

Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502) Unable to decode response Modbus Error: Unknown response 96

If this is different to the above, then I'm happy to log a new issue. Whilst the error number is different, the Connect call failed is the same. I'm currently going over the debug logging to see what I can find and will update this post shortly.

UPDATE: The logs are full of this:

[2024-04-17 09:00:49.512 WARNING (MainThread) [pymodbus.logging] Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502)
2024-04-17 09:00:49.715 WARNING (MainThread) [pymodbus.logging] Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502)
2024-04-17 09:00:49.918 WARNING (MainThread) [pymodbus.logging] Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502)
2024-04-17 09:00:50.120 WARNING (MainThread) [pymodbus.logging] Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502)
2024-04-17 09:00:50.324 WARNING (MainThread) [pymodbus.logging] Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502)
2024-04-17 09:00:50.527 WARNING (MainThread) [pymodbus.logging] Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502)
2024-04-17 09:00:50.730 WARNING (MainThread) [pymodbus.logging] Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502)
2024-04-17 09:00:50.932 WARNING (MainThread) [pymodbus.logging] Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502)
2024-04-17 09:00:51.134 WARNING (MainThread) [pymodbus.logging] Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502)
2024-04-17 09:00:51.337 WARNING (MainThread) [pymodbus.logging] Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502)
2024-04-17 09:00:51.540 WARNING (MainThread) [pymodbus.logging] Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502)
2024-04-17 09:00:51.743 WARNING (MainThread) [pymodbus.logging] Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502)
2024-04-17 09:00:51.945 WARNING (MainThread) [pymodbus.logging] Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502)
2024-04-17 09:00:52.148 WARNING (MainThread) [pymodbus.logging] Failed to connect [Errno 111] Connect call failed ('192.168.0.12', 502)

and the only other thing I found was this:

2024-04-17 13:45:42.521 ERROR (MainThread) [pymodbus.logging] Unable to decode response Modbus Error: Unknown response 96
2024-04-17 13:45:42.521 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

Hopefully that's of use to you

[chronvas]

@viking2010 The error is a bit different from the original post (111 vs 113) so this might be a different issue.

But just speaking about the number of errors I don't think there is something wrong there. Meaning that e.g. address 192.168.0.12 was not available at the time pymodbus tried to reach it (111, 113, or some other error), and it retried a bunch of times with the same result, which is what I would expect from the integration instead of giving up. The ammount of retries is basically whatever your refresh is set to multiplied by the total ammount of time that this error was present.

Is it the S2-WL-ST device that you have on address 192.168.0.12?

[viking2010]

@chronvas Thanks for the info. It's one of those where it was similar but different!! I've actually disabled a bunch of sensors I'm not using in any views, and this does seem to have stopped the errors, so whether that's related or not, we'll see in time!! If my question muddy's the waters with the original issue, I'm happy to delete the post.

[wills106]

Are people still having issues or can this be closed now?

[lazy-pete]

Hi - I still get the occasional drop-out, but much less often since I reshuffled my home network a bit.

I’ve no idea what changed to trigger the performance issues initially, but it’s better now. It looked from the errors as if comms to the inverter was lost, which I still see, but never recovered which it now seems to sort itself.

Cheers,

P

On Sat, 18 May 2024 at 13:36, wills106 @.***> wrote:

Are people still having issues or can this be closed now?

— Reply to this email directly, view it on GitHub https://github.com/wills106/homeassistant-solax-modbus/issues/822#issuecomment-2118810717, or unsubscribe https://github.com/notifications/unsubscribe-auth/AHMEIQ5UYV6EQNPA6XV2UGDZC5DOLAVCNFSM6AAAAABFKTOOHWVHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMZDCMJYHAYTANZRG4 . You are receiving this because you were mentioned.Message ID: @.***>

[wills106]

Closing down issue for now. Feel free to reopen if required.