Skip to content

Capture blocked-task backtraces lazily instead of on every block - #352

Open
sarsko wants to merge 1 commit into
mainfrom
lazy-deadlock-backtraces
Open

sarsko wants to merge 1 commit into
mainfrom
lazy-deadlock-backtraces

Conversation

@sarsko

@sarsko sarsko commented Sep 18, 2026

Copy link
Copy Markdown
Contributor

Addresses the cost complaint behind #263 (see my comment there for why the fix proposed in that issue — swapping to Backtrace::new_unresolved — turned out to be a no-op).

SHUTTLE_CAPTURE_BACKTRACE captured a full backtrace on every call to Task::block. That field is overwritten on each block and only read for unfinished tasks when the execution deadlocks, so on a 4-thread mutex workload it is ~70,000 stack walks to print at most a handful. Measured, the flag cost 87x (29.6ms → 2.57s).

A task blocked in a synchronous primitive does not need eager capture: it stays suspended inside continuation::switch with its whole blocking call chain still live on its own coroutine stack. So defer the walk until we know it matters.

How

A new ContinuationInput::CaptureBacktrace resumes a suspended task solely so it can walk its own stack and immediately re-suspend, without running any user code. The StepError::Deadlock arm drives one capture per still-blocked task.

The suspend point in switch becomes a loop, which is the whole mechanism:

loop {
    match unsafe { &(*yielder) }.suspend(ContinuationOutput::Yielded) {
        ContinuationInput::Exit => panic!("unexpected exit continuation"),
        ContinuationInput::Resume => break,
        ContinuationInput::CaptureBacktrace => { /* walk our own stack, stash it */ }
    }
}

Re-suspending with Yielded returns the continuation to ContinuationState::Ready — exactly the state it was in — so no new ContinuationOutput variant is needed.

Why it's safe at that point

At the deadlock arm, every unfinished task's continuation is still ContinuationState::Ready, the ContinuationPool is still in scope, std::thread::panicking() is false, and cleanup() is never reached on that path (the arm panics first). Nothing has been dropped, reset, or returned to the pool.

The resume is deliberately schedule-neutral: it re-enters the task at its yielder.suspend call, which is after record_tick and maybe_yield, so it makes no scheduling decision, records no annotation tick, and does not extend CurrentSchedule. That last part matters — persist_failure dedups on CurrentSchedule::len(), so growing the schedule here would make the panic hook persist a second, mutated schedule that no longer replays the deadlock.

A captured backtrace is never clobbered: the handler skips tasks that already have one, and skips tasks whose continuation has not started (resuming those would run the function rather than capture anything).

Scope

Tasks parked on a pending future are unaffected here. Their poll stack is already unwound by the time they suspend, so those sites still capture eagerly. Making those cheap and accurate is the follow-up PR.

Results

4-thread mutex workload, 500 increments each, 20 iterations; 5 samples, same machine and run:

SHUTTLE_CAPTURE_BACKTRACE=1 flag unset
2.565 s → 828 ms 29.6 ms → 29.1 ms

Deadlock reports for synchronous blocking are unchanged in substance. Frame-by-frame diff over both blocked tasks: 78/79 frames before vs 76/77 after, differing only in three hunks of Shuttle-internal plumbing (the capture site at the top; the resume path at the bottom naming the deadlock handler instead of the scheduler loop). Every user frame and the entire blocking call chain are identical, and the user's own frame moves from position #11 to #9.

Testing

  • cargo fmt --check, cargo clippy --workspace --all-targets, cargo doc all clean
  • cargo test --release -p shuttle: 426 passed, 0 failed
  • All other workspace crates pass
  • With the flag set, verified a sync deadlock still names the blocked user function (user_fn_locks) and the joining side

Note on flaky tests

Before rebasing onto current main I saw intermittent full-suite failures on both this branch and unmodified main — different tests each run, with ExecutionState: AlreadyBorrowed and tracing-subscriber "cloned a span that already closed" signatures, all passing reliably in isolation. They have not reproduced since rebasing onto main (which now includes #320 and #346). Mentioning it in case it resurfaces in CI.


By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

SHUTTLE_CAPTURE_BACKTRACE captured a full backtrace on every call to
Task::block, but the field is overwritten on each block and only read for
unfinished tasks when the execution deadlocks. On a 4-thread mutex
workload that is ~70k stack walks to print at most a handful, and it made
the flag cost 79x (27ms -> 2.12s).

A task blocked in a synchronous primitive does not need eager capture: it
stays suspended inside continuation::switch with its whole blocking call
chain still live on its coroutine stack. So defer the walk until we know
it matters. Add ContinuationInput::CaptureBacktrace, which resumes a
suspended task solely so it can walk its own stack and immediately
re-suspend, and drive it from the StepError::Deadlock arm.

This is safe to do there: every unfinished task's continuation is still
ContinuationState::Ready, the pool is still in scope, panicking() is
false, and cleanup() is never reached on that path.

The resume is deliberately schedule-neutral. It re-enters the task at its
yielder.suspend call, which is after record_tick and maybe_yield, so it
makes no scheduling decision and does not extend CurrentSchedule. That
last part matters because persist_failure dedups on CurrentSchedule::len,
so growing the schedule here would make the panic hook persist a second,
mutated schedule that no longer replays the deadlock.

Tasks parked on a pending future are unaffected: their poll stack is
already unwound by the time they suspend, so those sites still capture
eagerly and the deadlock handler leaves their backtrace alone.

Measured on the 4-thread mutex workload with the flag set: 2.12s -> 975ms.
The remainder is the eager capture on the async path, addressed separately.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant