ECU not respond after automation reboot

[ViperRNMC]

Hi, after using the newest version and automation (thanks) 96 after a few days the integration hungs.

what i see:

• switch ecu is on
• binary cached is on
• sensors remain last state
• no fault in log

what i tried:

• use shell command, no result
• use power cycle ecu, no result
• Use restart Home Assistant and it works again

[HAEdwin]

Are you sure you left it as is for a longer period than the interval? Waiting long enough to recover.

[ViperRNMC]

Check the picture, it is overnight to the next morning 😙

[HAEdwin]

If it occurs next time, see what happens when you flip the ECU Query Device off/on and wait a while. Are you using the suggested automation from the documentation?

[ViperRNMC]

I’ll try that. I use the automation from the doc. Any new about the rest command?

[HAEdwin]

Haven't spend time on that REST option yet. I am very interested in the part where the automatic reboot takes place. Maybe I'm overlooking something. I've modified the subject title. If someone else doesn't have a problem with the automation, that's also valuable information to help find the problem.

[HAEdwin]

I could make things easier by integrating the reboot in the integration, the automation is not needed then. I can work on that this weekend. To test if this would be possible, I've updated https://github.com/HAEdwin/homeassistant-apsystems_ecur/blob/main/custom_components/apsystems_ecur/switch.py If anyone would like to try and replace switch.py then turn the query switch off and back on, the ECU should reboot (ECU-R pro and ECU-C only). If this works I can then add it on the right place in the integration. Replace localhost on line 84 by your ECU's IP-Address before restart of HA. Please check response in home-assistant.log also.

The URL need some cleaning and reformatting though - can't test it myself but spaces are not allowed for example, so someone needs to find the correct formatted URL to get the ECU to reboot. This might work but I can't test: Line 84: get_url= urllib.request.urlopen("http://localhost/index.php/management/set_wlan_ap%20-H%20X-Requested-With:%20XMLHttpRequest%20--data-raw%20SSID=ECU-WIFI_local&channel=0&method=0&psk_wep=&psk_wpa=%20--compressed%20--insecure")

[sabatpoznan]

same problem here, integration keeps hanging

[HAEdwin]

My plan is to reset the ECU after 5 tries without flipping the switch because flipping the switch it is a unnecessary action. But I really need feedback on my previous message.

[ViperRNMC]

I could make things easier by integrating the reboot in the integration, the automation is not needed then. I can work on that this weekend. To test if this would be possible, I've updated https://github.com/HAEdwin/homeassistant-apsystems_ecur/blob/main/custom_components/apsystems_ecur/switch.py If anyone would like to try and replace switch.py then turn the query switch off and back on, the ECU should reboot (ECU-R pro and ECU-C only). If this works I can then add it on the right place in the integration. Replace localhost on line 84 by your ECU's IP-Address before restart of HA. Please check response in home-assistant.log also.

The URL need some cleaning and reformatting though - can't test it myself but spaces are not allowed for example, so someone needs to find the correct formatted URL to get the ECU to reboot. This might work but I can't test: Line 84: get_url= urllib.request.urlopen("http://localhost/index.php/management/set_wlan_ap%20-H%20X-Requested-With:%20XMLHttpRequest%20--data-raw%20SSID=ECU-WIFI_local&channel=0&method=0&psk_wep=&psk_wpa=%20--compressed%20--insecure")

Switch won’t go on, got this error on screen Failed to call service switch/turn_on. HTTP Error 400: Bad Request

nothing in debug log

[HAEdwin]

Thanks for testing, the switch works fine and triggers the URL to restart the ECU. Exception is the way the URL is formatted and if it needs to be a get or put method I'm not sure. HTTP Error 400 means that the ECU cannot process the request so the URL has to be formatted or called correctly. I take it that you've replaced localhost for the IP-Address from your ECU. The response should be: "Response Status: 200" which means the ECU was able to process the request. I might have made a mistake, hope this works and returns 200:

Replace line 2 for: import requests At line 84: get_url= requests.get("http:// < IP > /index.php/management/set_wlan_ap%20-H%20X-Requested-With:%20XMLHttpRequest%20--data-raw%20SSID=ECU-WIFI_local&channel=0&method=0&psk_wep=&psk_wpa=%20--compressed%20--insecure") At line 85: _LOGGER.warning("Response Status: "+ str(get_url.status_code))

If you see 200 in home-assistant.log the ECU should restart.

[ViperRNMC]

WARNING (SyncWorker_4) [custom_components.apsystems_ecur.switch] Response Status: 400

Sorry, still 400, not 200. ECU don't reset after changing the code in you message (incl ip).

[HAEdwin]

Í tried to reproduce the issue by powering down the ECU. This is my log:

2022-10-08 13:13:39.139 WARNING (SyncWorker_3) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Invalid data error: [Errno 113] Host is unreachable
2022-10-08 13:18:42.099 WARNING (SyncWorker_4) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Invalid data error: [Errno 113] Host is unreachable
2022-10-08 13:23:45.143 WARNING (SyncWorker_3) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Invalid data error: [Errno 113] Host is unreachable
2022-10-08 13:28:48.098 WARNING (SyncWorker_2) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Invalid data error: [Errno 113] Host is unreachable
2022-10-08 13:28:48.102 WARNING (SyncWorker_2) [custom_components.apsystems_ecur] Communication with the ECU fails after 5 repeated attempts. Try power cycling or reset the ECU. Querying is stopped automatically.
2022-10-08 13:29:48.456 WARNING (SyncWorker_1) [custom_components.apsystems_ecur.switch] Response Status: 200

So the fifth try the ECU query switch is turned off and the automation calls the reboot (in my case just http://google.com) which is successfull returning 200. I then power up the ECU within the minute then after that minute the automation turns the ECU Query switch back on. After five minutes the cache is turned off after a succesfull ECU query. All goes well here and I'm not able to reproduce the issue.

I checked the states of entities but they're all good (complies to the results above). I'm not sure what is going on but it would take some trouble shooting on your part to see where it goes wrong. Did the ECU indeed restart? What is the state of the ECU entities when looking using the developer tools?

[ViperRNMC]

The ECU didn't restart (checked with terminal and ping the ip). I see no other state change when switching the ecu switch

[HAEdwin]

So the first thing to focus on is getting the URL right to get the ECU to restart and return 200 instead of 400: How about leaving the double quotes out?

shell_command:
  reboot_ecu: '/usr/bin/curl "http:// < IP > /index.php/management/set_wlan_ap -H X-Requested-With: XMLHttpRequest --data-raw SSID=ECU-WIFI_local&channel=0&method=0&psk_wep=&psk_wpa=" '

Or simplifying the URL so that the ECU restarts anyway, for example leaving out: X-Requested-With: XMLHttpRequest --data-raw

[ViperRNMC]

I think I've found a solution, I've done a commits (only getting ip to the url string has to be done). What the curl command does is reset the ECU's local AP, causing the ECU to reset automatically. After some testing of the command I came to the conclusion that it needs a custom header and at least the SSID value.

url = 'http://<ip>/index.php/management/set_wlan_ap'
headers = {'X-Requested-With': 'XMLHttpRequest',}
data = {'SSID': 'ECU-WIFI_local'}
get_url = requests.post(url, headers=headers, data=data)

[HAEdwin]

Thank you for troubleshooting, I've added the code to the integration with additional error handling. I hope this works out fine, there is no need to change or add the IP-address of the ECU somewhere.

Just Released 1.2.20 beta for download. Do not forget to disable the old automation. I'm happy to receive any feedback on results.

[ViperRNMC]

Let’s try it the next couple of days

[HAEdwin]

If the restart works I'll add a binairy sensor to indicate when the ECU restarted, log entries will be removed. With this sensor you'll be able to raise a notify (to your phone for example) to monitor if all is good. When any results on the restart are there please post the home-assistant.log part so I can determen what to do with the response returned.

[ViperRNMC]

today I had the following error, integration stops working. Restarting the ECU won't help, even a power cycle. Only restarting Home Assistant helps.

Logger: custom_components.apsystems_ecur
Source: custom_components/apsystems_ecur/__init__.py:117
Integration: APSystems PV solar ECU (documentation, issues)
First occurred: 4:23:43 PM (1 occurrences)
Last logged: 4:23:43 PM
Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment

log around the message:

2022-10-12 16:07:43.006 DEBUG (SyncWorker_12) [custom_components.apsystems_ecur] Querying ECU
2022-10-12 16:07:58.024 DEBUG (SyncWorker_12) [custom_components.apsystems_ecur] Got data from ECU
2022-10-12 16:07:58.025 DEBUG (SyncWorker_12) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [33, 70, 33, 69], 'voltage': [229], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 81, 'frequency': 50.0, 'temperature': 23, 'model': 'QS1', 'channel_qty': 4, 'power': [33, 70, 33, 69], 'voltage': [229]}}, 'ecu_id': '216200070324', 'today_energy': 3.0, 'lifetime_energy': 130.1, 'current_power': 205, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': False, 'querying': True}
2022-10-12 16:07:58.025 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.023 seconds (success: True)
2022-10-12 16:12:58.003 DEBUG (SyncWorker_30) [custom_components.apsystems_ecur] Querying ECU
2022-10-12 16:13:13.025 DEBUG (SyncWorker_30) [custom_components.apsystems_ecur] Got data from ECU
2022-10-12 16:13:13.026 DEBUG (SyncWorker_30) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [28, 48, 27, 49], 'voltage': [229], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 80, 'frequency': 50.0, 'temperature': 22, 'model': 'QS1', 'channel_qty': 4, 'power': [28, 48, 27, 49], 'voltage': [229]}}, 'ecu_id': '216200070324', 'today_energy': 3.02, 'lifetime_energy': 130.1, 'current_power': 152, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': False, 'querying': True}
2022-10-12 16:13:13.027 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.027 seconds (success: True)
2022-10-12 16:18:13.002 DEBUG (SyncWorker_18) [custom_components.apsystems_ecur] Querying ECU
2022-10-12 16:18:28.031 DEBUG (SyncWorker_18) [custom_components.apsystems_ecur] Got data from ECU
2022-10-12 16:18:28.031 DEBUG (SyncWorker_18) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [35, 70, 35, 71], 'voltage': [229], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 81, 'frequency': 50.0, 'temperature': 22, 'model': 'QS1', 'channel_qty': 4, 'power': [35, 70, 35, 71], 'voltage': [229]}}, 'ecu_id': '216200070324', 'today_energy': 3.03, 'lifetime_energy': 130.1, 'current_power': 211, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': False, 'querying': True}
2022-10-12 16:18:28.032 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.031 seconds (success: True)
2022-10-12 16:23:28.002 DEBUG (SyncWorker_18) [custom_components.apsystems_ecur] Querying ECU
2022-10-12 16:23:43.026 WARNING (SyncWorker_18) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment
2022-10-12 16:23:43.028 DEBUG (SyncWorker_18) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [35, 70, 35, 71], 'voltage': [229], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 81, 'frequency': 50.0, 'temperature': 22, 'model': 'QS1', 'channel_qty': 4, 'power': [35, 70, 35, 71], 'voltage': [229]}}, 'ecu_id': '216200070324', 'today_energy': 3.03, 'lifetime_energy': 130.1, 'current_power': 211, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': True, 'querying': True}
2022-10-12 16:23:43.030 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.028 seconds (success: True)
2022-10-12 16:28:43.002 DEBUG (SyncWorker_11) [custom_components.apsystems_ecur] Querying ECU
2022-10-12 20:06:01.379 WARNING (SyncWorker_33) [urllib3.connectionpool] Connection pool is full, discarding connection: api.mcs3.miele.com. Connection pool size: 10
2022-10-12 20:06:12.146 WARNING (SyncWorker_22) [urllib3.connectionpool] Connection pool is full, discarding connection: api.mcs3.miele.com. Connection pool size: 10
2022-10-12 20:06:12.632 WARNING (SyncWorker_18) [urllib3.connectionpool] Connection pool is full, discarding connection: api.mcs3.miele.com. Connection pool size: 10
2022-10-12 20:06:14.808 WARNING (SyncWorker_9) [urllib3.connectionpool] Connection pool is full, discarding connection: api.mcs3.miele.com. Connection pool size: 10

[HAEdwin]

Must have been a glitch receiving data, I'll have to add some code to catch these exceptions in APSystemsSocket.py to enable looking at the received data.

[doug-last]

So the first thing to focus on is getting the URL right to get the ECU to restart and return 200 instead of 400: How about leaving the double quotes out?

shell_command:
  reboot_ecu: '/usr/bin/curl "http:// < IP > /index.php/management/set_wlan_ap -H X-Requested-With: XMLHttpRequest --data-raw SSID=ECU-WIFI_local&channel=0&method=0&psk_wep=&psk_wpa=" '

Or simplifying the URL so that the ECU restarts anyway, for example leaving out: X-Requested-With: XMLHttpRequest --data-raw

i'm having a similar problem on the last few days: "[custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Invalid data error: [Errno 113] Host is unreachable"

and tried the command: '/usr/bin/curl "http://192.168.0.44/index.php/management/set_wlan_ap -H X-Requested-With: XMLHttpRequest --data-raw SSID=ECU-WIFI_local&channel=0&method=0&psk_wep=&psk_wpa=" '

my ecu did not reboot, and the wifi network name for local access (side button) the ecu changed to "ECU-WIFI_local" instead of old id.

ecu is new: ECU-R-BR

[HAEdwin]

I included the restart procedure in release 1.2.21 If the hotspot changed to ECU-WIFI_local and is temporary available, you could assume the ECU did restart. You will have to wait at least 5 minutes (default interval=300 seconds) before data reappears in HA. What are the first four digits of your ECU-R-BR ID?

[ViperRNMC]

Yesterday again no proper restart of the ECU, had to restart ECU and Home Assistant and reinstall the integration to get it working.

I used release 1.2.20 and the last log from ECU was cached data.

2022-10-16 15:35:16.007 DEBUG (SyncWorker_2) [custom_components.apsystems_ecur] Querying ECU
2022-10-16 15:35:31.029 DEBUG (SyncWorker_2) [custom_components.apsystems_ecur] Got data from ECU
2022-10-16 15:35:31.029 DEBUG (SyncWorker_2) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [41, 93, 41, 91], 'voltage': [225], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 82, 'frequency': 50.0, 'temperature': 28, 'model': 'QS1', 'channel_qty': 4, 'power': [41, 93, 41, 91], 'voltage': [225]}}, 'ecu_id': '216200070324', 'today_energy': 2.94, 'lifetime_energy': 135.2, 'current_power': 266, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': False, 'querying': True}
2022-10-16 15:35:31.031 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.030 seconds (success: True)
2022-10-16 15:40:31.008 DEBUG (SyncWorker_11) [custom_components.apsystems_ecur] Querying ECU
2022-10-16 15:40:46.035 DEBUG (SyncWorker_11) [custom_components.apsystems_ecur] Got data from ECU
2022-10-16 15:40:46.036 DEBUG (SyncWorker_11) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [46, 121, 48, 119], 'voltage': [225], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 82, 'frequency': 50.0, 'temperature': 28, 'model': 'QS1', 'channel_qty': 4, 'power': [46, 121, 48, 119], 'voltage': [225]}}, 'ecu_id': '216200070324', 'today_energy': 2.97, 'lifetime_energy': 135.2, 'current_power': 334, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': False, 'querying': True}
2022-10-16 15:40:46.038 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.036 seconds (success: True)
2022-10-16 15:45:46.002 DEBUG (SyncWorker_4) [custom_components.apsystems_ecur] Querying ECU
2022-10-16 15:46:01.032 DEBUG (SyncWorker_4) [custom_components.apsystems_ecur] Got data from ECU
2022-10-16 15:46:01.032 DEBUG (SyncWorker_4) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [36, 84, 37, 84], 'voltage': [225], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 82, 'frequency': 49.9, 'temperature': 27, 'model': 'QS1', 'channel_qty': 4, 'power': [36, 84, 37, 84], 'voltage': [225]}}, 'ecu_id': '216200070324', 'today_energy': 2.99, 'lifetime_energy': 135.2, 'current_power': 241, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': False, 'querying': True}
2022-10-16 15:46:01.033 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.032 seconds (success: True)
2022-10-16 15:51:01.006 DEBUG (SyncWorker_16) [custom_components.apsystems_ecur] Querying ECU
2022-10-16 15:51:16.019 DEBUG (SyncWorker_16) [custom_components.apsystems_ecur] Got data from ECU
2022-10-16 15:51:16.019 DEBUG (SyncWorker_16) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [30, 58, 30, 58], 'voltage': [225], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 82, 'frequency': 50.0, 'temperature': 25, 'model': 'QS1', 'channel_qty': 4, 'power': [30, 58, 30, 58], 'voltage': [225]}}, 'ecu_id': '216200070324', 'today_energy': 3.0, 'lifetime_energy': 135.2, 'current_power': 176, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': False, 'querying': True}
2022-10-16 15:51:16.020 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.019 seconds (success: True)
2022-10-16 15:56:16.003 DEBUG (SyncWorker_9) [custom_components.apsystems_ecur] Querying ECU
2022-10-16 15:56:31.026 WARNING (SyncWorker_9) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment
2022-10-16 15:56:31.027 DEBUG (SyncWorker_9) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [30, 58, 30, 58], 'voltage': [225], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 82, 'frequency': 50.0, 'temperature': 25, 'model': 'QS1', 'channel_qty': 4, 'power': [30, 58, 30, 58], 'voltage': [225]}}, 'ecu_id': '216200070324', 'today_energy': 3.0, 'lifetime_energy': 135.2, 'current_power': 176, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': True, 'querying': True}
2022-10-16 15:56:31.028 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.027 seconds (success: True)
2022-10-16 16:01:31.006 DEBUG (SyncWorker_2) [custom_components.apsystems_ecur] Querying ECU

[HAEdwin]

It looks like the integration receives invalid data and uses the cache (that can happen once in a while). I can't see what is happening the next run 5 minutes later at 16:01:31 Querying ECU. Does the log end there and no further errors are logged? I would expect that either it got data (Got data from ECU) or again had to use the cache (Using cached data from last successful...) if the log does not show either of them I might have to direct you to add some extra debug lines so that I narrow the search where it goes wrong.

The restart procedure is initiated after 5 times using the cache but in your case it doesn't seem to get that far. All fails after the first time using the cache.

Reinstall of the integration does not sound logical unless the storage medium is corrupt. The software won't change before and after reinstall only the initial query is performed immediately. In that case you can initiate an immediate query by reconfiguring the integration. Results should be available directly after that.

[ViperRNMC]

Reinstall doesn't make sense to me either. The log stops after the last message. Is there another way to debug?

[HAEdwin]

Of course I tested all scenarios as best as possible and it works like a charm here but I might have found something that was introduced at some point in time. Best thing I can do is add some extra debug lines correct the possible cause and release a beta after doing some testing again... thanks for your patience.

[HAEdwin]

I've added some debugging lines and did one change. APSystemsInvalidData isn't an exception it calls one.

If you first install 1.2.21 and then overwrite it with my file, you will see more info. Hopefully things don't go wrong now and the reset procedure is going to work. https://github.com/HAEdwin/homeassistant-apsystems_ecur/blob/main/custom_components/apsystems_ecur/APSystemsSocket.py

[ViperRNMC]

thanks, I'll try it and let you know.

[doug-last]

I included the restart procedure in release 1.2.21 If the hotspot changed to ECU-WIFI_local and is temporary available, you could assume the ECU did restart. You will have to wait at least 5 minutes (default interval=300 seconds) before data reappears in HA. What are the first four digits of your ECU-R-BR ID?

ECU-R-BR id is 2162000xxxxx i tested again while pinging the ip on another window, confirmed that it stopped replying for a few seconds.

HA log still repeating "Using cached data from last successful communication from ECU. Invalid data error: [Errno 113] Host is unreachable" on v1.2.21 the "host is unreachable" message makes no sense to me (i'm not a python guy), the curl and ping works properly from "docker exec -it homeassistant /bin/bash", i reconfigured the integration with the ip found on "nmap -p 8899 192.168.0.1/24 --open" (still the same ip, still accepted.), and powercycling doesn't change anything.

[HAEdwin]

Thanks for the info, ICMP ping packets are connectionless and therefor different from TCP packets. You could well have a ping response but cannot make a connection. The temporary no response might indicate a restart though, the home-assistant.log should reflect the succes of the post method to the ECU. When the integration was still using the cache did you try to using Packet Sender to confirm it is not possible to connect?

[doug-last]

Thanks for the info, ICMP ping packets are connectionless and therefor different from TCP packets. You could well have a ping response but cannot make a connection. The temporary no response might indicate a restart though, the home-assistant.log should reflect the succes of the post method to the ECU. When the integration was still using the cache did you try to using Packet Sender to confirm it is not possible to connect?

i don't have the 'packet sender' here, but to make sure i'm testing the same network as docker is runing: on: 'docker exec -it homeassistant /bin/bash' did: "echo APS1100160001END | nc 192.168.0.44 8899" got: "APS120121000121620005633901C�� � "310016ECU_R_PRO_2.0.7B020America/Campo_Grande��Ũz�A00END " on "tail -f homeassistant.log" still: "2022-10-17 16:21:41.232 WARNING (SyncWorker_3) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Invalid data error: [Errno 113] Host is unreachable" (no other response on the last few days, tried other integration versions too)

[doug-last]

Thanks for the info, ICMP ping packets are connectionless and therefor different from TCP packets. You could well have a ping response but cannot make a connection. The temporary no response might indicate a restart though, the home-assistant.log should reflect the succes of the post method to the ECU. When the integration was still using the cache did you try to using Packet Sender to confirm it is not possible to connect?

i don't have the 'packet sender' here, but to make sure i'm testing the same network as docker is runing: on: 'docker exec -it homeassistant /bin/bash' did: "echo APS1100160001END | nc 192.168.0.44 8899" got: "APS120121000121620005633901C�� � "310016ECU_R_PRO_2.0.7B020America/Campo_Grande��Ũz�A00END " on "tail -f homeassistant.log" still: "2022-10-17 16:21:41.232 WARNING (SyncWorker_3) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Invalid data error: [Errno 113] Host is unreachable" (no other response on the last few days, tried other integration versions too)

also:

the right before the period in green, i possibly had HA and/or ECU offline (pluged off), but i remember that the moment i turned all on i had data on HA home

[HAEdwin]

Why would HA not be able to reach the ECU ([Errno 113] Host is unreachable), all seems to go well including the ECU restart. Is there a firewall blocking HA? What happens if you reconfigure the integration by going to [Settings] > [Devices & Services] and choose [Configure] in the integration box?

[doug-last]

Why would HA not be able to reach the ECU ([Errno 113] Host is unreachable), all seems to go well including the ECU restart. Is there a firewall blocking HA? What happens if you reconfigure the integration by going to [Settings] > [Devices & Services] and choose [Configure] in the integration box?

on HA page shows the popup "success" on tail -f homeassistant.log shows the "host unreachable" message (might be coincidence, it appears every few seconds anyways.

there's no firewall, and docker configs are on defaults (the "echo|nc" test confirms), there's some way to increase the details on the log to see what is the "host" and related variables ? (i'm not python savvy but can paste code if needed).

[doug-last]

Why would HA not be able to reach the ECU ([Errno 113] Host is unreachable), all seems to go well including the ECU restart. Is there a firewall blocking HA? What happens if you reconfigure the integration by going to [Settings] > [Devices & Services] and choose [Configure] in the integration box?

on HA page shows the popup "success" on tail -f homeassistant.log shows the "host unreachable" message (might be coincidence, it appears every few seconds anyways.

there's no firewall, and docker configs are on defaults (the "echo|nc" test confirms), there's some way to increase the details on the log to see what is the "host" and related variables ? (i'm not python savvy but can paste code if needed).

something is messing up some config somewhere:

i rebooted and got this on .log: "2022-10-17 21:29:17.137 DEBUG (MainThread) [custom_components.apsystems_ecur] config={'host': '192.168.0.52', 'scan_interval': 300} " the ip is wrong, changed again on HA:

still the same wrong ip on .log

tried including ip's that don't exists on HA, got errors:

for some reason its trying to get data from an ip that is not possible to include on config, while ignoring the ip i wrote on config.

[HAEdwin]

@doug-last This seems to be a new issue somewhere in the config flow. I'm also not that skilled at Python but glad if I can help - for me this integration works like a charm since long-time ago :) Let's continue this issue here #125

[ViperRNMC]

Today i got the same problem, see log below. Integration is stopping at query step 2

2022-10-22 07:56:54.006 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur] Querying ECU
2022-10-22 07:56:54.007 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur.APSystemsSocket] Query ECU step 1: open socket
2022-10-22 07:56:54.012 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur.APSystemsSocket] Query ECU step 2: send & receive data
2022-10-22 07:56:59.017 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur.APSystemsSocket] Query ECU step 3: close socket
2022-10-22 07:56:59.019 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur.APSystemsSocket] Query ECU step 4: process data
2022-10-22 07:56:59.019 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur.APSystemsSocket] Query Inverters step 1: open socket
2022-10-22 07:56:59.021 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur.APSystemsSocket] Query Inverters step 2: send & receive data
2022-10-22 07:57:04.027 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur.APSystemsSocket] Query Inverters step 3: close socket
2022-10-22 07:57:04.028 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur.APSystemsSocket] Query Inverters Signal step 1: open socket
2022-10-22 07:57:04.030 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur.APSystemsSocket] Query Inverters Signal step 2: send & receive data
2022-10-22 07:57:09.035 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur.APSystemsSocket] Query Inverters Signal step 3: open socket
2022-10-22 07:57:09.036 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur.APSystemsSocket] Process inverter data
2022-10-22 07:57:09.036 WARNING (SyncWorker_27) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment
2022-10-22 07:57:09.037 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [0, 0, 0, 0], 'voltage': [0], 'inverters': {'[806000038042](tel:806000038042)': {'uid': '[806000038042](tel:806000038042)', 'online': False, 'signal': 81, 'frequency': 0.0, 'model': 'QS1', 'channel_qty': 4, 'power': [0, 0, 0, 0], 'voltage': [0]}}, 'ecu_id': '[216200070324](tel:216200070324)', 'today_energy': 0.0, 'lifetime_energy': 144.9, 'current_power': 0, 'qty_of_inverters': 1, 'qty_of_online_inverters': 0, 'data_from_cache': True, 'querying': True, 'restart_ecu': False}
2022-10-22 07:57:09.038 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.033 seconds (success: True)
2022-10-22 08:02:09.005 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur] Querying ECU
2022-10-22 08:02:09.005 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur.APSystemsSocket] Query ECU step 1: open socket
2022-10-22 08:02:09.012 DEBUG (SyncWorker_27) [custom_components.apsystems_ecur.APSystemsSocket] Query ECU step 2: send & receive data

• reset ecu with command doesn’t work
• reset Home Assistant doesn’t work
• Disable/enable integration doesn’t work
• Remove/add integration and the ecu is found with the integration

[kuzabi]

Hi, I have ECU-R with SunSpec logo ECU-ID 21620002xxxx I had the same problem today, at evening I saw that integration (v1.2.22) had hanged at 13:31: 2022-10-25 13:31:06.022 WARNING (SyncWorker_4) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment I didn't have any Debug messages - should I enable it somwhere? Below what I had in HA at 20:25, before any activities.

At 20:25 I restarted ECU with curl query by manually activation of disabled automation (from previous version); ping was lost for some time.

After 1 hour nothing changed. Reboot of HA at 21:20 - integration started working as normal. Waiting for next hangs. :)

P.S. whole integration is a great piece of work, and need only cherry on the top - working workaround for new ECU-R. I keep finger crossed.

[HAEdwin]

Most obvious case is that the integration gets stuck in a loop in APSystemsSocket.py I would expect a received datastring would always contain END\n but it might sometimes not be the case because data is not being send when the ECU got stuck. You have to change lines 76,77 to this (note the indents).

If this works I'll release a new version asap. Don't forget to restart HA after editting

[kuzabi]

Hello, After the change you suggested, it looks like the reboot of the ECU has been successfully triggered. Great!

2022-10-26 23:39:42.723 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration apsystems_ecur 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
2022-10-29 14:19:17.021 WARNING (SyncWorker_9) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment
2022-10-29 14:24:32.021 WARNING (SyncWorker_2) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment
2022-10-29 14:29:47.022 WARNING (SyncWorker_9) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment
2022-10-29 14:35:02.021 WARNING (SyncWorker_3) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment
2022-10-29 14:40:17.019 WARNING (SyncWorker_9) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment
2022-10-29 14:40:17.021 WARNING (SyncWorker_9) [custom_components.apsystems_ecur] Communication with the ECU failed after 5 repeated attempts.

[HAEdwin]

@kuzabi Thank you for the detailed report on the changes. Glad it is solved...

[ViperRNMC]

i can confirm that restart if working fine now

2022-10-30 09:07:47.003 DEBUG (SyncWorker_11) [custom_components.apsystems_ecur] Querying ECU
2022-10-30 09:08:02.022 DEBUG (SyncWorker_11) [custom_components.apsystems_ecur] Got data from ECU
2022-10-30 09:08:02.022 DEBUG (SyncWorker_11) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [22, 19, 21, 21], 'voltage': [227], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 72, 'frequency': 50.0, 'temperature': 15, 'model': 'QS1', 'channel_qty': 4, 'power': [22, 19, 21, 21], 'voltage': [227]}}, 'ecu_id': '216200070324', 'today_energy': 0.06, 'lifetime_energy': 156.7, 'current_power': 83, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': False, 'querying': True, 'restart_ecu': False}
2022-10-30 09:08:02.023 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.022 seconds (success: True)
2022-10-30 09:13:02.006 DEBUG (SyncWorker_16) [custom_components.apsystems_ecur] Querying ECU
2022-10-30 09:13:17.036 WARNING (SyncWorker_16) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment
2022-10-30 09:13:17.059 DEBUG (SyncWorker_16) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [22, 19, 21, 21], 'voltage': [227], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 72, 'frequency': 50.0, 'temperature': 15, 'model': 'QS1', 'channel_qty': 4, 'power': [22, 19, 21, 21], 'voltage': [227]}}, 'ecu_id': '216200070324', 'today_energy': 0.06, 'lifetime_energy': 156.7, 'current_power': 83, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': True, 'querying': True, 'restart_ecu': False}
2022-10-30 09:13:17.061 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.060 seconds (success: True)
2022-10-30 09:18:17.005 DEBUG (SyncWorker_6) [custom_components.apsystems_ecur] Querying ECU
2022-10-30 09:18:32.024 WARNING (SyncWorker_6) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment
2022-10-30 09:18:32.026 DEBUG (SyncWorker_6) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [22, 19, 21, 21], 'voltage': [227], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 72, 'frequency': 50.0, 'temperature': 15, 'model': 'QS1', 'channel_qty': 4, 'power': [22, 19, 21, 21], 'voltage': [227]}}, 'ecu_id': '216200070324', 'today_energy': 0.06, 'lifetime_energy': 156.7, 'current_power': 83, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': True, 'querying': True, 'restart_ecu': False}
2022-10-30 09:18:32.027 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.026 seconds (success: True)
2022-10-30 09:23:32.006 DEBUG (SyncWorker_1) [custom_components.apsystems_ecur] Querying ECU
2022-10-30 09:23:47.026 WARNING (SyncWorker_1) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment
2022-10-30 09:23:47.028 DEBUG (SyncWorker_1) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [22, 19, 21, 21], 'voltage': [227], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 72, 'frequency': 50.0, 'temperature': 15, 'model': 'QS1', 'channel_qty': 4, 'power': [22, 19, 21, 21], 'voltage': [227]}}, 'ecu_id': '216200070324', 'today_energy': 0.06, 'lifetime_energy': 156.7, 'current_power': 83, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': True, 'querying': True, 'restart_ecu': False}
2022-10-30 09:23:47.029 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.028 seconds (success: True)
2022-10-30 09:28:47.002 DEBUG (SyncWorker_6) [custom_components.apsystems_ecur] Querying ECU
2022-10-30 09:29:02.037 WARNING (SyncWorker_6) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment
2022-10-30 09:29:02.038 DEBUG (SyncWorker_6) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [22, 19, 21, 21], 'voltage': [227], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 72, 'frequency': 50.0, 'temperature': 15, 'model': 'QS1', 'channel_qty': 4, 'power': [22, 19, 21, 21], 'voltage': [227]}}, 'ecu_id': '216200070324', 'today_energy': 0.06, 'lifetime_energy': 156.7, 'current_power': 83, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': True, 'querying': True, 'restart_ecu': False}
2022-10-30 09:29:02.040 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 15.039 seconds (success: True)
2022-10-30 09:34:02.004 DEBUG (SyncWorker_6) [custom_components.apsystems_ecur] Querying ECU
2022-10-30 09:34:17.036 WARNING (SyncWorker_6) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Exception error: 'NoneType' object does not support item assignment
2022-10-30 09:34:17.037 WARNING (SyncWorker_6) [custom_components.apsystems_ecur] Communication with the ECU failed after 5 repeated attempts.
2022-10-30 09:34:18.431 DEBUG (SyncWorker_6) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [22, 19, 21, 21], 'voltage': [227], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 72, 'frequency': 50.0, 'temperature': 15, 'model': 'QS1', 'channel_qty': 4, 'power': [22, 19, 21, 21], 'voltage': [227]}}, 'ecu_id': '216200070324', 'today_energy': 0.06, 'lifetime_energy': 156.7, 'current_power': 83, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': True, 'querying': True, 'restart_ecu': True}
2022-10-30 09:34:18.432 DEBUG (MainThread) [custom_components.apsystems_ecur] Finished fetching apsystems_ecur data in 16.429 seconds (success: True)
2022-10-30 09:39:18.005 DEBUG (SyncWorker_5) [custom_components.apsystems_ecur] Querying ECU
2022-10-30 09:39:33.030 DEBUG (SyncWorker_5) [custom_components.apsystems_ecur] Got data from ECU
2022-10-30 09:39:33.030 DEBUG (SyncWorker_5) [custom_components.apsystems_ecur] Returning {'model': 'QS1', 'channel_qty': 4, 'power': [77, 62, 82, 66], 'voltage': [227], 'inverters': {'806000038042': {'uid': '806000038042', 'online': True, 'signal': 74, 'frequency': 50.0, 'temperature': 18, 'model': 'QS1', 'channel_qty': 4, 'power': [77, 62, 82, 66], 'voltage': [227]}}, 'ecu_id': '216200070324', 'today_energy': 0.16, 'lifetime_energy': 156.8, 'current_power': 287, 'qty_of_inverters': 1, 'qty_of_online_inverters': 1, 'data_from_cache': False, 'querying': True, 'restart_ecu': False}

[HAEdwin]

Thanx for the feedback, this is now solved in v1.2.23 where an infinite loop caused the integration to get non-responsive and the ECU reset was never called due to that. Disadvantage: the check if all data was received is not there anymore, I would expect no larger data lengths than 1024 being returned but with large solararrays you never know...

[ViperRNMC]

Hi @HAEdwin, it's working great, the reset of the AP. But I was thinking, it reset the AP with a default name and no security. After this the AP is available for 1 hour. Maybe better to set a WPA password. Is it possible to make a config in the integration to set an own SSID, Channel, Method and Password?

data for requests.post would be: data= {'ssid': 'ECU-WIFI_local', 'channel'; 0, 'method': 2, 'psk_wep': 'pwd', 'psk_wpa': 'pwd'})

ssid = ssid channel = 0-13 (0=auto) method = 0,1,2 (no/wep/wpa) psk_wep = password wep psk_wpa = password wpa