From 24716a2f94ee5ad729c2f2dd5e4f9f6c7f4ea72f Mon Sep 17 00:00:00 2001 From: Quanzheng Long Date: Thu, 7 May 2026 09:50:58 -0700 Subject: [PATCH] test(langgraph): de-flake heartbeat progress test MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit `_TimedAttemptScope.__init__` sets `_last_progress = time.monotonic()`, but the watchdog doesn't actually start polling until after `wrap_config` and task scheduling. Under heavy CI load that gap can grow large enough to consume the entire idle window before the task body's first await runs — the watchdog then fires immediately with `elapsed: 0.000s`, since elapsed is measured from the post-scheduling `start` rather than from scope init. Two test-side defenses (no production change): - Bump idle_timeout from 0.2s to 1.0s so scheduling slack stays well within it. - Call `runtime.heartbeat()` at task-body entry before the first sleep, which resets `_last_progress` to "now" the moment the task actually starts. Confirmed stable: 10/10 local repeated runs pass. Co-authored-by: Cursor --- libs/langgraph/tests/test_retry.py | 21 +++++++++++++++++---- 1 file changed, 17 insertions(+), 4 deletions(-) diff --git a/libs/langgraph/tests/test_retry.py b/libs/langgraph/tests/test_retry.py index 8ee515e8e..f5d4d74e0 100644 --- a/libs/langgraph/tests/test_retry.py +++ b/libs/langgraph/tests/test_retry.py @@ -1674,15 +1674,28 @@ async def test_arun_with_retry_timeout_observer_tracks_attempts(): async def test_arun_with_retry_timeout_observer_emits_progress_on_heartbeat(): events: list = [] + # `_TimedAttemptScope.__init__` sets `_last_progress` to `time.monotonic()`, + # but the watchdog itself doesn't start running until after `wrap_config` + # and task scheduling — under CI load that gap can be large enough to eat + # the entire idle window before the task body's first await even runs. We + # defend against that by: + # 1. Using a generous idle_timeout so scheduling slack stays well within it. + # 2. Calling `runtime.heartbeat()` BEFORE the first sleep, which resets + # `_last_progress` to "now" the moment the task body actually starts. + idle_timeout_s = 1.0 + class HeartbeatProc: async def ainvoke(self, input, config): runtime = config[CONF][CONFIG_KEY_RUNTIME] + runtime.heartbeat() # reset the idle clock at task-body entry for _ in range(8): await asyncio.sleep(0.05) runtime.heartbeat() return "ok" - task = _make_task(HeartbeatProc(), timeout=_idle_timeout(0.2), name="heartbeat") + task = _make_task( + HeartbeatProc(), timeout=_idle_timeout(idle_timeout_s), name="heartbeat" + ) task.config[CONF][CONFIG_KEY_TIMED_ATTEMPT_OBSERVER] = events.append assert await arun_with_retry(task, retry_policy=None) == "ok" @@ -1691,13 +1704,13 @@ async def test_arun_with_retry_timeout_observer_emits_progress_on_heartbeat(): assert by_event[-1] == "finish" progress = [ev for ev in events if ev.event == "progress"] assert progress, "expected at least one progress event from heartbeat" - # Rate limit is `idle_timeout / 4` = 0.05s; with 8 heartbeats spaced ~0.05s - # we should see at most ~one progress event per heartbeat (well below 8). + # Rate limit is `idle_timeout / 4` = 0.25s; with the task running for + # ~400ms we expect 1–2 progress events (well below the 9 heartbeats). assert len(progress) <= len(by_event) for ev in progress: assert ev.context.task_name == "heartbeat" assert ev.context.attempt == 1 - assert ev.context.idle_timeout_secs == 0.2 + assert ev.context.idle_timeout_secs == idle_timeout_s assert isinstance(ev.progress_at, datetime)