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