From fd54fa67792da6e1b2dbff801a7a59dfc54da02a Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Wed, 16 Nov 2022 12:06:06 +0100 Subject: [PATCH 01/10] added ttid span to ActivityLifecycleIntegration --- .../api/sentry-android-core.api | 1 + .../core/ActivityLifecycleIntegration.java | 52 +++++++++++++++++++ .../core/ActivityLifecycleIntegrationTest.kt | 32 ++++++++++++ 3 files changed, 85 insertions(+) diff --git a/sentry-android-core/api/sentry-android-core.api b/sentry-android-core/api/sentry-android-core.api index 4bdcfecd27..a7d72b0095 100644 --- a/sentry-android-core/api/sentry-android-core.api +++ b/sentry-android-core/api/sentry-android-core.api @@ -15,6 +15,7 @@ public final class io/sentry/android/core/ActivityLifecycleIntegration : android public fun onActivityDestroyed (Landroid/app/Activity;)V public fun onActivityPaused (Landroid/app/Activity;)V public fun onActivityPostResumed (Landroid/app/Activity;)V + public fun onActivityPrePaused (Landroid/app/Activity;)V public fun onActivityResumed (Landroid/app/Activity;)V public fun onActivitySaveInstanceState (Landroid/app/Activity;Landroid/os/Bundle;)V public fun onActivityStarted (Landroid/app/Activity;)V diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java index a307b01679..0f4a915457 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java @@ -9,8 +9,12 @@ import android.content.Context; import android.os.Build; import android.os.Bundle; +import android.os.Handler; +import android.os.Looper; import android.os.Process; +import androidx.annotation.NonNull; import io.sentry.Breadcrumb; +import io.sentry.DateUtils; import io.sentry.Hint; import io.sentry.IHub; import io.sentry.ISpan; @@ -56,6 +60,9 @@ public final class ActivityLifecycleIntegration private boolean foregroundImportance = false; private @Nullable ISpan appStartSpan; + private @Nullable ISpan ttidSpan; + private @NotNull Date lastPausedTime = DateUtils.getCurrentDateTime(); + private final @NotNull Handler mainHandler = new Handler(Looper.getMainLooper()); // WeakHashMap isn't thread safe but ActivityLifecycleCallbacks is only called from the // main-thread @@ -198,8 +205,24 @@ private void startTracing(final @NotNull Activity activity) { appStartSpan = transaction.startChild( getAppStartOp(coldStart), getAppStartDesc(coldStart), appStartTime); + // The first activity ttidSpan should start at the same time as the app start time + ttidSpan = transaction.startChild("TTID", activityName + ".ttid", appStartTime); + } else { + // Other activities (or in case appStartTime is not available) the ttid span should + // start when the previous activity called its onPause method. + ttidSpan = transaction.startChild("TTID", activityName + ".ttid", lastPausedTime); } + // Posting a task to the main thread's handler will make it executed after it finished + // its current job. That is, right after the activity draws the layout. + mainHandler.post( + () -> { + // finishes ttidSpan span + if (ttidSpan != null && !ttidSpan.isFinished()) { + ttidSpan.finish(); + } + }); + // lets bind to the scope so other integrations can pick it up hub.configureScope( scope -> { @@ -258,6 +281,11 @@ private void finishTransaction(final @Nullable ITransaction transaction) { return; } + // in case the ttidSpan isn't completed yet, we finish it as cancelled to avoid memory leak + if (ttidSpan != null && !ttidSpan.isFinished()) { + ttidSpan.finish(SpanStatus.CANCELLED); + } + SpanStatus status = transaction.getStatus(); // status might be set by other integrations, let's not overwrite it if (status == null) { @@ -340,8 +368,20 @@ public synchronized void onActivityPostResumed(final @NotNull Activity activity) } } + @Override + public void onActivityPrePaused(@NonNull Activity activity) { + // only executed if API >= 29 otherwise it happens on onActivityPaused + if (isAllActivityCallbacksAvailable) { + lastPausedTime = DateUtils.getCurrentDateTime(); + } + } + @Override public synchronized void onActivityPaused(final @NotNull Activity activity) { + // only executed if API < 29 otherwise it happens on onActivityPrePaused + if (!isAllActivityCallbacksAvailable) { + lastPausedTime = DateUtils.getCurrentDateTime(); + } addBreadcrumb(activity, "paused"); } @@ -366,12 +406,18 @@ public synchronized void onActivityDestroyed(final @NotNull Activity activity) { appStartSpan.finish(SpanStatus.CANCELLED); } + // in case the ttidSpan isn't completed yet, we finish it as cancelled to avoid memory leak + if (ttidSpan != null && !ttidSpan.isFinished()) { + ttidSpan.finish(SpanStatus.CANCELLED); + } + // in case people opt-out enableActivityLifecycleTracingAutoFinish and forgot to finish it, // we make sure to finish it when the activity gets destroyed. stopTracing(activity, true); // set it to null in case its been just finished as cancelled appStartSpan = null; + ttidSpan = null; // clear it up, so we don't start again for the same activity if the activity is in the activity // stack still. @@ -399,6 +445,12 @@ ISpan getAppStartSpan() { return appStartSpan; } + @TestOnly + @Nullable + ISpan getTtidSpan() { + return ttidSpan; + } + private void setColdStart(final @Nullable Bundle savedInstanceState) { if (!firstActivityCreated) { // if Activity has savedInstanceState then its a warm start diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt index 7c530b0758..b522f61b41 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt @@ -498,6 +498,38 @@ class ActivityLifecycleIntegrationTest { assertNull(sut.appStartSpan) } + @Test + fun `When Activity is destroyed, sets ttidSpan status to cancelled and finish it`() { + val sut = fixture.getSut() + fixture.options.tracesSampleRate = 1.0 + sut.register(fixture.hub, fixture.options) + + setAppStartTime() + + val activity = mock() + sut.onActivityCreated(activity, fixture.bundle) + sut.onActivityDestroyed(activity) + + val span = fixture.transaction.children.first { it.description?.endsWith(".ttid") == true } + assertEquals(span.status, SpanStatus.CANCELLED) + assertTrue(span.isFinished) + } + + @Test + fun `When Activity is destroyed, sets ttidSpan to null`() { + val sut = fixture.getSut() + fixture.options.tracesSampleRate = 1.0 + sut.register(fixture.hub, fixture.options) + + setAppStartTime() + + val activity = mock() + sut.onActivityCreated(activity, fixture.bundle) + sut.onActivityDestroyed(activity) + + assertNull(sut.ttidSpan) + } + @Test fun `When new Activity and transaction is created, finish previous ones`() { val sut = fixture.getSut() From 1d48b5aa0b2e04d15222e2673a16b6dfce052740 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Wed, 16 Nov 2022 17:07:14 +0100 Subject: [PATCH 02/10] SentryFrameMetricsCollector start collecting frameMetrics in onActivityStarted(), not onActivityCreated() anymore --- CHANGELOG.md | 1 + 1 file changed, 1 insertion(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index af924736a8..d82778f935 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -10,6 +10,7 @@ ### Features +- Add ttid span to ActivityLifecycleIntegration ([#2369](https://github.com/getsentry/sentry-java/pull/2369)) - Update Spring Boot Jakarta to Spring Boot 3.0.0-RC2 ([#2347](https://github.com/getsentry/sentry-java/pull/2347)) ## 6.7.0 From 501d3e7988619016994b51a6b9e95eba729fb914 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Wed, 16 Nov 2022 18:08:52 +0100 Subject: [PATCH 03/10] updated changelog --- CHANGELOG.md | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index 00546dff42..63b2d2b115 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,11 @@ # Changelog +## Unreleased + +### Features + +- Add ttid span to ActivityLifecycleIntegration ([#2369](https://github.com/getsentry/sentry-java/pull/2369)) + ## 6.7.1 ### Fixes From ff733e57fb7c54f52fbaae9f79996cd581efd3e4 Mon Sep 17 00:00:00 2001 From: Stefano Date: Wed, 16 Nov 2022 18:12:41 +0100 Subject: [PATCH 04/10] Update CHANGELOG.md --- CHANGELOG.md | 1 - 1 file changed, 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 63b2d2b115..08777dfd8d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -17,7 +17,6 @@ ### Features -- Add ttid span to ActivityLifecycleIntegration ([#2369](https://github.com/getsentry/sentry-java/pull/2369)) - Update Spring Boot Jakarta to Spring Boot 3.0.0-RC2 ([#2347](https://github.com/getsentry/sentry-java/pull/2347)) ## 6.7.0 From 0c9a0a81ef1feae4dbc6895d31286212b9a738e4 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Wed, 30 Nov 2022 16:35:00 -0800 Subject: [PATCH 05/10] ActivityLifecycleIntegration now keeps a map of ttidSpans, with one span per activity updated ttidSpan finishing with Firebase's method: span is finished after the very first frame has been drawn using view.getViewTreeObserver().addOnDrawListener added FirstDrawDoneListener Sentry.getSpan() could cause issues --- .../core/ActivityLifecycleIntegration.java | 73 +++++---- .../internal/util/FirstDrawDoneListener.java | 95 ++++++++++++ .../core/ActivityLifecycleIntegrationTest.kt | 5 +- .../util/FirstDrawDoneListenerTest.kt | 138 ++++++++++++++++++ .../sentry/samples/android/MainActivity.java | 3 +- .../samples/android/ProfilingActivity.kt | 5 - .../main/kotlin/io/sentry/test/Reflection.kt | 8 +- 7 files changed, 289 insertions(+), 38 deletions(-) create mode 100644 sentry-android-core/src/main/java/io/sentry/android/core/internal/util/FirstDrawDoneListener.java create mode 100644 sentry-android-core/src/test/java/io/sentry/android/core/internal/util/FirstDrawDoneListenerTest.kt diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java index 0f4a915457..5d0f2cfbcc 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java @@ -3,6 +3,7 @@ import static android.app.ActivityManager.RunningAppProcessInfo.IMPORTANCE_FOREGROUND; import static io.sentry.TypeCheckHint.ANDROID_ACTIVITY; +import android.annotation.SuppressLint; import android.app.Activity; import android.app.ActivityManager; import android.app.Application; @@ -12,6 +13,7 @@ import android.os.Handler; import android.os.Looper; import android.os.Process; +import android.view.View; import androidx.annotation.NonNull; import io.sentry.Breadcrumb; import io.sentry.DateUtils; @@ -26,6 +28,7 @@ import io.sentry.SpanStatus; import io.sentry.TransactionContext; import io.sentry.TransactionOptions; +import io.sentry.android.core.internal.util.FirstDrawDoneListener; import io.sentry.protocol.TransactionNameSource; import io.sentry.util.Objects; import java.io.Closeable; @@ -48,6 +51,7 @@ public final class ActivityLifecycleIntegration static final String APP_START_COLD = "app.start.cold"; private final @NotNull Application application; + private final @NotNull BuildInfoProvider buildInfoProvider; private @Nullable IHub hub; private @Nullable SentryAndroidOptions options; @@ -60,7 +64,7 @@ public final class ActivityLifecycleIntegration private boolean foregroundImportance = false; private @Nullable ISpan appStartSpan; - private @Nullable ISpan ttidSpan; + private final @NotNull WeakHashMap ttidSpanMap = new WeakHashMap<>(); private @NotNull Date lastPausedTime = DateUtils.getCurrentDateTime(); private final @NotNull Handler mainHandler = new Handler(Looper.getMainLooper()); @@ -76,7 +80,8 @@ public ActivityLifecycleIntegration( final @NotNull BuildInfoProvider buildInfoProvider, final @NotNull ActivityFramesTracker activityFramesTracker) { this.application = Objects.requireNonNull(application, "Application is required"); - Objects.requireNonNull(buildInfoProvider, "BuildInfoProvider is required"); + this.buildInfoProvider = + Objects.requireNonNull(buildInfoProvider, "BuildInfoProvider is required"); this.activityFramesTracker = Objects.requireNonNull(activityFramesTracker, "ActivityFramesTracker is required"); @@ -152,7 +157,8 @@ private void stopPreviousTransactions() { for (final Map.Entry entry : activitiesWithOngoingTransactions.entrySet()) { final ITransaction transaction = entry.getValue(); - finishTransaction(transaction); + final ISpan ttidSpan = ttidSpanMap.get(entry.getKey()); + finishTransaction(transaction, ttidSpan); } } @@ -206,23 +212,15 @@ private void startTracing(final @NotNull Activity activity) { transaction.startChild( getAppStartOp(coldStart), getAppStartDesc(coldStart), appStartTime); // The first activity ttidSpan should start at the same time as the app start time - ttidSpan = transaction.startChild("TTID", activityName + ".ttid", appStartTime); + ttidSpanMap.put( + activity, transaction.startChild("TTID", activityName + ".ttid", appStartTime)); } else { // Other activities (or in case appStartTime is not available) the ttid span should // start when the previous activity called its onPause method. - ttidSpan = transaction.startChild("TTID", activityName + ".ttid", lastPausedTime); + ttidSpanMap.put( + activity, transaction.startChild("TTID", activityName + ".ttid", lastPausedTime)); } - // Posting a task to the main thread's handler will make it executed after it finished - // its current job. That is, right after the activity draws the layout. - mainHandler.post( - () -> { - // finishes ttidSpan span - if (ttidSpan != null && !ttidSpan.isFinished()) { - ttidSpan.finish(); - } - }); - // lets bind to the scope so other integrations can pick it up hub.configureScope( scope -> { @@ -269,11 +267,13 @@ private boolean isRunningTransaction(final @NotNull Activity activity) { private void stopTracing(final @NotNull Activity activity, final boolean shouldFinishTracing) { if (performanceEnabled && shouldFinishTracing) { final ITransaction transaction = activitiesWithOngoingTransactions.get(activity); - finishTransaction(transaction); + final ISpan ttidSpan = ttidSpanMap.get(activity); + finishTransaction(transaction, ttidSpan); } } - private void finishTransaction(final @Nullable ITransaction transaction) { + private void finishTransaction( + final @Nullable ITransaction transaction, final @Nullable ISpan ttidSpan) { if (transaction != null) { // if io.sentry.traces.activity.auto-finish.enable is disabled, transaction may be already // finished manually when this method is called. @@ -325,6 +325,7 @@ public synchronized void onActivityStarted(final @NotNull Activity activity) { addBreadcrumb(activity, "started"); } + @SuppressLint("NewApi") @Override public synchronized void onActivityResumed(final @NotNull Activity activity) { if (!firstActivityResumed) { @@ -350,6 +351,30 @@ public synchronized void onActivityResumed(final @NotNull Activity activity) { firstActivityResumed = true; } + final ISpan ttidSpan = ttidSpanMap.get(activity); + final View rootView = activity.findViewById(android.R.id.content); + if (buildInfoProvider.getSdkInfoVersion() >= Build.VERSION_CODES.JELLY_BEAN + && rootView != null) { + FirstDrawDoneListener.registerForNextDraw( + rootView, + () -> { + // finishes ttidSpan span + if (ttidSpan != null && !ttidSpan.isFinished()) { + ttidSpan.finish(); + } + }, + buildInfoProvider); + } else { + // Posting a task to the main thread's handler will make it executed after it finished + // its current job. That is, right after the activity draws the layout. + mainHandler.post( + () -> { + // finishes ttidSpan span + if (ttidSpan != null && !ttidSpan.isFinished()) { + ttidSpan.finish(); + } + }); + } addBreadcrumb(activity, "resumed"); // fallback call for API < 29 compatibility, otherwise it happens on onActivityPostResumed @@ -406,18 +431,14 @@ public synchronized void onActivityDestroyed(final @NotNull Activity activity) { appStartSpan.finish(SpanStatus.CANCELLED); } - // in case the ttidSpan isn't completed yet, we finish it as cancelled to avoid memory leak - if (ttidSpan != null && !ttidSpan.isFinished()) { - ttidSpan.finish(SpanStatus.CANCELLED); - } - // in case people opt-out enableActivityLifecycleTracingAutoFinish and forgot to finish it, // we make sure to finish it when the activity gets destroyed. stopTracing(activity, true); // set it to null in case its been just finished as cancelled appStartSpan = null; - ttidSpan = null; + // ttidSpan is finished in the stopTracing() method + ttidSpanMap.remove(activity); // clear it up, so we don't start again for the same activity if the activity is in the activity // stack still. @@ -446,9 +467,9 @@ ISpan getAppStartSpan() { } @TestOnly - @Nullable - ISpan getTtidSpan() { - return ttidSpan; + @NotNull + WeakHashMap getTtidSpanMap() { + return ttidSpanMap; } private void setColdStart(final @Nullable Bundle savedInstanceState) { diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/internal/util/FirstDrawDoneListener.java b/sentry-android-core/src/main/java/io/sentry/android/core/internal/util/FirstDrawDoneListener.java new file mode 100644 index 0000000000..7c5574ead0 --- /dev/null +++ b/sentry-android-core/src/main/java/io/sentry/android/core/internal/util/FirstDrawDoneListener.java @@ -0,0 +1,95 @@ +package io.sentry.android.core.internal.util; + +import android.annotation.SuppressLint; +import android.os.Build; +import android.os.Handler; +import android.os.Looper; +import android.view.View; +import android.view.ViewTreeObserver; +import androidx.annotation.RequiresApi; +import io.sentry.android.core.BuildInfoProvider; +import java.util.concurrent.atomic.AtomicReference; +import org.jetbrains.annotations.NotNull; + +/** + * OnDrawListener that unregisters itself and invokes callback when the next draw is done. This API + * 16+ implementation is an approximation of the initial-display-time defined by Android Vitals. + */ +@SuppressLint("ObsoleteSdkInt") +@RequiresApi(api = Build.VERSION_CODES.JELLY_BEAN) +public class FirstDrawDoneListener implements ViewTreeObserver.OnDrawListener { + private final @NotNull Handler mainThreadHandler = new Handler(Looper.getMainLooper()); + private final @NotNull AtomicReference viewReference; + private final @NotNull Runnable callback; + + /** Registers a post-draw callback for the next draw of a view. */ + public static void registerForNextDraw( + final @NotNull View view, + final @NotNull Runnable drawDoneCallback, + final @NotNull BuildInfoProvider buildInfoProvider) { + final FirstDrawDoneListener listener = new FirstDrawDoneListener(view, drawDoneCallback); + // Handle bug prior to API 26 where OnDrawListener from the floating ViewTreeObserver is not + // merged into the real ViewTreeObserver. + // https://android.googlesource.com/platform/frameworks/base/+/9f8ec54244a5e0343b9748db3329733f259604f3 + if (buildInfoProvider.getSdkInfoVersion() < 26 + && !isAliveAndAttached(view, buildInfoProvider)) { + view.addOnAttachStateChangeListener( + new View.OnAttachStateChangeListener() { + @Override + public void onViewAttachedToWindow(View view) { + view.getViewTreeObserver().addOnDrawListener(listener); + view.removeOnAttachStateChangeListener(this); + } + + @Override + public void onViewDetachedFromWindow(View view) { + view.removeOnAttachStateChangeListener(this); + } + }); + } else { + view.getViewTreeObserver().addOnDrawListener(listener); + } + } + + private FirstDrawDoneListener(final @NotNull View view, final @NotNull Runnable callback) { + this.viewReference = new AtomicReference<>(view); + this.callback = callback; + } + + @Override + public void onDraw() { + // Set viewReference to null so any onDraw past the first is a no-op + final View view = viewReference.getAndSet(null); + if (view == null) { + return; + } + // OnDrawListeners cannot be removed within onDraw, so we remove it with a + // GlobalLayoutListener + view.getViewTreeObserver() + .addOnGlobalLayoutListener(() -> view.getViewTreeObserver().removeOnDrawListener(this)); + mainThreadHandler.postAtFrontOfQueue(callback); + } + + /** + * Helper to avoid bug + * prior to API 26, where the floating ViewTreeObserver's OnDrawListeners are not merged into + * the real ViewTreeObserver during attach. + * + * @return true if the View is already attached and the ViewTreeObserver is not a floating + * placeholder. + */ + private static boolean isAliveAndAttached( + final @NotNull View view, final @NotNull BuildInfoProvider buildInfoProvider) { + return view.getViewTreeObserver().isAlive() && isAttachedToWindow(view, buildInfoProvider); + } + + @SuppressLint("NewApi") + private static boolean isAttachedToWindow( + final @NotNull View view, final @NotNull BuildInfoProvider buildInfoProvider) { + if (buildInfoProvider.getSdkInfoVersion() >= 19) { + return view.isAttachedToWindow(); + } + return view.getWindowToken() != null; + } +} diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt index b522f61b41..c3fb38755a 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt @@ -525,9 +525,10 @@ class ActivityLifecycleIntegrationTest { val activity = mock() sut.onActivityCreated(activity, fixture.bundle) - sut.onActivityDestroyed(activity) + assertNotNull(sut.ttidSpanMap[activity]) - assertNull(sut.ttidSpan) + sut.onActivityDestroyed(activity) + assertNull(sut.ttidSpanMap[activity]) } @Test diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/internal/util/FirstDrawDoneListenerTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/internal/util/FirstDrawDoneListenerTest.kt new file mode 100644 index 0000000000..07fc383e1d --- /dev/null +++ b/sentry-android-core/src/test/java/io/sentry/android/core/internal/util/FirstDrawDoneListenerTest.kt @@ -0,0 +1,138 @@ +package io.sentry.android.core.internal.util + +import android.content.Context +import android.os.Handler +import android.os.Looper +import android.view.View +import android.view.ViewTreeObserver +import androidx.test.core.app.ApplicationProvider +import androidx.test.ext.junit.runners.AndroidJUnit4 +import io.sentry.android.core.BuildInfoProvider +import io.sentry.test.getProperty +import org.junit.runner.RunWith +import org.mockito.kotlin.inOrder +import org.mockito.kotlin.mock +import org.mockito.kotlin.never +import org.mockito.kotlin.times +import org.mockito.kotlin.verify +import org.mockito.kotlin.whenever +import org.robolectric.Shadows +import java.util.concurrent.CopyOnWriteArrayList +import kotlin.test.Test +import kotlin.test.assertFalse +import kotlin.test.assertIs +import kotlin.test.assertTrue + +@RunWith(AndroidJUnit4::class) +class FirstDrawDoneListenerTest { + + private class Fixture { + val application: Context = ApplicationProvider.getApplicationContext() + val buildInfo = mock() + lateinit var onDrawListeners: ArrayList + + fun getSut(apiVersion: Int = 26): View { + whenever(buildInfo.sdkInfoVersion).thenReturn(apiVersion) + val view = View(application) + + // Adding a listener forces ViewTreeObserver.mOnDrawListeners to be initialized and non-null. + val dummyListener = ViewTreeObserver.OnDrawListener {} + view.viewTreeObserver.addOnDrawListener(dummyListener) + view.viewTreeObserver.removeOnDrawListener(dummyListener) + + // Obtain mOnDrawListeners field through reflection + onDrawListeners = view.viewTreeObserver.getProperty("mOnDrawListeners") + assertTrue(onDrawListeners.isEmpty()) + + return view + } + } + + private val fixture = Fixture() + + @Test + fun `registerForNextDraw adds listener on attach state changed on sdk 25-`() { + val view = fixture.getSut(25) + + // OnDrawListener is not registered, it is delayed for later + FirstDrawDoneListener.registerForNextDraw(view, {}, fixture.buildInfo) + assertTrue(fixture.onDrawListeners.isEmpty()) + + // Register listener after the view is attached to a window + val listenerInfo = Class.forName("android.view.View\$ListenerInfo") + val mListenerInfo: Any = view.getProperty("mListenerInfo") + val mOnAttachStateChangeListeners: CopyOnWriteArrayList = + mListenerInfo.getProperty(listenerInfo, "mOnAttachStateChangeListeners") + assertFalse(mOnAttachStateChangeListeners.isEmpty()) + + // Dispatch onViewAttachedToWindow() + for (listener in mOnAttachStateChangeListeners) { + listener.onViewAttachedToWindow(view) + } + + assertFalse(fixture.onDrawListeners.isEmpty()) + assertIs(fixture.onDrawListeners[0]) + + // mOnAttachStateChangeListeners is automatically removed + assertTrue(mOnAttachStateChangeListeners.isEmpty()) + } + + @Test + fun `registerForNextDraw adds listener on sdk 26+`() { + val view = fixture.getSut() + + // Immediately register an OnDrawListener to ViewTreeObserver + FirstDrawDoneListener.registerForNextDraw(view, {}, fixture.buildInfo) + assertFalse(fixture.onDrawListeners.isEmpty()) + assertIs(fixture.onDrawListeners[0]) + } + + @Test + fun `registerForNextDraw posts callback to front of queue`() { + val view = fixture.getSut() + val handler = Handler(Looper.getMainLooper()) + val drawDoneCallback = mock() + val otherCallback = mock() + val inOrder = inOrder(drawDoneCallback, otherCallback) + FirstDrawDoneListener.registerForNextDraw(view, drawDoneCallback, fixture.buildInfo) + handler.post(otherCallback) // 3rd in queue + handler.postAtFrontOfQueue(otherCallback) // 2nd in queue + view.viewTreeObserver.dispatchOnDraw() // 1st in queue + verify(drawDoneCallback, never()).run() + verify(otherCallback, never()).run() + + // Execute all posted tasks + Shadows.shadowOf(Looper.getMainLooper()).idle() + inOrder.verify(drawDoneCallback).run() + inOrder.verify(otherCallback, times(2)).run() + inOrder.verifyNoMoreInteractions() + } + + @Test + fun `registerForNextDraw unregister itself after onDraw`() { + val view = fixture.getSut() + FirstDrawDoneListener.registerForNextDraw(view, {}, fixture.buildInfo) + assertFalse(fixture.onDrawListeners.isEmpty()) + + // Does not remove OnDrawListener before onDraw, even if OnGlobalLayout is triggered + view.viewTreeObserver.dispatchOnGlobalLayout() + assertFalse(fixture.onDrawListeners.isEmpty()) + + // Removes OnDrawListener in the next OnGlobalLayout after onDraw + view.viewTreeObserver.dispatchOnDraw() + view.viewTreeObserver.dispatchOnGlobalLayout() + assertTrue(fixture.onDrawListeners.isEmpty()) + } + + @Test + fun `registerForNextDraw calls the given callback on the main thread after onDraw`() { + val view = fixture.getSut() + val r: Runnable = mock() + FirstDrawDoneListener.registerForNextDraw(view, r, fixture.buildInfo) + view.viewTreeObserver.dispatchOnDraw() + + // Execute all tasks posted to main looper + Shadows.shadowOf(Looper.getMainLooper()).idle() + verify(r).run() + } +} diff --git a/sentry-samples/sentry-samples-android/src/main/java/io/sentry/samples/android/MainActivity.java b/sentry-samples/sentry-samples-android/src/main/java/io/sentry/samples/android/MainActivity.java index 6f3c401633..3b3cc037b8 100644 --- a/sentry-samples/sentry-samples-android/src/main/java/io/sentry/samples/android/MainActivity.java +++ b/sentry-samples/sentry-samples-android/src/main/java/io/sentry/samples/android/MainActivity.java @@ -7,7 +7,6 @@ import io.sentry.ISpan; import io.sentry.MeasurementUnit; import io.sentry.Sentry; -import io.sentry.SpanStatus; import io.sentry.UserFeedback; import io.sentry.protocol.SentryId; import io.sentry.protocol.User; @@ -206,7 +205,7 @@ protected void onResume() { final ISpan span = Sentry.getSpan(); if (span != null) { span.setMeasurement("screen_load_count", screenLoadCount, new MeasurementUnit.Custom("test")); - span.finish(SpanStatus.OK); + // span.finish(SpanStatus.OK); } } } diff --git a/sentry-samples/sentry-samples-android/src/main/java/io/sentry/samples/android/ProfilingActivity.kt b/sentry-samples/sentry-samples-android/src/main/java/io/sentry/samples/android/ProfilingActivity.kt index 60def396b9..1ec37bee4b 100644 --- a/sentry-samples/sentry-samples-android/src/main/java/io/sentry/samples/android/ProfilingActivity.kt +++ b/sentry-samples/sentry-samples-android/src/main/java/io/sentry/samples/android/ProfilingActivity.kt @@ -140,11 +140,6 @@ class ProfilingActivity : AppCompatActivity() { } } - override fun onResume() { - super.onResume() - Sentry.getSpan()?.finish() - } - override fun onBackPressed() { if (profileFinished) { super.onBackPressed() diff --git a/sentry-test-support/src/main/kotlin/io/sentry/test/Reflection.kt b/sentry-test-support/src/main/kotlin/io/sentry/test/Reflection.kt index f8b4df892e..f76d86e817 100644 --- a/sentry-test-support/src/main/kotlin/io/sentry/test/Reflection.kt +++ b/sentry-test-support/src/main/kotlin/io/sentry/test/Reflection.kt @@ -37,11 +37,13 @@ fun Class<*>.containsMethod(name: String, parameterTypes: Array>): Bool fun Class<*>.containsMethod(name: String, parameterTypes: Class<*>): Boolean = containsMethod(name, arrayOf(parameterTypes)) -inline fun Any.getProperty(name: String): T = +inline fun Any.getProperty(name: String): T = this.getProperty(this::class.java, name) + +inline fun Any.getProperty(clz: Class<*>, name: String): T = try { - this::class.java.getDeclaredField(name) + clz.getDeclaredField(name) } catch (_: NoSuchFieldException) { - this::class.java.superclass.getDeclaredField(name) + clz.superclass.getDeclaredField(name) }.apply { this.isAccessible = true }.get(this) as T From 37b5edc2b0ce0b159517b65c7de04982248388b9 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Wed, 30 Nov 2022 17:05:49 -0800 Subject: [PATCH 06/10] added Instrumenter.Sentry to ttid span --- CHANGELOG.md | 7 ++++++- .../sentry/android/core/ActivityLifecycleIntegration.java | 8 ++++++-- 2 files changed, 12 insertions(+), 3 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 9beb4249a0..c146dc80a3 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,5 +1,11 @@ # Changelog +## Unreleased + +### Features + +- Add ttid span to ActivityLifecycleIntegration ([#2369](https://github.com/getsentry/sentry-java/pull/2369)) + ## 6.9.1 ### Fixes @@ -30,7 +36,6 @@ ### Features -- Add ttid span to ActivityLifecycleIntegration ([#2369](https://github.com/getsentry/sentry-java/pull/2369)) - Add FrameMetrics to Android profiling data ([#2342](https://github.com/getsentry/sentry-java/pull/2342)) ### Fixes diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java index 8a03274059..f4b8612351 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java @@ -217,12 +217,16 @@ private void startTracing(final @NotNull Activity activity) { Instrumenter.SENTRY); // The first activity ttidSpan should start at the same time as the app start time ttidSpanMap.put( - activity, transaction.startChild("TTID", activityName + ".ttid", appStartTime)); + activity, + transaction.startChild( + "TTID", activityName + ".ttid", appStartTime, Instrumenter.SENTRY)); } else { // Other activities (or in case appStartTime is not available) the ttid span should // start when the previous activity called its onPause method. ttidSpanMap.put( - activity, transaction.startChild("TTID", activityName + ".ttid", lastPausedTime)); + activity, + transaction.startChild( + "TTID", activityName + ".ttid", lastPausedTime, Instrumenter.SENTRY)); } // lets bind to the scope so other integrations can pick it up From 13a6c1a87ab681d7ed029032dbf4e36dae63e974 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Fri, 2 Dec 2022 14:26:43 -0800 Subject: [PATCH 07/10] added reference to Firebase sdk --- .../android/core/internal/util/FirstDrawDoneListener.java | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/internal/util/FirstDrawDoneListener.java b/sentry-android-core/src/main/java/io/sentry/android/core/internal/util/FirstDrawDoneListener.java index 7c5574ead0..10c160377b 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/internal/util/FirstDrawDoneListener.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/internal/util/FirstDrawDoneListener.java @@ -14,6 +14,10 @@ /** * OnDrawListener that unregisters itself and invokes callback when the next draw is done. This API * 16+ implementation is an approximation of the initial-display-time defined by Android Vitals. + * + *

Adapted from Firebase + * under the Apache License, Version 2.0. */ @SuppressLint("ObsoleteSdkInt") @RequiresApi(api = Build.VERSION_CODES.JELLY_BEAN) From 168e13807162d1a1327d669c34690044bd635698 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Fri, 9 Dec 2022 17:22:02 +0100 Subject: [PATCH 08/10] updated ttid span op and descr --- .../android/core/ActivityLifecycleIntegration.java | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java index f4b8612351..ea1499c129 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java @@ -50,6 +50,7 @@ public final class ActivityLifecycleIntegration static final String UI_LOAD_OP = "ui.load"; static final String APP_START_WARM = "app.start.warm"; static final String APP_START_COLD = "app.start.cold"; + static final String TTID_OP = "ui.load.initial_display"; private final @NotNull Application application; private final @NotNull BuildInfoProvider buildInfoProvider; @@ -219,14 +220,14 @@ private void startTracing(final @NotNull Activity activity) { ttidSpanMap.put( activity, transaction.startChild( - "TTID", activityName + ".ttid", appStartTime, Instrumenter.SENTRY)); + TTID_OP, getTtidDesc(activityName), appStartTime, Instrumenter.SENTRY)); } else { // Other activities (or in case appStartTime is not available) the ttid span should // start when the previous activity called its onPause method. ttidSpanMap.put( activity, transaction.startChild( - "TTID", activityName + ".ttid", lastPausedTime, Instrumenter.SENTRY)); + TTID_OP, getTtidDesc(activityName), lastPausedTime, Instrumenter.SENTRY)); } // lets bind to the scope so other integrations can pick it up @@ -488,6 +489,10 @@ private void setColdStart(final @Nullable Bundle savedInstanceState) { } } + private @NotNull String getTtidDesc(final @NotNull String activityName) { + return activityName + " initial display"; + } + private @NotNull String getAppStartDesc(final boolean coldStart) { if (coldStart) { return "Cold Start"; From da3486184e591b3981d8dbdb258c099914dc4541 Mon Sep 17 00:00:00 2001 From: Sentry Github Bot Date: Fri, 9 Dec 2022 16:25:36 +0000 Subject: [PATCH 09/10] Format code --- .../io/sentry/android/core/ActivityLifecycleIntegration.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java index ea1499c129..abdc54bf80 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java @@ -220,14 +220,14 @@ private void startTracing(final @NotNull Activity activity) { ttidSpanMap.put( activity, transaction.startChild( - TTID_OP, getTtidDesc(activityName), appStartTime, Instrumenter.SENTRY)); + TTID_OP, getTtidDesc(activityName), appStartTime, Instrumenter.SENTRY)); } else { // Other activities (or in case appStartTime is not available) the ttid span should // start when the previous activity called its onPause method. ttidSpanMap.put( activity, transaction.startChild( - TTID_OP, getTtidDesc(activityName), lastPausedTime, Instrumenter.SENTRY)); + TTID_OP, getTtidDesc(activityName), lastPausedTime, Instrumenter.SENTRY)); } // lets bind to the scope so other integrations can pick it up From 04bbc330aebc88c20ebbfbb30f02b14ee86a42b2 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Tue, 13 Dec 2022 11:17:36 +0100 Subject: [PATCH 10/10] ttid span is now cancelled only on destroyed or when a new activity starts, not anymore if auto-finish option is enabled --- CHANGELOG.md | 2 +- .../core/ActivityLifecycleIntegration.java | 45 +++++++++---------- .../core/ActivityLifecycleIntegrationTest.kt | 30 +++++++++++-- 3 files changed, 48 insertions(+), 29 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 523a6a0ef9..3a78300088 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,7 +4,7 @@ ### Features -- Add ttid span to ActivityLifecycleIntegration ([#2369](https://github.com/getsentry/sentry-java/pull/2369)) +- Add time-to-initial-display span to Activity transactions ([#2369](https://github.com/getsentry/sentry-java/pull/2369)) ### Dependencies diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java index abdc54bf80..00a5ed24b2 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/ActivityLifecycleIntegration.java @@ -276,8 +276,7 @@ private boolean isRunningTransaction(final @NotNull Activity activity) { private void stopTracing(final @NotNull Activity activity, final boolean shouldFinishTracing) { if (performanceEnabled && shouldFinishTracing) { final ITransaction transaction = activitiesWithOngoingTransactions.get(activity); - final ISpan ttidSpan = ttidSpanMap.get(activity); - finishTransaction(transaction, ttidSpan); + finishTransaction(transaction, null); } } @@ -291,9 +290,7 @@ private void finishTransaction( } // in case the ttidSpan isn't completed yet, we finish it as cancelled to avoid memory leak - if (ttidSpan != null && !ttidSpan.isFinished()) { - ttidSpan.finish(SpanStatus.CANCELLED); - } + finishSpan(ttidSpan, SpanStatus.CANCELLED); SpanStatus status = transaction.getStatus(); // status might be set by other integrations, let's not overwrite it @@ -365,24 +362,11 @@ public synchronized void onActivityResumed(final @NotNull Activity activity) { if (buildInfoProvider.getSdkInfoVersion() >= Build.VERSION_CODES.JELLY_BEAN && rootView != null) { FirstDrawDoneListener.registerForNextDraw( - rootView, - () -> { - // finishes ttidSpan span - if (ttidSpan != null && !ttidSpan.isFinished()) { - ttidSpan.finish(); - } - }, - buildInfoProvider); + rootView, () -> finishSpan(ttidSpan), buildInfoProvider); } else { // Posting a task to the main thread's handler will make it executed after it finished // its current job. That is, right after the activity draws the layout. - mainHandler.post( - () -> { - // finishes ttidSpan span - if (ttidSpan != null && !ttidSpan.isFinished()) { - ttidSpan.finish(); - } - }); + mainHandler.post(() -> finishSpan(ttidSpan)); } addBreadcrumb(activity, "resumed"); @@ -436,9 +420,11 @@ public synchronized void onActivityDestroyed(final @NotNull Activity activity) { // in case the appStartSpan isn't completed yet, we finish it as cancelled to avoid // memory leak - if (appStartSpan != null && !appStartSpan.isFinished()) { - appStartSpan.finish(SpanStatus.CANCELLED); - } + finishSpan(appStartSpan, SpanStatus.CANCELLED); + + // we finish the ttidSpan as cancelled in case it isn't completed yet + final ISpan ttidSpan = ttidSpanMap.get(activity); + finishSpan(ttidSpan, SpanStatus.CANCELLED); // in case people opt-out enableActivityLifecycleTracingAutoFinish and forgot to finish it, // we make sure to finish it when the activity gets destroyed. @@ -446,7 +432,6 @@ public synchronized void onActivityDestroyed(final @NotNull Activity activity) { // set it to null in case its been just finished as cancelled appStartSpan = null; - // ttidSpan is finished in the stopTracing() method ttidSpanMap.remove(activity); // clear it up, so we don't start again for the same activity if the activity is in the activity @@ -457,6 +442,18 @@ public synchronized void onActivityDestroyed(final @NotNull Activity activity) { } } + private void finishSpan(@Nullable ISpan span) { + if (span != null && !span.isFinished()) { + span.finish(); + } + } + + private void finishSpan(@Nullable ISpan span, @NotNull SpanStatus status) { + if (span != null && !span.isFinished()) { + span.finish(status); + } + } + @TestOnly @NotNull WeakHashMap getActivitiesWithOngoingTransactions() { diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt index c3fb38755a..89e7399f80 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/ActivityLifecycleIntegrationTest.kt @@ -363,13 +363,14 @@ class ActivityLifecycleIntegrationTest { } @Test - fun `When tracing auto finish is enabled, it stops the transaction on onActivityPostResumed`() { + fun `When tracing auto finish is enabled and ttid span is finished, it stops the transaction on onActivityPostResumed`() { val sut = fixture.getSut() fixture.options.tracesSampleRate = 1.0 sut.register(fixture.hub, fixture.options) val activity = mock() sut.onActivityCreated(activity, fixture.bundle) + sut.ttidSpanMap.values.first().finish() sut.onActivityPostResumed(activity) verify(fixture.hub).captureTransaction( @@ -381,6 +382,25 @@ class ActivityLifecycleIntegrationTest { ) } + @Test + fun `When tracing auto finish is enabled, it doesn't stop the transaction on onActivityPostResumed`() { + val sut = fixture.getSut() + fixture.options.tracesSampleRate = 1.0 + sut.register(fixture.hub, fixture.options) + + val activity = mock() + sut.onActivityCreated(activity, fixture.bundle) + sut.onActivityPostResumed(activity) + + verify(fixture.hub, never()).captureTransaction( + check { + assertEquals(SpanStatus.OK, it.status) + }, + anyOrNull(), + anyOrNull() + ) + } + @Test fun `When tracing has status, do not overwrite it`() { val sut = fixture.getSut() @@ -393,6 +413,7 @@ class ActivityLifecycleIntegrationTest { fixture.transaction.status = SpanStatus.UNKNOWN_ERROR sut.onActivityPostResumed(activity) + sut.onActivityDestroyed(activity) verify(fixture.hub).captureTransaction( check { @@ -510,8 +531,8 @@ class ActivityLifecycleIntegrationTest { sut.onActivityCreated(activity, fixture.bundle) sut.onActivityDestroyed(activity) - val span = fixture.transaction.children.first { it.description?.endsWith(".ttid") == true } - assertEquals(span.status, SpanStatus.CANCELLED) + val span = fixture.transaction.children.first { it.operation == ActivityLifecycleIntegration.TTID_OP } + assertEquals(SpanStatus.CANCELLED, span.status) assertTrue(span.isFinished) } @@ -571,13 +592,14 @@ class ActivityLifecycleIntegrationTest { } @Test - fun `stop transaction on resumed if API 29 less than 29`() { + fun `stop transaction on resumed if API 29 less than 29 and ttid is finished`() { val sut = fixture.getSut(14) fixture.options.tracesSampleRate = 1.0 sut.register(fixture.hub, fixture.options) val activity = mock() sut.onActivityCreated(activity, mock()) + sut.ttidSpanMap.values.first().finish() sut.onActivityResumed(activity) verify(fixture.hub).captureTransaction(any(), anyOrNull(), anyOrNull())