profiling

[Ralf Hemmecke]

Hello,

Can I ask for some help for interpreting the following sbcl profiling
output.

In particular I do not understand how I can interpret the 109.5 %. This
is percent of what? And why is it over 100%? Does not make sense to me.

Other question is. What is the function "TRUNCATE" in FriCAS doing?

Thank you
Ralf


Self Total Cumul
Nr Count % Count % Count % Calls Function
------------------------------------------------------------------------
1 226 13.0 226 13.0 226 13.0 - TRUNCATE
2 204 11.7 555 31.9 430 24.7 - |SMP;*;R2$;35|
3 178 10.2 1907 109.5 608 34.9 - |PR;addms!|
4 131 7.5 1838 105.6 739 42.4 - |IFFTS;*;3$;20|
5 124 7.1 289 16.6 863 49.6 - |IDPO;add_si|
6 99 5.7 233 13.4 962 55.3 - |SMP;+;3$;36|
7 98 5.6 104 6.0 1060 60.9 - |ABELMON-;zero?;SB;1|
8 67 3.8 102 5.9 1127 64.7 - |SMP;*;3$;39|
9 59 3.4 59 3.4 1186 68.1 - |SMP;zero?;$B;3|
10 57 3.3 59 3.4 1243 71.4 - |ZMOD;=;2$B;12|
11 49 2.8 278 16.0 1292 74.2 - |ZMOD;*;3$;13|
12 46 2.6 46 2.6 1338 76.9 - |ZMOD;+;3$;15|

[Waldek Hebisch]

On Sat, Oct 17, 2020 at 09:29:37PM +0200, Ralf Hemmecke wrote:
>
> Can I ask for some help for interpreting the following sbcl profiling
> output.
>
> In particular I do not understand how I can interpret the 109.5 %. This
> is percent of what? And why is it over 100%? Does not make sense to me.

109.5 % looks too large. There are estimates and heuristics
in comutation of "Total" time. Or maybe you found some
accounting paradox where some time was not counted towards
100% but was counted in other place. Some tools show
parallel execution dividing CPU time by real time, but
I did not see anything like that in FriCAS profiling
data.

>
> Other question is. What is the function "TRUNCATE" in FriCAS doing?

"TRUNCATE" is Lisp division with remainder. FriCAS uses is
almost exlusivly for integer arguments but Lisp defines it
also for floats.

> Self Total Cumul
> Nr Count % Count % Count % Calls Function
> ------------------------------------------------------------------------
> 1 226 13.0 226 13.0 226 13.0 - TRUNCATE
> 2 204 11.7 555 31.9 430 24.7 - |SMP;*;R2$;35|
> 3 178 10.2 1907 109.5 608 34.9 - |PR;addms!|
> 4 131 7.5 1838 105.6 739 42.4 - |IFFTS;*;3$;20|
> 5 124 7.1 289 16.6 863 49.6 - |IDPO;add_si|
> 6 99 5.7 233 13.4 962 55.3 - |SMP;+;3$;36|
> 7 98 5.6 104 6.0 1060 60.9 - |ABELMON-;zero?;SB;1|
> 8 67 3.8 102 5.9 1127 64.7 - |SMP;*;3$;39|
> 9 59 3.4 59 3.4 1186 68.1 - |SMP;zero?;$B;3|
> 10 57 3.3 59 3.4 1243 71.4 - |ZMOD;=;2$B;12|
> 11 49 2.8 278 16.0 1292 74.2 - |ZMOD;*;3$;13|
> 12 46 2.6 46 2.6 1338 76.9 - |ZMOD;+;3$;15|
>

--
Waldek Hebisch