From 82d7ee500df1408740f2e87eeaa515555ba46a95 Mon Sep 17 00:00:00 2001 From: Mickael Farina Date: Mon, 13 Jul 2026 15:05:50 +0200 Subject: [PATCH] test(ask_user): de-flake two CI-timing failures (unblocks dependabot #237) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit PR #237 (a harmless ruff version bump) went red on CI/smoke with two failures that have nothing to do with ruff — both pass in isolation and are pre-existing timing flakes: * test_deadline_timeout: `assert len(timeouts) == 1` saw 2. ask() is synchronous and finalizes exactly one timeout per call, so the extra event came from a background-threaded ask() in a NEIGHBOURING test finalizing late into this test's audit log (_log_event reads the log path live at write-time). Now scoped: count only emit/timeout events whose extra.pending_question_id is THIS test's qid. * test_round_trip: "notification not written". ask() writes the pending record and the notification as two separate writes; the test polled for the record then asserted on the notification, which can lag under load. Now polls for the notification too. Both are test-only changes; runtime code untouched. Verified: the two tests pass 10/10 under repeated runs; full suite 2497 passed. Co-Authored-By: Claude Fable 5 --- tests/test_ask_user.py | 22 ++++++++++++++++++---- 1 file changed, 18 insertions(+), 4 deletions(-) diff --git a/tests/test_ask_user.py b/tests/test_ask_user.py index e913b17..a07e7e8 100644 --- a/tests/test_ask_user.py +++ b/tests/test_ask_user.py @@ -97,7 +97,13 @@ def caller(): time.sleep(0.05) assert qid is not None, "ask() never wrote a pending record" - # Verify notifications.json has a type="question" entry. + # Verify notifications.json has a type="question" entry. ask() writes the + # pending record and the notification as two separate writes, so under load + # the notification can lag the record we polled for above — poll for it too + # rather than assume it landed simultaneously (CI flake, 2026-07). + _nd = time.monotonic() + 2.0 + while time.monotonic() < _nd and not notif_path.exists(): + time.sleep(0.05) assert notif_path.exists(), "notification not written" notifs = json.loads(notif_path.read_text()) assert any(n.get("type") == "question" and n.get("pending_question_id") == qid @@ -173,10 +179,18 @@ def test_deadline_timeout_returns_sentinel(temp_audit_log, temp_askuser_paths): # Should be roughly 2s (polling loop checks every 1s); allow up to 4s. assert 1.5 <= elapsed <= 4.5, f"deadline elapsed={elapsed:.2f}s" - # Audit: emit + timeout. + # Audit: emit + timeout. Scope to THIS question's id: a background-threaded + # ask() in a neighbouring test can finalize a late timeout into this test's + # audit log (the log path is read live at write-time), so a global count is + # flaky under CI load. Count only events for our own qid. + my_qid = json.loads(pq_path.read_text())["pending_questions"][0]["id"] + + def _for_me(events): + return [e for e in events if e.get("extra", {}).get("pending_question_id") == my_qid] + recs = _records(temp_audit_log) - emits = _events_of(recs, codec_ask_user.ASKUSER_EVENT_EMIT) - timeouts = _events_of(recs, codec_ask_user.ASKUSER_EVENT_TIMEOUT) + emits = _for_me(_events_of(recs, codec_ask_user.ASKUSER_EVENT_EMIT)) + timeouts = _for_me(_events_of(recs, codec_ask_user.ASKUSER_EVENT_TIMEOUT)) assert len(emits) == 1 assert len(timeouts) == 1 assert timeouts[0]["extra"]["reason"] == "deadline"