Skip to content

Commit 0bcdc34

Browse files
fuweidArkaSaha30
authored andcommitted
[3.5]backport: pkg/expect: fix data race
Let's say there is command which outputs one line and exit with error. There are three goroutines to acquire the lock: 1. ep.read() 2. ep.waitSaveExitErr() 3. ep.Expect() When ep.read goroutine reads the log but it doesn't acquire the lock in time, the ep.waitSaveExitErr acquires the lock and updates the `exitErr`. And then ep.Expect acquires lock but it doesn't see any log yet and then returns err. It's hard to reproduce it in local. Add the extra sleep can reproduce it. ```diff diff --git a/pkg/expect/expect.go b/pkg/expect/expect.go index a512a3c..602bea73f 100644 --- a/pkg/expect/expect.go +++ b/pkg/expect/expect.go @@ -128,6 +128,7 @@ func (ep *ExpectProcess) tryReadNextLine(r *bufio.Reader) error { printDebugLines := os.Getenv("EXPECT_DEBUG") != "" l, err := r.ReadString('\n') + time.Sleep(10 * time.Millisecond) ep.mu.Lock() defer ep.mu.Unlock() ``` See it once in Github Action [1]. In order to fix it, the patch introduces `readCloseCh` to wait for ep.read to get all the data and retry it. [1]: #16137 (comment) Signed-off-by: Wei Fu <[email protected]>
1 parent 28ad5e4 commit 0bcdc34

File tree

2 files changed

+31
-1
lines changed

2 files changed

+31
-1
lines changed

pkg/expect/expect.go

+23-1
Original file line numberDiff line numberDiff line change
@@ -44,6 +44,8 @@ type ExpectProcess struct {
4444
fpty *os.File
4545
wg sync.WaitGroup
4646

47+
readCloseCh chan struct{} // close it if async read goroutine exits
48+
4749
mu sync.Mutex // protects lines, count, cur, exitErr and exitCode
4850
lines []string
4951
count int // increment whenever new line gets added
@@ -67,6 +69,7 @@ func NewExpectWithEnv(name string, args []string, env []string, serverProcessCon
6769
args: args,
6870
env: env,
6971
},
72+
readCloseCh: make(chan struct{}),
7073
}
7174
ep.cmd = commandFromConfig(ep.cfg)
7275

@@ -100,7 +103,10 @@ func (ep *ExpectProcess) Pid() int {
100103
}
101104

102105
func (ep *ExpectProcess) read() {
103-
defer ep.wg.Done()
106+
defer func() {
107+
ep.wg.Done()
108+
close(ep.readCloseCh)
109+
}()
104110
defer func(fpty *os.File) {
105111
err := fpty.Close()
106112
if err != nil {
@@ -187,9 +193,25 @@ func (ep *ExpectProcess) ExpectFunc(ctx context.Context, f func(string) bool) (s
187193
}
188194
}
189195

196+
select {
197+
// NOTE: we wait readCloseCh for ep.read() to complete draining the log before acquring the lock.
198+
case <-ep.readCloseCh:
199+
case <-ctx.Done():
200+
return "", fmt.Errorf("failed to find match string: %w", ctx.Err())
201+
}
202+
190203
ep.mu.Lock()
191204
defer ep.mu.Unlock()
192205

206+
// retry it since we get all the log data
207+
for i < len(ep.lines) {
208+
line := ep.lines[i]
209+
i++
210+
if f(line) {
211+
return line, nil
212+
}
213+
}
214+
193215
lastLinesIndex := len(ep.lines) - DEBUG_LINES_TAIL
194216
if lastLinesIndex < 0 {
195217
lastLinesIndex = 0

pkg/expect/expect_test.go

+8
Original file line numberDiff line numberDiff line change
@@ -209,3 +209,11 @@ func TestExitCodeAfterKill(t *testing.T) {
209209
assert.Equal(t, 137, code)
210210
assert.NoError(t, err)
211211
}
212+
213+
func TestExpectForFailFastCommand(t *testing.T) {
214+
ep, err := NewExpect("sh", "-c", `echo "curl: (59) failed setting cipher list"; exit 59`)
215+
require.NoError(t, err)
216+
217+
_, err = ep.Expect("failed setting cipher list")
218+
require.NoError(t, err)
219+
}

0 commit comments

Comments
 (0)