Skip to content

tokio::time::sleep (and any timed futex/poll wait) only completes when unrelated I/O arrives #2639

Description

@max-lt

Environment: hermit 0.13.2 / kernel f510614, Rust 1.97.1 with
rust-std-hermit, QEMU 11 TCG on macOS (-cpu qemu64,apic,fsgsbase,fxsr, rdrand,rdtscp,xsave,xsaveopt, no TSC-deadline), virtio-net enabled.

Symptom

On a current_thread tokio runtime, tokio::time::sleep(200ms) never
completes while the runtime is parked; it is released only when a request
happens to arrive on a registered socket. The same holds for the primitives
underneath, with nothing of tokio involved:

sys_futex_wait(relative 200ms)  -> returns only when something else wakes the core
sys_poll(nfds = 0, timeout 200ms) -> same

A std::thread::sleep in another thread does fire on time, and its wakeup
releases the stuck waiters -- which is what made the bug look intermittent.

Root cause 1: block_on passes a wall-clock deadline as a relative timeout

executor/mod.rs, both task_notify.wait(wakeup_time) sites:

let wakeup_time =
    timeout.map(|duration| start + u64::try_from(duration.as_micros()).unwrap());
task_notify.wait(wakeup_time);

start comes from systemtime::now_micros(), which is
BOOT_TIME + get_timer_ticks() -- wall-clock microseconds (~1.8e15 in 2026).
But TaskNotify::wait passes the value to
futex_wait_and_set(.., Flags::RELATIVE, ..), which treats it as a
relative timeout: get_timer_ticks() + t. The effective timeout is ~56
years. Fix: pass the remaining relative time
(duration.as_micros().saturating_sub(now - start)).

Root cause 2: BlockedTaskQueue::add arms the one-shot with the wrong deadline

With cause 1 fixed, the wait arms correctly and is then clobbered. Timeline
from an instrumented __set_oneshot_timer (one task waiting 200ms, another
thread then sleeping 5s):

[0.1755] arm oneshot: wt=200000   ticks=24457    init=3057125     <- correct
[0.1770] arm oneshot: wt=5176886  ticks=4999846  init=624980750   <- 5s sleep OVERWRITES it
[5.1786] timer irq fired                                           <- 200ms waiter released at 5s

scheduler/task/mod.rs, BlockedTaskQueue::add: the set_oneshot_timer
closure always arms the added task's wakeup_time, even when the task is
inserted behind earlier deadlines. The APIC has a single counter, so a task
blocking with a later deadline pushes every earlier wakeup out to its own.
The network timer path amplifies it: an idle interface asks for a wakeup
half a DHCP lease away (12h here), repeatedly re-armed over anything sooner.
Fix: arm min(front-of-sorted-list, network_wakeup_time).

After both fixes

futex_wait(200ms rel)        -> 200.9ms
poll(nfds=0, 200ms)          -> 210.1ms
poll(eventfd, 200ms)         -> 205.5ms
tokio sleep, bare runtime    -> 207.2ms
tokio sleep, with listener   -> 234.3ms
axum graceful shutdown via tokio::time::sleep -> works

Reproduction: https://github.com/max-lt/hermit-timer-repro -- a standalone
crate with no tokio involved. Stock kernel output:

REPRO: futex_wait(abs 200ms) -> rc=-110 after 5.008289s   <- released by the watchdog, not the timer
REPRO: HANG - a 200ms wait did not finish within 5s       <- poll never returns

I can send PRs for both fixes; the patch in the repro repo is validated against f510614.

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions