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>

diff --git a/src/testing/sub_test.go b/src/testing/sub_test.go
index bb7b3e09255ea167de3001248b55c83e20b21109..1d1092c979968405ffc51821ce30ef6b2eeaa662 100644 (file)
--- 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 bd19a31c27c85ad61e3e378d00641ec615accf21..5efbc244fec961a006a94ccc1031d7d7713cba3d 100644 (file)
--- 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