Timing code



TQTimer.pas can be downloaded from : http://mapage.noos.fr/qnno/pages/delphi_fr.htm.)


TQTimer provides means to time code with the highest possible precision, using four different counters, and giving measures either in the used counter native unit,  or in the time unit of your choice, with a precision ranging from hours to nanoseconds (depending on the systeme it executes on).


TQTimer being an object definition, you can use as many instances of it as you want.

This can be usefull for example to have an instance by counter tool used (GetTickCount, RDTSC, aso.), and/or an instance by parts of code, ...





TQTimer properties and routines :

Setup properties :
   
fmtOutput : String;
// The wanted string output format.
// It is passed to the Format() function ;
// Defaults to  '%3.9n'

timeUnitsWanted  : Set of TQTimeScale;

// TQTimeScale   = (tsSeconds, tsMilliSec, tsMicroSec, tsNanosSec);

// The delta between start and stop will be outputed in

// each unit stored there.

removeOverHead : Boolean;
// If True, the API call overhead will be removed
// from deltas values (RDTSC ans QueryPerformanceCounter only,
// other counters' overhead being equal to 0 ) ;

deltaShowNatives : Boolean;
// If True, deltas native units will be outputed too.

deltaShowOptimal : Boolean;
// If True, deltas will be outputed in the most "readable" unit possible too;



More about optimal time unit :

When a delta (difference between a Stop and a Start) is computed, the result is expressed in the counter native units (for example, CPU cycles for ReaDTimeStampCounter, accessed through "aTimer.RDT( );" ).

This result can be translated by TQTimer in the time unit of your choice, but could give something not really easy to read.

The deltaShowOptimal property tells TQTimer that you want it to find by itself the time unit which will give the "easiest to read" result.

It is the one that will produce (if possible) a value below 100.00, and above 0.01

For example, a measure giving 88 cycles (which is the most frequent RDT overhead)
will be expressed in nanoseconds as 29,411764706 instead of 0.0294117647 microseconds,
or 0,000029412 milliseconds (to say nothing about seconds) ;

Similarly, a measure of  665 "units" returned by QueryPerformanceCounter would give, after translation, and dependending on the QueryPerformanceFrequency returned value :
0,222219994 µs  instead of 0,000222219 ns, or 222,219994 ms.




Setup default values are :

fmtOutput        := '%3.9n';
timeUnitsWanted  := [];
removeOverHead   := False;
deltaShowNatives := True;
deltaShowOptimal := True;  


With these settings, the string returned by TQTimer.sDeltaFmt[n] would give something like :

"12554092 units, 2.984520047 ms"



Instance methodes :

Constructor Create;
// In order to use TQTimer, you must instanciate it first.

Destructor  Destroy; override;
// To be used (Through "aQTimer.Free"), when no longer needed.





Making a measure :

All these functions return the value read;
They all wait for a parameter called "startOrStop", which represents the wanted destination of the measure made.
It is of kind TQTimerAction, defined as :

TQTimerAction = (taStart,taStop,taGlobalStop);   // (taGlobalStop is used internally)
         
(See below for more information ubout the way theses functions behave.)

As you can see in the TQTimer code (UHotLog.pas), the measure reading is made before checking the startOrStop parameter, thus preserving accuracy.


Function  HMS(startOrStop:TQTimerAction=taStart):TDateTime;
// Requests a TQTimer instance to store current time.

Function  GTC(startOrStop:TQTimerAction=taStart):Integer;
// Requests a TQTimer instance to store GetTickCount current value.
// GTC returns milliseconds.

Function  QPC(startOrStop:TQTimerAction=taStart):Int64;
// Requests a TQTimer instance to store the result of a call
// to QueryPerformanceCounter API.
// The returned value is the one read. QueryPerformanceCounter
// doesn't work with an identified unit (like milliseconds, or cycles)
// but in units that make sens only when compared to themselves, and
// which interpretation rely on the QueryPerformanceFrequency API
// returned value.
// However, TQTimer can translate them to the time unit(s) of
// your choice too.

Function  RDT(startOrStop:TQTimerAction=taStart):Int64;
// Requests a TQTimer instance to store the result of a call
// to the CPU time stamp counter.
// RDT returns CPU cycles.

Procedure GlobalStop;
// Searches in the storage table if a stop has been registered
// previously ;
// The first one found is copied into any free entry of the "stops"
// column of that table.
// If none is found, does nothing.

// Can be usefull to give the same stop value to all the measures
// done until now.

Procedure Reset;
// Empties the storing table




As long as the startOrStop parameter defaults to True, calling any of the timers above without parms will add a Start value in the storage table ;
Then, calling the same counter with "taStop" as parameter will start filling the "stops" colum from top to bottom.


Values read are stored in a single table by TQTimer instance.
This means that you shouldn't mix counters tools in a same table, unless you don't intend to use GlobalStop.


When a timing tool (say for example aTimer.RDT) is called with the parameter "taStart", a new line is added to the storage table, and the value read is added into the first column of that new line.


When a timing tool is called with the parameter "taStop", the result is added in the topmost free stop entry of the table.
Thus filling the table in the opposite order of the one used to add Starts.

The following pseudo-ceode illustrates this :

// Calls QueryPerformanceCounter, and adds its return as a new Start;
aTimer.QPC;           // table = [start1, -1] ;

aTimer.QPC;           //
table = [start1, -1],
                      //        
[start2, -1],


aTimer.QPC(taStop);   //
table = [start1, -1],
                      //        
[start2, firstStop];

aTimer.QPC(taStop);  
// table = [start1, newStop],
                      //        
[start2, firststop];


A call to  aTimer.GlobalStop, after the "firstStop" , would have copied the "firstStop" value into table[0,1], instead of adding into it the "newStop" value ;





Retrieving results :

Property isFinalized : Boolean;
// If false, TQtimer couldn't initalize itself.

Property RegistryFreq : int64;
// Returns a long int containing the CPU speed as stored into
// the registry. Sthg like "866000000" for a 866 mhz proc.

Property QueryPerfFreq : Int64;
// Returns the value of a call to QueryPerformanceFrequency API ;
// used internally to convert native units to time units

Property ReaDTSCOverhead : int64;
// Returns the cost, in native units (cycles) of a
// call to the ASM opcode RDTSC ;

Property QueryPerfOverhead  : int64;
// Returns the cost, in native units of a call to
// QueryPerformanceCounter API ;

Property Count : integer;
// Retunrs the actual number of entries in the storage table.

Property iStart[ix:Integer] : int64;
// returns the value stored at position [ix], for the START column,
// in the storage table, converted to an int64 (or -1 if ix is out
// of bounds).

Property iStop [ix:Integer] : int64;
// returns the value stored at position [ix], for the STOP column,
// in the storage table, converted to an int64 (or -1 if ix is out
// of bounds).


Property iDelta[ix:Integer] : int64;
// returns Stop - start for the entry [ix] of the storage table,
// converted to an int64, with or without overhead (depending
// on the setup property removeOverHead)
// (returns -1 if ix is out of bounds).


Property sStart[ix:Integer] : String;
// returns the start entry of line [ix] as string;
// (returns '-1' if ix is out of bounds).

Property sStop [ix:Integer] : String;
// returns the start entry of line [ix] as string;
// (returns '-1' if ix is out of bounds).

Property sDelta[ix:Integer] : String;
// returns the Stop - Start delta of line [ix] as string;
// (returns '-1' if ix is out of bounds).


Property iDeltaFmt[ix:Integer] : Extended;
// Returns the delta of line [ix] after conversion to real.
// Returns 0.00 if ix is out of bound ;

Property sDeltaFmt[ix:Integer] : String;
// Returns a string made of one or more parts, depending
// on the setup parameters :

// If the counter used was HMS, returns only hh:mm:ss ;

// otherwise, hads as many strings to the result as there are
// wanted outputs, following the order :
// . Native units (if deltaShowNatives)
// . Each time value, depending on the contents of timeUnitsWanted;
// . The optimal time unit, (if deltaShowOptimal);

// Returns an empty string in case a problem is met ;

// Each element in the string is followed by the symbol of the unit used (ms for milliseconds, µs for microseconds, aso.).







TQTimer example of use :
procedure TForm1.Button7Click(Sender: TObject);
var aTimer : TQTimer;
begin
  aTimer := TQTimer.Create;
  With aTimer Do
  Begin
    removeOverHead := True;
    reset;                                // Makes sure its count is zero ;
    QPC;                                  // Start[0] Stores qpc value at strartUp
    QPC;                                  // Start[1] Prepares measuring next step
    Sleep(100);                     
    QPC(taStop);                          // Stop[1]-> the length of DoPrepareEverything;
    QPC;                                  //
    Sleep(350);
    QPC(taStop);                          // Stop[2]-> the length of DoMainJob;
    QPC;
    Sleep(50);
    QPC(taStop);                          // Stop[3]-> the length of DoMainJob;
    GlobalStop;                           // Stop[0]-> Peered stop of the start[0]
  end;{with}                                    // Receives the last Stop value

  // Now gets the value as a formatted string :
  Memo1.Lines.Add('Job      start : ' + aTimer.sStart[0]);
  Memo1.Lines.Add('1st Step start : ' + aTimer.sStart[1]
                  + '  stops : '    + aTimer.sStop[1]
                  + '  duration : ' + aTimer.sDeltaFmt[1]);
  Memo1.Lines.Add('2nd Step start : ' + aTimer.sStart[2]
                  + '  stops : '    + aTimer.sStop[2]
                  + '  duration : ' + aTimer.sDeltaFmt[2]);
  Memo1.Lines.Add('3rd Step start : ' + aTimer.sStart[3]
                  + '  stops : '    + aTimer.sStop[3]
                  + '  duration : ' + aTimer.sDeltaFmt[3]);
  Memo1.Lines.Add('Job      ended : ' + aTimer.sStop[0]);
  Memo1.Lines.Add('Job  duration  : ' + aTimer.sDeltaFmt[0]);
  aTimer.Free;
end;
Would output :
 
Job      start : 25183871800780
1st Step start : 25183871803704  stops : 25184197376812  duration : 325573108 "units", 0,108794179 s.
2nd Step start : 25184197380260  stops : 25185272738342  duration : 1075358082 "units", 0,359343867 s.
3rd Step start : 25185272742054  stops : 25185459756194  duration : 187014140 "units", 62,493029380 ms
Job      ended : 25185459756194
Job  duration  : 1587955414 "units", 0,530634445 s.