Timing code

HotLog.pas contains the definition of another object, TQTimer, which may be used independently.
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 is an object. 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, ...), and/or an instance by parts of code, ...

TQTimer properties and routines:

Setup properties:

fmtOutput: String;

Format string used for the output. Passed to the Format( ) function.
Default: '%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 units:

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.

Measuring:

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 (HotLog.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-code 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 it into the "newStop" value.

Retrieving values:

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. Something 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;

eturns 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 of a problem.

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

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 startUp 
    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;

Output will be something like this: 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