Skip to content

Commit 5b832fc

Browse files
intendednullclaude
andauthored
test(actor): deflake debounce/derived/liveness timing tests (#665)
Replace fixed-sleep-then-assert with condition-based waiting (wait_for helper) in debounce.rs, derived.rs, and lib.rs. No production code changed — all fixes are test-only. Root cause per test: debounce_single_message / debounce_separate_bursts Test race: fixed sleeps (100ms / 80ms) smaller than the timer + actor message-delivery chain under parallel suite load. Fixed by polling count.load() with a 2000ms timeout instead of sleeping. debounce_rapid_messages / throttle_* tests Same class of race on the positive "eventually happens" assertions. Hardened proactively. throttle_rate_limited's "still throttled" assertion keeps a short fixed sleep (20ms << 100ms cooldown) with a comment explaining why it is a genuine timing invariant. debounce_timer_reset The intermediate assert_eq!(count, 0) at 30ms is a real timing invariant (timer must not have fired) — kept as-is with an explanatory comment. The final assert_eq!(count, 1) replaced with wait_for. derived_caches_unchanged Test race: DerivedActor::started() spawns a task to compute the initial UpdateCache. If the test's Subscribe(counter) message is processed by DerivedActor *before* that warm-up UpdateCache arrives, the actor's cache is still None when UpdateCache(2) arrives later — triggering a dirty→idle→Notify cycle that increments count to 1 (expected 0). Fixed by polling two consecutive d.get().await calls until they return Arc::ptr_eq (both served from self.cached, not fresh computes). Once ptr_eq holds, self.cached is definitely Some(2), so any subsequent UpdateCache(2) — including any late warm-up — deduplicates to no-op. The counter is then subscribed and Set(4) tested. derived_notifies_on_value_change Removed redundant 50ms warm-up sleep; uses wait_for for the positive "subscriber notified" assertion (count >= 1) instead. ask_dead_actor_returns_closed / send_dead_actor_returns_send_error / recipient_dead_actor / system_shutdown_terminates_ctx_spawned_child Test race: system.shutdown().await returns when done_rx fires (at end of run_mailbox), but the tokio task hasn't yet dropped the Receiver<T>, so tx.is_closed() (== is_alive()) can still return false for a brief window. Fixed by polling !addr.is_alive() with 1ms retries (max 200ms) before asserting channel-closed semantics. Verification: - Each of the 3 originally-reported flaky tests: 30/30 green in isolation - cargo test -p willow-actor --lib: 5/5 consecutive runs, 94/94 tests each - just check: zero warnings, all tests green Co-authored-by: Claude Opus 4.8 (1M context) <noreply@anthropic.com>
1 parent 94aa11a commit 5b832fc

3 files changed

Lines changed: 276 additions & 33 deletions

File tree

crates/actor/src/debounce.rs

Lines changed: 132 additions & 15 deletions
Original file line numberDiff line numberDiff line change
@@ -159,6 +159,25 @@ mod tests {
159159
use std::sync::atomic::{AtomicU32, Ordering};
160160
use std::sync::Arc;
161161

162+
// Poll `condition` every 10 ms until it returns true or `timeout_ms`
163+
// elapses. Panics with `msg` on timeout.
164+
//
165+
// Use this for POSITIVE "X eventually happens" assertions in tests that
166+
// depend on async delivery — actor timers and message routing can be
167+
// slower than the test's wall clock under parallel suite load.
168+
async fn wait_for(condition: impl Fn() -> bool, timeout_ms: u64, msg: &str) {
169+
let deadline = std::time::Instant::now() + std::time::Duration::from_millis(timeout_ms);
170+
loop {
171+
if condition() {
172+
return;
173+
}
174+
if std::time::Instant::now() >= deadline {
175+
panic!("wait_for timeout after {timeout_ms}ms: {msg}");
176+
}
177+
runtime::sleep(std::time::Duration::from_millis(10)).await;
178+
}
179+
}
180+
162181
#[derive(Clone)]
163182
struct Ping(u32);
164183
impl Message for Ping {
@@ -207,7 +226,15 @@ mod tests {
207226
let debounce = system.spawn(Debounce::new(collector.into(), Duration::from_millis(50)));
208227

209228
debounce.do_send(Enqueue(Ping(1))).unwrap();
210-
runtime::sleep(Duration::from_millis(100)).await;
229+
230+
// Wait for the debounce flush to arrive — actor timer + message
231+
// delivery can be slower than fixed sleeps under parallel suite load.
232+
wait_for(
233+
|| count.load(Ordering::SeqCst) >= 1,
234+
2000,
235+
"debounce should have forwarded exactly one message",
236+
)
237+
.await;
211238

212239
assert_eq!(count.load(Ordering::SeqCst), 1);
213240
assert_eq!(*last.lock().unwrap(), Some(1));
@@ -223,7 +250,14 @@ mod tests {
223250
for i in 0..5 {
224251
debounce.do_send(Enqueue(Ping(i))).unwrap();
225252
}
226-
runtime::sleep(Duration::from_millis(150)).await;
253+
254+
// Wait for the single coalesced flush to arrive.
255+
wait_for(
256+
|| count.load(Ordering::SeqCst) >= 1,
257+
2000,
258+
"debounce should have forwarded exactly one coalesced message",
259+
)
260+
.await;
227261

228262
assert_eq!(count.load(Ordering::SeqCst), 1);
229263
assert_eq!(*last.lock().unwrap(), Some(4));
@@ -237,11 +271,27 @@ mod tests {
237271
let debounce = system.spawn(Debounce::new(collector.into(), Duration::from_millis(60)));
238272

239273
debounce.do_send(Enqueue(Ping(1))).unwrap();
274+
// Sleep for half the debounce window, then reset the timer with Ping(2).
240275
runtime::sleep(Duration::from_millis(30)).await;
241276
debounce.do_send(Enqueue(Ping(2))).unwrap();
242277
runtime::sleep(Duration::from_millis(30)).await;
243-
assert_eq!(count.load(Ordering::SeqCst), 0);
244-
runtime::sleep(Duration::from_millis(50)).await;
278+
// Debounce window restarted from Ping(2); 30ms << 60ms — must not fire.
279+
// This is an intentional timing invariant: fixed sleep is correct here
280+
// because we're asserting a "not yet" condition within a known timed window.
281+
assert_eq!(
282+
count.load(Ordering::SeqCst),
283+
0,
284+
"timer should not have fired yet"
285+
);
286+
287+
// Wait for the eventual flush via condition-based polling.
288+
wait_for(
289+
|| count.load(Ordering::SeqCst) >= 1,
290+
2000,
291+
"debounce should have forwarded Ping(2) after quiet period",
292+
)
293+
.await;
294+
245295
assert_eq!(count.load(Ordering::SeqCst), 1);
246296
assert_eq!(*last.lock().unwrap(), Some(2));
247297
system.shutdown().await;
@@ -253,13 +303,26 @@ mod tests {
253303
let (collector, count, _) = setup_collector(&system);
254304
let debounce = system.spawn(Debounce::new(collector.into(), Duration::from_millis(30)));
255305

306+
// First burst — wait for it to flush before sending the second burst,
307+
// so the two bursts are truly separate and each yields exactly one flush.
256308
debounce.do_send(Enqueue(Ping(1))).unwrap();
257309
debounce.do_send(Enqueue(Ping(2))).unwrap();
258-
runtime::sleep(Duration::from_millis(80)).await;
259-
310+
wait_for(
311+
|| count.load(Ordering::SeqCst) >= 1,
312+
2000,
313+
"first burst should have flushed",
314+
)
315+
.await;
316+
317+
// Second burst — wait for its flush too.
260318
debounce.do_send(Enqueue(Ping(3))).unwrap();
261319
debounce.do_send(Enqueue(Ping(4))).unwrap();
262-
runtime::sleep(Duration::from_millis(80)).await;
320+
wait_for(
321+
|| count.load(Ordering::SeqCst) >= 2,
322+
2000,
323+
"second burst should have flushed",
324+
)
325+
.await;
263326

264327
assert_eq!(count.load(Ordering::SeqCst), 2);
265328
system.shutdown().await;
@@ -272,7 +335,15 @@ mod tests {
272335
let throttle = system.spawn(Throttle::new(collector.into(), Duration::from_millis(100)));
273336

274337
throttle.do_send(Enqueue(Ping(1))).unwrap();
275-
runtime::sleep(Duration::from_millis(20)).await;
338+
339+
// Throttle forwards the first message immediately (before any cooldown
340+
// fires). Wait for it to arrive rather than guessing a fixed sleep.
341+
wait_for(
342+
|| count.load(Ordering::SeqCst) >= 1,
343+
2000,
344+
"throttle should forward the first message immediately",
345+
)
346+
.await;
276347

277348
assert_eq!(count.load(Ordering::SeqCst), 1);
278349
assert_eq!(*last.lock().unwrap(), Some(1));
@@ -286,12 +357,29 @@ mod tests {
286357
let throttle = system.spawn(Throttle::new(collector.into(), Duration::from_millis(100)));
287358

288359
throttle.do_send(Enqueue(Ping(1))).unwrap();
289-
runtime::sleep(Duration::from_millis(10)).await;
360+
// First message is forwarded immediately. Wait for it so the cooldown
361+
// window is known to have started before we queue more messages.
362+
wait_for(
363+
|| count.load(Ordering::SeqCst) >= 1,
364+
2000,
365+
"throttle should forward first message",
366+
)
367+
.await;
368+
290369
throttle.do_send(Enqueue(Ping(2))).unwrap();
291370
throttle.do_send(Enqueue(Ping(3))).unwrap();
292-
runtime::sleep(Duration::from_millis(20)).await;
293371

294-
assert_eq!(count.load(Ordering::SeqCst), 1);
372+
// Cooldown is 100ms. Sleep for 20ms — well inside the cooldown window —
373+
// and assert count is still 1. This is an intentional timing invariant:
374+
// the cooldown MUST suppress extra messages during this window. A fixed
375+
// sleep is correct here because we're asserting a "not yet" condition
376+
// within a known timed window (20ms << 100ms cooldown).
377+
runtime::sleep(Duration::from_millis(20)).await;
378+
assert_eq!(
379+
count.load(Ordering::SeqCst),
380+
1,
381+
"throttle should suppress messages during cooldown"
382+
);
295383
system.shutdown().await;
296384
}
297385

@@ -302,9 +390,24 @@ mod tests {
302390
let throttle = system.spawn(Throttle::new(collector.into(), Duration::from_millis(50)));
303391

304392
throttle.do_send(Enqueue(Ping(1))).unwrap();
305-
runtime::sleep(Duration::from_millis(10)).await;
393+
// Wait for first forward so we know the cooldown has started before
394+
// queuing Ping(2).
395+
wait_for(
396+
|| count.load(Ordering::SeqCst) >= 1,
397+
2000,
398+
"throttle should forward first message",
399+
)
400+
.await;
401+
306402
throttle.do_send(Enqueue(Ping(2))).unwrap();
307-
runtime::sleep(Duration::from_millis(100)).await;
403+
404+
// After cooldown expires, pending Ping(2) should be forwarded.
405+
wait_for(
406+
|| count.load(Ordering::SeqCst) >= 2,
407+
2000,
408+
"throttle should forward pending message after cooldown",
409+
)
410+
.await;
308411

309412
assert_eq!(count.load(Ordering::SeqCst), 2);
310413
assert_eq!(*last.lock().unwrap(), Some(2));
@@ -318,10 +421,24 @@ mod tests {
318421
let throttle = system.spawn(Throttle::new(collector.into(), Duration::from_millis(50)));
319422

320423
throttle.do_send(Enqueue(Ping(1))).unwrap();
321-
runtime::sleep(Duration::from_millis(10)).await;
424+
// Wait for first forward so cooldown is active before queuing.
425+
wait_for(
426+
|| count.load(Ordering::SeqCst) >= 1,
427+
2000,
428+
"throttle should forward first message",
429+
)
430+
.await;
431+
322432
throttle.do_send(Enqueue(Ping(2))).unwrap();
323433
throttle.do_send(Enqueue(Ping(3))).unwrap();
324-
runtime::sleep(Duration::from_millis(100)).await;
434+
435+
// After cooldown, only the last pending (Ping(3)) should be forwarded.
436+
wait_for(
437+
|| count.load(Ordering::SeqCst) >= 2,
438+
2000,
439+
"throttle should forward only latest pending message after cooldown",
440+
)
441+
.await;
325442

326443
assert_eq!(count.load(Ordering::SeqCst), 2);
327444
assert_eq!(*last.lock().unwrap(), Some(3));

0 commit comments

Comments
 (0)