From ef5a20720200affb29b72c5615eb823a3456dc4e Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Tue, 8 Nov 2022 17:31:38 +0100 Subject: [PATCH 1/8] removed useless file exist check in AndroidTransactionProfiler wrapped AndroidTransactionProfiler methods in executor service fixed crash in sample app's ProfilingActivity --- .../core/AndroidTransactionProfiler.java | 30 +++++------ .../core/AndroidTransactionProfilerTest.kt | 24 ++++++--- .../samples/android/ProfilingActivity.kt | 54 +++++++++++-------- 3 files changed, 62 insertions(+), 46 deletions(-) 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 7f3ee8152a..8de11ccdad 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 @@ -138,9 +138,13 @@ private void init() { traceFilesDir = new File(tracesFilesDirPath); } - @SuppressLint("NewApi") @Override public synchronized void onTransactionStart(@NotNull ITransaction transaction) { + options.getExecutorService().submit(() -> onTransactionStartSafe(transaction)); + } + + @SuppressLint("NewApi") + private void onTransactionStartSafe(@NotNull ITransaction transaction) { // Debug.startMethodTracingSampling() is only available since Lollipop if (buildInfoProvider.getSdkInfoVersion() < Build.VERSION_CODES.LOLLIPOP) return; @@ -150,24 +154,14 @@ public synchronized void onTransactionStart(@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.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( @@ -185,8 +179,9 @@ public synchronized void onTransactionStart(@NotNull ITransaction transaction) { } @SuppressLint("NewApi") - private void onFirstTransactionStarted( - @NotNull ITransaction transaction, @NotNull File traceFile) { + private void onFirstTransactionStarted(@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(); @@ -244,12 +239,11 @@ public void onFrameMetricCollected( @Override public synchronized void onTransactionFinish(@NotNull ITransaction transaction) { - onTransactionFinish(transaction, false); + options.getExecutorService().submit(() -> onTransactionFinish(transaction, false)); } @SuppressLint("NewApi") - private synchronized void onTransactionFinish( - @NotNull ITransaction transaction, boolean isTimeout) { + private void onTransactionFinish(@NotNull ITransaction transaction, boolean isTimeout) { // onTransactionStart() is only available since Lollipop // and SystemClock.elapsedRealtimeNanos() since Jelly Bean 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 309e06035a..46f63d8f31 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.profilemeasurements.ProfileMeasurement 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() @@ -257,16 +272,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-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() { From 8941292c677b7fe2710db71b9ef49fff0ff50b89 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Tue, 8 Nov 2022 17:37:52 +0100 Subject: [PATCH 2/8] removed useless file exist check in AndroidTransactionProfiler wrapped AndroidTransactionProfiler methods in executor service fixed crash in sample app's ProfilingActivity --- CHANGELOG.md | 1 + .../android/core/AndroidTransactionProfilerTest.kt | 9 +++++++++ 2 files changed, 10 insertions(+) diff --git a/CHANGELOG.md b/CHANGELOG.md index f3bb776c95..79d60f0444 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,6 +6,7 @@ - Use correct set-cookie for the HTTP Client response object ([#2326](https://github.com/getsentry/sentry-java/pull/2326)) - Fix NoSuchElementException in CircularFifoQueue when cloning a Scope ([#2328](https://github.com/getsentry/sentry-java/pull/2328)) +- Remove profiler main thread io ([#2348](https://github.com/getsentry/sentry-java/pull/2348)) ### Features 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 46f63d8f31..0795cdbf7c 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 @@ -261,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) From b9dea130b86c35d3799d6b5eacbbc4f54ac4eb60 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Tue, 8 Nov 2022 18:17:13 +0100 Subject: [PATCH 3/8] updated ui tests --- .../io/sentry/uitest/android/EnvelopeTests.kt | 26 +++++++++---------- 1 file changed, 13 insertions(+), 13 deletions(-) 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 469337749a..a1ef7e8c3e 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 @@ -63,6 +63,11 @@ class EnvelopeTests : BaseUiTest() { transaction.finish() relay.assert { + assertEnvelope { + val transactionItem: SentryTransaction = it.assertItem() + it.assertNoOtherItems() + assertEquals("e2etests", transactionItem.transaction) + } assertEnvelope { val profilingTraceData: ProfilingTraceData = it.assertItem() it.assertNoOtherItems() @@ -89,11 +94,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() } @@ -129,6 +129,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() @@ -162,12 +168,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() } @@ -196,13 +196,13 @@ class EnvelopeTests : BaseUiTest() { 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 + assertFails { assertEnvelope {} } assertNoOtherEnvelopes() assertNoOtherRequests() } From 2fe6c810960950f6235dbe1261bf1ffceb15b5e3 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Wed, 9 Nov 2022 09:59:41 +0100 Subject: [PATCH 4/8] updated ui tests --- .../java/io/sentry/uitest/android/EnvelopeTests.kt | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) 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 a1ef7e8c3e..f288bd5035 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 @@ -9,6 +9,7 @@ import androidx.test.espresso.action.ViewActions import androidx.test.espresso.matcher.ViewMatchers import androidx.test.ext.junit.runners.AndroidJUnit4 import io.sentry.ProfilingTraceData +import io.sentry.ProfilingTransactionData import io.sentry.Sentry import io.sentry.SentryEvent import io.sentry.android.core.SentryAndroidOptions @@ -20,6 +21,7 @@ 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 @@ -193,7 +195,11 @@ 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 { assertEnvelope { @@ -202,7 +208,7 @@ class EnvelopeTests : BaseUiTest() { assertEquals("e2etests", transactionItem.transaction) } // The profile failed to be sent. Trying to read the envelope from the data transmitted throws an exception - assertFails { assertEnvelope {} } + assertFailsWith { assertEnvelope {} } assertNoOtherEnvelopes() assertNoOtherRequests() } From 3b23261da693008a8cc9fe8443bedf7fd699c709 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Wed, 9 Nov 2022 10:01:21 +0100 Subject: [PATCH 5/8] updated ui tests --- .../androidTest/java/io/sentry/uitest/android/EnvelopeTests.kt | 2 -- 1 file changed, 2 deletions(-) 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 f288bd5035..b49dc21557 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 @@ -9,7 +9,6 @@ import androidx.test.espresso.action.ViewActions import androidx.test.espresso.matcher.ViewMatchers import androidx.test.ext.junit.runners.AndroidJUnit4 import io.sentry.ProfilingTraceData -import io.sentry.ProfilingTransactionData import io.sentry.Sentry import io.sentry.SentryEvent import io.sentry.android.core.SentryAndroidOptions @@ -20,7 +19,6 @@ 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 From 6fe0bbdb3360922252cd071f68e5d6ff3bb46bf2 Mon Sep 17 00:00:00 2001 From: Sentry Github Bot Date: Tue, 15 Nov 2022 16:59:36 +0000 Subject: [PATCH 6/8] Format code --- .../io/sentry/android/core/AndroidTransactionProfiler.java | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) 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 67f28bdc45..20d81e6a49 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 @@ -245,7 +245,8 @@ public synchronized void onTransactionFinish(final @NotNull ITransaction transac } @SuppressLint("NewApi") - private void onTransactionFinish(final @NotNull ITransaction transaction, final boolean isTimeout) { + private void onTransactionFinish( + final @NotNull ITransaction transaction, final boolean isTimeout) { // onTransactionStart() is only available since Lollipop // and SystemClock.elapsedRealtimeNanos() since Jelly Bean From faf91755faa21111481c92c705ebf51bf37a3ed2 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Tue, 15 Nov 2022 17:59:37 +0100 Subject: [PATCH 7/8] fix merge --- .../io/sentry/android/core/AndroidTransactionProfiler.java | 6 +++--- 1 file changed, 3 insertions(+), 3 deletions(-) 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 67f28bdc45..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 @@ -180,8 +180,7 @@ private void onTransactionStartSafe(final @NotNull ITransaction transaction) { } @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"); @@ -245,7 +244,8 @@ public synchronized void onTransactionFinish(final @NotNull ITransaction transac } @SuppressLint("NewApi") - private void onTransactionFinish(final @NotNull ITransaction transaction, final boolean isTimeout) { + private void onTransactionFinish( + final @NotNull ITransaction transaction, final boolean isTimeout) { // onTransactionStart() is only available since Lollipop // and SystemClock.elapsedRealtimeNanos() since Jelly Bean From cf455ed2cf22f388305e0079011f757e20f0acf8 Mon Sep 17 00:00:00 2001 From: stefanosiano Date: Tue, 15 Nov 2022 18:01:29 +0100 Subject: [PATCH 8/8] updated changelog --- CHANGELOG.md | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 58e58a0c80..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 @@ -16,7 +17,6 @@ - Use correct set-cookie for the HTTP Client response object ([#2326](https://github.com/getsentry/sentry-java/pull/2326)) - Fix NoSuchElementException in CircularFifoQueue when cloning a Scope ([#2328](https://github.com/getsentry/sentry-java/pull/2328)) -- Remove profiler main thread io ([#2348](https://github.com/getsentry/sentry-java/pull/2348)) ### Features