From 1654a4fef009c0728fb53b8af6c03888ef45970f Mon Sep 17 00:00:00 2001 From: Timothy Zelinsky Date: Tue, 24 Mar 2026 23:00:03 +1100 Subject: [PATCH 1/3] Add opt-in SDK logging --- .../Shared/AgentDemoRuntimeFactory.swift | 32 ++- .../Shared/AgentDemoView+ChatSections.swift | 2 +- .../Shared/AgentDemoViewModel.swift | 44 +++ README.md | 47 ++++ .../CodexKit/Auth/ChatGPTSessionManager.swift | 42 ++- .../CodexKit/Memory/SQLiteMemoryStore.swift | 19 +- Sources/CodexKit/Runtime/AgentLogging.swift | 260 ++++++++++++++++++ .../AgentRuntime+ContextCompaction.swift | 31 ++- .../Runtime/AgentRuntime+History.swift | 44 +++ .../Runtime/AgentRuntime+Messaging.swift | 38 +++ .../Runtime/AgentRuntime+Threads.swift | 41 +++ ...gentRuntime+ToolInvocationResolution.swift | 37 +++ .../AgentRuntime+TurnConsumption.swift | 36 +++ Sources/CodexKit/Runtime/AgentRuntime.swift | 36 ++- .../CodexResponsesBackend+Compaction.swift | 27 ++ .../Runtime/CodexResponsesBackend.swift | 31 ++- .../Runtime/CodexResponsesTransport.swift | 50 +++- .../Runtime/CodexResponsesTurnRunner.swift | 68 ++++- .../Runtime/FileRuntimeStateStore.swift | 24 +- .../GRDBRuntimeStateStore+Persistence.swift | 5 +- .../Runtime/GRDBRuntimeStateStore.swift | 30 +- .../Runtime/InMemoryRuntimeStateStore.swift | 16 +- .../AgentRuntimeLoggingTests.swift | 127 +++++++++ 23 files changed, 1064 insertions(+), 23 deletions(-) create mode 100644 Sources/CodexKit/Runtime/AgentLogging.swift create mode 100644 Tests/CodexKitTests/AgentRuntimeLoggingTests.swift diff --git a/DemoApp/AssistantRuntimeDemoApp/Shared/AgentDemoRuntimeFactory.swift b/DemoApp/AssistantRuntimeDemoApp/Shared/AgentDemoRuntimeFactory.swift index 4a508f7..b8c3396 100644 --- a/DemoApp/AssistantRuntimeDemoApp/Shared/AgentDemoRuntimeFactory.swift +++ b/DemoApp/AssistantRuntimeDemoApp/Shared/AgentDemoRuntimeFactory.swift @@ -73,6 +73,8 @@ enum AgentDemoRuntimeFactory { approvalInbox: ApprovalInbox, deviceCodePromptCoordinator: DeviceCodePromptCoordinator ) -> AgentRuntime { + let diagnostics = DemoDiagnostics() + let sdkLogging = diagnostics.sdkLoggingConfiguration() let authProvider: any ChatGPTAuthProviding switch authenticationMethod { @@ -98,13 +100,21 @@ enum AgentDemoRuntimeFactory { configuration: CodexResponsesBackendConfiguration( model: model, reasoningEffort: reasoningEffort, - enableWebSearch: enableWebSearch + enableWebSearch: enableWebSearch, + logging: sdkLogging ) ), approvalPresenter: approvalInbox, - stateStore: try! GRDBRuntimeStateStore(url: stateURL ?? defaultStateURL()), + stateStore: try! GRDBRuntimeStateStore( + url: stateURL ?? defaultStateURL(), + logging: sdkLogging + ), + logging: sdkLogging, memory: .init( - store: try! SQLiteMemoryStore(url: defaultMemoryURL()), + store: try! SQLiteMemoryStore( + url: defaultMemoryURL(), + logging: sdkLogging + ), automaticCapturePolicy: .init( source: .lastTurn, options: .init( @@ -137,6 +147,8 @@ enum AgentDemoRuntimeFactory { reasoningEffort: ReasoningEffort = .medium, keychainAccount: String = defaultKeychainAccount ) -> AgentRuntime { + let diagnostics = DemoDiagnostics() + let sdkLogging = diagnostics.sdkLoggingConfiguration() let authProvider = try! ChatGPTAuthProvider(method: .oauth) return try! AgentRuntime(configuration: .init( @@ -149,13 +161,21 @@ enum AgentDemoRuntimeFactory { configuration: CodexResponsesBackendConfiguration( model: model, reasoningEffort: reasoningEffort, - enableWebSearch: enableWebSearch + enableWebSearch: enableWebSearch, + logging: sdkLogging ) ), approvalPresenter: NonInteractiveApprovalPresenter(), - stateStore: try! GRDBRuntimeStateStore(url: defaultStateURL()), + stateStore: try! GRDBRuntimeStateStore( + url: defaultStateURL(), + logging: sdkLogging + ), + logging: sdkLogging, memory: .init( - store: try! SQLiteMemoryStore(url: defaultMemoryURL()), + store: try! SQLiteMemoryStore( + url: defaultMemoryURL(), + logging: sdkLogging + ), automaticCapturePolicy: .init( source: .lastTurn, options: .init( diff --git a/DemoApp/AssistantRuntimeDemoApp/Shared/AgentDemoView+ChatSections.swift b/DemoApp/AssistantRuntimeDemoApp/Shared/AgentDemoView+ChatSections.swift index 70242ac..93f8c5f 100644 --- a/DemoApp/AssistantRuntimeDemoApp/Shared/AgentDemoView+ChatSections.swift +++ b/DemoApp/AssistantRuntimeDemoApp/Shared/AgentDemoView+ChatSections.swift @@ -50,7 +50,7 @@ extension AgentDemoView { ) .toggleStyle(.switch) - Text("Debug builds start with logging enabled. Logs print to the Xcode console for restore, sign-in, thread lifecycle, turn events, and tool activity.") + Text("Debug builds start with logging enabled. Logs print to the Xcode console for both demo actions and SDK internals like history writes, thread creation, network calls, retries, compaction, and tool activity.") .font(.caption) .foregroundStyle(.secondary) diff --git a/DemoApp/AssistantRuntimeDemoApp/Shared/AgentDemoViewModel.swift b/DemoApp/AssistantRuntimeDemoApp/Shared/AgentDemoViewModel.swift index 337a650..1bc66de 100644 --- a/DemoApp/AssistantRuntimeDemoApp/Shared/AgentDemoViewModel.swift +++ b/DemoApp/AssistantRuntimeDemoApp/Shared/AgentDemoViewModel.swift @@ -156,6 +156,10 @@ struct DemoDiagnostics { #endif } + func developerLoggingEnabled(userDefaults: UserDefaults = .standard) -> Bool { + initialDeveloperLoggingEnabled(userDefaults: userDefaults) + } + func persistDeveloperLoggingEnabled( _ enabled: Bool, userDefaults: UserDefaults = .standard @@ -176,6 +180,46 @@ struct DemoDiagnostics { logger.error("\(message, privacy: .public)") print("[CodexKit Demo][Error] \(message)") } + + func sdkLoggingConfiguration() -> AgentLoggingConfiguration { + AgentLoggingConfiguration( + minimumLevel: .debug, + sink: DemoSDKLogSink(diagnostics: self) + ) + } +} + +struct DemoSDKLogSink: AgentLogSink { + let diagnostics: DemoDiagnostics + + func log(_ entry: AgentLogEntry) { + guard diagnostics.developerLoggingEnabled() else { + return + } + + let levelLabel: String + switch entry.level { + case .debug: + levelLabel = "DEBUG" + case .info: + levelLabel = "INFO" + case .warning: + levelLabel = "WARN" + case .error: + levelLabel = "ERROR" + } + + var message = "[SDK][\(levelLabel)][\(entry.category.rawValue)] \(entry.message)" + if !entry.metadata.isEmpty { + let renderedMetadata = entry.metadata + .sorted { $0.key < $1.key } + .map { "\($0.key)=\($0.value)" } + .joined(separator: " ") + message += " | \(renderedMetadata)" + } + + diagnostics.log(message) + } } @MainActor diff --git a/README.md b/README.md index af6c733..8c172a8 100644 --- a/README.md +++ b/README.md @@ -20,6 +20,7 @@ Use `CodexKit` if you are building a SwiftUI app for iOS or macOS and want: - host-defined tools with approval gates - persona- and skill-aware agent behavior - hidden runtime context compaction with preserved user-visible history +- opt-in developer logging across runtime, auth, backend, and bundled stores - share/import-friendly message construction The SDK stays tool-agnostic. Your app defines the tool surface and runtime UX. @@ -227,6 +228,52 @@ let backend = CodexResponsesBackend( ) ``` +## Developer Logging + +`CodexKit` includes opt-in developer logging for the SDK itself. Logging is disabled by default and can be enabled independently on the runtime, built-in backend, and bundled stores. + +```swift +let logging = AgentLoggingConfiguration.console( + minimumLevel: .debug +) + +let backend = CodexResponsesBackend( + configuration: .init( + model: "gpt-5.4", + logging: logging + ) +) + +let stateStore = try GRDBRuntimeStateStore( + url: stateURL, + logging: logging +) + +let runtime = try AgentRuntime(configuration: .init( + authProvider: authProvider, + secureStore: secureStore, + backend: backend, + approvalPresenter: approvalInbox, + stateStore: stateStore, + logging: logging +)) +``` + +Available logging categories include: + +- `auth` +- `runtime` +- `persistence` +- `network` +- `retry` +- `compaction` +- `tools` +- `approvals` +- `structuredOutput` +- `memory` + +Use `AgentConsoleLogSink` for stderr-style console logs, `AgentOSLogSink` for unified Apple logging, or provide your own `AgentLogSink`. + Available values: - `.low` diff --git a/Sources/CodexKit/Auth/ChatGPTSessionManager.swift b/Sources/CodexKit/Auth/ChatGPTSessionManager.swift index b5f60bb..524d3f0 100644 --- a/Sources/CodexKit/Auth/ChatGPTSessionManager.swift +++ b/Sources/CodexKit/Auth/ChatGPTSessionManager.swift @@ -3,20 +3,28 @@ import Foundation public actor ChatGPTSessionManager { private let authProvider: any ChatGPTAuthProviding private let secureStore: any SessionSecureStoring + private let logger: AgentLogger private var session: ChatGPTSession? public init( authProvider: any ChatGPTAuthProviding, - secureStore: any SessionSecureStoring + secureStore: any SessionSecureStoring, + logging: AgentLoggingConfiguration = .disabled ) { self.authProvider = authProvider self.secureStore = secureStore + self.logger = AgentLogger(configuration: logging) } @discardableResult public func restore() throws -> ChatGPTSession? { let restored = try secureStore.loadSession() session = restored + logger.debug( + .auth, + "Restored session from secure store.", + metadata: ["restored": "\(restored != nil)"] + ) return restored } @@ -29,15 +37,33 @@ public actor ChatGPTSessionManager { let signedInSession = try await authProvider.signInInteractively() try secureStore.saveSession(signedInSession) session = signedInSession + logger.info( + .auth, + "Persisted signed-in session.", + metadata: ["account_id": signedInSession.account.id] + ) return signedInSession } @discardableResult public func refresh(reason: ChatGPTAuthRefreshReason) async throws -> ChatGPTSession { let current = try requireStoredSession() + logger.info( + .auth, + "Refreshing session.", + metadata: [ + "reason": String(describing: reason), + "account_id": current.account.id + ] + ) let refreshed = try await authProvider.refresh(session: current, reason: reason) try secureStore.saveSession(refreshed) session = refreshed + logger.info( + .auth, + "Session refresh completed.", + metadata: ["account_id": refreshed.account.id] + ) return refreshed } @@ -46,6 +72,11 @@ public actor ChatGPTSessionManager { session = nil try secureStore.deleteSession() await authProvider.signOut(session: current) + logger.info( + .auth, + "Session signed out.", + metadata: ["had_session": "\(current != nil)"] + ) } public func requireSession() async throws -> ChatGPTSession { @@ -61,11 +92,20 @@ public actor ChatGPTSessionManager { public func recoverUnauthorizedSession( previousAccessToken: String? ) async throws -> ChatGPTSession { + logger.warning( + .auth, + "Attempting unauthorized-session recovery." + ) if let restored = try secureStore.loadSession() { session = restored if let previousAccessToken, restored.accessToken != previousAccessToken, !restored.requiresRefresh() { + logger.info( + .auth, + "Recovered session from secure store after unauthorized response.", + metadata: ["account_id": restored.account.id] + ) return restored } } diff --git a/Sources/CodexKit/Memory/SQLiteMemoryStore.swift b/Sources/CodexKit/Memory/SQLiteMemoryStore.swift index 0b6ee32..b990e83 100644 --- a/Sources/CodexKit/Memory/SQLiteMemoryStore.swift +++ b/Sources/CodexKit/Memory/SQLiteMemoryStore.swift @@ -3,13 +3,18 @@ import GRDB public actor SQLiteMemoryStore: MemoryStoring { private let url: URL + private let logger: AgentLogger private let dbQueue: DatabaseQueue private let schema: SQLiteMemoryStoreSchema private let repository: SQLiteMemoryStoreRepository private let migrator: DatabaseMigrator - public init(url: URL) throws { + public init( + url: URL, + logging: AgentLoggingConfiguration = .disabled + ) throws { self.url = url + self.logger = AgentLogger(configuration: logging) self.schema = SQLiteMemoryStoreSchema() let codec = SQLiteMemoryStoreCodec() self.repository = SQLiteMemoryStoreRepository(codec: codec) @@ -36,9 +41,11 @@ public actor SQLiteMemoryStore: MemoryStoring { } try migrator.migrate(dbQueue) + logger.info(.memory, "SQLite memory store prepared.", metadata: ["url": url.path]) } public func put(_ record: MemoryRecord) async throws { + logger.debug(.memory, "Writing memory record.", metadata: ["namespace": record.namespace, "record_id": record.id]) try MemoryQueryEngine.validateNamespace(record.namespace) let repository = self.repository try await writeTransaction { db in @@ -51,6 +58,7 @@ public actor SQLiteMemoryStore: MemoryStoring { } public func putMany(_ records: [MemoryRecord]) async throws { + logger.debug(.memory, "Writing many memory records.", metadata: ["count": "\(records.count)"]) let repository = self.repository try await writeTransaction { db in for record in records { @@ -65,6 +73,7 @@ public actor SQLiteMemoryStore: MemoryStoring { } public func upsert(_ record: MemoryRecord, dedupeKey: String) async throws { + logger.debug(.memory, "Upserting memory record by dedupe key.", metadata: ["namespace": record.namespace, "record_id": record.id]) try MemoryQueryEngine.validateNamespace(record.namespace) let repository = self.repository try await writeTransaction { db in @@ -77,6 +86,14 @@ public actor SQLiteMemoryStore: MemoryStoring { } public func query(_ query: MemoryQuery) async throws -> MemoryQueryResult { + logger.debug( + .memory, + "Querying memory store.", + metadata: [ + "namespace": query.namespace, + "text_length": "\(query.text?.count ?? 0)" + ] + ) try MemoryQueryEngine.validateNamespace(query.namespace) let records = try await dbQueue.read { db in try repository.loadRecords(namespace: query.namespace, in: db) diff --git a/Sources/CodexKit/Runtime/AgentLogging.swift b/Sources/CodexKit/Runtime/AgentLogging.swift new file mode 100644 index 0000000..c3f1a63 --- /dev/null +++ b/Sources/CodexKit/Runtime/AgentLogging.swift @@ -0,0 +1,260 @@ +import Foundation +import OSLog + +public enum AgentLogLevel: Int, Sendable, Codable, CaseIterable { + case debug = 0 + case info = 1 + case warning = 2 + case error = 3 +} + +extension AgentLogLevel: Comparable { + public static func < (lhs: AgentLogLevel, rhs: AgentLogLevel) -> Bool { + lhs.rawValue < rhs.rawValue + } +} + +public enum AgentLogCategory: String, Sendable, Codable, Hashable, CaseIterable { + case auth + case runtime + case persistence + case network + case retry + case compaction + case tools + case approvals + case structuredOutput + case memory +} + +public struct AgentLogEntry: Sendable, Equatable { + public let timestamp: Date + public let level: AgentLogLevel + public let category: AgentLogCategory + public let message: String + public let metadata: [String: String] + + public init( + timestamp: Date = Date(), + level: AgentLogLevel, + category: AgentLogCategory, + message: String, + metadata: [String: String] = [:] + ) { + self.timestamp = timestamp + self.level = level + self.category = category + self.message = message + self.metadata = metadata + } +} + +public protocol AgentLogSink: Sendable { + func log(_ entry: AgentLogEntry) +} + +public struct AnyAgentLogSink: AgentLogSink, Sendable { + private let emit: @Sendable (AgentLogEntry) -> Void + + public init(_ emit: @escaping @Sendable (AgentLogEntry) -> Void) { + self.emit = emit + } + + public init(_ sink: Sink) { + self.emit = { entry in + sink.log(entry) + } + } + + public func log(_ entry: AgentLogEntry) { + emit(entry) + } +} + +public struct AgentConsoleLogSink: AgentLogSink, Sendable { + public init() {} + + public func log(_ entry: AgentLogEntry) { + FileHandle.standardError.write(Data((entry.renderedLine + "\n").utf8)) + } +} + +public struct AgentOSLogSink: AgentLogSink, Sendable { + public let subsystem: String + + public init(subsystem: String = "CodexKit") { + self.subsystem = subsystem + } + + public func log(_ entry: AgentLogEntry) { + let logger = Logger(subsystem: subsystem, category: entry.category.rawValue) + let renderedLine = entry.renderedLine + switch entry.level { + case .debug: + logger.debug("\(renderedLine, privacy: .public)") + case .info: + logger.info("\(renderedLine, privacy: .public)") + case .warning: + logger.notice("\(renderedLine, privacy: .public)") + case .error: + logger.error("\(renderedLine, privacy: .public)") + } + } +} + +public struct AgentLoggingConfiguration: Sendable { + public let isEnabled: Bool + public let minimumLevel: AgentLogLevel + public let categories: Set? + public let sink: AnyAgentLogSink? + + public init() { + self.isEnabled = false + self.minimumLevel = .info + self.categories = nil + self.sink = nil + } + + public init( + minimumLevel: AgentLogLevel = .info, + categories: Set? = nil, + sink: some AgentLogSink + ) { + self.isEnabled = true + self.minimumLevel = minimumLevel + self.categories = categories + self.sink = AnyAgentLogSink(sink) + } + + public static let disabled = AgentLoggingConfiguration() + + public static func console( + minimumLevel: AgentLogLevel = .info, + categories: Set? = nil + ) -> AgentLoggingConfiguration { + AgentLoggingConfiguration( + minimumLevel: minimumLevel, + categories: categories, + sink: AgentConsoleLogSink() + ) + } + + public static func osLog( + minimumLevel: AgentLogLevel = .info, + categories: Set? = nil, + subsystem: String = "CodexKit" + ) -> AgentLoggingConfiguration { + AgentLoggingConfiguration( + minimumLevel: minimumLevel, + categories: categories, + sink: AgentOSLogSink(subsystem: subsystem) + ) + } + + func allows( + level: AgentLogLevel, + category: AgentLogCategory + ) -> Bool { + guard isEnabled, + level >= minimumLevel + else { + return false + } + guard let categories else { + return true + } + return categories.contains(category) + } +} + +struct AgentLogger: Sendable { + let configuration: AgentLoggingConfiguration + + init(configuration: AgentLoggingConfiguration = .disabled) { + self.configuration = configuration + } + + func debug( + _ category: AgentLogCategory, + _ message: String, + metadata: [String: String] = [:] + ) { + log(.debug, category, message, metadata: metadata) + } + + func info( + _ category: AgentLogCategory, + _ message: String, + metadata: [String: String] = [:] + ) { + log(.info, category, message, metadata: metadata) + } + + func warning( + _ category: AgentLogCategory, + _ message: String, + metadata: [String: String] = [:] + ) { + log(.warning, category, message, metadata: metadata) + } + + func error( + _ category: AgentLogCategory, + _ message: String, + metadata: [String: String] = [:] + ) { + log(.error, category, message, metadata: metadata) + } + + private func log( + _ level: AgentLogLevel, + _ category: AgentLogCategory, + _ message: String, + metadata: [String: String] + ) { + guard configuration.allows(level: level, category: category), + let sink = configuration.sink + else { + return + } + + sink.log( + AgentLogEntry( + level: level, + category: category, + message: message, + metadata: metadata + ) + ) + } +} + +private extension AgentLogEntry { + var renderedLine: String { + let formatter = ISO8601DateFormatter() + var line = "[\(formatter.string(from: timestamp))] [\(level.renderedName)] [\(category.rawValue)] \(message)" + if !metadata.isEmpty { + let renderedMetadata = metadata + .sorted { $0.key < $1.key } + .map { "\($0.key)=\($0.value)" } + .joined(separator: " ") + line += " | \(renderedMetadata)" + } + return line + } +} + +private extension AgentLogLevel { + var renderedName: String { + switch self { + case .debug: + return "DEBUG" + case .info: + return "INFO" + case .warning: + return "WARN" + case .error: + return "ERROR" + } + } +} diff --git a/Sources/CodexKit/Runtime/AgentRuntime+ContextCompaction.swift b/Sources/CodexKit/Runtime/AgentRuntime+ContextCompaction.swift index 13b0243..d58572b 100644 --- a/Sources/CodexKit/Runtime/AgentRuntime+ContextCompaction.swift +++ b/Sources/CodexKit/Runtime/AgentRuntime+ContextCompaction.swift @@ -54,6 +54,15 @@ extension AgentRuntime { pendingMessage: request, instructions: instructions ) + logger.debug( + .compaction, + "Evaluated pre-turn compaction threshold.", + metadata: [ + "thread_id": thread.id, + "estimated_tokens": "\(estimatedTokens)", + "threshold": "\(threshold)" + ] + ) guard estimatedTokens > threshold else { return } @@ -137,7 +146,7 @@ extension AgentRuntime { instructions: String, tools: [ToolDefinition], session: ChatGPTSession - ) async throws -> AgentThreadContextState { + ) async throws -> AgentThreadContextState { guard shouldUseCompaction() else { throw AgentRuntimeError.contextCompactionDisabled() } @@ -150,6 +159,15 @@ extension AgentRuntime { threadID: threadID, effectiveMessages: state.messagesByThread[threadID] ?? [] ) + logger.info( + .compaction, + "Compacting thread context.", + metadata: [ + "thread_id": threadID, + "reason": reason.rawValue, + "effective_message_count": "\(current.effectiveMessages.count)" + ] + ) let result = try await performCompaction( thread: thread, effectiveHistory: current.effectiveMessages, @@ -195,6 +213,17 @@ extension AgentRuntime { state.nextHistorySequenceByThread[threadID] = nextGenerationSequence(afterAppendingTo: threadID) enqueueStoreOperation(.appendCompactionMarker(threadID: threadID, marker: markerRecord)) try await persistState() + logger.info( + .compaction, + "Thread context compaction completed.", + metadata: [ + "thread_id": threadID, + "reason": reason.rawValue, + "generation": "\(updated.generation)", + "effective_message_count_before": "\(current.effectiveMessages.count)", + "effective_message_count_after": "\(updated.effectiveMessages.count)" + ] + ) return updated } diff --git a/Sources/CodexKit/Runtime/AgentRuntime+History.swift b/Sources/CodexKit/Runtime/AgentRuntime+History.swift index 24152db..9ef7075 100644 --- a/Sources/CodexKit/Runtime/AgentRuntime+History.swift +++ b/Sources/CodexKit/Runtime/AgentRuntime+History.swift @@ -156,6 +156,20 @@ extension AgentRuntime { createdAt: createdAt, item: item ) + var metadata: [String: String] = [ + "thread_id": threadID, + "record_id": record.id, + "sequence": "\(record.sequenceNumber)", + "kind": historyItemKind(for: item).rawValue, + ] + if let systemEventType = historySystemEventType(for: item) { + metadata["system_event_type"] = systemEventType + } + logger.debug( + .persistence, + "Appending history item.", + metadata: metadata + ) state.historyByThread[threadID, default: []].append(record) state.nextHistorySequenceByThread[threadID] = nextSequence + 1 enqueueStoreOperation( @@ -329,6 +343,36 @@ extension AgentRuntime { resultPreview: result?.primaryText ) } + + private func historyItemKind( + for item: AgentHistoryItem + ) -> AgentHistoryItemKind { + switch item { + case .message: + return .message + case .toolCall: + return .toolCall + case .toolResult: + return .toolResult + case .structuredOutput: + return .structuredOutput + case .approval: + return .approval + case .systemEvent: + return .systemEvent + } + } + + private func historySystemEventType( + for item: AgentHistoryItem + ) -> String? { + switch item { + case let .systemEvent(record): + return record.type.rawValue + default: + return nil + } + } } private extension AgentHistoryFilter { diff --git a/Sources/CodexKit/Runtime/AgentRuntime+Messaging.swift b/Sources/CodexKit/Runtime/AgentRuntime+Messaging.swift index 7dfa20b..0ff0b16 100644 --- a/Sources/CodexKit/Runtime/AgentRuntime+Messaging.swift +++ b/Sources/CodexKit/Runtime/AgentRuntime+Messaging.swift @@ -55,6 +55,17 @@ extension AgentRuntime { images: request.images ) + logger.info( + .runtime, + "Starting structured streamed message.", + metadata: [ + "thread_id": threadID, + "text_length": "\(request.text.count)", + "image_count": "\(request.images.count)", + "response_format": responseFormat.name + ] + ) + try await appendMessage(userMessage) try await setThreadStatus(.streaming, for: threadID) @@ -108,6 +119,14 @@ extension AgentRuntime { continuation: continuation ) } catch { + self.logger.error( + .runtime, + "Structured streamed message failed during startup.", + metadata: [ + "thread_id": threadID, + "error": error.localizedDescription + ] + ) await self.handleStructuredTurnStartupFailure( error, for: threadID, @@ -194,6 +213,17 @@ extension AgentRuntime { images: request.images ) + logger.info( + .runtime, + "Starting streamed message.", + metadata: [ + "thread_id": threadID, + "text_length": "\(request.text.count)", + "image_count": "\(request.images.count)", + "structured_response": "\(responseFormat != nil || streamedStructuredOutput != nil)" + ] + ) + try await appendMessage(userMessage) try await setThreadStatus(.streaming, for: threadID) @@ -240,6 +270,14 @@ extension AgentRuntime { continuation: continuation ) } catch { + self.logger.error( + .runtime, + "Streamed message failed during startup.", + metadata: [ + "thread_id": threadID, + "error": error.localizedDescription + ] + ) await self.handleTurnStartupFailure( error, for: threadID, diff --git a/Sources/CodexKit/Runtime/AgentRuntime+Threads.swift b/Sources/CodexKit/Runtime/AgentRuntime+Threads.swift index c536851..beb5871 100644 --- a/Sources/CodexKit/Runtime/AgentRuntime+Threads.swift +++ b/Sources/CodexKit/Runtime/AgentRuntime+Threads.swift @@ -22,6 +22,14 @@ extension AgentRuntime { } let session = try await sessionManager.requireSession() + logger.info( + .runtime, + "Creating thread.", + metadata: [ + "has_title": "\(title != nil)", + "skill_count": "\(skillIDs.count)" + ] + ) let creation = try await withUnauthorizedRecovery( initialSession: session ) { session in @@ -48,11 +56,17 @@ extension AgentRuntime { ) updateThreadTimestamp(thread.createdAt, for: thread.id) try await persistState() + logger.info( + .runtime, + "Thread created.", + metadata: ["thread_id": thread.id] + ) return thread } @discardableResult public func resumeThread(id: String) async throws -> AgentThread { + logger.info(.runtime, "Resuming thread.", metadata: ["thread_id": id]) let session = try await sessionManager.requireSession() let resume = try await withUnauthorizedRecovery( initialSession: session @@ -74,6 +88,7 @@ extension AgentRuntime { ) updateThreadTimestamp(Date(), for: thread.id) try await persistState() + logger.info(.runtime, "Thread resumed.", metadata: ["thread_id": thread.id]) return thread } @@ -103,6 +118,14 @@ extension AgentRuntime { state.threads[index].updatedAt = Date() enqueueStoreOperation(.upsertThread(state.threads[index])) try await persistState() + logger.info( + .runtime, + "Updated thread title.", + metadata: [ + "thread_id": threadID, + "has_title": "\(title?.isEmpty == false)" + ] + ) } public func setPersonaStack( @@ -210,9 +233,27 @@ extension AgentRuntime { ) } try await persistState() + logger.debug( + .runtime, + "Thread status changed.", + metadata: [ + "thread_id": threadID, + "status": status.rawValue + ] + ) } func appendMessage(_ message: AgentMessage) async throws { + logger.debug( + .runtime, + "Appending message to thread.", + metadata: [ + "thread_id": message.threadID, + "role": message.role.rawValue, + "text_length": "\(message.text.count)", + "image_count": "\(message.images.count)" + ] + ) state.messagesByThread[message.threadID, default: []].append(message) appendEffectiveMessage(message) appendHistoryItem( diff --git a/Sources/CodexKit/Runtime/AgentRuntime+ToolInvocationResolution.swift b/Sources/CodexKit/Runtime/AgentRuntime+ToolInvocationResolution.swift index 970e111..0d77d08 100644 --- a/Sources/CodexKit/Runtime/AgentRuntime+ToolInvocationResolution.swift +++ b/Sources/CodexKit/Runtime/AgentRuntime+ToolInvocationResolution.swift @@ -48,6 +48,15 @@ extension AgentRuntime { yieldApprovalRequested: (ApprovalRequest) -> Void, yieldApprovalResolved: (ApprovalResolution) -> Void ) async throws -> ToolResultEnvelope { + logger.info( + .tools, + "Resolving tool invocation.", + metadata: [ + "thread_id": invocation.threadID, + "turn_id": invocation.turnID, + "tool_name": invocation.toolName + ] + ) if let definition = await toolRegistry.definition(named: invocation.toolName), definition.approvalPolicy == .requiresApproval { let approval = ApprovalRequest( @@ -82,6 +91,15 @@ extension AgentRuntime { try await setThreadStatus(.waitingForApproval, for: invocation.threadID) yieldThreadStatusChanged(invocation.threadID, .waitingForApproval) yieldApprovalRequested(approval) + logger.info( + .approvals, + "Tool invocation requires approval.", + metadata: [ + "thread_id": invocation.threadID, + "tool_name": invocation.toolName, + "request_id": approval.id + ] + ) let decision = try await approvalCoordinator.requestApproval(approval) let resolution = ApprovalResolution( @@ -104,6 +122,15 @@ extension AgentRuntime { ) try setPendingState(nil, for: invocation.threadID) yieldApprovalResolved(resolution) + logger.info( + .approvals, + "Tool approval resolved.", + metadata: [ + "thread_id": invocation.threadID, + "tool_name": invocation.toolName, + "decision": resolution.decision.rawValue + ] + ) guard decision == .approved else { let denied = ToolResultEnvelope.denied(invocation: invocation) @@ -150,6 +177,16 @@ extension AgentRuntime { let result = await toolRegistry.execute(invocation, session: session) let resultDate = Date() + logger.info( + .tools, + "Tool invocation completed.", + metadata: [ + "thread_id": invocation.threadID, + "turn_id": invocation.turnID, + "tool_name": invocation.toolName, + "success": "\(result.errorMessage == nil)" + ] + ) try setLatestToolState( latestToolState(for: invocation, result: result, updatedAt: resultDate), for: invocation.threadID diff --git a/Sources/CodexKit/Runtime/AgentRuntime+TurnConsumption.swift b/Sources/CodexKit/Runtime/AgentRuntime+TurnConsumption.swift index 89cdd5f..bb36629 100644 --- a/Sources/CodexKit/Runtime/AgentRuntime+TurnConsumption.swift +++ b/Sources/CodexKit/Runtime/AgentRuntime+TurnConsumption.swift @@ -23,6 +23,14 @@ extension AgentRuntime { for try await backendEvent in turnStream.events { switch backendEvent { case let .turnStarted(turn): + logger.info( + .runtime, + "Turn started.", + metadata: [ + "thread_id": threadID, + "turn_id": turn.id + ] + ) currentTurnID = turn.id appendHistoryItem( .systemEvent( @@ -55,6 +63,16 @@ extension AgentRuntime { if message.role == .assistant { assistantMessages.append(message) } + logger.debug( + .runtime, + "Assistant message committed.", + metadata: [ + "thread_id": threadID, + "turn_id": currentTurnID ?? "", + "text_length": "\(message.text.count)", + "image_count": "\(message.images.count)" + ] + ) continuation.yield(.messageCommitted(message)) case .structuredOutputPartial, @@ -148,6 +166,15 @@ extension AgentRuntime { userMessage: userMessage, assistantMessages: assistantMessages ) + logger.info( + .runtime, + "Turn completed.", + metadata: [ + "thread_id": threadID, + "turn_id": summary.turnID, + "output_tokens": "\(summary.usage?.outputTokens ?? 0)" + ] + ) continuation.yield(.threadStatusChanged(threadID: threadID, status: .idle)) continuation.yield(.turnCompleted(summary)) } @@ -176,6 +203,15 @@ extension AgentRuntime { try? setLatestTurnStatus(.failed, for: threadID) try? setLatestPartialStructuredOutput(nil, for: threadID) try? await setThreadStatus(.failed, for: threadID) + logger.error( + .runtime, + "Turn failed.", + metadata: [ + "thread_id": threadID, + "turn_id": currentTurnID ?? "", + "error": runtimeError.message + ] + ) continuation.yield(.threadStatusChanged(threadID: threadID, status: .failed)) continuation.yield(.turnFailed(runtimeError)) continuation.finish(throwing: error) diff --git a/Sources/CodexKit/Runtime/AgentRuntime.swift b/Sources/CodexKit/Runtime/AgentRuntime.swift index 61a564f..f4696b7 100644 --- a/Sources/CodexKit/Runtime/AgentRuntime.swift +++ b/Sources/CodexKit/Runtime/AgentRuntime.swift @@ -23,6 +23,7 @@ public actor AgentRuntime { public let backend: any AgentBackend public let approvalPresenter: any ApprovalPresenting public let stateStore: any RuntimeStateStoring + public let logging: AgentLoggingConfiguration public let memory: AgentMemoryConfiguration? public let baseInstructions: String? public let tools: [ToolRegistration] @@ -36,6 +37,7 @@ public actor AgentRuntime { backend: any AgentBackend, approvalPresenter: any ApprovalPresenting, stateStore: any RuntimeStateStoring, + logging: AgentLoggingConfiguration = .disabled, memory: AgentMemoryConfiguration? = nil, baseInstructions: String? = nil, tools: [ToolRegistration] = [], @@ -48,6 +50,7 @@ public actor AgentRuntime { self.backend = backend self.approvalPresenter = approvalPresenter self.stateStore = stateStore + self.logging = logging self.memory = memory self.baseInstructions = baseInstructions self.tools = tools @@ -60,6 +63,7 @@ public actor AgentRuntime { let backend: any AgentBackend let stateStore: any RuntimeStateStoring let sessionManager: ChatGPTSessionManager + let logger: AgentLogger let toolRegistry: ToolRegistry let approvalCoordinator: ApprovalCoordinator let memoryConfiguration: AgentMemoryConfiguration? @@ -160,9 +164,11 @@ public actor AgentRuntime { public init(configuration: Configuration) throws { self.backend = configuration.backend self.stateStore = configuration.stateStore + self.logger = AgentLogger(configuration: configuration.logging) self.sessionManager = ChatGPTSessionManager( authProvider: configuration.authProvider, - secureStore: configuration.secureStore + secureStore: configuration.secureStore, + logging: configuration.logging ) self.toolRegistry = try ToolRegistry(initialTools: configuration.tools) self.approvalCoordinator = ApprovalCoordinator( @@ -182,17 +188,36 @@ public actor AgentRuntime { @discardableResult public func restore() async throws -> StoredRuntimeState { + logger.info(.runtime, "Restoring runtime state.") _ = try await sessionManager.restore() _ = try await stateStore.prepare() state = try await stateStore.loadState() pendingStoreOperations.removeAll() publishAllObservations() + logger.info( + .runtime, + "Runtime restore completed.", + metadata: [ + "threads": "\(state.threads.count)", + "history_threads": "\(state.historyByThread.count)" + ] + ) return state } @discardableResult public func signIn() async throws -> ChatGPTSession { - try await sessionManager.signIn() + logger.info(.auth, "Starting interactive sign-in.") + let session = try await sessionManager.signIn() + logger.info( + .auth, + "Interactive sign-in completed.", + metadata: [ + "account_id": session.account.id, + "plan": session.account.plan.rawValue + ] + ) + return session } public func currentSession() async -> ChatGPTSession? { @@ -200,6 +225,7 @@ public actor AgentRuntime { } public func signOut() async throws { + logger.info(.auth, "Signing out current session.") try await sessionManager.signOut() } @@ -234,12 +260,18 @@ public actor AgentRuntime { func persistState() async throws { state = state.normalized() guard !pendingStoreOperations.isEmpty else { + logger.debug(.persistence, "Persisting full runtime state snapshot.") try await stateStore.saveState(state) publishAllObservations() return } let operations = pendingStoreOperations + logger.debug( + .persistence, + "Applying incremental runtime store operations.", + metadata: ["count": "\(operations.count)"] + ) try await stateStore.apply(operations) pendingStoreOperations.removeAll() publishObservations(for: operations) diff --git a/Sources/CodexKit/Runtime/CodexResponsesBackend+Compaction.swift b/Sources/CodexKit/Runtime/CodexResponsesBackend+Compaction.swift index e6510db..60dc9dc 100644 --- a/Sources/CodexKit/Runtime/CodexResponsesBackend+Compaction.swift +++ b/Sources/CodexKit/Runtime/CodexResponsesBackend+Compaction.swift @@ -8,6 +8,14 @@ extension CodexResponsesBackend: AgentBackendContextCompacting { tools: [ToolDefinition], session: ChatGPTSession ) async throws -> AgentCompactionResult { + logger.info( + .compaction, + "Starting remote context compaction.", + metadata: [ + "thread_id": thread.id, + "history_count": "\(effectiveHistory.count)" + ] + ) let requestFactory = CodexResponsesRequestFactory( configuration: configuration, encoder: encoder @@ -49,6 +57,15 @@ extension CodexResponsesBackend: AgentBackendContextCompacting { } guard (200 ..< 300).contains(httpResponse.statusCode) else { let body = String(data: data, encoding: .utf8) ?? "" + logger.error( + .compaction, + "Remote context compaction failed.", + metadata: [ + "thread_id": thread.id, + "status": "\(httpResponse.statusCode)", + "body": body + ] + ) throw AgentRuntimeError( code: "responses_compact_failed", message: "The ChatGPT compact endpoint failed with status \(httpResponse.statusCode): \(body)" @@ -64,6 +81,16 @@ extension CodexResponsesBackend: AgentBackendContextCompacting { throw AgentRuntimeError.contextCompactionUnsupported() } + logger.info( + .compaction, + "Remote context compaction completed.", + metadata: [ + "thread_id": thread.id, + "message_count_before": "\(effectiveHistory.count)", + "message_count_after": "\(messages.count)" + ] + ) + return AgentCompactionResult( effectiveMessages: messages, summaryPreview: messages.first?.displayText diff --git a/Sources/CodexKit/Runtime/CodexResponsesBackend.swift b/Sources/CodexKit/Runtime/CodexResponsesBackend.swift index ade2d4a..1b94d3d 100644 --- a/Sources/CodexKit/Runtime/CodexResponsesBackend.swift +++ b/Sources/CodexKit/Runtime/CodexResponsesBackend.swift @@ -10,6 +10,7 @@ public struct CodexResponsesBackendConfiguration: Sendable { public let extraHeaders: [String: String] public let enableWebSearch: Bool public let requestRetryPolicy: RequestRetryPolicy + public let logging: AgentLoggingConfiguration public init( baseURL: URL = URL(string: "https://chatgpt.com/backend-api/codex")!, @@ -22,7 +23,8 @@ public struct CodexResponsesBackendConfiguration: Sendable { streamIdleTimeout: TimeInterval = 60, extraHeaders: [String: String] = [:], enableWebSearch: Bool = false, - requestRetryPolicy: RequestRetryPolicy = .default + requestRetryPolicy: RequestRetryPolicy = .default, + logging: AgentLoggingConfiguration = .disabled ) { self.baseURL = baseURL self.model = model @@ -33,6 +35,7 @@ public struct CodexResponsesBackendConfiguration: Sendable { self.extraHeaders = extraHeaders self.enableWebSearch = enableWebSearch self.requestRetryPolicy = requestRetryPolicy + self.logging = logging } } @@ -57,6 +60,7 @@ public actor CodexResponsesBackend: AgentBackend { public nonisolated let baseInstructions: String? let configuration: CodexResponsesBackendConfiguration + let logger: AgentLogger let urlSession: URLSession let encoder = JSONEncoder() let decoder = JSONDecoder() @@ -66,6 +70,7 @@ public actor CodexResponsesBackend: AgentBackend { urlSession: URLSession = .shared ) { self.configuration = configuration + self.logger = AgentLogger(configuration: configuration.logging) self.urlSession = urlSession self.baseInstructions = configuration.instructions } @@ -90,6 +95,7 @@ public actor CodexResponsesBackend: AgentBackend { ) async throws -> any AgentTurnStreaming { CodexResponsesTurnSession( configuration: configuration, + logger: logger, instructions: instructions, responseFormat: responseFormat, streamedStructuredOutput: streamedStructuredOutput, @@ -140,10 +146,12 @@ extension CodexResponsesBackend { final class CodexResponsesTurnSession: AgentTurnStreaming, @unchecked Sendable { let events: AsyncThrowingStream + private let logger: AgentLogger private let pendingToolResults: PendingToolResults init( configuration: CodexResponsesBackendConfiguration, + logger: AgentLogger, instructions: String, responseFormat: AgentStructuredOutputFormat?, streamedStructuredOutput: AgentStreamedStructuredOutputRequest?, @@ -156,6 +164,7 @@ final class CodexResponsesTurnSession: AgentTurnStreaming, @unchecked Sendable { tools: [ToolDefinition], session: ChatGPTSession ) { + self.logger = logger let pendingToolResults = PendingToolResults() self.pendingToolResults = pendingToolResults let turn = AgentTurn(id: UUID().uuidString, threadID: thread.id) @@ -164,6 +173,7 @@ final class CodexResponsesTurnSession: AgentTurnStreaming, @unchecked Sendable { continuation.yield(.turnStarted(turn)) let runner = CodexResponsesTurnRunner( configuration: configuration, + logger: logger, instructions: instructions, responseFormat: responseFormat, streamedStructuredOutput: streamedStructuredOutput, @@ -185,6 +195,16 @@ final class CodexResponsesTurnSession: AgentTurnStreaming, @unchecked Sendable { newMessage: message ) + logger.info( + .network, + "Backend turn completed.", + metadata: [ + "thread_id": thread.id, + "turn_id": turn.id, + "output_tokens": "\(usage.outputTokens)" + ] + ) + continuation.yield( .turnCompleted( AgentTurnSummary( @@ -196,6 +216,15 @@ final class CodexResponsesTurnSession: AgentTurnStreaming, @unchecked Sendable { ) continuation.finish() } catch { + logger.error( + .network, + "Backend turn failed.", + metadata: [ + "thread_id": thread.id, + "turn_id": turn.id, + "error": error.localizedDescription + ] + ) continuation.finish(throwing: error) } } diff --git a/Sources/CodexKit/Runtime/CodexResponsesTransport.swift b/Sources/CodexKit/Runtime/CodexResponsesTransport.swift index d0c5d6f..a7b9daa 100644 --- a/Sources/CodexKit/Runtime/CodexResponsesTransport.swift +++ b/Sources/CodexKit/Runtime/CodexResponsesTransport.swift @@ -73,10 +73,19 @@ struct CodexResponsesRequestFactory: Sendable { struct CodexResponsesEventStreamClient: Sendable { let urlSession: URLSession let decoder: JSONDecoder + let logger: AgentLogger func streamEvents( request: URLRequest ) async throws -> AsyncThrowingStream { + logger.debug( + .network, + "Opening responses event stream.", + metadata: [ + "url": request.url?.absoluteString ?? "unknown", + "method": request.httpMethod ?? "POST" + ] + ) let (bytes, response) = try await urlSession.bytes(for: request) guard let httpResponse = response as? HTTPURLResponse else { throw AgentRuntimeError( @@ -88,6 +97,14 @@ struct CodexResponsesEventStreamClient: Sendable { if !(200 ..< 300).contains(httpResponse.statusCode) { let bodyData = try await readAll(bytes) let body = String(data: bodyData, encoding: .utf8) ?? "Unknown error" + logger.error( + .network, + "Responses event stream failed with HTTP status.", + metadata: [ + "status": "\(httpResponse.statusCode)", + "body": body + ] + ) if httpResponse.statusCode == 401 || httpResponse.statusCode == 403 { throw AgentRuntimeError.unauthorized(body) } @@ -155,18 +172,45 @@ struct CodexResponsesEventStreamClient: Sendable { return false } if let statusCode = httpStatusCode(from: runtimeError.code) { - return policy.retryableHTTPStatusCodes.contains(statusCode) + let shouldRetry = policy.retryableHTTPStatusCodes.contains(statusCode) + logger.debug( + .retry, + "Evaluated HTTP retry decision.", + metadata: [ + "status": "\(statusCode)", + "retry": "\(shouldRetry)" + ] + ) + return shouldRetry } return false } if let urlError = error as? URLError { - return policy.retryableURLErrorCodes.contains(urlError.errorCode) + let shouldRetry = policy.retryableURLErrorCodes.contains(urlError.errorCode) + logger.debug( + .retry, + "Evaluated URL error retry decision.", + metadata: [ + "code": "\(urlError.errorCode)", + "retry": "\(shouldRetry)" + ] + ) + return shouldRetry } let nsError = error as NSError if nsError.domain == NSURLErrorDomain { - return policy.retryableURLErrorCodes.contains(nsError.code) + let shouldRetry = policy.retryableURLErrorCodes.contains(nsError.code) + logger.debug( + .retry, + "Evaluated NSError retry decision.", + metadata: [ + "code": "\(nsError.code)", + "retry": "\(shouldRetry)" + ] + ) + return shouldRetry } return false diff --git a/Sources/CodexKit/Runtime/CodexResponsesTurnRunner.swift b/Sources/CodexKit/Runtime/CodexResponsesTurnRunner.swift index f4ce554..23e985b 100644 --- a/Sources/CodexKit/Runtime/CodexResponsesTurnRunner.swift +++ b/Sources/CodexKit/Runtime/CodexResponsesTurnRunner.swift @@ -2,6 +2,7 @@ import Foundation struct CodexResponsesTurnRunner { let configuration: CodexResponsesBackendConfiguration + let logger: AgentLogger let instructions: String let responseFormat: AgentStructuredOutputFormat? let streamedStructuredOutput: AgentStreamedStructuredOutputRequest? @@ -17,6 +18,7 @@ struct CodexResponsesTurnRunner { init( configuration: CodexResponsesBackendConfiguration, + logger: AgentLogger, instructions: String, responseFormat: AgentStructuredOutputFormat?, streamedStructuredOutput: AgentStreamedStructuredOutputRequest?, @@ -31,11 +33,16 @@ struct CodexResponsesTurnRunner { continuation: AsyncThrowingStream.Continuation ) { self.configuration = configuration + self.logger = logger self.instructions = instructions self.responseFormat = responseFormat self.streamedStructuredOutput = streamedStructuredOutput self.requestFactory = CodexResponsesRequestFactory(configuration: configuration, encoder: encoder) - self.streamClient = CodexResponsesEventStreamClient(urlSession: urlSession, decoder: decoder) + self.streamClient = CodexResponsesEventStreamClient( + urlSession: urlSession, + decoder: decoder, + logger: logger + ) self.toolOutputAdapter = CodexResponsesToolOutputAdapter(urlSession: urlSession) self.threadID = threadID self.turnID = turnID @@ -49,6 +56,16 @@ struct CodexResponsesTurnRunner { history: [AgentMessage], newMessage: UserMessageRequest ) async throws -> AgentUsage { + logger.debug( + .network, + "Starting backend turn runner.", + metadata: [ + "thread_id": threadID, + "turn_id": turnID, + "history_count": "\(history.count)", + "tool_count": "\(tools.count)" + ] + ) var state = TurnRunState( workingHistory: initialWorkingHistory(history: history, newMessage: newMessage) ) @@ -93,6 +110,15 @@ struct CodexResponsesTurnRunner { // Build one request per pass. Retries replay the same request, while a new pass // is only started after tool output mutates the working history. let request = try makeRequest(for: state) + logger.debug( + .network, + "Starting backend turn pass.", + metadata: [ + "thread_id": threadID, + "turn_id": turnID, + "working_items": "\(state.workingHistory.count)" + ] + ) for attempt in 1...retryPolicy.maxAttempts { var retryState = RetryAttemptState() @@ -109,8 +135,29 @@ struct CodexResponsesTurnRunner { policy: retryPolicy, retryState: retryState ) else { + logger.error( + .network, + "Backend turn pass failed without retry.", + metadata: [ + "thread_id": threadID, + "turn_id": turnID, + "attempt": "\(attempt)", + "error": error.localizedDescription + ] + ) throw error } + logger.warning( + .retry, + "Retrying backend turn pass.", + metadata: [ + "thread_id": threadID, + "turn_id": turnID, + "attempt": "\(attempt)", + "max_attempts": "\(retryPolicy.maxAttempts)", + "error": error.localizedDescription + ] + ) try await sleepBeforeRetry(attempt: attempt, policy: retryPolicy) } } @@ -175,6 +222,15 @@ struct CodexResponsesTurnRunner { return .none case let .functionCall(functionCall): + logger.info( + .tools, + "Received tool call from backend.", + metadata: [ + "thread_id": threadID, + "turn_id": turnID, + "tool_name": functionCall.name + ] + ) try await handleFunctionCall(functionCall, state: &state) return .toolCall @@ -182,6 +238,16 @@ struct CodexResponsesTurnRunner { state.aggregateUsage.inputTokens += usage.inputTokens state.aggregateUsage.cachedInputTokens += usage.cachedInputTokens state.aggregateUsage.outputTokens += usage.outputTokens + logger.debug( + .network, + "Backend stream completed pass.", + metadata: [ + "thread_id": threadID, + "turn_id": turnID, + "input_tokens": "\(usage.inputTokens)", + "output_tokens": "\(usage.outputTokens)" + ] + ) return .none } } diff --git a/Sources/CodexKit/Runtime/FileRuntimeStateStore.swift b/Sources/CodexKit/Runtime/FileRuntimeStateStore.swift index 001d5b9..d483d19 100644 --- a/Sources/CodexKit/Runtime/FileRuntimeStateStore.swift +++ b/Sources/CodexKit/Runtime/FileRuntimeStateStore.swift @@ -2,13 +2,18 @@ import Foundation public actor FileRuntimeStateStore: RuntimeStateStoring, RuntimeStateInspecting, AgentRuntimeQueryableStore { private let url: URL + private let logger: AgentLogger private let encoder = JSONEncoder() private let decoder = JSONDecoder() private let fileManager = FileManager.default private let attachmentStore: RuntimeAttachmentStore - public init(url: URL) { + public init( + url: URL, + logging: AgentLoggingConfiguration = .disabled + ) { self.url = url + self.logger = AgentLogger(configuration: logging) let basename = url.deletingPathExtension().lastPathComponent self.attachmentStore = RuntimeAttachmentStore( rootURL: url.deletingLastPathComponent() @@ -18,14 +23,24 @@ public actor FileRuntimeStateStore: RuntimeStateStoring, RuntimeStateInspecting, } public func loadState() async throws -> StoredRuntimeState { - try loadNormalizedStateMigratingIfNeeded() + logger.debug(.persistence, "Loading file runtime state.", metadata: ["url": url.path]) + return try loadNormalizedStateMigratingIfNeeded() } public func saveState(_ state: StoredRuntimeState) async throws { + logger.info( + .persistence, + "Saving file runtime state snapshot.", + metadata: [ + "url": url.path, + "threads": "\(state.threads.count)" + ] + ) try persistLayout(for: state.normalized()) } public func prepare() async throws -> AgentStoreMetadata { + logger.info(.persistence, "Preparing file runtime state store.", metadata: ["url": url.path]) _ = try loadNormalizedStateMigratingIfNeeded() return try await readMetadata() } @@ -107,6 +122,11 @@ public actor FileRuntimeStateStore: RuntimeStateStoring, RuntimeStateInspecting, let data = try Data(contentsOf: url) let legacy = try decoder.decode(StoredRuntimeState.self, from: data).normalized() + logger.info( + .persistence, + "Migrating legacy file runtime state layout.", + metadata: ["url": url.path] + ) try persistLayout(for: legacy) return legacy } diff --git a/Sources/CodexKit/Runtime/GRDBRuntimeStateStore+Persistence.swift b/Sources/CodexKit/Runtime/GRDBRuntimeStateStore+Persistence.swift index 94731ae..e618edf 100644 --- a/Sources/CodexKit/Runtime/GRDBRuntimeStateStore+Persistence.swift +++ b/Sources/CodexKit/Runtime/GRDBRuntimeStateStore+Persistence.swift @@ -27,7 +27,10 @@ extension GRDBRuntimeStateStore { return } - let legacyStore = FileRuntimeStateStore(url: legacyStateURL) + let legacyStore = FileRuntimeStateStore( + url: legacyStateURL, + logging: logger.configuration + ) let state = try await legacyStore.loadState().normalized() guard !state.threads.isEmpty || !state.historyByThread.isEmpty else { return diff --git a/Sources/CodexKit/Runtime/GRDBRuntimeStateStore.swift b/Sources/CodexKit/Runtime/GRDBRuntimeStateStore.swift index cf6748c..319a250 100644 --- a/Sources/CodexKit/Runtime/GRDBRuntimeStateStore.swift +++ b/Sources/CodexKit/Runtime/GRDBRuntimeStateStore.swift @@ -6,6 +6,7 @@ public actor GRDBRuntimeStateStore: RuntimeStateStoring, RuntimeStateInspecting, let url: URL let legacyStateURL: URL? + let logger: AgentLogger let attachmentStore: RuntimeAttachmentStore let databaseExistedAtInitialization: Bool let dbQueue: DatabaseQueue @@ -22,9 +23,11 @@ public actor GRDBRuntimeStateStore: RuntimeStateStoring, RuntimeStateInspecting, public init( url: URL, - importingLegacyStateFrom legacyStateURL: URL? = nil + importingLegacyStateFrom legacyStateURL: URL? = nil, + logging: AgentLoggingConfiguration = .disabled ) throws { self.url = url + self.logger = AgentLogger(configuration: logging) let fileManager = FileManager.default let basename = url.deletingPathExtension().lastPathComponent self.databaseExistedAtInitialization = fileManager.fileExists(atPath: url.path) @@ -77,6 +80,7 @@ public actor GRDBRuntimeStateStore: RuntimeStateStoring, RuntimeStateInspecting, public func loadState() async throws -> StoredRuntimeState { try await ensurePrepared() let persistence = self.persistence + logger.debug(.persistence, "Loading GRDB runtime state.", metadata: ["url": url.path]) return try await dbQueue.read { db in let threadRows = try RuntimeThreadRow.fetchAll(db) @@ -114,6 +118,14 @@ public actor GRDBRuntimeStateStore: RuntimeStateStoring, RuntimeStateInspecting, let normalized = state.normalized() let persistence = self.persistence + logger.info( + .persistence, + "Saving GRDB runtime state snapshot.", + metadata: [ + "url": url.path, + "threads": "\(normalized.threads.count)" + ] + ) try attachmentStore.reset() try await dbQueue.write { db in try persistence.replaceDatabaseContents( @@ -135,6 +147,15 @@ public actor GRDBRuntimeStateStore: RuntimeStateStoring, RuntimeStateInspecting, } let persistence = self.persistence + logger.debug( + .persistence, + "Applying GRDB runtime state operations.", + metadata: [ + "url": url.path, + "operation_count": "\(operations.count)", + "affected_threads": "\(affectedThreadIDs.count)" + ] + ) try await dbQueue.write { db in var partialState = try persistence.loadPartialState( for: affectedThreadIDs, @@ -241,6 +262,7 @@ public actor GRDBRuntimeStateStore: RuntimeStateStoring, RuntimeStateInspecting, return } + logger.info(.persistence, "Preparing GRDB runtime state store.", metadata: ["url": url.path]) let version = try await readUserVersion() guard version <= Self.currentStoreSchemaVersion else { throw AgentStoreError.migrationFailed( @@ -250,8 +272,14 @@ public actor GRDBRuntimeStateStore: RuntimeStateStoring, RuntimeStateInspecting, try migrator.migrate(dbQueue) if try await shouldImportLegacyState() { + logger.info( + .persistence, + "Importing legacy file runtime state into GRDB store.", + metadata: ["legacy_url": legacyStateURL?.path ?? ""] + ) try await importLegacyState() } isPrepared = true + logger.info(.persistence, "GRDB runtime state store prepared.", metadata: ["url": url.path]) } } diff --git a/Sources/CodexKit/Runtime/InMemoryRuntimeStateStore.swift b/Sources/CodexKit/Runtime/InMemoryRuntimeStateStore.swift index 84b1f9a..079cbbc 100644 --- a/Sources/CodexKit/Runtime/InMemoryRuntimeStateStore.swift +++ b/Sources/CodexKit/Runtime/InMemoryRuntimeStateStore.swift @@ -2,20 +2,32 @@ import Foundation public actor InMemoryRuntimeStateStore: RuntimeStateStoring, RuntimeStateInspecting, AgentRuntimeQueryableStore { private var state: StoredRuntimeState + private let logger: AgentLogger - public init(initialState: StoredRuntimeState = .empty) { + public init( + initialState: StoredRuntimeState = .empty, + logging: AgentLoggingConfiguration = .disabled + ) { state = initialState.normalized() + logger = AgentLogger(configuration: logging) } public func loadState() async throws -> StoredRuntimeState { - state + logger.debug(.persistence, "Loading in-memory runtime state.") + return state } public func saveState(_ state: StoredRuntimeState) async throws { + logger.debug( + .persistence, + "Saving in-memory runtime state.", + metadata: ["threads": "\(state.threads.count)"] + ) self.state = state.normalized() } public func prepare() async throws -> AgentStoreMetadata { + logger.info(.persistence, "Preparing in-memory runtime state store.") state = state.normalized() return try await readMetadata() } diff --git a/Tests/CodexKitTests/AgentRuntimeLoggingTests.swift b/Tests/CodexKitTests/AgentRuntimeLoggingTests.swift new file mode 100644 index 0000000..62bcc34 --- /dev/null +++ b/Tests/CodexKitTests/AgentRuntimeLoggingTests.swift @@ -0,0 +1,127 @@ +import CodexKit +import XCTest + +extension AgentRuntimeTests { + func testRuntimeLoggingEmitsAuthRuntimeAndPersistenceEntries() async throws { + let buffer = RuntimeLogBuffer() + let logging = AgentLoggingConfiguration( + minimumLevel: .debug, + sink: RuntimeTestLogSink(buffer: buffer) + ) + let runtime = try AgentRuntime(configuration: .init( + authProvider: DemoChatGPTAuthProvider(), + secureStore: KeychainSessionSecureStore( + service: "CodexKitTests.ChatGPTSession", + account: UUID().uuidString + ), + backend: InMemoryAgentBackend(), + approvalPresenter: AutoApprovalPresenter(), + stateStore: InMemoryRuntimeStateStore(logging: logging), + logging: logging + )) + + _ = try await runtime.restore() + _ = try await runtime.signIn() + let thread = try await runtime.createThread(title: "Logging") + _ = try await runtime.sendMessage( + UserMessageRequest(text: "Log this turn"), + in: thread.id + ) + + let entries = buffer.entries + XCTAssertTrue(entries.contains { $0.category == .auth && $0.message.contains("sign-in completed") }) + XCTAssertTrue(entries.contains { $0.category == .runtime && $0.message.contains("Thread created") }) + XCTAssertTrue(entries.contains { $0.category == .runtime && $0.message.contains("Starting streamed message") }) + XCTAssertTrue(entries.contains { $0.category == .persistence }) + } +} + +extension CodexResponsesBackendTests { + func testBackendLoggingEmitsRetryEntries() async throws { + let buffer = RuntimeLogBuffer() + let logging = AgentLoggingConfiguration( + minimumLevel: .debug, + sink: RuntimeTestLogSink(buffer: buffer) + ) + let backend = CodexResponsesBackend( + configuration: CodexResponsesBackendConfiguration( + requestRetryPolicy: .init( + maxAttempts: 2, + initialBackoff: 0, + maxBackoff: 0, + jitterFactor: 0 + ), + logging: logging + ), + urlSession: makeTestURLSession() + ) + let session = ChatGPTSession( + accessToken: "access-token", + refreshToken: "refresh-token", + account: ChatGPTAccount( + id: "workspace-123", + email: "taylor@example.com", + plan: .plus + ) + ) + + await TestURLProtocol.enqueue(.init( + statusCode: 503, + headers: ["Content-Type": "application/json"], + body: Data(#"{"error":"upstream overloaded"}"#.utf8) + )) + await TestURLProtocol.enqueue(.init( + headers: ["Content-Type": "text/event-stream"], + body: Data(""" + event: response.output_item.done + data: {"type":"response.output_item.done","item":{"type":"message","role":"assistant","content":[{"type":"output_text","text":"Recovered"}]}} + + event: response.completed + data: {"type":"response.completed","response":{"id":"resp_retry","usage":{"input_tokens":5,"input_tokens_details":{"cached_tokens":0},"output_tokens":2}}} + + """.utf8) + )) + + let turnStream = try await backend.beginTurn( + thread: AgentThread(id: "thread-retry"), + history: [], + message: UserMessageRequest(text: "Hi"), + instructions: "Resolved instructions", + responseFormat: nil, + streamedStructuredOutput: nil, + tools: [], + session: session + ) + + for try await _ in turnStream.events {} + + let entries = buffer.entries + XCTAssertTrue(entries.contains { $0.category == .retry && $0.message.contains("Retrying backend turn pass") }) + XCTAssertTrue(entries.contains { $0.category == .network && $0.message.contains("Opening responses event stream") }) + } +} + +private final class RuntimeLogBuffer: @unchecked Sendable { + private let lock = NSLock() + private var storage: [AgentLogEntry] = [] + + var entries: [AgentLogEntry] { + lock.lock() + defer { lock.unlock() } + return storage + } + + func append(_ entry: AgentLogEntry) { + lock.lock() + storage.append(entry) + lock.unlock() + } +} + +private struct RuntimeTestLogSink: AgentLogSink { + let buffer: RuntimeLogBuffer + + func log(_ entry: AgentLogEntry) { + buffer.append(entry) + } +} From 49cdaf51d02a82545a7555f5dfc6a0e7f318158d Mon Sep 17 00:00:00 2001 From: Timothy Zelinsky Date: Wed, 25 Mar 2026 08:55:07 +1100 Subject: [PATCH 2/3] Expand logging README guidance --- README.md | 44 +++++++++++++++++++++++++++++++++++++++----- 1 file changed, 39 insertions(+), 5 deletions(-) diff --git a/README.md b/README.md index 8c172a8..8e55661 100644 --- a/README.md +++ b/README.md @@ -259,6 +259,16 @@ let runtime = try AgentRuntime(configuration: .init( )) ``` +You can also filter by category: + +```swift +let logging = AgentLoggingConfiguration.osLog( + minimumLevel: .debug, + categories: [.runtime, .persistence, .network, .tools], + subsystem: "com.example.myapp" +) +``` + Available logging categories include: - `auth` @@ -274,12 +284,36 @@ Available logging categories include: Use `AgentConsoleLogSink` for stderr-style console logs, `AgentOSLogSink` for unified Apple logging, or provide your own `AgentLogSink`. -Available values: +Custom sinks make it possible to bridge `CodexKit` logs into your own telemetry or logging pipeline: + +```swift +struct RemoteTelemetrySink: AgentLogSink { + func log(_ entry: AgentLogEntry) { + Telemetry.shared.enqueue( + level: entry.level, + category: entry.category.rawValue, + message: entry.message, + metadata: entry.metadata, + timestamp: entry.timestamp + ) + } +} + +let logging = AgentLoggingConfiguration( + minimumLevel: .info, + sink: RemoteTelemetrySink() +) +``` + +`AgentLogEntry` includes: + +- timestamp +- level +- category +- message +- metadata -- `.low` -- `.medium` -- `.high` -- `.extraHigh` +For remote telemetry or file-backed logging, prefer a sink that buffers or enqueues work quickly. `AgentLogSink.log(_:)` is called inline, so it should avoid blocking network I/O on the caller's execution path. ## Persistent State And Queries From 45dc64fb159c2a2193373561d1949ede4943b64d Mon Sep 17 00:00:00 2001 From: Timothy Zelinsky Date: Wed, 25 Mar 2026 13:38:39 +1100 Subject: [PATCH 3/3] Redact SDK logging output --- Sources/CodexKit/Runtime/AgentLogging.swift | 8 ++++---- .../Runtime/CodexResponsesBackend+Compaction.swift | 2 +- Sources/CodexKit/Runtime/CodexResponsesTransport.swift | 2 +- 3 files changed, 6 insertions(+), 6 deletions(-) diff --git a/Sources/CodexKit/Runtime/AgentLogging.swift b/Sources/CodexKit/Runtime/AgentLogging.swift index c3f1a63..a681ae7 100644 --- a/Sources/CodexKit/Runtime/AgentLogging.swift +++ b/Sources/CodexKit/Runtime/AgentLogging.swift @@ -91,13 +91,13 @@ public struct AgentOSLogSink: AgentLogSink, Sendable { let renderedLine = entry.renderedLine switch entry.level { case .debug: - logger.debug("\(renderedLine, privacy: .public)") + logger.debug("\(renderedLine, privacy: .private)") case .info: - logger.info("\(renderedLine, privacy: .public)") + logger.info("\(renderedLine, privacy: .private)") case .warning: - logger.notice("\(renderedLine, privacy: .public)") + logger.notice("\(renderedLine, privacy: .private)") case .error: - logger.error("\(renderedLine, privacy: .public)") + logger.error("\(renderedLine, privacy: .private)") } } } diff --git a/Sources/CodexKit/Runtime/CodexResponsesBackend+Compaction.swift b/Sources/CodexKit/Runtime/CodexResponsesBackend+Compaction.swift index 60dc9dc..e1a2015 100644 --- a/Sources/CodexKit/Runtime/CodexResponsesBackend+Compaction.swift +++ b/Sources/CodexKit/Runtime/CodexResponsesBackend+Compaction.swift @@ -63,7 +63,7 @@ extension CodexResponsesBackend: AgentBackendContextCompacting { metadata: [ "thread_id": thread.id, "status": "\(httpResponse.statusCode)", - "body": body + "body_length": "\(body.count)" ] ) throw AgentRuntimeError( diff --git a/Sources/CodexKit/Runtime/CodexResponsesTransport.swift b/Sources/CodexKit/Runtime/CodexResponsesTransport.swift index a7b9daa..b8ab534 100644 --- a/Sources/CodexKit/Runtime/CodexResponsesTransport.swift +++ b/Sources/CodexKit/Runtime/CodexResponsesTransport.swift @@ -102,7 +102,7 @@ struct CodexResponsesEventStreamClient: Sendable { "Responses event stream failed with HTTP status.", metadata: [ "status": "\(httpResponse.statusCode)", - "body": body + "body_length": "\(body.count)" ] ) if httpResponse.statusCode == 401 || httpResponse.statusCode == 403 {