From 5e7abc5157b9e43973db9bc8e2a883d69d3fe136 Mon Sep 17 00:00:00 2001 From: Giancarlo Buenaflor Date: Mon, 4 Mar 2024 14:52:44 +0100 Subject: [PATCH] refactor: fetch app start in integration instead of event processor (#1905) * Change app start integration in a way that works with ttid as well * Formatting * Update * add visibleForTesting * Update * update * Add app start info test * Remove set app start info null * Review improvements * run on arm mac * Fix integration test --- .github/workflows/flutter_test.yml | 2 +- CHANGELOG.md | 4 + .../integration_test/integration_test.dart | 4 + .../native_app_start_event_processor.dart | 50 ++------ flutter/lib/src/frame_callback_handler.dart | 15 +++ .../native_app_start_integration.dart | 120 +++++++++++++++--- flutter/lib/src/native/sentry_native.dart | 3 + flutter/lib/src/sentry_flutter.dart | 11 +- flutter/test/fake_frame_callback_handler.dart | 19 +++ .../native_app_start_integration_test.dart | 23 ++-- flutter/test/mocks.dart | 3 + 11 files changed, 181 insertions(+), 73 deletions(-) create mode 100644 flutter/lib/src/frame_callback_handler.dart create mode 100644 flutter/test/fake_frame_callback_handler.dart diff --git a/.github/workflows/flutter_test.yml b/.github/workflows/flutter_test.yml index 637b4d1a41..4d60fabca5 100644 --- a/.github/workflows/flutter_test.yml +++ b/.github/workflows/flutter_test.yml @@ -111,7 +111,7 @@ jobs: cocoa: name: "${{ matrix.target }} | ${{ matrix.sdk }}" - runs-on: macos-13 + runs-on: macos-latest-xlarge timeout-minutes: 30 defaults: run: diff --git a/CHANGELOG.md b/CHANGELOG.md index 8377034385..a7f259f8b0 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,10 @@ - Use `recordHttpBreadcrumbs` to set iOS `enableNetworkBreadcrumbs` ([#1884](https://github.com/getsentry/sentry-dart/pull/1884)) +### Improvements + +- App start is now fetched within integration instead of event processor ([#1905](https://github.com/getsentry/sentry-dart/pull/1905)) + ## 7.16.1 ### Fixes diff --git a/flutter/example/integration_test/integration_test.dart b/flutter/example/integration_test/integration_test.dart index c4c71edb41..f292d04cfc 100644 --- a/flutter/example/integration_test/integration_test.dart +++ b/flutter/example/integration_test/integration_test.dart @@ -1,4 +1,5 @@ // ignore_for_file: avoid_print +// ignore_for_file: invalid_use_of_internal_member import 'dart:async'; import 'dart:convert'; @@ -8,6 +9,7 @@ import 'package:flutter_test/flutter_test.dart'; import 'package:sentry_flutter/sentry_flutter.dart'; import 'package:sentry_flutter_example/main.dart'; import 'package:http/http.dart'; +import 'package:sentry_flutter/src/integrations/native_app_start_integration.dart'; void main() { // const org = 'sentry-sdks'; @@ -24,6 +26,8 @@ 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/lib/src/event_processor/native_app_start_event_processor.dart b/flutter/lib/src/event_processor/native_app_start_event_processor.dart index a7abe62e05..fd1a5ec169 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,29 @@ import 'dart:async'; import 'package:sentry/sentry.dart'; +import '../integrations/integrations.dart'; import '../native/sentry_native.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; - - NativeAppStartEventProcessor( - this._native, - ); - final SentryNative _native; + NativeAppStartEventProcessor(this._native); + @override Future apply(SentryEvent event, {Hint? hint}) async { - final appStartEnd = _native.appStartEnd; + if (_native.didAddAppStartMeasurement || event is! SentryTransaction) { + return event; + } + + final appStartInfo = await NativeAppStartIntegration.getAppStartInfo(); + final measurement = appStartInfo?.toMeasurement(); - 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 (measurement != null) { event.measurements[measurement.name] = measurement; + _native.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..71a8f928b1 --- /dev/null +++ b/flutter/lib/src/frame_callback_handler.dart @@ -0,0 +1,15 @@ +import 'package:flutter/scheduler.dart'; + +abstract class FrameCallbackHandler { + void addPostFrameCallback(FrameCallback callback); +} + +class DefaultFrameCallbackHandler implements FrameCallbackHandler { + @override + void addPostFrameCallback(FrameCallback callback) { + try { + /// Flutter >= 2.12 throws if SchedulerBinding.instance isn't initialized. + SchedulerBinding.instance.addPostFrameCallback(callback); + } catch (_) {} + } +} diff --git a/flutter/lib/src/integrations/native_app_start_integration.dart b/flutter/lib/src/integrations/native_app_start_integration.dart index 47bf79dff4..91d0c01940 100644 --- a/flutter/lib/src/integrations/native_app_start_integration.dart +++ b/flutter/lib/src/integrations/native_app_start_integration.dart @@ -1,31 +1,103 @@ -import 'package:flutter/scheduler.dart'; -import 'package:sentry/sentry.dart'; +import 'dart:async'; -import '../sentry_flutter_options.dart'; +import 'package:meta/meta.dart'; + +import '../../sentry_flutter.dart'; +import '../frame_callback_handler.dart'; import '../native/sentry_native.dart'; import '../event_processor/native_app_start_event_processor.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._frameCallbackHandler); final SentryNative _native; - final SchedulerBindingProvider _schedulerBindingProvider; + final FrameCallbackHandler _frameCallbackHandler; + + /// We filter out App starts more than 60s + static const _maxAppStartMillis = 60000; + + static Completer _appStartCompleter = + Completer(); + static AppStartInfo? _appStartInfo; + + @internal + static bool isIntegrationTest = false; + + @internal + static void setAppStartInfo(AppStartInfo? appStartInfo) { + _appStartInfo = appStartInfo; + if (_appStartCompleter.isCompleted) { + _appStartCompleter = Completer(); + } + _appStartCompleter.complete(appStartInfo); + } + + @internal + static Future getAppStartInfo() { + if (_appStartInfo != null) { + return Future.value(_appStartInfo); + } + return _appStartCompleter.future; + } + + @visibleForTesting + static void clearAppStartInfo() { + _appStartInfo = null; + _appStartCompleter = 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))); + setAppStartInfo(appStartInfo); + return; + } + if (options.autoAppStart) { - final schedulerBinding = _schedulerBindingProvider(); - if (schedulerBinding == null) { - options.logger(SentryLevel.debug, - 'Scheduler binding is null. Can\'t auto detect app start time.'); - } else { - schedulerBinding.addPostFrameCallback((timeStamp) { - // ignore: invalid_use_of_internal_member - _native.appStartEnd = options.clock(); - }); - } + _frameCallbackHandler.addPostFrameCallback((timeStamp) async { + if (_native.didFetchAppStart) { + return; + } + + // We only assign the current time if it's not already set - this is useful in tests + // ignore: invalid_use_of_internal_member + _native.appStartEnd ??= options.clock(); + final appStartEnd = _native.appStartEnd; + final nativeAppStart = await _native.fetchNativeAppStart(); + + if (nativeAppStart == null || appStartEnd == null) { + return; + } + + final appStartDateTime = DateTime.fromMillisecondsSinceEpoch( + nativeAppStart.appStartTime.toInt()); + 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) { + setAppStartInfo(null); + return; + } + + final appStartInfo = AppStartInfo( + nativeAppStart.isColdStart ? AppStartType.cold : AppStartType.warm, + start: DateTime.fromMillisecondsSinceEpoch( + nativeAppStart.appStartTime.toInt()), + end: appStartEnd); + setAppStartInfo(appStartInfo); + }); } options.addEventProcessor(NativeAppStartEventProcessor(_native)); @@ -34,5 +106,19 @@ class NativeAppStartIntegration extends Integration { } } -/// Used to provide scheduler binding at call time. -typedef SchedulerBindingProvider = SchedulerBinding? Function(); +enum AppStartType { cold, warm } + +class AppStartInfo { + AppStartInfo(this.type, {required this.start, required this.end}); + + final AppStartType type; + final DateTime start; + final DateTime end; + + SentryMeasurement toMeasurement() { + final duration = end.difference(start); + return type == AppStartType.cold + ? SentryMeasurement.coldAppStart(duration) + : SentryMeasurement.warmAppStart(duration); + } +} diff --git a/flutter/lib/src/native/sentry_native.dart b/flutter/lib/src/native/sentry_native.dart index b8d2206a8d..a7973f8a12 100644 --- a/flutter/lib/src/native/sentry_native.dart +++ b/flutter/lib/src/native/sentry_native.dart @@ -27,6 +27,9 @@ class SentryNative { /// Flag indicating if app start was already fetched. bool get didFetchAppStart => _didFetchAppStart; + /// Flag indicating if app start measurement was added to the first transaction. + bool didAddAppStartMeasurement = false; + /// Fetch [NativeAppStart] from native channels. Can only be called once. Future fetchNativeAppStart() async { _didFetchAppStart = true; diff --git a/flutter/lib/src/sentry_flutter.dart b/flutter/lib/src/sentry_flutter.dart index 62a9043bc9..9822b49665 100644 --- a/flutter/lib/src/sentry_flutter.dart +++ b/flutter/lib/src/sentry_flutter.dart @@ -1,7 +1,6 @@ import 'dart:async'; import 'dart:ui'; -import 'package:flutter/scheduler.dart'; import 'package:flutter/services.dart'; import 'package:flutter/widgets.dart'; import 'package:meta/meta.dart'; @@ -9,6 +8,7 @@ import '../sentry_flutter.dart'; import 'event_processor/android_platform_exception_event_processor.dart'; import 'event_processor/flutter_exception_event_processor.dart'; import 'event_processor/platform_exception_event_processor.dart'; +import 'frame_callback_handler.dart'; import 'integrations/connectivity/connectivity_integration.dart'; import 'integrations/screenshot_integration.dart'; import 'native/factory.dart'; @@ -189,13 +189,7 @@ mixin SentryFlutter { if (_native != null) { integrations.add(NativeAppStartIntegration( _native!, - () { - try { - /// Flutter >= 2.12 throws if SchedulerBinding.instance isn't initialized. - return SchedulerBinding.instance; - } catch (_) {} - return null; - }, + DefaultFrameCallbackHandler(), )); } return integrations; @@ -231,6 +225,7 @@ mixin SentryFlutter { @internal static SentryNative? get native => _native; + @internal static set native(SentryNative? value) => _native = value; static SentryNative? _native; diff --git a/flutter/test/fake_frame_callback_handler.dart b/flutter/test/fake_frame_callback_handler.dart new file mode 100644 index 0000000000..103045d0e2 --- /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) async { + // ignore: inference_failure_on_instance_creation + 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..135d90f34b 100644 --- a/flutter/test/integrations/native_app_start_integration_test.dart +++ b/flutter/test/integrations/native_app_start_integration_test.dart @@ -1,5 +1,4 @@ @TestOn('vm') - import 'package:flutter_test/flutter_test.dart'; import 'package:mockito/mockito.dart'; import 'package:sentry_flutter/sentry_flutter.dart'; @@ -7,6 +6,7 @@ import 'package:sentry_flutter/src/integrations/native_app_start_integration.dar import 'package:sentry_flutter/src/native/sentry_native.dart'; import 'package:sentry/src/sentry_tracer.dart'; +import '../fake_frame_callback_handler.dart'; import '../mocks.dart'; import '../mocks.mocks.dart'; @@ -18,10 +18,10 @@ void main() { TestWidgetsFlutterBinding.ensureInitialized(); fixture = Fixture(); + NativeAppStartIntegration.clearAppStartInfo(); }); 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); @@ -40,7 +40,6 @@ 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); @@ -58,7 +57,6 @@ void main() { }); test('measurements appended', () async { - fixture.options.autoAppStart = false; fixture.native.appStartEnd = DateTime.fromMillisecondsSinceEpoch(10); fixture.binding.nativeAppStart = NativeAppStart(0, true); final measurement = SentryMeasurement.warmAppStart(Duration(seconds: 1)); @@ -79,7 +77,6 @@ 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); @@ -93,6 +90,18 @@ void main() { expect(enriched.measurements.isEmpty, true); }); + + test('native app start integration is called and sets app start info', + () async { + fixture.native.appStartEnd = DateTime.fromMillisecondsSinceEpoch(10); + fixture.binding.nativeAppStart = NativeAppStart(0, true); + + fixture.getNativeAppStartIntegration().call(fixture.hub, fixture.options); + + final appStartInfo = await NativeAppStartIntegration.getAppStartInfo(); + expect(appStartInfo?.start, DateTime.fromMillisecondsSinceEpoch(0)); + expect(appStartInfo?.end, DateTime.fromMillisecondsSinceEpoch(10)); + }); }); } @@ -110,9 +119,7 @@ class Fixture { NativeAppStartIntegration getNativeAppStartIntegration() { return NativeAppStartIntegration( native, - () { - return TestWidgetsFlutterBinding.ensureInitialized(); - }, + FakeFrameCallbackHandler(), ); } diff --git a/flutter/test/mocks.dart b/flutter/test/mocks.dart index b2e01788c1..41c3269393 100644 --- a/flutter/test/mocks.dart +++ b/flutter/test/mocks.dart @@ -171,6 +171,9 @@ class TestMockSentryNative implements SentryNative { @override bool get didFetchAppStart => _didFetchAppStart; + @override + bool didAddAppStartMeasurement = false; + Breadcrumb? breadcrumb; var numberOfAddBreadcrumbCalls = 0; var numberOfBeginNativeFramesCollectionCalls = 0;