chrono give different measures at same function

Question

i am trying to measure the execution time. i'm on windows 10 and use gcc compiler.

start_t = chrono::system_clock::now();
tree->insert();
end_t = chrono::system_clock::now();
rslt_period = chrono::duration_cast<chrono::nanoseconds>(end_t - start_t);

this is my code to measure time about bp_w->insert() the function insert work internally like follow (just pseudo code)

insert(){
    _load_node(node);
    // do something //
    _save_node(node, addr);
}

_save_node(n){
    ofstream file(name);
    file.write(n);
    file.close();
}

_load_node(n, addr){
    ifstream file(name);
    file.read_from(n, addr);
    file.close();
}

the actual results is, read is number of _load_node executions. write is number of _save_node executions. time is nano secs.

read  write time
1     1     1000000
1     1     0
2     1     0
1     1     0
1     1     0
1     1     0
2     1     0
1     1     1004000
1     1     1005000
1     1     0
1     1     0
1     1     15621000

i don't have any idea why this result come and want to know.

Answer 1

You are using the wrong clock. system_clock is not useful for timing intervals due to low resolution and its non-monotonic nature.

Use steady_clock instead. it is guaranteed to be monotonic and have a low enough resolution to be useful.

Answer 2

What you are trying to measure is ill-defined.

"How long did this code take to run" can seem simple. In practice, though, do you mean "how many CPU cycles my code took" ? Or how many cycles between my program and the other running programs ? Do you account for the time to load/unload it on the CPU ? Do you account for the CPU being throttled down when on battery ? Do you want to account for the time to access the main clock located on the motherboard (in terms of computation that is extremely far).

So, in practice timing will be affected by a lot of factors and the simple fact of measuring it will slow everything down. Don't expect nanosecond accuracy. Micros, maybe. Millis, certainly.

So, that leaves you in a position where any measurement will fluctuate a lot. The sane way is to average it out over multiple measurement. Or, even better, do the same operation (on different data) a thousand (million?) times and divide the results by a thousand.

Then, you'll get significant improvement on accuracy.

In code:

start_t = chrono::system_clock::now();
for(int i = 0; i < 1000000; i++)
tree->insert();
end_t = chrono::system_clock::now();