Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

fix: TTID/TTFD for app start transactions #3512

Merged
merged 5 commits into from
Dec 20, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@
### Fixes

- TTFD waits for next drawn frame (#3505)
- Fix TTID/TTFD for app start transactions (#3512): TTID/TTFD spans and measurements for app start transaction now include the app start duration.

## 8.17.2

Expand Down
16 changes: 12 additions & 4 deletions Sources/Sentry/SentryTimeToDisplayTracker.m
Original file line number Diff line number Diff line change
Expand Up @@ -66,6 +66,18 @@ - (void)startForTracer:(SentryTracer *)tracer

[SentryDependencyContainer.sharedInstance.framesTracker addListener:self];
[tracer setFinishCallback:^(SentryTracer *_tracer) {
// If the start time of the tracer changes, which is the case for app start transactions, we
// also need to adapt the start time of our spans.
self.initialDisplaySpan.startTimestamp = _tracer.startTimestamp;
[self addTimeToDisplayMeasurement:self.initialDisplaySpan name:@"time_to_initial_display"];

if (self.fullDisplaySpan == nil) {
return;
}

self.fullDisplaySpan.startTimestamp = _tracer.startTimestamp;
[self addTimeToDisplayMeasurement:self.fullDisplaySpan name:@"time_to_full_display"];

if (self.fullDisplaySpan.status != kSentrySpanStatusDeadlineExceeded) {
return;
}
Expand Down Expand Up @@ -97,8 +109,6 @@ - (void)framesTrackerHasNewFrame
if (_initialDisplayReported && self.initialDisplaySpan.isFinished == NO) {
self.initialDisplaySpan.timestamp = finishTime;

[self addTimeToDisplayMeasurement:self.initialDisplaySpan name:@"time_to_initial_display"];

[self.initialDisplaySpan finish];

if (!_waitForFullDisplay) {
Expand All @@ -109,8 +119,6 @@ - (void)framesTrackerHasNewFrame
&& self.initialDisplaySpan.isFinished == YES) {
self.fullDisplaySpan.timestamp = finishTime;

[self addTimeToDisplayMeasurement:self.fullDisplaySpan name:@"time_to_full_display"];

[self.fullDisplaySpan finish];
}

Expand Down
12 changes: 6 additions & 6 deletions Sources/Sentry/SentryTracer.m
Original file line number Diff line number Diff line change
Expand Up @@ -491,6 +491,12 @@ - (void)finishInternal
}
[super finishWithStatus:_finishStatus];
}
#if SENTRY_HAS_UIKIT
if (appStartMeasurement != nil) {
[self updateStartTime:appStartMeasurement.appStartTimestamp];
}
#endif // SENTRY_HAS_UIKIT

[self.delegate tracerDidFinish:self];

if (self.finishCallback) {
Expand All @@ -501,12 +507,6 @@ - (void)finishInternal
self.finishCallback = nil;
}

#if SENTRY_HAS_UIKIT
if (appStartMeasurement != nil) {
[self updateStartTime:appStartMeasurement.appStartTimestamp];
}
#endif // SENTRY_HAS_UIKIT

// Prewarming can execute code up to viewDidLoad of a UIViewController, and keep the app in the
// background. This can lead to auto-generated transactions lasting for minutes or even hours.
// Therefore, we drop transactions lasting longer than SENTRY_AUTO_TRANSACTION_MAX_DURATION.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -28,7 +28,7 @@ class SentryTimeToDisplayTrackerTest: XCTestCase {
func getTracer() throws -> SentryTracer {
let options = Options()
let hub = TestHub(client: SentryClient(options: options, fileManager: try TestFileManager(options: options), deleteOldEnvelopeItems: false), andScope: nil)
return SentryTracer(transactionContext: TransactionContext(operation: "Test Operation"), hub: hub, configuration: SentryTracerConfiguration(block: {
return SentryTracer(transactionContext: TransactionContext(operation: "ui.load"), hub: hub, configuration: SentryTracerConfiguration(block: {
$0.waitForChildren = true
$0.timerFactory = self.timerFactory
$0.dispatchQueueWrapper = TestSentryDispatchQueueWrapper()
Expand Down Expand Up @@ -67,6 +67,7 @@ class SentryTimeToDisplayTrackerTest: XCTestCase {
expect(ttidSpan.isFinished) == false

fixture.displayLinkWrapper.normalFrame()
tracer.finish()

expect(ttidSpan.timestamp) == fixture.dateProvider.date()
expect(ttidSpan.isFinished) == true
Expand Down Expand Up @@ -97,8 +98,7 @@ class SentryTimeToDisplayTrackerTest: XCTestCase {

expect(ttidSpan?.isFinished) == true
expect(ttidSpan?.timestamp) == Date(timeIntervalSince1970: 9)

assertMeasurement(tracer: tracer, name: "time_to_initial_display", duration: 2_000)
expect(tracer.measurements["time_to_initial_display"]) == nil

fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 11))
sut.reportFullyDisplayed()
Expand Down Expand Up @@ -188,6 +188,7 @@ class SentryTimeToDisplayTrackerTest: XCTestCase {

fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 12))
fixture.displayLinkWrapper.normalFrame()
tracer.finish()

expect(sut.initialDisplaySpan?.isFinished) == true
expect(sut.initialDisplaySpan?.timestamp) == Date(timeIntervalSince1970: 12)
Expand Down Expand Up @@ -284,6 +285,74 @@ class SentryTimeToDisplayTrackerTest: XCTestCase {
expect(sut.fullDisplaySpan) == nil
expect(tracer.measurements["time_to_full_display"]) == nil
}

func testTracerWithAppStartData_notWaitingForFullDisplay() throws {
let appStartMeasurement = TestData.getAppStartMeasurement(type: .cold, appStartTimestamp: Date(timeIntervalSince1970: 6))
SentrySDK.setAppStartMeasurement(appStartMeasurement)

fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 7))

let sut = fixture.getSut(for: UIViewController(), waitForFullDisplay: false)
let tracer = try fixture.getTracer()

sut.start(for: tracer)

fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 8))
sut.reportInitialDisplay()
fixture.displayLinkWrapper.normalFrame()

fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 9))
sut.reportFullyDisplayed()
fixture.displayLinkWrapper.normalFrame()

tracer.finish()

let ttidSpan = sut.initialDisplaySpan
expect(ttidSpan?.isFinished) == true
expect(ttidSpan?.startTimestamp) == tracer.startTimestamp
expect(ttidSpan?.timestamp) == Date(timeIntervalSince1970: 8)
assertMeasurement(tracer: tracer, name: "time_to_initial_display", duration: 2_000)

expect(sut.fullDisplaySpan) == nil
expect(tracer.measurements["time_to_full_display"]) == nil

expect(Dynamic(self.fixture.framesTracker).listeners.count) == 0
}

func testTracerWithAppStartData_waitingForFullDisplay() throws {
let appStartMeasurement = TestData.getAppStartMeasurement(type: .cold, appStartTimestamp: Date(timeIntervalSince1970: 6))
SentrySDK.setAppStartMeasurement(appStartMeasurement)

fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 7))

let sut = fixture.getSut(for: UIViewController(), waitForFullDisplay: true)
let tracer = try fixture.getTracer()

sut.start(for: tracer)

fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 8))
sut.reportInitialDisplay()
fixture.displayLinkWrapper.normalFrame()

fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 9))
sut.reportFullyDisplayed()
fixture.displayLinkWrapper.normalFrame()

tracer.finish()

let ttidSpan = sut.initialDisplaySpan

expect(ttidSpan?.isFinished) == true
expect(ttidSpan?.startTimestamp) == tracer.startTimestamp
expect(ttidSpan?.timestamp) == Date(timeIntervalSince1970: 8)
assertMeasurement(tracer: tracer, name: "time_to_initial_display", duration: 2_000)

expect(sut.fullDisplaySpan?.startTimestamp) == ttidSpan?.startTimestamp
expect(sut.fullDisplaySpan?.timestamp) == Date(timeIntervalSince1970: 9)
assertMeasurement(tracer: tracer, name: "time_to_full_display", duration: 3_000)

expect(Dynamic(self.fixture.framesTracker).listeners.count) == 0
}

func assertMeasurement(tracer: SentryTracer, name: String, duration: TimeInterval) {
expect(tracer.measurements[name]?.value) == NSNumber(value: duration)
Expand Down
Loading