In the process of simplifying code posted for another question, I noticed AbsoluteTiming returned different results for the same code being timed, Range[0, 99], when the surrounding code was different. It was constantly different.

What is going on? Is Map caching and Do-AppendTo not? Is the call to Range[0, 99] close enough to to cost to retrieve the value from the cache so the sum of timing is only off by ~0.01?

I have changed the order, Map then Do-AppendTo, and still the Map is faster by ~0.01.

I also tried substituting Range[0, Mod[i++, 10000]] to negate the caching effect, same results. I tried timing different code and noticed the same difference.

You are measuring in the microsecond range, just above the resolution of the timer of your system (you get discrete jumps). I wonder how accurate and how practically relevant such short timings are. It would be interesting to know what exactly causes the difference, but I have doubts about whether this difference is reproducible at practically relevant times. (Can you amplify the times and still show the difference?) (Absolute)Timing cannot return such short times on a Windows system, so I can't play with it. The Win7 resolution is 1 ms, the WinXP one is 15 ms.
–
SzabolcsFeb 24 '12 at 20:28

@Szabolcs Can you amplify the times and still show the difference? Sure, do you have a suggestion on what I should use? I do have a theory, which is that since the difference is so small, increasing the time might drown out the difference. I agree with your thoughts that it might just be running up against the resolution of my machine.
–
mmorrisFeb 24 '12 at 22:33

I mean, can you provide a code sample which will show the difference on some clearly measurable time scale? (E.g. one would run in 1.1 seconds, the other in 0.8) If this is not possible, that's good news: then we don't need to worry about this when optimizing code.
–
SzabolcsFeb 26 '12 at 16:00

2

@mmorris I did not put any effort into this. If you accept your own, that is very fine. Please just do that.
–
SzabolcsMar 9 '12 at 8:03

1

@mmorris As far as I know, you don't get rep for accepting your own answer, so it wouldn't be a method of gaming the system. If you feel your answer provides a correct answer to your question and is the best of the set (which it is if it is the only one) feel free to accept it. I would allow for a day or two, just to see if any better answers get in.
–
Sjoerd C. de VriesMar 9 '12 at 12:16

1 Answer
1

As Szabolcs pointed out, I was running into the resolution of the timer in my system in my attempts to micro benchmark. Also, my attempts at micro benchmarking were incorrect I might add, but more on that later.

I was able to see the light only after scratching my head for a number of days on Szabolcs' comment and working on a performance package, I finally came across $TimeUnithere. I got the idea to use Pause[10*$TimeUnit] as the code being tested in each case. Clearly Pause[10*$TimeUnit] is above the resolution of the timer in my system. Oh, in case you are curious, $TimeUnit is 1/100 on my system (2011 MBP 17" running Lion).

For those of you who want to play along at home, the following is the updated micro benchmarking code: (btw it is still incorrect).

The results are as expected, there is no longer a consistent difference between the Do an Map implementations.

Incorrect Micro Benchmarking Method

So why are were my two implementations of micro benchmarking above incorrect? I wanted to capture timing values for each call of the code being tested over a large number of iterations so that I could perform various analytics on them (sum, mean, min, max, std dev, plotting, histogram, ...).

I thought AbsoluteTiming was incredibly precise. When I evaluated the simple expression 1, AbsoluteTiming[1] returned {0.000014, 1}. 0.000014 is way more precise than $TimeUnit on my system which was 0.01 right? Wrong!

Lets look at two different ways of micro benching marking the expression 1 for 1000000 iterations. But first, lets establish a base case to help us understand the results.

First thing we notice is that the Total(2.26236) is less than our expectation(14.) . Why the difference? Well first look at the Min(0.) and Max(0.000167), they are out side our oneTime(0.000014), which is good. If there are a significant number of individual times less than our oneTime value, that could explain the difference. It just so happened that Length[Select[individualTimes, # < oneTime & ]] returned 999939 .

Anyone know how Min can be 0. ? Is it because the expression was cached? If it was cached, it still would have taken some time. Maybe the time it took is less than what AbsoluteTiming can observe, hmmmm.

Woe wait a minute, the totalTime(0.015782) is no where close to the Total of the individualTimes(2.26236) not to mention our expectation(14.)! I must have messed something up. Okay let me think about this, could it be AbsoluteTime is not as precise as I originally thought? Ding ding, ding, give that man a cigar!

As the chaps at Wolfram said it here. AbsoluteTiming does not have the precision past $TimeUnit. So the oneTime and all of the individually collected timing values were prone to error as a result of the resolution of the timer of the system. Thanks again Szabolcs!

The the one timing value for all iterations also has the same error, but only since it is only called one time for 1000000 iterations and is less than $TimeUnit (0.01) it has a much smaller effect.

Okay, yeah I know, I should rerun the One AbsoluteTiming Value for All Iterations with iterations = 1000000000 to get a more accurate value. totalTime: 12.440098 which makes making one call to 1 take 1.2440098*10^-8 seconds, which is a much much much smaller number than $TimeUnit. Poor AbsoluteTiming, it never stood a chance. ;)

Also note that AbsoluteTiming gives the total time between the beginning and end of the calculation, including the time when your code wasn't running at all because the processor was working on something else (like checking whether something on your screen needed updating, deciding what to do with some packet which happened to arrive on your network, your virus checker running in the background etc.). So even if your system would allow reliable microsecond timing, you'd still get quite varying times, depending on whether there happened to be an interrupt or even a task switch in between.
–
celtschkMar 9 '12 at 8:21

Mathematica is a registered trademark of Wolfram Research, Inc. While the mark is used herein with the limited permission of Wolfram Research, Stack Exchange and this site disclaim all affiliation therewith.