Skip to main content

ipfrs_storage/
profiling.rs

1//! Advanced performance profiling utilities
2//!
3//! Provides detailed performance profiling with histograms, percentiles,
4//! and latency distributions for in-depth performance analysis.
5
6use serde::{Deserialize, Serialize};
7use std::collections::BTreeMap;
8use std::time::Duration;
9
10/// Latency histogram for tracking operation latencies
11#[derive(Debug, Clone, Serialize, Deserialize)]
12pub struct LatencyHistogram {
13    /// Bucket boundaries in microseconds
14    buckets: Vec<u64>,
15    /// Counts for each bucket
16    counts: Vec<u64>,
17    /// Total samples
18    total_samples: u64,
19    /// Minimum latency observed
20    min_latency_us: u64,
21    /// Maximum latency observed
22    max_latency_us: u64,
23    /// Sum of all latencies for average calculation
24    sum_latency_us: u64,
25}
26
27impl LatencyHistogram {
28    /// Create a new latency histogram with default buckets
29    ///
30    /// Default buckets: [10, 50, 100, 500, 1000, 5000, 10000, 50000] microseconds
31    pub fn new() -> Self {
32        Self::with_buckets(vec![10, 50, 100, 500, 1000, 5000, 10000, 50000])
33    }
34
35    /// Create a histogram with custom bucket boundaries
36    pub fn with_buckets(mut buckets: Vec<u64>) -> Self {
37        buckets.sort_unstable();
38        let counts = vec![0; buckets.len() + 1];
39
40        Self {
41            buckets,
42            counts,
43            total_samples: 0,
44            min_latency_us: u64::MAX,
45            max_latency_us: 0,
46            sum_latency_us: 0,
47        }
48    }
49
50    /// Record a latency sample
51    pub fn record(&mut self, latency: Duration) {
52        let latency_us = latency.as_micros() as u64;
53
54        // Update min/max
55        self.min_latency_us = self.min_latency_us.min(latency_us);
56        self.max_latency_us = self.max_latency_us.max(latency_us);
57
58        // Update sum and count
59        self.sum_latency_us += latency_us;
60        self.total_samples += 1;
61
62        // Find bucket and increment
63        let bucket_idx = self
64            .buckets
65            .iter()
66            .position(|&b| latency_us < b)
67            .unwrap_or(self.buckets.len());
68        self.counts[bucket_idx] += 1;
69    }
70
71    /// Get average latency
72    pub fn avg(&self) -> Duration {
73        Duration::from_micros(
74            self.sum_latency_us
75                .checked_div(self.total_samples)
76                .unwrap_or(0),
77        )
78    }
79
80    /// Get minimum latency
81    pub fn min(&self) -> Duration {
82        if self.min_latency_us == u64::MAX {
83            Duration::from_micros(0)
84        } else {
85            Duration::from_micros(self.min_latency_us)
86        }
87    }
88
89    /// Get maximum latency
90    pub fn max(&self) -> Duration {
91        Duration::from_micros(self.max_latency_us)
92    }
93
94    /// Get percentile value (0.0 - 1.0)
95    ///
96    /// Example: percentile(0.99) returns the 99th percentile latency
97    pub fn percentile(&self, p: f64) -> Duration {
98        if self.total_samples == 0 {
99            return Duration::from_micros(0);
100        }
101
102        let target_count = (self.total_samples as f64 * p) as u64;
103        let mut cumulative = 0u64;
104
105        for (idx, &count) in self.counts.iter().enumerate() {
106            cumulative += count;
107            if cumulative >= target_count {
108                // Return upper bound of this bucket
109                let latency_us = if idx < self.buckets.len() {
110                    self.buckets[idx]
111                } else {
112                    self.max_latency_us
113                };
114                return Duration::from_micros(latency_us);
115            }
116        }
117
118        Duration::from_micros(self.max_latency_us)
119    }
120
121    /// Get p50 (median)
122    pub fn p50(&self) -> Duration {
123        self.percentile(0.50)
124    }
125
126    /// Get p90
127    pub fn p90(&self) -> Duration {
128        self.percentile(0.90)
129    }
130
131    /// Get p95
132    pub fn p95(&self) -> Duration {
133        self.percentile(0.95)
134    }
135
136    /// Get p99
137    pub fn p99(&self) -> Duration {
138        self.percentile(0.99)
139    }
140
141    /// Get p999 (99.9th percentile)
142    pub fn p999(&self) -> Duration {
143        self.percentile(0.999)
144    }
145
146    /// Get total number of samples
147    pub fn count(&self) -> u64 {
148        self.total_samples
149    }
150
151    /// Generate a summary report
152    pub fn summary(&self) -> String {
153        format!(
154            "Samples: {}, Min: {:?}, Max: {:?}, Avg: {:?}, P50: {:?}, P90: {:?}, P95: {:?}, P99: {:?}",
155            self.total_samples,
156            self.min(),
157            self.max(),
158            self.avg(),
159            self.p50(),
160            self.p90(),
161            self.p95(),
162            self.p99()
163        )
164    }
165}
166
167impl Default for LatencyHistogram {
168    fn default() -> Self {
169        Self::new()
170    }
171}
172
173/// Performance profiler for tracking multiple operation types
174#[derive(Debug, Clone, Default)]
175pub struct PerformanceProfiler {
176    /// Histograms for different operation types
177    histograms: BTreeMap<String, LatencyHistogram>,
178}
179
180impl PerformanceProfiler {
181    /// Create a new performance profiler
182    pub fn new() -> Self {
183        Self {
184            histograms: BTreeMap::new(),
185        }
186    }
187
188    /// Record a latency for an operation
189    pub fn record(&mut self, operation: &str, latency: Duration) {
190        self.histograms
191            .entry(operation.to_string())
192            .or_default()
193            .record(latency);
194    }
195
196    /// Get histogram for a specific operation
197    pub fn get_histogram(&self, operation: &str) -> Option<&LatencyHistogram> {
198        self.histograms.get(operation)
199    }
200
201    /// Get all histograms
202    pub fn histograms(&self) -> &BTreeMap<String, LatencyHistogram> {
203        &self.histograms
204    }
205
206    /// Generate a comprehensive report
207    pub fn report(&self) -> String {
208        let mut report = String::from("=== Performance Profile ===\n\n");
209
210        for (operation, histogram) in &self.histograms {
211            report.push_str(&format!("Operation: {operation}\n"));
212            report.push_str(&format!("  {}\n\n", histogram.summary()));
213        }
214
215        report
216    }
217
218    /// Reset all histograms
219    pub fn reset(&mut self) {
220        self.histograms.clear();
221    }
222}
223
224/// Throughput tracker for measuring operations per second
225#[derive(Debug, Clone)]
226pub struct ThroughputTracker {
227    /// Operation name
228    operation: String,
229    /// Total operations completed
230    total_ops: u64,
231    /// Total bytes processed (if applicable)
232    total_bytes: u64,
233    /// Start time
234    start_time: std::time::Instant,
235}
236
237impl ThroughputTracker {
238    /// Create a new throughput tracker
239    pub fn new(operation: String) -> Self {
240        Self {
241            operation,
242            total_ops: 0,
243            total_bytes: 0,
244            start_time: std::time::Instant::now(),
245        }
246    }
247
248    /// Record an operation completion
249    pub fn record_op(&mut self) {
250        self.total_ops += 1;
251    }
252
253    /// Record bytes processed
254    pub fn record_bytes(&mut self, bytes: u64) {
255        self.total_bytes += bytes;
256    }
257
258    /// Get operations per second
259    pub fn ops_per_second(&self) -> f64 {
260        let elapsed = self.start_time.elapsed().as_secs_f64();
261        if elapsed > 0.0 {
262            self.total_ops as f64 / elapsed
263        } else {
264            0.0
265        }
266    }
267
268    /// Get bytes per second
269    pub fn bytes_per_second(&self) -> f64 {
270        let elapsed = self.start_time.elapsed().as_secs_f64();
271        if elapsed > 0.0 {
272            self.total_bytes as f64 / elapsed
273        } else {
274            0.0
275        }
276    }
277
278    /// Get megabytes per second
279    pub fn megabytes_per_second(&self) -> f64 {
280        self.bytes_per_second() / (1024.0 * 1024.0)
281    }
282
283    /// Get elapsed time
284    pub fn elapsed(&self) -> Duration {
285        self.start_time.elapsed()
286    }
287
288    /// Generate a summary report
289    pub fn summary(&self) -> String {
290        format!(
291            "{}: {} ops in {:?} ({:.2} ops/s, {:.2} MB/s)",
292            self.operation,
293            self.total_ops,
294            self.elapsed(),
295            self.ops_per_second(),
296            self.megabytes_per_second()
297        )
298    }
299}
300
301/// Batch profiler for analyzing batch operation efficiency
302#[derive(Debug, Clone, Default)]
303pub struct BatchProfiler {
304    /// Total batch operations
305    total_batches: u64,
306    /// Total individual items in batches
307    total_items: u64,
308    /// Batch sizes histogram
309    batch_sizes: LatencyHistogram,
310    /// Batch latencies
311    batch_latencies: LatencyHistogram,
312}
313
314impl BatchProfiler {
315    /// Create a new batch profiler
316    pub fn new() -> Self {
317        Self {
318            total_batches: 0,
319            total_items: 0,
320            batch_sizes: LatencyHistogram::with_buckets(vec![1, 10, 50, 100, 500, 1000]),
321            batch_latencies: LatencyHistogram::new(),
322        }
323    }
324
325    /// Record a batch operation
326    pub fn record_batch(&mut self, batch_size: usize, latency: Duration) {
327        self.total_batches += 1;
328        self.total_items += batch_size as u64;
329
330        // Record batch size as "latency" for histogram purposes
331        self.batch_sizes
332            .record(Duration::from_micros(batch_size as u64));
333        self.batch_latencies.record(latency);
334    }
335
336    /// Get average batch size
337    pub fn avg_batch_size(&self) -> f64 {
338        if self.total_batches == 0 {
339            0.0
340        } else {
341            self.total_items as f64 / self.total_batches as f64
342        }
343    }
344
345    /// Get average latency per item
346    pub fn avg_latency_per_item(&self) -> Duration {
347        let total_latency_us = self.batch_latencies.sum_latency_us;
348        Duration::from_micros(total_latency_us.checked_div(self.total_items).unwrap_or(0))
349    }
350
351    /// Generate a summary report
352    pub fn summary(&self) -> String {
353        format!(
354            "Batches: {}, Items: {}, Avg Batch Size: {:.2}, Avg Latency: {:?}, Avg per Item: {:?}",
355            self.total_batches,
356            self.total_items,
357            self.avg_batch_size(),
358            self.batch_latencies.avg(),
359            self.avg_latency_per_item()
360        )
361    }
362}
363
364#[cfg(test)]
365mod tests {
366    use super::*;
367
368    #[test]
369    fn test_latency_histogram_basic() {
370        let mut hist = LatencyHistogram::new();
371
372        hist.record(Duration::from_micros(50));
373        hist.record(Duration::from_micros(100));
374        hist.record(Duration::from_micros(150));
375
376        assert_eq!(hist.count(), 3);
377        assert!(hist.min() <= Duration::from_micros(50));
378        assert!(hist.max() >= Duration::from_micros(150));
379    }
380
381    #[test]
382    fn test_latency_histogram_percentiles() {
383        let mut hist = LatencyHistogram::new();
384
385        // Use a wider range of values to ensure they fall into different buckets
386        for i in 1..=100 {
387            hist.record(Duration::from_micros(i * 100));
388        }
389
390        assert_eq!(hist.count(), 100);
391
392        let p50 = hist.p50();
393        let p90 = hist.p90();
394        let p99 = hist.p99();
395
396        // P90 should be >= P50, P99 should be >= P90
397        assert!(p50 <= p90);
398        assert!(p90 <= p99);
399    }
400
401    #[test]
402    fn test_performance_profiler() {
403        let mut profiler = PerformanceProfiler::new();
404
405        profiler.record("put", Duration::from_micros(100));
406        profiler.record("put", Duration::from_micros(150));
407        profiler.record("get", Duration::from_micros(50));
408
409        assert!(profiler.get_histogram("put").is_some());
410        assert!(profiler.get_histogram("get").is_some());
411        assert!(profiler.get_histogram("delete").is_none());
412
413        let put_hist = profiler.get_histogram("put").unwrap();
414        assert_eq!(put_hist.count(), 2);
415
416        let report = profiler.report();
417        assert!(report.contains("put"));
418        assert!(report.contains("get"));
419    }
420
421    #[test]
422    fn test_throughput_tracker() {
423        let mut tracker = ThroughputTracker::new("test".to_string());
424
425        for _ in 0..100 {
426            tracker.record_op();
427            tracker.record_bytes(1024);
428        }
429
430        assert_eq!(tracker.total_ops, 100);
431        assert_eq!(tracker.total_bytes, 102400);
432        assert!(tracker.ops_per_second() > 0.0);
433
434        let summary = tracker.summary();
435        assert!(summary.contains("test"));
436        assert!(summary.contains("100 ops"));
437    }
438
439    #[test]
440    fn test_batch_profiler() {
441        let mut profiler = BatchProfiler::new();
442
443        profiler.record_batch(10, Duration::from_micros(1000));
444        profiler.record_batch(20, Duration::from_micros(2000));
445        profiler.record_batch(30, Duration::from_micros(3000));
446
447        assert_eq!(profiler.total_batches, 3);
448        assert_eq!(profiler.total_items, 60);
449        assert_eq!(profiler.avg_batch_size(), 20.0);
450
451        let summary = profiler.summary();
452        assert!(summary.contains("Batches: 3"));
453        assert!(summary.contains("Items: 60"));
454    }
455}