Skip to content

Commit

Permalink
Include activity name in slow and frozen render reports (#373)
Browse files Browse the repository at this point in the history 
* downgrade so sample app can start

* add activity component name to span

* assert activity name field

* Update splunk-otel-android/src/main/java/com/splunk/rum/SlowRenderingDetectorImpl.java

Co-authored-by: Mateusz Rzeszutek <[email protected]>

* code review comments

Co-authored-by: Mateusz Rzeszutek <[email protected]>
  • Loading branch information
@breedx-splk
breedx-splk and Mateusz Rzeszutek authored Oct 11, 2022
1 parent d01f7fe commit d859a9d
Show file tree
Hide file tree
Showing 4 changed files with 91 additions and 60 deletions.
2 changes: 1 addition & 1 deletion sample-app/build.gradle.kts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -54,7 +54,7 @@ val otelAlphaVersion = "$otelVersion-alpha"

dependencies {
implementation("androidx.legacy:legacy-support-v4:1.0.0")
coreLibraryDesugaring("com.android.tools:desugar_jdk_libs:1.2.2")
coreLibraryDesugaring("com.android.tools:desugar_jdk_libs:1.1.8")

implementation("androidx.appcompat:appcompat:1.5.1")
implementation("androidx.webkit:webkit:1.5.0")
Expand Down
2 changes: 1 addition & 1 deletion splunk-otel-android/build.gradle.kts
View file
Original file line number Diff line number Diff line change
Expand Up @@ -68,7 +68,7 @@ dependencies {
testImplementation("androidx.test:core:1.4.0")
testImplementation("org.assertj:assertj-core:3.23.1")

coreLibraryDesugaring("com.android.tools:desugar_jdk_libs:1.2.2")
coreLibraryDesugaring("com.android.tools:desugar_jdk_libs:1.1.8")
}

extra["pomName"] = "Splunk Otel Android"
Expand Down
105 changes: 54 additions & 51 deletions splunk-otel-android/src/main/java/com/splunk/rum/SlowRenderingDetectorImpl.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -33,15 +33,14 @@
import io.opentelemetry.api.trace.Tracer;
import java.time.Duration;
import java.time.Instant;
import java.util.HashSet;
import java.util.Set;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ConcurrentMap;
import java.util.concurrent.Executors;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.TimeUnit;

@RequiresApi(api = Build.VERSION_CODES.N)
class SlowRenderingDetectorImpl
implements SlowRenderingDetector, Window.OnFrameMetricsAvailableListener {
class SlowRenderingDetectorImpl implements SlowRenderingDetector {

static final int SLOW_THRESHOLD_MS = 16;
static final int FROZEN_THRESHOLD_MS = 700;
Expand All @@ -58,13 +57,8 @@ class SlowRenderingDetectorImpl
private final Handler frameMetricsHandler;
private final Duration pollInterval;

private final Object lock = new Object();

@GuardedBy("lock")
private final Set<Activity> activities = new HashSet<>();

@GuardedBy("lock")
private SparseIntArray drawDurationHistogram = new SparseIntArray();
private final ConcurrentMap<Activity, PerActivityListener> activities =
new ConcurrentHashMap<>();

SlowRenderingDetectorImpl(Tracer tracer, Duration pollInterval) {
this(
Expand Down Expand Up @@ -97,25 +91,20 @@ private static Looper startFrameMetricsLoop() {

@Override
public void add(Activity activity) {
boolean added;
synchronized (lock) {
added = activities.add(activity);
}
if (added) {
activity.getWindow().addOnFrameMetricsAvailableListener(this, frameMetricsHandler);
PerActivityListener listener = new PerActivityListener(activity);
PerActivityListener existing = activities.putIfAbsent(activity, listener);
if (existing == null) {
activity.getWindow().addOnFrameMetricsAvailableListener(listener, frameMetricsHandler);
}
}

@Override
public void stop(Activity activity) {
boolean removed;
synchronized (lock) {
removed = activities.remove(activity);
}
if (removed) {
activity.getWindow().removeOnFrameMetricsAvailableListener(this);
PerActivityListener listener = activities.remove(activity);
if (listener != null) {
activity.getWindow().removeOnFrameMetricsAvailableListener(listener);
reportSlow(listener);
}
reportSlow(getMetrics());
}

// the returned future is very unlikely to fail
Expand All @@ -129,46 +118,59 @@ public void start() {
TimeUnit.MILLISECONDS);
}

@Override
public void onFrameMetricsAvailable(
Window window, FrameMetrics frameMetrics, int dropCountSinceLastInvocation) {
long drawDurationsNs = frameMetrics.getMetric(FrameMetrics.DRAW_DURATION);
// ignore values < 0; something must have gone wrong
if (drawDurationsNs >= 0) {
synchronized (lock) {
// calculation copied from FrameMetricsAggregator
int durationMs = (int) ((drawDurationsNs + NANOS_ROUNDING_VALUE) / NANOS_PER_MS);
int oldValue = drawDurationHistogram.get(durationMs);
drawDurationHistogram.put(durationMs, (oldValue + 1));
static class PerActivityListener implements Window.OnFrameMetricsAvailableListener {

private final Activity activity;
private final Object lock = new Object();

@GuardedBy("lock")
private SparseIntArray drawDurationHistogram = new SparseIntArray();

PerActivityListener(Activity activity) {
this.activity = activity;
}

@Override
public void onFrameMetricsAvailable(
Window window, FrameMetrics frameMetrics, int dropCountSinceLastInvocation) {
long drawDurationsNs = frameMetrics.getMetric(FrameMetrics.DRAW_DURATION);
// ignore values < 0; something must have gone wrong
if (drawDurationsNs >= 0) {
synchronized (lock) {
// calculation copied from FrameMetricsAggregator
int durationMs =
(int) ((drawDurationsNs + NANOS_ROUNDING_VALUE) / NANOS_PER_MS);
int oldValue = drawDurationHistogram.get(durationMs);
drawDurationHistogram.put(durationMs, (oldValue + 1));
}
}
}
}

private SparseIntArray getMetrics() {
synchronized (lock) {
return drawDurationHistogram.clone();
SparseIntArray resetMetrics() {
synchronized (lock) {
SparseIntArray metrics = drawDurationHistogram;
drawDurationHistogram = new SparseIntArray();
return metrics;
}
}
}

private SparseIntArray resetMetrics() {
synchronized (lock) {
SparseIntArray metrics = drawDurationHistogram;
drawDurationHistogram = new SparseIntArray();
return metrics;
public String getActivityName() {
return activity.getComponentName().flattenToShortString();
}
}

private void reportSlowRenders() {
try {
reportSlow(resetMetrics());
activities.forEach((activity, listener) -> reportSlow(listener));
} catch (Exception e) {
Log.w(LOG_TAG, "Exception while processing frame metrics", e);
}
}

private void reportSlow(SparseIntArray durationToCountHistogram) {
private void reportSlow(PerActivityListener listener) {
int slowCount = 0;
int frozenCount = 0;
SparseIntArray durationToCountHistogram = listener.resetMetrics();
for (int i = 0; i < durationToCountHistogram.size(); i++) {
int duration = durationToCountHistogram.keyAt(i);
int count = durationToCountHistogram.get(duration);
Expand All @@ -183,17 +185,18 @@ private void reportSlow(SparseIntArray durationToCountHistogram) {

Instant now = Instant.now();
if (slowCount > 0) {
makeSpan("slowRenders", slowCount, now);
makeSpan("slowRenders", listener.getActivityName(), slowCount, now);
}
if (frozenCount > 0) {
makeSpan("frozenRenders", frozenCount, now);
makeSpan("frozenRenders", listener.getActivityName(), frozenCount, now);
}
}

private void makeSpan(String name, int slowCount, Instant now) {
private void makeSpan(String spanName, String activityName, int slowCount, Instant now) {
Span span =
tracer.spanBuilder(name)
tracer.spanBuilder(spanName)
.setAttribute("count", slowCount)
.setAttribute("activity.name", activityName)
.setStartTimestamp(now)
.startSpan();
span.end(now);
Expand Down
42 changes: 35 additions & 7 deletions splunk-otel-android/src/test/java/com/splunk/rum/SlowRenderingDetectorImplTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@
package com.splunk.rum;

import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.assertThat;
import static org.junit.Assert.assertEquals;
import static org.mockito.ArgumentMatchers.any;
import static org.mockito.ArgumentMatchers.eq;
import static org.mockito.Mockito.doAnswer;
Expand All @@ -26,6 +27,7 @@
import static org.mockito.Mockito.when;

import android.app.Activity;
import android.content.ComponentName;
import android.os.Build;
import android.os.Handler;
import android.view.FrameMetrics;
Expand All @@ -44,6 +46,7 @@
import org.junit.Test;
import org.junit.runner.RunWith;
import org.mockito.Answers;
import org.mockito.ArgumentCaptor;
import org.mockito.Mock;
import org.mockito.junit.MockitoJUnit;
import org.mockito.junit.MockitoRule;
Expand All @@ -70,6 +73,8 @@ public class SlowRenderingDetectorImplTest {
@Before
public void setup() {
tracer = otelTesting.getOpenTelemetry().getTracer("testTracer");
ComponentName componentName = new ComponentName("io.otel", "Komponent");
when(activity.getComponentName()).thenReturn(componentName);
}

@Test
Expand All @@ -79,8 +84,12 @@ public void add() {

testInstance.add(activity);

ArgumentCaptor<SlowRenderingDetectorImpl.PerActivityListener> captor =
ArgumentCaptor.forClass(SlowRenderingDetectorImpl.PerActivityListener.class);

verify(activity.getWindow())
.addOnFrameMetricsAvailableListener(testInstance, frameMetricsHandler);
.addOnFrameMetricsAvailableListener(captor.capture(), eq(frameMetricsHandler));
assertEquals("io.otel/Komponent", captor.getValue().getActivityName());
}

@Test
Expand All @@ -102,9 +111,12 @@ public void addAndRemove() {
testInstance.add(activity);
testInstance.stop(activity);

ArgumentCaptor<SlowRenderingDetectorImpl.PerActivityListener> captor =
ArgumentCaptor.forClass(SlowRenderingDetectorImpl.PerActivityListener.class);

verify(activity.getWindow())
.addOnFrameMetricsAvailableListener(testInstance, frameMetricsHandler);
verify(activity.getWindow()).removeOnFrameMetricsAvailableListener(testInstance);
.addOnFrameMetricsAvailableListener(captor.capture(), eq(frameMetricsHandler));
verify(activity.getWindow()).removeOnFrameMetricsAvailableListener(captor.getValue());
assertThat(otelTesting.getSpans()).hasSize(0);
}

Expand All @@ -115,9 +127,14 @@ public void removeWithMetrics() {

testInstance.add(activity);

ArgumentCaptor<SlowRenderingDetectorImpl.PerActivityListener> captor =
ArgumentCaptor.forClass(SlowRenderingDetectorImpl.PerActivityListener.class);

verify(activity.getWindow()).addOnFrameMetricsAvailableListener(captor.capture(), any());
SlowRenderingDetectorImpl.PerActivityListener listener = captor.getValue();
for (long duration : makeSomeDurations()) {
when(frameMetrics.getMetric(FrameMetrics.DRAW_DURATION)).thenReturn(duration);
testInstance.onFrameMetricsAvailable(null, frameMetrics, 0);
listener.onFrameMetricsAvailable(null, frameMetrics, 0);
}

testInstance.stop(activity);
Expand Down Expand Up @@ -145,9 +162,14 @@ public void start() {

testInstance.add(activity);

ArgumentCaptor<SlowRenderingDetectorImpl.PerActivityListener> captor =
ArgumentCaptor.forClass(SlowRenderingDetectorImpl.PerActivityListener.class);

verify(activity.getWindow()).addOnFrameMetricsAvailableListener(captor.capture(), any());
SlowRenderingDetectorImpl.PerActivityListener listener = captor.getValue();
for (long duration : makeSomeDurations()) {
when(frameMetrics.getMetric(FrameMetrics.DRAW_DURATION)).thenReturn(duration);
testInstance.onFrameMetricsAvailable(null, frameMetrics, 0);
listener.onFrameMetricsAvailable(null, frameMetrics, 0);
}

testInstance.start();
Expand All @@ -164,12 +186,18 @@ private static void assertSpanContent(List<SpanData> spans) {
assertThat(span)
.hasName("slowRenders")
.endsAt(span.getStartEpochNanos())
.hasAttribute(COUNT_KEY, 3L),
.hasAttribute(COUNT_KEY, 3L)
.hasAttribute(
AttributeKey.stringKey("activity.name"),
"io.otel/Komponent"),
span ->
assertThat(span)
.hasName("frozenRenders")
.endsAt(span.getStartEpochNanos())
.hasAttribute(COUNT_KEY, 1L));
.hasAttribute(COUNT_KEY, 1L)
.hasAttribute(
AttributeKey.stringKey("activity.name"),
"io.otel/Komponent"));
}

private List<Long> makeSomeDurations() {
Expand Down

0 comments on commit d859a9d

Please sign in to comment.