Re: which time is counted by TStopwatch or what is CINT actually doing?

From: Pasha Murat (murat@cdfsga.fnal.gov)
Date: Tue Jan 20 1998 - 17:49:47 MET


	Dear Masa,

as execution times even for simple (from the user point of view) scripts 
interpreted by CINT can differ by several orders of magnitude it would be 
extremely helpful if conditions under which optimization takes (does not take) 
place were explicitly specified and made public. I'm pretty sure everybody 
would appreciate it.
					Thanks a lot, Pasha.
--------------------------------------------------------------------------------
Rene Brun writes:
 > CINT can generate optimized byte code for very simple loops not involving
 > calls to procedures or I/O.
 > In your example below, the first procedure is optimized.
 > The second cannot be optimized.
 > Masa will very likely provide more info.
 > 
 > Rene Brun
 > 
 > Pasha Murat wrote:
 > 
 > >         Hello,
 > >
 > > in the example below I'm interactively running 2 test routines which I
 > > consider to be exactly the same from the point of view of execution:
 > > the only difference between them consists in that one line which
 > > *should never be executed* is uncommented in the second routine.
 > >
 > > I'd also expect the execution times to be exactly the same.
 > > However ROOT TStopwatch timer reports *very* strange results:
 > > the reported times differ by more than a factor of 100...
 > >
 > > One could either suspect TStopwatch timer in reporting wrong time in one
 > > of 2 cases or CINT in doing much more than it has been asked to in case
 > > when `cout ...' is uncommented.
 > >
 > > I should also mention that replacing `cout' in test2 with `printf' makes
 > > both times *exactly* the same in agreement with the expectations...
 > >
 > >         Could anybody comment on it?
 > >                                                 Thanks, Pasha
 > >
 > > P.S. For the information to be complete <iostream.h> is included in logon macro.
 > > --------------------------------------------------------------------------------
 > > void test1 () {
 > >   TStopwatch t;
 > >   t.Start();
 > >   int k;
 > >   for (int i=0; i<100000; i++) {
 > >     k = i;
 > >     if (k == -1) {
 > >       //      cout << " oops! " << endl;
 > >     }
 > >   }
 > >   t.Stop();
 > >   printf("RealTime=%f seconds, CpuTime=%f seconds\n",t.RealTime(),t.CpuTime());
 > > }
 > >
 > > void test2 () {
 > >   TStopwatch t;
 > >   t.Start();
 > >   int k;
 > >   for (int i=0; i<100000; i++) {
 > >     k = i;
 > >     if (k == -1) {
 > >       cout << " oops! " << endl;
 > >     }
 > >   }
 > >   t.Stop();
 > >   printf("RealTime=%f seconds, CpuTime=%f seconds\n",t.RealTime(),t.CpuTime());
 > > }
 > > --------------------------------------------------------------------------------
 > > root [1] test1()
 > > RealTime=0.230000 seconds, CpuTime=0.240000 seconds
 > > root [2] test2()
 > > RealTime=28.810000 seconds, CpuTime=27.770000 seconds
 > 
 > 



This archive was generated by hypermail 2b29 : Tue Jan 04 2000 - 00:34:29 MET