home-assistant / core

:house_with_garden: Open source home automation that puts local control and privacy first.
https://www.home-assistant.io
Apache License 2.0
73.38k stars 30.64k forks source link

Solax integration occasionally returning all zeros #66912

Closed nmnogueira closed 2 years ago

nmnogueira commented 2 years ago

The problem

The Solax integration is occasionally returning zero for all values, including the energy. solax0 solax1 Because the value goes to zero and back to the correct value, the Total (sum) value is wrong. This breaks the statistics calculation solax4 solax3 This happens every one or two days.

What version of Home Assistant Core has the issue?

core-2022.2.9

What was the last working version of Home Assistant Core?

No response

What type of installation are you running?

Home Assistant OS

Integration causing the issue

solax

Link to integration documentation on our website

https://www.home-assistant.io/integrations/solax/

Diagnostics information

No response

Example YAML snippet

No response

Anything in the logs that might be useful for us?

No response

Additional information

No response

probot-home-assistant[bot] commented 2 years ago

solax documentation solax source (message by IssueLinks)

probot-home-assistant[bot] commented 2 years ago

Hey there @squishykid, mind taking a look at this issue as it has been labeled with an integration (solax) you are listed as a code owner for? Thanks! (message by CodeOwnersMention)

Azelphur commented 2 years ago

I appear to have the same issue and have been looking into it. For me, it seems to happen fairly consistently at sunrise. So every morning between 6am and 6:20am, the "Total Energy" value will drop to zero, then back up to where it was previously, causing the massive spikes in solar production shown in OPs screenshot.

This appears to be a bug in the inverter itself. I started logging the response body from the inverter so that I could catch it happening.

Here are the logs

192.168.1.11 - - [18/Mar/2022:06:01:12 +0000] "POST /?optType=ReadRealTimeData&pwd=admin& HTTP/1.1" 200 530 "-" "Python/3.9 aiohttp/3.8.1" 1.310 req_body:"-" resp_body:"{\x22sn\x22:\x22SNREDACTED\x22,\x22ver\x22:\x222.034.06\x22,\x22type\x22:4,\x22Data\x22:[0,0,0,0,0,0,0,0,0,0,0,1144,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,77,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],\x09\x09\x22Information\x22:[5.000,4,\x22SNREDACTED\x22,1,0.00,0.00,1.35,0.00,0.00,1]}"
192.168.1.11 - - [18/Mar/2022:06:01:42 +0000] "POST /?optType=ReadRealTimeData&pwd=admin& HTTP/1.1" 200 530 "-" "Python/3.9 aiohttp/3.8.1" 1.238 req_body:"-" resp_body:"{\x22sn\x22:\x22SNREDACTED\x22,\x22ver\x22:\x222.034.06\x22,\x22type\x22:4,\x22Data\x22:[0,0,0,0,0,0,0,0,0,0,0,1144,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,77,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],\x09\x09\x22Information\x22:[5.000,4,\x22SNREDACTED\x22,1,0.00,0.00,1.35,0.00,0.00,1]}"
192.168.1.11 - - [18/Mar/2022:06:02:12 +0000] "POST /?optType=ReadRealTimeData&pwd=admin& HTTP/1.1" 200 536 "-" "Python/3.9 aiohttp/3.8.1" 1.238 req_body:"-" resp_body:"{\x22sn\x22:\x22SNREDACTED\x22,\x22ver\x22:\x222.034.06\x22,\x22type\x22:4,\x22Data\x22:[2437,0,0,519,521,0,0,0,0,5015,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],\x09\x09\x22Information\x22:[5.000,4,\x22SNREDACTED\x22,1,2.14,0.00,1.35,0.00,0.00,1]}"
192.168.1.11 - - [18/Mar/2022:06:02:42 +0000] "POST /?optType=ReadRealTimeData&pwd=admin& HTTP/1.1" 200 542 "-" "Python/3.9 aiohttp/3.8.1" 1.240 req_body:"-" resp_body:"{\x22sn\x22:\x22SNREDACTED\x22,\x22ver\x22:\x222.034.06\x22,\x22type\x22:4,\x22Data\x22:[2331,0,0,548,550,0,0,0,0,5015,0,1144,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,21,0,77,0,0,0,0,0,0,0,0,0,0,0,0,0,24,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],\x09\x09\x22Information\x22:[5.000,4,\x22SNREDACTED\x22,1,2.14,0.00,1.35,0.00,0.00,1]}"
192.168.1.11 - - [18/Mar/2022:06:03:12 +0000] "POST /?optType=ReadRealTimeData&pwd=admin& HTTP/1.1" 200 542 "-" "Python/3.9 aiohttp/3.8.1" 1.238 req_body:"-" resp_body:"{\x22sn\x22:\x22SNREDACTED\x22,\x22ver\x22:\x222.034.06\x22,\x22type\x22:4,\x22Data\x22:[2433,0,0,617,619,0,0,0,0,5012,0,1144,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,21,0,77,0,0,0,0,0,0,0,0,0,0,0,0,0,25,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],\x09\x09\x22Information\x22:[5.000,4,\x22SNREDACTED\x22,1,2.14,0.00,1.35,0.00,0.00,1]}"
192.168.1.11 - - [18/Mar/2022:06:03:42 +0000] "POST /?optType=ReadRealTimeData&pwd=admin& HTTP/1.1" 200 544 "-" "Python/3.9 aiohttp/3.8.1" 1.239 req_body:"-" resp_body:"{\x22sn\x22:\x22SNREDACTED\x22,\x22ver\x22:\x222.034.06\x22,\x22type\x22:4,\x22Data\x22:[2429,0,0,2310,2312,0,0,0,0,5012,0,1144,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,21,0,77,0,0,0,0,0,0,0,0,0,0,0,0,0,26,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0],\x09\x09\x22Information\x22:[5.000,4,\x22SNREDACTED\x22,1,2.14,0.00,1.35,0.00,0.00,1]}"

You can see that on all but the 06:02:12 line, the value 1144 is logged. I believe 1144 to be the total energy (114.4kwh). On the 06:02:12 line, instead of 1144, it's returning 0, then immediately after, it jumps back to 114.4.

And of course, looking in home assistants history for the total_energy sensor, I see the same thing, 114.4kwh up until 06:02:12am, where it drops to zero, then immediately returns to 114.4kwh.

I suspect that the integration will need to be modified to tolerate/ignore the incorrect data being returned by the inverter.

Azelphur commented 2 years ago

From my inverter, I am unable to reproduce a few of the things mentioned in OP, but no doubt this is because we have slightly different inverters.

For me, Grid frequency, pv1 power, current, voltage, ac power, output current, network voltage, todays energy, etc are all 0 while the sun is down (which makes sense). I have not noticed any random drops to zero during the day of these sensors (at least, not yet)

Total energy seems to be the main problem, my solution has been to patch sensor.py to prevent the value of total energy from dropping.

--- a/homeassistant/components/solax/sensor.py
+++ b/homeassistant/components/solax/sensor.py
@@ -131,10 +131,12 @@ class RealTimeDataEndpoint:
         data = api_response.data
         for sensor in self.sensors:
             if sensor.key in data:
+                if sensor.key == "Total Energy" and data[sensor.key] == 0 and sensor.value >= 0:
+                    _LOGGER.warning("SolaX inverter reported 0 for total energy, ignoring.")
+                    continue
                 sensor.value = data[sensor.key]
                 sensor.async_schedule_update_ha_state()

This seemed to work this morning. I'll test it for a while longer before committing it, though.

squishykid commented 2 years ago

Thanks for including the logs! I can’t look into this just right now. Once I get a chance though the logs will be a great help!

Azelphur commented 2 years ago

No problem, thanks for looking into this! :)

Just to update, I can confirm my patch seems to resolve the issue, most mornings I get the line in my logs, and I don't get massive spikes in my Energy->Solar production chart any more

2022-03-27 06:38:59 WARNING (MainThread) [homeassistant.components.solax.sensor] SolaX inverter reported 0 for total energy, ignoring.
2022-03-29 06:50:04 WARNING (MainThread) [homeassistant.components.solax.sensor] SolaX inverter reported 0 for total energy, ignoring.

I'll hold off on making any commits to HA though, since I'm not really sure my solution is the best way of solving it, but it is at least a temporary solution :)

VadimKraus commented 2 years ago

I had a similar problem today. Coincidentally (or not), the web portal is showing some alerts around the same time.

squishykid commented 2 years ago

If you like, we could continue the discussion over here: https://github.com/squishykid/solax/issues/67

github-actions[bot] commented 2 years ago

There hasn't been any activity on this issue recently. Due to the high number of incoming GitHub notifications, we have to clean some of the old issues, as many of them have already been resolved with the latest updates. Please make sure to update to the latest Home Assistant version and check if that solves the issue. Let us know if that works for you by adding a comment 👍 This issue has now been marked as stale and will be closed if no further activity occurs. Thank you for your contributions.

Azelphur commented 2 years ago

Unless I'm mistaken, this issue is not resolved. The child issues / PR is still open, can we reopen this?