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`
This commit is contained in:
Jean-Hadrien Chabran 2024-07-04 19:11:10 +02:00 committed by GitHub
parent b98c7d084d
commit 2dfeb486d5
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
3 changed files with 18 additions and 4 deletions

View File

@ -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)
}()

View File

@ -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) {

View File

@ -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))