`tokio::time::sleep` (and any timed futex/poll wait) only completes when unrelated I/O arrives
- Dominant language
- Rust
- Stars
- 1.5k
- Forks
- 132
- Avg merge
- 1d 14h
- Merged PRs (30d)
- 39
Description
**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:
```rust
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`.
Contributor guide
No contributing guide indexed for this repository
Assessment
This issue has not been assessed yet.