Skip to content

Commit

Permalink
Collect slow and frozen frames as measurements (#3155)
Browse files Browse the repository at this point in the history
* Ensure slow and frozen frames values are reported as measurement values as well

* Interpolate total frame count to match span duration (#3158)

* Interpolate total frame count to match span duration

* Update Changelog
  • Loading branch information
markushi authored Jan 24, 2024
1 parent c38a8a9 commit 533109e
Show file tree
Hide file tree
Showing 5 changed files with 243 additions and 42 deletions.
1 change: 1 addition & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@
- Add ContentProvider and start profile ([#3128](https://github.com/getsentry/sentry-java/pull/3128))
- Extend internal performance collector APIs ([#3102](https://github.com/getsentry/sentry-java/pull/3102))
- Collect slow and frozen frames for spans using `OnFrameMetricsAvailableListener` ([#3111](https://github.com/getsentry/sentry-java/pull/3111))
- Interpolate total frame count to match span duration ([#3158](https://github.com/getsentry/sentry-java/pull/3158))

### Breaking changes

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -13,34 +13,41 @@ final class SentryFrameMetrics {
private long slowFrameDelayNanos;
private long frozenFrameDelayNanos;

private long totalDurationNanos;

public SentryFrameMetrics() {}

public SentryFrameMetrics(
int normalFrameCount,
int slowFrameCount,
long slowFrameDelayNanos,
int frozenFrameCount,
long frozenFrameDelayNanos) {
final int normalFrameCount,
final int slowFrameCount,
final long slowFrameDelayNanos,
final int frozenFrameCount,
final long frozenFrameDelayNanos,
final long totalDurationNanos) {
this.normalFrameCount = normalFrameCount;

this.slowFrameCount = slowFrameCount;
this.slowFrameDelayNanos = slowFrameDelayNanos;

this.frozenFrameCount = frozenFrameCount;
this.frozenFrameDelayNanos = frozenFrameDelayNanos;
this.totalDurationNanos = totalDurationNanos;
}

public void addSlowFrame(final long delayNanos) {
public void addSlowFrame(final long durationNanos, final long delayNanos) {
totalDurationNanos += durationNanos;
slowFrameDelayNanos += delayNanos;
slowFrameCount++;
}

public void addFrozenFrame(final long delayNanos) {
public void addFrozenFrame(final long durationNanos, final long delayNanos) {
totalDurationNanos += durationNanos;
frozenFrameDelayNanos += delayNanos;
frozenFrameCount++;
}

public void addNormalFrame() {
public void addNormalFrame(final long durationNanos) {
totalDurationNanos += durationNanos;
normalFrameCount++;
}

Expand Down Expand Up @@ -68,6 +75,10 @@ public int getTotalFrameCount() {
return normalFrameCount + slowFrameCount + frozenFrameCount;
}

public long getTotalDurationNanos() {
return totalDurationNanos;
}

public void clear() {
normalFrameCount = 0;

Expand All @@ -76,6 +87,8 @@ public void clear() {

frozenFrameCount = 0;
frozenFrameDelayNanos = 0;

totalDurationNanos = 0;
}

@NotNull
Expand All @@ -85,7 +98,8 @@ public SentryFrameMetrics duplicate() {
slowFrameCount,
slowFrameDelayNanos,
frozenFrameCount,
frozenFrameDelayNanos);
frozenFrameDelayNanos,
totalDurationNanos);
}

/**
Expand All @@ -99,11 +113,20 @@ public SentryFrameMetrics diffTo(final @NotNull SentryFrameMetrics other) {
slowFrameCount - other.slowFrameCount,
slowFrameDelayNanos - other.slowFrameDelayNanos,
frozenFrameCount - other.frozenFrameCount,
frozenFrameDelayNanos - other.frozenFrameDelayNanos);
frozenFrameDelayNanos - other.frozenFrameDelayNanos,
totalDurationNanos - other.totalDurationNanos);
}

/**
* @return true if the frame metrics contain valid data, meaning all values are greater or equal
* to 0
*/
public boolean containsValidData() {
// TODO sanity check durations?
return getTotalFrameCount() > 0;
return normalFrameCount >= 0
&& slowFrameCount >= 0
&& slowFrameDelayNanos >= 0
&& frozenFrameCount >= 0
&& frozenFrameDelayNanos >= 0
&& totalDurationNanos >= 0;
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -2,13 +2,17 @@

import io.sentry.IPerformanceContinuousCollector;
import io.sentry.ISpan;
import io.sentry.ITransaction;
import io.sentry.NoOpSpan;
import io.sentry.NoOpTransaction;
import io.sentry.SentryDate;
import io.sentry.SpanDataConvention;
import io.sentry.SpanId;
import io.sentry.android.core.internal.util.SentryFrameMetricsCollector;
import io.sentry.protocol.MeasurementValue;
import java.util.HashMap;
import java.util.Map;
import java.util.concurrent.TimeUnit;
import org.jetbrains.annotations.ApiStatus;
import org.jetbrains.annotations.NotNull;
import org.jetbrains.annotations.Nullable;
Expand All @@ -17,6 +21,7 @@
public class SpanFrameMetricsCollector
implements IPerformanceContinuousCollector,
SentryFrameMetricsCollector.FrameMetricsCollectorListener {

private @NotNull final Object lock = new Object();
private @Nullable final SentryFrameMetricsCollector frameMetricsCollector;
private @Nullable volatile String listenerId;
Expand All @@ -25,6 +30,8 @@ public class SpanFrameMetricsCollector
private @NotNull final SentryFrameMetrics currentFrameMetrics;
private final boolean enabled;

private float lastRefreshRate = 60.0f;

public SpanFrameMetricsCollector(final @NotNull SentryAndroidOptions options) {
frameMetricsCollector = options.getFrameMetricsCollector();
enabled = options.isEnablePerformanceV2() && options.isEnableFramesTracking();
Expand Down Expand Up @@ -76,10 +83,43 @@ public void onSpanFinished(final @NotNull ISpan span) {
diff = currentFrameMetrics.diffTo(metricsAtStart);
}
}

if (diff != null && diff.containsValidData()) {
int nonRenderedFrameCount = 0;

// if there are no content changes on Android, also no frames are rendered
// thus no frame metrics are provided
// in order to match the span duration with the total frame count,
// we simply interpolate the total number of frames based on the span duration
// this way the data is more sound and we also match the output of the cocoa SDK
final @Nullable SentryDate spanFinishDate = span.getFinishDate();
if (spanFinishDate != null) {
final long spanDurationNanos = spanFinishDate.diff(span.getStartDate());

final long frameMetricsDurationNanos = diff.getTotalDurationNanos();
final long nonRenderedDuration = spanDurationNanos - frameMetricsDurationNanos;
final double refreshRate = lastRefreshRate;

if (nonRenderedDuration > 0 && refreshRate > 0.0d) {
// e.g. at 60fps we would have 16.6ms per frame
final long normalFrameDurationNanos =
(long) ((double) TimeUnit.SECONDS.toNanos(1) / refreshRate);

nonRenderedFrameCount = (int) (nonRenderedDuration / normalFrameDurationNanos);
}
}

final int totalFrameCount = diff.getTotalFrameCount() + nonRenderedFrameCount;

span.setData(SpanDataConvention.FRAMES_TOTAL, totalFrameCount);
span.setData(SpanDataConvention.FRAMES_SLOW, diff.getSlowFrameCount());
span.setData(SpanDataConvention.FRAMES_FROZEN, diff.getFrozenFrameCount());
span.setData(SpanDataConvention.FRAMES_TOTAL, diff.getTotalFrameCount());

if (span instanceof ITransaction) {
span.setMeasurement(MeasurementValue.KEY_FRAMES_TOTAL, totalFrameCount);
span.setMeasurement(MeasurementValue.KEY_FRAMES_SLOW, diff.getSlowFrameCount());
span.setMeasurement(MeasurementValue.KEY_FRAMES_FROZEN, diff.getFrozenFrameCount());
}
}

synchronized (lock) {
Expand Down Expand Up @@ -114,11 +154,13 @@ public void onFrameMetricCollected(
final float refreshRate) {

if (isFrozen) {
currentFrameMetrics.addFrozenFrame(delayNanos);
currentFrameMetrics.addFrozenFrame(durationNanos, delayNanos);
} else if (isSlow) {
currentFrameMetrics.addSlowFrame(delayNanos);
currentFrameMetrics.addSlowFrame(durationNanos, delayNanos);
} else {
currentFrameMetrics.addNormalFrame();
currentFrameMetrics.addNormalFrame(durationNanos);
}

lastRefreshRate = refreshRate;
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -9,52 +9,52 @@ class SentryFrameMetricsTest {
@Test
fun addFastFrame() {
val frameMetrics = SentryFrameMetrics()
frameMetrics.addNormalFrame()
frameMetrics.addNormalFrame(10)
assertEquals(1, frameMetrics.normalFrameCount)

frameMetrics.addNormalFrame()
frameMetrics.addNormalFrame(10)
assertEquals(2, frameMetrics.normalFrameCount)
}

@Test
fun addSlowFrame() {
val frameMetrics = SentryFrameMetrics()
frameMetrics.addSlowFrame(100)
frameMetrics.addSlowFrame(116, 100)
assertEquals(1, frameMetrics.slowFrameCount)
assertEquals(100, frameMetrics.slowFrameDelayNanos)

frameMetrics.addSlowFrame(100)
frameMetrics.addSlowFrame(116, 100)
assertEquals(2, frameMetrics.slowFrameCount)
assertEquals(200, frameMetrics.slowFrameDelayNanos)
}

@Test
fun addFrozenFrame() {
val frameMetrics = SentryFrameMetrics()
frameMetrics.addFrozenFrame(1000)
frameMetrics.addFrozenFrame(1016, 1000)
assertEquals(1, frameMetrics.frozenFrameCount)
assertEquals(1000, frameMetrics.frozenFrameDelayNanos)

frameMetrics.addFrozenFrame(1000)
frameMetrics.addFrozenFrame(1016, 1000)
assertEquals(2, frameMetrics.frozenFrameCount)
assertEquals(2000, frameMetrics.frozenFrameDelayNanos)
}

@Test
fun totalFrameCount() {
val frameMetrics = SentryFrameMetrics()
frameMetrics.addNormalFrame()
frameMetrics.addSlowFrame(100)
frameMetrics.addFrozenFrame(1000)
frameMetrics.addNormalFrame(10)
frameMetrics.addSlowFrame(116, 100)
frameMetrics.addFrozenFrame(1016, 1000)
assertEquals(3, frameMetrics.totalFrameCount)
}

@Test
fun duplicate() {
val frameMetrics = SentryFrameMetrics()
frameMetrics.addNormalFrame()
frameMetrics.addSlowFrame(100)
frameMetrics.addFrozenFrame(1000)
frameMetrics.addNormalFrame(10)
frameMetrics.addSlowFrame(116, 100)
frameMetrics.addFrozenFrame(1016, 1000)

val dup = frameMetrics.duplicate()
assertEquals(1, dup.normalFrameCount)
Expand All @@ -69,17 +69,17 @@ class SentryFrameMetricsTest {
fun diffTo() {
// given one fast, 2 slow and 3 frozen frame
val frameMetricsA = SentryFrameMetrics()
frameMetricsA.addNormalFrame()
frameMetricsA.addSlowFrame(100)
frameMetricsA.addSlowFrame(100)
frameMetricsA.addFrozenFrame(1000)
frameMetricsA.addFrozenFrame(1000)
frameMetricsA.addFrozenFrame(1000)
frameMetricsA.addNormalFrame(10)
frameMetricsA.addSlowFrame(116, 100)
frameMetricsA.addSlowFrame(116, 100)
frameMetricsA.addFrozenFrame(1016, 1000)
frameMetricsA.addFrozenFrame(1016, 1000)
frameMetricsA.addFrozenFrame(1016, 1000)

// when 1 more slow and frozen frame is happening
val frameMetricsB = frameMetricsA.duplicate()
frameMetricsB.addSlowFrame(100)
frameMetricsB.addFrozenFrame(1000)
frameMetricsB.addSlowFrame(116, 100)
frameMetricsB.addFrozenFrame(1016, 1000)

// then the diff only contains the new data
val diff = frameMetricsB.diffTo(frameMetricsA)
Expand All @@ -95,9 +95,9 @@ class SentryFrameMetricsTest {
@Test
fun clear() {
val frameMetrics = SentryFrameMetrics().apply {
addNormalFrame()
addSlowFrame(100)
addFrozenFrame(1000)
addNormalFrame(10)
addSlowFrame(116, 100)
addFrozenFrame(1016, 1000)
}

frameMetrics.clear()
Expand All @@ -112,12 +112,15 @@ class SentryFrameMetricsTest {

@Test
fun containsValidData() {
// when no data is added, it's still valid
val frameMetrics = SentryFrameMetrics()
assertFalse(frameMetrics.containsValidData())
assertTrue(frameMetrics.containsValidData())

frameMetrics.addNormalFrame()
// when a normal frame is added, it's still valid
frameMetrics.addNormalFrame(10)
assertTrue(frameMetrics.containsValidData())

// when frame metrics are negative, it's invalid
val invalidData = SentryFrameMetrics().diffTo(frameMetrics)
assertFalse(invalidData.containsValidData())
}
Expand Down
Loading

0 comments on commit 533109e

Please sign in to comment.