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

View as plain text