From 2dfeb486d52064df50d2e1e57b2779ad2dda683e Mon Sep 17 00:00:00 2001
From: Jean-Hadrien Chabran <jean-hadrien.chabran@sourcegraph.com>
Date: Thu, 4 Jul 2024 19:11:10 +0200
Subject: [PATCH] fix(local): fix race in sg_start_test.go (#63642)

Fixes DINF-82; This was very much a rabbithole. A few things:

- The race that @bobheadxi mentioned here
https://github.com/sourcegraph/sourcegraph/pull/63405#discussion_r1648180713
wasn't from `*output.Output` being unsafe, but `outputtest.Buffer` as it
happened again (see
[DINF-82](https://linear.app/sourcegraph/issue/DINF-82/devsgsg-test-failed-with-a-detected-race-condition))
- There something messed up with `cmds.start()`, which sometimes ends up
printing the command output _after_ the exit message instead of before.
- The crude `sort.Strings(want|have)` that was there already fixes that.
- And without the sleep, it's possible to read the output from the
`outputtest.Buffer` before the command outputs get written to it.
- The `time.Sleep(300 * time.Milliseconds)` _mitigates/hides_ that
problem.

At least, this shouldn't blow up in CI and buys us time to fix the whole
thing. We're tracking this in DINF-104. And out of 200 runs, I also
stumbled on a race in `progress_tty`, tracked in DINF-105 (that packages
is originally meant to be used by `src-cli` and was re-used for `sg` 3
years ago).

I'm pretty unhappy about the solution, but a bandage is better than
nothing. While ideally, we should really reconsider dropping
`std.Output` entirely in `sg` and use the good stuff from
github.com/charmbracelet instead because we don't want to spend too much
time on arcane terminal things ourselves, I'm much more about concerned
the concurrency issues mentioned above.

## Test plan

CI + `sg bazel test //dev/sg:sg_test --runs_per_test=100`
---
 dev/sg/internal/run/logger.go   |  4 ----
 dev/sg/sg_start_test.go         |  7 +++++++
 lib/output/outputtest/buffer.go | 11 +++++++++++
 3 files changed, 18 insertions(+), 4 deletions(-)

diff --git a/dev/sg/internal/run/logger.go b/dev/sg/internal/run/logger.go
index e647eeee307..8e1c6f2b820 100644
--- a/dev/sg/internal/run/logger.go
+++ b/dev/sg/internal/run/logger.go
@@ -5,7 +5,6 @@ import (
 	"hash/fnv"
 	"io"
 	"strconv"
-	"sync"
 
 	"go.bobheadxi.dev/streamline/pipe"
 
@@ -42,12 +41,9 @@ func newOutputPipe(ctx context.Context, name string, out *output.Output, start <
 
 	w, stream := pipe.NewStream()
 	go func() {
-		var mux sync.Mutex
 		<-start
 		err := stream.Stream(func(line string) {
-			mux.Lock()
 			out.Writef(lineFormat, output.StyleBold, color, name, output.StyleReset, line)
-			mux.Unlock()
 		})
 		_ = w.CloseWithError(err)
 	}()
diff --git a/dev/sg/sg_start_test.go b/dev/sg/sg_start_test.go
index 856bb3ac9ce..527d2b1241c 100644
--- a/dev/sg/sg_start_test.go
+++ b/dev/sg/sg_start_test.go
@@ -5,6 +5,7 @@ import (
 	"sort"
 	"strings"
 	"testing"
+	"time"
 
 	"github.com/google/go-cmp/cmp"
 
@@ -121,8 +122,14 @@ func useOutputBuffer(t *testing.T) *outputtest.Buffer {
 func expectOutput(t *testing.T, buf *outputtest.Buffer, want []string) {
 	t.Helper()
 
+	// TODO: DINF-104, find out why we need this sleep. Basically, when running in tests,
+	// for some reason, even though cmds.start() returned, it hasn't finished writing
+	// the outputs in rare cases (6 out out 100 runs on my machine).
+	time.Sleep(300 * time.Millisecond)
 	have := buf.Lines()
 
+	// TODO: See DINF-104, without this, we can see the cmd output printed out after
+	// the exit message. For now, and to prevent flakes, we'll keep the sort.
 	sort.Strings(want)
 	sort.Strings(have)
 	if !cmp.Equal(want, have) {
diff --git a/lib/output/outputtest/buffer.go b/lib/output/outputtest/buffer.go
index e305cf1f872..8f04d118035 100644
--- a/lib/output/outputtest/buffer.go
+++ b/lib/output/outputtest/buffer.go
@@ -2,6 +2,7 @@ package outputtest
 
 import (
 	"strconv"
+	"sync"
 )
 
 // Buffer is used to test code that uses the `output` library to produce
@@ -14,6 +15,7 @@ import (
 // NOTE: Buffer is *not* complete and probably can't parse everything that
 // output produces. It should be extended as needed.
 type Buffer struct {
+	sync.Mutex
 	lines [][]byte
 
 	line   int
@@ -21,8 +23,14 @@ type Buffer struct {
 }
 
 func (t *Buffer) Write(b []byte) (int, error) {
+	t.Lock()
+	defer t.Unlock()
+
 	cur := 0
 
+	// Debug helper:
+	// fmt.Printf("b: %q\n", string(b))
+
 	for cur < len(b) {
 		switch b[cur] {
 		case '\n':
@@ -120,6 +128,9 @@ func (t *Buffer) writeToCurrentLine(b byte) {
 }
 
 func (t *Buffer) Lines() []string {
+	t.Lock()
+	defer t.Unlock()
+
 	var lines []string
 	for _, l := range t.lines {
 		lines = append(lines, string(l))