feat(logging): implement detailed logging for Codex operations and HTTP requests

This commit is contained in:
HouYunFei
2026-07-28 17:42:11 +08:00
parent b6e9954c0a
commit b3b02f75a9
13 changed files with 334 additions and 41 deletions
+27 -4
View File
@@ -6,6 +6,7 @@ import { createRequire } from "node:module";
import { fileURLToPath } from "node:url";
import { AGENT_PROMPT, VERSION } from "./config.js";
import { logger } from "./utils/logger.js";
import type { AgentAttachment, AgentEmit } from "./types.js";
type Json = Record<string, unknown>;
@@ -39,6 +40,7 @@ export function interruptCodexTurn(threadId?: string) {
async function runCodexTurnNow(prompt: string, emit: AgentEmit, attachments: AgentAttachment[], options: CodexRunOptions) {
let files: string[] = [];
try {
logger.info("Preparing Codex turn", { threadId: options.threadId, cwd: options.cwd, prompt, attachmentCount: attachments.length });
options.onStart?.();
files = await writeAttachmentFiles(attachments);
const app = await getCodexApp(options.appEmit || emit);
@@ -55,6 +57,7 @@ async function runCodexTurnNow(prompt: string, emit: AgentEmit, attachments: Age
await app.startTurn(threadId, prompt, files, options.onTurn);
}
} catch (error) {
logger.error("Codex turn failed", error);
emit("agent_error", { message: errorMessage(error) });
} finally {
options.onFinish?.();
@@ -153,12 +156,21 @@ class CodexAppClient {
private constructor(private child: ChildProcess, private emit: AgentEmit) {}
static async start(emit: AgentEmit) {
logger.info("Starting Codex app-server", { executable: process.execPath, codex: codexBin() });
const child = spawn(process.execPath, [codexBin(), "app-server", "--stdio"], { stdio: ["pipe", "pipe", "pipe"], windowsHide: true });
const client = new CodexAppClient(child, emit);
child.stdout?.on("data", (chunk) => client.read(chunk.toString()));
child.stderr?.on("data", (chunk) => emit("agent_log", { text: chunk.toString() }));
child.on("error", (error) => emit("agent_error", { message: error.message }));
child.stderr?.on("data", (chunk) => {
const text = chunk.toString();
logger.warn("Codex app-server stderr", { text });
emit("agent_log", { text });
});
child.on("error", (error) => {
logger.error("Codex app-server process error", error);
emit("agent_error", { message: error.message });
});
child.on("exit", (code) => {
logger.warn("Codex app-server exited", { code });
client.failAll(`Codex app-server exited: ${code ?? 0}`);
codexApp = null;
codexThreadId = "";
@@ -214,6 +226,7 @@ class CodexAppClient {
interruptCurrentTurn() {
if (this.activeTurns.size === 0) return false;
try {
logger.warn("Interrupting active Codex turn", { threadId: codexThreadId, activeTurns: this.activeTurns.size });
this.child.kill("SIGINT");
return true;
} catch {
@@ -232,6 +245,7 @@ class CodexAppClient {
}
private write(value: unknown) {
logger.debug("Codex app-server request", value);
this.child.stdin?.write(`${JSON.stringify(value)}\n`);
}
@@ -242,13 +256,15 @@ class CodexAppClient {
lines.filter(Boolean).forEach((line) => {
try {
this.handle(JSON.parse(line) as Json);
} catch {
} catch (error) {
logger.warn("Invalid Codex app-server output", { error, line });
this.emit("agent_log", { text: line });
}
});
}
private handle(message: Json) {
logger.debug("Codex app-server response", message);
const id = Number(message.id);
if (message.error && this.pending.has(id)) return this.reject(id, String(field(message.error, "message") || "Codex request failed"));
if (this.pending.has(id)) return this.resolve(id, message.result);
@@ -261,6 +277,13 @@ class CodexAppClient {
if (method === "thread/tokenUsage/updated") this.lastUsage = normalizeUsage(params);
const event = normalizeCodexNotification(method, params);
if (!event) return;
if (event.type === "item.completed") {
const item = field(event, "item") as Json | undefined;
const id = String(field(item, "id") || "");
const streamedText = this.textByItem.get(id);
if (item?.type === "agent_message" && streamedText && !item.text) item.text = streamedText;
if (id) this.textByItem.delete(id);
}
if (event.type === "turn.completed") event.usage = this.lastUsage;
this.emit("agent_event", { agent: "codex", ...event });
if (event.type === "turn.completed") {
@@ -432,7 +455,7 @@ function threadMessages(thread: unknown): AgentHistoryMessage[] {
}
if (type === "agentMessage") {
const text = String(field(item, "text") || "").trim();
if (text) messages.push({ id, role: "assistant", title: "Codex", text, streamId: id });
if (text) messages.push({ id, role: "assistant", title: "Codex", text });
}
if (type === "mcpToolCall") {
const tool = String(field(item, "tool") || "工具调用");
+12
View File
@@ -1,6 +1,7 @@
import crypto from "node:crypto";
import type { ServerResponse } from "node:http";
import { logger } from "./utils/logger.js";
import { type ToolName } from "./schemas.js";
import { compactCanvasState, compactNode, isToolName, nextCanvasX, parseToolInput } from "./tools.js";
import type { AgentAttachment, CanvasNode, CanvasNodeType, CanvasSnapshot } from "./types.js";
@@ -51,12 +52,14 @@ export class CanvasSession {
setCodexState(patch: Partial<CodexState>) {
this.codexState = { ...this.codexState, ...patch };
logger.debug("Codex state changed", this.codexState);
this.emitAll("codex_state", this.codexState);
}
openEvents(url: URL, res: ServerResponse) {
const clientId = url.searchParams.get("clientId") || crypto.randomUUID();
const statusOnly = url.searchParams.get("role") === "status";
logger.info("SSE client connected", { clientId, statusOnly });
res.writeHead(200, { "Content-Type": "text/event-stream", "Cache-Control": "no-cache", Connection: "keep-alive" });
if (!statusOnly) {
this.clients.set(clientId, res);
@@ -70,6 +73,7 @@ export class CanvasSession {
const timer = setInterval(() => sendEvent(res, "ping", { time: Date.now() }), 15000);
res.on("close", () => {
clearInterval(timer);
logger.info("SSE client disconnected", { clientId, statusOnly });
if (statusOnly || this.clients.get(clientId) !== res) return;
this.clients.delete(clientId);
this.clientFocusOrder.delete(clientId);
@@ -88,21 +92,25 @@ export class CanvasSession {
const targetClientId = clientId || this.activeClientId;
if (!targetClientId) return;
this.canvasStates.set(targetClientId, { ...((body && typeof body === "object" && !Array.isArray(body) ? body : {}) as Record<string, unknown>), clientId: targetClientId } as CanvasSnapshot);
logger.debug("Canvas state updated", { clientId: targetClientId, nodes: Array.isArray((body as CanvasSnapshot | null)?.nodes) ? (body as CanvasSnapshot).nodes.length : 0, connections: Array.isArray((body as CanvasSnapshot | null)?.connections) ? (body as CanvasSnapshot).connections.length : 0 });
}
activateClient(clientId: string) {
if (!this.clients.has(clientId)) throw new Error("当前网页未连接");
this.activeClientId = clientId;
this.clientFocusOrder.set(clientId, ++this.focusSequence);
logger.debug("Canvas client activated", { clientId });
}
bindClient(clientId: string) {
if (!this.clients.has(clientId)) throw new Error("当前网页未连接");
this.boundClientId = clientId;
logger.debug("Canvas client bound to turn", { clientId });
}
releaseClient(clientId: string) {
if (this.boundClientId === clientId) this.boundClientId = "";
logger.debug("Canvas client released from turn", { clientId });
}
setTurnAttachments(clientId: string, attachments: AgentAttachment[]) {
@@ -142,6 +150,7 @@ export class CanvasSession {
const item = body.requestId ? this.pending.get(body.requestId) : null;
if (!item || !body.requestId || item.clientId !== clientId) return false;
this.pending.delete(body.requestId);
logger.debug("Canvas tool result received", { clientId, requestId: body.requestId, error: body.error, result: body.result });
body.error ? item.reject(new Error(body.error)) : item.resolve(body.result);
return true;
}
@@ -156,6 +165,7 @@ export class CanvasSession {
async callTool(name: unknown, rawInput: unknown) {
if (!isToolName(name)) throw new Error(`未知工具:${String(name)}`);
logger.info("MCP tool called", { name, input: rawInput, targetClientId: this.targetClientId });
let tool: ToolName = name;
let input = parseToolInput(tool, rawInput) as Record<string, unknown>;
if (SITE_TOOLS.has(tool)) {
@@ -296,9 +306,11 @@ export class CanvasSession {
const client = this.clients.get(clientId);
if (!client) throw new Error("当前没有已连接画布");
sendEvent(client, "tool_call", { requestId, name, input });
logger.debug("Canvas tool request sent", { requestId, name, input, clientId });
return await new Promise((resolve, reject) => {
const timer = setTimeout(() => {
this.pending.delete(requestId);
logger.warn("Canvas tool request timed out", { requestId, name, clientId });
reject(new Error("画布操作超时"));
}, 30000);
this.pending.set(requestId, { clientId, resolve: (value) => (clearTimeout(timer), resolve(value)), reject: (error) => (clearTimeout(timer), reject(error)) });
+13 -4
View File
@@ -7,7 +7,8 @@ export const DEFAULT_PORT = 17371;
export const CONFIG_DIR = path.join(os.homedir(), ".infinite-canvas");
export const CONFIG_FILE = path.join(CONFIG_DIR, "canvas-agent.json");
export const VERSION = readPackageVersion();
export const AGENT_PROMPT = "你正在帮助用户操作 Infinite Canvas 网站。切换网站页面用 site_navigate,可跳 / (首页)、/canvas (我的画布)、/canvas/:id (指定画布)、/image、/video、/prompts、/assets、/config。需要改动画布时优先使用已配置的 infinite-canvas MCP 工具:先 canvas_get_state 读取当前画布,再根据任务使用 canvas_create_text_node、canvas_generate_text、canvas_generate_image、canvas_generate_video、canvas_generate_audio、canvas_create_generation_flow、canvas_create_config_node、canvas_run_generation、canvas_update_node、canvas_connect_nodes 等通用工具;复杂批量改动再用 canvas_apply_ops,删除连线可用 delete_connections。本轮若有用户上传的图片附件,会同时给出 attachmentId;用户要求把附件放入画布或作为生成参考图时,必须先用 canvas_create_attachment_nodes 创建真实图片节点,再把返回的节点 ID 传给 canvas_create_generation_flow.referenceNodeIds,不要创建空图片占位节点。若当前不在画布页,画布工具会报错,需先用 site_navigate 打开画布。想了解或打开用户已有画布,用 canvas_list_projects 获取画布清单和 id,再用 site_navigate 跳 /canvas/:id 打开。生图工作台可用 workbench_image_get_config 看可选项、workbench_image_generate 填提示词并生成;视频创作台对应 workbench_video_get_config 与 workbench_video_generate;用 prompts_search 分页搜索提示词库;用 assets_list 查看「我的素材」、assets_add 新增文本或图片素材。需要生成内容时直接调用对应生成工具,不要绑定特定业务场景。不要模拟鼠标点击,不要要求用户手动复制 JSON。";
export const AGENT_PROMPT = fs.readFileSync(new URL("../agent-instructions.md", import.meta.url), "utf8");
const initializedWorkspaces = new Set<string>();
export type SiteWorkspaceConfig = { workspacePath: string; activeThreadId?: string; pinnedThreadIds?: string[] };
export type CanvasAgentConfig = { url: string; token: string; origins?: string[]; workspace?: SiteWorkspaceConfig };
@@ -31,12 +32,12 @@ export function ensureSiteWorkspace(config: CanvasAgentConfig) {
const current = config.workspace;
if (current?.workspacePath) {
const workspacePath = resolveWorkspacePath(current.workspacePath);
fs.mkdirSync(workspacePath, { recursive: true });
initializeWorkspace(workspacePath);
return { ...current, workspacePath };
}
const workspacePath = path.join(CONFIG_DIR, "codex-workspaces", "site");
config.workspace = { workspacePath };
fs.mkdirSync(workspacePath, { recursive: true });
initializeWorkspace(workspacePath);
saveConfig(config);
return { workspacePath };
}
@@ -46,11 +47,19 @@ export function updateSiteWorkspace(config: CanvasAgentConfig, patch: Partial<Si
const workspacePath = patch.workspacePath ? resolveWorkspacePath(patch.workspacePath) : current.workspacePath;
const next = { ...current, ...patch, workspacePath };
config.workspace = { workspacePath: next.workspacePath, activeThreadId: next.activeThreadId, pinnedThreadIds: next.pinnedThreadIds };
fs.mkdirSync(workspacePath, { recursive: true });
initializeWorkspace(workspacePath);
saveConfig(config);
return config.workspace;
}
function initializeWorkspace(workspacePath: string) {
if (initializedWorkspaces.has(workspacePath)) return;
fs.mkdirSync(workspacePath, { recursive: true });
const instructionsFile = path.join(workspacePath, "AGENTS.md");
if (!fs.existsSync(instructionsFile)) fs.writeFileSync(instructionsFile, AGENT_PROMPT);
initializedWorkspaces.add(workspacePath);
}
function resolveWorkspacePath(value: string) {
if (value === "~") return os.homedir();
if (value.startsWith("~/")) return path.join(os.homedir(), value.slice(2));
+19 -2
View File
@@ -3,6 +3,7 @@ import express, { type NextFunction, type Request, type Response } from "express
import { DEFAULT_PORT, ensureSiteWorkspace, loadConfig, saveConfig, updateSiteWorkspace, type CanvasAgentConfig } from "./config.js";
import { CanvasSession } from "./canvas-session.js";
import { archiveCodexThread, interruptCodexTurn, isRecoverableThreadError, listCodexThreads, readCodexThread, resumeCodexThread, runClaudeTurn, runCodexTurn, startCodexThread, summarizeCodexThread, verifyCodexThreadWorkspace, withAgentPrompt } from "./agents.js";
import { logger } from "./utils/logger.js";
import type { AgentAttachment } from "./types.js";
export function startHttpServer() {
@@ -15,6 +16,7 @@ export function startHttpServer() {
const emit = (type: string, payload: unknown) => {
const data = payload && typeof payload === "object" && !Array.isArray(payload) ? payload as Record<string, unknown> : { value: payload };
const threadId = String(data.threadId || data.thread_id || ensureSiteWorkspace(config).activeThreadId || "");
logger.debug("Agent event", { type, threadId, payload: data });
threadId ? session.emitThread(type, threadId, data) : session.emitAll(type, data);
};
const setActiveThread = (activeThreadId: string, payload: Record<string, unknown> = {}) => {
@@ -25,6 +27,13 @@ export function startHttpServer() {
const app = express();
app.disable("x-powered-by");
app.use(express.json({ limit: "30mb" }));
app.use((req, res, next) => {
if (!logger.enabled) return next();
const startedAt = Date.now();
const url = requestUrl(req, config);
res.on("finish", () => logger.debug("HTTP request", { method: req.method, path: url.pathname, status: res.statusCode, durationMs: Date.now() - startedAt, origin: req.headers.origin, clientId: url.searchParams.get("clientId") }));
next();
});
app.use((req, res, next) => {
const url = requestUrl(req, config);
if (!setCors(req, res, url, config)) return void res.status(403).json({ ok: false, error: "origin not allowed" });
@@ -108,6 +117,7 @@ export function startHttpServer() {
const prompt = String(req.body?.prompt || "");
if (!prompt.trim()) return res.status(400).json({ ok: false, error: "请输入任务内容" });
const clientId = String(req.body?.clientId || "");
logger.info("Codex turn accepted", { clientId, threadId: req.body?.threadId, prompt, attachments: attachments.map(({ id, name, type, size, width, height }) => ({ id, name, type, size, width, height })) });
session.setCodexState({ busy: true, threadId: String(req.body?.threadId || workspace.activeThreadId || ""), turnId: "" });
try {
let threadId = String(req.body?.threadId || workspace.activeThreadId || "");
@@ -130,7 +140,7 @@ export function startHttpServer() {
const data = payload && typeof payload === "object" && !Array.isArray(payload) ? payload as Record<string, unknown> : { value: payload };
session.emitThread(type, threadId, data);
};
void runCodexTurn(withAgentPrompt(withAttachmentContext(prompt, attachmentRefs)), turnEmit, attachments, {
void runCodexTurn(withAttachmentContext(prompt, attachmentRefs), turnEmit, attachments, {
threadId,
cwd: workspace.workspacePath,
appEmit: emit,
@@ -148,9 +158,11 @@ export function startHttpServer() {
},
onTurn: (actualTurnId) => {
turnId = actualTurnId;
logger.info("Codex turn started", { threadId, turnId });
session.setCodexState({ busy: true, threadId, turnId });
},
onFinish: () => {
logger.info("Codex turn finished", { threadId, turnId });
session.clearTurnAttachments(clientId);
if (clientId) session.releaseClient(clientId);
session.setCodexState({ busy: false, threadId, turnId });
@@ -171,7 +183,10 @@ export function startHttpServer() {
res.json({ ok: true });
});
app.use((_req, res) => res.status(404).json({ ok: false, error: "not found" }));
app.use((error: Error, _req: Request, res: Response, _next: NextFunction) => res.status(500).json({ ok: false, error: error.message }));
app.use((error: Error, req: Request, res: Response, _next: NextFunction) => {
logger.error("HTTP request failed", { method: req.method, path: req.path, error });
res.status(500).json({ ok: false, error: error.message });
});
app.listen(port, "127.0.0.1", () => {
console.log("Infinite Canvas Agent");
@@ -180,6 +195,8 @@ export function startHttpServer() {
console.log("Codex MCP is not installed by this command.");
console.log("Optional MCP add: codex mcp add infinite-canvas -- npx -y @basketikun/canvas-agent mcp");
console.log("Remove manually added MCP: codex mcp remove infinite-canvas");
if (logger.enabled) console.log(`Debug log: ${logger.filePath}`);
logger.info("Canvas Agent started", { url: config.url, workspace: ensureSiteWorkspace(config).workspacePath, debugLog: logger.filePath });
});
}
+7
View File
@@ -0,0 +1,7 @@
/** 将日期格式化为适合文件名使用的本地日期字符串。 */
export function formatDateForFilename(date = new Date()) {
const year = date.getFullYear();
const month = String(date.getMonth() + 1).padStart(2, "0");
const day = String(date.getDate()).padStart(2, "0");
return `${year}-${month}-${day}`;
}
+77
View File
@@ -0,0 +1,77 @@
import fs from "node:fs";
import os from "node:os";
import path from "node:path";
import {inspect} from "node:util";
import winston, {format, transports, type Logger as WinstonLogger} from "winston";
import {formatDateForFilename} from "./date.js";
/** 管理 Canvas Agent 的终端与文件 Debug 日志。 */
export class Logger {
readonly enabled = process.argv.includes("--debug");
readonly filePath = this.enabled ? path.join(os.homedir(), ".infinite-canvas", "logs", `canvas-agent-${formatDateForFilename()}.log`) : "";
private readonly logger: WinstonLogger | null;
/** 根据命令行 Debug 参数初始化日志输出。 */
constructor() {
if (!this.enabled) {
this.logger = null;
return;
}
fs.mkdirSync(path.dirname(this.filePath), {recursive: true});
const line = format.printf(({level, message, timestamp, details}) => `[${level.toUpperCase()}][${timestamp}] ${message}${formatDetails(details)}`);
this.logger = winston.createLogger({
level: "debug",
transports: [
new transports.Console({format: format.combine(format.colorize(), format.timestamp({format: "HH:mm:ss"}), line)}),
new transports.File({filename: this.filePath, format: format.combine(format.timestamp({format: "HH:mm:ss"}), line)}),
],
});
}
/** 输出 Debug 级别日志。 */
debug(message: string, details?: unknown) {
if (details === undefined) this.logger?.debug(message);
else this.logger?.debug(message, {details: sanitize(details)});
}
/** 输出 Info 级别日志。 */
info(message: string, details?: unknown) {
if (details === undefined) this.logger?.info(message);
else this.logger?.info(message, {details: sanitize(details)});
}
/** 输出 Warn 级别日志。 */
warn(message: string, details?: unknown) {
if (details === undefined) this.logger?.warn(message);
else this.logger?.warn(message, {details: sanitize(details)});
}
/** 输出 Error 级别日志。 */
error(message: string, details?: unknown) {
if (details === undefined) this.logger?.error(message);
else this.logger?.error(message, {details: sanitize(details)});
}
}
/** 将日志详情格式化为紧凑的单行文本。 */
function formatDetails(details: unknown) {
if (details === undefined) return "";
if (!details || typeof details !== "object" || Array.isArray(details)) return ` ${inspect(details, {depth: null, breakLength: Infinity})}`;
return ` ${Object.entries(details).map(([key, value]) => `${key}=${inspect(value, {depth: null, breakLength: Infinity})}`).join(" ")}`;
}
/** 清理日志内容中的敏感数据和不可序列化引用。 */
function sanitize(value: unknown, key = "", seen = new WeakSet<object>()): unknown {
if (/token|authorization|api.?key|dataurl/i.test(key)) return "[REDACTED]";
if (typeof value === "string" && value.startsWith("data:")) return `[DATA URL ${value.length} chars]`;
if (value instanceof Error) return {name: value.name, message: value.message, stack: value.stack};
if (!value || typeof value !== "object") return value;
if (seen.has(value)) return "[CIRCULAR]";
seen.add(value);
if (Array.isArray(value)) return value.map((item) => sanitize(item, key, seen));
return Object.fromEntries(Object.entries(value as Record<string, unknown>).map(([field, item]) => [field, sanitize(item, field, seen)]));
}
export const logger = new Logger();