feat: add Span::elapsed() (#172)

* feat: add Span::elapsed()

Signed-off-by: Andy Lok <[email protected]>

* Update lib.rs

Signed-off-by: Andy Lok [email protected]

* fix

Signed-off-by: Andy Lok <[email protected]>

* fix

Signed-off-by: Andy Lok <[email protected]>

---------

Signed-off-by: Andy Lok <[email protected]>
Signed-off-by: Andy Lok [email protected]

CHANGELOG.md

@@ -6,6 +6,7 @@
 
 - Macro will use the full path of the function as span name instead of the only function name. You can turn it off by setting `#[trace(short_name = true)]`.
 - Add utility macros `func_name!()`, `full_name!()`, and `file_location!()` to generate names for use in span.
+- Add `Span::elapsed()` that returns the elapsed time since the span is created.
 
 ## v0.6.0
 

minitrace/src/lib.rs

@@ -19,7 +19,8 @@
 //! minitrace = "0.5"
 //! ```
 //!
-//! Libraries can attach their spans to the caller's span (if available) via the API boundary.
+//! Libraries can attach their spans to the caller's span (if caller has set [local parent](#local-span))
+//! via the API boundary.
 //!
 //! ```
 //! use minitrace::prelude::*;

minitrace/src/local/local_span.rs

@@ -84,7 +84,7 @@ impl LocalSpan {
     /// use minitrace::prelude::*;
     ///
     /// let span = LocalSpan::enter_with_local_parent("a child span")
-    ///     .with_properties(|| vec![("key1", "value1"), ("key2", "value2")]);
+    ///     .with_properties(|| [("key1", "value1"), ("key2", "value2")]);
     /// ```
     #[inline]
     pub fn with_properties<K, V, I, F>(self, properties: F) -> Self

minitrace/src/span.rs

@@ -4,6 +4,7 @@ use std::borrow::Cow;
 use std::cell::RefCell;
 use std::rc::Rc;
 use std::sync::Arc;
+use std::time::Duration;
 
 use minstant::Instant;
 
@@ -269,7 +270,7 @@ impl Span {
     /// use minitrace::prelude::*;
     ///
     /// let root = Span::root("root", SpanContext::random())
-    ///     .with_properties(|| vec![("key1", "value1"), ("key2", "value2")]);
+    ///     .with_properties(|| [("key1", "value1"), ("key2", "value2")]);
     /// ```
     #[inline]
     pub fn with_properties<K, V, I, F>(mut self, properties: F) -> Self
@@ -323,6 +324,36 @@ impl Span {
         }
     }
 
+    /// Returns the elapsed time since the span was created. If the `Span` is a noop span,
+    /// this function will return `None`.
+    ///
+    /// # Examples
+    ///
+    /// ```
+    /// use minitrace::prelude::*;
+    /// use std::time::Duration;
+    ///
+    /// let mut root = Span::root("root", SpanContext::random());
+    ///
+    /// // ...
+    ///
+    /// if root
+    ///     .elapsed()
+    ///     .map(|elapsed| elapsed < Duration::from_secs(1))
+    ///     .unwrap_or(false)
+    /// {
+    ///     root.cancel();
+    /// }
+    #[inline]
+    pub fn elapsed(&self) -> Option<Duration> {
+        #[cfg(feature = "enable")]
+        if let Some(inner) = self.inner.as_ref() {
+            return Some(inner.raw_span.begin_instant.elapsed());
+        }
+
+        None
+    }
+
     /// Dismisses the trace, preventing the reporting of any span records associated with it.
     ///
     /// This is particularly useful when focusing on the tail latency of a program. For instant,

minitrace/tests/lib.rs

@@ -1,7 +1,10 @@
 // Copyright 2021 TiKV Project Authors. Licensed under Apache-2.0.
 
+use std::time::Duration;
+
 use futures::executor::block_on;
 use minitrace::collector::Config;
+use minitrace::collector::ConsoleReporter;
 use minitrace::collector::TestReporter;
 use minitrace::local::LocalCollector;
 use minitrace::prelude::*;
@@ -393,7 +396,7 @@ fn test_macro() {
     #[trace(short_name = true, enter_on_poll = true)]
     async fn work(millis: &u64) {
         let _g = Span::enter_with_local_parent("work-inner");
-        tokio::time::sleep(std::time::Duration::from_millis(*millis))
+        tokio::time::sleep(Duration::from_millis(*millis))
             .enter_on_poll("sleep")
             .await;
     }
@@ -402,7 +405,7 @@ fn test_macro() {
         #[trace(short_name = true)]
         async fn work2(&self, millis: &u64) {
             let _g = Span::enter_with_local_parent("work-inner");
-            tokio::time::sleep(std::time::Duration::from_millis(*millis))
+            tokio::time::sleep(Duration::from_millis(*millis))
                 .enter_on_poll("sleep")
                 .await;
         }
@@ -411,10 +414,10 @@ fn test_macro() {
     #[trace(short_name = true)]
     async fn work3<'a>(millis1: &'a u64, millis2: &u64) {
         let _g = Span::enter_with_local_parent("work-inner");
-        tokio::time::sleep(std::time::Duration::from_millis(*millis1))
+        tokio::time::sleep(Duration::from_millis(*millis1))
             .enter_on_poll("sleep")
             .await;
-        tokio::time::sleep(std::time::Duration::from_millis(*millis2))
+        tokio::time::sleep(Duration::from_millis(*millis2))
             .enter_on_poll("sleep")
             .await;
     }
@@ -478,22 +481,22 @@ root []
 fn macro_example() {
     #[trace(short_name = true)]
     fn do_something_short_name(i: u64) {
-        std::thread::sleep(std::time::Duration::from_millis(i));
+        std::thread::sleep(Duration::from_millis(i));
     }
 
     #[trace(short_name = true)]
     async fn do_something_async_short_name(i: u64) {
-        futures_timer::Delay::new(std::time::Duration::from_millis(i)).await;
+        futures_timer::Delay::new(Duration::from_millis(i)).await;
     }
 
     #[trace]
     fn do_something(i: u64) {
-        std::thread::sleep(std::time::Duration::from_millis(i));
+        std::thread::sleep(Duration::from_millis(i));
     }
 
     #[trace]
     async fn do_something_async(i: u64) {
-        futures_timer::Delay::new(std::time::Duration::from_millis(i)).await;
+        futures_timer::Delay::new(Duration::from_millis(i)).await;
     }
 
     let (reporter, collected_spans) = TestReporter::new();
@@ -636,3 +639,22 @@ root []
         expected_graph
     );
 }
+
+#[test]
+#[serial]
+fn test_elapsed() {
+    minitrace::set_reporter(ConsoleReporter, Config::default());
+
+    {
+        let root = Span::root("root", SpanContext::random());
+
+        std::thread::sleep(Duration::from_millis(50));
+
+        let elapsed = root.elapsed().unwrap();
+
+        assert!(elapsed >= Duration::from_millis(50));
+        assert!(elapsed < Duration::from_millis(65));
+    }
+
+    minitrace::flush();
+}

test-statically-disable/src/main.rs

@@ -53,6 +53,8 @@ fn main() {
     assert!(SpanContext::current_local_parent().is_none());
     assert!(SpanContext::from_span(&span5).is_none());
 
+    assert!(root.elapsed().is_none());
+
     root.cancel();
 
     minitrace::flush();