A typical report would be:
Profiler sampled 564 times
Call tree
Symbol seen (%)
1: MOD 17 ( 3)
2: FLOOR 5 ( 1)
1: EQL 8 ( 1)
1: >= 7 ( 1)
2: REALP 2 ( 0)
1: + 6 ( 1)
1: LENGTH 4 ( 1)
Cumulative profile summary
Symbol called profile (%) top (%)
MOD 1000000 17 ( 3) 8 ( 1)
EQL 2000117 8 ( 1) 8 ( 1)
>= 1000001 7 ( 1) 5 ( 1)
+ 1000000 6 ( 1) 6 ( 1)
FLOOR 1000000 5 ( 1) 5 ( 1)
LENGTH 2000086 4 ( 1) 4 ( 1)
REALP 1000001 2 ( 0) 2 ( 0)
On average 1.0 stacks profiled each profiler sampling
Top of stack not monitored 93% of the time
Sampled while in GC 0 times (0% of 564 samplings)
The first line means that Lisp was interrupted 564 times by the profiler.
The call tree shows that in 17 of these interrupts (3% of them) the profiler found the function mod on the stack, in 5 of these interrupts it found the function floor on the stack, and so on. Moreover, floor only appears under the mod branch of the tree, which means that each of these times floor was called by mod.
The cumulative profile summary also shows how many times each symbol was found on the stack. Moreover it shows that the function mod was called 1000000 times, the function eql was called 2000117 times, and so on. (Note: this information is not collected by default.) In 17 of these interrupts it found the function mod on the stack, and on 8 of these occasions mod was on the top of the stack. You can deduce that 526 times the function on the top of the stack was none of those reported.
You can control sort order of the cumulative profile summary with print-profile-list.
One important figure is the amount of time it was found on top of the stack in the cumulative profile summary. Just because a function is found on the stack does not mean that it uses up much processing time, but if it is found consistently on the top of the stack then it is likely that this function has a significant execution time. Another thing to check is that you expect the functions near to top of the call tree to take significant time.
It must be remembered that the numbers produced are from random samples and thus it is important to be careful in interpreting their meaning. The rate of sampling is always coarse in comparison to the function call rate and so it is possible for strange effects to occur and significant events to be missed. For example, "resonance" may occur when an event always occurs between regular sampling times, though in practice this does not appear to be a problem.
Once profiling information has been recorded, either by stop-profiling or a normal exit from profile, it is possible to print specific parts of the information. The function profiler-tree-from-function prints a tree showing a specific function and the functions called inside it. The function profiler-tree-to-function prints a tree showing a specific function and its callers. This tree is inverted, which means that the children of a node are its callers, rather than callees as in the full tree and the tree printed by profiler-tree-from-function.
The function profiler-tree-to-allocation-functions prints an inverted tree, where the roots are allocation functions and the children are their callers.
LispWorks® User Guide and Reference Manual - 01 Dec 2021 19:30:20