diff --git a/CHANGELOG.md b/CHANGELOG.md index 7487b7ac6b..313a2ffb75 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -5,6 +5,7 @@ ### Fixes - Fix `Gpu.vendorId` should be a String ([#2343](https://github.com/getsentry/sentry-java/pull/2343)) +- Remove profiler main thread io ([#2348](https://github.com/getsentry/sentry-java/pull/2348)) ### Features 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 0e588fa122..ced0d976e9 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 @@ -139,9 +139,13 @@ private void init() { traceFilesDir = new File(tracesFilesDirPath); } - @SuppressLint("NewApi") @Override public synchronized void onTransactionStart(final @NotNull ITransaction transaction) { + options.getExecutorService().submit(() -> onTransactionStartSafe(transaction)); + } + + @SuppressLint("NewApi") + private void onTransactionStartSafe(final @NotNull ITransaction transaction) { // Debug.startMethodTracingSampling() is only available since Lollipop if (buildInfoProvider.getSdkInfoVersion() < Build.VERSION_CODES.LOLLIPOP) return; @@ -151,24 +155,14 @@ public synchronized void onTransactionStart(final @NotNull ITransaction transact // 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.exists()) { + if (traceFilesDir == null || intervalUs == 0 || !traceFilesDir.canWrite()) { return; } transactionsCounter++; // When the first transaction is starting, we can start profiling if (transactionsCounter == 1) { - - traceFile = new File(traceFilesDir, UUID.randomUUID() + ".trace"); - - if (traceFile.exists()) { - options - .getLogger() - .log(SentryLevel.DEBUG, "Trace file already exists: %s", traceFile.getPath()); - transactionsCounter--; - return; - } - onFirstTransactionStarted(transaction, traceFile); + onFirstTransactionStarted(transaction); } else { ProfilingTransactionData transactionData = new ProfilingTransactionData( @@ -186,8 +180,9 @@ public synchronized void onTransactionStart(final @NotNull ITransaction transact } @SuppressLint("NewApi") - private void onFirstTransactionStarted( - final @NotNull ITransaction transaction, final @NotNull File traceFile) { + private void 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"); measurementsMap.clear(); screenFrameRateMeasurements.clear(); @@ -245,11 +240,11 @@ public void onFrameMetricCollected( @Override public synchronized void onTransactionFinish(final @NotNull ITransaction transaction) { - onTransactionFinish(transaction, false); + options.getExecutorService().submit(() -> onTransactionFinish(transaction, false)); } @SuppressLint("NewApi") - private synchronized void onTransactionFinish( + private void onTransactionFinish( final @NotNull ITransaction transaction, final boolean isTimeout) { // onTransactionStart() is only available since Lollipop 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 fd0af55838..57dcb5448c 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 @@ -16,7 +16,6 @@ import io.sentry.assertEnvelopeItem import io.sentry.test.getCtor import org.junit.runner.RunWith import org.mockito.kotlin.any -import org.mockito.kotlin.argumentCaptor import org.mockito.kotlin.check import org.mockito.kotlin.mock import org.mockito.kotlin.never @@ -25,6 +24,8 @@ import org.mockito.kotlin.times import org.mockito.kotlin.verify import org.mockito.kotlin.whenever import java.io.File +import java.util.concurrent.Future +import java.util.concurrent.FutureTask import kotlin.test.AfterTest import kotlin.test.BeforeTest import kotlin.test.Test @@ -47,11 +48,25 @@ class AndroidTransactionProfilerTest { whenever(it.sdkInfoVersion).thenReturn(Build.VERSION_CODES.LOLLIPOP) } val mockLogger = mock() + var lastScheduledRunnable: Runnable? = null + val mockExecutorService = object : ISentryExecutorService { + override fun submit(runnable: Runnable): Future<*> { + runnable.run() + return FutureTask {} + } + override fun schedule(runnable: Runnable, delayMillis: Long): Future<*> { + lastScheduledRunnable = runnable + return FutureTask {} + } + override fun close(timeoutMillis: Long) {} + } + val options = spy(SentryAndroidOptions()).apply { dsn = mockDsn profilesSampleRate = 1.0 isDebug = true setLogger(mockLogger) + executorService = mockExecutorService } val hub: IHub = mock() @@ -246,6 +261,15 @@ class AndroidTransactionProfilerTest { assertNotNull(traceData) } + @Test + fun `profiler uses background threads`() { + val profiler = fixture.getSut(context) + fixture.options.executorService = mock() + profiler.onTransactionStart(fixture.transaction1) + profiler.onTransactionFinish(fixture.transaction1) + verify(fixture.hub, never()).captureEnvelope(any()) + } + @Test fun `onTransactionFinish works only if previously started`() { val profiler = fixture.getSut(context) @@ -257,16 +281,11 @@ class AndroidTransactionProfilerTest { fun `timedOutData has timeout truncation reason`() { val profiler = fixture.getSut(context) - val executorService = mock() - val captor = argumentCaptor() - whenever(executorService.schedule(captor.capture(), any())).thenReturn(null) - whenever(fixture.options.executorService).thenReturn(executorService) - // Start and finish first transaction profiling profiler.onTransactionStart(fixture.transaction1) // Set timed out data by calling the timeout scheduled job - captor.firstValue.run() + fixture.lastScheduledRunnable?.run() // First transaction finishes: timed out data is returned profiler.onTransactionFinish(fixture.transaction1) diff --git a/sentry-android-integration-tests/sentry-uitest-android/src/androidTest/java/io/sentry/uitest/android/EnvelopeTests.kt b/sentry-android-integration-tests/sentry-uitest-android/src/androidTest/java/io/sentry/uitest/android/EnvelopeTests.kt index 491205ec45..e41336fe48 100644 --- a/sentry-android-integration-tests/sentry-uitest-android/src/androidTest/java/io/sentry/uitest/android/EnvelopeTests.kt +++ b/sentry-android-integration-tests/sentry-uitest-android/src/androidTest/java/io/sentry/uitest/android/EnvelopeTests.kt @@ -19,7 +19,7 @@ import java.io.File import java.util.concurrent.TimeUnit import kotlin.test.Test import kotlin.test.assertEquals -import kotlin.test.assertFails +import kotlin.test.assertFailsWith import kotlin.test.assertFalse import kotlin.test.assertNotNull import kotlin.test.assertTrue @@ -68,6 +68,11 @@ class EnvelopeTests : BaseUiTest() { it.assertNoOtherItems() assertEquals("ProfilingSampleActivity", transactionItem.transaction) } + assertEnvelope { + val transactionItem: SentryTransaction = it.assertItem() + it.assertNoOtherItems() + assertEquals("e2etests", transactionItem.transaction) + } assertEnvelope { val profilingTraceData: ProfilingTraceData = it.assertItem() it.assertNoOtherItems() @@ -98,11 +103,6 @@ class EnvelopeTests : BaseUiTest() { .firstOrNull { t -> t.id == transaction.eventId.toString() } assertNotNull(transactionData) } - assertEnvelope { - val transactionItem: SentryTransaction = it.assertItem() - it.assertNoOtherItems() - assertEquals("e2etests", transactionItem.transaction) - } assertNoOtherEnvelopes() assertNoOtherRequests() } @@ -138,6 +138,12 @@ class EnvelopeTests : BaseUiTest() { assertEquals(transaction2.eventId.toString(), transactionItem.eventId.toString()) } // The profile is sent only in the last transaction envelope + assertEnvelope { + val transactionItem: SentryTransaction = it.assertItem() + it.assertNoOtherItems() + assertEquals(transaction3.eventId.toString(), transactionItem.eventId.toString()) + } + // The profile is sent only in the last transaction envelope assertEnvelope { val profilingTraceData: ProfilingTraceData = it.assertItem() it.assertNoOtherItems() @@ -171,12 +177,6 @@ class EnvelopeTests : BaseUiTest() { // The first and last transactions should be aligned to the start/stop of profile assertEquals(endTimes.last() - startTimes.first(), profilingTraceData.durationNs.toLong()) } - // The profile is sent only in the last transaction envelope - assertEnvelope { - val transactionItem: SentryTransaction = it.assertItem() - it.assertNoOtherItems() - assertEquals(transaction3.eventId.toString(), transactionItem.eventId.toString()) - } assertNoOtherEnvelopes() assertNoOtherRequests() } @@ -202,16 +202,20 @@ class EnvelopeTests : BaseUiTest() { } }.start() transaction.finish() - finished = true + // The profiler is stopped in background on the executor service, so we can stop deleting the trace file + // only after the profiler is stopped. This means we have to stop the deletion in the executorService + Sentry.getCurrentHub().options.executorService.submit { + finished = true + } relay.assert { - // The profile failed to be sent. Trying to read the envelope from the data transmitted throws an exception - assertFails { assertEnvelope {} } assertEnvelope { val transactionItem: SentryTransaction = it.assertItem() it.assertNoOtherItems() assertEquals("e2etests", transactionItem.transaction) } + // The profile failed to be sent. Trying to read the envelope from the data transmitted throws an exception + assertFailsWith { assertEnvelope {} } assertNoOtherEnvelopes() assertNoOtherRequests() } 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 95ed3b0bd5..60def396b9 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 @@ -59,14 +59,20 @@ class ProfilingActivity : AppCompatActivity() { executors.submit { runMathOperations() } } executors.submit { swipeList() } - binding.profilingStart.postDelayed({ finishTransactionAndPrintResults(t) }, (seconds * 1000).toLong()) + + Thread { + Thread.sleep((seconds * 1000).toLong()) + finishTransactionAndPrintResults(t) + binding.root.post { + binding.profilingProgressBar.visibility = View.GONE + } + }.start() } setContentView(binding.root) } private fun finishTransactionAndPrintResults(t: ITransaction) { t.finish() - binding.profilingProgressBar.visibility = View.GONE profileFinished = true val profilesDirPath = Sentry.getCurrentHub().options.profilingTracesDirPath if (profilesDirPath == null) { @@ -82,25 +88,31 @@ class ProfilingActivity : AppCompatActivity() { Thread.sleep((timeout - duration).coerceAtLeast(0)) } - // Get the last trace file, which is the current profile - val origProfileFile = File(profilesDirPath).listFiles()?.maxByOrNull { f -> f.lastModified() } - // Create a new profile file and copy the content of the original file into it - val profile = File(cacheDir, UUID.randomUUID().toString()) - origProfileFile?.copyTo(profile) - - val profileLength = profile.length() - val traceData = ProfilingTraceData(profile, t) - // Create envelope item from copied profile - val item = - SentryEnvelopeItem.fromProfilingTrace(traceData, Long.MAX_VALUE, Sentry.getCurrentHub().options.serializer) - val itemData = item.data - - // Compress the envelope item using Gzip - val bos = ByteArrayOutputStream() - GZIPOutputStream(bos).bufferedWriter().use { it.write(String(itemData)) } - - binding.profilingResult.text = - getString(R.string.profiling_result, profileLength, itemData.size, bos.toByteArray().size) + try { + // Get the last trace file, which is the current profile + val origProfileFile = File(profilesDirPath).listFiles()?.maxByOrNull { f -> f.lastModified() } + // Create a new profile file and copy the content of the original file into it + val profile = File(cacheDir, UUID.randomUUID().toString()) + origProfileFile?.copyTo(profile) + + val profileLength = profile.length() + val traceData = ProfilingTraceData(profile, t) + // Create envelope item from copied profile + val item = + SentryEnvelopeItem.fromProfilingTrace(traceData, Long.MAX_VALUE, Sentry.getCurrentHub().options.serializer) + val itemData = item.data + + // Compress the envelope item using Gzip + val bos = ByteArrayOutputStream() + GZIPOutputStream(bos).bufferedWriter().use { it.write(String(itemData)) } + + binding.root.post { + binding.profilingResult.text = + getString(R.string.profiling_result, profileLength, itemData.size, bos.toByteArray().size) + } + } catch (e: Exception) { + e.printStackTrace() + } } private fun swipeList() {