b.runN(1)
}()
<-b.signal
- return !b.hasSub
+ if b.failed {
+ fmt.Fprintf(b.w, "--- FAIL: %s\n%s", b.name, b.output)
+ return false
+ }
+ // Only print the output if we know we are not going to proceed.
+ // Otherwise it is printed in processBench.
+ if b.hasSub || b.finished {
+ tag := "BENCH"
+ if b.skipped {
+ tag = "SKIP"
+ }
+ if b.chatty && (len(b.output) > 0 || b.finished) {
+ b.trimOutput()
+ fmt.Fprintf(b.w, "--- %s: %s\n%s", tag, b.name, b.output)
+ }
+ return false
+ }
+ return true
}
// run executes the benchmark in a separate goroutine, including all of its
}
}
main := &B{
- common: common{name: "Main"},
+ common: common{
+ name: "Main",
+ w: os.Stdout,
+ chatty: *chatty,
+ },
benchFunc: func(b *B) {
for _, Benchmark := range bs {
b.Run(Benchmark.Name, Benchmark.F)
for i, procs := range cpuList {
runtime.GOMAXPROCS(procs)
benchName := benchmarkName(b.name, procs)
- fmt.Printf("%-*s\t", ctx.maxLen, benchName)
+ fmt.Fprintf(b.w, "%-*s\t", ctx.maxLen, benchName)
// Recompute the running time for all but the first iteration.
if i > 0 {
b = &B{
common: common{
signal: make(chan bool),
name: b.name,
+ w: b.w,
+ chatty: b.chatty,
},
benchFunc: b.benchFunc,
benchTime: b.benchTime,
// 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)
+ fmt.Fprintf(b.w, "--- FAIL: %s\n%s", benchName, b.output)
continue
}
results := r.String()
if *benchmarkMemory || b.showAllocResult {
results += "\t" + r.MemString()
}
- fmt.Println(results)
+ fmt.Fprintln(b.w, results)
// 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)
+ fmt.Fprintf(b.w, "--- 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)
name: benchName,
parent: &b.common,
level: b.level + 1,
+ w: b.w,
+ chatty: b.chatty,
},
benchFunc: f,
benchTime: b.benchTime,
b := &B{
common: common{
signal: make(chan bool),
+ w: discard{},
},
benchFunc: f,
benchTime: *benchTime,
}
+ if !b.run1() {
+ return BenchmarkResult{}
+ }
return b.run()
}
+
+type discard struct{}
+
+func (discard) Write(b []byte) (n int, err error) { return len(b), nil }
package testing
import (
- "io/ioutil"
+ "bytes"
"regexp"
+ "strings"
"sync/atomic"
"time"
)
desc string
ok bool
maxPar int
+ chatty bool
+ output string
f func(*T)
}{{
desc: "failnow skips future sequential and parallel tests at same level",
ok: false,
maxPar: 1,
+ output: `
+--- FAIL: failnow skips future sequential and parallel tests at same level (0.00s)
+ --- FAIL: failnow skips future sequential and parallel tests at same level/#00 (0.00s)
+ `,
f: func(t *T) {
ranSeq := false
ranPar := false
desc: "failure in parallel test propagates upwards",
ok: false,
maxPar: 1,
+ output: `
+--- FAIL: failure in parallel test propagates upwards (0.00s)
+ --- FAIL: failure in parallel test propagates upwards/#00 (0.00s)
+ --- FAIL: failure in parallel test propagates upwards/#00/par (0.00s)
+ `,
f: func(t *T) {
t.Run("", func(t *T) {
t.Parallel()
})
})
},
+ }, {
+ desc: "skipping without message, chatty",
+ ok: true,
+ chatty: true,
+ output: `
+=== RUN skipping without message, chatty
+--- SKIP: skipping without message, chatty (0.00s)`,
+ f: func(t *T) { t.SkipNow() },
+ }, {
+ desc: "skipping without message, not chatty",
+ ok: true,
+ f: func(t *T) { t.SkipNow() },
+ }, {
+ desc: "skipping after error",
+ output: `
+--- FAIL: skipping after error (0.00s)
+ sub_test.go:nnn: an error
+ sub_test.go:nnn: skipped`,
+ f: func(t *T) {
+ t.Error("an error")
+ t.Skip("skipped")
+ },
}, {
desc: "use Run to locally synchronize parallelism",
ok: true,
})
}
},
+ }, {
+ desc: "skip output",
+ ok: true,
+ maxPar: 4,
+ f: func(t *T) {
+ t.Skip()
+ },
}}
for _, tc := range testCases {
ctx := newTestContext(tc.maxPar, newMatcher(regexp.MatchString, "", ""))
+ buf := &bytes.Buffer{}
root := &T{
common: common{
signal: make(chan bool),
name: "Test",
- w: ioutil.Discard,
+ w: buf,
+ chatty: tc.chatty,
},
context: ctx,
}
if ctx.running != 0 || ctx.numWaiting != 0 {
t.Errorf("%s:running and waiting non-zero: got %d and %d", tc.desc, ctx.running, ctx.numWaiting)
}
+ got := sanitizeLog(buf.String())
+ want := sanitizeLog(tc.output)
+ if got != want {
+ t.Errorf("%s:ouput:\ngot:\n%s\nwant:\n%s", tc.desc, got, want)
+ }
}
}
testCases := []struct {
desc string
failed bool
+ chatty bool
+ output string
f func(*B)
}{{
desc: "simulate sequential run of subbenchmarks.",
}, {
desc: "failure carried over to root",
failed: true,
+ output: "--- FAIL: root",
f: func(b *B) { b.Fail() },
+ }, {
+ desc: "skipping without message, chatty",
+ chatty: true,
+ output: "--- SKIP: root",
+ f: func(b *B) { b.SkipNow() },
+ }, {
+ desc: "skipping with message, chatty",
+ chatty: true,
+ output: `
+--- SKIP: root
+ sub_test.go:: skipping`,
+ f: func(b *B) { b.Skip("skipping") },
+ }, {
+ desc: "skipping without message, not chatty",
+ f: func(b *B) { b.SkipNow() },
+ }, {
+ desc: "skipping after error",
+ failed: true,
+ output: `
+--- FAIL: root
+ sub_test.go:nnn: an error
+ sub_test.go:nnn: skipped`,
+ f: func(b *B) {
+ b.Error("an error")
+ b.Skip("skipped")
+ },
}, {
desc: "memory allocation",
f: func(b *B) {
}}
for _, tc := range testCases {
var ok bool
+ buf := &bytes.Buffer{}
// This is almost like the Benchmark function, except that we override
// the benchtime and catch the failure result of the subbenchmark.
root := &B{
common: common{
signal: make(chan bool),
+ name: "root",
+ w: buf,
+ chatty: tc.chatty,
},
benchFunc: func(b *B) { ok = b.Run("test", tc.f) }, // Use Run to catch failure.
benchTime: time.Microsecond,
if root.result.N != 1 {
t.Errorf("%s: N for parent benchmark was %d; want 1", tc.desc, root.result.N)
}
+ got := sanitizeLog(buf.String())
+ want := sanitizeLog(tc.output)
+ if got != want {
+ t.Errorf("%s:ouput:\ngot:\n%s\nwant:\n%s", tc.desc, got, want)
+ }
}
}
+
+// sanitizeLog removes line numbers from log entries.
+func sanitizeLog(s string) string {
+ s = strings.TrimSpace(s)
+ lines := strings.Split(s, "\n")
+ for i, line := range lines {
+ p := strings.IndexByte(line, ':')
+ if p > 0 && line[p+4] == ':' { // assuming 3-digit file positions
+ lines[i] = line[:p+1] + line[p+4:]
+ }
+ }
+ return strings.Join(lines, "\n")
+}
+
+func TestBenchmarkOutput(t *T) {
+ // Ensure Benchmark initialized common.w by invoking it with an error and
+ // normal case.
+ Benchmark(func(b *B) { b.Error("do not print this output") })
+ Benchmark(func(b *B) {})
+}
mu sync.RWMutex // guards output and failed
output []byte // Output generated by test or benchmark.
w io.Writer // For flushToParent.
+ chatty bool // A copy of the chatty flag.
failed bool // Test or benchmark has failed.
skipped bool // Test of benchmark has been skipped.
finished bool
defer p.mu.Unlock()
fmt.Fprintf(p.w, format, args...)
- fmt.Fprintln(p.w)
c.mu.Lock()
defer c.mu.Unlock()
name: testName,
parent: &t.common,
level: t.level + 1,
+ chatty: t.chatty,
},
context: t.context,
}
t.w = indenter{&t.common}
- if *chatty {
- fmt.Printf("=== RUN %s\n", t.name)
+ if t.chatty {
+ // Print directly to root's io.Writer so there is no delay.
+ root := t.parent
+ for ; root.parent != nil; root = t.parent {
+ }
+ fmt.Fprintf(root.w, "=== RUN %s\n", t.name)
}
// Instead of reducing the running count of this test before calling the
// tRunner and increasing it afterwards, we rely on tRunner keeping the
return
}
dstr := fmtDuration(t.duration)
- format := "--- %s: %s (%s)"
+ format := "--- %s: %s (%s)\n"
if t.Failed() {
t.flushToParent(format, "FAIL", t.name, dstr)
- } else if *chatty {
+ } else if t.chatty {
if t.Skipped() {
t.flushToParent(format, "SKIP", t.name, dstr)
} else {
signal: make(chan bool),
barrier: make(chan bool),
w: os.Stdout,
+ chatty: *chatty,
},
context: ctx,
}