Skip to content

Commit 2d5b829

Browse files
rohoswaggerclaude
andcommitted
fix(craft): accept either completion signal + add ACP debug logging
ACP behavior is inconsistent — some prompts get both a prompt_response notification AND a JSON-RPC response, others get only the notification. Accept whichever arrives first. Add per-message dequeue logging to understand the exact packet sequence ACP sends for each prompt. Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
1 parent 495e2f7 commit 2d5b829

File tree

1 file changed

+38
-5
lines changed

1 file changed

+38
-5
lines changed

backend/onyx/server/features/build/sandbox/kubernetes/internal/acp_exec_client.py

Lines changed: 38 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -621,7 +621,9 @@ def send_message(
621621
packet_logger = get_packet_logger()
622622

623623
logger.info(
624-
f"[ACP] Sending prompt: " f"acp_session={session_id} pod={self._pod_name}"
624+
f"[ACP] Sending prompt: "
625+
f"acp_session={session_id} pod={self._pod_name} "
626+
f"queue_backlog={self._response_queue.qsize()}"
625627
)
626628

627629
prompt_content = [{"type": "text", "text": message}]
@@ -658,6 +660,23 @@ def send_message(
658660
try:
659661
message_data = self._response_queue.get(timeout=min(remaining, 1.0))
660662
last_event_time = time.time()
663+
664+
# Log every dequeued message for debugging ACP behavior
665+
update_type = (
666+
message_data.get("params", {})
667+
.get("update", {})
668+
.get("sessionUpdate", "")
669+
)
670+
logger.info(
671+
f"[ACP] Dequeued: "
672+
f"id={message_data.get('id')} "
673+
f"method={message_data.get('method')} "
674+
f"update={update_type} "
675+
f"has_result={'result' in message_data} "
676+
f"has_error={'error' in message_data} "
677+
f"request_id={request_id} "
678+
f"elapsed={(time.time() - start_time) * 1000:.0f}ms"
679+
)
661680
except Empty:
662681
# Check if reader thread is still alive
663682
if (
@@ -746,9 +765,23 @@ def send_message(
746765
params_data = message_data.get("params", {})
747766
update = params_data.get("update", {})
748767

768+
prompt_complete = False
749769
for event in self._process_session_update(update):
750770
events_yielded += 1
751771
yield event
772+
if isinstance(event, PromptResponse):
773+
prompt_complete = True
774+
break
775+
776+
if prompt_complete:
777+
completion_reason = "prompt_response_via_notification"
778+
elapsed_ms = (time.time() - start_time) * 1000
779+
logger.info(
780+
f"[ACP] Prompt complete: "
781+
f"reason={completion_reason} acp_session={session_id} "
782+
f"events={events_yielded} elapsed={elapsed_ms:.0f}ms"
783+
)
784+
break
752785

753786
# Handle requests from agent - send error response
754787
elif "method" in message_data and "id" in message_data:
@@ -777,16 +810,17 @@ def _process_session_update(
777810
update_type = update.get("sessionUpdate")
778811

779812
# Map update types to their ACP schema classes.
780-
# Note: prompt_response is intentionally excluded here — turn completion
781-
# is determined by the JSON-RPC response to session/prompt, not by a
782-
# session/update notification. This matches the ACP spec and Zed's impl.
813+
# Note: prompt_response is included because ACP sometimes sends it as a
814+
# notification WITHOUT a corresponding JSON-RPC response. We accept
815+
# either signal as turn completion (first one wins).
783816
type_map: dict[str, type] = {
784817
"agent_message_chunk": AgentMessageChunk,
785818
"agent_thought_chunk": AgentThoughtChunk,
786819
"tool_call": ToolCallStart,
787820
"tool_call_update": ToolCallProgress,
788821
"plan": AgentPlanUpdate,
789822
"current_mode_update": CurrentModeUpdate,
823+
"prompt_response": PromptResponse,
790824
}
791825

792826
model_class = type_map.get(update_type) # type: ignore[arg-type]
@@ -800,7 +834,6 @@ def _process_session_update(
800834
"available_commands_update",
801835
"session_info_update",
802836
"usage_update",
803-
"prompt_response",
804837
):
805838
logger.debug(f"[ACP] Unknown update type: {update_type}")
806839

0 commit comments

Comments
 (0)