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
71.06k stars 29.73k forks source link

Goodwe integration daily total reset at wrong time #80588

Closed lyricnz closed 1 year ago

lyricnz commented 1 year ago

The problem

Since #76793 was merged the "Today's PV Generation" for Goodwe Inverts has been unreliable and incorrect (especially in our timezone +10-11). See #80216 #80145

It is resetting daily tallies at the wrong time, and causes problems during start-of-day, strobing between 0 and some other value, causing energy generation to be counted multiple times. See below, it reset the daily total at 5pm for no good reason (and solar was still generating). The day started at 0615 with PV power ramping up from zero, but the "todays generation" started at 9.9kWh

(PS: the inverter goes off at night, so having 0/unavailable when it's not generating is normal)

image

This worked perfectly until about 13th October (+11). Probably broken by core_2022.10.3 or so

image

What version of Home Assistant Core has the issue?

2022.10.4

What was the last working version of Home Assistant Core?

About 2022.10.2-3

What type of installation are you running?

Home Assistant OS

Integration causing the issue

goodwe

Link to integration documentation on our website

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

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

home-assistant[bot] commented 1 year ago

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


goodwe documentation goodwe source (message by IssueLinks)

lyricnz commented 1 year ago

I have reverted just this PR from my core:dev checkout on my workstation, and will leave it running overnight to see how it goes tomorrow morning. Will be able to compare to the latest HA OS core on my other machine, polling the same Goodwe inverter.

frenck commented 1 year ago

@lyricnz This is a duplicate of #80216? Why do you create duplicate issues? (unless I misunderstand of course).

../Frenck

starkillerOG commented 1 year ago

I will look into this, probably the midnight time is calculated wrong based on UTC timezone.

lyricnz commented 1 year ago

@lyricnz This is a duplicate of #80216? Why do you create duplicate issues? (unless I misunderstand of course).

I felt it was only semi-duplicate. The other issue was specifically about the strobing between zero and non-zero at the start of day. I hadn’t noticed the reset at 5pm, or the date when the problem started, or the fact that the start-of-day value is probably the remains from yesterday.

It didn’t feel like I was getting much traction, or made explicit the likely number of people impacted.

frenck commented 1 year ago

It didn’t feel like I was getting much traction

Well, that is not a reason to create more issues. More issues won't help. Additionally, could you please change the subject/title of this issue to something descriptive? This isn't a task or request, an issue should contain an issue description (including the title).

Thanks! 👍

../Frenck

starkillerOG commented 1 year ago

Anyone want to try my fix: https://github.com/home-assistant/core/pull/80624 Did not test it myself yet.

starkillerOG commented 1 year ago

fixed by https://github.com/home-assistant/core/pull/80624 which is merged, so this can be closed.

lyricnz commented 1 year ago

@starkillerOG I'm not convinced this is fixed yet. I was running the post-patch version last night (dropped a copy of "goodwe" directory into config/custom_components/goodwe and added version:0.0.1 to the manifest.json), with an additional line of logging:

❯ grep -C5 LOGGER sensor.py
)
import homeassistant.util.dt as dt_util

from .const import DOMAIN, KEY_COORDINATOR, KEY_DEVICE_INFO, KEY_INVERTER

_LOGGER = logging.getLogger(__name__)

# Sensor name of battery SoC
BATTERY_SOC = "battery_soc"

# Sensors that are reset to 0 at midnight.
--
        """Reset the value back to 0 at midnight."""
        if not self.coordinator.last_update_success:
            self._previous_value = 0
            self.coordinator.data[self._sensor.id_] = 0
            self.async_write_ha_state()
            _LOGGER.debug("Goodwe reset %s to 0", self.name)
        next_midnight = dt_util.start_of_local_day(
            dt_util.now() + timedelta(days=1, minutes=1)
        )
        self._stop_reset = async_track_point_in_time(
            self.hass, self.async_reset, next_midnight
--
        """Schedule reset task at midnight."""
        if self._sensor.id_ in DAILY_RESET:
            next_midnight = dt_util.start_of_local_day(
                dt_util.now() + timedelta(days=1)
            )
            _LOGGER.warning("XXXX Scheduled Goodwe %s sensor=%s at %s", self.name, self._sensor.id_, next_midnight)
            self._stop_reset = async_track_point_in_time(
                self.hass, self.async_reset, next_midnight
            )
        await super().async_added_to_hass()

Applied this and restarted my HA install at around 0920 yesterday. Here is the graph of Today's PV generation over that time. It looks like the inverter went dead by about 8pm, having done the usual/bug reset at 5pm (for my timezone!) then came up at about 6:20 with the old value. I notice the "lingering" value did go to zero at midnight, but came right back when the inverter started in the morning.

Note: two graphs not vertically aligned

image

lyricnz commented 1 year ago

Here's the log entry from HA startup with the code above. It looks like it's scheduling the reset OK, but... something else did the 5pm reset? And inverter kept old value?

2022-10-22 09:40:22.646 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration goodwe 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-22 09:40:28.044 INFO (MainThread) [homeassistant.bootstrap] Setting up stage 2: {'mobile_app', 'blueprint', 'tplink', 'goodwe', 'netgear', 'application_credentials', 'trace', 'upnp', 'logbook', 'diagnostics', 'sun', 'input_number', 'homeassistant_alerts', 'script', 'starlink', 'config', 'input_boolean', 'tts', 'input_datetime', 'tag', 'ffmpeg', 'cast', 'iotawatt', 'hacs', 'history', 'counter', 'input_text', 'automation', 'zone', 'met', 'file_upload', 'hardware', 'scene', 'map', 'input_select', 'system_health', 'image', 'repairs', 'ipp', 'brother', 'hue', 'device_automation', 'analytics', 'my', 'media_source', 'forecast_solar', 'template', 'homekit', 'timer', 'webostv', 'input_button', 'energy', 'mqtt', 'search', 'persistent_notification', 'schedule', 'auth', 'smartthings', 'device_tracker', 'reolink_dev', 'lovelace', 'co2signal', 'person', 'rest_command', 'onboarding', 'openweathermap', 'default_config'}
2022-10-22 09:40:28.285 INFO (MainThread) [homeassistant.setup] Setting up goodwe
2022-10-22 09:40:28.285 INFO (MainThread) [homeassistant.setup] Setup of domain goodwe took 0.0 seconds
2022-10-22 09:40:29.440 INFO (MainThread) [homeassistant.components.button] Setting up button.goodwe
2022-10-22 09:40:29.443 INFO (MainThread) [homeassistant.components.sensor] Setting up sensor.goodwe
2022-10-22 09:40:29.478 WARNING (MainThread) [custom_components.goodwe.sensor] XXXX Scheduled Goodwe Today's PV Generation sensor=e_day at 2022-10-23 00:00:00+11:00
2022-10-22 09:40:29.514 INFO (MainThread) [homeassistant.components.select] Setting up select.goodwe
2022-10-22 09:40:29.517 INFO (MainThread) [homeassistant.components.number] Setting up number.goodwe
lyricnz commented 1 year ago

Hmm, I think the timezone may have been wrong on my inverter? I've set this to my localtime now, will see how it goes tonight.

Edit: heheh, when I changed the time on the inverter, it did it's own daily reset. Must have noticed that it was after midnight image

lyricnz commented 1 year ago

Looks OK today. Closing. Screen Shot 2022-10-24 at 7 23 55 am

lyricnz commented 1 year ago

@starkillerOG maybe it could reset at 11:59 rather than 12:00? Otherwise the scale of the "today" chart is messed up, because it includes one minute of yesterdays generation. image

simon-anz commented 1 year ago

My inverter seems to keep losing timezone overnight, and coming up the next day with the wrong timezone. Might need to make an automation to reset it once it comes online for the day, if I can't get anything from goodwe support. (my inverter has never been very reliable connecting to semsportal - I think the goodwe HA integration more-or-less breaks it - frequent polling?)

PS: lyricnz == simon-anz

lyricnz commented 1 year ago

FWIW it seems that enable the HA GoodWe integration completely breaks communication to semsportal (which may be what is breaking the timezone). It's a bit annoying that we can't easily update the polling rate without modifying the code.

Meanwhile, I created an automation to fix the clock if it gets >60 seconds out of date, which happens every day for me.

image