blob: 3f0f71f647d8c11229d8e1dd92b8fc4b3874b8bc [file] [log] [blame]
// 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 testing
import (
"bytes"
"fmt"
"reflect"
"regexp"
"runtime"
"strings"
"sync"
"sync/atomic"
"time"
)
func init() {
// Make benchmark tests run 10x faster.
benchTime.d = 100 * time.Millisecond
}
func TestTestContext(t *T) {
const (
add1 = 0
done = 1
)
// After each of the calls are applied to the context, the
type call struct {
typ int // run or done
// result from applying the call
running int
waiting int
started bool
}
testCases := []struct {
max int
run []call
}{{
max: 1,
run: []call{
{typ: add1, running: 1, waiting: 0, started: true},
{typ: done, running: 0, waiting: 0, started: false},
},
}, {
max: 1,
run: []call{
{typ: add1, running: 1, waiting: 0, started: true},
{typ: add1, running: 1, waiting: 1, started: false},
{typ: done, running: 1, waiting: 0, started: true},
{typ: done, running: 0, waiting: 0, started: false},
{typ: add1, running: 1, waiting: 0, started: true},
},
}, {
max: 3,
run: []call{
{typ: add1, running: 1, waiting: 0, started: true},
{typ: add1, running: 2, waiting: 0, started: true},
{typ: add1, running: 3, waiting: 0, started: true},
{typ: add1, running: 3, waiting: 1, started: false},
{typ: add1, running: 3, waiting: 2, started: false},
{typ: add1, running: 3, waiting: 3, started: false},
{typ: done, running: 3, waiting: 2, started: true},
{typ: add1, running: 3, waiting: 3, started: false},
{typ: done, running: 3, waiting: 2, started: true},
{typ: done, running: 3, waiting: 1, started: true},
{typ: done, running: 3, waiting: 0, started: true},
{typ: done, running: 2, waiting: 0, started: false},
{typ: done, running: 1, waiting: 0, started: false},
{typ: done, running: 0, waiting: 0, started: false},
},
}}
for i, tc := range testCases {
ctx := &testContext{
startParallel: make(chan bool),
maxParallel: tc.max,
}
for j, call := range tc.run {
doCall := func(f func()) chan bool {
done := make(chan bool)
go func() {
f()
done <- true
}()
return done
}
started := false
switch call.typ {
case add1:
signal := doCall(ctx.waitParallel)
select {
case <-signal:
started = true
case ctx.startParallel <- true:
<-signal
}
case done:
signal := doCall(ctx.release)
select {
case <-signal:
case <-ctx.startParallel:
started = true
<-signal
}
}
if started != call.started {
t.Errorf("%d:%d:started: got %v; want %v", i, j, started, call.started)
}
if ctx.running != call.running {
t.Errorf("%d:%d:running: got %v; want %v", i, j, ctx.running, call.running)
}
if ctx.numWaiting != call.waiting {
t.Errorf("%d:%d:waiting: got %v; want %v", i, j, ctx.numWaiting, call.waiting)
}
}
}
}
func TestTRun(t *T) {
realTest := t
testCases := []struct {
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 (N.NNs)
--- FAIL: failnow skips future sequential and parallel tests at same level/#00 (N.NNs)
`,
f: func(t *T) {
ranSeq := false
ranPar := false
t.Run("", func(t *T) {
t.Run("par", func(t *T) {
t.Parallel()
ranPar = true
})
t.Run("seq", func(t *T) {
ranSeq = true
})
t.FailNow()
t.Run("seq", func(t *T) {
realTest.Error("test must be skipped")
})
t.Run("par", func(t *T) {
t.Parallel()
realTest.Error("test must be skipped.")
})
})
if !ranPar {
realTest.Error("parallel test was not run")
}
if !ranSeq {
realTest.Error("sequential test was not run")
}
},
}, {
desc: "failure in parallel test propagates upwards",
ok: false,
maxPar: 1,
output: `
--- FAIL: failure in parallel test propagates upwards (N.NNs)
--- FAIL: failure in parallel test propagates upwards/#00 (N.NNs)
--- FAIL: failure in parallel test propagates upwards/#00/par (N.NNs)
`,
f: func(t *T) {
t.Run("", func(t *T) {
t.Parallel()
t.Run("par", func(t *T) {
t.Parallel()
t.Fail()
})
})
},
}, {
desc: "skipping without message, chatty",
ok: true,
chatty: true,
output: `
=== RUN skipping without message, chatty
--- SKIP: skipping without message, chatty (N.NNs)`,
f: func(t *T) { t.SkipNow() },
}, {
desc: "chatty with recursion",
ok: true,
chatty: true,
output: `
=== RUN chatty with recursion
=== RUN chatty with recursion/#00
=== RUN chatty with recursion/#00/#00
--- PASS: chatty with recursion (N.NNs)
--- PASS: chatty with recursion/#00 (N.NNs)
--- PASS: chatty with recursion/#00/#00 (N.NNs)`,
f: func(t *T) {
t.Run("", func(t *T) {
t.Run("", func(t *T) {})
})
},
}, {
desc: "skipping without message, not chatty",
ok: true,
f: func(t *T) { t.SkipNow() },
}, {
desc: "skipping after error",
output: `
--- FAIL: skipping after error (N.NNs)
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,
maxPar: 1,
f: func(t *T) {
var count uint32
t.Run("waitGroup", func(t *T) {
for i := 0; i < 4; i++ {
t.Run("par", func(t *T) {
t.Parallel()
atomic.AddUint32(&count, 1)
})
}
})
if count != 4 {
t.Errorf("count was %d; want 4", count)
}
},
}, {
desc: "alternate sequential and parallel",
// Sequential tests should partake in the counting of running threads.
// Otherwise, if one runs parallel subtests in sequential tests that are
// itself subtests of parallel tests, the counts can get askew.
ok: true,
maxPar: 1,
f: func(t *T) {
t.Run("a", func(t *T) {
t.Parallel()
t.Run("b", func(t *T) {
// Sequential: ensure running count is decremented.
t.Run("c", func(t *T) {
t.Parallel()
})
})
})
},
}, {
desc: "alternate sequential and parallel 2",
// Sequential tests should partake in the counting of running threads.
// Otherwise, if one runs parallel subtests in sequential tests that are
// itself subtests of parallel tests, the counts can get askew.
ok: true,
maxPar: 2,
f: func(t *T) {
for i := 0; i < 2; i++ {
t.Run("a", func(t *T) {
t.Parallel()
time.Sleep(time.Nanosecond)
for i := 0; i < 2; i++ {
t.Run("b", func(t *T) {
time.Sleep(time.Nanosecond)
for i := 0; i < 2; i++ {
t.Run("c", func(t *T) {
t.Parallel()
time.Sleep(time.Nanosecond)
})
}
})
}
})
}
},
}, {
desc: "stress test",
ok: true,
maxPar: 4,
f: func(t *T) {
t.Parallel()
for i := 0; i < 12; i++ {
t.Run("a", func(t *T) {
t.Parallel()
time.Sleep(time.Nanosecond)
for i := 0; i < 12; i++ {
t.Run("b", func(t *T) {
time.Sleep(time.Nanosecond)
for i := 0; i < 12; i++ {
t.Run("c", func(t *T) {
t.Parallel()
time.Sleep(time.Nanosecond)
t.Run("d1", func(t *T) {})
t.Run("d2", func(t *T) {})
t.Run("d3", func(t *T) {})
t.Run("d4", func(t *T) {})
})
}
})
}
})
}
},
}, {
desc: "skip output",
ok: true,
maxPar: 4,
f: func(t *T) {
t.Skip()
},
}, {
desc: "subtest calls error on parent",
ok: false,
output: `
--- FAIL: subtest calls error on parent (N.NNs)
sub_test.go:NNN: first this
sub_test.go:NNN: and now this!
sub_test.go:NNN: oh, and this too`,
maxPar: 1,
f: func(t *T) {
t.Errorf("first this")
outer := t
t.Run("", func(t *T) {
outer.Errorf("and now this!")
})
t.Errorf("oh, and this too")
},
}, {
desc: "subtest calls fatal on parent",
ok: false,
output: `
--- FAIL: subtest calls fatal on parent (N.NNs)
sub_test.go:NNN: first this
sub_test.go:NNN: and now this!
--- FAIL: subtest calls fatal on parent/#00 (N.NNs)
testing.go:NNN: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test`,
maxPar: 1,
f: func(t *T) {
outer := t
t.Errorf("first this")
t.Run("", func(t *T) {
outer.Fatalf("and now this!")
})
t.Errorf("Should not reach here.")
},
}, {
desc: "subtest calls error on ancestor",
ok: false,
output: `
--- FAIL: subtest calls error on ancestor (N.NNs)
sub_test.go:NNN: Report to ancestor
--- FAIL: subtest calls error on ancestor/#00 (N.NNs)
sub_test.go:NNN: Still do this
sub_test.go:NNN: Also do this`,
maxPar: 1,
f: func(t *T) {
outer := t
t.Run("", func(t *T) {
t.Run("", func(t *T) {
outer.Errorf("Report to ancestor")
})
t.Errorf("Still do this")
})
t.Errorf("Also do this")
},
}, {
desc: "subtest calls fatal on ancestor",
ok: false,
output: `
--- FAIL: subtest calls fatal on ancestor (N.NNs)
sub_test.go:NNN: Nope`,
maxPar: 1,
f: func(t *T) {
outer := t
t.Run("", func(t *T) {
for i := 0; i < 4; i++ {
t.Run("", func(t *T) {
outer.Fatalf("Nope")
})
t.Errorf("Don't do this")
}
t.Errorf("And neither do this")
})
t.Errorf("Nor this")
},
}, {
desc: "panic on goroutine fail after test exit",
ok: false,
maxPar: 4,
f: func(t *T) {
ch := make(chan bool)
t.Run("", func(t *T) {
go func() {
<-ch
defer func() {
if r := recover(); r == nil {
realTest.Errorf("expected panic")
}
ch <- true
}()
t.Errorf("failed after success")
}()
})
ch <- true
<-ch
},
}, {
desc: "log in finished sub test logs to parent",
ok: false,
output: `
--- FAIL: log in finished sub test logs to parent (N.NNs)
sub_test.go:NNN: message2
sub_test.go:NNN: message1
sub_test.go:NNN: error`,
maxPar: 1,
f: func(t *T) {
ch := make(chan bool)
t.Run("sub", func(t2 *T) {
go func() {
<-ch
t2.Log("message1")
ch <- true
}()
})
t.Log("message2")
ch <- true
<-ch
t.Errorf("error")
},
}, {
// A chatty test should always log with fmt.Print, even if the
// parent test has completed.
// TODO(deklerk) Capture the log of fmt.Print and assert that the
// subtest message is not lost.
desc: "log in finished sub test with chatty",
ok: false,
chatty: true,
output: `
--- FAIL: log in finished sub test with chatty (N.NNs)`,
maxPar: 1,
f: func(t *T) {
ch := make(chan bool)
t.Run("sub", func(t2 *T) {
go func() {
<-ch
t2.Log("message1")
ch <- true
}()
})
t.Log("message2")
ch <- true
<-ch
t.Errorf("error")
},
}}
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: buf,
chatty: tc.chatty,
},
context: ctx,
}
ok := root.Run(tc.desc, tc.f)
ctx.release()
if ok != tc.ok {
t.Errorf("%s:ok: got %v; want %v", tc.desc, ok, tc.ok)
}
if ok != !root.Failed() {
t.Errorf("%s:root failed: got %v; want %v", tc.desc, !ok, root.Failed())
}
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 := strings.TrimSpace(buf.String())
want := strings.TrimSpace(tc.output)
re := makeRegexp(want)
if ok, err := regexp.MatchString(re, got); !ok || err != nil {
t.Errorf("%s:output:\ngot:\n%s\nwant:\n%s", tc.desc, got, want)
}
}
}
func TestBRun(t *T) {
work := func(b *B) {
for i := 0; i < b.N; i++ {
time.Sleep(time.Nanosecond)
}
}
testCases := []struct {
desc string
failed bool
chatty bool
output string
f func(*B)
}{{
desc: "simulate sequential run of subbenchmarks.",
f: func(b *B) {
b.Run("", func(b *B) { work(b) })
time1 := b.result.NsPerOp()
b.Run("", func(b *B) { work(b) })
time2 := b.result.NsPerOp()
if time1 >= time2 {
t.Errorf("no time spent in benchmark t1 >= t2 (%d >= %d)", time1, time2)
}
},
}, {
desc: "bytes set by all benchmarks",
f: func(b *B) {
b.Run("", func(b *B) { b.SetBytes(10); work(b) })
b.Run("", func(b *B) { b.SetBytes(10); work(b) })
if b.result.Bytes != 20 {
t.Errorf("bytes: got: %d; want 20", b.result.Bytes)
}
},
}, {
desc: "bytes set by some benchmarks",
// In this case the bytes result is meaningless, so it must be 0.
f: func(b *B) {
b.Run("", func(b *B) { b.SetBytes(10); work(b) })
b.Run("", func(b *B) { work(b) })
b.Run("", func(b *B) { b.SetBytes(10); work(b) })
if b.result.Bytes != 0 {
t.Errorf("bytes: got: %d; want 0", b.result.Bytes)
}
},
}, {
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: "chatty with recursion",
chatty: true,
f: func(b *B) {
b.Run("", func(b *B) {
b.Run("", func(b *B) {})
})
},
}, {
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) {
const bufSize = 256
alloc := func(b *B) {
var buf [bufSize]byte
for i := 0; i < b.N; i++ {
_ = append([]byte(nil), buf[:]...)
}
}
b.Run("", func(b *B) {
alloc(b)
b.ReportAllocs()
})
b.Run("", func(b *B) {
alloc(b)
b.ReportAllocs()
})
// runtime.MemStats sometimes reports more allocations than the
// benchmark is responsible for. Luckily the point of this test is
// to ensure that the results are not underreported, so we can
// simply verify the lower bound.
if got := b.result.MemAllocs; got < 2 {
t.Errorf("MemAllocs was %v; want 2", got)
}
if got := b.result.MemBytes; got < 2*bufSize {
t.Errorf("MemBytes was %v; want %v", got, 2*bufSize)
}
},
}}
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: benchTimeFlag{d: 1 * time.Microsecond},
}
root.runN(1)
if ok != !tc.failed {
t.Errorf("%s:ok: got %v; want %v", tc.desc, ok, !tc.failed)
}
if !ok != root.Failed() {
t.Errorf("%s:root failed: got %v; want %v", tc.desc, !ok, root.Failed())
}
// All tests are run as subtests
if root.result.N != 1 {
t.Errorf("%s: N for parent benchmark was %d; want 1", tc.desc, root.result.N)
}
got := strings.TrimSpace(buf.String())
want := strings.TrimSpace(tc.output)
re := makeRegexp(want)
if ok, err := regexp.MatchString(re, got); !ok || err != nil {
t.Errorf("%s:output:\ngot:\n%s\nwant:\n%s", tc.desc, got, want)
}
}
}
func makeRegexp(s string) string {
s = regexp.QuoteMeta(s)
s = strings.ReplaceAll(s, ":NNN:", `:\d\d\d:`)
s = strings.ReplaceAll(s, "N\\.NNs", `\d*\.\d*s`)
return s
}
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) {})
}
func TestBenchmarkStartsFrom1(t *T) {
var first = true
Benchmark(func(b *B) {
if first && b.N != 1 {
panic(fmt.Sprintf("Benchmark() first N=%v; want 1", b.N))
}
first = false
})
}
func TestBenchmarkReadMemStatsBeforeFirstRun(t *T) {
var first = true
Benchmark(func(b *B) {
if first && (b.startAllocs == 0 || b.startBytes == 0) {
panic(fmt.Sprintf("ReadMemStats not called before first run"))
}
first = false
})
}
func TestParallelSub(t *T) {
c := make(chan int)
block := make(chan int)
for i := 0; i < 10; i++ {
go func(i int) {
<-block
t.Run(fmt.Sprint(i), func(t *T) {})
c <- 1
}(i)
}
close(block)
for i := 0; i < 10; i++ {
<-c
}
}
type funcWriter func([]byte) (int, error)
func (fw funcWriter) Write(b []byte) (int, error) { return fw(b) }
func TestRacyOutput(t *T) {
var runs int32 // The number of running Writes
var races int32 // Incremented for each race detected
raceDetector := func(b []byte) (int, error) {
// Check if some other goroutine is concurrently calling Write.
if atomic.LoadInt32(&runs) > 0 {
atomic.AddInt32(&races, 1) // Race detected!
}
atomic.AddInt32(&runs, 1)
defer atomic.AddInt32(&runs, -1)
runtime.Gosched() // Increase probability of a race
return len(b), nil
}
var wg sync.WaitGroup
root := &T{
common: common{w: funcWriter(raceDetector), chatty: true},
context: newTestContext(1, newMatcher(regexp.MatchString, "", "")),
}
root.Run("", func(t *T) {
for i := 0; i < 100; i++ {
wg.Add(1)
go func(i int) {
defer wg.Done()
t.Run(fmt.Sprint(i), func(t *T) {
t.Logf("testing run %d", i)
})
}(i)
}
})
wg.Wait()
if races > 0 {
t.Errorf("detected %d racy Writes", races)
}
}
// The late log message did not include the test name. Issue 29388.
func TestLogAfterComplete(t *T) {
ctx := newTestContext(1, newMatcher(regexp.MatchString, "", ""))
var buf bytes.Buffer
t1 := &T{
common: common{
// Use a buffered channel so that tRunner can write
// to it although nothing is reading from it.
signal: make(chan bool, 1),
w: &buf,
},
context: ctx,
}
c1 := make(chan bool)
c2 := make(chan string)
tRunner(t1, func(t *T) {
t.Run("TestLateLog", func(t *T) {
go func() {
defer close(c2)
defer func() {
p := recover()
if p == nil {
c2 <- "subtest did not panic"
return
}
s, ok := p.(string)
if !ok {
c2 <- fmt.Sprintf("subtest panic with unexpected value %v", p)
return
}
const want = "Log in goroutine after TestLateLog has completed"
if !strings.Contains(s, want) {
c2 <- fmt.Sprintf("subtest panic %q does not contain %q", s, want)
}
}()
<-c1
t.Log("log after test")
}()
})
})
close(c1)
if s := <-c2; s != "" {
t.Error(s)
}
}
func TestBenchmark(t *T) {
if Short() {
t.Skip("skipping in short mode")
}
res := Benchmark(func(b *B) {
for i := 0; i < 5; i++ {
b.Run("", func(b *B) {
for i := 0; i < b.N; i++ {
time.Sleep(time.Millisecond)
}
})
}
})
if res.NsPerOp() < 4000000 {
t.Errorf("want >5ms; got %v", time.Duration(res.NsPerOp()))
}
}
func TestCleanup(t *T) {
var cleanups []int
t.Run("test", func(t *T) {
t.Cleanup(func() { cleanups = append(cleanups, 1) })
t.Cleanup(func() { cleanups = append(cleanups, 2) })
})
if got, want := cleanups, []int{2, 1}; !reflect.DeepEqual(got, want) {
t.Errorf("unexpected cleanup record; got %v want %v", got, want)
}
}
func TestConcurrentCleanup(t *T) {
cleanups := 0
t.Run("test", func(t *T) {
done := make(chan struct{})
for i := 0; i < 2; i++ {
i := i
go func() {
t.Cleanup(func() {
cleanups |= 1 << i
})
done <- struct{}{}
}()
}
<-done
<-done
})
if cleanups != 1|2 {
t.Errorf("unexpected cleanup; got %d want 3", cleanups)
}
}
func TestCleanupCalledEvenAfterGoexit(t *T) {
cleanups := 0
t.Run("test", func(t *T) {
t.Cleanup(func() {
cleanups++
})
t.Cleanup(func() {
runtime.Goexit()
})
})
if cleanups != 1 {
t.Errorf("unexpected cleanup count; got %d want 1", cleanups)
}
}
func TestRunCleanup(t *T) {
outerCleanup := 0
innerCleanup := 0
t.Run("test", func(t *T) {
t.Cleanup(func() { outerCleanup++ })
t.Run("x", func(t *T) {
t.Cleanup(func() { innerCleanup++ })
})
})
if innerCleanup != 1 {
t.Errorf("unexpected inner cleanup count; got %d want 1", innerCleanup)
}
if outerCleanup != 1 {
t.Errorf("unexpected outer cleanup count; got %d want 0", outerCleanup)
}
}