Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Start missing TTFD for root screen transaction #2332

Merged
merged 8 commits into from
Oct 11, 2024
Merged
Show file tree
Hide file tree
Changes from 5 commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@
- Rounding error used on frames.total and reject frame measurements if frames.total is less than frames.slow or frames.frozen ([#2308](https://github.com/getsentry/sentry-dart/pull/2308))
- iOS replay integration when only `onErrorSampleRate` is specified ([#2306](https://github.com/getsentry/sentry-dart/pull/2306))
- Fix TTID timing issue ([#2326](https://github.com/getsentry/sentry-dart/pull/2326))
- Start missing TTFD for root screen transaction ([#2332](https://github.com/getsentry/sentry-dart/pull/2332))

### Deprecate

Expand Down
80 changes: 28 additions & 52 deletions flutter/lib/src/integrations/native_app_start_handler.dart
Original file line number Diff line number Diff line change
Expand Up @@ -21,7 +21,7 @@ class NativeAppStartHandler {
static const _maxAppStartMillis = 60000;

Future<void> call(Hub hub, SentryFlutterOptions options,
{required DateTime? appStartEnd}) async {
{required DateTime appStartEnd}) async {
_hub = hub;
_options = options;

Expand All @@ -42,43 +42,33 @@ class NativeAppStartHandler {
SentrySpanOperations.uiLoad,
startTimestamp: appStartInfo.start,
);
final ttidSpan = transaction.startChild(
SentrySpanOperations.uiTimeToInitialDisplay,
description: '$screenName initial display',

await options.timeToDisplayTracker.track(
transaction,
startTimestamp: appStartInfo.start,
endTimestamp: appStartInfo.end,
origin: SentryTraceOrigins.autoUiTimeToDisplay,
);

// 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
// Enrich Transaction
SentryMeasurement? measurement = appStartInfo.toMeasurement();
sentryTracer.measurements[measurement.name] = appStartInfo.toMeasurement();
await _attachAppStartSpans(appStartInfo, sentryTracer);

await ttidSpan.finish(endTimestamp: appStartInfo.end);
// Finish Transaction
await transaction.finish(endTimestamp: appStartInfo.end);
}

_AppStartInfo? _infoNativeAppStart(
NativeAppStart nativeAppStart,
DateTime? appStartEnd,
DateTime appStartEnd,
) {
final sentrySetupStartDateTime = SentryFlutter.sentrySetupStartTime;
if (sentrySetupStartDateTime == null) {
Expand All @@ -90,23 +80,18 @@ class NativeAppStartHandler {
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;
}
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 = [];
Expand Down Expand Up @@ -145,9 +130,6 @@ class NativeAppStartHandler {
_AppStartInfo appStartInfo, SentryTracer transaction) async {
final transactionTraceId = transaction.context.traceId;
final appStartEnd = appStartInfo.end;
if (appStartEnd == null) {
return;
}

final appStartSpan = await _createAndFinishSpan(
tracer: transaction,
Expand Down Expand Up @@ -256,30 +238,24 @@ class _AppStartInfo {
_AppStartInfo(
this.type, {
required this.start,
required this.end,
required this.pluginRegistration,
required this.sentrySetupStart,
required this.nativeSpanTimes,
this.end,
});

final _AppStartType type;
final DateTime start;
final DateTime end;
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);
Duration get duration => end.difference(start);

SentryMeasurement? toMeasurement() {
SentryMeasurement toMeasurement() {
final duration = this.duration;
if (duration == null) {
return null;
}
return type == _AppStartType.cold
? SentryMeasurement.coldAppStart(duration)
: SentryMeasurement.warmAppStart(duration);
Expand Down
25 changes: 17 additions & 8 deletions flutter/lib/src/integrations/native_app_start_integration.dart
Original file line number Diff line number Diff line change
Expand Up @@ -33,15 +33,24 @@
void call(Hub hub, SentryFlutterOptions options) async {
_frameCallbackHandler.addPostFrameCallback((timeStamp) async {
try {
if (!options.autoAppStart && _appStartEnd == null) {
await _appStartEndCompleter.future
.timeout(const Duration(seconds: 10));
DateTime? appStartEnd;
if (options.autoAppStart) {
appStartEnd = options.clock();

Check warning on line 38 in flutter/lib/src/integrations/native_app_start_integration.dart

View workflow job for this annotation

GitHub Actions / analyze / analyze

The member 'clock' can only be used within its package.

See https://dart.dev/diagnostics/invalid_use_of_internal_member to learn more about this problem.
} else if (_appStartEnd == null) {
await _appStartEndCompleter.future.timeout(
const Duration(seconds: 10),
);
appStartEnd = _appStartEnd;
} else {
appStartEnd = null;
}
if (appStartEnd != null) {
await _nativeAppStartHandler.call(
hub,
options,
appStartEnd: appStartEnd,
);
}
await _nativeAppStartHandler.call(
hub,
options,
appStartEnd: _appStartEnd,
);
} catch (exception, stackTrace) {
options.logger(
SentryLevel.error,
Expand Down
21 changes: 7 additions & 14 deletions flutter/lib/src/navigation/sentry_navigator_observer.dart
Original file line number Diff line number Diff line change
Expand Up @@ -78,7 +78,6 @@ class SentryNavigatorObserver extends RouteObserver<PageRoute<dynamic>> {
bool setRouteNameAsTransaction = false,
RouteNameExtractor? routeNameExtractor,
AdditionalInfoExtractor? additionalInfoProvider,
@visibleForTesting TimeToDisplayTracker? timeToDisplayTracker,
List<String>? ignoreRoutes,
}) : _hub = hub ?? HubAdapter(),
_enableAutoTransactions = enableAutoTransactions,
Expand All @@ -92,19 +91,17 @@ class SentryNavigatorObserver extends RouteObserver<PageRoute<dynamic>> {
if (enableAutoTransactions) {
_hub.options.sdk.addIntegration('UINavigationTracing');
}
_timeToDisplayTracker =
timeToDisplayTracker ?? _initializeTimeToDisplayTracker();
_timeToDisplayTracker = _initializeTimeToDisplayTracker();
}

/// Initializes the TimeToDisplayTracker with the option to enable time to full display tracing.
TimeToDisplayTracker _initializeTimeToDisplayTracker() {
bool enableTimeToFullDisplayTracing = false;
TimeToDisplayTracker? _initializeTimeToDisplayTracker() {
final options = _hub.options;
if (options is SentryFlutterOptions) {
enableTimeToFullDisplayTracing = options.enableTimeToFullDisplayTracing;
return options.timeToDisplayTracker;
} else {
return null;
}
return TimeToDisplayTracker(
enableTimeToFullDisplayTracing: enableTimeToFullDisplayTracing);
}

final Hub _hub;
Expand All @@ -115,11 +112,7 @@ class SentryNavigatorObserver extends RouteObserver<PageRoute<dynamic>> {
final AdditionalInfoExtractor? _additionalInfoProvider;
final SentryNativeBinding? _native;
final List<String> _ignoreRoutes;
static TimeToDisplayTracker? _timeToDisplayTracker;

@internal
static TimeToDisplayTracker? get timeToDisplayTracker =>
_timeToDisplayTracker;
TimeToDisplayTracker? _timeToDisplayTracker;

ISentrySpan? _transaction;

Expand Down Expand Up @@ -362,7 +355,7 @@ class SentryNavigatorObserver extends RouteObserver<PageRoute<dynamic>> {
}

if (!isAppStart) {
await _timeToDisplayTracker?.trackRegularRouteTTD(
await _timeToDisplayTracker?.track(
transaction,
startTimestamp: startTimestamp,
);
Expand Down
50 changes: 31 additions & 19 deletions flutter/lib/src/navigation/time_to_display_tracker.dart
Original file line number Diff line number Diff line change
Expand Up @@ -9,38 +9,50 @@
@internal
class TimeToDisplayTracker {
final TimeToInitialDisplayTracker _ttidTracker;
final TimeToFullDisplayTracker? _ttfdTracker;
final bool enableTimeToFullDisplayTracing;
final TimeToFullDisplayTracker _ttfdTracker;
final SentryFlutterOptions options;

TimeToDisplayTracker({
TimeToInitialDisplayTracker? ttidTracker,
TimeToFullDisplayTracker? ttfdTracker,
required this.enableTimeToFullDisplayTracing,
required this.options,
}) : _ttidTracker = ttidTracker ?? TimeToInitialDisplayTracker(),
_ttfdTracker = enableTimeToFullDisplayTracing
? ttfdTracker ?? TimeToFullDisplayTracker()
: null;

Future<void> trackRegularRouteTTD(ISentrySpan transaction,
{required DateTime startTimestamp}) async {
await _ttidTracker.trackRegularRoute(transaction, startTimestamp);
await _trackTTFDIfEnabled(transaction, startTimestamp);
}

Future<void> _trackTTFDIfEnabled(
ISentrySpan transaction, DateTime startTimestamp) async {
if (enableTimeToFullDisplayTracing) {
await _ttfdTracker?.track(transaction, startTimestamp);
_ttfdTracker = ttfdTracker ?? TimeToFullDisplayTracker();

Future<void> track(
ISentrySpan transaction, {
required DateTime startTimestamp,
DateTime? endTimestamp,
String? origin,
}) async {
// TTID
await _ttidTracker.track(
transaction: transaction,
startTimestamp: startTimestamp,
endTimestamp: endTimestamp,
origin: origin,
);

// TTFD
if (options.enableTimeToFullDisplayTracing) {
await _ttfdTracker.track(
transaction: transaction,
startTimestamp: startTimestamp,
);
}
}

@internal
Future<void> reportFullyDisplayed() async {
return _ttfdTracker?.reportFullyDisplayed();
if (options.enableTimeToFullDisplayTracing) {
denrase marked this conversation as resolved.
Show resolved Hide resolved
return _ttfdTracker.reportFullyDisplayed();
}
}

void clear() {
_ttidTracker.clear();
_ttfdTracker?.clear();
if (options.enableTimeToFullDisplayTracing) {
_ttfdTracker.clear();

Check warning on line 55 in flutter/lib/src/navigation/time_to_display_tracker.dart

View check run for this annotation

Codecov / codecov/patch

flutter/lib/src/navigation/time_to_display_tracker.dart#L55

Added line #L55 was not covered by tests
}
}
}
57 changes: 29 additions & 28 deletions flutter/lib/src/navigation/time_to_full_display_tracker.dart
Original file line number Diff line number Diff line change
Expand Up @@ -37,54 +37,55 @@
EndTimestampProvider _endTimestampProvider = ttidEndTimestampProvider();
Completer<void> _completedTTFDTracking = Completer<void>();

Future<void> track(ISentrySpan transaction, DateTime startTimestamp) async {
Future<void> track({
required ISentrySpan transaction,
required DateTime startTimestamp,
}) async {
_startTimestamp = startTimestamp;
_transaction = transaction as SentryTracer;
_ttfdSpan = transaction.startChild(SentrySpanOperations.uiTimeToFullDisplay,
description: '${transaction.name} full display',
startTimestamp: startTimestamp);
_ttfdSpan = transaction.startChild(
SentrySpanOperations.uiTimeToFullDisplay,
description: '${transaction.name} full display',
startTimestamp: startTimestamp,
);
_ttfdSpan?.origin = SentryTraceOrigins.manualUiTimeToDisplay;
// Wait for TTFD to finish
await _completedTTFDTracking.future
.timeout(_autoFinishAfter, onTimeout: handleTimeout);
await _completedTTFDTracking.future.timeout(
_autoFinishAfter,
onTimeout: _handleTimeout,
);
}

clear();
Future<void> reportFullyDisplayed() async {
await _complete(getUtcDateTime());
}

void _handleTimeout() {
_complete(null);
}

void handleTimeout() {
Future<void> _complete(DateTime? timestamp) async {
final ttfdSpan = _ttfdSpan;
final startTimestamp = _startTimestamp;
final endTimestamp = _endTimestampProvider();
final endTimestamp = timestamp ?? _endTimestampProvider();

if (ttfdSpan == null ||
ttfdSpan.finished == true ||
startTimestamp == null ||
endTimestamp == null) {
_completedTTFDTracking.complete();
clear();

Check warning on line 77 in flutter/lib/src/navigation/time_to_full_display_tracker.dart

View check run for this annotation

Codecov / codecov/patch

flutter/lib/src/navigation/time_to_full_display_tracker.dart#L77

Added line #L77 was not covered by tests
return;
}

_setTTFDMeasurement(startTimestamp, endTimestamp);
ttfdSpan.finish(
status: SpanStatus.deadlineExceeded(), endTimestamp: endTimestamp);

_completedTTFDTracking.complete();
}

Future<void> reportFullyDisplayed() async {
final endTimestamp = getUtcDateTime();
final startTimestamp = _startTimestamp;
final ttfdSpan = _ttfdSpan;

if (ttfdSpan?.finished == true || startTimestamp == null) {
_completedTTFDTracking.complete();
return;
}

_setTTFDMeasurement(startTimestamp, endTimestamp);
await ttfdSpan?.finish(status: SpanStatus.ok(), endTimestamp: endTimestamp);

await ttfdSpan.finish(
status:
timestamp != null ? SpanStatus.ok() : SpanStatus.deadlineExceeded(),
endTimestamp: endTimestamp,
);
_completedTTFDTracking.complete();
clear();
}

void _setTTFDMeasurement(DateTime startTimestamp, DateTime endTimestamp) {
Expand Down
Loading
Loading