hotpath 0.26.0

One profiler for CPU, time, memory, SQL, and async code - quickly find and debug performance bottlenecks.
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
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237

//! Integration tests for per-route memory profiling: bytes allocated while a
//! handler future is polled are attributed to the matched route and reported
//! as a second `server` sub-table / the JSON `alloc` object.
//!
//! These run the `test-axum` `route_alloc` example as a subprocess with
//! `hotpath-alloc` and assert on the JSON report printed when the guard drops.
#[cfg(all(test, feature = "hotpath"))]
pub mod tests {
    use hotpath::json::{JsonReport, JsonServerEntry};
    use std::process::Command;

    const BIG_BYTES: f64 = 1024.0 * 1024.0;
    /// `GET /block` allocates 128 KiB before its `.await` and 256 KiB after.
    const BLOCK_BYTES: f64 = (128.0 + 256.0) * 1024.0;

    fn run_example_raw(envs: &[(&str, &str)]) -> String {
        let mut cmd = Command::new("cargo");
        cmd.args([
            "run",
            "-p",
            "test-axum",
            "--example",
            "route_alloc",
            "--features",
            "hotpath,hotpath-alloc",
        ]);
        for (key, value) in envs {
            cmd.env(key, value);
        }
        let output = cmd.output().expect("Failed to execute command");
        assert!(
            output.status.success(),
            "Command failed with status: {}\nstderr:\n{}",
            output.status,
            String::from_utf8_lossy(&output.stderr),
        );
        String::from_utf8_lossy(&output.stdout).into_owned()
    }

    fn run_example(envs: &[(&str, &str)]) -> JsonReport {
        let mut envs = envs.to_vec();
        envs.push(("HOTPATH_OUTPUT_FORMAT", "json"));
        let stdout = run_example_raw(&envs);
        let json_start = stdout.find('{').expect("No JSON report in output");
        serde_json::Deserializer::from_str(&stdout[json_start..])
            .into_iter::<JsonReport>()
            .next()
            .expect("No JSON value in output")
            .expect("Failed to parse JSON report")
    }

    fn by_route<'a>(entries: &'a [JsonServerEntry], route: &str) -> &'a JsonServerEntry {
        entries
            .iter()
            .find(|e| e.route == route)
            .unwrap_or_else(|| panic!("{route} server entry missing: {entries:?}"))
    }

    #[test]
    fn test_route_alloc_attributes_bytes_per_route() {
        let report = run_example(&[]);
        let server = report.server.expect("No server section in report");
        assert!(
            server.total_alloc_bytes as f64 >= 3.0 * BIG_BYTES,
            "{server:?}"
        );

        let big = by_route(&server.data, "GET /big");
        assert_eq!(big.count, 3);
        let alloc = big.alloc.as_ref().expect("GET /big alloc missing");
        // The handler's 1 MiB body, plus whatever the framework adds.
        let bytes = alloc.bytes_per_request.expect("bytes_per_request");
        assert!(bytes >= BIG_BYTES, "{alloc:?}");
        assert!(alloc.allocs_per_request.unwrap() >= 1.0, "{alloc:?}");
        assert!(alloc.total_bytes as f64 >= 3.0 * BIG_BYTES, "{alloc:?}");
        assert!(alloc.percentiles.contains_key("p95"), "{alloc:?}");

        // Framework overhead only: far below the 1 MiB body.
        let small = by_route(&server.data, "GET /small");
        assert_eq!(small.count, 4);
        let alloc = small.alloc.as_ref().expect("GET /small alloc missing");
        let bytes = alloc.bytes_per_request.expect("bytes_per_request");
        assert!(bytes < 64.0 * 1024.0, "{alloc:?}");

        // Unmatched requests carry no route scope, so no memory.
        let missing = by_route(&server.data, "GET <unmatched>");
        assert_eq!(missing.count, 1);
        let alloc = missing.alloc.as_ref().expect("unmatched alloc object");
        assert_eq!(alloc.bytes_per_request, None, "{alloc:?}");
        assert_eq!(alloc.allocs_per_request, None, "{alloc:?}");
        assert_eq!(alloc.total_bytes, 0, "{alloc:?}");
    }

    /// A `measure_block!` spanning an `.await` leaves the block's allocation
    /// frame open when the route scope closes for that poll. Both halves count
    /// towards the route, and neither counts twice.
    #[test]
    fn test_route_alloc_counts_block_spanning_await() {
        let report = run_example(&[]);
        let server = report.server.expect("No server section in report");

        let block = by_route(&server.data, "GET /block");
        assert_eq!(block.count, 2);
        let alloc = block.alloc.as_ref().expect("GET /block alloc missing");
        let bytes = alloc.bytes_per_request.expect("bytes_per_request");
        assert!(bytes >= BLOCK_BYTES, "{alloc:?}");
        assert!(bytes < 1.5 * BLOCK_BYTES, "{alloc:?}");
    }

    /// The route counts the block's bytes inclusively while the block itself
    /// keeps reporting them as its own exclusive total: the scope adds no frame
    /// to the allocation stack, so function accounting is unchanged.
    #[test]
    fn test_route_alloc_block_keeps_function_totals_exclusive() {
        let report = run_example(&[("HOTPATH_REPORT", "server,functions-alloc")]);
        let functions = report
            .functions_alloc
            .expect("No functions_alloc section in report");
        let block = functions
            .data
            .iter()
            .find(|f| f.name == "block_await")
            .unwrap_or_else(|| panic!("block_await missing: {:?}", functions.data));
        assert_eq!(block.calls, 2, "{block:?}");
        // 128 KiB before the await plus 256 KiB after, both in the block's own
        // frame, counted once.
        assert!(
            block.avg.starts_with("384.") && block.avg.ends_with("KB"),
            "{block:?}"
        );

        let server = report.server.expect("No server section in report");
        let alloc = by_route(&server.data, "GET /block")
            .alloc
            .as_ref()
            .expect("GET /block alloc missing")
            .clone();
        assert!(alloc.bytes_per_request.unwrap() >= BLOCK_BYTES, "{alloc:?}");
    }

    /// `HOTPATH_ALLOC_CUMULATIVE=1` makes function frames inclusive by
    /// propagating each pop into its parent. Route totals are inclusive either
    /// way, so they must not pick the same bytes up twice.
    #[test]
    fn test_route_alloc_cumulative_mode_does_not_double_count() {
        let report = run_example(&[("HOTPATH_ALLOC_CUMULATIVE", "1")]);
        let server = report.server.expect("No server section in report");

        let big = by_route(&server.data, "GET /big")
            .alloc
            .as_ref()
            .expect("GET /big alloc missing")
            .clone();
        let bytes = big.bytes_per_request.expect("bytes_per_request");
        assert!(bytes >= BIG_BYTES && bytes < 1.5 * BIG_BYTES, "{big:?}");

        let block = by_route(&server.data, "GET /block")
            .alloc
            .as_ref()
            .expect("GET /block alloc missing")
            .clone();
        let bytes = block.bytes_per_request.expect("bytes_per_request");
        assert!(
            bytes >= BLOCK_BYTES && bytes < 1.5 * BLOCK_BYTES,
            "{block:?}"
        );
    }

    #[test]
    fn test_route_alloc_server_table_columns() {
        let stdout = run_example_raw(&[]);
        for expected in ["Allocs/req", "GET /big", "GET /small"] {
            assert!(
                stdout.contains(expected),
                "Expected:\n{expected}\n\nGot:\n{stdout}",
            );
        }
        // Second occurrence of the route is the memory sub-table row:
        // Route | Calls | Allocs/req | Avg | ... | Total | % Total
        let big_rows: Vec<&str> = stdout.lines().filter(|l| l.contains("GET /big")).collect();
        assert_eq!(big_rows.len(), 2, "{stdout}");
        let cells: Vec<&str> = big_rows[1].split('|').map(str::trim).collect();
        assert_eq!(&cells[1..3], &["GET /big", "3"], "{}", big_rows[1]);
        assert!(cells[4].ends_with(" MB"), "avg bytes: {}", big_rows[1]);

        let missing_rows: Vec<&str> = stdout
            .lines()
            .filter(|l| l.contains("GET <unmatched>"))
            .collect();
        assert_eq!(missing_rows.len(), 2, "{stdout}");
        let cells: Vec<&str> = missing_rows[1].split('|').map(str::trim).collect();
        assert_eq!(
            &cells[1..5],
            &["GET <unmatched>", "1", "-", "-"],
            "{}",
            missing_rows[1]
        );
    }

    #[test]
    fn test_route_alloc_nested_layer_reports_once() {
        let report = run_example(&[("NESTED", "1")]);
        let server = report.server.expect("No server section in report");
        // Three requests through two layers: counted once, by the outer one,
        // with the nested handler's bytes.
        let nested = by_route(&server.data, "GET /nested/big");
        assert_eq!(nested.count, 3, "{:?}", server.data);
        let total: u64 = server.data.iter().map(|e| e.count).sum();
        assert_eq!(total, 4, "{:?}", server.data);
        let alloc = nested.alloc.as_ref().expect("nested alloc missing");
        assert!(alloc.bytes_per_request.unwrap() >= BIG_BYTES, "{alloc:?}");

        // Still counted once when no route scope exists at all.
        let report = run_example(&[("NESTED", "1"), ("HOTPATH_ROUTE_SCOPE", "0")]);
        let server = report.server.expect("No server section in report");
        assert_eq!(
            by_route(&server.data, "GET /nested/big").count,
            3,
            "{:?}",
            server.data
        );
        let total: u64 = server.data.iter().map(|e| e.count).sum();
        assert_eq!(total, 4, "{:?}", server.data);
    }

    #[test]
    fn test_route_alloc_disabled_scope_reports_nothing() {
        let report = run_example(&[("HOTPATH_ROUTE_SCOPE", "0")]);
        let server = report.server.expect("No server section in report");
        assert_eq!(server.total_alloc_bytes, 0, "{server:?}");
        for entry in &server.data {
            let alloc = entry.alloc.as_ref().expect("alloc object present");
            assert_eq!(alloc.bytes_per_request, None, "{entry:?}");
            assert_eq!(alloc.total_bytes, 0, "{entry:?}");
        }
    }
}