diff --git a/CHANGELOG.md b/CHANGELOG.md index 6af90577b4..ec08b2ae2d 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -17,6 +17,7 @@ ### Fixes +- Android Profiler on calling thread ([#2691](https://github.com/getsentry/sentry-java/pull/2691)) - Use `configureScope` instead of `withScope` in `Hub.close()`. This ensures that the main scope releases the in-memory data when closing a hub instance. ([#2688](https://github.com/getsentry/sentry-java/pull/2688)) ### Dependencies diff --git a/sentry-android-core/src/main/java/io/sentry/android/core/AndroidTransactionProfiler.java b/sentry-android-core/src/main/java/io/sentry/android/core/AndroidTransactionProfiler.java index 9322bf50e1..fb7afe9b1d 100644 --- a/sentry-android-core/src/main/java/io/sentry/android/core/AndroidTransactionProfiler.java +++ b/sentry-android-core/src/main/java/io/sentry/android/core/AndroidTransactionProfiler.java @@ -32,7 +32,6 @@ import java.util.List; import java.util.Map; import java.util.UUID; -import java.util.concurrent.ExecutionException; import java.util.concurrent.Future; import java.util.concurrent.RejectedExecutionException; import java.util.concurrent.TimeUnit; @@ -144,21 +143,6 @@ private void init() { @Override public synchronized void onTransactionStart(final @NotNull ITransaction transaction) { - try { - options.getExecutorService().submit(() -> onTransactionStartSafe(transaction)); - } catch (RejectedExecutionException e) { - options - .getLogger() - .log( - SentryLevel.ERROR, - "Failed to call the executor. Profiling will not be started. Did you call Sentry.close()?", - e); - } - } - - @SuppressLint("NewApi") - private void onTransactionStartSafe(final @NotNull ITransaction transaction) { - // Debug.startMethodTracingSampling() is only available since Lollipop if (buildInfoProvider.getSdkInfoVersion() < Build.VERSION_CODES.LOLLIPOP) return; @@ -167,21 +151,22 @@ private void onTransactionStartSafe(final @NotNull ITransaction transaction) { // traceFilesDir is null or intervalUs is 0 only if there was a problem in the init, but // we already logged that - if (traceFilesDir == null || intervalUs == 0 || !traceFilesDir.canWrite()) { + if (traceFilesDir == null || intervalUs == 0) { return; } transactionsCounter++; // When the first transaction is starting, we can start profiling if (transactionsCounter == 1) { - onFirstTransactionStarted(transaction); - options - .getLogger() - .log( - SentryLevel.DEBUG, - "Transaction %s (%s) started and being profiled.", - transaction.getName(), - transaction.getSpanContext().getTraceId().toString()); + if (onFirstTransactionStarted(transaction)) { + options + .getLogger() + .log( + SentryLevel.DEBUG, + "Transaction %s (%s) started and being profiled.", + transaction.getName(), + transaction.getSpanContext().getTraceId().toString()); + } } else { transactionsCounter--; options @@ -195,7 +180,7 @@ private void onTransactionStartSafe(final @NotNull ITransaction transaction) { } @SuppressLint("NewApi") - private void onFirstTransactionStarted(final @NotNull ITransaction transaction) { + private boolean onFirstTransactionStarted(final @NotNull ITransaction transaction) { // We create a file with a uuid name, so no need to check if it already exists traceFile = new File(traceFilesDir, UUID.randomUUID() + ".trace"); @@ -273,33 +258,28 @@ public void onFrameMetricCollected( currentProfilingTransactionData = new ProfilingTransactionData(transaction, transactionStartNanos, profileStartCpuMillis); - Debug.startMethodTracingSampling(traceFile.getPath(), BUFFER_SIZE_BYTES, intervalUs); + // We don't make any check on the file existence or writeable state, because we don't want to + // make file IO in the main thread. + // We cannot offload the work to the executorService, as if that's very busy, profiles could + // start/stop with a lot of delay and even cause ANRs. + try { + // If there is any problem with the file this method will throw (but it will not throw in + // tests) + Debug.startMethodTracingSampling(traceFile.getPath(), BUFFER_SIZE_BYTES, intervalUs); + return true; + } catch (Throwable e) { + onTransactionFinish(transaction, null); + options.getLogger().log(SentryLevel.ERROR, "Unable to start a profile: ", e); + return false; + } } @Override public @Nullable synchronized ProfilingTraceData onTransactionFinish( final @NotNull ITransaction transaction, final @Nullable List performanceCollectionData) { - try { - return options - .getExecutorService() - .submit(() -> onTransactionFinish(transaction, false, performanceCollectionData)) - .get(); - } catch (ExecutionException | InterruptedException e) { - options.getLogger().log(SentryLevel.ERROR, "Error finishing profiling: ", e); - // We stop profiling even on exceptions, so profiles don't run indefinitely - onTransactionFinish(transaction, false, null); - } catch (RejectedExecutionException e) { - options - .getLogger() - .log( - SentryLevel.ERROR, - "Failed to call the executor. Profiling could not be finished. Did you call Sentry.close()?", - e); - // We stop profiling even on exceptions, so profiles don't run indefinitely - onTransactionFinish(transaction, false, null); - } - return null; + + return onTransactionFinish(transaction, false, performanceCollectionData); } @SuppressLint("NewApi") @@ -370,7 +350,14 @@ public void onFrameMetricCollected( return null; } - Debug.stopMethodTracing(); + try { + // If there is any problem with the file this method could throw, but the start is also + // wrapped, so this should never happen (except for tests, where this is the only method that + // throws) + Debug.stopMethodTracing(); + } catch (Throwable e) { + options.getLogger().log(SentryLevel.ERROR, "Error while stopping profiling: ", e); + } frameMetricsCollector.stopCollection(frameMetricsCollectorId); long transactionEndNanos = SystemClock.elapsedRealtimeNanos(); diff --git a/sentry-android-core/src/test/java/io/sentry/android/core/AndroidTransactionProfilerTest.kt b/sentry-android-core/src/test/java/io/sentry/android/core/AndroidTransactionProfilerTest.kt index b72854e7cd..6486315807 100644 --- a/sentry-android-core/src/test/java/io/sentry/android/core/AndroidTransactionProfilerTest.kt +++ b/sentry-android-core/src/test/java/io/sentry/android/core/AndroidTransactionProfilerTest.kt @@ -20,6 +20,7 @@ import io.sentry.test.getCtor import io.sentry.test.getProperty import org.junit.runner.RunWith import org.mockito.kotlin.any +import org.mockito.kotlin.eq import org.mockito.kotlin.mock import org.mockito.kotlin.never import org.mockito.kotlin.spy @@ -39,6 +40,7 @@ import kotlin.test.assertFailsWith import kotlin.test.assertFalse import kotlin.test.assertNotNull import kotlin.test.assertNull +import kotlin.test.assertTrue @RunWith(AndroidJUnit4::class) class AndroidTransactionProfilerTest { @@ -291,16 +293,27 @@ class AndroidTransactionProfilerTest { } @Test - fun `profiler uses background threads`() { + fun `profiler never use background threads`() { val profiler = fixture.getSut(context) val mockExecutorService: ISentryExecutorService = mock() fixture.options.executorService = mockExecutorService whenever(mockExecutorService.submit(any>())).thenReturn(mock()) profiler.onTransactionStart(fixture.transaction1) - verify(mockExecutorService).submit(any()) + verify(mockExecutorService, never()).submit(any()) val profilingTraceData: ProfilingTraceData? = profiler.onTransactionFinish(fixture.transaction1, null) - assertNull(profilingTraceData) - verify(mockExecutorService).submit(any>()) + assertNotNull(profilingTraceData) + verify(mockExecutorService, never()).submit(any>()) + } + + @Test + fun `profiler does not throw if traces cannot be written to disk`() { + File(fixture.options.profilingTracesDirPath!!).setWritable(false) + val profiler = fixture.getSut(context) + profiler.onTransactionStart(fixture.transaction1) + profiler.onTransactionFinish(fixture.transaction1, null) + // We assert that no trace files are written + assertTrue(File(fixture.options.profilingTracesDirPath!!).list()!!.isEmpty()) + verify(fixture.mockLogger).log(eq(SentryLevel.ERROR), eq("Error while stopping profiling: "), any()) } @Test