From 5375c2498464d02c5364f7845ce36b52da7bc170 Mon Sep 17 00:00:00 2001 From: Ariel Ben-Yehuda Date: Wed, 13 Nov 2024 16:24:26 +0000 Subject: [PATCH] make self-tracing public --- tokio/src/runtime/dump.rs | 28 +++++++- tokio/src/runtime/task/trace/mod.rs | 3 +- tokio/tests/task_trace_self.rs | 108 ++++++++++++++++++++++++++++ 3 files changed, 137 insertions(+), 2 deletions(-) create mode 100644 tokio/tests/task_trace_self.rs diff --git a/tokio/src/runtime/dump.rs b/tokio/src/runtime/dump.rs index aea2381127b..1d7554475ba 100644 --- a/tokio/src/runtime/dump.rs +++ b/tokio/src/runtime/dump.rs @@ -3,7 +3,14 @@ //! See [Handle::dump][crate::runtime::Handle::dump]. use crate::task::Id; -use std::fmt; +use std::{fmt, future::Future}; + +pub use crate::runtime::task::trace::Root; + +/// before merging add documentation +pub fn root(f: F) -> Root { + crate::runtime::task::trace::Trace::root(f) +} /// A snapshot of a runtime's state. /// @@ -38,6 +45,25 @@ pub struct Trace { inner: super::task::trace::Trace, } +impl Trace { + /// document + pub fn capture(f: F) -> (R, Trace) + where + F: FnOnce() -> R, + { + let (res, trace) = super::task::trace::Trace::capture(f); + (res, Trace { inner: trace }) + } + + /// doc doc doc + pub fn root(f: F) -> Root + where + F: Future, + { + crate::runtime::task::trace::Trace::root(f) + } +} + impl Dump { pub(crate) fn new(tasks: Vec) -> Self { Self { diff --git a/tokio/src/runtime/task/trace/mod.rs b/tokio/src/runtime/task/trace/mod.rs index bb411f42d72..2787c1ecd58 100644 --- a/tokio/src/runtime/task/trace/mod.rs +++ b/tokio/src/runtime/task/trace/mod.rs @@ -56,7 +56,8 @@ pub(crate) struct Trace { pin_project_lite::pin_project! { #[derive(Debug, Clone)] #[must_use = "futures do nothing unless you `.await` or poll them"] - pub(crate) struct Root { + /// before merging add documentation: roots a trace + pub struct Root { #[pin] future: T, } diff --git a/tokio/tests/task_trace_self.rs b/tokio/tests/task_trace_self.rs new file mode 100644 index 00000000000..723252d14f7 --- /dev/null +++ b/tokio/tests/task_trace_self.rs @@ -0,0 +1,108 @@ +#![allow(unknown_lints, unexpected_cfgs)] +#![cfg(all( + tokio_unstable, + tokio_taskdump, + target_os = "linux", + any(target_arch = "aarch64", target_arch = "x86", target_arch = "x86_64") +))] + +use std::{ + future::Future, + pin::Pin, + sync::{Arc, Mutex}, + task::{Context, Poll}, + time::{Duration, Instant}, +}; + +use tokio::runtime::dump::{Root, Trace}; + +pin_project_lite::pin_project! { pub struct PrettyFuture { + #[pin] + f: Root, + t_last: State, + logs: Arc>>, +} +} + +enum State { + NotStarted, + Running { since: Instant }, + Alerted, +} + +impl PrettyFuture { + pub fn pretty(f: F, logs: Arc>>) -> Self { + PrettyFuture { + f: Trace::root(f), + t_last: State::NotStarted, + logs, + } + } +} + +impl Future for PrettyFuture { + type Output = F::Output; + + fn poll(self: Pin<&mut Self>, cx: &mut Context<'_>) -> Poll { + let mut this = self.project(); + let now = Instant::now(); + let t_last = match this.t_last { + State::Running { since } => Some(*since), + State::NotStarted => { + *this.t_last = State::Running { since: now }; + None + } + State::Alerted => { + // don't double-alert for the same future + None + } + }; + if t_last.is_some_and(|t_last| now.duration_since(t_last) > Duration::from_millis(500)) { + let (res, trace) = tokio::runtime::dump::Trace::capture(|| this.f.as_mut().poll(cx)); + this.logs.lock().unwrap().push(trace); + *this.t_last = State::Alerted; + return res; + } + this.f.poll(cx) + } +} + +#[tokio::test] +async fn task_trace_self() { + let log = Arc::new(Mutex::new(vec![])); + let log2 = Arc::new(Mutex::new(vec![])); + let mut good_line = vec![]; + let mut bad_line = vec![]; + PrettyFuture::pretty( + PrettyFuture::pretty( + async { + bad_line.push(line!() + 1); + tokio::task::yield_now().await; + bad_line.push(line!() + 1); + tokio::time::sleep(Duration::from_millis(1)).await; + for _ in 0..100 { + good_line.push(line!() + 1); + tokio::time::sleep(Duration::from_millis(10)).await; + } + }, + log.clone(), + ), + log2.clone(), + ) + .await; + for line in good_line { + let s = format!("{}:{}:", file!(), line); + assert!(log.lock().unwrap().iter().any(|x| { + eprintln!("{}", x); + format!("{}", x).contains(&s) + })); + } + for line in bad_line { + let s = format!("{}:{}:", file!(), line); + assert!(!log + .lock() + .unwrap() + .iter() + .any(|x| format!("{}", x).contains(&s))); + } +}