From 725935e270e59d522527455f30eb48d8b365f7c6 Mon Sep 17 00:00:00 2001 From: Huarch Date: Wed, 20 May 2026 17:32:08 +0800 Subject: [PATCH] =?UTF-8?q?=E5=A2=9E=E5=8A=A0=20agent=20=E5=86=B7=E5=90=AF?= =?UTF-8?q?=E5=8A=A8=E7=9A=84=E5=BC=80=E5=8F=91=E8=B0=83=E8=AF=95=E6=97=A5?= =?UTF-8?q?=E5=BF=97=E8=AE=B0=E5=BD=95?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit --- src/routes/chatStream.ts | 54 ++++++++++++++++++++++++++++++++++++++++ src/runtime/opencode.ts | 28 +++++++++++++++++++++ 2 files changed, 82 insertions(+) diff --git a/src/routes/chatStream.ts b/src/routes/chatStream.ts index e31c6c5..60adf6c 100644 --- a/src/routes/chatStream.ts +++ b/src/routes/chatStream.ts @@ -318,6 +318,11 @@ export const streamPromptResponse = async ({ const reasoningDeltas = new Map(); const reasoningStatuses = new Map(); const toolStatuses = new Map(); + let firstSessionEventLogged = false; + let firstNonStatusEventLogged = false; + let firstTokenLogged = false; + let firstReasoningLogged = false; + let firstToolEventLogged = false; let lastSessionStatus: string | null = null; let lastSessionStatusMessage: string | null = null; let emittedText = false; @@ -470,6 +475,16 @@ export const streamPromptResponse = async ({ continue; } + if (!firstSessionEventLogged) { + firstSessionEventLogged = true; + logDevelopmentDebug("first session event received", { + ...debugContext, + eventType: event.type, + elapsedMs: Math.max(0, Date.now() - requestStartedAt), + sincePromptDispatchMs: Math.max(0, Date.now() - promptStartedAt), + }); + } + if (event.type === "session.status") { const nextStatus = event.properties.status.type; const nextStatusMessage = @@ -505,6 +520,16 @@ export const streamPromptResponse = async ({ continue; } + if (!firstNonStatusEventLogged) { + firstNonStatusEventLogged = true; + logDevelopmentDebug("first non-status session event received", { + ...debugContext, + eventType: event.type, + elapsedMs: Math.max(0, Date.now() - requestStartedAt), + sincePromptDispatchMs: Math.max(0, Date.now() - promptStartedAt), + }); + } + if (isSkillEvent(event)) { const { name, reason, payload } = extractSkillAuditInfo(event); logDevelopmentDebug("skill event received", { @@ -532,12 +557,30 @@ export const streamPromptResponse = async ({ if (event.type === "message.part.delta" && event.properties.field === "text") { const partType = partTypes.get(event.properties.partID); if (partType === "text") { + if (!firstTokenLogged) { + firstTokenLogged = true; + logDevelopmentDebug("first response token emitted", { + ...debugContext, + partId: event.properties.partID, + elapsedMs: Math.max(0, Date.now() - requestStartedAt), + sincePromptDispatchMs: Math.max(0, Date.now() - promptStartedAt), + }); + } emittedText = true; write("token", { session_id: clientSessionId, content: event.properties.delta, }); } else if (partType === "reasoning") { + if (!firstReasoningLogged) { + firstReasoningLogged = true; + logDevelopmentDebug("first reasoning delta received", { + ...debugContext, + partId: event.properties.partID, + elapsedMs: Math.max(0, Date.now() - requestStartedAt), + sincePromptDispatchMs: Math.max(0, Date.now() - promptStartedAt), + }); + } const pending = reasoningDeltas.get(event.properties.partID) ?? []; pending.push(event.properties.delta); reasoningDeltas.set(event.properties.partID, pending); @@ -593,6 +636,17 @@ export const streamPromptResponse = async ({ }); } if (part.type === "tool") { + if (!firstToolEventLogged) { + firstToolEventLogged = true; + logDevelopmentDebug("first tool event received", { + ...debugContext, + partId: part.id, + tool: part.tool, + status: part.state.status, + elapsedMs: Math.max(0, Date.now() - requestStartedAt), + sincePromptDispatchMs: Math.max(0, Date.now() - promptStartedAt), + }); + } const toolParams = normalizeToolParams(part.state.input); const reason = extractRequestReason(toolParams); const isToolFinalState = diff --git a/src/runtime/opencode.ts b/src/runtime/opencode.ts index 087fcc2..0a8c089 100644 --- a/src/runtime/opencode.ts +++ b/src/runtime/opencode.ts @@ -7,6 +7,18 @@ import { import { config } from "../config.js"; import { logger } from "../logger.js"; +const isDevelopmentDebugLoggingEnabled = process.env.NODE_ENV === "development"; + +const logDevelopmentDebug = ( + message: string, + metadata: Record, +) => { + if (!isDevelopmentDebugLoggingEnabled) { + return; + } + logger.info(metadata, message); +}; + export type RuntimeHealth = { healthy: boolean; version: string; @@ -59,11 +71,27 @@ export class OpencodeRuntimeAdapter { async prompt(sessionId: string, text: string, model?: RuntimeModelOverride) { const client = await this.ensureClient(); + const startedAt = Date.now(); + logDevelopmentDebug( + "dispatching opencode session.prompt", + { + sessionId, + model: model ?? null, + textChars: text.length, + }, + ); await client.session.prompt({ sessionID: sessionId, model, parts: [{ type: "text", text }], }); + logDevelopmentDebug( + "opencode session.prompt returned", + { + sessionId, + elapsedMs: Math.max(0, Date.now() - startedAt), + }, + ); } async messages(sessionId: string, limit = 20) {