since we don't have many options for doing time profiling with our PB code, here is another one, which has already proved useful to me.
- Main advantages: Flexible and simple (this also means e.g. that it is cross-platform, and compatible with ASCII as well as Unicode compilation).
- Main disadvantage: You'll have to manually insert commands before and after each code block in your program of which you want to measure the execution time.
Code: Select all
; Poor (wo)man's time profiling version 1.42 for PureBasic;
; cross-platform (tested with PB 5.62, PB 5.70 LTS and PB 6.02 LTS
; on Windows 10, Windows 11 and Linux Mint 19.1 Cinnamon)
; <https://www.purebasic.fr/english/viewtopic.php?t=72017>
; INCLUDE THIS FILE in your program.
; At the beginning of your program and/or module, write '#TimeProfile = #True'.
; Note that this line written inside of a module does not take effect outside
; of the module, and vice versa (it's the same as with 'EnableExplicit').
; The code in this module only takes effect if the DEBUGGER is OFF, because
; measuring execution time otherwise doesn't make sense.
DeclareModule TimeProfile
EnableExplicit
; Call the following two macros pairwise with the same name before and
; after each code block in your program of which you want to measure
; the execution time.
;
; When there are *sequential* calls with the same name, e.g.
; Start("This")
; <code>
; Stop("This")
; <code>
; Start("This")
; <code>
; Stop("This")
; then all measured times for "This" will be added.
;
; When there are *nested* calls with the same name, e.g.
; Start("That")
; <code>
; Start("That")
; <code>
; Stop("That")
; <code>
; Stop("That")
; then only the outer calls of Start() and Stop() are
; taken into account for the time measurement.
Macro Start (_name_)
CompilerIf Defined(TimeProfile, #PB_Constant)
CompilerIf #TimeProfile = #True And #PB_Compiler_Debugger = #False
TimeProfile::_Start(#PB_Compiler_Module, _name_)
CompilerEndIf
CompilerEndIf
EndMacro
Macro Stop (_name_)
CompilerIf Defined(TimeProfile, #PB_Constant)
CompilerIf #TimeProfile = #True And #PB_Compiler_Debugger = #False
TimeProfile::_Stop(#PB_Compiler_Module, _name_)
CompilerEndIf
CompilerEndIf
EndMacro
; Show the results of the time measurements, and reset the state of the module.
Macro Results (_title_="")
CompilerIf Defined(TimeProfile, #PB_Constant)
CompilerIf #TimeProfile = #True And #PB_Compiler_Debugger = #False
TimeProfile::_Results(_title_)
CompilerEndIf
CompilerEndIf
EndMacro
; Reset the state of the module, without showing the results
; (only needed in special cases).
Macro Clear ()
CompilerIf Defined(TimeProfile, #PB_Constant)
CompilerIf #TimeProfile = #True And #PB_Compiler_Debugger = #False
TimeProfile::_Clear()
CompilerEndIf
CompilerEndIf
EndMacro
; Do not call the following procedures directly.
Declare _Start(modul$, name$)
Declare _Stop (modul$, name$)
Declare _Results(title$)
Declare _Clear()
EndDeclareModule
Module TimeProfile
#Title$ = "Time profile"
Structure MeasureTime
CurStart.q
CurStop.q
Called.i
Level.i
Error.i
EndStructure
Structure DisplayTime
Name$
DurationAbs.q
DurationRel.d
Called.i
EndStructure
Global NewMap gTimeProfile.MeasureTime()
Global.i gProfilingIsActive = #False
Global.q gTotalStart, gTotalStop
Procedure _Start (modul$, name$)
If Asc(modul$) <> 0
name$ = modul$ + "::" + name$
EndIf
If gTimeProfile(name$)\Level = 0
gTimeProfile()\CurStart = ElapsedMilliseconds()
If gProfilingIsActive = #False
gProfilingIsActive = #True
gTotalStart = gTimeProfile()\CurStart
EndIf
EndIf
gTimeProfile()\Called + 1
gTimeProfile()\Level + 1
EndProcedure
Procedure _Stop (modul$, name$)
If Asc(modul$) <> 0
name$ = modul$ + "::" + name$
EndIf
gTimeProfile(name$)\Level - 1
If gTimeProfile()\Level = 0
gTotalStop = ElapsedMilliseconds()
gTimeProfile()\CurStop = gTotalStop
ElseIf gTimeProfile()\Level < 0
gTotalStop = ElapsedMilliseconds()
gTimeProfile()\Error = #True
EndIf
EndProcedure
Procedure _Clear()
ClearMap(gTimeProfile())
gProfilingIsActive = #False
EndProcedure
; ---------------------------------------------------------------------------
Procedure.s _RAlign (s$, width.i)
If Len(s$) >= width
ProcedureReturn s$
Else
ProcedureReturn RSet(s$, width)
EndIf
EndProcedure
Procedure.s _FormatTime (ms.i)
; in : duration expressed in milliseconds
; out: duration expressed in milliseconds, seconds, minutes or hours as appropriate
Protected ret$
If ms < 1000
ret$ = ReplaceString(RSet(Str(ms), 3), " ", " ") + " ms"
ElseIf ms < 60000
ret$ = StrD(ms/1000, 1) + " Sec."
ElseIf ms < 3600000
ret$ = StrD(ms/60000, 1) + " Min."
Else
ret$ = StrD(ms/3600000, 1) + " Hrs."
EndIf
ProcedureReturn ret$
EndProcedure
#ListIcon_Width = 60 + 3*80 + 250 + 10
#ListIcon_Height = 250
#Editor_Height = 80
#WinMain_Width = #ListIcon_Width + 20
#WinMain_Height = #ListIcon_Height + 50 + #Editor_Height + 10
Procedure _Results (title$)
Protected winMain.i, gadList.i, gadText.i, gadEdit.i
Protected msg$, item$, totalDuration.q, error.i=#False
Protected NewList profile.DisplayTime()
If Asc(title$) = 0
title$ = #Title$
EndIf
winMain = OpenWindow(#PB_Any, 0, 0, #WinMain_Width, #WinMain_Height, title$,
#PB_Window_MinimizeGadget|#PB_Window_ScreenCentered|#PB_Window_Invisible)
If winMain = 0
msg$ = "Couldn't open main window." + #LF$ +
#LF$ +
"Program terminated."
MessageRequester(#Title$, msg$, #PB_MessageRequester_Error)
End
EndIf
gadList = ListIconGadget(#PB_Any, 10, 10, #ListIcon_Width, #ListIcon_Height, " % Time", 60,
#PB_ListIcon_GridLines|#PB_ListIcon_FullRowSelect|#PB_ListIcon_MultiSelect)
AddGadgetColumn(gadList, 1, " Time", 80)
AddGadgetColumn(gadList, 2, " Called", 80)
AddGadgetColumn(gadList, 3, " Time/Call", 80)
AddGadgetColumn(gadList, 4, " Name", 250)
gadText = TextGadget (#PB_Any, 10, #ListIcon_Height+30, #WinMain_Width-20, 20, "Error - unbalanced calls of Start() and Stop():")
gadEdit = EditorGadget(#PB_Any, 10, #ListIcon_Height+50, #WinMain_Width-20, #Editor_Height, #PB_Editor_ReadOnly)
totalDuration = gTotalStop - gTotalStart
ForEach gTimeProfile()
If gTimeProfile()\Error = #True Or gTimeProfile()\Level <> 0
error = #True
AddGadgetItem(gadEdit, -1, MapKey(gTimeProfile()))
Else
AddElement(profile())
profile()\Name$ = MapKey(gTimeProfile())
profile()\DurationAbs = gTimeProfile()\CurStop - gTimeProfile()\CurStart
If totalDuration > 0
profile()\DurationRel = profile()\DurationAbs / totalDuration
Else
profile()\DurationRel = 1.0
EndIf
profile()\Called = gTimeProfile()\Called
EndIf
Next
ClearMap(gTimeProfile())
gProfilingIsActive = #False
SortStructuredList(profile(), #PB_Sort_Descending, OffsetOf(DisplayTime\DurationRel), TypeOf(DisplayTime\DurationRel))
; Add the 'Total' line to the ListIconGadget
item$ = "100.0" + #LF$ + _FormatTime(totalDuration) + #LF$ + Space(11) + "---" + #LF$ +
"---" + #LF$ + "From first call of Start() to last call of Stop()"
AddGadgetItem(gadList, -1, item$)
; Add the results of all time measurements to the ListIconGadget
ForEach profile()
item$ = ReplaceString(RSet(StrD(100 * profile()\DurationRel, 1), 5), " ", " ") + #LF$ +
_FormatTime(profile()\DurationAbs) + #LF$ +
ReplaceString(_RAlign(Str(profile()\Called), 8), " ", " ") + #LF$ +
_FormatTime(profile()\DurationAbs / profile()\Called) + #LF$ +
" " + profile()\Name$
AddGadgetItem(gadList, -1, item$)
Next
If error = #False
HideGadget(gadText, #True)
HideGadget(gadEdit, #True)
ResizeGadget(gadList, #PB_Ignore, #PB_Ignore, #PB_Ignore, #WinMain_Height-20)
EndIf
SetGadgetState(gadList, 0)
SetActiveGadget(gadList)
HideWindow(winMain, #False)
Repeat
Until WaitWindowEvent() = #PB_Event_CloseWindow
CloseWindow(winMain)
EndProcedure
EndModule
CompilerIf #PB_Compiler_IsMainFile
; -- Demo
DeclareModule MyModule
EnableExplicit
#TimeProfile = #True
Declare MyProc (n.i)
EndDeclareModule
Module MyModule
Procedure MyProc (n.i)
Protected i.i
TimeProfile::Start("MyProc")
If n <= 0
Delay(10)
TimeProfile::Stop("MyProc")
ProcedureReturn
EndIf
For i = 1 To n
Delay(2)
Next
TimeProfile::Stop("MyProc")
ProcedureReturn
EndProcedure
EndModule
EnableExplicit
#TimeProfile = #True
; First time profiling section
TimeProfile::Start("Foo")
Delay(500)
TimeProfile::Stop("Foo")
MyModule::MyProc(100)
TimeProfile::Results("My title")
; Another time profiling section, independent from the first one
TimeProfile::Start("Bar")
Delay(300)
TimeProfile::Stop("Bar")
TimeProfile::Results()
CompilerEndIf
-------------------------------------------------
My best tricks & tips from 15+ years
Create arrays elegantly
Extended date library
Save JSON data with object members well-arranged
Evaluate and process math expressions
Functions for sets
Statistics with R
Thue-Morse sequence
Natural sorting
Sort array indexes and parallel arrays
Time profiling
VectorIcons