core icon indicating copy to clipboard operation
core copied to clipboard

Local NTP server with future time causes time-based trigger misfires since 2024.2.0/11.5

Open aigarius opened this issue 1 year ago • 5 comments

The problem

Symptoms:

  1. The HA appears to be running a minute in the future - running "date" over ssh in core container and rendering now() in template both shows time about a minute into the future
  2. Editing an object and then immediately opening its information shows modification time "In 1 minute" that then slowly counts down to "Now" and then to "x seconds ago"
  3. (new) Automations with time-based triggers (including fixed time, time helpers and sunrise/sunset) do not fire at the expected time, neither do they fire 1 minute earlier or later, instead they fire at a seemingly random time that is up to 100 minutes later than the expected trigger time

The symptoms 1 and 2 were visible in this installation for a long time, but did not impact functionality until an upgrade was made from 2023.12.5 (and OS 11.4) to 2024.2.0 (and OS 11.5). Since then the third symptom also appeared.

Workaround:

Debugging showed that the local ISP router was providing an NTP server with an incorrect time information (roughly 67 seconds into the future). Changing the HAOS IP address settings from DHCP to a manual IPv4 configuration made the HA stop using the local NTP server (as a known side-effect). This made all the issues above to go away.

What did not work:

Rebooting the core, rebooting the whole system, wiping the system and re-installing from a backup, setting correct time in BIOS - all of that had no effect on the bugs above. Restoring the same backup to a VM (without bridge! so NAT networking) created a system that did not show the bugs above.

Suspicions:

I've tried looking trough the diff in the code base between the versions affected and not affected and could only find one change that raised my suspicions in this context - https://github.com/home-assistant/core/commit/f96f4d31f76bd3a942cba0b658480592e58a4308 - if the time-related entities are getting cached for up 100 minutes and the cache does not get invalidated correctly when there is a time skew between the components, that that could produce the observed symptoms - the automation with its related entities gets cached just before it is supposed to fire, but on next checks the time value (in a now cached and unchanging helper) is never reaching the requested trigger time, so the even never fires, until the object expires from the cache 100 minutes later.

It's a weak theory, so I'd love to try something else, including trying to reproduce the bug it a clean VM (it should happen in a clean install of VM in bridge mode, but not in NAT mode in my network). If there are specific log files or config/database fields I could read to help you narrow the problem down, please let me know. It appears that I should be able to break/fix my main instance at will by just changing IPv4 settings between DHCP and manual.

What version of Home Assistant Core has the issue?

core-2024.2.0

What was the last working version of Home Assistant Core?

core-2023.12.5

What type of installation are you running?

Home Assistant OS

Integration causing the issue

No response

Link to integration documentation on our website

No response

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

aigarius avatar Feb 26 '24 14:02 aigarius

Screenshot from 2024-02-26 15-07-19 Screenshot from 2024-02-26 15-07-09

aigarius avatar Feb 26 '24 14:02 aigarius

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.

Still happening with 2024.5.5

aigarius avatar May 26 '24 16:05 aigarius

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.

Still active.

aigarius avatar Aug 26 '24 16:08 aigarius

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.