taskdump: `trace_leaf` returning `Pending` without a wake (#8043) permanently strands `FuturesUnordered` children polled under `trace_with`
Version
tokio 1.53.1 (introduced in 1.53.0 by #8043). Not reproducible on 1.52.3.
Platform
Linux 6.12 aarch64. Needs the taskdump feature and --cfg tokio_unstable.
Description
Since #8043, trace_leaf() returns Poll::Pending without waking anything when it runs inside trace_with / Trace::capture. The updated docs say the caller should re-schedule the task, e.g. cx.waker().wake_by_ref(). That is enough for a leaf directly under the task, but it does not reach a future that is being driven through a sub-executor such as FuturesUnordered (or join_all, select_all, a hand-written ready-queue, ...).
FuturesUnordered::poll_next clears a child's queued flag before polling it and only re-polls the child when the child's own waker fires. If the child reaches a tokio leaf inside trace_with, the leaf returns Pending from trace_leaf() before it registers a waiter, so no waker is stored anywhere for that child. Waking the task re-polls the task, poll_next finds an empty ready queue, and the child is never polled again. In 1.52.3 trace_leaf(cx) deferred a wake of cx.waker(), which for a FuturesUnordered child is the per-child waker, so the child was re-queued and the trace re-poll was benign.
It gets worse when a permit is in flight: if the child had just been handed a tokio::sync::Mutex/Semaphore permit (its Acquire node popped and woken by add_permits_locked) and is then polled inside trace_with, Acquire::poll returns at trace_leaf() without consuming the permit. The permit stays assigned to a future that is never polled again and never dropped, so the mutex is locked forever for everyone else.
How we hit it: dial9-tokio-telemetry's task-dump wrapper re-polls a task under trace_with after every Pending poll (the pattern the trace_with docs describe). A production task kept 32 in-progress operations in a FuturesUnordered. A completion from another thread woke one child between the real poll and the re-poll; inside the re-poll that child released a Mutex (permit handed to the next waiter, which was woken) and then hit Semaphore::acquire; both children returned Pending from trace_leaf() and were never polled again; the mutex stayed locked; every other child queued behind it. The process sat like that for hours. I have not checked whether the runtime's own Handle::dump() path has the same exposure when a traced task's FuturesUnordered child happens to be in the ready queue at dump time.
Minimal reproduction (deterministic, no dial9)
Cargo.toml
[package]
name = "trace-leaf-strand"
version = "0.1.0"
edition = "2021"
[dependencies]
tokio = { version = "=1.53.1", features = ["rt", "sync", "taskdump"] }
futures = "0.3".cargo/config.toml
[build]
rustflags = ["--cfg", "tokio_unstable"]src/main.rs
use std::future::Future;
use std::pin::Pin;
use std::sync::atomic::{AtomicBool, AtomicUsize, Ordering};
use std::sync::Arc;
use std::task::{Context, Wake, Waker};
use futures::channel::oneshot;
use futures::stream::{FuturesUnordered, StreamExt};
use futures::FutureExt;
use tokio::sync::{Mutex, Semaphore};
/// Task waker that only counts wakes; we drive the actor by hand.
struct CountingWaker(AtomicUsize);
impl Wake for CountingWaker {
fn wake(self: Arc<Self>) { self.0.fetch_add(1, Ordering::SeqCst); }
fn wake_by_ref(self: &Arc<Self>) { self.0.fetch_add(1, Ordering::SeqCst); }
}
fn main() {
let repoll = !std::env::args().any(|a| a == "--no-repoll");
let rt = tokio::runtime::Builder::new_current_thread().build().unwrap();
let stranded = rt.block_on(scenario(repoll));
std::process::exit(if stranded { 1 } else { 0 });
}
async fn scenario(repoll: bool) -> bool {
let mutex = Arc::new(Mutex::new(()));
let sem = Arc::new(Semaphore::new(4));
let (tx, rx) = oneshot::channel::<()>();
let done_a = Arc::new(AtomicBool::new(false));
let done_b = Arc::new(AtomicBool::new(false));
// A holds the mutex from the start, so poll order does not matter.
let guard = mutex.clone().try_lock_owned().expect("fresh mutex");
let child_a = {
let (sem, done) = (sem.clone(), done_a.clone());
async move {
rx.await.expect("completion arrives"); // non-tokio leaf (custom completion future)
drop(guard); // mutex permit handed to B, B woken
let _permit = sem.acquire().await.unwrap(); // tokio leaf -> trace_leaf() inside trace_with
done.store(true, Ordering::SeqCst);
}
};
let child_b = {
let (mutex, done) = (mutex.clone(), done_b.clone());
async move {
let _g = mutex.lock().await; // tokio leaf; waiter registered in the real poll
done.store(true, Ordering::SeqCst);
}
};
let actor = async move {
let mut set = FuturesUnordered::new();
set.push(child_a.boxed());
set.push(child_b.boxed());
while set.next().await.is_some() {}
};
let mut actor: Pin<Box<dyn Future<Output = ()>>> = Box::pin(actor);
let wakes = Arc::new(CountingWaker(AtomicUsize::new(0)));
let waker = Waker::from(wakes.clone());
let mut cx = Context::from_waker(&waker);
// 1. real poll
assert!(actor.as_mut().poll(&mut cx).is_pending());
println!("1. real poll: Pending (A holds mutex, parked on completion; B parked on mutex)");
// 2. completion from another thread, landing before the re-poll
std::thread::spawn(move || tx.send(()).unwrap()).join().unwrap();
println!("2. completion delivered from another thread; task wakes so far = {}",
wakes.0.load(Ordering::SeqCst));
// 3. task-dump style capture re-poll
if repoll {
let mut leaves = 0;
let r = tokio::runtime::dump::trace_with(|| actor.as_mut().poll(&mut cx), |_meta| leaves += 1);
println!("3. re-poll under trace_with: {:?}, tokio leaves hit = {leaves}", r.map(|_| ()));
} else {
println!("3. (re-poll skipped: --no-repoll)");
}
// 4. keep polling the way the runtime would on any later wake, yielding so that any
// deferred wakers (tokio <= 1.52 trace_leaf) get a chance to fire.
for i in 0..50 {
if actor.as_mut().poll(&mut cx).is_ready() {
println!("4. actor completed after {} extra poll(s): done_a={} done_b={}", i + 1,
done_a.load(Ordering::SeqCst), done_b.load(Ordering::SeqCst));
return false;
}
tokio::task::yield_now().await;
}
println!("4. STRANDED after 50 polls: done_a={} done_b={} mutex_locked={} sem_permits={} task_wakes={}",
done_a.load(Ordering::SeqCst), done_b.load(Ordering::SeqCst),
mutex.try_lock().is_err(), sem.available_permits(), wakes.0.load(Ordering::SeqCst));
true
}Sequence: (1) real poll: A locks and parks on the oneshot, B registers as a mutex waiter. (2) Another thread fires the oneshot; A's per-child waker fires and A is queued in the set. (3) Re-poll under trace_with: A resolves, drops the guard (permit handed to B, B woken and queued), then reaches Semaphore::acquire → trace_leaf() → Pending, no waiter registered. B is polled next, resumes inside Acquire::poll → trace_leaf() → Pending, still holding the assigned permit. (4) Every later poll finds an empty ready queue.
Actual (tokio 1.53.1, cargo run --release)
1. real poll: Pending (A holds mutex, parked on completion; B parked on mutex)
2. completion delivered from another thread; task wakes so far = 2
3. re-poll under trace_with: Pending, tokio leaves hit = 2
4. STRANDED after 50 polls: done_a=false done_b=false mutex_locked=true sem_permits=4 task_wakes=4Exit code 1. mutex_locked=true is the permit stranded inside B's never-again-polled Acquire.
Expected
Same binary with --no-repoll (no trace_with):
4. actor completed after 1 extra poll(s): done_a=true done_b=trueSame code with tokio = "=1.52.3", re-poll included:
3. re-poll under trace_with: Pending, tokio leaves hit = 2
4. actor completed after 2 extra poll(s): done_a=true done_b=trueSuggested fix
Either restore a deferred wake of cx.waker() in trace_leaf (as 1.52 did) so a traced leaf still honours the Future contract from the perspective of whatever is polling it, or make trace_with / Trace::capture document that polling a future containing a sub-executor inside them can permanently strand its children, and that cx.waker().wake_by_ref() on the task does not fix that. The #8043 motivation (a wrapper that captures on every poll loops forever) could perhaps be addressed by deferring the wake only when cx.waker() is not the task's own waker, or by giving trace_with an option.
Source: tokio-rs/tokio