增加 agent 冷启动的开发调试日志记录

This commit is contained in:
2026-05-20 17:32:08 +08:00
parent 6c53e12962
commit 725935e270
2 changed files with 82 additions and 0 deletions
+54
View File
@@ -318,6 +318,11 @@ export const streamPromptResponse = async ({
const reasoningDeltas = new Map<string, string[]>(); const reasoningDeltas = new Map<string, string[]>();
const reasoningStatuses = new Map<string, "running" | "completed">(); const reasoningStatuses = new Map<string, "running" | "completed">();
const toolStatuses = new Map<string, string>(); const toolStatuses = new Map<string, string>();
let firstSessionEventLogged = false;
let firstNonStatusEventLogged = false;
let firstTokenLogged = false;
let firstReasoningLogged = false;
let firstToolEventLogged = false;
let lastSessionStatus: string | null = null; let lastSessionStatus: string | null = null;
let lastSessionStatusMessage: string | null = null; let lastSessionStatusMessage: string | null = null;
let emittedText = false; let emittedText = false;
@@ -470,6 +475,16 @@ export const streamPromptResponse = async ({
continue; 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") { if (event.type === "session.status") {
const nextStatus = event.properties.status.type; const nextStatus = event.properties.status.type;
const nextStatusMessage = const nextStatusMessage =
@@ -505,6 +520,16 @@ export const streamPromptResponse = async ({
continue; 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)) { if (isSkillEvent(event)) {
const { name, reason, payload } = extractSkillAuditInfo(event); const { name, reason, payload } = extractSkillAuditInfo(event);
logDevelopmentDebug("skill event received", { logDevelopmentDebug("skill event received", {
@@ -532,12 +557,30 @@ export const streamPromptResponse = async ({
if (event.type === "message.part.delta" && event.properties.field === "text") { if (event.type === "message.part.delta" && event.properties.field === "text") {
const partType = partTypes.get(event.properties.partID); const partType = partTypes.get(event.properties.partID);
if (partType === "text") { 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; emittedText = true;
write("token", { write("token", {
session_id: clientSessionId, session_id: clientSessionId,
content: event.properties.delta, content: event.properties.delta,
}); });
} else if (partType === "reasoning") { } 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) ?? []; const pending = reasoningDeltas.get(event.properties.partID) ?? [];
pending.push(event.properties.delta); pending.push(event.properties.delta);
reasoningDeltas.set(event.properties.partID, pending); reasoningDeltas.set(event.properties.partID, pending);
@@ -593,6 +636,17 @@ export const streamPromptResponse = async ({
}); });
} }
if (part.type === "tool") { 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 toolParams = normalizeToolParams(part.state.input);
const reason = extractRequestReason(toolParams); const reason = extractRequestReason(toolParams);
const isToolFinalState = const isToolFinalState =
+28
View File
@@ -7,6 +7,18 @@ import {
import { config } from "../config.js"; import { config } from "../config.js";
import { logger } from "../logger.js"; import { logger } from "../logger.js";
const isDevelopmentDebugLoggingEnabled = process.env.NODE_ENV === "development";
const logDevelopmentDebug = (
message: string,
metadata: Record<string, unknown>,
) => {
if (!isDevelopmentDebugLoggingEnabled) {
return;
}
logger.info(metadata, message);
};
export type RuntimeHealth = { export type RuntimeHealth = {
healthy: boolean; healthy: boolean;
version: string; version: string;
@@ -59,11 +71,27 @@ export class OpencodeRuntimeAdapter {
async prompt(sessionId: string, text: string, model?: RuntimeModelOverride) { async prompt(sessionId: string, text: string, model?: RuntimeModelOverride) {
const client = await this.ensureClient(); 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({ await client.session.prompt({
sessionID: sessionId, sessionID: sessionId,
model, model,
parts: [{ type: "text", text }], parts: [{ type: "text", text }],
}); });
logDevelopmentDebug(
"opencode session.prompt returned",
{
sessionId,
elapsedMs: Math.max(0, Date.now() - startedAt),
},
);
} }
async messages(sessionId: string, limit = 20) { async messages(sessionId: string, limit = 20) {