I am trying to speed up a code and by placing Timing statements in the code I identified a suspect calculation that I do repeatedly. In order to test out the calculation I generated some random numbers and looked at the timing of the calculation outside the main code. Here is an example of doing the calculation a number of times.
a = Table[
n1 = 10000;
n2 = 50;
cmatT = RandomComplex[{-1. + -I, 1. + I}, {n2, n1}];
w = RandomComplex[{-1 + -I, 1 + I}, n2];
Timing[Transpose[cmatT] . w;][[1]], {50}]
The output is
{0., 0., 0., 0., 0., 0., 0., 0., 0., 0., 0., 0., 0., 0., 0., \
0.015625, 0., 0., 0., 0., 0., 0., 0.015625, 0.015625, 0., 0., 0., 0., \
0., 0., 0., 0., 0., 0., 0., 0., 0., 0., 0., 0., 0., 0., 0., 0., 0., \
0., 0., 0., 0., 0.}
So the timing is inconsistent with three cases taking a long time and the remainder being very fast. In my code it always takes a long time. If you run the above code repeatedly then the long times appear inconsistently in the output.
To try to understand the output I stored the matrices involved and ran the following code
a = Table[n1 = 10000;
n2 = 50;
cmatT = RandomComplex[{-1. + -I, 1. + I}, {n2, n1}];
w = RandomComplex[{-1 + -I, 1 + I}, n2];
{cmatT, w, Timing[Transpose[cmatT] . w;][[1]]}, {50}];
I tried to find an example where the time was significant and see where the problem lies using the following
{tim} = Select[a[[All, 3]], # != 0. &, 1];
n = Position[a[[All, 3]], tim][[1, 1]];
cmatT = a[[n, 1]]; w = a[[n, 2]];
Timing[Transpose[cmatT] . w;][[1]]
Output
0.
So what is happening? I expected one of the same times as I had previously. I suspect this is something more to do with the way Timing works rather than my code. I have tried to run ClearSystemCache[] to see if this was an issue without success.
Any ideas? What is the correct way to work out this sort of problem?
Edit
Following the suggestion of MarcoB I tried AbsoluteTiming instead of Timing. The code is now
a = Table[n1 = 10000;
n2 = 50;
cmatT = RandomComplex[{-1. + -I, 1. + I}, {n2, n1}];
w = RandomComplex[{-1 + -I, 1 + I}, n2];
AbsoluteTiming[Transpose[cmatT] . w;][[1]], {50}]
with output
{0.0020004, 0.0017151, 0.0033361, 0.002125, 0.0017301, 0.0017893, \
0.0015143, 0.0014935, 0.0015266, 0.0015972, 0.0017455, 0.0014958, \
0.0014959, 0.0014849, 0.0014875, 0.0014839, 0.0014996, 0.0015271, \
0.0015269, 0.0014784, 0.0016972, 0.0015954, 0.0015108, 0.0016923, \
0.0015294, 0.0015364, 0.0017162, 0.0015108, 0.0017251, 0.0016942, \
0.0017495, 0.0017094, 0.0015394, 0.0016843, 0.0015176, 0.0015188, \
0.0015184, 0.0015009, 0.0015237, 0.0014876, 0.0015088, 0.0015569, \
0.0016929, 0.0015513, 0.0016194, 0.0015381, 0.0016187, 0.0014727, \
0.0020828, 0.001443}
which makes much more sense.
Can someone check to see if this is a bug? My Version is 13.3 Windows
AbsoluteTimingand see if any perceived weirdness disappears. See Difference betweenAbsoluteTimingandTiming. – MarcoB Dec 13 '23 at 14:59AbsoluteTimingdoes seem to give more sensible results. I will look at this. Thanks. – Hugh Dec 13 '23 at 16:46Timingare discussed in the documentation. It includes phrases like "does not include time spent..." and "may ignore these additional...." And these things vary by computer system. It has been this way for years. OTOH, wall-clock time (AbsoluteTiming) includes time the operating system spends ignoring Mathematica while taking care of other tasks. I'm usually interested in user-experience time and useAbsoluteTiming. Since I cannot be sure whatTimingis actually timing, I tend not to use it. – Goofy Dec 13 '23 at 18:42Timingwhich might be OS dependent. There isRepeatedTimingwhich might give a more accurate picture. – Daniel Lichtblau Dec 13 '23 at 22:38