Prev: All pairs shortest paths
Next: tweaking VectorPlot...
From: Jean-Eric on 24 Jul 2010 05:09
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(a)results,tag];
Last(a)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(a)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}

From: David Bailey on 25 Jul 2010 01:56
On 24/07/10 10:09, Jean-Eric wrote:
> 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(a)results,tag];
> Last(a)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(a)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}
>
To get meaningful timing results you absolutely have to time
computations that take (say) 10 seconds or longer. The reason for this,
is that there are always other things going on inside your computer, and
these cannot be totally accounted for, even by Timing, which tries to
time a computation without including time spent on other processes.

David Bailey
http://www.dbaileyconsultancy.co.uk

 | 
Pages: 1
Prev: All pairs shortest paths
Next: tweaking VectorPlot...