diff --git a/cmd/daily_run.go b/cmd/daily_run.go index 9b17183..1189362 100644 --- a/cmd/daily_run.go +++ b/cmd/daily_run.go @@ -244,6 +244,9 @@ func explainAgentOutcome(res *agent.RunResult, statErr error) error { } else { fmt.Fprintf(&b, "\nagent said: ") } + if res.SubprocessStderr != "" { + fmt.Fprintf(&b, "\nclaude stderr: %s", truncateText(res.SubprocessStderr, 2000)) + } return errors.New(b.String()) } diff --git a/cmd/daily_run_test.go b/cmd/daily_run_test.go index 5004172..eb1db0d 100644 --- a/cmd/daily_run_test.go +++ b/cmd/daily_run_test.go @@ -491,6 +491,23 @@ func TestRunDaily_AgentTextTruncated(t *testing.T) { assert.Less(t, len(msg), 2000, "error message should be bounded") } +// Subprocess stderr captured by the SDK is surfaced in the +// verification-failure error so the operator can see what claude +// actually wrote before exiting. +func TestRunDaily_VerificationErrorIncludesSubprocessStderr(t *testing.T) { + deps, gatherer, runtime, _ := fixtureDeps(t) + gatherer.issues = []domain.Issue{{Ref: domain.ExternalRef{Provider: "linear", ID: "X"}, Title: "x"}} + + runtime.result = &agent.RunResult{ + SubprocessStderr: "Error: unknown flag --bogus", + } + + _, err := runDaily(context.Background(), deps, dailyOptions{}) + require.Error(t, err) + assert.Contains(t, err.Error(), "claude stderr:") + assert.Contains(t, err.Error(), "unknown flag --bogus") +} + // Turns, duration, and cost from the SDK are surfaced so the operator // can tell whether the model was consulted at all when both tool // calls and text are empty. diff --git a/internal/agent/run.go b/internal/agent/run.go index 3031987..abe88c8 100644 --- a/internal/agent/run.go +++ b/internal/agent/run.go @@ -4,10 +4,15 @@ import ( "context" "errors" "fmt" + "io" + "sort" "strings" + "sync" "time" claude "github.com/partio-io/claude-agent-sdk-go" + + "github.com/rebelopsio/archy/internal/config" ) // RunRequest describes a single skill execution. @@ -45,6 +50,10 @@ type RunResult struct { // CostUSD is the model's reported cost for this run, if available. // Zero means unknown. CostUSD float64 + // SubprocessStderr is everything the claude CLI subprocess wrote + // to its stderr during this run, joined newline-per-callback. + // Empty when the subprocess produced no stderr output. + SubprocessStderr string } // ToolCallRecord is one tool invocation observed during a run. @@ -85,6 +94,23 @@ func (r *Runtime) Run(ctx context.Context, req RunRequest) (*RunResult, error) { } opts = append(opts, claude.WithAppendSystemPrompt(systemPromptAddition(req))) + // Capture the claude CLI subprocess's stderr so silent-failure + // modes (subprocess exits before consulting the model) surface + // the underlying error. The callback fires from the SDK's drain + // goroutine, so guard the buffer with a mutex. + var ( + stderrMu sync.Mutex + stderrBuf strings.Builder + ) + opts = append(opts, claude.WithStderrCallback(func(line string) { + stderrMu.Lock() + defer stderrMu.Unlock() + stderrBuf.WriteString(line) + stderrBuf.WriteByte('\n') + })) + + logSDKInvocation(r.stderrLog, r.cfg, r.opts, opts, req) + emit := func(ev ProgressEvent) { if req.ProgressFn != nil { req.ProgressFn(ev) @@ -95,6 +121,14 @@ func (r *Runtime) Run(ctx context.Context, req RunRequest) (*RunResult, error) { emit(ProgressEvent{Kind: ProgressStart, At: start}) res := &RunResult{} + // readStderr returns the captured subprocess output. Called on + // every return path so RunResult.SubprocessStderr is always + // populated (empty when nothing was written). + readStderr := func() string { + stderrMu.Lock() + defer stderrMu.Unlock() + return stderrBuf.String() + } pending := make(map[string]*ToolCallRecord) // tool_use_id → in-flight record var assistantText strings.Builder systemSeen := false @@ -105,6 +139,11 @@ func (r *Runtime) Run(ctx context.Context, req RunRequest) (*RunResult, error) { if ctx.Err() != nil && (errors.Is(err, context.Canceled) || errors.Is(err, context.DeadlineExceeded)) { return nil, fmt.Errorf("agent run canceled: %w", ctx.Err()) } + // Surface the subprocess stderr alongside the SDK error so + // the operator sees what claude actually said before exiting. + if s := readStderr(); s != "" { + return nil, fmt.Errorf("%w: %v (claude stderr: %s)", ErrRun, err, s) + } return nil, fmt.Errorf("%w: %v", ErrRun, err) } if ctx.Err() != nil { @@ -143,6 +182,7 @@ func (r *Runtime) Run(ctx context.Context, req RunRequest) (*RunResult, error) { emit(ProgressEvent{Kind: ProgressEnd, Message: endMsg, At: time.Now()}) res.Text = assistantText.String() res.Duration = time.Since(start) + res.SubprocessStderr = readStderr() return res, fmt.Errorf("%w: %s", ErrRun, endMsg) } } @@ -150,10 +190,39 @@ func (r *Runtime) Run(ctx context.Context, req RunRequest) (*RunResult, error) { res.Text = assistantText.String() res.Duration = time.Since(start) + res.SubprocessStderr = readStderr() emit(ProgressEvent{Kind: ProgressEnd, Message: "completed", At: time.Now()}) return res, nil } +// logSDKInvocation writes a one-time summary of the agent invocation +// to w. This is the last thing archy controls before subprocess +// handoff; if claude exits without consulting the model, the answer +// is almost certainly in what we passed it. Secrets (bearer tokens, +// auth headers) are never logged. +func logSDKInvocation(w io.Writer, cfg *config.Config, opts Options, sdkOpts []claude.Option, req RunRequest) { + mcpEnabled := []string{} + for name, srv := range cfg.MCPServers { + if srv.Enabled { + mcpEnabled = append(mcpEnabled, name) + } + } + sort.Strings(mcpEnabled) + + _, _ = fmt.Fprintln(w, "archy agent invocation:") + _, _ = fmt.Fprintf(w, " skill=%s\n", req.SkillName) + _, _ = fmt.Fprintf(w, " model=%s\n", cfg.Agent.Model) + _, _ = fmt.Fprintf(w, " max_turns=%d\n", cfg.Agent.MaxTurns) + _, _ = fmt.Fprintf(w, " permission_mode=%s\n", cfg.Agent.PermissionMode) + _, _ = fmt.Fprintf(w, " cwd=%s\n", opts.Cwd) + _, _ = fmt.Fprintf(w, " cli_path=%s\n", opts.CLIPath) + _, _ = fmt.Fprintf(w, " archy_binary=%s\n", opts.ArchyBinaryPath) + _, _ = fmt.Fprintf(w, " sdk_option_count=%d\n", len(sdkOpts)) + _, _ = fmt.Fprintf(w, " mcp_servers_enabled=%v\n", mcpEnabled) + _, _ = fmt.Fprintf(w, " skills_project_dir=%s\n", cfg.Skills.ProjectDir) + _, _ = fmt.Fprintf(w, " skills_user_dir=%s\n", cfg.Skills.UserDir) +} + // systemPromptAddition is the one-line skill-invocation instruction the // runtime appends via [claude.WithAppendSystemPrompt]. Skill authors // can rely on the agent seeing this exact phrasing. diff --git a/internal/agent/runtime.go b/internal/agent/runtime.go index 99c6f9f..189efcf 100644 --- a/internal/agent/runtime.go +++ b/internal/agent/runtime.go @@ -3,6 +3,7 @@ package agent import ( "context" "fmt" + "io" "iter" "os" "sync" @@ -23,6 +24,11 @@ type Runtime struct { // the iter.Seq2 yielded by Stream. runner runner + // stderrLog is where the agent writes operational diagnostic lines + // (SDK invocation summary, subprocess stderr). Defaults to + // os.Stderr; tests override with io.Discard or a buffer. + stderrLog io.Writer + // closeOnce guards Close from being called multiple times. closeOnce sync.Once } @@ -75,9 +81,10 @@ func New(opts Options) (*Runtime, error) { } return &Runtime{ - cfg: opts.Config, - opts: opts, - runner: realRunner{}, + cfg: opts.Config, + opts: opts, + runner: realRunner{}, + stderrLog: os.Stderr, }, nil } diff --git a/internal/agent/runtime_test.go b/internal/agent/runtime_test.go index c5007d7..38be8bd 100644 --- a/internal/agent/runtime_test.go +++ b/internal/agent/runtime_test.go @@ -3,6 +3,7 @@ package agent import ( "context" "errors" + "io" "iter" "testing" "time" @@ -54,6 +55,8 @@ func (f *fakeRunner) run(ctx context.Context, prompt string, opts []claude.Optio // newTestRuntime returns a Runtime with a baseline-valid config and a // substituted fake runner. The caller drives the fakeRunner's messages. +// stderrLog is replaced with io.Discard to keep test output quiet — +// the invocation log fires on every Run. func newTestRuntime(t *testing.T, fr *fakeRunner) *Runtime { t.Helper() rt, err := New(Options{ @@ -63,6 +66,7 @@ func newTestRuntime(t *testing.T, fr *fakeRunner) *Runtime { }) require.NoError(t, err) rt.runner = fr + rt.stderrLog = io.Discard return rt }