Skip to content

Commit

Permalink
Stable JVM semconv implementation: GC (#9890)
Browse files Browse the repository at this point in the history
  • Loading branch information
Mateusz Rzeszutek authored Nov 17, 2023
1 parent 4bde25f commit 7400025
Show file tree
Hide file tree
Showing 2 changed files with 208 additions and 27 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -5,16 +5,18 @@

package io.opentelemetry.instrumentation.runtimemetrics.java8;

import static io.opentelemetry.api.common.AttributeKey.stringKey;
import static java.util.Arrays.asList;
import static java.util.Collections.emptyList;
import static java.util.Collections.unmodifiableList;

import com.sun.management.GarbageCollectionNotificationInfo;
import io.opentelemetry.api.OpenTelemetry;
import io.opentelemetry.api.common.AttributeKey;
import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.metrics.DoubleHistogram;
import io.opentelemetry.api.metrics.DoubleHistogramBuilder;
import io.opentelemetry.api.metrics.Meter;
import io.opentelemetry.extension.incubator.metrics.ExtendedDoubleHistogramBuilder;
import io.opentelemetry.instrumentation.api.internal.SemconvStability;
import io.opentelemetry.instrumentation.runtimemetrics.java8.internal.JmxRuntimeMetricsUtil;
import java.lang.management.GarbageCollectorMXBean;
import java.lang.management.ManagementFactory;
Expand All @@ -24,6 +26,7 @@
import java.util.concurrent.TimeUnit;
import java.util.function.Function;
import java.util.logging.Logger;
import javax.annotation.Nullable;
import javax.management.Notification;
import javax.management.NotificationEmitter;
import javax.management.NotificationFilter;
Expand All @@ -38,15 +41,37 @@
* <pre>{@code
* GarbageCollector.registerObservers(GlobalOpenTelemetry.get());
* }</pre>
*
* <p>Example metrics being exported:
*
* <pre>
* process.runtime.jvm.gc.duration{gc="G1 Young Generation",action="end of minor GC"} 0.022
* </pre>
*
* <p>In case you enable the preview of stable JVM semantic conventions (e.g. by setting the {@code
* otel.semconv-stability.opt-in} system property to {@code jvm}), the metrics being exported will
* follow <a
* href="https://github.com/open-telemetry/semantic-conventions/blob/main/docs/runtime/jvm-metrics.md">the
* most recent JVM semantic conventions</a>. This is how the example above looks when stable JVM
* semconv is enabled:
*
* <pre>
* jvm.gc.duration{jvm.gc.name="G1 Young Generation",jvm.gc.action="end of minor GC"} 0.022
* </pre>
*/
public final class GarbageCollector {

private static final Logger logger = Logger.getLogger(GarbageCollector.class.getName());

private static final double MILLIS_PER_S = TimeUnit.SECONDS.toMillis(1);

private static final AttributeKey<String> GC_KEY = AttributeKey.stringKey("gc");
private static final AttributeKey<String> ACTION_KEY = AttributeKey.stringKey("action");
private static final AttributeKey<String> GC_KEY = stringKey("gc");
private static final AttributeKey<String> ACTION_KEY = stringKey("action");

// TODO: use the opentelemetry-semconv classes once we have metrics attributes there
private static final AttributeKey<String> JVM_GC_NAME = stringKey("jvm.gc.name");
private static final AttributeKey<String> JVM_GC_ACTION = stringKey("jvm.gc.action");
static final List<Double> GC_DURATION_BUCKETS = unmodifiableList(asList(0.01, 0.1, 1., 10.));

private static final NotificationFilter GC_FILTER =
notification ->
Expand Down Expand Up @@ -76,13 +101,27 @@ static List<AutoCloseable> registerObservers(
Function<Notification, GarbageCollectionNotificationInfo> notificationInfoExtractor) {
Meter meter = JmxRuntimeMetricsUtil.getMeter(openTelemetry);

DoubleHistogramBuilder gcDurationBuilder =
meter
.histogramBuilder("process.runtime.jvm.gc.duration")
.setDescription("Duration of JVM garbage collection actions")
.setUnit("s");
setGcDurationBuckets(gcDurationBuilder);
DoubleHistogram gcDuration = gcDurationBuilder.build();
DoubleHistogram oldGcDuration = null;
DoubleHistogram stableGcDuration = null;

if (SemconvStability.emitOldJvmSemconv()) {
oldGcDuration =
meter
.histogramBuilder("process.runtime.jvm.gc.duration")
.setDescription("Duration of JVM garbage collection actions")
.setUnit("s")
.setExplicitBucketBoundariesAdvice(emptyList())
.build();
}
if (SemconvStability.emitStableJvmSemconv()) {
stableGcDuration =
meter
.histogramBuilder("jvm.gc.duration")
.setDescription("Duration of JVM garbage collection actions.")
.setUnit("s")
.setExplicitBucketBoundariesAdvice(GC_DURATION_BUCKETS)
.build();
}

List<AutoCloseable> result = new ArrayList<>();
for (GarbageCollectorMXBean gcBean : gcBeans) {
Expand All @@ -91,42 +130,45 @@ static List<AutoCloseable> registerObservers(
}
NotificationEmitter notificationEmitter = (NotificationEmitter) gcBean;
GcNotificationListener listener =
new GcNotificationListener(gcDuration, notificationInfoExtractor);
new GcNotificationListener(oldGcDuration, stableGcDuration, notificationInfoExtractor);
notificationEmitter.addNotificationListener(listener, GC_FILTER, null);
result.add(() -> notificationEmitter.removeNotificationListener(listener));
}
return result;
}

private static void setGcDurationBuckets(DoubleHistogramBuilder builder) {
if (!(builder instanceof ExtendedDoubleHistogramBuilder)) {
// that shouldn't really happen
return;
}
((ExtendedDoubleHistogramBuilder) builder).setExplicitBucketBoundariesAdvice(emptyList());
}

private static final class GcNotificationListener implements NotificationListener {

private final DoubleHistogram gcDuration;
@Nullable private final DoubleHistogram oldGcDuration;
@Nullable private final DoubleHistogram stableGcDuration;
private final Function<Notification, GarbageCollectionNotificationInfo>
notificationInfoExtractor;

private GcNotificationListener(
DoubleHistogram gcDuration,
@Nullable DoubleHistogram oldGcDuration,
@Nullable DoubleHistogram stableGcDuration,
Function<Notification, GarbageCollectionNotificationInfo> notificationInfoExtractor) {
this.gcDuration = gcDuration;
this.oldGcDuration = oldGcDuration;
this.stableGcDuration = stableGcDuration;
this.notificationInfoExtractor = notificationInfoExtractor;
}

@Override
public void handleNotification(Notification notification, Object unused) {
GarbageCollectionNotificationInfo notificationInfo =
notificationInfoExtractor.apply(notification);
gcDuration.record(
notificationInfo.getGcInfo().getDuration() / MILLIS_PER_S,
Attributes.of(
GC_KEY, notificationInfo.getGcName(), ACTION_KEY, notificationInfo.getGcAction()));

String gcName = notificationInfo.getGcName();
String gcAction = notificationInfo.getGcAction();
double duration = notificationInfo.getGcInfo().getDuration() / MILLIS_PER_S;

if (oldGcDuration != null) {
oldGcDuration.record(duration, Attributes.of(GC_KEY, gcName, ACTION_KEY, gcAction));
}
if (stableGcDuration != null) {
stableGcDuration.record(
duration, Attributes.of(JVM_GC_NAME, gcName, JVM_GC_ACTION, gcAction));
}
}
}

Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,139 @@
/*
* Copyright The OpenTelemetry Authors
* SPDX-License-Identifier: Apache-2.0
*/

package io.opentelemetry.instrumentation.runtimemetrics.java8;

import static io.opentelemetry.instrumentation.runtimemetrics.java8.ScopeUtil.EXPECTED_SCOPE;
import static io.opentelemetry.sdk.testing.assertj.OpenTelemetryAssertions.assertThat;
import static java.util.Collections.singletonList;
import static org.mockito.ArgumentMatchers.any;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.when;

import com.sun.management.GarbageCollectionNotificationInfo;
import com.sun.management.GcInfo;
import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.instrumentation.testing.junit.InstrumentationExtension;
import io.opentelemetry.instrumentation.testing.junit.LibraryInstrumentationExtension;
import java.lang.management.GarbageCollectorMXBean;
import java.util.concurrent.atomic.AtomicLong;
import javax.management.Notification;
import javax.management.NotificationEmitter;
import javax.management.NotificationListener;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.extension.ExtendWith;
import org.junit.jupiter.api.extension.RegisterExtension;
import org.mockito.ArgumentCaptor;
import org.mockito.Captor;
import org.mockito.Mock;
import org.mockito.junit.jupiter.MockitoExtension;
import org.mockito.junit.jupiter.MockitoSettings;
import org.mockito.quality.Strictness;

@ExtendWith(MockitoExtension.class)
@MockitoSettings(strictness = Strictness.LENIENT)
class GarbageCollectorTest {

static final double[] GC_DURATION_BUCKETS =
GarbageCollector.GC_DURATION_BUCKETS.stream().mapToDouble(d -> d).toArray();

@RegisterExtension
static final InstrumentationExtension testing = LibraryInstrumentationExtension.create();

@Mock(extraInterfaces = NotificationEmitter.class)
private GarbageCollectorMXBean gcBean;

@Captor private ArgumentCaptor<NotificationListener> listenerCaptor;

@Test
void registerObservers() {
GarbageCollector.registerObservers(
testing.getOpenTelemetry(),
singletonList(gcBean),
GarbageCollectorTest::getGcNotificationInfo);

NotificationEmitter notificationEmitter = (NotificationEmitter) gcBean;
verify(notificationEmitter).addNotificationListener(listenerCaptor.capture(), any(), any());
NotificationListener listener = listenerCaptor.getValue();

listener.handleNotification(
createTestNotification("G1 Young Generation", "end of minor GC", 10), null);
listener.handleNotification(
createTestNotification("G1 Young Generation", "end of minor GC", 12), null);
listener.handleNotification(
createTestNotification("G1 Old Generation", "end of major GC", 11), null);

testing.waitAndAssertMetrics(
"io.opentelemetry.runtime-telemetry-java8",
"jvm.gc.duration",
metrics ->
metrics.anySatisfy(
metricData ->
assertThat(metricData)
.hasInstrumentationScope(EXPECTED_SCOPE)
.hasDescription("Duration of JVM garbage collection actions.")
.hasUnit("s")
.hasHistogramSatisfying(
histogram ->
histogram.hasPointsSatisfying(
point ->
point
.hasCount(2)
.hasSum(0.022)
.hasAttributes(
Attributes.builder()
.put("jvm.gc.name", "G1 Young Generation")
.put("jvm.gc.action", "end of minor GC")
.build())
.hasBucketBoundaries(GC_DURATION_BUCKETS),
point ->
point
.hasCount(1)
.hasSum(0.011)
.hasAttributes(
Attributes.builder()
.put("jvm.gc.name", "G1 Old Generation")
.put("jvm.gc.action", "end of major GC")
.build())
.hasBucketBoundaries(GC_DURATION_BUCKETS)))));
}

private static Notification createTestNotification(
String gcName, String gcAction, long duration) {
GarbageCollectionNotificationInfo gcNotificationInfo =
mock(GarbageCollectionNotificationInfo.class);
when(gcNotificationInfo.getGcName()).thenReturn(gcName);
when(gcNotificationInfo.getGcAction()).thenReturn(gcAction);
GcInfo gcInfo = mock(GcInfo.class);
when(gcInfo.getDuration()).thenReturn(duration);
when(gcNotificationInfo.getGcInfo()).thenReturn(gcInfo);
return new TestNotification(gcNotificationInfo);
}

private static GarbageCollectionNotificationInfo getGcNotificationInfo(
Notification notification) {
return ((TestNotification) notification).gcNotificationInfo;
}

/**
* A {@link Notification} when is initialized with a mock {@link
* GarbageCollectionNotificationInfo}.
*/
private static class TestNotification extends Notification {

private static final AtomicLong sequence = new AtomicLong(0);

private final GarbageCollectionNotificationInfo gcNotificationInfo;

private TestNotification(GarbageCollectionNotificationInfo gcNotificationInfo) {
super(
GarbageCollectionNotificationInfo.GARBAGE_COLLECTION_NOTIFICATION,
"test",
sequence.incrementAndGet());
this.gcNotificationInfo = gcNotificationInfo;
}
}
}

0 comments on commit 7400025

Please sign in to comment.