From 87790b90428206e2c228748c9df46d3a26ac166d Mon Sep 17 00:00:00 2001 From: "pulse-triage[bot]" <249995291+pulse-triage[bot]@users.noreply.github.com> Date: Mon, 5 Oct 2026 05:39:25 +0100 Subject: [PATCH] Separate copied-guidance preparation, request and cleanup deadlines A bounded synthetic comparison shows the whole-shell watchdog can kill a POST before its own curl deadline or expire before a PBS request starts. Observe each phase privately, preserve curl arguments and exact request limits, cancel owned descendants and retain incomplete pipe results. Exercise delayed preparation, one-shot transport, private responses and every cancellation phase without changing any guide or runtime. Contract-Neutral: Repair Bash documentation test timing and owned-child observation only; no guide, mirror, runtime, API, authentication, request deadline, dependency or permission contract changes. Change-source: pulse-maintainer --- scripts/installtests/api_guidance_test.go | 37 +- .../guidance_recipe_runner_test.go | 328 ++++++++++++++++++ scripts/installtests/pbs_api_guidance_test.go | 32 +- 3 files changed, 359 insertions(+), 38 deletions(-) create mode 100644 scripts/installtests/guidance_recipe_runner_test.go diff --git a/scripts/installtests/api_guidance_test.go b/scripts/installtests/api_guidance_test.go index f8f461a8f1..951049acb8 100644 --- a/scripts/installtests/api_guidance_test.go +++ b/scripts/installtests/api_guidance_test.go @@ -1,7 +1,8 @@ +//go:build !windows + package installtests import ( - "context" "encoding/pem" "fmt" "io" @@ -59,24 +60,11 @@ func pulseAPIReference(t *testing.T) (string, string, []string) { func runPulseAPIRecipe(t *testing.T, script, home, bin string, extraEnv ...string) (string, int) { t.Helper() - ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second) - defer cancel() - cmd := exec.CommandContext(ctx, "bash", "-c", script) - cmd.Env = append(os.Environ(), "HOME="+home, "PATH="+bin+":"+os.Getenv("PATH"), - "http_proxy=", "HTTP_PROXY=", "https_proxy=", "HTTPS_PROXY=", "ALL_PROXY=", "all_proxy=", "NO_PROXY=", "no_proxy=") - cmd.Env = append(cmd.Env, extraEnv...) - out, err := cmd.CombinedOutput() - if ctx.Err() != nil { - t.Fatal("API recipe exceeded the test watchdog; its own deadline did not complete") + result, err := observeGuidanceRecipe(t, script, home, bin, guidanceRecipeLimits(20*time.Second), extraEnv...) + if err != nil { + t.Fatalf("API recipe observation failed: %v; %s", err, result.summary()) } - if err == nil { - return string(out), 0 - } - if failure, ok := err.(*exec.ExitError); ok { - return string(out), failure.ExitCode() - } - t.Fatal(err) - return "", -1 + return result.output, result.exit } func TestPulseAPIGuidancePreparationIsPrivateAndFailClosed(t *testing.T) { @@ -413,9 +401,16 @@ func TestPulseAPIGuidanceTimedOutPOSTIsNotRepeated(t *testing.T) { // Use the actual documented twenty-second limit, not a test-only shortened // deadline. An execution endpoint can have acted even when this read fails. helper = strings.Replace(helper, "http://127.0.0.1:7655", server.URL, 1) - start := time.Now() - output, exit := runPulseAPIRecipe(t, helper+"\n"+calls[5], home, bin) - if exit != 28 || time.Since(start) > 25*time.Second || len(requests) != 1 { + // A deliberate preparation delay exceeds the old whole-shell comparison + // once added to the actual twenty-second request. It must not shorten curl's + // limit or be mistaken for request time. + result, err := observeGuidanceRecipe(t, "sleep 12\n"+helper+"\n"+calls[5], home, bin, guidanceRecipeLimits(20*time.Second)) + if err != nil { + t.Fatalf("timed-out POST observation failed: %v; %s", err, result.summary()) + } + t.Log(result.summary()) + output, exit := result.output, result.exit + if exit != 28 || result.request > 25*time.Second || result.curlStarts != 1 || result.curlEnds != 1 || len(requests) != 1 { t.Fatal("POST did not stop at its request deadline or was retried") } if strings.Contains(output, "private-partial-response") || strings.Contains(output, "synthetic-timeout-secret") { diff --git a/scripts/installtests/guidance_recipe_runner_test.go b/scripts/installtests/guidance_recipe_runner_test.go new file mode 100644 index 0000000000..234fa02c98 --- /dev/null +++ b/scripts/installtests/guidance_recipe_runner_test.go @@ -0,0 +1,328 @@ +//go:build !windows + +package installtests + +import ( + "bufio" + "bytes" + "context" + "errors" + "fmt" + "os" + "os/exec" + "path/filepath" + "strconv" + "strings" + "syscall" + "testing" + "time" +) + +type guidanceLimits struct{ preparation, request, completion time.Duration } + +func guidanceRecipeLimits(requestLimit time.Duration) guidanceLimits { + // These are fixture watchdogs, not changed request limits. The five-second + // margin observes curl's own terminal result; preparation and subsequent + // shell work cannot consume the documented request budget. + return guidanceLimits{30 * time.Second, requestLimit + 5*time.Second, 5 * time.Second} +} + +type guidanceObservation struct { + output string + exit, curlStarts, curlEnds int + preparation, request, completion time.Duration + phase string + signal string + terminal, outputComplete bool +} + +func (r guidanceObservation) summary() string { + // Never put recipe output, argv, credentials or response bodies in phase + // diagnostics. Independent synthetic peers still check HTTP request counts. + return fmt.Sprintf("phase=%s preparation=%s request=%s completion=%s curl_starts=%d curl_ends=%d bash_exit=%d bash_signal=%s terminal=%t output_complete=%t", + r.phase, r.preparation, r.request, r.completion, r.curlStarts, r.curlEnds, r.exit, r.signal, r.terminal, r.outputComplete) +} + +// Observe copied Bash recipes without rewriting their curl arguments. The shim +// calls the existing PATH fixture (or real curl), preserving its argv capture, +// output, TLS, privacy, request deadlines and exit status. A dedicated pipe +// carries only two fixed phase markers, never public stdout or private data. +func observeGuidanceRecipe(t *testing.T, script, home, bin string, limits guidanceLimits, extraEnv ...string) (result guidanceObservation, resultErr error) { + t.Helper() + result.exit, result.phase = -1, "preparation" + curl := filepath.Join(bin, "curl") + if _, err := os.Stat(curl); os.IsNotExist(err) { + curl, err = exec.LookPath("curl") + if err != nil { + return result, errors.New("curl is required for copied guidance") + } + } else if err != nil { + return result, err + } + shimDir := t.TempDir() + const shim = `#!/bin/sh +printf 'curl-start\n' >&3 +"$PULSE_GUIDANCE_CURL" "$@" +curl_exit=$? +printf 'curl-end %d\n' "$curl_exit" >&3 +exit "$curl_exit" +` + if err := os.WriteFile(filepath.Join(shimDir, "curl"), []byte(shim), 0700); err != nil { + return result, err + } + reader, writer, err := os.Pipe() + if err != nil { + return result, err + } + defer reader.Close() + defer writer.Close() + ctx, cancel := context.WithCancel(context.Background()) + defer cancel() + cmd := exec.CommandContext(ctx, "bash", "-c", script) + cmd.SysProcAttr = &syscall.SysProcAttr{Setpgid: true} + cmd.Cancel = func() error { + err := syscall.Kill(-cmd.Process.Pid, syscall.SIGKILL) + if errors.Is(err, syscall.ESRCH) { + return os.ErrProcessDone + } + return err + } + // Killing only Bash can leave curl holding CombinedOutput pipes open. Kill + // this fixture's entire process group and bound pipe drainage separately. + cmd.WaitDelay = 2 * time.Second + cmd.ExtraFiles = []*os.File{writer} + cmd.Env = append(os.Environ(), "HOME="+home, "PATH="+shimDir+":"+bin+":"+os.Getenv("PATH"), + "http_proxy=", "HTTP_PROXY=", "https_proxy=", "HTTPS_PROXY=", "ALL_PROXY=", "all_proxy=", "NO_PROXY=", "no_proxy=") + cmd.Env = append(cmd.Env, extraEnv...) + cmd.Env = append(cmd.Env, "PULSE_GUIDANCE_CURL="+curl) + var output bytes.Buffer + cmd.Stdout, cmd.Stderr = &output, &output + started := time.Now() + if err := cmd.Start(); err != nil { + return result, err + } + _ = writer.Close() + type event struct { + line string + at time.Time + } + events := make(chan event, 4) + go func() { + defer close(events) + scanner := bufio.NewScanner(reader) + scanner.Buffer(make([]byte, 128), 128) + for scanner.Scan() { + select { + case events <- event{scanner.Text(), time.Now()}: + case <-ctx.Done(): + return + } + } + if scanner.Err() != nil { + select { + case events <- event{"phase-pipe-error", time.Now()}: + case <-ctx.Done(): + } + } + }() + done := make(chan error, 1) + go func() { done <- cmd.Wait() }() + timer := time.NewTimer(limits.preparation) + defer timer.Stop() + phaseStarted := started + reset := func(d time.Duration) { + if !timer.Stop() { + select { + case <-timer.C: + default: + } + } + timer.Reset(d) + } + observe := func(e event) error { + switch { + case e.line == "curl-start" && result.phase == "preparation": + result.curlStarts++ + result.preparation = e.at.Sub(started) + phaseStarted, result.phase = e.at, "request" + reset(limits.request) + case strings.HasPrefix(e.line, "curl-end ") && result.phase == "request": + if _, err := strconv.Atoi(strings.TrimPrefix(e.line, "curl-end ")); err != nil { + return errors.New("invalid curl terminal marker") + } + result.curlEnds++ + result.request = e.at.Sub(phaseStarted) + phaseStarted, result.phase = e.at, "completion" + reset(limits.completion) + default: + return errors.New("unexpected or repeated curl phase marker") + } + return nil + } + for { + select { + case e, open := <-events: + if !open { + events = nil + } else if err := observe(e); err != nil { + resultErr = err + cancel() + } + case <-timer.C: + resultErr = fmt.Errorf("%s fixture watchdog expired", result.phase) + cancel() + case err := <-done: + // Wait may win the select after a fast request. Collect its already + // written markers before evaluating the final observation. + if errors.Is(err, exec.ErrWaitDelay) { + _ = cmd.Cancel() + } + markerTimer := time.NewTimer(2 * time.Second) + for events != nil { + select { + case e, open := <-events: + if !open { + events = nil + } else if eventErr := observe(e); eventErr != nil && resultErr == nil { + resultErr = eventErr + } + case <-markerTimer.C: + _ = cmd.Cancel() + _ = reader.Close() + cancel() + if resultErr == nil { + resultErr = errors.New("phase-pipe collection did not complete") + } + events = nil + } + } + markerTimer.Stop() + result.output, result.exit, result.terminal = output.String(), cmd.ProcessState.ExitCode(), true + if state, ok := cmd.ProcessState.Sys().(syscall.WaitStatus); ok && state.Signaled() { + result.signal = state.Signal().String() + } + result.outputComplete = !errors.Is(err, exec.ErrWaitDelay) + switch result.phase { + case "preparation": + result.preparation = time.Since(started) + case "request": + result.request = time.Since(phaseStarted) + case "completion": + result.completion = time.Since(phaseStarted) + } + var exitError *exec.ExitError + if err != nil && !errors.As(err, &exitError) && resultErr == nil { + resultErr = err + } + if resultErr == nil && result.curlStarts != result.curlEnds { + resultErr = errors.New("missing curl terminal observation") + } + return result, resultErr + } + } +} + +func guidanceRunnerFixture(t *testing.T, curlScript string) (home, bin, childFile string) { + t.Helper() + home, bin = t.TempDir(), t.TempDir() + if err := os.WriteFile(filepath.Join(bin, "curl"), []byte("#!/bin/sh\n"+curlScript), 0700); err != nil { + t.Fatal(err) + } + return home, bin, filepath.Join(home, "child-pid") +} + +func guidanceRunnerChildStopped(t *testing.T, childFile string) { + t.Helper() + data, err := os.ReadFile(childFile) + if err != nil { + t.Fatalf("owned child identity missing: %v", err) + } + pid, err := strconv.Atoi(strings.TrimSpace(string(data))) + if err != nil || pid <= 1 { + t.Fatal("invalid owned child identity") + } + deadline := time.Now().Add(2 * time.Second) + for { + if err := syscall.Kill(pid, 0); errors.Is(err, syscall.ESRCH) { + return + } + if time.Now().After(deadline) { + t.Fatal("owned child remains after fixture cancellation") + } + time.Sleep(10 * time.Millisecond) + } +} + +func TestGuidanceRecipeRunnerSeparatesPreparationFromCurl(t *testing.T) { + home, bin, _ := guidanceRunnerFixture(t, "printf 'synthetic-private-response'; exit 22\n") + limits := guidanceLimits{2 * time.Second, 200 * time.Millisecond, time.Second} + result, err := observeGuidanceRecipe(t, "sleep 0.5\ncurl --disable --max-time 15", home, bin, limits) + if err != nil || result.exit != 22 || result.curlStarts != 1 || result.curlEnds != 1 || result.preparation < 500*time.Millisecond || result.request >= limits.request || !result.terminal || !result.outputComplete { + t.Fatalf("preparation consumed curl budget or changed terminal result: %v; %s", err, result.summary()) + } + if result.output != "synthetic-private-response" || strings.Contains(result.summary(), "synthetic-private") { + t.Fatal("observer changed output or disclosed it in phase diagnostics") + } +} + +func TestGuidanceRecipeRunnerBoundsEachPhaseAndStopsOwnedChildren(t *testing.T) { + const child = "sleep 60 & child=$!; printf '%s\\n' \"$child\" > \"$CHILD_FILE\"; wait\n" + for _, phase := range []string{"preparation", "request", "completion"} { + t.Run(phase, func(t *testing.T) { + curlScript, recipe := "exit 0\n", child + if phase == "request" { + curlScript, recipe = child, "curl --disable" + } else if phase == "completion" { + recipe = "curl --disable\n" + child + } + home, bin, childFile := guidanceRunnerFixture(t, curlScript) + limits := guidanceLimits{2 * time.Second, 2 * time.Second, 2 * time.Second} + switch phase { + case "preparation": + limits.preparation = 500 * time.Millisecond + case "request": + limits.request = 500 * time.Millisecond + case "completion": + limits.completion = 500 * time.Millisecond + } + started := time.Now() + result, err := observeGuidanceRecipe(t, recipe, home, bin, limits, "CHILD_FILE="+childFile) + if err == nil || !strings.Contains(err.Error(), phase+" fixture watchdog expired") || result.phase != phase || result.exit != -1 || result.signal != "killed" || !result.terminal || !result.outputComplete || time.Since(started) > 4*time.Second { + t.Fatalf("phase did not reach bounded terminal observation: %v; %s", err, result.summary()) + } + if phase == "preparation" && result.curlStarts != 0 || phase != "preparation" && result.curlStarts != 1 { + t.Fatal("request admission attribution is wrong") + } + guidanceRunnerChildStopped(t, childFile) + }) + } +} + +func TestGuidanceRecipeRunnerRejectsDuplicateAndPrivateMarkers(t *testing.T) { + for _, recipe := range []string{"curl --disable\ncurl --disable", "printf 'synthetic-private-marker\\n' >&3", "printf '%0200d\\n' 0 >&3"} { + home, bin, _ := guidanceRunnerFixture(t, "exit 0\n") + result, err := observeGuidanceRecipe(t, recipe, home, bin, guidanceLimits{time.Second, time.Second, time.Second}) + if err == nil || strings.Contains(err.Error(), "synthetic-private") || strings.Contains(result.summary(), "synthetic-private") { + t.Fatalf("invalid phase protocol accepted or disclosed: %v; %s", err, result.summary()) + } + } +} + +func TestGuidanceRecipeRunnerRetainsIncompletePipeResult(t *testing.T) { + home, bin, childFile := guidanceRunnerFixture(t, "exit 0\n") + recipe := "sleep 60 & child=$!; printf '%s\\n' \"$child\" > \"$CHILD_FILE\"; printf done\n" + result, err := observeGuidanceRecipe(t, recipe, home, bin, guidanceLimits{10 * time.Second, time.Second, time.Second}, "CHILD_FILE="+childFile) + if !errors.Is(err, exec.ErrWaitDelay) || result.outputComplete || !result.terminal || result.exit != 0 { + t.Fatalf("incomplete output became a pass: %v; %s", err, result.summary()) + } + guidanceRunnerChildStopped(t, childFile) +} + +func TestGuidanceRecipeRunnerWatchdogsPreserveDocumentedLimits(t *testing.T) { + for _, duration := range []time.Duration{15 * time.Second, 20 * time.Second, 60 * time.Second} { + limits := guidanceRecipeLimits(duration) + if limits.request != duration+5*time.Second || limits.preparation != 30*time.Second || limits.completion != 5*time.Second { + t.Fatal("fixture phases no longer leave the documented curl limit intact") + } + } +} diff --git a/scripts/installtests/pbs_api_guidance_test.go b/scripts/installtests/pbs_api_guidance_test.go index ddeca21d09..46e6b2a245 100644 --- a/scripts/installtests/pbs_api_guidance_test.go +++ b/scripts/installtests/pbs_api_guidance_test.go @@ -1,7 +1,8 @@ +//go:build !windows + package installtests import ( - "context" "encoding/pem" "fmt" "io" @@ -104,24 +105,15 @@ func pbsAPIGuidance(t *testing.T) [4]string { func runPBSRecipe(t *testing.T, recipe, home, bin string, extraEnv ...string) (string, int) { t.Helper() - ctx, cancel := context.WithTimeout(context.Background(), 25*time.Second) - defer cancel() - cmd := exec.CommandContext(ctx, "bash", "-c", recipe) - cmd.Env = append(os.Environ(), "HOME="+home, "PATH="+bin+":"+os.Getenv("PATH"), - "http_proxy=", "HTTP_PROXY=", "https_proxy=", "HTTPS_PROXY=", "ALL_PROXY=", "all_proxy=", "NO_PROXY=", "no_proxy=") - cmd.Env = append(cmd.Env, extraEnv...) - output, err := cmd.CombinedOutput() - if ctx.Err() != nil { - t.Fatal("copied PBS recipe exceeded its bounded test deadline") + requestLimit := 15 * time.Second + if strings.Contains(recipe, "--max-time 60") { + requestLimit = 60 * time.Second } - if err == nil { - return string(output), 0 + result, err := observeGuidanceRecipe(t, recipe, home, bin, guidanceRecipeLimits(requestLimit), extraEnv...) + if err != nil { + t.Fatalf("PBS recipe observation failed: %v; %s", err, result.summary()) } - failure, ok := err.(*exec.ExitError) - if !ok { - t.Fatal(err) - } - return string(output), failure.ExitCode() + return result.output, result.exit } func TestPBSAPIGuidancePreparationIsPrivateAndFailClosed(t *testing.T) { @@ -358,6 +350,12 @@ func TestPBSAPIGuidanceCopiedRequestsKeepSecretsPrivate(t *testing.T) { } recipe = strings.Replace(recipe, "curl --disable ", `curl --disable --cacert "$HOME/ca.pem" `, 1) } + if index == 0 && scenario == "wrong success status" { + // The old 25-second watchdog expired during this controlled + // preparation, before curl. Keep the real 60-second download + // limit and verify that HTTP 206 still cannot become an installer. + recipe = "sleep 26\n" + recipe + } output, exit := runPBSRecipe(t, recipe, home, bin, "PBS_ARGV="+capture, "PBS_CURL="+realCurl) wantExit := 0 switch scenario {