// 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 gc
import (
"fmt"
"io"
"strings"
"time"
)
// Timings collects the execution times of labeled phases
// which are added trough 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
}