Polish up impl, remove pasted test tracer, add more tests

Author: ktoso

Package@swift-6.1.swift

@@ -83,6 +83,7 @@ let package = Package(
                 .product(name: "Algorithms", package: "swift-algorithms"),
                 // Observability support
                 .product(name: "Tracing", package: "swift-distributed-tracing", condition: .when(traits: ["TracingSupport"])),
+                .product(name: "InMemoryTracing", package: "swift-distributed-tracing", condition: .when(traits: ["TracingSupport"])),
             ],
             swiftSettings: strictConcurrencySettings
         ),
@@ -102,6 +103,9 @@ let package = Package(
                 .product(name: "Logging", package: "swift-log"),
                 .product(name: "Atomics", package: "swift-atomics"),
                 .product(name: "Algorithms", package: "swift-algorithms"),
+                // Observability support
+                .product(name: "Tracing", package: "swift-distributed-tracing", condition: .when(traits: ["TracingSupport"])),
+                .product(name: "InMemoryTracing", package: "swift-distributed-tracing", condition: .when(traits: ["TracingSupport"])),
             ],
             resources: [
                 .copy("Resources/self_signed_cert.pem"),

Sources/AsyncHTTPClient/AsyncAwait/HTTPClient+execute.swift

@@ -39,12 +39,27 @@ extension HTTPClient {
         deadline: NIODeadline,
         logger: Logger? = nil
     ) async throws -> HTTPClientResponse {
-        try await self.executeAndFollowRedirectsIfNeeded(
-            request,
-            deadline: deadline,
-            logger: logger ?? Self.loggingDisabled,
-            redirectState: RedirectState(self.configuration.redirectConfiguration.mode, initialURL: request.url)
-        )
+        func doExecute() async throws -> HTTPClientResponse {
+            try await self.executeAndFollowRedirectsIfNeeded(
+                request,
+                deadline: deadline,
+                logger: logger ?? Self.loggingDisabled,
+                redirectState: RedirectState(self.configuration.redirectConfiguration.mode, initialURL: request.url)
+            )
+        }
+
+        #if TracingSupport
+        if let tracer = self.tracer {
+            return try await tracer.withSpan("\(request.method)") { span -> (HTTPClientResponse) in
+                let attr = self.configuration.tracing.attributeKeys
+                span.attributes[attr.requestMethod] = request.method.rawValue
+                // Set more attributes on the span
+                return try await doExecute()
+            }
+        }
+        #endif
+        
+        return try await doExecute()
     }
 }
 

Sources/AsyncHTTPClient/AsyncAwait/Transaction.swift

@@ -52,7 +52,6 @@ final class Transaction:
         span: (any Span)?,
         responseContinuation: CheckedContinuation<HTTPClientResponse, Error>
     ) {
-        print("[swift] new transaction WITH SPAN = \(request); span = \(span)")
         self.request = request
         self.requestOptions = requestOptions
         self.logger = logger

Sources/AsyncHTTPClient/HTTPClient.swift

@@ -61,9 +61,6 @@ let globalRequestID = ManagedAtomic(0)
 ///         }
 ///     }
 /// ```
-// #if TracingSupport
-// @available(macOS 10.15, iOS 13, tvOS 13, watchOS 6, *)
-// #endif
 public final class HTTPClient: Sendable {
     /// The `EventLoopGroup` in use by this ``HTTPClient``.
     ///
@@ -80,8 +77,9 @@ public final class HTTPClient: Sendable {
 
     #if TracingSupport
     @_spi(Tracing)
-    public var tracer: (any Tracer)? { // Tracer requires macOS 10.15... so we're forced into annotating HTTPClient :-/ 
-        configuration.tracer
+    @available(macOS 10.15, iOS 13, tvOS 13, watchOS 6, *)  // for TaskLocal ServiceContext
+    public var tracer: (any Tracer)? {
+        configuration.tracing.tracer
     }
     #endif // TracingSupport
 
@@ -368,8 +366,7 @@ public final class HTTPClient: Sendable {
     ///     - url: Remote URL.
     ///     - deadline: Point in time by which the request must complete.
     public func get(url: String, deadline: NIODeadline? = nil) -> EventLoopFuture<Response> {
-        print("[swift] GET \(url)")
-        return self.get(url: url, deadline: deadline, logger: HTTPClient.loggingDisabled)
+        self.get(url: url, deadline: deadline, logger: HTTPClient.loggingDisabled)
     }
 
     /// Execute `GET` request using specified URL.
@@ -496,7 +493,6 @@ public final class HTTPClient: Sendable {
     ) -> EventLoopFuture<Response> {
         do {
             let request = try Request(url: url, method: method, body: body)
-            print("[swift] request \(request)")
             return self.execute(request: request, deadline: deadline, logger: logger ?? HTTPClient.loggingDisabled)
         } catch {
             return self.eventLoopGroup.any().makeFailedFuture(error)
@@ -575,7 +571,7 @@ public final class HTTPClient: Sendable {
     ///     - deadline: Point in time by which the request must complete.
     ///     - logger: The logger to use for this request.
     public func execute(request: Request, deadline: NIODeadline? = nil, logger: Logger) -> EventLoopFuture<Response> {
-        let accumulator = ResponseAccumulator(request: request) // FIXME: end here?
+        let accumulator = ResponseAccumulator(request: request)
         return self.execute(request: request, delegate: accumulator, deadline: deadline, logger: logger).futureResult
     }
 
@@ -688,8 +684,6 @@ public final class HTTPClient: Sendable {
         deadline: NIODeadline? = nil,
         logger: Logger?
     ) -> Task<Delegate.Response> {
-        print("[swift] EXECUTE HERE")
-        assert(self.configuration.tracer != nil)
         return self._execute(
             request: request,
             delegate: delegate,
@@ -717,14 +711,28 @@ public final class HTTPClient: Sendable {
         eventLoop eventLoopPreference: EventLoopPreference,
         deadline: NIODeadline? = nil,
         logger originalLogger: Logger?,
-        redirectState: RedirectState?
+        redirectState: RedirectState?,
     ) -> Task<Delegate.Response> {
-        assert(self.configuration.tracer != nil)
         let logger = (originalLogger ?? HTTPClient.loggingDisabled).attachingRequestInformation(
             request,
             requestID: globalRequestID.wrappingIncrementThenLoad(ordering: .relaxed)
         )
-        let tracer = self.configuration.tracer
+
+        // #if TracingSupport 
+        // let span: (any Span)? // we may be still executing the same span, e.g. under redirection etc.
+        // if let activeSpan {
+        //     span = activeSpan
+        // } else if let tracer = self.tracer {
+        //     let s = tracer.startSpan(request.method.rawValue)
+        //     let attrs = self.configuration.tracing.attributeKeys
+        //     s.attributes[attrs.requestMethod] = request.method.rawValue
+        //     s.attributes["loc"] = "\(#fileID):\(#line)"
+        //     span = s
+        // } else {
+        //     span = nil
+        // }
+        // #endif
+        
         let taskEL: EventLoop
         switch eventLoopPreference.preference {
         case .indifferent:
@@ -760,10 +768,14 @@ public final class HTTPClient: Sendable {
                 return nil
             case .shuttingDown, .shutDown:
                 logger.debug("client is shutting down, failing request")
-                // TODO: span immediately failed ops
+                let error = HTTPClientError.alreadyShutdown
+                // #if TracingSupport
+                // span?.recordError(error)
+                // span?.end()
+                // #endif
                 return Task<Delegate.Response>.failedTask(
                     eventLoop: taskEL,
-                    error: HTTPClientError.alreadyShutdown,
+                    error: error,
                     logger: logger,
                     tracer: tracer,
                     makeOrGetFileIOThreadPool: self.makeOrGetFileIOThreadPool
@@ -778,7 +790,6 @@ public final class HTTPClient: Sendable {
         let redirectHandler: RedirectHandler<Delegate.Response>? = {
             guard let redirectState = redirectState else { return nil }
 
-            // TODO: span for redirects?
             return .init(request: request, redirectState: redirectState) { newRequest, newRedirectState in
                 self._execute(
                     request: newRequest,
@@ -791,26 +802,12 @@ public final class HTTPClient: Sendable {
             }
         }()
 
-        print("[swift](\(#fileID):\(#line)) tracer was = \(tracer)")
-        precondition(tracer != nil, "Expected tracer to be set in \(#function) @ \(#fileID):\(#line)")
-        #if TracingSupport
-        let task = Task<Delegate.Response>(
-                eventLoop: taskEL,
-                logger: logger,
-                tracer: tracer,
-                makeOrGetFileIOThreadPool: self.makeOrGetFileIOThreadPool
-            )
-        #else
         let task = Task<Delegate.Response>(
-                eventLoop: taskEL,
-                logger: logger,
-                tracer: tracer,
-                makeOrGetFileIOThreadPool: self.makeOrGetFileIOThreadPool
-            )
-        #endif // TracingSupport 
-
-        precondition(task.tracer != nil, "Expected tracer to be set in \(#function)")
-        print("[swift] task.tracer was nil? \(task.tracer == nil)")
+            eventLoop: taskEL,
+            logger: logger,
+            tracer: tracer,
+            makeOrGetFileIOThreadPool: self.makeOrGetFileIOThreadPool
+        )
 
         do {
             let requestBag = try RequestBag(
@@ -924,12 +921,7 @@ public final class HTTPClient: Sendable {
         public var http2StreamChannelDebugInitializer: (@Sendable (Channel) -> EventLoopFuture<Void>)?
 
         #if TracingSupport
-        /// Tracer that should be used by the HTTPClient. 
-        /// 
-        /// This is selected at configuration creation time, and if no tracer is passed explicitly,
-        /// (including `nil` in order to disable traces), the default global bootstrapped tracer will
-        /// be stored in this property, and used for all subsequent requests made by this client.
-        public var tracer: (any Tracer)? = InstrumentationSystem.tracer
+        public var tracing: TracingConfiguration = .init()
         #endif
 
         public init(
@@ -1059,9 +1051,6 @@ public final class HTTPClient: Sendable {
             self.http1_1ConnectionDebugInitializer = http1_1ConnectionDebugInitializer
             self.http2ConnectionDebugInitializer = http2ConnectionDebugInitializer
             self.http2StreamChannelDebugInitializer = http2StreamChannelDebugInitializer
-            #if TracingSupport
-            self.tracer = InstrumentationSystem.tracer
-            #endif
         }
 
         #if TracingSupport
@@ -1076,7 +1065,7 @@ public final class HTTPClient: Sendable {
             http1_1ConnectionDebugInitializer: (@Sendable (Channel) -> EventLoopFuture<Void>)? = nil,
             http2ConnectionDebugInitializer: (@Sendable (Channel) -> EventLoopFuture<Void>)? = nil,
             http2StreamChannelDebugInitializer: (@Sendable (Channel) -> EventLoopFuture<Void>)? = nil,
-            tracer: (any Tracer)? = InstrumentationSystem.tracer
+            tracing: TracingConfiguration = .init()
         ) {
             self.init(
                 tlsConfiguration: tlsConfiguration,
@@ -1090,11 +1079,62 @@ public final class HTTPClient: Sendable {
             self.http1_1ConnectionDebugInitializer = http1_1ConnectionDebugInitializer
             self.http2ConnectionDebugInitializer = http2ConnectionDebugInitializer
             self.http2StreamChannelDebugInitializer = http2StreamChannelDebugInitializer
-            self.tracer = tracer
+            self.tracing = tracing
         }
         #endif
     }
 
+    #if TracingSupport
+    public struct TracingConfiguration: Sendable {
+        
+        @usableFromInline 
+        var _tracer: Optional<any Sendable> // erasure trick so we don't have to make Configuration @available
+
+        /// Tracer that should be used by the HTTPClient. 
+        /// 
+        /// This is selected at configuration creation time, and if no tracer is passed explicitly,
+        /// (including `nil` in order to disable traces), the default global bootstrapped tracer will
+        /// be stored in this property, and used for all subsequent requests made by this client.
+        @inlinable
+        @available(macOS 10.15, iOS 13, tvOS 13, watchOS 6, *)
+        public var tracer: (any Tracer)? { 
+            get { 
+                guard let _tracer else {
+                    return nil
+                }
+                return _tracer as! (any Tracer)?
+            }
+            set {
+                self._tracer = newValue
+            }
+        }
+
+        public var attributeKeys: AttributeKeys
+
+        public init(
+            tracer: (any Tracer)? = InstrumentationSystem.tracer,
+            attributeKeys: AttributeKeys = .init()
+        ) {
+            self._tracer = tracer
+            self.attributeKeys = attributeKeys
+        }
+
+        /// Span attribute keys that the HTTPClient should set automatically.
+        /// This struct allows the configuration of the attribute names (keys) which will be used for the apropriate values.
+        public struct AttributeKeys: Sendable { 
+            public var requestMethod: String = "http.request.method"
+            public var requestBodySize: String = "http.request.body.size"
+
+            public var responseBodySize: String = "http.response.size"
+            public var responseStatusCode: String = "http.status_code"
+            
+            public var httpFlavor: String = "http.flavor"
+
+            public init() {}
+        }
+    }
+    #endif
+
     /// Specifies how `EventLoopGroup` will be created and establishes lifecycle ownership.
     public enum EventLoopGroupProvider {
         /// `EventLoopGroup` will be provided by the user. Owner of this group is responsible for its lifecycle.

Sources/AsyncHTTPClient/RequestBag.swift

@@ -54,8 +54,11 @@ final class RequestBag<Delegate: HTTPClientResponseDelegate & Sendable>: Sendabl
         var consumeBodyPartStackDepth: Int
         // if a redirect occurs, we store the task for it so we can propagate cancellation
         var redirectTask: HTTPClient.Task<Delegate.Response>? = nil
-        // The current span, if active.
+        
+        #if TracingSupport 
+        // The current span, representing the entire request/response made by an execute call.
         var activeSpan: (any Span)? = nil
+        #endif // TracingSupport
     }
 
     private let loopBoundState: NIOLoopBoundBox<LoopBoundState>
@@ -66,13 +69,11 @@ final class RequestBag<Delegate: HTTPClientResponseDelegate & Sendable>: Sendabl
         self.task.logger
     }
 
-    #if TracingSupport
-    var tracer: (any Tracer)? {
+    let connectionDeadline: NIODeadline
+
+    var tracer: HTTPClientTracingSupportTracerType? {
         self.task.tracer
     }
-    #endif
-
-    let connectionDeadline: NIODeadline
 
     let requestOptions: RequestOptions
 
@@ -126,17 +127,20 @@ final class RequestBag<Delegate: HTTPClientResponseDelegate & Sendable>: Sendabl
     // MARK: - Request -
 
     private func willExecuteRequest0(_ executor: HTTPRequestExecutor) {
+        // Immediately start a span for the "whole" request
+        self.loopBoundState.value.startRequestSpan(tracer: self.tracer)
+
         let action = self.loopBoundState.value.state.willExecuteRequest(executor)
         switch action {
         case .cancelExecuter(let executor):
             executor.cancelRequest(self)
+            self.loopBoundState.value.failRequestSpan(error: CancellationError())
         case .failTaskAndCancelExecutor(let error, let executor):
             self.delegate.didReceiveError(task: self.task, error)
             self.task.failInternal(with: error)
             executor.cancelRequest(self)
+            self.loopBoundState.value.failRequestSpan(error: CancellationError())
         case .none:
-            let request = self.loopBoundState.value.request
-            self.activeSpan = self.tracer?.startSpan("\(request.method) \(request.host)")
             break
         }
     }
@@ -244,6 +248,7 @@ final class RequestBag<Delegate: HTTPClientResponseDelegate & Sendable>: Sendabl
 
     private func receiveResponseHead0(_ head: HTTPResponseHead) {
         self.delegate.didVisitURL(task: self.task, self.loopBoundState.value.request, head)
+        self.loopBoundState.value.endRequestSpan(response: head)
 
         // runs most likely on channel eventLoop
         switch self.loopBoundState.value.state.receiveResponseHead(head) {