Strange use of time...
- To: mathgroup at smc.vnet.net
- Subject: [mg111240] Strange use of time...
- From: Jean-Eric <jecampagne at free.fr>
- Date: Sat, 24 Jul 2010 05:09:45 -0400 (EDT)
Hello,
See below a short test of the time used by a function
brpCrossCorrCh1AndCh2[];
Looking at the time spent it turns out that
1) the total time spend by the Do-Loop is governed by few calls to the
above brpCrossCorrCh1AndCh2;
2) the distribution of time spend is strange at first look: mostly ~ <
10^-16 sec or few ~0.015 sec!
3) the proportion of large time spent (~0.015sec) depends on the
number of complex data generated and then treat by
brpCrossCorrCh1AndCh2
I have tried to tackle from where the large time spent come from.
Working on Latitude E6400 dual processor running Windows XP, I have
looked at memory, cpu... I have turn off FireFox...
But nothing change.
So I come with the below short nb file that you can run in your
computer and let me know if you experience the some strange behavior
mentionned above.
Sincerely
Jean-Eric
In[1]:= $HistoryLength =0;
In[2]:= memStart =MemoryInUse[];
In[3]:= Clear[profiletime];
Attributes[profiletime]={HoldAll};
profiletime[expr_,tag_]:=Module[{results=Timing[expr]},Sow[First@results,tag];
Last@results]
In[6]:= data = RandomComplex[10+5 I,{2,10000}];
cplxAmpCh1=data[[1]];
cplxAmpCh2= data[[2]];
In[9]:= Clear[brpCrossCorrCh1AndCh2];
brpCrossCorrCh1AndCh2[f_Integer:1,l_Integer:-1]:=Module[{corr},
corr = Total[N[cplxAmpCh1[[f;;l]]*Conjugate[cplxAmpCh2[[f;;l]]]]];
corr /= Length[ cplxAmpCh1[[f;;l]]];
(* result *)
{Re[corr],Im[corr]}
];(* end of module *)
In[11]:= tStart = Sow[TimeUsed[]];
dataTime=Last@Reap[
Do[profiletime[Module[{},
(*brpAutoCorrCh1AndCh2[];*)
brpCrossCorrCh1AndCh2[];
];,"crossCorr"],{i,1000}]
];
In[13]:= Print["Time used ",Sow[TimeUsed[]]-tStart]
Print["Memory used ",MemoryInUse[]-memStart]
During evaluation of In[13]:= Time used 0.437
During evaluation of In[13]:= Memory used 603728
In[15]:= ListPlot[dataTime,PlotRange->Full]
In[16]:= Max[dataTime]
Out[16]= 0.016
In[17]:= BinCounts[dataTime[[1]],{0,0.02,0.01}]
Out[17]= {972,28}