From 15037c6d80742b000f46dca754cdb309427df9f6 Mon Sep 17 00:00:00 2001 From: Eric Rakestraw Date: Mon, 4 May 2026 13:05:04 -0500 Subject: [PATCH] Add additional subprocess diagnostics for the audita interface --- internal/adapters/audita/subprocess.go | 20 +++++++++++-- internal/adapters/audita/subprocess_test.go | 33 +++++++++++++++++++++ internal/adapters/subprocess/run.go | 20 ++++++++++++- internal/adapters/subprocess/run_test.go | 32 ++++++++++++++++++++ 4 files changed, 102 insertions(+), 3 deletions(-) diff --git a/internal/adapters/audita/subprocess.go b/internal/adapters/audita/subprocess.go index 1d2834f..e45e630 100644 --- a/internal/adapters/audita/subprocess.go +++ b/internal/adapters/audita/subprocess.go @@ -189,11 +189,16 @@ func (r *SubprocessRunner) Run(ctx context.Context, req PolishRequest) (PolishRe StderrLogPath: req.StderrLogPath, }) if err != nil { - return r.failureResult(req, reqModules, runRes, credentialPresent, primaryConcurrencyViaEnv), fmt.Errorf( - "run audita process (binary=%q, stdout_log=%q, stderr_log=%q): %w", + wrappedMessage := fmt.Sprintf( + "run audita process (binary=%q, stdout_log=%q, stderr_log=%q)", r.binary, req.StdoutLogPath, req.StderrLogPath, + ) + wrappedMessage = addSubprocessStreamHint(wrappedMessage, err) + return r.failureResult(req, reqModules, runRes, credentialPresent, primaryConcurrencyViaEnv), fmt.Errorf( + "%s: %w", + wrappedMessage, err, ) } @@ -328,6 +333,17 @@ func validateProcessedOutput(path string) error { return nil } +func addSubprocessStreamHint(message string, runErr error) string { + if runErr == nil { + return message + } + lower := strings.ToLower(runErr.Error()) + if strings.Contains(lower, "bad file descriptor") || strings.Contains(lower, "exit code 120") { + return message + "; hint=audita child process may have started with invalid stderr/stdout descriptors" + } + return message +} + func validateJSONFile(path string) error { data, err := os.ReadFile(path) if err != nil { diff --git a/internal/adapters/audita/subprocess_test.go b/internal/adapters/audita/subprocess_test.go index a4448fc..9ce7cc9 100644 --- a/internal/adapters/audita/subprocess_test.go +++ b/internal/adapters/audita/subprocess_test.go @@ -247,6 +247,36 @@ func TestSubprocessRunnerSubprocessFailure(t *testing.T) { } } +func TestSubprocessRunnerSubprocessFailureAddsStderrDescriptorHint(t *testing.T) { + if runtime.GOOS == "windows" { + t.Skip("helper wrapper script uses /bin/sh") + } + t.Setenv("GO_WANT_AUDITA_HELPER", "1") + t.Setenv("AUDITA_HELPER_MODE", "fail_bad_fd") + t.Setenv("OPENAI_KEY_SOURCE", "super-secret") + t.Setenv("AUDITA_HELPER_RECORD_PATH", filepath.Join(t.TempDir(), "record.json")) + + llmConcurrency := 1 + runner := mustAuditaRunner(t, SubprocessRunnerConfig{ + Binary: writeAuditaHelperWrapper(t), + Timeout: mustParseAuditaDuration(t, "2s"), + LLMAPIKeyEnv: "OPENAI_KEY_SOURCE", + Modules: []string{"glossary"}, + BaseURL: "https://openrouter.ai/api/v1", + Model: "openrouter/google/gemma-4-31b-it", + LLMConcurrency: &llmConcurrency, + Report: true, + }) + req := auditaReqForTest(t, true) + _, err := runner.Run(context.Background(), req) + if err == nil { + t.Fatal("expected error, got nil") + } + if !strings.Contains(err.Error(), "hint=audita child process may have started with invalid stderr/stdout descriptors") { + t.Fatalf("error = %q, want stderr descriptor hint", err.Error()) + } +} + func TestSubprocessRunnerMissingOutputFails(t *testing.T) { if runtime.GOOS == "windows" { t.Skip("helper wrapper script uses /bin/sh") @@ -442,6 +472,9 @@ func TestAuditaSubprocessHelper(t *testing.T) { case "fail": _, _ = os.Stderr.WriteString("audita helper failure\n") os.Exit(8) + case "fail_bad_fd": + _, _ = os.Stderr.WriteString("OSError: [Errno 9] Bad file descriptor\n") + os.Exit(120) case "missing_output": if reportPath != "" { writeAuditaHelperFile(reportPath, `{"schema":"audita.report.v1","steps":[]}`) diff --git a/internal/adapters/subprocess/run.go b/internal/adapters/subprocess/run.go index 0f8f9de..e6767e5 100644 --- a/internal/adapters/subprocess/run.go +++ b/internal/adapters/subprocess/run.go @@ -276,9 +276,27 @@ func buildDiagnostics(req RunRequest, result RunResult, stderrTail string) strin req.StderrLogPath, ) if strings.TrimSpace(stderrTail) == "" { + if hint := fdDiagnosticsHint(result.ExitCode, ""); hint != "" { + return details + fmt.Sprintf(" hint=%q", hint) + } return details } - return details + fmt.Sprintf(" stderr_tail=%q", stderrTail) + details = details + fmt.Sprintf(" stderr_tail=%q", stderrTail) + if hint := fdDiagnosticsHint(result.ExitCode, stderrTail); hint != "" { + details = details + fmt.Sprintf(" hint=%q", hint) + } + return details +} + +func fdDiagnosticsHint(exitCode int, stderrTail string) string { + lowerTail := strings.ToLower(stderrTail) + if strings.Contains(lowerTail, "bad file descriptor") || strings.Contains(lowerTail, "errno 9") { + return "stderr stream appears invalid in child process (fd 2); check wrapper/subprocess environment differences versus direct shell execution" + } + if exitCode == 120 { + return "exit code 120 may indicate interpreter shutdown stream-flush failures (commonly invalid stdout/stderr descriptors in Python processes)" + } + return "" } func readRedactedTail(path string, envOverrides map[string]string, maxBytes int64) string { diff --git a/internal/adapters/subprocess/run_test.go b/internal/adapters/subprocess/run_test.go index e47aa0f..42cc538 100644 --- a/internal/adapters/subprocess/run_test.go +++ b/internal/adapters/subprocess/run_test.go @@ -122,6 +122,35 @@ func TestRunFailureRedactsSensitiveTail(t *testing.T) { } } +func TestRunFailureAddsBadDescriptorHint(t *testing.T) { + exe, err := os.Executable() + if err != nil { + t.Fatalf("os.Executable() error = %v", err) + } + + dir := t.TempDir() + req := RunRequest{ + Executable: exe, + Args: []string{"-test.run=TestSubprocessHelper", "--", "failbadfd"}, + EnvOverrides: map[string]string{ + "GO_WANT_SUBPROCESS_HELPER": "1", + }, + StdoutLogPath: filepath.Join(dir, "stdout.log"), + StderrLogPath: filepath.Join(dir, "stderr.log"), + } + + _, err = Run(context.Background(), req) + if err == nil { + t.Fatal("Run() error = nil, want non-nil") + } + if !strings.Contains(err.Error(), "Bad file descriptor") { + t.Fatalf("error = %q, want stderr tail content", err.Error()) + } + if !strings.Contains(err.Error(), "stderr stream appears invalid in child process") { + t.Fatalf("error = %q, want bad-descriptor hint", err.Error()) + } +} + func TestRunTimeout(t *testing.T) { exe, err := os.Executable() if err != nil { @@ -329,6 +358,9 @@ func TestSubprocessHelper(t *testing.T) { key := os.Getenv("SUBPROCESS_HELPER_ENV_KEY") _, _ = os.Stderr.WriteString("secret:" + os.Getenv(key) + "\n") os.Exit(4) + case "failbadfd": + _, _ = os.Stderr.WriteString("OSError: [Errno 9] Bad file descriptor\n") + os.Exit(120) case "sleep": time.Sleep(500 * time.Millisecond) os.Exit(0)