metrics_lib/
timer.rs

1//! # High-Precision Timer
2//!
3//! Ultra-fast timer implementation with nanosecond precision.
4//!
5//! ## Features
6//!
7//! - **Nanosecond precision** - Using system high-resolution clocks
8//! - **Zero allocation** - Pure stack operations
9//! - **RAII support** - Automatic timing with scoped timers
10//! - **Lock-free** - Never blocks, never waits
11//! - **Cache optimized** - Aligned to prevent false sharing
12
13use std::sync::atomic::{AtomicU64, Ordering};
14use std::time::{Duration, Instant};
15
16/// High-precision timer with automatic statistics
17///
18/// Optimized for sub-10ns timing operations.
19/// Cache-line aligned to prevent false sharing.
20#[repr(align(64))]
21pub struct Timer {
22    /// Number of timing samples
23    count: AtomicU64,
24    /// Sum of all recorded durations in nanoseconds
25    total_nanos: AtomicU64,
26    /// Minimum duration in nanoseconds
27    min_nanos: AtomicU64,
28    /// Maximum duration in nanoseconds
29    max_nanos: AtomicU64,
30    /// Creation timestamp
31    created_at: Instant,
32}
33
34/// Running timer instance (RAII)
35///
36/// When dropped, automatically records the elapsed time
37pub struct RunningTimer<'a> {
38    timer: &'a Timer,
39    start_time: Instant,
40    stopped: bool,
41}
42
43/// Timer statistics
44#[derive(Debug, Clone)]
45pub struct TimerStats {
46    /// Total number of timing samples
47    pub count: u64,
48    /// Sum of all durations
49    pub total: Duration,
50    /// Average duration
51    pub average: Duration,
52    /// Minimum duration recorded
53    pub min: Duration,
54    /// Maximum duration recorded
55    pub max: Duration,
56    /// Time since timer creation
57    pub age: Duration,
58    /// Rate of samples per second
59    pub rate_per_second: f64,
60}
61
62impl Timer {
63    /// Create new timer
64    #[inline]
65    pub fn new() -> Self {
66        Self {
67            count: AtomicU64::new(0),
68            total_nanos: AtomicU64::new(0),
69            min_nanos: AtomicU64::new(u64::MAX),
70            max_nanos: AtomicU64::new(0),
71            created_at: Instant::now(),
72        }
73    }
74
75    /// Start timing - returns RAII guard that auto-records on drop
76    #[inline(always)]
77    pub fn start(&self) -> RunningTimer<'_> {
78        RunningTimer {
79            timer: self,
80            start_time: Instant::now(),
81            stopped: false,
82        }
83    }
84
85    /// Record a duration manually
86    #[inline]
87    pub fn record(&self, duration: Duration) {
88        let duration_ns = duration.as_nanos() as u64;
89        self.record_ns(duration_ns);
90    }
91
92    /// Record nanoseconds directly - fastest path
93    #[inline(always)]
94    pub fn record_ns(&self, duration_ns: u64) {
95        // Update total and count
96        self.total_nanos.fetch_add(duration_ns, Ordering::Relaxed);
97        self.count.fetch_add(1, Ordering::Relaxed);
98
99        // Update min (compare-and-swap loop)
100        self.update_min(duration_ns);
101
102        // Update max (compare-and-swap loop)
103        self.update_max(duration_ns);
104    }
105
106    /// Record multiple durations at once
107    #[inline]
108    pub fn record_batch(&self, durations: &[Duration]) {
109        if durations.is_empty() {
110            return;
111        }
112
113        let mut total_ns = 0u64;
114        let mut local_min = u64::MAX;
115        let mut local_max = 0u64;
116
117        for duration in durations {
118            let ns = duration.as_nanos() as u64;
119            total_ns += ns;
120            local_min = local_min.min(ns);
121            local_max = local_max.max(ns);
122        }
123
124        self.total_nanos.fetch_add(total_ns, Ordering::Relaxed);
125        self.count
126            .fetch_add(durations.len() as u64, Ordering::Relaxed);
127
128        if local_min < u64::MAX {
129            self.update_min(local_min);
130        }
131        if local_max > 0 {
132            self.update_max(local_max);
133        }
134    }
135
136    /// Get current count of samples
137    #[inline(always)]
138    pub fn count(&self) -> u64 {
139        self.count.load(Ordering::Relaxed)
140    }
141
142    /// Get total accumulated time
143    #[inline]
144    pub fn total(&self) -> Duration {
145        Duration::from_nanos(self.total_nanos.load(Ordering::Relaxed))
146    }
147
148    /// Get average duration
149    #[inline]
150    pub fn average(&self) -> Duration {
151        let count = self.count();
152        if count == 0 {
153            return Duration::ZERO;
154        }
155
156        let total_ns = self.total_nanos.load(Ordering::Relaxed);
157        Duration::from_nanos(total_ns / count)
158    }
159
160    /// Get minimum duration
161    #[inline]
162    pub fn min(&self) -> Duration {
163        let min_ns = self.min_nanos.load(Ordering::Relaxed);
164        if min_ns == u64::MAX {
165            Duration::ZERO
166        } else {
167            Duration::from_nanos(min_ns)
168        }
169    }
170
171    /// Get maximum duration
172    #[inline]
173    pub fn max(&self) -> Duration {
174        Duration::from_nanos(self.max_nanos.load(Ordering::Relaxed))
175    }
176
177    /// Reset all statistics
178    #[inline]
179    pub fn reset(&self) {
180        self.total_nanos.store(0, Ordering::SeqCst);
181        self.count.store(0, Ordering::SeqCst);
182        self.min_nanos.store(u64::MAX, Ordering::SeqCst);
183        self.max_nanos.store(0, Ordering::SeqCst);
184    }
185
186    /// Get comprehensive statistics
187    pub fn stats(&self) -> TimerStats {
188        let count = self.count();
189        let total_ns = self.total_nanos.load(Ordering::Relaxed);
190        let min_ns = self.min_nanos.load(Ordering::Relaxed);
191        let max_ns = self.max_nanos.load(Ordering::Relaxed);
192
193        let total = Duration::from_nanos(total_ns);
194        let average = if count > 0 {
195            Duration::from_nanos(total_ns / count)
196        } else {
197            Duration::ZERO
198        };
199
200        let min = if min_ns == u64::MAX {
201            Duration::ZERO
202        } else {
203            Duration::from_nanos(min_ns)
204        };
205
206        let max = Duration::from_nanos(max_ns);
207        let age = self.created_at.elapsed();
208
209        let rate_per_second = if age.as_secs_f64() > 0.0 {
210            count as f64 / age.as_secs_f64()
211        } else {
212            0.0
213        };
214
215        TimerStats {
216            count,
217            total,
218            average,
219            min,
220            max,
221            age,
222            rate_per_second,
223        }
224    }
225
226    /// Get age since creation
227    #[inline]
228    pub fn age(&self) -> Duration {
229        self.created_at.elapsed()
230    }
231
232    /// Check if timer has recorded any samples
233    #[inline]
234    pub fn is_empty(&self) -> bool {
235        self.count() == 0
236    }
237
238    /// Get samples per second rate
239    #[inline]
240    pub fn rate_per_second(&self) -> f64 {
241        let age_seconds = self.age().as_secs_f64();
242        if age_seconds > 0.0 {
243            self.count() as f64 / age_seconds
244        } else {
245            0.0
246        }
247    }
248
249    // Internal helper methods
250
251    #[inline(always)]
252    fn update_min(&self, value: u64) {
253        loop {
254            let current = self.min_nanos.load(Ordering::Relaxed);
255            if value >= current {
256                break; // Current min is already smaller
257            }
258
259            match self.min_nanos.compare_exchange_weak(
260                current,
261                value,
262                Ordering::Relaxed,
263                Ordering::Relaxed,
264            ) {
265                Ok(_) => break,
266                Err(_) => continue, // Retry
267            }
268        }
269    }
270
271    #[inline(always)]
272    fn update_max(&self, value: u64) {
273        loop {
274            let current = self.max_nanos.load(Ordering::Relaxed);
275            if value <= current {
276                break; // Current max is already larger
277            }
278
279            match self.max_nanos.compare_exchange_weak(
280                current,
281                value,
282                Ordering::Relaxed,
283                Ordering::Relaxed,
284            ) {
285                Ok(_) => break,
286                Err(_) => continue, // Retry
287            }
288        }
289    }
290}
291
292impl Default for Timer {
293    #[inline]
294    fn default() -> Self {
295        Self::new()
296    }
297}
298
299impl std::fmt::Display for Timer {
300    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
301        let stats = self.stats();
302        write!(f, "Timer(count: {}, avg: {:?})", stats.count, stats.average)
303    }
304}
305
306impl std::fmt::Debug for Timer {
307    fn fmt(&self, f: &mut std::fmt::Formatter<'_>) -> std::fmt::Result {
308        let stats = self.stats();
309        f.debug_struct("Timer")
310            .field("count", &stats.count)
311            .field("total", &stats.total)
312            .field("average", &stats.average)
313            .field("min", &stats.min)
314            .field("max", &stats.max)
315            .field("rate_per_second", &stats.rate_per_second)
316            .finish()
317    }
318}
319
320// Thread safety
321unsafe impl Send for Timer {}
322unsafe impl Sync for Timer {}
323
324/// Running timer implementation (RAII)
325impl<'a> RunningTimer<'a> {
326    /// Get elapsed time without stopping the timer
327    #[inline]
328    pub fn elapsed(&self) -> Duration {
329        self.start_time.elapsed()
330    }
331
332    /// Stop the timer manually and record the duration
333    #[inline]
334    pub fn stop(mut self) {
335        if !self.stopped {
336            let elapsed = self.start_time.elapsed();
337            self.timer.record(elapsed);
338            self.stopped = true;
339        }
340        // Timer is consumed here, preventing double recording
341    }
342}
343
344impl<'a> Drop for RunningTimer<'a> {
345    #[inline]
346    fn drop(&mut self) {
347        if !self.stopped {
348            let elapsed = self.start_time.elapsed();
349            self.timer.record(elapsed);
350        }
351    }
352}
353
354/// Utility functions for timing
355pub mod utils {
356    use super::*;
357
358    /// Time a function execution and return the result + duration
359    #[inline]
360    pub fn time_fn<T>(f: impl FnOnce() -> T) -> (T, Duration) {
361        let start = Instant::now();
362        let result = f();
363        let duration = start.elapsed();
364        (result, duration)
365    }
366
367    /// Time a function and record the duration in the provided timer
368    #[inline]
369    pub fn time_and_record<T>(timer: &Timer, f: impl FnOnce() -> T) -> T {
370        let _timing_guard = timer.start();
371        f() // Timer automatically records when guard drops
372    }
373
374    /// Create a scoped timer that records to the provided timer
375    #[inline]
376    pub fn scoped_timer(timer: &Timer) -> RunningTimer<'_> {
377        timer.start()
378    }
379
380    /// Benchmark a function with multiple iterations
381    pub fn benchmark<F>(name: &str, iterations: usize, f: F) -> Duration
382    where
383        F: Fn(),
384    {
385        let timer = Timer::new();
386
387        for _ in 0..iterations {
388            let _guard = timer.start();
389            f();
390        }
391
392        let stats = timer.stats();
393        println!(
394            "Benchmark '{}': {} iterations, avg: {:?}, total: {:?}",
395            name, iterations, stats.average, stats.total
396        );
397
398        stats.average
399    }
400}
401
402/// Convenience macros
403#[macro_export]
404macro_rules! time_block {
405    ($timer:expr, $block:block) => {{
406        let _timing_guard = $timer.start();
407        $block
408    }};
409}
410
411#[macro_export]
412/// Macro to time a function call and record the result
413///
414/// # Examples
415///
416/// ```rust
417/// # use metrics_lib::time_fn;
418/// let (result, duration) = time_fn!({
419///     // Some work to time
420///     std::thread::sleep(std::time::Duration::from_millis(10));
421///     "done"
422/// });
423/// assert!(duration >= std::time::Duration::from_millis(10));
424/// assert_eq!(result, "done");
425/// ```
426macro_rules! time_fn {
427    ($func:expr) => {{
428        let start = std::time::Instant::now();
429        let result = $func;
430        let duration = start.elapsed();
431        (result, duration)
432    }};
433}
434
435#[cfg(test)]
436mod tests {
437    use super::*;
438    use std::sync::Arc;
439    use std::thread;
440
441    #[test]
442    fn test_basic_operations() {
443        let timer = Timer::new();
444
445        assert!(timer.is_empty());
446        assert_eq!(timer.count(), 0);
447        assert_eq!(timer.total(), Duration::ZERO);
448        assert_eq!(timer.average(), Duration::ZERO);
449
450        // Record a duration
451        timer.record(Duration::from_millis(100));
452
453        assert!(!timer.is_empty());
454        assert_eq!(timer.count(), 1);
455        assert!(timer.total() >= Duration::from_millis(99)); // Account for precision
456        assert!(timer.average() >= Duration::from_millis(99));
457    }
458
459    #[test]
460    fn test_running_timer() {
461        let timer = Timer::new();
462
463        {
464            let running = timer.start();
465            thread::sleep(Duration::from_millis(10));
466            assert!(running.elapsed() >= Duration::from_millis(9));
467        } // Automatically recorded when dropped
468
469        assert_eq!(timer.count(), 1);
470        assert!(timer.average() >= Duration::from_millis(9));
471    }
472
473    #[test]
474    fn test_manual_stop() {
475        let timer = Timer::new();
476
477        let running = timer.start();
478        thread::sleep(Duration::from_millis(5));
479        running.stop(); // Manual stop
480
481        assert_eq!(timer.count(), 1);
482        assert!(timer.average() >= Duration::from_millis(4));
483    }
484
485    #[test]
486    fn test_batch_recording() {
487        let timer = Timer::new();
488
489        let durations = vec![
490            Duration::from_millis(10),
491            Duration::from_millis(20),
492            Duration::from_millis(30),
493        ];
494
495        timer.record_batch(&durations);
496
497        assert_eq!(timer.count(), 3);
498        assert_eq!(timer.min(), Duration::from_millis(10));
499        assert_eq!(timer.max(), Duration::from_millis(30));
500        assert_eq!(timer.total(), Duration::from_millis(60));
501        assert_eq!(timer.average(), Duration::from_millis(20));
502    }
503
504    #[test]
505    fn test_min_max_tracking() {
506        let timer = Timer::new();
507
508        timer.record(Duration::from_millis(50));
509        timer.record(Duration::from_millis(10));
510        timer.record(Duration::from_millis(100));
511        timer.record(Duration::from_millis(25));
512
513        assert_eq!(timer.count(), 4);
514        assert_eq!(timer.min(), Duration::from_millis(10));
515        assert_eq!(timer.max(), Duration::from_millis(100));
516
517        // Check average is approximately 46.25ms (allowing for precision differences)
518        let avg = timer.average();
519        assert!(
520            avg >= Duration::from_millis(46) && avg <= Duration::from_millis(47),
521            "Average {:?} should be between 46ms and 47ms",
522            avg
523        );
524    }
525
526    #[test]
527    fn test_reset() {
528        let timer = Timer::new();
529
530        timer.record(Duration::from_millis(100));
531        assert!(!timer.is_empty());
532
533        timer.reset();
534        assert!(timer.is_empty());
535        assert_eq!(timer.count(), 0);
536        assert_eq!(timer.total(), Duration::ZERO);
537        assert_eq!(timer.min(), Duration::ZERO);
538        assert_eq!(timer.max(), Duration::ZERO);
539    }
540
541    #[test]
542    fn test_statistics() {
543        let timer = Timer::new();
544
545        for i in 1..=10 {
546            timer.record(Duration::from_millis(i * 10));
547        }
548
549        let stats = timer.stats();
550        assert_eq!(stats.count, 10);
551        assert_eq!(stats.total, Duration::from_millis(550)); // Sum of 10+20+...+100
552        assert_eq!(stats.average, Duration::from_millis(55));
553        assert_eq!(stats.min, Duration::from_millis(10));
554        assert_eq!(stats.max, Duration::from_millis(100));
555        assert!(stats.rate_per_second > 0.0);
556        assert!(stats.age > Duration::from_nanos(0));
557    }
558
559    #[test]
560    fn test_high_concurrency() {
561        let timer = Arc::new(Timer::new());
562        let num_threads = 50;
563        let recordings_per_thread = 1000;
564
565        let handles: Vec<_> = (0..num_threads)
566            .map(|thread_id| {
567                let timer = Arc::clone(&timer);
568                thread::spawn(move || {
569                    for i in 0..recordings_per_thread {
570                        // Record varying durations
571                        let duration_ms = (thread_id * recordings_per_thread + i) % 100 + 1;
572                        timer.record(Duration::from_millis(duration_ms as u64));
573                    }
574                })
575            })
576            .collect();
577
578        for handle in handles {
579            handle.join().unwrap();
580        }
581
582        let stats = timer.stats();
583        assert_eq!(stats.count, num_threads * recordings_per_thread);
584        assert!(stats.min > Duration::ZERO);
585        assert!(stats.max > Duration::ZERO);
586        assert!(stats.average > Duration::ZERO);
587        assert!(stats.rate_per_second > 0.0);
588    }
589
590    #[test]
591    fn test_concurrent_timing() {
592        let timer = Arc::new(Timer::new());
593        let num_threads = 20;
594
595        let handles: Vec<_> = (0..num_threads)
596            .map(|_| {
597                let timer = Arc::clone(&timer);
598                thread::spawn(move || {
599                    for _ in 0..100 {
600                        let _guard = timer.start();
601                        thread::sleep(Duration::from_micros(100)); // Very short sleep
602                    }
603                })
604            })
605            .collect();
606
607        for handle in handles {
608            handle.join().unwrap();
609        }
610
611        let stats = timer.stats();
612        assert_eq!(stats.count, num_threads * 100);
613        assert!(stats.average >= Duration::from_micros(50)); // Should be at least 50μs
614    }
615
616    #[test]
617    fn test_utility_functions() {
618        // Test time_fn
619        let (result, duration) = utils::time_fn(|| {
620            thread::sleep(Duration::from_millis(10));
621            42
622        });
623
624        assert_eq!(result, 42);
625        assert!(duration >= Duration::from_millis(9));
626
627        // Test time_and_record
628        let timer = Timer::new();
629        let result = utils::time_and_record(&timer, || {
630            thread::sleep(Duration::from_millis(5));
631            "hello"
632        });
633
634        assert_eq!(result, "hello");
635        assert_eq!(timer.count(), 1);
636        assert!(timer.average() >= Duration::from_millis(4));
637
638        // Test benchmark
639        let avg_duration = utils::benchmark("test_function", 10, || {
640            thread::sleep(Duration::from_millis(1));
641        });
642
643        assert!(avg_duration >= Duration::from_millis(1));
644    }
645
646    #[test]
647    fn test_macros() {
648        let timer = Timer::new();
649
650        // Test time_block macro
651        let result = time_block!(timer, {
652            thread::sleep(Duration::from_millis(5));
653            "result"
654        });
655
656        assert_eq!(result, "result");
657        assert_eq!(timer.count(), 1);
658
659        // Test time_fn macro
660        let (result, duration) = time_fn!({
661            thread::sleep(Duration::from_millis(2));
662            100
663        });
664
665        assert_eq!(result, 100);
666        assert!(duration >= Duration::from_millis(1));
667    }
668
669    #[test]
670    fn test_display_and_debug() {
671        let timer = Timer::new();
672        timer.record(Duration::from_millis(100));
673
674        let display_str = format!("{}", timer);
675        assert!(display_str.contains("Timer"));
676        assert!(display_str.contains("count: 1"));
677
678        let debug_str = format!("{:?}", timer);
679        assert!(debug_str.contains("Timer"));
680        assert!(debug_str.contains("count"));
681        assert!(debug_str.contains("average"));
682    }
683}
684
685#[cfg(all(test, feature = "bench-tests", not(tarpaulin)))]
686#[allow(unused_imports)]
687mod benchmarks {
688    use super::*;
689    use std::time::Instant;
690
691    #[cfg_attr(not(feature = "bench-tests"), ignore)]
692    #[test]
693    fn bench_timer_record() {
694        let timer = Timer::new();
695        let duration = Duration::from_nanos(1000);
696        let iterations = 1_000_000;
697
698        let start = Instant::now();
699        for _ in 0..iterations {
700            timer.record(duration);
701        }
702        let elapsed = start.elapsed();
703
704        println!(
705            "Timer record: {:.2} ns/op",
706            elapsed.as_nanos() as f64 / iterations as f64
707        );
708
709        assert_eq!(timer.count(), iterations);
710        // Should be under 300ns per record (relaxed from 200ns)
711        assert!(elapsed.as_nanos() / (iterations as u128) < 300);
712    }
713
714    #[cfg_attr(not(feature = "bench-tests"), ignore)]
715    #[test]
716    fn bench_running_timer() {
717        let timer = Timer::new();
718        let iterations = 100_000;
719
720        let start = Instant::now();
721        for _ in 0..iterations {
722            let guard = timer.start();
723            // Do minimal work
724            let _ = guard.elapsed();
725            guard.stop();
726        }
727        let elapsed = start.elapsed();
728
729        println!(
730            "Running timer: {:.2} ns/op",
731            elapsed.as_nanos() as f64 / iterations as f64
732        );
733
734        assert_eq!(timer.count(), iterations);
735        // Should be under 1500ns per timer operation (relaxed from 1000ns)
736        assert!(elapsed.as_nanos() / (iterations as u128) < 1500);
737    }
738
739    #[cfg_attr(not(feature = "bench-tests"), ignore)]
740    #[test]
741    fn bench_timer_stats() {
742        let timer = Timer::new();
743
744        // Fill timer with data
745        for i in 0..1000 {
746            timer.record(Duration::from_nanos(i * 1000));
747        }
748
749        let iterations = 1_000_000;
750        let start = Instant::now();
751
752        for _ in 0..iterations {
753            let _ = timer.stats();
754        }
755
756        let elapsed = start.elapsed();
757        println!(
758            "Timer stats: {:.2} ns/op",
759            elapsed.as_nanos() as f64 / iterations as f64
760        );
761
762        // Should be very fast since it's just atomic loads (relaxed from 100ns to 300ns)
763        assert!(elapsed.as_nanos() / iterations < 300);
764    }
765}