diff --git a/Package.swift b/Package.swift index e3ceb7c..2366ce3 100644 --- a/Package.swift +++ b/Package.swift @@ -8,7 +8,7 @@ let package = Package( .library(name: "Tracing", targets: ["Tracing"]), ], dependencies: [ - .package(url: "https://github.com/apple/swift-distributed-tracing-baggage.git", .upToNextMinor(from: "0.3.0")), + .package(url: "https://github.com/apple/swift-distributed-tracing-baggage.git", .upToNextMinor(from: "0.4.1")), .package(url: "https://github.com/apple/swift-docc-plugin", from: "1.0.0"), ], targets: [ diff --git a/Package@swift-5.2.swift b/Package@swift-5.2.swift index 954727a..111d4ff 100644 --- a/Package@swift-5.2.swift +++ b/Package@swift-5.2.swift @@ -8,7 +8,7 @@ let package = Package( .library(name: "Tracing", targets: ["Tracing"]), ], dependencies: [ - .package(url: "https://github.com/apple/swift-distributed-tracing-baggage.git", .upToNextMinor(from: "0.3.0")), + .package(url: "https://github.com/apple/swift-distributed-tracing-baggage.git", .upToNextMinor(from: "0.4.1")), ], targets: [ // ==== -------------------------------------------------------------------------------------------------------- diff --git a/Package@swift-5.3.swift b/Package@swift-5.3.swift index 954727a..111d4ff 100644 --- a/Package@swift-5.3.swift +++ b/Package@swift-5.3.swift @@ -8,7 +8,7 @@ let package = Package( .library(name: "Tracing", targets: ["Tracing"]), ], dependencies: [ - .package(url: "https://github.com/apple/swift-distributed-tracing-baggage.git", .upToNextMinor(from: "0.3.0")), + .package(url: "https://github.com/apple/swift-distributed-tracing-baggage.git", .upToNextMinor(from: "0.4.1")), ], targets: [ // ==== -------------------------------------------------------------------------------------------------------- diff --git a/Package@swift-5.4.swift b/Package@swift-5.4.swift index 954727a..111d4ff 100644 --- a/Package@swift-5.4.swift +++ b/Package@swift-5.4.swift @@ -8,7 +8,7 @@ let package = Package( .library(name: "Tracing", targets: ["Tracing"]), ], dependencies: [ - .package(url: "https://github.com/apple/swift-distributed-tracing-baggage.git", .upToNextMinor(from: "0.3.0")), + .package(url: "https://github.com/apple/swift-distributed-tracing-baggage.git", .upToNextMinor(from: "0.4.1")), ], targets: [ // ==== -------------------------------------------------------------------------------------------------------- diff --git a/Package@swift-5.5.swift b/Package@swift-5.5.swift index 954727a..111d4ff 100644 --- a/Package@swift-5.5.swift +++ b/Package@swift-5.5.swift @@ -8,7 +8,7 @@ let package = Package( .library(name: "Tracing", targets: ["Tracing"]), ], dependencies: [ - .package(url: "https://github.com/apple/swift-distributed-tracing-baggage.git", .upToNextMinor(from: "0.3.0")), + .package(url: "https://github.com/apple/swift-distributed-tracing-baggage.git", .upToNextMinor(from: "0.4.1")), ], targets: [ // ==== -------------------------------------------------------------------------------------------------------- diff --git a/Sources/Tracing/NoOpTracer.swift b/Sources/Tracing/NoOpTracer.swift index a851094..97bfc35 100644 --- a/Sources/Tracing/NoOpTracer.swift +++ b/Sources/Tracing/NoOpTracer.swift @@ -24,7 +24,10 @@ public struct NoOpTracer: Tracer { _ operationName: String, baggage: Baggage, ofKind kind: SpanKind, - at time: DispatchWallTime + at time: DispatchWallTime, + function: String, + file fileID: String, + line: UInt ) -> Span { NoOpSpan(baggage: baggage) } diff --git a/Sources/Tracing/Tracer.swift b/Sources/Tracing/Tracer.swift index 91857d7..f0b3cb4 100644 --- a/Sources/Tracing/Tracer.swift +++ b/Sources/Tracing/Tracer.swift @@ -30,11 +30,17 @@ public protocol Tracer: Instrument { /// - baggage: The `Baggage` providing information on where to start the new ``Span``. /// - kind: The ``SpanKind`` of the new ``Span``. /// - time: The `DispatchTime` at which to start the new ``Span``. + /// - function: The function name in which the span was started + /// - fileID: The `fileID` where the span was started. + /// - line: The file line where the span was started. func startSpan( _ operationName: String, baggage: Baggage, ofKind kind: SpanKind, - at time: DispatchWallTime + at time: DispatchWallTime, + function: String, + file fileID: String, + line: UInt ) -> Span /// Export all ended spans to the configured backend that have not yet been exported. @@ -47,25 +53,111 @@ public protocol Tracer: Instrument { } extension Tracer { - /// Start a new ``Span`` with the given `Baggage` starting at `DispatchWallTime.now()`. + #if swift(>=5.3.0) + /// Start a new ``Span`` with the given `Baggage` starting "now". /// /// - Parameters: /// - operationName: The name of the operation being traced. This may be a handler function, database call, ... /// - baggage: Baggage potentially containing trace identifiers of a parent ``Span``. /// - kind: The ``SpanKind`` of the ``Span`` to be created. Defaults to ``SpanKind/internal``. + /// - function: The function name in which the span was started. + /// - fileID: The `fileID` where the span was started. + /// - line: The file line where the span was started. public func startSpan( _ operationName: String, baggage: Baggage, - ofKind kind: SpanKind = .internal + ofKind kind: SpanKind = .internal, + function: String = #function, + file fileID: String = #fileID, + line: UInt = #line ) -> Span { - self.startSpan(operationName, baggage: baggage, ofKind: kind, at: .now()) + self.startSpan( + operationName, + baggage: baggage, + ofKind: kind, + at: .now(), + function: function, + file: fileID, + line: line + ) } + #else + /// Start a new ``Span`` with the given `Baggage` starting "now". + /// + /// - Parameters: + /// - operationName: The name of the operation being traced. This may be a handler function, database call, ... + /// - baggage: Baggage potentially containing trace identifiers of a parent ``Span``. + /// - kind: The ``SpanKind`` of the ``Span`` to be created. Defaults to ``SpanKind/internal``. + /// - function: The function name in which the span was started. + /// - file: The `file` where the span was started. + /// - line: The file line where the span was started. + public func startSpan( + _ operationName: String, + baggage: Baggage, + ofKind kind: SpanKind = .internal, + function: String = #function, + file: String = #file, + line: UInt = #line + ) -> Span { + self.startSpan( + operationName, + baggage: baggage, + ofKind: kind, + at: .now(), + function: function, + file: file, + line: line + ) + } + #endif } // ==== ---------------------------------------------------------------------------------------------------------------- // MARK: Starting spans: `withSpan` extension Tracer { + #if swift(>=5.3.0) + /// Execute a specific task within a newly created ``Span``. + /// + /// 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, ... + /// - baggage: Baggage 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 + /// - function: The function name in which the span was started. + /// - fileID: The `fileID` where the span was started. + /// - line: The file line where the span was started. + /// - Returns: the value returned by `operation` + /// - Throws: the error the `operation` has thrown (if any) + public func withSpan( + _ operationName: String, + baggage: Baggage, + ofKind kind: SpanKind = .internal, + function: String = #function, + file fileID: String = #fileID, + line: UInt = #line, + _ operation: (Span) throws -> T + ) rethrows -> T { + let span = self.startSpan( + operationName, + baggage: baggage, + ofKind: kind, + at: .now(), + function: function, + file: fileID, + line: line + ) + defer { span.end() } + do { + return try operation(span) + } catch { + span.recordError(error) + throw error // rethrow + } + } + #else /// Execute a specific task within a newly created ``Span``. /// /// DO NOT `end()` the passed in span manually. It will be ended automatically when the `operation` returns. @@ -75,15 +167,29 @@ extension Tracer { /// - baggage: Baggage 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 + /// - function: The function name in which the span was started. + /// - file: The `#file` where the span was started. + /// - line: The file line where the span was started. /// - Returns: the value returned by `operation` /// - Throws: the error the `operation` has thrown (if any) public func withSpan( _ operationName: String, baggage: Baggage, ofKind kind: SpanKind = .internal, + function: String = #function, + file: String = #file, + line: UInt = #line, _ operation: (Span) throws -> T ) rethrows -> T { - let span = self.startSpan(operationName, baggage: baggage, ofKind: kind) + let span = self.startSpan( + operationName, + baggage: baggage, + ofKind: kind, + at: .now(), + function: function, + file: file, + line: line + ) defer { span.end() } do { return try operation(span) @@ -92,6 +198,7 @@ extension Tracer { throw error // rethrow } } + #endif } // ==== ---------------------------------------------------------------------------------------------------------------- @@ -109,14 +216,27 @@ extension Tracer { /// - 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 + /// - function: The function name in which the span was started. + /// - fileID: The `fileID` where the span was started. + /// - line: The file line where the span was started. /// - Returns: the value returned by `operation` /// - Throws: the error the `operation` has thrown (if any) public func withSpan( _ operationName: String, ofKind kind: SpanKind = .internal, + function: String = #function, + file fileID: String = #fileID, + line: UInt = #line, _ operation: (Span) throws -> T ) rethrows -> T { - try self.withSpan(operationName, baggage: .current ?? .topLevel, ofKind: kind) { span in + try self.withSpan( + operationName, + baggage: .current ?? .topLevel, + ofKind: kind, + function: function, + file: fileID, + line: line + ) { span in try Baggage.$current.withValue(span.baggage) { try operation(span) } @@ -132,14 +252,27 @@ extension Tracer { /// - 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 + /// - function: The function name in which the span was started. + /// - fileID: The `fileID` where the span was started. + /// - line: The file line where the span was started. /// - Returns: the value returned by `operation` /// - Throws: the error the `operation` has thrown (if any) public func withSpan( _ operationName: String, ofKind kind: SpanKind = .internal, + function: String = #function, + file fileID: String = #fileID, + line: UInt = #line, _ operation: (Span) async throws -> T ) async rethrows -> T { - let span = self.startSpan(operationName, baggage: .current ?? .topLevel, ofKind: kind) + let span = self.startSpan( + operationName, + baggage: .current ?? .topLevel, + ofKind: kind, + function: function, + file: fileID, + line: line + ) defer { span.end() } do { return try await Baggage.$current.withValue(span.baggage) { @@ -162,15 +295,21 @@ extension Tracer { // task local and modified before passing into this function. The baggage will be made the current task-local baggage for the duration of the `operation`. /// - kind: The `SpanKind` of the `Span` to be created. Defaults to `.internal`. /// - operation: operation to wrap in a span start/end and execute immediately + /// - function: The function name in which the span was started. + /// - fileID: The `fileID` where the span was started. + /// - line: The file line where the span was started. /// - Returns: the value returned by `operation` /// - Throws: the error the `operation` has thrown (if any) public func withSpan( _ operationName: String, baggage: Baggage, ofKind kind: SpanKind = .internal, + function: String = #function, + file fileID: String = #fileID, + line: UInt = #line, _ operation: (Span) async throws -> T ) async rethrows -> T { - let span = self.startSpan(operationName, baggage: baggage, ofKind: kind) + let span = self.startSpan(operationName, baggage: baggage, ofKind: kind, function: function, file: fileID, line: line) defer { span.end() } do { return try await Baggage.$current.withValue(span.baggage) { diff --git a/Tests/LinuxMain.swift b/Tests/LinuxMain.swift index 88768ba..c8bf729 100644 --- a/Tests/LinuxMain.swift +++ b/Tests/LinuxMain.swift @@ -34,6 +34,7 @@ class LinuxMainRunnerImpl: LinuxMainRunner { @available(*, deprecated, message: "not actually deprecated. Just deprecated to allow deprecated tests (which test deprecated functionality) without warnings") func run() { XCTMain([ + testCase(DynamicTracepointTracerTests.allTests), testCase(InstrumentTests.allTests), testCase(InstrumentationSystemTests.allTests), testCase(SpanTests.allTests), diff --git a/Tests/TracingTests/DynamicTracepointTracerTests+XCTest.swift b/Tests/TracingTests/DynamicTracepointTracerTests+XCTest.swift new file mode 100644 index 0000000..8c3a061 --- /dev/null +++ b/Tests/TracingTests/DynamicTracepointTracerTests+XCTest.swift @@ -0,0 +1,34 @@ +//===----------------------------------------------------------------------===// +// +// This source file is part of the Swift Distributed Tracing open source project +// +// Copyright (c) 2020-2021 Apple Inc. and the Swift Distributed Tracing project +// authors +// Licensed under Apache License v2.0 +// +// See LICENSE.txt for license information +// +// SPDX-License-Identifier: Apache-2.0 +// +//===----------------------------------------------------------------------===// +// +// DynamicTracepointTracerTests+XCTest.swift +// +import XCTest +/// +/// NOTE: This file was generated by generate_linux_tests.rb +/// +/// Do NOT edit this file directly as it will be regenerated automatically when needed. +/// + +extension DynamicTracepointTracerTests { + + @available(*, deprecated, message: "not actually deprecated. Just deprecated to allow deprecated tests (which test deprecated functionality) without warnings") + static var allTests : [(String, (DynamicTracepointTracerTests) -> () throws -> Void)] { + return [ + ("test_adhoc_enableBySourceLoc", test_adhoc_enableBySourceLoc), + ("test_adhoc_enableByFunction", test_adhoc_enableByFunction), + ] + } +} + diff --git a/Tests/TracingTests/DynamicTracepointTracerTests.swift b/Tests/TracingTests/DynamicTracepointTracerTests.swift new file mode 100644 index 0000000..34b3b73 --- /dev/null +++ b/Tests/TracingTests/DynamicTracepointTracerTests.swift @@ -0,0 +1,290 @@ +//===----------------------------------------------------------------------===// +// +// This source file is part of the Swift Distributed Tracing open source project +// +// Copyright (c) 2020-2021 Apple Inc. and the Swift Distributed Tracing project +// authors +// Licensed under Apache License v2.0 +// +// See LICENSE.txt for license information +// +// SPDX-License-Identifier: Apache-2.0 +// +//===----------------------------------------------------------------------===// + +@testable import Instrumentation +import InstrumentationBaggage +import Tracing +import XCTest + +final class DynamicTracepointTracerTests: XCTestCase { + override class func tearDown() { + super.tearDown() + InstrumentationSystem.bootstrapInternal(nil) + } + + func test_adhoc_enableBySourceLoc() { + #if swift(>=5.5) + let tracer = DynamicTracepointTestTracer() + + InstrumentationSystem.bootstrapInternal(tracer) + defer { + InstrumentationSystem.bootstrapInternal(NoOpTracer()) + } + + let fileID = #fileID + let fakeLine: UInt = 77 // trick number, see withSpan below. + let fakeNextLine: UInt = fakeLine + 11 + tracer.enableTracepoint(fileID: fileID, line: fakeLine) + // Imagine this is set via some "ops command", e.g. ` trace enable Sample.swift:1234` + // Effectively enabling tracepoints is similar to tracer bullets, tho bullets are generally "one off", + // but here we could attach a trace-rate, so e.g.: control ` trace enable Sample:1234 .2` to set 20% sampling rate etc. + + tracer.withSpan("dont") { _ in + // don't capture this span... + } + tracer.withSpan("yes", line: fakeLine) { _ in + // do capture this span, and all child spans of it! + tracer.withSpan("yes-inner", line: fakeNextLine) { _ in + // since the parent of this span was captured, this shall be captured as well + } + } + + XCTAssertEqual(tracer.spans.count, 2) + for span in tracer.spans { + XCTAssertEqual(span.baggage.traceID, "trace-id-fake-\(fileID)-\(fakeLine)") + } + XCTAssertEqual(tracer.spans[0].baggage.spanID, "span-id-fake-\(fileID)-\(fakeLine)") + XCTAssertEqual(tracer.spans[1].baggage.spanID, "span-id-fake-\(fileID)-\(fakeNextLine)") + #endif + } + + func test_adhoc_enableByFunction() { + #if swift(>=5.5) + let tracer = DynamicTracepointTestTracer() + + InstrumentationSystem.bootstrapInternal(tracer) + defer { + InstrumentationSystem.bootstrapInternal(NoOpTracer()) + } + + let fileID = #fileID + tracer.enableTracepoint(function: "traceMeLogic(fakeLine:)") + + let fakeLine: UInt = 66 + let fakeNextLine: UInt = fakeLine + 11 + + self.logic(fakeLine: 55) + self.traceMeLogic(fakeLine: fakeLine) + + XCTAssertEqual(tracer.spans.count, 2) + for span in tracer.spans { + XCTAssertEqual(span.baggage.traceID, "trace-id-fake-\(fileID)-\(fakeLine)") + } + XCTAssertEqual(tracer.spans[0].baggage.spanID, "span-id-fake-\(fileID)-\(fakeLine)") + XCTAssertEqual(tracer.spans[1].baggage.spanID, "span-id-fake-\(fileID)-\(fakeNextLine)") + #endif + } + + func logic(fakeLine: UInt) { + #if swift(>=5.5) + InstrumentationSystem.tracer.withSpan("\(#function)-dont", line: fakeLine) { _ in + } + #endif + } + + func traceMeLogic(fakeLine: UInt) { + #if swift(>=5.5) + InstrumentationSystem.tracer.withSpan("\(#function)-yes", line: fakeLine) { _ in + InstrumentationSystem.tracer.withSpan("\(#function)-yes-inside", line: fakeLine + 11) { _ in + // inside + } + } + #endif + } +} + +final class DynamicTracepointTestTracer: Tracer { + private(set) var activeTracepoints: Set = [] + + struct TracepointID: Hashable { + let function: String? + let fileID: String? + let line: UInt? + + func matches(tracepoint: TracepointID) -> Bool { + var match = true + if let fun = self.function { + match = match && fun == tracepoint.function + if !match { // short-circuit further checks + return false + } + } + if let fid = self.fileID { + match = match && fid == tracepoint.fileID + if !match { // short-circuit further checks + return false + } + } + if let l = self.line { + match = match && l == tracepoint.line + if !match { // short-circuit further checks + return false + } + } + + return match + } + } + + private(set) var spans: [TracepointSpan] = [] + var onEndSpan: (Span) -> Void = { _ in + } + + func startSpan(_ operationName: String, + baggage: InstrumentationBaggage.Baggage, + ofKind kind: Tracing.SpanKind, + at time: DispatchWallTime, + function: String, + file fileID: String, + line: UInt) -> Tracing.Span + { + let tracepoint = TracepointID(function: function, fileID: fileID, line: line) + guard self.shouldRecord(tracepoint: tracepoint) else { + return NoOpTracer.NoOpSpan(baggage: baggage) + } + + let span = TracepointSpan( + operationName: operationName, + startTime: time, + baggage: baggage, + kind: kind, + file: fileID, + line: line, + onEnd: onEndSpan + ) + self.spans.append(span) + return span + } + + private func shouldRecord(tracepoint: TracepointID) -> Bool { + #if swift(>=5.5) && canImport(_Concurrency) + if self.isActive(tracepoint: tracepoint) { + // this tracepoint was specifically activated! + return true + } + + // else, perhaps there is already an active span, if so, attach to it + guard let baggage = Baggage.current else { // TODO: we could make this such that we only ever once pick-up 🧳 + return false + } + + guard baggage.traceID != nil else { + // no span is active, return the baggage though + return false + } + + // there is some active trace already, so we should record as well + // TODO: this logic may need to become smarter + return true + #else + return false + #endif + } + + func isActive(tracepoint: TracepointID) -> Bool { + for activeTracepoint in self.activeTracepoints { + if activeTracepoint.matches(tracepoint: tracepoint) { + return true + } + } + return false + } + + @discardableResult + func enableTracepoint(fileID: String, line: UInt? = nil) -> Bool { + self.activeTracepoints.insert(TracepointID(function: nil, fileID: fileID, line: line)).inserted + } + + @discardableResult + func enableTracepoint(function: String, fileID: String? = nil, line: UInt? = nil) -> Bool { + self.activeTracepoints.insert(TracepointID(function: function, fileID: fileID, line: line)).inserted + } + + func forceFlush() {} + + func extract(_ carrier: Carrier, into baggage: inout Baggage, using extractor: Extract) where Extract: Extractor, Extract.Carrier == Carrier { + let traceID = extractor.extract(key: "trace-id", from: carrier) ?? UUID().uuidString + baggage.traceID = traceID + } + + func inject(_ baggage: Baggage, into carrier: inout Carrier, using injector: Inject) where Inject: Injector, Inject.Carrier == Carrier { + guard let traceID = baggage.traceID else { + return + } + injector.inject(traceID, forKey: "trace-id", into: &carrier) + } +} + +extension DynamicTracepointTestTracer { + final class TracepointSpan: Tracing.Span { + private let operationName: String + private let kind: SpanKind + + private var status: SpanStatus? + + private let startTime: DispatchWallTime + private(set) var endTime: DispatchWallTime? + + private(set) var baggage: Baggage + private(set) var isRecording: Bool = false + + let onEnd: (Span) -> Void + + init(operationName: String, + startTime: DispatchWallTime, + baggage: Baggage, + kind: SpanKind, + file fileID: String, + line: UInt, + onEnd: @escaping (Span) -> Void) + { + self.operationName = operationName + self.startTime = startTime + self.baggage = baggage + self.onEnd = onEnd + self.kind = kind + + // inherit or make a new traceID: + if baggage.traceID == nil { + self.baggage.traceID = "trace-id-fake-\(fileID)-\(line)" + } + + // always make up a new spanID: + self.baggage.spanID = "span-id-fake-\(fileID)-\(line)" + } + + var attributes: Tracing.SpanAttributes = [:] + + func setStatus(_ status: Tracing.SpanStatus) { + // nothing + } + + func addEvent(_ event: Tracing.SpanEvent) { + // nothing + } + + func recordError(_ error: Error) { + print("") + } + + func addLink(_ link: SpanLink) { + // nothing + } + + func end(at time: DispatchWallTime) { + self.endTime = time + self.onEnd(self) + } + } +} diff --git a/Tests/TracingTests/TestTracer.swift b/Tests/TracingTests/TestTracer.swift index ba7a8bb..e9ec3a3 100644 --- a/Tests/TracingTests/TestTracer.swift +++ b/Tests/TracingTests/TestTracer.swift @@ -26,7 +26,10 @@ final class TestTracer: Tracer { _ operationName: String, baggage: Baggage, ofKind kind: SpanKind, - at time: DispatchWallTime + at time: DispatchWallTime, + function: String, + file fileID: String, + line: UInt ) -> Span { let span = TestSpan( operationName: operationName, @@ -64,6 +67,10 @@ extension TestTracer { enum TraceIDKey: BaggageKey { typealias Value = String } + + enum SpanIDKey: BaggageKey { + typealias Value = String + } } extension Baggage { @@ -75,6 +82,15 @@ extension Baggage { self[TestTracer.TraceIDKey.self] = newValue } } + + var spanID: String? { + get { + self[TestTracer.SpanIDKey.self] + } + set { + self[TestTracer.SpanIDKey.self] = newValue + } + } } final class TestSpan: Span { diff --git a/Tests/TracingTests/TracedLockTests.swift b/Tests/TracingTests/TracedLockTests.swift index 07e1f07..81ad3d9 100644 --- a/Tests/TracingTests/TracedLockTests.swift +++ b/Tests/TracingTests/TracedLockTests.swift @@ -63,7 +63,10 @@ private final class TracedLockPrintlnTracer: Tracer { _ operationName: String, baggage: Baggage, ofKind kind: SpanKind, - at time: DispatchWallTime + at time: DispatchWallTime, + function: String, + file fileID: String, + line: UInt ) -> Span { TracedLockPrintlnSpan( operationName: operationName,