I am currently experiencing a strange issue with program execution timing. Due to this being intellectual property/patent related research, I simply cannot post the code that I am using, or any portion of it, but the nearest approximation in pseudo-code is:
int main()
{
// Loop through a given number of iterations for a parameter.
for (int i = 0; i < 10; i++)
{
// Loop through a given number of iterations for another parameter.
for (int j = 0; j < 10; j++)
{
// Read in some specific data files.
input = read_from_files(files[i][j]);
// Instantiate the model with parameters that directly relate to the input.
Model model(parameters);
start_time = clock();
// Run the model and get the result.
result = model.process(input);
end_time = clock();
processing_time = end_time - start_time;
out_file << processing_time << std::endl;
}
}
}
The data-set contains hundreds of files that are all exactly the same size/format/layout (think gene sequences), and I’m iterating through each and every file, applying a sophisticated processing algorithm, and getting a numerical result at the end. It is expected that the run time per file would be very close to identical (statistically acceptable standard deviation, that is), with fluctuations due to Windows and everything else that the computer is doing.
The problem that I am seeing is that, the longer that the program runs, the slower that it gets. Example, where the first entry is the result of the clock() – clock() call (seconds) and the second is the result of using QueryPerformanceCounter(), as implemented in http://advancedcppwithexamples.blogspot.com.au/2009/08/measuring-elapsed-time-in-c-using_21.html:
5.195 5195
5.207 5207
5.246 5246
5.372 5372
5.418 5418
5.552 5552
5.886 5886
5.508 5508
5.559 5559
5.593 5593
5.587 5587
5.645 5645
5.74 5740
5.727 5728
5.635 5635
5.78 5781
5.706 5706
5.683 5683
5.647 5646
5.593 5594
5.651 5651
5.668 5667
This second sequence is from an earlier trial (approximately half the data size per file, hence relatively twice the processing throughput).
2.558
2.512
2.497
2.527
2.545
2.527
2.511
2.513
2.514
2.511
2.53
2.559
2.511
2.561
2.528
2.528
2.498
2.543
2.543
2.576
2.621
2.543
2.544
2.605
2.558
2.529
2.527
2.543
2.528
2.574
2.527
2.543
2.543
2.574
2.543
2.527
2.559
2.543
2.543
2.543
2.543
2.547
2.558
2.574
2.589
2.561
2.559
2.549
2.574
2.621
2.606
2.577
2.574
2.578
2.59
2.574
2.576
2.591
2.605
2.59
2.591
2.652
2.639
2.607
2.621
2.607
2.62
2.667
2.701
2.701
2.667
2.749
2.637
2.668
2.639
2.671
2.636
2.654
2.622
2.652
2.638
2.652
2.636
2.686
2.668
2.683
2.669
2.683
2.668
2.699
2.683
2.699
2.717
2.746
2.762
2.745
2.777
2.762
2.795
2.761
2.808
2.796
2.808
2.808
2.795
2.808
2.808
2.795
2.902
2.821
2.746
2.762
2.907
2.795
2.903
2.796
2.825
2.808
2.824
2.798
2.857
2.841
2.915
3.029
3.053
3.025
2.985
2.87
3.313
2.93
2.925
2.934
2.949
2.906
2.892
2.914
2.914
2.908
2.934
2.915
2.946
2.897
2.954
2.919
3.041
3.003
3.001
2.954
2.952
2.974
2.903
2.937
2.977
2.922
2.967
2.9
2.965
2.933
2.959
3.032
3.014
2.973
2.945
2.917
2.948
2.958
2.942
2.928
2.966
2.928
2.969
3.015
2.986
2.987
3.006
3.005
3.032
3.02
3.035
2.959
2.972
2.95
2.969
2.946
2.944
2.958
2.985
3.006
2.979
2.964
2.985
2.986
3.05
3.079
3.058
3.007
2.98
2.95
3.004
2.956
2.969
2.909
2.952
2.975
2.971
2.937
2.939
2.94
2.914
2.95
3.103
2.934
3.048
2.929
2.953
2.927
2.95
2.938
2.974
2.92
2.939
2.896
2.911
2.935
3.005
2.927
2.934
3.085
3.164
2.966
3.198
2.999
2.983
3.045
2.938
2.988
2.973
2.916
2.944
2.953
2.959
2.895
2.95
2.928
2.914
2.947
2.942
3.073
3.086
3.119
3.111
3.104
3.117
2.916
2.954
2.924
2.924
3.018
2.949
3.058
3.058
2.998
3.324
3.026
3.057
2.932
3.058
3.057
3.058
3.03
3.058
3.073
3.058
3.058
3.042
3.057
3.088
3.042
3.044
3.044
3.073
3.097
3.057
3.058
3.059
2.933
3.042
3.089
3.042
3.074
3.028
2.933
3.058
3.089
3.058
3.058
3.058
2.933
3.042
3.074
3.042
2.933
3.06
3.073
3.057
3.06
3.042
3.074
3.042
3.089
3.042
3.058
3.043
2.919
3.057
3.057
3.057
3.029
3.043
3.047
3.027
3.138
3.166
3.104
3.076
3.06
3.074
3.198
3.12
3.073
While this may not seem like a problem (0.5 seconds per iteration), when you are dealing with hundreds to thousands of iterations, time adds up and the standard deviation of the model output increases.
This has all been undertaken on a Core i5-4570 with 8 GB DDR3 running Visual Studio 2010, with certain functions of OpenCV 2.4.7 used due to the fact that, although we aren’t working with images, the function is exactly what we need and is relatively optimised.
Our initial thoughts was a memory issue, but given that the class instantiations are scoped within the lowest layer of the looping, each iteration should destroy the instances before the next iteration?