hultenvp / solis-sensor

HomeAssistant integration for the SolisCloud PV Monitoring portal via SolisCloud API
Apache License 2.0
208 stars 42 forks source link

The integration stops retrieving data from the server. #180

Closed heebo1974 closed 1 year ago

heebo1974 commented 1 year ago

Describe the bug Every now and then (daily) integration stops updating data from server. I have Solar Sofar 4.4KTL-X inverter.

I use these settings: Sofar solar (home.solarman.cn) portal version ginlong_v2

Versions HA Version an deployment 2022.10.5 HACS version Integration version 1.28.3

core logs ... 2022-10-28 08:36:26.070 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.solar_sofar_pv1_power is taking over 10 seconds 2022-10-28 08:37:26.073 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.solar_sofar_pv1_power is taking over 10 seconds 2022-10-28 08:38:26.074 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.solar_sofar_pv1_power is taking over 10 seconds 2022-10-28 08:39:26.076 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.solar_sofar_pv1_power is taking over 10 seconds 2022-10-28 08:40:26.075 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.solar_sofar_pv1_power is taking over 10 seconds 2022-10-28 08:41:26.076 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.solar_sofar_pv1_power is taking over 10 seconds 2022-10-28 08:42:26.077 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.solar_sofar_pv1_power is taking over 10 seconds 2022-10-28 08:43:26.083 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.solar_sofar_pv1_power is taking over 10 seconds 2022-10-28 08:44:26.082 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.solar_sofar_pv1_power is taking over 10 seconds 2022-10-28 08:45:26.084 WARNING (MainThread) [homeassistant.helpers.entity] Update of sensor.solar_sofar_pv1_power is taking over 10 seconds 2022-10-28 09:20:17.614 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved Traceback (most recent call last): File "/config/custom_components/solis/service.py", line 182, in async_update if await self._login(): File "/config/custom_components/solis/service.py", line 92, in _login if await self._api.login(async_get_clientsession(self._hass)): File "/config/custom_components/solis/ginlong_api.py", line 225, in login self._plant_name = getattr(data, INVERTER_PLANT_NAME) AttributeError: 'NoneType' object has no attribute 'plantName'

heebo1974 commented 1 year ago

I'll add debug logs later.

metcrl commented 1 year ago

Same here. I hope we'll find a solution

donal222022 commented 1 year ago

I am having the same issue since I moved the config from yaml to GUI Integration, stops at least once everyday.

TiemenSoeteman commented 1 year ago

I have the same issue. Also started when I stopped using the yaml configuration. At first I thought it might have something to do with the inverter going offline when it stops producing electricity, but I also noticed it stopped working during the day. Reloading the integration solves the problem for roughly 24 hours.

hultenvp commented 1 year ago

I added reading the plant name to the login procedure. Apparently after some point in time the integration is forced to renew the login. This succeeds but reading the plant name doesn't for some reason. It's easy to avoid the crash, but I cannot reproduce the issue myself, so need your feedback to check it works now. Do all of you see the issue on the ginlong API or are there also people seeing it on Soliscloud?

metcrl commented 1 year ago

I added reading the plant name to the login procedure. Apparently after some point in time the integration is forced to renew the login. This succeeds but reading the plant name doesn't for some reason. It's easy to avoid the crash, but I cannot reproduce the issue myself, so need your feedback to check it works now. Do all of you see the issue on the ginlong API or are there also people seeing it on Soliscloud?

For me the problem is on ginlong API. I'll check if it's working now

donal222022 commented 1 year ago

Its ginlong API for me , will feedback on the results

hultenvp commented 1 year ago

@donal222022 Fix is in v3.0.6

metcrl commented 1 year ago

It's happening again, it just stopped receiving data yet

hultenvp commented 1 year ago

Reopening. General remark: There are so many different systems out there all resulting in even different behavior from the server it is impossible for me to system test all possible versions. It took me months to even get something simple as Energy Today stable and reliable. So if an issue occurs: please add the logs. Without them you can tell me 100x it doesn't work, but I cannot solve it.

heebo1974 commented 1 year ago

I haven't had any problems since the update so far.

metcrl commented 1 year ago

I have now updated to 3.0.7 and I have duplicated all sensors, so I need to fix this first. In any case, I'll keep an eye on the "2" versions of the sensors to see if they get stuck. Forgive the ignorance where do I find the log specifically?

donal222022 commented 1 year ago

I thought the issue had happened again, but it was the duplicates was my problem this time, will turn on debug and monitor.

hultenvp commented 1 year ago

I have now updated to 3.0.7 and I have duplicated all sensors, so I need to fix this first. In any case, I'll keep an eye on the "2" versions of the sensors to see if they get stuck. Forgive the ignorance where do I find the log specifically?

Yeah the remaining dups are a pain as well. Another example of how many different use cases there are. Doesn't help that I need to learn it myself on the fly as well ;-). I hope the issue #186 will give me some leads here.

Logs are under settings->System->logs and then log details. Best if debug is on: https://github.com/hultenvp/solis-sensor/wiki/FAQ#you-ask-me-for-debug-logs-how-do-i-do-that

metcrl commented 1 year ago

Just to understand, is it better to fix duplicate sensors by hand or are we waiting for a resolutive update? If you say we fix them by hand by eliminating the old ones, and see if the new ones still encounter the problem of stuck retrieving data.

Thanks a lot!!!

snigehere commented 1 year ago

Adding to this ticket from what I see ...

I am seeing issues with data in my energy dashboard - the solar data is not being updated.

If I look into the statistics database for the entity my energy today I see the same value every hour even though its sunny and the "my solis app shows I am generating solar (10:00 -> 14:00)

209723 2022-10-31 09:00:10.081428 2022-10-31 08:00:00.000000 1667204682.573863 1667202802.0 1667206248.0 NULL NULL NULL 12 209782 2022-10-31 10:00:10.050826 2022-10-31 09:00:00.000000 1667206553.7326205 1667206248.0 1667206561.0 NULL NULL NULL 12 209844 2022-10-31 11:00:10.035818 2022-10-31 10:00:00.000000 1667206561.0 1667206561.0 1667206561.0 NULL NULL NULL 12 209906 2022-10-31 12:00:10.050893 2022-10-31 11:00:00.000000 1667206561.0 1667206561.0 1667206561.0 NULL NULL NULL 12 210030 2022-10-31 14:00:10.042807 2022-10-31 13:00:00.000000 1667206561.0 1667206561.0 1667206561.0 NULL NULL NULL 12 210092 2022-10-31 15:00:10.032270 2022-10-31 14:00:00.000000 1667206561.0 1667206561.0 1667206561.0 NULL NULL NULL 12

It appears to be an issue with the solis integration as the sensor.my_solis_inverter_energy_today shows static for a chunk of the day

mstoday

however I don't see any issue in the log (debug is on for solis) other than a time out ... which of course maybe the root cause .. this is the log going past 10 when the next update of the energy data should have happened.

Line 2347: 2022-10-31 09:27:40.640 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2348: 2022-10-31 09:27:41.038 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2349: 2022-10-31 09:29:41.043 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2350: 2022-10-31 09:29:43.932 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2351: 2022-10-31 09:31:43.933 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2352: 2022-10-31 09:31:44.523 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2353: 2022-10-31 09:33:44.524 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2354: 2022-10-31 09:33:45.291 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2355: 2022-10-31 09:35:45.292 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2356: 2022-10-31 09:35:47.040 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2357: 2022-10-31 09:37:47.041 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2358: 2022-10-31 09:37:47.443 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2359: 2022-10-31 09:39:47.445 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2360: 2022-10-31 09:39:49.312 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2361: 2022-10-31 09:41:49.313 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2362: 2022-10-31 09:41:49.877 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2363: 2022-10-31 09:43:49.878 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2364: 2022-10-31 09:43:50.176 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2365: 2022-10-31 09:45:50.178 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2366: 2022-10-31 09:45:51.953 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2367: 2022-10-31 09:47:51.955 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2368: 2022-10-31 09:47:52.335 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2369: 2022-10-31 09:49:52.337 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2370: 2022-10-31 09:49:52.997 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2371: 2022-10-31 09:51:52.998 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2372: 2022-10-31 09:51:54.250 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2373: 2022-10-31 09:53:54.252 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2374: 2022-10-31 09:53:55.226 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2375: 2022-10-31 09:55:55.229 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2376: 2022-10-31 09:55:55.567 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2394: 2022-10-31 09:57:55.569 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2395: 2022-10-31 09:57:55.881 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2430: 2022-10-31 09:59:55.882 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2431: 2022-10-31 09:59:56.168 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2466: 2022-10-31 10:01:56.170 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2467: 2022-10-31 10:01:56.766 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2502: 2022-10-31 10:03:56.768 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2503: 2022-10-31 10:03:57.754 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2538: 2022-10-31 10:05:57.756 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx

I do see a few times the app times out and wonder if there is some code issue caused by this .. What I notice in the log extract below is two fetch cycles without a schedule between them and also "device id" it is mentioned where al the other messages are "data for serial" .. I don't know if these are pointers to a root cause

Line 2321: 2022-10-31 09:07:53.189 INFO (MainThread) [custom_components.solis.ginlong_api] Login Successful! Line 2322: 2022-10-31 09:07:55.175 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2323: 2022-10-31 09:08:05.177 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> Line 2324: 2022-10-31 09:08:05.177 INFO (MainThread) [custom_components.solis.ginlong_api] Unable to fetch details for device with ID: yyyyyyyy Line 2325: 2022-10-31 09:08:05.177 DEBUG (MainThread) [custom_components.solis.ginlong_api] Could not fetch inverter data, retry loging attempt Line 2326: 2022-10-31 09:08:05.178 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 1 minutes. Line 2327: 2022-10-31 09:09:10.196 INFO (MainThread) [custom_components.solis.ginlong_api] Login Successful! Line 2328: 2022-10-31 09:09:18.008 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2329: 2022-10-31 09:09:25.881 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2330: 2022-10-31 09:09:32.513 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes. Line 2331: 2022-10-31 09:11:32.515 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxx Line 2332: 2022-10-31 09:11:33.083 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 2 minutes..

Hope this assists

heebo1974 commented 1 year ago

Hmm.. Now I think that it stopped again ?

2022-11-02 10:18:27.700 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxxxx 2022-11-02 10:18:37.702 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> 2022-11-02 10:18:37.702 INFO (MainThread) [custom_components.solis.ginlong_api] Unable to fetch details for device with ID: 105176242 2022-11-02 10:18:37.702 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 1 minutes. 2022-11-02 10:19:45.978 INFO (MainThread) [custom_components.solis.ginlong_api] Login Successful! 2022-11-02 10:19:55.979 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> File "/config/custom_components/solis/service.py", line 182, in async_update File "/config/custom_components/solis/service.py", line 92, in _login File "/config/custom_components/solis/ginlong_api.py", line 224, in login

metcrl commented 1 year ago

Yes it's stopped again, i can confirm

snigehere commented 1 year ago

Mine stopped as well ...which I guess suggests a common incident on the cloud may be the trigger ... Unfortunately I don't have the logs for this one as I did a couple of restarts a bit later to update some other stuff before I spotted it had stopped. I have added the last update timestamp to my main dashboard so I can spot if it stops. stopped

Incident was around 08:12 UTC

Edit to add a couple more pictures

totalpower timestamp history

hultenvp commented 1 year ago

Hmm.. Now I think that it stopped again ?

2022-11-02 10:18:27.700 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxxxxx 2022-11-02 10:18:37.702 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> 2022-11-02 10:18:37.702 INFO (MainThread) [custom_components.solis.ginlong_api] Unable to fetch details for device with ID: 105176242 2022-11-02 10:18:37.702 DEBUG (MainThread) [custom_components.solis.service] Scheduling next update in 1 minutes. 2022-11-02 10:19:45.978 INFO (MainThread) [custom_components.solis.ginlong_api] Login Successful! 2022-11-02 10:19:55.979 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> File "/config/custom_components/solis/service.py", line 182, in async_update File "/config/custom_components/solis/service.py", line 92, in _login File "/config/custom_components/solis/ginlong_api.py", line 224, in login

Looks like an outage server side. The timeout error is new, I'll catch it so at least it recovers (I assume it didn't)

snigehere commented 1 year ago

The last update I saw was at 03-Nov-2022 08:57:25 UTC ... I saw there were timeouts before that time and later a home assistant exception which seems to have killed the integration Again I see the double fetch after the timeout ... longer log attached rather than in the page

solis log.txt

donal222022 commented 1 year ago

Adding my log which failed earlier:

2022-11-03 09:13:30.947 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:15:31.916 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:17:33.682 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:19:34.342 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:21:38.667 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:23:39.428 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:25:40.142 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:27:55.436 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:29:58.146 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:31:59.172 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:32:09.175 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> 2022-11-03 09:32:09.175 INFO (MainThread) [custom_components.solis.ginlong_api] Unable to fetch details for device with ID: xxxxxxxxxxxxxx 2022-11-03 09:33:10.404 INFO (MainThread) [custom_components.solis.ginlong_api] Login Successful! 2022-11-03 09:33:14.397 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:33:22.565 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:33:32.568 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> 2022-11-03 09:33:32.569 INFO (MainThread) [custom_components.solis.ginlong_api] Unable to fetch details for device with ID: xxxxxxxxxxxxxx 2022-11-03 09:34:35.026 INFO (MainThread) [custom_components.solis.ginlong_api] Login Successful! 2022-11-03 09:34:44.543 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:35:00.107 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> 2022-11-03 09:35:00.108 INFO (MainThread) [custom_components.solis.ginlong_api] Unable to fetch details for device with ID: xxxxxxxxxxxxxx 2022-11-03 09:35:00.108 DEBUG (MainThread) [custom_components.solis.ginlong_api] Could not fetch inverter data, retry loging attempt 2022-11-03 09:36:00.691 INFO (MainThread) [custom_components.solis.ginlong_api] Login Successful! 2022-11-03 09:36:00.932 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:36:01.426 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:38:02.038 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:40:03.729 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:42:07.217 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:44:08.522 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:46:09.097 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:48:13.351 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:50:19.253 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:50:29.327 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> 2022-11-03 09:50:29.328 INFO (MainThread) [custom_components.solis.ginlong_api] Unable to fetch details for device with ID: xxxxxxxxxxxxxx 2022-11-03 09:51:37.164 INFO (MainThread) [custom_components.solis.ginlong_api] Login Successful! 2022-11-03 09:51:47.166 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> 2022-11-03 09:51:47.167 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved Traceback (most recent call last): File "/config/custom_components/solis/service.py", line 182, in async_update if await self._login(): File "/config/custom_components/solis/service.py", line 92, in _login if await self._api.login(async_get_clientsession(self._hass)): File "/config/custom_components/solis/ginlong_api.py", line 224, in login data = await self.fetch_inverter_data(next(iter(self._inverter_list))) TypeError: 'NoneType' object is not iterable

On Thu, 3 Nov 2022 at 10:05, snigehere @.***> wrote:

The last update I saw was at 03-Nov-2022 08:57:25 UTC ... I saw there were timeouts before that time and later a home assistant exception which seems to have killed the integration Again I see the double fetch after the timeout ... longer log attached rather than in the page

solis log.txt https://github.com/hultenvp/solis-sensor/files/9927277/solis.log.txt

— Reply to this email directly, view it on GitHub https://github.com/hultenvp/solis-sensor/issues/180#issuecomment-1301874072, or unsubscribe https://github.com/notifications/unsubscribe-auth/AXSDF7WJOASQDS54WP5BQFTWGOE5PANCNFSM6AAAAAARQZIARA . You are receiving this because you were mentioned.Message ID: @.***>

donal222022 commented 1 year ago

Adding my log which failed earlier: 2022-11-03 09:13:30.947 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:15:31.916 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:17:33.682 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:19:34.342 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:21:38.667 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:23:39.428 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:25:40.142 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:27:55.436 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:29:58.146 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:31:59.172 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:32:09.175 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> 2022-11-03 09:32:09.175 INFO (MainThread) [custom_components.solis.ginlong_api] Unable to fetch details for device with ID: xxxxxxxxxxxxxx 2022-11-03 09:33:10.404 INFO (MainThread) [custom_components.solis.ginlong_api] Login Successful! 2022-11-03 09:33:14.397 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:33:22.565 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:33:32.568 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> 2022-11-03 09:33:32.569 INFO (MainThread) [custom_components.solis.ginlong_api] Unable to fetch details for device with ID: xxxxxxxxxxxxxx 2022-11-03 09:34:35.026 INFO (MainThread) [custom_components.solis.ginlong_api] Login Successful! 2022-11-03 09:34:44.543 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:35:00.107 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> 2022-11-03 09:35:00.108 INFO (MainThread) [custom_components.solis.ginlong_api] Unable to fetch details for device with ID: xxxxxxxxxxxxxx 2022-11-03 09:35:00.108 DEBUG (MainThread) [custom_components.solis.ginlong_api] Could not fetch inverter data, retry loging attempt 2022-11-03 09:36:00.691 INFO (MainThread) [custom_components.solis.ginlong_api] Login Successful! 2022-11-03 09:36:00.932 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:36:01.426 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:38:02.038 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:40:03.729 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:42:07.217 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:44:08.522 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:46:09.097 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:48:13.351 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:50:19.253 DEBUG (MainThread) [custom_components.solis.ginlong_api] Fetching data for serial: xxxxxxxxxxxxxx 2022-11-03 09:50:29.327 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> 2022-11-03 09:50:29.328 INFO (MainThread) [custom_components.solis.ginlong_api] Unable to fetch details for device with ID: xxxxxxxxxxxxxx 2022-11-03 09:51:37.164 INFO (MainThread) [custom_components.solis.ginlong_api] Login Successful! 2022-11-03 09:51:47.166 DEBUG (MainThread) [custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> 2022-11-03 09:51:47.167 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved Traceback (most recent call last): File "/config/custom_components/solis/service.py", line 182, in async_update if await self._login(): File "/config/custom_components/solis/service.py", line 92, in _login if await self._api.login(async_get_clientsession(self._hass)): File "/config/custom_components/solis/ginlong_api.py", line 224, in login data = await self.fetch_inverter_data(next(iter(self._inverter_list))) TypeError: 'NoneType' object is not iterable On Thu, 3 Nov 2022 at 10:05, snigehere @.> wrote: The last update I saw was at 03-Nov-2022 08:57:25 UTC ... I saw there were timeouts before that time and later a home assistant exception which seems to have killed the integration Again I see the double fetch after the timeout ... longer log attached rather than in the page solis log.txt https://github.com/hultenvp/solis-sensor/files/9927277/solis.log.txt — Reply to this email directly, view it on GitHub <#180 (comment)>, or unsubscribe https://github.com/notifications/unsubscribe-auth/AXSDF7WJOASQDS54WP5BQFTWGOE5PANCNFSM6AAAAAARQZIARA . You are receiving this because you were mentioned.Message ID: @.>

In relation to this, I am able to get it working again by Disabling and Enabling the integration again.

Many Thanks,

Donal.

hultenvp commented 1 year ago

First of all thanks for all the logs, this really helps.

I'll try to get out a fix tonight.

donal222022 commented 1 year ago

Thanks a mill, let me know if you need more logs etc.

snigehere commented 1 year ago

In relation to this, I am able to get it working again by Disabling and Enabling the integration again.

I am able to get it going again just by hitting reload (option at the top of the menu where disable is at the bottom)

trialek commented 1 year ago

Hi all, I have the same issue and use 3.0.7 v Stops reviving data.

hultenvp commented 1 year ago

@snigehere

I do see a few times the app times out and wonder if there is some code issue caused by this .. What I notice in the log extract below is two fetch cycles without a schedule between them and also "device id" it is mentioned where al the other messages are "data for serial" .. I don't know if these are pointers to a root cause

What you see there is actually the integration recovering from a timeout. If it fails to retrieve data it will log out and log in again and merrily continue. Still it is pointing to the root cause. You see that in this part of the error @donal222022 reported:

[custom_components.solis.ginlong_api] Error: Exception: <class 'asyncio.exceptions.TimeoutError'> 2022-11-03 09:51:47.167 ERROR (MainThread) [homeassistant] Error doing job: Task exception was never retrieved Traceback (most recent call last): File "/config/custom_components/solis/service.py", line 182, in async_update if await self._login(): File "/config/custom_components/solis/service.py", line 92, in _login if await self._api.login(async_get_clientsession(self._hass)): File "/config/custom_components/solis/ginlong_api.py", line 224, in login data = await self.fetch_inverter_data(next(iter(self._inverter_list))) TypeError: 'NoneType' object is not iterable

There as part of the login the get inverter list fails (it uses the same low-level service call and in that call the timeout occurs), resulting in an empty list. Next line it trips over trying to iterate a non-existing list while trying to fetch the plant name.

hultenvp commented 1 year ago

The TypeError should now be handled properly. Feel free to reopen if crashes still occur