Source file src/testing/sub_test.go

     1  // Copyright 2016 The Go Authors. All rights reserved.
     2  // Use of this source code is governed by a BSD-style
     3  // license that can be found in the LICENSE file.
     4  
     5  package testing
     6  
     7  import (
     8  	"bytes"
     9  	"fmt"
    10  	"reflect"
    11  	"regexp"
    12  	"runtime"
    13  	"strings"
    14  	"sync"
    15  	"sync/atomic"
    16  	"time"
    17  )
    18  
    19  func init() {
    20  	// Make benchmark tests run 10x faster.
    21  	benchTime.d = 100 * time.Millisecond
    22  }
    23  
    24  func TestTestContext(t *T) {
    25  	const (
    26  		add1 = 0
    27  		done = 1
    28  	)
    29  	// After each of the calls are applied to the context, the
    30  	type call struct {
    31  		typ int // run or done
    32  		// result from applying the call
    33  		running int
    34  		waiting int
    35  		started bool
    36  	}
    37  	testCases := []struct {
    38  		max int
    39  		run []call
    40  	}{{
    41  		max: 1,
    42  		run: []call{
    43  			{typ: add1, running: 1, waiting: 0, started: true},
    44  			{typ: done, running: 0, waiting: 0, started: false},
    45  		},
    46  	}, {
    47  		max: 1,
    48  		run: []call{
    49  			{typ: add1, running: 1, waiting: 0, started: true},
    50  			{typ: add1, running: 1, waiting: 1, started: false},
    51  			{typ: done, running: 1, waiting: 0, started: true},
    52  			{typ: done, running: 0, waiting: 0, started: false},
    53  			{typ: add1, running: 1, waiting: 0, started: true},
    54  		},
    55  	}, {
    56  		max: 3,
    57  		run: []call{
    58  			{typ: add1, running: 1, waiting: 0, started: true},
    59  			{typ: add1, running: 2, waiting: 0, started: true},
    60  			{typ: add1, running: 3, waiting: 0, started: true},
    61  			{typ: add1, running: 3, waiting: 1, started: false},
    62  			{typ: add1, running: 3, waiting: 2, started: false},
    63  			{typ: add1, running: 3, waiting: 3, started: false},
    64  			{typ: done, running: 3, waiting: 2, started: true},
    65  			{typ: add1, running: 3, waiting: 3, started: false},
    66  			{typ: done, running: 3, waiting: 2, started: true},
    67  			{typ: done, running: 3, waiting: 1, started: true},
    68  			{typ: done, running: 3, waiting: 0, started: true},
    69  			{typ: done, running: 2, waiting: 0, started: false},
    70  			{typ: done, running: 1, waiting: 0, started: false},
    71  			{typ: done, running: 0, waiting: 0, started: false},
    72  		},
    73  	}}
    74  	for i, tc := range testCases {
    75  		ctx := &testContext{
    76  			startParallel: make(chan bool),
    77  			maxParallel:   tc.max,
    78  		}
    79  		for j, call := range tc.run {
    80  			doCall := func(f func()) chan bool {
    81  				done := make(chan bool)
    82  				go func() {
    83  					f()
    84  					done <- true
    85  				}()
    86  				return done
    87  			}
    88  			started := false
    89  			switch call.typ {
    90  			case add1:
    91  				signal := doCall(ctx.waitParallel)
    92  				select {
    93  				case <-signal:
    94  					started = true
    95  				case ctx.startParallel <- true:
    96  					<-signal
    97  				}
    98  			case done:
    99  				signal := doCall(ctx.release)
   100  				select {
   101  				case <-signal:
   102  				case <-ctx.startParallel:
   103  					started = true
   104  					<-signal
   105  				}
   106  			}
   107  			if started != call.started {
   108  				t.Errorf("%d:%d:started: got %v; want %v", i, j, started, call.started)
   109  			}
   110  			if ctx.running != call.running {
   111  				t.Errorf("%d:%d:running: got %v; want %v", i, j, ctx.running, call.running)
   112  			}
   113  			if ctx.numWaiting != call.waiting {
   114  				t.Errorf("%d:%d:waiting: got %v; want %v", i, j, ctx.numWaiting, call.waiting)
   115  			}
   116  		}
   117  	}
   118  }
   119  
   120  func TestTRun(t *T) {
   121  	realTest := t
   122  	testCases := []struct {
   123  		desc   string
   124  		ok     bool
   125  		maxPar int
   126  		chatty bool
   127  		json   bool
   128  		output string
   129  		f      func(*T)
   130  	}{{
   131  		desc:   "failnow skips future sequential and parallel tests at same level",
   132  		ok:     false,
   133  		maxPar: 1,
   134  		output: `
   135  --- FAIL: failnow skips future sequential and parallel tests at same level (N.NNs)
   136      --- FAIL: failnow skips future sequential and parallel tests at same level/#00 (N.NNs)
   137      `,
   138  		f: func(t *T) {
   139  			ranSeq := false
   140  			ranPar := false
   141  			t.Run("", func(t *T) {
   142  				t.Run("par", func(t *T) {
   143  					t.Parallel()
   144  					ranPar = true
   145  				})
   146  				t.Run("seq", func(t *T) {
   147  					ranSeq = true
   148  				})
   149  				t.FailNow()
   150  				t.Run("seq", func(t *T) {
   151  					realTest.Error("test must be skipped")
   152  				})
   153  				t.Run("par", func(t *T) {
   154  					t.Parallel()
   155  					realTest.Error("test must be skipped.")
   156  				})
   157  			})
   158  			if !ranPar {
   159  				realTest.Error("parallel test was not run")
   160  			}
   161  			if !ranSeq {
   162  				realTest.Error("sequential test was not run")
   163  			}
   164  		},
   165  	}, {
   166  		desc:   "failure in parallel test propagates upwards",
   167  		ok:     false,
   168  		maxPar: 1,
   169  		output: `
   170  --- FAIL: failure in parallel test propagates upwards (N.NNs)
   171      --- FAIL: failure in parallel test propagates upwards/#00 (N.NNs)
   172          --- FAIL: failure in parallel test propagates upwards/#00/par (N.NNs)
   173          `,
   174  		f: func(t *T) {
   175  			t.Run("", func(t *T) {
   176  				t.Parallel()
   177  				t.Run("par", func(t *T) {
   178  					t.Parallel()
   179  					t.Fail()
   180  				})
   181  			})
   182  		},
   183  	}, {
   184  		desc:   "skipping without message, chatty",
   185  		ok:     true,
   186  		chatty: true,
   187  		output: `
   188  === RUN   skipping without message, chatty
   189  --- SKIP: skipping without message, chatty (N.NNs)`,
   190  		f: func(t *T) { t.SkipNow() },
   191  	}, {
   192  		desc:   "chatty with recursion",
   193  		ok:     true,
   194  		chatty: true,
   195  		output: `
   196  === RUN   chatty with recursion
   197  === RUN   chatty with recursion/#00
   198  === RUN   chatty with recursion/#00/#00
   199  --- PASS: chatty with recursion (N.NNs)
   200      --- PASS: chatty with recursion/#00 (N.NNs)
   201          --- PASS: chatty with recursion/#00/#00 (N.NNs)`,
   202  		f: func(t *T) {
   203  			t.Run("", func(t *T) {
   204  				t.Run("", func(t *T) {})
   205  			})
   206  		},
   207  	}, {
   208  		desc:   "chatty with recursion and json",
   209  		ok:     false,
   210  		chatty: true,
   211  		json:   true,
   212  		output: `
   213  ^V=== RUN   chatty with recursion and json
   214  ^V=== RUN   chatty with recursion and json/#00
   215  ^V=== RUN   chatty with recursion and json/#00/#00
   216  ^V--- PASS: chatty with recursion and json/#00/#00 (N.NNs)
   217  ^V=== NAME  chatty with recursion and json/#00
   218  ^V=== RUN   chatty with recursion and json/#00/#01
   219      sub_test.go:NNN: skip
   220  ^V--- SKIP: chatty with recursion and json/#00/#01 (N.NNs)
   221  ^V=== NAME  chatty with recursion and json/#00
   222  ^V=== RUN   chatty with recursion and json/#00/#02
   223      sub_test.go:NNN: fail
   224  ^V--- FAIL: chatty with recursion and json/#00/#02 (N.NNs)
   225  ^V=== NAME  chatty with recursion and json/#00
   226  ^V--- FAIL: chatty with recursion and json/#00 (N.NNs)
   227  ^V=== NAME  chatty with recursion and json
   228  ^V--- FAIL: chatty with recursion and json (N.NNs)
   229  ^V=== NAME  `,
   230  		f: func(t *T) {
   231  			t.Run("", func(t *T) {
   232  				t.Run("", func(t *T) {})
   233  				t.Run("", func(t *T) { t.Skip("skip") })
   234  				t.Run("", func(t *T) { t.Fatal("fail") })
   235  			})
   236  		},
   237  	}, {
   238  		desc: "skipping without message, not chatty",
   239  		ok:   true,
   240  		f:    func(t *T) { t.SkipNow() },
   241  	}, {
   242  		desc: "skipping after error",
   243  		output: `
   244  --- FAIL: skipping after error (N.NNs)
   245      sub_test.go:NNN: an error
   246      sub_test.go:NNN: skipped`,
   247  		f: func(t *T) {
   248  			t.Error("an error")
   249  			t.Skip("skipped")
   250  		},
   251  	}, {
   252  		desc:   "use Run to locally synchronize parallelism",
   253  		ok:     true,
   254  		maxPar: 1,
   255  		f: func(t *T) {
   256  			var count uint32
   257  			t.Run("waitGroup", func(t *T) {
   258  				for i := 0; i < 4; i++ {
   259  					t.Run("par", func(t *T) {
   260  						t.Parallel()
   261  						atomic.AddUint32(&count, 1)
   262  					})
   263  				}
   264  			})
   265  			if count != 4 {
   266  				t.Errorf("count was %d; want 4", count)
   267  			}
   268  		},
   269  	}, {
   270  		desc: "alternate sequential and parallel",
   271  		// Sequential tests should partake in the counting of running threads.
   272  		// Otherwise, if one runs parallel subtests in sequential tests that are
   273  		// itself subtests of parallel tests, the counts can get askew.
   274  		ok:     true,
   275  		maxPar: 1,
   276  		f: func(t *T) {
   277  			t.Run("a", func(t *T) {
   278  				t.Parallel()
   279  				t.Run("b", func(t *T) {
   280  					// Sequential: ensure running count is decremented.
   281  					t.Run("c", func(t *T) {
   282  						t.Parallel()
   283  					})
   284  
   285  				})
   286  			})
   287  		},
   288  	}, {
   289  		desc: "alternate sequential and parallel 2",
   290  		// Sequential tests should partake in the counting of running threads.
   291  		// Otherwise, if one runs parallel subtests in sequential tests that are
   292  		// itself subtests of parallel tests, the counts can get askew.
   293  		ok:     true,
   294  		maxPar: 2,
   295  		f: func(t *T) {
   296  			for i := 0; i < 2; i++ {
   297  				t.Run("a", func(t *T) {
   298  					t.Parallel()
   299  					time.Sleep(time.Nanosecond)
   300  					for i := 0; i < 2; i++ {
   301  						t.Run("b", func(t *T) {
   302  							time.Sleep(time.Nanosecond)
   303  							for i := 0; i < 2; i++ {
   304  								t.Run("c", func(t *T) {
   305  									t.Parallel()
   306  									time.Sleep(time.Nanosecond)
   307  								})
   308  							}
   309  
   310  						})
   311  					}
   312  				})
   313  			}
   314  		},
   315  	}, {
   316  		desc:   "stress test",
   317  		ok:     true,
   318  		maxPar: 4,
   319  		f: func(t *T) {
   320  			t.Parallel()
   321  			for i := 0; i < 12; i++ {
   322  				t.Run("a", func(t *T) {
   323  					t.Parallel()
   324  					time.Sleep(time.Nanosecond)
   325  					for i := 0; i < 12; i++ {
   326  						t.Run("b", func(t *T) {
   327  							time.Sleep(time.Nanosecond)
   328  							for i := 0; i < 12; i++ {
   329  								t.Run("c", func(t *T) {
   330  									t.Parallel()
   331  									time.Sleep(time.Nanosecond)
   332  									t.Run("d1", func(t *T) {})
   333  									t.Run("d2", func(t *T) {})
   334  									t.Run("d3", func(t *T) {})
   335  									t.Run("d4", func(t *T) {})
   336  								})
   337  							}
   338  						})
   339  					}
   340  				})
   341  			}
   342  		},
   343  	}, {
   344  		desc:   "skip output",
   345  		ok:     true,
   346  		maxPar: 4,
   347  		f: func(t *T) {
   348  			t.Skip()
   349  		},
   350  	}, {
   351  		desc: "subtest calls error on parent",
   352  		ok:   false,
   353  		output: `
   354  --- FAIL: subtest calls error on parent (N.NNs)
   355      sub_test.go:NNN: first this
   356      sub_test.go:NNN: and now this!
   357      sub_test.go:NNN: oh, and this too`,
   358  		maxPar: 1,
   359  		f: func(t *T) {
   360  			t.Errorf("first this")
   361  			outer := t
   362  			t.Run("", func(t *T) {
   363  				outer.Errorf("and now this!")
   364  			})
   365  			t.Errorf("oh, and this too")
   366  		},
   367  	}, {
   368  		desc: "subtest calls fatal on parent",
   369  		ok:   false,
   370  		output: `
   371  --- FAIL: subtest calls fatal on parent (N.NNs)
   372      sub_test.go:NNN: first this
   373      sub_test.go:NNN: and now this!
   374      --- FAIL: subtest calls fatal on parent/#00 (N.NNs)
   375          testing.go:NNN: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test`,
   376  		maxPar: 1,
   377  		f: func(t *T) {
   378  			outer := t
   379  			t.Errorf("first this")
   380  			t.Run("", func(t *T) {
   381  				outer.Fatalf("and now this!")
   382  			})
   383  			t.Errorf("Should not reach here.")
   384  		},
   385  	}, {
   386  		desc: "subtest calls error on ancestor",
   387  		ok:   false,
   388  		output: `
   389  --- FAIL: subtest calls error on ancestor (N.NNs)
   390      sub_test.go:NNN: Report to ancestor
   391      --- FAIL: subtest calls error on ancestor/#00 (N.NNs)
   392          sub_test.go:NNN: Still do this
   393      sub_test.go:NNN: Also do this`,
   394  		maxPar: 1,
   395  		f: func(t *T) {
   396  			outer := t
   397  			t.Run("", func(t *T) {
   398  				t.Run("", func(t *T) {
   399  					outer.Errorf("Report to ancestor")
   400  				})
   401  				t.Errorf("Still do this")
   402  			})
   403  			t.Errorf("Also do this")
   404  		},
   405  	}, {
   406  		desc: "subtest calls fatal on ancestor",
   407  		ok:   false,
   408  		output: `
   409  --- FAIL: subtest calls fatal on ancestor (N.NNs)
   410      sub_test.go:NNN: Nope`,
   411  		maxPar: 1,
   412  		f: func(t *T) {
   413  			outer := t
   414  			t.Run("", func(t *T) {
   415  				for i := 0; i < 4; i++ {
   416  					t.Run("", func(t *T) {
   417  						outer.Fatalf("Nope")
   418  					})
   419  					t.Errorf("Don't do this")
   420  				}
   421  				t.Errorf("And neither do this")
   422  			})
   423  			t.Errorf("Nor this")
   424  		},
   425  	}, {
   426  		desc:   "panic on goroutine fail after test exit",
   427  		ok:     false,
   428  		maxPar: 4,
   429  		f: func(t *T) {
   430  			ch := make(chan bool)
   431  			t.Run("", func(t *T) {
   432  				go func() {
   433  					<-ch
   434  					defer func() {
   435  						if r := recover(); r == nil {
   436  							realTest.Errorf("expected panic")
   437  						}
   438  						ch <- true
   439  					}()
   440  					t.Errorf("failed after success")
   441  				}()
   442  			})
   443  			ch <- true
   444  			<-ch
   445  		},
   446  	}, {
   447  		desc: "log in finished sub test logs to parent",
   448  		ok:   false,
   449  		output: `
   450  		--- FAIL: log in finished sub test logs to parent (N.NNs)
   451      sub_test.go:NNN: message2
   452      sub_test.go:NNN: message1
   453      sub_test.go:NNN: error`,
   454  		maxPar: 1,
   455  		f: func(t *T) {
   456  			ch := make(chan bool)
   457  			t.Run("sub", func(t2 *T) {
   458  				go func() {
   459  					<-ch
   460  					t2.Log("message1")
   461  					ch <- true
   462  				}()
   463  			})
   464  			t.Log("message2")
   465  			ch <- true
   466  			<-ch
   467  			t.Errorf("error")
   468  		},
   469  	}, {
   470  		// A chatty test should always log with fmt.Print, even if the
   471  		// parent test has completed.
   472  		desc:   "log in finished sub test with chatty",
   473  		ok:     false,
   474  		chatty: true,
   475  		output: `
   476  		--- FAIL: log in finished sub test with chatty (N.NNs)`,
   477  		maxPar: 1,
   478  		f: func(t *T) {
   479  			ch := make(chan bool)
   480  			t.Run("sub", func(t2 *T) {
   481  				go func() {
   482  					<-ch
   483  					t2.Log("message1")
   484  					ch <- true
   485  				}()
   486  			})
   487  			t.Log("message2")
   488  			ch <- true
   489  			<-ch
   490  			t.Errorf("error")
   491  		},
   492  	}, {
   493  		// If a subtest panics we should run cleanups.
   494  		desc:   "cleanup when subtest panics",
   495  		ok:     false,
   496  		chatty: false,
   497  		output: `
   498  --- FAIL: cleanup when subtest panics (N.NNs)
   499      --- FAIL: cleanup when subtest panics/sub (N.NNs)
   500      sub_test.go:NNN: running cleanup`,
   501  		f: func(t *T) {
   502  			t.Cleanup(func() { t.Log("running cleanup") })
   503  			t.Run("sub", func(t2 *T) {
   504  				t2.FailNow()
   505  			})
   506  		},
   507  	}}
   508  	for _, tc := range testCases {
   509  		t.Run(tc.desc, func(t *T) {
   510  			ctx := newTestContext(tc.maxPar, allMatcher())
   511  			buf := &strings.Builder{}
   512  			root := &T{
   513  				common: common{
   514  					signal:  make(chan bool),
   515  					barrier: make(chan bool),
   516  					name:    "",
   517  					w:       buf,
   518  				},
   519  				context: ctx,
   520  			}
   521  			if tc.chatty {
   522  				root.chatty = newChattyPrinter(root.w)
   523  				root.chatty.json = tc.json
   524  			}
   525  			ok := root.Run(tc.desc, tc.f)
   526  			ctx.release()
   527  
   528  			if ok != tc.ok {
   529  				t.Errorf("%s:ok: got %v; want %v", tc.desc, ok, tc.ok)
   530  			}
   531  			if ok != !root.Failed() {
   532  				t.Errorf("%s:root failed: got %v; want %v", tc.desc, !ok, root.Failed())
   533  			}
   534  			if ctx.running != 0 || ctx.numWaiting != 0 {
   535  				t.Errorf("%s:running and waiting non-zero: got %d and %d", tc.desc, ctx.running, ctx.numWaiting)
   536  			}
   537  			got := strings.TrimSpace(buf.String())
   538  			want := strings.TrimSpace(tc.output)
   539  			re := makeRegexp(want)
   540  			if ok, err := regexp.MatchString(re, got); !ok || err != nil {
   541  				t.Errorf("%s:output:\ngot:\n%s\nwant:\n%s", tc.desc, got, want)
   542  			}
   543  		})
   544  	}
   545  }
   546  
   547  func TestBRun(t *T) {
   548  	work := func(b *B) {
   549  		for i := 0; i < b.N; i++ {
   550  			time.Sleep(time.Nanosecond)
   551  		}
   552  	}
   553  	testCases := []struct {
   554  		desc   string
   555  		failed bool
   556  		chatty bool
   557  		output string
   558  		f      func(*B)
   559  	}{{
   560  		desc: "simulate sequential run of subbenchmarks.",
   561  		f: func(b *B) {
   562  			b.Run("", func(b *B) { work(b) })
   563  			time1 := b.result.NsPerOp()
   564  			b.Run("", func(b *B) { work(b) })
   565  			time2 := b.result.NsPerOp()
   566  			if time1 >= time2 {
   567  				t.Errorf("no time spent in benchmark t1 >= t2 (%d >= %d)", time1, time2)
   568  			}
   569  		},
   570  	}, {
   571  		desc: "bytes set by all benchmarks",
   572  		f: func(b *B) {
   573  			b.Run("", func(b *B) { b.SetBytes(10); work(b) })
   574  			b.Run("", func(b *B) { b.SetBytes(10); work(b) })
   575  			if b.result.Bytes != 20 {
   576  				t.Errorf("bytes: got: %d; want 20", b.result.Bytes)
   577  			}
   578  		},
   579  	}, {
   580  		desc: "bytes set by some benchmarks",
   581  		// In this case the bytes result is meaningless, so it must be 0.
   582  		f: func(b *B) {
   583  			b.Run("", func(b *B) { b.SetBytes(10); work(b) })
   584  			b.Run("", func(b *B) { work(b) })
   585  			b.Run("", func(b *B) { b.SetBytes(10); work(b) })
   586  			if b.result.Bytes != 0 {
   587  				t.Errorf("bytes: got: %d; want 0", b.result.Bytes)
   588  			}
   589  		},
   590  	}, {
   591  		desc:   "failure carried over to root",
   592  		failed: true,
   593  		output: "--- FAIL: root",
   594  		f:      func(b *B) { b.Fail() },
   595  	}, {
   596  		desc:   "skipping without message, chatty",
   597  		chatty: true,
   598  		output: "--- SKIP: root",
   599  		f:      func(b *B) { b.SkipNow() },
   600  	}, {
   601  		desc:   "chatty with recursion",
   602  		chatty: true,
   603  		f: func(b *B) {
   604  			b.Run("", func(b *B) {
   605  				b.Run("", func(b *B) {})
   606  			})
   607  		},
   608  	}, {
   609  		desc: "skipping without message, not chatty",
   610  		f:    func(b *B) { b.SkipNow() },
   611  	}, {
   612  		desc:   "skipping after error",
   613  		failed: true,
   614  		output: `
   615  --- FAIL: root
   616      sub_test.go:NNN: an error
   617      sub_test.go:NNN: skipped`,
   618  		f: func(b *B) {
   619  			b.Error("an error")
   620  			b.Skip("skipped")
   621  		},
   622  	}, {
   623  		desc: "memory allocation",
   624  		f: func(b *B) {
   625  			const bufSize = 256
   626  			alloc := func(b *B) {
   627  				var buf [bufSize]byte
   628  				for i := 0; i < b.N; i++ {
   629  					_ = append([]byte(nil), buf[:]...)
   630  				}
   631  			}
   632  			b.Run("", func(b *B) {
   633  				alloc(b)
   634  				b.ReportAllocs()
   635  			})
   636  			b.Run("", func(b *B) {
   637  				alloc(b)
   638  				b.ReportAllocs()
   639  			})
   640  			// runtime.MemStats sometimes reports more allocations than the
   641  			// benchmark is responsible for. Luckily the point of this test is
   642  			// to ensure that the results are not underreported, so we can
   643  			// simply verify the lower bound.
   644  			if got := b.result.MemAllocs; got < 2 {
   645  				t.Errorf("MemAllocs was %v; want 2", got)
   646  			}
   647  			if got := b.result.MemBytes; got < 2*bufSize {
   648  				t.Errorf("MemBytes was %v; want %v", got, 2*bufSize)
   649  			}
   650  		},
   651  	}, {
   652  		desc: "cleanup is called",
   653  		f: func(b *B) {
   654  			var calls, cleanups, innerCalls, innerCleanups int
   655  			b.Run("", func(b *B) {
   656  				calls++
   657  				b.Cleanup(func() {
   658  					cleanups++
   659  				})
   660  				b.Run("", func(b *B) {
   661  					b.Cleanup(func() {
   662  						innerCleanups++
   663  					})
   664  					innerCalls++
   665  				})
   666  				work(b)
   667  			})
   668  			if calls == 0 || calls != cleanups {
   669  				t.Errorf("mismatched cleanups; got %d want %d", cleanups, calls)
   670  			}
   671  			if innerCalls == 0 || innerCalls != innerCleanups {
   672  				t.Errorf("mismatched cleanups; got %d want %d", cleanups, calls)
   673  			}
   674  		},
   675  	}, {
   676  		desc:   "cleanup is called on failure",
   677  		failed: true,
   678  		f: func(b *B) {
   679  			var calls, cleanups int
   680  			b.Run("", func(b *B) {
   681  				calls++
   682  				b.Cleanup(func() {
   683  					cleanups++
   684  				})
   685  				b.Fatalf("failure")
   686  			})
   687  			if calls == 0 || calls != cleanups {
   688  				t.Errorf("mismatched cleanups; got %d want %d", cleanups, calls)
   689  			}
   690  		},
   691  	}}
   692  	hideStdoutForTesting = true
   693  	defer func() {
   694  		hideStdoutForTesting = false
   695  	}()
   696  	for _, tc := range testCases {
   697  		t.Run(tc.desc, func(t *T) {
   698  			var ok bool
   699  			buf := &strings.Builder{}
   700  			// This is almost like the Benchmark function, except that we override
   701  			// the benchtime and catch the failure result of the subbenchmark.
   702  			root := &B{
   703  				common: common{
   704  					signal: make(chan bool),
   705  					name:   "root",
   706  					w:      buf,
   707  				},
   708  				benchFunc: func(b *B) { ok = b.Run("test", tc.f) }, // Use Run to catch failure.
   709  				benchTime: durationOrCountFlag{d: 1 * time.Microsecond},
   710  			}
   711  			if tc.chatty {
   712  				root.chatty = newChattyPrinter(root.w)
   713  			}
   714  			root.runN(1)
   715  			if ok != !tc.failed {
   716  				t.Errorf("%s:ok: got %v; want %v", tc.desc, ok, !tc.failed)
   717  			}
   718  			if !ok != root.Failed() {
   719  				t.Errorf("%s:root failed: got %v; want %v", tc.desc, !ok, root.Failed())
   720  			}
   721  			// All tests are run as subtests
   722  			if root.result.N != 1 {
   723  				t.Errorf("%s: N for parent benchmark was %d; want 1", tc.desc, root.result.N)
   724  			}
   725  			got := strings.TrimSpace(buf.String())
   726  			want := strings.TrimSpace(tc.output)
   727  			re := makeRegexp(want)
   728  			if ok, err := regexp.MatchString(re, got); !ok || err != nil {
   729  				t.Errorf("%s:output:\ngot:\n%s\nwant:\n%s", tc.desc, got, want)
   730  			}
   731  		})
   732  	}
   733  }
   734  
   735  func makeRegexp(s string) string {
   736  	s = regexp.QuoteMeta(s)
   737  	s = strings.ReplaceAll(s, "^V", "\x16")
   738  	s = strings.ReplaceAll(s, ":NNN:", `:\d\d\d\d?:`)
   739  	s = strings.ReplaceAll(s, "N\\.NNs", `\d*\.\d*s`)
   740  	return s
   741  }
   742  
   743  func TestBenchmarkOutput(t *T) {
   744  	// Ensure Benchmark initialized common.w by invoking it with an error and
   745  	// normal case.
   746  	Benchmark(func(b *B) { b.Error("do not print this output") })
   747  	Benchmark(func(b *B) {})
   748  }
   749  
   750  func TestBenchmarkStartsFrom1(t *T) {
   751  	var first = true
   752  	Benchmark(func(b *B) {
   753  		if first && b.N != 1 {
   754  			panic(fmt.Sprintf("Benchmark() first N=%v; want 1", b.N))
   755  		}
   756  		first = false
   757  	})
   758  }
   759  
   760  func TestBenchmarkReadMemStatsBeforeFirstRun(t *T) {
   761  	var first = true
   762  	Benchmark(func(b *B) {
   763  		if first && (b.startAllocs == 0 || b.startBytes == 0) {
   764  			panic("ReadMemStats not called before first run")
   765  		}
   766  		first = false
   767  	})
   768  }
   769  
   770  type funcWriter struct {
   771  	write func([]byte) (int, error)
   772  }
   773  
   774  func (fw *funcWriter) Write(b []byte) (int, error) {
   775  	return fw.write(b)
   776  }
   777  
   778  func TestRacyOutput(t *T) {
   779  	var runs int32  // The number of running Writes
   780  	var races int32 // Incremented for each race detected
   781  	raceDetector := func(b []byte) (int, error) {
   782  		// Check if some other goroutine is concurrently calling Write.
   783  		if atomic.LoadInt32(&runs) > 0 {
   784  			atomic.AddInt32(&races, 1) // Race detected!
   785  		}
   786  		atomic.AddInt32(&runs, 1)
   787  		defer atomic.AddInt32(&runs, -1)
   788  		runtime.Gosched() // Increase probability of a race
   789  		return len(b), nil
   790  	}
   791  
   792  	root := &T{
   793  		common:  common{w: &funcWriter{raceDetector}},
   794  		context: newTestContext(1, allMatcher()),
   795  	}
   796  	root.chatty = newChattyPrinter(root.w)
   797  	root.Run("", func(t *T) {
   798  		var wg sync.WaitGroup
   799  		for i := 0; i < 100; i++ {
   800  			wg.Add(1)
   801  			go func(i int) {
   802  				defer wg.Done()
   803  				t.Run(fmt.Sprint(i), func(t *T) {
   804  					t.Logf("testing run %d", i)
   805  				})
   806  			}(i)
   807  		}
   808  		wg.Wait()
   809  	})
   810  
   811  	if races > 0 {
   812  		t.Errorf("detected %d racy Writes", races)
   813  	}
   814  }
   815  
   816  // The late log message did not include the test name.  Issue 29388.
   817  func TestLogAfterComplete(t *T) {
   818  	ctx := newTestContext(1, allMatcher())
   819  	var buf bytes.Buffer
   820  	t1 := &T{
   821  		common: common{
   822  			// Use a buffered channel so that tRunner can write
   823  			// to it although nothing is reading from it.
   824  			signal: make(chan bool, 1),
   825  			w:      &buf,
   826  		},
   827  		context: ctx,
   828  	}
   829  
   830  	c1 := make(chan bool)
   831  	c2 := make(chan string)
   832  	tRunner(t1, func(t *T) {
   833  		t.Run("TestLateLog", func(t *T) {
   834  			go func() {
   835  				defer close(c2)
   836  				defer func() {
   837  					p := recover()
   838  					if p == nil {
   839  						c2 <- "subtest did not panic"
   840  						return
   841  					}
   842  					s, ok := p.(string)
   843  					if !ok {
   844  						c2 <- fmt.Sprintf("subtest panic with unexpected value %v", p)
   845  						return
   846  					}
   847  					const want = "Log in goroutine after TestLateLog has completed: log after test"
   848  					if !strings.Contains(s, want) {
   849  						c2 <- fmt.Sprintf("subtest panic %q does not contain %q", s, want)
   850  					}
   851  				}()
   852  
   853  				<-c1
   854  				t.Log("log after test")
   855  			}()
   856  		})
   857  	})
   858  	close(c1)
   859  
   860  	if s := <-c2; s != "" {
   861  		t.Error(s)
   862  	}
   863  }
   864  
   865  func TestBenchmark(t *T) {
   866  	if Short() {
   867  		t.Skip("skipping in short mode")
   868  	}
   869  	res := Benchmark(func(b *B) {
   870  		for i := 0; i < 5; i++ {
   871  			b.Run("", func(b *B) {
   872  				for i := 0; i < b.N; i++ {
   873  					time.Sleep(time.Millisecond)
   874  				}
   875  			})
   876  		}
   877  	})
   878  	if res.NsPerOp() < 4000000 {
   879  		t.Errorf("want >5ms; got %v", time.Duration(res.NsPerOp()))
   880  	}
   881  }
   882  
   883  func TestCleanup(t *T) {
   884  	var cleanups []int
   885  	t.Run("test", func(t *T) {
   886  		t.Cleanup(func() { cleanups = append(cleanups, 1) })
   887  		t.Cleanup(func() { cleanups = append(cleanups, 2) })
   888  	})
   889  	if got, want := cleanups, []int{2, 1}; !reflect.DeepEqual(got, want) {
   890  		t.Errorf("unexpected cleanup record; got %v want %v", got, want)
   891  	}
   892  }
   893  
   894  func TestConcurrentCleanup(t *T) {
   895  	cleanups := 0
   896  	t.Run("test", func(t *T) {
   897  		var wg sync.WaitGroup
   898  		wg.Add(2)
   899  		for i := 0; i < 2; i++ {
   900  			i := i
   901  			go func() {
   902  				t.Cleanup(func() {
   903  					// Although the calls to Cleanup are concurrent, the functions passed
   904  					// to Cleanup should be called sequentially, in some nondeterministic
   905  					// order based on when the Cleanup calls happened to be scheduled.
   906  					// So these assignments to the cleanups variable should not race.
   907  					cleanups |= 1 << i
   908  				})
   909  				wg.Done()
   910  			}()
   911  		}
   912  		wg.Wait()
   913  	})
   914  	if cleanups != 1|2 {
   915  		t.Errorf("unexpected cleanup; got %d want 3", cleanups)
   916  	}
   917  }
   918  
   919  func TestCleanupCalledEvenAfterGoexit(t *T) {
   920  	cleanups := 0
   921  	t.Run("test", func(t *T) {
   922  		t.Cleanup(func() {
   923  			cleanups++
   924  		})
   925  		t.Cleanup(func() {
   926  			runtime.Goexit()
   927  		})
   928  	})
   929  	if cleanups != 1 {
   930  		t.Errorf("unexpected cleanup count; got %d want 1", cleanups)
   931  	}
   932  }
   933  
   934  func TestRunCleanup(t *T) {
   935  	outerCleanup := 0
   936  	innerCleanup := 0
   937  	t.Run("test", func(t *T) {
   938  		t.Cleanup(func() { outerCleanup++ })
   939  		t.Run("x", func(t *T) {
   940  			t.Cleanup(func() { innerCleanup++ })
   941  		})
   942  	})
   943  	if innerCleanup != 1 {
   944  		t.Errorf("unexpected inner cleanup count; got %d want 1", innerCleanup)
   945  	}
   946  	if outerCleanup != 1 {
   947  		t.Errorf("unexpected outer cleanup count; got %d want 0", outerCleanup)
   948  	}
   949  }
   950  
   951  func TestCleanupParallelSubtests(t *T) {
   952  	ranCleanup := 0
   953  	t.Run("test", func(t *T) {
   954  		t.Cleanup(func() { ranCleanup++ })
   955  		t.Run("x", func(t *T) {
   956  			t.Parallel()
   957  			if ranCleanup > 0 {
   958  				t.Error("outer cleanup ran before parallel subtest")
   959  			}
   960  		})
   961  	})
   962  	if ranCleanup != 1 {
   963  		t.Errorf("unexpected cleanup count; got %d want 1", ranCleanup)
   964  	}
   965  }
   966  
   967  func TestNestedCleanup(t *T) {
   968  	ranCleanup := 0
   969  	t.Run("test", func(t *T) {
   970  		t.Cleanup(func() {
   971  			if ranCleanup != 2 {
   972  				t.Errorf("unexpected cleanup count in first cleanup: got %d want 2", ranCleanup)
   973  			}
   974  			ranCleanup++
   975  		})
   976  		t.Cleanup(func() {
   977  			if ranCleanup != 0 {
   978  				t.Errorf("unexpected cleanup count in second cleanup: got %d want 0", ranCleanup)
   979  			}
   980  			ranCleanup++
   981  			t.Cleanup(func() {
   982  				if ranCleanup != 1 {
   983  					t.Errorf("unexpected cleanup count in nested cleanup: got %d want 1", ranCleanup)
   984  				}
   985  				ranCleanup++
   986  			})
   987  		})
   988  	})
   989  	if ranCleanup != 3 {
   990  		t.Errorf("unexpected cleanup count: got %d want 3", ranCleanup)
   991  	}
   992  }
   993  

View as plain text