Skip to content

Commit

Permalink
Count Generational ZGC cycles as concurrent time
Browse files Browse the repository at this point in the history
This was missed when support for Generational ZGC was otherwise added in gh-4258. Non-generational ZGC uses the collector name `ZGC Cycles` for concurrent phases. Generational ZGC however uses `ZGC Minor Cycles` and `ZGC Major Cycles` which was not included in prior conditional for ZGC.

This conditionally enables a previously disabled test and makes sure it accounts for any GC that happens before metrics are recorded. It only works with a limited number of collectors (ZGC and Shenandoah) but it would have caught this issue and will ensure we don't introduce regressions.

Resolves gh-4764
  • Loading branch information
shakuzen committed Feb 28, 2024
1 parent a476849 commit 39ef7ff
Show file tree
Hide file tree
Showing 2 changed files with 51 additions and 17 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -37,13 +37,16 @@ static Stream<MemoryPoolMXBean> getLongLivedHeapPools() {
}

static boolean isConcurrentPhase(String cause, String name) {
return "No GC".equals(cause) || "Shenandoah Cycles".equals(name) || "ZGC Cycles".equals(name)
|| (name.startsWith("GPGC") && !name.endsWith("Pauses"));
return "No GC".equals(cause) //
|| "Shenandoah Cycles".equals(name) // Shenandoah
|| (name.startsWith("ZGC") && name.endsWith("Cycles")) // ZGC
|| (name.startsWith("GPGC") && !name.endsWith("Pauses")) // Zing GPGC
;
}

static boolean isAllocationPool(String name) {
return name != null && (name.endsWith("Eden Space") || "Shenandoah".equals(name) || "ZHeap".equals(name) // ZGC
// non-generational
return name != null && (name.endsWith("Eden Space") || "Shenandoah".equals(name) //
|| "ZHeap".equals(name) // ZGC non-generational
|| "ZGC Young Generation".equals(name) // generational ZGC
|| name.endsWith("New Gen") // Zing GPGC
|| name.endsWith("nursery-allocate") || name.endsWith("-eden") // "balanced-eden"
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -25,10 +25,9 @@
import io.micrometer.core.instrument.Timer;
import io.micrometer.core.instrument.binder.jvm.JvmGcMetrics.GcMetricsNotificationListener;
import io.micrometer.core.instrument.simple.SimpleMeterRegistry;
import org.junit.jupiter.api.BeforeEach;
import org.junit.jupiter.api.Disabled;
import org.junit.jupiter.api.Test;
import org.junit.jupiter.api.condition.EnabledForJreRange;
import org.junit.jupiter.api.condition.EnabledIf;
import org.junit.jupiter.api.condition.JRE;

import javax.management.ListenerNotFoundException;
Expand All @@ -37,6 +36,7 @@
import javax.management.NotificationListener;
import java.lang.management.GarbageCollectorMXBean;
import java.lang.management.ManagementFactory;
import java.lang.management.MemoryManagerMXBean;
import java.util.ArrayList;
import java.util.Collection;
import java.util.Collections;
Expand All @@ -60,13 +60,7 @@ class JvmGcMetricsTest {

SimpleMeterRegistry registry = new SimpleMeterRegistry();

JvmGcMetrics binder;

@BeforeEach
void beforeEach() {
this.binder = new JvmGcMetrics(DEFAULT_TAGS);
binder.bindTo(registry);
}
JvmGcMetrics binder = new JvmGcMetrics(DEFAULT_TAGS);

@Test
void noJvmImplementationSpecificApiSignatures() {
Expand All @@ -83,6 +77,7 @@ void noJvmImplementationSpecificApiSignatures() {

@Test
void gcMetricsAvailableAfterGc() {
binder.bindTo(registry);
System.gc();
await().timeout(200, TimeUnit.MILLISECONDS)
.alias("NotificationListener takes time after GC")
Expand All @@ -104,12 +99,35 @@ void gcMetricsAvailableAfterGc() {
}

@Test
@Disabled("Garbage collection can happen before JvmGcMetrics are registered, making our metrics not match overall counts/timings")
@EnabledIf(value = "isPauseCyclesGc", disabledReason = "test only works with certain collectors")
// available for some platforms and distributions earlier, but broadest availability
// in an LTS is 17
@EnabledForJreRange(min = JRE.JAVA_17)
void gcTimingIsCorrect() {
void gcTimingIsCorrectForPauseCycleCollectors() {
// get initial GC timing metrics from JMX, if any
// GC could have happened before this test due to testing infrastructure
// If it did, it will not be captured in the metrics
long initialPausePhaseCount = 0;
long initialPauseTimeMs = 0;
long initialConcurrentPhaseCount = 0;
long initialConcurrentTimeMs = 0;
for (GarbageCollectorMXBean mbean : ManagementFactory.getGarbageCollectorMXBeans()) {
if (mbean.getName().contains("Pauses")) {
initialPausePhaseCount += mbean.getCollectionCount();
initialPauseTimeMs += mbean.getCollectionTime();
}
else if (mbean.getName().contains("Cycles")) {
initialConcurrentPhaseCount += mbean.getCollectionCount();
initialConcurrentTimeMs += mbean.getCollectionTime();
}
}

// bind to start tracking GC metrics with Micrometer
binder.bindTo(registry);
// cause GC to record new metrics
System.gc();

// get metrics from JMX again to obtain difference
long pausePhaseCount = 0;
long pauseTimeMs = 0;
long concurrentPhaseCount = 0;
Expand All @@ -123,16 +141,29 @@ else if (mbean.getName().contains("Cycles")) {
concurrentPhaseCount += mbean.getCollectionCount();
concurrentTimeMs += mbean.getCollectionTime();
}
System.out
.println(mbean.getName() + " (" + mbean.getCollectionCount() + ") " + mbean.getCollectionTime() + "ms");
}

// subtract any difference
pausePhaseCount -= initialPausePhaseCount;
pauseTimeMs -= initialPauseTimeMs;
concurrentPhaseCount -= initialConcurrentPhaseCount;
concurrentTimeMs -= initialConcurrentTimeMs;

checkPhaseCount(pausePhaseCount, concurrentPhaseCount);
checkCollectionTime(pauseTimeMs, concurrentTimeMs);
}

boolean isPauseCyclesGc() {
return ManagementFactory.getGarbageCollectorMXBeans()
.stream()
.map(MemoryManagerMXBean::getName)
.anyMatch(name -> name.contains("Pauses"));
}

@Test
@Issue("gh-2872")
void sizeMetricsNotSetToZero() throws InterruptedException {
binder.bindTo(registry);
GcMetricsNotificationListener gcMetricsNotificationListener = binder.gcNotificationListener;
NotificationCapturingListener capturingListener = new NotificationCapturingListener();
Collection<Runnable> notificationListenerCleanUpRunnables = new ArrayList<>();
Expand Down

0 comments on commit 39ef7ff

Please sign in to comment.