simple tool to compare traces between executions (#4628)

# Objective

- Have an easy way to compare spans between executions

## Solution

- Add a tool to compare spans from chrome traces

```bash
> cargo run --release  -p spancmp -- --help
   Compiling spancmp v0.1.0
    Finished release [optimized] target(s) in 1.10s
     Running `target/release/spancmp --help`
spancmp

USAGE:
    spancmp [OPTIONS] <TRACE> [SECOND_TRACE]

ARGS:
    <TRACE>
    <SECOND_TRACE>

OPTIONS:
    -h, --help                     Print help information
    -p, --pattern <PATTERN>        Filter spans by name matching the pattern
    -t, --threshold <THRESHOLD>    Filter spans that have an average shorther than the threshold
                                   [default: 0]
```

for each span, it will display the count, minimum duration, average duration and max duration. It can be filtered by a pattern on the span name or by a minimum average duration.

just displaying a trace
![Screenshot 2022-04-28 at 21 56 21](https://user-images.githubusercontent.com/8672791/165835310-f465c6f2-9e6b-4808-803e-884b06e49292.png)

comparing two traces
![Screenshot 2022-04-28 at 21 56 55](https://user-images.githubusercontent.com/8672791/165835353-097d266b-a70c-41b8-a8c1-27804011dc97.png)



Co-authored-by: Robert Swain <robert.swain@gmail.com>

Cargo.toml

@@ -13,7 +13,7 @@ repository = "https://github.com/bevyengine/bevy"
 
 [workspace]
 exclude = ["benches", "crates/bevy_ecs_compile_fail_tests"]
-members = ["crates/*", "examples/ios", "tools/ci", "errors"]
+members = ["crates/*", "examples/ios", "tools/ci", "tools/spancmp", "errors"]
 
 [features]
 default = [

tools/ci/src/main.rs

@@ -12,6 +12,7 @@ bitflags! {
         const DOC_CHECK = 0b00100000;
         const BENCH_CHECK = 0b01000000;
         const EXAMPLE_CHECK = 0b10000000;
+        const COMPILE_CHECK = 0b100000000;
     }
 }
 
@@ -32,7 +33,9 @@ fn main() {
         Some("example-check") => Check::EXAMPLE_CHECK,
         Some("lints") => Check::FORMAT | Check::CLIPPY,
         Some("doc") => Check::DOC_TEST | Check::DOC_CHECK,
-        Some("compile") => Check::COMPILE_FAIL | Check::BENCH_CHECK | Check::EXAMPLE_CHECK,
+        Some("compile") => {
+            Check::COMPILE_FAIL | Check::BENCH_CHECK | Check::EXAMPLE_CHECK | Check::COMPILE_CHECK
+        }
         _ => Check::all(),
     };
 
@@ -97,4 +100,11 @@ fn main() {
             .run()
             .expect("Please fix failing doc-tests in output above.");
     }
+
+    if what_to_run.contains(Check::COMPILE_CHECK) {
+        // Build examples and check they compile
+        cmd!("cargo check --workspace")
+            .run()
+            .expect("Please fix failing doc-tests in output above.");
+    }
 }

tools/spancmp/Cargo.toml

@@ -0,0 +1,16 @@
+[package]
+name = "spancmp"
+version = "0.1.0"
+edition = "2021"
+description = "compare spans for Bevy"
+publish = false
+license = "MIT OR Apache-2.0"
+
+[dependencies]
+serde_json = "1.0"
+serde = { version = "1.0", features = ["derive"] }
+clap = { version = "3.1.12", features = ["derive"] }
+regex = "1.5"
+termcolor = "1.1"
+bevy_reflect = { path = "../../crates/bevy_reflect", version = "0.8.0-dev" }
+lazy_static = "1.4"

tools/spancmp/src/main.rs

@@ -0,0 +1,162 @@
+//! helper to extract span stats from a chrome trace file
+//! spec: <https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview#heading=h.puwqg050lyuy>
+
+use std::ops::Div;
+
+use clap::Parser;
+use parse::read_trace;
+use regex::Regex;
+use termcolor::{ColorChoice, StandardStream};
+
+use crate::pretty::{print_spanstats, set_bold, simplify_name};
+
+mod parse;
+mod pretty;
+
+#[derive(Parser, Debug)]
+struct Args {
+    #[clap(short, long, default_value_t = 0.0)]
+    /// Filter spans that have an average shorther than the threshold
+    threshold: f32,
+
+    #[clap(short, long)]
+    /// Filter spans by name matching the pattern
+    pattern: Option<Regex>,
+
+    #[clap(short, long)]
+    /// Simplify system names
+    short: bool,
+
+    trace: String,
+    /// Optional, second trace to compare
+    second_trace: Option<String>,
+}
+
+fn main() {
+    let cli = Args::parse();
+
+    // Setup stdout to support colors
+    let mut stdout = StandardStream::stdout(ColorChoice::Auto);
+
+    // Read the first trace file
+    let reference = read_trace(cli.trace);
+    if let Some(comparison) = cli.second_trace {
+        // Read the second trace file
+        let mut comparison = read_trace(comparison);
+
+        reference
+            .iter()
+            .filter(|(_, stats)| filter_by_threshold(stats, cli.threshold))
+            .filter(|(name, _)| filter_by_pattern(name, cli.pattern.as_ref()))
+            .for_each(|(span, reference)| {
+                // for each span in the first trace
+                set_bold(&mut stdout, true);
+                if cli.short {
+                    println!("{}", simplify_name(span));
+                } else {
+                    println!("{}", span);
+                }
+                set_bold(&mut stdout, false);
+                print!("  ");
+                let comparison = comparison.remove(span);
+                print_spanstats(&mut stdout, Some(reference), comparison.as_ref(), false);
+            });
+        comparison
+            .iter()
+            .filter(|(_, stats)| filter_by_threshold(stats, cli.threshold))
+            .filter(|(name, _)| filter_by_pattern(name, cli.pattern.as_ref()))
+            .for_each(|(span, comparison)| {
+                // print the spans only present in the second trace
+                set_bold(&mut stdout, true);
+                if cli.short {
+                    println!("{}", simplify_name(span));
+                } else {
+                    println!("{}", span);
+                }
+                set_bold(&mut stdout, false);
+                print!("  ");
+                print_spanstats(&mut stdout, None, Some(comparison), false);
+            });
+    } else {
+        // just print stats from the first trace
+        reference
+            .iter()
+            .filter(|(_, stats)| filter_by_threshold(stats, cli.threshold))
+            .filter(|(name, _)| filter_by_pattern(name, cli.pattern.as_ref()))
+            .for_each(|(span, reference)| {
+                set_bold(&mut stdout, true);
+                if cli.short {
+                    println!("{}", simplify_name(span));
+                } else {
+                    println!("{}", span);
+                }
+                set_bold(&mut stdout, false);
+                print!("  ");
+                print_spanstats(&mut stdout, Some(reference), None, true);
+            });
+    }
+}
+
+fn filter_by_threshold(span_stats: &SpanStats, threshold: f32) -> bool {
+    span_stats.avg > threshold
+}
+
+fn filter_by_pattern(name: &str, pattern: Option<&Regex>) -> bool {
+    if let Some(pattern) = pattern {
+        pattern.is_match(name)
+    } else {
+        true
+    }
+}
+
+#[derive(Debug)]
+pub struct SpanStats {
+    pub count: usize,
+    pub avg: f32,
+    pub min: f32,
+    pub max: f32,
+}
+
+impl Default for SpanStats {
+    fn default() -> Self {
+        Self {
+            count: 0,
+            avg: 0.0,
+            min: f32::MAX,
+            max: 0.0,
+        }
+    }
+}
+
+impl SpanStats {
+    fn add_span(&mut self, duration: f32) {
+        if duration < self.min {
+            self.min = duration;
+        }
+        if duration > self.max {
+            self.max = duration;
+        }
+        self.avg = (self.avg * self.count as f32 + duration) / (self.count as f32 + 1.0);
+        self.count += 1;
+    }
+}
+
+pub struct SpanRelative {
+    count: f32,
+    avg: f32,
+    min: f32,
+    max: f32,
+}
+
+impl Div for &SpanStats {
+    type Output = SpanRelative;
+
+    fn div(self, rhs: Self) -> Self::Output {
+        Self::Output {
+            count: self.count as f32 / rhs.count as f32,
+            avg: self.avg / rhs.avg,
+            min: self.min / rhs.min,
+            max: self.max / rhs.max,
+        }
+    }
+}

tools/spancmp/src/parse.rs

@@ -0,0 +1,96 @@
+use std::{
+    cell::RefCell,
+    collections::HashMap,
+    fs::File,
+    io::{BufReader, Read},
+    rc::Rc,
+};
+
+use serde::Deserialize;
+use serde_json::Deserializer;
+
+use crate::SpanStats;
+
+/// A span from the trace
+#[derive(Deserialize, Debug)]
+struct Span {
+    /// name
+    name: String,
+    /// phase
+    ph: String,
+    /// timestamp
+    ts: f32,
+}
+
+/// Ignore entries in the trace that are not a span
+#[derive(Deserialize, Debug)]
+struct Ignore {}
+
+/// deserialize helper
+#[derive(Deserialize, Debug)]
+#[serde(untagged)]
+enum SpanOrIgnore {
+    /// deserialize as a span
+    Span(Span),
+    /// catchall that didn't match a span
+    Ignore(Ignore),
+}
+
+#[derive(Clone)]
+struct SkipperWrapper {
+    reader: Rc<RefCell<BufReader<File>>>,
+}
+
+impl SkipperWrapper {
+    fn from(mut reader: BufReader<File>) -> SkipperWrapper {
+        let _ = reader.seek_relative(1);
+
+        Self {
+            reader: Rc::new(RefCell::new(reader)),
+        }
+    }
+
+    fn skip(&self) {
+        let _ = self.reader.borrow_mut().seek_relative(1);
+    }
+}
+
+impl Read for SkipperWrapper {
+    fn read(&mut self, buf: &mut [u8]) -> Result<usize, std::io::Error> {
+        self.reader.borrow_mut().read(buf)
+    }
+}
+
+pub fn read_trace(file: String) -> HashMap<String, SpanStats> {
+    let file = File::open(file).unwrap();
+    let reader = BufReader::new(file);
+    let reader_wrapper = SkipperWrapper::from(reader);
+
+    let spans = Deserializer::from_reader(reader_wrapper.clone()).into_iter::<SpanOrIgnore>();
+
+    let mut open_spans: HashMap<String, f32> = HashMap::new();
+    let mut all_spans_stats: HashMap<String, SpanStats> = HashMap::new();
+    spans
+        .flat_map(move |s| {
+            reader_wrapper.skip();
+
+            if let Ok(SpanOrIgnore::Span(span)) = s {
+                Some(span)
+            } else {
+                None
+            }
+        })
+        .for_each(|s| {
+            if s.ph == "B" {
+                open_spans.insert(s.name.clone(), s.ts);
+            } else if s.ph == "E" {
+                let begin = open_spans.remove(&s.name).unwrap();
+                all_spans_stats
+                    .entry(s.name)
+                    .or_default()
+                    .add_span(s.ts - begin);
+            }
+        });
+
+    all_spans_stats
+}