From f9fc9dfd05784ae1637e9662280e7fdd7dbf1f70 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pablo=20G=C3=B3mez?= Date: Fri, 24 Jul 2026 10:39:22 +0200 Subject: [PATCH 1/2] fix: make advance_time re-entrancy guard exception-safe advance_time set _is_advancing_time=True before validating its arguments and only cleared it on the normal return path, so any early return (radiation events) or exception left the guard stuck True, poisoning every subsequent call with a spurious 'advance_time is already running' assertion. In real-time activity mode the measured interval can round to zero, tripping the positive-time assert, which crashed the background ActivityProcessor and deadlocked wait_for_activity. Release the guard in a finally block, treat a zero interval as a no-op, and skip zero-length processor updates instead of asserting. --- paseos/activities/activity_processor.py | 6 +- paseos/paseos.py | 181 +++++++++++++----------- 2 files changed, 101 insertions(+), 86 deletions(-) diff --git a/paseos/activities/activity_processor.py b/paseos/activities/activity_processor.py index 8e35acf..2f71385 100644 --- a/paseos/activities/activity_processor.py +++ b/paseos/activities/activity_processor.py @@ -83,7 +83,11 @@ async def _update(self, elapsed_time: float): Args: elapsed_time (float): Elapsed time in seconds. """ - assert elapsed_time > 0, "Elapsed time cannot be negative." + assert elapsed_time >= 0, "Elapsed time cannot be negative." + # A zero interval can occur when updates are scheduled back-to-back; skip it + # rather than asserting, which would crash the background processor task. + if elapsed_time == 0: + return logger.debug("Running ActivityProcessor update.") logger.debug(f"Time since last update: {elapsed_time}s") logger.trace(f"Applying time multiplier of {self._time_multiplier}") diff --git a/paseos/paseos.py b/paseos/paseos.py index d842528..b9e4fe1 100644 --- a/paseos/paseos.py +++ b/paseos/paseos.py @@ -98,97 +98,108 @@ def advance_time( float: Time remaining to advance (or 0 if done) """ + assert current_power_consumption_in_W >= 0, "Power consumption cannot be negative." + assert time_to_advance >= 0, "Time to advance cannot be negative." + + # In real-time (async activity) mode the measured interval between updates can + # round to zero. Advancing by zero is a no-op, so return before touching the + # re-entrancy guard to avoid leaving it set. + if time_to_advance == 0: + return 0.0 + assert not self._is_advancing_time, ( "advance_time is already running. This function is not thread-safe. Avoid mixing (async) activities and calling it." ) self._is_advancing_time = True - - assert time_to_advance > 0, "Time to advance has to be positive." - assert current_power_consumption_in_W >= 0, "Power consumption cannot be negative." - - # Check constraint function returns something - if constraint_function is not None: - assert constraint_function() is not None, ( - "Your constraint function failed to return True or False." - ) - - logger.debug("Advancing time by " + str(time_to_advance) + " s.") - target_time = self._state.time + time_to_advance - dt = self._cfg.sim.dt - - time_since_constraint_check = float("inf") - - # Perform timesteps until target_time - dt reached, - # then final smaller or equal timestep to reach target_time - while self._state.time < target_time: - # Check constraint function - if ( - constraint_function is not None - and time_since_constraint_check > self._cfg.sim.activity_timestep - ): - time_since_constraint_check = 0 - if not constraint_function(): - logger.info("Time advancing interrupted. Constraint false.") - break - - if self._state.time > target_time - dt: - # compute final timestep to catch up - dt = target_time - self._state.time - logger.trace(f"Time {self._state.time}, advancing {dt}") - - # Perform updates for local actor (e.g. charging) - # Each actor only updates itself - - # check for device and / or activity failure - if self.local_actor.has_radiation_model: - if self.local_actor.is_dead: - logger.warning(f"Tried to advance time on dead actor {self.local_actor}.") - return max(target_time - self._state.time, 0) - if self.local_actor._radiation_model.did_device_restart(dt): - logger.info(f"Actor {self.local_actor} interrupted during advance_time.") - self.local_actor.set_was_interrupted() - return max(target_time - self._state.time, 0) - if self.local_actor._radiation_model.did_device_experience_failure(dt): - logger.info(f"Actor {self.local_actor} died during advance_time.") - self.local_actor.set_is_dead() - return max(target_time - self._state.time, 0) - - # charge from current moment to time after timestep - if self.local_actor.has_power_model: - self._local_actor.charge(dt) - - # Update actor temperature - if self.local_actor.has_thermal_model: - self.local_actor._thermal_model.update_temperature( - dt, current_power_consumption_in_W + # Wrap the body so the guard is always released, even on an early return or an + # exception. Leaking it True would poison every later advance_time call. + try: + # Check constraint function returns something + if constraint_function is not None: + assert constraint_function() is not None, ( + "Your constraint function failed to return True or False." ) - # Update state of charge - if self.local_actor.has_power_model: - self.local_actor.discharge(current_power_consumption_in_W, dt) - - # Update user-defined properties in the actor - for property_name in self.local_actor.custom_properties.keys(): - update_function = self.local_actor.get_custom_property_update_function( - property_name - ) - new_value = update_function(self.local_actor, dt, current_power_consumption_in_W) - self.local_actor.set_custom_property(property_name, new_value) - - self._state.time += dt - time_since_constraint_check += dt - self.local_actor.set_time(pk.epoch(self._state.time * pk.SEC2DAY)) - - # Check if we should update the status log - if self._time_since_previous_log > self._cfg.io.logging_interval: - self.log_status() - self._time_since_previous_log = 0 - else: - self._time_since_previous_log += dt - - logger.debug("New time is: " + str(self._state.time) + " s.") - self._is_advancing_time = False - return max(target_time - self._state.time, 0) + logger.debug("Advancing time by " + str(time_to_advance) + " s.") + target_time = self._state.time + time_to_advance + dt = self._cfg.sim.dt + + time_since_constraint_check = float("inf") + + # Perform timesteps until target_time - dt reached, + # then final smaller or equal timestep to reach target_time + while self._state.time < target_time: + # Check constraint function + if ( + constraint_function is not None + and time_since_constraint_check > self._cfg.sim.activity_timestep + ): + time_since_constraint_check = 0 + if not constraint_function(): + logger.info("Time advancing interrupted. Constraint false.") + break + + if self._state.time > target_time - dt: + # compute final timestep to catch up + dt = target_time - self._state.time + logger.trace(f"Time {self._state.time}, advancing {dt}") + + # Perform updates for local actor (e.g. charging) + # Each actor only updates itself + + # check for device and / or activity failure + if self.local_actor.has_radiation_model: + if self.local_actor.is_dead: + logger.warning(f"Tried to advance time on dead actor {self.local_actor}.") + return max(target_time - self._state.time, 0) + if self.local_actor._radiation_model.did_device_restart(dt): + logger.info(f"Actor {self.local_actor} interrupted during advance_time.") + self.local_actor.set_was_interrupted() + return max(target_time - self._state.time, 0) + if self.local_actor._radiation_model.did_device_experience_failure(dt): + logger.info(f"Actor {self.local_actor} died during advance_time.") + self.local_actor.set_is_dead() + return max(target_time - self._state.time, 0) + + # charge from current moment to time after timestep + if self.local_actor.has_power_model: + self._local_actor.charge(dt) + + # Update actor temperature + if self.local_actor.has_thermal_model: + self.local_actor._thermal_model.update_temperature( + dt, current_power_consumption_in_W + ) + + # Update state of charge + if self.local_actor.has_power_model: + self.local_actor.discharge(current_power_consumption_in_W, dt) + + # Update user-defined properties in the actor + for property_name in self.local_actor.custom_properties.keys(): + update_function = self.local_actor.get_custom_property_update_function( + property_name + ) + new_value = update_function( + self.local_actor, dt, current_power_consumption_in_W + ) + self.local_actor.set_custom_property(property_name, new_value) + + self._state.time += dt + time_since_constraint_check += dt + self.local_actor.set_time(pk.epoch(self._state.time * pk.SEC2DAY)) + + # Check if we should update the status log + if self._time_since_previous_log > self._cfg.io.logging_interval: + self.log_status() + self._time_since_previous_log = 0 + else: + self._time_since_previous_log += dt + + logger.debug("New time is: " + str(self._state.time) + " s.") + return max(target_time - self._state.time, 0) + finally: + self._is_advancing_time = False def add_known_actor(self, actor: BaseActor): """Adds an actor to the simulation. From cfdb92ba32479d9e7b8fd85ec9efb26e16424aa6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Pablo=20G=C3=B3mez?= Date: Fri, 24 Jul 2026 11:43:29 +0200 Subject: [PATCH 2/2] test: add advance_time guard regression tests; clarify zero-skip comment Covers the two failure modes fixed here: a zero-length interval is a no-op that never engages the guard, and an exception mid-advance_time still releases it so a subsequent call succeeds (previously deadlocked). Also corrects the ActivityProcessor._update comment now that advance_time handles zero intervals itself. --- paseos/activities/activity_processor.py | 5 +-- paseos/tests/advance_time_test.py | 45 +++++++++++++++++++++++++ 2 files changed, 48 insertions(+), 2 deletions(-) create mode 100644 paseos/tests/advance_time_test.py diff --git a/paseos/activities/activity_processor.py b/paseos/activities/activity_processor.py index 2f71385..fbd5359 100644 --- a/paseos/activities/activity_processor.py +++ b/paseos/activities/activity_processor.py @@ -84,8 +84,9 @@ async def _update(self, elapsed_time: float): elapsed_time (float): Elapsed time in seconds. """ assert elapsed_time >= 0, "Elapsed time cannot be negative." - # A zero interval can occur when updates are scheduled back-to-back; skip it - # rather than asserting, which would crash the background processor task. + # A zero interval can occur when updates are scheduled back-to-back. advance_time + # already treats it as a no-op, so return early here to skip the redundant call + # and its per-tick debug logging. if elapsed_time == 0: return logger.debug("Running ActivityProcessor update.") diff --git a/paseos/tests/advance_time_test.py b/paseos/tests/advance_time_test.py new file mode 100644 index 0000000..fe88112 --- /dev/null +++ b/paseos/tests/advance_time_test.py @@ -0,0 +1,45 @@ +"""Regression tests for the advance_time re-entrancy guard. + +These cover the failure modes fixed alongside the uv/Python 3.8 CI migration: +the guard used to be set before argument validation and only cleared on the +normal return, so a zero-length interval or an exception mid-advance_time left +it stuck True and poisoned every later call (deadlocking wait_for_activity). +""" + +import sys + +sys.path.append("../..") + +import pytest +from test_utils import get_default_instance + + +def test_advance_time_zero_interval_is_noop(): + """Advancing by zero returns 0.0 and never engages the guard.""" + sim, _, _ = get_default_instance() + + assert sim.advance_time(0, 0) == 0.0 + assert sim._is_advancing_time is False + + # A normal advancement still works right after a zero-length call. + assert sim.advance_time(10, 0) == 0 + assert sim._is_advancing_time is False + + +def test_advance_time_releases_guard_on_exception(): + """An exception mid-advance_time must still release the guard. + + Previously the guard leaked True and the next call failed the + 'advance_time is already running' assertion, deadlocking the simulation. + """ + sim, _, _ = get_default_instance() + + # A constraint function returning None raises inside advance_time (after the + # guard is set), which must be cleaned up by the finally block. + with pytest.raises(AssertionError): + sim.advance_time(10, 0, constraint_function=lambda: None) + assert sim._is_advancing_time is False + + # The guard was not left poisoned, so a subsequent call still succeeds. + assert sim.advance_time(10, 0) == 0 + assert sim._is_advancing_time is False