David K. Bainbridge | 528b318 | 2017-01-23 08:51:59 -0800 | [diff] [blame] | 1 | // Copyright 2013 Canonical Ltd. |
| 2 | // Licensed under the LGPLv3, see LICENCE file for details. |
| 3 | |
| 4 | package utils |
| 5 | |
| 6 | import ( |
| 7 | "fmt" |
| 8 | "os" |
| 9 | "time" |
| 10 | ) |
| 11 | |
| 12 | type timer struct { |
| 13 | action string |
| 14 | start time.Time |
| 15 | depth int |
| 16 | duration time.Duration |
| 17 | subActions []*timer |
| 18 | } |
| 19 | |
| 20 | func (t *timer) String() string { |
| 21 | this := fmt.Sprintf("%.3fs %*s%s\n", t.duration.Seconds(), t.depth, "", t.action) |
| 22 | for _, sub := range t.subActions { |
| 23 | this += sub.String() |
| 24 | } |
| 25 | return this |
| 26 | } |
| 27 | |
| 28 | var stack []*timer |
| 29 | |
| 30 | // Start a timer, used for tracking time spent. |
| 31 | // Generally used with either defer, as in: |
| 32 | // defer utils.Timeit("my func")() |
| 33 | // Which will track how much time is spent in your function. Or |
| 34 | // if you want to track the time spent in a function you are calling |
| 35 | // then you would use: |
| 36 | // toc := utils.Timeit("anotherFunc()") |
| 37 | // anotherFunc() |
| 38 | // toc() |
| 39 | // This tracks nested calls by indenting the output, and will print out the |
| 40 | // full stack of timing when we reach the top of the stack. |
| 41 | func Timeit(action string) func() { |
| 42 | cur := &timer{action: action, start: time.Now(), depth: len(stack)} |
| 43 | if len(stack) != 0 { |
| 44 | tip := stack[len(stack)-1] |
| 45 | tip.subActions = append(tip.subActions, cur) |
| 46 | } |
| 47 | stack = append(stack, cur) |
| 48 | return func() { |
| 49 | cur.duration = time.Since(cur.start) |
| 50 | if len(stack) == 0 || cur == stack[0] { |
| 51 | fmt.Fprint(os.Stderr, cur) |
| 52 | stack = nil |
| 53 | } else { |
| 54 | stack = stack[0 : len(stack)-1] |
| 55 | } |
| 56 | } |
| 57 | } |