Quick and Dirty Function Timing in Go

When I want to do some rough timing comparisons or get a quick idea of what part of Thing X is taking so long I sometimes just time a few functions. I used to do this by getting st := time.Now() at the beginning of the function and then time.Since(st) at the end. It recently hit me that the same thing could be achieved with less duplication and messiness to clean up (when removing the timings) with something like this:

func TimeElapsed(label string, minDuration time.Duration) func() {
	st := time.Now()
	return func() {
		el := time.Since(st)
		if el >= minDuration {
			fmt.Printf("%s ran in %v\n", label, el)
		}
	}
}

In the function we’re timing:

func MyCoolFunction() {
	defer lib.TimeElapsed("my cool function", time.Millisecond)()
    // Do other stuff
}

Explanation

defer will execute a function after the outer function returns.

TimeElapsed() returns a closure. This will happen immediately (so at the time we run defer..., and the returned function is run when MyCoolFunction() returns.

comments powered by Disqus