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.

Sign up for GitHub

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

Jump to bottom

Profile envelopes sent directly from profiler #2298

Merged
merged 9 commits into from
Oct 19, 2022
Merged

Profile envelopes sent directly from profiler #2298

Show file tree
Hide file tree
Changes from 5 commits
Commits
Show all changes
9 commits
Select commit Hold shift + click to select a range
c333c48
AndroidTransactionProfiler now directly sends profile envelopes
stefanosiano Oct 14, 2022
1287e69
Merge branch 'main' into feat/android-profiler-sends-envelopes
stefanosiano Oct 14, 2022
0ebc5ae
Fixed ui tests not clearing unasserted requests after running test
stefanosiano Oct 14, 2022
103e4a9
Fixed dogfood ui test sending data after some time to mock relay
stefanosiano Oct 14, 2022
4a7b8ef
Merge branch 'main' into feat/android-profiler-sends-envelopes
stefanosiano Oct 14, 2022
e858a65
added hub parameter to AndroidTransactionProfiler ctor
stefanosiano Oct 17, 2022
3adb5db
Merge branch 'main' into feat/android-profiler-sends-envelopes
stefanosiano Oct 17, 2022
314686f
Merge branch 'main' into feat/android-profiler-sends-envelopes
stefanosiano Oct 18, 2022
00571fc
Merge branch 'main' into feat/android-profiler-sends-envelopes
stefanosiano Oct 19, 2022
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
91 changes: 33 additions & 58 deletions sentry-android-core/src/main/java/io/sentry/android/core/AndroidTransactionProfiler.java
View file
Open in desktop
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);
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

How about we move this into the constructor? Then we should be also able to test it properly without overriding Sentry.setCurrentHub

Perhaps, we could even make AndroidTransactionProfiler an integration, but I'm not sure if it was ever discussed before @marandaneto

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Maybe create an envelope out of the profilingTraceData and call captureEnvelope instead?
Your call here @romtsn
I don't recall any discussion related to AndroidTransactionProfiler as an integration.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Out of curiosity, why is it preferred to create an Envelope and call captureEnvelope instead of calling captureProfile/captureTransaction/captureWhatever?
Is it for consistency or are there other reasons? @marandaneto
I can quickly create the envelope and drop the captureProfile methods, if it's better

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Because this expands the public API and is not needed.

Copy link
Member

@adinauer adinauer Oct 17, 2022 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Does this mean we want to delay the 6.6.0 release until we removed captureProfile from the public API again in main?

Ah it's marked internal anyways, nevermind.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@adinauer Actually, HubAdapter is public, and it has a captureProfile method

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

HubAdapter is just to make Sentry static class testable.

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

That's fine, but HubAdapter isn't marked as internal, so technically there's nothing preventing users to actually use it.
Just wanted to make sure we are aware of this

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@marandaneto i made the change. Would you take another look before merging?

}

/**
Expand Down
115 changes: 55 additions & 60 deletions sentry-android-core/src/test/java/io/sentry/android/core/AndroidTransactionProfilerTest.kt
View file
Open in desktop
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
Open in desktop
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