From 31b2afb442b730ab5e1c190ef0de71fbcee6bb38 Mon Sep 17 00:00:00 2001 From: Giancarlo Buenaflor Date: Thu, 7 Mar 2024 17:18:10 +0100 Subject: [PATCH] feat: ttid (#1910) * Change app start integration in a way that works with ttid as well * Formatting * Update * add visibleForTesting * Update * update * Add app start info test * Remove set app start info null * Review improvements * Add TTID * Improvements * Improvements * Fix integration test * Update * Clear after tracking * Update CHANGELOG * Format * Update * Update * remove import * Update sentry tracer * Add (not all) improvements for pr review * combine transaction handler * Refactor trackAppStart and trackRegularRoute to use private method * Fix dart analyzer * Remove clear * Clear in tearDown * Apply suggestions from code review Co-authored-by: Philipp Hofmann * Apply PR suggestions * fix analyze * update * update * Fix tests * Fix analyze * revert sample * Update * Update * Fix test * Move clear to the beginning of function * Fix start time * Fix analyze * remove comment * Formatting * fix test * add ttid duration assertion and determineEndTime timeout * Rename finish transaction and do an early exit with enableAutoTransactions * Rename function * Remove static and getter for in navigator observer * Expose SentryDisplayWidget as public api and add it to example app * Fix dart analyze * Fix dart doc * Improve tests * Reduce fake frame finishing time and improve tests * Improve test names * Fix tests * Apply formatting * Add extra assertion in tests --------- Co-authored-by: Philipp Hofmann --- CHANGELOG.md | 10 + dart/lib/sentry.dart | 2 + dart/lib/src/sentry_measurement.dart | 7 + dart/lib/src/sentry_span_operations.dart | 7 + dart/lib/src/sentry_trace_origins.dart | 2 + flutter/example/android/app/build.gradle | 2 +- flutter/example/lib/main.dart | 4 +- flutter/lib/sentry_flutter.dart | 1 + .../native_app_start_integration.dart | 2 +- .../src/navigation/sentry_display_widget.dart | 60 ++++++ .../navigation/sentry_navigator_observer.dart | 106 ++++++--- .../navigation/time_to_display_tracker.dart | 34 +++ .../time_to_initial_display_tracker.dart | 136 ++++++++++++ flutter/test/fake_frame_callback_handler.dart | 7 +- .../sentry_display_widget_test.dart | 122 +++++++++++ .../time_to_display_tracker_test.dart | 186 ++++++++++++++++ .../time_to_initial_display_tracker_test.dart | 201 ++++++++++++++++++ .../test/sentry_navigator_observer_test.dart | 144 +++++++++---- 18 files changed, 961 insertions(+), 72 deletions(-) create mode 100644 dart/lib/src/sentry_span_operations.dart create mode 100644 flutter/lib/src/navigation/sentry_display_widget.dart create mode 100644 flutter/lib/src/navigation/time_to_display_tracker.dart create mode 100644 flutter/lib/src/navigation/time_to_initial_display_tracker.dart create mode 100644 flutter/test/navigation/sentry_display_widget_test.dart create mode 100644 flutter/test/navigation/time_to_display_tracker_test.dart create mode 100644 flutter/test/navigation/time_to_initial_display_tracker_test.dart diff --git a/CHANGELOG.md b/CHANGELOG.md index cadf415d7..aaf3e24ab 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -10,6 +10,16 @@ ### Features +- Add TTID (time to initial display), which allows you to measure the time it takes to render the first frame of your screen ([#1910](https://github.com/getsentry/sentry-dart/pull/1910)) + - Requires using the [routing instrumentation](https://docs.sentry.io/platforms/flutter/integrations/routing-instrumentation/). + - Introduces two modes: + - `automatic` mode is enabled by default for all screens and will yield only an approximation result. + - `manual` mode requires manual instrumentation and will yield a more accurate result. + - To use `manual` mode, you need to wrap your desired widget: `SentryDisplayWidget(child: MyScreen())`. + - You can mix and match both modes in your app. + - Other significant fixes + - `didPop` doesn't trigger a new transaction + - Change transaction operation name to `ui.load` instead of `navigation` - Use `recordHttpBreadcrumbs` to set iOS `enableNetworkBreadcrumbs` ([#1884](https://github.com/getsentry/sentry-dart/pull/1884)) - Apply `beforeBreadcrumb` on native iOS crumbs ([#1914](https://github.com/getsentry/sentry-dart/pull/1914)) - Add `maxQueueSize` to limit the number of unawaited events sent to Sentry ([#1868](https://github.com/getsentry/sentry-dart/pull/1868)) diff --git a/dart/lib/sentry.dart b/dart/lib/sentry.dart index 5419aa45b..f416d0b79 100644 --- a/dart/lib/sentry.dart +++ b/dart/lib/sentry.dart @@ -49,6 +49,8 @@ export 'src/utils/http_header_utils.dart'; // ignore: invalid_export_of_internal_element export 'src/sentry_trace_origins.dart'; // ignore: invalid_export_of_internal_element +export 'src/sentry_span_operations.dart'; +// ignore: invalid_export_of_internal_element export 'src/utils.dart'; // spotlight debugging export 'src/spotlight.dart'; diff --git a/dart/lib/src/sentry_measurement.dart b/dart/lib/src/sentry_measurement.dart index 481c513e9..b95e506aa 100644 --- a/dart/lib/src/sentry_measurement.dart +++ b/dart/lib/src/sentry_measurement.dart @@ -39,6 +39,13 @@ class SentryMeasurement { value = duration.inMilliseconds, unit = DurationSentryMeasurementUnit.milliSecond; + /// Duration of the time to initial display in milliseconds + SentryMeasurement.timeToInitialDisplay(Duration duration) + : assert(!duration.isNegative), + name = 'time_to_initial_display', + value = duration.inMilliseconds, + unit = DurationSentryMeasurementUnit.milliSecond; + final String name; final num value; final SentryMeasurementUnit? unit; diff --git a/dart/lib/src/sentry_span_operations.dart b/dart/lib/src/sentry_span_operations.dart new file mode 100644 index 000000000..fca22fc1e --- /dev/null +++ b/dart/lib/src/sentry_span_operations.dart @@ -0,0 +1,7 @@ +import 'package:meta/meta.dart'; + +@internal +class SentrySpanOperations { + static const String uiLoad = 'ui.load'; + static const String uiTimeToInitialDisplay = 'ui.load.initial_display'; +} diff --git a/dart/lib/src/sentry_trace_origins.dart b/dart/lib/src/sentry_trace_origins.dart index 5a7c49b33..4377fa2c0 100644 --- a/dart/lib/src/sentry_trace_origins.dart +++ b/dart/lib/src/sentry_trace_origins.dart @@ -27,4 +27,6 @@ class SentryTraceOrigins { static const autoDbDriftQueryExecutor = 'auto.db.drift.query.executor'; static const autoDbDriftTransactionExecutor = 'auto.db.drift.transaction.executor'; + static const autoUiTimeToDisplay = 'auto.ui.time_to_display'; + static const manualUiTimeToDisplay = 'manual.ui.time_to_display'; } diff --git a/flutter/example/android/app/build.gradle b/flutter/example/android/app/build.gradle index b54cd7fdf..ac4557e2c 100644 --- a/flutter/example/android/app/build.gradle +++ b/flutter/example/android/app/build.gradle @@ -48,7 +48,7 @@ android { defaultConfig { applicationId "io.sentry.samples.flutter" - minSdkVersion 19 + minSdkVersion flutter.minSdkVersion targetSdkVersion 33 versionCode flutterVersionCode.toInteger() versionName flutterVersionName diff --git a/flutter/example/lib/main.dart b/flutter/example/lib/main.dart index 6a0c0a5b8..19050ec79 100644 --- a/flutter/example/lib/main.dart +++ b/flutter/example/lib/main.dart @@ -13,6 +13,7 @@ import 'package:sentry_flutter/sentry_flutter.dart'; import 'package:sentry_isar/sentry_isar.dart'; import 'package:sentry_sqflite/sentry_sqflite.dart'; import 'package:sqflite/sqflite.dart'; + // import 'package:sqflite_common_ffi/sqflite_ffi.dart'; // import 'package:sqflite_common_ffi_web/sqflite_ffi_web.dart'; import 'package:universal_platform/universal_platform.dart'; @@ -80,6 +81,7 @@ Future setupSentry( // going to log too much for your app, but can be useful when figuring out // configuration issues, e.g. finding out why your events are not uploaded. options.debug = true; + options.spotlight = Spotlight(enabled: true); options.maxRequestBodySize = MaxRequestBodySize.always; options.maxResponseBodySize = MaxResponseBodySize.always; @@ -732,7 +734,7 @@ void navigateToAutoCloseScreen(BuildContext context) { context, MaterialPageRoute( settings: const RouteSettings(name: 'AutoCloseScreen'), - builder: (context) => const AutoCloseScreen(), + builder: (context) => SentryDisplayWidget(child: const AutoCloseScreen()), ), ); } diff --git a/flutter/lib/sentry_flutter.dart b/flutter/lib/sentry_flutter.dart index 0f43bf741..d15c8b7a7 100644 --- a/flutter/lib/sentry_flutter.dart +++ b/flutter/lib/sentry_flutter.dart @@ -16,3 +16,4 @@ export 'src/screenshot/sentry_screenshot_quality.dart'; export 'src/user_interaction/sentry_user_interaction_widget.dart'; export 'src/binding_wrapper.dart'; export 'src/sentry_widget.dart'; +export 'src/navigation/sentry_display_widget.dart'; diff --git a/flutter/lib/src/integrations/native_app_start_integration.dart b/flutter/lib/src/integrations/native_app_start_integration.dart index 91d0c0194..0ba5c77c4 100644 --- a/flutter/lib/src/integrations/native_app_start_integration.dart +++ b/flutter/lib/src/integrations/native_app_start_integration.dart @@ -114,9 +114,9 @@ class AppStartInfo { final AppStartType type; final DateTime start; final DateTime end; + Duration get duration => end.difference(start); SentryMeasurement toMeasurement() { - final duration = end.difference(start); return type == AppStartType.cold ? SentryMeasurement.coldAppStart(duration) : SentryMeasurement.warmAppStart(duration); diff --git a/flutter/lib/src/navigation/sentry_display_widget.dart b/flutter/lib/src/navigation/sentry_display_widget.dart new file mode 100644 index 000000000..e42f5c4f7 --- /dev/null +++ b/flutter/lib/src/navigation/sentry_display_widget.dart @@ -0,0 +1,60 @@ +import 'package:flutter/cupertino.dart'; +import 'time_to_initial_display_tracker.dart'; + +import '../frame_callback_handler.dart'; + +/// A widget that reports the Time To Initially Displayed (TTID) of its child widget. +/// +/// This widget wraps around another widget to measure and report the time it takes +/// for the child widget to be initially displayed on the screen. This method +/// allows a more accurate measurement than what the default TTID implementation +/// provides. The TTID measurement begins when the route to the widget is pushed and ends +/// when `addPostFramecallback` is triggered. +/// +/// Wrap the widget you want to measure with [SentryDisplayWidget], and ensure that you +/// have set up Sentry's routing instrumentation according to the Sentry documentation. +/// +/// ```dart +/// SentryDisplayWidget( +/// child: MyWidget(), +/// ) +/// ``` +/// +/// Make sure to configure Sentry's routing instrumentation in your app by following +/// the guidelines provided in Sentry's documentation for Flutter integrations: +/// https://docs.sentry.io/platforms/flutter/integrations/routing-instrumentation/ +/// +/// See also: +/// - [Sentry's documentation on Flutter integrations](https://docs.sentry.io/platforms/flutter/) +/// for more information on how to integrate Sentry into your Flutter application. +class SentryDisplayWidget extends StatefulWidget { + final Widget child; + final FrameCallbackHandler _frameCallbackHandler; + + SentryDisplayWidget({ + super.key, + required this.child, + @visibleForTesting FrameCallbackHandler? frameCallbackHandler, + }) : _frameCallbackHandler = + frameCallbackHandler ?? DefaultFrameCallbackHandler(); + + @override + _SentryDisplayWidgetState createState() => _SentryDisplayWidgetState(); +} + +class _SentryDisplayWidgetState extends State { + @override + void initState() { + super.initState(); + TimeToInitialDisplayTracker().markAsManual(); + + widget._frameCallbackHandler.addPostFrameCallback((_) { + TimeToInitialDisplayTracker().completeTracking(); + }); + } + + @override + Widget build(BuildContext context) { + return widget.child; + } +} diff --git a/flutter/lib/src/navigation/sentry_navigator_observer.dart b/flutter/lib/src/navigation/sentry_navigator_observer.dart index 30beaa75b..5eb788400 100644 --- a/flutter/lib/src/navigation/sentry_navigator_observer.dart +++ b/flutter/lib/src/navigation/sentry_navigator_observer.dart @@ -1,5 +1,12 @@ +// ignore_for_file: invalid_use_of_internal_member + +import 'dart:async'; + +import 'package:flutter/material.dart'; import 'package:flutter/widgets.dart'; import 'package:meta/meta.dart'; +import '../integrations/integrations.dart'; +import 'time_to_display_tracker.dart'; import '../../sentry_flutter.dart'; import '../event_processor/flutter_enricher_event_processor.dart'; @@ -19,6 +26,8 @@ typedef AdditionalInfoExtractor = Map? Function( /// This is a navigation observer to record navigational breadcrumbs. /// For now it only records navigation events and no gestures. /// +/// It also records Time to Initial Display (TTID). +/// /// [Route]s can always be null and their [Route.settings] can also always be null. /// For example, if the application starts, there is no previous route. /// The [RouteSettings] is null if a developer has not specified any @@ -44,22 +53,21 @@ typedef AdditionalInfoExtractor = Map? Function( /// ) /// ``` /// -/// See the constructor docs for the argument documentation. +/// The option [enableAutoTransactions] is enabled by default. For every new +/// route a transaction is started. It's automatically finished after +/// [autoFinishAfter] duration or when all child spans are finished, +/// if those happen to take longer. The transaction will be set to [Scope.span] +/// if the latter is empty. +/// +/// Enabling the [setRouteNameAsTransaction] option overrides the current +/// [Scope.transaction] which will also override the name of the current +/// [Scope.span]. So be careful when this is used together with performance +/// monitoring. /// /// See also: /// - [RouteObserver](https://api.flutter.dev/flutter/widgets/RouteObserver-class.html) /// - [Navigating with arguments](https://flutter.dev/docs/cookbook/navigation/navigate-with-arguments) class SentryNavigatorObserver extends RouteObserver> { - /// The option [enableAutoTransactions] is enabled by default. - /// For every new route a transaction is started. It's automatically finished - /// after [autoFinishAfter] duration or when all child spans are - /// finished, if those happen to take longer. - /// The transaction will be set to [Scope.span] if the latter is empty. - /// - /// Enabling the [setRouteNameAsTransaction] option overrides the - /// current [Scope.transaction] which will also override the name of the current - /// [Scope.span]. So be careful when this is used together with performance - /// monitoring. SentryNavigatorObserver({ Hub? hub, bool enableAutoTransactions = true, @@ -67,15 +75,16 @@ class SentryNavigatorObserver extends RouteObserver> { bool setRouteNameAsTransaction = false, RouteNameExtractor? routeNameExtractor, AdditionalInfoExtractor? additionalInfoProvider, + @visibleForTesting TimeToDisplayTracker? timeToDisplayTracker, }) : _hub = hub ?? HubAdapter(), _enableAutoTransactions = enableAutoTransactions, _autoFinishAfter = autoFinishAfter, _setRouteNameAsTransaction = setRouteNameAsTransaction, _routeNameExtractor = routeNameExtractor, _additionalInfoProvider = additionalInfoProvider, - _native = SentryFlutter.native { + _native = SentryFlutter.native, + _timeToDisplayTracker = timeToDisplayTracker ?? TimeToDisplayTracker() { if (enableAutoTransactions) { - // ignore: invalid_use_of_internal_member _hub.options.sdk.addIntegration('UINavigationTracing'); } } @@ -87,6 +96,7 @@ class SentryNavigatorObserver extends RouteObserver> { final RouteNameExtractor? _routeNameExtractor; final AdditionalInfoExtractor? _additionalInfoProvider; final SentryNative? _native; + final TimeToDisplayTracker? _timeToDisplayTracker; ISentrySpan? _transaction; @@ -95,6 +105,12 @@ class SentryNavigatorObserver extends RouteObserver> { @internal static String? get currentRouteName => _currentRouteName; + Completer? _completedDisplayTracking; + + // Since didPush does not have a future, we can keep track of when the display tracking has finished + @visibleForTesting + Completer? get completedDisplayTracking => _completedDisplayTracking; + @override void didPush(Route route, Route? previousRoute) { super.didPush(route, previousRoute); @@ -108,8 +124,8 @@ class SentryNavigatorObserver extends RouteObserver> { to: route.settings, ); - _finishTransaction(); - _startTransaction(route); + _finishTimeToDisplayTracking(); + _startTimeToDisplayTracking(route); } @override @@ -139,8 +155,7 @@ class SentryNavigatorObserver extends RouteObserver> { to: previousRoute?.settings, ); - _finishTransaction(); - _startTransaction(previousRoute); + _finishTimeToDisplayTracking(); } void _addBreadcrumb({ @@ -152,7 +167,6 @@ class SentryNavigatorObserver extends RouteObserver> { navigationType: type, from: _routeNameExtractor?.call(from) ?? from, to: _routeNameExtractor?.call(to) ?? to, - // ignore: invalid_use_of_internal_member timestamp: _hub.options.clock(), data: _additionalInfoProvider?.call(from, to), )); @@ -179,11 +193,8 @@ class SentryNavigatorObserver extends RouteObserver> { } } - Future _startTransaction(Route? route) async { - if (!_enableAutoTransactions) { - return; - } - + Future _startTransaction( + Route? route, DateTime startTimestamp) async { String? name = _getRouteName(route); final arguments = route?.settings.arguments; @@ -196,14 +207,14 @@ class SentryNavigatorObserver extends RouteObserver> { } final transactionContext = SentryTransactionContext( name, - 'navigation', + SentrySpanOperations.uiLoad, transactionNameSource: SentryTransactionNameSource.component, - // ignore: invalid_use_of_internal_member origin: SentryTraceOrigins.autoNavigationRouteObserver, ); _transaction = _hub.startTransactionWithContext( transactionContext, + startTimestamp: startTimestamp, waitForChildren: true, autoFinishAfter: _autoFinishAfter, trimEnd: true, @@ -242,7 +253,9 @@ class SentryNavigatorObserver extends RouteObserver> { await _native?.beginNativeFramesCollection(); } - Future _finishTransaction() async { + Future _finishTimeToDisplayTracking() async { + _timeToDisplayTracker?.clear(); + final transaction = _transaction; _transaction = null; if (transaction == null || transaction.finished) { @@ -251,6 +264,47 @@ class SentryNavigatorObserver extends RouteObserver> { transaction.status ??= SpanStatus.ok(); await transaction.finish(); } + + Future _startTimeToDisplayTracking(Route? route) async { + if (!_enableAutoTransactions) { + return; + } + + _completedDisplayTracking = Completer(); + String? routeName = _currentRouteName; + if (routeName == null) return; + + DateTime startTimestamp = _hub.options.clock(); + DateTime? endTimestamp; + + if (routeName == '/') { + final appStartInfo = await NativeAppStartIntegration.getAppStartInfo(); + if (appStartInfo == null) { + return; + } + + startTimestamp = appStartInfo.start; + endTimestamp = appStartInfo.end; + } + + await _startTransaction(route, startTimestamp); + final transaction = _transaction; + if (transaction == null) { + return; + } + + if (routeName == '/' && endTimestamp != null) { + await _timeToDisplayTracker?.trackAppStartTTD(transaction, + startTimestamp: startTimestamp, endTimestamp: endTimestamp); + } else { + await _timeToDisplayTracker?.trackRegularRouteTTD(transaction, + startTimestamp: startTimestamp); + } + + // Mark the tracking as completed and clear any temporary state. + _completedDisplayTracking?.complete(); + _timeToDisplayTracker?.clear(); + } } /// This class makes it easier to record breadcrumbs for events of Flutters diff --git a/flutter/lib/src/navigation/time_to_display_tracker.dart b/flutter/lib/src/navigation/time_to_display_tracker.dart new file mode 100644 index 000000000..713bc16ff --- /dev/null +++ b/flutter/lib/src/navigation/time_to_display_tracker.dart @@ -0,0 +1,34 @@ +// ignore_for_file: invalid_use_of_internal_member + +import 'dart:async'; + +import 'package:meta/meta.dart'; + +import '../../sentry_flutter.dart'; +import 'time_to_initial_display_tracker.dart'; + +@internal +class TimeToDisplayTracker { + final TimeToInitialDisplayTracker _ttidTracker; + + TimeToDisplayTracker({ + TimeToInitialDisplayTracker? ttidTracker, + }) : _ttidTracker = ttidTracker ?? TimeToInitialDisplayTracker(); + + Future trackAppStartTTD(ISentrySpan transaction, + {required DateTime startTimestamp, + required DateTime endTimestamp}) async { + // We start and immediately finish the spans since we cannot mutate the history of spans. + await _ttidTracker.trackAppStart(transaction, + startTimestamp: startTimestamp, endTimestamp: endTimestamp); + } + + Future trackRegularRouteTTD(ISentrySpan transaction, + {required DateTime startTimestamp}) async { + await _ttidTracker.trackRegularRoute(transaction, startTimestamp); + } + + void clear() { + _ttidTracker.clear(); + } +} diff --git a/flutter/lib/src/navigation/time_to_initial_display_tracker.dart b/flutter/lib/src/navigation/time_to_initial_display_tracker.dart new file mode 100644 index 000000000..ce2f7b9e9 --- /dev/null +++ b/flutter/lib/src/navigation/time_to_initial_display_tracker.dart @@ -0,0 +1,136 @@ +// ignore_for_file: invalid_use_of_internal_member + +import 'dart:async'; + +import 'package:meta/meta.dart'; + +// ignore: implementation_imports +import 'package:sentry/src/sentry_tracer.dart'; + +import '../../sentry_flutter.dart'; +import '../frame_callback_handler.dart'; + +@internal +class TimeToInitialDisplayTracker { + static final TimeToInitialDisplayTracker _instance = + TimeToInitialDisplayTracker._(); + + factory TimeToInitialDisplayTracker( + {FrameCallbackHandler? frameCallbackHandler}) { + if (frameCallbackHandler != null) { + _instance._frameCallbackHandler = frameCallbackHandler; + } + return _instance; + } + + TimeToInitialDisplayTracker._(); + + FrameCallbackHandler _frameCallbackHandler = DefaultFrameCallbackHandler(); + bool _isManual = false; + Completer? _trackingCompleter; + DateTime? _endTimestamp; + final Duration _determineEndtimeTimeout = Duration(seconds: 5); + + /// This endTimestamp is needed in the [TimeToFullDisplayTracker] class + @internal + DateTime? get endTimestamp => _endTimestamp; + + Future trackRegularRoute( + ISentrySpan transaction, + DateTime startTimestamp, + ) async { + await _trackTimeToInitialDisplay( + transaction: transaction, + startTimestamp: startTimestamp, + ); + } + + Future trackAppStart(ISentrySpan transaction, + {required DateTime startTimestamp, + required DateTime endTimestamp}) async { + await _trackTimeToInitialDisplay( + transaction: transaction, + startTimestamp: startTimestamp, + endTimestamp: endTimestamp, + origin: SentryTraceOrigins.autoUiTimeToDisplay, + ); + + // Store the end timestamp for potential use by TTFD tracking + _endTimestamp = endTimestamp; + } + + Future _trackTimeToInitialDisplay({ + required ISentrySpan transaction, + required DateTime startTimestamp, + DateTime? endTimestamp, + String? origin, + }) async { + final _endTimestamp = endTimestamp ?? await determineEndTime(); + if (_endTimestamp == null) return; + + final tracer = transaction as SentryTracer; + + final ttidSpan = transaction.startChild( + SentrySpanOperations.uiTimeToInitialDisplay, + description: '${tracer.name} initial display', + startTimestamp: startTimestamp, + ); + + ttidSpan.origin = origin ?? + (_isManual + ? SentryTraceOrigins.manualUiTimeToDisplay + : SentryTraceOrigins.autoUiTimeToDisplay); + + final duration = Duration( + milliseconds: _endTimestamp.difference(startTimestamp).inMilliseconds); + final ttidMeasurement = SentryMeasurement.timeToInitialDisplay(duration); + + transaction.setMeasurement(ttidMeasurement.name, ttidMeasurement.value, + unit: ttidMeasurement.unit); + await ttidSpan.finish(endTimestamp: _endTimestamp); + } + + Future? determineEndTime() { + _trackingCompleter = Completer(); + final future = _trackingCompleter?.future.timeout( + _determineEndtimeTimeout, + onTimeout: () { + return Future.value(null); + }, + ); + + // If we already know it's manual we can return the future immediately + if (_isManual) { + return future; + } + + // Schedules a check at the end of the frame to determine if the tracking + // should be completed immediately (approximation mode) or deferred (manual mode). + _frameCallbackHandler.addPostFrameCallback((_) { + if (!_isManual) { + completeTracking(); + } + }); + + return future; + } + + void markAsManual() { + _isManual = true; + } + + void completeTracking() { + if (_trackingCompleter != null && !_trackingCompleter!.isCompleted) { + final endTimestamp = DateTime.now(); + _endTimestamp = endTimestamp; + _trackingCompleter?.complete(endTimestamp); + } + } + + void clear() { + _isManual = false; + _trackingCompleter = null; + // We can't clear the ttid end time stamp here, because it might be needed + // in the [TimeToFullDisplayTracker] class + } +} diff --git a/flutter/test/fake_frame_callback_handler.dart b/flutter/test/fake_frame_callback_handler.dart index 103045d0e..0dc968f22 100644 --- a/flutter/test/fake_frame_callback_handler.dart +++ b/flutter/test/fake_frame_callback_handler.dart @@ -4,16 +4,15 @@ import 'package:sentry_flutter/src/frame_callback_handler.dart'; class FakeFrameCallbackHandler implements FrameCallbackHandler { FrameCallback? storedCallback; - final Duration _finishAfterDuration; + final Duration finishAfterDuration; FakeFrameCallbackHandler( - {Duration finishAfterDuration = const Duration(milliseconds: 500)}) - : _finishAfterDuration = finishAfterDuration; + {this.finishAfterDuration = const Duration(milliseconds: 50)}); @override void addPostFrameCallback(FrameCallback callback) async { // ignore: inference_failure_on_instance_creation - await Future.delayed(_finishAfterDuration); + await Future.delayed(finishAfterDuration); callback(Duration.zero); } } diff --git a/flutter/test/navigation/sentry_display_widget_test.dart b/flutter/test/navigation/sentry_display_widget_test.dart new file mode 100644 index 000000000..6fb61c5b8 --- /dev/null +++ b/flutter/test/navigation/sentry_display_widget_test.dart @@ -0,0 +1,122 @@ +// ignore_for_file: invalid_use_of_internal_member + +import 'package:flutter/material.dart'; +import 'package:flutter_test/flutter_test.dart'; +import 'package:sentry_flutter/sentry_flutter.dart'; +import 'package:sentry/src/sentry_tracer.dart'; +import 'package:sentry_flutter/src/integrations/integrations.dart'; + +import '../fake_frame_callback_handler.dart'; +import '../mocks.dart'; + +void main() { + PageRoute route(RouteSettings? settings) => PageRouteBuilder( + pageBuilder: (_, __, ___) => Container(), + settings: settings, + ); + + late Fixture fixture; + + setUp(() { + fixture = Fixture(); + }); + + testWidgets('SentryDisplayWidget reports manual ttid span after didPush', + (WidgetTester tester) async { + final currentRoute = route(RouteSettings(name: 'Current Route')); + + await tester.runAsync(() async { + fixture.navigatorObserver.didPush(currentRoute, null); + await tester.pumpWidget(fixture.getSut()); + await fixture.navigatorObserver.completedDisplayTracking?.future; + }); + + final tracer = fixture.hub.getSpan() as SentryTracer; + final spans = tracer.children.where((element) => + element.context.operation == + SentrySpanOperations.uiTimeToInitialDisplay); + + expect(spans, hasLength(1)); + + final ttidSpan = spans.first; + expect(ttidSpan.context.operation, + SentrySpanOperations.uiTimeToInitialDisplay); + expect(ttidSpan.finished, isTrue); + expect(ttidSpan.context.description, 'Current Route initial display'); + expect(ttidSpan.origin, SentryTraceOrigins.manualUiTimeToDisplay); + final ttidSpanDuration = + ttidSpan.endTimestamp!.difference(ttidSpan.startTimestamp); + + expect(tracer.measurements, hasLength(1)); + final measurement = tracer.measurements['time_to_initial_display']; + expect(measurement, isNotNull); + expect(measurement?.unit, DurationSentryMeasurementUnit.milliSecond); + expect(measurement?.value, ttidSpanDuration.inMilliseconds); + }); + + testWidgets('SentryDisplayWidget is ignored for app starts', + (WidgetTester tester) async { + final currentRoute = route(RouteSettings(name: '/')); + final appStartInfo = AppStartInfo( + AppStartType.cold, + start: getUtcDateTime().add(Duration(seconds: 1)), + end: getUtcDateTime().add(Duration(seconds: 2)), + ); + NativeAppStartIntegration.setAppStartInfo(appStartInfo); + + await tester.runAsync(() async { + fixture.navigatorObserver.didPush(currentRoute, null); + await tester.pumpWidget(fixture.getSut()); + await fixture.navigatorObserver.completedDisplayTracking?.future; + }); + + final tracer = fixture.hub.getSpan() as SentryTracer; + final spans = tracer.children.where((element) => + element.context.operation == + SentrySpanOperations.uiTimeToInitialDisplay); + + expect(spans, hasLength(1)); + + final ttidSpan = spans.first; + expect(ttidSpan.context.operation, + SentrySpanOperations.uiTimeToInitialDisplay); + expect(ttidSpan.finished, isTrue); + expect(ttidSpan.context.description, 'root ("/") initial display'); + expect(ttidSpan.origin, SentryTraceOrigins.autoUiTimeToDisplay); + + expect(ttidSpan.startTimestamp, appStartInfo.start); + expect(ttidSpan.endTimestamp, appStartInfo.end); + final ttidSpanDuration = + ttidSpan.endTimestamp!.difference(ttidSpan.startTimestamp); + + expect(tracer.measurements, hasLength(1)); + final measurement = tracer.measurements['time_to_initial_display']; + expect(measurement, isNotNull); + expect(measurement?.value, appStartInfo.duration.inMilliseconds); + expect(measurement?.value, ttidSpanDuration.inMilliseconds); + expect(measurement?.unit, DurationSentryMeasurementUnit.milliSecond); + }); +} + +class Fixture { + final Hub hub = + Hub(SentryFlutterOptions(dsn: fakeDsn)..tracesSampleRate = 1.0); + late final SentryNavigatorObserver navigatorObserver; + final fakeFrameCallbackHandler = FakeFrameCallbackHandler(); + + Fixture() { + SentryFlutter.native = TestMockSentryNative(); + navigatorObserver = SentryNavigatorObserver(hub: hub); + } + + MaterialApp getSut() { + return MaterialApp( + home: SentryDisplayWidget( + frameCallbackHandler: FakeFrameCallbackHandler( + finishAfterDuration: Duration(milliseconds: 50), + ), + child: Text('my text'), + ), + ); + } +} diff --git a/flutter/test/navigation/time_to_display_tracker_test.dart b/flutter/test/navigation/time_to_display_tracker_test.dart new file mode 100644 index 000000000..942f9ccb3 --- /dev/null +++ b/flutter/test/navigation/time_to_display_tracker_test.dart @@ -0,0 +1,186 @@ +// ignore_for_file: invalid_use_of_internal_member +// ignore_for_file: inference_failure_on_instance_creation + +import 'package:flutter_test/flutter_test.dart'; +import 'package:sentry_flutter/sentry_flutter.dart'; +import 'package:sentry_flutter/src/frame_callback_handler.dart'; +import 'package:sentry_flutter/src/navigation/time_to_display_tracker.dart'; +import 'package:sentry/src/sentry_tracer.dart'; +import 'package:sentry_flutter/src/navigation/time_to_initial_display_tracker.dart'; + +import '../fake_frame_callback_handler.dart'; +import '../mocks.dart'; + +void main() { + late Fixture fixture; + + setUp(() { + TestWidgetsFlutterBinding.ensureInitialized(); + fixture = Fixture(); + }); + + tearDown(() { + fixture.ttidTracker?.clear(); + }); + + group('time to initial display', () { + group('in root screen app start route', () { + test('matches startTimestamp of transaction', () async { + final sut = fixture.getSut(); + + final transaction = fixture.getTransaction(name: '/') as SentryTracer; + await sut.trackRegularRouteTTD(transaction, + startTimestamp: fixture.startTimestamp); + + final ttidSpan = transaction.children + .where((element) => + element.context.operation == + SentrySpanOperations.uiTimeToInitialDisplay) + .first; + expect(transaction, isNotNull); + expect(transaction.context.operation, SentrySpanOperations.uiLoad); + expect(transaction.startTimestamp, ttidSpan.startTimestamp); + }); + + test('finishes ttid span', () async { + SentryFlutter.native = TestMockSentryNative(); + final sut = fixture.getSut(); + final endTimestamp = + fixture.startTimestamp.add(const Duration(milliseconds: 10)); + + final transaction = fixture.getTransaction(name: '/') as SentryTracer; + await sut.trackAppStartTTD(transaction, + startTimestamp: fixture.startTimestamp, endTimestamp: endTimestamp); + + final ttidSpan = transaction.children + .where((element) => + element.context.operation == + SentrySpanOperations.uiTimeToInitialDisplay) + .first; + expect(ttidSpan.context.operation, + SentrySpanOperations.uiTimeToInitialDisplay); + expect(ttidSpan.finished, isTrue); + expect(ttidSpan.origin, SentryTraceOrigins.autoUiTimeToDisplay); + }); + }); + + group('in regular routes', () { + test('matches startTimestamp of transaction', () async { + final sut = fixture.getSut(); + + final transaction = fixture.getTransaction() as SentryTracer; + await sut.trackRegularRouteTTD(transaction, + startTimestamp: fixture.startTimestamp); + + final ttidSpan = transaction.children + .where((element) => + element.context.operation == + SentrySpanOperations.uiTimeToInitialDisplay) + .first; + expect(transaction, isNotNull); + expect(transaction.context.operation, SentrySpanOperations.uiLoad); + expect(transaction.startTimestamp, ttidSpan.startTimestamp); + }); + + group('with approximation strategy', () { + test('finishes ttid span', () async { + final sut = fixture.getSut(); + + final transaction = fixture.getTransaction() as SentryTracer; + await sut.trackRegularRouteTTD(transaction, + startTimestamp: fixture.startTimestamp); + + final ttidSpan = transaction.children + .where((element) => + element.context.operation == + SentrySpanOperations.uiTimeToInitialDisplay) + .first; + expect(ttidSpan.context.operation, + SentrySpanOperations.uiTimeToInitialDisplay); + expect(ttidSpan.finished, isTrue); + expect(ttidSpan.origin, SentryTraceOrigins.autoUiTimeToDisplay); + }); + + test('completes with timeout when not completing the tracking', + () async { + final sut = fixture.getSut(triggerApproximationTimeout: true); + + final transaction = fixture.getTransaction() as SentryTracer; + await sut.trackRegularRouteTTD(transaction, + startTimestamp: fixture.startTimestamp); + }); + }); + + group('with manual strategy', () { + test('finishes ttid span', () async { + final sut = fixture.getSut(); + + Future.delayed(const Duration(milliseconds: 1), () { + fixture.ttidTracker?.markAsManual(); + fixture.ttidTracker?.completeTracking(); + }); + final transaction = fixture.getTransaction() as SentryTracer; + await sut.trackRegularRouteTTD(transaction, + startTimestamp: fixture.startTimestamp); + + final ttidSpan = transaction.children + .where((element) => + element.context.operation == + SentrySpanOperations.uiTimeToInitialDisplay) + .first; + expect(ttidSpan, isNotNull); + expect(ttidSpan.finished, isTrue); + expect(ttidSpan.origin, SentryTraceOrigins.manualUiTimeToDisplay); + }); + + test('completes with timeout when not completing the tracking', + () async { + final sut = fixture.getSut(); + + fixture.ttidTracker?.markAsManual(); + // Not calling completeTracking() triggers the manual timeout + + final transaction = fixture.getTransaction() as SentryTracer; + await sut.trackRegularRouteTTD(transaction, + startTimestamp: fixture.startTimestamp); + }); + }); + }); + }); + + test('screen load tracking creates ui.load transaction', () async { + final sut = fixture.getSut(); + + final transaction = fixture.getTransaction() as SentryTracer; + await sut.trackRegularRouteTTD(transaction, + startTimestamp: fixture.startTimestamp); + + expect(transaction, isNotNull); + expect(transaction.context.operation, SentrySpanOperations.uiLoad); + }); +} + +class Fixture { + final startTimestamp = getUtcDateTime(); + final options = SentryFlutterOptions() + ..dsn = fakeDsn + ..tracesSampleRate = 1.0; + + late final hub = Hub(options); + TimeToInitialDisplayTracker? ttidTracker; + + ISentrySpan getTransaction({String? name = "Current route"}) { + return hub.startTransaction(name!, 'ui.load', + startTimestamp: startTimestamp); + } + + TimeToDisplayTracker getSut({bool triggerApproximationTimeout = false}) { + ttidTracker = TimeToInitialDisplayTracker( + frameCallbackHandler: triggerApproximationTimeout + ? DefaultFrameCallbackHandler() + : FakeFrameCallbackHandler()); + return TimeToDisplayTracker( + ttidTracker: ttidTracker, + ); + } +} diff --git a/flutter/test/navigation/time_to_initial_display_tracker_test.dart b/flutter/test/navigation/time_to_initial_display_tracker_test.dart new file mode 100644 index 000000000..6e5502957 --- /dev/null +++ b/flutter/test/navigation/time_to_initial_display_tracker_test.dart @@ -0,0 +1,201 @@ +// ignore_for_file: invalid_use_of_internal_member + +import 'package:flutter_test/flutter_test.dart'; +import 'package:sentry_flutter/sentry_flutter.dart'; +import 'package:sentry_flutter/src/frame_callback_handler.dart'; +import 'package:sentry_flutter/src/navigation/time_to_initial_display_tracker.dart'; + +import '../fake_frame_callback_handler.dart'; +import '../mocks.dart'; +import 'package:sentry/src/sentry_tracer.dart'; + +void main() { + late Fixture fixture; + late TimeToInitialDisplayTracker sut; + + setUp(() { + fixture = Fixture(); + sut = fixture.getSut(); + }); + + tearDown(() { + sut.clear(); + }); + + group('app start', () { + test('tracking creates and finishes ttid span with correct measurements', + () async { + final endTimestamp = + fixture.startTimestamp.add(const Duration(milliseconds: 10)); + + final transaction = + fixture.getTransaction(name: 'root ("/")') as SentryTracer; + await sut.trackAppStart(transaction, + startTimestamp: fixture.startTimestamp, endTimestamp: endTimestamp); + + 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, 'root ("/") initial display'); + expect(ttidSpan.origin, SentryTraceOrigins.autoUiTimeToDisplay); + expect(ttidSpan.startTimestamp, fixture.startTimestamp); + expect(ttidSpan.endTimestamp, endTimestamp); + + final ttidMeasurement = + transaction.measurements['time_to_initial_display']; + expect(ttidMeasurement, isNotNull); + expect(ttidMeasurement?.unit, DurationSentryMeasurementUnit.milliSecond); + expect( + ttidMeasurement?.value, + ttidSpan.endTimestamp! + .difference(ttidSpan.startTimestamp) + .inMilliseconds); + }); + }); + + group('regular route', () { + test( + 'approximation tracking creates and finishes ttid span with correct measurements', + () async { + 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.autoUiTimeToDisplay); + + 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); + }); + + test( + 'manual tracking creates and finishes ttid span with correct measurements', + () async { + sut.markAsManual(); + Future.delayed(fixture.finishFrameDuration, () { + 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', () { + test('can complete as null in approximation mode with timeout', () async { + final futureEndTime = await fixture + .getSut(triggerApproximationTimeout: true) + .determineEndTime(); + + expect(futureEndTime, null); + }); + + test('can complete as null in manual mode with timeout', () async { + final sut = fixture.getSut(); + sut.markAsManual(); + // Not calling completeTracking() triggers the manual timeout + + final futureEndTime = await sut.determineEndTime(); + + expect(futureEndTime, null); + }); + + test('can complete automatically in approximation mode', () async { + final futureEndTime = await sut.determineEndTime(); + + expect(futureEndTime, isNotNull); + }); + + test('can complete manually in manual mode', () async { + sut.markAsManual(); + Future.delayed(Duration(milliseconds: 1), () { + sut.completeTracking(); + }); + final futureEndTime = await sut.determineEndTime(); + + expect(futureEndTime, isNotNull); + }); + + test('returns the correct approximation end time', () async { + final endTme = await sut.determineEndTime(); + + expect(endTme?.difference(fixture.startTimestamp).inSeconds, + fixture.finishFrameDuration.inSeconds); + }); + + test('returns the correct manual end time', () async { + sut.markAsManual(); + Future.delayed(fixture.finishFrameDuration, () { + sut.completeTracking(); + }); + + final endTime = await sut.determineEndTime(); + + expect(endTime?.difference(fixture.startTimestamp).inSeconds, + fixture.finishFrameDuration.inSeconds); + }); + }); +} + +class Fixture { + final startTimestamp = getUtcDateTime(); + final hub = Hub(SentryFlutterOptions(dsn: fakeDsn)..tracesSampleRate = 1.0); + late final fakeFrameCallbackHandler = FakeFrameCallbackHandler(); + + ISentrySpan getTransaction({String? name = "Regular route"}) { + return hub.startTransaction(name!, 'ui.load', + bindToScope: true, startTimestamp: startTimestamp); + } + + /// The time it takes until a fake frame has been triggered + Duration get finishFrameDuration => + fakeFrameCallbackHandler.finishAfterDuration; + + TimeToInitialDisplayTracker getSut( + {bool triggerApproximationTimeout = false}) { + return TimeToInitialDisplayTracker( + frameCallbackHandler: triggerApproximationTimeout + ? DefaultFrameCallbackHandler() + : FakeFrameCallbackHandler()); + } +} diff --git a/flutter/test/sentry_navigator_observer_test.dart b/flutter/test/sentry_navigator_observer_test.dart index aca9646c0..5a7528d90 100644 --- a/flutter/test/sentry_navigator_observer_test.dart +++ b/flutter/test/sentry_navigator_observer_test.dart @@ -5,9 +5,13 @@ import 'package:flutter/widgets.dart'; import 'package:flutter_test/flutter_test.dart'; import 'package:mockito/mockito.dart'; import 'package:sentry_flutter/sentry_flutter.dart'; +import 'package:sentry_flutter/src/integrations/integrations.dart'; import 'package:sentry_flutter/src/native/sentry_native.dart'; import 'package:sentry/src/sentry_tracer.dart'; +import 'package:sentry_flutter/src/navigation/time_to_display_tracker.dart'; +import 'package:sentry_flutter/src/navigation/time_to_initial_display_tracker.dart'; +import 'fake_frame_callback_handler.dart'; import 'mocks.dart'; import 'mocks.mocks.dart'; @@ -30,10 +34,12 @@ void main() { customSamplingContext: anyNamed('customSamplingContext'), startTimestamp: anyNamed('startTimestamp'), )).thenReturn(thenReturnSpan); + when(mockHub.getSpan()).thenReturn(thenReturnSpan); } setUp(() { fixture = Fixture(); + WidgetsFlutterBinding.ensureInitialized(); }); group('NativeFrames', () { @@ -55,6 +61,12 @@ void main() { final tracer = getMockSentryTracer(); _whenAnyStart(mockHub, tracer); + when(tracer.startChild('ui.load.initial_display', + description: anyNamed('description'), + startTimestamp: anyNamed('startTimestamp'))) + .thenReturn(NoOpSentrySpan()); + when(tracer.finished).thenReturn(false); + when(tracer.status).thenReturn(SpanStatus.ok()); final sut = fixture.getSut(hub: mockHub); @@ -73,13 +85,14 @@ void main() { options.tracesSampleRate = 1; final hub = Hub(options); + mockNativeChannel = MockNativeChannel(); + SentryFlutter.native = + SentryNative(SentryFlutterOptions(dsn: fakeDsn), mockNativeChannel); + final nativeFrames = NativeFrames(3, 2, 1); mockNativeChannel.nativeFrames = nativeFrames; - final sut = fixture.getSut( - hub: hub, - autoFinishAfter: Duration(milliseconds: 50), - ); + final sut = fixture.getSut(hub: hub); sut.didPush(currentRoute, null); @@ -91,13 +104,15 @@ void main() { actualTransaction = scope.span as SentryTracer; }); - await Future.delayed(Duration(milliseconds: 500)); + await sut.completedDisplayTracking?.future; + + await Future.delayed(Duration(milliseconds: 1500)); expect(mockNativeChannel.numberOfEndNativeFramesCalls, 1); final measurements = actualTransaction?.measurements ?? {}; - expect(measurements.length, 3); + expect(measurements.length, 4); final expectedTotal = SentryMeasurement.totalFrames(3); final expectedSlow = SentryMeasurement.slowFrames(2); @@ -117,15 +132,21 @@ void main() { }); group('$SentryNavigatorObserver', () { - test('didPush starts transaction', () { + test('didPush starts transaction', () async { const name = 'Current Route'; final currentRoute = route(RouteSettings(name: name)); - const op = 'navigation'; + const op = 'ui.load'; final hub = _MockHub(); final span = getMockSentryTracer(name: name); when(span.context).thenReturn(SentrySpanContext(operation: op)); _whenAnyStart(hub, span); + when(span.finished).thenReturn(false); + when(span.status).thenReturn(SpanStatus.ok()); + when(span.startChild('ui.load.initial_display', + description: anyNamed('description'), + startTimestamp: anyNamed('startTimestamp'))) + .thenReturn(NoOpSentrySpan()); final sut = fixture.getSut( hub: hub, @@ -136,6 +157,7 @@ void main() { final context = verify(hub.startTransactionWithContext( captureAny, + startTimestamp: anyNamed('startTimestamp'), waitForChildren: true, autoFinishAfter: anyNamed('autoFinishAfter'), trimEnd: true, @@ -157,6 +179,7 @@ void main() { final span = NoOpSentrySpan(); _whenAnyStart(hub, span); + when(hub.getSpan()).thenReturn(null); final sut = fixture.getSut( hub: hub, @@ -167,6 +190,7 @@ void main() { verify(hub.startTransactionWithContext( any, + startTimestamp: anyNamed('startTimestamp'), waitForChildren: true, autoFinishAfter: Duration(seconds: 5), trimEnd: true, @@ -185,6 +209,8 @@ void main() { final hub = _MockHub(); final span = getMockSentryTracer(); when(span.context).thenReturn(SentrySpanContext(operation: 'op')); + when(span.finished).thenReturn(false); + when(span.status).thenReturn(SpanStatus.ok()); _whenAnyStart(hub, span); final sut = fixture.getSut(hub: hub); @@ -193,6 +219,7 @@ void main() { verifyNever(hub.startTransactionWithContext( any, + startTimestamp: anyNamed('startTimestamp'), waitForChildren: true, autoFinishAfter: anyNamed('autoFinishAfter'), trimEnd: true, @@ -211,6 +238,8 @@ void main() { final span = getMockSentryTracer(); when(span.context).thenReturn(SentrySpanContext(operation: 'op')); _whenAnyStart(hub, span); + when(span.finished).thenReturn(false); + when(span.status).thenReturn(SpanStatus.ok()); final sut = fixture.getSut(hub: hub, enableAutoTransactions: false); @@ -218,6 +247,7 @@ void main() { verifyNever(hub.startTransactionWithContext( any, + startTimestamp: anyNamed('startTimestamp'), waitForChildren: true, autoFinishAfter: anyNamed('autoFinishAfter'), trimEnd: true, @@ -237,6 +267,12 @@ void main() { final span = getMockSentryTracer(); when(span.context).thenReturn(SentrySpanContext(operation: 'op')); + when(span.finished).thenReturn(false); + when(span.status).thenReturn(SpanStatus.ok()); + when(span.startChild('ui.load.initial_display', + description: anyNamed('description'), + startTimestamp: anyNamed('startTimestamp'))) + .thenReturn(NoOpSentrySpan()); _whenAnyStart(hub, span); final sut = fixture.getSut(hub: hub); @@ -245,6 +281,7 @@ void main() { verify(hub.startTransactionWithContext( any, + startTimestamp: anyNamed('startTimestamp'), waitForChildren: true, autoFinishAfter: anyNamed('autoFinishAfter'), trimEnd: true, @@ -256,7 +293,7 @@ void main() { }); }); - test('didPush finishes previous transaction', () { + test('didPush finishes previous transaction', () async { final firstRoute = route(RouteSettings(name: 'First Route')); final secondRoute = route(RouteSettings(name: 'Second Route')); @@ -264,6 +301,11 @@ void main() { final span = getMockSentryTracer(finished: false); when(span.context).thenReturn(SentrySpanContext(operation: 'op')); when(span.status).thenReturn(null); + when(span.finished).thenReturn(false); + when(span.startChild('ui.load.initial_display', + description: anyNamed('description'), + startTimestamp: anyNamed('startTimestamp'))) + .thenReturn(NoOpSentrySpan()); _whenAnyStart(hub, span); final sut = fixture.getSut(hub: hub); @@ -282,6 +324,11 @@ void main() { final span = getMockSentryTracer(finished: false); when(span.context).thenReturn(SentrySpanContext(operation: 'op')); when(span.status).thenReturn(null); + when(span.finished).thenReturn(false); + when(span.startChild('ui.load.initial_display', + description: anyNamed('description'), + startTimestamp: anyNamed('startTimestamp'))) + .thenReturn(NoOpSentrySpan()); _whenAnyStart(hub, span); final sut = fixture.getSut(hub: hub); @@ -305,40 +352,13 @@ void main() { final sut = fixture.getSut(hub: hub); sut.didPush(currentRoute, null); + sut.didPop(currentRoute, null); sut.didPop(currentRoute, null); verify(span.finish()).called(1); }); - test('didPop re-starts previous', () { - final previousRoute = route(RouteSettings(name: 'Previous Route')); - final currentRoute = route(RouteSettings(name: 'Current Route')); - - final hub = _MockHub(); - final previousSpan = getMockSentryTracer(); - when(previousSpan.context).thenReturn(SentrySpanContext(operation: 'op')); - when(previousSpan.status).thenReturn(null); - - _whenAnyStart(hub, previousSpan); - - final sut = fixture.getSut(hub: hub); - - sut.didPop(currentRoute, previousRoute); - - verify(hub.startTransactionWithContext( - any, - waitForChildren: true, - autoFinishAfter: anyNamed('autoFinishAfter'), - trimEnd: true, - onFinish: anyNamed('onFinish'), - )); - - hub.configureScope((scope) { - expect(scope.span, previousSpan); - }); - }); - test('route arguments are set on transaction', () { final arguments = {'foo': 'bar'}; final currentRoute = route(RouteSettings( @@ -350,6 +370,11 @@ void main() { final span = getMockSentryTracer(); when(span.context).thenReturn(SentrySpanContext(operation: 'op')); when(span.status).thenReturn(null); + when(span.finished).thenReturn(false); + when(span.startChild('ui.load.initial_display', + description: anyNamed('description'), + startTimestamp: anyNamed('startTimestamp'))) + .thenReturn(NoOpSentrySpan()); _whenAnyStart(hub, span); final sut = fixture.getSut(hub: hub); @@ -359,21 +384,37 @@ void main() { verify(span.setData('route_settings_arguments', arguments)); }); - test('flutter root name is replaced', () { + test('flutter root name is replaced', () async { final rootRoute = route(RouteSettings(name: '/')); + NativeAppStartIntegration.setAppStartInfo( + AppStartInfo( + AppStartType.cold, + start: DateTime.now().add(const Duration(seconds: 1)), + end: DateTime.now().add(const Duration(seconds: 2)), + ), + ); final hub = _MockHub(); final span = getMockSentryTracer(name: '/'); when(span.context).thenReturn(SentrySpanContext(operation: 'op')); + when(span.finished).thenReturn(false); + when(span.status).thenReturn(SpanStatus.ok()); + when(span.startChild('ui.load.initial_display', + description: anyNamed('description'), + startTimestamp: anyNamed('startTimestamp'))) + .thenReturn(NoOpSentrySpan()); _whenAnyStart(hub, span); final sut = fixture.getSut(hub: hub); sut.didPush(rootRoute, null); + await Future.delayed(const Duration(milliseconds: 100)); + final context = verify(hub.startTransactionWithContext( captureAny, waitForChildren: true, + startTimestamp: anyNamed('startTimestamp'), autoFinishAfter: anyNamed('autoFinishAfter'), trimEnd: true, onFinish: anyNamed('onFinish'), @@ -394,6 +435,12 @@ void main() { final hub = _MockHub(); final span = getMockSentryTracer(name: name); when(span.context).thenReturn(SentrySpanContext(operation: op)); + when(span.finished).thenReturn(false); + when(span.status).thenReturn(SpanStatus.ok()); + when(span.startChild('ui.load.initial_display', + description: anyNamed('description'), + startTimestamp: anyNamed('startTimestamp'))) + .thenReturn(NoOpSentrySpan()); _whenAnyStart(hub, span); final sut = fixture.getSut( @@ -416,6 +463,12 @@ void main() { final hub = _MockHub(); final span = getMockSentryTracer(name: oldRouteName); when(span.context).thenReturn(SentrySpanContext(operation: op)); + when(span.finished).thenReturn(false); + when(span.status).thenReturn(SpanStatus.ok()); + when(span.startChild('ui.load.initial_display', + description: anyNamed('description'), + startTimestamp: anyNamed('startTimestamp'))) + .thenReturn(NoOpSentrySpan()); _whenAnyStart(hub, span); final sut = fixture.getSut( @@ -440,6 +493,11 @@ void main() { final span = getMockSentryTracer(name: oldRouteName); when(span.context).thenReturn(SentrySpanContext(operation: op)); when(span.status).thenReturn(null); + when(span.finished).thenReturn(false); + when(span.startChild('ui.load.initial_display', + description: anyNamed('description'), + startTimestamp: anyNamed('startTimestamp'))) + .thenReturn(NoOpSentrySpan()); _whenAnyStart(hub, span); final sut = fixture.getSut( @@ -659,6 +717,7 @@ void main() { final hub = _MockHub(); final observer = fixture.getSut(hub: hub); + when(hub.getSpan()).thenReturn(NoOpSentrySpan()); final to = route(); final previous = route(); @@ -818,11 +877,17 @@ class Fixture { SentryNavigatorObserver getSut({ required Hub hub, bool enableAutoTransactions = true, - Duration autoFinishAfter = const Duration(seconds: 3), + Duration autoFinishAfter = const Duration(seconds: 1), bool setRouteNameAsTransaction = false, RouteNameExtractor? routeNameExtractor, AdditionalInfoExtractor? additionalInfoProvider, }) { + final frameCallbackHandler = FakeFrameCallbackHandler(); + final timeToInitialDisplayTracker = + TimeToInitialDisplayTracker(frameCallbackHandler: frameCallbackHandler); + final timeToDisplayTracker = TimeToDisplayTracker( + ttidTracker: timeToInitialDisplayTracker, + ); return SentryNavigatorObserver( hub: hub, enableAutoTransactions: enableAutoTransactions, @@ -830,6 +895,7 @@ class Fixture { setRouteNameAsTransaction: setRouteNameAsTransaction, routeNameExtractor: routeNameExtractor, additionalInfoProvider: additionalInfoProvider, + timeToDisplayTracker: timeToDisplayTracker, ); }