| // Copyright 2016 The Go Authors. All rights reserved. |
| // Use of this source code is governed by a BSD-style |
| // license that can be found in the LICENSE file. |
| |
| package base |
| |
| import ( |
| "fmt" |
| "io" |
| "strings" |
| "time" |
| ) |
| |
| var Timer Timings |
| |
| // Timings collects the execution times of labeled phases |
| // which are added through a sequence of Start/Stop calls. |
| // Events may be associated with each phase via AddEvent. |
| type Timings struct { |
| list []timestamp |
| events map[int][]*event // lazily allocated |
| } |
| |
| type timestamp struct { |
| time time.Time |
| label string |
| start bool |
| } |
| |
| type event struct { |
| size int64 // count or amount of data processed (allocations, data size, lines, funcs, ...) |
| unit string // unit of size measure (count, MB, lines, funcs, ...) |
| } |
| |
| func (t *Timings) append(labels []string, start bool) { |
| t.list = append(t.list, timestamp{time.Now(), strings.Join(labels, ":"), start}) |
| } |
| |
| // Start marks the beginning of a new phase and implicitly stops the previous phase. |
| // The phase name is the colon-separated concatenation of the labels. |
| func (t *Timings) Start(labels ...string) { |
| t.append(labels, true) |
| } |
| |
| // Stop marks the end of a phase and implicitly starts a new phase. |
| // The labels are added to the labels of the ended phase. |
| func (t *Timings) Stop(labels ...string) { |
| t.append(labels, false) |
| } |
| |
| // AddEvent associates an event, i.e., a count, or an amount of data, |
| // with the most recently started or stopped phase; or the very first |
| // phase if Start or Stop hasn't been called yet. The unit specifies |
| // the unit of measurement (e.g., MB, lines, no. of funcs, etc.). |
| func (t *Timings) AddEvent(size int64, unit string) { |
| m := t.events |
| if m == nil { |
| m = make(map[int][]*event) |
| t.events = m |
| } |
| i := len(t.list) |
| if i > 0 { |
| i-- |
| } |
| m[i] = append(m[i], &event{size, unit}) |
| } |
| |
| // Write prints the phase times to w. |
| // The prefix is printed at the start of each line. |
| func (t *Timings) Write(w io.Writer, prefix string) { |
| if len(t.list) > 0 { |
| var lines lines |
| |
| // group of phases with shared non-empty label prefix |
| var group struct { |
| label string // label prefix |
| tot time.Duration // accumulated phase time |
| size int // number of phases collected in group |
| } |
| |
| // accumulated time between Stop/Start timestamps |
| var unaccounted time.Duration |
| |
| // process Start/Stop timestamps |
| pt := &t.list[0] // previous timestamp |
| tot := t.list[len(t.list)-1].time.Sub(pt.time) |
| for i := 1; i < len(t.list); i++ { |
| qt := &t.list[i] // current timestamp |
| dt := qt.time.Sub(pt.time) |
| |
| var label string |
| var events []*event |
| if pt.start { |
| // previous phase started |
| label = pt.label |
| events = t.events[i-1] |
| if qt.start { |
| // start implicitly ended previous phase; nothing to do |
| } else { |
| // stop ended previous phase; append stop labels, if any |
| if qt.label != "" { |
| label += ":" + qt.label |
| } |
| // events associated with stop replace prior events |
| if e := t.events[i]; e != nil { |
| events = e |
| } |
| } |
| } else { |
| // previous phase stopped |
| if qt.start { |
| // between a stopped and started phase; unaccounted time |
| unaccounted += dt |
| } else { |
| // previous stop implicitly started current phase |
| label = qt.label |
| events = t.events[i] |
| } |
| } |
| if label != "" { |
| // add phase to existing group, or start a new group |
| l := commonPrefix(group.label, label) |
| if group.size == 1 && l != "" || group.size > 1 && l == group.label { |
| // add to existing group |
| group.label = l |
| group.tot += dt |
| group.size++ |
| } else { |
| // start a new group |
| if group.size > 1 { |
| lines.add(prefix+group.label+"subtotal", 1, group.tot, tot, nil) |
| } |
| group.label = label |
| group.tot = dt |
| group.size = 1 |
| } |
| |
| // write phase |
| lines.add(prefix+label, 1, dt, tot, events) |
| } |
| |
| pt = qt |
| } |
| |
| if group.size > 1 { |
| lines.add(prefix+group.label+"subtotal", 1, group.tot, tot, nil) |
| } |
| |
| if unaccounted != 0 { |
| lines.add(prefix+"unaccounted", 1, unaccounted, tot, nil) |
| } |
| |
| lines.add(prefix+"total", 1, tot, tot, nil) |
| |
| lines.write(w) |
| } |
| } |
| |
| func commonPrefix(a, b string) string { |
| i := 0 |
| for i < len(a) && i < len(b) && a[i] == b[i] { |
| i++ |
| } |
| return a[:i] |
| } |
| |
| type lines [][]string |
| |
| func (lines *lines) add(label string, n int, dt, tot time.Duration, events []*event) { |
| var line []string |
| add := func(format string, args ...interface{}) { |
| line = append(line, fmt.Sprintf(format, args...)) |
| } |
| |
| add("%s", label) |
| add(" %d", n) |
| add(" %d ns/op", dt) |
| add(" %.2f %%", float64(dt)/float64(tot)*100) |
| |
| for _, e := range events { |
| add(" %d", e.size) |
| add(" %s", e.unit) |
| add(" %d", int64(float64(e.size)/dt.Seconds()+0.5)) |
| add(" %s/s", e.unit) |
| } |
| |
| *lines = append(*lines, line) |
| } |
| |
| func (lines lines) write(w io.Writer) { |
| // determine column widths and contents |
| var widths []int |
| var number []bool |
| for _, line := range lines { |
| for i, col := range line { |
| if i < len(widths) { |
| if len(col) > widths[i] { |
| widths[i] = len(col) |
| } |
| } else { |
| widths = append(widths, len(col)) |
| number = append(number, isnumber(col)) // first line determines column contents |
| } |
| } |
| } |
| |
| // make column widths a multiple of align for more stable output |
| const align = 1 // set to a value > 1 to enable |
| if align > 1 { |
| for i, w := range widths { |
| w += align - 1 |
| widths[i] = w - w%align |
| } |
| } |
| |
| // print lines taking column widths and contents into account |
| for _, line := range lines { |
| for i, col := range line { |
| format := "%-*s" |
| if number[i] { |
| format = "%*s" // numbers are right-aligned |
| } |
| fmt.Fprintf(w, format, widths[i], col) |
| } |
| fmt.Fprintln(w) |
| } |
| } |
| |
| func isnumber(s string) bool { |
| for _, ch := range s { |
| if ch <= ' ' { |
| continue // ignore leading whitespace |
| } |
| return '0' <= ch && ch <= '9' || ch == '.' || ch == '-' || ch == '+' |
| } |
| return false |
| } |