Refactor JvmGcMonitorService for testing

This commit refactors the JvmGcMonitorService so that it can be
tested. In particular, hooks are added to verify that the
JvmMonitorService correctly observes slow GC events, and that the
JvmGcMonitorService logs the correct messages.

Relates #18378
This commit is contained in:
Jason Tedor 2016-05-17 13:05:36 -04:00
parent 9ba554dfd2
commit 584be0b3f8
4 changed files with 572 additions and 34 deletions

View File

@ -517,7 +517,6 @@
<suppress files="core[/\\]src[/\\]main[/\\]java[/\\]org[/\\]elasticsearch[/\\]ingest[/\\]processor[/\\]ConvertProcessor.java" checks="LineLength" />
<suppress files="core[/\\]src[/\\]main[/\\]java[/\\]org[/\\]elasticsearch[/\\]monitor[/\\]jvm[/\\]GcNames.java" checks="LineLength" />
<suppress files="core[/\\]src[/\\]main[/\\]java[/\\]org[/\\]elasticsearch[/\\]monitor[/\\]jvm[/\\]HotThreads.java" checks="LineLength" />
<suppress files="core[/\\]src[/\\]main[/\\]java[/\\]org[/\\]elasticsearch[/\\]monitor[/\\]jvm[/\\]JvmGcMonitorService.java" checks="LineLength" />
<suppress files="core[/\\]src[/\\]main[/\\]java[/\\]org[/\\]elasticsearch[/\\]monitor[/\\]jvm[/\\]JvmStats.java" checks="LineLength" />
<suppress files="core[/\\]src[/\\]main[/\\]java[/\\]org[/\\]elasticsearch[/\\]node[/\\]Node.java" checks="LineLength" />
<suppress files="core[/\\]src[/\\]main[/\\]java[/\\]org[/\\]elasticsearch[/\\]node[/\\]internal[/\\]InternalSettingsPreparer.java" checks="LineLength" />

View File

@ -20,9 +20,11 @@
package org.elasticsearch.monitor.jvm;
import org.elasticsearch.common.component.AbstractLifecycleComponent;
import org.elasticsearch.common.logging.ESLogger;
import org.elasticsearch.common.settings.Setting;
import org.elasticsearch.common.settings.Setting.Property;
import org.elasticsearch.common.settings.Settings;
import org.elasticsearch.common.unit.ByteSizeValue;
import org.elasticsearch.common.unit.TimeValue;
import org.elasticsearch.common.util.concurrent.FutureUtils;
import org.elasticsearch.monitor.jvm.JvmStats.GarbageCollector;
@ -30,14 +32,13 @@ import org.elasticsearch.threadpool.ThreadPool;
import java.util.HashMap;
import java.util.Map;
import java.util.Objects;
import java.util.concurrent.ScheduledFuture;
import java.util.concurrent.TimeUnit;
import java.util.function.BiFunction;
import static java.util.Collections.unmodifiableMap;
import static org.elasticsearch.monitor.jvm.JvmStats.jvmStats;
/**
*
*/
public class JvmGcMonitorService extends AbstractLifecycleComponent<JvmGcMonitorService> {
private final ThreadPool threadPool;
@ -119,12 +120,123 @@ public class JvmGcMonitorService extends AbstractLifecycleComponent<JvmGcMonitor
return GC_COLLECTOR_PREFIX + key + "." + level;
}
private static final String LOG_MESSAGE =
"[gc][{}][{}][{}] duration [{}], collections [{}]/[{}], total [{}]/[{}], memory [{}]->[{}]/[{}], all_pools {}";
@Override
protected void doStart() {
if (!enabled) {
return;
}
scheduledFuture = threadPool.scheduleWithFixedDelay(new JvmMonitor(), interval);
scheduledFuture = threadPool.scheduleWithFixedDelay(new JvmMonitor(gcThresholds) {
@Override
void onMonitorFailure(Throwable t) {
logger.debug("failed to monitor", t);
}
@Override
void onSlowGc(final Threshold threshold, final long seq, final SlowGcEvent slowGcEvent) {
logSlowGc(logger, threshold, seq, slowGcEvent, JvmGcMonitorService::buildPools);
}
}, interval);
}
static void logSlowGc(
final ESLogger logger,
final JvmMonitor.Threshold threshold,
final long seq,
final JvmMonitor.SlowGcEvent slowGcEvent,
BiFunction<JvmStats, JvmStats, String> pools) {
final String name = slowGcEvent.currentGc.getName();
final long elapsed = slowGcEvent.elapsed;
final long totalGcCollectionCount = slowGcEvent.currentGc.getCollectionCount();
final long currentGcCollectionCount = slowGcEvent.collectionCount;
final TimeValue totalGcCollectionTime = slowGcEvent.currentGc.getCollectionTime();
final TimeValue currentGcCollectionTime = slowGcEvent.collectionTime;
final JvmStats lastJvmStats = slowGcEvent.lastJvmStats;
final JvmStats currentJvmStats = slowGcEvent.currentJvmStats;
final ByteSizeValue maxHeapUsed = slowGcEvent.maxHeapUsed;
switch (threshold) {
case WARN:
if (logger.isWarnEnabled()) {
logger.warn(
LOG_MESSAGE,
name,
seq,
totalGcCollectionCount,
currentGcCollectionTime,
currentGcCollectionCount,
TimeValue.timeValueMillis(elapsed),
currentGcCollectionTime,
totalGcCollectionTime,
lastJvmStats.getMem().getHeapUsed(),
currentJvmStats.getMem().getHeapUsed(),
maxHeapUsed,
pools.apply(lastJvmStats, currentJvmStats));
}
break;
case INFO:
if (logger.isInfoEnabled()) {
logger.info(
LOG_MESSAGE,
name,
seq,
totalGcCollectionCount,
currentGcCollectionTime,
currentGcCollectionCount,
TimeValue.timeValueMillis(elapsed),
currentGcCollectionTime,
totalGcCollectionTime,
lastJvmStats.getMem().getHeapUsed(),
currentJvmStats.getMem().getHeapUsed(),
maxHeapUsed,
pools.apply(lastJvmStats, currentJvmStats));
}
break;
case DEBUG:
if (logger.isDebugEnabled()) {
logger.debug(
LOG_MESSAGE,
name,
seq,
totalGcCollectionCount,
currentGcCollectionTime,
currentGcCollectionCount,
TimeValue.timeValueMillis(elapsed),
currentGcCollectionTime,
totalGcCollectionTime,
lastJvmStats.getMem().getHeapUsed(),
currentJvmStats.getMem().getHeapUsed(),
maxHeapUsed,
pools.apply(lastJvmStats, currentJvmStats));
}
break;
}
}
static String buildPools(JvmStats last, JvmStats current) {
StringBuilder sb = new StringBuilder();
for (JvmStats.MemoryPool currentPool : current.getMem()) {
JvmStats.MemoryPool prevPool = null;
for (JvmStats.MemoryPool pool : last.getMem()) {
if (pool.getName().equals(currentPool.getName())) {
prevPool = pool;
break;
}
}
sb.append("{[")
.append(currentPool.getName())
.append("] [")
.append(prevPool == null ? "?" : prevPool.getUsed())
.append("]->[")
.append(currentPool.getUsed())
.append("]/[")
.append(currentPool.getMax())
.append("]}");
}
return sb.toString();
}
@Override
@ -139,12 +251,46 @@ public class JvmGcMonitorService extends AbstractLifecycleComponent<JvmGcMonitor
protected void doClose() {
}
private class JvmMonitor implements Runnable {
static abstract class JvmMonitor implements Runnable {
enum Threshold { DEBUG, INFO, WARN }
static class SlowGcEvent {
final GarbageCollector currentGc;
final long collectionCount;
final TimeValue collectionTime;
final long elapsed;
final JvmStats lastJvmStats;
final JvmStats currentJvmStats;
final ByteSizeValue maxHeapUsed;
public SlowGcEvent(
final GarbageCollector currentGc,
final long collectionCount,
final TimeValue collectionTime,
final long elapsed,
final JvmStats lastJvmStats,
final JvmStats currentJvmStats,
final ByteSizeValue maxHeapUsed) {
this.currentGc = currentGc;
this.collectionCount = collectionCount;
this.collectionTime = collectionTime;
this.elapsed = elapsed;
this.lastJvmStats = lastJvmStats;
this.currentJvmStats = currentJvmStats;
this.maxHeapUsed = maxHeapUsed;
}
}
private long lastTime = now();
private JvmStats lastJvmStats = jvmStats();
private long seq = 0;
private final Map<String, GcThreshold> gcThresholds;
public JvmMonitor() {
public JvmMonitor(Map<String, GcThreshold> gcThresholds) {
this.gcThresholds = Objects.requireNonNull(gcThresholds);
}
@Override
@ -152,24 +298,28 @@ public class JvmGcMonitorService extends AbstractLifecycleComponent<JvmGcMonitor
try {
monitorLongGc();
} catch (Throwable t) {
logger.debug("failed to monitor", t);
onMonitorFailure(t);
}
}
private synchronized void monitorLongGc() {
abstract void onMonitorFailure(Throwable t);
synchronized void monitorLongGc() {
seq++;
final long currentTime = now();
JvmStats currentJvmStats = jvmStats();
final long elapsed = TimeUnit.NANOSECONDS.toMillis(currentTime - lastTime);
for (int i = 0; i < currentJvmStats.getGc().getCollectors().length; i++) {
GarbageCollector gc = currentJvmStats.getGc().getCollectors()[i];
GarbageCollector prevGc = lastJvmStats.gc.collectors[i];
GarbageCollector prevGc = lastJvmStats.getGc().getCollectors()[i];
// no collection has happened
long collections = gc.collectionCount - prevGc.collectionCount;
long collections = gc.getCollectionCount() - prevGc.getCollectionCount();
if (collections == 0) {
continue;
}
long collectionTime = gc.collectionTime - prevGc.collectionTime;
long collectionTime = gc.getCollectionTime().millis() - prevGc.getCollectionTime().millis();
if (collectionTime == 0) {
continue;
}
@ -181,34 +331,39 @@ public class JvmGcMonitorService extends AbstractLifecycleComponent<JvmGcMonitor
long avgCollectionTime = collectionTime / collections;
Threshold threshold = null;
if (avgCollectionTime > gcThreshold.warnThreshold) {
logger.warn("[gc][{}][{}][{}] duration [{}], collections [{}]/[{}], total [{}]/[{}], memory [{}]->[{}]/[{}], all_pools {}",
gc.getName(), seq, gc.getCollectionCount(), TimeValue.timeValueMillis(collectionTime), collections, TimeValue.timeValueMillis(currentJvmStats.getTimestamp() - lastJvmStats.getTimestamp()), TimeValue.timeValueMillis(collectionTime), gc.getCollectionTime(), lastJvmStats.getMem().getHeapUsed(), currentJvmStats.getMem().getHeapUsed(), JvmInfo.jvmInfo().getMem().getHeapMax(), buildPools(lastJvmStats, currentJvmStats));
threshold = Threshold.WARN;
} else if (avgCollectionTime > gcThreshold.infoThreshold) {
logger.info("[gc][{}][{}][{}] duration [{}], collections [{}]/[{}], total [{}]/[{}], memory [{}]->[{}]/[{}], all_pools {}",
gc.getName(), seq, gc.getCollectionCount(), TimeValue.timeValueMillis(collectionTime), collections, TimeValue.timeValueMillis(currentJvmStats.getTimestamp() - lastJvmStats.getTimestamp()), TimeValue.timeValueMillis(collectionTime), gc.getCollectionTime(), lastJvmStats.getMem().getHeapUsed(), currentJvmStats.getMem().getHeapUsed(), JvmInfo.jvmInfo().getMem().getHeapMax(), buildPools(lastJvmStats, currentJvmStats));
} else if (avgCollectionTime > gcThreshold.debugThreshold && logger.isDebugEnabled()) {
logger.debug("[gc][{}][{}][{}] duration [{}], collections [{}]/[{}], total [{}]/[{}], memory [{}]->[{}]/[{}], all_pools {}",
gc.getName(), seq, gc.getCollectionCount(), TimeValue.timeValueMillis(collectionTime), collections, TimeValue.timeValueMillis(currentJvmStats.getTimestamp() - lastJvmStats.getTimestamp()), TimeValue.timeValueMillis(collectionTime), gc.getCollectionTime(), lastJvmStats.getMem().getHeapUsed(), currentJvmStats.getMem().getHeapUsed(), JvmInfo.jvmInfo().getMem().getHeapMax(), buildPools(lastJvmStats, currentJvmStats));
threshold = Threshold.INFO;
} else if (avgCollectionTime > gcThreshold.debugThreshold) {
threshold = Threshold.DEBUG;
}
if (threshold != null) {
onSlowGc(threshold, seq, new SlowGcEvent(
gc,
collections,
TimeValue.timeValueMillis(collectionTime),
elapsed,
lastJvmStats,
currentJvmStats,
JvmInfo.jvmInfo().getMem().getHeapMax()));
}
}
lastTime = currentTime;
lastJvmStats = currentJvmStats;
}
private String buildPools(JvmStats prev, JvmStats current) {
StringBuilder sb = new StringBuilder();
for (JvmStats.MemoryPool currentPool : current.getMem()) {
JvmStats.MemoryPool prevPool = null;
for (JvmStats.MemoryPool pool : prev.getMem()) {
if (pool.getName().equals(currentPool.getName())) {
prevPool = pool;
break;
}
}
sb.append("{[").append(currentPool.getName())
.append("] [").append(prevPool == null ? "?" : prevPool.getUsed()).append("]->[").append(currentPool.getUsed()).append("]/[").append(currentPool.getMax()).append("]}");
}
return sb.toString();
JvmStats jvmStats() {
return JvmStats.jvmStats();
}
long now() {
return System.nanoTime();
}
abstract void onSlowGc(final Threshold threshold, final long seq, final SlowGcEvent slowGcEvent);
}
}

View File

@ -0,0 +1,136 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.monitor.jvm;
import org.elasticsearch.common.logging.ESLogger;
import org.elasticsearch.common.unit.ByteSizeValue;
import org.elasticsearch.common.unit.TimeValue;
import org.elasticsearch.test.ESTestCase;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.verifyNoMoreInteractions;
import static org.mockito.Mockito.when;
public class JvmGcMonitorServiceTests extends ESTestCase {
public void testSlowGcLogging() {
final ESLogger logger = mock(ESLogger.class);
when(logger.isWarnEnabled()).thenReturn(true);
when(logger.isInfoEnabled()).thenReturn(true);
when(logger.isDebugEnabled()).thenReturn(true);
final JvmGcMonitorService.JvmMonitor.Threshold threshold = randomFrom(JvmGcMonitorService.JvmMonitor.Threshold.values());
final String name = randomAsciiOfLength(16);
final long seq = randomIntBetween(1, 1 << 30);
final int elapsedValue = randomIntBetween(1, 1 << 10);
final long totalCollectionCount = randomIntBetween(1, 16);
final long currentCollectionCount = randomIntBetween(1, 16);
final TimeValue totalCollectionTime = TimeValue.timeValueMillis(randomIntBetween(1, elapsedValue));
final TimeValue currentCollectionTime = TimeValue.timeValueMillis(randomIntBetween(1, elapsedValue));
final ByteSizeValue lastHeapUsed = new ByteSizeValue(randomIntBetween(1, 1 << 10));
JvmStats lastJvmStats = mock(JvmStats.class);
JvmStats.Mem lastMem = mock(JvmStats.Mem.class);
when(lastMem.getHeapUsed()).thenReturn(lastHeapUsed);
when(lastJvmStats.getMem()).thenReturn(lastMem);
when(lastJvmStats.toString()).thenReturn("last");
final ByteSizeValue currentHeapUsed = new ByteSizeValue(randomIntBetween(1, 1 << 10));
JvmStats currentJvmStats = mock(JvmStats.class);
JvmStats.Mem currentMem = mock(JvmStats.Mem.class);
when(currentMem.getHeapUsed()).thenReturn(currentHeapUsed);
when(currentJvmStats.getMem()).thenReturn(currentMem);
when(currentJvmStats.toString()).thenReturn("current");
JvmStats.GarbageCollector gc = mock(JvmStats.GarbageCollector.class);
when(gc.getName()).thenReturn(name);
when(gc.getCollectionCount()).thenReturn(totalCollectionCount);
when(gc.getCollectionTime()).thenReturn(totalCollectionTime);
final ByteSizeValue maxHeapUsed = new ByteSizeValue(Math.max(lastHeapUsed.bytes(), currentHeapUsed.bytes()) + 1 << 10);
JvmGcMonitorService.JvmMonitor.SlowGcEvent slowGcEvent = new JvmGcMonitorService.JvmMonitor.SlowGcEvent(
gc,
currentCollectionCount,
currentCollectionTime,
elapsedValue,
lastJvmStats,
currentJvmStats,
maxHeapUsed);
JvmGcMonitorService.logSlowGc(logger, threshold, seq, slowGcEvent, (l, c) -> l.toString() + ", " + c.toString());
switch (threshold) {
case WARN:
verify(logger).isWarnEnabled();
verify(logger).warn(
"[gc][{}][{}][{}] duration [{}], collections [{}]/[{}], total [{}]/[{}], memory [{}]->[{}]/[{}], all_pools {}",
name,
seq,
totalCollectionCount,
currentCollectionTime,
currentCollectionCount,
TimeValue.timeValueMillis(elapsedValue),
currentCollectionTime,
totalCollectionTime,
lastHeapUsed,
currentHeapUsed,
maxHeapUsed,
"last, current");
break;
case INFO:
verify(logger).isInfoEnabled();
verify(logger).info(
"[gc][{}][{}][{}] duration [{}], collections [{}]/[{}], total [{}]/[{}], memory [{}]->[{}]/[{}], all_pools {}",
name,
seq,
totalCollectionCount,
currentCollectionTime,
currentCollectionCount,
TimeValue.timeValueMillis(elapsedValue),
currentCollectionTime,
totalCollectionTime,
lastHeapUsed,
currentHeapUsed,
maxHeapUsed,
"last, current");
break;
case DEBUG:
verify(logger).isDebugEnabled();
verify(logger).debug(
"[gc][{}][{}][{}] duration [{}], collections [{}]/[{}], total [{}]/[{}], memory [{}]->[{}]/[{}], all_pools {}",
name,
seq,
totalCollectionCount,
currentCollectionTime,
currentCollectionCount,
TimeValue.timeValueMillis(elapsedValue),
currentCollectionTime,
totalCollectionTime,
lastHeapUsed,
currentHeapUsed,
maxHeapUsed,
"last, current");
break;
}
verifyNoMoreInteractions(logger);
}
}

View File

@ -0,0 +1,248 @@
/*
* Licensed to Elasticsearch under one or more contributor
* license agreements. See the NOTICE file distributed with
* this work for additional information regarding copyright
* ownership. Elasticsearch licenses this file to you under
* the Apache License, Version 2.0 (the "License"); you may
* not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing,
* software distributed under the License is distributed on an
* "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
* KIND, either express or implied. See the License for the
* specific language governing permissions and limitations
* under the License.
*/
package org.elasticsearch.monitor.jvm;
import org.elasticsearch.common.unit.TimeValue;
import org.elasticsearch.test.ESTestCase;
import java.util.Collections;
import java.util.HashMap;
import java.util.Map;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.concurrent.atomic.AtomicInteger;
import java.util.concurrent.atomic.AtomicLong;
import java.util.concurrent.atomic.AtomicReference;
import static org.hamcrest.CoreMatchers.anyOf;
import static org.hamcrest.CoreMatchers.containsString;
import static org.hamcrest.CoreMatchers.equalTo;
import static org.hamcrest.CoreMatchers.instanceOf;
import static org.hamcrest.Matchers.hasToString;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.when;
public class JvmMonitorTests extends ESTestCase {
public void testMonitorFailure() {
AtomicBoolean shouldFail = new AtomicBoolean();
AtomicBoolean invoked = new AtomicBoolean();
JvmGcMonitorService.JvmMonitor monitor = new JvmGcMonitorService.JvmMonitor(Collections.emptyMap()) {
@Override
void onMonitorFailure(Throwable t) {
invoked.set(true);
assertThat(t, instanceOf(RuntimeException.class));
assertThat(t, hasToString(containsString("simulated")));
}
@Override
synchronized void monitorLongGc() {
if (shouldFail.get()) {
throw new RuntimeException("simulated");
}
}
@Override
void onSlowGc(final Threshold threshold, final long seq, final SlowGcEvent slowGcEvent) {
}
};
monitor.run();
assertFalse(invoked.get());
shouldFail.set(true);
monitor.run();
assertTrue(invoked.get());
}
public void testSlowGc() {
final int initialYoungCollectionCount = randomIntBetween(1, 4);
final int initialYoungCollectionTime = randomIntBetween(initialYoungCollectionCount * 100, initialYoungCollectionCount * 200);
final int initialOldCollectionCount = randomIntBetween(1, 4);
final int initialOldCollectionTime = randomIntBetween(initialYoungCollectionCount * 1000, initialYoungCollectionCount * 2000);
final JvmStats.GarbageCollector initialYoungCollector = mock(JvmStats.GarbageCollector.class);
when(initialYoungCollector.getName()).thenReturn("young");
when(initialYoungCollector.getCollectionCount()).thenReturn((long) initialYoungCollectionCount);
when(initialYoungCollector.getCollectionTime()).thenReturn(TimeValue.timeValueMillis(initialYoungCollectionTime));
final JvmStats.GarbageCollector initialOldCollector = mock(JvmStats.GarbageCollector.class);
when(initialOldCollector.getName()).thenReturn("old");
when(initialOldCollector.getCollectionCount()).thenReturn((long) initialOldCollectionCount);
when(initialOldCollector.getCollectionTime()).thenReturn(TimeValue.timeValueMillis(initialOldCollectionTime));
JvmStats initialJvmStats = jvmStats(initialYoungCollector, initialOldCollector);
final Map<String, JvmGcMonitorService.GcThreshold> gcThresholds = new HashMap<>();
// fake debug threshold, info will be double this and warn will
// be triple
final int youngDebugThreshold = randomIntBetween(1, 10) * 100;
gcThresholds.put(
"young",
new JvmGcMonitorService.GcThreshold("young", youngDebugThreshold * 3, youngDebugThreshold * 2, youngDebugThreshold));
final boolean youngGcThreshold = randomBoolean();
final JvmGcMonitorService.JvmMonitor.Threshold youngThresholdLevel = randomFrom(JvmGcMonitorService.JvmMonitor.Threshold.values());
final int youngMultiplier = 1 + youngThresholdLevel.ordinal();
final int youngCollections = randomIntBetween(1, 4);
final JvmStats.GarbageCollector youngCollector;
youngCollector = mock(JvmStats.GarbageCollector.class);
when(youngCollector.getName()).thenReturn("young");
when(youngCollector.getCollectionCount()).thenReturn((long) (initialYoungCollectionCount + youngCollections));
final int youngIncrement;
if (youngGcThreshold) {
// we are faking that youngCollections collections occurred
// this number is chosen so that we squeak over the
// random threshold when computing the average collection
// time: note that average collection time will just be
// youngMultiplier * youngDebugThreshold + 1 which ensures
// that we are over the right threshold but below the next
// threshold
youngIncrement = youngCollections * youngMultiplier * youngDebugThreshold + youngCollections;
} else {
// fake that we did not exceed the threshold
youngIncrement = randomIntBetween(1, youngDebugThreshold);
}
when(youngCollector.getCollectionTime()).thenReturn(TimeValue.timeValueMillis(initialYoungCollectionTime + youngIncrement));
// fake debug threshold, info will be double this and warn will
// be triple
final int oldDebugThreshold = randomIntBetween(1, 10) * 100;
gcThresholds.put(
"old",
new JvmGcMonitorService.GcThreshold("old", oldDebugThreshold * 3, oldDebugThreshold * 2, oldDebugThreshold));
final boolean oldGcThreshold = randomBoolean();
final JvmGcMonitorService.JvmMonitor.Threshold oldThresholdLevel = randomFrom(JvmGcMonitorService.JvmMonitor.Threshold.values());
final int oldMultiplier = 1 + oldThresholdLevel.ordinal();
final int oldCollections = randomIntBetween(1, 4);
final JvmStats.GarbageCollector oldCollector = mock(JvmStats.GarbageCollector.class);
when(oldCollector.getName()).thenReturn("old");
when(oldCollector.getCollectionCount()).thenReturn((long) (initialOldCollectionCount + oldCollections));
final int oldIncrement;
if (oldGcThreshold) {
// we are faking that oldCollections collections occurred
// this number is chosen so that we squeak over the
// random threshold when computing the average collection
// time: note that average collection time will just be
// oldMultiplier * oldDebugThreshold + 1 which ensures
// that we are over the right threshold but below the next
// threshold
oldIncrement = oldCollections * oldMultiplier * oldDebugThreshold + oldCollections;
} else {
// fake that we did not exceed the threshold
oldIncrement = randomIntBetween(1, oldDebugThreshold);
}
when(oldCollector.getCollectionTime()).thenReturn(TimeValue.timeValueMillis(initialOldCollectionTime + oldIncrement));
final long start = randomIntBetween(1, 1 << 30);
final long expectedElapsed = randomIntBetween(1, 1000);
final AtomicLong now = new AtomicLong(start);
final AtomicReference<JvmStats> jvmStats = new AtomicReference<>();
jvmStats.set(initialJvmStats);
final AtomicInteger count = new AtomicInteger();
JvmGcMonitorService.JvmMonitor monitor = new JvmGcMonitorService.JvmMonitor(gcThresholds) {
@Override
void onMonitorFailure(Throwable t) {
}
@Override
void onSlowGc(final Threshold threshold, final long seq, final SlowGcEvent slowGcEvent) {
count.incrementAndGet();
assertThat(seq, equalTo(1L));
assertThat(slowGcEvent.elapsed, equalTo(expectedElapsed));
assertThat(slowGcEvent.currentGc.getName(), anyOf(equalTo("young"), equalTo("old")));
if ("young".equals(slowGcEvent.currentGc.getName())) {
assertCollection(
threshold,
youngThresholdLevel,
slowGcEvent,
initialYoungCollectionCount,
youngCollections,
initialYoungCollectionTime,
youngIncrement);
} else if ("old".equals(slowGcEvent.currentGc.getName())) {
assertCollection(
threshold,
oldThresholdLevel,
slowGcEvent,
initialOldCollectionCount,
oldCollections,
initialOldCollectionTime,
oldIncrement);
}
}
@Override
long now() {
return now.get();
}
@Override
JvmStats jvmStats() {
return jvmStats.get();
}
};
final JvmStats monitorJvmStats = jvmStats(youngCollector, oldCollector);
now.set(start + TimeUnit.NANOSECONDS.convert(expectedElapsed, TimeUnit.MILLISECONDS));
jvmStats.set(monitorJvmStats);
monitor.monitorLongGc();
assertThat(count.get(), equalTo((youngGcThreshold ? 1 : 0) + (oldGcThreshold ? 1 : 0)));
}
private void assertCollection(
final JvmGcMonitorService.JvmMonitor.Threshold actualThreshold,
final JvmGcMonitorService.JvmMonitor.Threshold expectedThreshold,
final JvmGcMonitorService.JvmMonitor.SlowGcEvent slowGcEvent,
final int initialCollectionCount,
final int collections,
final int initialCollectionTime,
final int increment) {
assertThat(actualThreshold, equalTo(expectedThreshold));
assertThat(slowGcEvent.currentGc.getCollectionCount(), equalTo((long) (initialCollectionCount + collections)));
assertThat(slowGcEvent.collectionCount, equalTo((long) collections));
assertThat(slowGcEvent.collectionTime, equalTo(TimeValue.timeValueMillis(increment)));
assertThat(slowGcEvent.currentGc.getCollectionTime(), equalTo(TimeValue.timeValueMillis(initialCollectionTime + increment)));
}
private JvmStats jvmStats(JvmStats.GarbageCollector youngCollector, JvmStats.GarbageCollector oldCollector) {
final JvmStats jvmStats = mock(JvmStats.class);
final JvmStats.GarbageCollectors initialGcs = mock(JvmStats.GarbageCollectors.class);
final JvmStats.GarbageCollector[] initialCollectors = new JvmStats.GarbageCollector[2];
initialCollectors[0] = youngCollector;
initialCollectors[1] = oldCollector;
when(initialGcs.getCollectors()).thenReturn(initialCollectors);
when(jvmStats.getGc()).thenReturn(initialGcs);
when(jvmStats.getMem()).thenReturn(JvmStats.jvmStats().getMem());
return jvmStats;
}
}