From 98a8c16494c5fb68f2218a5635a2443961ce7749 Mon Sep 17 00:00:00 2001 From: Dhiogo Brustolin Date: Fri, 31 Mar 2023 10:52:16 +0200 Subject: [PATCH] feat: Add time-to-initial-display and time-to-full-display measurements to ViewController transactions (#2843) Added time-to-initial-display and time-to-full-display measurements to ViewController transactions Co-authored-by: Philipp Hofmann Co-authored-by: Andrew McKnight --- CHANGELOG.md | 1 + Sources/Sentry/SentryMeasurementValue.m | 1 - Sources/Sentry/SentryTimeToDisplayTracker.m | 28 +++++++++-- .../SentryTimeToDisplayTrackerTest.swift | 46 ++++++++++++++++++- .../SentryTests/SentryTests-Bridging-Header.h | 1 + Tests/SentryTests/State/TestHub.swift | 6 +++ 6 files changed, 78 insertions(+), 5 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 187552b3c70..906dbb00646 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,7 @@ ### Features - Time to initial and full display (#2724) +- Add time-to-initial-display and time-to-full-display measurements to ViewController transactions (#2843) - Add `name` and `geo` to User (#2710) ### Fixes diff --git a/Sources/Sentry/SentryMeasurementValue.m b/Sources/Sentry/SentryMeasurementValue.m index 6099ede4ac5..e91b38224e5 100644 --- a/Sources/Sentry/SentryMeasurementValue.m +++ b/Sources/Sentry/SentryMeasurementValue.m @@ -23,7 +23,6 @@ - (instancetype)initWithValue:(NSNumber *)value unit:(SentryMeasurementUnit *)un - (NSDictionary *)serialize { - if (self.unit != nil) { return @{ @"value" : _value, @"unit" : _unit.unit }; } else { diff --git a/Sources/Sentry/SentryTimeToDisplayTracker.m b/Sources/Sentry/SentryTimeToDisplayTracker.m index d0ed138d51d..295f86fe9a3 100644 --- a/Sources/Sentry/SentryTimeToDisplayTracker.m +++ b/Sources/Sentry/SentryTimeToDisplayTracker.m @@ -1,6 +1,7 @@ #import "SentryTimeToDisplayTracker.h" #import "SentryCurrentDate.h" #import "SentryFramesTracker.h" +#import "SentryMeasurementValue.h" #import "SentrySpan.h" #import "SentrySpanContext.h" #import "SentrySpanId.h" @@ -74,22 +75,43 @@ - (void)reportFullyDisplayed { _fullyDisplayedReported = YES; if (self.waitForFullDisplay && _isReadyToDisplay) { + // We need the timestamp to be able to calculate the duration + // but we can't finish first and add measure later because + // finishing the span may trigger the tracer finishInternal. + self.fullDisplaySpan.timestamp = [SentryCurrentDate date]; + [self addTimeToDisplayMeasurement:self.fullDisplaySpan name:@"time_to_full_display"]; [self.fullDisplaySpan finish]; } } +- (void)addTimeToDisplayMeasurement:(SentrySpan *)span name:(NSString *)name +{ + NSTimeInterval duration = [span.timestamp timeIntervalSinceDate:span.startTimestamp] * 1000; + [span setMeasurement:name value:@(duration) unit:SentryMeasurementUnitDuration.millisecond]; +} + - (void)framesTrackerHasNewFrame { + NSDate *finishTime = [SentryCurrentDate date]; + // The purpose of TTID and TTFD is to measure how long // takes to the content of the screen to change. // Thats why we need to wait for the next frame to be drawn. - if (_waitForFullDisplay && _fullyDisplayedReported && self.fullDisplaySpan.isFinished == NO) { - [self.fullDisplaySpan finish]; - } if (_isReadyToDisplay && self.initialDisplaySpan.isFinished == NO) { + self.initialDisplaySpan.timestamp = finishTime; + + [self addTimeToDisplayMeasurement:self.initialDisplaySpan name:@"time_to_initial_display"]; + [self.initialDisplaySpan finish]; [_frameTracker removeListener:self]; } + if (_waitForFullDisplay && _fullyDisplayedReported && self.fullDisplaySpan.isFinished == NO) { + self.fullDisplaySpan.timestamp = finishTime; + + [self addTimeToDisplayMeasurement:self.initialDisplaySpan name:@"time_to_full_display"]; + + [self.fullDisplaySpan finish]; + } } - (void)trimTTFDIdNecessaryForTracer:(SentryTracer *)tracer diff --git a/Tests/SentryTests/Integrations/Performance/UIViewController/SentryTimeToDisplayTrackerTest.swift b/Tests/SentryTests/Integrations/Performance/UIViewController/SentryTimeToDisplayTrackerTest.swift index 6d9f15abc0b..4c1d3673975 100644 --- a/Tests/SentryTests/Integrations/Performance/UIViewController/SentryTimeToDisplayTrackerTest.swift +++ b/Tests/SentryTests/Integrations/Performance/UIViewController/SentryTimeToDisplayTrackerTest.swift @@ -58,6 +58,8 @@ class SentryTimeToDisplayTrackerTest: XCTestCase { XCTAssertEqual(ttidSpan.spanDescription, "UIViewController initial display") XCTAssertEqual(ttidSpan.operation, SentrySpanOperationUILoadInitialDisplay) + assertMeasurement(tracer: tracer, name: "time_to_initial_display", duration: 2_000) + XCTAssertEqual(Dynamic(fixture.framesTracker).listeners.count, 0) } @@ -110,6 +112,9 @@ class SentryTimeToDisplayTrackerTest: XCTestCase { fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 11)) sut.reportFullyDisplayed() + assertMeasurement(tracer: tracer, name: "time_to_initial_display", duration: 2_000) + assertMeasurement(tracer: tracer, name: "time_to_full_display", duration: 4_000) + XCTAssertEqual(ttidSpan?.timestamp, Date(timeIntervalSince1970: 9)) XCTAssertTrue(ttidSpan?.isFinished ?? false) XCTAssertEqual(tracer.children.count, 2) @@ -209,10 +214,11 @@ class SentryTimeToDisplayTrackerTest: XCTestCase { } func testFullDisplay_reportedBefore_initialDisplay() { + fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 7)) + let sut = fixture.getSut(for: UIViewController(), waitForFullDisplay: true) let tracer = fixture.tracer sut.start(for: tracer) - fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 7)) fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 9)) sut.reportFullyDisplayed() @@ -221,9 +227,47 @@ class SentryTimeToDisplayTrackerTest: XCTestCase { sut.reportReadyToDisplay() fixture.displayLinkWrapper.normalFrame() + assertMeasurement(tracer: tracer, name: "time_to_initial_display", duration: 4_000) + assertMeasurement(tracer: tracer, name: "time_to_full_display", duration: 4_000) + XCTAssertEqual(sut.initialDisplaySpan?.timestamp, fixture.dateProvider.date()) XCTAssertEqual(sut.fullDisplaySpan?.timestamp, sut.initialDisplaySpan?.timestamp) } + + func testReportFullyDisplayed_afterFinishingTracer_withWaitForChildren() { + fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 9)) + + let hub = TestHub(client: SentryClient(options: Options()), andScope: nil) + let tracer = SentryTracer(transactionContext: TransactionContext(operation: "Test Operation"), hub: hub, waitForChildren: true) + let sut = fixture.getSut(for: UIViewController(), waitForFullDisplay: true) + + sut.start(for: tracer) + + fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 10)) + sut.reportReadyToDisplay() + fixture.displayLinkWrapper.normalFrame() + + fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 11)) + + tracer.finish() + + fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 12)) + sut.reportFullyDisplayed() + + let transaction = hub.capturedTransactionsWithScope.first?.transaction + let measurements = transaction?["measurements"] as? [String: Any] + let ttid = measurements?["time_to_initial_display"] as? [String: Any] + let ttfd = measurements?["time_to_full_display"] as? [String: Any] + + XCTAssertEqual(ttid?["value"] as? Int, 1_000) + XCTAssertEqual(ttfd?["value"] as? Int, 3_000) + } + + func assertMeasurement(tracer: SentryTracer, name: String, duration: TimeInterval) { + XCTAssertEqual(tracer.measurements[name]?.value, NSNumber(value: duration)) + XCTAssertEqual(tracer.measurements[name]?.unit?.unit, "millisecond") + + } } #endif diff --git a/Tests/SentryTests/SentryTests-Bridging-Header.h b/Tests/SentryTests/SentryTests-Bridging-Header.h index f9377481e4e..9b42fc83605 100644 --- a/Tests/SentryTests/SentryTests-Bridging-Header.h +++ b/Tests/SentryTests/SentryTests-Bridging-Header.h @@ -185,6 +185,7 @@ #import "URLSessionTaskMock.h" @import SentryPrivate; #import "SentryEnvelopeAttachmentHeader.h" +#import "SentryMeasurementValue.h" #import "SentryNSProcessInfoWrapper.h" #import "SentryPerformanceTracker+Testing.h" #import "SentrySpanOperations.h" diff --git a/Tests/SentryTests/State/TestHub.swift b/Tests/SentryTests/State/TestHub.swift index 925518c4a04..a4bc4ea5695 100644 --- a/Tests/SentryTests/State/TestHub.swift +++ b/Tests/SentryTests/State/TestHub.swift @@ -43,4 +43,10 @@ class TestHub: SentryHub { return event.eventId } + + var capturedTransactionsWithScope: [(transaction: [String: Any], scope: Scope)] = [] + override func capture(_ transaction: Transaction, with scope: Scope) -> SentryId { + capturedTransactionsWithScope.append((transaction.serialize(), scope)) + return super.capture(transaction, with: scope) + } }