Skip to content

Commit

Permalink
HBTracingMiddleware with attaching baggage to request (#163)
Browse files Browse the repository at this point in the history
* Add HBTracingMiddleware

* Add baggage to request instead of using task local variables

* Add withSpan functions

* Add EventLoopFuture versions of withSpan

* Edit HBTracingMiddleware to use withSpan

* Set Baggage task local for HBAsyncCallbackResponder

Also added test to verify baggage is propagated

* Move Baggage.swift to Server folder

* Move tracing/baggage tests to own class

* Remove unnecessary XCT calls

* Swift format

* Propagate baggage into async middleware

- Copy request baggage into task local before calling middleware
- Copy task local baggage back to request after calling middleware

* Remove async versions of withSpan/Baggage

If you are in an async environment you should be using InstrumentationSystem.tracer

* Use Baggage.testID

* Remove code prefixing "/" to endpoint path

* public

* Update Sources/Hummingbird/Middleware/TracingMiddleware.swift

Co-authored-by: Moritz Lang <[email protected]>

* comments

* comments

* Updated to work with beta of distributed tracing

This now requires swift 5.6 and macOS 10.15

* Use legacyTracer to get 5.6 to compile

* Set span attributes in one go

* Revert to LegacyTracer while we support 5.6

* Using 1.0 of TracingMiddleware

* Added Span.updateAttributes

* Update to use swift-distributed-tracing 1.0.1

And remove platform requirements

* Add @available

---------

Co-authored-by: Moritz Lang <[email protected]>
  • Loading branch information
adam-fowler and slashmo authored Jun 27, 2023
1 parent bac6817 commit 1179f5e
Show file tree
Hide file tree
Showing 8 changed files with 1,080 additions and 7 deletions.
2 changes: 2 additions & 0 deletions Package.swift
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@ let package = Package(
dependencies: [
.package(url: "https://github.com/apple/swift-log.git", from: "1.4.0"),
.package(url: "https://github.com/apple/swift-metrics.git", "1.0.0"..<"3.0.0"),
.package(url: "https://github.com/apple/swift-distributed-tracing.git", from: "1.0.1"),
.package(url: "https://github.com/apple/swift-nio.git", from: "2.45.0"),
.package(url: "https://github.com/swift-server/swift-service-lifecycle.git", from: "1.0.0-alpha.9"),
.package(url: "https://github.com/hummingbird-project/hummingbird-core.git", from: "1.2.1"),
Expand All @@ -27,6 +28,7 @@ let package = Package(
.product(name: "LifecycleNIOCompat", package: "swift-service-lifecycle"),
.product(name: "Logging", package: "swift-log"),
.product(name: "Metrics", package: "swift-metrics"),
.product(name: "Tracing", package: "swift-distributed-tracing"),
.product(name: "NIOCore", package: "swift-nio"),
.product(name: "NIOPosix", package: "swift-nio"),
.product(name: "NIOHTTP1", package: "swift-nio"),
Expand Down
25 changes: 22 additions & 3 deletions Sources/Hummingbird/AsyncAwaitSupport/AsyncMiddleware.swift
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@
//===----------------------------------------------------------------------===//

import NIOCore
import ServiceContextModule

/// Middleware using async/await
@available(macOS 10.15, iOS 13.0, tvOS 13.0, watchOS 6.0, *)
Expand All @@ -24,10 +25,28 @@ public protocol HBAsyncMiddleware: HBMiddleware {
extension HBAsyncMiddleware {
public func apply(to request: HBRequest, next: HBResponder) -> EventLoopFuture<HBResponse> {
let promise = request.eventLoop.makePromise(of: HBResponse.self)
promise.completeWithTask {
return try await apply(to: request, next: next)
return ServiceContext.$current.withValue(request.serviceContext) {
promise.completeWithTask {
return try await self.apply(to: request, next: HBPropagateServiceContextResponder(responder: next))
}
return promise.futureResult
}
}
}

/// Propagate Task Local serviceContext back to HBRequest after running AsyncMiddleware
@available(macOS 10.15, iOS 13.0, tvOS 13.0, watchOS 6.0, *)
struct HBPropagateServiceContextResponder: HBResponder {
let responder: HBResponder

func respond(to request: HBRequest) -> EventLoopFuture<HBResponse> {
if let serviceContext = ServiceContext.$current.get() {
return request.withServiceContext(serviceContext) { request in
self.responder.respond(to: request)
}
} else {
return self.responder.respond(to: request)
}
return promise.futureResult
}
}

Expand Down
9 changes: 6 additions & 3 deletions Sources/Hummingbird/AsyncAwaitSupport/AsyncResponder.swift
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@
//===----------------------------------------------------------------------===//

import NIO
import ServiceContextModule

/// Responder that calls supplied closure
@available(macOS 10.15, iOS 13.0, tvOS 13.0, watchOS 6.0, *)
Expand All @@ -26,9 +27,11 @@ public struct HBAsyncCallbackResponder: HBResponder {
/// Return EventLoopFuture that will be fulfilled with response to the request supplied
public func respond(to request: HBRequest) -> EventLoopFuture<HBResponse> {
let promise = request.eventLoop.makePromise(of: HBResponse.self)
promise.completeWithTask {
try await callback(request)
return ServiceContext.$current.withValue(request.serviceContext) {
promise.completeWithTask {
try await self.callback(request)
}
return promise.futureResult
}
return promise.futureResult
}
}
158 changes: 158 additions & 0 deletions Sources/Hummingbird/Middleware/TracingMiddleware.swift
Original file line number Diff line number Diff line change
@@ -0,0 +1,158 @@
//===----------------------------------------------------------------------===//
//
// This source file is part of the Hummingbird server framework project
//
// Copyright (c) 2023 the Hummingbird authors
// Licensed under Apache License v2.0
//
// See LICENSE.txt for license information
// See hummingbird/CONTRIBUTORS.txt for the list of Hummingbird authors
//
// SPDX-License-Identifier: Apache-2.0
//
//===----------------------------------------------------------------------===//

import Tracing

/// Middleware creating Distributed Tracing spans for each request.
///
/// Creates a span for each request, including attributes such as the HTTP method.
///
/// You may opt in to recording a specific subset of HTTP request/response header values by passing
/// a set of header names to ``init(recordingHeaders:)``.
@available(macOS 10.15, iOS 13.0, tvOS 13.0, watchOS 6.0, *)
public struct HBTracingMiddleware: HBMiddleware {
private let headerNamesToRecord: Set<RecordingHeader>

/// Intialize a new HBTracingMiddleware.
///
/// - Parameter recordingHeaders: A list of HTTP header names to be recorded as span attributes. By default, no headers
/// are being recorded.
public init<C: Collection>(recordingHeaders headerNamesToRecord: C) where C.Element == String {
self.headerNamesToRecord = Set(headerNamesToRecord.map(RecordingHeader.init))
}

/// Intialize a new HBTracingMiddleware.
public init() {
self.init(recordingHeaders: [])
}

public func apply(to request: HBRequest, next: HBResponder) -> EventLoopFuture<HBResponse> {
var serviceContext = request.serviceContext
InstrumentationSystem.instrument.extract(request.headers, into: &serviceContext, using: HTTPHeadersExtractor())

let operationName: String = {
guard let endpointPath = request.endpointPath else {
return "HTTP \(request.method.rawValue) route not found"
}
return endpointPath
}()

return request.withSpan(operationName, context: serviceContext, ofKind: .server) { request, span in
span.updateAttributes { attributes in
attributes["http.method"] = request.method.rawValue
attributes["http.target"] = request.uri.path
attributes["http.flavor"] = "\(request.version.major).\(request.version.minor)"
attributes["http.scheme"] = request.uri.scheme?.rawValue
attributes["http.user_agent"] = request.headers.first(name: "user-agent")
attributes["http.request_content_length"] = request.body.buffer?.readableBytes

attributes["net.host.name"] = request.application.server.configuration.address.host
attributes["net.host.port"] = request.application.server.configuration.address.port

if let remoteAddress = request.remoteAddress {
attributes["net.sock.peer.port"] = remoteAddress.port

switch remoteAddress.protocol {
case .inet:
attributes["net.sock.peer.addr"] = remoteAddress.ipAddress
case .inet6:
attributes["net.sock.family"] = "inet6"
attributes["net.sock.peer.addr"] = remoteAddress.ipAddress
case .unix:
attributes["net.sock.family"] = "unix"
attributes["net.sock.peer.addr"] = remoteAddress.pathname
default:
break
}
}
attributes = self.recordHeaders(request.headers, toSpanAttributes: attributes, withPrefix: "http.request.header.")
}

return next.respond(to: request)
.always { result in
switch result {
case .success(let response):
span.updateAttributes { attributes in
attributes = self.recordHeaders(response.headers, toSpanAttributes: attributes, withPrefix: "http.response.header.")

attributes["http.status_code"] = Int(response.status.code)
switch response.body {
case .byteBuffer(let buffer):
attributes["http.response_content_length"] = buffer.readableBytes
case .stream, .empty:
break
}
}
case .failure(let error):
if let httpError = error as? HBHTTPResponseError {
span.attributes["http.status_code"] = Int(httpError.status.code)

if 500..<600 ~= httpError.status.code {
span.setStatus(.init(code: .error))
}
}
}
}
}
}

func recordHeaders(_ headers: HTTPHeaders, toSpanAttributes attributes: SpanAttributes, withPrefix prefix: String) -> SpanAttributes {
var attributes = attributes
for header in self.headerNamesToRecord {
let values = headers[header.name]
guard !values.isEmpty else { continue }
let attribute = "\(prefix)\(header.attributeName)"

if values.count == 1 {
attributes[attribute] = values[0]
} else {
attributes[attribute] = values
}
}
return attributes
}
}

struct RecordingHeader: Hashable {
let name: String
let attributeName: String

init(name: String) {
self.name = name
self.attributeName = name.lowercased().replacingOccurrences(of: "-", with: "_")
}
}

private struct HTTPHeadersExtractor: Extractor {
func extract(key name: String, from headers: HTTPHeaders) -> String? {
headers.first(name: name)
}
}

extension Span {
/// Update Span attributes in a block instead of individually
///
/// Updating a span attribute will involve some type of thread synchronisation
/// primitive to avoid multiple threads updating the attributes at the same
/// time. If you update each attributes individually this could cause slowdown.
/// This function updates the attributes in one call to avoid hitting the
/// thread synchronisation code multiple times
///
/// - Parameter update: closure used to update span attributes
func updateAttributes(_ update: (inout SpanAttributes) -> Void) {
var attributes = self.attributes
update(&attributes)
self.attributes = attributes
}
}
157 changes: 157 additions & 0 deletions Sources/Hummingbird/Server/ServiceContext.swift
Original file line number Diff line number Diff line change
@@ -0,0 +1,157 @@
//===----------------------------------------------------------------------===//
//
// This source file is part of the Hummingbird server framework project
//
// Copyright (c) 2021-2023 the Hummingbird authors
// Licensed under Apache License v2.0
//
// See LICENSE.txt for license information
// See hummingbird/CONTRIBUTORS.txt for the list of Hummingbird authors
//
// SPDX-License-Identifier: Apache-2.0
//
//===----------------------------------------------------------------------===//

import Tracing

@available(macOS 10.15, iOS 13.0, tvOS 13.0, watchOS 6.0, *)
extension HBRequest {
/// ServiceContext attached to request. Used to propagate serviceContext to child functions
///
/// Attaching serviceContext to the request should be used when we aren't inside an async
/// function and serviceContext cannot be propagated via Task local variables. Otherwise
/// serviceContext should be propagated using Task local variables using `ServiceContext.$current.withValue(_)`
public var serviceContext: ServiceContext {
get { self.extensions.get(\.serviceContext) ?? ServiceContext.topLevel }
set { self.extensions.set(\.serviceContext, value: newValue) }
}

/// Execute the given operation with edited request that includes serviceContext.
///
/// Be sure to use the ``HBRequest`` passed to the closure as that includes the serviceContext.
/// This function should be used when we aren't inside an async function and serviceContext
/// cannot be propagated via Task local variables using `ServiceContext.$current.withValue(_)`
///
/// - Parameters:
/// - serviceContext: ServiceContext to attach to request
/// - operation: operation to run
/// - Returns: return value of operation
public func withServiceContext<Return>(_ context: ServiceContext, _ operation: (HBRequest) throws -> Return) rethrows -> Return {
var request = self
request.serviceContext = context
return try operation(request)
}

/// Execute the given operation within a newly created ``Span``
///
/// Calls operation with edited request that includes the serviceContext from span, and the span Be sure to use the
/// `HBRequest` passed to the closure as that includes the serviceContext
///
/// This function should be used when we aren't inside an async function and serviceContext cannot be propagated
/// via Task local variables. The equivalent async version of this is
/// `InstrumentationSystem.tracer.withSpan(_:ofKind:_)`
///
/// DO NOT `end()` the passed in span manually. It will be ended automatically when the `operation` returns.
///
/// - Parameters:
/// - operationName: The name of the operation being traced. This may be a handler function, database call, ...
/// - kind: The ``SpanKind`` of the ``Span`` to be created. Defaults to ``SpanKind/internal``.
/// - operation: operation to wrap in a span start/end and execute immediately
/// - Returns: the value returned by `operation`
/// - Throws: the error the `operation` has thrown (if any)
public func withSpan<Return>(
_ operationName: String,
ofKind kind: SpanKind = .internal,
_ operation: (HBRequest, Span) throws -> Return
) rethrows -> Return {
return try self.withSpan(operationName, context: self.serviceContext, ofKind: kind, operation)
}

/// Execute a specific task within a newly created ``Span``.
///
/// Calls operation with edited request that includes the serviceContext, and the span Be sure to use the
/// `HBRequest` passed to the closure as that includes the serviceContext
///
/// This function should be used when we aren't inside an async function and serviceContext cannot be propagated
/// via Task local variables. The equivalent async version of this is
/// `InstrumentationSystem.tracer.withSpan(_:serviceContext:ofKind:_)`
///
/// DO NOT `end()` the passed in span manually. It will be ended automatically when the `operation` returns.
///
/// - Parameters:
/// - operationName: The name of the operation being traced. This may be a handler function, database call, ...
/// - serviceContext: ServiceContext potentially containing trace identifiers of a parent ``Span``.
/// - kind: The ``SpanKind`` of the ``Span`` to be created. Defaults to ``SpanKind/internal``.
/// - operation: operation to wrap in a span start/end and execute immediately
/// - Returns: the value returned by `operation`
/// - Throws: the error the `operation` has thrown (if any)
public func withSpan<Return>(
_ operationName: String,
context: ServiceContext,
ofKind kind: SpanKind = .internal,
_ operation: (HBRequest, Span) throws -> Return
) rethrows -> Return {
let span = InstrumentationSystem.legacyTracer.startAnySpan(operationName, context: context, ofKind: kind)
defer { span.end() }
return try self.withServiceContext(span.context) { request in
do {
return try operation(request, span)
} catch {
span.recordError(error)
throw error
}
}
}

/// Execute the given operation within a newly created ``Span``
///
/// Calls operation with edited request that includes the serviceContext from span, and the span. Be sure to use the
/// `HBRequest` passed to the closure as that includes the serviceContext
///
/// DO NOT `end()` the passed in span manually. It will be ended automatically when the `operation` returns.
///
/// - Parameters:
/// - operationName: The name of the operation being traced. This may be a handler function, database call, ...
/// - kind: The ``SpanKind`` of the ``Span`` to be created. Defaults to ``SpanKind/internal``.
/// - operation: operation to wrap in a span start/end and execute immediately
/// - Returns: the value returned by `operation`
/// - Throws: the error the `operation` has thrown (if any)
public func withSpan<Return>(
_ operationName: String,
ofKind kind: SpanKind = .internal,
_ operation: (HBRequest, Span) -> EventLoopFuture<Return>
) -> EventLoopFuture<Return> {
return self.withSpan(operationName, context: self.serviceContext, ofKind: kind, operation)
}

/// Execute the given operation within a newly created ``Span``,
///
/// Calls operation with edited request that includes the serviceContext, and the span. Be sure to use the
/// `HBRequest` passed to the closure as that includes the serviceContext
///
/// DO NOT `end()` the passed in span manually. It will be ended automatically when the `operation` returns.
///
/// - Parameters:
/// - operationName: The name of the operation being traced. This may be a handler function, database call, ...
/// - kind: The ``SpanKind`` of the ``Span`` to be created. Defaults to ``SpanKind/internal``.
/// - operation: operation to wrap in a span start/end and execute immediately
/// - Returns: the value returned by `operation`
/// - Throws: the error the `operation` has thrown (if any)
public func withSpan<Return>(
_ operationName: String,
context: ServiceContext,
ofKind kind: SpanKind = .internal,
_ operation: (HBRequest, Span) -> EventLoopFuture<Return>
) -> EventLoopFuture<Return> {
let span = InstrumentationSystem.legacyTracer.startAnySpan(operationName, context: context, ofKind: kind)
return self.withServiceContext(span.context) { request in
return operation(request, span)
.flatMapErrorThrowing { error in
span.recordError(error)
throw error
}.always { _ in
span.end()
}
}
}
}
Loading

0 comments on commit 1179f5e

Please sign in to comment.