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

[QA] Avoid collecting normal frames #3782

Merged
merged 5 commits into from
Nov 14, 2024
Merged
Show file tree
Hide file tree
Changes from 2 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 @@ -4,6 +4,7 @@

### Fixes

- Avoid collecting normal frames ([#3782](https://github.com/getsentry/sentry-java/pull/3782))
- Deprecate `enableTracing` option ([#3777](https://github.com/getsentry/sentry-java/pull/3777))

## 7.15.0
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -6,7 +6,6 @@
@ApiStatus.Internal
final class SentryFrameMetrics {

private int normalFrameCount;
private int slowFrameCount;
private int frozenFrameCount;

Expand All @@ -18,15 +17,11 @@ final class SentryFrameMetrics {
public SentryFrameMetrics() {}

public SentryFrameMetrics(
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;

Expand All @@ -47,15 +42,9 @@ public void addFrame(
} else if (isSlow) {
slowFrameDelayNanos += delayNanos;
slowFrameCount += 1;
} else {
normalFrameCount += 1;
}
}

public int getNormalFrameCount() {
return normalFrameCount;
}

public int getSlowFrameCount() {
return slowFrameCount;
}
Expand All @@ -73,16 +62,14 @@ public long getFrozenFrameDelayNanos() {
}

public int getTotalFrameCount() {
return normalFrameCount + slowFrameCount + frozenFrameCount;
return slowFrameCount + frozenFrameCount;
Copy link
Member

Choose a reason for hiding this comment

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

but the total frame count would be incorrect now, why are we removing it?

Copy link
Member Author

@stefanosiano stefanosiano Oct 11, 2024

Choose a reason for hiding this comment

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

we are still calculating the normal frames based on the span duration.
Actually, previously we were interpolating the number of frames by removing the fast frames duration, too, which could lead to having more total frames than expected. Now it should be more accurate.
E.g. a frame take 2ms to render in a span of 10ms.
Previously we were adding the frames that we were interpolating based on the remaining 8ms (10-2) which was logically wrong, since there should be only 1 frame in that case.

Does it make sense?

Copy link
Member

Choose a reason for hiding this comment

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

I see two issues:

  • If the list doesn't contain the normal frames anymore, the duration may be considered as a delayed frame. E.g. if a span takes 1000ms and only normal frames happen, the list will be empty and it will be considered a frame delay, see the code here:
    final long durationBeforeSpan = Math.max(0, spanStartNanos - frame.startNanos);
    final long delayBeforeSpan =
    Math.max(0, durationBeforeSpan - frame.expectedDurationNanos);
    final long delayWithinSpan =
    Math.min(frame.delayNanos - delayBeforeSpan, spanDurationNanos);
    final long frameStart = Math.max(spanStartNanos, frame.startNanos);
    final long frameEnd = Math.min(spanEndNanos, frame.endNanos);
    final long frameDuration = frameEnd - frameStart;
  • the method is called getTotalFrameCount but it only returns the sum of slow+frozen 😅

Copy link
Member Author

@stefanosiano stefanosiano Oct 24, 2024

Choose a reason for hiding this comment

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

If the list doesn't contain the normal frames anymore, the duration may be considered as a delayed frame. E.g. if a span takes 1000ms and only normal frames happen, the list will be empty and it will be considered a frame delay

That part is skipped if the list is empty, and the whole span is considered without delay. We have a test for that, too. Now it just verifies the number of frames, but i'll add the 0 delay verification

the method is called getTotalFrameCount but it only returns the sum of slow+frozen

Ok 😅 I'll rename it to getSlowFrozenFrameCount

}

public long getTotalDurationNanos() {
return totalDurationNanos;
}

public void clear() {
normalFrameCount = 0;

slowFrameCount = 0;
slowFrameDelayNanos = 0;

Expand All @@ -95,7 +82,6 @@ public void clear() {
@NotNull
public SentryFrameMetrics duplicate() {
return new SentryFrameMetrics(
normalFrameCount,
slowFrameCount,
slowFrameDelayNanos,
frozenFrameCount,
Expand All @@ -110,7 +96,6 @@ public SentryFrameMetrics duplicate() {
@NotNull
public SentryFrameMetrics diffTo(final @NotNull SentryFrameMetrics other) {
return new SentryFrameMetrics(
normalFrameCount - other.normalFrameCount,
slowFrameCount - other.slowFrameCount,
slowFrameDelayNanos - other.slowFrameDelayNanos,
frozenFrameCount - other.frozenFrameCount,
Expand All @@ -123,8 +108,7 @@ public SentryFrameMetrics diffTo(final @NotNull SentryFrameMetrics other) {
* to 0
*/
public boolean containsValidData() {
return normalFrameCount >= 0
&& slowFrameCount >= 0
return slowFrameCount >= 0
&& slowFrameDelayNanos >= 0
&& frozenFrameCount >= 0
&& frozenFrameDelayNanos >= 0
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -254,15 +254,17 @@ public void onFrameMetricCollected(
(long) ((double) ONE_SECOND_NANOS / (double) refreshRate);
lastKnownFrameDurationNanos = expectedFrameDurationNanos;

frames.add(
new Frame(
frameStartNanos,
frameEndNanos,
durationNanos,
delayNanos,
isSlow,
isFrozen,
expectedFrameDurationNanos));
if (isSlow || isFrozen) {
frames.add(
new Frame(
frameStartNanos,
frameEndNanos,
durationNanos,
delayNanos,
isSlow,
isFrozen,
expectedFrameDurationNanos));
}
}

private static int interpolateFrameCount(
Expand All @@ -277,7 +279,7 @@ private static int interpolateFrameCount(
final long frameMetricsDurationNanos = frameMetrics.getTotalDurationNanos();
final long nonRenderedDuration = spanDurationNanos - frameMetricsDurationNanos;
if (nonRenderedDuration > 0) {
return (int) (nonRenderedDuration / frameDurationNanos);
return (int) Math.ceil((double) nonRenderedDuration / frameDurationNanos);
stefanosiano marked this conversation as resolved.
Show resolved Hide resolved
}
return 0;
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -6,15 +6,6 @@ import kotlin.test.assertFalse
import kotlin.test.assertTrue

class SentryFrameMetricsTest {
@Test
fun addFastFrame() {
val frameMetrics = SentryFrameMetrics()
frameMetrics.addFrame(10, 0, false, false)
assertEquals(1, frameMetrics.normalFrameCount)

frameMetrics.addFrame(10, 0, false, false)
assertEquals(2, frameMetrics.normalFrameCount)
}

@Test
fun addSlowFrame() {
Expand Down Expand Up @@ -43,10 +34,12 @@ class SentryFrameMetricsTest {
@Test
fun totalFrameCount() {
val frameMetrics = SentryFrameMetrics()
// Normal frames are ignored
frameMetrics.addFrame(10, 0, false, false)
// Slow and frozen frames are considered
frameMetrics.addFrame(116, 100, true, false)
frameMetrics.addFrame(1016, 1000, true, true)
assertEquals(3, frameMetrics.totalFrameCount)
assertEquals(2, frameMetrics.totalFrameCount)
}

@Test
Expand All @@ -57,12 +50,11 @@ class SentryFrameMetricsTest {
frameMetrics.addFrame(1016, 1000, true, true)

val dup = frameMetrics.duplicate()
assertEquals(1, dup.normalFrameCount)
assertEquals(1, dup.slowFrameCount)
assertEquals(100, dup.slowFrameDelayNanos)
assertEquals(1, dup.frozenFrameCount)
assertEquals(1000, dup.frozenFrameDelayNanos)
assertEquals(3, dup.totalFrameCount)
assertEquals(2, dup.totalFrameCount)
}

@Test
Expand Down Expand Up @@ -102,7 +94,6 @@ class SentryFrameMetricsTest {

frameMetrics.clear()

assertEquals(0, frameMetrics.normalFrameCount)
assertEquals(0, frameMetrics.slowFrameCount)
assertEquals(0, frameMetrics.slowFrameDelayNanos)
assertEquals(0, frameMetrics.frozenFrameCount)
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -192,7 +192,7 @@ class SpanFrameMetricsCollectorTest {
sut.onFrameMetricCollected(0, 10, 10, 0, false, false, 60.0f)
sut.onFrameMetricCollected(16, 48, 32, 16, true, false, 60.0f)
sut.onFrameMetricCollected(60, 92, 32, 16, true, false, 60.0f)
sut.onFrameMetricCollected(100, 800, 800, 784, true, true, 60.0f)
sut.onFrameMetricCollected(100, 800, 700, 784, true, true, 60.0f)

// then a second span starts
fixture.timeNanos = 800
Expand Down Expand Up @@ -337,8 +337,8 @@ class SpanFrameMetricsCollectorTest {
fixture.timeNanos = TimeUnit.SECONDS.toNanos(2)
sut.onSpanFinished(span)

// then still 60 frames should be reported (1 second at 60fps)
verify(span).setData("frames.total", 60)
// then still 61 frames should be reported (1 second at 60fps with approximation)
verify(span).setData("frames.total", 61)
verify(span).setData("frames.slow", 0)
verify(span).setData("frames.frozen", 0)
}
Expand All @@ -364,9 +364,9 @@ class SpanFrameMetricsCollectorTest {
sut.onSpanFinished(span)

// then
// still 60 fps should be reported for 1 seconds
// still 61 fps should be reported for 1 seconds (with approximation)
// and one frame with frame delay should be reported (1s - 16ms)
verify(span).setData("frames.total", 61)
verify(span).setData("frames.total", 62)
verify(span).setData("frames.slow", 0)
verify(span).setData("frames.frozen", 1)
verify(span).setData(eq("frames.delay"), AdditionalMatchers.eq(0.983333334, 0.01))
Expand Down
Loading