In C++, with chrono, I need to measure small elapsed times with precision.
Googling this didn't help me much... As the topic seems messy...
As this stays unclear, I came to write my own dummy code with 2 things in mind:
Check timer resolution: How to get the precision of high_resolution_clock?.
Get maximum precision: use
long doubleinstead ofdoubleas timecount: long double vs double.
Here is the code (test_elapse_measure.cpp):
#include <iostream>
#include <thread>
#include <chrono>
int main(int argc, char ** argv) {
int n = (argc == 2) ? atoi(argv[1]) : 1;
long double time_resolution = (long double) std::chrono::high_resolution_clock::period::num;
time_resolution /= (long double) std::chrono::high_resolution_clock::period::den;
std::cout << "time_resolution: " << time_resolution << " s" << std::endl;
std::chrono::high_resolution_clock::time_point start, stop;
{
start = std::chrono::high_resolution_clock::now();
std::this_thread::sleep_for(std::chrono::seconds(n));
stop = std::chrono::high_resolution_clock::now();
auto elaps = std::chrono::duration_cast<std::chrono::seconds>(stop - start);
long double count = elaps.count(); // precision: long double.
std::cout << "sleep: " << count << " s" << std::endl;
}
{
start = std::chrono::high_resolution_clock::now();
std::this_thread::sleep_for(std::chrono::milliseconds(n));
stop = std::chrono::high_resolution_clock::now();
auto elaps = std::chrono::duration_cast<std::chrono::milliseconds>(stop - start);
long double count = elaps.count(); // precision: long double.
std::cout << "sleep: " << count << " ms" << std::endl;
}
{
start = std::chrono::high_resolution_clock::now();
std::this_thread::sleep_for(std::chrono::nanoseconds(n));
stop = std::chrono::high_resolution_clock::now();
auto elaps = std::chrono::duration_cast<std::chrono::nanoseconds>(stop - start);
long double count = elaps.count(); // precision: long double.
std::cout << "sleep: " << count << " ns" << std::endl;
}
}
Running the code gives:
>> g++ -o test_elapse_measure test_elapse_measure.cpp
>> ./test_elapse_measure
time_resolution: 1e-09 s
sleep: 1 s
sleep: 1 ms
sleep: 94129 ns
>> ./test_elapse_measure 10
time_resolution: 1e-09 s
sleep: 10 s
sleep: 10 ms
sleep: 82093 ns
>> ./test_elapse_measure 100
time_resolution: 1e-09 s
sleep: 100 s
sleep: 100 ms
sleep: 70069 ns
Ideally, I need to measure elapsed from 1 nanoseconds up to several seconds. Timing resolution seems to say that I could measure nanoseconds (the timer seems precise enough), but, all nanosecond elapsed time measure are wrong?!...
Why is that? What did I miss?
EDIT
Or is there not way to measure nanosecond elapsed time?
Found this afterwards: measuring precise time in nanoseconds C++.
Best one can measure reliably with C++ would be millisecond?
EDIT
Adding here a bit of context.
I work on an algorithm which has 3 parts in it (in an iterative loop), and, has also several parameters to it. On overall, the algorithm takes a "long" time mostly because there may be a large number of iterations (loop), but, the 3 parts in the loop may be "fast". Turns out that, with some parameters, each part in the loop may take several seconds to milliseconds. But, with some other parameters, each part in the loop may take several milliseconds to nanoseconds (as milliseconds count prints 0!). I was in the process to try to understand where time was spent, so I started using chrono deeper. Unluckily, it's a one-shot algorithm and I wanted to understand where time is spent "inside" the algorithm, so, it's quite difficult/impossible to "loop over each part (itself in a loop...) of the algorithm to get an averaged timing" (I thought about that first - not realistic as questions raise only when large graphs are passed as inputs to the algorithm which becomes tricky/intractable to debug such that profiling was possibly a way to understand what's going on and where).
From answers below, I understand this is no easy for good reasons. I actually expected that, but, I wanted to have external points of view.
At that point, say in a case I have an overall time of 3000 ms, when I time each part in the loop and sum timing across iterations, I get 300 ms! Which is 10 times less than 3000: I'd have accepted a 1.x factor but 10 is an order of magnitude lost in space?! So I was like "Ok, maybe I add up many many 0's as I use milliseconds counters but some parts may take less and they are seen as 0". For now still not sure what's going on: my timings are not consistent (overall magnitude very different from accumulated parts magnitude). Bugs are still possible although I wrote code as carefully as possible. For me, at this point, there is no bug (generated results are tested OK with expected results), but I still don't get why I have inconsistent timing (overall vs parts).
Ideally I was looking for a way, in all cases (even measuring nanoseconds), to have a sensible superior estimate (even not exact for reasons well explained in answers here) of the elapsed time spent (up to now, in nanoseconds, I get outer-space timings): I guess, there is no way to get that...
