I need to understand the SBCL profiler a little if anyone can help
interpret: I have 5 dependent functions:
F5 calls F4 which calls F3 which calls F2 which calls F1.
Now it seems that F1 and F2 are the problematic ones (and indeed when
I converted F1 and F2 into C functions and used the ECL FFI to call
them the speed of the computation was increased about 5 to 10 times; I
could as well optimze the code solely in common lisp of course). But
why in F3 which consed 509,804,392 it says that the measuring seconds
is 0.000? shouldn't it consume time with garbage collection if it's so
much consed? (same question for F4). Thanks
measuring PROFILE overhead..done
seconds | consed | calls | sec/call | name
---------------------------------------------------------------
5.787 | 3,052,856,136 | 1,002,001 | 0.000006 | F1
3.932 | 1,075,334,352 | 3,006,003 | 0.000001 | F2
0.000 | 509,804,392 | 4,004 | 0.000000 | F3
0.000 | 5,441,872 | 4 | 0.000000 | F4
0.000 | 36,824 | 1 | 0.000000 | F5
---------------------------------------------------------------
9.719 | 4,643,473,576 | 4,012,013 | | Total
On Apr 1, 10:59 am, Francogrex <······@grex.org> wrote:
> I need to understand the SBCL profiler a little if anyone can help
> interpret: I have 5 dependent functions:
> F5 calls F4 which calls F3 which calls F2 which calls F1.
> Now it seems that F1 and F2 are the problematic ones (and indeed when
> I converted F1 and F2 into C functions and used the ECL FFI to call
> them the speed of the computation was increased about 5 to 10 times; I
> could as well optimze the code solely in common lisp of course). But
> why in F3 which consed 509,804,392 it says that the measuring seconds
> is 0.000? shouldn't it consume time with garbage collection if it's so
> much consed? (same question for F4). Thanks
>
> measuring PROFILE overhead..done
> seconds | consed | calls | sec/call | name
> ---------------------------------------------------------------
> 5.787 | 3,052,856,136 | 1,002,001 | 0.000006 | F1
> 3.932 | 1,075,334,352 | 3,006,003 | 0.000001 | F2
> 0.000 | 509,804,392 | 4,004 | 0.000000 | F3
> 0.000 | 5,441,872 | 4 | 0.000000 | F4
> 0.000 | 36,824 | 1 | 0.000000 | F5
> ---------------------------------------------------------------
> 9.719 | 4,643,473,576 | 4,012,013 | | Total
I don't know the exact answer, but note that profiler also reports
time usage for GC separately, maybe it's not counted as running time.