Improved and more detailed logging to catch the intermittent issues with proxy stopping responding in certain scenarios.

Sources/ProxyCore/ProxyLogging.swift

@@ -2,6 +2,71 @@ import Foundation
 import Logging
 import NIOConcurrencyHelpers
 
+private struct CompactDateLogHandler: LogHandler {
+    private static let cachedFormatter = NIOLockedValueBox<DateFormatter>({
+        let formatter = DateFormatter()
+        formatter.locale = Locale(identifier: "en_US_POSIX")
+        formatter.timeZone = .autoupdatingCurrent
+        formatter.dateFormat = "yy-MM-dd HH:mm:ss"
+        return formatter
+    }())
+
+    let label: String
+    var logLevel: Logger.Level
+    var metadata: Logger.Metadata = [:]
+
+    init(label: String, logLevel: Logger.Level) {
+        self.label = label
+        self.logLevel = logLevel
+    }
+
+    subscript(metadataKey key: String) -> Logger.Metadata.Value? {
+        get { metadata[key] }
+        set { metadata[key] = newValue }
+    }
+
+    func log(
+        level: Logger.Level,
+        message: Logger.Message,
+        metadata explicitMetadata: Logger.Metadata?,
+        source: String,
+        file: String,
+        function: String,
+        line: UInt
+    ) {
+        guard level >= logLevel else { return }
+
+        let mergedMetadata = metadata.merging(explicitMetadata ?? [:], uniquingKeysWith: { _, new in new })
+        let timestamp = Self.formatTimestamp(Date())
+
+        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)
+    }
+
+    private static func formatTimestamp(_ date: Date) -> String {
+        cachedFormatter.withLockedValue { formatter in
+            formatter.string(from: date)
+        }
+    }
+
+    private static func formatMetadata(_ metadata: Logger.Metadata) -> String {
+        metadata
+            .keys
+            .sorted()
+            .compactMap { key in
+                guard let value = metadata[key] else { return nil }
+                return "\(key)=\(value)"
+            }
+            .joined(separator: " ")
+    }
+}
+
 public enum ProxyLogging {
     private static let bootstrapState = NIOLockedValueBox(false)
     private static let labelPrefix = "XcodeMCPProxy"
@@ -21,9 +86,7 @@ public enum ProxyLogging {
         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)
         }
     }
 

Sources/ProxyHTTPTransport/HTTPHandler.swift

@@ -17,6 +17,19 @@ package final class HTTPHandler: ChannelInboundHandler, Sendable {
         package let method: String
         package let path: String
         package let remoteAddress: String?
+        package let mcpInvocation: String
+        package let requestParamsJSON: String
+
+        package func withMCPDetails(invocation: String, paramsJSON: String) -> RequestLogContext {
+            RequestLogContext(
+                id: id,
+                method: method,
+                path: path,
+                remoteAddress: remoteAddress,
+                mcpInvocation: invocation,
+                requestParamsJSON: paramsJSON
+            )
+        }
     }
 
     package struct State: Sendable {
@@ -150,7 +163,9 @@ package final class HTTPHandler: ChannelInboundHandler, Sendable {
             id: UUID().uuidString,
             method: head.method.rawValue,
             path: path,
-            remoteAddress: remoteAddressString(for: context.channel)
+            remoteAddress: remoteAddressString(for: context.channel),
+            mcpInvocation: "unknown",
+            requestParamsJSON: "null"
         )
         logRequest(requestLog)
 
@@ -399,6 +414,12 @@ package final class HTTPHandler: ChannelInboundHandler, Sendable {
             return
         }
 
+        let details = Self.mcpLogDetails(from: bodyData)
+        let requestLog = requestLog.withMCPDetails(
+            invocation: details.invocation,
+            paramsJSON: details.paramsJSON
+        )
+
         let headerSessionID = HTTPRequestValidator.sessionID(from: head.headers)
         let headerSessionExists = headerSessionID.map { controlService.hasSession(id: $0) } ?? false
         let keepAlive = head.isKeepAlive
@@ -460,4 +481,52 @@ package final class HTTPHandler: ChannelInboundHandler, Sendable {
         }
     }
 
+    package static func mcpLogDetails(from bodyData: Data) -> (invocation: String, paramsJSON: String) {
+        guard let requestJSON = try? JSONSerialization.jsonObject(with: bodyData, options: []) else {
+            return ("unknown", "null")
+        }
+
+        if let object = requestJSON as? [String: Any] {
+            return (
+                mcpInvocation(from: object),
+                jsonString((object["params"] as Any?) ?? NSNull())
+            )
+        }
+
+        if let array = requestJSON as? [Any] {
+            let paramsArray = array.map { item -> Any in
+                guard let object = item as? [String: Any] else { return NSNull() }
+                return object["params"] ?? NSNull()
+            }
+            return (
+                "batch[\(array.count)]",
+                jsonString(paramsArray)
+            )
+        }
+
+        return ("unknown", "null")
+    }
+
+    private static func mcpInvocation(from object: [String: Any]) -> String {
+        let method = (object["method"] as? String) ?? "unknown"
+        guard method == "tools/call",
+            let params = object["params"] as? [String: Any],
+            let toolName = params["name"] as? String,
+            toolName.isEmpty == false
+        else {
+            return method
+        }
+        return "\(method):\(toolName)"
+    }
+
+    private static func jsonString(_ value: Any) -> String {
+        guard JSONSerialization.isValidJSONObject(value),
+            let data = try? JSONSerialization.data(withJSONObject: value, options: []),
+            let string = String(data: data, encoding: .utf8)
+        else {
+            return "null"
+        }
+        return string
+    }
+
 }

Sources/ProxyHTTPTransport/HTTPResponseWriter.swift

@@ -199,29 +199,57 @@ package struct HTTPResponseWriter: Sendable {
         if let remote = request.remoteAddress {
             metadata["remote"] = .string(remote)
         }
-        logger.info("HTTP request", metadata: metadata)
+        logger.debug("HTTP request received", metadata: metadata)
     }
 
     package func logResponse(
         _ request: HTTPHandler.RequestLogContext,
         status: HTTPResponseStatus,
         sessionID: String?
     ) {
-        var metadata: Logger.Metadata = [
-            "id": .string(request.id),
-            "method": .string(request.method),
-            "path": .string(request.path),
-            "status": .string("\(status.code)"),
-        ]
-        if let remote = request.remoteAddress {
-            metadata["remote"] = .string(remote)
+        let resolvedSessionID = sessionID ?? "no-session"
+        let message = Self.makeHTTPLogBlock(
+            request: request,
+            statusCode: status.code,
+            sessionID: resolvedSessionID
+        )
+        // 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)
         }
-        if let sessionID {
-            metadata["session"] = .string(sessionID)
+    }
+
+    package static func makeHTTPLogBlock(
+        request: HTTPHandler.RequestLogContext,
+        statusCode: UInt,
+        sessionID: String,
+        date: Date = Date()
+    ) -> String {
+        let header = "\(formatHeaderDate(date)) info \(sessionID) \(statusCode)"
+        let requestLine = "\(request.method) \(request.path)"
+        return [header, requestLine, request.mcpInvocation, request.requestParamsJSON].joined(separator: "\n")
+    }
+
+    private static let headerDateFormatterThreadKey = "ProxyHTTPTransport.HTTPResponseWriter.headerDateFormatter"
+
+    private static func headerDateFormatter() -> DateFormatter {
+        let threadDictionary = Thread.current.threadDictionary
+        if let formatter = threadDictionary[headerDateFormatterThreadKey] as? DateFormatter {
+            return formatter
         }
-        logger.info("HTTP response", metadata: metadata)
+
+        let formatter = DateFormatter()
+        formatter.locale = Locale(identifier: "en_US_POSIX")
+        formatter.timeZone = .autoupdatingCurrent
+        formatter.dateFormat = "yy-MM-dd HH:mm:ss"
+        threadDictionary[headerDateFormatterThreadKey] = formatter
+        return formatter
     }
 
+    private static func formatHeaderDate(_ date: Date) -> String {
+        headerDateFormatter().string(from: date)
+    }
     private func sendResponseData(
         on channel: Channel,
         data: Data,

Tests/ProxyHTTPTransportTests/HTTPLoggingFormatTests.swift

@@ -0,0 +1,78 @@
+import Foundation
+import Testing
+
+@testable import ProxyHTTPTransport
+
+struct HTTPLoggingFormatTests {
+    @Test func mcpLogDetailsExtractsToolsCallNameAndParams() throws {
+        let payload = """
+        {
+          "jsonrpc": "2.0",
+          "id": 1,
+          "method": "tools/call",
+          "params": {
+            "name": "XcodeListWindows",
+            "arguments": {
+              "includeMinimized": true
+            }
+          }
+        }
+        """.data(using: .utf8)!
+
+        let details = HTTPHandler.mcpLogDetails(from: payload)
+
+        #expect(details.invocation == "tools/call:XcodeListWindows")
+        let paramsJSON = try #require(details.paramsJSON.data(using: .utf8))
+        let paramsObject = try JSONSerialization.jsonObject(with: paramsJSON, options: []) as? [String: Any]
+        let name = paramsObject?["name"] as? String
+        let arguments = paramsObject?["arguments"] as? [String: Any]
+        #expect(name == "XcodeListWindows")
+        #expect(arguments?["includeMinimized"] as? Bool == true)
+    }
+
+    @Test func mcpLogDetailsHandlesBatchRequests() throws {
+        let payload = """
+        [
+          {"jsonrpc":"2.0","id":1,"method":"tools/list","params":{"cursor":"next"}},
+          {"jsonrpc":"2.0","id":2,"method":"ping"}
+        ]
+        """.data(using: .utf8)!
+
+        let details = HTTPHandler.mcpLogDetails(from: payload)
+
+        #expect(details.invocation == "batch[2]")
+        let paramsJSON = try #require(details.paramsJSON.data(using: .utf8))
+        let paramsArray = try JSONSerialization.jsonObject(with: paramsJSON, options: []) as? [Any]
+        #expect(paramsArray?.count == 2)
+        let first = paramsArray?[0] as? [String: Any]
+        #expect(first?["cursor"] as? String == "next")
+        #expect(paramsArray?[1] is NSNull)
+    }
+
+    @Test func makeHTTPLogBlockUsesRequiredFourLineFormat() throws {
+        let request = HTTPHandler.RequestLogContext(
+            id: "request-1",
+            method: "POST",
+            path: "/mcp",
+            remoteAddress: nil,
+            mcpInvocation: "tools/list",
+            requestParamsJSON: "{\"cursor\":\"next\"}"
+        )
+
+        let logBlock = HTTPResponseWriter.makeHTTPLogBlock(
+            request: request,
+            statusCode: 200,
+            sessionID: "session-123",
+            date: Date(timeIntervalSince1970: 1_714_469_200)
+        )
+        let lines = logBlock.split(separator: "\n", omittingEmptySubsequences: false).map(String.init)
+
+        #expect(lines.count == 4)
+        #expect(lines[0].contains(" info session-123 200"))
+        #expect(lines[0].contains("+") == false)
+        #expect(lines[0].range(of: #"^\d{2}-\d{2}-\d{2} \d{2}:\d{2}:\d{2} info session-123 200$"#, options: .regularExpression) != nil)
+        #expect(lines[1] == "POST /mcp")
+        #expect(lines[2] == "tools/list")
+        #expect(lines[3] == "{\"cursor\":\"next\"}")
+    }
+}