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

  1. takes a timestamp of when the function starts,
  2. gets the result of the expression,
  3. prints the execution time and finally
  4. 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

…but…

This is because we’re passing a list into our macro rather than just a single symbol.

which does what we want:

and

So it’s then trivial to update our time macro merging these two concepts together:

Which outputs exactly what I’m after:

Hooray!

One clap, two clap, three clap, forty?

By clapping more or less, you can signal to us which stories really stand out.