I wrote two empty functions in rust with the hope of using each to test the use of retain on vectors or the use of filter on iterators, after writing the empty function for each case, on running the program, i noticed a huge dissimilarity between the duration of each function, this means that adding any logic to the currently empty function would lead to erroneous conclusions on their execution time.
use std::time::Instant;
fn use_filter() {
}
fn use_retain() {
}
fn run_multiple(f: fn(), times: u64) {
for _ in 0..times {
f()
}
}
fn main() {
let iter_count: u32 = 1_000_000_000;
let _start_1 = Instant::now();
run_multiple(use_filter, iter_count as u64);
let duration = Instant::now() - _start_1;
println!("Use Filter duration: {:?}", duration / iter_count);
let _start_2 = Instant::now();
run_multiple(use_retain, iter_count as u64);
let duration = Instant::now() - _start_2;
println!("Use Retain duration: {:?}", duration / iter_count);
}
Expected output
Use Filter duration: xns
Use Retain duration: xns
where x is the same for both function, since they are both empty and do nothing
Actual Output
Use Filter duration: 8ns
Use Retain duration: 10ns
what could explain empty functions having very different execution time in rust programming language.
The result as given in the question is entirely due to noise, and carries no useful information. What the code compiles down to is
movq std::time::Instant::now@GOTPCREL(%rip), %r14
callq *%r14 // First call to `Instant::now()`
movq %rax, %rbx
// `use_filter` went away entirely, as one would expect
movl %edx, %ebp
callq *%r14 // Second call to `Instand::now()`
movq %rax, %rdi
movl %edx, %esi
movq %rbx, %rdx
movl %ebp, %ecx
callq *<std::time::Instant as core::ops::arith::Sub>::sub@GOTPCREL(%rip)
// [...] print result
callq *%r14 // Third call to `Instant::now()`
movq %rax, %rbx
// `use_retention` went away entirely
movl %edx, %ebp
callq *%r14 // Third call to `Instant::now()`
movq %rax, %rdi
movl %edx, %esi
movq %rbx, %rdx
movl %ebp, %ecx
callq *<std::time::Instant as core::ops::arith::Sub>::sub@GOTPCREL(%rip)
// [...] print result
That is, the time difference you are measuring is the time it took to issue the two calls to Instant::now()
, with nothing in between. There is no difference. The time difference you are seeing is caused by inaccuracies in the implementation of Instant::now()
, thread-scheduling, or general noise.