I've designed a very simple profiling framework. Currently its in the shape of a Delphi Unit.
The Profiling.pas unit should be included in your project. At the start of each functionaility being profiled just execute a [pascal]ProfileOn(<ID>)[/pascal] statement, where ID is a unique identifier for the section.
Currently the profiling unit can only monitor 10 unique sections but the MaxProfiles constant can be change to monitor as many as you want.
At the end of your program (I do it on FormDestroy) just do a [pascal]SaveProfile('Profiles.txt');[/pascal] statement to store the profile information to a file.
Open the file created to see the impact of each section in the program.
The file will look something like this:
From this output we can see that Profile Section 1 was called 88 times and used a total of 0ms (therefore an average of 0), while section 6 was called 88 times and used a total of 1517 milliseconds - an average of 17ms each time it is called. (BTW this was the canvas function and Profile section 3 was the DXDraw.Flip statement).Code:PROFILE 1: 0 called 88 average 0.00000000000000E+0000 ms 2: 0 called 88 average 0.00000000000000E+0000 ms 3: 1250 called 88 average 1.42000000000000E+0001 ms 4: 16 called 87 average 1.80000000000000E-0001 ms 5: 0 called 88 average 0.00000000000000E+0000 ms 6: 1517 called 88 average 1.72400000000000E+0001 ms 7: 186 called 88 average 2.11000000000000E+0000 ms
Using this output file it is possible to identify sections of the code that are significantly slower than others.
The complete source code for the profiling unit is included below. I have tried to optimise as much as possible. e.g. Using Records as they do the memory allocation on program start and not during the program run time etc.
[pascal]
unit Profiling;
interface
Uses
Math, Windows;
Const
MaxProfiles = 10;
Type
TProfile = Record
Time : Integer;
Count : Integer;
End;
Var
Profiles : Array[0..MaxProfiles] of TProfile;
CurrentProfile : Integer;
LastTime : Integer;
Procedure ProfileOff;
Procedure ProfileOn(ProfileID : Integer);
Procedure SaveProfile(FileName : String);
Procedure ClearProfile;
implementation
// Stop all profiling activities.
Procedure ProfileOff;
Var
T : Integer;
Begin
If CurrentProfile <> 0 then
Begin
T := GetTickCount;
Profiles[CurrentProfile].Time := Profiles[CurrentProfile].Time + T - LastTime;
Inc(Profiles[CurrentProfile].Count);
CurrentProfile := 0;
End;
End;
// Start Profiling a specfic ID
Procedure ProfileOn(ProfileID : Integer);
Var
T : Integer;
Begin
T := GetTickCount;
If CurrentProfile <> 0 then
Begin
Profiles[CurrentProfile].Time := Profiles[CurrentProfile].Time + T - LastTime;
Inc(Profiles[CurrentProfile].Count);
End;
CurrentProfile := ProfileID;
LastTime := T;
End;
// Save Profiling information to a Text File
Procedure SaveProfile(FileName : String);
Var
T : TextFile;
I : Integer;
Begin
AssignFile(T,FileName);
Rewrite(T);
WriteLn(T,'PROFILE');
For I := 0 to MaxProfiles do
Begin
If Profiles[I].Count > 0 then
WriteLn(T,I,': ',Profiles[I].Time,' called ',Profiles[I].Count,' average ',RoundTo(Profiles[I].Time / Profiles[I].Count,-2),' ms');
End;
CloseFile(T);
End;
// Clear all current profiling records.
Procedure ClearProfile;
Var
I : Integer;
Begin
For I := 0 to MaxProfiles do
Begin
Profiles[I].Count := 0;
Profiles[I].Time := 0;
End;
CurrentProfile := 0;
LastTime := GetTickCount;
End;
Initialization
// Start by ensuring that no profiles are being done.
CurrentProfile := 0;
end.
[/pascal]
Here is the example that I used to profile. Its the gameloop procedure from a game to be:
[pascal]procedure TForm1.GameLoop(Sender: TObject; var Done: Boolean);
Var
I : Integer;
Begin
Done := False;
{ Game Stuff Goes here... }
DXDraw1.Surface.Fill(clBlack);
ProfileOn(7);
Map.Draw;
ProfileOn(1);
ProfileOn(2);
DXImageList1.Items[5].Draw(DXDraw1.Surface, 10, 10,0);
DXImageList1.Items[4].Draw(DXDraw1.Surface, 40, 30,0);
DXImageList1.Items[6].Draw(DXDraw1.Surface, 40, 90,0);
// Release the Canvas!
ProfileOn(6);
For I := 0 to 10 do
Begin
DXDraw1.Surface.Canvas.MoveTo(900+I, 50+(ABS(I-5)));
DXDraw1.Surface.Canvas.Pen.Color := $00AAFF-(ABS(I-4)*$001515);
DXDraw1.Surface.Canvas.LineTo(900+I,700-(ABS(I-5)));
End;
ProfileOn(5);
DXDraw1.Surface.Canvas.Release;
// Flip the Back-Buffer to the Screen
ProfileOn(3);
DXDraw1.Flip;
ProfileOn(4);
End;[/pascal]
To-Do
ProfilePause - Just delay while somethign else executes.
Neaten the output.
Use a better method than GetTickCount to calculate delays as GetTickCount seems to work in increments of 10ms at a time therefore does not give a really acurate view (But probably good enough anyway).
[/code]
Bookmarks