Timing Clojure functions
Having built Rareburg in a bit of a hurry I didn’t have time to optimize some of the functionality as much as I would have liked so I’m now back tracking over some of the code base to measure and improve.
As far as benchmarking libraries go Criterion is certainly a bells and whistles one but before I discovered that I was using the built in macro time to do my time measuring. The annoying thing with time when using it more than a little is it doesn’t identify the function that is being measured and just prints “Elapsed time xxx”:
Digging into this time macro shows what is going on under the hood:
So the macro
- takes a timestamp of when the function starts,
- gets the result of the expression,
- prints the execution time and finally
- returns the result of the expression.
To get the name of the function being executed I needed to look into the metadata of the function:
Then running this returns the correct name of the function
This is because we’re passing a list into our macro rather than just a single symbol.
which does what we want:
So it’s then trivial to update our time macro merging these two concepts together:
Which outputs exactly what I’m after: