diff --git a/dart/lib/sentry.dart b/dart/lib/sentry.dart index 5419aa45b8..f416d0b797 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_span_operations.dart b/dart/lib/src/sentry_span_operations.dart new file mode 100644 index 0000000000..27b1d22496 --- /dev/null +++ b/dart/lib/src/sentry_span_operations.dart @@ -0,0 +1,8 @@ +import 'package:meta/meta.dart'; + +@internal +class SentrySpanOperations { + static const String uiLoad = 'ui.load'; + static const String uiTimeToInitialDisplay = 'ui.load.initial_display'; + static const String uiTimeToFullDisplay = 'ui.load.full_display'; +} diff --git a/dart/lib/src/sentry_trace_origins.dart b/dart/lib/src/sentry_trace_origins.dart index 5a7c49b339..4377fa2c03 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/dart/lib/src/sentry_tracer.dart b/dart/lib/src/sentry_tracer.dart index 6012a13bfb..56be03a690 100644 --- a/dart/lib/src/sentry_tracer.dart +++ b/dart/lib/src/sentry_tracer.dart @@ -109,18 +109,24 @@ class SentryTracer extends ISentrySpan { } var _rootEndTimestamp = commonEndTimestamp; + + // Trim the end timestamp of the transaction to the very last timestamp of child spans if (_trimEnd && children.isNotEmpty) { - final childEndTimestamps = children - .where((child) => child.endTimestamp != null) - .map((child) => child.endTimestamp!); - - if (childEndTimestamps.isNotEmpty) { - final oldestChildEndTimestamp = - childEndTimestamps.reduce((a, b) => a.isAfter(b) ? a : b); - if (_rootEndTimestamp.isAfter(oldestChildEndTimestamp)) { - _rootEndTimestamp = oldestChildEndTimestamp; + DateTime? latestEndTime; + + for (var child in children) { + final childEndTimestamp = child.endTimestamp; + if (childEndTimestamp != null) { + if (latestEndTime == null || + childEndTimestamp.isAfter(latestEndTime)) { + latestEndTime = child.endTimestamp; + } } } + + if (latestEndTime != null) { + _rootEndTimestamp = latestEndTime; + } } // the callback should run before because if the span is finished, @@ -362,7 +368,8 @@ class SentryTracer extends ISentrySpan { Dsn.parse(_hub.options.dsn!).publicKey, release: _hub.options.release, environment: _hub.options.environment, - userId: null, // because of PII not sending it for now + userId: null, + // because of PII not sending it for now userSegment: user?.segment, transaction: _isHighQualityTransactionName(transactionNameSource) ? name : null, diff --git a/flutter/example/lib/auto_close_screen.dart b/flutter/example/lib/auto_close_screen.dart index 15e8fac1fb..7caa09a836 100644 --- a/flutter/example/lib/auto_close_screen.dart +++ b/flutter/example/lib/auto_close_screen.dart @@ -1,5 +1,6 @@ import 'package:flutter/material.dart'; import 'package:sentry/sentry.dart'; +import 'package:sentry_flutter/sentry_flutter.dart'; /// This screen is only used to demonstrate how route navigation works. /// Init will create a child span and pop the screen after 3 seconds. @@ -25,9 +26,10 @@ class AutoCloseScreenState extends State { final childSpan = activeSpan?.startChild('complex operation', description: 'running a $delayInSeconds seconds operation'); await Future.delayed(const Duration(seconds: delayInSeconds)); - childSpan?.finish(); + await childSpan?.finish(); + SentryFlutter.reportFullyDisplayed(); // ignore: use_build_context_synchronously - Navigator.of(context).pop(); + // Navigator.of(context).pop(); } @override diff --git a/flutter/example/lib/main.dart b/flutter/example/lib/main.dart index 55b9072394..6c6a2b5815 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'; @@ -71,10 +72,13 @@ Future setupSentry(AppRunner appRunner, String dsn, options.attachScreenshot = true; options.screenshotQuality = SentryScreenshotQuality.low; options.attachViewHierarchy = true; + options.enableTimeToFullDisplayTracing = false; + options.spotlight = Spotlight(enabled: true); // We can enable Sentry debug logging during development. This is likely // 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.enableTimeToFullDisplayTracing = true; options.maxRequestBodySize = MaxRequestBodySize.always; options.maxResponseBodySize = MaxResponseBodySize.always; @@ -98,6 +102,16 @@ class MyApp extends StatefulWidget { } class _MyAppState extends State { + @override + void initState() { + super.initState(); + // Example of reporting TTFD + Future.delayed( + const Duration(seconds: 1), + () => SentryFlutter.reportFullyDisplayed(), + ); + } + @override Widget build(BuildContext context) { return feedback.BetterFeedback( @@ -719,9 +733,10 @@ void navigateToAutoCloseScreen(BuildContext context) { Navigator.push( context, MaterialPageRoute( - settings: const RouteSettings(name: 'AutoCloseScreen'), - builder: (context) => const AutoCloseScreen(), - ), + settings: const RouteSettings(name: 'AutoCloseScreen'), + builder: (context) => SentryDisplayWidget( + child: const AutoCloseScreen(), + )), ); } @@ -838,7 +853,11 @@ int loop(int val) { } class SecondaryScaffold extends StatelessWidget { - const SecondaryScaffold({Key? key}) : super(key: key); + SecondaryScaffold({Key? key}) : super(key: key) { + Timer(const Duration(milliseconds: 500), () { + SentryFlutter.reportFullyDisplayed(); + }); + } static Future openSecondaryScaffold(BuildContext context) { return Navigator.push( @@ -847,7 +866,7 @@ class SecondaryScaffold extends StatelessWidget { settings: const RouteSettings(name: 'SecondaryScaffold', arguments: 'foobar'), builder: (context) { - return const SecondaryScaffold(); + return SecondaryScaffold(); }, ), ); diff --git a/flutter/lib/sentry_flutter.dart b/flutter/lib/sentry_flutter.dart index 0f43bf741b..d15c8b7a70 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/event_processor/native_app_start_event_processor.dart b/flutter/lib/src/event_processor/native_app_start_event_processor.dart index a7abe62e05..d438d098e3 100644 --- a/flutter/lib/src/event_processor/native_app_start_event_processor.dart +++ b/flutter/lib/src/event_processor/native_app_start_event_processor.dart @@ -2,57 +2,34 @@ import 'dart:async'; import 'package:sentry/sentry.dart'; -import '../native/sentry_native.dart'; +import '../../sentry_flutter.dart'; +import '../integrations/app_start/app_start_tracker.dart'; /// EventProcessor that enriches [SentryTransaction] objects with app start /// measurement. class NativeAppStartEventProcessor implements EventProcessor { - /// We filter out App starts more than 60s - static const _maxAppStartMillis = 60000; + final AppStartTracker? _appStartTracker; - NativeAppStartEventProcessor( - this._native, - ); + NativeAppStartEventProcessor({ + AppStartTracker? appStartTracker, + }) : _appStartTracker = appStartTracker ?? AppStartTracker(); - final SentryNative _native; + bool _didAddAppStartMeasurement = false; @override Future apply(SentryEvent event, {Hint? hint}) async { - final appStartEnd = _native.appStartEnd; - - if (appStartEnd != null && - event is SentryTransaction && - !_native.didFetchAppStart) { - final nativeAppStart = await _native.fetchNativeAppStart(); - if (nativeAppStart == null) { - return event; - } - final measurement = nativeAppStart.toMeasurement(appStartEnd); - // We filter out app start more than 60s. - // This could be due to many different reasons. - // If you do the manual init and init the SDK too late and it does not - // compute the app start end in the very first Screen. - // If the process starts but the App isn't in the foreground. - // If the system forked the process earlier to accelerate the app start. - // And some unknown reasons that could not be reproduced. - // We've seen app starts with hours, days and even months. - if (measurement.value >= _maxAppStartMillis) { - return event; - } + if (!_didAddAppStartMeasurement || event is! SentryTransaction) { + return event; + } + + final appStartInfo = await _appStartTracker?.getAppStartInfo(); + final measurement = appStartInfo?.measurement; + + if (measurement != null) { event.measurements[measurement.name] = measurement; + _didAddAppStartMeasurement = true; } return event; } } -extension NativeAppStartMeasurement on NativeAppStart { - SentryMeasurement toMeasurement(DateTime appStartEnd) { - final appStartDateTime = - DateTime.fromMillisecondsSinceEpoch(appStartTime.toInt()); - final duration = appStartEnd.difference(appStartDateTime); - - return isColdStart - ? SentryMeasurement.coldAppStart(duration) - : SentryMeasurement.warmAppStart(duration); - } -} diff --git a/flutter/lib/src/frame_callback_handler.dart b/flutter/lib/src/frame_callback_handler.dart new file mode 100644 index 0000000000..4c02a0a7a4 --- /dev/null +++ b/flutter/lib/src/frame_callback_handler.dart @@ -0,0 +1,13 @@ +import 'package:flutter/scheduler.dart'; +import 'package:flutter/widgets.dart'; + +abstract class FrameCallbackHandler { + void addPostFrameCallback(FrameCallback callback); +} + +class DefaultFrameCallbackHandler implements FrameCallbackHandler { + @override + void addPostFrameCallback(FrameCallback callback) { + WidgetsBinding.instance.addPostFrameCallback(callback); + } +} diff --git a/flutter/lib/src/integrations/app_start/app_start_tracker.dart b/flutter/lib/src/integrations/app_start/app_start_tracker.dart new file mode 100644 index 0000000000..9bbead7945 --- /dev/null +++ b/flutter/lib/src/integrations/app_start/app_start_tracker.dart @@ -0,0 +1,39 @@ +import 'dart:async'; + +import 'package:meta/meta.dart'; + +import '../../../sentry_flutter.dart'; + +@internal +class AppStartInfo { + final DateTime start; + final DateTime end; + final SentryMeasurement measurement; + + AppStartInfo(this.start, this.end, this.measurement); +} + +@internal +class AppStartTracker { + static final AppStartTracker _instance = AppStartTracker._(); + factory AppStartTracker() => _instance; + AppStartTracker._(); + + Completer _appStartCompleter = Completer(); + AppStartInfo? _appStartInfo; + + void setAppStartInfo(AppStartInfo? appStartInfo) { + _appStartInfo = appStartInfo; + if (!_appStartCompleter.isCompleted) { + _appStartCompleter = Completer(); + } + _appStartCompleter.complete(appStartInfo); + } + + Future getAppStartInfo() { + if (_appStartInfo != null) { + return Future.value(_appStartInfo); + } + return _appStartCompleter.future; + } +} diff --git a/flutter/lib/src/integrations/native_app_start_integration.dart b/flutter/lib/src/integrations/native_app_start_integration.dart index 47bf79dff4..c7472ce2d2 100644 --- a/flutter/lib/src/integrations/native_app_start_integration.dart +++ b/flutter/lib/src/integrations/native_app_start_integration.dart @@ -1,17 +1,26 @@ import 'package:flutter/scheduler.dart'; +import 'package:meta/meta.dart'; import 'package:sentry/sentry.dart'; +import '../../sentry_flutter.dart'; import '../sentry_flutter_options.dart'; import '../native/sentry_native.dart'; import '../event_processor/native_app_start_event_processor.dart'; +import 'app_start/app_start_tracker.dart'; /// Integration which handles communication with native frameworks in order to /// enrich [SentryTransaction] objects with app start data for mobile vitals. class NativeAppStartIntegration extends Integration { - NativeAppStartIntegration(this._native, this._schedulerBindingProvider); + NativeAppStartIntegration(this._native, this._schedulerBindingProvider, + {AppStartTracker? appStartTracker}) + : _appStartTracker = appStartTracker ?? AppStartTracker(); final SentryNative _native; final SchedulerBindingProvider _schedulerBindingProvider; + final AppStartTracker? _appStartTracker; + + /// We filter out App starts more than 60s + static const _maxAppStartMillis = 60000; @override void call(Hub hub, SentryFlutterOptions options) { @@ -21,14 +30,48 @@ class NativeAppStartIntegration extends Integration { options.logger(SentryLevel.debug, 'Scheduler binding is null. Can\'t auto detect app start time.'); } else { - schedulerBinding.addPostFrameCallback((timeStamp) { + schedulerBinding.addPostFrameCallback((timeStamp) async { // ignore: invalid_use_of_internal_member - _native.appStartEnd = options.clock(); + final appStartEnd = options.clock(); + _native.appStartEnd = appStartEnd; + + if (_native.didFetchAppStart) { + _appStartTracker?.setAppStartInfo(null); + return; + } + + final nativeAppStart = await _native.fetchNativeAppStart(); + final measurement = nativeAppStart?.toMeasurement(appStartEnd); + + // We filter out app start more than 60s. + // This could be due to many different reasons. + // If you do the manual init and init the SDK too late and it does not + // compute the app start end in the very first Screen. + // If the process starts but the App isn't in the foreground. + // If the system forked the process earlier to accelerate the app start. + // And some unknown reasons that could not be reproduced. + // We've seen app starts with hours, days and even months. + if (nativeAppStart == null || + measurement == null || + measurement.value > _maxAppStartMillis) { + _appStartTracker?.setAppStartInfo(null); + return; + } + + final appStartInfo = AppStartInfo( + DateTime.fromMillisecondsSinceEpoch( + nativeAppStart.appStartTime.toInt()), + appStartEnd, + measurement, + ); + + _appStartTracker?.setAppStartInfo(appStartInfo); }); } } - options.addEventProcessor(NativeAppStartEventProcessor(_native)); + options.addEventProcessor( + NativeAppStartEventProcessor(appStartTracker: _appStartTracker)); options.sdk.addIntegration('nativeAppStartIntegration'); } @@ -36,3 +79,15 @@ class NativeAppStartIntegration extends Integration { /// Used to provide scheduler binding at call time. typedef SchedulerBindingProvider = SchedulerBinding? Function(); + +extension NativeAppStartMeasurement on NativeAppStart { + SentryMeasurement toMeasurement(DateTime appStartEnd) { + final appStartDateTime = + DateTime.fromMillisecondsSinceEpoch(appStartTime.toInt()); + final duration = appStartEnd.difference(appStartDateTime); + + return isColdStart + ? 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 0000000000..ffed11cce7 --- /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 [WidgetsBinding.instance.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, + 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 b24f4f0c7b..9c27210de3 100644 --- a/flutter/lib/src/navigation/sentry_navigator_observer.dart +++ b/flutter/lib/src/navigation/sentry_navigator_observer.dart @@ -1,9 +1,14 @@ +import 'dart:async'; + +import 'package:flutter/material.dart'; import 'package:flutter/widgets.dart'; import 'package:meta/meta.dart'; +import 'time_to_display_transaction_handler.dart'; import '../../sentry_flutter.dart'; import '../event_processor/flutter_enricher_event_processor.dart'; import '../native/sentry_native.dart'; +import 'time_to_display_tracker.dart'; /// This key must be used so that the web interface displays the events nicely /// See https://develop.sentry.dev/sdk/event-payloads/breadcrumbs/ @@ -19,6 +24,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) and Time to Full Display (TTFD). +/// /// [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 @@ -66,34 +73,52 @@ class SentryNavigatorObserver extends RouteObserver> { bool setRouteNameAsTransaction = false, RouteNameExtractor? routeNameExtractor, AdditionalInfoExtractor? additionalInfoProvider, + @internal TimeToDisplayTracker? timeToDisplayTracker, }) : _hub = hub ?? HubAdapter(), - _enableAutoTransactions = enableAutoTransactions, - _autoFinishAfter = autoFinishAfter, _setRouteNameAsTransaction = setRouteNameAsTransaction, _routeNameExtractor = routeNameExtractor, - _additionalInfoProvider = additionalInfoProvider, - _native = SentryFlutter.native { + _additionalInfoProvider = additionalInfoProvider { if (enableAutoTransactions) { // ignore: invalid_use_of_internal_member _hub.options.sdk.addIntegration('UINavigationTracing'); } + final options = _hub.options; + if (options is SentryFlutterOptions) { + final enableTimeToFullDisplayTracing = + options.enableTimeToFullDisplayTracing; + _timeToDisplayTracker = timeToDisplayTracker ?? + TimeToDisplayTracker( + enableTimeToFullDisplayTracing: enableTimeToFullDisplayTracing, + ttdTransactionHandler: TimeToDisplayTransactionHandler( + hub: hub, + enableAutoTransactions: enableAutoTransactions, + autoFinishAfter: autoFinishAfter, + ), + ); + } } final Hub _hub; - final bool _enableAutoTransactions; - final Duration _autoFinishAfter; final bool _setRouteNameAsTransaction; final RouteNameExtractor? _routeNameExtractor; final AdditionalInfoExtractor? _additionalInfoProvider; - final SentryNative? _native; - ISentrySpan? _transaction; + static TimeToDisplayTracker? _timeToDisplayTracker; + + @internal + static TimeToDisplayTracker? get timeToDisplayTracker => + _timeToDisplayTracker; static String? _currentRouteName; @internal static String? get currentRouteName => _currentRouteName; + Completer? _completedDisplayTracking; + + @visibleForTesting + Completer? get completedDisplayTracking => _completedDisplayTracking; + @override void didPush(Route route, Route? previousRoute) { super.didPush(route, previousRoute); @@ -108,7 +133,16 @@ class SentryNavigatorObserver extends RouteObserver> { ); _finishTransaction(); - _startTransaction(route); + _startTimeToDisplayTracking(route); + } + + Future _finishTransaction() async { + final transaction = _hub.getSpan(); + if (transaction == null || transaction.finished) { + return; + } + transaction.status ??= SpanStatus.ok(); + await transaction.finish(); } @override @@ -139,7 +173,6 @@ class SentryNavigatorObserver extends RouteObserver> { ); _finishTransaction(); - _startTransaction(previousRoute); } void _addBreadcrumb({ @@ -178,77 +211,14 @@ class SentryNavigatorObserver extends RouteObserver> { } } - Future _startTransaction(Route? route) async { - if (!_enableAutoTransactions) { - return; - } + Future _startTimeToDisplayTracking(Route? route) async { + _completedDisplayTracking = Completer(); + final routeName = _getRouteName(route); + _currentRouteName = routeName; - String? name = _getRouteName(route); final arguments = route?.settings.arguments; - - if (name == null) { - return; - } - - if (name == '/') { - name = 'root ("/")'; - } - final transactionContext = SentryTransactionContext( - name, - 'navigation', - transactionNameSource: SentryTransactionNameSource.component, - // ignore: invalid_use_of_internal_member - origin: SentryTraceOrigins.autoNavigationRouteObserver, - ); - - _transaction = _hub.startTransactionWithContext( - transactionContext, - waitForChildren: true, - autoFinishAfter: _autoFinishAfter, - trimEnd: true, - onFinish: (transaction) async { - _transaction = null; - final nativeFrames = await _native - ?.endNativeFramesCollection(transaction.context.traceId); - if (nativeFrames != null) { - final measurements = nativeFrames.toMeasurements(); - for (final item in measurements.entries) { - final measurement = item.value; - transaction.setMeasurement( - item.key, - measurement.value, - unit: measurement.unit, - ); - } - } - }, - ); - - // if _enableAutoTransactions is enabled but there's no traces sample rate - if (_transaction is NoOpSentrySpan) { - _transaction = null; - return; - } - - if (arguments != null) { - _transaction?.setData('route_settings_arguments', arguments); - } - - await _hub.configureScope((scope) { - scope.span ??= _transaction; - }); - - await _native?.beginNativeFramesCollection(); - } - - Future _finishTransaction() async { - final transaction = _transaction; - _transaction = null; - if (transaction == null || transaction.finished) { - return; - } - transaction.status ??= SpanStatus.ok(); - await transaction.finish(); + await _timeToDisplayTracker?.startTracking(routeName, arguments); + completedDisplayTracking?.complete(); } } 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 0000000000..518084e4ac --- /dev/null +++ b/flutter/lib/src/navigation/time_to_display_tracker.dart @@ -0,0 +1,94 @@ +import 'dart:async'; + +import 'package:meta/meta.dart'; +import 'time_to_full_display_tracker.dart'; + +import '../../sentry_flutter.dart'; +import '../integrations/app_start/app_start_tracker.dart'; +import '../native/sentry_native.dart'; +import 'time_to_display_transaction_handler.dart'; +import 'time_to_initial_display_tracker.dart'; + +@internal +class TimeToDisplayTracker { + final SentryNative? _native; + final AppStartTracker _appStartTracker; + final TimeToDisplayTransactionHandler _ttdTransactionHandler; + final TimeToInitialDisplayTracker _ttidTracker; + final bool _enableTimeToFullDisplayTracing; + final TimeToFullDisplayTracker _ttfdTracker; + + TimeToDisplayTracker({ + required bool enableTimeToFullDisplayTracing, + required TimeToDisplayTransactionHandler ttdTransactionHandler, + AppStartTracker? appStartTracker, + TimeToInitialDisplayTracker? ttidTracker, + TimeToFullDisplayTracker? ttfdTracker, + }) : _native = SentryFlutter.native, + _enableTimeToFullDisplayTracing = enableTimeToFullDisplayTracing, + _ttdTransactionHandler = ttdTransactionHandler, + _appStartTracker = appStartTracker ?? AppStartTracker(), + _ttfdTracker = ttfdTracker ?? TimeToFullDisplayTracker(), + _ttidTracker = ttidTracker ?? TimeToInitialDisplayTracker(); + + Future startTracking(String? routeName, Object? arguments) async { + final startTimestamp = DateTime.now(); + if (routeName == '/') { + routeName = 'root ("/")'; + } + final isRootScreen = routeName == 'root ("/")'; + final didFetchAppStart = _native?.didFetchAppStart; + if (isRootScreen && didFetchAppStart == false) { + // Dart cannot infer here that routeName is not nullable + if (routeName == null) return; + return _trackAppStartTTD(routeName, arguments); + } else { + return _trackRegularRouteTTD(routeName, arguments, startTimestamp); + } + } + + /// This method listens for the completion of the app's start process via + /// [AppStartTracker], then: + /// - Starts a transaction with the app start start timestamp + /// - Starts TTID and optionally TTFD spans based on the app start start timestamp + /// - Finishes the TTID span immediately with the app start end timestamp + /// + /// We start and immediately finish the TTID span since we cannot mutate the history of spans. + Future _trackAppStartTTD(String routeName, Object? arguments) async { + final appStartInfo = await _appStartTracker.getAppStartInfo(); + final name = routeName; + + if (appStartInfo == null) return; + + final transaction = await _ttdTransactionHandler + .startTransaction(name, arguments, startTimestamp: appStartInfo.start); + if (transaction == null) return; + + if (_enableTimeToFullDisplayTracing) { + _ttfdTracker.startTracking(transaction, appStartInfo.start, name); + } + + await _ttidTracker.trackAppStart(transaction, appStartInfo, name); + } + + /// Starts and finishes Time To Display spans for regular routes meaning routes that are not root. + Future _trackRegularRouteTTD( + String? routeName, Object? arguments, DateTime startTimestamp) async { + final transaction = await _ttdTransactionHandler + .startTransaction(routeName, arguments, startTimestamp: startTimestamp); + + if (transaction == null || routeName == null) return; + + if (_enableTimeToFullDisplayTracing) { + _ttfdTracker.startTracking(transaction, startTimestamp, routeName); + } + + await _ttidTracker.trackRegularRoute( + transaction, startTimestamp, routeName); + } + + @internal + Future reportFullyDisplayed() async { + return _ttfdTracker.reportFullyDisplayed(); + } +} diff --git a/flutter/lib/src/navigation/time_to_display_transaction_handler.dart b/flutter/lib/src/navigation/time_to_display_transaction_handler.dart new file mode 100644 index 0000000000..c6538b91d0 --- /dev/null +++ b/flutter/lib/src/navigation/time_to_display_transaction_handler.dart @@ -0,0 +1,80 @@ +import 'package:meta/meta.dart'; +import '../../sentry_flutter.dart'; +import '../native/sentry_native.dart'; + +@internal +class TimeToDisplayTransactionHandler { + final Hub? _hub; + final bool? _enableAutoTransactions; + final Duration? _autoFinishAfter; + final SentryNative? _native; + + TimeToDisplayTransactionHandler({ + required Hub? hub, + required bool? enableAutoTransactions, + required Duration? autoFinishAfter, + }) : _hub = hub ?? HubAdapter(), + _enableAutoTransactions = enableAutoTransactions, + _autoFinishAfter = autoFinishAfter, + _native = SentryFlutter.native; + + @override + Future startTransaction(String? routeName, Object? arguments, + {DateTime? startTimestamp}) async { + if (_enableAutoTransactions == false) { + return null; + } + + if (routeName == null) { + return null; + } + + final transactionContext = SentryTransactionContext( + routeName, + SentrySpanOperations.uiLoad, + transactionNameSource: SentryTransactionNameSource.component, + // ignore: invalid_use_of_internal_member + origin: SentryTraceOrigins.autoNavigationRouteObserver, + ); + + final transaction = _hub?.startTransactionWithContext( + transactionContext, + waitForChildren: true, + autoFinishAfter: _autoFinishAfter, + trimEnd: true, + startTimestamp: startTimestamp, + onFinish: (transaction) async { + final nativeFrames = await _native + ?.endNativeFramesCollection(transaction.context.traceId); + if (nativeFrames != null) { + final measurements = nativeFrames.toMeasurements(); + for (final item in measurements.entries) { + final measurement = item.value; + transaction.setMeasurement( + item.key, + measurement.value, + unit: measurement.unit, + ); + } + } + }, + ); + + // if _enableAutoTransactions is enabled but there's no traces sample rate + if (transaction is NoOpSentrySpan) { + return null; + } + + if (arguments != null) { + transaction?.setData('route_settings_arguments', arguments); + } + + _hub?.configureScope((scope) { + scope.span ??= transaction; + }); + + await _native?.beginNativeFramesCollection(); + + return transaction; + } +} diff --git a/flutter/lib/src/navigation/time_to_full_display_tracker.dart b/flutter/lib/src/navigation/time_to_full_display_tracker.dart new file mode 100644 index 0000000000..0bbe70d6f7 --- /dev/null +++ b/flutter/lib/src/navigation/time_to_full_display_tracker.dart @@ -0,0 +1,110 @@ +import 'dart:async'; + +import 'package:meta/meta.dart'; + +import '../../sentry_flutter.dart'; +import '../sentry_flutter_measurement.dart'; +import 'time_to_initial_display_tracker.dart'; + +/// We need to retrieve the end time stamp in case TTFD timeout is triggered. +/// In those cases TTFD end time should match TTID end time. +/// This provider allows us to inject endTimestamps for testing as well. +@internal +abstract class EndTimestampProvider { + DateTime? get endTimestamp; +} + +@internal +class TTIDEndTimestampProvider implements EndTimestampProvider { + @override + DateTime? get endTimestamp => TimeToInitialDisplayTracker().endTimestamp; +} + +@internal +class TimeToFullDisplayTracker { + static final TimeToFullDisplayTracker _instance = + TimeToFullDisplayTracker._(); + + factory TimeToFullDisplayTracker( + {EndTimestampProvider? endTimestampProvider, Duration? autoFinishAfter}) { + if (autoFinishAfter != null) { + _instance._autoFinishAfter = autoFinishAfter; + } + if (endTimestampProvider != null) { + _instance._endTimestampProvider = endTimestampProvider; + } + return _instance; + } + + TimeToFullDisplayTracker._(); + + DateTime? _startTimestamp; + ISentrySpan? _ttfdSpan; + Timer? _ttfdTimer; + ISentrySpan? _transaction; + Duration _autoFinishAfter = const Duration(seconds: 30); + EndTimestampProvider _endTimestampProvider = TTIDEndTimestampProvider(); + + void startTracking( + ISentrySpan transaction, DateTime startTimestamp, String routeName) { + _startTimestamp = startTimestamp; + _transaction = transaction; + _ttfdSpan = transaction.startChild(SentrySpanOperations.uiTimeToFullDisplay, + description: '$routeName full display', startTimestamp: startTimestamp); + _ttfdSpan?.origin = SentryTraceOrigins.manualUiTimeToDisplay; + _ttfdTimer = Timer(_autoFinishAfter, handleTimeToFullDisplayTimeout); + } + + void handleTimeToFullDisplayTimeout() { + final ttfdSpan = _ttfdSpan; + final startTimestamp = _startTimestamp; + if (ttfdSpan == null || + ttfdSpan.finished == true || + startTimestamp == null) { + return; + } + + // If for some reason we can't get the ttid end timestamp + // we'll use the start timestamp + autoFinishAfter as a fallback + final endTimestamp = _endTimestampProvider.endTimestamp ?? + startTimestamp.add(_autoFinishAfter); + + _setTTFDMeasurement(startTimestamp, endTimestamp); + ttfdSpan.finish( + status: SpanStatus.deadlineExceeded(), endTimestamp: endTimestamp); + + clearState(); + } + + Future reportFullyDisplayed() async { + _ttfdTimer?.cancel(); + final endTimestamp = DateTime.now(); + final startTimestamp = _startTimestamp; + final ttfdSpan = _ttfdSpan; + + if (ttfdSpan == null || + ttfdSpan.finished == true || + startTimestamp == null) { + return; + } + + _setTTFDMeasurement(startTimestamp, endTimestamp); + await ttfdSpan.finish(endTimestamp: endTimestamp); + + clearState(); + } + + void _setTTFDMeasurement(DateTime startTimestamp, DateTime endTimestamp) { + final duration = endTimestamp.difference(startTimestamp); + final measurement = SentryFlutterMeasurement.timeToFullDisplay(duration); + _transaction?.setMeasurement(measurement.name, measurement.value, + unit: measurement.unit); + } + + void clearState() { + _startTimestamp = null; + _ttfdSpan = null; + _ttfdTimer = null; + _transaction = 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 new file mode 100644 index 0000000000..6a8f31d406 --- /dev/null +++ b/flutter/lib/src/navigation/time_to_initial_display_tracker.dart @@ -0,0 +1,122 @@ +import 'dart:async'; + +import 'package:meta/meta.dart'; + +import '../../sentry_flutter.dart'; +import '../frame_callback_handler.dart'; +import '../integrations/app_start/app_start_tracker.dart'; +import '../sentry_flutter_measurement.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; + + /// This endTimestamp is needed in the [TimeToFullDisplayTracker] class + @internal + DateTime? get endTimestamp => _endTimestamp; + + Future trackRegularRoute(ISentrySpan transaction, + DateTime startTimestamp, String routeName) async { + final endTimestamp = await determineEndTime(); + if (endTimestamp == null) return; + + final ttidSpan = transaction.startChild( + SentrySpanOperations.uiTimeToInitialDisplay, + description: '$routeName initial display', + startTimestamp: startTimestamp); + + if (_isManual) { + ttidSpan.origin = SentryTraceOrigins.manualUiTimeToDisplay; + } else { + ttidSpan.origin = SentryTraceOrigins.autoUiTimeToDisplay; + } + + final ttidMeasurement = SentryFlutterMeasurement.timeToInitialDisplay( + Duration( + milliseconds: + endTimestamp.difference(startTimestamp).inMilliseconds)); + transaction.setMeasurement(ttidMeasurement.name, ttidMeasurement.value, + unit: ttidMeasurement.unit); + await ttidSpan.finish(endTimestamp: endTimestamp); + + // We can clear the state after creating and finishing the ttid span has finished + clear(); + } + + Future trackAppStart(ISentrySpan transaction, AppStartInfo appStartInfo, + String routeName) async { + final ttidSpan = transaction.startChild( + SentrySpanOperations.uiTimeToInitialDisplay, + description: '$routeName initial display', + startTimestamp: appStartInfo.start, + ); + ttidSpan.origin = SentryTraceOrigins.autoUiTimeToDisplay; + + final ttidMeasurement = SentryFlutterMeasurement.timeToInitialDisplay( + Duration(milliseconds: appStartInfo.measurement.value.toInt()), + ); + transaction.setMeasurement(ttidMeasurement.name, ttidMeasurement.value, + unit: ttidMeasurement.unit); + + // Since app start measurement is immediate, finish the TTID span with the app start's end timestamp + await ttidSpan.finish(endTimestamp: appStartInfo.end); + + // Store the end timestamp for potential use by TTFD tracking + _endTimestamp = appStartInfo.end; + } + + Future? determineEndTime() { + _trackingCompleter = Completer(); + + // If we already know it's manual we can return the future immediately + if (_isManual) { + return _trackingCompleter?.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 _trackingCompleter?.future; + } + + void markAsManual() { + _isManual = true; + } + + void completeTracking() { + if (_trackingCompleter != null && !_trackingCompleter!.isCompleted) { + final endTimestamp = DateTime.now(); + _endTimestamp = endTimestamp; + // Reset after completion + _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/lib/src/sentry_flutter.dart b/flutter/lib/src/sentry_flutter.dart index 62a9043bc9..9c4f777f4a 100644 --- a/flutter/lib/src/sentry_flutter.dart +++ b/flutter/lib/src/sentry_flutter.dart @@ -13,6 +13,7 @@ import 'integrations/connectivity/connectivity_integration.dart'; import 'integrations/screenshot_integration.dart'; import 'native/factory.dart'; import 'native/native_scope_observer.dart'; +import 'navigation/time_to_display_tracker.dart'; import 'profiling.dart'; import 'renderer/renderer.dart'; import 'native/sentry_native.dart'; @@ -229,8 +230,14 @@ mixin SentryFlutter { options.sdk = sdk; } + /// Reports the time it took for the screen to be fully displayed. + static Future reportFullyDisplayed() async { + return SentryNavigatorObserver.timeToDisplayTracker?.reportFullyDisplayed(); + } + @internal static SentryNative? get native => _native; + @internal static set native(SentryNative? value) => _native = value; static SentryNative? _native; diff --git a/flutter/lib/src/sentry_flutter_measurement.dart b/flutter/lib/src/sentry_flutter_measurement.dart new file mode 100644 index 0000000000..8b47a3fc56 --- /dev/null +++ b/flutter/lib/src/sentry_flutter_measurement.dart @@ -0,0 +1,23 @@ +import '../sentry_flutter.dart'; + +extension SentryFlutterMeasurement on SentryMeasurement { + /// Duration of the time to initial display in milliseconds + static SentryMeasurement timeToInitialDisplay(Duration duration) { + assert(!duration.isNegative); + return SentryMeasurement( + 'time_to_initial_display', + duration.inMilliseconds.toDouble(), + unit: DurationSentryMeasurementUnit.milliSecond, + ); + } + + /// Duration of the time to full display in milliseconds + static SentryMeasurement timeToFullDisplay(Duration duration) { + assert(!duration.isNegative); + return SentryMeasurement( + 'time_to_full_display', + duration.inMilliseconds.toDouble(), + unit: DurationSentryMeasurementUnit.milliSecond, + ); + } +} diff --git a/flutter/lib/src/sentry_flutter_options.dart b/flutter/lib/src/sentry_flutter_options.dart index ee722f8e9e..e84a68159f 100644 --- a/flutter/lib/src/sentry_flutter_options.dart +++ b/flutter/lib/src/sentry_flutter_options.dart @@ -223,6 +223,12 @@ class SentryFlutterOptions extends SentryOptions { /// Read timeout. This will only be synced to the Android native SDK. Duration readTimeout = Duration(seconds: 5); + /// Enable or disable the tracing of time to full display (TTFD). + /// If `SentryFlutter.reportFullyDisplayed()` is not called within 30 seconds + /// after the creation of the TTFD span, it will finish with the status [SpanStatus.deadlineExceeded]. + /// This feature requires using the [Routing Instrumentation](https://docs.sentry.io/platforms/flutter/integrations/routing-instrumentation/). + bool enableTimeToFullDisplayTracing = false; + /// By using this, you are disabling native [Breadcrumb] tracking and instead /// you are just tracking [Breadcrumb]s which result from events available /// in the current Flutter environment. diff --git a/flutter/lib/src/sentry_widget.dart b/flutter/lib/src/sentry_widget.dart index ed390d1ab4..0b4eb779de 100644 --- a/flutter/lib/src/sentry_widget.dart +++ b/flutter/lib/src/sentry_widget.dart @@ -1,4 +1,8 @@ +import 'dart:async'; + import 'package:flutter/cupertino.dart'; +import 'package:flutter/material.dart'; +import 'package:meta/meta.dart'; import '../sentry_flutter.dart'; /// This widget serves as a wrapper to include Sentry widgets such diff --git a/flutter/test/fake_frame_callback_handler.dart b/flutter/test/fake_frame_callback_handler.dart new file mode 100644 index 0000000000..eac89466f4 --- /dev/null +++ b/flutter/test/fake_frame_callback_handler.dart @@ -0,0 +1,19 @@ +import 'package:flutter/scheduler.dart'; +import 'package:sentry_flutter/src/frame_callback_handler.dart'; + +class FakeFrameCallbackHandler implements FrameCallbackHandler { + FrameCallback? storedCallback; + + final Duration _finishAfterDuration; + + FakeFrameCallbackHandler( + {Duration finishAfterDuration = const Duration(milliseconds: 500)}) + : _finishAfterDuration = finishAfterDuration; + + @override + void addPostFrameCallback(FrameCallback callback, + {String debugLabel = 'callback'}) async { + await Future.delayed(_finishAfterDuration); + callback(Duration.zero); + } +} diff --git a/flutter/test/integrations/native_app_start_integration_test.dart b/flutter/test/integrations/native_app_start_integration_test.dart index d4b8deaaf5..54efcd419c 100644 --- a/flutter/test/integrations/native_app_start_integration_test.dart +++ b/flutter/test/integrations/native_app_start_integration_test.dart @@ -3,6 +3,7 @@ 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/app_start/app_start_tracker.dart'; import 'package:sentry_flutter/src/integrations/native_app_start_integration.dart'; import 'package:sentry_flutter/src/native/sentry_native.dart'; import 'package:sentry/src/sentry_tracer.dart'; @@ -22,8 +23,14 @@ void main() { test('native app start measurement added to first transaction', () async { fixture.options.autoAppStart = false; - fixture.native.appStartEnd = DateTime.fromMillisecondsSinceEpoch(10); - fixture.binding.nativeAppStart = NativeAppStart(0, true); + fixture.appStartTracker.setAppStartInfo( + AppStartInfo( + DateTime.fromMillisecondsSinceEpoch(0), + DateTime.fromMillisecondsSinceEpoch(10), + SentryMeasurement('app_start_cold', 10, + unit: DurationSentryMeasurementUnit.milliSecond), + ), + ); fixture.getNativeAppStartIntegration().call(fixture.hub, fixture.options); @@ -41,8 +48,14 @@ void main() { test('native app start measurement not added to following transactions', () async { fixture.options.autoAppStart = false; - fixture.native.appStartEnd = DateTime.fromMillisecondsSinceEpoch(10); - fixture.binding.nativeAppStart = NativeAppStart(0, true); + fixture.appStartTracker.setAppStartInfo( + AppStartInfo( + DateTime.fromMillisecondsSinceEpoch(0), + DateTime.fromMillisecondsSinceEpoch(10), + SentryMeasurement('app_start_cold', 10, + unit: DurationSentryMeasurementUnit.milliSecond), + ), + ); fixture.getNativeAppStartIntegration().call(fixture.hub, fixture.options); @@ -59,8 +72,14 @@ void main() { test('measurements appended', () async { fixture.options.autoAppStart = false; - fixture.native.appStartEnd = DateTime.fromMillisecondsSinceEpoch(10); - fixture.binding.nativeAppStart = NativeAppStart(0, true); + fixture.appStartTracker.setAppStartInfo( + AppStartInfo( + DateTime.fromMillisecondsSinceEpoch(0), + DateTime.fromMillisecondsSinceEpoch(10), + SentryMeasurement('app_start_cold', 10, + unit: DurationSentryMeasurementUnit.milliSecond), + ), + ); final measurement = SentryMeasurement.warmAppStart(Duration(seconds: 1)); fixture.getNativeAppStartIntegration().call(fixture.hub, fixture.options); @@ -80,8 +99,14 @@ void main() { test('native app start measurement not added if more than 60s', () async { fixture.options.autoAppStart = false; - fixture.native.appStartEnd = DateTime.fromMillisecondsSinceEpoch(60001); - fixture.binding.nativeAppStart = NativeAppStart(0, true); + fixture.appStartTracker.setAppStartInfo( + AppStartInfo( + DateTime.fromMillisecondsSinceEpoch(0), + DateTime.fromMillisecondsSinceEpoch(60001), + SentryMeasurement('app_start_cold', 60001, + unit: DurationSentryMeasurementUnit.milliSecond), + ), + ); fixture.getNativeAppStartIntegration().call(fixture.hub, fixture.options); @@ -93,6 +118,37 @@ void main() { expect(enriched.measurements.isEmpty, true); }); + + test( + 'native app start measurement only added once for multiple different transactions', + () async { + fixture.options.autoAppStart = false; + await fixture.native.fetchNativeAppStart(); + fixture.appStartTracker.setAppStartInfo( + AppStartInfo( + DateTime.fromMillisecondsSinceEpoch(0), + DateTime.fromMillisecondsSinceEpoch(10), + SentryMeasurement('app_start_cold', 10, + unit: DurationSentryMeasurementUnit.milliSecond), + ), + ); + + fixture.getNativeAppStartIntegration().call(fixture.hub, fixture.options); + + final processor = fixture.options.eventProcessors.first; + final tracer = fixture.createTracer(); + + // Represents the app start transaction + final transaction = SentryTransaction(tracer); + var enriched = await processor.apply(transaction) as SentryTransaction; + expect(enriched.measurements.length, 1); + + // Represents any other transaction that happened afterwards + final transaction2 = SentryTransaction(tracer); + var secondEnriched = + await processor.apply(transaction2) as SentryTransaction; + expect(secondEnriched.measurements.length, 0); + }); }); } @@ -100,6 +156,7 @@ class Fixture { final hub = MockHub(); final options = SentryFlutterOptions(dsn: fakeDsn); final binding = MockNativeChannel(); + final appStartTracker = AppStartTracker(); late final native = SentryNative(options, binding); Fixture() { @@ -113,6 +170,7 @@ class Fixture { () { return TestWidgetsFlutterBinding.ensureInitialized(); }, + appStartTracker: appStartTracker, ); } 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 0000000000..62884d4d65 --- /dev/null +++ b/flutter/test/navigation/sentry_display_widget_test.dart @@ -0,0 +1,120 @@ +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/app_start/app_start_tracker.dart'; +import 'package:sentry_flutter/src/navigation/time_to_initial_display_tracker.dart'; +import 'package:sentry_flutter/src/sentry_flutter_measurement.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); + expect(tracer.measurements, hasLength(1)); + final measurement = tracer.measurements['time_to_initial_display']; + expect(measurement, isNotNull); + expect(measurement?.unit, DurationSentryMeasurementUnit.milliSecond); + }); + + testWidgets('SentryDisplayWidget is ignored for app starts', + (WidgetTester tester) async { + final currentRoute = route(RouteSettings(name: '/')); + + await tester.runAsync(() async { + fixture.navigatorObserver.didPush(currentRoute, null); + await tester.pumpWidget(fixture.getSut()); + AppStartTracker().setAppStartInfo(AppStartInfo( + DateTime.fromMillisecondsSinceEpoch(0).toUtc(), + DateTime.fromMillisecondsSinceEpoch(10).toUtc(), + SentryFlutterMeasurement.timeToInitialDisplay( + Duration(milliseconds: 10), + ), + )); + 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, + DateTime.fromMillisecondsSinceEpoch(0).toUtc()); + expect( + ttidSpan.endTimestamp, DateTime.fromMillisecondsSinceEpoch(10).toUtc()); + + expect(tracer.measurements, hasLength(1)); + final measurement = tracer.measurements['time_to_initial_display']; + expect(measurement, isNotNull); + expect(measurement?.value, 10); + expect(measurement?.unit, DurationSentryMeasurementUnit.milliSecond); + }); +} + +class Fixture { + final Hub hub = + Hub(SentryFlutterOptions(dsn: fakeDsn)..tracesSampleRate = 1.0); + late final SentryNavigatorObserver navigatorObserver; + late final TimeToInitialDisplayTracker timeToInitialDisplayTracker; + final fakeFrameCallbackHandler = FakeFrameCallbackHandler(); + + Fixture() { + SentryFlutter.native = TestMockSentryNative(); + navigatorObserver = SentryNavigatorObserver(hub: hub); + timeToInitialDisplayTracker = TimeToInitialDisplayTracker( + frameCallbackHandler: fakeFrameCallbackHandler); + } + + 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 0000000000..fb592343cd --- /dev/null +++ b/flutter/test/navigation/time_to_display_tracker_test.dart @@ -0,0 +1,242 @@ +import 'package:flutter_test/flutter_test.dart'; +import 'package:sentry_flutter/sentry_flutter.dart'; +import 'package:sentry_flutter/src/integrations/app_start/app_start_tracker.dart'; +import 'package:sentry_flutter/src/integrations/integrations.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_display_transaction_handler.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'; +import '../mocks.dart'; + +void main() { + late Fixture fixture; + + setUp(() { + TestWidgetsFlutterBinding.ensureInitialized(); + fixture = Fixture(); + }); + + group('time to initial display', () { + group('in root screen app start route', () { + test('startMeasurement finishes ttid span', () async { + SentryFlutter.native = TestMockSentryNative(); + final sut = fixture.getSut(); + + Future.delayed(const Duration(milliseconds: 500), () async { + AppStartTracker().setAppStartInfo(AppStartInfo( + DateTime.fromMillisecondsSinceEpoch(0), + DateTime.fromMillisecondsSinceEpoch(10), + SentryMeasurement('', 10, + unit: DurationSentryMeasurementUnit.milliSecond))); + }); + + await sut.startTracking('/', null); + + await Future.delayed(const Duration(milliseconds: 100)); + + final transaction = fixture.hub.getSpan() as SentryTracer; + + final spans = transaction.children; + expect(transaction.children, hasLength(1)); + expect(spans[0].context.operation, + SentrySpanOperations.uiTimeToInitialDisplay); + expect(spans[0].finished, isTrue); + }); + }); + + group('in regular routes', () { + group('with approximation strategy', () { + test('startMeasurement finishes ttid span', () async { + final sut = fixture.getSut(); + + await sut.startTracking('Current Route', null); + + final transaction = fixture.hub.getSpan() as SentryTracer; + await Future.delayed(const Duration(milliseconds: 2000)); + + final spans = transaction.children; + expect(transaction.children, hasLength(1)); + expect(spans[0].context.operation, + SentrySpanOperations.uiTimeToInitialDisplay); + expect(spans[0].finished, isTrue); + }); + }); + + group('with manual strategy', () { + test('finishes ttid span after reporting with manual api', () async { + final sut = fixture.getSut(); + + Future.delayed(const Duration(milliseconds: 100), () { + fixture.ttidTracker.markAsManual(); + fixture.ttidTracker.completeTracking(); + }); + await sut.startTracking('Current Route', null); + + final transaction = fixture.hub.getSpan() as SentryTracer; + + await Future.delayed(const Duration(milliseconds: 100)); + + final ttidSpan = transaction.children + .where((element) => + element.context.operation == + SentrySpanOperations.uiTimeToInitialDisplay) + .first; + expect(ttidSpan, isNotNull); + + await Future.delayed(const Duration(milliseconds: 100)); + + expect(ttidSpan.finished, isTrue); + }); + }); + }); + }); + + group('time to full display', () { + setUp(() { + fixture.options.enableTimeToFullDisplayTracing = true; + }); + + test('startMeasurement creates ttfd and ttid span', () { + final sut = fixture.getSut(); + + return sut.startTracking('Current Route', null).then((value) { + final transaction = fixture.hub.getSpan() as SentryTracer; + + final spans = transaction.children; + expect(transaction.children, hasLength(2)); + expect(spans[0].context.operation, + SentrySpanOperations.uiTimeToInitialDisplay); + expect(spans[1].context.operation, + SentrySpanOperations.uiTimeToFullDisplay); + }); + }); + + group('in root screen app start route', () { + test('startMeasurement finishes ttfd span', () async { + SentryFlutter.native = TestMockSentryNative(); + final sut = fixture.getSut(); + + // Simulate app start info being fetched async + Future.delayed(const Duration(milliseconds: 500), () async { + AppStartTracker().setAppStartInfo(AppStartInfo( + DateTime.fromMillisecondsSinceEpoch(0), + DateTime.fromMillisecondsSinceEpoch(10), + SentryMeasurement('', 10, + unit: DurationSentryMeasurementUnit.milliSecond))); + }); + + await sut.startTracking('/', null); + + final transaction = fixture.hub.getSpan() as SentryTracer; + + final ttfdSpan = transaction.children + .where((element) => + element.context.operation == + SentrySpanOperations.uiTimeToFullDisplay) + .first; + expect(ttfdSpan, isNotNull); + + await fixture.getSut().reportFullyDisplayed(); + + expect(ttfdSpan.finished, isTrue); + }); + }); + + group('in regular routes', () { + test('finishes ttfd span after calling reportFullyDisplayed', () async { + final sut = fixture.getSut(); + + await sut.startTracking('Current Route', null); + + final transaction = fixture.hub.getSpan() as SentryTracer; + + final ttfdSpan = transaction.children + .where((element) => + element.context.operation == + SentrySpanOperations.uiTimeToFullDisplay) + .first; + expect(ttfdSpan, isNotNull); + + await fixture.getSut().reportFullyDisplayed(); + + expect(ttfdSpan.finished, isTrue); + }); + + test( + 'not using reportFullyDisplayed finishes ttfd span after timeout with deadline exceeded and ttid matching end time', + () async { + final sut = fixture.getSut(); + + await sut.startTracking('Current Route', null); + + final transaction = fixture.hub.getSpan() as SentryTracer; + + final ttidSpan = transaction.children + .where((element) => + element.context.operation == + SentrySpanOperations.uiTimeToInitialDisplay) + .first; + expect(ttidSpan, isNotNull); + + final ttfdSpan = transaction.children + .where((element) => + element.context.operation == + SentrySpanOperations.uiTimeToFullDisplay) + .first; + expect(ttfdSpan, isNotNull); + + await Future.delayed( + fixture.ttfdAutoFinishAfter + const Duration(milliseconds: 100)); + + expect(ttfdSpan.finished, isTrue); + expect(ttfdSpan.status, SpanStatus.deadlineExceeded()); + expect(ttfdSpan.endTimestamp, ttidSpan.endTimestamp); + }); + }); + }); + + test('screen load tracking creates ui.load transaction', () async { + final sut = fixture.getSut(); + + await sut.startTracking('Current Route', null); + + final transaction = fixture.hub.getSpan(); + expect(transaction, isNotNull); + expect(transaction?.context.operation, SentrySpanOperations.uiLoad); + }); +} + +class Fixture { + final options = SentryFlutterOptions() + ..dsn = fakeDsn + ..tracesSampleRate = 1.0; + + late final hub = Hub(options); + + final frameCallbackHandler = FakeFrameCallbackHandler(); + late final ttidTracker = + TimeToInitialDisplayTracker(frameCallbackHandler: frameCallbackHandler); + + final ttfdAutoFinishAfter = Duration(milliseconds: 500); + late final ttfdTracker = + TimeToFullDisplayTracker(autoFinishAfter: ttfdAutoFinishAfter); + + TimeToDisplayTracker getSut() { + final enableTimeToFullDisplayTracing = + options.enableTimeToFullDisplayTracing; + + return TimeToDisplayTracker( + enableTimeToFullDisplayTracing: enableTimeToFullDisplayTracing, + ttdTransactionHandler: TimeToDisplayTransactionHandler( + hub: hub, + enableAutoTransactions: true, + autoFinishAfter: const Duration(seconds: 30), + ), + ttidTracker: ttidTracker, + ttfdTracker: ttfdTracker, + ); + } +} diff --git a/flutter/test/navigation/time_to_full_display_tracker_test.dart b/flutter/test/navigation/time_to_full_display_tracker_test.dart new file mode 100644 index 0000000000..19520de804 --- /dev/null +++ b/flutter/test/navigation/time_to_full_display_tracker_test.dart @@ -0,0 +1,82 @@ +import 'package:flutter_test/flutter_test.dart'; +import 'package:sentry_flutter/sentry_flutter.dart'; +import 'package:sentry_flutter/src/navigation/time_to_full_display_tracker.dart'; +import 'package:sentry/src/sentry_tracer.dart'; + +import '../mocks.dart'; + +void main() { + late Fixture fixture; + late SentryTracer transaction; + late DateTime startTimestamp; + late EndTimestampProvider endTimestampProvider; + const routeName = 'regular route'; + + setUp(() { + fixture = Fixture(); + transaction = fixture.hub.startTransaction('test_transaction', 'test') + as SentryTracer; + + // start timestamp needs to be after the transaction has started + startTimestamp = DateTime.now().toUtc(); + endTimestampProvider = FakeTTIDEndTimeStampProvider(startTimestamp); + }); + + test('reportFullyDisplayed() marks the TTFD span as finished', () async { + final sut = fixture.getSut(endTimestampProvider); + + sut.startTracking(transaction, startTimestamp, routeName); + await sut.reportFullyDisplayed(); + + final ttfdSpan = transaction.children.first; + expect(transaction.children, hasLength(1)); + expect(ttfdSpan.context.operation, + equals(SentrySpanOperations.uiTimeToFullDisplay)); + expect(ttfdSpan.finished, isTrue); + expect(ttfdSpan.context.description, equals('$routeName full display')); + expect(ttfdSpan.origin, equals(SentryTraceOrigins.manualUiTimeToDisplay)); + }); + + test( + 'TTFD span finishes automatically after timeout with correct status and end time', + () async { + final sut = fixture.getSut(endTimestampProvider); + + sut.startTracking(transaction, startTimestamp, routeName); + + // Simulate delay to trigger automatic finish + await Future.delayed( + fixture.autoFinishAfter + const Duration(milliseconds: 100)); + + final ttfdSpan = transaction.children.first; + expect(transaction.children, hasLength(1)); + expect(ttfdSpan.endTimestamp, equals(endTimestampProvider.endTimestamp)); + expect(ttfdSpan.context.operation, + equals(SentrySpanOperations.uiTimeToFullDisplay)); + expect(ttfdSpan.finished, isTrue); + expect(ttfdSpan.status, equals(SpanStatus.deadlineExceeded())); + expect(ttfdSpan.context.description, equals('$routeName full display')); + expect(ttfdSpan.origin, equals(SentryTraceOrigins.manualUiTimeToDisplay)); + }); +} + +class Fixture { + final hub = Hub(SentryFlutterOptions(dsn: fakeDsn)..tracesSampleRate = 1.0); + final autoFinishAfter = const Duration(milliseconds: 100); + + TimeToFullDisplayTracker getSut(EndTimestampProvider endTimestampProvider) { + return TimeToFullDisplayTracker( + endTimestampProvider: endTimestampProvider, + autoFinishAfter: autoFinishAfter); + } +} + +class FakeTTIDEndTimeStampProvider implements EndTimestampProvider { + final DateTime _endTimestamp; + + FakeTTIDEndTimeStampProvider(DateTime startTimestamp) + : _endTimestamp = startTimestamp.add(const Duration(seconds: 1)).toUtc(); + + @override + DateTime? get endTimestamp => _endTimestamp; +} 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 0000000000..de9855389a --- /dev/null +++ b/flutter/test/navigation/time_to_initial_display_tracker_test.dart @@ -0,0 +1,182 @@ +import 'package:flutter_test/flutter_test.dart'; +import 'package:sentry_flutter/sentry_flutter.dart'; +import 'package:sentry_flutter/src/integrations/app_start/app_start_tracker.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 transaction = + fixture.hub.startTransaction('fake', 'fake') as SentryTracer; + final startTimestamp = DateTime.now(); + final appStartInfo = AppStartInfo( + startTimestamp, + startTimestamp.add(Duration(milliseconds: 10)), + SentryMeasurement.coldAppStart(Duration(milliseconds: 10))); + + await sut.trackAppStart(transaction, appStartInfo, 'route ("/")'); + + 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, '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, 10); + + final appStartMeasurement = transaction.measurements['app_start_cold']; + expect(appStartMeasurement, isNotNull); + expect( + appStartMeasurement?.unit, DurationSentryMeasurementUnit.milliSecond); + expect(appStartMeasurement?.value, 10); + }); + }); + + group('regular route', () { + test( + 'approximation tracking creates and finishes ttid span with correct measurements', + () async { + final transaction = + fixture.hub.startTransaction('fake', 'fake') as SentryTracer; + final startTimestamp = DateTime.now(); + + await sut.trackRegularRoute(transaction, startTimestamp, 'regular route'); + + 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.finishFrameAfterDuration.inMilliseconds)); + }); + + test( + 'manual tracking creates and finishes ttid span with correct measurements', + () async { + final transaction = + fixture.hub.startTransaction('fake', 'fake') as SentryTracer; + final startTimestamp = DateTime.now(); + + sut.markAsManual(); + Future.delayed(fixture.finishFrameAfterDuration, () { + sut.completeTracking(); + }); + await sut.trackRegularRoute(transaction, startTimestamp, 'regular route'); + + 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.finishFrameAfterDuration.inMilliseconds)); + }); + }); + + group('determineEndtime', () { + test('can complete automatically in approximation mode', () async { + final futureEndTime = sut.determineEndTime(); + + expect(futureEndTime, completes); + }); + + test('prevents automatic completion in manual mode', () async { + sut.markAsManual(); + final futureEndTime = sut.determineEndTime(); + + expect(futureEndTime, doesNotComplete); + }); + + test('can complete manually in manual mode', () async { + sut.markAsManual(); + final futureEndTime = sut.determineEndTime(); + + sut.completeTracking(); + expect(futureEndTime, completes); + }); + + test('returns the correct approximation end time', () async { + final startTime = DateTime.now(); + + final futureEndTime = sut.determineEndTime(); + + final endTime = await futureEndTime; + expect(endTime?.difference(startTime).inSeconds, + fixture.finishFrameAfterDuration.inSeconds); + }); + + test('returns the correct manual end time', () async { + final startTime = DateTime.now(); + + sut.markAsManual(); + final futureEndTime = sut.determineEndTime(); + + Future.delayed(fixture.finishFrameAfterDuration, () { + sut.completeTracking(); + }); + + final endTime = await futureEndTime; + expect(endTime?.difference(startTime).inSeconds, + fixture.finishFrameAfterDuration.inSeconds); + }); + }); +} + +class Fixture { + final hub = Hub(SentryFlutterOptions(dsn: fakeDsn)..tracesSampleRate = 1.0); + final finishFrameAfterDuration = Duration(milliseconds: 100); + late final fakeFrameCallbackHandler = + FakeFrameCallbackHandler(finishAfterDuration: finishFrameAfterDuration); + + TimeToInitialDisplayTracker getSut() { + return TimeToInitialDisplayTracker( + frameCallbackHandler: fakeFrameCallbackHandler); + } +} diff --git a/flutter/test/sentry_navigator_observer_test.dart b/flutter/test/sentry_navigator_observer_test.dart index aca9646c0b..6b35342e1c 100644 --- a/flutter/test/sentry_navigator_observer_test.dart +++ b/flutter/test/sentry_navigator_observer_test.dart @@ -7,7 +7,11 @@ import 'package:mockito/mockito.dart'; import 'package:sentry_flutter/sentry_flutter.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_display_transaction_handler.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,14 @@ void main() { final sut = fixture.getSut(hub: hub); sut.didPush(currentRoute, null); + when(span.finished).thenReturn(true); + 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 +371,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); @@ -365,6 +391,12 @@ void main() { 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); @@ -374,6 +406,7 @@ void main() { final context = verify(hub.startTransactionWithContext( captureAny, waitForChildren: true, + startTimestamp: anyNamed('startTimestamp'), autoFinishAfter: anyNamed('autoFinishAfter'), trimEnd: true, onFinish: anyNamed('onFinish'), @@ -394,6 +427,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 +455,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 +485,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 +709,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 +869,23 @@ 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( + enableTimeToFullDisplayTracing: false, + ttdTransactionHandler: TimeToDisplayTransactionHandler( + hub: hub, + enableAutoTransactions: enableAutoTransactions, + autoFinishAfter: autoFinishAfter, + ), + ttidTracker: timeToInitialDisplayTracker, + ); return SentryNavigatorObserver( hub: hub, enableAutoTransactions: enableAutoTransactions, @@ -830,6 +893,7 @@ class Fixture { setRouteNameAsTransaction: setRouteNameAsTransaction, routeNameExtractor: routeNameExtractor, additionalInfoProvider: additionalInfoProvider, + timeToDisplayTracker: timeToDisplayTracker, ); }