Merge lp:~jameinel/juju-utils/timeit into lp:juju-utils

[John A Meinel]

Pulling the timeit functionality out of juju-core itself.
It still is the only thing that gives wallclock time for what functions you're blocking in.
The nesting can still be wrong with concurrent routines, but it still gives correct *time* just incorrect nesting of the output display.

We talked about moving this out into "juju-core-utils", but since you've already created juju-utils I figured I'd just use it.
The focus is slightly different (your's seems more executable vs library oriented), but it seems reasonable.

Unmerged revisions

3. By John A Meinel on 2013-05-23

Add timeit from juju-core itself.

=== added directory 'utils'
=== added file 'utils/timeit.go'
--- utils/timeit.go	1970-01-01 00:00:00 +0000
+++ utils/timeit.go	2013-05-23 07:22:23 +0000
@@ -0,0 +1,54 @@
+package utils
+
+import (
+	"fmt"
+	"os"
+	"time"
+)
+
+type timer struct {
+	action     string
+	start      time.Time
+	depth      int
+	duration   time.Duration
+	subActions []*timer
+}
+
+func (t *timer) String() string {
+	this := fmt.Sprintf("%.3fs %*s%s\n", t.duration.Seconds(), t.depth, "", t.action)
+	for _, sub := range t.subActions {
+		this += sub.String()
+	}
+	return this
+}
+
+var stack []*timer
+
+// Start a timer, used for tracking time spent.
+// Generally used with either defer, as in:
+//  defer utils.Timeit("my func")()
+// Which will track how much time is spent in your function. Or
+// if you want to track the time spent in a function you are calling
+// then you would use:
+//  toc := utils.Timeit("anotherFunc()")
+//  anotherFunc()
+//  toc()
+// This tracks nested calls by indenting the output, and will print out the
+// full stack of timing when we reach the top of the stack.
+func Timeit(action string) func() {
+	cur := &timer{action: action, start: time.Now(), depth: len(stack)}
+	if len(stack) != 0 {
+		tip := stack[len(stack)-1]
+		tip.subActions = append(tip.subActions, cur)
+	}
+	stack = append(stack, cur)
+	return func() {
+		cur.duration = time.Since(cur.start)
+		if len(stack) == 0 || cur == stack[0] {
+			fmt.Fprint(os.Stderr, cur)
+			stack = nil
+		} else {
+			stack = stack[0 : len(stack)-1]
+		}
+	}
+}