feat: SwiftUI View Rendering Instrumentation

Examples/SmokeTest/SmokeTest.xcodeproj/project.pbxproj

@@ -7,6 +7,7 @@
 	objects = {
 
 /* Begin PBXBuildFile section */
+		452B71DD2CE52C8600C27FB2 /* ViewInstrumentationView.swift in Sources */ = {isa = PBXBuildFile; fileRef = 452B71DC2CE52C8600C27FB2 /* ViewInstrumentationView.swift */; };
 		AF6DEFEA2C8D3CE000363027 /* SmokeTestApp.swift in Sources */ = {isa = PBXBuildFile; fileRef = AF6DEFE92C8D3CE000363027 /* SmokeTestApp.swift */; };
 		AF6DEFEC2C8D3CE000363027 /* ContentView.swift in Sources */ = {isa = PBXBuildFile; fileRef = AF6DEFEB2C8D3CE000363027 /* ContentView.swift */; };
 		AF6DEFEE2C8D3CE100363027 /* Assets.xcassets in Resources */ = {isa = PBXBuildFile; fileRef = AF6DEFED2C8D3CE100363027 /* Assets.xcassets */; };
@@ -37,6 +38,7 @@
 /* End PBXContainerItemProxy section */
 
 /* Begin PBXFileReference section */
+		452B71DC2CE52C8600C27FB2 /* ViewInstrumentationView.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = ViewInstrumentationView.swift; sourceTree = "<group>"; };
 		AF6DEFE62C8D3CE000363027 /* SmokeTest.app */ = {isa = PBXFileReference; explicitFileType = wrapper.application; includeInIndex = 0; path = SmokeTest.app; sourceTree = BUILT_PRODUCTS_DIR; };
 		AF6DEFE92C8D3CE000363027 /* SmokeTestApp.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = SmokeTestApp.swift; sourceTree = "<group>"; };
 		AF6DEFEB2C8D3CE000363027 /* ContentView.swift */ = {isa = PBXFileReference; lastKnownFileType = sourcecode.swift; path = ContentView.swift; sourceTree = "<group>"; };
@@ -103,6 +105,7 @@
 			children = (
 				AFA277C32CC71DF5007F8A46 /* NetworkView.swift */,
 				AFA0BA5B2C8E12E700F54611 /* MetricKitTestHelpers.swift */,
+				452B71DC2CE52C8600C27FB2 /* ViewInstrumentationView.swift */,
 				AF6DEFE92C8D3CE000363027 /* SmokeTestApp.swift */,
 				AF6DEFEB2C8D3CE000363027 /* ContentView.swift */,
 				AF6DEFED2C8D3CE100363027 /* Assets.xcassets */,
@@ -280,6 +283,7 @@
 				AFA277C42CC71DF7007F8A46 /* NetworkView.swift in Sources */,
 				AF6DEFEA2C8D3CE000363027 /* SmokeTestApp.swift in Sources */,
 				AFA0BA5C2C8E12E700F54611 /* MetricKitTestHelpers.swift in Sources */,
+				452B71DD2CE52C8600C27FB2 /* ViewInstrumentationView.swift in Sources */,
 			);
 			runOnlyForDeploymentPostprocessing = 0;
 		};

Examples/SmokeTest/SmokeTest/ContentView.swift

@@ -65,6 +65,10 @@ struct ContentView: View {
             NetworkView()
                 .padding()
                 .tabItem { Label("Network", systemImage: "network") }
+
+            ViewInstrumentationView()
+                .padding()
+                .tabItem { Label("View Instrumentation", systemImage: "ruler") }
         }
     }
 }

Examples/SmokeTest/SmokeTest/ViewInstrumentationView.swift

@@ -0,0 +1,110 @@
+import Foundation
+import OpenTelemetryApi
+import SwiftUI
+import UIKit
+
+@testable import Honeycomb
+
+private struct NestedExpensiveView: View {
+    let delay: Double
+
+    var body: some View {
+        HStack {
+            HoneycombInstrumentedView(name: "nested expensive text") {
+                Text(String(timeConsumingCalculation(delay)))
+            }
+        }
+    }
+}
+
+// lets us adjust the slider value without re-rendering
+// the main ExpensiveView
+// once the user stops editing the slider, we propagate it back
+// up to ExpensiveView and then that will re-render
+struct DelayedSlider: View {
+    @State private var sliderDelay = 2.0
+    @State private var isEditing = false
+    var delay: Binding<Double>
+
+    var body: some View {
+        Slider(
+            value: $sliderDelay,
+            in: 0...4,
+            step: 0.5
+        ) {
+            Text("Delay")
+        } minimumValueLabel: {
+            Text("0")
+        } maximumValueLabel: {
+            Text("4")
+        } onEditingChanged: { editing in
+            isEditing = editing
+            if !editing {
+                delay.wrappedValue = sliderDelay
+            }
+        }
+    }
+}
+
+private struct ExpensiveView: View {
+    @State private var delay = 2.0
+
+    var body: some View {
+        HoneycombInstrumentedView(name: "main view") {
+            VStack {
+                Spacer()
+
+                DelayedSlider(delay: $delay)
+
+                HoneycombInstrumentedView(name: "expensive text 1") {
+                    Text(timeConsumingCalculation(delay))
+                }
+
+                HoneycombInstrumentedView(name: "expensive text 2") {
+                    Text(timeConsumingCalculation(delay))
+                }
+
+                HoneycombInstrumentedView(name: "expensive text 3") {
+                    Text(timeConsumingCalculation(delay))
+                }
+
+                HoneycombInstrumentedView(name: "nested expensive view") {
+                    NestedExpensiveView(delay: delay)
+                }
+
+                HoneycombInstrumentedView(name: "expensive text 4") {
+                    Text(timeConsumingCalculation(delay))
+                }
+
+                Spacer()
+            }
+        }
+    }
+}
+
+struct ViewInstrumentationView: View {
+    @State private var isEnabled = false
+
+    var body: some View {
+        VStack {
+            Toggle(isOn: $isEnabled) { Text("enable slow render") }
+            Spacer()
+            if isEnabled {
+                ExpensiveView()
+            }
+        }
+        .onDisappear {
+            isEnabled = false
+        }
+    }
+}
+
+private func timeConsumingCalculation(_ delay: TimeInterval) -> String {
+    print("starting time consuming calculation")
+    Thread.sleep(forTimeInterval: delay)
+    return "slow text: \(round(delay * 100) / 100)"
+}
+
+#Preview {
+    ViewInstrumentationView()
+}

Examples/SmokeTest/SmokeTestUITests/SmokeTestUITests.swift

@@ -153,6 +153,20 @@ final class SmokeTestUITests: XCTestCase {
         app.buttons["Flush"].tap()
     }
 
+    func testRenderPerformace() throws {
+        let app = XCUIApplication()
+        app.launch()
+        app.buttons["View Instrumentation"].tap()
+        XCTAssert(app.staticTexts["enable slow render"].waitForExistence(timeout: uiUpdateTimeout))
+
+        app.setToggle("enable slow render", to: true)
+
+        // make sure the metrics get flushed
+        app.buttons["Core"].tap()
+        XCTAssert(app.buttons["Flush"].waitForExistence(timeout: uiUpdateTimeout))
+        app.buttons["Flush"].tap()
+    }
+
     func testLaunchPerformance() throws {
         if #available(macOS 10.15, iOS 13.0, tvOS 13.0, watchOS 7.0, *) {
             // This measures how long it takes to launch your application.

README.md

@@ -75,3 +75,32 @@ To manually send a span:
 
 The following auto-instrumentation libraries are automatically included:
 * [MetricKit](https://developer.apple.com/documentation/metrickit) data is automatically collected.
+
+## Manual Instrumentation
+### SwiftUI View Instrumentation
+
+Wrap your SwiftUI views with `HoneycombInstrumentedView(name: String)`, like so:
+
+```
+var body: some View {
+    HoneycombInstrumentedView(name: "main view") {
+        VStack {
+            // ...
+        }
+    }
+}
+```
+
+This will measure and emit instrumentation for your View's render times, ex:
+
+![view instrumentation trace](docs/img/view-instrumentation.png)
+
+Specifically, it will emit 2 kinds of span for each view that is wrapped:
+
+`View Render` spans encompass the entire rendering process, from initialization to appearing on screen. They include the following attributes:
+- `ViewName` (string): the name passed to `HoneycombInstrumentedView`
+- `RenderDuration` (double): amount of time to spent initializing the contents of `HoneycombInstrumentedView`
+- `TotalDuration` (double): amount of time from when `HoneycombInstrumentedView.body()` is called to when the contents appear on screen
+
+`View Body` spans encompass just the `body()` call of `HoneycombInstrumentedView, and include the following attributes:
+- `ViewName` (string): the name passed to `HoneycombInstrumentedView` 

Sources/Honeycomb/HoneycombInstrumentedView.swift

@@ -0,0 +1,67 @@
+import OpenTelemetryApi
+import SwiftUI
+
+private let honeycombInstrumentedViewName = "@honeycombio/instrumentation-view"
+
+struct HoneycombInstrumentedView<Content: View>: View {
+    private let span: Span
+    private let content: () -> Content
+    private let name: String
+    private let initTime: Date
+
+    init(name: String, @ViewBuilder _ content: @escaping () -> Content) {
+        self.initTime = Date()
+        self.name = name
+        self.content = content
+
+        self.span = getViewTracer().spanBuilder(spanName: "View Render")
+            .setStartTime(time: Date())
+            .setAttribute(key: "ViewName", value: name)
+            .startSpan()
+    }
+
+    var body: some View {
+        let start = Date()
+
+        // contents start init
+        let bodySpan = getViewTracer().spanBuilder(spanName: "View Body")
+            .setStartTime(time: Date())
+            .setAttribute(key: "ViewName", value: name)
+            .setParent(span)
+            .setActive(true)
+            .startSpan()
+
+        let c = content()
+        // contents end init
+
+        // we don't end `bodySpan` here so that it remains active in context
+        //   that way subsequent spans get nested in correctly
+        //   but we are going to want to track how long it took, so we need to store the endTime:
+        let endTime = Date()
+
+        span.setAttribute(
+            key: "RenderDuration",
+            value: endTime.timeIntervalSince(start)
+        )
+
+        return c.onAppear {
+            // contents end render
+            // we haven't ended `bodySpan` yet because we wanted it to remain active in context
+            //   now we need to end it, and we pass in the endTime from earlier, when the body actually
+            //   finished rendering. Otherwise this span would stretch out to cover the rendering time
+            //   of other views in the tree, and we wouldn't get an accurate duration.
+            bodySpan.end(time: endTime)
+
+            let appearTime = Date()
+            span.setAttribute(key: "TotalDuration", value: appearTime.timeIntervalSince(initTime))
+            span.end(time: appearTime)
+        }
+    }
+}
+
+func getViewTracer() -> Tracer {
+    return OpenTelemetry.instance.tracerProvider.get(
+        instrumentationName: honeycombInstrumentedViewName,
+        instrumentationVersion: honeycombLibraryVersion
+    )
+}

smoke-tests/smoke-e2e.bats

@@ -166,3 +166,19 @@ mk_diag_attr() {
   assert_equal "$result" '  30 "localhost"'
 }
 
+@test "Render Instrumentation attributes are correct" {
+  # we got the spans we expect
+  result=$(span_names_for "@honeycombio/instrumentation-view" | sort | uniq -c)
+  assert_equal "$result" '   7 "View Body"
+   7 "View Render"'
+
+  # the View Render spans are tracking the views we expect
+  total_duration=$(attribute_for_span_key "@honeycombio/instrumentation-view" "View Render" ViewName string | sort)
+  assert_equal "$total_duration" '"expensive text 1"
+"expensive text 2"
+"expensive text 3"
+"expensive text 4"
+"main view"
+"nested expensive text"
+"nested expensive view"'
+}

smoke-tests/test_helpers/utilities.bash

@@ -20,7 +20,7 @@ span_attributes_for() {
 #   $3 - attribute key
 #   $4 - attribute type
 attribute_for_span_key() {
-	attributes_from_span_named $1 $2 | \
+	attributes_from_span_named "$1" "$2" | \
 		jq "select (.key == \"$3\").value" | \
 		jq ".${4}Value"
 }