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

Calculate frame delay, slow+frozen frames inside SentryFrameMetricsCollector #3100

Merged
merged 3 commits into from
Dec 15, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
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
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -9,6 +9,7 @@
- Attaches spans for Application, ContentProvider, and Activities to app-start timings
- Uses Process.startUptimeMillis to calculate app-start timings
- To enable this feature set `options.isEnablePerformanceV2 = true`
- Move slow+frozen frame calculation, as well as frame delay inside SentryFrameMetricsCollector ([#3100](https://github.com/getsentry/sentry-java/pull/3100))

### Fixes

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -139,13 +139,17 @@ public AndroidProfiler(
frameMetricsCollectorId =
frameMetricsCollector.startCollection(
new SentryFrameMetricsCollector.FrameMetricsCollectorListener() {
final long nanosInSecond = TimeUnit.SECONDS.toNanos(1);
final long frozenFrameThresholdNanos = TimeUnit.MILLISECONDS.toNanos(700);
float lastRefreshRate = 0;

@Override
public void onFrameMetricCollected(
final long frameEndNanos, final long durationNanos, float refreshRate) {
final long frameStartNanos,
final long frameEndNanos,
final long durationNanos,
final long delayNanos,
final boolean isSlow,
final boolean isFrozen,
final float refreshRate) {
// transactionStartNanos is calculated through SystemClock.elapsedRealtimeNanos(),
// but frameEndNanos uses System.nanotime(), so we convert it to get the timestamp
// relative to transactionStartNanos
Expand All @@ -160,22 +164,17 @@ public void onFrameMetricCollected(
if (frameTimestampRelativeNanos < 0) {
return;
}
// Most frames take just a few nanoseconds longer than the optimal calculated
// duration.
// Therefore we subtract one, because otherwise almost all frames would be slow.
boolean isSlow = durationNanos > nanosInSecond / (refreshRate - 1);
float newRefreshRate = (int) (refreshRate * 100) / 100F;
if (durationNanos > frozenFrameThresholdNanos) {
if (isFrozen) {
frozenFrameRenderMeasurements.addLast(
new ProfileMeasurementValue(frameTimestampRelativeNanos, durationNanos));
} else if (isSlow) {
slowFrameRenderMeasurements.addLast(
new ProfileMeasurementValue(frameTimestampRelativeNanos, durationNanos));
}
if (newRefreshRate != lastRefreshRate) {
lastRefreshRate = newRefreshRate;
if (refreshRate != lastRefreshRate) {
lastRefreshRate = refreshRate;
screenFrameRateMeasurements.addLast(
new ProfileMeasurementValue(frameTimestampRelativeNanos, newRefreshRate));
new ProfileMeasurementValue(frameTimestampRelativeNanos, refreshRate));
}
}
});
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -25,12 +25,16 @@
import java.util.UUID;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.CopyOnWriteArraySet;
import java.util.concurrent.TimeUnit;
import org.jetbrains.annotations.ApiStatus;
import org.jetbrains.annotations.NotNull;
import org.jetbrains.annotations.Nullable;

@ApiStatus.Internal
public final class SentryFrameMetricsCollector implements Application.ActivityLifecycleCallbacks {
private static final long oneSecondInNanos = TimeUnit.SECONDS.toNanos(1);
private static final long frozenFrameThresholdNanos = TimeUnit.MILLISECONDS.toNanos(700);

private final @NotNull BuildInfoProvider buildInfoProvider;
private final @NotNull Set<Window> trackedWindows = new CopyOnWriteArraySet<>();
private final @NotNull ILogger logger;
Expand Down Expand Up @@ -132,6 +136,7 @@ public SentryFrameMetricsCollector(
logger.log(
SentryLevel.ERROR, "Unable to get the frame timestamp from the choreographer: ", e);
}

frameMetricsAvailableListener =
(window, frameMetrics, dropCountSinceLastInvocation) -> {
final long now = System.nanoTime();
Expand All @@ -140,7 +145,14 @@ public SentryFrameMetricsCollector(
? window.getContext().getDisplay().getRefreshRate()
: window.getWindowManager().getDefaultDisplay().getRefreshRate();

final long expectedFrameDuration = (long) (oneSecondInNanos / refreshRate);

final long cpuDuration = getFrameCpuDuration(frameMetrics);

// if totalDurationNanos is smaller than expectedFrameTimeNanos,
// it means that the frame was drawn within it's time budget, thus 0 delay
final long delayNanos = Math.max(0, cpuDuration - expectedFrameDuration);

long startTime = getFrameStartTimestamp(frameMetrics);
// If we couldn't get the timestamp through reflection, we use current time
if (startTime < 0) {
Expand All @@ -155,8 +167,21 @@ public SentryFrameMetricsCollector(
lastFrameStartNanos = startTime;
lastFrameEndNanos = startTime + cpuDuration;

// Most frames take just a few nanoseconds longer than the optimal calculated
// duration.
// Therefore we subtract one, because otherwise almost all frames would be slow.
final boolean isSlow = cpuDuration > oneSecondInNanos / (refreshRate - 1);
markushi marked this conversation as resolved.
Show resolved Hide resolved
final boolean isFrozen = isSlow && cpuDuration > frozenFrameThresholdNanos;

for (FrameMetricsCollectorListener l : listenerMap.values()) {
l.onFrameMetricCollected(lastFrameEndNanos, cpuDuration, refreshRate);
l.onFrameMetricCollected(
startTime,
lastFrameEndNanos,
cpuDuration,
delayNanos,
isSlow,
isFrozen,
refreshRate);
}
};
}
Expand Down Expand Up @@ -193,6 +218,8 @@ private long getFrameStartTimestamp(final @NotNull FrameMetrics frameMetrics) {
*/
@RequiresApi(api = Build.VERSION_CODES.N)
private long getFrameCpuDuration(final @NotNull FrameMetrics frameMetrics) {
// Inspired by JankStats
// https://cs.android.com/androidx/platform/frameworks/support/+/androidx-main:metrics/metrics-performance/src/main/java/androidx/metrics/performance/JankStatsApi24Impl.kt;l=74-79;drc=1de6215c6bd9e887e3d94556e9ac55cfb7b8c797
return frameMetrics.getMetric(FrameMetrics.UNKNOWN_DELAY_DURATION)
+ frameMetrics.getMetric(FrameMetrics.INPUT_HANDLING_DURATION)
+ frameMetrics.getMetric(FrameMetrics.ANIMATION_DURATION)
Expand Down Expand Up @@ -299,13 +326,26 @@ public interface FrameMetricsCollectorListener {
/**
* Called when a frame is collected.
*
* @param frameStartNanos Start timestamp of a frame in nanoseconds relative to
* System.nanotime().
* @param frameEndNanos End timestamp of a frame in nanoseconds relative to System.nanotime().
* @param durationNanos Duration in nanoseconds of the time spent from the cpu on the main
* thread to create the frame.
* @param refreshRate Refresh rate of the screen.
* @param delayNanos the frame delay, in nanoseconds.
* @param isSlow True if the frame is considered slow, rendering taking longer than the
* refresh-rate based budget, false otherwise.
* @param isFrozen True if the frame is considered frozen, rendering taking longer than 700ms,
* false otherwise.
* @param refreshRate the last known refresh rate when the frame was rendered.
*/
void onFrameMetricCollected(
final long frameEndNanos, final long durationNanos, final float refreshRate);
final long frameStartNanos,
final long frameEndNanos,
final long durationNanos,
final long delayNanos,
final boolean isSlow,
final boolean isFrozen,
final float refreshRate);
}

@ApiStatus.Internal
Expand Down
Loading