fix(ttfd): unfinished ttfd should match ttid duration (#2347)

* update

* update

* update

* update

* update

* fix compilation

* update

* add tesT

* fix timezone

* fix tests

CHANGELOG.md

@@ -66,6 +66,7 @@
 - iOS replay integration when only `onErrorSampleRate` is specified ([#2306](https:/getsentry/sentry-dart/pull/2306))
 - Fix TTID timing issue ([#2326](https:/getsentry/sentry-dart/pull/2326))
 - Start missing TTFD for root screen transaction ([#2332](https:/getsentry/sentry-dart/pull/2332))
+- Match TTFD to TTID end timespan if TTFD is unfinished when user navigates to another screen ([#2347](https:/getsentry/sentry-dart/pull/2347))
 - Accessing invalid json fields from `fetchNativeAppStart` should return null ([#2340](https:/getsentry/sentry-dart/pull/2340))
 - Error when calling `SentryFlutter.reportFullyDisplayed()` twice ([#2339](https:/getsentry/sentry-dart/pull/2339))
 - TTFD measurements should only be added for successful TTFD spans ([#2348](https:/getsentry/sentry-dart/pull/2348))

flutter/lib/src/navigation/sentry_navigator_observer.dart

@@ -8,6 +8,7 @@ import 'package:meta/meta.dart';
 import '../native/native_frames.dart';
 import '../native/sentry_native_binding.dart';
 import 'time_to_display_tracker.dart';
+import 'time_to_full_display_tracker.dart';
 
 import '../../sentry_flutter.dart';
 import '../event_processor/flutter_enricher_event_processor.dart';
@@ -309,13 +310,18 @@ class SentryNavigatorObserver extends RouteObserver<PageRoute<dynamic>> {
  // Cancel unfinished TTID/TTFD spans, e.g this might happen if the user navigates
  // away from the current route before TTFD or TTID is finished.
  for (final child in (transaction as SentryTracer).children) {
+ if (child.finished) continue;
+
  final isTTIDSpan = child.context.operation ==
  SentrySpanOperations.uiTimeToInitialDisplay;
  final isTTFDSpan =
  child.context.operation == SentrySpanOperations.uiTimeToFullDisplay;
- if (!child.finished && (isTTIDSpan || isTTFDSpan)) {
+ if (isTTIDSpan || isTTFDSpan) {
+ final finishTimestamp = isTTFDSpan
+ ? (ttidEndTimestampProvider() ?? endTimestamp)
+ : endTimestamp;
  await child.finish(
- endTimestamp: endTimestamp,
+ endTimestamp: finishTimestamp,
  status: SpanStatus.deadlineExceeded(),
  );
  }

flutter/lib/src/navigation/time_to_full_display_tracker.dart

@@ -35,7 +35,7 @@ class TimeToFullDisplayTracker {
  final options = Sentry.currentHub.options;
 
  // End timestamp provider is only needed when the TTFD timeout is triggered
- EndTimestampProvider _endTimestampProvider = ttidEndTimestampProvider();
+ EndTimestampProvider _endTimestampProvider = ttidEndTimestampProvider;
  Completer<void> _completedTTFDTracking = Completer<void>();
 
  Future<void> track({
@@ -130,5 +130,5 @@ class TimeToFullDisplayTracker {
 typedef EndTimestampProvider = DateTime? Function();
 
 @internal
-EndTimestampProvider ttidEndTimestampProvider() =>
+EndTimestampProvider ttidEndTimestampProvider =
  () => TimeToInitialDisplayTracker().endTimestamp;

flutter/lib/src/navigation/time_to_initial_display_tracker.dart

@@ -129,4 +129,10 @@ class TimeToInitialDisplayTracker {
  // We can't clear the ttid end time stamp here, because it might be needed
  // in the [TimeToFullDisplayTracker] class
  }
+
+ @visibleForTesting
+ void clearForTest() {
+ clear();
+ _endTimestamp = null;
+ }
 }

flutter/test/navigation/time_to_display_tracker_test.dart

@@ -198,7 +198,7 @@ class Fixture {
  final options = defaultTestOptions()
  ..dsn = fakeDsn
  ..tracesSampleRate = 1.0;
- late final endTimeProvider = ttidEndTimestampProvider();
+ late final endTimeProvider = ttidEndTimestampProvider;
  late final hub = Hub(options);
 
  TimeToInitialDisplayTracker? ttidTracker;

flutter/test/sentry_navigator_observer_test.dart

@@ -10,6 +10,7 @@ import 'package:sentry_flutter/sentry_flutter.dart';
 import 'package:sentry/src/sentry_tracer.dart';
 import 'package:sentry_flutter/src/native/native_frames.dart';
 import 'package:sentry_flutter/src/navigation/time_to_display_tracker.dart';
+import 'package:sentry_flutter/src/navigation/time_to_full_display_tracker.dart';
 import 'package:sentry_flutter/src/navigation/time_to_initial_display_tracker.dart';
 
 import 'fake_frame_callback_handler.dart';
@@ -128,6 +129,11 @@ void main() {
  });
 
  group('$SentryNavigatorObserver', () {
+ tearDown(() {
+ fixture.timeToInitialDisplayTracker.clearForTest();
+ fixture.timeToFullDisplayTracker.clear();
+ });
+
  test('didPush starts transaction', () async {
  const name = 'Current Route';
  final currentRoute = route(RouteSettings(name: name));
@@ -380,48 +386,189 @@ void main() {
  .called(1);
  });
 
+ // e.g when a user navigates to another screen before ttfd or ttid is finished
+ test('cancelled TTID and TTFD spans do not add measurements', () async {
+ final initialRoute = route(RouteSettings(name: 'Initial Route'));
+ final newRoute = route(RouteSettings(name: 'New Route'));
+
+ final hub = _MockHub();
+ final transaction = getMockSentryTracer(finished: false) as SentryTracer;
+
+ final mockChildTTID = MockSentrySpan();
+ final mockChildTTFD = MockSentrySpan();
+
+ when(transaction.children).thenReturn([
+ mockChildTTID,
+ mockChildTTFD,
+ ]);
+
+ when(transaction.measurements).thenReturn(<String, SentryMeasurement>{});
+
+ when(mockChildTTID.finished).thenReturn(false);
+ when(mockChildTTID.context).thenReturn(SentrySpanContext(
+ operation: SentrySpanOperations.uiTimeToInitialDisplay));
+ when(mockChildTTID.status).thenReturn(SpanStatus.cancelled());
+
+ when(mockChildTTFD.finished).thenReturn(false);
+ when(mockChildTTFD.context).thenReturn(SentrySpanContext(
+ operation: SentrySpanOperations.uiTimeToFullDisplay));
+ when(mockChildTTFD.status).thenReturn(SpanStatus.cancelled());
+
+ when(transaction.context)
+ .thenReturn(SentrySpanContext(operation: 'navigation'));
+ when(transaction.status).thenReturn(null);
+ when(transaction.finished).thenReturn(false);
+
+ when(transaction.startChild(
+ 'ui.load.initial_display',
+ description: anyNamed('description'),
+ startTimestamp: anyNamed('startTimestamp'),
+ )).thenReturn(MockSentrySpan());
+
+ when(hub.getSpan()).thenReturn(transaction);
+ when(hub.startTransactionWithContext(
+ any,
+ startTimestamp: anyNamed('startTimestamp'),
+ waitForChildren: true,
+ autoFinishAfter: anyNamed('autoFinishAfter'),
+ trimEnd: true,
+ onFinish: anyNamed('onFinish'),
+ )).thenReturn(transaction);
+
+ final sut =
+ fixture.getSut(hub: hub, autoFinishAfter: Duration(seconds: 5));
+
+ // Simulate pushing the initial route
+ sut.didPush(initialRoute, null);
+
+ // Simulate navigating to a new route before TTID and TTFD spans finish
+ sut.didPush(newRoute, initialRoute);
+
+ // Allow async operations to complete
+ await Future<void>.delayed(const Duration(milliseconds: 100));
+
+ // Verify that the TTID and TTFD spans are finished with a cancelled status
+ verify(mockChildTTID.finish(
+ endTimestamp: anyNamed('endTimestamp'),
+ status: SpanStatus.deadlineExceeded()))
+ .called(1);
+ verify(mockChildTTFD.finish(
+ endTimestamp: anyNamed('endTimestamp'),
+ status: SpanStatus.deadlineExceeded()))
+ .called(1);
+
+ // Verify that the measurements are not added to the transaction
+ final measurements = transaction.measurements;
+ expect(measurements.containsKey('time_to_initial_display'), isFalse);
+ expect(measurements.containsKey('time_to_full_display'), isFalse);
+ });
+
+ test('unfinished ttfd will match ttid duration if available', () async {
+ final currentRoute = route(RouteSettings(name: 'Current Route'));
+
+ final hub = _MockHub();
+ final options = hub.options as SentryFlutterOptions;
+ options.enableTimeToFullDisplayTracing = true;
+
+ final transaction = getMockSentryTracer(finished: false) as SentryTracer;
+ final ttidSpan = MockSentrySpan();
+ final ttfdSpan = MockSentrySpan();
+ when(transaction.children).thenReturn([
+ ttfdSpan,
+ ttidSpan,
+ ]);
+ when(ttidSpan.finished).thenReturn(false);
+ when(ttfdSpan.finished).thenReturn(false);
+ when(ttidSpan.context).thenReturn(SentrySpanContext(
+ operation: SentrySpanOperations.uiTimeToInitialDisplay));
+ when(ttfdSpan.context).thenReturn(SentrySpanContext(
+ operation: SentrySpanOperations.uiTimeToFullDisplay));
+ when(transaction.context).thenReturn(SentrySpanContext(operation: 'op'));
+ when(transaction.status).thenReturn(null);
+ when(transaction.startChild('ui.load.initial_display',
+ description: anyNamed('description'),
+ startTimestamp: anyNamed('startTimestamp')))
+ .thenReturn(NoOpSentrySpan());
+ when(transaction.startChild('ui.load.full_display',
+ description: anyNamed('description'),
+ startTimestamp: anyNamed('startTimestamp')))
+ .thenReturn(NoOpSentrySpan());
+ _whenAnyStart(hub, transaction);
+
+ final sut = fixture.getSut(hub: hub);
+
+ sut.didPush(currentRoute, null);
+
+ final anotherRoute = route(RouteSettings(name: 'Another Route'));
+ sut.didPush(anotherRoute, null);
+
+ await Future<void>.delayed(const Duration(milliseconds: 100));
+
+ final ttidFinishVerification = verify(ttidSpan.finish(
+ endTimestamp: captureAnyNamed('endTimestamp'),
+ status: anyNamed('status'),
+ ));
+ final ttidEndTimestamp =
+ ttidFinishVerification.captured.single as DateTime;
+
+ final ttfdFinishVerification = verify(ttfdSpan.finish(
+ endTimestamp: captureAnyNamed('endTimestamp'),
+ status: anyNamed('status'),
+ ));
+ final ttfdEndTimestamp =
+ ttfdFinishVerification.captured.single as DateTime;
+
+ expect(ttfdEndTimestamp.toUtc(), equals(ttidEndTimestamp.toUtc()));
+ });
+
  test(
  'unfinished children will be finished with deadline_exceeded on didPush',
  () async {
  final currentRoute = route(RouteSettings(name: 'Current Route'));
 
  final hub = _MockHub();
- final span = getMockSentryTracer(finished: false) as SentryTracer;
- final mockChildA = MockSentrySpan();
- final mockChildB = MockSentrySpan();
- when(span.children).thenReturn([
- mockChildB,
- mockChildA,
+ final options = hub.options as SentryFlutterOptions;
+ options.enableTimeToFullDisplayTracing = true;
+
+ final transaction = getMockSentryTracer(finished: false) as SentryTracer;
+ final ttidSpan = MockSentrySpan();
+ final ttfdSpan = MockSentrySpan();
+ when(transaction.children).thenReturn([
+ ttfdSpan,
+ ttidSpan,
  ]);
- when(mockChildA.finished).thenReturn(false);
- when(mockChildB.finished).thenReturn(false);
- when(mockChildA.context).thenReturn(SentrySpanContext(
+ when(ttidSpan.finished).thenReturn(false);
+ when(ttfdSpan.finished).thenReturn(false);
+ when(ttidSpan.context).thenReturn(SentrySpanContext(
  operation: SentrySpanOperations.uiTimeToInitialDisplay));
- when(mockChildB.context).thenReturn(SentrySpanContext(
+ when(ttfdSpan.context).thenReturn(SentrySpanContext(
  operation: SentrySpanOperations.uiTimeToFullDisplay));
- when(span.context).thenReturn(SentrySpanContext(operation: 'op'));
- when(span.status).thenReturn(null);
- when(span.startChild('ui.load.initial_display',
+ when(transaction.context).thenReturn(SentrySpanContext(operation: 'op'));
+ when(transaction.status).thenReturn(null);
+ when(transaction.startChild('ui.load.initial_display',
  description: anyNamed('description'),
  startTimestamp: anyNamed('startTimestamp')))
  .thenReturn(NoOpSentrySpan());
- _whenAnyStart(hub, span);
+ when(transaction.startChild('ui.load.full_display',
+ description: anyNamed('description'),
+ startTimestamp: anyNamed('startTimestamp')))
+ .thenReturn(NoOpSentrySpan());
+ _whenAnyStart(hub, transaction);
 
  final sut = fixture.getSut(hub: hub);
 
- // Push to new screen, e.g app start / root screen
  sut.didPush(currentRoute, null);
 
- // Push to screen e.g root to user screen
- sut.didPush(currentRoute, null);
+ final anotherRoute = route(RouteSettings(name: 'Another Route'));
+ sut.didPush(anotherRoute, null);
 
  await Future<void>.delayed(const Duration(milliseconds: 100));
 
- verify(mockChildA.finish(
+ verify(ttidSpan.finish(
  endTimestamp: captureAnyNamed('endTimestamp'),
  status: SpanStatus.deadlineExceeded()))
  .called(1);
- verify(mockChildB.finish(
+ verify(ttfdSpan.finish(
  endTimestamp: captureAnyNamed('endTimestamp'),
  status: SpanStatus.deadlineExceeded()))
  .called(1);
@@ -1038,6 +1185,9 @@ void main() {
 }
 
 class Fixture {
+ late TimeToInitialDisplayTracker timeToInitialDisplayTracker;
+ late TimeToFullDisplayTracker timeToFullDisplayTracker;
+
  SentryNavigatorObserver getSut({
  required Hub hub,
  bool enableAutoTransactions = true,
@@ -1048,13 +1198,17 @@ class Fixture {
  List<String>? ignoreRoutes,
  }) {
  final frameCallbackHandler = FakeFrameCallbackHandler();
- final timeToInitialDisplayTracker = TimeToInitialDisplayTracker(
+ timeToInitialDisplayTracker = TimeToInitialDisplayTracker(
  frameCallbackHandler: frameCallbackHandler,
  );
+ timeToFullDisplayTracker = TimeToFullDisplayTracker(
+ endTimestampProvider: () => timeToInitialDisplayTracker.endTimestamp,
+ );
  final options = hub.options;
  if (options is SentryFlutterOptions) {
  options.timeToDisplayTracker = TimeToDisplayTracker(
  ttidTracker: timeToInitialDisplayTracker,
+ ttfdTracker: timeToFullDisplayTracker,
  options: hub.options as SentryFlutterOptions,
  );
  }