Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Trace HTTPClient request execution #320

Draft
wants to merge 1 commit into
base: main
Choose a base branch
from
Draft
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 4 additions & 0 deletions Package.swift
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,8 @@ let package = Package(
.package(url: "https://github.com/apple/swift-nio-extras.git", from: "1.13.0"),
.package(url: "https://github.com/apple/swift-nio-transport-services.git", from: "1.19.0"),
.package(url: "https://github.com/apple/swift-log.git", from: "1.4.4"),
.package(url: "https://github.com/apple/swift-distributed-tracing.git", from: "1.0.0"),
.package(url: "https://github.com/apple/swift-service-context.git", from: "1.0.0"),
.package(url: "https://github.com/apple/swift-atomics.git", from: "1.0.2"),
.package(url: "https://github.com/apple/swift-algorithms.git", from: "1.0.0"),
],
Expand All @@ -53,6 +55,8 @@ let package = Package(
.product(name: "NIOSOCKS", package: "swift-nio-extras"),
.product(name: "NIOTransportServices", package: "swift-nio-transport-services"),
.product(name: "Logging", package: "swift-log"),
.product(name: "Tracing", package: "swift-distributed-tracing"),
.product(name: "ServiceContextModule", package: "swift-service-context"),
.product(name: "Atomics", package: "swift-atomics"),
.product(name: "Algorithms", package: "swift-algorithms"),
]
Expand Down
112 changes: 78 additions & 34 deletions Sources/AsyncHTTPClient/AsyncAwait/HTTPClient+execute.swift
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,8 @@
import Logging
import NIOCore
import NIOHTTP1
import ServiceContextModule
import Tracing

import struct Foundation.URL

Expand All @@ -30,18 +32,20 @@ extension HTTPClient {
public func execute(
_ request: HTTPClientRequest,
deadline: NIODeadline,
logger: Logger? = nil
logger: Logger? = nil,
context: ServiceContext? = nil

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Adding a parameter is technically breaking, so we'll need one more variant of this function with the original signature and @_disfavoredOverload and a deprecation warning, calling out to this new method.

) async throws -> HTTPClientResponse {
try await self.executeAndFollowRedirectsIfNeeded(
request,
deadline: deadline,
logger: logger ?? Self.loggingDisabled,
context: context ?? .current ?? .topLevel,
redirectState: RedirectState(self.configuration.redirectConfiguration.mode, initialURL: request.url)
)
}
}

// MARK: Connivence methods
// MARK: Convenience methods

@available(macOS 10.15, iOS 13.0, watchOS 6.0, tvOS 13.0, *)
extension HTTPClient {
Expand All @@ -55,12 +59,14 @@ extension HTTPClient {
public func execute(
_ request: HTTPClientRequest,
timeout: TimeAmount,
logger: Logger? = nil
logger: Logger? = nil,
context: ServiceContext? = nil

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Same here re re-adding the previous variant for backwards compatibility.

) async throws -> HTTPClientResponse {
try await self.execute(
request,
deadline: .now() + timeout,
logger: logger
logger: logger,
context: context
)
}
}
Expand All @@ -71,15 +77,23 @@ extension HTTPClient {
_ request: HTTPClientRequest,
deadline: NIODeadline,
logger: Logger,
context: ServiceContext,
redirectState: RedirectState?
) async throws -> HTTPClientResponse {
var currentRequest = request
var currentRedirectState = redirectState
var resendCount = 0

// this loop is there to follow potential redirects
while true {
let preparedRequest = try HTTPClientRequest.Prepared(currentRequest, dnsOverride: configuration.dnsOverride)
let response = try await self.executeCancellable(preparedRequest, deadline: deadline, logger: logger)
let response = try await self.executeCancellable(
preparedRequest,
deadline: deadline,
logger: logger,
context: context,
resendCount: resendCount > 0 ? resendCount : nil
)

guard var redirectState = currentRedirectState else {
// a `nil` redirectState means we should not follow redirects
Expand Down Expand Up @@ -112,46 +126,76 @@ extension HTTPClient {
return response
}

resendCount += 1
currentRequest = newRequest
}
}

private func executeCancellable(
_ request: HTTPClientRequest.Prepared,
deadline: NIODeadline,
logger: Logger
logger: Logger,
context: ServiceContext,
resendCount: Int?
) async throws -> HTTPClientResponse {
let cancelHandler = TransactionCancelHandler()

return try await withTaskCancellationHandler(
operation: { () async throws -> HTTPClientResponse in
let eventLoop = self.eventLoopGroup.any()
let deadlineTask = eventLoop.scheduleTask(deadline: deadline) {
cancelHandler.cancel(reason: .deadlineExceeded)
}
defer {
deadlineTask.cancel()
}
return try await withCheckedThrowingContinuation {
(continuation: CheckedContinuation<HTTPClientResponse, Swift.Error>) -> Void in
let transaction = Transaction(
request: request,
requestOptions: .fromClientConfiguration(self.configuration),
logger: logger,
connectionDeadline: .now() + (self.configuration.timeout.connectionCreationTimeout),
preferredEventLoop: eventLoop,
responseContinuation: continuation
)

cancelHandler.registerTransaction(transaction)

self.poolManager.executeRequest(transaction)
}
},
onCancel: {
cancelHandler.cancel(reason: .taskCanceled)
return try await withSpan(request.head.method.rawValue, context: context, ofKind: .client) { span in
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM on using just the method as low cardinality name (matches otel well) 👍

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Should the Tracer be a property of the client, to allow for easier unit testing? And just default it to the current process-bootstrapped tracer in the initializer, unless it's overridden?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We could do that, yeah. Elsewhere we just use InstrumentationSystem.bootstrapInternal in unit tests which also works fine but I'd be happy either way.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Unless there are downsides, I prefer the explicit dependency injection. Easy enough to debug and reason about.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Sounds good to me as long as we don't expose this initializer publicly.

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What's the downside of adding it to the public initializer?

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It goes against the way Swift Distributed Tracing usually works, where a single tracer is chosen for the system and used transparently everywhere. Having said that, Logging also allows passing specific Loggers around and still use LoggingSystem. I'm curious to hear what @ktoso thinks about this.

var request = request
request.head.headers.propagate(span.context)
span.updateAttributes { attributes in
attributes["http.request.method"] = request.head.method.rawValue

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Do we also attach the path as a separate attribute, or is url.full the only place it's expected to show up?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Path may be nice tbh... it's not a "standardized" convention but I could see it be useful... Up to y'all if we want to duplicate; url.full seems to be the "expected one" to set otel wise...

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

url.path seems to be recommended for the server span only here: https://opentelemetry.io/docs/specs/semconv/http/http-spans/#http-server-semantic-conventions? But here it's simply listed, without that server guidance: https://opentelemetry.io/docs/specs/semconv/attributes-registry/url/#url-path

I guess wouldn't hurt to add it, but I guess the client is expected not to have the full URL broken out into components, but the server does.

I'm happy to keep it as-is, with just url.full.

Copy link
Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yeah, I think it's fine to just include url.full for now. That being said, something I haven't yet implemented in the PR is redaction as recommended (although experimental) in OTel SemConv:

https://opentelemetry.io/docs/specs/semconv/http/http-spans/#http-client

[4] url.full: For network calls, URL usually has scheme://host[:port][path][?query][#fragment] format, where the fragment is not transmitted over HTTP, but if it is known, it SHOULD be included nevertheless.

url.full MUST NOT contain credentials passed via URL in form of https://username:[email protected]/. In such case username and password SHOULD be redacted and attribute’s value SHOULD be https://REDACTED:[email protected]/.
Sensitive content provided in url.full SHOULD be scrubbed when instrumentations can identify it.

Experimental Query string values for the following keys SHOULD be redacted by default and replaced by the value REDACTED:
AWSAccessKeyId / Signature / sig / X-Goog-Signature
This list is subject to change over time.

When a query string value is redacted, the query string key SHOULD still be preserved, e.g. https://www.example.com/path?color=blue&sig=REDACTED.

What do you think about adding these? I'm a bit torn but I don't think we'd want to include these specific keys in AsyncHTTPClient. Perhaps we could skip adding them for now and only redact the basic auth parameters, and tackle the other redaction in swift-otel/swift-otel-semantic-conventions and eventually add a dependency on it to AsyncHTTPClient.

attributes["server.address"] = request.poolKey.connectionTarget.host
attributes["server.port"] = request.poolKey.connectionTarget.port
attributes["url.full"] = request.url.absoluteString
attributes["http.request.resend_count"] = resendCount
}
)

do {
let response = try await withTaskCancellationHandler(
operation: { () async throws -> HTTPClientResponse in
let eventLoop = self.eventLoopGroup.any()
let deadlineTask = eventLoop.scheduleTask(deadline: deadline) {
cancelHandler.cancel(reason: .deadlineExceeded)
}
defer {
deadlineTask.cancel()
}
let response = try await withCheckedThrowingContinuation {
(continuation: CheckedContinuation<HTTPClientResponse, Swift.Error>) -> Void in
let transaction = Transaction(
request: request,
requestOptions: .fromClientConfiguration(self.configuration),
logger: logger,
connectionDeadline: .now() + (self.configuration.timeout.connectionCreationTimeout),
preferredEventLoop: eventLoop,
responseContinuation: continuation
)

cancelHandler.registerTransaction(transaction)

self.poolManager.executeRequest(transaction)
}
if response.status.code >= 400 {
span.setStatus(.init(code: .error))
span.attributes["error.type"] = "\(response.status.code)"
}
span.attributes["http.response.status_code"] = "\(response.status.code)"
return response
},
onCancel: {
span.setStatus(.init(code: .error))
span.attributes["error.type"] = "\(CancellationError.self)"
cancelHandler.cancel(reason: .taskCanceled)
}
)
return response
} catch {
span.setStatus(.init(code: .error))
span.attributes["error.type"] = "\(type(of: error))"
throw error

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does this mean the span doesn't include the error description, and it's up to user code to attach it higher up the stack?

Copy link
Contributor

@ktoso ktoso Feb 10, 2025

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Comes back to the entire "can we log errors" (not really since no idea what they contain) discussion we were having elsewhere recently. 😅

The otel guidance is the same tbh: https://opentelemetry.io/docs/specs/semconv/general/recording-errors/#recording-errors-on-spans but you'll notice it gets hand wavy with it with exception messages -- Java influenced wording there;

SHOULD set the span status code to Error

SHOULD set the error.type attribute

SHOULD set the span status description when it has additional information about the error which is not expected to contain sensitive details and aligns with Span Status Description definition.

It’s NOT RECOMMENDED to duplicate status code or error.type in span status description.

When the operation fails with an exception, the span status description SHOULD be set to the exception message.

So that leaves us back at step 1 where we need to decide what is safe -- the "exception message" is not a thing in Swift after all, and "(error)" may or may not be safe...

Unless we're able to confirm all errors that can be thrown here are "safe to be logged" and only from inside the HTTP infra and don't include request details it doesn't seem like we should log the "message" (that being the "(error)" in swift). I'm not sure if we're 100% confident about it here?

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Unsure, but I wouldn't want this PR to be blocked on that, I'm happy with the first iteration not including the message here.

}
}
}
}

Expand Down
32 changes: 32 additions & 0 deletions Sources/AsyncHTTPClient/ServiceContextPropagation.swift
Original file line number Diff line number Diff line change
@@ -0,0 +1,32 @@
//===----------------------------------------------------------------------===//
//
// This source file is part of the AsyncHTTPClient open source project
//
// Copyright (c) 2024 Apple Inc. and the AsyncHTTPClient project authors
// Licensed under Apache License v2.0
//
// See LICENSE.txt for license information
// See CONTRIBUTORS.txt for the list of AsyncHTTPClient project authors
//
// SPDX-License-Identifier: Apache-2.0
//
//===----------------------------------------------------------------------===//

import Instrumentation
import NIOHTTP1
import ServiceContextModule

@available(macOS 10.15, iOS 13.0, watchOS 6.0, tvOS 13.0, *)
extension HTTPHeaders {
mutating func propagate(_ context: ServiceContext) {
InstrumentationSystem.instrument.inject(context, into: &self, using: Self.injector)
}

private static let injector = HTTPHeadersInjector()
}

private struct HTTPHeadersInjector: Injector {
func inject(_ value: String, forKey name: String, into headers: inout HTTPHeaders) {
headers.add(name: name, value: value)
}
}