performance_timing/
lib.rs

1use std::time::Instant;
2use core::arch::x86_64::_rdtsc;
3use criterion::measurement::Measurement;
4use criterion::measurement::ValueFormatter;
5use criterion::Throughput;
6
7/// Run function with known latency.
8/// Assume both `sub` & `and` ops are single cycle on all architectures.
9/// Might not behave as expected with another code running on the same
10/// phisical core.
11/// 
12/// Returns final counter value. Useful for creating dep chains with known latency.
13pub fn const_cycle_loop(mut cycles: u64) -> u64 {
14    assert_eq!(cycles % 4, 0);
15    assert!(cycles < 0xFFFFFFFFu64);
16
17    // Trick the compiler not to optimize this loop out
18    cycles = cycles / 2;
19    while cycles > 0 {
20        cycles = cycles - 1;
21        cycles = cycles & 0x700FFFFFFFFu64;
22    }
23    return cycles;
24}
25
26/// CPU frequency information structure
27#[derive(Debug)]
28pub struct FreqInfo {
29    /// Current core running frequency
30    frequency: f32,
31    /// Time stamp counter scaling factor
32    tsc_scaling: f32
33}
34
35/// CPU information structure. Provides frequency and TSC-to-cycle scaling information.
36pub struct CPUInfo;
37
38impl CPUInfo {
39    /// Get current core frequency.
40    /// Runs known latency loop and time it. This information allows to calculate core frequency.
41    /// Current method might not work correctly when something running on second thread (SMT).
42    pub fn get_frequency_hz() -> FreqInfo {
43        let tot_cycles = 1_000_000;
44        let start = Instant::now();
45        // TODO: More accurate freq measurement
46        let ts_s = CPUInfo::get_time_stamp();
47        let r = const_cycle_loop(tot_cycles);
48        let ts_e = CPUInfo::get_time_stamp();
49        let elapsed = start.elapsed();
50        let time_ns = elapsed.as_nanos() + r as u128;
51        let mut freq = (1e9 * tot_cycles as f32) / ( time_ns as f32 );
52        freq = (freq  / 50_000_000f32) * 50_000_000f32;
53
54        return FreqInfo {
55            frequency: freq,
56            tsc_scaling: tot_cycles as f32 / (ts_e - ts_s) as f32 };
57    }
58
59    /// Get core frequency in GHz.
60    /// Uses `CPUInfo::get_frequency_hz` method.
61    pub fn get_frequency_ghz() -> FreqInfo {
62        let mut r = CPUInfo::get_frequency_hz();
63        r.frequency /= 1e9f32;
64        return r;
65    }
66
67    /// Get current CPU time stamp counter value
68    /// Uses `RDTSC` instruction on `x86` architectures
69    pub fn get_time_stamp() -> u64 {
70        let r: u64;
71        unsafe {
72            r = _rdtsc();
73        }
74      return r;
75    }
76}
77
78/// Measure code block performance by collecting samples.
79/// It relies on the fact that objects get destroyed 
80/// at the end of the block.
81/// 
82/// ```rust
83/// let mut loop_timing = MeasureRegion::new();
84/// for _ in 0..N {
85///   let _ = loop_timing.get_sample();
86///   foo();
87/// }
88/// let cpu_cycles = loop_timing.get_average_sample() *
89///   CPUInfo::get_frequency_hz().tsc_scaling;
90/// ```
91pub struct MeasureRegion {
92    region_name: String,
93    dump_on_drop: bool,
94    num_samples: u64,
95    sum_samples: u64
96}
97
98/// Measurement sample created by `MeasureRegion`
99/// Shall not be created directly.
100pub struct MeasureSample<'a> {
101    parent: &'a mut MeasureRegion,
102    start_time: u64,
103    end_time: u64
104}
105
106impl MeasureRegion {
107    pub fn new_named(region_name: String, dump_on_drop: bool) -> Self {
108        MeasureRegion { region_name, dump_on_drop, num_samples: 0, sum_samples: 0 }
109    }
110    
111    pub fn new() -> Self {
112        MeasureRegion { region_name: String::from("default_name"), dump_on_drop: false,
113                        num_samples: 0, sum_samples: 0 }
114    }
115
116    pub fn get_sample(&mut self) -> MeasureSample {
117        MeasureSample::new(self)
118    }
119
120    pub fn get_average_sample(&self) -> f32 {
121        return self.sum_samples as f32 / self.num_samples as f32;
122    }
123
124    /// Get total running time in milliseconds
125    pub fn get_total_time(&self) -> u64 {
126        return self.sum_samples;
127    }
128
129    fn record_sample(&mut self, sample: u64) {
130        self.num_samples += 1;
131        self.sum_samples += sample;
132    }
133}
134
135impl Drop for MeasureRegion {
136    fn drop(&mut self) {
137        if self.dump_on_drop {
138            println!("{}: {} ref.cycles", self.region_name, self.get_average_sample());
139        }
140    }
141}
142
143impl<'a> MeasureSample<'a> {
144
145  pub fn new(parent: &'a mut MeasureRegion) -> Self {
146    MeasureSample { parent, start_time: CPUInfo::get_time_stamp(), end_time: 0 }
147  }
148
149  /// Get sample value
150  fn get_value(&self) -> u64 {
151      self.end_time - self.start_time
152  }
153}
154
155impl<'a> Drop for MeasureSample<'a> {
156    fn drop(&mut self) {
157        // Store sample in the parent container
158        if self.end_time == 0 {
159            self.end_time = CPUInfo::get_time_stamp();
160        }
161        self.parent.record_sample(self.get_value());
162    }
163}
164
165// Get function running time in reference cycles
166pub fn measure_function_perf<F>(f: F)  -> f32
167where F: Fn() {
168    let min_test: usize = 100;
169    let min_bench_time: u64 = 10_000_000;
170
171    let mut m = MeasureRegion::new();
172
173    while m.get_total_time() < min_bench_time {
174        let _s = m.get_sample();
175        for _ in 0..min_test {
176            f();
177        }
178    }
179    return m.get_average_sample() / min_test as f32;
180}
181
182pub struct CycleInstant {
183    start: u64
184}
185
186impl CycleInstant {
187    pub fn now() -> CycleInstant {
188        CycleInstant { start: CPUInfo::get_time_stamp() }
189    }
190
191    pub fn elapsed(&self) -> u64 {
192        CPUInfo::get_time_stamp() - self.start
193    }
194}
195
196/// Custom cycle accurate measurement class for criterion
197/// 
198/// ```rust
199/// pub fn criterion_benchmark(c: &mut Criterion<CriterionCycleCounter>) {
200///   c.bench_function("cycle_10K", |b| b.iter(|| const_cycle_loop(black_box(10_000))));
201/// }
202///
203/// fn core_cycle_measurement() -> Criterion<CriterionCycleCounter> {
204///   Criterion::default().with_measurement(CriterionCycleCounter)
205/// }
206///
207/// criterion_group! {
208///   name = benches;
209///   config = core_cycle_measurement();
210///   targets = criterion_benchmark
211/// }
212/// ```
213pub struct CriterionCycleCounter;
214
215impl Measurement for CriterionCycleCounter {
216    type Intermediate = CycleInstant;
217    type Value = u64;
218
219    fn start(&self) -> Self::Intermediate {
220        CycleInstant::now()
221    }
222
223    fn end(&self, i: Self::Intermediate) -> Self::Value {
224        i.elapsed()
225    }
226
227    fn add(&self, v1: &Self::Value, v2: &Self::Value) -> Self::Value {
228        *v1 + *v2
229    }
230
231    fn zero(&self) -> Self::Value {
232        0u64
233    }
234
235    fn to_f64(&self, val: &Self::Value) -> f64 {
236        *val as f64 * CPUInfo::get_frequency_hz().tsc_scaling as f64
237    }
238
239    fn formatter(&self) -> &dyn ValueFormatter {
240        &CriterionCycleCounter
241    }
242}
243
244impl ValueFormatter for CriterionCycleCounter {
245    fn format_value(&self, value: f64) -> String {
246        format!("{:.3} clocks", value)
247    }
248
249    fn format_throughput(&self, throughput: &Throughput, value: f64) -> String {
250        match *throughput {
251            Throughput::Bytes(bytes) => format!(
252                "{} b/c",
253                bytes as f64 / (value)
254            ),
255            Throughput::Elements(elems) => format!(
256                "{} elem/c",
257                elems as f64 / (value)
258            ),
259        }
260    }
261
262    fn scale_values(&self, _typical_value: f64, _values: &mut [f64]) -> &'static str {
263        "clocks"
264    }
265
266    fn scale_throughputs(&self, _typical_value: f64, throughput: &Throughput, _values: &mut [f64]) -> &'static str {
267        match *throughput {
268            Throughput::Bytes(_bytes) => {
269                "b/c"
270            }
271            Throughput::Elements(_elems) => {
272                "elem/c"
273            }
274        }
275    }
276    
277    fn scale_for_machines(&self, _values: &mut [f64]) -> &'static str {
278        "clocks"
279    }
280}
281
282pub fn cycle_accurate_config() -> criterion::Criterion<CriterionCycleCounter> {
283    criterion::Criterion::default().with_measurement(CriterionCycleCounter)
284}
285
286#[cfg(test)]
287mod tests {
288    use crate::{CPUInfo, MeasureRegion};
289    use crate::const_cycle_loop;
290
291    #[test]
292    fn it_works() {
293        const_cycle_loop(200_000_000); // Warmup CPU
294        for _ in 0..10 {
295            println!("Current CPU freq: {}GHz", CPUInfo::get_frequency_hz().frequency / 1e9f32);
296        }
297
298        let mut loop_timing = MeasureRegion::new();
299        for _ in 0..10 {
300            let _s = loop_timing.get_sample();
301            const_cycle_loop(100_000_000);
302        }
303        println!("Timing info: {}",loop_timing.get_average_sample());
304    }
305
306    #[test]
307    fn test_tsc_scaling() {
308        let ckl_cnt = 100_000_000u64;
309        const_cycle_loop(ckl_cnt); // Warmup CPU
310        let mut loop_timing = MeasureRegion::new();
311        for _ in 0..10 {
312            let _s = loop_timing.get_sample();
313            const_cycle_loop(ckl_cnt);
314        }
315        let cpu_info = CPUInfo::get_frequency_hz();
316
317        let measured_cycles = loop_timing.get_average_sample() * cpu_info.tsc_scaling;
318        let d = (ckl_cnt as f32 - measured_cycles).abs();
319
320        println!("CPU info: {:?}", cpu_info);
321        println!("expected {}, measured {}", ckl_cnt, measured_cycles);
322
323        // Measured average cycles are within 5% accuracy
324        let accuracy = 0.05f32;
325        assert_eq!(d < (ckl_cnt as f32 * accuracy), true);
326    }
327}
performance_timing/lib.rs

performance_timing/
lib.rs
