From 5ae7b24fe32c05953e124432d7d1c48920244cd6 Mon Sep 17 00:00:00 2001 From: kongh2021 Date: Wed, 14 Oct 2026 23:23:50 +0800 Subject: [PATCH] fix(core): stop the relay timeout path returning the target agent's tool output MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit HandleRelay accumulated every EventToolResult into textParts, and the timeout path hands textParts back to the caller verbatim. A relay whose target agent ran past the deadline therefore returned its whole tool log as if it were the answer: measured at 11932 chars in a single timed-out relay, against 165 to 2034 for turns that finished normally. That blob then sat in the caller's context and was re-billed on every later turn of its session — the token cost two /bind-ed bots were paying for nothing. Tool output is intermediate state, not an answer, so it no longer reaches textParts. The normal path is unaffected either way: both agent/claudecode and agent/cursor populate EventResult.Content, so resp is the final answer and textParts gets discarded. The timeout path also stops returning a bare truncated fragment as a success. relayPartialResponseOrError now trims to 2000 runes and wraps the fragment in an explicit notice (MsgRelayPartial, all five languages), because a silent fragment is indistinguishable from a real answer — the caller had no way to tell it had been cut off. It becomes a method on *Engine to reach i18n. TestHandleRelay_TimeoutExcludesToolResults is the regression test: a tool result carrying a sentinel is not relayed, assistant text still is. TestHandleRelay_ReturnsPartialOnTimeout keeps asserting the partial text survives, now through the notice. --- core/engine.go | 42 +++++++++++++++++++-------------- core/i18n.go | 8 +++++++ core/relay_test.go | 58 ++++++++++++++++++++++++++++++++++++++++++++-- 3 files changed, 88 insertions(+), 20 deletions(-) diff --git a/core/engine.go b/core/engine.go index 4f66d842d..042a0717d 100644 --- a/core/engine.go +++ b/core/engine.go @@ -16427,17 +16427,13 @@ func (e *Engine) HandleRelay(ctx context.Context, fromProject, sourceSessionKey, saveRelaySessionID(event.SessionID, false) } case EventToolResult: - out := strings.TrimSpace(event.Content) - if out == "" { - out = strings.TrimSpace(event.ToolResult) - } - if out != "" { - tn := strings.TrimSpace(event.ToolName) - if tn == "" { - tn = "tool" - } - textParts = append(textParts, fmt.Sprintf(e.i18n.T(MsgToolResult), tn, out)+"\n\n") - } + // Tool output is intermediate state, not an answer. It is + // deliberately NOT accumulated into textParts: on the timeout + // path textParts is handed back to the caller verbatim, so a + // tool dump would be billed into the caller's context — and + // re-billed on every later turn of that session. + slog.Debug("relay: tool result (not relayed)", + "from", fromProject, "to", e.name, "tool", event.ToolName) case EventResult: // Use agentSession.CurrentSessionID() for the same reason as above. if currentID := agentSession.CurrentSessionID(); currentID != "" { @@ -16471,7 +16467,7 @@ func (e *Engine) HandleRelay(ctx context.Context, fromProject, sourceSessionKey, // background so the session state is saved cleanly and the // session remains resumable for the next relay call. go e.drainRelaySession(agentSession, session, sessions, agent.Name(), relaySessionKey) - return relayPartialResponseOrError(ctx.Err(), textParts, fromProject, e.name) + return e.relayPartialResponseOrError(ctx.Err(), textParts, fromProject, e.name) } } @@ -16479,7 +16475,7 @@ func (e *Engine) HandleRelay(ctx context.Context, fromProject, sourceSessionKey, agentSession.Close() if ctx.Err() != nil { - return relayPartialResponseOrError(ctx.Err(), textParts, fromProject, e.name) + return e.relayPartialResponseOrError(ctx.Err(), textParts, fromProject, e.name) } if len(textParts) > 0 { @@ -16488,19 +16484,29 @@ func (e *Engine) HandleRelay(ctx context.Context, fromProject, sourceSessionKey, return "", fmt.Errorf("relay: agent process exited without response") } -func relayPartialResponseOrError(ctxErr error, textParts []string, fromProject, toProject string) (string, error) { - if len(textParts) == 0 { +// relayPartialNoticeMaxRunes bounds the partial text handed back to the caller +// when a relay times out. Tool output never reaches textParts (see +// HandleRelay), so this only ever caps assistant prose. +const relayPartialNoticeMaxRunes = 2000 + +// relayPartialResponseOrError reports a relay that hit its deadline before the +// target agent produced a final EventResult. The partial text is wrapped in an +// explicit timeout notice: without one the caller cannot tell a truncated +// fragment from a real answer, and silently treats it as the answer. +func (e *Engine) relayPartialResponseOrError(ctxErr error, textParts []string, fromProject, toProject string) (string, error) { + partial := strings.TrimSpace(strings.Join(textParts, "")) + if partial == "" { return "", ctxErr } + partial = truncateRelay(partial, relayPartialNoticeMaxRunes) - resp := strings.Join(textParts, "") slog.Warn("relay: context done before final result; returning partial response", "from", fromProject, "to", toProject, "error", ctxErr, - "response_len", len(resp), + "response_len", len(partial), ) - return resp, nil + return fmt.Sprintf(e.i18n.T(MsgRelayPartial), partial), nil } // drainRelaySession runs in a goroutine after a relay timeout. It lets the diff --git a/core/i18n.go b/core/i18n.go index 0cef4d522..c50496488 100644 --- a/core/i18n.go +++ b/core/i18n.go @@ -574,6 +574,7 @@ const ( MsgRelaySetupOK MsgKey = "relay_setup_ok" MsgRelaySetupExists MsgKey = "relay_setup_exists" MsgRelaySetupNoMemory MsgKey = "relay_setup_no_memory" + MsgRelayPartial MsgKey = "relay_partial_response" MsgSetupNative MsgKey = "setup_native" MsgCronSetupOK MsgKey = "cron_setup_ok" @@ -3476,6 +3477,13 @@ var messages = map[MsgKey]map[Language]string{ LangEnglish: "Current relay binding: %s", LangChinese: "当前中继绑定: %s", }, + MsgRelayPartial: { + LangEnglish: "⏳ The other bot is still working — this relay timed out before it produced a final answer.\n\nPartial output so far:\n---\n%s", + LangChinese: "⏳ 对方仍在运行 —— 本次中继在它给出最终结果前超时了。\n\n目前的片段输出：\n---\n%s", + LangTraditionalChinese: "⏳ 對方仍在執行 —— 本次中繼在它給出最終結果前逾時了。\n\n目前的片段輸出：\n---\n%s", + LangJapanese: "⏳ 相手はまだ実行中です —— 最終結果が出る前に中継がタイムアウトしました。\n\n現時点の部分的な出力：\n---\n%s", + LangSpanish: "⏳ El otro bot sigue trabajando: este relay agotó el tiempo antes de dar una respuesta final.\n\nSalida parcial hasta ahora:\n---\n%s", + }, MsgRelayUsage: { LangEnglish: "Usage:\n /bind — bind with another bot in this group\n /bind remove — remove binding\n /bind — show current binding\n\n is the project name from config.toml [[projects]].", LangChinese: "用法:\n /bind <项目名> — 绑定群聊中的另一个机器人\n /bind remove — 解除绑定\n /bind — 查看当前绑定\n\n<项目名> 是 config.toml 中 [[projects]] 的 name 字段。", diff --git a/core/relay_test.go b/core/relay_test.go index b6623319f..8529a40b8 100644 --- a/core/relay_test.go +++ b/core/relay_test.go @@ -385,8 +385,13 @@ func TestHandleRelay_ReturnsPartialOnTimeout(t *testing.T) { if got.err != nil { t.Fatalf("HandleRelay() error = %v, want nil", got.err) } - if got.resp != "partial response" { - t.Fatalf("HandleRelay() response = %q, want %q", got.resp, "partial response") + // The partial text is wrapped in an explicit timeout notice, so the caller + // can tell a truncated fragment from a real answer. + if !strings.Contains(got.resp, "partial response") { + t.Fatalf("HandleRelay() response = %q, want it to carry the partial text", got.resp) + } + if !strings.Contains(got.resp, "---") { + t.Fatalf("HandleRelay() response = %q, want the timeout notice around the partial text", got.resp) } // Wait for the background drain goroutine to close the session. @@ -397,6 +402,55 @@ func TestHandleRelay_ReturnsPartialOnTimeout(t *testing.T) { } } +// TestHandleRelay_TimeoutExcludesToolResults is the regression test for the +// relay timeout path leaking the target agent's tool output back to the caller. +// Every EventToolResult used to be appended to textParts, and on timeout +// textParts is handed back verbatim — so a turn that ran past the deadline +// returned the whole tool log as if it were the answer. That blob then sat in +// the caller's context and was re-billed on every later turn of its session. +func TestHandleRelay_TimeoutExcludesToolResults(t *testing.T) { + e := newTestEngine() + session := newControllableSession("relay-session") + e.agent = &controllableAgent{nextSession: session} + + ctx, cancel := context.WithTimeout(context.Background(), 20*time.Millisecond) + defer cancel() + + type relayResult struct { + resp string + err error + } + done := make(chan relayResult, 1) + go func() { + resp, err := e.HandleRelay(ctx, "source", "test:chat-1:user", "hello") + done <- relayResult{resp: resp, err: err} + }() + + const toolDump = "TOOL-OUTPUT-MUST-NOT-BE-RELAYED" + session.events <- Event{Type: EventToolResult, ToolName: "Bash", Content: toolDump, SessionID: "relay-session"} + session.events <- Event{Type: EventText, Content: "working on it", SessionID: "relay-session"} + time.Sleep(40 * time.Millisecond) + session.events <- Event{Type: EventThinking, Content: "still working"} + session.events <- Event{Type: EventResult, Content: "done", Done: true} + + got := <-done + if got.err != nil { + t.Fatalf("HandleRelay() error = %v, want nil", got.err) + } + if strings.Contains(got.resp, toolDump) { + t.Fatalf("HandleRelay() leaked tool output to the caller: %q", got.resp) + } + if !strings.Contains(got.resp, "working on it") { + t.Fatalf("HandleRelay() response = %q, want the assistant text preserved", got.resp) + } + + select { + case <-session.closed: + case <-time.After(2 * time.Second): + t.Fatal("background drain goroutine did not close the session") + } +} + func TestHandleRelay_TimeoutWithoutTextReturnsContextError(t *testing.T) { e := newTestEngine() session := newControllableSession("relay-session")