diff --git a/homeassistant/const.py b/homeassistant/const.py index 9f92d11e4cdc..eac648bc929e 100644 --- a/homeassistant/const.py +++ b/homeassistant/const.py @@ -633,7 +633,3 @@ CLOUD_NEVER_EXPOSED_ENTITIES = ["group.all_locks"] # The ID of the Home Assistant Cast App CAST_APP_ID_HOMEASSISTANT = "B12CE3CA" - -# The tracker error allow when converting -# loop time to human readable time -MAX_TIME_TRACKING_ERROR = 0.001 diff --git a/homeassistant/helpers/event.py b/homeassistant/helpers/event.py index 2044dbd78565..661e1a11b56c 100644 --- a/homeassistant/helpers/event.py +++ b/homeassistant/helpers/event.py @@ -28,7 +28,6 @@ from homeassistant.const import ( EVENT_STATE_CHANGED, EVENT_TIME_CHANGED, MATCH_ALL, - MAX_TIME_TRACKING_ERROR, SUN_EVENT_SUNRISE, SUN_EVENT_SUNSET, ) @@ -1133,16 +1132,36 @@ def async_track_point_in_utc_time( # having to figure out how to call the action every time its called. job = action if isinstance(action, HassJob) else HassJob(action) - cancel_callback = hass.loop.call_at( - hass.loop.time() + point_in_time.timestamp() - time.time(), - hass.async_run_hass_job, - job, - utc_point_in_time, - ) + cancel_callback: Optional[asyncio.TimerHandle] = None + + @callback + def run_action() -> None: + """Call the action.""" + nonlocal cancel_callback + + now = time_tracker_utcnow() + + # Depending on the available clock support (including timer hardware + # and the OS kernel) it can happen that we fire a little bit too early + # as measured by utcnow(). That is bad when callbacks have assumptions + # about the current time. Thus, we rearm the timer for the remaining + # time. + delta = (utc_point_in_time - now).total_seconds() + if delta > 0: + _LOGGER.debug("Called %f seconds too early, rearming", delta) + + cancel_callback = hass.loop.call_later(delta, run_action) + return + + hass.async_run_hass_job(job, utc_point_in_time) + + delta = utc_point_in_time.timestamp() - time.time() + cancel_callback = hass.loop.call_later(delta, run_action) @callback def unsub_point_in_time_listener() -> None: """Cancel the call_later.""" + assert cancel_callback is not None cancel_callback.cancel() return unsub_point_in_time_listener @@ -1294,7 +1313,7 @@ def async_track_sunset( track_sunset = threaded_listener_factory(async_track_sunset) # For targeted patching in tests -pattern_utc_now = dt_util.utcnow +time_tracker_utcnow = dt_util.utcnow @callback @@ -1325,75 +1344,38 @@ def async_track_utc_time_change( matching_minutes = dt_util.parse_time_expression(minute, 0, 59) matching_hours = dt_util.parse_time_expression(hour, 0, 23) - next_time: datetime = dt_util.utcnow() - - def calculate_next(now: datetime) -> None: + def calculate_next(now: datetime) -> datetime: """Calculate and set the next time the trigger should fire.""" - nonlocal next_time - localized_now = dt_util.as_local(now) if local else now - next_time = dt_util.find_next_time_expression_time( + return dt_util.find_next_time_expression_time( localized_now, matching_seconds, matching_minutes, matching_hours ) - # Make sure rolling back the clock doesn't prevent the timer from - # triggering. - cancel_callback: Optional[asyncio.TimerHandle] = None - calculate_next(next_time) + time_listener: Optional[CALLBACK_TYPE] = None @callback - def pattern_time_change_listener() -> None: + def pattern_time_change_listener(_: datetime) -> None: """Listen for matching time_changed events.""" - nonlocal next_time, cancel_callback + nonlocal time_listener - now = pattern_utc_now() + now = time_tracker_utcnow() hass.async_run_hass_job(job, dt_util.as_local(now) if local else now) - calculate_next(now + timedelta(seconds=1)) - - cancel_callback = hass.loop.call_at( - -time.time() - + hass.loop.time() - + next_time.timestamp() - + MAX_TIME_TRACKING_ERROR, + time_listener = async_track_point_in_utc_time( + hass, pattern_time_change_listener, + calculate_next(now + timedelta(seconds=1)), ) - # We always get time.time() first to avoid time.time() - # ticking forward after fetching hass.loop.time() - # and callback being scheduled a few microseconds early. - # - # Since we loose additional time calling `hass.loop.time()` - # we add MAX_TIME_TRACKING_ERROR to ensure - # we always schedule the call within the time window between - # second and the next second. - # - # For example: - # If the clock ticks forward 30 microseconds when fectching - # `hass.loop.time()` and we want the event to fire at exactly - # 03:00:00.000000, the event would actually fire around - # 02:59:59.999970. To ensure we always fire sometime between - # 03:00:00.000000 and 03:00:00.999999 we add - # MAX_TIME_TRACKING_ERROR to make up for the time - # lost fetching the time. This ensures we do not fire the - # event before the next time pattern match which would result - # in the event being fired again since we would otherwise - # potentially fire early. - # - cancel_callback = hass.loop.call_at( - -time.time() - + hass.loop.time() - + next_time.timestamp() - + MAX_TIME_TRACKING_ERROR, - pattern_time_change_listener, + time_listener = async_track_point_in_utc_time( + hass, pattern_time_change_listener, calculate_next(dt_util.utcnow()) ) @callback def unsub_pattern_time_change_listener() -> None: - """Cancel the call_later.""" - nonlocal cancel_callback - assert cancel_callback is not None - cancel_callback.cancel() + """Cancel the time listener.""" + assert time_listener is not None + time_listener() return unsub_pattern_time_change_listener diff --git a/homeassistant/helpers/ratelimit.py b/homeassistant/helpers/ratelimit.py index d7099e9fe3da..40f10e69d251 100644 --- a/homeassistant/helpers/ratelimit.py +++ b/homeassistant/helpers/ratelimit.py @@ -4,7 +4,6 @@ from datetime import datetime, timedelta import logging from typing import Any, Callable, Dict, Hashable, Optional -from homeassistant.const import MAX_TIME_TRACKING_ERROR from homeassistant.core import HomeAssistant, callback import homeassistant.util.dt as dt_util @@ -95,7 +94,7 @@ class KeyedRateLimit: if key not in self._rate_limit_timers: self._rate_limit_timers[key] = self.hass.loop.call_later( - (next_call_time - now).total_seconds() + MAX_TIME_TRACKING_ERROR, + (next_call_time - now).total_seconds(), action, *args, ) diff --git a/tests/common.py b/tests/common.py index 0b56d10188e5..f41122bc2b7f 100644 --- a/tests/common.py +++ b/tests/common.py @@ -301,7 +301,7 @@ def async_fire_time_changed(hass, datetime_, fire_all=False): if fire_all or mock_seconds_into_future >= future_seconds: with patch( - "homeassistant.helpers.event.pattern_utc_now", + "homeassistant.helpers.event.time_tracker_utcnow", return_value=date_util.as_utc(datetime_), ): task._run() diff --git a/tests/components/homekit_controller/conftest.py b/tests/components/homekit_controller/conftest.py index dbb1db36aa7a..cb75fc205e28 100644 --- a/tests/components/homekit_controller/conftest.py +++ b/tests/components/homekit_controller/conftest.py @@ -15,7 +15,7 @@ from tests.components.light.conftest import mock_light_profiles # noqa def utcnow(request): """Freeze time at a known point.""" now = dt_util.utcnow() - start_dt = datetime.datetime(now.year + 1, 1, 1, 0, 0, 0) + start_dt = datetime.datetime(now.year + 1, 1, 1, 0, 0, 0, tzinfo=now.tzinfo) with mock.patch("homeassistant.util.dt.utcnow") as dt_utcnow: dt_utcnow.return_value = start_dt yield dt_utcnow diff --git a/tests/helpers/test_event.py b/tests/helpers/test_event.py index 64c5d79469b1..1b9ddc521916 100644 --- a/tests/helpers/test_event.py +++ b/tests/helpers/test_event.py @@ -93,6 +93,38 @@ async def test_track_point_in_time(hass): assert len(runs) == 2 +async def test_track_point_in_time_drift_rearm(hass): + """Test tasks with the time rolling backwards.""" + specific_runs = [] + + now = dt_util.utcnow() + + time_that_will_not_match_right_away = datetime( + now.year + 1, 5, 24, 21, 59, 55, tzinfo=dt_util.UTC + ) + + async_track_point_in_utc_time( + hass, + callback(lambda x: specific_runs.append(x)), + time_that_will_not_match_right_away, + ) + + async_fire_time_changed( + hass, + datetime(now.year + 1, 5, 24, 21, 59, 00, tzinfo=dt_util.UTC), + fire_all=True, + ) + await hass.async_block_till_done() + assert len(specific_runs) == 0 + + async_fire_time_changed( + hass, + datetime(now.year + 1, 5, 24, 21, 59, 55, tzinfo=dt_util.UTC), + ) + await hass.async_block_till_done() + assert len(specific_runs) == 1 + + async def test_track_state_change_from_to_state_match(hass): """Test track_state_change with from and to state matchers.""" from_and_to_state_runs = [] @@ -2762,7 +2794,7 @@ async def test_periodic_task_clock_rollback(hass): fire_all=True, ) await hass.async_block_till_done() - assert len(specific_runs) == 2 + assert len(specific_runs) == 1 async_fire_time_changed( hass, @@ -2770,13 +2802,13 @@ async def test_periodic_task_clock_rollback(hass): fire_all=True, ) await hass.async_block_till_done() - assert len(specific_runs) == 3 + assert len(specific_runs) == 1 async_fire_time_changed( hass, datetime(now.year + 1, 5, 25, 2, 0, 0, 999999, tzinfo=dt_util.UTC) ) await hass.async_block_till_done() - assert len(specific_runs) == 4 + assert len(specific_runs) == 2 unsub() @@ -2784,7 +2816,7 @@ async def test_periodic_task_clock_rollback(hass): hass, datetime(now.year + 1, 5, 25, 2, 0, 0, 999999, tzinfo=dt_util.UTC) ) await hass.async_block_till_done() - assert len(specific_runs) == 4 + assert len(specific_runs) == 2 async def test_periodic_task_duplicate_time(hass):