tracing-calltree 0.1.2

Always-on hierarchical profiling for Rust tracing spans with rolling latency statistics.
Documentation
use crate::snapshot::{CallTreeSnapshot, NodeSnapshot};
use std::fmt;
use std::time::Duration;

pub struct SnapshotDisplay<'a>(pub(crate) &'a CallTreeSnapshot);

impl fmt::Display for SnapshotDisplay<'_> {
    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
        let rows = build_rows(self.0);
        let widths = ColumnWidths::from_rows(&rows);

        for (index, row) in rows.iter().enumerate() {
            write_row(f, row, &widths)?;
            if index + 1 != rows.len() {
                writeln!(f)?;
            }
        }

        Ok(())
    }
}

impl fmt::Display for CallTreeSnapshot {
    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
        self.display().fmt(f)
    }
}

fn write_row(f: &mut fmt::Formatter<'_>, row: &DisplayRow, widths: &ColumnWidths) -> fmt::Result {
    write!(
        f,
        "{:<name_width$} {:>avg_width$} {:>p95_width$} {:>samples_width$}",
        row.label,
        row.avg,
        row.p95,
        row.samples,
        name_width = widths.name,
        avg_width = widths.avg,
        p95_width = widths.p95,
        samples_width = widths.samples,
    )
}

fn build_rows(snapshot: &CallTreeSnapshot) -> Vec<DisplayRow> {
    let mut roots = snapshot.roots.iter().collect::<Vec<_>>();
    roots.sort_by(|left, right| {
        right
            .wall
            .mean
            .cmp(&left.wall.mean)
            .then_with(|| left.name.cmp(&right.name))
    });

    let mut rows = Vec::new();
    for (index, root) in roots.into_iter().enumerate() {
        collect_rows(root, "", true, index + 1 == snapshot.roots.len(), &mut rows);
    }
    rows
}

fn collect_rows(
    node: &NodeSnapshot,
    prefix: &str,
    is_root: bool,
    is_last: bool,
    rows: &mut Vec<DisplayRow>,
) {
    let branch = if is_root {
        ""
    } else if is_last {
        "└── "
    } else {
        "├── "
    };

    rows.push(DisplayRow {
        label: format!("{prefix}{branch}{}", node.name),
        avg: format!("{} avg", format_duration(node.wall.mean)),
        p95: format!("{} p95", format_duration(node.wall.p95)),
        samples: format!("n={}", node.wall.samples),
    });

    let child_prefix = if is_root {
        String::new()
    } else {
        format!("{prefix}{}", if is_last { "    " } else { "" })
    };

    for (index, child) in node.children.iter().enumerate() {
        collect_rows(
            child,
            &child_prefix,
            false,
            index + 1 == node.children.len(),
            rows,
        );
    }
}

fn format_duration(duration: Duration) -> String {
    let nanos = duration.as_nanos();

    if nanos >= 1_000_000_000 {
        format!("{:.1}s", nanos as f64 / 1_000_000_000.0)
    } else if nanos >= 1_000_000 {
        format!("{:.1}ms", nanos as f64 / 1_000_000.0)
    } else if nanos >= 1_000 {
        format!("{:.1}us", nanos as f64 / 1_000.0)
    } else {
        format!("{nanos}ns")
    }
}

#[derive(Debug)]
struct DisplayRow {
    label: String,
    avg: String,
    p95: String,
    samples: String,
}

#[derive(Debug)]
struct ColumnWidths {
    name: usize,
    avg: usize,
    p95: usize,
    samples: usize,
}

impl ColumnWidths {
    fn from_rows(rows: &[DisplayRow]) -> Self {
        Self {
            name: rows.iter().map(|row| row.label.len()).max().unwrap_or(0),
            avg: rows.iter().map(|row| row.avg.len()).max().unwrap_or(0),
            p95: rows.iter().map(|row| row.p95.len()).max().unwrap_or(0),
            samples: rows.iter().map(|row| row.samples.len()).max().unwrap_or(0),
        }
    }
}

#[cfg(test)]
mod tests {
    use crate::snapshot::CallTreeSnapshot;
    use crate::stats::TimingStats;
    use std::time::Duration;

    #[test]
    fn renders_tree_display_with_dynamic_columns_and_sorted_roots() {
        use super::format_duration;
        use crate::snapshot::NodeSnapshot;

        let snapshot = CallTreeSnapshot {
            roots: vec![
                NodeSnapshot {
                    name: "request".to_string(),
                    target: "app".to_string(),
                    module_path: None,
                    line: None,
                    total_calls: 4,
                    wall: TimingStats {
                        samples: 4,
                        min: Duration::from_millis(8),
                        max: Duration::from_millis(12),
                        mean: Duration::from_millis(10),
                        p95: Duration::from_millis(12),
                    },
                    active: TimingStats {
                        samples: 4,
                        min: Duration::from_millis(4),
                        max: Duration::from_millis(8),
                        mean: Duration::from_millis(6),
                        p95: Duration::from_millis(8),
                    },
                    suspended: TimingStats {
                        samples: 4,
                        min: Duration::from_millis(2),
                        max: Duration::from_millis(4),
                        mean: Duration::from_millis(3),
                        p95: Duration::from_millis(4),
                    },
                    children: vec![
                        NodeSnapshot {
                            name: "authenticate".to_string(),
                            target: "app".to_string(),
                            module_path: None,
                            line: None,
                            total_calls: 1,
                            wall: TimingStats {
                                samples: 1,
                                min: Duration::from_millis(5),
                                max: Duration::from_millis(5),
                                mean: Duration::from_millis(5),
                                p95: Duration::from_millis(5),
                            },
                            active: TimingStats::from_nanos(std::iter::empty()),
                            suspended: TimingStats::from_nanos(std::iter::empty()),
                            children: vec![],
                        },
                        NodeSnapshot {
                            name: "database".to_string(),
                            target: "app".to_string(),
                            module_path: None,
                            line: None,
                            total_calls: 1,
                            wall: TimingStats {
                                samples: 1,
                                min: Duration::from_millis(20),
                                max: Duration::from_millis(20),
                                mean: Duration::from_millis(20),
                                p95: Duration::from_millis(20),
                            },
                            active: TimingStats::from_nanos(std::iter::empty()),
                            suspended: TimingStats::from_nanos(std::iter::empty()),
                            children: vec![NodeSnapshot {
                                name: "query".to_string(),
                                target: "app".to_string(),
                                module_path: None,
                                line: None,
                                total_calls: 1,
                                wall: TimingStats {
                                    samples: 1,
                                    min: Duration::from_millis(1),
                                    max: Duration::from_millis(1),
                                    mean: Duration::from_millis(1),
                                    p95: Duration::from_millis(1),
                                },
                                active: TimingStats::from_nanos(std::iter::empty()),
                                suspended: TimingStats::from_nanos(std::iter::empty()),
                                children: vec![],
                            }],
                        },
                    ],
                },
                NodeSnapshot {
                    name: "maintenance_job_with_long_name".to_string(),
                    target: "app".to_string(),
                    module_path: None,
                    line: None,
                    total_calls: 12,
                    wall: TimingStats {
                        samples: 12,
                        min: Duration::from_secs(2),
                        max: Duration::from_secs(2),
                        mean: Duration::from_secs(2),
                        p95: Duration::from_secs(2),
                    },
                    active: TimingStats::from_nanos(std::iter::empty()),
                    suspended: TimingStats::from_nanos(std::iter::empty()),
                    children: vec![],
                },
            ],
        };

        let rendered = snapshot.to_string();

        let name_width = "maintenance_job_with_long_name".len();
        let avg_width = "20.0ms avg".len();
        let p95_width = "20.0ms p95".len();
        let samples_width = "n=12".len();

        let line_root = format!(
            "{:<name_width$} {:>avg_width$} {:>p95_width$} {:>samples_width$}",
            "maintenance_job_with_long_name", "2.0s avg", "2.0s p95", "n=12",
        );

        let line_request = format!(
            "{:<name_width$} {:>avg_width$} {:>p95_width$} {:>samples_width$}",
            "request",
            format!("{} avg", format_duration(Duration::from_millis(10))),
            format!("{} p95", format_duration(Duration::from_millis(12))),
            "n=4",
        );

        let line_auth = format!(
            "{:<name_width$} {:>avg_width$} {:>p95_width$} {:>samples_width$}",
            "├── authenticate",
            format!("{} avg", format_duration(Duration::from_millis(5))),
            format!("{} p95", format_duration(Duration::from_millis(5))),
            "n=1",
        );

        let line_db = format!(
            "{:<name_width$} {:>avg_width$} {:>p95_width$} {:>samples_width$}",
            "└── database",
            format!("{} avg", format_duration(Duration::from_millis(20))),
            format!("{} p95", format_duration(Duration::from_millis(20))),
            "n=1",
        );

        let line_query = format!(
            "{:<name_width$} {:>avg_width$} {:>p95_width$} {:>samples_width$}",
            "    └── query",
            format!("{} avg", format_duration(Duration::from_millis(1))),
            format!("{} p95", format_duration(Duration::from_millis(1))),
            "n=1",
        );

        let expected = format!(
            "{}\n{}\n{}\n{}\n{}",
            line_root, line_request, line_auth, line_db, line_query
        );

        assert_eq!(rendered, expected);
    }
}