diff --git a/CHANGELOG.md b/CHANGELOG.md index cb487b7781b..22c1b0ea0c2 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -14,6 +14,7 @@ Docs: https://docs.openclaw.ai - CLI/plugins: have `openclaw plugins doctor` warn when a configured runtime needs a missing owner plugin, sharing the same install mapping as `openclaw doctor --fix`. Fixes #81326. (#81674) Thanks @Zavianx. - Agents/Codex: route OpenAI runs that resolve to `openai-codex` through the Codex provider and bootstrap OpenClaw's stored OAuth profile into the Codex harness when the harness owns transport, so `openai/*` model refs no longer fail with `No API key found for openai-codex` despite an existing Codex OAuth profile. (#82864) Thanks @ragesaq. +- Agents/ACP: distinguish prompt-submitted and runtime-active child stalls from true interactive waits, including redacted proxy-env diagnostics for Codex ACP no-output runs. Fixes #44810. - Agents/skills: apply the full effective tool policy pipeline to inline `command-dispatch: tool` skill dispatch before owner-only filtering, preserving configured allow, deny, sandbox, sender, group, and subagent restrictions. (#78525) - Channel accounts: keep top-level default channel accounts visible when named accounts are added alongside default credential material, so mixed legacy/new account configs keep resolving `default` instead of silently dropping it. - Codex/Telegram: synthesize native Codex tool progress from final turn snapshots so Telegram `/verbose` stays visible when command events arrive only at completion. diff --git a/src/acp/control-plane/manager.core.ts b/src/acp/control-plane/manager.core.ts index d7fa0213200..b3c835e1807 100644 --- a/src/acp/control-plane/manager.core.ts +++ b/src/acp/control-plane/manager.core.ts @@ -896,6 +896,10 @@ export class AcpSessionManager { ? AbortSignal.any([input.signal, internalAbortController.signal]) : internalAbortController.signal; const eventGate = { open: true }; + await input.onLifecycle?.({ + type: "prompt_submitted", + at: Date.now(), + }); const turnPromise = consumeAcpTurnStream({ runtime, turn: { diff --git a/src/acp/control-plane/manager.types.ts b/src/acp/control-plane/manager.types.ts index f8357d24854..2afebb5cf05 100644 --- a/src/acp/control-plane/manager.types.ts +++ b/src/acp/control-plane/manager.types.ts @@ -62,9 +62,15 @@ export type AcpRunTurnInput = { mode: AcpRuntimePromptMode; requestId: string; signal?: AbortSignal; + onLifecycle?: (event: AcpTurnLifecycleEvent) => Promise | void; onEvent?: (event: AcpRuntimeEvent) => Promise | void; }; +export type AcpTurnLifecycleEvent = { + type: "prompt_submitted"; + at: number; +}; + export type AcpCloseSessionInput = { cfg: OpenClawConfig; sessionKey: string; diff --git a/src/agents/acp-spawn-parent-stream.test.ts b/src/agents/acp-spawn-parent-stream.test.ts index 77b07f43865..882be3bb914 100644 --- a/src/agents/acp-spawn-parent-stream.test.ts +++ b/src/agents/acp-spawn-parent-stream.test.ts @@ -247,7 +247,7 @@ describe("startAcpSpawnParentStreamRelay", () => { relay.dispose(); }); - it("emits a no-output notice and a resumed notice when output returns", () => { + it("emits a pre-prompt stall notice and a resumed notice when output returns", () => { const relay = startAcpSpawnParentStreamRelay({ runId: "run-2", parentSessionKey: "agent:main:main", @@ -259,7 +259,7 @@ describe("startAcpSpawnParentStreamRelay", () => { }); vi.advanceTimersByTime(1_500); - expectTextWithFragment(collectedTexts(), "has produced no output for 1s"); + expectTextWithFragment(collectedTexts(), "no prompt submission was observed for 1s"); emitAgentEvent({ runId: "run-2", @@ -286,6 +286,80 @@ describe("startAcpSpawnParentStreamRelay", () => { relay.dispose(); }); + it("classifies stalls after prompt submission but before the first runtime event", () => { + const relay = startAcpSpawnParentStreamRelay({ + runId: "run-prompt-stall", + parentSessionKey: "agent:main:main", + childSessionKey: "agent:codex:acp:child-prompt-stall", + agentId: "codex", + streamFlushMs: 1, + noOutputNoticeMs: 1_000, + noOutputPollMs: 250, + }); + + emitAgentEvent({ + runId: "run-prompt-stall", + stream: "acp", + data: { + phase: "prompt_submitted", + at: Date.now(), + proxyEnvKeys: ["HTTPS_PROXY"], + }, + }); + vi.advanceTimersByTime(1_500); + + const texts = collectedTexts(); + expectTextWithFragment(texts, "prompt was submitted but no ACP runtime event arrived for 1s"); + expectTextWithFragment(texts, "proxy env: HTTPS_PROXY"); + expectNoTextWithFragment(texts, "waiting for interactive input"); + relay.dispose(); + }); + + it("classifies runtime activity without visible assistant output separately from input waits", () => { + const relay = startAcpSpawnParentStreamRelay({ + runId: "run-runtime-stall", + parentSessionKey: "agent:main:main", + childSessionKey: "agent:codex:acp:child-runtime-stall", + agentId: "codex", + streamFlushMs: 1, + noOutputNoticeMs: 1_000, + noOutputPollMs: 250, + }); + + emitAgentEvent({ + runId: "run-runtime-stall", + stream: "acp", + data: { + phase: "prompt_submitted", + at: Date.now(), + proxyEnvKeys: [], + }, + }); + vi.advanceTimersByTime(750); + emitAgentEvent({ + runId: "run-runtime-stall", + stream: "acp", + data: { + phase: "runtime_event", + eventType: "status", + text: "connecting to upstream", + }, + }); + vi.advanceTimersByTime(750); + expectNoTextWithFragment(collectedTexts(), "has ACP runtime activity"); + + vi.advanceTimersByTime(500); + + const texts = collectedTexts(); + expectTextWithFragment( + texts, + "has ACP runtime activity but no visible assistant output for 1s", + ); + expectTextWithFragment(texts, "Last ACP event: status"); + expectNoTextWithFragment(texts, "waiting for interactive input"); + relay.dispose(); + }); + it("auto-disposes stale relays after max lifetime timeout", () => { const relay = startAcpSpawnParentStreamRelay({ runId: "run-3", diff --git a/src/agents/acp-spawn-parent-stream.ts b/src/agents/acp-spawn-parent-stream.ts index 242d69ddd00..c8b59165b2e 100644 --- a/src/agents/acp-spawn-parent-stream.ts +++ b/src/agents/acp-spawn-parent-stream.ts @@ -37,6 +37,20 @@ function toFiniteNumber(value: unknown): number | undefined { return typeof value === "number" && Number.isFinite(value) ? value : undefined; } +function normalizeStringArray(value: unknown): string[] { + if (!Array.isArray(value)) { + return []; + } + return value.filter((item): item is string => typeof item === "string" && item.length > 0); +} + +function formatProxyEnvSummary(keys: string[]): string { + if (keys.length === 0) { + return "proxy env: none"; + } + return `proxy env: ${keys.join(", ")}`; +} + function resolveAcpStreamLogPathFromSessionFile(sessionFile: string, sessionId: string): string { const baseDir = path.dirname(path.resolve(sessionFile)); return path.join(baseDir, `${sessionId}.acp-stream.jsonl`); @@ -243,6 +257,11 @@ export function startAcpSpawnParentStreamRelay(params: { let pendingText = ""; let lastProgressAt = Date.now(); let stallNotified = false; + let promptSubmittedAt: number | undefined; + let firstRuntimeEventAt: number | undefined; + let firstVisibleOutputAt: number | undefined; + let lastRuntimeEventType: string | undefined; + let proxyEnvKeysAtPrompt: string[] = []; let flushTimer: NodeJS.Timeout | undefined; let relayLifetimeTimer: NodeJS.Timeout | undefined; @@ -284,6 +303,34 @@ export function startAcpSpawnParentStreamRelay(params: { flushTimer.unref?.(); }; + const buildNoOutputNotice = () => { + const seconds = Math.round(noOutputNoticeMs / 1000); + if (!promptSubmittedAt) { + return { + summary: `No prompt submission observed for ${seconds}s after child start.`, + text: `${relayLabel} session started but no prompt submission was observed for ${seconds}s.`, + }; + } + if (!firstRuntimeEventAt) { + const proxySummary = formatProxyEnvSummary(proxyEnvKeysAtPrompt); + return { + summary: `Prompt submitted but no ACP runtime event for ${seconds}s (${proxySummary}).`, + text: `${relayLabel} prompt was submitted but no ACP runtime event arrived for ${seconds}s (${proxySummary}). Check upstream connectivity, auth, or proxy/network access in the gateway child environment.`, + }; + } + if (!firstVisibleOutputAt) { + const lastEvent = lastRuntimeEventType ? ` Last ACP event: ${lastRuntimeEventType}.` : ""; + return { + summary: `ACP runtime active but no visible assistant output for ${seconds}s.${lastEvent}`, + text: `${relayLabel} has ACP runtime activity but no visible assistant output for ${seconds}s.${lastEvent} It may be working, blocked on a tool, or failing before visible output.`, + }; + } + return { + summary: `No visible output for ${seconds}s. It may be waiting for input.`, + text: `${relayLabel} has produced no visible output for ${seconds}s. It may be waiting for interactive input.`, + }; + }; + const noOutputWatcherTimer = setInterval(() => { if (disposed || noOutputNoticeMs <= 0) { return; @@ -295,17 +342,15 @@ export function startAcpSpawnParentStreamRelay(params: { return; } stallNotified = true; + const notice = buildNoOutputNotice(); recordTaskRunProgressByRunId({ runId, runtime: "acp", sessionKey: params.childSessionKey, lastEventAt: Date.now(), - eventSummary: `No output for ${Math.round(noOutputNoticeMs / 1000)}s. It may be waiting for input.`, + eventSummary: notice.summary, }); - emit( - `${relayLabel} has produced no output for ${Math.round(noOutputNoticeMs / 1000)}s. It may be waiting for interactive input.`, - `${contextPrefix}:stall`, - ); + emit(notice.text, `${contextPrefix}:stall`); }, noOutputPollMs); noOutputWatcherTimer.unref?.(); @@ -365,6 +410,7 @@ export function startAcpSpawnParentStreamRelay(params: { } lastProgressAt = Date.now(); + firstVisibleOutputAt ??= lastProgressAt; pendingText += delta; if (pendingText.length > STREAM_BUFFER_MAX_CHARS) { pendingText = pendingText.slice(-STREAM_BUFFER_MAX_CHARS); @@ -377,6 +423,34 @@ export function startAcpSpawnParentStreamRelay(params: { return; } + if (event.stream === "acp") { + const data = event.data as + | { + phase?: unknown; + at?: unknown; + eventType?: unknown; + proxyEnvKeys?: unknown; + } + | undefined; + const phase = normalizeOptionalString(data?.phase); + logEvent("acp", { phase: phase ?? "unknown", data: event.data }); + if (phase === "prompt_submitted") { + const at = toFiniteNumber(data?.at) ?? Date.now(); + promptSubmittedAt ??= at; + proxyEnvKeysAtPrompt = normalizeStringArray(data?.proxyEnvKeys); + lastProgressAt = Date.now(); + return; + } + if (phase === "runtime_event") { + const eventType = normalizeOptionalString(data?.eventType); + firstRuntimeEventAt ??= Date.now(); + lastRuntimeEventType = eventType; + lastProgressAt = Date.now(); + return; + } + return; + } + if (event.stream !== "lifecycle") { return; } diff --git a/src/agents/agent-command.ts b/src/agents/agent-command.ts index 46159059250..e2558f59ee0 100644 --- a/src/agents/agent-command.ts +++ b/src/agents/agent-command.ts @@ -575,7 +575,23 @@ async function agentCommandInternal( mode: "prompt", requestId: runId, signal: opts.abortSignal, + onLifecycle: (event) => { + if (event.type === "prompt_submitted") { + attemptExecutionRuntime.emitAcpPromptSubmitted({ + runId, + sessionKey, + at: event.at, + }); + } + }, onEvent: (event) => { + if (event.type !== "text_delta") { + attemptExecutionRuntime.emitAcpRuntimeEvent({ + runId, + sessionKey, + event, + }); + } if (event.type === "done") { stopReason = event.stopReason; return; diff --git a/src/agents/command/attempt-execution.error-propagation.test.ts b/src/agents/command/attempt-execution.error-propagation.test.ts index c0ddc596b5e..4fac46377c2 100644 --- a/src/agents/command/attempt-execution.error-propagation.test.ts +++ b/src/agents/command/attempt-execution.error-propagation.test.ts @@ -5,7 +5,12 @@ import { onAgentEvent, resetAgentEventsForTest, } from "../../infra/agent-events.js"; -import { emitAcpLifecycleError, formatAcpLifecycleError } from "./attempt-execution.js"; +import { + emitAcpLifecycleError, + emitAcpPromptSubmitted, + emitAcpRuntimeEvent, + formatAcpLifecycleError, +} from "./attempt-execution.js"; let captured: AgentEventPayload[] = []; let unsubscribe: (() => void) | undefined; @@ -18,6 +23,57 @@ beforeEach(() => { }); }); +describe("ACP diagnostic events", () => { + it("emits prompt-submitted state with proxy env names but not values", () => { + const previous = process.env.HTTPS_PROXY; + process.env.HTTPS_PROXY = "http://proxy.example.invalid:8080"; + try { + emitAcpPromptSubmitted({ + runId: "run-prompt", + sessionKey: "agent:codex:acp:child", + at: 123, + }); + } finally { + if (previous === undefined) { + delete process.env.HTTPS_PROXY; + } else { + process.env.HTTPS_PROXY = previous; + } + } + + const event = captured[0]; + expect(event?.stream).toBe("acp"); + expect(event?.sessionKey).toBe("agent:codex:acp:child"); + expect(event?.data).toMatchObject({ + phase: "prompt_submitted", + at: 123, + proxyEnvKeys: expect.arrayContaining(["HTTPS_PROXY"]), + }); + expect(JSON.stringify(event?.data)).not.toContain("proxy.example.invalid"); + }); + + it("emits sanitized non-text runtime events for parent relay diagnostics", () => { + emitAcpRuntimeEvent({ + runId: "run-status", + event: { + type: "status", + text: "connecting token=sk-abcdefghijklmnopqrstuvwxyz123456", + tag: "session_info_update", + }, + }); + + const event = captured[0]; + expect(event?.stream).toBe("acp"); + expect(event?.data).toMatchObject({ + phase: "runtime_event", + eventType: "status", + tag: "session_info_update", + }); + expect(String(event?.data.text)).toContain("connecting"); + expect(String(event?.data.text)).not.toContain("sk-abcdefghijklmnopqrstuvwxyz123456"); + }); +}); + afterEach(() => { unsubscribe?.(); unsubscribe = undefined; diff --git a/src/agents/command/attempt-execution.runtime.ts b/src/agents/command/attempt-execution.runtime.ts index 495142f204f..fc725d9f009 100644 --- a/src/agents/command/attempt-execution.runtime.ts +++ b/src/agents/command/attempt-execution.runtime.ts @@ -5,6 +5,8 @@ export { emitAcpLifecycleEnd, emitAcpLifecycleError, emitAcpLifecycleStart, + emitAcpPromptSubmitted, + emitAcpRuntimeEvent, persistAcpTurnTranscript, persistCliTurnTranscript, runAgentAttempt, diff --git a/src/agents/command/attempt-execution.ts b/src/agents/command/attempt-execution.ts index 6a18cf22d06..8adc28a15f5 100644 --- a/src/agents/command/attempt-execution.ts +++ b/src/agents/command/attempt-execution.ts @@ -1,5 +1,6 @@ import type { AgentMessage } from "@earendil-works/pi-agent-core"; import { formatAcpErrorChain } from "../../acp/runtime/errors.js"; +import type { AcpRuntimeEvent } from "../../acp/runtime/types.js"; import { normalizeReplyPayload } from "../../auto-reply/reply/normalize-reply.js"; import type { ThinkLevel, VerboseLevel } from "../../auto-reply/thinking.js"; import { appendSessionTranscriptMessage } from "../../config/sessions/transcript-append.js"; @@ -11,6 +12,7 @@ import type { SessionEntry } from "../../config/sessions/types.js"; import type { OpenClawConfig } from "../../config/types.openclaw.js"; import { emitAgentEvent } from "../../infra/agent-events.js"; import { readErrorName } from "../../infra/errors.js"; +import { redactSensitiveText } from "../../logging/redact.js"; import { createSubsystemLogger } from "../../logging/subsystem.js"; import { annotateInterSessionPromptText } from "../../sessions/input-provenance.js"; import { emitSessionTranscriptUpdate } from "../../sessions/transcript-events.js"; @@ -722,6 +724,93 @@ export function emitAcpLifecycleStart(params: { runId: string; startedAt: number }); } +const ACP_PROXY_ENV_KEYS = [ + "HTTP_PROXY", + "HTTPS_PROXY", + "ALL_PROXY", + "http_proxy", + "https_proxy", + "all_proxy", +] as const; + +function resolvePresentProxyEnvKeys(env: NodeJS.ProcessEnv = process.env): string[] { + return ACP_PROXY_ENV_KEYS.filter((key) => { + const value = env[key]; + return typeof value === "string" && value.trim().length > 0; + }); +} + +function sanitizeAcpDiagnosticText(value: string): string { + return redactSensitiveText(value).replace(/\s+/g, " ").trim().slice(0, 240); +} + +function acpRuntimeEventDiagnostics(event: AcpRuntimeEvent): Record { + if (event.type === "status") { + return { + eventType: event.type, + text: sanitizeAcpDiagnosticText(event.text), + ...(event.tag ? { tag: event.tag } : {}), + }; + } + if (event.type === "tool_call") { + return { + eventType: event.type, + text: sanitizeAcpDiagnosticText(event.text), + ...(event.tag ? { tag: event.tag } : {}), + ...(event.status ? { status: sanitizeAcpDiagnosticText(event.status) } : {}), + ...(event.title ? { title: sanitizeAcpDiagnosticText(event.title) } : {}), + ...(event.toolCallId ? { toolCallId: sanitizeAcpDiagnosticText(event.toolCallId) } : {}), + }; + } + if (event.type === "error") { + return { + eventType: event.type, + message: sanitizeAcpDiagnosticText(event.message), + ...(event.code ? { code: sanitizeAcpDiagnosticText(event.code) } : {}), + ...(typeof event.retryable === "boolean" ? { retryable: event.retryable } : {}), + }; + } + if (event.type === "done") { + return { + eventType: event.type, + ...(event.stopReason ? { stopReason: sanitizeAcpDiagnosticText(event.stopReason) } : {}), + }; + } + return { + eventType: event.type, + stream: event.stream ?? "output", + }; +} + +export function emitAcpPromptSubmitted(params: { runId: string; sessionKey?: string; at: number }) { + emitAgentEvent({ + runId: params.runId, + stream: "acp", + ...(params.sessionKey ? { sessionKey: params.sessionKey } : {}), + data: { + phase: "prompt_submitted", + at: params.at, + proxyEnvKeys: resolvePresentProxyEnvKeys(), + }, + }); +} + +export function emitAcpRuntimeEvent(params: { + runId: string; + event: AcpRuntimeEvent; + sessionKey?: string; +}) { + emitAgentEvent({ + runId: params.runId, + stream: "acp", + ...(params.sessionKey ? { sessionKey: params.sessionKey } : {}), + data: { + phase: "runtime_event", + ...acpRuntimeEventDiagnostics(params.event), + }, + }); +} + export function emitAcpLifecycleEnd(params: { runId: string }) { emitAgentEvent({ runId: params.runId, diff --git a/src/commands/agent.acp.test.ts b/src/commands/agent.acp.test.ts index d7f85547e5a..c68c93105b9 100644 --- a/src/commands/agent.acp.test.ts +++ b/src/commands/agent.acp.test.ts @@ -34,6 +34,8 @@ const attemptExecutionMocks = vi.hoisted(() => ({ emitAcpLifecycleStart: vi.fn(), emitAcpLifecycleEnd: vi.fn(), emitAcpLifecycleError: vi.fn(), + emitAcpPromptSubmitted: vi.fn(), + emitAcpRuntimeEvent: vi.fn(), persistAcpTurnTranscript: vi.fn( async ({ sessionEntry }: { sessionEntry?: unknown }) => sessionEntry, ), @@ -74,6 +76,8 @@ vi.mock("../agents/command/attempt-execution.runtime.js", () => { emitAcpLifecycleStart: attemptExecutionMocks.emitAcpLifecycleStart, emitAcpLifecycleEnd: attemptExecutionMocks.emitAcpLifecycleEnd, emitAcpLifecycleError: attemptExecutionMocks.emitAcpLifecycleError, + emitAcpPromptSubmitted: attemptExecutionMocks.emitAcpPromptSubmitted, + emitAcpRuntimeEvent: attemptExecutionMocks.emitAcpRuntimeEvent, emitAcpAssistantDelta: ({ runId, text,