Page 1 of 2
Profiling compiling mode
Posted: Thu Mar 09, 2023 8:10 pm
by StarBootics
Hello everyone,
Profiling mode would be very useful to see where our code is taking time to execute. I know it's possible to do it our self but an integrated system would be nice. Something like that is possible with Javascript shown in the following video :
https://www.youtube.com/watch?v=oewDaISQpw0
Best regards
StarBootics
Re: Profiling compiling mode
Posted: Thu Mar 09, 2023 8:15 pm
by Caronte3D
+100000
That would be a great improvement to put PB on par with other language IDEs that have that feature, because once you get used to it, it's hard to live without it.
Re: Profiling compiling mode
Posted: Thu Mar 09, 2023 9:00 pm
by Fred
Did you tried the profiler in the IDE ?
Re: Profiling compiling mode
Posted: Thu Mar 09, 2023 9:40 pm
by luis
The one included in PB measures the number of times some code has been executed, and while it's an interesting information that can be useful does not measure the time spent in the code, and very often that's the main thing you are looking for I believe.
Re: Profiling compiling mode
Posted: Thu Mar 09, 2023 10:12 pm
by Caronte3D
Exactly!
Re: Profiling compiling mode
Posted: Thu Mar 09, 2023 10:29 pm
by StarBootics
Fred wrote: Thu Mar 09, 2023 9:00 pm
Did you tried the profiler in the IDE ?
I just try to use it but it show absolutely nothing, the program we try to profile freezes as well as the IDE. But what is supposed to show when working ?
Best regards
StarBootics
Re: Profiling compiling mode
Posted: Sat Mar 11, 2023 11:30 pm
by StarBootics
StarBootics wrote: Thu Mar 09, 2023 10:29 pm
I just try to use it but it show absolutely nothing, the program we try to profile freezes as well as the IDE. But what is supposed to show when working ?
I just retry with a simple code and the Profiler seem to work but it's not giving something useful to me. What is the difference between the Profiler and the procedures Callstack beside the presentation ?
@Fred : Did you take time to watch the video I have posted ?
What I would like to have is a Profiler that work without the debugger mode and tell me where I spend time inside a given code. Something like this can be very handy for speed critical application such as a game when you have a small time budget per frame let's say between 0.016 and 0.032 seconds.
Best regards
StarBootics
Re: Profiling compiling mode
Posted: Tue Mar 14, 2023 11:34 pm
by idle
time profiler
CPU Frequency 2.75 ghz
foo sum time 685 ms avg cycles 18,614,901 0
main sum time 685 ms avg cycles 1,861,570,995 0
bar sum time 677 ms avg cycles 18,396 0
main elapsed ms check 686
press any key to end
viewtopic.php?t=81099
Re: Profiling compiling mode
Posted: Wed Mar 15, 2023 11:24 am
by PeDe
Thanks for the idea. I have always used macros at the beginning and end of a procedure. With this I can follow the program flow, this also works with threads. I only had to add two lines to the macros, and could now program a time measurement. At the end of the program a window is shown with the results. Net is the time without further procedure calls within the measured procedure, gross is the total time the procedure took.
Screenshot (The times are formatted in German):
https://www.dreisiebner.at/temp/PB_Prof ... cedure.png
Peter
Re: Profiling compiling mode
Posted: Wed Mar 15, 2023 12:19 pm
by luis
PeDe wrote: Wed Mar 15, 2023 11:24 am
I have always used macros at the beginning and end of a procedure.
Your reporting tool is very nice, I like the distinction between "gross" and "net", the downside is one has to manually add those macros for every procedure or implement some kind of tool to do that.
Would be nice if PB had a compiler option to force it to generate two predefined function calls, one when entering and one when exiting a procedure, maybe passing a pointer to a structure containing some useful info. One could use them as he sees fit, not last profiling.
Re: Profiling compiling mode
Posted: Wed Mar 15, 2023 3:58 pm
by idle
Thanks Pede your welcome I think or did I miss understand, I havent tried it threaded yet what did you add to the macros to make it work?
Picture looks good
Luis did you even look at the code I posted. I only spent half a day on it.
The compiler could of course add timing code but what exactly is it going to add. It needs some research.
The time stamp counter is ok for relative performance of the cumulative average cycles as it may add in time from another thread on context switches but it's sufficient to show the performance at the finest level.
Q How long does it take for a 64 bit counter to roll over runing at 2 and 4 ghz?
Q What's the arm equivalent asm.
Fred could look at using gprof in gcc that might be an option just compile with -pg and it will complie with profile data then run it with gprof but thats only c backend.
Back to sleep my dog was howling and I only had 2 hours sleep
Re: Profiling compiling mode
Posted: Wed Mar 15, 2023 5:00 pm
by PeDe
Hello idle,
here is the macro for the procedure start. For the procedure end and threads there are the same macros:
Code: Select all
Macro MProcIn(uDebugViewData = uDebugViewData)
CompilerIf #fDebugOutEnabled And (#fDebugOut And #fDebugHigh And #DebugOutModule)
DebugView::Out(#Null$, #PB_Compiler_Module, #PB_Compiler_Procedure, DebugView::#eProcIn, uDebugViewData)
CompilerEndIf
CompilerIf #fDebugOutEnabled And Defined(fDebugProfiling, #PB_Constant)
DebugProfiling::Proc(#PB_Compiler_Module, #PB_Compiler_Procedure, DebugView::#eProcIn, uDebugViewData)
CompilerEndIf
EndMacro
There are still #eProcOut, #eThreadIn, #eThreadOut etc. as event.
uDebugViewData is a structure that contains an instance number, thread number and thread type.
I can use it to distinguish each instance of a window, object or thread. So profiling works with threads as well.
A procedure then looks like this:
Code: Select all
Procedure.i Calc(iParam1.i, ... , DebugView::MDInstance)
DebugView::MInstanceD()
DebugView::MProcIn()
; code
DebugView:MProcOut
EndProcedure
With this I can output the program flow to a log window, or send it to DebugView++ with 'OutputDebugString_()'.
Here is a screenshot when all debug outputs are enabled. Threads have their own indentation and background color purple/violet:
https://www.dreisiebner.at/temp/PB_DebugView.png
Peter
Re: Profiling compiling mode
Posted: Wed Mar 15, 2023 5:47 pm
by Caronte3D
Nice!
You add the Macros on each Procedure by hand or do you have some tool to add it automatically in every one?
Re: Profiling compiling mode
Posted: Wed Mar 15, 2023 7:20 pm
by luis
idle wrote: Wed Mar 15, 2023 3:58 pm
Luis did you even look at the code I posted. I only spent half a day on it.
Yes, I saw it thank you, I saved it as a starting point if I ever decide I actually need to profile something.
Even if probably using just ElapsedMilliseconds() would be enough for my uses.
idle wrote: Wed Mar 15, 2023 3:58 pm
Fred could look at using gprof in gcc that might be an option just compile with -pg and it will complie with profile data then run it with gprof but thats only c backend.
Yes, I still think providing a mechanism to let anyone write his own profiling code (the two special functions) would be fine for most uses.
It is not like profiling a process externally using a sampling profiler but it would be universal to all backends/platforms and customizable.
Anyway I would take even a pre-cooked profiler.
PS: is rollover really a problem ? Unless the time between the two polls is gigantic the math works even after a rollover.
I suppose you have to make some distinctions if you have to interpret the data as unsigned or not.
Code: Select all
t1.q = $fffffffffffffff0 ; 64 bits about to roll over
t2.q = 10
Debug (t2 - t1) ; separated by 26 units
Re: Profiling compiling mode
Posted: Thu Mar 16, 2023 1:46 am
by idle
@PeDe
Ok thanks, that looks like you've been working at this for a while, if the timing codes of any use to you your welcome to use it. I haven't really considered how to use the time profile data yet. but yes debugview++ is certainly a good example of what to aim for, just want it to be cross platform.
@luis
If you don't mind having 0 time results then ElapsedMillisconds() is fine, there's a lot of cpu cycles in 1ms
Thanks yes your right about the roll over
@Caronte3D
Yes you can add the blocks as required but it would also be easy to automate but I'm not sure how it'd work with recursive functions yet.
if we can get a working solution it will make it easier for Fred to add it.