diff --git a/docs/logs/engineering-log.md b/docs/logs/engineering-log.md index 47cdb1df4..3614ae925 100644 --- a/docs/logs/engineering-log.md +++ b/docs/logs/engineering-log.md @@ -6064,3 +6064,41 @@ Skipped creating separate issues for Op/EventMsg protocol (already covered by SS - Regression: `TestRestoreRewindPoint_PruneKeepsOlderPointsFromEarlierRuns` drives two real runs, restores to run 2's edit point, then restores to run 1's write point and asserts it still succeeds. + +# 2026-09-06 (Issue #1395 trailing system-role message empties DeepSeek responses) + +- Cause: the harness appends the per-turn `` block as a + second, trailing `system`-role message after the user/tool history + (`buildTurnMessages` in `internal/harness/clone.go`, content from + `internal/systemprompt/runtime_context.go`), so the cacheable + system+tools+history prefix stays stable across turns. `mapMessages` in + `internal/provider/openai/client.go` forwarded every role verbatim onto + the OpenAI-compatible chat-completions wire. DeepSeek models reached + through OpenRouter return an empty assistant message (1-3 completion + tokens, `finish_reason: stop`) whenever the *last* message in the request + has role `system`, so every run died within three turns with + `max_empty_responses`. A logging-proxy replay of the captured request + confirmed the same body succeeds 3/3 when only the trailing message's + role is changed to `user`; `gpt-4.1-mini` tolerates either role, which is + why the fake/OpenAI paths never surfaced this (issue #1395 has the full + replay table). +- Fix: `mapMessages` now sends any `system`-role message that is not the + first message (index 0) as role `user` instead, leaving content and + position unchanged. The leading system message is untouched. This keeps + the fix scoped to the OpenAI-compatible wire mapper; `buildTurnMessages` + and the harness's internal message model are unchanged, and the + Anthropic client (`extractSystem`, which already hoists every system + message into the top-level `system` parameter regardless of position) is + unaffected. `prompts/compiled/system_prompt.txt` comments updated to + describe the wire role split between providers. +- Regression: `TestMapMessagesNonLeadingSystemSentAsUser` and + `TestCompleteWireBodyTrailingSystemAsUser` cover the mapper contract + directly (leading system stays `system`, trailing system becomes `user`, + content unchanged); `TestMapMessagesLeadingOnlySystemUnchanged` guards the + single-leading-system case already worked. `TestRunnerRuntimeContextReachesOpenAIWireAsUser` + drives a real `harness.Runner` through the real `openai.Client` end to + end and asserts the wire body's trailing message is `user` -- confirmed to + fail with the pre-fix mapper by re-running it against the reverted + client.go. Live verification against DeepSeek via OpenRouter is a + follow-up for whoever holds the API key; this PR only proves the + fake/unit/integration paths. diff --git a/internal/provider/openai/client.go b/internal/provider/openai/client.go index efb716664..4215af0d2 100644 --- a/internal/provider/openai/client.go +++ b/internal/provider/openai/client.go @@ -1127,11 +1127,25 @@ func valueOrZero(v *int) int { // Providers that require this passback (DeepSeek, OpenRouter/DeepSeek models) // will reject second-turn tool-result messages if the prior assistant turn's // reasoning is not present. +// +// Issue #1395: the harness appends the per-turn block as a +// second system-role message at the end of the turn (runner_step_engine.go +// buildTurnMessages), to keep the cacheable system+tools+history prefix +// stable. DeepSeek (and other OpenAI-compatible backends reached through +// OpenRouter) return an empty assistant message whenever the LAST message in +// the request has role "system". A trailing "user" message is accepted by +// every OpenAI-compatible chat API, so any system message that is not the +// first message is sent as role "user" instead; content and position are +// unchanged. The leading system message (index 0) is left alone. func mapMessages(messages []harness.Message, replayReasoning bool) []chatMessage { mapped := make([]chatMessage, 0, len(messages)) - for _, msg := range messages { + for i, msg := range messages { + role := msg.Role + if role == "system" && i != 0 { + role = "user" + } chatMsg := chatMessage{ - Role: msg.Role, + Role: role, ToolCallID: msg.ToolCallID, Name: msg.Name, } diff --git a/internal/provider/openai/client_trailing_system_test.go b/internal/provider/openai/client_trailing_system_test.go new file mode 100644 index 000000000..ff4b677af --- /dev/null +++ b/internal/provider/openai/client_trailing_system_test.go @@ -0,0 +1,201 @@ +package openai + +import ( + "context" + "encoding/json" + "sync/atomic" + "testing" + + "go-agent-harness/internal/harness" + "go-agent-harness/internal/systemprompt" +) + +// TestMapMessagesNonLeadingSystemSentAsUser is the issue #1395 regression: +// DeepSeek (via OpenRouter) returns an empty assistant response whenever the +// LAST message in the request has role "system". The harness places the +// per-turn block last with role "system" (runner_step_engine.go +// buildTurnMessages) to keep the cacheable prefix unchanged, so the OpenAI- +// compatible mapper must rewrite any non-leading system message to role +// "user" on the wire while leaving the leading system message (and its +// content) untouched. +func TestMapMessagesNonLeadingSystemSentAsUser(t *testing.T) { + t.Parallel() + + messages := []harness.Message{ + {Role: "system", Content: "You are a helpful agent."}, + {Role: "user", Content: "do the thing"}, + {Role: "assistant", Content: "", ToolCalls: []harness.ToolCall{{ID: "tc1", Name: "write", Arguments: "{}"}}}, + {Role: "tool", ToolCallID: "tc1", Content: "ok"}, + {Role: "system", Content: "turn 2"}, + } + + out := mapMessages(messages, false) + if len(out) != 5 { + t.Fatalf("len(out) = %d, want 5", len(out)) + } + + if out[0].Role != "system" { + t.Errorf("leading message role = %q, want system (must stay system)", out[0].Role) + } + if s, ok := out[0].Content.(string); !ok || s != "You are a helpful agent." { + t.Errorf("leading system content = %v, want unchanged", out[0].Content) + } + + last := out[len(out)-1] + if last.Role != "user" { + t.Errorf("trailing runtime_context message role = %q, want user (this is the #1395 fix)", last.Role) + } + if s, ok := last.Content.(string); !ok || s != "turn 2" { + t.Errorf("trailing message content = %v, want unchanged text", last.Content) + } +} + +// TestMapMessagesLeadingOnlySystemUnchanged guards the non-regression case: +// a request with only a single leading system message must not be altered. +func TestMapMessagesLeadingOnlySystemUnchanged(t *testing.T) { + t.Parallel() + + messages := []harness.Message{ + {Role: "system", Content: "You are a helpful agent."}, + {Role: "user", Content: "hello"}, + } + + out := mapMessages(messages, false) + if len(out) != 2 { + t.Fatalf("len(out) = %d, want 2", len(out)) + } + if out[0].Role != "system" { + t.Errorf("out[0].Role = %q, want system", out[0].Role) + } + if out[1].Role != "user" { + t.Errorf("out[1].Role = %q, want user", out[1].Role) + } +} + +// TestCompleteWireBodyTrailingSystemAsUser proves the fix end-to-end through +// Complete(): the JSON body sent to an OpenAI-compatible endpoint has the +// trailing runtime_context message on the wire as role "user", with the +// leading system message untouched. +func TestCompleteWireBodyTrailingSystemAsUser(t *testing.T) { + t.Parallel() + + var hits atomic.Int32 + var bodies atomic.Pointer[[]byte] + srv := captureChatServer(t, &hits, &bodies) + + client, err := NewClient(Config{APIKey: "test-key", BaseURL: srv.URL, ProviderName: "openrouter"}) + if err != nil { + t.Fatalf("NewClient: %v", err) + } + + _, err = client.Complete(context.Background(), harness.CompletionRequest{ + Model: "deepseek/deepseek-v4-flash", + Messages: []harness.Message{ + {Role: "system", Content: "You are a helpful agent."}, + {Role: "user", Content: "do the thing"}, + {Role: "system", Content: "turn 1"}, + }, + }) + if err != nil { + t.Fatalf("Complete: %v", err) + } + if hits.Load() != 1 { + t.Fatalf("server hit %d times, want 1", hits.Load()) + } + + var wire struct { + Messages []struct { + Role string `json:"role"` + Content string `json:"content"` + } `json:"messages"` + } + if err := json.Unmarshal(*bodies.Load(), &wire); err != nil { + t.Fatalf("unmarshal wire body: %v", err) + } + if len(wire.Messages) != 3 { + t.Fatalf("wire messages len = %d, want 3", len(wire.Messages)) + } + if wire.Messages[0].Role != "system" { + t.Errorf("wire.Messages[0].Role = %q, want system", wire.Messages[0].Role) + } + last := wire.Messages[len(wire.Messages)-1] + if last.Role != "user" { + t.Errorf("wire.Messages[last].Role = %q, want user (trailing system must ride as user on the wire)", last.Role) + } + if last.Content != "turn 1" { + t.Errorf("wire.Messages[last].Content = %q, want the runtime_context text unchanged", last.Content) + } +} + +// fixedRuntimeContextEngine is a minimal systemprompt.Engine stub that always +// resolves a static prompt and returns a fixed runtime_context body, so a +// full Runner run deterministically produces a trailing system message. +type fixedRuntimeContextEngine struct{} + +func (fixedRuntimeContextEngine) Resolve(systemprompt.ResolveRequest) (systemprompt.ResolvedPrompt, error) { + return systemprompt.ResolvedPrompt{StaticPrompt: "STATIC_SYSTEM_PROMPT"}, nil +} + +func (fixedRuntimeContextEngine) RuntimeContext(systemprompt.RuntimeContextInput) string { + return "fixed" +} + +// TestRunnerRuntimeContextReachesOpenAIWireAsUser is the issue #1395 +// regression test at the integration seam: it drives a real harness.Runner +// (buildTurnMessages appends the runtime_context block as a trailing +// system-role message, per runner_step_engine.go) through the real +// openai.Client, and asserts that on the wire the trailing message is role +// "user" (not "system") — this is what stops DeepSeek/OpenRouter from +// returning empty responses. Unlike the unit-level mapMessages tests above, +// this exercises the actual production seam (Runner → buildTurnMessages → +// Complete → mapMessages) rather than calling mapMessages directly, so it +// would also fail if a future change moved the trailing-system rewrite +// somewhere that no longer sees runner-built turn messages. +func TestRunnerRuntimeContextReachesOpenAIWireAsUser(t *testing.T) { + t.Parallel() + + var hits atomic.Int32 + var bodies atomic.Pointer[[]byte] + srv := captureChatServer(t, &hits, &bodies) + + client, err := NewClient(Config{APIKey: "test-key", BaseURL: srv.URL, ProviderName: "openrouter"}) + if err != nil { + t.Fatalf("NewClient: %v", err) + } + + runner := harness.NewRunner(client, harness.NewRegistry(), harness.RunnerConfig{ + DefaultModel: "deepseek/deepseek-v4-flash", + DefaultAgentIntent: "general", + MaxSteps: 1, + PromptEngine: fixedRuntimeContextEngine{}, + }) + run, err := runner.StartRun(harness.RunRequest{Prompt: "do the thing"}) + if err != nil { + t.Fatalf("StartRun: %v", err) + } + waitTerminal(t, runner, run.ID) + + if hits.Load() != 1 { + t.Fatalf("server hit %d times, want 1", hits.Load()) + } + + var wire struct { + Messages []struct { + Role string `json:"role"` + Content string `json:"content"` + } `json:"messages"` + } + if err := json.Unmarshal(*bodies.Load(), &wire); err != nil { + t.Fatalf("unmarshal wire body: %v", err) + } + if len(wire.Messages) == 0 { + t.Fatal("wire request had no messages") + } + lastWire := wire.Messages[len(wire.Messages)-1] + if lastWire.Content != "fixed" { + t.Fatalf("last wire message content = %q, want the runtime_context block (it must stay last)", lastWire.Content) + } + if lastWire.Role != "user" { + t.Errorf("last wire message role = %q, want user — reverting the #1395 fix would send this as system and DeepSeek would go empty", lastWire.Role) + } +} diff --git a/prompts/compiled/system_prompt.txt b/prompts/compiled/system_prompt.txt index d3c562613..e203bc519 100644 --- a/prompts/compiled/system_prompt.txt +++ b/prompts/compiled/system_prompt.txt @@ -5,7 +5,13 @@ # # Format: sections wrapped in [SECTION ]...[END SECTION] tags, # separated by double newlines. The runtime_context block is injected -# as a separate system message each turn (not part of the static prompt). +# as a separate message each turn (not part of the static prompt). It is +# built with role "system" in the harness's turn messages array; the +# OpenAI-compatible provider client sends it on the wire as role "user" +# (issue #1395 — a trailing system-role message causes empty responses +# from some OpenAI-compatible backends, e.g. DeepSeek via OpenRouter). The +# Anthropic client hoists all system-role messages into the top-level +# system parameter regardless of position, so it is unaffected. # # To assemble the full per-turn system prompt, append the runtime_context # block (shown at the end of this file) after the static sections. @@ -97,11 +103,15 @@ Model guidance: # [END SECTION] # --------------------------------------------------------------------------- -# RUNTIME CONTEXT (injected as a separate system message each LLM turn) +# RUNTIME CONTEXT (injected as a separate message each LLM turn) # --------------------------------------------------------------------------- # This block is produced by BuildRuntimeContext() in -# internal/systemprompt/runtime_context.go and appended as a system-role -# message to the turn messages array, NOT to the static system prompt. +# internal/systemprompt/runtime_context.go and appended with role "system" +# to the turn messages array, NOT to the static system prompt. The +# OpenAI-compatible provider client (internal/provider/openai/client.go +# mapMessages) sends this trailing message on the wire as role "user" +# instead (issue #1395); the Anthropic client hoists it into the top-level +# system parameter regardless of wire role. # # Example shape (values are live at runtime): #