diff --git a/features/memory_service_clock_wait.feature b/features/memory_service_clock_wait.feature new file mode 100644 index 000000000..a3af193f1 --- /dev/null +++ b/features/memory_service_clock_wait.feature @@ -0,0 +1,25 @@ +Feature: Memory service clock-advance guard determinism + As a CleverAgents developer + I want the _wait_for_clock_advance() helper to behave deterministically + So that entity-tracking tests never produce spurious timestamp failures on fast CI runners + + # This feature verifies the monotonic busy-wait helper introduced in + # features/steps/memory_service_coverage_steps.py to replace the four + # bare time.sleep(0.01) guards that caused intermittent timestamp failures + # on heavily-loaded CI runners (issue #9963). + # + # The helper spins on the monotonic clock until the UTC clock has advanced + # past the supplied `before` timestamp, raising AssertionError if the + # deadline is exceeded. + + @mock_only + Scenario: Clock-advance guard raises AssertionError when deadline is exceeded + Given a zero-second clock-advance deadline + When I invoke the clock-advance guard with a future timestamp + Then an AssertionError should be raised mentioning the deadline + + @mock_only + Scenario: Clock-advance guard returns successfully once the clock advances + Given the UTC clock will advance on the next check + When I invoke the clock-advance guard with the current timestamp + Then the guard should return without raising diff --git a/features/steps/memory_service_clock_wait_steps.py b/features/steps/memory_service_clock_wait_steps.py new file mode 100644 index 000000000..9ca1cd0e2 --- /dev/null +++ b/features/steps/memory_service_clock_wait_steps.py @@ -0,0 +1,77 @@ +"""Step definitions for memory_service_clock_wait.feature. + +Verifies the _wait_for_clock_advance() helper introduced in +memory_service_coverage_steps.py raises AssertionError when the deadline +is exceeded, and returns normally once the clock actually advances. +""" + +from __future__ import annotations + +from datetime import UTC, datetime, timedelta +from typing import Any + +from behave import given, then, when + +from features.steps.memory_service_coverage_steps import _wait_for_clock_advance + + +@given("a zero-second clock-advance deadline") +def step_zero_second_deadline(context: Any) -> None: + """Store a zero-second deadline for use in subsequent steps.""" + context.clock_advance_deadline = 0.0 + + +@when("I invoke the clock-advance guard with a future timestamp") +def step_invoke_guard_with_future_timestamp(context: Any) -> None: + """Call _wait_for_clock_advance with a timestamp far in the future. + + Because the deadline is 0 seconds, the guard should immediately raise + AssertionError — the clock cannot advance past a future timestamp + before the deadline expires. + """ + # Use a timestamp one hour in the future so the guard can never succeed. + future = datetime.now(UTC) + timedelta(hours=1) + context.clock_advance_error = None + try: + _wait_for_clock_advance(future, deadline_secs=context.clock_advance_deadline) + except AssertionError as exc: + context.clock_advance_error = exc + + +@then("an AssertionError should be raised mentioning the deadline") +def step_assert_error_raised(context: Any) -> None: + """Verify the guard raised AssertionError with the expected message.""" + assert context.clock_advance_error is not None, ( + "_wait_for_clock_advance() should have raised AssertionError but did not" + ) + assert "Clock did not advance" in str(context.clock_advance_error), ( + f"AssertionError message missing expected text: {context.clock_advance_error}" + ) + + +@given("the UTC clock will advance on the next check") +def step_clock_will_advance(context: Any) -> None: + """Capture the current UTC timestamp; the clock will advance naturally.""" + context.before_timestamp = datetime.now(UTC) + + +@when("I invoke the clock-advance guard with the current timestamp") +def step_invoke_guard_current_timestamp(context: Any) -> None: + """Call _wait_for_clock_advance with the captured timestamp. + + The guard should return normally once the UTC clock advances past + context.before_timestamp, which will happen within milliseconds. + """ + context.clock_advance_error = None + try: + _wait_for_clock_advance(context.before_timestamp, deadline_secs=2.0) + except AssertionError as exc: + context.clock_advance_error = exc + + +@then("the guard should return without raising") +def step_guard_returns_normally(context: Any) -> None: + """Verify the guard returned without raising an error.""" + assert context.clock_advance_error is None, ( + f"_wait_for_clock_advance() raised unexpectedly: {context.clock_advance_error}" + ) diff --git a/features/steps/memory_service_coverage_steps.py b/features/steps/memory_service_coverage_steps.py index 5e8143aff..9a190068d 100644 --- a/features/steps/memory_service_coverage_steps.py +++ b/features/steps/memory_service_coverage_steps.py @@ -6,7 +6,7 @@ import asyncio import shutil import tempfile import time -from datetime import UTC +from datetime import UTC, datetime from pathlib import Path from typing import Any from unittest.mock import patch @@ -24,6 +24,22 @@ from cleveragents.application.services.memory_service import ( ) +def _wait_for_clock_advance(before: datetime, deadline_secs: float = 2.0) -> None: + """Spin until the UTC clock advances past *before*, bounded by deadline. + + Uses the monotonic clock for the deadline check so the guard itself is + immune to wall-clock adjustments. Raises ``AssertionError`` if the UTC + clock has not advanced within ``deadline_secs`` seconds. + """ + deadline = time.monotonic() + deadline_secs + while datetime.now(UTC) <= before: + if time.monotonic() > deadline: + raise AssertionError( + f"Clock did not advance past {before} within {deadline_secs}s" + ) + time.sleep(0.001) + + @given("a conversation adapter configured to return text values") def step_adapter_returning_text(context: Any) -> None: """Create an adapter that returns buffer strings.""" @@ -437,7 +453,7 @@ def step_have_tracked_file_entity(context: Any, name: str) -> None: @when("I track the same entity again") def step_track_same_entity(context: Any) -> None: """Track the same entity again to update it.""" - time.sleep(0.01) # Small delay to ensure time difference + _wait_for_clock_advance(datetime.now(UTC)) context.tracked_entity = context.memory_service.track_entity( context.tracked_entity.name, context.tracked_entity.entity_type ) @@ -504,11 +520,11 @@ def step_memory_service_entities_over_time(context: Any) -> None: """Track entities at different times.""" context.memory_service = MemoryService(session_id="time-entity-session") - # Track entities with small delays to ensure different timestamps + # Track entities with clock-advance guards to ensure different timestamps context.memory_service.track_entity("oldest", EntityType.PROJECT) - time.sleep(0.01) + _wait_for_clock_advance(datetime.now(UTC)) context.memory_service.track_entity("middle", EntityType.PLAN) - time.sleep(0.01) + _wait_for_clock_advance(datetime.now(UTC)) context.memory_service.track_entity("newest", EntityType.FILE) @@ -763,7 +779,7 @@ def step_track_project_with_initial_metadata(context: Any, name: str) -> None: @when("I track the same project entity again with additional metadata") def step_track_same_entity_with_additional_metadata(context: Any) -> None: """Track the same entity with additional metadata to trigger update.""" - time.sleep(0.01) # Small delay to ensure time difference + _wait_for_clock_advance(datetime.now(UTC)) additional_metadata = {"status": "active", "priority": "high"} context.tracked_entity = context.memory_service.track_entity( context.entity_name, EntityType.PROJECT, additional_metadata