Skip to content

Commit ed00ecb

Browse files
authored
added FrameMetrics to Android profiling data (#2342)
* added ProfileMeasurements to AndroidTransactionProfiler and ProfilingTraceData * added frameMetrics (slow and frozen frames) and screen refresh rate * added a SentryFrameMetricsCollector to collect frameMetrics * updated espresso test dependency to stable to run on Android 13 devices * increased benchmark cpu overhead threshold from 5% to 5.5% * updated benchmark device from OnePlus Nord N200 to Google Pixel 3a * added automatic activity transaction in ui test * Remove profiler main thread io (#2348) * fixed crash in sample app's ProfilingActivity
1 parent 84f0ef1 commit ed00ecb

File tree

20 files changed

+1276
-149
lines changed

20 files changed

+1276
-149
lines changed

.sauce/sentry-uitest-android-benchmark-lite.yml

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -20,7 +20,7 @@ suites:
2020

2121
- name: "Android 11 (api 30)"
2222
devices:
23-
- id: OnePlus_Nord_N200_5G_real_us # OnePlus Nord N200 5G - api 30 (11)
23+
- id: Google_Pixel_3a_real # Google Pixel 3a - api 30 (11)
2424

2525
artifacts:
2626
download:

.sauce/sentry-uitest-android-benchmark.yml

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -28,11 +28,11 @@ suites:
2828
devices:
2929
- id: OnePlus_9_Pro_real_us # OnePlus 9 Pro - api 30 (11) - high end
3030
- id: Google_Pixel_4_real_us # Google Pixel 4 - api 30 (11) - mid end
31-
- id: OnePlus_Nord_N200_5G_real_us # OnePlus Nord N200 5G - api 30 (11) - low end
31+
- id: Google_Pixel_3a_real # Google Pixel 3a - api 30 (11) - low end
3232

3333
- name: "Android 10 (api 29)"
3434
devices:
35-
- id: OnePlus_7T_real_us # OnePlus 7T - api 29 (10)
35+
- id: Google_Pixel_4_XL_real_us1 # Google Pixel 4 XL - api 29 (10)
3636
- id: Nokia_7_1_real_us # Nokia 7.1 - api 29 (10)
3737

3838
# At the time of writing (July, 4, 2022), the market share per android version is:

CHANGELOG.md

Lines changed: 12 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,15 @@
11
# Changelog
22

3+
## Unreleased
4+
5+
### Fixes
6+
7+
- Remove profiler main thread io ([#2348](https://github.com/getsentry/sentry-java/pull/2348))
8+
9+
### Features
10+
11+
- Add FrameMetrics to Android profiling data ([#2342](https://github.com/getsentry/sentry-java/pull/2342))
12+
313
## 6.7.1
414

515
### Fixes
@@ -11,6 +21,8 @@
1121

1222
### Features
1323

24+
- Don't set device name on Android if `sendDefaultPii` is disabled ([#2354](https://github.com/getsentry/sentry-java/pull/2354))
25+
- Fix corrupted UUID on Motorola devices ([#2363](https://github.com/getsentry/sentry-java/pull/2363))
1426
- Update Spring Boot Jakarta to Spring Boot 3.0.0-RC2 ([#2347](https://github.com/getsentry/sentry-java/pull/2347))
1527

1628
## 6.7.0

buildSrc/src/main/java/Config.kt

Lines changed: 2 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -139,10 +139,8 @@ object Config {
139139
}
140140

141141
object TestLibs {
142-
// todo These rc versions are needed to run ui tests on Android 13.
143-
// They will be replaced by stable version when 1.5.0/3.5.0 will be out.
144-
private val androidxTestVersion = "1.5.0-rc01"
145-
private val espressoVersion = "3.5.0-rc01"
142+
private val androidxTestVersion = "1.5.0"
143+
private val espressoVersion = "3.5.0"
146144

147145
val androidJUnitRunner = "androidx.test.runner.AndroidJUnitRunner"
148146
val kotlinTestJunit = "org.jetbrains.kotlin:kotlin-test-junit:$kotlinVersion"

sentry-android-core/src/main/java/io/sentry/android/core/AndroidOptionsInitializer.java

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@
1313
import io.sentry.SentryLevel;
1414
import io.sentry.android.core.cache.AndroidEnvelopeCache;
1515
import io.sentry.android.core.internal.modules.AssetsModulesLoader;
16+
import io.sentry.android.core.internal.util.SentryFrameMetricsCollector;
1617
import io.sentry.android.fragment.FragmentLifecycleIntegration;
1718
import io.sentry.android.timber.SentryTimberIntegration;
1819
import io.sentry.util.Objects;
@@ -154,8 +155,10 @@ static void init(
154155
options.addEventProcessor(new PerformanceAndroidEventProcessor(options, activityFramesTracker));
155156

156157
options.setTransportGate(new AndroidTransportGate(context, options.getLogger()));
158+
final SentryFrameMetricsCollector frameMetricsCollector =
159+
new SentryFrameMetricsCollector(context, options, buildInfoProvider);
157160
options.setTransactionProfiler(
158-
new AndroidTransactionProfiler(context, options, buildInfoProvider));
161+
new AndroidTransactionProfiler(context, options, buildInfoProvider, frameMetricsCollector));
159162
options.setModulesLoader(new AssetsModulesLoader(context, options.getLogger()));
160163
}
161164

sentry-android-core/src/main/java/io/sentry/android/core/AndroidTransactionProfiler.java

Lines changed: 122 additions & 35 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@
1111
import android.os.Debug;
1212
import android.os.Process;
1313
import android.os.SystemClock;
14+
import android.view.FrameMetrics;
1415
import io.sentry.HubAdapter;
1516
import io.sentry.IHub;
1617
import io.sentry.ITransaction;
@@ -20,15 +21,20 @@
2021
import io.sentry.SentryEnvelope;
2122
import io.sentry.SentryLevel;
2223
import io.sentry.android.core.internal.util.CpuInfoUtils;
24+
import io.sentry.android.core.internal.util.SentryFrameMetricsCollector;
2325
import io.sentry.exception.SentryEnvelopeException;
26+
import io.sentry.profilemeasurements.ProfileMeasurement;
27+
import io.sentry.profilemeasurements.ProfileMeasurementValue;
2428
import io.sentry.util.Objects;
2529
import java.io.File;
30+
import java.util.ArrayDeque;
2631
import java.util.ArrayList;
2732
import java.util.HashMap;
2833
import java.util.List;
2934
import java.util.Map;
3035
import java.util.UUID;
3136
import java.util.concurrent.Future;
37+
import java.util.concurrent.TimeUnit;
3238
import org.jetbrains.annotations.NotNull;
3339
import org.jetbrains.annotations.Nullable;
3440

@@ -60,23 +66,41 @@ final class AndroidTransactionProfiler implements ITransactionProfiler {
6066
private long profileStartCpuMillis = 0;
6167
private boolean isInitialized = false;
6268
private int transactionsCounter = 0;
69+
private @Nullable String frameMetricsCollectorId;
70+
private final @NotNull SentryFrameMetricsCollector frameMetricsCollector;
6371
private final @NotNull Map<String, ProfilingTransactionData> transactionMap = new HashMap<>();
72+
private final @NotNull ArrayDeque<ProfileMeasurementValue> screenFrameRateMeasurements =
73+
new ArrayDeque<>();
74+
private final @NotNull ArrayDeque<ProfileMeasurementValue> slowFrameRenderMeasurements =
75+
new ArrayDeque<>();
76+
private final @NotNull ArrayDeque<ProfileMeasurementValue> frozenFrameRenderMeasurements =
77+
new ArrayDeque<>();
78+
private final @NotNull Map<String, ProfileMeasurement> measurementsMap = new HashMap<>();
6479

6580
public AndroidTransactionProfiler(
6681
final @NotNull Context context,
6782
final @NotNull SentryAndroidOptions sentryAndroidOptions,
68-
final @NotNull BuildInfoProvider buildInfoProvider) {
69-
this(context, sentryAndroidOptions, buildInfoProvider, HubAdapter.getInstance());
83+
final @NotNull BuildInfoProvider buildInfoProvider,
84+
final @NotNull SentryFrameMetricsCollector frameMetricsCollector) {
85+
this(
86+
context,
87+
sentryAndroidOptions,
88+
buildInfoProvider,
89+
frameMetricsCollector,
90+
HubAdapter.getInstance());
7091
}
7192

7293
public AndroidTransactionProfiler(
7394
final @NotNull Context context,
7495
final @NotNull SentryAndroidOptions sentryAndroidOptions,
7596
final @NotNull BuildInfoProvider buildInfoProvider,
97+
final @NotNull SentryFrameMetricsCollector frameMetricsCollector,
7698
final @NotNull IHub hub) {
7799
this.context = Objects.requireNonNull(context, "The application context is required");
78100
this.options = Objects.requireNonNull(sentryAndroidOptions, "SentryAndroidOptions is required");
79101
this.hub = Objects.requireNonNull(hub, "Hub is required");
102+
this.frameMetricsCollector =
103+
Objects.requireNonNull(frameMetricsCollector, "SentryFrameMetricsCollector is required");
80104
this.buildInfoProvider =
81105
Objects.requireNonNull(buildInfoProvider, "The BuildInfoProvider is required.");
82106
this.packageInfo = ContextUtils.getPackageInfo(context, options.getLogger(), buildInfoProvider);
@@ -115,9 +139,13 @@ private void init() {
115139
traceFilesDir = new File(tracesFilesDirPath);
116140
}
117141

118-
@SuppressLint("NewApi")
119142
@Override
120-
public synchronized void onTransactionStart(@NotNull ITransaction transaction) {
143+
public synchronized void onTransactionStart(final @NotNull ITransaction transaction) {
144+
options.getExecutorService().submit(() -> onTransactionStartSafe(transaction));
145+
}
146+
147+
@SuppressLint("NewApi")
148+
private void onTransactionStartSafe(final @NotNull ITransaction transaction) {
121149

122150
// Debug.startMethodTracingSampling() is only available since Lollipop
123151
if (buildInfoProvider.getSdkInfoVersion() < Build.VERSION_CODES.LOLLIPOP) return;
@@ -127,38 +155,14 @@ public synchronized void onTransactionStart(@NotNull ITransaction transaction) {
127155

128156
// traceFilesDir is null or intervalUs is 0 only if there was a problem in the init, but
129157
// we already logged that
130-
if (traceFilesDir == null || intervalUs == 0 || !traceFilesDir.exists()) {
158+
if (traceFilesDir == null || intervalUs == 0 || !traceFilesDir.canWrite()) {
131159
return;
132160
}
133161

134162
transactionsCounter++;
135163
// When the first transaction is starting, we can start profiling
136164
if (transactionsCounter == 1) {
137-
138-
traceFile = new File(traceFilesDir, UUID.randomUUID() + ".trace");
139-
140-
if (traceFile.exists()) {
141-
options
142-
.getLogger()
143-
.log(SentryLevel.DEBUG, "Trace file already exists: %s", traceFile.getPath());
144-
transactionsCounter--;
145-
return;
146-
}
147-
148-
// We stop profiling after a timeout to avoid huge profiles to be sent
149-
scheduledFinish =
150-
options
151-
.getExecutorService()
152-
.schedule(() -> onTransactionFinish(transaction, true), PROFILING_TIMEOUT_MILLIS);
153-
154-
transactionStartNanos = SystemClock.elapsedRealtimeNanos();
155-
profileStartCpuMillis = Process.getElapsedCpuTime();
156-
157-
ProfilingTransactionData transactionData =
158-
new ProfilingTransactionData(transaction, transactionStartNanos, profileStartCpuMillis);
159-
transactionMap.put(transaction.getEventId().toString(), transactionData);
160-
161-
Debug.startMethodTracingSampling(traceFile.getPath(), BUFFER_SIZE_BYTES, intervalUs);
165+
onFirstTransactionStarted(transaction);
162166
} else {
163167
ProfilingTransactionData transactionData =
164168
new ProfilingTransactionData(
@@ -175,14 +179,73 @@ public synchronized void onTransactionStart(@NotNull ITransaction transaction) {
175179
transactionsCounter);
176180
}
177181

182+
@SuppressLint("NewApi")
183+
private void onFirstTransactionStarted(final @NotNull ITransaction transaction) {
184+
// We create a file with a uuid name, so no need to check if it already exists
185+
traceFile = new File(traceFilesDir, UUID.randomUUID() + ".trace");
186+
187+
measurementsMap.clear();
188+
screenFrameRateMeasurements.clear();
189+
slowFrameRenderMeasurements.clear();
190+
frozenFrameRenderMeasurements.clear();
191+
192+
frameMetricsCollectorId =
193+
frameMetricsCollector.startCollection(
194+
new SentryFrameMetricsCollector.FrameMetricsCollectorListener() {
195+
final long nanosInSecond = TimeUnit.SECONDS.toNanos(1);
196+
final long frozenFrameThresholdNanos = TimeUnit.MILLISECONDS.toNanos(700);
197+
float lastRefreshRate = 0;
198+
199+
@Override
200+
public void onFrameMetricCollected(
201+
@NotNull FrameMetrics frameMetrics, float refreshRate) {
202+
long frameTimestampRelativeNanos =
203+
SystemClock.elapsedRealtimeNanos() - transactionStartNanos;
204+
long durationNanos = frameMetrics.getMetric(FrameMetrics.TOTAL_DURATION);
205+
// Most frames take just a few nanoseconds longer than the optimal calculated
206+
// duration.
207+
// Therefore we subtract one, because otherwise almost all frames would be slow.
208+
boolean isSlow = durationNanos > nanosInSecond / (refreshRate - 1);
209+
float newRefreshRate = (int) (refreshRate * 100) / 100F;
210+
if (durationNanos > frozenFrameThresholdNanos) {
211+
frozenFrameRenderMeasurements.addLast(
212+
new ProfileMeasurementValue(frameTimestampRelativeNanos, durationNanos));
213+
} else if (isSlow) {
214+
slowFrameRenderMeasurements.addLast(
215+
new ProfileMeasurementValue(frameTimestampRelativeNanos, durationNanos));
216+
}
217+
if (newRefreshRate != lastRefreshRate) {
218+
lastRefreshRate = newRefreshRate;
219+
screenFrameRateMeasurements.addLast(
220+
new ProfileMeasurementValue(frameTimestampRelativeNanos, newRefreshRate));
221+
}
222+
}
223+
});
224+
225+
// We stop profiling after a timeout to avoid huge profiles to be sent
226+
scheduledFinish =
227+
options
228+
.getExecutorService()
229+
.schedule(() -> onTransactionFinish(transaction, true), PROFILING_TIMEOUT_MILLIS);
230+
231+
transactionStartNanos = SystemClock.elapsedRealtimeNanos();
232+
profileStartCpuMillis = Process.getElapsedCpuTime();
233+
234+
ProfilingTransactionData transactionData =
235+
new ProfilingTransactionData(transaction, transactionStartNanos, profileStartCpuMillis);
236+
transactionMap.put(transaction.getEventId().toString(), transactionData);
237+
238+
Debug.startMethodTracingSampling(traceFile.getPath(), BUFFER_SIZE_BYTES, intervalUs);
239+
}
240+
178241
@Override
179-
public synchronized void onTransactionFinish(@NotNull ITransaction transaction) {
180-
onTransactionFinish(transaction, false);
242+
public synchronized void onTransactionFinish(final @NotNull ITransaction transaction) {
243+
options.getExecutorService().submit(() -> onTransactionFinish(transaction, false));
181244
}
182245

183246
@SuppressLint("NewApi")
184-
private synchronized void onTransactionFinish(
185-
@NotNull ITransaction transaction, boolean isTimeout) {
247+
private void onTransactionFinish(
248+
final @NotNull ITransaction transaction, final boolean isTimeout) {
186249

187250
// onTransactionStart() is only available since Lollipop
188251
// and SystemClock.elapsedRealtimeNanos() since Jelly Bean
@@ -226,8 +289,14 @@ private synchronized void onTransactionFinish(
226289
}
227290
return;
228291
}
292+
onLastTransactionFinished(transaction, isTimeout);
293+
}
229294

295+
@SuppressLint("NewApi")
296+
private void onLastTransactionFinished(final ITransaction transaction, final boolean isTimeout) {
230297
Debug.stopMethodTracing();
298+
frameMetricsCollector.stopCollection(frameMetricsCollectorId);
299+
231300
long transactionEndNanos = SystemClock.elapsedRealtimeNanos();
232301
long transactionEndCpuMillis = Process.getElapsedCpuTime();
233302
long transactionDurationNanos = transactionEndNanos - transactionStartNanos;
@@ -270,6 +339,23 @@ private synchronized void onTransactionFinish(
270339
profileStartCpuMillis);
271340
}
272341

342+
if (!slowFrameRenderMeasurements.isEmpty()) {
343+
measurementsMap.put(
344+
ProfileMeasurement.ID_SLOW_FRAME_RENDERS,
345+
new ProfileMeasurement(ProfileMeasurement.UNIT_NANOSECONDS, slowFrameRenderMeasurements));
346+
}
347+
if (!frozenFrameRenderMeasurements.isEmpty()) {
348+
measurementsMap.put(
349+
ProfileMeasurement.ID_FROZEN_FRAME_RENDERS,
350+
new ProfileMeasurement(
351+
ProfileMeasurement.UNIT_NANOSECONDS, frozenFrameRenderMeasurements));
352+
}
353+
if (!screenFrameRateMeasurements.isEmpty()) {
354+
measurementsMap.put(
355+
ProfileMeasurement.ID_SCREEN_FRAME_RATES,
356+
new ProfileMeasurement(ProfileMeasurement.UNIT_HZ, screenFrameRateMeasurements));
357+
}
358+
273359
// cpu max frequencies are read with a lambda because reading files is involved, so it will be
274360
// done in the background when the trace file is read
275361
ProfilingTraceData profilingTraceData =
@@ -292,7 +378,8 @@ private synchronized void onTransactionFinish(
292378
options.getEnvironment(),
293379
isTimeout
294380
? ProfilingTraceData.TRUNCATION_REASON_TIMEOUT
295-
: ProfilingTraceData.TRUNCATION_REASON_NORMAL);
381+
: ProfilingTraceData.TRUNCATION_REASON_NORMAL,
382+
measurementsMap);
296383

297384
SentryEnvelope envelope;
298385
try {

0 commit comments

Comments
 (0)