binsentsu / home-assistant-solaredge-modbus

Home assistant Component for reading data locally from Solaredge inverter through modbus TCP
268 stars 69 forks source link

Multiple drops of communication #210

Open Omega00123 opened 8 months ago

Omega00123 commented 8 months ago

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 commented 8 months ago

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 commented 7 months ago

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(minsize) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 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(minsize) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 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(minsize) ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ 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 commented 7 months ago

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 commented 7 months ago

This is my inverter:

ChristophCaina commented 7 months ago

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 commented 7 months ago

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 commented 7 months ago

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 commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago

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 commented 6 months ago

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

TroLoos commented 6 months ago

@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 commented 6 months ago

The change probably properly fixes https://github.com/binsentsu/home-assistant-solaredge-modbus/issues/100

TroLoos commented 6 months ago

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 commented 6 months ago

There is a clear improvement. I have the update running now for 7 Hours and only have 5 missed communications where I had 35 before so 7* better. It is still not zero let’s see how it evolves.

Oscar H.M. De Vries @.***

Op 4 jan. 2024 om 18:01 heeft TroLoos @.***> het volgende geschreven:  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.png (view on web) — Reply to this email directly, view it on GitHub, or unsubscribe. You are receiving this because you authored the thread.

TroLoos commented 6 months ago

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 commented 6 months ago

@TroLoos Can you share latest logging with connection errors?

TroLoos commented 5 months ago

@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!