Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Multiple drops of communication #210

Open
Omega00123 opened this issue Oct 28, 2023 · 20 comments
Open

Multiple drops of communication #210

Omega00123 opened this issue Oct 28, 2023 · 20 comments
Assignees

Comments

@Omega00123
Copy link

Hello I am using the Solar edge integration now for 4 weeks and found it to be a good integration. It dos however create multiple errors in my log and I have not got proof but it seems to make the total system unstable. 172.116.0.114 is my Soloar edge controller.

Here is a copy of part of the log which I see regularly:

File "/usr/local/lib/python3.11/site-packages/pymodbus/client/tcp.py", line 262, in _handle_abrupt_socket_close
raise ConnectionException(msg)
pymodbus.exceptions.ConnectionException: Modbus Error: [Connection] ModbusTcpClient(172.116.0.114:1502): Connection unexpectedly closed 0.00030922889709472656 seconds into read of 8 bytes without response from slave before it closed connection
2023-10-27 20:20:05.767 ERROR (MainThread) [pymodbus.logging] Connection to (172.116.0.114, 1502) failed: [Errno 113] Host is unreachable
2023-10-27 20:20:05.768 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 172.116.0.114:1502
2023-10-27 20:21:01.766 ERROR (MainThread) [pymodbus.logging] Connection to (172.116.0.114, 1502) failed: timed out
2023-10-27 20:21:01.769 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 172.116.0.114:1502
2023-10-27 20:21:18.219 WARNING (MainThread) [haffmpeg.core] Timeout while waiting of FFmpeg
2023-10-27 20:32:29.353 WARNING (MainThread) [homeassistant.components.websocket_api.http.connection] [140293215605440] from 172.116.0.102 (Home Assistant/2023.7 (io.robbie.HomeAssistant; build:2023.471; iPadOS 15.8.0)): Disconnected: Did not receive auth message within 10 seconds
2023-10-27 21:59:04.269 WARNING (MainThread) [homeassistant.components.sonos.speaker] No recent activity and cannot reach Woonkamer, marking unavailable
2023-10-27 21:59:45.612 WARNING (Thread-5) [pychromecast.socket_client] [Huiskamer(172.116.0.11):8009] Heartbeat timeout, resetting connection
2023-10-27 22:00:15.624 ERROR (Thread-5) [pychromecast.socket_client] [Huiskamer(172.116.0.11):8009] Failed to connect to service ServiceInfo(type='host', data=('172.116.0.11', 8009)), retrying in 5.0s
2023-10-28 06:20:13.652 ERROR (MainThread) [custom_components.solaredge_modbus] Error reading modbus data
Traceback (most recent call last):
File "/config/custom_components/solaredge_modbus/init.py", line 232, in async_refresh_modbus_data
update_result = self.read_modbus_data()

What can it be?

@adibis
Copy link

adibis commented Nov 3, 2023

When you say entire system unresponsive, do you mean home assistant becomes unresponsive and won't let you interact with it?

If yes then that's exactly what I have noticed too. I just got the inverter, installed the integration and my system started to lag/fail to connect/etc

Removing the integration gets rid of this.

I unfortunately don't have logs right now. I'll try to post something tomorrow if I can get it.

@mauriziosacca
Copy link

mauriziosacca commented Dec 3, 2023

I'm experiencing the same issue.
The entire system becomes unresponsive and many others integration stop working; not just custom integrations, native ones too.
I got rid of the problem by disabling this integration and everything starts working again.
I did some tests always with the same result: the problem disappears when I disable this integration.
Here are an extract of last test's logs. In some tests the "successfully connected to 192.168.10.51:1502" and "modbus client is not connected, trying to reconnect" steps repeated dozens of times at 30 second intervals.
Of course the issue doesn't always occur, at the time of writing it is working fine.

2023-12-03 13:21:34.999 WARNING (SyncWorker_2) [homeassistant.loader] We found a custom integration solaredge_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
2023-12-03 13:59:55.302 ERROR (MainThread) [custom_components.solaredge_modbus] Error reading modbus data
Traceback (most recent call last):
File "/config/custom_components/solaredge_modbus/init.py", line 232, in async_refresh_modbus_data
update_result = self.read_modbus_data()
^^^^^^^^^^^^^^^^^^^^^^^
File "/config/custom_components/solaredge_modbus/init.py", line 307, in read_modbus_data
self.read_modbus_data_inverter()
File "/config/custom_components/solaredge_modbus/init.py", line 593, in read_modbus_data_inverter
inverter_data = self.read_holding_registers(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/config/custom_components/solaredge_modbus/init.py", line 291, in read_holding_registers
return self._client.read_holding_registers(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/client/mixin.py", line 102, in read_holding_registers
return self.execute(
^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/client/base.py", line 177, in execute
if self.use_sync:
^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 168, in execute
response, last_exception = self._transact(
^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 313, in _transact
result = self._recv(response_length, full)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 343, in recv
read_min = self.client.framer.recvPacket(min_size)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/base.py", line 77, in recvPacket
return self.client.recv(size)
^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/client/tcp.py", line 210, in recv
ready = select.select([self.socket], [], [], end - time
)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/client/tcp.py", line 257, in _handle_abrupt_socket_close
if data:
pymodbus.exceptions.ConnectionException: Modbus Error: [Connection] ModbusTcpClient(192.168.10.51:1502): Connection unexpectedly closed 11.543798685073853 seconds into read of 8 bytes without response from slave before it closed connection
2023-12-03 14:00:13.762 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2023-12-03 14:00:13.783 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.10.51:1502
2023-12-03 14:05:43.771 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2023-12-03 14:05:43.780 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.10.51:1502
2023-12-03 14:08:13.951 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2023-12-03 14:08:16.993 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.10.51:1502
2023-12-03 14:14:46.477 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2023-12-03 14:14:46.504 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.10.51:1502
2023-12-03 14:16:16.574 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2023-12-03 14:16:34.970 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.10.51, 1502) failed: [Errno 113] Host is unreachable
2023-12-03 14:16:34.971 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.10.51:1502
2023-12-03 14:16:46.575 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2023-12-03 14:16:49.657 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.10.51, 1502) failed: [Errno 113] Host is unreachable
2023-12-03 14:16:49.658 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.10.51:1502
2023-12-03 14:17:16.576 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2023-12-03 14:17:16.608 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.10.51:1502
2023-12-03 14:22:46.639 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2023-12-03 14:22:46.658 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.10.51:1502
2023-12-03 14:28:47.614 ERROR (MainThread) [custom_components.solaredge_modbus] Error reading modbus data
Traceback (most recent call last):
File "/config/custom_components/solaredge_modbus/init.py", line 232, in async_refresh_modbus_data
update_result = self.read_modbus_data()
^^^^^^^^^^^^^^^^^^^^^^^
File "/config/custom_components/solaredge_modbus/init.py", line 307, in read_modbus_data
self.read_modbus_data_inverter()
File "/config/custom_components/solaredge_modbus/init.py", line 593, in read_modbus_data_inverter
inverter_data = self.read_holding_registers(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/config/custom_components/solaredge_modbus/init.py", line 291, in read_holding_registers
return self._client.read_holding_registers(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/client/mixin.py", line 102, in read_holding_registers
return self.execute(
^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/client/base.py", line 177, in execute
if self.use_sync:
^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 168, in execute
response, last_exception = self._transact(
^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 313, in _transact
result = self._recv(response_length, full)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 343, in recv
read_min = self.client.framer.recvPacket(min_size)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/base.py", line 77, in recvPacket
return self.client.recv(size)
^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/client/tcp.py", line 210, in recv
ready = select.select([self.socket], [], [], end - time
)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/client/tcp.py", line 257, in _handle_abrupt_socket_close
if data:
pymodbus.exceptions.ConnectionException: Modbus Error: [Connection] ModbusTcpClient(192.168.10.51:1502): Connection unexpectedly closed 4.5299530029296875e-05 seconds into read of 8 bytes without response from slave before it closed connection
2023-12-03 14:29:17.607 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2023-12-03 14:29:17.615 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.10.51:1502
2023-12-03 14:31:22.139 ERROR (MainThread) [custom_components.solaredge_modbus] Error reading modbus data
Traceback (most recent call last):
File "/config/custom_components/solaredge_modbus/init.py", line 232, in async_refresh_modbus_data
update_result = self.read_modbus_data()
^^^^^^^^^^^^^^^^^^^^^^^
File "/config/custom_components/solaredge_modbus/init.py", line 307, in read_modbus_data
self.read_modbus_data_inverter()
File "/config/custom_components/solaredge_modbus/init.py", line 593, in read_modbus_data_inverter
inverter_data = self.read_holding_registers(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/config/custom_components/solaredge_modbus/init.py", line 291, in read_holding_registers
return self._client.read_holding_registers(
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/client/mixin.py", line 102, in read_holding_registers
return self.execute(
^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/client/base.py", line 177, in execute
if self.use_sync:
^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 168, in execute
response, last_exception = self._transact(
^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 313, in _transact
result = self._recv(response_length, full)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/transaction.py", line 343, in recv
read_min = self.client.framer.recvPacket(min_size)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/framer/base.py", line 77, in recvPacket
return self.client.recv(size)
^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/client/tcp.py", line 210, in recv
ready = select.select([self.socket], [], [], end - time
)
^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
File "/usr/local/lib/python3.11/site-packages/pymodbus/client/tcp.py", line 257, in _handle_abrupt_socket_close
if data:
pymodbus.exceptions.ConnectionException: Modbus Error: [Connection] ModbusTcpClient(192.168.10.51:1502): Connection unexpectedly closed 4.447946548461914 seconds into read of 8 bytes without response from slave before it closed connection
2023-12-03 14:31:47.699 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2023-12-03 14:31:47.714 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.10.51:1502
2023-12-03 14:34:18.012 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2023-12-03 14:34:18.018 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.10.51:1502

@ChristophCaina
Copy link
Contributor

the logs from the topic opener seem to be a network issue:

File "/usr/local/lib/python3.11/site-packages/pymodbus/client/tcp.py", line 262, in _handle_abrupt_socket_close
raise ConnectionException(msg)
pymodbus.exceptions.ConnectionException: Modbus Error: [Connection] ModbusTcpClient(172.116.0.114:1502): Connection unexpectedly closed 0.00030922889709472656 seconds into read of 8 bytes without response from slave before it closed connection
2023-10-27 20:20:05.767 ERROR (MainThread) [pymodbus.logging] Connection to (172.116.0.114, 1502) failed: [Errno 113] Host is unreachable
2023-10-27 20:20:05.768 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 172.116.0.114:1502
2023-10-27 20:21:01.766 ERROR (MainThread) [pymodbus.logging] Connection to (172.116.0.114, 1502) failed: timed out
2023-10-27 20:21:01.769 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 172.116.0.114:1502
2023-10-27 20:21:18.219 WARNING (MainThread) [haffmpeg.core] Timeout while waiting of FFmpeg
2023-10-27 20:32:29.353 WARNING (MainThread) [homeassistant.components.websocket_api.http.connection] [140293215605440] from 172.116.0.102 (Home Assistant/2023.7 (io.robbie.HomeAssistant; build:2023.471; iPadOS 15.8.0)): Disconnected: Did not receive auth message within 10 seconds
2023-10-27 21:59:04.269 WARNING (MainThread) [homeassistant.components.sonos.speaker] No recent activity and cannot reach Woonkamer, marking unavailable
2023-10-27 21:59:45.612 WARNING (Thread-5) [pychromecast.socket_client] [Huiskamer(172.116.0.11):8009] Heartbeat timeout, resetting connection
2023-10-27 22:00:15.624 ERROR (Thread-5) [pychromecast.socket_client] [Huiskamer(172.116.0.11):8009] Failed to connect to service ServiceInfo(type='host', data=('172.116.0.11', 8009)), retrying in 5.0s
2023-10-28 06:20:13.652 ERROR (MainThread) [custom_components.solaredge_modbus] Error reading modbus data
Traceback (most recent call last):
File "/config/custom_components/solaredge_modbus/init.py", line 232, in async_refresh_modbus_data
update_result = self.read_modbus_data()

This is the Error logged for Modbus:
Connection unexpectedly closed
2023-10-27 20:20:05.767 ERROR (MainThread) [pymodbus.logging] Connection to (172.116.0.114, 1502) failed: [Errno 113] Host is unreachable

But there are also similar issues for other integrations:

from 172.116.0.102 (Home Assistant/2023.7 (io.robbie.HomeAssistant; build:2023.471; iPadOS 15.8.0)): Disconnected: Did not receive auth message within 10 seconds
2023-10-27 21:59:04.269 WARNING (MainThread) [homeassistant.components.sonos.speaker] No recent activity and cannot reach Woonkamer, marking unavailable
2023-10-27 21:59:45.612 WARNING (Thread-5) [pychromecast.socket_client] [Huiskamer(172.116.0.11):8009] Heartbeat timeout, resetting connection
2023-10-27 22:00:15.624 ERROR (Thread-5) [pychromecast.socket_client] [Huiskamer(172.116.0.11):8009] Failed to connect to service ServiceInfo(type='host', data=('172.116.0.11', 8009)), retrying in 5.0s

There is also the question:

  1. Is the inverter connected per ethernet (wired) or wifi?
  2. What Firmware versions are running?

--> You can get the information when using the Core-Integration (connected to the Web API) - they are provided as attributes within the "Inverters" Sensor:

image

That's pretty sure either a network issue, or something with the inverter (Firmware) - but not a general issue with the integration itself.

@mauriziosacca
Copy link

This is my inverter:

  • name: Inverter 1
    manufacturer: SolarEdge
    model: SE3000H-RW000NWN2
    communicationMethod: WIFI
    cpuVersion: 3.2221.0
    SN: *******
    connectedOptimizers: 9

@ChristophCaina
Copy link
Contributor

So you are connected via WiFi...
Can you try to Connect via Ethernet to See, If this would make the Connection more stable?

At least, that would rule Out one possible source

@mauriziosacca
Copy link

Unfortunately I can not. Inverter and router are separated by a wall, without doors or windows, and I have no way to pass an ethernet cable, except through the pipes where the electrical cables pass, and in that case the operation would be complex

@ChristophCaina
Copy link
Contributor

The Problem is, that there were issues in the past where the Inverter caused disconnects when it was connected via WiFi.

Such disconnects are hard to identify - at least, it's unlikely that they are caused by the Integration itself.

You might also get in contact with the Solar Edge Support to Check this from the Inverter Side.

@TroLoos
Copy link

TroLoos commented Dec 24, 2023

Yes, I confirm - there is a serious issue with these hiccups. Whole HA Core becomes unavailable for 30 seconds. It makes whole HA installation very unstable... I started to monitor this unstability with Uptime Kuma, and sensor loads HA webpage. Here's how it looks like on a fresh HA installation (Docker container) with only SolarEdge Modbus integration installed (nothing else at all):

Screenshot 2023-12-24 at 16 15 01

Those vertical red lines are the moments when HA is unavailable.

And here's as a contrary example fully loaded HA instance with no SolarEdge Modbus integration:

Screenshot 2023-12-24 at 16 15 21

I've spent last couple of that trying to filter out which integration causes such instability... Of course ping to HA host works all the time, only 'homeassistant' container is blocker and freezes.

@binsentsu binsentsu self-assigned this Dec 31, 2023
@binsentsu
Copy link
Owner

binsentsu commented Dec 31, 2023

I think the reason is that the sensor values are currently updated within the main HA thread. As long as there is a quick and stable connection towards the inverter this does not pose a problem. But if connecting/getting the values takes a considerable amount of time, the HA main thread is occupied long enough so it becomes visible through for example unresponsive UI. I'll check if the updating can be offloaded to a HA executor job

@henrikpieter
Copy link

Upgrading from 2023.8.4. to 2023.12.3 makes HA slow in responding. Same messages in log as descibed by Mauriziosacca. Doubt if it has anything to do with the network, given that all other integrations work as designed and I don't see any wierd network behaviour.

Re-installing the plug-in doesn't solve the problem. The moment you disable the plug-in, the issues dissapear.

Making the interval period longer gives some releave but problems don't dissapear.

@simone7121
Copy link

Upgrading from 2023.8.4. to 2023.12.3 makes HA slow in responding. Same messages in log as descibed by Mauriziosacca. Doubt if it has anything to do with the network, given that all other integrations work as designed and I don't see any wierd network behaviour.

Re-installing the plug-in doesn't solve the problem. The moment you disable the plug-in, the issues dissapear.

Making the interval period longer gives some releave but problems don't dissapear.

I've got the same problem here, for now i've just disabled the integration for now.

@simone7121
Copy link

simone7121 commented Jan 2, 2024

This is the log file from my homeassistant instance.

2024-01-02 02:08:38.170 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:08:38.170 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:08:42.174 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:08:42.174 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:08:42.233 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: [Errno 113] Host is unreachable
2024-01-02 02:08:42.233 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:08:46.181 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:08:46.181 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:08:58.234 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:08:58.234 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:09:09.832 WARNING (MainThread) [homeassistant.helpers.entity] Update of media_player.tv_salone is taking over 10 seconds
2024-01-02 02:09:09.832 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.ham_radio_propagation_solar_flux_index is taking over 10 seconds
2024-01-02 02:09:09.837 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /info request
2024-01-02 02:09:09.837 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /host/info request
2024-01-02 02:09:09.837 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /store request
2024-01-02 02:09:09.838 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /core/info request
2024-01-02 02:09:09.838 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /supervisor/info request
2024-01-02 02:09:09.838 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /os/info request
2024-01-02 02:09:09.841 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /info request
2024-01-02 02:09:09.842 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /core/info request
2024-01-02 02:09:09.843 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /supervisor/info request
2024-01-02 02:09:09.844 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /os/info request
2024-01-02 02:09:14.689 WARNING (MainThread) [homeassistant.components.hassio] Can't read Supervisor data: 
2024-01-02 02:09:14.690 ERROR (MainThread) [homeassistant.components.hassio] Error fetching hassio data: Error on Supervisor API: 
2024-01-02 02:09:14.709 WARNING (MainThread) [homeassistant.components.media_player] Updating samsungtv_smart media_player took longer than the scheduled update interval 0:00:15
2024-01-02 02:09:30.105 ERROR (MainThread) [homeassistant.components.homeassistant_alerts] Timeout fetching homeassistant_alerts data

And this is another behavior, it acts like it works, but drop the connection after 1s

2024-01-02 02:18:26.352 DEBUG (MainThread) [custom_components.solaredge_modbus] Setup solaredge_modbus.SolarEdge Inverter (MODBUS)
2024-01-02 02:18:29.367 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:18:29.367 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:18:30.368 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:18:33.372 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:18:33.372 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:18:33.409 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:18:33.433 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: [Errno 113] Host is unreachable
2024-01-02 02:18:33.433 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:18:34.386 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:18:37.389 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:18:37.390 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:18:37.425 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:18:39.481 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.189.102:1502
2024-01-02 02:18:43.030 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:18:46.033 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:18:46.034 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:18:46.084 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:18:48.125 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.189.102:1502
2024-01-02 02:18:54.130 DEBUG (MainThread) [custom_components.solaredge_modbus] Could not read Active Power Limit
2024-01-02 02:18:54.195 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:18:56.313 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.189.102:1502
2024-01-02 02:19:02.319 DEBUG (MainThread) [custom_components.solaredge_modbus] Could not read Active Power Limit
2024-01-02 02:19:02.404 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:19:05.409 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:19:05.409 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:19:05.411 WARNING (MainThread) [homeassistant.components.cover] Updating shelly cover took longer than the scheduled update interval 0:00:15
2024-01-02 02:19:05.411 WARNING (MainThread) [homeassistant.components.media_player] Updating samsungtv_smart media_player took longer than the scheduled update interval 0:00:15
2024-01-02 02:19:05.424 WARNING (MainThread) [homeassistant.helpers.entity] Update of media_player.tv_salone is taking over 10 seconds
2024-01-02 02:19:05.434 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:19:08.437 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:19:08.437 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:19:08.507 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:19:11.511 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:19:11.511 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:19:11.554 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:19:14.557 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:19:14.557 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:19:14.597 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:19:16.639 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.189.102:1502
2024-01-02 02:19:22.645 DEBUG (MainThread) [custom_components.solaredge_modbus] Could not read Active Power Limit
2024-01-02 02:19:22.678 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.ham_radio_propagation_solar_flux_index is taking over 10 seconds
2024-01-02 02:19:22.692 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:19:25.693 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:19:25.693 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:19:25.694 WARNING (MainThread) [homeassistant.components.sensor] Updating shelly sensor took longer than the scheduled update interval 0:00:30
2024-01-02 02:19:25.695 WARNING (MainThread) [homeassistant.components.cover] Updating shelly cover took longer than the scheduled update interval 0:00:15
2024-01-02 02:19:25.768 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:19:28.771 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:19:28.771 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:19:28.838 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:19:30.019 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.189.102:1502
2024-01-02 02:19:36.025 DEBUG (MainThread) [custom_components.solaredge_modbus] Could not read Active Power Limit
2024-01-02 02:19:36.058 WARNING (MainThread) [homeassistant.helpers.entity] Update of media_player.tv_salone is taking over 10 seconds
2024-01-02 02:19:36.092 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:19:39.095 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:19:39.096 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:19:39.101 ERROR (MainThread) [homeassistant.components.wled] Error fetching wled data: Invalid response from API: Timeout occurred while connecting to WLED device at 192.168.189.50
2024-01-02 02:19:39.137 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /info request
2024-01-02 02:19:39.138 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /core/info request
2024-01-02 02:19:39.138 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /supervisor/info request
2024-01-02 02:19:39.139 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /os/info request
2024-01-02 02:19:39.139 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /info request
2024-01-02 02:19:39.139 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /host/info request
2024-01-02 02:19:39.139 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /store request
2024-01-02 02:19:39.140 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /core/info request
2024-01-02 02:19:39.140 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /supervisor/info request
2024-01-02 02:19:39.140 ERROR (MainThread) [homeassistant.components.hassio.handler] Timeout on /os/info request
2024-01-02 02:19:39.146 ERROR (MainThread) [homeassistant.components.wled] Error fetching wled data: Invalid response from API: Timeout occurred while connecting to WLED device at 192.168.189.170
2024-01-02 02:19:39.153 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:19:42.157 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:19:42.158 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:19:42.158 WARNING (MainThread) [homeassistant.components.media_player] Updating samsungtv_smart media_player took longer than the scheduled update interval 0:00:15
2024-01-02 02:19:42.203 ERROR (MainThread) [homeassistant.components.hassio] Error fetching hassio data: Error on Supervisor API: 
2024-01-02 02:19:42.207 WARNING (MainThread) [homeassistant.components.hassio] Can't read Supervisor data: 
2024-01-02 02:19:42.223 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:19:45.226 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:19:45.226 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:19:45.292 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:19:46.593 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.189.102:1502
2024-01-02 02:19:49.644 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:19:50.663 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.189.102:1502
2024-01-02 02:19:56.668 DEBUG (MainThread) [custom_components.solaredge_modbus] Could not read Active Power Limit
2024-01-02 02:19:56.713 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:19:59.715 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:19:59.715 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:19:59.718 WARNING (MainThread) [homeassistant.components.sensor] Updating shelly sensor took longer than the scheduled update interval 0:00:30
2024-01-02 02:19:59.808 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:20:02.810 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:20:02.810 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:20:02.842 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:20:05.847 ERROR (MainThread) [pymodbus.logging] Connection to (192.168.189.102, 1502) failed: timed out
2024-01-02 02:20:05.847 WARNING (MainThread) [custom_components.solaredge_modbus] not able to connect to 192.168.189.102:1502
2024-01-02 02:20:05.900 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:20:07.969 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.189.102:1502
2024-01-02 02:20:13.977 DEBUG (MainThread) [custom_components.solaredge_modbus] Could not read Active Power Limit
2024-01-02 02:20:14.014 WARNING (MainThread) [homeassistant.helpers.entity] Update of media_player.tv_salone is taking over 10 seconds
2024-01-02 02:20:14.031 INFO (MainThread) [custom_components.solaredge_modbus] modbus client is not connected, trying to reconnect
2024-01-02 02:20:15.048 INFO (MainThread) [custom_components.solaredge_modbus] successfully connected to 192.168.189.102:1502

@binsentsu
Copy link
Owner

Could you try version V1.10.2 if it's any better?

@TroLoos
Copy link

TroLoos commented Jan 4, 2024

@binsentsu I think it would be wise to wait a bit for a final result, it's been only few hours since I updated to v1.10.2 but it already looks so much BETTER. Take a look at screen below to see how whole HA web gui (and main core at the same time) stabilizes after update. I will let you know in a day or two the result in longer period of time. The spike at 4:51 was just before updating (couldn't sleep at night ;-) - after that the graph is flat and this is what we are looking for!).

Screenshot 2024-01-04 at 09 52 10

@Meatballs1
Copy link

The change probably properly fixes #100

@TroLoos
Copy link

TroLoos commented Jan 4, 2024

The change probably properly fixes #100

Yes, 100% sure it should - what I'm measuring exactly is UI responsiveness (this sensor loads HA login webpage, so it comes from main 'homeassistant' container).

State for now, the fix relieved UI in 100%. I've updated this integration around 5 am, and until now 24h average response time is improving dramatically toward positive side (was 32ms, is already 21ms, it should be completely flat tomorrow morning):

Screenshot 2024-01-04 at 17 58 05

@Omega00123
Copy link
Author

Omega00123 commented Jan 4, 2024 via email

@TroLoos
Copy link

TroLoos commented Jan 5, 2024

Yes, definitely now it works as expected:

Screenshot 2024-01-05 at 09 14 26

Avg. Response for 24-hour time period went down from initial 142ms (2 weeks ago) to 7ms (full day after upgrade to newest version).

Since working thread is now a separate from core HA, perhaps it would be a good idea to give SolarEdge a little bit more time to answer the call? This integration still generates quite a lot of warning/error related to connectivity issues. I think it is not really a matter of device availability on WiFi network (ping works 100% of the time) but rather exclusive access to TCP port 1502. Even if I setup to poll SolarEdge every 30s (or every 5s) - it doesn't make a difference, errors and warnings still appear in a pretty much same amount. I guess it is a matter of handling TCP connection.

@binsentsu
Copy link
Owner

@TroLoos Can you share latest logging with connection errors?

@TroLoos
Copy link

TroLoos commented Jan 7, 2024

@binsentsu actually, turns out that my WiFi link to inverter isn't that solid as I thought... and I guess this is a problem showing up in my logs. I will change the antenna to something better and see if it help. For now - I think this issue has been successfully resolved.

Thank you for your support!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

9 participants