diff --git a/CHANGELOG.md b/CHANGELOG.md index 387633d6e3..5d7b75b7bf 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,13 @@ # Changelog +## Unreleased + +### Enhancements + +- Improve app start integration ([#2266](https://github.com/getsentry/sentry-dart/pull/2266)) + - Fixes ([#2103](https://github.com/getsentry/sentry-dart/issues/2103)) + - Fixes ([#2233](https://github.com/getsentry/sentry-dart/issues/2233)) + ## 8.9.0 ### Features diff --git a/flutter/example/integration_test/integration_test.dart b/flutter/example/integration_test/integration_test.dart index 7a961083b5..89ee5723f4 100644 --- a/flutter/example/integration_test/integration_test.dart +++ b/flutter/example/integration_test/integration_test.dart @@ -8,7 +8,6 @@ import 'package:flutter/widgets.dart'; import 'package:flutter_test/flutter_test.dart'; import 'package:http/http.dart'; import 'package:sentry_flutter/sentry_flutter.dart'; -import 'package:sentry_flutter/src/integrations/native_app_start_integration.dart'; import 'package:sentry_flutter_example/main.dart'; void main() { @@ -26,8 +25,6 @@ void main() { // Using fake DSN for testing purposes. Future setupSentryAndApp(WidgetTester tester, {String? dsn, BeforeSendCallback? beforeSendCallback}) async { - NativeAppStartIntegration.isIntegrationTest = true; - await setupSentry( () async { await tester.pumpWidget(SentryScreenshotWidget( diff --git a/flutter/example/ios/Runner/AppDelegate.swift b/flutter/example/ios/Runner/AppDelegate.swift index a231cc9c60..c24cacbbb2 100644 --- a/flutter/example/ios/Runner/AppDelegate.swift +++ b/flutter/example/ios/Runner/AppDelegate.swift @@ -2,7 +2,7 @@ import UIKit import Flutter import Sentry -@UIApplicationMain +@main @objc class AppDelegate: FlutterAppDelegate { private let _channel = "example.flutter.sentry.io" diff --git a/flutter/example/lib/user_feedback_dialog.dart b/flutter/example/lib/user_feedback_dialog.dart index 495c9c7b7a..159f3c69d9 100644 --- a/flutter/example/lib/user_feedback_dialog.dart +++ b/flutter/example/lib/user_feedback_dialog.dart @@ -143,7 +143,7 @@ class _SentryLogo extends StatelessWidget { var color = Colors.white; final brightenss = Theme.of(context).brightness; if (brightenss == Brightness.light) { - color = const Color(0xff362d59).withOpacity(1.0); + color = const Color(0xff362d59); } return FittedBox( 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 deleted file mode 100644 index a5d67595bd..0000000000 --- a/flutter/lib/src/event_processor/native_app_start_event_processor.dart +++ /dev/null @@ -1,155 +0,0 @@ -// ignore_for_file: invalid_use_of_internal_member - -import 'dart:async'; - -import '../../sentry_flutter.dart'; -import '../integrations/integrations.dart'; - -// ignore: implementation_imports -import 'package:sentry/src/sentry_tracer.dart'; - -/// EventProcessor that enriches [SentryTransaction] objects with app start -/// measurement. -class NativeAppStartEventProcessor implements EventProcessor { - final Hub _hub; - - NativeAppStartEventProcessor({Hub? hub}) : _hub = hub ?? HubAdapter(); - - @override - Future apply(SentryEvent event, Hint hint) async { - final options = _hub.options; - if (NativeAppStartIntegration.didAddAppStartMeasurement || - event is! SentryTransaction || - options is! SentryFlutterOptions) { - return event; - } - - AppStartInfo? appStartInfo; - if (!options.autoAppStart) { - final appStartEnd = NativeAppStartIntegration.appStartEnd; - if (appStartEnd != null) { - appStartInfo = await NativeAppStartIntegration.getAppStartInfo(); - appStartInfo?.end = appStartEnd; - } else { - // If autoAppStart is disabled and appStartEnd is not set, we can't add app starts - return event; - } - } else { - appStartInfo = await NativeAppStartIntegration.getAppStartInfo(); - } - - final measurement = appStartInfo?.toMeasurement(); - if (measurement != null) { - event.measurements[measurement.name] = measurement; - NativeAppStartIntegration.didAddAppStartMeasurement = true; - } - - if (appStartInfo != null) { - await _attachAppStartSpans(appStartInfo, event.tracer); - } - - return event; - } - - Future _attachAppStartSpans( - AppStartInfo appStartInfo, SentryTracer transaction) async { - final transactionTraceId = transaction.context.traceId; - final appStartEnd = appStartInfo.end; - if (appStartEnd == null) { - return; - } - - final appStartSpan = await _createAndFinishSpan( - tracer: transaction, - operation: appStartInfo.appStartTypeOperation, - description: appStartInfo.appStartTypeDescription, - parentSpanId: transaction.context.spanId, - traceId: transactionTraceId, - startTimestamp: appStartInfo.start, - endTimestamp: appStartEnd); - - await _attachNativeSpans(appStartInfo, transaction, appStartSpan); - - final pluginRegistrationSpan = await _createAndFinishSpan( - tracer: transaction, - operation: appStartInfo.appStartTypeOperation, - description: appStartInfo.pluginRegistrationDescription, - parentSpanId: appStartSpan.context.spanId, - traceId: transactionTraceId, - startTimestamp: appStartInfo.start, - endTimestamp: appStartInfo.pluginRegistration); - - final sentrySetupSpan = await _createAndFinishSpan( - tracer: transaction, - operation: appStartInfo.appStartTypeOperation, - description: appStartInfo.sentrySetupDescription, - parentSpanId: appStartSpan.context.spanId, - traceId: transactionTraceId, - startTimestamp: appStartInfo.pluginRegistration, - endTimestamp: appStartInfo.sentrySetupStart); - - final firstFrameRenderSpan = await _createAndFinishSpan( - tracer: transaction, - operation: appStartInfo.appStartTypeOperation, - description: appStartInfo.firstFrameRenderDescription, - parentSpanId: appStartSpan.context.spanId, - traceId: transactionTraceId, - startTimestamp: appStartInfo.sentrySetupStart, - endTimestamp: appStartEnd); - - transaction.children.addAll([ - appStartSpan, - pluginRegistrationSpan, - sentrySetupSpan, - firstFrameRenderSpan - ]); - } - - Future _attachNativeSpans(AppStartInfo appStartInfo, - SentryTracer transaction, SentrySpan parent) async { - await Future.forEach(appStartInfo.nativeSpanTimes, - (timeSpan) async { - try { - final span = await _createAndFinishSpan( - tracer: transaction, - operation: appStartInfo.appStartTypeOperation, - description: timeSpan.description, - parentSpanId: parent.context.spanId, - traceId: transaction.context.traceId, - startTimestamp: timeSpan.start, - endTimestamp: timeSpan.end); - span.data.putIfAbsent('native', () => true); - transaction.children.add(span); - } catch (e) { - _hub.options.logger(SentryLevel.warning, - 'Failed to attach native span to app start transaction: $e'); - if (_hub.options.automatedTestMode) { - rethrow; - } - } - }); - } - - Future _createAndFinishSpan({ - required SentryTracer tracer, - required String operation, - required String description, - required SpanId parentSpanId, - required SentryId traceId, - required DateTime startTimestamp, - required DateTime endTimestamp, - }) async { - final span = SentrySpan( - tracer, - SentrySpanContext( - operation: operation, - description: description, - parentSpanId: parentSpanId, - traceId: traceId, - ), - _hub, - startTimestamp: startTimestamp); - await span.finish(endTimestamp: endTimestamp); - return span; - } -} diff --git a/flutter/lib/src/integrations/native_app_start_handler.dart b/flutter/lib/src/integrations/native_app_start_handler.dart new file mode 100644 index 0000000000..a503d351d4 --- /dev/null +++ b/flutter/lib/src/integrations/native_app_start_handler.dart @@ -0,0 +1,304 @@ +// ignore_for_file: invalid_use_of_internal_member + +import '../../sentry_flutter.dart'; +import '../native/native_app_start.dart'; +import '../native/sentry_native_binding.dart'; + +// ignore: implementation_imports +import 'package:sentry/src/sentry_tracer.dart'; + +/// Handles communication with native frameworks in order to enrich +/// root [SentryTransaction] with app start data for mobile vitals. +class NativeAppStartHandler { + NativeAppStartHandler(this._native); + + final SentryNativeBinding _native; + + late final Hub _hub; + late final SentryFlutterOptions _options; + + /// We filter out App starts more than 60s + static const _maxAppStartMillis = 60000; + + Future call(Hub hub, SentryFlutterOptions options, + {required DateTime? appStartEnd}) async { + _hub = hub; + _options = options; + + final nativeAppStart = await _native.fetchNativeAppStart(); + if (nativeAppStart == null) { + return; + } + final appStartInfo = _infoNativeAppStart(nativeAppStart, appStartEnd); + if (appStartInfo == null) { + return; + } + + // Create Transaction & Span + + const screenName = 'root /'; + final transaction = _hub.startTransaction( + screenName, + SentrySpanOperations.uiLoad, + startTimestamp: appStartInfo.start, + ); + final ttidSpan = transaction.startChild( + SentrySpanOperations.uiTimeToInitialDisplay, + description: '$screenName initial display', + startTimestamp: appStartInfo.start, + ); + + // Enrich Transaction + + SentryTracer sentryTracer; + if (transaction is SentryTracer) { + sentryTracer = transaction; + } else { + return; + } + + SentryMeasurement? measurement; + if (options.autoAppStart) { + measurement = appStartInfo.toMeasurement(); + } else if (appStartEnd != null) { + appStartInfo.end = appStartEnd; + measurement = appStartInfo.toMeasurement(); + } + + if (measurement != null) { + sentryTracer.measurements[measurement.name] = measurement; + await _attachAppStartSpans(appStartInfo, sentryTracer); + } + + // Finish Transaction & Span + + await ttidSpan.finish(endTimestamp: appStartInfo.end); + await transaction.finish(endTimestamp: appStartInfo.end); + } + + _AppStartInfo? _infoNativeAppStart( + NativeAppStart nativeAppStart, + DateTime? appStartEnd, + ) { + final sentrySetupStartDateTime = SentryFlutter.sentrySetupStartTime; + if (sentrySetupStartDateTime == null) { + return null; + } + + final appStartDateTime = DateTime.fromMillisecondsSinceEpoch( + nativeAppStart.appStartTime.toInt()); + final pluginRegistrationDateTime = DateTime.fromMillisecondsSinceEpoch( + nativeAppStart.pluginRegistrationTime); + + if (_options.autoAppStart) { + // We only assign the current time if it's not already set - this is useful in tests + appStartEnd ??= _options.clock(); + + final duration = appStartEnd.difference(appStartDateTime); + + // 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 (duration.inMilliseconds > _maxAppStartMillis) { + return null; + } + } + + List<_TimeSpan> nativeSpanTimes = []; + for (final entry in nativeAppStart.nativeSpanTimes.entries) { + try { + final startTimestampMs = + entry.value['startTimestampMsSinceEpoch'] as int; + final endTimestampMs = entry.value['stopTimestampMsSinceEpoch'] as int; + nativeSpanTimes.add(_TimeSpan( + start: DateTime.fromMillisecondsSinceEpoch(startTimestampMs), + end: DateTime.fromMillisecondsSinceEpoch(endTimestampMs), + description: entry.key as String, + )); + } catch (e) { + _options.logger( + SentryLevel.warning, 'Failed to parse native span times: $e'); + continue; + } + } + + // We want to sort because the native spans are not guaranteed to be in order. + // Performance wise this won't affect us since the native span amount is very low. + nativeSpanTimes.sort((a, b) => a.start.compareTo(b.start)); + + return _AppStartInfo( + nativeAppStart.isColdStart ? _AppStartType.cold : _AppStartType.warm, + start: appStartDateTime, + end: appStartEnd, + pluginRegistration: pluginRegistrationDateTime, + sentrySetupStart: sentrySetupStartDateTime, + nativeSpanTimes: nativeSpanTimes, + ); + } + + Future _attachAppStartSpans( + _AppStartInfo appStartInfo, SentryTracer transaction) async { + final transactionTraceId = transaction.context.traceId; + final appStartEnd = appStartInfo.end; + if (appStartEnd == null) { + return; + } + + final appStartSpan = await _createAndFinishSpan( + tracer: transaction, + operation: appStartInfo.appStartTypeOperation, + description: appStartInfo.appStartTypeDescription, + parentSpanId: transaction.context.spanId, + traceId: transactionTraceId, + startTimestamp: appStartInfo.start, + endTimestamp: appStartEnd, + ); + + await _attachNativeSpans(appStartInfo, transaction, appStartSpan); + + final pluginRegistrationSpan = await _createAndFinishSpan( + tracer: transaction, + operation: appStartInfo.appStartTypeOperation, + description: appStartInfo.pluginRegistrationDescription, + parentSpanId: appStartSpan.context.spanId, + traceId: transactionTraceId, + startTimestamp: appStartInfo.start, + endTimestamp: appStartInfo.pluginRegistration, + ); + + final sentrySetupSpan = await _createAndFinishSpan( + tracer: transaction, + operation: appStartInfo.appStartTypeOperation, + description: appStartInfo.sentrySetupDescription, + parentSpanId: appStartSpan.context.spanId, + traceId: transactionTraceId, + startTimestamp: appStartInfo.pluginRegistration, + endTimestamp: appStartInfo.sentrySetupStart, + ); + + final firstFrameRenderSpan = await _createAndFinishSpan( + tracer: transaction, + operation: appStartInfo.appStartTypeOperation, + description: appStartInfo.firstFrameRenderDescription, + parentSpanId: appStartSpan.context.spanId, + traceId: transactionTraceId, + startTimestamp: appStartInfo.sentrySetupStart, + endTimestamp: appStartEnd, + ); + + transaction.children.addAll([ + appStartSpan, + pluginRegistrationSpan, + sentrySetupSpan, + firstFrameRenderSpan + ]); + } + + Future _attachNativeSpans( + _AppStartInfo appStartInfo, + SentryTracer transaction, + SentrySpan parent, + ) async { + await Future.forEach<_TimeSpan>(appStartInfo.nativeSpanTimes, + (timeSpan) async { + try { + final span = await _createAndFinishSpan( + tracer: transaction, + operation: appStartInfo.appStartTypeOperation, + description: timeSpan.description, + parentSpanId: parent.context.spanId, + traceId: transaction.context.traceId, + startTimestamp: timeSpan.start, + endTimestamp: timeSpan.end, + ); + span.data.putIfAbsent('native', () => true); + transaction.children.add(span); + } catch (e) { + _options.logger(SentryLevel.warning, + 'Failed to attach native span to app start transaction: $e'); + } + }); + } + + Future _createAndFinishSpan({ + required SentryTracer tracer, + required String operation, + required String description, + required SpanId parentSpanId, + required SentryId traceId, + required DateTime startTimestamp, + required DateTime endTimestamp, + }) async { + final span = SentrySpan( + tracer, + SentrySpanContext( + operation: operation, + description: description, + parentSpanId: parentSpanId, + traceId: traceId, + ), + _hub, + startTimestamp: startTimestamp, + ); + await span.finish(endTimestamp: endTimestamp); + return span; + } +} + +enum _AppStartType { cold, warm } + +class _AppStartInfo { + _AppStartInfo( + this.type, { + required this.start, + required this.pluginRegistration, + required this.sentrySetupStart, + required this.nativeSpanTimes, + this.end, + }); + + final _AppStartType type; + final DateTime start; + final List<_TimeSpan> nativeSpanTimes; + + // We allow the end to be null, since it might be set at a later time + // with setAppStartEnd when autoAppStart is disabled + DateTime? end; + + final DateTime pluginRegistration; + final DateTime sentrySetupStart; + + Duration? get duration => end?.difference(start); + + SentryMeasurement? toMeasurement() { + final duration = this.duration; + if (duration == null) { + return null; + } + return type == _AppStartType.cold + ? SentryMeasurement.coldAppStart(duration) + : SentryMeasurement.warmAppStart(duration); + } + + String get appStartTypeOperation => 'app.start.${type.name}'; + + String get appStartTypeDescription => + type == _AppStartType.cold ? 'Cold Start' : 'Warm Start'; + final pluginRegistrationDescription = 'App start to plugin registration'; + final sentrySetupDescription = 'Before Sentry Init Setup'; + final firstFrameRenderDescription = 'First frame render'; +} + +class _TimeSpan { + _TimeSpan( + {required this.start, required this.end, required this.description}); + + final DateTime start; + final DateTime end; + final String description; +} diff --git a/flutter/lib/src/integrations/native_app_start_integration.dart b/flutter/lib/src/integrations/native_app_start_integration.dart index 2456dd4524..31dc2b6ad8 100644 --- a/flutter/lib/src/integrations/native_app_start_integration.dart +++ b/flutter/lib/src/integrations/native_app_start_integration.dart @@ -1,259 +1,59 @@ -// ignore_for_file: invalid_use_of_internal_member - import 'dart:async'; import 'package:meta/meta.dart'; import '../../sentry_flutter.dart'; import '../frame_callback_handler.dart'; -import '../native/sentry_native_binding.dart'; -import '../event_processor/native_app_start_event_processor.dart'; +import 'native_app_start_handler.dart'; -/// Integration which handles communication with native frameworks in order to -/// enrich [SentryTransaction] objects with app start data for mobile vitals. +/// Integration which calls [NativeAppStartHandler] after +/// [SchedulerBinding.instance.addPostFrameCallback] is called. class NativeAppStartIntegration extends Integration { - NativeAppStartIntegration(this._native, this._frameCallbackHandler, - {Hub? hub}) - : _hub = hub ?? HubAdapter(); + NativeAppStartIntegration( + this._frameCallbackHandler, this._nativeAppStartHandler); - final SentryNativeBinding _native; final FrameCallbackHandler _frameCallbackHandler; - final Hub _hub; - - /// This timestamp marks the end of app startup. Either set automatically when - /// [SentryFlutterOptions.autoAppStart] is true, or by calling - /// [SentryFlutter.setAppStartEnd] - @internal - static DateTime? appStartEnd; - - /// Flag indicating if app start was already fetched. - static bool _didFetchAppStart = false; - - /// Flag indicating if app start measurement was added to the first transaction. - @internal - static bool didAddAppStartMeasurement = false; - - /// Timeout duration to wait for the app start info to be fetched. - static const _timeoutDuration = Duration(seconds: 10); - - @visibleForTesting - static Duration get timeoutDuration => _timeoutDuration; - - /// We filter out App starts more than 60s - static const _maxAppStartMillis = 60000; - - static Completer _appStartCompleter = - Completer(); - static AppStartInfo? _appStartInfo; + final NativeAppStartHandler _nativeAppStartHandler; + DateTime? _appStartEnd; + /// This timestamp marks the end of app startup. Either set by calling + /// [SentryFlutter.setAppStartEnd]. The [SentryFlutterOptions.autoAppStart] + /// option needs to be false. @internal - static bool isIntegrationTest = false; - - @internal - static void setAppStartInfo(AppStartInfo? appStartInfo) { - _appStartInfo = appStartInfo; - if (_appStartCompleter.isCompleted) { - _appStartCompleter = Completer(); + set appStartEnd(DateTime appStartEnd) { + _appStartEnd = appStartEnd; + if (!_appStartEndCompleter.isCompleted) { + _appStartEndCompleter.complete(); } - _appStartCompleter.complete(appStartInfo); } - @internal - static Future getAppStartInfo() { - if (_appStartInfo != null) { - return Future.value(_appStartInfo); - } - return _appStartCompleter.future - .timeout(_timeoutDuration, onTimeout: () => null); - } - - @visibleForTesting - static void clearAppStartInfo() { - _appStartInfo = null; - _appStartCompleter = Completer(); - didAddAppStartMeasurement = false; - } - - /// Reset state - @visibleForTesting - static void reset() { - appStartEnd = null; - _didFetchAppStart = false; - } + final Completer _appStartEndCompleter = Completer(); @override - void call(Hub hub, SentryFlutterOptions options) { - if (isIntegrationTest) { - final appStartInfo = AppStartInfo( - AppStartType.cold, - start: DateTime.now(), - end: DateTime.now().add(const Duration(milliseconds: 100)), - pluginRegistration: - DateTime.now().add(const Duration(milliseconds: 50)), - sentrySetupStart: DateTime.now().add(const Duration(milliseconds: 60)), - nativeSpanTimes: [], - ); - setAppStartInfo(appStartInfo); - return; - } - - if (_didFetchAppStart) { - return; - } - + void call(Hub hub, SentryFlutterOptions options) async { _frameCallbackHandler.addPostFrameCallback((timeStamp) async { - _didFetchAppStart = true; - final nativeAppStart = await _native.fetchNativeAppStart(); - if (nativeAppStart == null) { - setAppStartInfo(null); - return; - } - - final sentrySetupStartDateTime = SentryFlutter.sentrySetupStartTime; - if (sentrySetupStartDateTime == null) { - setAppStartInfo(null); - return; - } - - final appStartDateTime = DateTime.fromMillisecondsSinceEpoch( - nativeAppStart.appStartTime.toInt()); - final pluginRegistrationDateTime = DateTime.fromMillisecondsSinceEpoch( - nativeAppStart.pluginRegistrationTime); - - if (options.autoAppStart) { - // We only assign the current time if it's not already set - this is useful in tests - appStartEnd ??= options.clock(); - - final duration = appStartEnd?.difference(appStartDateTime); - - // 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 (duration != null && duration.inMilliseconds > _maxAppStartMillis) { - setAppStartInfo(null); - return; + try { + if (!options.autoAppStart && _appStartEnd == null) { + await _appStartEndCompleter.future + .timeout(const Duration(seconds: 10)); } - } - - List nativeSpanTimes = []; - for (final entry in nativeAppStart.nativeSpanTimes.entries) { - try { - final startTimestampMs = - entry.value['startTimestampMsSinceEpoch'] as int; - final endTimestampMs = - entry.value['stopTimestampMsSinceEpoch'] as int; - nativeSpanTimes.add(TimeSpan( - start: DateTime.fromMillisecondsSinceEpoch(startTimestampMs), - end: DateTime.fromMillisecondsSinceEpoch(endTimestampMs), - description: entry.key as String, - )); - } catch (e) { - _hub.options.logger( - SentryLevel.warning, 'Failed to parse native span times: $e'); - if (_hub.options.automatedTestMode) { - rethrow; - } - continue; + await _nativeAppStartHandler.call( + hub, + options, + appStartEnd: _appStartEnd, + ); + } catch (exception, stackTrace) { + options.logger( + SentryLevel.error, + 'Error while capturing native app start', + exception: exception, + stackTrace: stackTrace, + ); + if (options.automatedTestMode) { + rethrow; } } - - // We want to sort because the native spans are not guaranteed to be in order. - // Performance wise this won't affect us since the native span amount is very low. - nativeSpanTimes.sort((a, b) => a.start.compareTo(b.start)); - - final appStartInfo = AppStartInfo( - nativeAppStart.isColdStart ? AppStartType.cold : AppStartType.warm, - start: appStartDateTime, - end: appStartEnd, - pluginRegistration: pluginRegistrationDateTime, - sentrySetupStart: sentrySetupStartDateTime, - nativeSpanTimes: nativeSpanTimes); - - setAppStartInfo(appStartInfo); - - // When we don't have a SentryNavigatorObserver, a TTID transaction - // is not created therefore we need to create a transaction ourselves. - // We detect this by checking if the currentRouteName is null. - // This is a workaround since there is no api that tells us if - // the navigator observer exists and has been attached. - // The navigator observer also triggers much earlier so if it was attached - // it would have already set the routeName and the isCreated flag. - // The currentRouteName is always set during a didPush triggered - // by the navigator observer. - if (!SentryNavigatorObserver.isCreated && - SentryNavigatorObserver.currentRouteName == null) { - const screenName = SentryNavigatorObserver.rootScreenName; - final transaction = hub.startTransaction( - screenName, SentrySpanOperations.uiLoad, - startTimestamp: appStartInfo.start); - final ttidSpan = transaction.startChild( - SentrySpanOperations.uiTimeToInitialDisplay, - description: '$screenName initial display', - startTimestamp: appStartInfo.start); - await ttidSpan.finish(endTimestamp: appStartInfo.end); - await transaction.finish(endTimestamp: appStartInfo.end); - } }); - - options.addEventProcessor(NativeAppStartEventProcessor(hub: hub)); - options.sdk.addIntegration('nativeAppStartIntegration'); } } - -enum AppStartType { cold, warm } - -class AppStartInfo { - AppStartInfo( - this.type, { - required this.start, - required this.pluginRegistration, - required this.sentrySetupStart, - required this.nativeSpanTimes, - this.end, - }); - - final AppStartType type; - final DateTime start; - final List nativeSpanTimes; - - // We allow the end to be null, since it might be set at a later time - // with setAppStartEnd when autoAppStart is disabled - DateTime? end; - - final DateTime pluginRegistration; - final DateTime sentrySetupStart; - - Duration? get duration => end?.difference(start); - - SentryMeasurement? toMeasurement() { - final duration = this.duration; - if (duration == null) { - return null; - } - return type == AppStartType.cold - ? SentryMeasurement.coldAppStart(duration) - : SentryMeasurement.warmAppStart(duration); - } - - String get appStartTypeOperation => 'app.start.${type.name}'; - - String get appStartTypeDescription => - type == AppStartType.cold ? 'Cold Start' : 'Warm Start'; - final pluginRegistrationDescription = 'App start to plugin registration'; - final sentrySetupDescription = 'Before Sentry Init Setup'; - final firstFrameRenderDescription = 'First frame render'; -} - -class TimeSpan { - TimeSpan({required this.start, required this.end, required this.description}); - - final DateTime start; - final DateTime end; - final String description; -} diff --git a/flutter/lib/src/navigation/sentry_navigator_observer.dart b/flutter/lib/src/navigation/sentry_navigator_observer.dart index 48b1059258..0554c0ad2a 100644 --- a/flutter/lib/src/navigation/sentry_navigator_observer.dart +++ b/flutter/lib/src/navigation/sentry_navigator_observer.dart @@ -5,7 +5,6 @@ import 'dart:async'; import 'package:flutter/material.dart'; import 'package:flutter/widgets.dart'; import 'package:meta/meta.dart'; -import '../integrations/integrations.dart'; import '../native/native_frames.dart'; import '../native/sentry_native_binding.dart'; import 'time_to_display_tracker.dart'; @@ -244,13 +243,10 @@ class SentryNavigatorObserver extends RouteObserver> { String? name = _getRouteName(route); final arguments = route?.settings.arguments; - if (name == null) { + if (name == null || (name == '/')) { return; } - if (name == '/') { - name = rootScreenName; - } final transactionContext = SentryTransactionContext( name, SentrySpanOperations.uiLoad, @@ -351,15 +347,6 @@ class SentryNavigatorObserver extends RouteObserver> { bool isAppStart = routeName == '/'; DateTime startTimestamp = _hub.options.clock(); - DateTime? endTimestamp; - - if (isAppStart) { - final appStartInfo = await NativeAppStartIntegration.getAppStartInfo(); - if (appStartInfo == null) return; - - startTimestamp = appStartInfo.start; - endTimestamp = appStartInfo.end; - } await _startTransaction(route, startTimestamp); @@ -368,12 +355,11 @@ class SentryNavigatorObserver extends RouteObserver> { return; } - if (isAppStart && endTimestamp != null) { - await _timeToDisplayTracker?.trackAppStartTTD(transaction, - startTimestamp: startTimestamp, endTimestamp: endTimestamp); - } else { - await _timeToDisplayTracker?.trackRegularRouteTTD(transaction, - startTimestamp: startTimestamp); + if (!isAppStart) { + await _timeToDisplayTracker?.trackRegularRouteTTD( + transaction, + startTimestamp: startTimestamp, + ); } } catch (exception, stacktrace) { _hub.options.logger( @@ -398,9 +384,6 @@ class SentryNavigatorObserver extends RouteObserver> { _timeToDisplayTracker?.clear(); } - @internal - static const String rootScreenName = 'root /'; - bool _isRouteIgnored(Route route) { return _ignoreRoutes.isNotEmpty && _ignoreRoutes.contains(_getRouteName(route)); diff --git a/flutter/lib/src/navigation/time_to_display_tracker.dart b/flutter/lib/src/navigation/time_to_display_tracker.dart index 342e305c75..a2c1813317 100644 --- a/flutter/lib/src/navigation/time_to_display_tracker.dart +++ b/flutter/lib/src/navigation/time_to_display_tracker.dart @@ -21,15 +21,6 @@ class TimeToDisplayTracker { ? ttfdTracker ?? TimeToFullDisplayTracker() : null; - 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); - await _trackTTFDIfEnabled(transaction, startTimestamp); - } - Future trackRegularRouteTTD(ISentrySpan transaction, {required DateTime startTimestamp}) async { await _ttidTracker.trackRegularRoute(transaction, startTimestamp); diff --git a/flutter/lib/src/navigation/time_to_initial_display_tracker.dart b/flutter/lib/src/navigation/time_to_initial_display_tracker.dart index ce2f7b9e9c..051d0602b2 100644 --- a/flutter/lib/src/navigation/time_to_initial_display_tracker.dart +++ b/flutter/lib/src/navigation/time_to_initial_display_tracker.dart @@ -45,20 +45,6 @@ class TimeToInitialDisplayTracker { ); } - 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, diff --git a/flutter/lib/src/sentry_flutter.dart b/flutter/lib/src/sentry_flutter.dart index 16e6d7a4d7..e190115149 100644 --- a/flutter/lib/src/sentry_flutter.dart +++ b/flutter/lib/src/sentry_flutter.dart @@ -16,6 +16,7 @@ import 'flutter_exception_type_identifier.dart'; import 'frame_callback_handler.dart'; import 'integrations/connectivity/connectivity_integration.dart'; import 'integrations/integrations.dart'; +import 'integrations/native_app_start_handler.dart'; import 'integrations/screenshot_integration.dart'; import 'native/factory.dart'; import 'native/native_scope_observer.dart'; @@ -194,10 +195,12 @@ mixin SentryFlutter { integrations.add(LoadReleaseIntegration()); if (native != null) { - integrations.add(NativeAppStartIntegration( - native, - DefaultFrameCallbackHandler(), - )); + integrations.add( + NativeAppStartIntegration( + DefaultFrameCallbackHandler(), + NativeAppStartHandler(native), + ), + ); } return integrations; } @@ -213,9 +216,15 @@ mixin SentryFlutter { } /// Manually set when your app finished startup. Make sure to set - /// [SentryFlutterOptions.autoAppStart] to false on init. + /// [SentryFlutterOptions.autoAppStart] to false on init. The timeout duration + /// for this to work is 10 seconds. static void setAppStartEnd(DateTime appStartEnd) { - NativeAppStartIntegration.appStartEnd = appStartEnd; + // ignore: invalid_use_of_internal_member + final integrations = Sentry.currentHub.options.integrations + .whereType(); + for (final integration in integrations) { + integration.appStartEnd = appStartEnd; + } } static void _setSdk(SentryFlutterOptions options) { diff --git a/flutter/test/integrations/native_app_start_handler_test.dart b/flutter/test/integrations/native_app_start_handler_test.dart new file mode 100644 index 0000000000..925879ea6a --- /dev/null +++ b/flutter/test/integrations/native_app_start_handler_test.dart @@ -0,0 +1,348 @@ +@TestOn('vm') +library flutter_test; + +import 'package:collection/collection.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/integrations/native_app_start_handler.dart'; +import 'package:sentry_flutter/src/integrations/native_app_start_integration.dart'; +import 'package:sentry/src/sentry_tracer.dart'; +import 'package:sentry_flutter/src/native/native_app_start.dart'; + +import '../mocks.dart'; +import '../mocks.mocks.dart'; + +void main() { + void setupMocks(Fixture fixture) { + when(fixture.hub.startTransaction( + 'root /', + 'ui.load', + description: null, + startTimestamp: anyNamed('startTimestamp'), + )).thenReturn(fixture.tracer); + + when(fixture.hub.configureScope(captureAny)).thenAnswer((_) {}); + when(fixture.hub.captureTransaction( + any, + traceContext: anyNamed('traceContext'), + )).thenAnswer((_) async => SentryId.empty()); + + when(fixture.nativeBinding.fetchNativeAppStart()).thenAnswer( + (_) async => fixture.nativeAppStart, + ); + } + + group('$NativeAppStartIntegration', () { + late Fixture fixture; + + setUp(() { + fixture = Fixture(); + setupMocks(fixture); + }); + + test('native app start measurement added to first transaction', () async { + await fixture.call( + appStartEnd: DateTime.fromMillisecondsSinceEpoch(10), + ); + final transaction = fixture.capturedTransaction(); + + final measurement = transaction.measurements['app_start_cold']!; + expect(measurement.value, 10); + expect(measurement.unit, DurationSentryMeasurementUnit.milliSecond); + }); + + test('measurements appended', () async { + await fixture.call( + appStartEnd: DateTime.fromMillisecondsSinceEpoch(10), + ); + + final measurement = SentryMeasurement.warmAppStart(Duration(seconds: 1)); + + final transaction = fixture.capturedTransaction().copyWith(); + transaction.measurements[measurement.name] = measurement; + + expect(transaction.measurements.length, 2); + expect(transaction.measurements.containsKey(measurement.name), true); + }); + + test('native app start measurement not added if more than 60s', () async { + await fixture.call( + appStartEnd: DateTime.fromMillisecondsSinceEpoch(60001), + ); + + verifyNever(fixture.hub.captureTransaction( + captureAny, + traceContext: captureAnyNamed('traceContext'), + )); + }); + + test( + 'autoAppStart is false and appStartEnd is not set does not add app start measurement', + () async { + fixture.options.autoAppStart = false; + await fixture.call( + appStartEnd: null, + ); + + final transaction = fixture.capturedTransaction(); + + expect(transaction.measurements.isEmpty, true); + expect(transaction.spans.length, + 1); // Only containing ui.load.initial_display + expect(transaction.spans[0].context.operation, 'ui.load.initial_display'); + }); + + test( + 'autoAppStart is false and appStartEnd is set adds app start measurement', + () async { + fixture.options.autoAppStart = false; + + await fixture.call( + appStartEnd: DateTime.fromMillisecondsSinceEpoch(10), + ); + + final transaction = fixture.capturedTransaction(); + + final measurement = transaction.measurements['app_start_cold']!; + expect(measurement.value, 10); + expect(measurement.unit, DurationSentryMeasurementUnit.milliSecond); + + final spans = transaction.spans; + + final appStartSpan = spans.firstWhereOrNull( + (element) => element.context.description == 'Cold Start'); + + final pluginRegistrationSpan = spans.firstWhereOrNull((element) => + element.context.description == 'App start to plugin registration'); + + final sentrySetupSpan = spans.firstWhereOrNull((element) => + element.context.description == 'Before Sentry Init Setup'); + + final firstFrameRenderSpan = spans.firstWhereOrNull( + (element) => element.context.description == 'First frame render'); + + expect(appStartSpan, isNotNull); + expect(pluginRegistrationSpan, isNotNull); + expect(sentrySetupSpan, isNotNull); + expect(firstFrameRenderSpan, isNotNull); + }); + }); + + group('App start spans', () { + late SentrySpan? coldStartSpan, + pluginRegistrationSpan, + sentrySetupSpan, + firstFrameRenderSpan; + // ignore: invalid_use_of_internal_member + late SentryTracer tracer; + late Fixture fixture; + late SentryTransaction enriched; + + final validNativeSpanTimes = { + 'correct span description': { + 'startTimestampMsSinceEpoch': 1, + 'stopTimestampMsSinceEpoch': 2, + }, + 'correct span description 2': { + 'startTimestampMsSinceEpoch': 4, + 'stopTimestampMsSinceEpoch': 6, + }, + 'correct span description 3': { + 'startTimestampMsSinceEpoch': 3, + 'stopTimestampMsSinceEpoch': 4, + }, + }; + + final invalidNativeSpanTimes = { + 'failing span with null timestamp': { + 'startTimestampMsSinceEpoch': null, + 'stopTimestampMsSinceEpoch': 3, + }, + 'failing span with string timestamp': { + 'startTimestampMsSinceEpoch': '1', + 'stopTimestampMsSinceEpoch': 3, + }, + }; + + final appStartInfoSrc = NativeAppStart( + appStartTime: 0, + pluginRegistrationTime: 10, + isColdStart: true, + nativeSpanTimes: { + ...validNativeSpanTimes, + ...invalidNativeSpanTimes, + }); + + setUp(() async { + fixture = Fixture(); + tracer = fixture.tracer; + + // dartLoadingEnd needs to be set after engine end (see MockNativeChannel) + SentryFlutter.sentrySetupStartTime = + DateTime.fromMillisecondsSinceEpoch(15); + + setupMocks(fixture); + + when(fixture.nativeBinding.fetchNativeAppStart()) + .thenAnswer((_) async => appStartInfoSrc); + + await fixture.call(appStartEnd: DateTime.fromMillisecondsSinceEpoch(50)); + enriched = fixture.capturedTransaction(); + + final spans = enriched.spans; + + coldStartSpan = spans.firstWhereOrNull( + (element) => element.context.description == 'Cold Start'); + + pluginRegistrationSpan = spans.firstWhereOrNull((element) => + element.context.description == 'App start to plugin registration'); + + sentrySetupSpan = spans.firstWhereOrNull((element) => + element.context.description == 'Before Sentry Init Setup'); + + firstFrameRenderSpan = spans.firstWhereOrNull( + (element) => element.context.description == 'First frame render'); + }); + + test('includes only valid native spans', () async { + final spans = + enriched.spans.where((element) => element.data['native'] == true); + + expect(spans.length, validNativeSpanTimes.length); + + for (final span in spans) { + final validSpan = validNativeSpanTimes[span.context.description]; + expect(validSpan, isNotNull); + expect( + span.startTimestamp, + DateTime.fromMillisecondsSinceEpoch( + validSpan!['startTimestampMsSinceEpoch']!) + .toUtc()); + expect( + span.endTimestamp, + DateTime.fromMillisecondsSinceEpoch( + validSpan['stopTimestampMsSinceEpoch']!) + .toUtc()); + } + }); + + test('are correctly ordered', () async { + final spans = + enriched.spans.where((element) => element.data['native'] == true); + + final orderedSpans = spans.toList() + ..sort((a, b) => a.startTimestamp.compareTo(b.startTimestamp)); + + expect(spans, orderedEquals(orderedSpans)); + }); + + test('ignores invalid spans', () async { + final spans = + enriched.spans.where((element) => element.data['native'] == true); + + expect(spans, isNot(contains('failing span'))); + }); + + test('are added by event processor', () async { + expect(coldStartSpan, isNotNull); + expect(pluginRegistrationSpan, isNotNull); + expect(sentrySetupSpan, isNotNull); + expect(firstFrameRenderSpan, isNotNull); + }); + + test('have correct op', () async { + const op = 'app.start.cold'; + expect(coldStartSpan?.context.operation, op); + expect(pluginRegistrationSpan?.context.operation, op); + expect(sentrySetupSpan?.context.operation, op); + expect(firstFrameRenderSpan?.context.operation, op); + }); + + test('have correct parents', () async { + expect(coldStartSpan?.context.parentSpanId, tracer.context.spanId); + expect(pluginRegistrationSpan?.context.parentSpanId, + coldStartSpan?.context.spanId); + expect( + sentrySetupSpan?.context.parentSpanId, coldStartSpan?.context.spanId); + expect(firstFrameRenderSpan?.context.parentSpanId, + coldStartSpan?.context.spanId); + }); + + test('have correct traceId', () async { + final traceId = tracer.context.traceId; + expect(coldStartSpan?.context.traceId, traceId); + expect(pluginRegistrationSpan?.context.traceId, traceId); + expect(sentrySetupSpan?.context.traceId, traceId); + expect(firstFrameRenderSpan?.context.traceId, traceId); + }); + + test('have correct startTimestamp', () async { + final appStartTime = DateTime.fromMillisecondsSinceEpoch( + appStartInfoSrc.appStartTime.toInt()) + .toUtc(); + expect(coldStartSpan?.startTimestamp, appStartTime); + expect(pluginRegistrationSpan?.startTimestamp, appStartTime); + expect(sentrySetupSpan?.startTimestamp, + pluginRegistrationSpan?.endTimestamp); + expect( + firstFrameRenderSpan?.startTimestamp, sentrySetupSpan?.endTimestamp); + }); + + test('have correct endTimestamp', () async { + final appStartEnd = DateTime.fromMillisecondsSinceEpoch(50); + + final engineReadyEndtime = DateTime.fromMillisecondsSinceEpoch( + appStartInfoSrc.pluginRegistrationTime.toInt()) + .toUtc(); + expect(coldStartSpan?.endTimestamp, appStartEnd.toUtc()); + expect(pluginRegistrationSpan?.endTimestamp, engineReadyEndtime); + expect(sentrySetupSpan?.endTimestamp, + SentryFlutter.sentrySetupStartTime?.toUtc()); + expect(firstFrameRenderSpan?.endTimestamp, coldStartSpan?.endTimestamp); + }); + }); +} + +class Fixture { + final options = SentryFlutterOptions(dsn: fakeDsn); + final nativeBinding = MockSentryNativeBinding(); + final hub = MockHub(); + + late final tracer = SentryTracer( + SentryTransactionContext( + 'name', + 'op', + samplingDecision: SentryTracesSamplingDecision(true), + ), + hub, + startTimestamp: DateTime.fromMillisecondsSinceEpoch(0), + ); + + final nativeAppStart = NativeAppStart( + appStartTime: 0, + pluginRegistrationTime: 10, + isColdStart: true, + nativeSpanTimes: {}, + ); + + late final sut = NativeAppStartHandler(nativeBinding); + + Fixture() { + when(hub.options).thenReturn(options); + SentryFlutter.sentrySetupStartTime = DateTime.now().toUtc(); + } + + Future call({DateTime? appStartEnd}) async { + await sut.call(hub, options, appStartEnd: appStartEnd); + } + + SentryTransaction capturedTransaction() { + final args = verify(hub.captureTransaction( + captureAny, + traceContext: captureAnyNamed('traceContext'), + )).captured; + return args[0] as SentryTransaction; + } +} diff --git a/flutter/test/integrations/native_app_start_integration_test.dart b/flutter/test/integrations/native_app_start_integration_test.dart index 8fc85e6157..02dbee7116 100644 --- a/flutter/test/integrations/native_app_start_integration_test.dart +++ b/flutter/test/integrations/native_app_start_integration_test.dart @@ -1,436 +1,124 @@ @TestOn('vm') library flutter_test; -import 'package:collection/collection.dart'; +import 'dart:core'; + 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/integrations/native_app_start_handler.dart'; import 'package:sentry_flutter/src/integrations/native_app_start_integration.dart'; -import 'package:sentry/src/sentry_tracer.dart'; -import 'package:sentry_flutter/src/native/native_app_start.dart'; -import '../fake_frame_callback_handler.dart'; +import '../mock_frame_callback_handler.dart'; +import '../mocks.dart'; import '../mocks.mocks.dart'; -import 'fixture.dart'; void main() { - void setupMocks(Fixture fixture) { - when(fixture.hub.startTransaction('root /', 'ui.load', - description: null, startTimestamp: anyNamed('startTimestamp'))) - .thenReturn(fixture.createTracer()); - when(fixture.hub.configureScope(captureAny)).thenAnswer((_) {}); - when(fixture.hub - .captureTransaction(any, traceContext: anyNamed('traceContext'))) - .thenAnswer((_) async => SentryId.empty()); - } - - Future registerIntegration(Fixture fixture) async { - await fixture.registerIntegration(); - // Wait for the app start info to be fetched - // This ensures that setAppStartInfo has been called, which happens asynchronously - // in a post-frame callback. Waiting here prevents race conditions in subsequent tests - // that might depend on or modify the app start info. - await NativeAppStartIntegration.getAppStartInfo(); - } - - group('$NativeAppStartIntegration', () { - late Fixture fixture; - - setUp(() { - fixture = Fixture(); - setupMocks(fixture); - when(fixture.binding.fetchNativeAppStart()).thenAnswer((_) async => - NativeAppStart( - appStartTime: 0, - pluginRegistrationTime: 10, - isColdStart: true, - nativeSpanTimes: {})); - NativeAppStartIntegration.clearAppStartInfo(); - }); - - test('native app start measurement added to first transaction', () async { - NativeAppStartIntegration.appStartEnd = - DateTime.fromMillisecondsSinceEpoch(10); - - await registerIntegration(fixture); - final tracer = fixture.createTracer(); - final transaction = SentryTransaction(tracer); - - final processor = fixture.options.eventProcessors.first; - final enriched = - await processor.apply(transaction, Hint()) as SentryTransaction; - - final measurement = enriched.measurements['app_start_cold']!; - expect(measurement.value, 10); - expect(measurement.unit, DurationSentryMeasurementUnit.milliSecond); - }); - - test('native app start measurement not added to following transactions', - () async { - NativeAppStartIntegration.appStartEnd = - DateTime.fromMillisecondsSinceEpoch(10); - - await registerIntegration(fixture); - final tracer = fixture.createTracer(); - final transaction = SentryTransaction(tracer); - - final processor = fixture.options.eventProcessors.first; - - var enriched = - await processor.apply(transaction, Hint()) as SentryTransaction; - var secondEnriched = - await processor.apply(enriched, Hint()) as SentryTransaction; - - expect(secondEnriched.measurements.length, 1); - }); - - test('measurements appended', () async { - NativeAppStartIntegration.appStartEnd = - DateTime.fromMillisecondsSinceEpoch(10); - final measurement = SentryMeasurement.warmAppStart(Duration(seconds: 1)); - - await registerIntegration(fixture); - final tracer = fixture.createTracer(); - final transaction = SentryTransaction(tracer).copyWith(); - transaction.measurements[measurement.name] = measurement; - - final processor = fixture.options.eventProcessors.first; - - var enriched = - await processor.apply(transaction, Hint()) as SentryTransaction; - var secondEnriched = - await processor.apply(enriched, Hint()) as SentryTransaction; - - expect(secondEnriched.measurements.length, 2); - expect(secondEnriched.measurements.containsKey(measurement.name), true); - }); - - test('native app start measurement not added if more than 60s', () async { - NativeAppStartIntegration.appStartEnd = - DateTime.fromMillisecondsSinceEpoch(60001); - - await registerIntegration(fixture); - final tracer = fixture.createTracer(); - final transaction = SentryTransaction(tracer); - - final processor = fixture.options.eventProcessors.first; - final enriched = - await processor.apply(transaction, Hint()) as SentryTransaction; - - expect(enriched.measurements.isEmpty, true); - }); - - test('native app start integration is called and sets app start info', - () async { - NativeAppStartIntegration.appStartEnd = - DateTime.fromMillisecondsSinceEpoch(10); - - await registerIntegration(fixture); - final appStartInfo = await NativeAppStartIntegration.getAppStartInfo(); - expect(appStartInfo?.start, DateTime.fromMillisecondsSinceEpoch(0)); - expect(appStartInfo?.end, DateTime.fromMillisecondsSinceEpoch(10)); - }); - - test( - 'autoAppStart is false and appStartEnd is not set does not add app start measurement', - () async { - fixture.options.autoAppStart = false; - - await registerIntegration(fixture); - - final tracer = fixture.createTracer(); - final transaction = SentryTransaction(tracer); - - final processor = fixture.options.eventProcessors.first; - final enriched = - await processor.apply(transaction, Hint()) as SentryTransaction; - - expect(enriched.measurements.isEmpty, true); - expect(enriched.spans.isEmpty, true); - }); - - test( - 'does not trigger timeout if autoAppStart is false and setAppStartEnd is not called', - () async { - // setting a frame callback with a bigger timeout than our app start timeout so the timeout would theoretically be triggered - fixture = Fixture( - frameCallbackTimeout: NativeAppStartIntegration.timeoutDuration + - const Duration(seconds: 5)); - fixture.options.autoAppStart = false; + late Fixture fixture; - await registerIntegration(fixture); - final tracer = fixture.createTracer(); - final transaction = SentryTransaction(tracer); - - final processor = fixture.options.eventProcessors.first; - - final stopwatch = Stopwatch()..start(); - await processor.apply(transaction, Hint()) as SentryTransaction; - stopwatch.stop(); - - expect(stopwatch.elapsed < NativeAppStartIntegration.timeoutDuration, - isTrue); - }); - - test( - 'autoAppStart is false and appStartEnd is set adds app start measurement', - () async { - fixture.options.autoAppStart = false; - - await registerIntegration(fixture); - SentryFlutter.setAppStartEnd(DateTime.fromMillisecondsSinceEpoch(10)); - - final tracer = fixture.createTracer(); - final transaction = SentryTransaction(tracer); - - final processor = fixture.options.eventProcessors.first; - final enriched = - await processor.apply(transaction, Hint()) as SentryTransaction; - - final measurement = enriched.measurements['app_start_cold']!; - expect(measurement.value, 10); - expect(measurement.unit, DurationSentryMeasurementUnit.milliSecond); - - final appStartInfo = await NativeAppStartIntegration.getAppStartInfo(); - - final appStartSpan = enriched.spans.firstWhereOrNull((element) => - element.context.description == appStartInfo!.appStartTypeDescription); - final pluginRegistrationSpan = enriched.spans.firstWhereOrNull( - (element) => - element.context.description == - appStartInfo!.pluginRegistrationDescription); - final sentrySetupSpan = enriched.spans.firstWhereOrNull((element) => - element.context.description == appStartInfo!.sentrySetupDescription); - final firstFrameRenderSpan = enriched.spans.firstWhereOrNull((element) => - element.context.description == - appStartInfo!.firstFrameRenderDescription); - - expect(appStartSpan, isNotNull); - expect(pluginRegistrationSpan, isNotNull); - expect(sentrySetupSpan, isNotNull); - expect(firstFrameRenderSpan, isNotNull); - }); + setUp(() { + fixture = Fixture(); }); - group('App start spans', () { - late SentrySpan? coldStartSpan, - pluginRegistrationSpan, - sentrySetupSpan, - firstFrameRenderSpan; - // ignore: invalid_use_of_internal_member - late SentryTracer tracer; - late Fixture fixture; - late SentryTransaction enriched; - - final validNativeSpanTimes = { - 'correct span description': { - 'startTimestampMsSinceEpoch': 1, - 'stopTimestampMsSinceEpoch': 2, - }, - 'correct span description 2': { - 'startTimestampMsSinceEpoch': 4, - 'stopTimestampMsSinceEpoch': 6, - }, - 'correct span description 3': { - 'startTimestampMsSinceEpoch': 3, - 'stopTimestampMsSinceEpoch': 4, - }, - }; - - final invalidNativeSpanTimes = { - 'failing span with null timestamp': { - 'startTimestampMsSinceEpoch': null, - 'stopTimestampMsSinceEpoch': 3, - }, - 'failing span with string timestamp': { - 'startTimestampMsSinceEpoch': '1', - 'stopTimestampMsSinceEpoch': 3, - }, - }; - - final appStartInfoSrc = NativeAppStart( - appStartTime: 0, - pluginRegistrationTime: 10, - isColdStart: true, - nativeSpanTimes: { - ...validNativeSpanTimes, - ...invalidNativeSpanTimes, - }); - - setUp(() async { - fixture = Fixture(); - NativeAppStartIntegration.clearAppStartInfo(); - - NativeAppStartIntegration.appStartEnd = - DateTime.fromMillisecondsSinceEpoch(50); + test('$NativeAppStartIntegration adds integration', () async { + fixture.callIntegration(); - // dartLoadingEnd needs to be set after engine end (see MockNativeChannel) - SentryFlutter.sentrySetupStartTime = - DateTime.fromMillisecondsSinceEpoch(15); - - setupMocks(fixture); + expect( + fixture.options.sdk.integrations.contains('nativeAppStartIntegration'), + true); + }); - when(fixture.binding.fetchNativeAppStart()) - .thenAnswer((_) async => appStartInfoSrc); + test('$NativeAppStartIntegration adds postFrameCallback', () async { + fixture.callIntegration(); - await registerIntegration(fixture); - final processor = fixture.options.eventProcessors.first; - tracer = fixture.createTracer(); - final transaction = SentryTransaction(tracer); - enriched = - await processor.apply(transaction, Hint()) as SentryTransaction; + expect(fixture.frameCallbackHandler.postFrameCallback, isNotNull); + }); - final appStartInfo = await NativeAppStartIntegration.getAppStartInfo(); + test( + '$NativeAppStartIntegration postFrameCallback calls nativeAppStartHandler', + () async { + fixture.callIntegration(); - coldStartSpan = enriched.spans.firstWhereOrNull((element) => - element.context.description == appStartInfo?.appStartTypeDescription); - pluginRegistrationSpan = enriched.spans.firstWhereOrNull((element) => - element.context.description == - appStartInfo?.pluginRegistrationDescription); - sentrySetupSpan = enriched.spans.firstWhereOrNull((element) => - element.context.description == appStartInfo?.sentrySetupDescription); - firstFrameRenderSpan = enriched.spans.firstWhereOrNull((element) => - element.context.description == - appStartInfo?.firstFrameRenderDescription); - }); + final appStartEnd = DateTime.fromMicrosecondsSinceEpoch(50); + fixture.sut.appStartEnd = appStartEnd; - test('native app start spans not added to following transactions', - () async { - final processor = fixture.options.eventProcessors.first; + final postFrameCallback = fixture.frameCallbackHandler.postFrameCallback!; + postFrameCallback(Duration(seconds: 0)); - final transaction = SentryTransaction(fixture.createTracer()); + expect(fixture.nativeAppStartHandler.calls, 1); + expect(fixture.nativeAppStartHandler.appStartEnd, appStartEnd); + }); - final secondEnriched = - await processor.apply(transaction, Hint()) as SentryTransaction; + test( + '$NativeAppStartIntegration with disabled auto app start waits until appStartEnd is set', + () async { + fixture.options.autoAppStart = false; - expect(secondEnriched.spans.length, 0); - }); + fixture.callIntegration(); + final postFrameCallback = fixture.frameCallbackHandler.postFrameCallback!; + postFrameCallback(Duration(seconds: 0)); - test('includes only valid native spans', () async { - final spans = - enriched.spans.where((element) => element.data['native'] == true); + expect(fixture.nativeAppStartHandler.calls, 0); - expect(spans.length, validNativeSpanTimes.length); + final appStartEnd = DateTime.fromMicrosecondsSinceEpoch(50); + fixture.sut.appStartEnd = appStartEnd; - for (final span in spans) { - final validSpan = validNativeSpanTimes[span.context.description]; - expect(validSpan, isNotNull); - expect( - span.startTimestamp, - DateTime.fromMillisecondsSinceEpoch( - validSpan!['startTimestampMsSinceEpoch']!) - .toUtc()); - expect( - span.endTimestamp, - DateTime.fromMillisecondsSinceEpoch( - validSpan['stopTimestampMsSinceEpoch']!) - .toUtc()); - } - }); + await Future.delayed(Duration(milliseconds: 10)); - test('are correctly ordered', () async { - final spans = - enriched.spans.where((element) => element.data['native'] == true); + expect(fixture.frameCallbackHandler.postFrameCallback, isNotNull); + expect(fixture.nativeAppStartHandler.calls, 1); + expect(fixture.nativeAppStartHandler.appStartEnd, appStartEnd); + }); - final orderedSpans = spans.toList() - ..sort((a, b) => a.startTimestamp.compareTo(b.startTimestamp)); + test( + '$NativeAppStartIntegration with disabled auto app start waits until timeout', + () async { + fixture.options.autoAppStart = false; - expect(spans, orderedEquals(orderedSpans)); - }); + fixture.callIntegration(); + final postFrameCallback = fixture.frameCallbackHandler.postFrameCallback!; + postFrameCallback(Duration(seconds: 0)); - test('ignores invalid spans', () async { - final spans = - enriched.spans.where((element) => element.data['native'] == true); + expect(fixture.nativeAppStartHandler.calls, 0); - expect(spans, isNot(contains('failing span'))); - }); + await Future.delayed(Duration(seconds: 11)); - test('are added by event processor', () async { - expect(coldStartSpan, isNotNull); - expect(pluginRegistrationSpan, isNotNull); - expect(sentrySetupSpan, isNotNull); - expect(firstFrameRenderSpan, isNotNull); - }); + expect(fixture.frameCallbackHandler.postFrameCallback, isNotNull); + expect(fixture.nativeAppStartHandler.calls, 0); + expect(fixture.nativeAppStartHandler.appStartEnd, null); + }); +} - test('have correct op', () async { - const op = 'app.start.cold'; - expect(coldStartSpan?.context.operation, op); - expect(pluginRegistrationSpan?.context.operation, op); - expect(sentrySetupSpan?.context.operation, op); - expect(firstFrameRenderSpan?.context.operation, op); - }); +class Fixture { + final options = SentryFlutterOptions(dsn: fakeDsn); + final hub = MockHub(); - test('have correct parents', () async { - expect(coldStartSpan?.context.parentSpanId, tracer.context.spanId); - expect(pluginRegistrationSpan?.context.parentSpanId, - coldStartSpan?.context.spanId); - expect( - sentrySetupSpan?.context.parentSpanId, coldStartSpan?.context.spanId); - expect(firstFrameRenderSpan?.context.parentSpanId, - coldStartSpan?.context.spanId); - }); + final frameCallbackHandler = MockFrameCallbackHandler(); + final nativeAppStartHandler = MockNativeAppStartHandler(); - test('have correct traceId', () async { - final traceId = tracer.context.traceId; - expect(coldStartSpan?.context.traceId, traceId); - expect(pluginRegistrationSpan?.context.traceId, traceId); - expect(sentrySetupSpan?.context.traceId, traceId); - expect(firstFrameRenderSpan?.context.traceId, traceId); - }); + late NativeAppStartIntegration sut = NativeAppStartIntegration( + frameCallbackHandler, + nativeAppStartHandler, + ); - test('have correct startTimestamp', () async { - final appStartTime = DateTime.fromMillisecondsSinceEpoch( - appStartInfoSrc.appStartTime.toInt()) - .toUtc(); - expect(coldStartSpan?.startTimestamp, appStartTime); - expect(pluginRegistrationSpan?.startTimestamp, appStartTime); - expect(sentrySetupSpan?.startTimestamp, - pluginRegistrationSpan?.endTimestamp); - expect( - firstFrameRenderSpan?.startTimestamp, sentrySetupSpan?.endTimestamp); - }); + Fixture() { + when(hub.options).thenReturn(options); + } - test('have correct endTimestamp', () async { - final engineReadyEndtime = DateTime.fromMillisecondsSinceEpoch( - appStartInfoSrc.pluginRegistrationTime.toInt()) - .toUtc(); - expect(coldStartSpan?.endTimestamp, - NativeAppStartIntegration.appStartEnd?.toUtc()); - expect(pluginRegistrationSpan?.endTimestamp, engineReadyEndtime); - expect(sentrySetupSpan?.endTimestamp, - SentryFlutter.sentrySetupStartTime?.toUtc()); - expect(firstFrameRenderSpan?.endTimestamp, coldStartSpan?.endTimestamp); - }); - }); + void callIntegration() { + sut.call(hub, options); + } } -class Fixture extends IntegrationTestFixture { - @override - MockHub get hub => super.hub as MockHub; - - Fixture({Duration? frameCallbackTimeout}) - : super((binding) => NativeAppStartIntegration( - binding, - FakeFrameCallbackHandler( - finishAfterDuration: frameCallbackTimeout ?? - const Duration(milliseconds: 50)))) { - NativeAppStartIntegration.reset(); - hub = MockHub(); - // ignore: invalid_use_of_internal_member - when(hub.options).thenReturn(options); - SentryFlutter.sentrySetupStartTime = DateTime.now().toUtc(); - } +class MockNativeAppStartHandler implements NativeAppStartHandler { + DateTime? appStartEnd; + var calls = 0; - // ignore: invalid_use_of_internal_member - SentryTracer createTracer({ - bool? sampled = true, - }) { - final context = SentryTransactionContext( - 'name', - 'op', - samplingDecision: SentryTracesSamplingDecision(sampled!), - ); - return SentryTracer(context, hub); + @override + Future call(Hub hub, SentryFlutterOptions options, + {required DateTime? appStartEnd}) async { + this.appStartEnd = appStartEnd; + calls += 1; } } diff --git a/flutter/test/mock_frame_callback_handler.dart b/flutter/test/mock_frame_callback_handler.dart new file mode 100644 index 0000000000..e57a7c681c --- /dev/null +++ b/flutter/test/mock_frame_callback_handler.dart @@ -0,0 +1,25 @@ +import 'dart:async'; + +import 'package:flutter/scheduler.dart'; +import 'package:sentry_flutter/src/frame_callback_handler.dart'; + +class MockFrameCallbackHandler implements FrameCallbackHandler { + FrameCallback? postFrameCallback; + FrameCallback? persistentFrameCallback; + + @override + void addPostFrameCallback(FrameCallback callback) { + postFrameCallback = callback; + } + + @override + void addPersistentFrameCallback(FrameCallback callback) { + persistentFrameCallback = callback; + } + + @override + bool hasScheduledFrame = true; + + @override + Future get endOfFrame => Future.value(); +} diff --git a/flutter/test/navigation/sentry_display_widget_test.dart b/flutter/test/navigation/sentry_display_widget_test.dart index abbd6e70dc..37f5e26988 100644 --- a/flutter/test/navigation/sentry_display_widget_test.dart +++ b/flutter/test/navigation/sentry_display_widget_test.dart @@ -4,7 +4,6 @@ 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'; @@ -53,52 +52,6 @@ void main() { 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)), - pluginRegistration: getUtcDateTime().add(Duration(seconds: 3)), - sentrySetupStart: getUtcDateTime().add(Duration(seconds: 4)), - nativeSpanTimes: [], - ); - 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 { diff --git a/flutter/test/navigation/time_to_display_tracker_test.dart b/flutter/test/navigation/time_to_display_tracker_test.dart index 6e074bac6e..79f2d377d9 100644 --- a/flutter/test/navigation/time_to_display_tracker_test.dart +++ b/flutter/test/navigation/time_to_display_tracker_test.dart @@ -50,22 +50,6 @@ void main() { expect(transaction.context.operation, SentrySpanOperations.uiLoad); expect(transaction.startTimestamp, ttidSpan?.startTimestamp); }); - - test('finishes ttid span', () async { - 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 = _getTTIDSpan(transaction); - expect(ttidSpan?.context.operation, - SentrySpanOperations.uiTimeToInitialDisplay); - expect(ttidSpan?.finished, isTrue); - expect(ttidSpan?.origin, SentryTraceOrigins.autoUiTimeToDisplay); - }); }); group('in regular routes', () { @@ -166,32 +150,6 @@ void main() { }); }); - group('in root screen app start route', () { - test( - 'finishes span after timeout with deadline exceeded and ttid matching end time', - () async { - final sut = fixture.getSut(); - final transaction = - fixture.getTransaction(name: 'root ("/")') as SentryTracer; - final endTimestamp = - fixture.startTimestamp.add(const Duration(milliseconds: 10)); - - await sut.trackAppStartTTD(transaction, - startTimestamp: fixture.startTimestamp, endTimestamp: endTimestamp); - - final ttidSpan = _getTTIDSpan(transaction); - expect(ttidSpan, isNotNull); - - final ttfdSpan = _getTTFDSpan(transaction); - expect(ttfdSpan, isNotNull); - - expect(ttfdSpan?.finished, isTrue); - expect(ttfdSpan?.status, SpanStatus.deadlineExceeded()); - expect(ttfdSpan?.endTimestamp, ttidSpan?.endTimestamp); - expect(ttfdSpan?.startTimestamp, ttidSpan?.startTimestamp); - }); - }); - test('multiple ttfd timeouts have correct ttid matching end time', () async { final sut = fixture.getSut(); diff --git a/flutter/test/navigation/time_to_initial_display_tracker_test.dart b/flutter/test/navigation/time_to_initial_display_tracker_test.dart index 1f85360f55..526343a8bd 100644 --- a/flutter/test/navigation/time_to_initial_display_tracker_test.dart +++ b/flutter/test/navigation/time_to_initial_display_tracker_test.dart @@ -22,41 +22,6 @@ void main() { 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', diff --git a/flutter/test/sentry_navigator_observer_test.dart b/flutter/test/sentry_navigator_observer_test.dart index 524f3e2ece..6d487a3b4f 100644 --- a/flutter/test/sentry_navigator_observer_test.dart +++ b/flutter/test/sentry_navigator_observer_test.dart @@ -7,7 +7,6 @@ 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/src/sentry_tracer.dart'; import 'package:sentry_flutter/src/native/native_frames.dart'; import 'package:sentry_flutter/src/navigation/time_to_display_tracker.dart'; @@ -489,49 +488,32 @@ void main() { verify(span.setData('route_settings_arguments', arguments)); }); - test('flutter root name is replaced', () async { + test('root route does not start transaction', () 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)), - pluginRegistration: DateTime.now().add(const Duration(seconds: 3)), - sentrySetupStart: DateTime.now().add(const Duration(seconds: 4)), - nativeSpanTimes: [], - ), - ); final hub = _MockHub(); - final span = getMockSentryTracer(name: '/'); + 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); sut.didPush(rootRoute, null); - await Future.delayed(const Duration(milliseconds: 100)); - final context = verify(hub.startTransactionWithContext( - captureAny, - waitForChildren: true, + verifyNever(hub.startTransactionWithContext( + any, startTimestamp: anyNamed('startTimestamp'), + waitForChildren: true, autoFinishAfter: anyNamed('autoFinishAfter'), trimEnd: true, onFinish: anyNamed('onFinish'), - )).captured.single as SentryTransactionContext; - - expect(context.name, 'root /'); + )); hub.configureScope((scope) { - expect(scope.span, span); + expect(scope.span, null); }); });