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

Remove profiler main thread io #2348

Merged
merged 10 commits into from
Nov 15, 2022
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -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))
stefanosiano marked this conversation as resolved.
Show resolved Hide resolved

### Features

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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));
stefanosiano marked this conversation as resolved.
Show resolved Hide resolved
}

@SuppressLint("NewApi")
private void onTransactionStartSafe(@NotNull ITransaction transaction) {

// Debug.startMethodTracingSampling() is only available since Lollipop
if (buildInfoProvider.getSdkInfoVersion() < Build.VERSION_CODES.LOLLIPOP) return;
Expand All @@ -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(
Expand All @@ -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();
Expand Down Expand Up @@ -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
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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
Expand All @@ -47,11 +48,25 @@ class AndroidTransactionProfilerTest {
whenever(it.sdkInfoVersion).thenReturn(Build.VERSION_CODES.LOLLIPOP)
}
val mockLogger = mock<ILogger>()
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()
Expand Down Expand Up @@ -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)
Expand All @@ -257,16 +281,11 @@ class AndroidTransactionProfilerTest {
fun `timedOutData has timeout truncation reason`() {
val profiler = fixture.getSut(context)

val executorService = mock<ISentryExecutorService>()
val captor = argumentCaptor<Runnable>()
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)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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) {
Expand All @@ -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() {
Expand Down