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  	"regexp"
    11  	"runtime"
    12  	"slices"
    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 TestTestState(t *T) {
    25  	const (
    26  		add1 = 0
    27  		done = 1
    28  	)
    29  	type call struct {
    30  		typ int // run or done
    31  		// result from applying the call
    32  		running int
    33  		waiting int
    34  		started bool
    35  	}
    36  	testCases := []struct {
    37  		max int
    38  		run []call
    39  	}{{
    40  		max: 1,
    41  		run: []call{
    42  			{typ: add1, running: 1, waiting: 0, started: true},
    43  			{typ: done, running: 0, waiting: 0, started: false},
    44  		},
    45  	}, {
    46  		max: 1,
    47  		run: []call{
    48  			{typ: add1, running: 1, waiting: 0, started: true},
    49  			{typ: add1, running: 1, waiting: 1, started: false},
    50  			{typ: done, running: 1, waiting: 0, started: true},
    51  			{typ: done, running: 0, waiting: 0, started: false},
    52  			{typ: add1, running: 1, waiting: 0, started: true},
    53  		},
    54  	}, {
    55  		max: 3,
    56  		run: []call{
    57  			{typ: add1, running: 1, waiting: 0, started: true},
    58  			{typ: add1, running: 2, waiting: 0, started: true},
    59  			{typ: add1, running: 3, waiting: 0, started: true},
    60  			{typ: add1, running: 3, waiting: 1, started: false},
    61  			{typ: add1, running: 3, waiting: 2, started: false},
    62  			{typ: add1, running: 3, waiting: 3, started: false},
    63  			{typ: done, running: 3, waiting: 2, started: true},
    64  			{typ: add1, running: 3, waiting: 3, started: false},
    65  			{typ: done, running: 3, waiting: 2, started: true},
    66  			{typ: done, running: 3, waiting: 1, started: true},
    67  			{typ: done, running: 3, waiting: 0, started: true},
    68  			{typ: done, running: 2, waiting: 0, started: false},
    69  			{typ: done, running: 1, waiting: 0, started: false},
    70  			{typ: done, running: 0, waiting: 0, started: false},
    71  		},
    72  	}}
    73  	for i, tc := range testCases {
    74  		tstate := &testState{
    75  			startParallel: make(chan bool),
    76  			maxParallel:   tc.max,
    77  		}
    78  		for j, call := range tc.run {
    79  			doCall := func(f func()) chan bool {
    80  				done := make(chan bool)
    81  				go func() {
    82  					f()
    83  					done <- true
    84  				}()
    85  				return done
    86  			}
    87  			started := false
    88  			switch call.typ {
    89  			case add1:
    90  				signal := doCall(tstate.waitParallel)
    91  				select {
    92  				case <-signal:
    93  					started = true
    94  				case tstate.startParallel <- true:
    95  					<-signal
    96  				}
    97  			case done:
    98  				signal := doCall(tstate.release)
    99  				select {
   100  				case <-signal:
   101  				case <-tstate.startParallel:
   102  					started = true
   103  					<-signal
   104  				}
   105  			}
   106  			if started != call.started {
   107  				t.Errorf("%d:%d:started: got %v; want %v", i, j, started, call.started)
   108  			}
   109  			if tstate.running != call.running {
   110  				t.Errorf("%d:%d:running: got %v; want %v", i, j, tstate.running, call.running)
   111  			}
   112  			if tstate.numWaiting != call.waiting {
   113  				t.Errorf("%d:%d:waiting: got %v; want %v", i, j, tstate.numWaiting, call.waiting)
   114  			}
   115  		}
   116  	}
   117  }
   118  
   119  func TestTRun(t *T) {
   120  	realTest := t
   121  	testCases := []struct {
   122  		desc   string
   123  		ok     bool
   124  		maxPar int
   125  		chatty bool
   126  		json   bool
   127  		output string
   128  		f      func(*T)
   129  	}{{
   130  		desc:   "failnow skips future sequential and parallel tests at same level",
   131  		ok:     false,
   132  		maxPar: 1,
   133  		output: `
   134  --- FAIL: failnow skips future sequential and parallel tests at same level (N.NNs)
   135      --- FAIL: failnow skips future sequential and parallel tests at same level/#00 (N.NNs)
   136      `,
   137  		f: func(t *T) {
   138  			ranSeq := false
   139  			ranPar := false
   140  			t.Run("", func(t *T) {
   141  				t.Run("par", func(t *T) {
   142  					t.Parallel()
   143  					ranPar = true
   144  				})
   145  				t.Run("seq", func(t *T) {
   146  					ranSeq = true
   147  				})
   148  				t.FailNow()
   149  				t.Run("seq", func(t *T) {
   150  					realTest.Error("test must be skipped")
   151  				})
   152  				t.Run("par", func(t *T) {
   153  					t.Parallel()
   154  					realTest.Error("test must be skipped.")
   155  				})
   156  			})
   157  			if !ranPar {
   158  				realTest.Error("parallel test was not run")
   159  			}
   160  			if !ranSeq {
   161  				realTest.Error("sequential test was not run")
   162  			}
   163  		},
   164  	}, {
   165  		desc:   "failure in parallel test propagates upwards",
   166  		ok:     false,
   167  		maxPar: 1,
   168  		output: `
   169  --- FAIL: failure in parallel test propagates upwards (N.NNs)
   170      --- FAIL: failure in parallel test propagates upwards/#00 (N.NNs)
   171          --- FAIL: failure in parallel test propagates upwards/#00/par (N.NNs)
   172          `,
   173  		f: func(t *T) {
   174  			t.Run("", func(t *T) {
   175  				t.Parallel()
   176  				t.Run("par", func(t *T) {
   177  					t.Parallel()
   178  					t.Fail()
   179  				})
   180  			})
   181  		},
   182  	}, {
   183  		desc:   "skipping without message, chatty",
   184  		ok:     true,
   185  		chatty: true,
   186  		output: `
   187  === RUN   skipping without message, chatty
   188  --- SKIP: skipping without message, chatty (N.NNs)`,
   189  		f: func(t *T) { t.SkipNow() },
   190  	}, {
   191  		desc:   "chatty with recursion",
   192  		ok:     true,
   193  		chatty: true,
   194  		output: `
   195  === RUN   chatty with recursion
   196  === RUN   chatty with recursion/#00
   197  === RUN   chatty with recursion/#00/#00
   198  --- PASS: chatty with recursion (N.NNs)
   199      --- PASS: chatty with recursion/#00 (N.NNs)
   200          --- PASS: chatty with recursion/#00/#00 (N.NNs)`,
   201  		f: func(t *T) {
   202  			t.Run("", func(t *T) {
   203  				t.Run("", func(t *T) {})
   204  			})
   205  		},
   206  	}, {
   207  		desc:   "chatty with recursion and json",
   208  		ok:     false,
   209  		chatty: true,
   210  		json:   true,
   211  		output: `
   212  ^V=== RUN   chatty with recursion and json
   213  ^V=== RUN   chatty with recursion and json/#00
   214  ^V=== RUN   chatty with recursion and json/#00/#00
   215  ^V--- PASS: chatty with recursion and json/#00/#00 (N.NNs)
   216  ^V=== NAME  chatty with recursion and json/#00
   217  ^V=== RUN   chatty with recursion and json/#00/#01
   218      sub_test.go:NNN: skip
   219  ^V--- SKIP: chatty with recursion and json/#00/#01 (N.NNs)
   220  ^V=== NAME  chatty with recursion and json/#00
   221  ^V=== RUN   chatty with recursion and json/#00/#02
   222  ^O    sub_test.go:NNN: fail^N
   223  ^V--- FAIL: chatty with recursion and json/#00/#02 (N.NNs)
   224  ^V=== NAME  chatty with recursion and json/#00
   225  ^V=== RUN   chatty with recursion and json/#00/#03
   226  ^O    sub_test.go:NNN: ^[^O^[^N^[^[^N
   227  ^V--- FAIL: chatty with recursion and json/#00/#03 (N.NNs)
   228  ^V=== NAME  chatty with recursion and json/#00
   229  ^V--- FAIL: chatty with recursion and json/#00 (N.NNs)
   230  ^V=== NAME  chatty with recursion and json
   231  ^V--- FAIL: chatty with recursion and json (N.NNs)
   232  ^V=== NAME  `,
   233  		f: func(t *T) {
   234  			t.Run("", func(t *T) {
   235  				t.Run("", func(t *T) {})
   236  				t.Run("", func(t *T) { t.Skip("skip") })
   237  				t.Run("", func(t *T) { t.Fatal("fail") })
   238  				t.Run("", func(t *T) { t.Error(string(markErrBegin) + string(markErrEnd) + string(markEscape)) })
   239  			})
   240  		},
   241  	}, {
   242  		desc: "skipping without message, not chatty",
   243  		ok:   true,
   244  		f:    func(t *T) { t.SkipNow() },
   245  	}, {
   246  		desc: "skipping after error",
   247  		output: `
   248  --- FAIL: skipping after error (N.NNs)
   249      sub_test.go:NNN: an error
   250      sub_test.go:NNN: skipped`,
   251  		f: func(t *T) {
   252  			t.Error("an error")
   253  			t.Skip("skipped")
   254  		},
   255  	}, {
   256  		desc:   "use Run to locally synchronize parallelism",
   257  		ok:     true,
   258  		maxPar: 1,
   259  		f: func(t *T) {
   260  			var count uint32
   261  			t.Run("waitGroup", func(t *T) {
   262  				for i := 0; i < 4; i++ {
   263  					t.Run("par", func(t *T) {
   264  						t.Parallel()
   265  						atomic.AddUint32(&count, 1)
   266  					})
   267  				}
   268  			})
   269  			if count != 4 {
   270  				t.Errorf("count was %d; want 4", count)
   271  			}
   272  		},
   273  	}, {
   274  		desc: "alternate sequential and parallel",
   275  		// Sequential tests should partake in the counting of running threads.
   276  		// Otherwise, if one runs parallel subtests in sequential tests that are
   277  		// itself subtests of parallel tests, the counts can get askew.
   278  		ok:     true,
   279  		maxPar: 1,
   280  		f: func(t *T) {
   281  			t.Run("a", func(t *T) {
   282  				t.Parallel()
   283  				t.Run("b", func(t *T) {
   284  					// Sequential: ensure running count is decremented.
   285  					t.Run("c", func(t *T) {
   286  						t.Parallel()
   287  					})
   288  				})
   289  			})
   290  		},
   291  	}, {
   292  		desc: "alternate sequential and parallel 2",
   293  		// Sequential tests should partake in the counting of running threads.
   294  		// Otherwise, if one runs parallel subtests in sequential tests that are
   295  		// itself subtests of parallel tests, the counts can get askew.
   296  		ok:     true,
   297  		maxPar: 2,
   298  		f: func(t *T) {
   299  			for i := 0; i < 2; i++ {
   300  				t.Run("a", func(t *T) {
   301  					t.Parallel()
   302  					time.Sleep(time.Nanosecond)
   303  					for i := 0; i < 2; i++ {
   304  						t.Run("b", func(t *T) {
   305  							time.Sleep(time.Nanosecond)
   306  							for i := 0; i < 2; i++ {
   307  								t.Run("c", func(t *T) {
   308  									t.Parallel()
   309  									time.Sleep(time.Nanosecond)
   310  								})
   311  							}
   312  						})
   313  					}
   314  				})
   315  			}
   316  		},
   317  	}, {
   318  		desc:   "stress test",
   319  		ok:     true,
   320  		maxPar: 4,
   321  		f: func(t *T) {
   322  			t.Parallel()
   323  			for i := 0; i < 12; i++ {
   324  				t.Run("a", func(t *T) {
   325  					t.Parallel()
   326  					time.Sleep(time.Nanosecond)
   327  					for i := 0; i < 12; i++ {
   328  						t.Run("b", func(t *T) {
   329  							time.Sleep(time.Nanosecond)
   330  							for i := 0; i < 12; i++ {
   331  								t.Run("c", func(t *T) {
   332  									t.Parallel()
   333  									time.Sleep(time.Nanosecond)
   334  									t.Run("d1", func(t *T) {})
   335  									t.Run("d2", func(t *T) {})
   336  									t.Run("d3", func(t *T) {})
   337  									t.Run("d4", func(t *T) {})
   338  								})
   339  							}
   340  						})
   341  					}
   342  				})
   343  			}
   344  		},
   345  	}, {
   346  		desc:   "skip output",
   347  		ok:     true,
   348  		maxPar: 4,
   349  		f: func(t *T) {
   350  			t.Skip()
   351  		},
   352  	}, {
   353  		desc: "subtest calls error on parent",
   354  		ok:   false,
   355  		output: `
   356  --- FAIL: subtest calls error on parent (N.NNs)
   357      sub_test.go:NNN: first this
   358      sub_test.go:NNN: and now this!
   359      sub_test.go:NNN: oh, and this too`,
   360  		maxPar: 1,
   361  		f: func(t *T) {
   362  			t.Errorf("first this")
   363  			outer := t
   364  			t.Run("", func(t *T) {
   365  				outer.Errorf("and now this!")
   366  			})
   367  			t.Errorf("oh, and this too")
   368  		},
   369  	}, {
   370  		desc: "subtest calls fatal on parent",
   371  		ok:   false,
   372  		output: `
   373  --- FAIL: subtest calls fatal on parent (N.NNs)
   374      sub_test.go:NNN: first this
   375      sub_test.go:NNN: and now this!
   376      --- FAIL: subtest calls fatal on parent/#00 (N.NNs)
   377          testing.go:NNN: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test`,
   378  		maxPar: 1,
   379  		f: func(t *T) {
   380  			outer := t
   381  			t.Errorf("first this")
   382  			t.Run("", func(t *T) {
   383  				outer.Fatalf("and now this!")
   384  			})
   385  			t.Errorf("Should not reach here.")
   386  		},
   387  	}, {
   388  		desc: "subtest calls error on ancestor",
   389  		ok:   false,
   390  		output: `
   391  --- FAIL: subtest calls error on ancestor (N.NNs)
   392      sub_test.go:NNN: Report to ancestor
   393      --- FAIL: subtest calls error on ancestor/#00 (N.NNs)
   394          sub_test.go:NNN: Still do this
   395      sub_test.go:NNN: Also do this`,
   396  		maxPar: 1,
   397  		f: func(t *T) {
   398  			outer := t
   399  			t.Run("", func(t *T) {
   400  				t.Run("", func(t *T) {
   401  					outer.Errorf("Report to ancestor")
   402  				})
   403  				t.Errorf("Still do this")
   404  			})
   405  			t.Errorf("Also do this")
   406  		},
   407  	}, {
   408  		desc: "subtest calls fatal on ancestor",
   409  		ok:   false,
   410  		output: `
   411  --- FAIL: subtest calls fatal on ancestor (N.NNs)
   412      sub_test.go:NNN: Nope`,
   413  		maxPar: 1,
   414  		f: func(t *T) {
   415  			outer := t
   416  			t.Run("", func(t *T) {
   417  				for i := 0; i < 4; i++ {
   418  					t.Run("", func(t *T) {
   419  						outer.Fatalf("Nope")
   420  					})
   421  					t.Errorf("Don't do this")
   422  				}
   423  				t.Errorf("And neither do this")
   424  			})
   425  			t.Errorf("Nor this")
   426  		},
   427  	}, {
   428  		desc:   "panic on goroutine fail after test exit",
   429  		ok:     false,
   430  		maxPar: 4,
   431  		f: func(t *T) {
   432  			ch := make(chan bool)
   433  			t.Run("", func(t *T) {
   434  				go func() {
   435  					<-ch
   436  					defer func() {
   437  						if r := recover(); r == nil {
   438  							realTest.Errorf("expected panic")
   439  						}
   440  						ch <- true
   441  					}()
   442  					t.Errorf("failed after success")
   443  				}()
   444  			})
   445  			ch <- true
   446  			<-ch
   447  		},
   448  	}, {
   449  		desc: "log in finished sub test logs to parent",
   450  		ok:   false,
   451  		output: `
   452  		--- FAIL: log in finished sub test logs to parent (N.NNs)
   453      sub_test.go:NNN: message2
   454      sub_test.go:NNN: message1
   455      sub_test.go:NNN: error`,
   456  		maxPar: 1,
   457  		f: func(t *T) {
   458  			ch := make(chan bool)
   459  			t.Run("sub", func(t2 *T) {
   460  				go func() {
   461  					<-ch
   462  					t2.Log("message1")
   463  					ch <- true
   464  				}()
   465  			})
   466  			t.Log("message2")
   467  			ch <- true
   468  			<-ch
   469  			t.Errorf("error")
   470  		},
   471  	}, {
   472  		// A chatty test should always log with fmt.Print, even if the
   473  		// parent test has completed.
   474  		desc:   "log in finished sub test with chatty",
   475  		ok:     false,
   476  		chatty: true,
   477  		output: `
   478  		--- FAIL: log in finished sub test with chatty (N.NNs)`,
   479  		maxPar: 1,
   480  		f: func(t *T) {
   481  			ch := make(chan bool)
   482  			t.Run("sub", func(t2 *T) {
   483  				go func() {
   484  					<-ch
   485  					t2.Log("message1")
   486  					ch <- true
   487  				}()
   488  			})
   489  			t.Log("message2")
   490  			ch <- true
   491  			<-ch
   492  			t.Errorf("error")
   493  		},
   494  	}, {
   495  		// If a subtest panics we should run cleanups.
   496  		desc:   "cleanup when subtest panics",
   497  		ok:     false,
   498  		chatty: false,
   499  		output: `
   500  --- FAIL: cleanup when subtest panics (N.NNs)
   501      --- FAIL: cleanup when subtest panics/sub (N.NNs)
   502      sub_test.go:NNN: running cleanup`,
   503  		f: func(t *T) {
   504  			t.Cleanup(func() { t.Log("running cleanup") })
   505  			t.Run("sub", func(t2 *T) {
   506  				t2.FailNow()
   507  			})
   508  		},
   509  	}, {
   510  		desc: "buffered output gets flushed at test end",
   511  		ok:   false,
   512  		output: `
   513  --- FAIL: buffered output gets flushed at test end (N.NNs)
   514      --- FAIL: buffered output gets flushed at test end/#00 (N.NNs)
   515          a
   516          b`,
   517  		f: func(t *T) {
   518  			t.Run("", func(t *T) {
   519  				o := t.Output()
   520  				o.Write([]byte("a\n"))
   521  				o.Write([]byte("b"))
   522  				t.Fail()
   523  			})
   524  		},
   525  	}, {
   526  		desc:   "output with chatty",
   527  		ok:     true,
   528  		chatty: true,
   529  		output: `
   530  === RUN   output with chatty
   531  === RUN   output with chatty/#00
   532      a
   533      b
   534  --- PASS: output with chatty (N.NNs)
   535      --- PASS: output with chatty/#00 (N.NNs)`,
   536  		f: func(t *T) {
   537  			t.Run("", func(t *T) {
   538  				o := t.Output()
   539  				o.Write([]byte("a\n"))
   540  				o.Write([]byte("b"))
   541  			})
   542  		},
   543  	}, {
   544  		desc:   "output with chatty and json",
   545  		ok:     true,
   546  		chatty: true,
   547  		json:   true,
   548  		output: `
   549  ^V=== RUN   output with chatty and json
   550  ^V=== RUN   output with chatty and json/#00
   551      a
   552      b
   553  ^V--- PASS: output with chatty and json/#00 (N.NNs)
   554  ^V=== NAME  output with chatty and json
   555  ^V--- PASS: output with chatty and json (N.NNs)
   556  ^V=== NAME
   557  `,
   558  		f: func(t *T) {
   559  			t.Run("", func(t *T) {
   560  				o := t.Output()
   561  				o.Write([]byte("a\n"))
   562  				o.Write([]byte("b"))
   563  			})
   564  		},
   565  	}, {
   566  		desc: "output in finished sub test outputs to parent",
   567  		ok:   false,
   568  		output: `
   569  		--- FAIL: output in finished sub test outputs to parent (N.NNs)
   570      message2
   571      message1
   572      sub_test.go:NNN: error`,
   573  		f: func(t *T) {
   574  			ch := make(chan bool)
   575  			t.Run("sub", func(t2 *T) {
   576  				go func() {
   577  					<-ch
   578  					t2.Output().Write([]byte("message1\n"))
   579  					ch <- true
   580  				}()
   581  			})
   582  			t.Output().Write([]byte("message2\n"))
   583  			ch <- true
   584  			<-ch
   585  			t.Errorf("error")
   586  		},
   587  	}, {
   588  		desc: "newline between buffered log and log",
   589  		ok:   false,
   590  		output: `
   591  --- FAIL: newline between buffered log and log (N.NNs)
   592      --- FAIL: newline between buffered log and log/#00 (N.NNs)
   593          buffered message
   594          sub_test.go:NNN: log`,
   595  		f: func(t *T) {
   596  			t.Run("", func(t *T) {
   597  				o := t.Output()
   598  				o.Write([]byte("buffered message"))
   599  				t.Log("log")
   600  				t.Fail()
   601  			})
   602  		},
   603  	}}
   604  	for _, tc := range testCases {
   605  		t.Run(tc.desc, func(t *T) {
   606  			tstate := newTestState(tc.maxPar, allMatcher())
   607  			buf := &strings.Builder{}
   608  			root := &T{
   609  				common: common{
   610  					signal:  make(chan bool),
   611  					barrier: make(chan bool),
   612  					name:    "",
   613  					w:       buf,
   614  				},
   615  				tstate: tstate,
   616  			}
   617  			if tc.chatty {
   618  				root.chatty = newChattyPrinter(root.w)
   619  				root.chatty.json = tc.json
   620  			}
   621  			ok := root.Run(tc.desc, tc.f)
   622  			tstate.release()
   623  
   624  			if ok != tc.ok {
   625  				t.Errorf("%s:ok: got %v; want %v", tc.desc, ok, tc.ok)
   626  			}
   627  			if ok != !root.Failed() {
   628  				t.Errorf("%s:root failed: got %v; want %v", tc.desc, !ok, root.Failed())
   629  			}
   630  			if tstate.running != 0 || tstate.numWaiting != 0 {
   631  				t.Errorf("%s:running and waiting non-zero: got %d and %d", tc.desc, tstate.running, tstate.numWaiting)
   632  			}
   633  			got := strings.TrimSpace(buf.String())
   634  			want := strings.TrimSpace(tc.output)
   635  			re := makeRegexp(want)
   636  			if ok, err := regexp.MatchString(re, got); !ok || err != nil {
   637  				t.Errorf("%s:output:\ngot:\n%s\nwant:\n%s", tc.desc, notateOutput(got), want)
   638  			}
   639  		})
   640  	}
   641  }
   642  
   643  func TestBRun(t *T) {
   644  	work := func(b *B) {
   645  		for i := 0; i < b.N; i++ {
   646  			time.Sleep(time.Nanosecond)
   647  		}
   648  	}
   649  	testCases := []struct {
   650  		desc   string
   651  		failed bool
   652  		chatty bool
   653  		output string
   654  		f      func(*B)
   655  	}{{
   656  		desc: "simulate sequential run of subbenchmarks.",
   657  		f: func(b *B) {
   658  			b.Run("", func(b *B) { work(b) })
   659  			time1 := b.result.NsPerOp()
   660  			b.Run("", func(b *B) { work(b) })
   661  			time2 := b.result.NsPerOp()
   662  			if time1 >= time2 {
   663  				t.Errorf("no time spent in benchmark t1 >= t2 (%d >= %d)", time1, time2)
   664  			}
   665  		},
   666  	}, {
   667  		desc: "bytes set by all benchmarks",
   668  		f: func(b *B) {
   669  			b.Run("", func(b *B) { b.SetBytes(10); work(b) })
   670  			b.Run("", func(b *B) { b.SetBytes(10); work(b) })
   671  			if b.result.Bytes != 20 {
   672  				t.Errorf("bytes: got: %d; want 20", b.result.Bytes)
   673  			}
   674  		},
   675  	}, {
   676  		desc: "bytes set by some benchmarks",
   677  		// In this case the bytes result is meaningless, so it must be 0.
   678  		f: func(b *B) {
   679  			b.Run("", func(b *B) { b.SetBytes(10); work(b) })
   680  			b.Run("", func(b *B) { work(b) })
   681  			b.Run("", func(b *B) { b.SetBytes(10); work(b) })
   682  			if b.result.Bytes != 0 {
   683  				t.Errorf("bytes: got: %d; want 0", b.result.Bytes)
   684  			}
   685  		},
   686  	}, {
   687  		desc:   "failure carried over to root",
   688  		failed: true,
   689  		output: "--- FAIL: root",
   690  		f:      func(b *B) { b.Fail() },
   691  	}, {
   692  		desc:   "skipping without message, chatty",
   693  		chatty: true,
   694  		output: "--- SKIP: root",
   695  		f:      func(b *B) { b.SkipNow() },
   696  	}, {
   697  		desc:   "chatty with recursion",
   698  		chatty: true,
   699  		f: func(b *B) {
   700  			b.Run("", func(b *B) {
   701  				b.Run("", func(b *B) {})
   702  			})
   703  		},
   704  	}, {
   705  		desc: "skipping without message, not chatty",
   706  		f:    func(b *B) { b.SkipNow() },
   707  	}, {
   708  		desc:   "skipping after error",
   709  		failed: true,
   710  		output: `
   711  --- FAIL: root
   712      sub_test.go:NNN: an error
   713      sub_test.go:NNN: skipped`,
   714  		f: func(b *B) {
   715  			b.Error("an error")
   716  			b.Skip("skipped")
   717  		},
   718  	}, {
   719  		desc: "memory allocation",
   720  		f: func(b *B) {
   721  			const bufSize = 256
   722  			alloc := func(b *B) {
   723  				var buf [bufSize]byte
   724  				for i := 0; i < b.N; i++ {
   725  					_ = append([]byte(nil), buf[:]...)
   726  				}
   727  			}
   728  			b.Run("", func(b *B) {
   729  				alloc(b)
   730  				b.ReportAllocs()
   731  			})
   732  			b.Run("", func(b *B) {
   733  				alloc(b)
   734  				b.ReportAllocs()
   735  			})
   736  			// runtime.MemStats sometimes reports more allocations than the
   737  			// benchmark is responsible for. Luckily the point of this test is
   738  			// to ensure that the results are not underreported, so we can
   739  			// simply verify the lower bound.
   740  			if got := b.result.MemAllocs; got < 2 {
   741  				t.Errorf("MemAllocs was %v; want 2", got)
   742  			}
   743  			if got := b.result.MemBytes; got < 2*bufSize {
   744  				t.Errorf("MemBytes was %v; want %v", got, 2*bufSize)
   745  			}
   746  		},
   747  	}, {
   748  		desc: "cleanup is called",
   749  		f: func(b *B) {
   750  			var calls, cleanups, innerCalls, innerCleanups int
   751  			b.Run("", func(b *B) {
   752  				calls++
   753  				b.Cleanup(func() {
   754  					cleanups++
   755  				})
   756  				b.Run("", func(b *B) {
   757  					b.Cleanup(func() {
   758  						innerCleanups++
   759  					})
   760  					innerCalls++
   761  				})
   762  				work(b)
   763  			})
   764  			if calls == 0 || calls != cleanups {
   765  				t.Errorf("mismatched cleanups; got %d want %d", cleanups, calls)
   766  			}
   767  			if innerCalls == 0 || innerCalls != innerCleanups {
   768  				t.Errorf("mismatched cleanups; got %d want %d", cleanups, calls)
   769  			}
   770  		},
   771  	}, {
   772  		desc:   "cleanup is called on failure",
   773  		failed: true,
   774  		f: func(b *B) {
   775  			var calls, cleanups int
   776  			b.Run("", func(b *B) {
   777  				calls++
   778  				b.Cleanup(func() {
   779  					cleanups++
   780  				})
   781  				b.Fatalf("failure")
   782  			})
   783  			if calls == 0 || calls != cleanups {
   784  				t.Errorf("mismatched cleanups; got %d want %d", cleanups, calls)
   785  			}
   786  		},
   787  	}}
   788  	hideStdoutForTesting = true
   789  	defer func() {
   790  		hideStdoutForTesting = false
   791  	}()
   792  	for _, tc := range testCases {
   793  		t.Run(tc.desc, func(t *T) {
   794  			var ok bool
   795  			buf := &strings.Builder{}
   796  			// This is almost like the Benchmark function, except that we override
   797  			// the benchtime and catch the failure result of the subbenchmark.
   798  			root := &B{
   799  				common: common{
   800  					signal: make(chan bool),
   801  					name:   "root",
   802  					w:      buf,
   803  				},
   804  				benchFunc: func(b *B) { ok = b.Run("test", tc.f) }, // Use Run to catch failure.
   805  				benchTime: durationOrCountFlag{d: 1 * time.Microsecond},
   806  			}
   807  			if tc.chatty {
   808  				root.chatty = newChattyPrinter(root.w)
   809  			}
   810  			root.runN(1)
   811  			if ok != !tc.failed {
   812  				t.Errorf("%s:ok: got %v; want %v", tc.desc, ok, !tc.failed)
   813  			}
   814  			if !ok != root.Failed() {
   815  				t.Errorf("%s:root failed: got %v; want %v", tc.desc, !ok, root.Failed())
   816  			}
   817  			// All tests are run as subtests
   818  			if root.result.N != 1 {
   819  				t.Errorf("%s: N for parent benchmark was %d; want 1", tc.desc, root.result.N)
   820  			}
   821  			got := strings.TrimSpace(buf.String())
   822  			want := strings.TrimSpace(tc.output)
   823  			re := makeRegexp(want)
   824  			if ok, err := regexp.MatchString(re, got); !ok || err != nil {
   825  				t.Errorf("%s:output:\ngot:\n%s\nwant:\n%s", tc.desc, got, want)
   826  			}
   827  		})
   828  	}
   829  }
   830  
   831  // makeRegexp transforms a line in the text notation to a pattern.
   832  func makeRegexp(s string) string {
   833  	s = regexp.QuoteMeta(s)
   834  	s = strings.ReplaceAll(s, "^V", string(markFraming))
   835  	s = strings.ReplaceAll(s, "^O", string(markErrBegin))
   836  	s = strings.ReplaceAll(s, "^N", string(markErrEnd))
   837  	s = strings.ReplaceAll(s, "^\\[", string(markEscape))
   838  	s = strings.ReplaceAll(s, ":NNN:", `:\d\d\d\d?:`)
   839  	s = strings.ReplaceAll(s, "N\\.NNs", `\d*\.\d*s`)
   840  	return s
   841  }
   842  
   843  // notateOutput transforms an output line into something more easily comparable
   844  // to text notation.
   845  func notateOutput(s string) string {
   846  	s = strings.ReplaceAll(s, string(markFraming), "^V")
   847  	s = strings.ReplaceAll(s, string(markErrBegin), "^O")
   848  	s = strings.ReplaceAll(s, string(markErrEnd), "^N")
   849  	s = strings.ReplaceAll(s, string(markEscape), "^[")
   850  	return s
   851  }
   852  
   853  func TestBenchmarkOutput(t *T) {
   854  	// Ensure Benchmark initialized common.w by invoking it with an error and
   855  	// normal case.
   856  	Benchmark(func(b *B) { b.Error("do not print this output") })
   857  	Benchmark(func(b *B) {})
   858  }
   859  
   860  func TestBenchmarkStartsFrom1(t *T) {
   861  	first := true
   862  	Benchmark(func(b *B) {
   863  		if first && b.N != 1 {
   864  			panic(fmt.Sprintf("Benchmark() first N=%v; want 1", b.N))
   865  		}
   866  		first = false
   867  	})
   868  }
   869  
   870  func TestBenchmarkReadMemStatsBeforeFirstRun(t *T) {
   871  	first := true
   872  	Benchmark(func(b *B) {
   873  		if first && (b.startAllocs == 0 || b.startBytes == 0) {
   874  			panic("ReadMemStats not called before first run")
   875  		}
   876  		first = false
   877  	})
   878  }
   879  
   880  type funcWriter struct {
   881  	write func([]byte) (int, error)
   882  }
   883  
   884  func (fw *funcWriter) Write(b []byte) (int, error) {
   885  	return fw.write(b)
   886  }
   887  
   888  func TestRacyOutput(t *T) {
   889  	var runs int32  // The number of running Writes
   890  	var races int32 // Incremented for each race detected
   891  	raceDetector := func(b []byte) (int, error) {
   892  		// Check if some other goroutine is concurrently calling Write.
   893  		if atomic.LoadInt32(&runs) > 0 {
   894  			atomic.AddInt32(&races, 1) // Race detected!
   895  		}
   896  		atomic.AddInt32(&runs, 1)
   897  		defer atomic.AddInt32(&runs, -1)
   898  		runtime.Gosched() // Increase probability of a race
   899  		return len(b), nil
   900  	}
   901  
   902  	root := &T{
   903  		common: common{w: &funcWriter{raceDetector}},
   904  		tstate: newTestState(1, allMatcher()),
   905  	}
   906  	root.chatty = newChattyPrinter(root.w)
   907  	root.Run("", func(t *T) {
   908  		var wg sync.WaitGroup
   909  		for i := 0; i < 100; i++ {
   910  			wg.Add(1)
   911  			go func(i int) {
   912  				defer wg.Done()
   913  				t.Run(fmt.Sprint(i), func(t *T) {
   914  					t.Logf("testing run %d", i)
   915  				})
   916  			}(i)
   917  		}
   918  		wg.Wait()
   919  	})
   920  
   921  	if races > 0 {
   922  		t.Errorf("detected %d racy Writes", races)
   923  	}
   924  }
   925  
   926  // The late log message did not include the test name.  Issue 29388.
   927  func TestLogAfterComplete(t *T) {
   928  	tstate := newTestState(1, allMatcher())
   929  	var buf bytes.Buffer
   930  	t1 := &T{
   931  		common: common{
   932  			// Use a buffered channel so that tRunner can write
   933  			// to it although nothing is reading from it.
   934  			signal: make(chan bool, 1),
   935  			w:      &buf,
   936  		},
   937  		tstate: tstate,
   938  	}
   939  
   940  	c1 := make(chan bool)
   941  	c2 := make(chan string)
   942  	tRunner(t1, func(t *T) {
   943  		t.Run("TestLateLog", func(t *T) {
   944  			go func() {
   945  				defer close(c2)
   946  				defer func() {
   947  					p := recover()
   948  					if p == nil {
   949  						c2 <- "subtest did not panic"
   950  						return
   951  					}
   952  					s, ok := p.(string)
   953  					if !ok {
   954  						c2 <- fmt.Sprintf("subtest panic with unexpected value %v of type %T", p, p)
   955  						return
   956  					}
   957  					const want = "Log in goroutine after TestLateLog has completed: log after test"
   958  					if !strings.Contains(s, want) {
   959  						c2 <- fmt.Sprintf("subtest panic %q does not contain %q", s, want)
   960  					}
   961  				}()
   962  
   963  				<-c1
   964  				t.Log("log after test")
   965  			}()
   966  		})
   967  	})
   968  	close(c1)
   969  
   970  	if s := <-c2; s != "" {
   971  		t.Error(s)
   972  	}
   973  }
   974  
   975  func TestBenchmark(t *T) {
   976  	if Short() {
   977  		t.Skip("skipping in short mode")
   978  	}
   979  	res := Benchmark(func(b *B) {
   980  		for i := 0; i < 5; i++ {
   981  			b.Run("", func(b *B) {
   982  				for i := 0; i < b.N; i++ {
   983  					time.Sleep(time.Millisecond)
   984  				}
   985  			})
   986  		}
   987  	})
   988  	if res.NsPerOp() < 4000000 {
   989  		t.Errorf("want >5ms; got %v", time.Duration(res.NsPerOp()))
   990  	}
   991  }
   992  
   993  func TestCleanup(t *T) {
   994  	var cleanups []int
   995  	t.Run("test", func(t *T) {
   996  		t.Cleanup(func() { cleanups = append(cleanups, 1) })
   997  		t.Cleanup(func() { cleanups = append(cleanups, 2) })
   998  	})
   999  	if got, want := cleanups, []int{2, 1}; !slices.Equal(got, want) {
  1000  		t.Errorf("unexpected cleanup record; got %v want %v", got, want)
  1001  	}
  1002  }
  1003  
  1004  func TestConcurrentCleanup(t *T) {
  1005  	cleanups := 0
  1006  	t.Run("test", func(t *T) {
  1007  		var wg sync.WaitGroup
  1008  		wg.Add(2)
  1009  		for i := 0; i < 2; i++ {
  1010  			go func() {
  1011  				t.Cleanup(func() {
  1012  					// Although the calls to Cleanup are concurrent, the functions passed
  1013  					// to Cleanup should be called sequentially, in some nondeterministic
  1014  					// order based on when the Cleanup calls happened to be scheduled.
  1015  					// So these assignments to the cleanups variable should not race.
  1016  					cleanups |= 1 << i
  1017  				})
  1018  				wg.Done()
  1019  			}()
  1020  		}
  1021  		wg.Wait()
  1022  	})
  1023  	if cleanups != 1|2 {
  1024  		t.Errorf("unexpected cleanup; got %d want 3", cleanups)
  1025  	}
  1026  }
  1027  
  1028  func TestCleanupCalledEvenAfterGoexit(t *T) {
  1029  	cleanups := 0
  1030  	t.Run("test", func(t *T) {
  1031  		t.Cleanup(func() {
  1032  			cleanups++
  1033  		})
  1034  		t.Cleanup(func() {
  1035  			runtime.Goexit()
  1036  		})
  1037  	})
  1038  	if cleanups != 1 {
  1039  		t.Errorf("unexpected cleanup count; got %d want 1", cleanups)
  1040  	}
  1041  }
  1042  
  1043  func TestRunCleanup(t *T) {
  1044  	outerCleanup := 0
  1045  	innerCleanup := 0
  1046  	t.Run("test", func(t *T) {
  1047  		t.Cleanup(func() { outerCleanup++ })
  1048  		t.Run("x", func(t *T) {
  1049  			t.Cleanup(func() { innerCleanup++ })
  1050  		})
  1051  	})
  1052  	if innerCleanup != 1 {
  1053  		t.Errorf("unexpected inner cleanup count; got %d want 1", innerCleanup)
  1054  	}
  1055  	if outerCleanup != 1 {
  1056  		t.Errorf("unexpected outer cleanup count; got %d want 0", outerCleanup)
  1057  	}
  1058  }
  1059  
  1060  func TestCleanupParallelSubtests(t *T) {
  1061  	ranCleanup := 0
  1062  	t.Run("test", func(t *T) {
  1063  		t.Cleanup(func() { ranCleanup++ })
  1064  		t.Run("x", func(t *T) {
  1065  			t.Parallel()
  1066  			if ranCleanup > 0 {
  1067  				t.Error("outer cleanup ran before parallel subtest")
  1068  			}
  1069  		})
  1070  	})
  1071  	if ranCleanup != 1 {
  1072  		t.Errorf("unexpected cleanup count; got %d want 1", ranCleanup)
  1073  	}
  1074  }
  1075  
  1076  func TestNestedCleanup(t *T) {
  1077  	ranCleanup := 0
  1078  	t.Run("test", func(t *T) {
  1079  		t.Cleanup(func() {
  1080  			if ranCleanup != 2 {
  1081  				t.Errorf("unexpected cleanup count in first cleanup: got %d want 2", ranCleanup)
  1082  			}
  1083  			ranCleanup++
  1084  		})
  1085  		t.Cleanup(func() {
  1086  			if ranCleanup != 0 {
  1087  				t.Errorf("unexpected cleanup count in second cleanup: got %d want 0", ranCleanup)
  1088  			}
  1089  			ranCleanup++
  1090  			t.Cleanup(func() {
  1091  				if ranCleanup != 1 {
  1092  					t.Errorf("unexpected cleanup count in nested cleanup: got %d want 1", ranCleanup)
  1093  				}
  1094  				ranCleanup++
  1095  			})
  1096  		})
  1097  	})
  1098  	if ranCleanup != 3 {
  1099  		t.Errorf("unexpected cleanup count: got %d want 3", ranCleanup)
  1100  	}
  1101  }
  1102  
  1103  // TestOutput checks that log messages are written,
  1104  // formatted and buffered as expected by Output. It
  1105  // checks both the chatty and non-chatty cases.
  1106  func TestOutput(t *T) {
  1107  	tstate := newTestState(1, allMatcher())
  1108  	root := &T{
  1109  		tstate: tstate,
  1110  	}
  1111  	root.setOutputWriter()
  1112  	o := root.Output()
  1113  
  1114  	// Chatty case
  1115  	tstateChatty := newTestState(1, allMatcher())
  1116  	bufChatty := &strings.Builder{}
  1117  	rootChatty := &T{
  1118  		common: common{
  1119  			w: bufChatty,
  1120  		},
  1121  		tstate: tstateChatty,
  1122  	}
  1123  	rootChatty.setOutputWriter()
  1124  	rootChatty.chatty = newChattyPrinter(rootChatty.w)
  1125  	oChatty := rootChatty.Output()
  1126  
  1127  	testCases := []struct {
  1128  		in  string
  1129  		out string
  1130  		buf string
  1131  	}{{
  1132  		in:  "a",
  1133  		out: "",
  1134  		buf: "a",
  1135  	}, {
  1136  		in:  "b",
  1137  		out: "",
  1138  		buf: "ab",
  1139  	}, {
  1140  		in:  "\n",
  1141  		out: "    ab\n",
  1142  		buf: "",
  1143  	}, {
  1144  		in:  "\nc",
  1145  		out: "    ab\n    \n",
  1146  		buf: "c",
  1147  	}, {
  1148  		in:  "d",
  1149  		out: "    ab\n    \n",
  1150  		buf: "cd",
  1151  	}}
  1152  	for _, tc := range testCases {
  1153  		o.Write([]byte(tc.in))
  1154  		if string(root.output) != tc.out {
  1155  			t.Errorf("output:\ngot:\n%s\nwant:\n%s", root.output, tc.out)
  1156  		}
  1157  		if string(root.o.partial) != tc.buf {
  1158  			t.Errorf("buffer:\ngot:\n%s\nwant:\n%s", root.o.partial, tc.buf)
  1159  		}
  1160  
  1161  		// Chatty case
  1162  		oChatty.Write([]byte(tc.in))
  1163  		if got := bufChatty.String(); got != tc.out {
  1164  			t.Errorf("output:\ngot:\n%s\nwant:\n%s", got, tc.out)
  1165  		}
  1166  	}
  1167  }
  1168  
  1169  // TestOutputAfterComplete ensures that Output panics
  1170  // if called after a test function returns.
  1171  func TestOutputAfterComplete(t *T) {
  1172  	tstate := newTestState(1, allMatcher())
  1173  	var buf bytes.Buffer
  1174  	t1 := &T{
  1175  		common: common{
  1176  			// Use a buffered channel so that tRunner can write
  1177  			// to it although nothing is reading from it.
  1178  			signal: make(chan bool, 1),
  1179  			w:      &buf,
  1180  		},
  1181  		tstate: tstate,
  1182  	}
  1183  
  1184  	c1 := make(chan bool)
  1185  	c2 := make(chan string)
  1186  	tRunner(t1, func(t *T) {
  1187  		t.Run("TestLateOutput", func(t *T) {
  1188  			go func() {
  1189  				defer close(c2)
  1190  				defer func() {
  1191  					p := recover()
  1192  					if p == nil {
  1193  						c2 <- "subtest did not panic"
  1194  						return
  1195  					}
  1196  					s, ok := p.(string)
  1197  					if !ok {
  1198  						c2 <- fmt.Sprintf("subtest panic with unexpected value %v of type %T", p, p)
  1199  						return
  1200  					}
  1201  					const want = "Output called after TestLateOutput has completed"
  1202  					if !strings.Contains(s, want) {
  1203  						c2 <- fmt.Sprintf("subtest panic %q does not contain %q", s, want)
  1204  					}
  1205  				}()
  1206  
  1207  				<-c1
  1208  				t.Output()
  1209  			}()
  1210  		})
  1211  	})
  1212  	close(c1)
  1213  
  1214  	if s := <-c2; s != "" {
  1215  		t.Error(s)
  1216  	}
  1217  }
  1218  
  1219  // TestOutputWriteAfterComplete ensures that Write panics
  1220  // if called on t.Output() of a finished test t.
  1221  func TestOutputWriteAfterComplete(t *T) {
  1222  	tstate := newTestState(1, allMatcher())
  1223  	var buf bytes.Buffer
  1224  	t1 := &T{
  1225  		common: common{
  1226  			// Use a buffered channel so that tRunner can write
  1227  			// to it although nothing is reading from it.
  1228  			signal: make(chan bool, 1),
  1229  			w:      &buf,
  1230  		},
  1231  		tstate: tstate,
  1232  	}
  1233  
  1234  	c1 := make(chan bool)
  1235  	c2 := make(chan string)
  1236  	tRunner(t1, func(t *T) {
  1237  		t.Run("TestLateWrite", func(t *T) {
  1238  			o := t.Output()
  1239  			go func() {
  1240  				defer close(c2)
  1241  				defer func() {
  1242  					p := recover()
  1243  					if p == nil {
  1244  						c2 <- "subtest did not panic"
  1245  						return
  1246  					}
  1247  					s, ok := p.(string)
  1248  					if !ok {
  1249  						c2 <- fmt.Sprintf("subtest panic with unexpected value %v of type %T", p, p)
  1250  						return
  1251  					}
  1252  					const want = "Write called after TestLateWrite has completed"
  1253  					if !strings.Contains(s, want) {
  1254  						c2 <- fmt.Sprintf("subtest panic %q does not contain %q", s, want)
  1255  					}
  1256  				}()
  1257  
  1258  				<-c1
  1259  				o.Write([]byte("write after test"))
  1260  			}()
  1261  		})
  1262  	})
  1263  	close(c1)
  1264  
  1265  	if s := <-c2; s != "" {
  1266  		t.Error(s)
  1267  	}
  1268  }
  1269  
  1270  // Verify that logging to an inactive top-level testing.T does not panic.
  1271  // These tests can run in either order.
  1272  
  1273  func TestOutputEscape1(t *T) { testOutputEscape(t) }
  1274  func TestOutputEscape2(t *T) { testOutputEscape(t) }
  1275  
  1276  var global *T
  1277  
  1278  func testOutputEscape(t *T) {
  1279  	if global == nil {
  1280  		// Store t in a global, to set up for the second execution.
  1281  		global = t
  1282  	} else {
  1283  		// global is inactive here.
  1284  		global.Log("hello")
  1285  	}
  1286  }
  1287  

View as plain text