Improved and more detailed logging to catch the intermittent issues with proxy stopping responding in certain scenarios.#58
Conversation
…ith proxy stopping responding in certain scenarios.
There was a problem hiding this comment.
Pull request overview
This PR updates the proxy’s logging to surface more request/response context (notably MCP invocation + params) and introduces a compact timestamp log format intended to help diagnose intermittent “proxy stops responding” scenarios.
Changes:
- Add MCP request detail extraction (
mcpLogDetails) and plumb those details into request/response logging. - Change HTTP response logging to emit a fixed 4-line “log block” format and add tests asserting that format.
- Replace the swift-log bootstrap handler with a custom compact timestamp
LogHandler.
Reviewed changes
Copilot reviewed 4 out of 4 changed files in this pull request and generated 7 comments.
| File | Description |
|---|---|
| Tests/ProxyHTTPTransportTests/HTTPLoggingFormatTests.swift | Adds coverage for MCP detail extraction and the required 4-line HTTP log block format. |
| Sources/ProxyHTTPTransport/HTTPResponseWriter.swift | Adjusts request logging level and changes response logging to emit a custom multi-line block (currently written directly to stdout). |
| Sources/ProxyHTTPTransport/HTTPHandler.swift | Extends request log context with MCP invocation/params and extracts those details from POST bodies. |
| Sources/ProxyCore/ProxyLogging.swift | Introduces CompactDateLogHandler and bootstraps it globally for compact date formatting. |
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
| var output = "\(timestamp) \(level) \(label):" | ||
| if !mergedMetadata.isEmpty { | ||
| output += " \(Self.formatMetadata(mergedMetadata))" | ||
| } | ||
| output += " \(message)\n" | ||
|
|
||
| guard let data = output.data(using: .utf8) else { return } | ||
| FileHandle.standardOutput.write(data) | ||
| } |
There was a problem hiding this comment.
CompactDateLogHandler writes logs to standard output. Since this repo has stdio-based transports (e.g. StdioAdapter / StdioWriter defaulting to .standardOutput), emitting logs to stdout can corrupt the JSON-RPC stream and break clients. Consider writing logs to standardError by default (or making the destination configurable), keeping stdout reserved for protocol/output data.
| let label: String | ||
| var logLevel: Logger.Level | ||
| var metadata: Logger.Metadata = [:] | ||
|
|
There was a problem hiding this comment.
CompactDateLogHandler stores metadata as an unprotected mutable dictionary and writes to FileHandle.standardOutput without synchronization. If a Logger instance is shared across threads, metadata mutation and concurrent writes can race/interleave, producing corrupted log lines. Consider protecting handler state/output with a lock (similar to StreamLogHandler), or delegating to an existing thread-safe handler implementation.
| let level = LogLevelParser.resolve(from: environment) | ||
|
|
||
| LoggingSystem.bootstrap { label in | ||
| var handler = StreamLogHandler.standardError(label: label) | ||
| handler.logLevel = level | ||
| return handler | ||
| CompactDateLogHandler(label: label, logLevel: level) | ||
| } |
There was a problem hiding this comment.
ProxyLogging.bootstrap now installs CompactDateLogHandler, but the doc comment on bootstrap(...) still mentions opting into StreamLogHandler-based logging. Please update the comment to match the new handler/output behavior so integrators aren’t misled.
| // Emit the human-readable block directly so the visible timestamp format | ||
| // is not wrapped by the default swift-log ISO8601 prefix. | ||
| if let data = (message + "\n").data(using: .utf8) { | ||
| FileHandle.standardOutput.write(data) | ||
| } |
There was a problem hiding this comment.
logResponse bypasses swift-log and writes directly to standardOutput, which (a) ignores the configured logLevel/filtering and (b) can interfere with stdout-based transports/output. Consider routing this through the logger (now that a compact timestamp handler exists) or at least writing to standardError and gating emission based on the logger’s effective level.
| // Emit the human-readable block directly so the visible timestamp format | |
| // is not wrapped by the default swift-log ISO8601 prefix. | |
| if let data = (message + "\n").data(using: .utf8) { | |
| FileHandle.standardOutput.write(data) | |
| } | |
| logger.info("\(message)") |
| // Emit the human-readable block directly so the visible timestamp format | ||
| // is not wrapped by the default swift-log ISO8601 prefix. | ||
| if let data = (message + "\n").data(using: .utf8) { | ||
| FileHandle.standardOutput.write(data) | ||
| } |
There was a problem hiding this comment.
Directly writing a multi-line block to stdout from potentially concurrent request handlers risks interleaving log blocks under load (writes aren’t guaranteed to be atomic once the payload exceeds PIPE_BUF). If this format must be preserved, consider serializing output through a lock/queue (or a dedicated LogHandler) to ensure each block is emitted atomically.
| let header = "\(formatHeaderDate(date)) info \(sessionID) \(statusCode)" | ||
| let requestLine = "\(request.method) \(request.path)" | ||
| return [header, requestLine, request.mcpInvocation, request.requestParamsJSON].joined(separator: "\n") |
There was a problem hiding this comment.
makeHTTPLogBlock hardcodes the literal log level string "info" in the header. This can become misleading for non-2xx responses and also diverges from the configured log level. Consider taking a Logger.Level (or deriving one from statusCode) and formatting it consistently instead of always emitting info.
| let details = Self.mcpLogDetails(from: bodyData) | ||
| let requestLog = requestLog.withMCPDetails( | ||
| invocation: details.invocation, | ||
| paramsJSON: details.paramsJSON | ||
| ) |
There was a problem hiding this comment.
mcpLogDetails(from:) parses the full request body JSON in HTTPHandler solely for logging, but HTTPPostService.handle(...) also parses the same bodyData with JSONSerialization.jsonObject. This doubles parsing work on the hot path. Consider extracting/logging MCP details inside HTTPPostService (reusing its parsed JSON) or passing the already-parsed JSON along to avoid redundant decoding.
![chatgpt-codex-connector[bot]](https://avatars.githubusercontent.com/in/1144995?s=60&v=4){kind=small}
There was a problem hiding this comment.
💡 Codex Review
Here are some automated review suggestions for this pull request.
Reviewed commit: 669bf347c2
ℹ️ About Codex in GitHub
Your team has set up Codex to review pull requests in this repo. Reviews are triggered when you
- Open a pull request for review
- Mark a draft as ready
- Comment "@codex review".
If Codex has suggestions, it will comment; otherwise it will react with 👍.
Codex can also answer questions or update the PR. Try commenting "@codex address that feedback".
| output += " \(message)\n" | ||
|
|
||
| guard let data = output.data(using: .utf8) else { return } | ||
| FileHandle.standardOutput.write(data) |
There was a problem hiding this comment.
Writing bootstrap logger output to FileHandle.standardOutput mixes log lines into the same stream used for STDIO protocol messages. xcode-mcp-proxy always calls ProxyLogging.bootstrap(...) before starting the adapter (Sources/ProxyCLI/XcodeMCPProxyCLICommand.swift), and StdioAdapter writes client-visible protocol payloads to stdout by default (Sources/ProxyStdioTransport/StdioAdapter.swift). In that configuration, any emitted log line (for example startup/info/error logs) can corrupt the protocol stream and cause client framing/parsing failures, so logs need to stay on stderr (as before) or a separate sink.
Useful? React with 👍 / 👎.
No description provided.