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

Feat: Slow/Frozen frames metrics #1609

Merged
merged 16 commits into from
Jul 28, 2021
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -3,6 +3,7 @@
## Unreleased

* Fix: set min sdk version of sentry-android-fragment to API 14 (#1608)
* Feat: Slow/Frozen frames metrics (#)
marandaneto marked this conversation as resolved.
Show resolved Hide resolved

## 5.1.0-beta.5

Expand Down
1 change: 1 addition & 0 deletions buildSrc/src/main/java/Config.kt
Original file line number Diff line number Diff line change
Expand Up @@ -52,6 +52,7 @@ object Config {
private val lifecycleVersion = "2.2.0"
val lifecycleProcess = "androidx.lifecycle:lifecycle-process:$lifecycleVersion"
val lifecycleCommonJava8 = "androidx.lifecycle:lifecycle-common-java8:$lifecycleVersion"
val androidxCore = "androidx.core:core:1.3.2"

val slf4jApi = "org.slf4j:slf4j-api:1.7.30"
val logbackVersion = "1.2.3"
Expand Down
6 changes: 6 additions & 0 deletions sentry-android-core/api/sentry-android-core.api
Original file line number Diff line number Diff line change
@@ -1,3 +1,6 @@
public final class io/sentry/android/core/ActivityFramesState {
}

public final class io/sentry/android/core/ActivityLifecycleIntegration : android/app/Application$ActivityLifecycleCallbacks, io/sentry/Integration, java/io/Closeable {
public fun <init> (Landroid/app/Application;Lio/sentry/android/core/IBuildInfoProvider;)V
public fun close ()V
Expand Down Expand Up @@ -35,6 +38,9 @@ public final class io/sentry/android/core/AppLifecycleIntegration : io/sentry/In
}

public final class io/sentry/android/core/AppStartState {
public fun getAppStartInterval ()Ljava/lang/Long;
public static fun getInstance ()Lio/sentry/android/core/AppStartState;
public fun isColdStart ()Z
}

public final class io/sentry/android/core/BuildConfig {
Expand Down
1 change: 1 addition & 0 deletions sentry-android-core/build.gradle.kts
Original file line number Diff line number Diff line change
Expand Up @@ -79,6 +79,7 @@ dependencies {
// lifecycle processor, session tracking
implementation(Config.Libs.lifecycleProcess)
implementation(Config.Libs.lifecycleCommonJava8)
implementation(Config.Libs.androidxCore)

compileOnly(Config.CompileOnly.nopen)
errorprone(Config.CompileOnly.nopenChecker)
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,91 @@
package io.sentry.android.core;

import android.app.Activity;
import android.util.SparseIntArray;
import androidx.core.app.FrameMetricsAggregator;
import io.sentry.protocol.MeasurementValue;
import io.sentry.protocol.SentryId;
import java.util.Collections;
import java.util.HashMap;
import java.util.Map;
import java.util.WeakHashMap;
import org.jetbrains.annotations.ApiStatus;
import org.jetbrains.annotations.NotNull;
import org.jetbrains.annotations.Nullable;

@ApiStatus.Internal
public final class ActivityFramesState {

private static final @NotNull ActivityFramesState instance = new ActivityFramesState();

private final @NotNull FrameMetricsAggregator frameMetricsAggregator =
new FrameMetricsAggregator();

private ActivityFramesState() {}

static @NotNull ActivityFramesState getInstance() {
return instance;
}

private final @NotNull Map<SentryId, Map<String, @NotNull MeasurementValue>>
activityMeasurements = Collections.synchronizedMap(new WeakHashMap<>());
marandaneto marked this conversation as resolved.
Show resolved Hide resolved

void addActivity(final @NotNull Activity activity) {
frameMetricsAggregator.add(activity);
}

void setMetrics(final @NotNull Activity activity, final @NotNull SentryId sentryId) {
int totalFrames = 0;
int slowFrames = 0;
int frozenFrames = 0;

final SparseIntArray[] framesRates = frameMetricsAggregator.remove(activity);

if (framesRates != null) {
final SparseIntArray totalIndexArray = framesRates[FrameMetricsAggregator.TOTAL_INDEX];
if (totalIndexArray != null) {
for (int i = 0; i < totalIndexArray.size(); i++) {
int frameTime = totalIndexArray.keyAt(i);
int numFrames = totalIndexArray.valueAt(i);
totalFrames += numFrames;
// hard coded values, its also in the official android docs and frame metrics API
if (frameTime > 700) {
// frozen frames, threshold is 700ms
frozenFrames += numFrames;
}
if (frameTime > 16) {
philipphofmann marked this conversation as resolved.
Show resolved Hide resolved
// slow frames, above 16ms, 60 frames/second
slowFrames += numFrames;
}
}
}
}

if (totalFrames == 0 && slowFrames == 0 && frozenFrames == 0) {
return;
}

final MeasurementValue tfValues = new MeasurementValue(totalFrames);
final MeasurementValue sfValues = new MeasurementValue(slowFrames);
final MeasurementValue ffValues = new MeasurementValue(frozenFrames);
final Map<String, @NotNull MeasurementValue> measurements = new HashMap<>();
measurements.put("frames_total", tfValues);
measurements.put("frames_slow", sfValues);
measurements.put("frames_frozen", ffValues);

activityMeasurements.put(sentryId, measurements);
}

@Nullable
Map<String, @NotNull MeasurementValue> getMetrics(final @NotNull SentryId sentryId) {
return activityMeasurements.get(sentryId);
}

void removeMetrics(final @NotNull SentryId sentryId) {
activityMeasurements.remove(sentryId);
}

void close() {
frameMetricsAggregator.stop();
marandaneto marked this conversation as resolved.
Show resolved Hide resolved
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -95,6 +95,8 @@ public void close() throws IOException {
if (options != null) {
options.getLogger().log(SentryLevel.DEBUG, "ActivityLifecycleIntegration removed.");
}

ActivityFramesState.getInstance().close();
marandaneto marked this conversation as resolved.
Show resolved Hide resolved
}

private void addBreadcrumb(final @NonNull Activity activity, final @NotNull String state) {
Expand Down Expand Up @@ -134,10 +136,26 @@ private void startTracing(final @NonNull Activity activity) {

// in case appStartTime isn't available, we don't create a span for it.
if (firstActivityCreated || appStartTime == null) {
transaction = hub.startTransaction(activityName, UI_LOAD_OP, (Date) null, true);
transaction =
hub.startTransaction(
activityName,
UI_LOAD_OP,
(Date) null,
true,
(finishingTransaction) -> {
setMetricsForActivity(activity, finishingTransaction);
});
} else {
// start transaction with app start timestamp
transaction = hub.startTransaction(activityName, UI_LOAD_OP, appStartTime, true);
transaction =
hub.startTransaction(
activityName,
UI_LOAD_OP,
appStartTime,
true,
(finishingTransaction) -> {
setMetricsForActivity(activity, finishingTransaction);
});
// start specific span for app start

appStartSpan = transaction.startChild(getAppStartOp(), getAppStartDesc(), appStartTime);
Expand All @@ -153,6 +171,12 @@ private void startTracing(final @NonNull Activity activity) {
}
}

private void setMetricsForActivity(
final @NotNull Activity activity, final @NotNull ITransaction transaction) {
// set metrics and remove the slow/frozen detection since transaction is finished.
marandaneto marked this conversation as resolved.
Show resolved Hide resolved
ActivityFramesState.getInstance().setMetrics(activity, transaction.getEventId());
}

@VisibleForTesting
void applyScope(final @NotNull Scope scope, final @NotNull ITransaction transaction) {
scope.withTransaction(
Expand Down Expand Up @@ -185,6 +209,12 @@ private void stopTracing(final @NonNull Activity activity, final boolean shouldF

private void finishTransaction(final @Nullable ITransaction transaction) {
if (transaction != null) {
// if io.sentry.traces.activity.auto-finish.enable is disabled, transaction may be already
// finished when this method is called.
if (transaction.isFinished()) {
marandaneto marked this conversation as resolved.
Show resolved Hide resolved
return;
}

SpanStatus status = transaction.getStatus();
// status might be set by other integrations, let's not overwrite it
if (status == null) {
Expand All @@ -202,6 +232,9 @@ public synchronized void onActivityPreCreated(
if (isAllActivityCallbacksAvailable) {
setColdStart(savedInstanceState);

// start collecting frame metrics for transaction
ActivityFramesState.getInstance().addActivity(activity);

// if activity has global fields being init. and
// they are slow, this won't count the whole fields/ctor initialization time, but only
// when onCreate is actually called.
Expand All @@ -220,6 +253,9 @@ public synchronized void onActivityCreated(

// fallback call for API < 29 compatibility, otherwise it happens on onActivityPreCreated
if (!isAllActivityCallbacksAvailable) {
// start collecting frame metrics for transaction
ActivityFramesState.getInstance().addActivity(activity);

startTracing(activity);
}
firstActivityCreated = true;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -25,7 +25,7 @@ public final class AppStartState {

private AppStartState() {}

static @NotNull AppStartState getInstance() {
public static @NotNull AppStartState getInstance() {
marandaneto marked this conversation as resolved.
Show resolved Hide resolved
return instance;
}

Expand All @@ -44,14 +44,14 @@ void setAppStartEnd(final long appStartEndMillis) {
}

@Nullable
synchronized Long getAppStartInterval() {
public synchronized Long getAppStartInterval() {
marandaneto marked this conversation as resolved.
Show resolved Hide resolved
if (appStartMillis == null || appStartEndMillis == null) {
return null;
}
return appStartEndMillis - appStartMillis;
}

boolean isColdStart() {
public boolean isColdStart() {
return coldStart;
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -5,9 +5,11 @@

import io.sentry.EventProcessor;
import io.sentry.protocol.MeasurementValue;
import io.sentry.protocol.SentryId;
import io.sentry.protocol.SentrySpan;
import io.sentry.protocol.SentryTransaction;
import java.util.List;
import java.util.Map;
import org.jetbrains.annotations.NotNull;
import org.jetbrains.annotations.Nullable;

Expand All @@ -25,9 +27,14 @@ final class PerformanceAndroidEventProcessor implements EventProcessor {
@Override
public synchronized @NotNull SentryTransaction process(
@NotNull SentryTransaction transaction, @Nullable Object hint) {

if (!tracingEnabled) {
return transaction;
}

// the app start measurement is only sent once and only if the transaction has
// the app.start span, which is automatically created by the SDK.
if (!sentStartMeasurement && tracingEnabled && hasAppStartSpan(transaction.getSpans())) {
if (!sentStartMeasurement && hasAppStartSpan(transaction.getSpans())) {
final Long appStartUpInterval = AppStartState.getInstance().getAppStartInterval();
// if appStartUpInterval is null, metrics are not ready to be sent
if (appStartUpInterval != null) {
Expand All @@ -41,6 +48,16 @@ final class PerformanceAndroidEventProcessor implements EventProcessor {
}
}

final SentryId eventId = transaction.getEventId();
if (eventId != null) {
final Map<String, @NotNull MeasurementValue> framesMetrics =
ActivityFramesState.getInstance().getMetrics(eventId);
if (framesMetrics != null) {
transaction.getMeasurements().putAll(framesMetrics);
ActivityFramesState.getInstance().removeMetrics(eventId);
}
}

return transaction;
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -41,7 +41,7 @@ class ActivityLifecycleIntegrationTest {

fun getSut(apiVersion: Int = 29): ActivityLifecycleIntegration {
whenever(hub.options).thenReturn(options)
whenever(hub.startTransaction(any(), any(), anyOrNull<Date>(), any())).thenReturn(transaction)
whenever(hub.startTransaction(any(), any(), anyOrNull(), any(), any())).thenReturn(transaction)
whenever(buildInfo.sdkInfoVersion).thenReturn(apiVersion)
return ActivityLifecycleIntegration(application, buildInfo)
}
Expand Down Expand Up @@ -218,7 +218,7 @@ class ActivityLifecycleIntegrationTest {
val activity = mock<Activity>()
sut.onActivityPreCreated(activity, fixture.bundle)

verify(fixture.hub, never()).startTransaction(any(), any(), anyOrNull<Date>(), any())
verify(fixture.hub, never()).startTransaction(any(), any(), anyOrNull(), any(), anyOrNull())
}

@Test
Expand All @@ -231,7 +231,7 @@ class ActivityLifecycleIntegrationTest {
sut.onActivityPreCreated(activity, fixture.bundle)
sut.onActivityPreCreated(activity, fixture.bundle)

verify(fixture.hub).startTransaction(any(), any(), anyOrNull<Date>(), any())
verify(fixture.hub).startTransaction(any(), any(), anyOrNull(), any(), anyOrNull())
}

@Test
Expand All @@ -247,7 +247,7 @@ class ActivityLifecycleIntegrationTest {

verify(fixture.hub).startTransaction(any(), check {
assertEquals("ui.load", it)
}, anyOrNull<Date>(), any())
}, anyOrNull(), any(), anyOrNull())
}

@Test
Expand All @@ -263,7 +263,7 @@ class ActivityLifecycleIntegrationTest {

verify(fixture.hub).startTransaction(check {
assertEquals("Activity", it)
}, any(), anyOrNull<Date>(), any())
}, any(), anyOrNull(), any(), anyOrNull())
}

@Test
Expand Down Expand Up @@ -423,7 +423,7 @@ class ActivityLifecycleIntegrationTest {
val activity = mock<Activity>()
sut.onActivityCreated(activity, mock())

verify(fixture.hub, never()).startTransaction(any(), any(), anyOrNull<Date>(), any())
verify(fixture.hub, never()).startTransaction(any(), any(), anyOrNull(), any(), any())
}

@Test
Expand All @@ -450,7 +450,7 @@ class ActivityLifecycleIntegrationTest {
val activity = mock<Activity>()
sut.onActivityCreated(activity, mock())

verify(fixture.hub).startTransaction(any(), any(), anyOrNull<Date>(), any())
verify(fixture.hub).startTransaction(any(), any(), anyOrNull(), any(), any())
}

@Test
Expand Down Expand Up @@ -534,7 +534,7 @@ class ActivityLifecycleIntegrationTest {
sut.onActivityPreCreated(activity, fixture.bundle)

// call only once
verify(fixture.hub).startTransaction(any(), any(), eq(date), any())
verify(fixture.hub).startTransaction(any(), any(), eq(date), any(), any())
}

@Test
Expand Down Expand Up @@ -617,15 +617,15 @@ class ActivityLifecycleIntegrationTest {
val activity = mock<Activity>()
sut.onActivityPreCreated(activity, fixture.bundle)

verify(fixture.hub).startTransaction(any(), any(), eq(date), any())
verify(fixture.hub).startTransaction(any(), any(), eq(date), any(), any())
sut.onActivityCreated(activity, fixture.bundle)
sut.onActivityPostResumed(activity)

val newActivity = mock<Activity>()
sut.onActivityPreCreated(newActivity, fixture.bundle)

val nullDate: Date? = null
verify(fixture.hub).startTransaction(any(), any(), eq(nullDate), any())
verify(fixture.hub).startTransaction(any(), any(), eq(nullDate), any(), any())
}

private fun setAppStartTime(date: Date = Date(0)) {
Expand Down
Loading