gemini_adk_rs/live/
telemetry.rs

1//! Lightweight session telemetry — atomic fast-lane counters + periodic aggregation.
2//!
3//! All hot-path operations (counter increments, timestamp recording) are lock-free
4//! and zero-allocation (~1ns per call). Aggregation only happens periodically on
5//! the telemetry lane or at turn boundaries, ensuring no impact on the
6//! latency-sensitive audio pipeline.
7//!
8//! The number a voice product is judged on is **response latency**: the time
9//! from the user's end of speech to the model's first audio byte. It is
10//! recorded per turn into [`LatencyStats`] — last, min, max, mean, the p50/
11//! p90/p99 of recent turns, and a fixed-bucket histogram — and read through
12//! [`SessionTelemetry::latency`] or [`SessionTelemetry::snapshot`].
13
14use std::fmt;
15use std::sync::atomic::{
16    AtomicBool, AtomicU64,
17    Ordering::{Acquire, Relaxed, Release},
18};
19use std::time::{Duration, Instant};
20
21use serde::{Deserialize, Serialize};
22use serde_json::json;
23
24/// Upper bounds, in milliseconds, of the response-latency histogram buckets.
25///
26/// A final open bucket collects everything above the last bound. The bounds
27/// are denser where voice products live (150–1000 ms) and coarser beyond.
28pub const LATENCY_BUCKETS_MS: [u64; 17] = [
29    50, 100, 150, 200, 300, 400, 500, 650, 800, 1000, 1300, 1600, 2000, 2500, 3000, 4000, 5000,
30];
31
32/// Number of most-recent samples the percentiles are computed over.
33///
34/// Percentiles are exact over this window (nearest-rank on a sorted copy),
35/// which covers every turn of all but the longest sessions; the histogram
36/// carries the full session.
37pub const LATENCY_RECENT_WINDOW: usize = 256;
38
39const BUCKET_COUNT: usize = LATENCY_BUCKETS_MS.len() + 1;
40
41/// One bucket of the response-latency histogram.
42#[derive(Debug, Clone, Copy, PartialEq, Eq, Serialize, Deserialize)]
43pub struct LatencyBucket {
44    /// Inclusive upper bound in milliseconds; `None` for the open top bucket.
45    pub upper_ms: Option<u64>,
46    /// Number of turns whose latency fell in this bucket.
47    pub count: u64,
48}
49
50/// Response-latency distribution for the session so far.
51///
52/// All durations are whole milliseconds. Every field is `0` until the first
53/// turn has been measured (`count == 0`).
54#[derive(Debug, Clone, PartialEq, Eq, Default, Serialize, Deserialize)]
55pub struct LatencyStats {
56    /// Number of measured turns.
57    pub count: u64,
58    /// Latency of the most recent turn.
59    pub last_ms: u64,
60    /// Fastest turn.
61    pub min_ms: u64,
62    /// Slowest turn.
63    pub max_ms: u64,
64    /// Mean over all measured turns.
65    pub mean_ms: u64,
66    /// Median of the most recent [`LATENCY_RECENT_WINDOW`] turns.
67    pub p50_ms: u64,
68    /// 90th percentile of the most recent [`LATENCY_RECENT_WINDOW`] turns.
69    pub p90_ms: u64,
70    /// 99th percentile of the most recent [`LATENCY_RECENT_WINDOW`] turns.
71    pub p99_ms: u64,
72    /// Full-session histogram, one entry per [`LATENCY_BUCKETS_MS`] bound plus
73    /// the open top bucket.
74    pub histogram: Vec<LatencyBucket>,
75}
76
77impl fmt::Display for LatencyStats {
78    /// One line, fit for a log: `turns=12 last=420ms p50=380ms p90=610ms max=900ms`.
79    fn fmt(&self, f: &mut fmt::Formatter<'_>) -> fmt::Result {
80        if self.count == 0 {
81            return write!(f, "turns=0 (no response measured yet)");
82        }
83        write!(
84            f,
85            "turns={} last={}ms p50={}ms p90={}ms p99={}ms min={}ms max={}ms",
86            self.count,
87            self.last_ms,
88            self.p50_ms,
89            self.p90_ms,
90            self.p99_ms,
91            self.min_ms,
92            self.max_ms
93        )
94    }
95}
96
97/// Lock-free per-turn latency recorder: scalars, a histogram, and a ring of
98/// recent samples, all atomics.
99struct LatencyRecorder {
100    last_ns: AtomicU64,
101    sum_ns: AtomicU64,
102    count: AtomicU64,
103    min_ns: AtomicU64,
104    max_ns: AtomicU64,
105    buckets: [AtomicU64; BUCKET_COUNT],
106    recent: [AtomicU64; LATENCY_RECENT_WINDOW],
107    recent_next: AtomicU64,
108}
109
110impl LatencyRecorder {
111    fn new() -> Self {
112        Self {
113            last_ns: AtomicU64::new(0),
114            sum_ns: AtomicU64::new(0),
115            count: AtomicU64::new(0),
116            min_ns: AtomicU64::new(u64::MAX),
117            max_ns: AtomicU64::new(0),
118            buckets: std::array::from_fn(|_| AtomicU64::new(0)),
119            recent: std::array::from_fn(|_| AtomicU64::new(0)),
120            recent_next: AtomicU64::new(0),
121        }
122    }
123
124    /// Record one turn's latency.
125    ///
126    /// `count` is the publication point and is written **last**, with
127    /// [`Release`]: a reader that observes `count == n` (with [`Acquire`], as
128    /// [`stats`](Self::stats) does) is guaranteed to see all `n` samples in the
129    /// ring and in the scalars. Bumping it first would let a reader see
130    /// `count == 1` while the first ring slot was still unwritten, and compute
131    /// a percentile over an empty window.
132    #[inline]
133    fn record(&self, latency_ns: u64) {
134        self.last_ns.store(latency_ns, Relaxed);
135        self.sum_ns.fetch_add(latency_ns, Relaxed);
136        self.min_ns.fetch_min(latency_ns, Relaxed);
137        self.max_ns.fetch_max(latency_ns, Relaxed);
138
139        let ms = latency_ns / 1_000_000;
140        let bucket = LATENCY_BUCKETS_MS
141            .iter()
142            .position(|&upper| ms <= upper)
143            .unwrap_or(BUCKET_COUNT - 1);
144        self.buckets[bucket].fetch_add(1, Relaxed);
145
146        // Ring of recent samples: one atomic slot per turn, index wraps.
147        let slot = self.recent_next.fetch_add(1, Relaxed) as usize % LATENCY_RECENT_WINDOW;
148        self.recent[slot].store(latency_ns, Relaxed);
149
150        self.count.fetch_add(1, Release);
151    }
152
153    fn stats(&self) -> LatencyStats {
154        // Acquire pairs with the Release in `record`: every sample counted here
155        // is already visible in the ring and the scalars.
156        // Acquire pairs with the Release in `record`: every sample counted here
157        // is already visible in the ring and the scalars.
158        let count = self.count.load(Acquire);
159        let histogram = self
160            .buckets
161            .iter()
162            .enumerate()
163            .map(|(i, b)| LatencyBucket {
164                upper_ms: LATENCY_BUCKETS_MS.get(i).copied(),
165                count: b.load(Relaxed),
166            })
167            .collect();
168        if count == 0 {
169            return LatencyStats {
170                histogram,
171                ..LatencyStats::default()
172            };
173        }
174
175        // `count` and `recent_next` advance together, one per sample, so the
176        // count sizes the window too — and reading one atomic instead of two
177        // leaves no room for the pair to disagree.
178        // `count` and `recent_next` advance together, one per sample, so the
179        // count sizes the window too — and reading one atomic instead of two
180        // leaves no room for the pair to disagree.
181        let filled = (count as usize).min(LATENCY_RECENT_WINDOW);
182        let mut recent: Vec<u64> = self.recent[..filled]
183            .iter()
184            .map(|s| s.load(Relaxed))
185            .collect();
186        recent.sort_unstable();
187        // Nearest-rank percentile over the sorted recent window.
188        let pct = |p: usize| -> u64 {
189            let rank = (p * recent.len()).div_ceil(100).max(1);
190            recent.get(rank - 1).copied().unwrap_or(0) / 1_000_000
191        };
192
193        LatencyStats {
194            count,
195            last_ms: self.last_ns.load(Relaxed) / 1_000_000,
196            min_ms: self.min_ns.load(Relaxed) / 1_000_000,
197            max_ms: self.max_ns.load(Relaxed) / 1_000_000,
198            mean_ms: self.sum_ns.load(Relaxed) / count / 1_000_000,
199            p50_ms: pct(50),
200            p90_ms: pct(90),
201            p99_ms: pct(99),
202            histogram,
203        }
204    }
205}
206
207/// Zero-overhead telemetry collector for speech-to-speech sessions.
208///
209/// Designed for the three-lane processor model:
210/// - **Fast lane** (sync, <1ms): No telemetry calls — pure audio/text forwarding.
211/// - **Telemetry lane** (async, debounced): Calls `record_*` methods on every event.
212///   These use only atomic operations — no allocations, no locks, no syscalls.
213/// - **Control lane** (async): Calls `snapshot()` at turn boundaries to get
214///   aggregated stats as a JSON value ready to send to the browser.
215pub struct SessionTelemetry {
216    start: Instant,
217
218    // ── Audio throughput ──
219    audio_chunks_out: AtomicU64,
220    audio_bytes_out: AtomicU64,
221
222    // ── Interruptions ──
223    interruptions: AtomicU64,
224
225    // ── Response latency tracking ──
226    // Stores nanos-since-session-start for atomic compatibility with Instant.
227    vad_end_ns: AtomicU64,
228    awaiting_response: AtomicBool,
229    /// Timestamp when user sent text (for text-input latency tracking).
230    text_send_ns: AtomicU64,
231    awaiting_text_response: AtomicBool,
232    /// Per-turn response latency: end of user speech (or text send) to the
233    /// model's first output.
234    latency: LatencyRecorder,
235
236    // ── Turn timing ──
237    turn_complete_count: AtomicU64,
238    last_turn_start_ns: AtomicU64,
239    turn_duration_sum_ns: AtomicU64,
240    turn_duration_count: AtomicU64,
241
242    // ── Token usage (from UsageMetadata) ──
243    /// Latest total token count from server.
244    total_token_count: AtomicU64,
245    /// Latest prompt token count from server.
246    prompt_token_count: AtomicU64,
247    /// Latest response token count from server.
248    response_token_count: AtomicU64,
249    /// Latest cached content token count from server.
250    cached_content_token_count: AtomicU64,
251    /// Latest thoughts token count (thinking models).
252    thoughts_token_count: AtomicU64,
253}
254
255impl SessionTelemetry {
256    /// Create a new telemetry tracker, starting the session clock.
257    pub fn new() -> Self {
258        Self {
259            start: Instant::now(),
260            audio_chunks_out: AtomicU64::new(0),
261            audio_bytes_out: AtomicU64::new(0),
262            interruptions: AtomicU64::new(0),
263            vad_end_ns: AtomicU64::new(0),
264            awaiting_response: AtomicBool::new(false),
265            text_send_ns: AtomicU64::new(0),
266            awaiting_text_response: AtomicBool::new(false),
267            latency: LatencyRecorder::new(),
268            turn_complete_count: AtomicU64::new(0),
269            last_turn_start_ns: AtomicU64::new(0),
270            turn_duration_sum_ns: AtomicU64::new(0),
271            turn_duration_count: AtomicU64::new(0),
272            total_token_count: AtomicU64::new(0),
273            prompt_token_count: AtomicU64::new(0),
274            response_token_count: AtomicU64::new(0),
275            cached_content_token_count: AtomicU64::new(0),
276            thoughts_token_count: AtomicU64::new(0),
277        }
278    }
279
280    // ── Atomic methods (~1ns each) ──
281
282    /// Record an outgoing audio chunk. Called from the telemetry lane.
283    ///
284    /// Returns the response latency when this chunk is the model's first
285    /// output after the user's end of speech (or text send) — once per turn,
286    /// via a CAS so only the first chunk wins.
287    #[inline]
288    pub fn record_audio_out(&self, byte_len: usize) -> Option<Duration> {
289        self.audio_chunks_out.fetch_add(1, Relaxed);
290        self.audio_bytes_out.fetch_add(byte_len as u64, Relaxed);
291
292        // A text send answered with audio counts as a response too.
293        let text = self.record_text_response_latency();
294
295        // Latency: if we're awaiting the model's first byte after VAD end,
296        // record the response latency via CAS (only the first chunk wins).
297        if self
298            .awaiting_response
299            .compare_exchange(true, false, Relaxed, Relaxed)
300            .is_ok()
301        {
302            let now_ns = self.elapsed_ns();
303            let vad_end = self.vad_end_ns.load(Relaxed);
304            if now_ns > vad_end && vad_end > 0 {
305                let latency = now_ns - vad_end;
306                self.latency.record(latency);
307                return Some(Duration::from_nanos(latency));
308            }
309        }
310        text
311    }
312
313    /// Record VAD end (user stopped speaking).
314    #[inline]
315    pub fn record_vad_end(&self) {
316        self.vad_end_ns.store(self.elapsed_ns(), Relaxed);
317        self.awaiting_response.store(true, Relaxed);
318    }
319
320    /// Record that user sent a text message (for text-input latency tracking).
321    #[inline]
322    pub fn record_text_send(&self) {
323        self.text_send_ns.store(self.elapsed_ns(), Relaxed);
324        self.awaiting_text_response.store(true, Relaxed);
325    }
326
327    /// Record first model output for text-input latency.
328    /// Call on first TextDelta or AudioData after a text send.
329    #[inline]
330    fn record_text_response_latency(&self) -> Option<Duration> {
331        if self
332            .awaiting_text_response
333            .compare_exchange(true, false, Relaxed, Relaxed)
334            .is_ok()
335        {
336            let now_ns = self.elapsed_ns();
337            let send_ns = self.text_send_ns.load(Relaxed);
338            if now_ns > send_ns && send_ns > 0 {
339                let latency = now_ns - send_ns;
340                self.latency.record(latency);
341                return Some(Duration::from_nanos(latency));
342            }
343        }
344        None
345    }
346
347    /// Record first model text output (TextDelta). Tracks text-input latency.
348    ///
349    /// Returns the response latency when this delta is the model's first
350    /// output after a text send.
351    #[inline]
352    pub fn record_text_out(&self) -> Option<Duration> {
353        self.record_text_response_latency()
354    }
355
356    /// Record an interruption (barge-in).
357    #[inline]
358    pub fn record_interruption(&self) {
359        self.interruptions.fetch_add(1, Relaxed);
360    }
361
362    /// Record turn completion for duration tracking.
363    #[inline]
364    pub fn record_turn_complete(&self) {
365        self.turn_complete_count.fetch_add(1, Relaxed);
366        let now = self.elapsed_ns();
367        let turn_start = self.last_turn_start_ns.swap(now, Relaxed);
368        if turn_start > 0 {
369            let duration = now.saturating_sub(turn_start);
370            self.turn_duration_sum_ns.fetch_add(duration, Relaxed);
371            self.turn_duration_count.fetch_add(1, Relaxed);
372        }
373    }
374
375    /// Record token usage from a `UsageMetadata` event.
376    #[inline]
377    pub fn record_usage(
378        &self,
379        total: Option<u32>,
380        prompt: Option<u32>,
381        response: Option<u32>,
382        cached: Option<u32>,
383        thoughts: Option<u32>,
384    ) {
385        if let Some(v) = total {
386            self.total_token_count.store(v as u64, Relaxed);
387        }
388        if let Some(v) = prompt {
389            self.prompt_token_count.store(v as u64, Relaxed);
390        }
391        if let Some(v) = response {
392            self.response_token_count.store(v as u64, Relaxed);
393        }
394        if let Some(v) = cached {
395            self.cached_content_token_count.store(v as u64, Relaxed);
396        }
397        if let Some(v) = thoughts {
398            self.thoughts_token_count.store(v as u64, Relaxed);
399        }
400    }
401
402    /// Mark the beginning of a new turn (e.g., when model starts responding).
403    #[inline]
404    pub fn mark_turn_start(&self) {
405        let now = self.elapsed_ns();
406        // Only set if not already set (first call per turn wins)
407        self.last_turn_start_ns
408            .compare_exchange(0, now, Relaxed, Relaxed)
409            .ok();
410    }
411
412    // ── Aggregation (called at turn boundaries / periodic flush) ──
413
414    /// Per-turn response latency: end of user speech (or text send) to the
415    /// model's first output, as a distribution over the session so far.
416    ///
417    /// Cheap enough to call once per turn (it sorts at most
418    /// [`LATENCY_RECENT_WINDOW`] samples); not for the audio hot path.
419    pub fn latency(&self) -> LatencyStats {
420        self.latency.stats()
421    }
422
423    /// Snapshot all metrics as a JSON value.
424    ///
425    /// The flat `*_response_latency_ms` keys are kept for existing dashboards;
426    /// `response_latency` carries the full [`LatencyStats`] (percentiles and
427    /// histogram included).
428    pub fn snapshot(&self) -> serde_json::Value {
429        let elapsed = self.start.elapsed();
430        let elapsed_secs = elapsed.as_secs_f64();
431
432        let chunks = self.audio_chunks_out.load(Relaxed);
433        let bytes = self.audio_bytes_out.load(Relaxed);
434        let latency = self.latency.stats();
435
436        let turn_count = self.turn_duration_count.load(Relaxed);
437        let turn_complete_count = self.turn_complete_count.load(Relaxed);
438        let avg_turn_ms = if turn_count > 0 {
439            self.turn_duration_sum_ns.load(Relaxed) / turn_count / 1_000_000
440        } else {
441            0
442        };
443
444        // Audio throughput (KB/s over session lifetime)
445        let throughput_kbps = if elapsed_secs > 0.0 {
446            (bytes as f64 / 1024.0) / elapsed_secs
447        } else {
448            0.0
449        };
450
451        let total_tokens = self.total_token_count.load(Relaxed);
452        let prompt_tokens = self.prompt_token_count.load(Relaxed);
453        let response_tokens = self.response_token_count.load(Relaxed);
454        let cached_tokens = self.cached_content_token_count.load(Relaxed);
455        let thoughts_tokens = self.thoughts_token_count.load(Relaxed);
456
457        json!({
458            "uptime_secs": elapsed.as_secs(),
459            "audio_chunks_out": chunks,
460            "audio_kbytes_out": bytes / 1024,
461            "audio_throughput_kbps": (throughput_kbps * 10.0).round() / 10.0,
462            "interruptions": self.interruptions.load(Relaxed),
463            "last_response_latency_ms": latency.last_ms,
464            "avg_response_latency_ms": latency.mean_ms,
465            "min_response_latency_ms": latency.min_ms,
466            "max_response_latency_ms": latency.max_ms,
467            "response_count": latency.count,
468            "response_latency": latency,
469            "turn_count": turn_complete_count,
470            "avg_turn_duration_ms": avg_turn_ms,
471            "total_token_count": total_tokens,
472            "prompt_token_count": prompt_tokens,
473            "response_token_count": response_tokens,
474            "cached_content_token_count": cached_tokens,
475            "thoughts_token_count": thoughts_tokens,
476        })
477    }
478
479    #[inline]
480    fn elapsed_ns(&self) -> u64 {
481        self.start.elapsed().as_nanos() as u64
482    }
483}
484
485impl Default for SessionTelemetry {
486    fn default() -> Self {
487        Self::new()
488    }
489}
490
491#[cfg(test)]
492mod tests {
493    use super::*;
494
495    #[test]
496    fn new_snapshot_is_zeroed() {
497        let t = SessionTelemetry::new();
498        let snap = t.snapshot();
499        assert_eq!(snap["audio_chunks_out"], 0);
500        assert_eq!(snap["interruptions"], 0);
501        assert_eq!(snap["last_response_latency_ms"], 0);
502        assert_eq!(snap["response_count"], 0);
503        assert_eq!(snap["turn_count"], 0);
504        assert_eq!(snap["response_latency"]["count"], 0);
505        assert_eq!(
506            t.latency(),
507            LatencyStats {
508                histogram: t.latency().histogram.clone(),
509                ..LatencyStats::default()
510            }
511        );
512        assert_eq!(
513            t.latency().to_string(),
514            "turns=0 (no response measured yet)"
515        );
516    }
517
518    #[test]
519    fn audio_counters_accumulate() {
520        let t = SessionTelemetry::new();
521        t.record_audio_out(480);
522        t.record_audio_out(480);
523        t.record_audio_out(480);
524        let snap = t.snapshot();
525        assert_eq!(snap["audio_chunks_out"], 3);
526    }
527
528    #[test]
529    fn interruption_counter() {
530        let t = SessionTelemetry::new();
531        t.record_interruption();
532        t.record_interruption();
533        assert_eq!(t.snapshot()["interruptions"], 2);
534    }
535
536    #[test]
537    fn turn_complete_counter_is_independent_of_latency() {
538        let t = SessionTelemetry::new();
539        t.record_turn_complete();
540        t.record_turn_complete();
541
542        let snap = t.snapshot();
543        assert_eq!(snap["turn_count"], 2);
544        assert_eq!(snap["response_count"], 0);
545    }
546
547    #[test]
548    fn latency_tracking() {
549        let t = SessionTelemetry::new();
550        // Simulate: VAD end → short delay → first audio chunk
551        t.record_vad_end();
552        std::thread::sleep(std::time::Duration::from_millis(10));
553        let first = t.record_audio_out(480);
554        assert!(
555            first.is_some(),
556            "first chunk after VAD end reports the latency"
557        );
558        // Subsequent chunks should not re-record latency
559        assert!(t.record_audio_out(480).is_none());
560        assert!(t.record_audio_out(480).is_none());
561
562        let snap = t.snapshot();
563        assert_eq!(snap["response_count"], 1);
564        // Latency should be >= 10ms (we slept 10ms)
565        assert!(snap["last_response_latency_ms"].as_u64().unwrap() >= 5);
566        assert_eq!(snap["response_latency"]["count"], 1);
567    }
568
569    #[test]
570    fn multiple_turns_average_latency() {
571        let t = SessionTelemetry::new();
572
573        // Turn 1
574        t.record_vad_end();
575        std::thread::sleep(std::time::Duration::from_millis(10));
576        t.record_audio_out(480);
577
578        // Turn 2
579        t.record_vad_end();
580        std::thread::sleep(std::time::Duration::from_millis(10));
581        t.record_audio_out(480);
582
583        let snap = t.snapshot();
584        assert_eq!(snap["response_count"], 2);
585        assert!(snap["avg_response_latency_ms"].as_u64().unwrap() >= 5);
586    }
587
588    #[test]
589    fn text_input_latency_via_text_out() {
590        let t = SessionTelemetry::new();
591        // Simulate: user sends text → delay → model responds with text
592        t.record_text_send();
593        std::thread::sleep(std::time::Duration::from_millis(10));
594        assert!(t.record_text_out().is_some());
595        // Subsequent text outputs should not re-record
596        assert!(t.record_text_out().is_none());
597
598        let snap = t.snapshot();
599        assert_eq!(snap["response_count"], 1);
600        assert!(snap["last_response_latency_ms"].as_u64().unwrap() >= 5);
601    }
602
603    #[test]
604    fn text_input_latency_via_audio_out() {
605        let t = SessionTelemetry::new();
606        // Simulate: user sends text → delay → model responds with audio
607        t.record_text_send();
608        std::thread::sleep(std::time::Duration::from_millis(10));
609        assert!(t.record_audio_out(480).is_some());
610
611        let snap = t.snapshot();
612        // Should record text-send latency (response_count = 1)
613        assert_eq!(snap["response_count"], 1);
614        assert!(snap["last_response_latency_ms"].as_u64().unwrap() >= 5);
615    }
616
617    #[test]
618    fn mixed_voice_and_text_turns() {
619        let t = SessionTelemetry::new();
620
621        // Voice turn
622        t.record_vad_end();
623        std::thread::sleep(std::time::Duration::from_millis(10));
624        t.record_audio_out(480);
625
626        // Text turn
627        t.record_text_send();
628        std::thread::sleep(std::time::Duration::from_millis(10));
629        t.record_text_out();
630
631        let snap = t.snapshot();
632        assert_eq!(snap["response_count"], 2);
633    }
634
635    // ── LatencyRecorder: distribution semantics, fed directly in nanos ──
636
637    fn ms(n: u64) -> u64 {
638        n * 1_000_000
639    }
640
641    #[test]
642    fn recorder_scalars_and_percentiles() {
643        let r = LatencyRecorder::new();
644        for v in [300, 100, 500, 200, 400] {
645            r.record(ms(v));
646        }
647        let s = r.stats();
648        assert_eq!(s.count, 5);
649        assert_eq!(s.last_ms, 400);
650        assert_eq!(s.min_ms, 100);
651        assert_eq!(s.max_ms, 500);
652        assert_eq!(s.mean_ms, 300);
653        // Nearest rank over [100,200,300,400,500]: p50 → rank 3 → 300,
654        // p90 → rank 5 → 500, p99 → rank 5 → 500.
655        assert_eq!(s.p50_ms, 300);
656        assert_eq!(s.p90_ms, 500);
657        assert_eq!(s.p99_ms, 500);
658        assert_eq!(
659            s.to_string(),
660            "turns=5 last=400ms p50=300ms p90=500ms p99=500ms min=100ms max=500ms"
661        );
662    }
663
664    #[test]
665    fn recorder_first_sample_is_visible_to_percentiles() {
666        // A count of 1 must come with a window of 1 — never an empty window
667        // that the nearest-rank index would then read past the end of.
668        let r = LatencyRecorder::new();
669        r.record(ms(420));
670        let s = r.stats();
671        assert_eq!(s.count, 1);
672        assert_eq!((s.p50_ms, s.p90_ms, s.p99_ms), (420, 420, 420));
673        assert_eq!(s.mean_ms, 420);
674    }
675
676    #[test]
677    fn recorder_stats_survives_a_count_without_its_sample() {
678        // The panic this pins: `stats()` gated on `count` but sized its
679        // percentile window from `recent_next`. A count that ran ahead of the
680        // ring — as it did while `record` bumped the count first — left an
681        // empty window that the nearest-rank index then read past the end of.
682        // `stats()` now sizes the window from the same counter it gates on.
683        let r = LatencyRecorder::new();
684        r.count.store(1, Release); // counted, ring slot not yet written
685        let s = r.stats();
686        assert_eq!(s.count, 1);
687        assert_eq!((s.p50_ms, s.p90_ms, s.p99_ms), (0, 0, 0));
688    }
689
690    #[test]
691    fn recorder_snapshots_stay_consistent_under_concurrent_records() {
692        // `stats()` runs on whatever thread the caller likes while the
693        // telemetry lane records; no snapshot may mix samples from different
694        // moments into an impossible summary.
695        use std::sync::Arc;
696        use std::sync::atomic::AtomicBool;
697
698        let r = Arc::new(LatencyRecorder::new());
699        let done = Arc::new(AtomicBool::new(false));
700
701        let reader = {
702            let r = Arc::clone(&r);
703            let done = Arc::clone(&done);
704            std::thread::spawn(move || {
705                while !done.load(Relaxed) {
706                    let s = r.stats();
707                    if s.count > 0 {
708                        assert!(s.p99_ms >= s.p50_ms);
709                        assert!(s.max_ms >= s.p99_ms);
710                        assert!(s.min_ms <= s.max_ms);
711                    }
712                }
713            })
714        };
715
716        for _ in 0..2_000 {
717            r.record(ms(100));
718        }
719        done.store(true, Relaxed);
720        reader.join().expect("reader saw an inconsistent snapshot");
721        assert_eq!(r.stats().count, 2_000);
722    }
723
724    #[test]
725    fn recorder_histogram_buckets_by_upper_bound() {
726        let r = LatencyRecorder::new();
727        r.record(ms(50)); // ≤ 50 → bucket 0 (inclusive bound)
728        r.record(ms(51)); // ≤ 100 → bucket 1
729        r.record(ms(999)); // ≤ 1000 → bucket 9
730        r.record(ms(9_000)); // > 5000 → open top bucket
731        let h = r.stats().histogram;
732        assert_eq!(h.len(), LATENCY_BUCKETS_MS.len() + 1);
733        assert_eq!(
734            h[0],
735            LatencyBucket {
736                upper_ms: Some(50),
737                count: 1
738            }
739        );
740        assert_eq!(
741            h[1],
742            LatencyBucket {
743                upper_ms: Some(100),
744                count: 1
745            }
746        );
747        assert_eq!(
748            h[9],
749            LatencyBucket {
750                upper_ms: Some(1000),
751                count: 1
752            }
753        );
754        assert_eq!(
755            h[h.len() - 1],
756            LatencyBucket {
757                upper_ms: None,
758                count: 1
759            }
760        );
761        assert_eq!(h.iter().map(|b| b.count).sum::<u64>(), 4);
762    }
763
764    #[test]
765    fn recorder_percentiles_use_recent_window_only() {
766        let r = LatencyRecorder::new();
767        // Fill the window with slow turns, then overwrite it entirely with
768        // fast ones: the percentiles follow the recent window, min/max and
769        // the histogram keep the whole session.
770        for _ in 0..LATENCY_RECENT_WINDOW {
771            r.record(ms(2_000));
772        }
773        for _ in 0..LATENCY_RECENT_WINDOW {
774            r.record(ms(200));
775        }
776        let s = r.stats();
777        assert_eq!(s.count, 2 * LATENCY_RECENT_WINDOW as u64);
778        assert_eq!(s.p50_ms, 200);
779        assert_eq!(s.p99_ms, 200);
780        assert_eq!(s.max_ms, 2_000);
781        assert_eq!(s.min_ms, 200);
782        let slow: u64 = s
783            .histogram
784            .iter()
785            .filter(|b| b.upper_ms == Some(2000))
786            .map(|b| b.count)
787            .sum();
788        assert_eq!(slow, LATENCY_RECENT_WINDOW as u64);
789    }
790
791    #[test]
792    fn stats_round_trip_through_json() {
793        let r = LatencyRecorder::new();
794        r.record(ms(420));
795        let s = r.stats();
796        let v = serde_json::to_value(&s).unwrap();
797        assert_eq!(v["p50_ms"], 420);
798        let back: LatencyStats = serde_json::from_value(v).unwrap();
799        assert_eq!(back, s);
800    }
801}