Skip to content

Commit 0437746

Browse files
authored
Fix deadlock when bundle script hooks write large stderr output (#5499)
## Why Found during a full-repo review of the CLI. Bundle script hooks (`experimental.scripts`) can deadlock a deploy forever. Hook output was read sequentially: stdout to EOF first, then stderr. A hook that writes more than the OS pipe buffer (about 64KiB) to stderr while stdout is still open blocks on the stderr write and never closes stdout, so the script and the CLI wait on each other indefinitely. ## Changes Before, stderr was only read after stdout reached EOF (via `io.MultiReader`); now stderr is drained concurrently, so the hook can never block on a full stderr pipe. In `bundle/scripts/scripts.go`, a goroutine spools stderr to memory while stdout is streamed line by line, and the spooled stderr is logged after stdout EOF. This keeps the existing stdout-then-stderr output order (no interleaving), so observable output is unchanged for hooks that complete today. The line logging loop is extracted into a `logOutput` helper and still emits a final line without a trailing newline. ## Test plan - [x] New unit test `TestExecuteLargeStderrOutputDoesNotDeadlock` writes well over the pipe buffer to stderr before touching stdout; verified it deadlocks against the previous implementation (killed by the test context after 60s) and passes in ~0.05s with the fix - [x] `go test -race ./bundle/scripts` passes, including the existing no-trailing-newline test - [x] Acceptance tests under `acceptance/bundle/scripts` pass for both engines with no output changes - [x] `./task fmt-q`, `./task lint-q`, `./task checks` all clean This pull request and its description were written by Isaac.
1 parent 26d315c commit 0437746

2 files changed

Lines changed: 66 additions & 16 deletions

File tree

bundle/scripts/scripts.go

Lines changed: 29 additions & 16 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@ package scripts
22

33
import (
44
"bufio"
5+
"bytes"
56
"context"
67
"errors"
78
"fmt"
@@ -43,13 +44,37 @@ func (m *script) Apply(ctx context.Context, b *bundle.Bundle) diag.Diagnostics {
4344
return diag.FromErr(err)
4445
}
4546

46-
cmd, out, err := executeHook(ctx, executor, command)
47+
cmd, err := executeHook(ctx, executor, command)
4748
if err != nil {
4849
return diag.FromErr(fmt.Errorf("failed to execute script: %w", err))
4950
}
5051

5152
cmdio.LogString(ctx, fmt.Sprintf("Executing '%s' script", m.scriptHook))
5253

54+
// Reading the pipes sequentially deadlocks once the script fills the ~64KiB
55+
// stderr pipe buffer while stdout is still open, so drain stderr concurrently.
56+
// Spooling it to memory preserves the stdout-then-stderr output order.
57+
var stderr bytes.Buffer
58+
stderrDone := make(chan struct{})
59+
go func() {
60+
defer close(stderrDone)
61+
_, _ = io.Copy(&stderr, cmd.Stderr())
62+
}()
63+
64+
logOutput(ctx, cmd.Stdout())
65+
<-stderrDone
66+
logOutput(ctx, &stderr)
67+
68+
err = cmd.Wait()
69+
if err != nil {
70+
return diag.FromErr(fmt.Errorf("failed to execute script: %w", err))
71+
}
72+
73+
return nil
74+
}
75+
76+
// logOutput logs output line by line, including a final line without a trailing newline.
77+
func logOutput(ctx context.Context, out io.Reader) {
5378
reader := bufio.NewReader(out)
5479
for {
5580
line, err := reader.ReadString('\n')
@@ -60,27 +85,15 @@ func (m *script) Apply(ctx context.Context, b *bundle.Bundle) diag.Diagnostics {
6085
break
6186
}
6287
}
63-
64-
err = cmd.Wait()
65-
if err != nil {
66-
return diag.FromErr(fmt.Errorf("failed to execute script: %w", err))
67-
}
68-
69-
return nil
7088
}
7189

72-
func executeHook(ctx context.Context, executor *exec.Executor, command config.Command) (exec.Command, io.Reader, error) {
90+
func executeHook(ctx context.Context, executor *exec.Executor, command config.Command) (exec.Command, error) {
7391
// Don't run any arbitrary code when restricted execution is enabled.
7492
if _, ok := env.RestrictedExecution(ctx); ok {
75-
return nil, nil, errors.New("running scripts is not allowed when DATABRICKS_BUNDLE_RESTRICTED_CODE_EXECUTION is set")
76-
}
77-
78-
cmd, err := executor.StartCommand(ctx, string(command))
79-
if err != nil {
80-
return nil, nil, err
93+
return nil, errors.New("running scripts is not allowed when DATABRICKS_BUNDLE_RESTRICTED_CODE_EXECUTION is set")
8194
}
8295

83-
return cmd, io.MultiReader(cmd.Stdout(), cmd.Stderr()), nil
96+
return executor.StartCommand(ctx, string(command))
8497
}
8598

8699
func getCommand(b *bundle.Bundle, hook config.ScriptHook) config.Command {

bundle/scripts/scripts_test.go

Lines changed: 37 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,8 +1,11 @@
11
package scripts_test
22

33
import (
4+
"context"
45
"runtime"
6+
"strings"
57
"testing"
8+
"time"
69

710
"github.com/databricks/cli/bundle"
811
"github.com/databricks/cli/bundle/config"
@@ -38,3 +41,37 @@ func TestExecuteOutputWithoutTrailingNewline(t *testing.T) {
3841
assert.Contains(t, output, "line2")
3942
assert.Contains(t, output, "last line without newline")
4043
}
44+
45+
func TestExecuteLargeStderrOutputDoesNotDeadlock(t *testing.T) {
46+
if runtime.GOOS == "windows" {
47+
t.Skip("skipping on windows")
48+
}
49+
50+
dir := t.TempDir()
51+
b := &bundle.Bundle{
52+
BundleRootPath: dir,
53+
Config: config.Root{
54+
Experimental: &config.Experimental{
55+
Scripts: map[config.ScriptHook]config.Command{
56+
// Overflows the ~64KiB stderr pipe buffer before stdout
57+
// closes, which deadlocked the old sequential draining.
58+
config.ScriptPreInit: "seq 100000 | tr -d '\\n' >&2; echo stdout-after-stderr",
59+
},
60+
},
61+
},
62+
}
63+
64+
// A reintroduced deadlock fails fast: the context timeout kills the script.
65+
ctx, cancel := context.WithTimeout(t.Context(), time.Minute)
66+
defer cancel()
67+
68+
ctx, stderr := cmdio.NewTestContextWithStderr(ctx)
69+
diags := bundle.Apply(ctx, b, scripts.Execute(config.ScriptPreInit))
70+
require.NoError(t, diags.Error())
71+
72+
output := stderr.String()
73+
assert.Contains(t, output, "99999100000")
74+
assert.Contains(t, output, "stdout-after-stderr")
75+
// The script writes stderr first, but spooling preserves the stdout-then-stderr order.
76+
assert.Less(t, strings.Index(output, "stdout-after-stderr"), strings.Index(output, "99999100000"))
77+
}

0 commit comments

Comments
 (0)