libgo/go/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         "strings"
  13         "sync"
  14         "sync/atomic"
  15         "time"
  16 )
  17
  18 func init() {
  19         // Make benchmark tests run 10x faster.
  20         benchTime.d = 100 * time.Millisecond
  21 }
  22
  23 func TestTestContext(t *T) {
  24         const (
  25                 add1 = 0
  26                 done = 1
  27         )
  28         // After each of the calls are applied to the context, the
  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                 ctx := &testContext{
  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(ctx.waitParallel)
  91                                 select {
  92                                 case <-signal:
  93                                         started = true
  94                                 case ctx.startParallel <- true:
  95                                         <-signal
  96                                 }
  97                         case done:
  98                                 signal := doCall(ctx.release)
  99                                 select {
 100                                 case <-signal:
 101                                 case <-ctx.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 ctx.running != call.running {
 110                                 t.Errorf("%d:%d:running: got %v; want %v", i, j, ctx.running, call.running)
 111                         }
 112                         if ctx.numWaiting != call.waiting {
 113                                 t.Errorf("%d:%d:waiting: got %v; want %v", i, j, ctx.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                 output string
 127                 f      func(*T)
 128         }{{
 129                 desc:   "failnow skips future sequential and parallel tests at same level",
 130                 ok:     false,
 131                 maxPar: 1,
 132                 output: `
 133 --- FAIL: failnow skips future sequential and parallel tests at same level (N.NNs)
 134     --- FAIL: failnow skips future sequential and parallel tests at same level/#00 (N.NNs)
 135     `,
 136                 f: func(t *T) {
 137                         ranSeq := false
 138                         ranPar := false
 139                         t.Run("", func(t *T) {
 140                                 t.Run("par", func(t *T) {
 141                                         t.Parallel()
 142                                         ranPar = true
 143                                 })
 144                                 t.Run("seq", func(t *T) {
 145                                         ranSeq = true
 146                                 })
 147                                 t.FailNow()
 148                                 t.Run("seq", func(t *T) {
 149                                         realTest.Error("test must be skipped")
 150                                 })
 151                                 t.Run("par", func(t *T) {
 152                                         t.Parallel()
 153                                         realTest.Error("test must be skipped.")
 154                                 })
 155                         })
 156                         if !ranPar {
 157                                 realTest.Error("parallel test was not run")
 158                         }
 159                         if !ranSeq {
 160                                 realTest.Error("sequential test was not run")
 161                         }
 162                 },
 163         }, {
 164                 desc:   "failure in parallel test propagates upwards",
 165                 ok:     false,
 166                 maxPar: 1,
 167                 output: `
 168 --- FAIL: failure in parallel test propagates upwards (N.NNs)
 169     --- FAIL: failure in parallel test propagates upwards/#00 (N.NNs)
 170         --- FAIL: failure in parallel test propagates upwards/#00/par (N.NNs)
 171         `,
 172                 f: func(t *T) {
 173                         t.Run("", func(t *T) {
 174                                 t.Parallel()
 175                                 t.Run("par", func(t *T) {
 176                                         t.Parallel()
 177                                         t.Fail()
 178                                 })
 179                         })
 180                 },
 181         }, {
 182                 desc:   "skipping without message, chatty",
 183                 ok:     true,
 184                 chatty: true,
 185                 output: `
 186 === RUN   skipping without message, chatty
 187 --- SKIP: skipping without message, chatty (N.NNs)`,
 188                 f: func(t *T) { t.SkipNow() },
 189         }, {
 190                 desc:   "chatty with recursion",
 191                 ok:     true,
 192                 chatty: true,
 193                 output: `
 194 === RUN   chatty with recursion
 195 === RUN   chatty with recursion/#00
 196 === RUN   chatty with recursion/#00/#00
 197 --- PASS: chatty with recursion (N.NNs)
 198     --- PASS: chatty with recursion/#00 (N.NNs)
 199         --- PASS: chatty with recursion/#00/#00 (N.NNs)`,
 200                 f: func(t *T) {
 201                         t.Run("", func(t *T) {
 202                                 t.Run("", func(t *T) {})
 203                         })
 204                 },
 205         }, {
 206                 desc: "skipping without message, not chatty",
 207                 ok:   true,
 208                 f:    func(t *T) { t.SkipNow() },
 209         }, {
 210                 desc: "skipping after error",
 211                 output: `
 212 --- FAIL: skipping after error (N.NNs)
 213     sub_test.go:NNN: an error
 214     sub_test.go:NNN: skipped`,
 215                 f: func(t *T) {
 216                         t.Error("an error")
 217                         t.Skip("skipped")
 218                 },
 219         }, {
 220                 desc:   "use Run to locally synchronize parallelism",
 221                 ok:     true,
 222                 maxPar: 1,
 223                 f: func(t *T) {
 224                         var count uint32
 225                         t.Run("waitGroup", func(t *T) {
 226                                 for i := 0; i < 4; i++ {
 227                                         t.Run("par", func(t *T) {
 228                                                 t.Parallel()
 229                                                 atomic.AddUint32(&count, 1)
 230                                         })
 231                                 }
 232                         })
 233                         if count != 4 {
 234                                 t.Errorf("count was %d; want 4", count)
 235                         }
 236                 },
 237         }, {
 238                 desc: "alternate sequential and parallel",
 239                 // Sequential tests should partake in the counting of running threads.
 240                 // Otherwise, if one runs parallel subtests in sequential tests that are
 241                 // itself subtests of parallel tests, the counts can get askew.
 242                 ok:     true,
 243                 maxPar: 1,
 244                 f: func(t *T) {
 245                         t.Run("a", func(t *T) {
 246                                 t.Parallel()
 247                                 t.Run("b", func(t *T) {
 248                                         // Sequential: ensure running count is decremented.
 249                                         t.Run("c", func(t *T) {
 250                                                 t.Parallel()
 251                                         })
 252
 253                                 })
 254                         })
 255                 },
 256         }, {
 257                 desc: "alternate sequential and parallel 2",
 258                 // Sequential tests should partake in the counting of running threads.
 259                 // Otherwise, if one runs parallel subtests in sequential tests that are
 260                 // itself subtests of parallel tests, the counts can get askew.
 261                 ok:     true,
 262                 maxPar: 2,
 263                 f: func(t *T) {
 264                         for i := 0; i < 2; i++ {
 265                                 t.Run("a", func(t *T) {
 266                                         t.Parallel()
 267                                         time.Sleep(time.Nanosecond)
 268                                         for i := 0; i < 2; i++ {
 269                                                 t.Run("b", func(t *T) {
 270                                                         time.Sleep(time.Nanosecond)
 271                                                         for i := 0; i < 2; i++ {
 272                                                                 t.Run("c", func(t *T) {
 273                                                                         t.Parallel()
 274                                                                         time.Sleep(time.Nanosecond)
 275                                                                 })
 276                                                         }
 277
 278                                                 })
 279                                         }
 280                                 })
 281                         }
 282                 },
 283         }, {
 284                 desc:   "stress test",
 285                 ok:     true,
 286                 maxPar: 4,
 287                 f: func(t *T) {
 288                         t.Parallel()
 289                         for i := 0; i < 12; i++ {
 290                                 t.Run("a", func(t *T) {
 291                                         t.Parallel()
 292                                         time.Sleep(time.Nanosecond)
 293                                         for i := 0; i < 12; i++ {
 294                                                 t.Run("b", func(t *T) {
 295                                                         time.Sleep(time.Nanosecond)
 296                                                         for i := 0; i < 12; i++ {
 297                                                                 t.Run("c", func(t *T) {
 298                                                                         t.Parallel()
 299                                                                         time.Sleep(time.Nanosecond)
 300                                                                         t.Run("d1", func(t *T) {})
 301                                                                         t.Run("d2", func(t *T) {})
 302                                                                         t.Run("d3", func(t *T) {})
 303                                                                         t.Run("d4", func(t *T) {})
 304                                                                 })
 305                                                         }
 306                                                 })
 307                                         }
 308                                 })
 309                         }
 310                 },
 311         }, {
 312                 desc:   "skip output",
 313                 ok:     true,
 314                 maxPar: 4,
 315                 f: func(t *T) {
 316                         t.Skip()
 317                 },
 318         }, {
 319                 desc: "subtest calls error on parent",
 320                 ok:   false,
 321                 output: `
 322 --- FAIL: subtest calls error on parent (N.NNs)
 323     sub_test.go:NNN: first this
 324     sub_test.go:NNN: and now this!
 325     sub_test.go:NNN: oh, and this too`,
 326                 maxPar: 1,
 327                 f: func(t *T) {
 328                         t.Errorf("first this")
 329                         outer := t
 330                         t.Run("", func(t *T) {
 331                                 outer.Errorf("and now this!")
 332                         })
 333                         t.Errorf("oh, and this too")
 334                 },
 335         }, {
 336                 desc: "subtest calls fatal on parent",
 337                 ok:   false,
 338                 output: `
 339 --- FAIL: subtest calls fatal on parent (N.NNs)
 340     sub_test.go:NNN: first this
 341     sub_test.go:NNN: and now this!
 342     --- FAIL: subtest calls fatal on parent/#00 (N.NNs)
 343         testing.go:NNN: test executed panic(nil) or runtime.Goexit: subtest may have called FailNow on a parent test`,
 344                 maxPar: 1,
 345                 f: func(t *T) {
 346                         outer := t
 347                         t.Errorf("first this")
 348                         t.Run("", func(t *T) {
 349                                 outer.Fatalf("and now this!")
 350                         })
 351                         t.Errorf("Should not reach here.")
 352                 },
 353         }, {
 354                 desc: "subtest calls error on ancestor",
 355                 ok:   false,
 356                 output: `
 357 --- FAIL: subtest calls error on ancestor (N.NNs)
 358     sub_test.go:NNN: Report to ancestor
 359     --- FAIL: subtest calls error on ancestor/#00 (N.NNs)
 360         sub_test.go:NNN: Still do this
 361     sub_test.go:NNN: Also do this`,
 362                 maxPar: 1,
 363                 f: func(t *T) {
 364                         outer := t
 365                         t.Run("", func(t *T) {
 366                                 t.Run("", func(t *T) {
 367                                         outer.Errorf("Report to ancestor")
 368                                 })
 369                                 t.Errorf("Still do this")
 370                         })
 371                         t.Errorf("Also do this")
 372                 },
 373         }, {
 374                 desc: "subtest calls fatal on ancestor",
 375                 ok:   false,
 376                 output: `
 377 --- FAIL: subtest calls fatal on ancestor (N.NNs)
 378     sub_test.go:NNN: Nope`,
 379                 maxPar: 1,
 380                 f: func(t *T) {
 381                         outer := t
 382                         t.Run("", func(t *T) {
 383                                 for i := 0; i < 4; i++ {
 384                                         t.Run("", func(t *T) {
 385                                                 outer.Fatalf("Nope")
 386                                         })
 387                                         t.Errorf("Don't do this")
 388                                 }
 389                                 t.Errorf("And neither do this")
 390                         })
 391                         t.Errorf("Nor this")
 392                 },
 393         }, {
 394                 desc:   "panic on goroutine fail after test exit",
 395                 ok:     false,
 396                 maxPar: 4,
 397                 f: func(t *T) {
 398                         ch := make(chan bool)
 399                         t.Run("", func(t *T) {
 400                                 go func() {
 401                                         <-ch
 402                                         defer func() {
 403                                                 if r := recover(); r == nil {
 404                                                         realTest.Errorf("expected panic")
 405                                                 }
 406                                                 ch <- true
 407                                         }()
 408                                         t.Errorf("failed after success")
 409                                 }()
 410                         })
 411                         ch <- true
 412                         <-ch
 413                 },
 414         }, {
 415                 desc: "log in finished sub test logs to parent",
 416                 ok:   false,
 417                 output: `
 418                 --- FAIL: log in finished sub test logs to parent (N.NNs)
 419     sub_test.go:NNN: message2
 420     sub_test.go:NNN: message1
 421     sub_test.go:NNN: error`,
 422                 maxPar: 1,
 423                 f: func(t *T) {
 424                         ch := make(chan bool)
 425                         t.Run("sub", func(t2 *T) {
 426                                 go func() {
 427                                         <-ch
 428                                         t2.Log("message1")
 429                                         ch <- true
 430                                 }()
 431                         })
 432                         t.Log("message2")
 433                         ch <- true
 434                         <-ch
 435                         t.Errorf("error")
 436                 },
 437         }}
 438         for _, tc := range testCases {
 439                 ctx := newTestContext(tc.maxPar, newMatcher(regexp.MatchString, "", ""))
 440                 buf := &bytes.Buffer{}
 441                 root := &T{
 442                         common: common{
 443                                 signal: make(chan bool),
 444                                 name:   "Test",
 445                                 w:      buf,
 446                                 chatty: tc.chatty,
 447                         },
 448                         context: ctx,
 449                 }
 450                 ok := root.Run(tc.desc, tc.f)
 451                 ctx.release()
 452
 453                 if ok != tc.ok {
 454                         t.Errorf("%s:ok: got %v; want %v", tc.desc, ok, tc.ok)
 455                 }
 456                 if ok != !root.Failed() {
 457                         t.Errorf("%s:root failed: got %v; want %v", tc.desc, !ok, root.Failed())
 458                 }
 459                 if ctx.running != 0 || ctx.numWaiting != 0 {
 460                         t.Errorf("%s:running and waiting non-zero: got %d and %d", tc.desc, ctx.running, ctx.numWaiting)
 461                 }
 462                 got := strings.TrimSpace(buf.String())
 463                 want := strings.TrimSpace(tc.output)
 464                 re := makeRegexp(want)
 465                 if ok, err := regexp.MatchString(re, got); !ok || err != nil {
 466                         t.Errorf("%s:output:\ngot:\n%s\nwant:\n%s", tc.desc, got, want)
 467                 }
 468         }
 469 }
 470
 471 func TestBRun(t *T) {
 472         work := func(b *B) {
 473                 for i := 0; i < b.N; i++ {
 474                         time.Sleep(time.Nanosecond)
 475                 }
 476         }
 477         testCases := []struct {
 478                 desc   string
 479                 failed bool
 480                 chatty bool
 481                 output string
 482                 f      func(*B)
 483         }{{
 484                 desc: "simulate sequential run of subbenchmarks.",
 485                 f: func(b *B) {
 486                         b.Run("", func(b *B) { work(b) })
 487                         time1 := b.result.NsPerOp()
 488                         b.Run("", func(b *B) { work(b) })
 489                         time2 := b.result.NsPerOp()
 490                         if time1 >= time2 {
 491                                 t.Errorf("no time spent in benchmark t1 >= t2 (%d >= %d)", time1, time2)
 492                         }
 493                 },
 494         }, {
 495                 desc: "bytes set by all benchmarks",
 496                 f: func(b *B) {
 497                         b.Run("", func(b *B) { b.SetBytes(10); work(b) })
 498                         b.Run("", func(b *B) { b.SetBytes(10); work(b) })
 499                         if b.result.Bytes != 20 {
 500                                 t.Errorf("bytes: got: %d; want 20", b.result.Bytes)
 501                         }
 502                 },
 503         }, {
 504                 desc: "bytes set by some benchmarks",
 505                 // In this case the bytes result is meaningless, so it must be 0.
 506                 f: func(b *B) {
 507                         b.Run("", func(b *B) { b.SetBytes(10); work(b) })
 508                         b.Run("", func(b *B) { work(b) })
 509                         b.Run("", func(b *B) { b.SetBytes(10); work(b) })
 510                         if b.result.Bytes != 0 {
 511                                 t.Errorf("bytes: got: %d; want 0", b.result.Bytes)
 512                         }
 513                 },
 514         }, {
 515                 desc:   "failure carried over to root",
 516                 failed: true,
 517                 output: "--- FAIL: root",
 518                 f:      func(b *B) { b.Fail() },
 519         }, {
 520                 desc:   "skipping without message, chatty",
 521                 chatty: true,
 522                 output: "--- SKIP: root",
 523                 f:      func(b *B) { b.SkipNow() },
 524         }, {
 525                 desc:   "skipping with message, chatty",
 526                 chatty: true,
 527                 output: `
 528 --- SKIP: root
 529     sub_test.go:NNN: skipping`,
 530                 f: func(b *B) { b.Skip("skipping") },
 531         }, {
 532                 desc:   "chatty with recursion",
 533                 chatty: true,
 534                 f: func(b *B) {
 535                         b.Run("", func(b *B) {
 536                                 b.Run("", func(b *B) {})
 537                         })
 538                 },
 539         }, {
 540                 desc: "skipping without message, not chatty",
 541                 f:    func(b *B) { b.SkipNow() },
 542         }, {
 543                 desc:   "skipping after error",
 544                 failed: true,
 545                 output: `
 546 --- FAIL: root
 547     sub_test.go:NNN: an error
 548     sub_test.go:NNN: skipped`,
 549                 f: func(b *B) {
 550                         b.Error("an error")
 551                         b.Skip("skipped")
 552                 },
 553         }, {
 554                 desc: "memory allocation",
 555                 f: func(b *B) {
 556                         const bufSize = 256
 557                         alloc := func(b *B) {
 558                                 var buf [bufSize]byte
 559                                 for i := 0; i < b.N; i++ {
 560                                         _ = append([]byte(nil), buf[:]...)
 561                                 }
 562                         }
 563                         b.Run("", func(b *B) {
 564                                 alloc(b)
 565                                 b.ReportAllocs()
 566                         })
 567                         b.Run("", func(b *B) {
 568                                 alloc(b)
 569                                 b.ReportAllocs()
 570                         })
 571                         // runtime.MemStats sometimes reports more allocations than the
 572                         // benchmark is responsible for. Luckily the point of this test is
 573                         // to ensure that the results are not underreported, so we can
 574                         // simply verify the lower bound.
 575                         if got := b.result.MemAllocs; got < 2 {
 576                                 t.Errorf("MemAllocs was %v; want 2", got)
 577                         }
 578                         if got := b.result.MemBytes; got < 2*bufSize {
 579                                 t.Errorf("MemBytes was %v; want %v", got, 2*bufSize)
 580                         }
 581                 },
 582         }}
 583         for _, tc := range testCases {
 584                 var ok bool
 585                 buf := &bytes.Buffer{}
 586                 // This is almost like the Benchmark function, except that we override
 587                 // the benchtime and catch the failure result of the subbenchmark.
 588                 root := &B{
 589                         common: common{
 590                                 signal: make(chan bool),
 591                                 name:   "root",
 592                                 w:      buf,
 593                                 chatty: tc.chatty,
 594                         },
 595                         benchFunc: func(b *B) { ok = b.Run("test", tc.f) }, // Use Run to catch failure.
 596                         benchTime: benchTimeFlag{d: 1 * time.Microsecond},
 597                 }
 598                 root.runN(1)
 599                 if ok != !tc.failed {
 600                         t.Errorf("%s:ok: got %v; want %v", tc.desc, ok, !tc.failed)
 601                 }
 602                 if !ok != root.Failed() {
 603                         t.Errorf("%s:root failed: got %v; want %v", tc.desc, !ok, root.Failed())
 604                 }
 605                 // All tests are run as subtests
 606                 if root.result.N != 1 {
 607                         t.Errorf("%s: N for parent benchmark was %d; want 1", tc.desc, root.result.N)
 608                 }
 609                 got := strings.TrimSpace(buf.String())
 610                 want := strings.TrimSpace(tc.output)
 611                 re := makeRegexp(want)
 612                 if ok, err := regexp.MatchString(re, got); !ok || err != nil {
 613                         t.Errorf("%s:output:\ngot:\n%s\nwant:\n%s", tc.desc, got, want)
 614                 }
 615         }
 616 }
 617
 618 func makeRegexp(s string) string {
 619         s = regexp.QuoteMeta(s)
 620         s = strings.ReplaceAll(s, ":NNN:", `:\d\d\d:`)
 621         s = strings.ReplaceAll(s, "N\\.NNs", `\d*\.\d*s`)
 622         return s
 623 }
 624
 625 func TestBenchmarkOutput(t *T) {
 626         // Ensure Benchmark initialized common.w by invoking it with an error and
 627         // normal case.
 628         Benchmark(func(b *B) { b.Error("do not print this output") })
 629         Benchmark(func(b *B) {})
 630 }
 631
 632 func TestBenchmarkStartsFrom1(t *T) {
 633         var first = true
 634         Benchmark(func(b *B) {
 635                 if first && b.N != 1 {
 636                         panic(fmt.Sprintf("Benchmark() first N=%v; want 1", b.N))
 637                 }
 638                 first = false
 639         })
 640 }
 641
 642 func TestBenchmarkReadMemStatsBeforeFirstRun(t *T) {
 643         var first = true
 644         Benchmark(func(b *B) {
 645                 if first && (b.startAllocs == 0 || b.startBytes == 0) {
 646                         panic(fmt.Sprintf("ReadMemStats not called before first run"))
 647                 }
 648                 first = false
 649         })
 650 }
 651
 652 func TestParallelSub(t *T) {
 653         c := make(chan int)
 654         block := make(chan int)
 655         for i := 0; i < 10; i++ {
 656                 go func(i int) {
 657                         <-block
 658                         t.Run(fmt.Sprint(i), func(t *T) {})
 659                         c <- 1
 660                 }(i)
 661         }
 662         close(block)
 663         for i := 0; i < 10; i++ {
 664                 <-c
 665         }
 666 }
 667
 668 type funcWriter func([]byte) (int, error)
 669
 670 func (fw funcWriter) Write(b []byte) (int, error) { return fw(b) }
 671
 672 func TestRacyOutput(t *T) {
 673         var runs int32  // The number of running Writes
 674         var races int32 // Incremented for each race detected
 675         raceDetector := func(b []byte) (int, error) {
 676                 // Check if some other goroutine is concurrently calling Write.
 677                 if atomic.LoadInt32(&runs) > 0 {
 678                         atomic.AddInt32(&races, 1) // Race detected!
 679                 }
 680                 atomic.AddInt32(&runs, 1)
 681                 defer atomic.AddInt32(&runs, -1)
 682                 runtime.Gosched() // Increase probability of a race
 683                 return len(b), nil
 684         }
 685
 686         var wg sync.WaitGroup
 687         root := &T{
 688                 common:  common{w: funcWriter(raceDetector), chatty: true},
 689                 context: newTestContext(1, newMatcher(regexp.MatchString, "", "")),
 690         }
 691         root.Run("", func(t *T) {
 692                 for i := 0; i < 100; i++ {
 693                         wg.Add(1)
 694                         go func(i int) {
 695                                 defer wg.Done()
 696                                 t.Run(fmt.Sprint(i), func(t *T) {
 697                                         t.Logf("testing run %d", i)
 698                                 })
 699                         }(i)
 700                 }
 701         })
 702         wg.Wait()
 703
 704         if races > 0 {
 705                 t.Errorf("detected %d racy Writes", races)
 706         }
 707 }
 708
 709 // The late log message did not include the test name.  Issue 29388.
 710 func TestLogAfterComplete(t *T) {
 711         ctx := newTestContext(1, newMatcher(regexp.MatchString, "", ""))
 712         var buf bytes.Buffer
 713         t1 := &T{
 714                 common: common{
 715                         // Use a buffered channel so that tRunner can write
 716                         // to it although nothing is reading from it.
 717                         signal: make(chan bool, 1),
 718                         w:      &buf,
 719                 },
 720                 context: ctx,
 721         }
 722
 723         c1 := make(chan bool)
 724         c2 := make(chan string)
 725         tRunner(t1, func(t *T) {
 726                 t.Run("TestLateLog", func(t *T) {
 727                         go func() {
 728                                 defer close(c2)
 729                                 defer func() {
 730                                         p := recover()
 731                                         if p == nil {
 732                                                 c2 <- "subtest did not panic"
 733                                                 return
 734                                         }
 735                                         s, ok := p.(string)
 736                                         if !ok {
 737                                                 c2 <- fmt.Sprintf("subtest panic with unexpected value %v", p)
 738                                                 return
 739                                         }
 740                                         const want = "Log in goroutine after TestLateLog has completed"
 741                                         if !strings.Contains(s, want) {
 742                                                 c2 <- fmt.Sprintf("subtest panic %q does not contain %q", s, want)
 743                                         }
 744                                 }()
 745
 746                                 <-c1
 747                                 t.Log("log after test")
 748                         }()
 749                 })
 750         })
 751         close(c1)
 752
 753         if s := <-c2; s != "" {
 754                 t.Error(s)
 755         }
 756 }
 757
 758 func TestBenchmark(t *T) {
 759         if Short() {
 760                 t.Skip("skipping in short mode")
 761         }
 762         res := Benchmark(func(b *B) {
 763                 for i := 0; i < 5; i++ {
 764                         b.Run("", func(b *B) {
 765                                 for i := 0; i < b.N; i++ {
 766                                         time.Sleep(time.Millisecond)
 767                                 }
 768                         })
 769                 }
 770         })
 771         if res.NsPerOp() < 4000000 {
 772                 t.Errorf("want >5ms; got %v", time.Duration(res.NsPerOp()))
 773         }
 774 }