From a24bd2990e0ce5a3c0bc7b0a6fca61106c8ddea3 Mon Sep 17 00:00:00 2001 From: ysrastogi Date: Fri, 2 May 2025 22:25:25 +0530 Subject: [PATCH 1/5] feat: implement WorkspaceLogger for session logging and management --- .../src/utils/logger/workspace-logger.ts | 201 ++++++++++++++++++ 1 file changed, 201 insertions(+) create mode 100644 codex-cli/src/utils/logger/workspace-logger.ts diff --git a/codex-cli/src/utils/logger/workspace-logger.ts b/codex-cli/src/utils/logger/workspace-logger.ts new file mode 100644 index 000000000..56f9b39b4 --- /dev/null +++ b/codex-cli/src/utils/logger/workspace-logger.ts @@ -0,0 +1,201 @@ +import * as fs from "fs"; +import * as fsPromises from "fs/promises"; +import * as path from "path"; + +export enum LogEntryType { + SESSION_START = "SESSION_START", + SESSION_END = "SESSION_END", + USER_INPUT = "USER_INPUT", + MODEL_REASONING = "MODEL_REASONING", + MODEL_ACTION = "MODEL_ACTION", + FILE_CHANGE = "FILE_CHANGE", + COMMAND = "COMMAND", + ERROR = "ERROR", +} + +export class WorkspaceLogger { + private logFilePath: string; + private sessionStartTime: Date; + private fileChanges = 0; + private commandsExecuted = 0; + private isWriting: boolean = false; + private queue: Array = []; + + constructor(workspacePath: string) { + this.sessionStartTime = new Date(); + const timestamp = this.formatTimestamp(this.sessionStartTime, "file"); + const logDir = path.join(workspacePath, ".codex", "logs"); + + // Create directory if it doesn't exist + fs.mkdirSync(logDir, { recursive: true }); + + this.logFilePath = path.join(logDir, `codex-session-${timestamp}.log`); + this.logSessionStart(workspacePath); + } + + private formatTimestamp(date: Date, format: "log" | "file" = "log"): string { + if (format === "file") { + return date.toISOString().replace(/:/g, "-").replace(/\..+/, ""); + } + return date.toISOString().split(".")[0].replace("T", " "); + } + + private async appendToLog(entry: string): Promise { + this.queue.push(entry + "\n"); + await this.flushQueue(); + } + + private async flushQueue(): Promise { + if (this.isWriting || this.queue.length === 0) { + return; + } + + this.isWriting = true; + const entries = this.queue.join(""); + this.queue = []; + + try { + await fsPromises.appendFile(this.logFilePath, entries); + } catch (error) { + this.queue.push(`[ERROR] Failed to write to workspace log: ${error}\n`); + // eslint-disable-next-line no-console + console.error("Failed to write to workspace log:", error); + } finally { + this.isWriting = false; + } + + if (this.queue.length > 0) { + await this.flushQueue(); + } + } + + private async logEntry( + type: LogEntryType, + content: string, + details?: Array, + ): Promise { + const timestamp = this.formatTimestamp(new Date()); + let entry = `[${timestamp}] [${type}] ${content}`; + + if (details && details.length > 0) { + entry += "\n " + details.join("\n "); + } + + await this.appendToLog(entry); + } + + async logSessionStart(workspacePath: string): Promise { + await this.logEntry( + LogEntryType.SESSION_START, + "New Codex session initialized", + [ + `Working directory: ${workspacePath}`, + `Session ID: ${Math.random().toString(36).substring(2, 10)}`, + ], + ); + } + + async logSessionEnd(): Promise { + const endTime = new Date(); + const duration = + (endTime.getTime() - this.sessionStartTime.getTime()) / 1000; + const minutes = Math.floor(duration / 60); + const seconds = Math.floor(duration % 60); + + await this.logEntry(LogEntryType.SESSION_END, "Session completed", [ + `Duration: ${minutes}m ${seconds}s`, + `Files changed: ${this.fileChanges}`, + `Commands executed: ${this.commandsExecuted}`, + ]); + } + + async logUserInput(input: string, rawInput?: string): Promise { + const details = rawInput ? [`Raw prompt: "${rawInput}"`] : []; + await this.logEntry(LogEntryType.USER_INPUT, input, details); + } + + async logModelReasoning(reasoning: string): Promise { + const details = reasoning + .split("\n") + .filter((line) => line.trim().length > 0); + + await this.logEntry( + LogEntryType.MODEL_REASONING, + "Planning approach", + details, + ); + } + + async logModelAction(action: string, target?: string): Promise { + const details = target ? [`Target: ${target}`] : []; + await this.logEntry(LogEntryType.MODEL_ACTION, action, details); + } + + async logFileChange( + changeType: "Created" | "Modified" | "Deleted", + filePath: string, + ): Promise { + this.fileChanges++; + const details = []; + + if (changeType !== "Deleted" && fs.existsSync(filePath)) { + const stats = fs.statSync(filePath); + details.push(`Size: ${stats.size} bytes`); + } + + await this.logEntry( + LogEntryType.FILE_CHANGE, + `${changeType}: ${filePath}`, + details, + ); + } + + async logCommand( + command: string, + exitCode: number, + duration: number, + output?: string, + ): Promise { + this.commandsExecuted++; + const details = [ + `Exit code: ${exitCode}`, + `Duration: ${duration.toFixed(1)}s`, + ]; + + if (output) { + details.push( + `Output: ${output.length > 100 ? output.substring(0, 100) + "..." : output}`, + ); + } + + await this.logEntry(LogEntryType.COMMAND, command, details); + } + + async logError(message: string, error?: Error): Promise { + const details = []; + if (error) { + details.push(`Error: ${error.message}`); + if (error.stack) { + details.push( + `Stack: ${error.stack.substring(0, 500)}${error.stack.length > 500 ? "..." : ""}`, + ); + } + } + + await this.logEntry(LogEntryType.ERROR, message, details); + } +} + +// Singleton instance +let workspaceLogger: WorkspaceLogger | null = null; + +export function initWorkspaceLogger(workspacePath: string): WorkspaceLogger { + if (!workspaceLogger) { + workspaceLogger = new WorkspaceLogger(workspacePath); + } + return workspaceLogger; +} + +export function getWorkspaceLogger(): WorkspaceLogger | null { + return workspaceLogger; +} From 655101a39a5e79c354da9dbdcd08b0bec44e6bdd Mon Sep 17 00:00:00 2001 From: ysrastogi Date: Fri, 2 May 2025 22:25:43 +0530 Subject: [PATCH 2/5] feat: add command logging to handleExecCommand for performance tracking --- .../src/utils/agent/handle-exec-command.ts | 37 ++++++++++++++++++- 1 file changed, 35 insertions(+), 2 deletions(-) diff --git a/codex-cli/src/utils/agent/handle-exec-command.ts b/codex-cli/src/utils/agent/handle-exec-command.ts index ec0ba617a..843f5e084 100644 --- a/codex-cli/src/utils/agent/handle-exec-command.ts +++ b/codex-cli/src/utils/agent/handle-exec-command.ts @@ -12,6 +12,7 @@ import { ReviewDecision } from "./review.js"; import { isLoggingEnabled, log } from "../logger/log.js"; import { SandboxType } from "./sandbox/interface.js"; import { PATH_TO_SEATBELT_EXECUTABLE } from "./sandbox/macos-seatbelt.js"; +import { getWorkspaceLogger } from "../logger/workspace-logger.js"; import fs from "fs/promises"; // --------------------------------------------------------------------------- @@ -82,6 +83,7 @@ export async function handleExecCommand( ) => Promise, abortSignal?: AbortSignal, ): Promise { + const startTime = Date.now(); const { cmd: command, workdir } = args; const key = deriveCommandKey(command); @@ -89,13 +91,24 @@ export async function handleExecCommand( // 1) If the user has already said "always approve", skip // any policy & never sandbox. if (alwaysApprovedCommands.has(key)) { - return execCommand( + const summary = await execCommand( args, /* applyPatch */ undefined, /* runInSandbox */ false, additionalWritableRoots, abortSignal, - ).then(convertSummaryToResult); + ); + const duration = (Date.now() - startTime) / 1000; + const logger = getWorkspaceLogger(); + if (logger) { + await logger.logCommand( + args.cmd.join(" "), + summary.exitCode, + duration, + summary.stdout || summary.stderr, + ); + } + return convertSummaryToResult(summary); } // 2) Otherwise fall back to the normal policy @@ -181,9 +194,29 @@ export async function handleExecCommand( additionalWritableRoots, abortSignal, ); + const duration = (Date.now() - startTime) / 1000; + const logger = getWorkspaceLogger(); + if (logger) { + await logger.logCommand( + args.cmd.join(" "), + summary.exitCode, + duration, + summary.stdout || summary.stderr, + ); + } return convertSummaryToResult(summary); } } else { + const duration = (Date.now() - startTime) / 1000; + const logger = getWorkspaceLogger(); + if (logger) { + await logger.logCommand( + args.cmd.join(" "), + summary.exitCode, + duration, + summary.stdout || summary.stderr, + ); + } return convertSummaryToResult(summary); } } From 81a596be20cdc6bd1cde094ba7fd38930cc4cc9b Mon Sep 17 00:00:00 2001 From: ysrastogi Date: Fri, 2 May 2025 22:25:58 +0530 Subject: [PATCH 3/5] feat: integrate workspace logger for file change tracking in apply_commit function --- codex-cli/src/utils/agent/apply-patch.ts | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/codex-cli/src/utils/agent/apply-patch.ts b/codex-cli/src/utils/agent/apply-patch.ts index 525404c30..b403513b9 100644 --- a/codex-cli/src/utils/agent/apply-patch.ts +++ b/codex-cli/src/utils/agent/apply-patch.ts @@ -1,6 +1,7 @@ // Based on reference implementation from // https://cookbook.openai.com/examples/gpt4-1_prompting_guide#reference-implementation-apply_patchpy +import { getWorkspaceLogger } from "../logger/workspace-logger"; import fs from "fs"; import path from "path"; import { @@ -676,17 +677,23 @@ export function apply_commit( writeFn: (p: string, c: string) => void, removeFn: (p: string) => void, ): void { + const logger = getWorkspaceLogger(); + for (const [p, change] of Object.entries(commit.changes)) { if (change.type === ActionType.DELETE) { removeFn(p); + logger?.logFileChange("Deleted", p); } else if (change.type === ActionType.ADD) { writeFn(p, change.new_content ?? ""); + logger?.logFileChange("Created", p); } else if (change.type === ActionType.UPDATE) { if (change.move_path) { writeFn(change.move_path, change.new_content ?? ""); removeFn(p); + logger?.logFileChange("Modified", `${p} → ${change.move_path}`); } else { writeFn(p, change.new_content ?? ""); + logger?.logFileChange("Modified", p); } } } From ec12d568f44f26432bc3682d6e5b22d79067dcf1 Mon Sep 17 00:00:00 2001 From: ysrastogi Date: Fri, 2 May 2025 22:26:08 +0530 Subject: [PATCH 4/5] feat: integrate workspace logger for enhanced command and session tracking in AgentLoop --- codex-cli/src/utils/agent/agent-loop.ts | 99 ++++++++++++++++++++++++- 1 file changed, 98 insertions(+), 1 deletion(-) diff --git a/codex-cli/src/utils/agent/agent-loop.ts b/codex-cli/src/utils/agent/agent-loop.ts index 53da69798..89a2ae05c 100644 --- a/codex-cli/src/utils/agent/agent-loop.ts +++ b/codex-cli/src/utils/agent/agent-loop.ts @@ -19,6 +19,9 @@ import { getBaseUrl, } from "../config.js"; import { log } from "../logger/log.js"; +import { + initWorkspaceLogger +} from "../logger/workspace-logger.js"; import { parseToolCallArguments } from "../parsers.js"; import { responsesCreateViaChatCompletions } from "../responses.js"; import { @@ -32,6 +35,20 @@ import { handleExecCommand } from "./handle-exec-command.js"; import { randomUUID } from "node:crypto"; import OpenAI, { APIConnectionTimeoutError } from "openai"; +// interface ReasoningItem { +// type: string; +// text?: string; +// summary?: Array; +// duration_ms?: number; +// } + +// interface ExecInput { +// command: string | Array; +// workdir?: string; +// timeout?: number; +// [key: string]: unknown; +// } + // Wait time before retrying after rate limit errors (ms). const RATE_LIMIT_RETRY_WAIT_MS = parseInt( process.env["OPENAI_RATE_LIMIT_RETRY_WAIT_MS"] || "500", @@ -158,6 +175,8 @@ export class AgentLoop { /** Master abort controller – fires when terminate() is invoked. */ private readonly hardAbort = new AbortController(); + private workspaceLogger; + /** * Abort the ongoing request/stream, if any. This allows callers (typically * the UI layer) to interrupt the current agent step so the user can issue @@ -236,6 +255,11 @@ export class AgentLoop { if (this.terminated) { return; } + + if (this.workspaceLogger) { + this.workspaceLogger.logSessionEnd(); + } + this.terminated = true; this.hardAbort.abort(); @@ -327,6 +351,9 @@ export class AgentLoop { () => this.execAbortController?.abort(), { once: true }, ); + + this.workspaceLogger = initWorkspaceLogger(process.cwd()); + this.workspaceLogger.logSessionStart(process.cwd()); } private async handleFunctionCall( @@ -423,6 +450,19 @@ export class AgentLoop { this.getCommandConfirmation, this.execAbortController?.signal, ); + + const cmd = args.command || args.cmd || []; // Try both possible property names + const commandStr = Array.isArray(cmd) + ? cmd.join(" ") + : String(cmd); + + this.workspaceLogger?.logCommand( + commandStr, + metadata && typeof metadata['exit_code'] === 'number' ? metadata['exit_code'] : 0, + metadata && typeof metadata['duration_seconds'] === 'number' ? metadata['duration_seconds'] : 0, + outputText, + ); + outputItem.output = JSON.stringify({ output: outputText, metadata }); if (additionalItemsFromExec) { @@ -445,10 +485,32 @@ export class AgentLoop { // the user retry the request if desired. // --------------------------------------------------------------------- + // --------------------------------------------------------------------- + // Top‑level error wrapper so that known transient network issues like + // `ERR_STREAM_PREMATURE_CLOSE` do not crash the entire CLI process. + // Instead we surface the failure to the user as a regular system‑message + // and terminate the current run gracefully. The calling UI can then let + // the user retry the request if desired. + // --------------------------------------------------------------------- + try { if (this.terminated) { throw new Error("AgentLoop has been terminated"); } + + // Log user input at the start of a run + const userInput = input.find( + (item) => item.type === "message" && item.role === "user", + ); + + if (userInput) { + const contentItem = userInput.type === "message" && userInput.content && userInput.content[0]; + const content = typeof contentItem === 'object' && contentItem != null && 'text' in contentItem + ? contentItem.text + : JSON.stringify(userInput); + this.workspaceLogger?.logUserInput(content); + } + // Record when we start "thinking" so we can report accurate elapsed time. const thinkingStart = Date.now(); // Bump generation so that any late events from previous runs can be @@ -923,10 +985,20 @@ export class AgentLoop { if (event.type === "response.output_item.done") { const item = event.item; // 1) if it's a reasoning item, annotate it - type ReasoningItem = { type?: string; duration_ms?: number }; + type ReasoningItem = { + type?: string; + text?: string; + duration_ms?: number; + summary?: Array; + }; + const maybeReasoning = item as ReasoningItem; if (maybeReasoning.type === "reasoning") { maybeReasoning.duration_ms = Date.now() - thinkingStart; + // Add debug logging for reasoning summary + log( + `Reasoning summary received: ${JSON.stringify(maybeReasoning.summary)}`, + ); } if (item.type === "function_call") { // Track outstanding tool call so we can abort later if needed. @@ -942,6 +1014,23 @@ export class AgentLoop { } else { stageItem(item as ResponseItem); } + + if (item.type === "reasoning") { + const reasoningItem = item as ReasoningItem; + const reasoningText = reasoningItem.text || JSON.stringify(item); + log( + `Logging reasoning to workspace: ${reasoningText.substring(0, 100)}...`, + ); + this.workspaceLogger?.logModelReasoning(reasoningText); + if ( + reasoningItem.summary && + Array.isArray(reasoningItem.summary) + ) { + log( + `Reasoning summary: ${JSON.stringify(reasoningItem.summary)}`, + ); + } + } } if (event.type === "response.completed") { @@ -1233,6 +1322,14 @@ export class AgentLoop { // End of main logic. The corresponding catch block for the wrapper at the // start of this method follows next. } catch (err) { + // Log errors + if (err instanceof Error) { + this.workspaceLogger?.logError( + `Error in agent loop: ${err.message}`, + err, + ); + } + // Handle known transient network/streaming issues so they do not crash the // CLI. We currently match Node/undici's `ERR_STREAM_PREMATURE_CLOSE` // error which manifests when the HTTP/2 stream terminates unexpectedly From 8f010b334f15f0d2325a0628667c8c5aeafe2aa8 Mon Sep 17 00:00:00 2001 From: ysrastogi Date: Fri, 2 May 2025 22:28:53 +0530 Subject: [PATCH 5/5] refactor: remove unused interfaces for cleaner code in agent-loop --- codex-cli/src/utils/agent/agent-loop.ts | 13 ------------- 1 file changed, 13 deletions(-) diff --git a/codex-cli/src/utils/agent/agent-loop.ts b/codex-cli/src/utils/agent/agent-loop.ts index 19596853e..dbd9412a4 100644 --- a/codex-cli/src/utils/agent/agent-loop.ts +++ b/codex-cli/src/utils/agent/agent-loop.ts @@ -35,19 +35,6 @@ import { handleExecCommand } from "./handle-exec-command.js"; import { randomUUID } from "node:crypto"; import OpenAI, { APIConnectionTimeoutError } from "openai"; -// interface ReasoningItem { -// type: string; -// text?: string; -// summary?: Array; -// duration_ms?: number; -// } - -// interface ExecInput { -// command: string | Array; -// workdir?: string; -// timeout?: number; -// [key: string]: unknown; -// } // Wait time before retrying after rate limit errors (ms). const RATE_LIMIT_RETRY_WAIT_MS = parseInt(