Profiling your application

Jeff · Post by **Jeff** » Mon Jul 28, 2008 4:33 pm

I wrote a simple profiler that gives you the number of calls to a function and how long was spent in the function:

http://static.artfulcode.net/newlisp/profiler.lsp.html

The overhead is pretty low - a call to time and two calls to inc per profiled function call. Even with the overhead, though, the relative stats are useful, and the larger the function, the less relative the overhead per call is. In that way, it is somewhat skewed on small function calls, but only by ~5 ms for each 10,000 calls:

Code: Select all

> (setq x 0 y 0)
0
> (time (begin (inc 'x) (inc 'y (time '()))))
0
> (time (begin (inc 'x) (inc 'y (time '()))) 10)
0
> (time (begin (inc 'x) (inc 'y (time '()))) 100)
0
> (time (begin (inc 'x) (inc 'y (time '()))) 1000)
0
> (time (begin (inc 'x) (inc 'y (time '()))) 10000)
5

cormullion · Post by **cormullion** » Mon Jul 28, 2008 6:38 pm

Works really well Jeff! I like the output - very neat. (I'd quite like a %age of total time column as well! :)

Jeff · Post by **Jeff** » Mon Jul 28, 2008 7:01 pm

It's added (but not thoroughly tested)

cormullion · Post by **cormullion** » Wed Sep 17, 2008 5:49 pm

Jeff - I've been trying to get this running on newlisp 9.3 without success - is it using 9.4-specific features?

Jeff · Post by **Jeff** » Wed Sep 17, 2008 5:54 pm

I don't remember. It uses the new dictionary syntax, I know that. What is the error you are getting?

cormullion · Post by **cormullion** » Wed Sep 17, 2008 6:32 pm

invalid function : (calls "markdown:amps-and-angles" 0)
called from user defined function Profiler:profile-functions
called from user defined function Profiler:profile-context

I think it must be the new hash table stuff in 9.4?

I thought I'd try and get some profiling done of the blog output, but there I'm stuck on 9.3.

No problem...

Lutz · Post by **Lutz** » Thu Sep 18, 2008 1:49 pm

You can easily replace a hash with context statements, to make it work on older versions of newLISP:

(MyHash <str-key> <value>)
replace with
(context MyHash <str-key> <value>)

(MyHash <str-key>)
replace with
(context MyHash <str-key>)

Leave the (define MyHash:MyHash) statement, because it conveniently creates and pre-declares the context, wihtout the need to switch back to MAIN when using the alternative: (context 'MyHash) (context MAIN).

The only difference between the two methods is, that when using the 'context' function, there is no underscore prepended to the key. But this shouldn't make a difference in most applications. Else both methods are completely compatible and do the same things internally.

Jeff · Post by **Jeff** » Thu Sep 18, 2008 1:53 pm

I think the profiler uses the underscores in situations when it needs to iterate over the keys.