hultenvp / solis-sensor

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

WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found #223

Closed barthoefs closed 1 year ago

barthoefs commented 1 year ago
2022-12-01 02:29:26.837 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 02:30:26.967 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 02:31:27.082 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 02:32:27.214 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 02:33:27.380 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 02:49:22.618 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 02:50:22.744 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 02:51:22.861 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 02:52:22.984 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 02:53:23.108 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 02:57:24.748 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 03:01:25.658 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 03:02:25.790 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 03:03:25.914 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 03:04:26.046 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 03:05:26.178 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 03:06:26.304 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 03:07:26.428 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 06:17:13.337 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 06:19:22.708 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 06:20:22.828 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 06:21:22.958 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 06:22:23.095 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 07:22:23.035 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 08:01:39.672 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found

Is this fixable? What is the default polling for the API?

hultenvp commented 1 year ago

Would be great if you could dump a debug log, but I assume you have the same issue as others discussing here: https://github.com/hultenvp/solis-sensor/issues/183#issuecomment-1330424320

hultenvp commented 1 year ago

Interestingly, when I extend timeouts to 100sec I now see the same issue.

2022-12-01 19:57:23.463 DEBUG (MainThread) [custom_components.solis.soliscloud_api] Error from URI (/v1/api/inveterList) : 0, message='Attempt to decode JSON with unexpected mimetype: text/html', url=URL('https://www.soliscloud.com:13333/v1/api/inveterList')
2022-12-01 19:57:23.479 WARNING (MainThread) [custom_components.solis.soliscloud_api] No inverters found
2022-12-01 19:57:23.509 WARNING (MainThread) [custom_components.solis.service] Failed to discover, scheduling retry in 300 seconds.
2022-12-01 19:57:23.564 DEBUG (MainThread) [custom_components.solis.service] Scheduling discovery in 300 seconds.
jmason commented 1 year ago

I added some extra logging to log the raw text in order to debug this mime type error. here's what I got:

homeassistant         | 2022-12-09 11:12:29.595 INFO (MainThread) [custom_components.solis.soliscloud_api] Output from URI (/v1/api/inveterList) : <html>
homeassistant         | <head><title>502 Bad Gateway</title></head>
homeassistant         | <body bgcolor="white">
homeassistant         | <center><h1>502 Bad Gateway</h1></center>
homeassistant         | <hr><center>nginx</center>
homeassistant         | </body>
homeassistant         | </html>

That's a load-balancer generated error page. I would say that's a problem on the backend with the Solis Cloud API servers.

barthoefs commented 1 year ago

Yeah seems like Solis Cloud api issue today

viking2010 commented 1 year ago

I'm seeing the same at my end too. The solistest.py is pulling back data ok, but the integration isn't and reports the same errors as above.

UPDATE: Although having just posted that, it all came back to life!!

rossdargan commented 1 year ago

I get this issue following a reboot for a bit (maybe 30 - 60 minutes). I wonder if there is more to this. It does eventually come back up.

hultenvp commented 1 year ago

@jmason, @viking2010 , @rossdargan : I recently had some connectivity troubles myself. Running now with extra logs to get more clarity, but I saw both 408 and 502 errors.

jmason commented 1 year ago

I think you are probably on the money regarding the 408 error being related to the VM time drift. Also that's a good theory about the 502s being related to the backend disliking repeated API calls too close together; that would explain how the same API calls work ok from the test app, but then give a 502 once called via the library.

hultenvp commented 1 year ago

Thanks for the response. I'd like to somehow get confirmation on the 502 theory. Let's see if I can use the test app to mimic a single session making to frequent calls.

hultenvp commented 1 year ago

I modified the test app to also use aiohttp and one single session. If I make 10 calls in parallel I get a 429: {"error": "Too Many Requests", "message": "too much request 2 times in 1000 millseconds", "path": "/v1/api/inveterList", "status": 429, "timestamp": 1671179957966}

So it looks like the 502 is probably not caused by frequent calls. It still could be a load-balancer issue, but then why it only causes issues with the integration and not the test app.....

Still, I'll change the integration not to make more than 1 call per second as the 429 indicates 2 per second is max

hultenvp commented 1 year ago

I'll close this issue, further issues after release 3.2.0 please report in #232