Sunday, December 30, 2007

SLIME - How to Profile in Lisp

If you have worked on a fairly *BIG* project you must have heard people saying, "Let's profile it first." When I started lisp programming I was clueless about profiling a lisp code. This was fairly easy in other programming languages by the tools they provide; I knew how to profile C/C++ code with GCC compiler options but not for lisp.
Here I am going to explain how to profile lisp codes using SLIME.
Suppose you have a function:

(defun foo()
(format t "Hello foo"))

and you call it like:

(loop for n
from 1 to 1000
do(progn
(print n)
(foo)))

Now you have to find how much time foo has taken. Below are the steps for that:

  • Run the command: M-x slime-toggle-profile-fdefinition and hit enter. It will ask you the function name you want to profile. Enter the function name (foo in our case) you want to profile.
  • Now run the function; as in our example we will run the loop for getting more data.
  • To see the profile data use command M-x slime-profile-report. This will show the profiled data in the format below:
seconds consed calls sec/call name
-----------------------------------------------------
0.015 587,712 1,000 0.000015 FOO
-----------------------------------------------------
0.015 587,712 1,000 Total

estimated total profiling overhead: .002 seconds
overhead estimation parameters:
0.0s/call, 2.03e-6s total profiling, 9.36e-7s internal profiling

There is profiling options for packages. For more details you can refer to SLIME Manual.