|
| 1 | +# Samply Markers |
| 2 | + |
| 3 | +Emit profiler markers that [samply] records and displays in the [Firefox Profiler] UI. |
| 4 | + |
| 5 | +## Quick Demo |
| 6 | + |
| 7 | +The following Fibonacci Sequence example demonstrates recursive function call tracking. |
| 8 | + |
| 9 | +The [`samply_measure!`] macro emits an interval marker |
| 10 | +for each recursive call, allowing the profiler to display the complete call tree with timing information for every `fib(n)` invocation. |
| 11 | + |
| 12 | +**[macOS][fib-profile-macos] | [Ubuntu][fib-profile-ubuntu] | Windows (not yet supported)** |
| 13 | + |
| 14 | +```rust |
| 15 | +use samply_markers::prelude::*; |
| 16 | + |
| 17 | +fn fib(n: u64) -> u64 { |
| 18 | + samply_measure!({ |
| 19 | + match n { |
| 20 | + 0 | 1 => n, |
| 21 | + _ => fib(n - 1) + fib(n - 2), |
| 22 | + } |
| 23 | + }, marker: { |
| 24 | + name: format!("fib({n})"), |
| 25 | + }) |
| 26 | +} |
| 27 | + |
| 28 | +fn main() { |
| 29 | + let n = 10; |
| 30 | + let value = fib(n); |
| 31 | + println!("fib({n}) = {}", value); |
| 32 | +} |
| 33 | +``` |
| 34 | + |
| 35 | +## Project Configuration |
| 36 | + |
| 37 | +<br> **1)** Add [samply-markers] as a dependency to your project's `Cargo.toml`. |
| 38 | + |
| 39 | +```toml |
| 40 | +[dependencies] |
| 41 | +samply-markers = "{version}" |
| 42 | +``` |
| 43 | + |
| 44 | +<br> **2)** Add a `samply-markers` feature flag to your project's `Cargo.toml`. |
| 45 | + |
| 46 | +> [!NOTE] |
| 47 | +> Samply markers are designed to no-op by default, so they must be explicitly enabled in order |
| 48 | +> to see them in profiles. |
| 49 | +> |
| 50 | +> * Using [samply-markers] has effectively zero cost when not enabled. |
| 51 | +> * Using [samply-markers] does not pull in any additional dependencies when not enabled. |
| 52 | +
|
| 53 | +```toml |
| 54 | +[features] |
| 55 | +samply-markers = ["samply-markers/enabled"] |
| 56 | +``` |
| 57 | + |
| 58 | +<br> **3)** Add a `profiling` profile to your project's `Cargo.toml`. |
| 59 | + |
| 60 | +> [!NOTE] |
| 61 | +> This step is optional, but highly recommended for profiling with [samply]. |
| 62 | +
|
| 63 | +```toml |
| 64 | +[profile.profiling] |
| 65 | +inherits = "release" |
| 66 | +debug = true |
| 67 | +``` |
| 68 | + |
| 69 | +<br> **4)** Build your project for profiling, then record the resulting binary with [samply] to process the emitted markers. |
| 70 | + |
| 71 | +```text |
| 72 | +cargo build --profile profiling --features samply-markers |
| 73 | +samply record target/profiling/{binary} |
| 74 | +``` |
| 75 | + |
| 76 | +## Public API |
| 77 | + |
| 78 | +### The [`samply_marker!`] macro |
| 79 | + |
| 80 | +The [`samply_marker!`] macro is the foundational way to emit profiler markers. |
| 81 | +It creates and emits a [`SamplyMarker`] at the current location in your code, |
| 82 | +supporting both instant markers (a single point in time) and interval markers (a span of time). |
| 83 | + |
| 84 | +#### Instant Marker |
| 85 | + |
| 86 | +An instant marker marks a specific point in time: |
| 87 | + |
| 88 | +```rust |
| 89 | +use samply_markers::prelude::*; |
| 90 | + |
| 91 | +fn process_request(request_id: u32) { |
| 92 | + // Emit an instant marker at this exact moment |
| 93 | + samply_marker!({ name: format!("processing request {request_id}") }); |
| 94 | + |
| 95 | + // ... process the request. |
| 96 | +} |
| 97 | +``` |
| 98 | + |
| 99 | +#### Interval Marker |
| 100 | + |
| 101 | +An interval marker spans from a start time to the current time using [`SamplyTimestamp`]: |
| 102 | + |
| 103 | +```rust |
| 104 | +use samply_markers::prelude::*; |
| 105 | + |
| 106 | +fn query_database(query: &str) -> Vec<String> { |
| 107 | + let start = SamplyTimestamp::now(); |
| 108 | + |
| 109 | + // ... execute the database query. |
| 110 | + let results = vec![]; // Placeholder for actual results. |
| 111 | + |
| 112 | + // Emit an interval marker from start to now. |
| 113 | + samply_marker!({ |
| 114 | + name: format!("database query: {query}"), |
| 115 | + start_time: start, |
| 116 | + }); |
| 117 | + |
| 118 | + results |
| 119 | +} |
| 120 | +``` |
| 121 | + |
| 122 | +--- |
| 123 | + |
| 124 | +### The [`samply_timer!`] macro |
| 125 | + |
| 126 | +While [`samply_marker!`] requires manually providing a |
| 127 | +[`SamplyTimestamp`] for interval markers, |
| 128 | +the [`samply_timer!`] macro simplifies this pattern |
| 129 | +by wrapping the timestamp in a scoped RAII object. It creates a [`SamplyTimer`] |
| 130 | +that registers the time it was created and automatically emits the interval marker when dropped at the end of its scope. |
| 131 | + |
| 132 | +#### Automatic Interval |
| 133 | + |
| 134 | +The interval marker emits when the timer is dropped: |
| 135 | + |
| 136 | +```rust |
| 137 | +use samply_markers::prelude::*; |
| 138 | + |
| 139 | +fn expensive_computation() { |
| 140 | + let _timer = samply_timer!({ name: "expensive computation" }); |
| 141 | + |
| 142 | + // ... perform expensive work. |
| 143 | + |
| 144 | + // The interval marker is automatically emitted here when _timer is dropped. |
| 145 | +} |
| 146 | +``` |
| 147 | + |
| 148 | +#### Early Emit |
| 149 | + |
| 150 | +You can explicitly emit the interval marker before the end of the scope: |
| 151 | + |
| 152 | +```rust |
| 153 | +use samply_markers::prelude::*; |
| 154 | + |
| 155 | +fn process_with_cleanup() { |
| 156 | + let timer = samply_timer!({ name: "core processing" }); |
| 157 | + |
| 158 | + // ... perform core processing work. |
| 159 | + |
| 160 | + // Emit the interval marker now, excluding cleanup from the measurement. |
| 161 | + timer.emit(); |
| 162 | + |
| 163 | + // ... perform cleanup tasks (not included in the interval marker). |
| 164 | + |
| 165 | + // The interval marker will not emit a second time when dropped. |
| 166 | +} |
| 167 | +``` |
| 168 | + |
| 169 | +--- |
| 170 | + |
| 171 | +### The [`samply_measure!`] macro |
| 172 | + |
| 173 | +Building on the scoped approach of [`samply_timer!`], |
| 174 | +the [`samply_measure!`] macro further simplifies profiling |
| 175 | +by eliminating the need to create a scoped timer yourself. Instead, you wrap a code block, then its execution time is automatically measured with an interval marker. |
| 176 | + |
| 177 | +#### Measure Synchronous Code |
| 178 | + |
| 179 | +The value of the measured block expression is preserved: |
| 180 | + |
| 181 | +```rust |
| 182 | +use samply_markers::prelude::*; |
| 183 | + |
| 184 | +fn compute_sum(values: &[i32]) -> i32 { |
| 185 | + samply_measure!({ |
| 186 | + values.iter().sum() |
| 187 | + }, marker: { |
| 188 | + name: "compute sum", |
| 189 | + }) |
| 190 | +} |
| 191 | + |
| 192 | +let values = vec![1, 2, 3, 4, 5]; |
| 193 | +let result = compute_sum(&values); |
| 194 | +assert_eq!(result, 15); |
| 195 | +``` |
| 196 | + |
| 197 | +#### With `?` Operator |
| 198 | + |
| 199 | +The block's control flow is preserved, including early returns: |
| 200 | + |
| 201 | +```rust |
| 202 | +use samply_markers::prelude::*; |
| 203 | + |
| 204 | +fn parse_and_validate(data: &str) -> Result<u32, String> { |
| 205 | + samply_measure!({ |
| 206 | + let parsed = data.parse::<u32>() |
| 207 | + .map_err(|e| format!("parse error: {e}"))?; |
| 208 | + |
| 209 | + if parsed > 100 { |
| 210 | + return Err(String::from("value too large")); |
| 211 | + } |
| 212 | + |
| 213 | + Ok(parsed) |
| 214 | + }, marker: { |
| 215 | + name: "parse and validate", |
| 216 | + }) |
| 217 | +} |
| 218 | +``` |
| 219 | + |
| 220 | +#### Measure Asynchronous Code |
| 221 | + |
| 222 | +The macro works the same within asynchronous code. However, the clock does not stop between polls. |
| 223 | +The resulting interval will span the total time to completion, including time spent waiting: |
| 224 | + |
| 225 | +```rust |
| 226 | +use samply_markers::prelude::*; |
| 227 | + |
| 228 | +async fn fetch_data() -> String { |
| 229 | + String::from("data") |
| 230 | +} |
| 231 | + |
| 232 | +async fn process_data(data_id: u64) -> String { |
| 233 | + samply_measure!({ |
| 234 | + let data = fetch_data().await; |
| 235 | + format!("Processed: {data} (id: {data_id})") |
| 236 | + }, marker: { |
| 237 | + name: format!("process data {data_id}"), |
| 238 | + }) |
| 239 | +} |
| 240 | +``` |
| 241 | + |
| 242 | +#### Create a New Async Block |
| 243 | + |
| 244 | +Use the `async` keyword to create a new async block, which allows the `?` |
| 245 | +operator to return from this measured block instead of the enclosing function: |
| 246 | + |
| 247 | +```rust |
| 248 | +use samply_markers::prelude::*; |
| 249 | + |
| 250 | +async fn read_file(path: &str) -> Option<String> { |
| 251 | + Some(String::from("100,200")) |
| 252 | +} |
| 253 | + |
| 254 | +async fn load_config(path: &str) -> (u32, u32) { |
| 255 | + let config = samply_measure!(async { |
| 256 | + let contents = read_file(path).await?; |
| 257 | + let mut parts = contents.split(','); |
| 258 | + |
| 259 | + let x = parts.next()?.parse::<u32>().ok()?; |
| 260 | + let y = parts.next()?.parse::<u32>().ok()?; |
| 261 | + |
| 262 | + Some((x, y)) |
| 263 | + }, marker: { |
| 264 | + name: "load config", |
| 265 | + }) |
| 266 | + .await; |
| 267 | + |
| 268 | + config.unwrap_or((0, 0)) |
| 269 | +} |
| 270 | +``` |
| 271 | + |
| 272 | +## Example |
| 273 | + |
| 274 | +Here's a complete example demonstrating everything in context: |
| 275 | + |
| 276 | + |
| 277 | +**[macOS] | [Ubuntu] | Windows (not yet supported)** |
| 278 | + |
| 279 | +```rust |
| 280 | +use samply_markers::prelude::*; |
| 281 | + |
| 282 | +async fn fetch_url(url: &str) -> (String, Option<String>) { |
| 283 | + // Emit an interval marker for the time it takes to fetch. |
| 284 | + let result = samply_measure!(async { |
| 285 | + let response = reqwest::get(url).await?; |
| 286 | + response.text().await |
| 287 | + }, marker: { |
| 288 | + name: format!("fetch {url}"), |
| 289 | + }) |
| 290 | + .await; |
| 291 | + |
| 292 | + match result { |
| 293 | + Ok(content) => { |
| 294 | + println!(" ✓ Fetched {url} ({} bytes)", content.len()); |
| 295 | + (String::from(url), Some(content)) |
| 296 | + } |
| 297 | + Err(error) => { |
| 298 | + // Emit an instant marker any time a fetch fails. |
| 299 | + samply_marker!({ name: format!("fetch failed: {url}") }); |
| 300 | + println!(" ✗ Failed to fetch {url}: {error}"); |
| 301 | + (String::from(url), None) |
| 302 | + } |
| 303 | + } |
| 304 | +} |
| 305 | + |
| 306 | +#[tokio::main] |
| 307 | +async fn main() { |
| 308 | + // Create a timer that will span the entirety of main(). |
| 309 | + // The timer will emit an interval marker when it is dropped at the end of the scope. |
| 310 | + let _main_timer = samply_timer!({ name: "main()" }); |
| 311 | + |
| 312 | + println!("\nStarting samply-markers demo...\n"); |
| 313 | + |
| 314 | + std::thread::sleep(std::time::Duration::from_millis(200)); |
| 315 | + |
| 316 | + let urls = &[ |
| 317 | + "https://example.com", |
| 318 | + "https://fail.invalid", |
| 319 | + "https://fail.invalid", |
| 320 | + "https://en.wikipedia.org/wiki/Firefox", |
| 321 | + "https://fail.invalid", |
| 322 | + "https://github.com/nordzilla", |
| 323 | + ]; |
| 324 | + |
| 325 | + println!("\n=== Sequential Fetching ===\n"); |
| 326 | + |
| 327 | + // Emit an interval marker for the total time to fetch all URLs sequentially. |
| 328 | + samply_measure!({ |
| 329 | + for url in urls { |
| 330 | + fetch_url(url).await; |
| 331 | + } |
| 332 | + }, marker: { |
| 333 | + name: "fetch all URLs sequentially", |
| 334 | + }); |
| 335 | + |
| 336 | + std::thread::sleep(std::time::Duration::from_millis(200)); |
| 337 | + |
| 338 | + println!("\n=== Concurrent Fetching ===\n"); |
| 339 | + |
| 340 | + // Emit an interval marker for the total time to fetch all URLs concurrently. |
| 341 | + samply_measure!({ |
| 342 | + futures::future::join_all( |
| 343 | + urls.iter().map(|url| fetch_url(url)) |
| 344 | + ).await; |
| 345 | + }, marker: { |
| 346 | + name: "fetch all URLs concurrently", |
| 347 | + }); |
| 348 | + |
| 349 | + std::thread::sleep(std::time::Duration::from_millis(200)); |
| 350 | + |
| 351 | + println!("\nDemo completed!\n"); |
| 352 | +} |
| 353 | +``` |
| 354 | + |
| 355 | +[`samply_marker!`]: https://docs.rs/samply-markers/latest/samply_markers/macro.samply_marker.html |
| 356 | +[`samply_measure!`]: https://docs.rs/samply-markers/latest/samply_markers/macro.samply_measure.html |
| 357 | +[`samply_timer!`]: https://docs.rs/samply-markers/latest/samply_markers/macro.samply_timer.html |
| 358 | +[`SamplyMarker`]: https://docs.rs/samply-markers/latest/samply_markers/marker/struct.SamplyMarker.html |
| 359 | +[`SamplyTimer`]: https://docs.rs/samply-markers/latest/samply_markers/marker/struct.SamplyTimer.html |
| 360 | +[`SamplyTimestamp`]: https://docs.rs/samply-markers/latest/samply_markers/marker/struct.SamplyTimestamp.html |
| 361 | +[examples directory]: https://github.com/mstange/samply/tree/main/samply-markers/examples |
| 362 | +[fib-profile-macos]: https://share.firefox.dev/3WYOibS |
| 363 | +[fib-profile-ubuntu]: https://share.firefox.dev/3M31SZq |
| 364 | +[Firefox Profiler]: https://profiler.firefox.com/ |
| 365 | +[macOS]: https://share.firefox.dev/48eHTj8 |
| 366 | +[samply]: https://github.com/mstange/samply?tab=readme-ov-file#samply |
| 367 | +[samply-markers]: https://crates.io/crates/samply-markers |
| 368 | +[Ubuntu]: https://share.firefox.dev/3LzT6lJ |
0 commit comments