search

ksheumaker / homeassistant-apsystems_ecur

Home Assistant custom component for local querying of APSystems ECU-R Solar System
Apache License 2.0
178 stars 43 forks source link

Invalid data from ECU after issuing cmd=APS1100160001END #39

Closed albatorsk closed 2 years ago

albatorsk commented 2 years ago

I have an ECU-R (Article No. 209018) running firmware ECU_R_PRO 2.0.4. Using the integration version 1.1.2 works just fine on a wired connection (I have not tried wifi).

After upgrading the integration through HACS to version 1.2.2, Home Assistant is no longer able to communicate with the ECU-R. I checked home-assistant.log and the information below is everything that pertains to the APsystetems ECU-R integration.

Downgrading the integration to version 1.1.2 solves the problem for me and Home Assistant can once again communicate with the ECU-R.

Please let me know what other troubleshooting steps I can take, or if I can help in any way.

2022-02-06 15:01:48 WARNING (SyncWorker_3) [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-02-06 15:01:55 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 1 of 3

2022-02-06 15:01:57 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 2 of 3

2022-02-06 15:01:59 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 3 of 3

2022-02-06 15:02:01 WARNING (MainThread) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Error: Incomplete data from ECU after 3 attempts, cmd='APS1100160001END' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'

2022-02-06 15:02:01 WARNING (MainThread) [homeassistant.config_entries] Config entry 'ECU: 216200014656' for apsystems_ecur integration not ready yet: Cached data doesn't contain a valid ecu_id; Retrying in background

2022-02-06 15:02:54 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 1 of 3

2022-02-06 15:02:57 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 2 of 3

2022-02-06 15:02:59 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 3 of 3

2022-02-06 15:03:01 WARNING (MainThread) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Error: Incomplete data from ECU after 3 attempts, cmd='APS1100160001END' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'

2022-02-06 15:03:11 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 1 of 3

2022-02-06 15:03:13 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 2 of 3

2022-02-06 15:03:15 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 3 of 3

2022-02-06 15:03:17 WARNING (MainThread) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Error: Incomplete data from ECU after 3 attempts, cmd='APS1100160001END' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'

2022-02-06 15:03:38 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 1 of 3

2022-02-06 15:03:40 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 2 of 3

2022-02-06 15:03:42 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 3 of 3

2022-02-06 15:03:44 WARNING (MainThread) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Error: Incomplete data from ECU after 3 attempts, cmd='APS1100160001END' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'

2022-02-06 15:04:24 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 1 of 3

2022-02-06 15:04:26 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 2 of 3

2022-02-06 15:04:29 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Invalid data from ECU after issuing cmd=APS1100160001END error=End suffix (b'END\n') missing from ECU response end_data=b'\x00A\x00\n' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'. Closing socket and trying again try 3 of 3

2022-02-06 15:04:31 WARNING (MainThread) [custom_components.apsystems_ecur] Using cached data from last successful communication from ECU. Error: Incomplete data from ECU after 3 attempts, cmd='APS1100160001END' data=b'APS120112000121620001465601\x00\x00\x00\xc1\x00\x00\x01\x80\x00\x00\x02\xb0 "\x02\x06\x15\x00A\x00\n'
ksheumaker commented 2 years ago

Thanks. Still working on the 1.2.X branch of the code. This is an issue with the data your ECU is returning, all data the ECU sends should end with the text END sometimes it doesn't. We don't know why, but it happens occasionally. When it does return invalid data we try again 3 times, and then revert to pulling data from a cache of the last good result. If you just restarted HA there is no last good result, which is why you are seeing the error about no ecu_id in cached data.

I just released a new beta 1.2.4 that attempt so fix some of this. If you can try it that would be great. Please remove the old integration and add it again as new. When you do you will see there is a new checkbox

Screen Shot 2022-02-06 at 10 30 31 AM

Please try it w/o checking the box and see if that works. If it proves to be problematic, check it and try again. We are trying to hunt down the inconsistencies between ECUs and hopefully have a universally working option.

For example my ECU_R is very unstable when closing/reopening socket, but we've heard from others that the ECU_R_PRO and C do a better job when the socket does get closed.

albatorsk commented 2 years ago

I have now tried upgrading to version 1.2.5 and I have three different results.

  1. If I simply upgrade from 1.1.2 to 1.2.5, everything works as expected.

  2. If I first remove the integration, and then add it again without checking the "Close and re-open socket..." checkbox, it does not work. Here's the relevant part from home-assistant.log: 2022-02-07 09:07:02 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Status of reopen_socket False 2022-02-07 09:07:02 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Unkonwn error from ECU after issuing cmd=APS1100280002216200014656END error=[Errno 104] Connection reset by peer. Closing socket and trying again try 1 of 3 2022-02-07 09:07:02 ERROR (MainThread) [custom_components.apsystems_ecur.config_flow] Unhandled exception: [Errno 104] Connection reset by peer Traceback (most recent call last): File "/config/custom_components/apsystems_ecur/config_flow.py", line 44, in async_step_user test_query = await ap_ecu.async_query_ecu() File "/config/custom_components/apsystems_ecur/APSystemsECUR.py", line 203, in async_query_ecu self.inverter_raw_data = await self.async_send_read_from_socket(cmd) File "/config/custom_components/apsystems_ecur/APSystemsECUR.py", line 128, in async_send_read_from_socket await self.writer.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 375, in drain raise exc File "/config/custom_components/apsystems_ecur/APSystemsECUR.py", line 131, in async_send_read_from_socket return await asyncio.wait_for(self.async_read_from_socket(), File "/usr/local/lib/python3.9/asyncio/tasks.py", line 481, in wait_for return fut.result() File "/config/custom_components/apsystems_ecur/APSystemsECUR.py", line 93, in async_read_from_socket data = await self.reader.read(self.recv_size) File "/usr/local/lib/python3.9/asyncio/streams.py", line 684, in read await self._wait_for_data('read') File "/usr/local/lib/python3.9/asyncio/streams.py", line 517, in _wait_for_data await self._waiter File "/usr/local/lib/python3.9/asyncio/selector_events.py", line 856, in _read_ready__data_received data = self._sock.recv(self.max_size) ConnectionResetError: [Errno 104] Connection reset by peer

  3. If I first remove the integration, and then add it again and check the "Close and re-open socket..." checkbox, it does not work. Here's the relevant part from home-assistant.log: 2022-02-07 09:07:21 WARNING (MainThread) [custom_components.apsystems_ecur.APSystemsECUR] Status of reopen_socket False 2022-02-07 09:07:21 ERROR (MainThread) [custom_components.apsystems_ecur.config_flow] Unhandled exception: Connection lost Traceback (most recent call last): File "/config/custom_components/apsystems_ecur/config_flow.py", line 44, in async_step_user test_query = await ap_ecu.async_query_ecu() File "/config/custom_components/apsystems_ecur/APSystemsECUR.py", line 210, in async_query_ecu self.inverter_raw_signal = await self.async_send_read_from_socket(cmd) File "/config/custom_components/apsystems_ecur/APSystemsECUR.py", line 128, in async_send_read_from_socket await self.writer.drain() File "/usr/local/lib/python3.9/asyncio/streams.py", line 387, in drain await self._protocol._drain_helper() File "/usr/local/lib/python3.9/asyncio/streams.py", line 190, in _drain_helper raise ConnectionResetError('Connection lost') ConnectionResetError: Connection lost

I am now happily running the integration by first installing version 1.1.2 from HACS, setting up the integration, and then upgrading to 1.2.5 through HACS.

ksheumaker commented 2 years ago

Can you try the 1.2.10 release? It's changed the socket code more, and I hope to get feedback on if it will work for R_PRO and C users, I've been running it for the last 2 days on my ECU-R without issues.

tv3 commented 2 years ago

I am running an adapted version of the main branch on my ecu-r-pro. It queries the internal webpages as it exposes some web apis. Currently running 8 hours. Will keep it running for a few days and hoping it will keep working. Fingers crossed. If it works, I'll come back and see how we can merge.

ksheumaker commented 2 years ago

Great. I think this is the correct approach for devices that have a web ui. APsystems actually designed it for users to look at, vs how we are querying now. I wish my ECU had a web interface.

I'm certainly willing to build in both data retrieval methods into the integration.

HAEdwin commented 2 years ago

@albatorsk Did you try the latest 1.2.12 release of the integration? Also pay attention to this fix: #71 Please let me know if it solves the issue so that it can be closed.

albatorsk commented 2 years ago

Hi,

I can confirm that 1.2.12 works perfectly fine for me.

First I tried updating from 1.2.10 beta (which was the last version that worked for me, and that I have been using up until now), to 1.2.12, and the update went fine. I then tried removing the integration, restarting Home Assistant and then adding the integration again while still on version 1.2.12, which also worked fine! Previously, I would have to do a whole song and dance by installing a much earlier version and then updating to the latest beta for it to work.

Info about my ECU-R: ECU-R with SunSpec logo Firmware: ECU_R_PRO_2.0.6

Thank you.