Stable JVM semconv implementation: GC (#9890)

This commit is contained in:
Mateusz Rzeszutek 2023-11-17 10:45:34 +01:00 committed by GitHub
parent 4bde25f067
commit 7400025c10
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
2 changed files with 208 additions and 27 deletions

View File

@ -5,16 +5,18 @@
package io.opentelemetry.instrumentation.runtimemetrics.java8; 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.emptyList;
import static java.util.Collections.unmodifiableList;
import com.sun.management.GarbageCollectionNotificationInfo; import com.sun.management.GarbageCollectionNotificationInfo;
import io.opentelemetry.api.OpenTelemetry; import io.opentelemetry.api.OpenTelemetry;
import io.opentelemetry.api.common.AttributeKey; import io.opentelemetry.api.common.AttributeKey;
import io.opentelemetry.api.common.Attributes; import io.opentelemetry.api.common.Attributes;
import io.opentelemetry.api.metrics.DoubleHistogram; import io.opentelemetry.api.metrics.DoubleHistogram;
import io.opentelemetry.api.metrics.DoubleHistogramBuilder;
import io.opentelemetry.api.metrics.Meter; 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 io.opentelemetry.instrumentation.runtimemetrics.java8.internal.JmxRuntimeMetricsUtil;
import java.lang.management.GarbageCollectorMXBean; import java.lang.management.GarbageCollectorMXBean;
import java.lang.management.ManagementFactory; import java.lang.management.ManagementFactory;
@ -24,6 +26,7 @@ import java.util.List;
import java.util.concurrent.TimeUnit; import java.util.concurrent.TimeUnit;
import java.util.function.Function; import java.util.function.Function;
import java.util.logging.Logger; import java.util.logging.Logger;
import javax.annotation.Nullable;
import javax.management.Notification; import javax.management.Notification;
import javax.management.NotificationEmitter; import javax.management.NotificationEmitter;
import javax.management.NotificationFilter; import javax.management.NotificationFilter;
@ -38,6 +41,23 @@ import javax.management.openmbean.CompositeData;
* <pre>{@code * <pre>{@code
* GarbageCollector.registerObservers(GlobalOpenTelemetry.get()); * GarbageCollector.registerObservers(GlobalOpenTelemetry.get());
* }</pre> * }</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 { public final class GarbageCollector {
@ -45,8 +65,13 @@ public final class GarbageCollector {
private static final double MILLIS_PER_S = TimeUnit.SECONDS.toMillis(1); 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> GC_KEY = stringKey("gc");
private static final AttributeKey<String> ACTION_KEY = AttributeKey.stringKey("action"); 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 = private static final NotificationFilter GC_FILTER =
notification -> notification ->
@ -76,13 +101,27 @@ public final class GarbageCollector {
Function<Notification, GarbageCollectionNotificationInfo> notificationInfoExtractor) { Function<Notification, GarbageCollectionNotificationInfo> notificationInfoExtractor) {
Meter meter = JmxRuntimeMetricsUtil.getMeter(openTelemetry); Meter meter = JmxRuntimeMetricsUtil.getMeter(openTelemetry);
DoubleHistogramBuilder gcDurationBuilder = DoubleHistogram oldGcDuration = null;
meter DoubleHistogram stableGcDuration = null;
.histogramBuilder("process.runtime.jvm.gc.duration")
.setDescription("Duration of JVM garbage collection actions") if (SemconvStability.emitOldJvmSemconv()) {
.setUnit("s"); oldGcDuration =
setGcDurationBuckets(gcDurationBuilder); meter
DoubleHistogram gcDuration = gcDurationBuilder.build(); .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<>(); List<AutoCloseable> result = new ArrayList<>();
for (GarbageCollectorMXBean gcBean : gcBeans) { for (GarbageCollectorMXBean gcBean : gcBeans) {
@ -91,31 +130,26 @@ public final class GarbageCollector {
} }
NotificationEmitter notificationEmitter = (NotificationEmitter) gcBean; NotificationEmitter notificationEmitter = (NotificationEmitter) gcBean;
GcNotificationListener listener = GcNotificationListener listener =
new GcNotificationListener(gcDuration, notificationInfoExtractor); new GcNotificationListener(oldGcDuration, stableGcDuration, notificationInfoExtractor);
notificationEmitter.addNotificationListener(listener, GC_FILTER, null); notificationEmitter.addNotificationListener(listener, GC_FILTER, null);
result.add(() -> notificationEmitter.removeNotificationListener(listener)); result.add(() -> notificationEmitter.removeNotificationListener(listener));
} }
return result; 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 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> private final Function<Notification, GarbageCollectionNotificationInfo>
notificationInfoExtractor; notificationInfoExtractor;
private GcNotificationListener( private GcNotificationListener(
DoubleHistogram gcDuration, @Nullable DoubleHistogram oldGcDuration,
@Nullable DoubleHistogram stableGcDuration,
Function<Notification, GarbageCollectionNotificationInfo> notificationInfoExtractor) { Function<Notification, GarbageCollectionNotificationInfo> notificationInfoExtractor) {
this.gcDuration = gcDuration; this.oldGcDuration = oldGcDuration;
this.stableGcDuration = stableGcDuration;
this.notificationInfoExtractor = notificationInfoExtractor; this.notificationInfoExtractor = notificationInfoExtractor;
} }
@ -123,10 +157,18 @@ public final class GarbageCollector {
public void handleNotification(Notification notification, Object unused) { public void handleNotification(Notification notification, Object unused) {
GarbageCollectionNotificationInfo notificationInfo = GarbageCollectionNotificationInfo notificationInfo =
notificationInfoExtractor.apply(notification); notificationInfoExtractor.apply(notification);
gcDuration.record(
notificationInfo.getGcInfo().getDuration() / MILLIS_PER_S, String gcName = notificationInfo.getGcName();
Attributes.of( String gcAction = notificationInfo.getGcAction();
GC_KEY, notificationInfo.getGcName(), ACTION_KEY, 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));
}
} }
} }

View File

@ -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;
}
}
}