Merge pull request #323 from DataDog/ncreated/RUMM-776-add-custom-tim…

…ings-support-in-RUM

RUMM-776 Add custom timings API for RUM Views

Datadog/Example/Scenarios/RUM/ManualInstrumentation/SendRUMFixture1ViewController.swift

@@ -20,6 +20,10 @@ internal class SendRUMFixture1ViewController: UIViewController {
         super.viewDidAppear(animated)
 
         rumMonitor.startView(viewController: self)
+
+        DispatchQueue.main.asyncAfter(deadline: .now() + 0.05) {
+            rumMonitor.addTiming(name: "content-ready")
+        }
     }
 
     override func viewWillDisappear(_ animated: Bool) {
@@ -29,6 +33,8 @@ internal class SendRUMFixture1ViewController: UIViewController {
     }
 
     @IBAction func didTapDownloadResourceButton(_ sender: Any) {
+        rumMonitor.addTiming(name: "first-interaction")
+
         let simulatedResourceKey1 = "/resource/1"
         let simulatedResourceRequest1 = URLRequest(url: URL(string: "https://foo.com/resource/1")!)
         let simulatedResourceKey2 = "/resource/2"

Sources/Datadog/Core/Utils/JSONEncoder.swift

@@ -15,7 +15,25 @@ extension JSONEncoder {
             try container.encode(formatted)
         }
         if #available(iOS 13.0, OSX 10.15, *) {
-            encoder.outputFormatting = [.withoutEscapingSlashes]
+            // NOTE: The `.sortedKeys` option was added in RUMM-776 after discovering an issue
+            // with backend processing of the RUM View payloads. The custom timings encoding for
+            // RUM views requires following structure:
+            //
+            //  ```
+            //  {
+            //     view: { /* serialized, auto-generated RUM view event */ },
+            //     view.custom_timings.<custom-timing-1-name>: <custom-timing-value>,
+            //     view.custom_timings.<custom-timing-2-name>: <custom-timing-value>
+            //     ...
+            //  }
+            //  ```
+            //
+            // To guarantee proper backend-side processing, the `view.custom_timings` keys must be
+            // encoded after the `view` object. Using `.sortedKeys` enforces this order.
+            //
+            encoder.outputFormatting = [.withoutEscapingSlashes, .sortedKeys]
+        } else {
+            encoder.outputFormatting = [.sortedKeys]
         }
         return encoder
     }

Sources/Datadog/DDRUMMonitor.swift

@@ -33,6 +33,14 @@ public class DDRUMMonitor {
         attributes: [AttributeKey: AttributeValue] = [:]
     ) {}
 
+    /// Adds a specific timing in the currently presented View. The timing duration will be computed as the
+    /// number of nanoseconds between the time the View was started and the time the timing was added.
+    /// - Parameters:
+    ///   - name: the name of the custom timing attribute. It must be unique for each timing.
+    public func addTiming(
+        name: String
+    ) {}
+
     /// Notifies that an Error occurred in currently presented View.
     /// - Parameters:
     ///   - message: a message explaining the Error.

Sources/Datadog/RUM/RUMEvent/RUMEventBuilder.swift

@@ -13,11 +13,16 @@ internal class RUMEventBuilder {
         self.userInfoProvider = userInfoProvider
     }
 
-    func createRUMEvent<DM: RUMDataModel>(with model: DM, attributes: [String: Encodable]) -> RUMEvent<DM> {
+    func createRUMEvent<DM: RUMDataModel>(
+        with model: DM,
+        attributes: [String: Encodable],
+        customTimings: [String: Int64]? = nil
+    ) -> RUMEvent<DM> {
         return RUMEvent(
             model: model,
             attributes: attributes,
-            userInfoAttributes: userInfoProvider.value.extraInfo
+            userInfoAttributes: userInfoProvider.value.extraInfo,
+            customViewTimings: customTimings
         )
     }
 }

Sources/Datadog/RUM/RUMEvent/RUMEventEncoder.swift

@@ -15,6 +15,9 @@ internal struct RUMEvent<DM: RUMDataModel>: Encodable {
     let attributes: [String: Encodable]
     let userInfoAttributes: [String: Encodable]
 
+    /// Custom View timings (only available if `DM` is a RUM View model)
+    let customViewTimings: [String: Int64]?
+
     func encode(to encoder: Encoder) throws {
         try RUMEventEncoder().encode(self, to: encoder)
     }
@@ -40,6 +43,9 @@ internal struct RUMEventEncoder {
         try event.userInfoAttributes.forEach { attributeName, attributeValue in
             try attributesContainer.encode(EncodableValue(attributeValue), forKey: DynamicCodingKey("context.usr.\(attributeName)"))
         }
+        try event.customViewTimings?.forEach { timingName, timingDuration in
+            try attributesContainer.encode(timingDuration, forKey: DynamicCodingKey("view.custom_timings.\(timingName)"))
+        }
 
         // Encode `RUMDataModel`
         try event.model.encode(to: encoder)

Sources/Datadog/RUM/RUMMonitor/RUMCommand.swift

@@ -92,6 +92,15 @@ internal struct RUMAddCurrentViewErrorCommand: RUMCommand {
     }
 }
 
+internal struct RUMAddViewTimingCommand: RUMCommand {
+    let time: Date
+    var attributes: [AttributeKey: AttributeValue]
+
+    /// The name of the timing. It will be used as a JSON key, whereas the value will be the timing duration,
+    /// measured since the start of the View.
+    let timingName: String
+}
+
 // MARK: - RUM Resource related commands
 
 internal protocol RUMResourceCommand: RUMCommand {

Sources/Datadog/RUM/RUMMonitor/Scopes/RUMSessionScope.swift

@@ -74,6 +74,7 @@ internal class RUMSessionScope: RUMScope, RUMContextProvider {
                 identity: expiredViewIdentity,
                 uri: expiredView.viewURI,
                 attributes: expiredView.attributes,
+                customTimings: expiredView.customTimings,
                 startTime: startTime
             )
         }
@@ -123,6 +124,7 @@ internal class RUMSessionScope: RUMScope, RUMContextProvider {
                 identity: command.identity,
                 uri: command.path,
                 attributes: command.attributes,
+                customTimings: [:],
                 startTime: command.time
             )
         )

Sources/Datadog/RUM/RUMMonitor/Scopes/RUMViewScope.swift

@@ -23,6 +23,8 @@ internal class RUMViewScope: RUMScope, RUMContextProvider {
     private(set) weak var identity: AnyObject?
     /// View attributes.
     private(set) var attributes: [AttributeKey: AttributeValue]
+    /// View custom timings, keyed by name. The value of timing is given in nanoseconds.
+    private(set) var customTimings: [String: Int64] = [:]
 
     /// This View's UUID.
     let viewUUID: RUMUUID
@@ -54,12 +56,14 @@ internal class RUMViewScope: RUMScope, RUMContextProvider {
         identity: AnyObject,
         uri: String,
         attributes: [AttributeKey: AttributeValue],
+        customTimings: [String: Int64],
         startTime: Date
     ) {
         self.parent = parent
         self.dependencies = dependencies
         self.identity = identity
         self.attributes = attributes
+        self.customTimings = customTimings
         self.viewUUID = dependencies.rumUUIDGenerator.generateUnique()
         self.viewURI = uri
         self.viewStartTime = startTime
@@ -113,6 +117,10 @@ internal class RUMViewScope: RUMScope, RUMContextProvider {
             isActiveView = false
             needsViewUpdate = true
 
+        case let command as RUMAddViewTimingCommand where isActiveView:
+            customTimings[command.timingName] = command.time.timeIntervalSince(viewStartTime).toInt64Nanoseconds
+            needsViewUpdate = true
+
         // Resource commands
         case let command as RUMStartResourceCommand where isActiveView:
             startResource(on: command)
@@ -271,7 +279,7 @@ internal class RUMViewScope: RUMScope, RUMContextProvider {
             dd: .init(documentVersion: version.toInt64)
         )
 
-        let event = dependencies.eventBuilder.createRUMEvent(with: eventData, attributes: attributes)
+        let event = dependencies.eventBuilder.createRUMEvent(with: eventData, attributes: attributes, customTimings: customTimings)
         dependencies.eventOutput.write(rumEvent: event)
     }
 

Sources/Datadog/RUMMonitor.swift

@@ -239,6 +239,18 @@ public class RUMMonitor: DDRUMMonitor, RUMCommandSubscriber {
         )
     }
 
+    override public func addTiming(
+        name: String
+    ) {
+        process(
+            command: RUMAddViewTimingCommand(
+                time: dateProvider.currentDate(),
+                attributes: [:],
+                timingName: name
+            )
+        )
+    }
+
     override public func addError(
         message: String,
         source: RUMErrorSource,

Tests/DatadogBenchmarkTests/DataStorage/RUMStorageBenchmarkTests.swift

@@ -106,7 +106,8 @@ class RUMStorageBenchmarkTests: XCTestCase {
                 dd: .init(documentVersion: .mockAny())
             ),
             attributes: ["attribute": "value"],
-            userInfoAttributes: ["str": "value", "int": 11_235, "bool": true]
+            userInfoAttributes: ["str": "value", "int": 11_235, "bool": true],
+            customViewTimings: nil
         )
     }
 }

Tests/DatadogIntegrationTests/Scenarios/RUM/RUMManualInstrumentationScenarioTests.swift

@@ -54,7 +54,7 @@ class RUMManualInstrumentationScenarioTests: IntegrationTests, RUMCommonAsserts
 
         let view1 = session.viewVisits[0]
         XCTAssertEqual(view1.path, "SendRUMFixture1ViewController")
-        XCTAssertEqual(view1.viewEvents.count, 4, "First view should receive 4 updates")
+        XCTAssertEqual(view1.viewEvents.count, 6, "First view should receive 6 updates")
         XCTAssertEqual(view1.viewEvents.last?.view.action.count, 2)
         XCTAssertEqual(view1.viewEvents.last?.view.resource.count, 1)
         XCTAssertEqual(view1.viewEvents.last?.view.error.count, 1)
@@ -77,6 +77,13 @@ class RUMManualInstrumentationScenarioTests: IntegrationTests, RUMCommonAsserts
         XCTAssertEqual(view1.errorEvents[0].error.resource?.method, .methodGET)
         XCTAssertEqual(view1.errorEvents[0].error.resource?.statusCode, 400)
 
+        let contentReadyTiming = try XCTUnwrap(view1.viewEventMatchers.last?.timing(named: "content-ready"))
+        let firstInteractionTiming = try XCTUnwrap(view1.viewEventMatchers.last?.timing(named: "first-interaction"))
+        XCTAssertGreaterThanOrEqual(contentReadyTiming, 50_000)
+        XCTAssertLessThan(contentReadyTiming, 1_000_000_000)
+        XCTAssertGreaterThan(firstInteractionTiming, 0)
+        XCTAssertLessThan(firstInteractionTiming, 5_000_000_000)
+
         let view2 = session.viewVisits[1]
         XCTAssertEqual(view2.path, "SendRUMFixture2ViewController")
         XCTAssertEqual(view2.viewEvents.last?.view.action.count, 0)

Tests/DatadogTests/Datadog/Core/Utils/JSONEncoderTests.swift

@@ -29,4 +29,31 @@ class JSONEncoderTests: XCTestCase {
             XCTAssertEqual(encodedURL.utf8String, #"{"value":"https:\/\/example.com\/foo"}"#)
         }
     }
+
+    func testWhenEncoding_thenKeysFollowLexicographicOrder() throws {
+        struct Foo: Codable {
+            var one = 1
+            var two = 1
+            var three = 1
+            var four = 1
+            var five = 1
+
+            enum CodingKeys: String, CodingKey {
+                case one = "aaaaaa"
+                case two = "bb"
+                case three = "aaa"
+                case four = "bbb"
+                case five = "aaa.aaa"
+            }
+        }
+
+        // When
+        let encodedFoo = try jsonEncoder.encode(Foo())
+
+        // Then
+        XCTAssertEqual(
+            encodedFoo.utf8String,
+            #"{"aaa":1,"aaa.aaa":1,"aaaaaa":1,"bb":1,"bbb":1}"#
+        )
+    }
 }

Tests/DatadogTests/Datadog/Mocks/CoreMocks.swift

@@ -334,6 +334,29 @@ extension FeaturesCommonDependencies {
             launchTimeProvider: launchTimeProvider
         )
     }
+
+    /// Creates new instance of `FeaturesCommonDependencies` by replacing individual dependencies.
+    func replacing(
+        performance: PerformancePreset? = nil,
+        httpClient: HTTPClient? = nil,
+        mobileDevice: MobileDevice? = nil,
+        dateProvider: DateProvider? = nil,
+        userInfoProvider: UserInfoProvider? = nil,
+        networkConnectionInfoProvider: NetworkConnectionInfoProviderType? = nil,
+        carrierInfoProvider: CarrierInfoProviderType? = nil,
+        launchTimeProvider: LaunchTimeProviderType? = nil
+    ) -> FeaturesCommonDependencies {
+        return FeaturesCommonDependencies(
+            performance: performance ?? self.performance,
+            httpClient: httpClient ?? self.httpClient,
+            mobileDevice: mobileDevice ?? self.mobileDevice,
+            dateProvider: dateProvider ?? self.dateProvider,
+            userInfoProvider: userInfoProvider ?? self.userInfoProvider,
+            networkConnectionInfoProvider: networkConnectionInfoProvider ?? self.networkConnectionInfoProvider,
+            carrierInfoProvider: carrierInfoProvider ?? self.carrierInfoProvider,
+            launchTimeProvider: launchTimeProvider ?? self.launchTimeProvider
+        )
+    }
 }
 
 class NoOpFileWriter: FileWriterType {

Tests/DatadogTests/Datadog/Mocks/LoggingFeatureMocks.swift

@@ -35,7 +35,12 @@ extension LoggingFeature {
         dependencies: FeaturesCommonDependencies = .mockAny()
     ) -> LoggingFeature {
         // Get the full feature mock:
-        let fullFeature: LoggingFeature = .mockWith(directory: directory, dependencies: dependencies)
+        let fullFeature: LoggingFeature = .mockWith(
+            directory: directory,
+            dependencies: dependencies.replacing(
+                dateProvider: SystemDateProvider() // replace date provider in mocked `Feature.Storage`
+            )
+        )
         let uploadWorker = DataUploadWorkerMock()
         let observedStorage = uploadWorker.observe(featureStorage: fullFeature.storage)
         // Replace by mocking the `FeatureUpload` and observing the `FatureStorage`:

Tests/DatadogTests/Datadog/Mocks/RUMFeatureMocks.swift

@@ -36,7 +36,12 @@ extension RUMFeature {
         dependencies: FeaturesCommonDependencies = .mockAny()
     ) -> RUMFeature {
         // Get the full feature mock:
-        let fullFeature: RUMFeature = .mockWith(directory: directory, dependencies: dependencies)
+        let fullFeature: RUMFeature = .mockWith(
+            directory: directory,
+            dependencies: dependencies.replacing(
+                dateProvider: SystemDateProvider() // replace date provider in mocked `Feature.Storage`
+            )
+        )
         let uploadWorker = DataUploadWorkerMock()
         let observedStorage = uploadWorker.observe(featureStorage: fullFeature.storage)
         // Replace by mocking the `FeatureUpload` and observing the `FatureStorage`:
@@ -165,6 +170,18 @@ extension RUMAddCurrentViewErrorCommand {
     }
 }
 
+extension RUMAddViewTimingCommand {
+    static func mockWith(
+        time: Date = Date(),
+        attributes: [AttributeKey: AttributeValue] = [:],
+        timingName: String = .mockAny()
+    ) -> RUMAddViewTimingCommand {
+        return RUMAddViewTimingCommand(
+            time: time, attributes: attributes, timingName: timingName
+        )
+    }
+}
+
 extension RUMStartResourceCommand {
     static func mockAny() -> RUMStartResourceCommand { mockWith() }
 
@@ -417,6 +434,7 @@ extension RUMViewScope {
         identity: AnyObject = mockView,
         uri: String = .mockAny(),
         attributes: [AttributeKey: AttributeValue] = [:],
+        customTimings: [String: Int64] = [:],
         startTime: Date = .mockAny()
     ) -> RUMViewScope {
         return RUMViewScope(
@@ -425,6 +443,7 @@ extension RUMViewScope {
             identity: identity,
             uri: uri,
             attributes: attributes,
+            customTimings: customTimings,
             startTime: startTime
         )
     }

Tests/DatadogTests/Datadog/Mocks/TracingFeatureMocks.swift

@@ -48,7 +48,11 @@ extension TracingFeature {
     ) -> TracingFeature {
         // Get the full feature mock:
         let fullFeature: TracingFeature = .mockWith(
-            directory: directory, dependencies: dependencies, loggingFeature: loggingFeature, tracingUUIDGenerator: tracingUUIDGenerator
+            directory: directory,
+            dependencies: dependencies.replacing(
+                dateProvider: SystemDateProvider() // replace date provider in mocked `Feature.Storage`
+            ),
+            loggingFeature: loggingFeature, tracingUUIDGenerator: tracingUUIDGenerator
         )
         let uploadWorker = DataUploadWorkerMock()
         let observedStorage = uploadWorker.observe(featureStorage: fullFeature.storage)