// B is a type passed to Benchmark functions to manage benchmark
// timing and to specify the number of iterations to run.
type B struct {
+ common
N int
benchmark InternalBenchmark
- ns time.Duration
bytes int64
- start time.Time
timerOn bool
+ result BenchmarkResult
}
// StartTimer starts timing a test. This function is called automatically
// want to measure.
func (b *B) StopTimer() {
if b.timerOn {
- b.ns += time.Now().Sub(b.start)
+ b.duration += time.Now().Sub(b.start)
b.timerOn = false
}
}
if b.timerOn {
b.start = time.Now()
}
- b.ns = 0
+ b.duration = 0
}
// SetBytes records the number of bytes processed in a single operation.
if b.N <= 0 {
return 0
}
- return b.ns.Nanoseconds() / int64(b.N)
+ return b.duration.Nanoseconds() / int64(b.N)
}
// runN runs a single benchmark for the specified number of iterations.
return 10 * base
}
-// run times the benchmark function. It gradually increases the number
+// run times the benchmark function in a separate goroutine.
+func (b *B) run() BenchmarkResult {
+ go b.launch()
+ <-b.signal
+ return b.result
+}
+
+// launch launches the benchmark function. It gradually increases the number
// of benchmark iterations until the benchmark runs for a second in order
// to get a reasonable measurement. It prints timing information in this form
// testing.BenchmarkHello 100000 19 ns/op
-func (b *B) run() BenchmarkResult {
+// launch is run by the fun function as a separate goroutine.
+func (b *B) launch() {
// Run the benchmark for a single iteration in case it's expensive.
n := 1
b.runN(n)
// Run the benchmark for at least the specified amount of time.
d := time.Duration(*benchTime * float64(time.Second))
- for b.ns < d && n < 1e9 {
+ for !b.failed && b.duration < d && n < 1e9 {
last := n
// Predict iterations/sec.
if b.nsPerOp() == 0 {
n = roundUp(n)
b.runN(n)
}
- return BenchmarkResult{b.N, b.ns, b.bytes}
+ b.result = BenchmarkResult{b.N, b.duration, b.bytes}
+ b.signal <- b
}
// The results of a benchmark run.
}
for _, procs := range cpuList {
runtime.GOMAXPROCS(procs)
- b := &B{benchmark: Benchmark}
+ b := &B{
+ common: common{
+ signal: make(chan interface{}),
+ },
+ benchmark: Benchmark,
+ }
benchName := Benchmark.Name
if procs != 1 {
benchName = fmt.Sprintf("%s-%d", Benchmark.Name, procs)
}
fmt.Printf("%s\t", benchName)
r := b.run()
+ if b.failed {
+ // The output could be very long here, but probably isn't.
+ // We print it all, regardless, because we don't want to trim the reason
+ // the benchmark failed.
+ fmt.Printf("--- FAIL: %s\n%s", benchName, b.output)
+ continue
+ }
fmt.Printf("%v\n", r)
+ // Unlike with tests, we ignore the -chatty flag and always print output for
+ // benchmarks since the output generation time will skew the results.
+ if len(b.output) > 0 {
+ b.trimOutput()
+ fmt.Printf("--- BENCH: %s\n%s", benchName, b.output)
+ }
if p := runtime.GOMAXPROCS(-1); p != procs {
fmt.Fprintf(os.Stderr, "testing: %s left GOMAXPROCS set to %d\n", benchName, p)
}
}
}
+// trimOutput shortens the output from a benchmark, which can be very long.
+func (b *B) trimOutput() {
+ // The output is likely to appear multiple times because the benchmark
+ // is run multiple times, but at least it will be seen. This is not a big deal
+ // because benchmarks rarely print, but just in case, we trim it if it's too long.
+ const maxNewlines = 10
+ for nlCount, j := 0, 0; j < len(b.output); j++ {
+ if b.output[j] == '\n' {
+ nlCount++
+ if nlCount >= maxNewlines {
+ b.output = append(b.output[:j], "\n\t... [output truncated]\n"...)
+ break
+ }
+ }
+ }
+}
+
// Benchmark benchmarks a single function. Useful for creating
// custom benchmarks that do not use gotest.
func Benchmark(f func(b *B)) BenchmarkResult {
- b := &B{benchmark: InternalBenchmark{"", f}}
+ b := &B{
+ common: common{
+ signal: make(chan interface{}),
+ },
+ benchmark: InternalBenchmark{"", f},
+ }
return b.run()
}
// }
// The benchmark package will vary b.N until the benchmark function lasts
// long enough to be timed reliably. The output
-// testing.BenchmarkHello 500000 4076 ns/op
-// means that the loop ran 500000 times at a speed of 4076 ns per loop.
+// testing.BenchmarkHello 10000000 282 ns/op
+// means that the loop ran 10000000 times at a speed of 282 ns per loop.
//
// If a benchmark needs some expensive setup before running, the timer
// may be stopped:
cpuList []int
)
+// common holds the elements common between T and B and
+// captures common methods such as Errorf.
+type common struct {
+ output []byte // Output generated by test or benchmark.
+ failed bool // Test or benchmark has failed.
+ start time.Time // Time test or benchmark started
+ duration time.Duration
+ self interface{} // To be sent on signal channel when done.
+ signal chan interface{} // Output for serial tests.
+}
+
// Short reports whether the -test.short flag is set.
func Short() bool {
return *short
// T is a type passed to Test functions to manage test state and support formatted test logs.
// Logs are accumulated during execution and dumped to standard error when done.
type T struct {
- name string // Name of test.
- errors string // Error string from test.
- failed bool // Test has failed.
- ch chan *T // Output for serial tests.
- startParallel chan bool // Parallel tests will wait on this.
- start time.Time // Time test started
- dt time.Duration // Length of test
+ common
+ name string // Name of test.
+ startParallel chan bool // Parallel tests will wait on this.
}
-// Fail marks the Test function as having failed but continues execution.
-func (t *T) Fail() { t.failed = true }
+// Fail marks the function as having failed but continues execution.
+func (c *common) Fail() { c.failed = true }
-// Failed returns whether the Test function has failed.
-func (t *T) Failed() bool { return t.failed }
+// Failed returns whether the function has failed.
+func (c *common) Failed() bool { return c.failed }
-// FailNow marks the Test function as having failed and stops its execution.
+// FailNow marks the function as having failed and stops its execution.
// Execution will continue at the next Test.
-func (t *T) FailNow() {
- t.dt = time.Now().Sub(t.start)
- t.Fail()
- t.ch <- t
+func (c *common) FailNow() {
+ c.duration = time.Now().Sub(c.start)
+ c.Fail()
+ c.signal <- c.self
runtime.Goexit()
}
// log generates the output. It's always at the same stack depth.
-func (t *T) log(s string) { t.errors += decorate(s, true) }
+func (c *common) log(s string) {
+ c.output = append(c.output, decorate(s, true)...)
+}
// Log formats its arguments using default formatting, analogous to Print(),
// and records the text in the error log.
-func (t *T) Log(args ...interface{}) { t.log(fmt.Sprintln(args...)) }
+func (c *common) Log(args ...interface{}) { c.log(fmt.Sprintln(args...)) }
// Logf formats its arguments according to the format, analogous to Printf(),
// and records the text in the error log.
-func (t *T) Logf(format string, args ...interface{}) { t.log(fmt.Sprintf(format, args...)) }
+func (c *common) Logf(format string, args ...interface{}) { c.log(fmt.Sprintf(format, args...)) }
// Error is equivalent to Log() followed by Fail().
-func (t *T) Error(args ...interface{}) {
- t.log(fmt.Sprintln(args...))
- t.Fail()
+func (c *common) Error(args ...interface{}) {
+ c.log(fmt.Sprintln(args...))
+ c.Fail()
}
// Errorf is equivalent to Logf() followed by Fail().
-func (t *T) Errorf(format string, args ...interface{}) {
- t.log(fmt.Sprintf(format, args...))
- t.Fail()
+func (c *common) Errorf(format string, args ...interface{}) {
+ c.log(fmt.Sprintf(format, args...))
+ c.Fail()
}
// Fatal is equivalent to Log() followed by FailNow().
-func (t *T) Fatal(args ...interface{}) {
- t.log(fmt.Sprintln(args...))
- t.FailNow()
+func (c *common) Fatal(args ...interface{}) {
+ c.log(fmt.Sprintln(args...))
+ c.FailNow()
}
// Fatalf is equivalent to Logf() followed by FailNow().
-func (t *T) Fatalf(format string, args ...interface{}) {
- t.log(fmt.Sprintf(format, args...))
- t.FailNow()
+func (c *common) Fatalf(format string, args ...interface{}) {
+ c.log(fmt.Sprintf(format, args...))
+ c.FailNow()
}
// Parallel signals that this test is to be run in parallel with (and only with)
// other parallel tests in this CPU group.
func (t *T) Parallel() {
- t.ch <- nil // Release main testing loop
+ t.signal <- nil // Release main testing loop
<-t.startParallel // Wait for serial tests to finish
}
func tRunner(t *T, test *InternalTest) {
t.start = time.Now()
test.F(t)
- t.dt = time.Now().Sub(t.start)
- t.ch <- t
+ t.duration = time.Now().Sub(t.start)
+ t.signal <- t
}
// An internal function but exported because it is cross-package; part of the implementation
after()
}
-func report(t *T) {
- tstr := fmt.Sprintf("(%.2f seconds)", t.dt.Seconds())
+func (t *T) report() {
+ tstr := fmt.Sprintf("(%.2f seconds)", t.duration.Seconds())
format := "--- %s: %s %s\n%s"
if t.failed {
- fmt.Printf(format, "FAIL", t.name, tstr, t.errors)
+ fmt.Printf(format, "FAIL", t.name, tstr, t.output)
} else if *chatty {
- fmt.Printf(format, "PASS", t.name, tstr, t.errors)
+ fmt.Printf(format, "PASS", t.name, tstr, t.output)
}
}
fmt.Fprintln(os.Stderr, "testing: warning: no tests to run")
return
}
- ch := make(chan *T)
+ // TODO: each test should have its own channel, although that means
+ // keeping track of the channels when we're running parallel tests.
+ signal := make(chan interface{})
for _, procs := range cpuList {
runtime.GOMAXPROCS(procs)
if procs != 1 {
testName = fmt.Sprintf("%s-%d", tests[i].Name, procs)
}
- t := &T{ch: ch, name: testName, startParallel: startParallel}
+ t := &T{
+ common: common{
+ signal: signal,
+ },
+ name: testName,
+ startParallel: startParallel,
+ }
+ t.self = t
if *chatty {
fmt.Printf("=== RUN %s\n", t.name)
}
go tRunner(t, &tests[i])
- out := <-t.ch
+ out := (<-t.signal).(*T)
if out == nil { // Parallel run.
numParallel++
continue
}
- report(t)
+ t.report()
ok = ok && !out.failed
}
numParallel--
continue
}
- t := <-ch
- report(t)
+ t := (<-signal).(*T)
+ t.report()
ok = ok && !t.failed
running--
}