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: Finish TTFD when binding transaction to scope #4526

Merged
2 changes: 2 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,8 @@
### Fixes

- Make `Scope.span` fully thread safe (#4519)
- Finish TTFD on new UIViewControllers when not calling reportFullyDisplayed (#4526).

### Features

- Transactions for crashes (#4504): Finish the transaction bound to the scope when the app crashes. This __experimental__ feature is disabled by default. You can enable it via the option `enablePersistingTracesWhenCrashing`.
Expand Down
16 changes: 16 additions & 0 deletions Sources/Sentry/SentryTimeToDisplayTracker.m
Original file line number Diff line number Diff line change
Expand Up @@ -137,6 +137,22 @@ - (void)reportFullyDisplayed
[_dispatchQueueWrapper dispatchAsyncOnMainQueue:^{ self->_fullyDisplayedReported = YES; }];
}

- (void)finishSpansIfNotFinished
{
if (self.initialDisplaySpan.isFinished == NO) {
[self.initialDisplaySpan finish];
}

if (self.fullDisplaySpan.isFinished == NO) {
SENTRY_LOG_WARN(
@"You didn't call SentrySDK.reportFullyDisplayed(). Finishing full display span with "
@"status deadline exceeded.");

[self.fullDisplaySpan finishWithStatus:kSentrySpanStatusDeadlineExceeded];
return;
}
}

- (void)framesTrackerHasNewFrame:(NSDate *)newFrameDate
{
// The purpose of TTID and TTFD is to measure how long
Expand Down
2 changes: 2 additions & 0 deletions Sources/Sentry/SentryUIViewControllerPerformanceTracker.m
Original file line number Diff line number Diff line change
Expand Up @@ -163,8 +163,10 @@ - (void)createTimeToDisplay:(UIViewController *)controller
objc_setAssociatedObject(controller, &SENTRY_UI_PERFORMANCE_TRACKER_TTD_TRACKER, ttdTracker,
OBJC_ASSOCIATION_ASSIGN);

[self.currentTTDTracker finishSpansIfNotFinished];
self.currentTTDTracker = ttdTracker;
} else {
[self.currentTTDTracker finishSpansIfNotFinished];
self.currentTTDTracker = nil;
}
}
Expand Down
2 changes: 2 additions & 0 deletions Sources/Sentry/include/SentryTimeToDisplayTracker.h
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,8 @@ SENTRY_NO_INIT

- (void)reportFullyDisplayed;

- (void)finishSpansIfNotFinished;

@end

NS_ASSUME_NONNULL_END
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -412,6 +412,77 @@ class SentryTimeToDisplayTrackerTest: XCTestCase {

XCTAssertEqual(Dynamic(self.fixture.framesTracker).listeners.count, 0)
}

func testFinish_WithoutCallingReportFullyDisplayed() throws {
fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 9))

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

sut.start(for: tracer)

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

fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 11))
sut.finishSpansIfNotFinished()

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

fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 13))
tracer.finish()

XCTAssertNotNil(sut.fullDisplaySpan)
XCTAssertEqual(sut.fullDisplaySpan?.startTimestamp, Date(timeIntervalSince1970: 9))
XCTAssertEqual(sut.fullDisplaySpan?.timestamp, Date(timeIntervalSince1970: 10))
XCTAssertEqual(sut.fullDisplaySpan?.status, .deadlineExceeded)

XCTAssertEqual(sut.fullDisplaySpan?.spanDescription, "UIViewController full display - Deadline Exceeded")
XCTAssertEqual(sut.fullDisplaySpan?.operation, SentrySpanOperationUILoadFullDisplay)
XCTAssertEqual(sut.fullDisplaySpan?.origin, "manual.ui.time_to_display")

assertMeasurement(tracer: tracer, name: "time_to_full_display", duration: 1_000)

XCTAssertEqual(Dynamic(self.fixture.framesTracker).listeners.count, 0)
}

func testFinish_WithoutTTID() throws {
fixture.dateProvider.setDate(date: Date(timeIntervalSince1970: 9))

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

sut.start(for: tracer)

tracer.finish()

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

sut.finishSpansIfNotFinished()

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

let ttidSpan = try XCTUnwrap(sut.initialDisplaySpan)

XCTAssertEqual(ttidSpan.isFinished, true)
XCTAssertEqual(ttidSpan.startTimestamp, tracer.startTimestamp)
XCTAssertEqual(ttidSpan.timestamp, Date(timeIntervalSince1970: 10))
assertMeasurement(tracer: tracer, name: "time_to_initial_display", duration: 1_000)

let fullDisplaySpan = try XCTUnwrap(sut.fullDisplaySpan)
XCTAssertEqual(fullDisplaySpan.startTimestamp, tracer.startTimestamp)
XCTAssertEqual(fullDisplaySpan.timestamp, ttidSpan.timestamp)
XCTAssertEqual(fullDisplaySpan.status, .deadlineExceeded)

XCTAssertEqual(fullDisplaySpan.spanDescription, "UIViewController full display - Deadline Exceeded")
XCTAssertEqual(fullDisplaySpan.operation, SentrySpanOperationUILoadFullDisplay)
XCTAssertEqual(fullDisplaySpan.origin, "manual.ui.time_to_display")
assertMeasurement(tracer: tracer, name: "time_to_full_display", duration: 1_000)

XCTAssertEqual(Dynamic(self.fixture.framesTracker).listeners.count, 0)
}

func assertMeasurement(tracer: SentryTracer, name: String, duration: TimeInterval) {
XCTAssertEqual(tracer.measurements[name]?.value, NSNumber(value: duration))
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -766,6 +766,127 @@ class SentryUIViewControllerPerformanceTrackerTests: XCTestCase {
XCTAssertEqual("ui.load", child3.operation)
XCTAssertEqual("viewDidLoad", child3.spanDescription)
}

func test_waitForFullDisplay_NewViewControllerLoaded_BeforeReportTTFD() throws {
let sut = fixture.getSut()
let tracker = fixture.tracker
let firstController = TestViewController()
let secondController = TestViewController()

var firstTracer: SentryTracer?
var secondTracer: SentryTracer?

sut.enableWaitForFullDisplay = true

sut.viewControllerLoadView(firstController) {
firstTracer = self.getStack(tracker).first as? SentryTracer
}

sut.viewControllerViewDidLoad(firstController) {
// Empty on purpose
}

sut.viewControllerViewWillAppear(firstController) {
// Empty on purpose
}

sut.viewControllerViewDidAppear(firstController) {
// Empty on purpose
}

let firstFullDisplaySpan = try XCTUnwrap(firstTracer?.children.first { $0.operation == "ui.load.full_display" })

XCTAssertFalse(firstFullDisplaySpan.isFinished)

XCTAssertEqual(firstTracer?.traceId, SentrySDK.span?.traceId)

sut.viewControllerLoadView(secondController) {
secondTracer = self.getStack(tracker).first as? SentryTracer
}

XCTAssertTrue(firstFullDisplaySpan.isFinished)
XCTAssertEqual(.deadlineExceeded, firstFullDisplaySpan.status)

let secondFullDisplaySpan = try XCTUnwrap(secondTracer?.children.first { $0.operation == "ui.load.full_display" })

XCTAssertFalse(secondFullDisplaySpan.isFinished)
}

func test_waitForFullDisplay_NewViewControllerLoaded_BeforeReportTTFD_FramesTrackerStopped() throws {
let sut = fixture.getSut()
let tracker = fixture.tracker
let firstController = TestViewController()
let secondController = TestViewController()

var firstTracer: SentryTracer?
var secondTracer: SentryTracer?

sut.enableWaitForFullDisplay = true

sut.viewControllerLoadView(firstController) {
firstTracer = self.getStack(tracker).first as? SentryTracer
}

sut.viewControllerViewDidLoad(firstController) {
// Empty on purpose
}

sut.viewControllerViewWillAppear(firstController) {
// Empty on purpose
}

sut.viewControllerViewDidAppear(firstController) {
// Empty on purpose
}

let firstFullDisplaySpan = try XCTUnwrap(firstTracer?.children.first { $0.operation == "ui.load.full_display" })

XCTAssertFalse(firstFullDisplaySpan.isFinished)

fixture.framesTracker.stop()

sut.viewControllerLoadView(secondController) {
secondTracer = self.getStack(tracker).first as? SentryTracer
}

XCTAssertTrue(firstFullDisplaySpan.isFinished)
XCTAssertEqual(.deadlineExceeded, firstFullDisplaySpan.status)

XCTAssertEqual(0, secondTracer?.children.filter { $0.operation == "ui.load.full_display" }.count, "There should be no full display span, because the frames tracker is not running.")
}

func test_ForceBindToScope() throws {
let sut = fixture.getSut()
let tracker = fixture.tracker
let firstController = TestViewController()
let secondController = TestViewController()

var firstTracer: SentryTracer?
var secondTracer: SentryTracer?

sut.viewControllerLoadView(firstController) {
firstTracer = self.getStack(tracker).first as? SentryTracer
}

sut.viewControllerViewDidLoad(firstController) {
// Empty on purpose
}

sut.viewControllerViewWillAppear(firstController) {
// Empty on purpose
}

XCTAssertFalse(firstTracer?.isFinished ?? true)
XCTAssertEqual(firstTracer?.traceId, SentrySDK.span?.traceId)

sut.viewControllerLoadView(secondController) {
secondTracer = self.getStack(tracker).first as? SentryTracer
}

XCTAssertFalse(firstTracer?.isFinished ?? true, "Force bind to scope should not finish the first transaction. It should only remove it from the scope.")

XCTAssertEqual(secondTracer?.traceId, SentrySDK.span?.traceId)
}

func test_captureAllAutomaticSpans() {
let sut = fixture.getSut()
Expand Down
Loading