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
/*! A lightweight micro-benchmarking library which: * uses linear regression to screen off constant error; * handles benchmarks which mutate state; * is very easy to use! Easybench is designed for benchmarks with a running time in the range `1 ns < x < 1 ms` - results may be unreliable if benchmarks are very quick or very slow. It's inspired by [criterion], but doesn't do as much sophisticated analysis (no outlier detection, no HTML output). [criterion]: https://hackage.haskell.org/package/criterion ``` use easybench::{bench,bench_env}; # fn fib(_: usize) -> usize { 0 } # // Simple benchmarks are performed with `bench`. println!("fib 200: {}", bench(|| fib(200) )); println!("fib 500: {}", bench(|| fib(500) )); // If a function needs to mutate some state, use `bench_env`. println!("reverse: {}", bench_env(vec![0;100], |xs| xs.reverse() )); println!("sort: {}", bench_env(vec![0;100], |xs| xs.sort() )); ``` Running the above yields the following results: ```none fib 200: 38 ns (R²=1.000, 26053497 iterations in 154 samples) fib 500: 110 ns (R²=1.000, 9131584 iterations in 143 samples) reverse: 54 ns (R²=0.999, 5669992 iterations in 138 samples) sort: 93 ns (R²=1.000, 4685942 iterations in 136 samples) ``` Easy! However, please read the [caveats](#caveats) below before using. # Benchmarking algorithm An *iteration* is a single execution of your code. A *sample* is a measurement, during which your code may be run many times. In other words: taking a sample means performing some number of iterations and measuring the total time. The first sample we take performs only 1 iteration, but as we continue taking samples we increase the number of iterations exponentially. We stop when a global time limit is reached (currently 1 second). If a benchmark must mutate some state while running, before taking a sample `n` copies of the initial state are prepared, where `n` is the number of iterations in that sample. Once we have the data, we perform OLS linear regression to find out how the sample time varies with the number of iterations in the sample. The gradient of the regression line tells us how long it takes to perform a single iteration of the benchmark. The R² value is a measure of how much noise there is in the data. # Caveats ## Caveat 1: Harness overhead **TL;DR: Compile with `--release`; the overhead is likely to be within the noise of your benchmark.** Any work which easybench does once-per-sample is ignored (this is the purpose of the linear regression technique described above). However, work which is done once-per-iteration *will* be counted in the final times. * In the case of [`bench`] this amounts to incrementing the loop counter and [copying the return value](#bonus-caveat-black-box). * In the case of [`bench_env`], we also do a lookup into a big vector in order to get the environment for that iteration. * If you compile your program unoptimised, there may be additional overhead. [`bench`]: fn.bench.html [`bench_env`]: fn.bench_env.html The cost of the above operations depend on the details of your benchmark; namely: (1) how large is the return value? and (2) does the benchmark evict the environment vector from the CPU cache? In practice, these criteria are only satisfied by longer-running benchmarks, making these effects hard to measure. If you have concerns about the results you're seeing, please take a look at [the inner loop of `bench_env`][source]. The whole library `cloc`s in at under 100 lines of code, so it's pretty easy to read. [source]: ../src/easybench/lib.rs.html#229-237 ## Caveat 2: Sufficient data **TL;DR: Measurements are unreliable when code takes too long (> 1 ms) to run.** Each benchmark collects data for 1 second. This means that in order to collect a statistically significant amount of data, your code should run much faster than this. When inspecting the results, make sure things look statistically significant. In particular: * Make sure the number of samples is big enough. More than 100 is probably OK. * Make sure the R² isn't suspiciously low. It's easy to achieve a high R² value when the number of samples is small, so unfortunately the definition of "suspiciously low" depends on how many samples were taken. As a rule of thumb, expect values greater than 0.99. ## Caveat 3: Pure functions **TL;DR: Return enough information to prevent the optimiser from eliminating code from your benchmark.** Benchmarking pure functions involves a nasty gotcha which users should be aware of. Consider the following benchmarks: ``` # use easybench::{bench,bench_env}; # # fn fib(_: usize) -> usize { 0 } # let fib_1 = bench(|| fib(500) ); // fine let fib_2 = bench(|| { fib(500); } ); // spoiler: NOT fine let fib_3 = bench_env(0, |x| { *x = fib(500); } ); // also fine, but ugly # let _ = (fib_1, fib_2, fib_3); ``` The results are a little surprising: ```none fib_1: 110 ns (R²=1.000, 9131585 iterations in 144 samples) fib_2: 0 ns (R²=1.000, 413289203 iterations in 184 samples) fib_3: 109 ns (R²=1.000, 9131585 iterations in 144 samples) ``` Oh, `fib_2`, why do you lie? The answer is: `fib(500)` is pure, and its return value is immediately thrown away, so the optimiser replaces the call with a no-op (which clocks in at 0 ns). What about the other two? `fib_1` looks very similar, with one exception: the closure which we're benchmarking returns the result of the `fib(500)` call. When it runs your code, easybench takes the return value and tricks the optimiser into thinking it's going to use it for something, before throwing it away. This is why `fib_1` is safe from having code accidentally eliminated. In the case of `fib_3`, we actually *do* use the return value: each iteration we take the result of `fib(500)` and store it in the iteration's environment. This has the desired effect, but looks a bit weird. ## Bonus caveat: Black box The function which easybench uses to trick the optimiser (`black_box`) is stolen from [bencher], which [states]: [bencher]: https://docs.rs/bencher/ [states]: https://docs.rs/bencher/0.1.2/bencher/fn.black_box.html > NOTE: We don't have a proper black box in stable Rust. This is a workaround implementation, that > may have a too big performance overhead, depending on operation, or it may fail to properly avoid > having code optimized out. It is good enough that it is used by default. */ extern crate humantime; use std::f64; use std::fmt::{self,Display,Formatter}; use std::time::*; // Each time we take a sample we increase the number of iterations: // iters = ITER_SCALE_FACTOR ^ sample_no const ITER_SCALE_FACTOR: f64 = 1.1; // We try to spend this many seconds (roughly) in total on each benchmark. const BENCH_TIME_LIMIT_SECS: u64 = 1; /// Statistics for a benchmark run. #[derive(Debug, PartialEq, Clone)] pub struct Stats { /// The time, in nanoseconds, per iteration. If the benchmark generated fewer than 2 samples in /// the allotted time then this will be NaN. pub ns_per_iter: f64, /// The coefficient of determination, R². /// /// This is an indication of how noisy the benchmark was, where 1 is good and 0 is bad. Be /// suspicious of values below 0.9. pub goodness_of_fit: f64, /// How many times the benchmarked code was actually run. pub iterations: usize, /// How many samples were taken (ie. how many times we allocated the environment and measured /// the time). pub samples: usize, } impl Display for Stats { fn fmt(&self, f: &mut Formatter) -> fmt::Result { if self.ns_per_iter.is_nan() { write!(f, "Only generated {} sample(s) - we can't fit a regression line to that! \ Try making your benchmark faster.", self.samples) } else { let per_iter: humantime::Duration = Duration::from_nanos(self.ns_per_iter as u64).into(); let per_iter = format!("{}", per_iter); write!(f, "{:>11} (R²={:.3}, {} iterations in {} samples)", per_iter, self.goodness_of_fit, self.iterations, self.samples) } } } /// Run a benchmark. /// /// The return value of `f` is not used, but we trick the optimiser into thinking we're going to /// use it. Make sure to return enough information to prevent the optimiser from eliminating code /// from your benchmark! (See the module docs for more.) pub fn bench<F, O>(f: F) -> Stats where F: Fn() -> O { bench_env((), |_| f() ) } /// Run a benchmark with an environment. /// /// The value `env` is a clonable prototype for the "benchmark environment". Each iteration /// receives a freshly-cloned mutable copy of this environment. The time taken to clone the /// environment is not included in the results. /// /// Nb: it's very possible that we will end up allocating many (>10,000) copies of `env` at the /// same time. Probably best to keep it small. /// /// See `bench` and the module docs for more. /// /// ## Overhead /// /// Every iteration, `bench_env` performs a lookup into a big vector in order to get the /// environment for that iteration. If your benchmark is memory-intensive then this could, in the /// worst case, amount to a systematic cache-miss (ie. this vector would have to be fetched from /// DRAM at the start of every iteration). In this case the results could be affected by a hundred /// nanoseconds. This is a worst-case scenario however, and I haven't actually been able to trigger /// it in practice... but it's good to be aware of the possibility. pub fn bench_env<F, I, O>(env: I, f: F) -> Stats where F: Fn(&mut I) -> O, I: Clone { let mut data = Vec::new(); let bench_start = Instant::now(); // The time we started the benchmark (not used in results) // Collect data until BENCH_TIME_LIMIT_SECS is reached. while bench_start.elapsed() < Duration::from_secs(BENCH_TIME_LIMIT_SECS) { let iters = ITER_SCALE_FACTOR.powi(data.len() as i32).round() as usize; let mut xs = vec![env.clone();iters]; // Prepare the environments - one per iteration let iter_start = Instant::now(); // Start the clock for i in 0..iters { let ref mut x = xs[i]; // Lookup the env for this iteration pretend_to_use(f(x)); // Run the code and pretend to use the output } let time = iter_start.elapsed(); data.push((iters, time)); } // If the first iter in a sample is consistently slow, that's fine - that's why we do the // linear regression. If the first sample is slower than the rest, however, that's not fine. // Therefore, we discard the first sample as a cache-warming exercise. data.remove(0); // Compute some stats let (grad, r2) = regression(&data[..]); Stats { ns_per_iter: grad, goodness_of_fit: r2, iterations: data.iter().map(|&(x,_)| x).sum(), samples: data.len(), } } /// Compute the OLS linear regression line for the given data set, returning the line's gradient /// and R². Requires at least 2 samples. // // Overflows: // // * sum(x * x): num_samples <= 0.5 * log_k (1 + 2 ^ 64 (FACTOR - 1)) fn regression(data: &[(usize, Duration)]) -> (f64, f64) { if data.len() < 2 { return (f64::NAN, f64::NAN); } let data: Vec<(u64, u64)> = data.iter().map(|&(x,y)| (x as u64, as_nanos(y))).collect(); let n = data.len() as f64; let nxbar = data.iter().map(|&(x,_)| x ).sum::<u64>(); // iter_time > 5e-11 ns let nybar = data.iter().map(|&(_,y)| y ).sum::<u64>(); // TIME_LIMIT < 2 ^ 64 ns let nxxbar = data.iter().map(|&(x,_)| x*x).sum::<u64>(); // num_iters < 13_000_000_000 let nyybar = data.iter().map(|&(_,y)| y*y).sum::<u64>(); // TIME_LIMIT < 4.3 e9 ns let nxybar = data.iter().map(|&(x,y)| x*y).sum::<u64>(); let ncovar = nxybar as f64 - ((nxbar * nybar) as f64 / n); let nxvar = nxxbar as f64 - ((nxbar * nxbar) as f64 / n); let nyvar = nyybar as f64 - ((nybar * nybar) as f64 / n); let gradient = ncovar / nxvar; let r2 = (ncovar * ncovar) / (nxvar * nyvar); (gradient, r2) } // Panics if x is longer than 584 years (1.8e10 seconds) fn as_nanos(x: Duration) -> u64 { x.as_secs().checked_mul(1_000_000_000).expect("overflow: Duration was longer than 584 years") .checked_add(x.subsec_nanos() as u64).unwrap() } // Stolen from `bencher`, where it's known as `black_box`. // // NOTE: We don't have a proper black box in stable Rust. This is // a workaround implementation, that may have a too big performance overhead, // depending on operation, or it may fail to properly avoid having code // optimized out. It is good enough that it is used by default. // // A function that is opaque to the optimizer, to allow benchmarks to // pretend to use outputs to assist in avoiding dead-code // elimination. fn pretend_to_use<T>(dummy: T) -> T { unsafe { let ret = ::std::ptr::read_volatile(&dummy); ::std::mem::forget(dummy); ret } } #[cfg(test)] mod tests { use super::*; use std::thread; use std::time::Duration; fn fib(n: usize) -> usize { let mut i = 0; let mut sum = 0; let mut last = 0; let mut curr = 1usize; while i < n - 1 { sum = curr.wrapping_add(last); last = curr; curr = sum; i += 1; } sum } // This is only here because doctests don't work with `--nocapture`. #[test] #[ignore] fn doctests_again() { println!(); println!("fib 200: {}", bench(|| fib(200) )); println!("fib 500: {}", bench(|| fib(500) )); println!("reverse: {}", bench_env(vec![0;100], |xs| xs.reverse())); println!("sort: {}", bench_env(vec![0;100], |xs| xs.sort())); // This is fine: println!("fib 1: {}", bench(|| fib(500) )); // This is NOT fine: println!("fib 2: {}", bench(|| { fib(500); } )); // This is also fine, but a bit weird: println!("fib 3: {}", bench_env(0, |x| { *x = fib(500); } )); } #[test] fn very_quick() { println!(); println!("very quick: {}", bench(|| {})); } #[test] fn very_slow() { println!(); println!("very slow: {}", bench(|| thread::sleep(Duration::from_millis(400)))); } #[test] fn test_sleep() { println!(); println!("sleep 1 ms: {}", bench(|| thread::sleep(Duration::from_millis(1)))); } #[test] fn noop() { println!(); println!("noop base: {}", bench( | | {})); println!("noop 0: {}", bench_env(vec![0u64;0], |_| {})); println!("noop 16: {}", bench_env(vec![0u64;16], |_| {})); println!("noop 64: {}", bench_env(vec![0u64;64], |_| {})); println!("noop 256: {}", bench_env(vec![0u64;256], |_| {})); println!("noop 512: {}", bench_env(vec![0u64;512], |_| {})); } #[test] fn ret_value() { println!(); println!("no ret 32: {}", bench_env(vec![0u64;32], |x| { x.clone() })); println!("return 32: {}", bench_env(vec![0u64;32], |x| x.clone())); println!("no ret 256: {}", bench_env(vec![0u64;256], |x| { x.clone() })); println!("return 256: {}", bench_env(vec![0u64;256], |x| x.clone())); println!("no ret 1024: {}", bench_env(vec![0u64;1024], |x| { x.clone() })); println!("return 1024: {}", bench_env(vec![0u64;1024], |x| x.clone())); println!("no ret 4096: {}", bench_env(vec![0u64;4096], |x| { x.clone() })); println!("return 4096: {}", bench_env(vec![0u64;4096], |x| x.clone())); println!("no ret 50000: {}", bench_env(vec![0u64;50000], |x| { x.clone() })); println!("return 50000: {}", bench_env(vec![0u64;50000], |x| x.clone())); } }