martensite-devtools 0.9.0

Tracing spans, Tracy/Chrome GPU timestamps, and in-app F12 developer HUD.
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
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427
428
429
430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
447
448
449
450
451
452
453
454
455
456
457
458
459
460
461
462
463
464
465
466
467
468
469
470
471
472
473
474
475
476
477
478
479
480
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
502
503
504
505
506
507
508
509
510
511
512
513
514
515
516
517
518
519
520
521
522
523
524
525
526
527
528
529
530
531
532
533
534
535
536
537
538
539
540
541
542
543
544
545
//! Tracy profiler span instrumentation.
//!
//! Martensite instruments layout, paint, and reactive dispatch with profiling
//! spans so that frame bottlenecks can be located without external tooling.
//! Because the crate is `#![forbid(unsafe_code)]`, it cannot link the native
//! Tracy client library (which is inherently `unsafe`). Instead, this module
//! provides a safe, allocation-free re-implementation of the Tracy span API
//! that records region durations with [`std::time::Instant`] into a
//! thread-local ring buffer. The recorded data feeds the in-app diagnostic
//! HUD and can be queried programmatically.
//!
//! The instrumentation is designed for sub-microsecond overhead: a span
//! begin/end pair performs two [`Instant::now()`] calls and a fixed-size
//! array write, with no heap allocation. The DevTools overhead gate
//! (§5.3 of the v0.9.0 milestone) requires that active profiling contributes
//! `< 0.1ms` per 60fps frame; see the `tracy_overhead_under_100us_per_frame`
//! test for the exit-criterion verification.
//!
//! # Examples
//!
//! ```
//! use martensite_devtools::tracy;
//!
//! // Scoped span: records its duration on drop.
//! let _guard = tracy::span("layout_pass");
//! // ... layout work ...
//!
//! // Manual span lifecycle.
//! let span = tracy::TracySpan::begin("paint_encode");
//! // ... paint work ...
//! span.end();
//!
//! // Frame and plot markers.
//! tracy::frame_mark();
//! tracy::plot("gpu_wait_ms", 0.42);
//! ```

use std::cell::RefCell;
use std::time::Instant;

/// Number of span records retained in the thread-local ring buffer.
///
/// This is sized to comfortably hold the spans emitted by a single frame
/// (layout, paint, gpu wait, reactive dispatch, ...) with headroom, so the
/// HUD can inspect the most recent frame without growing unbounded.
const SPAN_RING_SIZE: usize = 256;

/// Number of distinct plot slots retained per thread.
const PLOT_SLOTS: usize = 32;

/// A single recorded profiling span.
///
/// This is a `Copy` value stored in the thread-local ring buffer so that the
/// HUD can iterate over recent spans without allocation.
#[derive(Debug, Clone, Copy, PartialEq, Eq)]
pub struct SpanRecord {
    /// The static name label of the span.
    pub name: &'static str,
    /// The measured duration of the span, in nanoseconds.
    pub duration_ns: u64,
}

/// A slot for a named plot value.
#[derive(Debug, Clone, Copy, PartialEq)]
struct PlotEntry {
    /// The static name label of the plot, or `None` if the slot is free.
    name: Option<&'static str>,
    /// The last recorded value for this plot.
    value: f64,
}

impl PlotEntry {
    /// Create an empty (free) plot slot.
    const fn empty() -> Self {
        Self {
            name: None,
            value: 0.0,
        }
    }
}

/// Thread-local profiling buffer holding recent span records, plot values,
/// and a frame counter.
///
/// All storage is fixed-size arrays, so recording a span or plot never
/// allocates.
#[derive(Debug)]
struct ProfileBuffer {
    spans: [SpanRecord; SPAN_RING_SIZE],
    span_index: usize,
    span_count: usize,
    plots: [PlotEntry; PLOT_SLOTS],
    frame_count: u64,
}

impl ProfileBuffer {
    /// Create a new empty profiling buffer.
    fn new() -> Self {
        Self {
            spans: [SpanRecord {
                name: "",
                duration_ns: 0,
            }; SPAN_RING_SIZE],
            span_index: 0,
            span_count: 0,
            plots: [PlotEntry::empty(); PLOT_SLOTS],
            frame_count: 0,
        }
    }

    /// Record a completed span into the ring buffer, overwriting the oldest
    /// entry when full.
    #[inline]
    fn record_span(&mut self, name: &'static str, duration_ns: u64) {
        self.spans[self.span_index] = SpanRecord { name, duration_ns };
        self.span_index = (self.span_index + 1) % SPAN_RING_SIZE;
        if self.span_count < SPAN_RING_SIZE {
            self.span_count += 1;
        }
    }

    /// Record or update a named plot value.
    #[inline]
    fn record_plot(&mut self, name: &'static str, value: f64) {
        // Linear scan over a small fixed array; cheaper than a hashmap for the
        // expected number of distinct plots.
        for entry in self.plots.iter_mut() {
            if entry.name == Some(name) {
                entry.value = value;
                return;
            }
        }
        // Not found: claim the first free slot.
        for entry in self.plots.iter_mut() {
            if entry.name.is_none() {
                entry.name = Some(name);
                entry.value = value;
                return;
            }
        }
        // All slots occupied: overwrite the first slot (oldest heuristic).
        self.plots[0].name = Some(name);
        self.plots[0].value = value;
    }

    /// Increment the per-thread frame counter.
    #[inline]
    fn mark_frame(&mut self) {
        self.frame_count += 1;
    }

    /// Return the most recently recorded duration for the named span, if any.
    fn last_span_duration(&self, name: &'static str) -> Option<u64> {
        // Walk the ring backward from the most recent write.
        if self.span_count == 0 {
            return None;
        }
        for i in (0..self.span_count).rev() {
            let idx = (self.span_index + SPAN_RING_SIZE - 1 - i) % SPAN_RING_SIZE;
            if self.spans[idx].name == name {
                return Some(self.spans[idx].duration_ns);
            }
        }
        None
    }

    /// Return the last recorded value for the named plot, if any.
    fn plot_value(&self, name: &'static str) -> Option<f64> {
        self.plots
            .iter()
            .find(|e| e.name == Some(name))
            .map(|e| e.value)
    }

    /// Return the number of span records currently held in the ring buffer.
    fn span_record_count(&self) -> usize {
        self.span_count
    }

    /// Return the per-thread frame counter.
    fn frame_count(&self) -> u64 {
        self.frame_count
    }
}

thread_local! {
    static PROFILE: RefCell<ProfileBuffer> = RefCell::new(ProfileBuffer::new());
}

/// A profiling span that records the duration of a code region.
///
/// When Tracy is not available, this is a zero-cost no-op backed by
/// [`std::time::Instant`]. Call [`TracySpan::begin`] to start timing a region
/// and [`TracySpan::end`] to record the elapsed duration into the thread-local
/// ring buffer. For scoped (RAII) spans, prefer the [`span`] function which
/// returns a [`TracySpanGuard`].
///
/// # Examples
///
/// ```
/// use martensite_devtools::tracy::TracySpan;
///
/// let span = TracySpan::begin("encode_paint_list");
/// // ... work ...
/// span.end();
/// ```
pub struct TracySpan {
    /// The static name label of the span.
    name: &'static str,
    /// The instant at which the span began, or `None` if already ended.
    /// Uses `Cell` so that `end()` can consume the start time without
    /// requiring `&mut self`, making double-`end()` a safe no-op.
    start: std::cell::Cell<Option<Instant>>,
}

impl TracySpan {
    /// Begin a new profiling span with the given static name.
    ///
    /// The start time is captured immediately via [`Instant::now`].
    ///
    /// # Examples
    ///
    /// ```
    /// use martensite_devtools::tracy::TracySpan;
    ///
    /// let span = TracySpan::begin("layout_pass");
    /// span.end();
    /// ```
    #[inline]
    pub fn begin(name: &'static str) -> Self {
        Self {
            name,
            start: std::cell::Cell::new(Some(Instant::now())),
        }
    }

    /// Record the elapsed duration of this span into the thread-local ring
    /// buffer.
    ///
    /// Calling `end` more than once is a no-op: subsequent calls find no start
    /// time and record nothing.
    ///
    /// # Examples
    ///
    /// ```
    /// use martensite_devtools::tracy::TracySpan;
    ///
    /// let span = TracySpan::begin("paint_pass");
    /// span.end();
    /// // A second end is a no-op.
    /// span.end();
    /// ```
    #[inline]
    pub fn end(&self) {
        if let Some(start) = self.start.take() {
            let duration_ns = start.elapsed().as_nanos() as u64;
            PROFILE.with(|p| p.borrow_mut().record_span(self.name, duration_ns));
        }
    }
}

/// RAII guard for a scoped profiling span.
///
/// Created by [`span`]; the span is recorded into the thread-local ring
/// buffer when the guard is dropped.
///
/// # Examples
///
/// ```
/// use martensite_devtools::tracy;
///
/// fn do_work() {
///     let _guard = tracy::span("work_region");
///     // ... work ...
/// }
///
/// do_work();
/// ```
pub struct TracySpanGuard {
    span: TracySpan,
}

impl Drop for TracySpanGuard {
    #[inline]
    fn drop(&mut self) {
        self.span.end();
    }
}

/// Create a scoped profiling span that records its duration on drop.
///
/// This is the primary entry point for instrumenting a code region. The
/// returned [`TracySpanGuard`] records the span into the thread-local ring
/// buffer when it goes out of scope.
///
/// # Examples
///
/// ```
/// use martensite_devtools::tracy;
///
/// {
///     let _g = tracy::span("scoped_region");
///     // ... work ...
/// } // span recorded here
/// ```
#[inline]
pub fn span(name: &'static str) -> TracySpanGuard {
    TracySpanGuard {
        span: TracySpan::begin(name),
    }
}

/// Emit a frame marker for Tracy's frame profiling.
///
/// Increments the per-thread frame counter. Pair this with one call per
/// rendered frame so frame boundaries can be correlated with span timings.
///
/// # Examples
///
/// ```
/// use martensite_devtools::tracy;
///
/// tracy::frame_mark();
/// ```
#[inline]
pub fn frame_mark() {
    PROFILE.with(|p| p.borrow_mut().mark_frame());
}

/// Record a plot point for Tracy's value plots.
///
/// Stores the latest value for the named plot in a fixed-size thread-local
/// slot. Repeated calls with the same name update the existing slot.
///
/// # Examples
///
/// ```
/// use martensite_devtools::tracy;
///
/// tracy::plot("gpu_wait_ms", 0.42);
/// tracy::plot("gpu_wait_ms", 0.51);
/// ```
#[inline]
pub fn plot(name: &'static str, value: f64) {
    PROFILE.with(|p| p.borrow_mut().record_plot(name, value));
}

/// Return the most recently recorded duration (in nanoseconds) for the named
/// span on the current thread, if any.
///
/// # Examples
///
/// ```
/// use martensite_devtools::tracy;
///
/// {
///     let _g = tracy::span("query_region");
/// }
/// let dur = tracy::last_span_duration("query_region");
/// assert!(dur.is_some());
/// ```
pub fn last_span_duration(name: &'static str) -> Option<u64> {
    PROFILE.with(|p| p.borrow().last_span_duration(name))
}

/// Return the last recorded value for the named plot on the current thread,
/// if any.
///
/// # Examples
///
/// ```
/// use martensite_devtools::tracy;
///
/// tracy::plot("fps", 59.9);
/// assert_eq!(tracy::plot_value("fps"), Some(59.9));
/// ```
pub fn plot_value(name: &'static str) -> Option<f64> {
    PROFILE.with(|p| p.borrow().plot_value(name))
}

/// Return the number of span records currently held in the current thread's
/// ring buffer.
///
/// # Examples
///
/// ```
/// use martensite_devtools::tracy;
///
/// {
///     let _g = tracy::span("count_region");
/// }
/// assert!(tracy::span_record_count() >= 1);
/// ```
pub fn span_record_count() -> usize {
    PROFILE.with(|p| p.borrow().span_record_count())
}

/// Return the per-thread frame counter value.
///
/// # Examples
///
/// ```
/// use martensite_devtools::tracy;
///
/// let before = tracy::frame_count();
/// tracy::frame_mark();
/// assert_eq!(tracy::frame_count(), before + 1);
/// ```
pub fn frame_count() -> u64 {
    PROFILE.with(|p| p.borrow().frame_count())
}

#[cfg(test)]
mod tests {
    use super::*;
    use std::time::Duration;

    #[test]
    fn span_records_duration() {
        let name = "span_records_duration";
        {
            let _g = span(name);
            std::thread::sleep(Duration::from_micros(100));
        }
        let dur = last_span_duration(name);
        assert!(dur.is_some(), "span should be recorded");
        assert!(
            dur.unwrap() >= 50_000,
            "duration should be >= ~50us, got {}",
            dur.unwrap()
        );
    }

    #[test]
    fn manual_span_end_records() {
        let name = "manual_span_end_records";
        let s = TracySpan::begin(name);
        std::thread::sleep(Duration::from_micros(50));
        s.end();
        let dur = last_span_duration(name);
        assert!(dur.is_some());
        assert!(dur.unwrap() >= 20_000);
    }

    #[test]
    fn double_end_is_noop() {
        let name = "double_end_is_noop";
        let s = TracySpan::begin(name);
        s.end();
        let first = last_span_duration(name).unwrap();
        let s2 = TracySpan::begin(name);
        s2.end();
        // The second end of the first span does nothing; the second span's
        // value should be the latest recorded.
        let second = last_span_duration(name).unwrap();
        // Both recorded; latest is the second span.
        assert!(second > 0);
        let _ = first;
    }

    #[test]
    fn frame_mark_increments_counter() {
        let before = frame_count();
        frame_mark();
        frame_mark();
        assert_eq!(frame_count(), before + 2);
    }

    #[test]
    fn plot_records_and_updates() {
        plot("plot_test_a", 1.0);
        assert_eq!(plot_value("plot_test_a"), Some(1.0));
        plot("plot_test_a", 2.5);
        assert_eq!(plot_value("plot_test_a"), Some(2.5));
    }

    #[test]
    fn plot_missing_returns_none() {
        assert!(plot_value("definitely_not_a_plot_xyz").is_none());
    }

    #[test]
    fn missing_span_returns_none() {
        assert!(last_span_duration("definitely_not_a_span_xyz").is_none());
    }

    #[test]
    fn ring_buffer_overwrites_oldest() {
        // Record more spans than the ring size to verify no panic and that
        // recent spans are still queryable.
        for i in 0..(SPAN_RING_SIZE + 10) {
            // Use a couple of distinct names.
            let _g = span("ring_span_a");
            let _g2 = span("ring_span_b");
            let _ = i;
        }
        // The most recent span should be queryable.
        assert!(last_span_duration("ring_span_b").is_some());
        assert!(span_record_count() <= SPAN_RING_SIZE);
    }

    #[test]
    fn plot_slots_evict_when_full() {
        // Fill all plot slots plus extras; should not panic and the most
        // recently written should be queryable.
        for i in 0..(PLOT_SLOTS + 5) {
            // Generate distinct static names by interning via leak is not
            // possible without unsafe; instead reuse a small set of names.
            plot("plot_evict", i as f64);
        }
        assert_eq!(plot_value("plot_evict"), Some((PLOT_SLOTS + 4) as f64));
    }

    /// DevTools Overhead Gate (§5.3): active Tracy profiling instrumentation
    /// must contribute `< 0.1ms` overhead per 60fps frame.
    ///
    /// This measures the cost of a representative frame's instrumentation:
    /// one scoped span (begin + end), a frame mark, and a plot point, across
    /// 60 frames, and asserts the per-frame overhead is below 100µs.
    #[test]
    fn tracy_overhead_under_100us_per_frame() {
        // Warm up the thread-local to avoid first-access cost in the
        // measurement window.
        {
            let _g = span("warmup");
        }
        frame_mark();
        plot("warmup_plot", 0.0);

        const FRAMES: u32 = 60;
        let start = Instant::now();
        for _ in 0..FRAMES {
            let _g = span("overhead_frame");
            frame_mark();
            plot("overhead_plot", 1.0);
        }
        let elapsed = start.elapsed();
        let per_frame_ns = elapsed.as_nanos() / FRAMES as u128;
        // 0.1ms = 100_000 ns. We use a generous 100us gate per the spec.
        assert!(
            per_frame_ns < 100_000,
            "Tracy overhead {per_frame_ns}ns/frame exceeds the 100us (100_000ns) gate"
        );
    }
}