tracing-calltree 0.1.0

Always-on hierarchical profiling for Rust tracing spans with rolling latency statistics.
Documentation 
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127

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 {
        for (index, root) in self.0.roots.iter().enumerate() {
            let is_last = index + 1 == self.0.roots.len();
            write_node(f, root, "", is_last)?;
            if !is_last {
                writeln!(f)?;
            }
        }

        Ok(())
    }
}

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

fn write_node(
    f: &mut fmt::Formatter<'_>,
    node: &NodeSnapshot,
    prefix: &str,
    is_last: bool,
) -> fmt::Result {
    let branch = if prefix.is_empty() {
        ""
    } else if is_last {
        "└── "
    } else {
        "├── "
    };

    write!(
        f,
        "{prefix}{branch}{:<28} {:>8} avg {:>8} p95 n={}",
        node.name,
        format_duration(node.wall.mean),
        format_duration(node.wall.p95),
        node.wall.samples,
    )?;

    if !node.children.is_empty() {
        let child_prefix = if prefix.is_empty() {
            String::new()
        } else if is_last {
            format!("{prefix}    ")
        } else {
            format!("{prefix}│   ")
        };

        for (index, child) in node.children.iter().enumerate() {
            writeln!(f)?;
            write_node(f, child, &child_prefix, index + 1 == node.children.len())?;
        }
    }

    Ok(())
}

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")
    }
}

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

    #[test]
    fn renders_tree_display() {
        let snapshot = CallTreeSnapshot {
            roots: vec![NodeSnapshot {
                name: "request".to_string(),
                target: "app".to_string(),
                module_path: None,
                line: None,
                total_calls: 2,
                wall: TimingStats {
                    samples: 2,
                    min: Duration::from_millis(8),
                    max: Duration::from_millis(12),
                    mean: Duration::from_millis(10),
                    p95: Duration::from_millis(12),
                },
                active: TimingStats {
                    samples: 2,
                    min: Duration::from_millis(4),
                    max: Duration::from_millis(8),
                    mean: Duration::from_millis(6),
                    p95: Duration::from_millis(8),
                },
                suspended: TimingStats {
                    samples: 2,
                    min: Duration::from_millis(2),
                    max: Duration::from_millis(4),
                    mean: Duration::from_millis(3),
                    p95: Duration::from_millis(4),
                },
                children: vec![],
            }],
        };

        let rendered = snapshot.to_string();
        assert!(rendered.contains("request"));
        assert!(rendered.contains("10.0ms avg"));
        assert!(rendered.contains("12.0ms p95 n=2"));
    }
}