testing: synchronize writes to the root's Writer

Prior to this change it was possible to see interleaved messages:
<<<
=== RUN   Test/LongLongLongLongName48
=== RUN   Test/LongLon=== RUN   Test/LongLongLongLongName50
gLongLongName49
=== RUN   Test/LongLongLongLongName51
>>>

This change fixes it such that you see:
<<<
=== RUN   Test/LongLongLongLongName48
=== RUN   Test/LongLongLongLongName49
=== RUN   Test/LongLongLongLongName50
=== RUN   Test/LongLongLongLongName51
>>>

Fixes #18741

Change-Id: I2529d724065dc65b3e9eb3d7cbeeda82a2d0cfd4
Reviewed-on: https://go-review.googlesource.com/35556
Reviewed-by: Brad Fitzpatrick <bradfitz@golang.org>
Run-TryBot: Joe Tsai <thebrokentoaster@gmail.com>

2 files changed, 46 insertions, 1 deletions

diff --git a/src/testing/sub_test.go b/src/testing/sub_test.go
index bb7b3e0925..1d1092c979 100644
--- a/src/testing/sub_test.go
+++ b/src/testing/sub_test.go
@@ -8,7 +8,9 @@ import (
 	"bytes"
 	"fmt"
 	"regexp"
+	"runtime"
 	"strings"
+	"sync"
 	"sync/atomic"
 	"time"
 )
@@ -532,3 +534,44 @@ func TestParallelSub(t *T) {
 		<-c
 	}
 }
+
+type funcWriter func([]byte) (int, error)
+
+func (fw funcWriter) Write(b []byte) (int, error) { return fw(b) }
+
+func TestRacyOutput(t *T) {
+	var runs int32  // The number of running Writes
+	var races int32 // Incremented for each race detected
+	raceDetector := func(b []byte) (int, error) {
+		// Check if some other goroutine is concurrently calling Write.
+		if atomic.LoadInt32(&runs) > 0 {
+			atomic.AddInt32(&races, 1) // Race detected!
+		}
+		atomic.AddInt32(&runs, 1)
+		defer atomic.AddInt32(&runs, -1)
+		runtime.Gosched() // Increase probability of a race
+		return len(b), nil
+	}
+
+	var wg sync.WaitGroup
+	root := &T{
+		common:  common{w: funcWriter(raceDetector), chatty: true},
+		context: newTestContext(1, newMatcher(regexp.MatchString, "", "")),
+	}
+	root.Run("", func(t *T) {
+		for i := 0; i < 100; i++ {
+			wg.Add(1)
+			go func(i int) {
+				defer wg.Done()
+				t.Run(fmt.Sprint(i), func(t *T) {
+					t.Logf("testing run %d", i)
+				})
+			}(i)
+		}
+	})
+	wg.Wait()
+
+	if races > 0 {
+		t.Errorf("detected %d racy Writes", races)
+	}
+}
diff --git a/src/testing/testing.go b/src/testing/testing.go
index bd19a31c27..5efbc244fe 100644
--- a/src/testing/testing.go
+++ b/src/testing/testing.go
@@ -259,7 +259,7 @@ var (
 // common holds the elements common between T and B and
 // captures common methods such as Errorf.
 type common struct {
-	mu         sync.RWMutex // guards output, failed, and done.
+	mu         sync.RWMutex // guards output, w, failed, and done.
 	output     []byte       // Output generated by test or benchmark.
 	w          io.Writer    // For flushToParent.
 	chatty     bool         // A copy of the chatty flag.
@@ -687,7 +687,9 @@ func (t *T) Run(name string, f func(t *T)) bool {
 		root := t.parent
 		for ; root.parent != nil; root = root.parent {
 		}
+		root.mu.Lock()
 		fmt.Fprintf(root.w, "=== RUN   %s\n", t.name)
+		root.mu.Unlock()
 	}
 	// Instead of reducing the running count of this test before calling the
 	// tRunner and increasing it afterwards, we rely on tRunner keeping the