From 3bd5c5d6906d86361ca95ee336581a0f830dc6ea Mon Sep 17 00:00:00 2001 From: Denis Andrasec Date: Wed, 2 Oct 2024 14:03:20 +0200 Subject: [PATCH] use correct timestamps, use teimestamp internally to handle completion before start --- .../navigation/sentry_navigator_observer.dart | 14 ++++++--- .../time_to_initial_display_tracker.dart | 22 +++++++++---- .../time_to_initial_display_tracker_test.dart | 31 +++++++++++++++++++ 3 files changed, 57 insertions(+), 10 deletions(-) diff --git a/flutter/lib/src/navigation/sentry_navigator_observer.dart b/flutter/lib/src/navigation/sentry_navigator_observer.dart index 454974d11e..ffeeb1406e 100644 --- a/flutter/lib/src/navigation/sentry_navigator_observer.dart +++ b/flutter/lib/src/navigation/sentry_navigator_observer.dart @@ -164,7 +164,8 @@ class SentryNavigatorObserver extends RouteObserver> { _finishAndStartTTIDTracking(route, timestamp); } - Future _finishAndStartTTIDTracking(Route? route, DateTime timestamp) async { + Future _finishAndStartTTIDTracking( + Route? route, DateTime timestamp) async { await _finishTimeToDisplayTracking(endTimestamp: timestamp); await _startTimeToDisplayTracking(route, timestamp); } @@ -302,7 +303,8 @@ class SentryNavigatorObserver extends RouteObserver> { await _native?.beginNativeFrames(); } - Future _finishTimeToDisplayTracking({required DateTime endTimestamp, bool clearAfter = false}) async { + Future _finishTimeToDisplayTracking( + {required DateTime endTimestamp, bool clearAfter = false}) async { final transaction = _transaction; _transaction = null; try { @@ -324,7 +326,10 @@ class SentryNavigatorObserver extends RouteObserver> { final isTTFDSpan = child.context.operation == SentrySpanOperations.uiTimeToFullDisplay; if (!child.finished && (isTTIDSpan || isTTFDSpan)) { - await child.finish(endTimestamp: endTimestamp, status: SpanStatus.deadlineExceeded()); + await child.finish( + endTimestamp: endTimestamp, + status: SpanStatus.deadlineExceeded(), + ); } } } catch (exception, stacktrace) { @@ -345,7 +350,8 @@ class SentryNavigatorObserver extends RouteObserver> { } } - Future _startTimeToDisplayTracking(Route? route, DateTime startTimestamp) async { + Future _startTimeToDisplayTracking( + Route? route, DateTime startTimestamp) async { try { final routeName = _getRouteName(route) ?? _currentRouteName; if (!_enableAutoTransactions || routeName == null) { diff --git a/flutter/lib/src/navigation/time_to_initial_display_tracker.dart b/flutter/lib/src/navigation/time_to_initial_display_tracker.dart index d342e97769..7895ec4fa0 100644 --- a/flutter/lib/src/navigation/time_to_initial_display_tracker.dart +++ b/flutter/lib/src/navigation/time_to_initial_display_tracker.dart @@ -29,6 +29,8 @@ class TimeToInitialDisplayTracker { bool _isManual = false; Completer? _trackingCompleter; DateTime? _endTimestamp; + DateTime? _completeTrackingTimeStamp; + final Duration _determineEndtimeTimeout = Duration(seconds: 5); /// This endTimestamp is needed in the [TimeToFullDisplayTracker] class @@ -87,6 +89,13 @@ class TimeToInitialDisplayTracker { // If we already know it's manual we can return the future immediately if (_isManual) { + final completeTrackingTimeStamp = _completeTrackingTimeStamp; + if (completeTrackingTimeStamp != null) { + // If complete was called before we could call start, complete it here. + _endTimestamp = completeTrackingTimeStamp; + _trackingCompleter?.complete(completeTrackingTimeStamp); + _completeTrackingTimeStamp = null; + } return future; } @@ -102,16 +111,17 @@ class TimeToInitialDisplayTracker { } void markAsManual() { - if (_trackingCompleter != null && !_trackingCompleter!.isCompleted) { - _isManual = true; - } + _isManual = true; } void completeTracking() { + final timestamp = DateTime.now(); + if (_trackingCompleter != null && !_trackingCompleter!.isCompleted) { - final endTimestamp = DateTime.now(); - _endTimestamp = endTimestamp; - _trackingCompleter?.complete(endTimestamp); + _endTimestamp = timestamp; + _trackingCompleter?.complete(timestamp); + } else { + _completeTrackingTimeStamp = timestamp; } } diff --git a/flutter/test/navigation/time_to_initial_display_tracker_test.dart b/flutter/test/navigation/time_to_initial_display_tracker_test.dart index 526343a8bd..b73e9d4d56 100644 --- a/flutter/test/navigation/time_to_initial_display_tracker_test.dart +++ b/flutter/test/navigation/time_to_initial_display_tracker_test.dart @@ -84,6 +84,37 @@ void main() { .difference(ttidSpan.startTimestamp) .inMilliseconds); }); + + test('starting after completing still finished correctly', () async { + await Future.delayed(fixture.finishFrameDuration, () { + sut.markAsManual(); + sut.completeTracking(); + }); + + final transaction = fixture.getTransaction() as SentryTracer; + await sut.trackRegularRoute(transaction, fixture.startTimestamp); + + final children = transaction.children; + expect(children, hasLength(1)); + + final ttidSpan = children.first; + expect(ttidSpan.context.operation, + SentrySpanOperations.uiTimeToInitialDisplay); + expect(ttidSpan.finished, isTrue); + expect(ttidSpan.context.description, 'Regular route initial display'); + expect(ttidSpan.origin, SentryTraceOrigins.manualUiTimeToDisplay); + final ttidMeasurement = + transaction.measurements['time_to_initial_display']; + expect(ttidMeasurement, isNotNull); + expect(ttidMeasurement?.unit, DurationSentryMeasurementUnit.milliSecond); + expect(ttidMeasurement?.value, + greaterThanOrEqualTo(fixture.finishFrameDuration.inMilliseconds)); + expect( + ttidMeasurement?.value, + ttidSpan.endTimestamp! + .difference(ttidSpan.startTimestamp) + .inMilliseconds); + }); }); group('determineEndtime', () {