CODEWITHSUNDEEP
profilingcommon-lispprofilersbcl
Sim
Sim

Reputation: 4184

How to read sbcl deterministic profiler output?

How is the output of the deterministic profiler of sbcl to be interpreted?

  seconds  |     gc     |   consed  | calls |  sec/call  |  name
-------------------------------------------------------

seconds (total execution time),calls (amount overall calls),sec/call (average time per call), and name (well the name of the function) are quite straight forward. What does consed and gcmean?

I guess consed tells the allocated memory (though in what unit?) and I'd say that gc tells the amount of units reclaimed by the gc but those two values never match and even use a different representation scheme (gc has a . every 3 numbers and consed a , .

E.g. what would this example output tell me (if my guess is right I'd have a massive memory leak):

  seconds  |     gc     |   consed  | calls |  sec/call  |  name
-------------------------------------------------------     
     0.011 |      0.000 |   965,488 |     6 |   0.001817 | PACKAGE:NAME
-------------------------------------------------------
     0.011 |      0.000 |   965,488 |     6 |             | Total

Upvotes: 0

Views: 325

Answers (1)

Orivej Desh
Orivej Desh

Reputation: 382

The columns are easier to interpret if you are familiar with the output of (free …) under SBCL (abbreviated):

Evaluation took:
  0.771 seconds of real time
  [ Run times consist of 0.061 seconds GC time, and 0.639 seconds non-GC time. ]
  166,575,680 bytes consed

In your example package:name was at the top of the call stack (among profiled functions only) for 0.011 seconds, and GC did not affect it because it never happened during this time or was too fast, and 965488 bytes of SBCL-managed memory were allocated.

The amount of memory that was used and became unused after each GC can not be broken down per function, because this information is not tracked. You can measure overall memory consumption by evaluating (sb-ext:gc :full t) (room) before and after, but note that the reported amount fluctuates slightly, and does not include memory allocated by foreign code (C libraries, if your application uses them), and that the last three results and expressions at the REPL are retained.

Upvotes: 1

Related Questions