Skip to content

Commit

Permalink
Merge 0ebc5ae into adee765
Browse files Browse the repository at this point in the history
  • Loading branch information
@stefanosiano
stefanosiano committed Oct 14, 2022
2 parents adee765 + 0ebc5ae commit adfb80f
Show file tree
Hide file tree
Showing 11 changed files with 128 additions and 142 deletions.
91 changes: 33 additions & 58 deletions sentry-android-core/src/main/java/io/sentry/android/core/AndroidTransactionProfiler.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -11,13 +11,13 @@
import android.os.Debug;
import android.os.Process;
import android.os.SystemClock;
import io.sentry.HubAdapter;
import io.sentry.ITransaction;
import io.sentry.ITransactionProfiler;
import io.sentry.ProfilingTraceData;
import io.sentry.ProfilingTransactionData;
import io.sentry.SentryLevel;
import io.sentry.android.core.internal.util.CpuInfoUtils;
import io.sentry.util.CollectionUtils;
import io.sentry.util.Objects;
import java.io.File;
import java.util.ArrayList;
Expand Down Expand Up @@ -48,7 +48,6 @@ final class AndroidTransactionProfiler implements ITransactionProfiler {
private @Nullable File traceFile = null;
private @Nullable File traceFilesDir = null;
private @Nullable Future<?> scheduledFinish = null;
private volatile @Nullable ProfilingTraceData timedOutProfilingData = null;
private final @NotNull Context context;
private final @NotNull SentryAndroidOptions options;
private final @NotNull BuildInfoProvider buildInfoProvider;
Expand Down Expand Up @@ -137,9 +136,7 @@ public synchronized void onTransactionStart(@NotNull ITransaction transaction) {
scheduledFinish =
options
.getExecutorService()
.schedule(
() -> timedOutProfilingData = onTransactionFinish(transaction, true),
PROFILING_TIMEOUT_MILLIS);
.schedule(() -> onTransactionFinish(transaction, true), PROFILING_TIMEOUT_MILLIS);

transactionStartNanos = SystemClock.elapsedRealtimeNanos();
profileStartCpuMillis = Process.getElapsedCpuTime();
Expand All @@ -166,53 +163,28 @@ public synchronized void onTransactionStart(@NotNull ITransaction transaction) {
}

@Override
public synchronized @Nullable ProfilingTraceData onTransactionFinish(
@NotNull ITransaction transaction) {
return onTransactionFinish(transaction, false);
public synchronized void onTransactionFinish(@NotNull ITransaction transaction) {
onTransactionFinish(transaction, false);
}

@SuppressLint("NewApi")
private synchronized @Nullable ProfilingTraceData onTransactionFinish(
private synchronized void onTransactionFinish(
@NotNull ITransaction transaction, boolean isTimeout) {

// onTransactionStart() is only available since Lollipop
// and SystemClock.elapsedRealtimeNanos() since Jelly Bean
if (buildInfoProvider.getSdkInfoVersion() < Build.VERSION_CODES.LOLLIPOP) return null;

final ProfilingTraceData profilingData = timedOutProfilingData;
if (buildInfoProvider.getSdkInfoVersion() < Build.VERSION_CODES.LOLLIPOP) return;

// Transaction finished, but it's not in the current profile
// Transaction finished, but it's not in the current profile. We can skip it
if (!transactionMap.containsKey(transaction.getEventId().toString())) {
// We check if we cached a profiling data due to a timeout with this profile in it
// If so, we return it back, otherwise we would simply lose it
if (profilingData != null) {
// Don't use method reference. This can cause issues on Android
List<String> ids =
CollectionUtils.map(profilingData.getTransactions(), (data) -> data.getId());
if (ids.contains(transaction.getEventId().toString())) {
timedOutProfilingData = null;
return profilingData;
} else {
// Another transaction is finishing before the timed out one
options
.getLogger()
.log(
SentryLevel.INFO,
"A timed out profiling data exists, but the finishing transaction %s (%s) is not part of it",
transaction.getName(),
transaction.getSpanContext().getTraceId().toString());
return null;
}
}
// A transaction is finishing, but it's not profiled. We can skip it
options
.getLogger()
.log(
SentryLevel.INFO,
"Transaction %s (%s) finished, but was not currently being profiled. Skipping",
transaction.getName(),
transaction.getSpanContext().getTraceId().toString());
return null;
return;
}

if (transactionsCounter > 0) {
Expand All @@ -239,7 +211,7 @@ public synchronized void onTransactionStart(@NotNull ITransaction transaction) {
Process.getElapsedCpuTime(),
profileStartCpuMillis);
}
return null;
return;
}

Debug.stopMethodTracing();
Expand All @@ -259,7 +231,7 @@ public synchronized void onTransactionStart(@NotNull ITransaction transaction) {

if (traceFile == null) {
options.getLogger().log(SentryLevel.ERROR, "Trace file does not exists");
return null;
return;
}

String versionName = "";
Expand Down Expand Up @@ -287,26 +259,29 @@ public synchronized void onTransactionStart(@NotNull ITransaction transaction) {

// cpu max frequencies are read with a lambda because reading files is involved, so it will be
// done in the background when the trace file is read
return new ProfilingTraceData(
traceFile,
transactionList,
transaction,
Long.toString(transactionDurationNanos),
buildInfoProvider.getSdkInfoVersion(),
abis != null && abis.length > 0 ? abis[0] : "",
() -> CpuInfoUtils.getInstance().readMaxFrequencies(),
buildInfoProvider.getManufacturer(),
buildInfoProvider.getModel(),
buildInfoProvider.getVersionRelease(),
buildInfoProvider.isEmulator(),
totalMem,
options.getProguardUuid(),
versionName,
versionCode,
options.getEnvironment(),
isTimeout
? ProfilingTraceData.TRUNCATION_REASON_TIMEOUT
: ProfilingTraceData.TRUNCATION_REASON_NORMAL);
ProfilingTraceData profilingTraceData =
new ProfilingTraceData(
traceFile,
transactionList,
transaction,
Long.toString(transactionDurationNanos),
buildInfoProvider.getSdkInfoVersion(),
abis != null && abis.length > 0 ? abis[0] : "",
() -> CpuInfoUtils.getInstance().readMaxFrequencies(),
buildInfoProvider.getManufacturer(),
buildInfoProvider.getModel(),
buildInfoProvider.getVersionRelease(),
buildInfoProvider.isEmulator(),
totalMem,
options.getProguardUuid(),
versionName,
versionCode,
options.getEnvironment(),
isTimeout
? ProfilingTraceData.TRUNCATION_REASON_TIMEOUT
: ProfilingTraceData.TRUNCATION_REASON_NORMAL);

HubAdapter.getInstance().captureProfile(profilingTraceData);
}

/**
Expand Down
115 changes: 55 additions & 60 deletions sentry-android-core/src/test/java/io/sentry/android/core/AndroidTransactionProfilerTest.kt
View file
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ import androidx.test.core.app.ApplicationProvider
import androidx.test.ext.junit.runners.AndroidJUnit4
import com.nhaarman.mockitokotlin2.any
import com.nhaarman.mockitokotlin2.argumentCaptor
import com.nhaarman.mockitokotlin2.check
import com.nhaarman.mockitokotlin2.mock
import com.nhaarman.mockitokotlin2.never
import com.nhaarman.mockitokotlin2.spy
Expand All @@ -16,6 +17,7 @@ import io.sentry.IHub
import io.sentry.ILogger
import io.sentry.ISentryExecutorService
import io.sentry.ProfilingTraceData
import io.sentry.Sentry
import io.sentry.SentryLevel
import io.sentry.SentryTracer
import io.sentry.TransactionContext
Expand All @@ -28,7 +30,6 @@ import kotlin.test.Test
import kotlin.test.assertEquals
import kotlin.test.assertFailsWith
import kotlin.test.assertNotNull
import kotlin.test.assertNull
import kotlin.test.assertTrue

@RunWith(AndroidJUnit4::class)
Expand Down Expand Up @@ -63,6 +64,7 @@ class AndroidTransactionProfilerTest {
transaction1 = SentryTracer(TransactionContext("", ""), hub)
transaction2 = SentryTracer(TransactionContext("", ""), hub)
transaction3 = SentryTracer(TransactionContext("", ""), hub)
Sentry.setCurrentHub(hub)
return AndroidTransactionProfiler(context, options, buildInfoProvider)
}
}
Expand Down Expand Up @@ -100,8 +102,13 @@ class AndroidTransactionProfilerTest {
fun `profiler profiles current transaction`() {
val profiler = fixture.getSut(context)
profiler.onTransactionStart(fixture.transaction1)
val traceData = profiler.onTransactionFinish(fixture.transaction1)
assertEquals(fixture.transaction1.eventId.toString(), traceData!!.transactionId)
profiler.onTransactionFinish(fixture.transaction1)

verify(fixture.hub).captureProfile(
check {
assertEquals(it.transactionId, fixture.transaction1.eventId.toString())
}
)
}

@Test
Expand All @@ -111,8 +118,8 @@ class AndroidTransactionProfilerTest {
}
val profiler = fixture.getSut(context, buildInfo)
profiler.onTransactionStart(fixture.transaction1)
val traceData = profiler.onTransactionFinish(fixture.transaction1)
assertNull(traceData)
profiler.onTransactionFinish(fixture.transaction1)
verify(fixture.hub, never()).captureProfile(any())
}

@Test
Expand All @@ -122,8 +129,8 @@ class AndroidTransactionProfilerTest {
}
val profiler = fixture.getSut(context)
profiler.onTransactionStart(fixture.transaction1)
val traceData = profiler.onTransactionFinish(fixture.transaction1)
assertNull(traceData)
profiler.onTransactionFinish(fixture.transaction1)
verify(fixture.hub, never()).captureProfile(any())
}

@Test
Expand Down Expand Up @@ -195,8 +202,8 @@ class AndroidTransactionProfilerTest {
}
val profiler = fixture.getSut(context)
profiler.onTransactionStart(fixture.transaction1)
val traceData = profiler.onTransactionFinish(fixture.transaction1)
assertNull(traceData)
profiler.onTransactionFinish(fixture.transaction1)
verify(fixture.hub, never()).captureProfile(any())
}

@Test
Expand All @@ -206,8 +213,8 @@ class AndroidTransactionProfilerTest {
}
val profiler = fixture.getSut(context)
profiler.onTransactionStart(fixture.transaction1)
val traceData = profiler.onTransactionFinish(fixture.transaction1)
assertNull(traceData)
profiler.onTransactionFinish(fixture.transaction1)
verify(fixture.hub, never()).captureProfile(any())
}

@Test
Expand All @@ -217,8 +224,8 @@ class AndroidTransactionProfilerTest {
}
val profiler = fixture.getSut(context)
profiler.onTransactionStart(fixture.transaction1)
val traceData = profiler.onTransactionFinish(fixture.transaction1)
assertNull(traceData)
profiler.onTransactionFinish(fixture.transaction1)
verify(fixture.hub, never()).captureProfile(any())
}

@Test
Expand All @@ -235,34 +242,8 @@ class AndroidTransactionProfilerTest {
@Test
fun `onTransactionFinish works only if previously started`() {
val profiler = fixture.getSut(context)
val traceData = profiler.onTransactionFinish(fixture.transaction1)
assertNull(traceData)
}

@Test
fun `onTransactionFinish returns timedOutData to the timed out transaction once, even after other transactions`() {
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()

// Start and finish second transaction. Since profiler returned data, it means no other profiling is running
profiler.onTransactionStart(fixture.transaction2)
assertEquals(fixture.transaction2.eventId.toString(), profiler.onTransactionFinish(fixture.transaction2)!!.transactionId)

// First transaction finishes: timed out data is returned
val traceData = profiler.onTransactionFinish(fixture.transaction1)
assertEquals(traceData!!.transactionId, fixture.transaction1.eventId.toString())

// If first transaction is finished again, nothing is returned
assertNull(profiler.onTransactionFinish(fixture.transaction1))
profiler.onTransactionFinish(fixture.transaction1)
verify(fixture.hub, never()).captureProfile(any())
}

@Test
Expand All @@ -281,9 +262,13 @@ class AndroidTransactionProfilerTest {
captor.firstValue.run()

// First transaction finishes: timed out data is returned
val traceData = profiler.onTransactionFinish(fixture.transaction1)
assertEquals(traceData!!.transactionId, fixture.transaction1.eventId.toString())
assertEquals(ProfilingTraceData.TRUNCATION_REASON_TIMEOUT, traceData.truncationReason)
profiler.onTransactionFinish(fixture.transaction1)
verify(fixture.hub).captureProfile(
check {
assertEquals(it.transactionId, fixture.transaction1.eventId.toString())
assertEquals(ProfilingTraceData.TRUNCATION_REASON_TIMEOUT, it.truncationReason)
}
)
}

@Test
Expand All @@ -292,11 +277,15 @@ class AndroidTransactionProfilerTest {
profiler.onTransactionStart(fixture.transaction1)
profiler.onTransactionStart(fixture.transaction2)

var traceData = profiler.onTransactionFinish(fixture.transaction2)
assertNull(traceData)
profiler.onTransactionFinish(fixture.transaction2)
verify(fixture.hub, never()).captureProfile(any())

traceData = profiler.onTransactionFinish(fixture.transaction1)
assertEquals(fixture.transaction1.eventId.toString(), traceData!!.transactionId)
profiler.onTransactionFinish(fixture.transaction1)
verify(fixture.hub).captureProfile(
check {
assertEquals(it.transactionId, fixture.transaction1.eventId.toString())
}
)
}

@Test
Expand All @@ -305,20 +294,26 @@ class AndroidTransactionProfilerTest {
profiler.onTransactionStart(fixture.transaction1)
profiler.onTransactionStart(fixture.transaction2)

var traceData = profiler.onTransactionFinish(fixture.transaction1)
assertNull(traceData)
profiler.onTransactionFinish(fixture.transaction1)
verify(fixture.hub, never()).captureProfile(any())

profiler.onTransactionStart(fixture.transaction3)
traceData = profiler.onTransactionFinish(fixture.transaction3)
assertNull(traceData)
traceData = profiler.onTransactionFinish(fixture.transaction2)
assertEquals(fixture.transaction2.eventId.toString(), traceData!!.transactionId)
val expectedTransactions = listOf(
fixture.transaction1.eventId.toString(),
fixture.transaction3.eventId.toString(),
fixture.transaction2.eventId.toString()
profiler.onTransactionFinish(fixture.transaction3)
verify(fixture.hub, never()).captureProfile(any())

profiler.onTransactionFinish(fixture.transaction2)
verify(fixture.hub).captureProfile(
check {
val expectedTransactions = listOf(
fixture.transaction1.eventId.toString(),
fixture.transaction3.eventId.toString(),
fixture.transaction2.eventId.toString()
)
assertEquals(it.transactionId, fixture.transaction2.eventId.toString())

assertTrue(it.transactions.map { it.id }.containsAll(expectedTransactions))
assertTrue(expectedTransactions.containsAll(it.transactions.map { it.id }))
}
)
assertTrue(traceData.transactions.map { it.id }.containsAll(expectedTransactions))
assertTrue(expectedTransactions.containsAll(traceData.transactions.map { it.id }))
}
}
3 changes: 1 addition & 2 deletions sentry-android-core/src/test/java/io/sentry/android/core/SentryAndroidOptionsTest.kt
View file
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,6 @@ package io.sentry.android.core
import io.sentry.ITransaction
import io.sentry.ITransactionProfiler
import io.sentry.NoOpTransactionProfiler
import io.sentry.ProfilingTraceData
import io.sentry.protocol.DebugImage
import kotlin.test.Test
import kotlin.test.assertEquals
Expand Down Expand Up @@ -110,6 +109,6 @@ class SentryAndroidOptionsTest {

private class CustomTransactionProfiler : ITransactionProfiler {
override fun onTransactionStart(transaction: ITransaction) {}
override fun onTransactionFinish(transaction: ITransaction): ProfilingTraceData? = null
override fun onTransactionFinish(transaction: ITransaction) {}
}
}
Loading

0 comments on commit adfb80f

Please sign in to comment.