PureBasic Forums - English

Posted: **Mon Dec 31, 2018 1:26 pm**

Hi,

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
Generate focus events

Posted: **Tue Jan 01, 2019 2:41 pm**

Very nice, Thanks!
I hope you don't mind if I share a similar module here. It doesn't have the nice results window, but it can stop/resume timers and can give you an info string about timers for easy debugging. The example code uses the debugger for simple output, so enable it to see something.
Happy new year

Code: Select all

DeclareModule stopwatch
  EnableExplicit
  
  Declare   reset(name.s)
  Declare.q elapsed(name.s)
  Declare.q resume(name.s)
  Declare   restart(name.s)
  Declare.q stop(name.s)
  Declare.s info(name.s)
  Declare.q stopDebugInfo(name.s)
  Declare.s stopGetInfo(name.s)
  Declare   remove(name.s)
  
EndDeclareModule

Module stopwatch
  EnableExplicit
  
  Structure sStopwatch
    running.i
    timeStarted.q
    timeStopped.q
    timeElapsed.q
    timeElapsedTotal.q
  EndStructure
  
  Global NewMap stopwatch.sStopwatch()
  
  ; reset and stop
  Procedure reset(name.s)
    stopwatch(name)\running = #False
    stopwatch(name)\timeStarted = 0
    stopwatch(name)\timeStopped = 0
    stopwatch(name)\timeElapsed = 0
    stopwatch(name)\timeElapsedTotal = 0
  EndProcedure
  
  ; return elapsed
  Procedure.q elapsed(name.s)
    If stopwatch(name)\running
      ProcedureReturn stopwatch(name)\timeElapsedTotal + (ElapsedMilliseconds() - stopwatch(name)\timeStarted)
    Else
      ProcedureReturn stopwatch(name)\timeElapsedTotal
    EndIf
  EndProcedure
  
  ; start or resume
  Procedure.q resume(name.s)
    If Not stopwatch(name)\running
      stopwatch(name)\running = #True
      stopwatch(name)\timeStarted = ElapsedMilliseconds()
      stopwatch(name)\timeStopped = 0
      stopwatch(name)\timeElapsed = 0
      ;stopwatch(name)\timeElapsedTotal = 0  ; (keep total)
    EndIf
    ProcedureReturn elapsed(name)
  EndProcedure
  
  ; reset and start
  Procedure restart(name.s)
    reset(name)
    resume(name)
  EndProcedure
  
  ; stop and return elapsed
  Procedure.q stop(name.s)
    If stopwatch(name)\running
      stopwatch(name)\timeStopped = ElapsedMilliseconds()
      stopwatch(name)\timeElapsed = stopwatch(name)\timeStopped - stopwatch(name)\timeStarted
      stopwatch(name)\timeElapsedTotal + stopwatch(name)\timeElapsed
      stopwatch(name)\running = #False
    EndIf
    ProcedureReturn elapsed(name)
  EndProcedure
  
  ; return info string
  Procedure.s info(name.s)
    If stopwatch(name)\running
      ProcedureReturn "stopwatch '" + name + "' running. elapsed: " + elapsed(name)
    Else
      ProcedureReturn "stopwatch '" + name + "' stopped. elapsed: " + elapsed(name)
    EndIf
  EndProcedure
  
  ; stop, debug info string and return elapsed (debugger required)
  Procedure.q stopDebugInfo(name.s)
    stop(name)
    Debug info(name)
    ProcedureReturn elapsed(name)
  EndProcedure
  
  ; stop and return info string (i.e. for console print without debugger)
  Procedure.s stopGetInfo(name.s)
    stop(name)
    ProcedureReturn info(name)
  EndProcedure
  
  ; remove map element
  Procedure remove(name.s)
    DeleteMapElement(stopwatch(), name)
  EndProcedure
  
EndModule

CompilerIf #PB_Compiler_IsMainFile
  Debug "[" + #PB_Compiler_Filename + "]"
  EnableExplicit
  
  ;XIncludeFile "stopwatch.pb"
  
  ; test functions
  stopwatch::restart("sw 1")
  Delay(100)
  Debug stopwatch::elapsed("sw 1")                     ; 100
  Delay(100)
  Debug stopwatch::info("sw 1")                        ; stopwatch 'sw 1' running. elapsed: 200
  Delay(100)
  stopwatch::stopDebugInfo("sw 1")                     ; stopwatch 'sw 1' stopped. elapsed: 300
  Delay(100)
  Debug stopwatch::elapsed("sw 1")                     ; 300
  Debug stopwatch::resume("sw 1")                      ; 300
  Delay(100)
  Debug stopwatch::info("sw 1")                        ; stopwatch 'sw 1' running. elapsed: 400
  Delay(100)
  Debug stopwatch::stopGetInfo("sw 1")                 ; stopwatch 'sw 1' stopped. elapsed: 500
  Delay(100)
  stopwatch::reset("sw 1")
  Debug stopwatch::info("sw 1")                        ; stopwatch 'sw 1' stopped. elapsed: 0
  stopwatch::remove("sw 1")
  Debug "----------"                                   ; ----------
  ; test overlapping
  stopwatch::restart("sw 2")
  Delay(100)
  stopwatch::restart("sw 3")
  Delay(100)
  stopwatch::stop("sw 2")
  Delay(100)
  stopwatch::stop("sw 3")
  Delay(100)
  Debug stopwatch::info("sw 2")                        ; stopwatch 'sw 2' stopped. elapsed: 200
  Debug stopwatch::info("sw 3")                        ; stopwatch 'sw 3' stopped. elapsed: 200
  Delay(100)
  Debug stopwatch::info("sw 2")                        ; stopwatch 'sw 2' stopped. elapsed: 200
  Debug stopwatch::info("sw 3")                        ; stopwatch 'sw 3' stopped. elapsed: 200
  stopwatch::remove("sw 2")
  stopwatch::remove("sw 3")
  Debug "----------"                                   ; ----------
  ; test without restart/reset
  Debug stopwatch::info("sw a")                        ; stopwatch 'sw a' stopped. elapsed: 0
  Debug stopwatch::stopGetInfo("sw b")                 ; stopwatch 'sw b' stopped. elapsed: 0
  stopwatch::stopDebugInfo("sw c")                     ; stopwatch 'sw c' stopped. elapsed: 0
  Debug stopwatch::elapsed("sw d")                     ; 0
  Debug stopwatch::resume("sw e")                      ; 0
  Delay(100)
  Debug stopwatch::resume("sw e")                      ; 100
  Delay(100)
  Debug stopwatch::stop("sw e")                        ; 200
  Delay(100)
  Debug stopwatch::resume("sw e")                      ; 200
  Delay(100)
  Debug stopwatch::stopGetInfo("sw e")                 ; stopwatch 'sw e' stopped. elapsed: 300
  
  Debug stopwatch::stop("sw f")                        ; 0
  Delay(100)
  Debug stopwatch::resume("sw f")                      ; 0
  Delay(100)
  Debug stopwatch::stop("sw f")                        ; 100
  
  stopwatch::remove("sw xyz")
CompilerEndIf

Posted: **Tue Jan 01, 2019 7:29 pm**

Nice, thank you.
Happy new year to you, too!

Posted: **Sun Jan 27, 2019 1:59 pm**

New version 1.10, 2019-01-27

Changes

Renamed Update() to Stop() and _Update() to _Stop().

New

In the output window, added columns "Called" and "Time/Call".

Posted: **Sun Jan 27, 2019 5:08 pm**

Like it

I would hide the error part in the result dialog when no error exists...

Code: Select all

	Procedure _Results ()
		
		Protected total.q, msg$, item$
		Protected NewList profile.TimeProfileStruc()
		Protected Errors.i

		If TimeProfile("Total")\Error = #True Or TimeProfile()\Level <> 0
			msg$ = ~"Both Start(\"Total\") and Stop(\"Total\") must be called exactly once." + #LF$ +
			#LF$ +
			"Program terminated."
			MessageRequester(#Title$, msg$, #PB_MessageRequester_Error)
			End
		EndIf

		If OpenWindow(#WinMain, 0, 0, #WinMain_Width, #WinMain_Height, #Title$, #PB_Window_MinimizeGadget|#PB_Window_ScreenCentered|#PB_Window_Invisible) = 0
			msg$ = "Couldn't open main window." + #LF$ +
			#LF$ +
			"Program terminated."
			MessageRequester(#Title$, msg$, #PB_MessageRequester_Error)
			End
		EndIf

		ListIconGadget (#ListIcon, 10, 10, #ListIcon_Width, #ListIcon_Height, " % Time", 60, #PB_ListIcon_GridLines|#PB_ListIcon_FullRowSelect|#PB_ListIcon_MultiSelect)
		AddGadgetColumn(#ListIcon, 1, " Time", 70)
		AddGadgetColumn(#ListIcon, 2, "  Called", 70)
		AddGadgetColumn(#ListIcon, 3, " Time/Call", 70)
		AddGadgetColumn(#ListIcon, 4, " Name", 200)
		TextGadget     (#Text,   10, #ListIcon_Height+30, #WinMain_Width-20, 20, "No error.")
		EditorGadget   (#Editor, 10, #ListIcon_Height+50, #WinMain_Width-20, #Editor_Height, #PB_Editor_ReadOnly)

		total = TimeProfile("Total")\DurationAbs

		ForEach TimeProfile()
			If TimeProfile()\Error = #True Or TimeProfile()\Level <> 0
				Errors+1
				SetGadgetText(#Text, "Error - unbalanced calls of Start() and Stop():")
				AddGadgetItem(#Editor, -1, MapKey(TimeProfile()))
			Else
				AddElement(profile())
				profile()\Name$ = MapKey(TimeProfile())
				profile()\DurationAbs = TimeProfile()\DurationAbs
				If total > 0
					profile()\DurationRel = profile()\DurationAbs / total
				Else
					profile()\DurationRel = 1.0
				EndIf
				profile()\Called = TimeProfile()\Called
			EndIf
		Next

		SortStructuredList(profile(), #PB_Sort_Descending, OffsetOf(TimeProfileStruc\DurationRel), TypeOf(TimeProfileStruc\DurationRel))

		ForEach profile()
			item$ = ReplaceString(RSet(StrD(100 * profile()\DurationRel, 1), 5), " ", "  ") + #LF$
			item$ + _FormatTime(profile()\DurationAbs) + #LF$
			item$ + ReplaceString(_RAlign(Str(profile()\Called), 8), " ", "  ") + #LF$
			item$ + _FormatTime(profile()\DurationAbs / profile()\Called) + #LF$
			item$ + " " + profile()\Name$

			AddGadgetItem(#ListIcon, -1, item$)
		Next
		
		If Errors=#Null
			HideGadget(#Text,1)
			HideGadget(#Editor,1)
			ResizeGadget(#ListIcon,#PB_Ignore,#PB_Ignore,#PB_Ignore,#WinMain_Height-20)
		EndIf
		
		SetGadgetState(#ListIcon, 0)
		SetActiveGadget(#ListIcon)
		HideWindow(#WinMain,0)
		
		Repeat
		Until WaitWindowEvent() = #PB_Event_CloseWindow
	EndProcedure

Another simple extension would be to include procedure names automatically...

Code: Select all

Macro Start (_name_)
	:
	TimeProfile::_Start(_name_,#PB_Compiler_Procedure)
	:
EndMacro

Structure TimeProfileStruc
	:
	Modul.s
	:
EndStructure

Procedure _Start (name$,modul.s)
	If TimeProfile(name$)\Level = 0
		TimeProfile()\CurStart = ElapsedMilliseconds()
	EndIf
	TimeProfile()\Modul=modul
	:
EndProcedure

Procedure _Results ()
	:
	AddGadgetColumn(#ListIcon, 4, " Name", 120)
	AddGadgetColumn(#ListIcon, 5, " Modul", 120)
	:
	profile()\Name$ = MapKey(TimeProfile())
	profile()\Modul = TimeProfile()\Modul
	:
	item$ + " " + profile()\Name$+#LF$
	item$ + " " + profile()\Modul
	:
EndProcedure

Posted: **Sun Jan 27, 2019 8:00 pm**

Hi Michael,

thank you for your good suggestions! I just posted a new version.

Module names are included automatically now, but not as a separate structure field. They are now prepended to the name that is chosen for the time measurement block, similar to the way PB does do it itself with module names. So if someone (by accident) writes e.g. TimeProfile::Start("Foo") not only in one module, but also in another module, there still will be no naming conflict for my little tool.

New version 1.20, 2019-01-27

Changes

In the results window, the panel for error messages is now only shown if there are actually errors.

New

If a block for time measurement is inside of a module, then the self-chosen name for that block is automatically prepended with "<modulename>::".

Posted: **Sat Feb 09, 2019 10:35 pm**

Hi Little John,
Earlier tonight I tested the timing module: It is very good. Thank you.

However, when I tested this on my MacBook the program crashed.
I noticed that this was due to me missing both 'Totals'.
This is not an oblique complaint with your instructions; they are clear.
I didn't read them.

Posted: **Sun Feb 10, 2019 3:30 pm**

Hello davido,

thank you for your kind words, and for reporting that issue.
I just posted a new version, which has extended error checking.

Since to err is human, I think software should assist us in this regard whenever possible.
And since you drew my attention to Start("Total") and Stop("Total"), I found a related bug. Thank you!

New version 1.30, 2019-02-10

Fixed

Due to changes made in the previous version, time profiling did not work anymore if Start("Total") and Stop("Total") were called inside of a module.

Changed

Extended error checking.
Extended demo code, that also demonstrates how to use this module with other modules.
Improved documentation, especially in regard to usage of this modiule with other modules.

Posted: **Sun Feb 10, 2019 5:22 pm**

Wouldn't a total result of the time between the first starttimer and last stoptimer event easier for to handle?

For me I did something like this, but this is also too complicate...

Code: Select all

	Global TotalFlag
	#TotalName="Total"

	Macro Start (_name_)
		CompilerIf Defined(TimeProfile,#PB_Constant)
			CompilerIf #TimeProfile = #True And #PB_Compiler_Debugger = #False
				If TimeProfile::TotalFlag=0
					If _name_<>TimeProfile::#TotalName
						TimeProfile::_Start("",TimeProfile::#TotalName)
					Else
						TimeProfile::TotalFlag=#True
					EndIf
				EndIf
				TimeProfile::_Start(#PB_Compiler_Module, _name_)
			CompilerEndIf
		CompilerEndIf
	EndMacro

Posted: **Sun Feb 10, 2019 7:22 pm**

Michael Vogel wrote:Wouldn't a total result of the time between the first starttimer and last stoptimer event easier for to handle?

Great idea!

I didn't think of that.

That will make things simpler! I'll implement it in the next version.
Thank you!

Posted: **Mon Feb 11, 2019 7:41 am**

New version 1.40, 2019-02-11

Changed

Removed the need to call Start("Total") and Stop("Total")
and all related error checks that I introduced in the previous version.
Slightly increased the column widths of the output window.
Simplified the demo code a bit.

Thanks again to davido and Michael for the idea of doing without Start("Total") and Stop("Total").
That makes it considerably simpler and clearer!
It seems that I couldn't see the wood for the trees.

Posted: **Tue Mar 05, 2019 9:39 pm**

New version 1.41, 2019-03-05

Often, I'm using this module once for a whole program, i.e. I'm calling TimeProfile::Results() only at the end of the program. However, sometimes I find it useful to do time profiling in several sections of a program independently from each other, i.e. calling TimeProfile::Results() multiple times in the program. This is now better supported in the current version.

Fixed

Added missing CloseWindow(#WinMain) after the event loop.

Changed

You can now optionally pass your own title for the output window to the public Macro Results().
Demo code a bit extended.
Comments slightly improved.

New

Public Macro Clear() for resetting the state of the module, without showing the results.

Posted: **Tue Aug 06, 2019 6:58 pm**

New version 1.42, 2019-08-06

Changed
For the window and the gadgets no constants are used anymore, but variables in combination with #PB_Any.

PureBasic Forums - English

Poor (wo)man's time profiling

Poor (wo)man's time profiling

Re: Poor (wo)man's time profiling

Re: Poor (wo)man's time profiling

Re: Poor (wo)man's time profiling

Re: Poor (wo)man's time profiling

Re: Poor (wo)man's time profiling

Re: Poor (wo)man's time profiling

Re: Poor (wo)man's time profiling

Re: Poor (wo)man's time profiling

Re: Poor (wo)man's time profiling

Re: Poor (wo)man's time profiling

Re: Poor (wo)man's time profiling

Re: Poor (wo)man's time profiling