add statistics to dump

README.md

@@ -100,12 +100,13 @@ fn bar() {
 
 #[timed::timed(tracing = true)]
 fn main() {
-    timed::init_tracing!(
-        "Main", 
-        TraceOptions::new()
-        .with_chrome_trace(|x: &str| println!("{}", x)).build()
-    );
+    let trace = timed::TraceOptions::new()
+        .with_chrome_trace(|x: &str| println!("{}", x))
+        .build_named("Main");
+
     foo();
+
+    trace.finish();
 }
 
 ```

tests/examples/demo_duration.rs

@@ -1,26 +1,33 @@
 use timed::timed;
-#[macro_use] extern crate log;
+#[macro_use]
+extern crate log;
 
 #[timed]
-fn add(x: i32, y: i32) -> i32 { x + y }
+fn add(x: i32, y: i32) -> i32 {
+    x + y
+}
 
 #[timed]
-fn mul(x: i32, y: i32) -> i32 { x * y }
+fn mul(x: i32, y: i32) -> i32 {
+    x * y
+}
 
 #[timed(printer = "println!")]
-fn mul_println(x: i32, y: i32) -> i32 { x * y}
+fn mul_println(x: i32, y: i32) -> i32 {
+    x * y
+}
 
 #[timed(printer = "info!")]
-fn mul_info(x: i32, y: i32) -> i32 { x * y }
-
+fn mul_info(x: i32, y: i32) -> i32 {
+    x * y
+}
 
 #[test]
 fn timing() {
-
     pretty_env_logger::init();
 
     assert_eq!(add(1, 2), 3);
     assert_eq!(mul(1, 2), 2);
     assert_eq!(mul_println(1, 2), 2);
     assert_eq!(mul_info(1, 2), 2);
-}
+}

tests/examples/demo_tracing.rs

@@ -16,9 +16,12 @@ fn bar() {
 
 #[timed::timed(tracing = true)]
 fn main() {
-    timed::init_tracing!("Main", timed::TraceOptions::new()
-    .with_chrome_trace(
-        |x: &str| println!("{}", x)
-    ).build());
+    let trace = timed::TraceOptions::new()
+        .with_chrome_trace(|x: &str| println!("{}", x))
+        .with_statistics(|x: &str| println!("{}", x))
+        .build_named("Main");
+
     foo();
+
+    trace.finish();
 }

tests/src/tests_expand.rs

@@ -18,9 +18,11 @@ fn bar() {
 
 #[timed::timed(tracing = true)]
 fn main() {
-    timed::init_tracing!("Test", timed::TraceOptions::new()
-    .with_chrome_trace(
-        |x: &str| println!("{}", x)
-    ).build());
+    let trace = timed::TraceOptions::new()
+        .with_chrome_trace(|x: &str| println!("{}", x))
+        .build_named("Tests");
+
     foo();
+
+    trace.finish();
 }

tests/src/tests_macro.rs

@@ -1,6 +1,6 @@
 fn main() {
-    timed::init_tracing!("Hei", timed::TraceOptions::new()
-    .with_chrome_trace(
-        |x: &str| println!("{}", x)
-    ).build());
+    timed::TraceOptions::new()
+        .with_chrome_trace(|x: &str| println!("{}", x))
+        .with_statistics(|x: &str| println!("{}", x))
+        .build_named("Hei");
 }

tests/src/tests_tracing.rs

@@ -30,6 +30,7 @@ pub mod foo {
     pub mod bar {
         pub mod baz {
             use timed::timed;
+
             #[timed(tracing = true)]
             pub fn foobar() {
                 println!("Foobar");
@@ -41,50 +42,54 @@ pub mod foo {
 #[test]
 #[timed::timed(tracing = true)]
 fn test_tracing_chrome_tracing() {
-    timed::init_tracing!("Test", timed::TraceOptions::new()
-    .with_chrome_trace(
-        |x: &str| println!("{}", x)
-    ).build());
+    let trace = timed::TraceOptions::new()
+        .with_chrome_trace(|x: &str| println!("{}", x))
+        .build_named("Test");
 
     println!("Running main");
     sleep();
     foo();
+
+    trace.finish();
 }
 
 #[test]
 #[timed::timed(tracing = true)]
 fn test_tracing_with_stats() {
-    timed::init_tracing!("TestWithStats", timed::TraceOptions::new()
-    .with_statistics(
-        |x: &str| println!("{}", x)
-    ).build());
+    let trace = timed::TraceOptions::new()
+        .with_statistics(|x: &str| println!("{}", x))
+        .build_named("TestWithStats");
 
     println!("Running main");
     sleep();
     foo();
+
+    trace.finish();
 }
 
 #[test]
 #[timed::timed(tracing = true)]
 fn test_tracing_with_both() {
-    timed::init_tracing!("TestWithBoth", timed::TraceOptions::new()
-    .with_statistics(
-        |x: &str| println!("{}", x)
-    ).with_chrome_trace(
-        |x: &str| println!("{}", x)
-    ).build());
+    let trace = timed::TraceOptions::new()
+        .with_statistics(|x: &str| println!("{}", x))
+        .with_chrome_trace(|x: &str| println!("{}", x))
+        .build_named("TestWithBoth");
 
     println!("Running main");
     sleep();
     foo();
+
+    trace.finish();
 }
 
 #[test]
 #[timed::timed(tracing = true)]
 fn test_tracing_with_none() {
-    timed::init_tracing!("TestWithNone", timed::TraceOptions::new().build());
+    let trace = timed::TraceOptions::new().build_named("TestWithNone");
 
     println!("Running main");
     sleep();
     foo();
+
+    trace.finish();
 }

timed/src/lib.rs

@@ -50,27 +50,24 @@ pub use timed_proc_macros::timed;
 #[macro_use]
 extern crate lazy_static;
 
+use crate::Phase::Finish;
 use std::collections::HashMap;
 use std::sync::Mutex;
 use std::time::Duration;
-use crate::Phase::Finish;
 
 lazy_static! {
     static ref TRACES: Mutex<HashMap<String, Vec<Hop>>> = Mutex::new(HashMap::new());
 }
 
-#[derive(Copy, Clone)]
+#[derive(Copy, Clone, Default)]
 pub struct TraceOptions {
     pub statistics: Option<fn(&str)>,
     pub chrome_trace: Option<fn(&str)>,
 }
 
 impl TraceOptions {
     pub fn new() -> TraceOptions {
-        TraceOptions {
-            statistics: None,
-            chrome_trace: None
-        }
+        TraceOptions::default()
     }
 
     pub fn with_statistics(&mut self, f: fn(&str)) -> &mut TraceOptions {
@@ -83,8 +80,8 @@ impl TraceOptions {
         self
     }
 
-    pub fn build(self) -> TraceOptions {
-        self
+    pub fn build_named(self, name: &str) -> Trace {
+        Trace::new(name, self)
     }
 }
 
@@ -104,7 +101,7 @@ impl Phase {
     fn to_string(&self) -> String {
         match self {
             Phase::Start => "B".to_string(),
-            Finish(_) => "E".to_string()
+            Finish(_) => "E".to_string(),
         }
     }
 }
@@ -127,69 +124,89 @@ impl Trace {
         }
     }
 
-    pub fn dump(id: &str, options: &TraceOptions) {
-        if options.chrome_trace.is_none() && options.statistics.is_none() { return; }
+    pub fn new(id: &str, options: TraceOptions) -> Trace {
+        let trace = Trace {
+            id: id.into(),
+            options,
+        };
+        Self::register(&trace.id);
+        trace
+    }
+
+    pub fn finish(self) {
+        self.dump();
+    }
+
+    fn dump(&self) {
+        if self.options.chrome_trace.is_none() && self.options.statistics.is_none() {
+            return;
+        }
 
         let mut traces = TRACES.lock().unwrap();
-        let entry = traces.entry(id.to_string()).or_insert(vec![]);
+        let entry = traces.entry(self.id.to_string()).or_insert(vec![]);
         let mut stats_map = HashMap::new();
         let mut total_time_nanos: u128 = 0;
         let mut chrome_trace_string = String::new();
 
-        if options.chrome_trace.is_some() {
+        if self.options.chrome_trace.is_some() {
             chrome_trace_string.push_str("[\n");
         }
 
         for (i, hop) in entry.iter().enumerate() {
-            if options.statistics.is_some() {
+            if self.options.statistics.is_some() {
                 if let Finish(d) = hop.ph {
-                    stats_map.entry(hop.name.clone())
-                        .or_insert(vec![])
-                        .push(d);
+                    stats_map.entry(hop.name.clone()).or_insert(vec![]).push(d);
                     total_time_nanos += d.as_nanos();
                 }
             }
 
-            if options.chrome_trace.is_some() {
+            if self.options.chrome_trace.is_some() {
                 let is_last = i == entry.len() - 1;
                 let trace = format!(
                     "{{ \"pid\": 0, \"ts\": {},  \"ph\": \"{}\", \"name\": \"{}\" }}",
-                    hop.ts, hop.ph.to_string(), hop.name
+                    hop.ts,
+                    hop.ph.to_string(),
+                    hop.name
                 );
-                chrome_trace_string.push_str(&format!("    {}{}\n", trace, if !is_last { "," } else { "" }));
+                chrome_trace_string.push_str(&format!(
+                    "    {}{}\n",
+                    trace,
+                    if !is_last { "," } else { "" }
+                ));
             }
         }
 
-        if options.chrome_trace.is_some() {
+        if self.options.chrome_trace.is_some() {
             chrome_trace_string.push_str("]");
         }
 
-        options.chrome_trace.map(|f| f(&chrome_trace_string));
-        options.statistics.map(|f| Trace::print_statistics(&f, &stats_map, total_time_nanos));
-    }
+        if let Some(f) = self.options.chrome_trace {
+            f(&chrome_trace_string);
+        }
 
-    pub fn new(id: &str, options: TraceOptions) -> Trace {
-        let trace = Trace {
-            id: id.into(),
-            options,
-        };
-        Self::register(&trace.id);
-        trace
+        if let Some(f) = self.options.statistics {
+            Trace::print_statistics(&f, &stats_map, total_time_nanos);
+        }
     }
 
-    fn print_statistics(processor: &fn(&str), stats_map: &HashMap<String, Vec<Duration>>, total_time_nanos: u128) {
+    fn print_statistics(
+        processor: &fn(&str),
+        stats_map: &HashMap<String, Vec<Duration>>,
+        total_time_nanos: u128,
+    ) {
         struct FnStats {
             name: String,
             calls: usize,
             overall_time: Duration,
         }
         impl FnStats {
             fn to_string(&self, total_time_nanos: f64) -> String {
-                format!("- {}\n\t> calls: {:>6}\n\t> total time: {:<11} ({:.5}%)",
-                        self.name,
-                        self.calls,
-                        format!("{:?}", self.overall_time),
-                        100.0 * self.overall_time.as_nanos() as f64 / total_time_nanos
+                format!(
+                    "- {}\n\t> calls: {:>6}\n\t> total time: {:<11} ({:.5}%)",
+                    self.name,
+                    self.calls,
+                    format!("{:?}", self.overall_time),
+                    100.0 * self.overall_time.as_nanos() as f64 / total_time_nanos
                 )
             }
         }
@@ -206,20 +223,12 @@ impl Trace {
         });
 
         fn_stats.sort_by(|x, y| y.overall_time.as_nanos().cmp(&x.overall_time.as_nanos()));
-        fn_stats.iter().for_each(|f| processor(&f.to_string(total_time_nanos as f64)));
-        processor(&format!("========================\nall functions total time: {:?}", Duration::from_nanos(total_time_nanos as u64)));
-    }
-}
-
-#[macro_export]
-macro_rules! init_tracing {
-    ($name:expr, $options:expr) => {
-        let __trace = timed::Trace::new($name, $options);
-    };
-}
-
-impl Drop for Trace {
-    fn drop(&mut self) {
-        Trace::dump(&self.id, &self.options);
+        fn_stats
+            .iter()
+            .for_each(|f| processor(&f.to_string(total_time_nanos as f64)));
+        processor(&format!(
+            "========================\nall functions total time: {:?}",
+            Duration::from_nanos(total_time_nanos as u64)
+        ));
     }
 }