with tokio::spawn, tokio::time::timeout does not time out promptly?

[jorendorff]

This test fails for me. (Playground link)

It's meant to simulate a case where a task is a bit greedy with the CPU, but it calls yield_now once every 1msec, which ought to be good enough, right? It seems like tokio ought to stay responsive. However, the test calls yield_now 61 times before the timeout actually occurs, even though the timeout elapses after about 3.

I've noticed this only happens with tokio::spawn. The number 61 is robust; changing BUSY or TIMEOUT a bit doesn't perturb it.

How should I understand this behavior? Is there anything I can do to make my task time out more promptly?

#[cfg(test)]
mod tests {
    use std::sync::atomic::{AtomicUsize, Ordering};
    use std::sync::Arc;
    use std::time::Duration;

    const BUSY: Duration = Duration::from_millis(1);
    const TIMEOUT: Duration = Duration::from_millis(3);

    async fn busy_task(counter: Arc<AtomicUsize>) {
        for _i in 0..1000_usize {
            std::thread::sleep(BUSY); // simulate hogging the CPU, but only for a moment
            tokio::task::yield_now().await; // should time out
            counter.fetch_add(1, Ordering::SeqCst);
        }
    }

    #[tokio::test]
    async fn test_slow_timeout_with_spawn() {
        let counter = Arc::new(AtomicUsize::new(0));
        let result = tokio::spawn(tokio::time::timeout(TIMEOUT, busy_task(counter.clone())))
            .await
            .expect("task panicked");

        if result.is_ok() {
            panic!("should have timed out");
        }
        let nloops = counter.load(Ordering::SeqCst);
        assert!(nloops < 10, "expected <10 iterations before timeout, got {}", nloops);
    }
}

[Darksonn]

This is due to the following:

tokio/tokio/src/runtime/basic_scheduler.rs

Line 113 in d101fea

const MAX_TASKS_PER_TICK: usize = 61;

The basic runtime will poll up to 61 futures before it checks the timer or IO drivers.

It's meant to simulate a case where a task is a bit greedy with the CPU, but it calls yield_now once every 1msec, which ought to be good enough, right?

Well, it's one to two orders of magnitude more than what I suggest using in my blog post on blocking.

[jorendorff]

Thanks so much for this response. It's everything I needed in two sentences.

I had grepped the tokio codebase for 64, but not for 61. :)