diff --git a/core/src/main/java/org/elasticsearch/common/settings/ClusterSettings.java b/core/src/main/java/org/elasticsearch/common/settings/ClusterSettings.java index dad5f48ce27..e66534a4feb 100644 --- a/core/src/main/java/org/elasticsearch/common/settings/ClusterSettings.java +++ b/core/src/main/java/org/elasticsearch/common/settings/ClusterSettings.java @@ -397,6 +397,9 @@ public final class ClusterSettings extends AbstractScopedSettings { JvmGcMonitorService.ENABLED_SETTING, JvmGcMonitorService.REFRESH_INTERVAL_SETTING, JvmGcMonitorService.GC_SETTING, + JvmGcMonitorService.GC_OVERHEAD_WARN_SETTING, + JvmGcMonitorService.GC_OVERHEAD_INFO_SETTING, + JvmGcMonitorService.GC_OVERHEAD_DEBUG_SETTING, PageCacheRecycler.LIMIT_HEAP_SETTING, PageCacheRecycler.WEIGHT_BYTES_SETTING, PageCacheRecycler.WEIGHT_INT_SETTING, diff --git a/core/src/main/java/org/elasticsearch/common/settings/Setting.java b/core/src/main/java/org/elasticsearch/common/settings/Setting.java index edd5d511f86..1efb65c18b1 100644 --- a/core/src/main/java/org/elasticsearch/common/settings/Setting.java +++ b/core/src/main/java/org/elasticsearch/common/settings/Setting.java @@ -18,19 +18,6 @@ */ package org.elasticsearch.common.settings; -import java.io.IOException; -import java.util.ArrayList; -import java.util.Arrays; -import java.util.EnumSet; -import java.util.List; -import java.util.Map; -import java.util.Objects; -import java.util.function.BiConsumer; -import java.util.function.Consumer; -import java.util.function.Function; -import java.util.regex.Pattern; -import java.util.stream.Collectors; - import org.elasticsearch.ElasticsearchException; import org.elasticsearch.ElasticsearchParseException; import org.elasticsearch.action.support.ToXContentToBytes; @@ -50,6 +37,19 @@ import org.elasticsearch.common.xcontent.XContentFactory; import org.elasticsearch.common.xcontent.XContentParser; import org.elasticsearch.common.xcontent.XContentType; +import java.io.IOException; +import java.util.ArrayList; +import java.util.Arrays; +import java.util.EnumSet; +import java.util.List; +import java.util.Map; +import java.util.Objects; +import java.util.function.BiConsumer; +import java.util.function.Consumer; +import java.util.function.Function; +import java.util.regex.Pattern; +import java.util.stream.Collectors; + /** * A setting. Encapsulates typical stuff like default value, parsing, and scope. * Some (SettingsProperty.Dynamic) can by modified at run time using the API. @@ -504,7 +504,7 @@ public class Setting extends ToXContentToBytes { throw new IllegalArgumentException("Failed to parse value [" + s + "] for setting [" + key + "] must be >= " + minValue); } if (value > maxValue) { - throw new IllegalArgumentException("Failed to parse value [" + s + "] for setting [" + key + "] must be =< " + maxValue); + throw new IllegalArgumentException("Failed to parse value [" + s + "] for setting [" + key + "] must be <= " + maxValue); } return value; } @@ -572,7 +572,7 @@ public class Setting extends ToXContentToBytes { throw new IllegalArgumentException("Failed to parse value [" + s + "] for setting [" + key + "] must be >= " + minValue); } if (value.bytes() > maxValue.bytes()) { - throw new IllegalArgumentException("Failed to parse value [" + s + "] for setting [" + key + "] must be =< " + maxValue); + throw new IllegalArgumentException("Failed to parse value [" + s + "] for setting [" + key + "] must be <= " + maxValue); } return value; } diff --git a/core/src/main/java/org/elasticsearch/monitor/jvm/JvmGcMonitorService.java b/core/src/main/java/org/elasticsearch/monitor/jvm/JvmGcMonitorService.java index 01b4c68537e..ac75eb93aaa 100644 --- a/core/src/main/java/org/elasticsearch/monitor/jvm/JvmGcMonitorService.java +++ b/core/src/main/java/org/elasticsearch/monitor/jvm/JvmGcMonitorService.java @@ -31,6 +31,7 @@ import org.elasticsearch.monitor.jvm.JvmStats.GarbageCollector; import org.elasticsearch.threadpool.ThreadPool; import java.util.HashMap; +import java.util.Locale; import java.util.Map; import java.util.Objects; import java.util.concurrent.ScheduledFuture; @@ -45,6 +46,7 @@ public class JvmGcMonitorService extends AbstractLifecycleComponent gcThresholds; + private final GcOverheadThreshold gcOverheadThreshold; private volatile ScheduledFuture scheduledFuture; @@ -57,6 +59,27 @@ public class JvmGcMonitorService extends AbstractLifecycleComponent GC_SETTING = Setting.groupSetting(GC_COLLECTOR_PREFIX, Property.NodeScope); + public final static Setting GC_OVERHEAD_WARN_SETTING = + Setting.intSetting("monitor.jvm.gc.overhead.warn", 50, 0, 100, Property.NodeScope); + public final static Setting GC_OVERHEAD_INFO_SETTING = + Setting.intSetting("monitor.jvm.gc.overhead.info", 25, 0, 100, Property.NodeScope); + public final static Setting GC_OVERHEAD_DEBUG_SETTING = + Setting.intSetting("monitor.jvm.gc.overhead.debug", 10, 0, 100, Property.NodeScope); + + static class GcOverheadThreshold { + final int warnThreshold; + final int infoThreshold; + final int debugThreshold; + + public GcOverheadThreshold(final int warnThreshold, final int infoThreshold, final int debugThreshold) { + this.warnThreshold = warnThreshold; + this.infoThreshold = infoThreshold; + this.debugThreshold = debugThreshold; + } + } + + + static class GcThreshold { public final String name; public final long warnThreshold; @@ -102,7 +125,42 @@ public class JvmGcMonitorService extends AbstractLifecycleComponent[{}]/[{}], all_pools {}"; - @Override protected void doStart() { if (!enabled) { return; } - scheduledFuture = threadPool.scheduleWithFixedDelay(new JvmMonitor(gcThresholds) { + scheduledFuture = threadPool.scheduleWithFixedDelay(new JvmMonitor(gcThresholds, gcOverheadThreshold) { @Override void onMonitorFailure(Throwable t) { logger.debug("failed to monitor", t); @@ -138,9 +193,17 @@ public class JvmGcMonitorService extends AbstractLifecycleComponent[{}]/[{}], all_pools {}"; + static void logSlowGc( final ESLogger logger, final JvmMonitor.Threshold threshold, @@ -162,7 +225,7 @@ public class JvmGcMonitorService extends AbstractLifecycleComponent gcThresholds; + private final Map gcThresholds; + final GcOverheadThreshold gcOverheadThreshold; - public JvmMonitor(Map gcThresholds) { + public JvmMonitor(final Map gcThresholds, final GcOverheadThreshold gcOverheadThreshold) { this.gcThresholds = Objects.requireNonNull(gcThresholds); + this.gcOverheadThreshold = Objects.requireNonNull(gcOverheadThreshold); } @Override public void run() { try { - monitorLongGc(); + monitorGc(); } catch (Throwable t) { onMonitorFailure(t); } @@ -304,12 +396,21 @@ public class JvmGcMonitorService extends AbstractLifecycleComponent= gcOverheadThreshold.warnThreshold) { + overheadThreshold = Threshold.WARN; + } else if (fraction >= gcOverheadThreshold.infoThreshold) { + overheadThreshold = Threshold.INFO; + } else if (fraction >= gcOverheadThreshold.debugThreshold) { + overheadThreshold = Threshold.DEBUG; + } + if (overheadThreshold != null) { + onGcOverhead(overheadThreshold, current, elapsed, seq); + } } JvmStats jvmStats() { @@ -364,6 +488,8 @@ public class JvmGcMonitorService extends AbstractLifecycleComponent null, t -> { + assertThat(t, instanceOf(IllegalArgumentException.class)); + assertThat(t.getMessage(), containsString("setting [monitor.jvm.gc.overhead." + threshold + "] must be >= 0")); + }, true, null); + } + + for (final String threshold : new String[] { "warn", "info", "debug" }) { + final Settings.Builder builder = Settings.builder(); + builder.put("monitor.jvm.gc.overhead." + threshold, randomIntBetween(100 + 1, Integer.MAX_VALUE)); + execute(builder.build(), (command, interval) -> null, t -> { + assertThat(t, instanceOf(IllegalArgumentException.class)); + assertThat(t.getMessage(), containsString("setting [monitor.jvm.gc.overhead." + threshold + "] must be <= 100")); + }, true, null); + } + + final Settings.Builder infoWarnOutOfOrderBuilder = Settings.builder(); + final int info = randomIntBetween(2, 98); + infoWarnOutOfOrderBuilder.put("monitor.jvm.gc.overhead.info", info); + final int warn = randomIntBetween(1, info - 1); + infoWarnOutOfOrderBuilder.put("monitor.jvm.gc.overhead.warn", warn); + execute(infoWarnOutOfOrderBuilder.build(), (command, interval) -> null, t -> { + assertThat(t, instanceOf(IllegalArgumentException.class)); + assertThat(t.getMessage(), containsString("[monitor.jvm.gc.overhead.warn] must be greater than [monitor.jvm.gc.overhead.info] [" + info + "] but was [" + warn + "]")); + }, true, null); + + final Settings.Builder debugInfoOutOfOrderBuilder = Settings.builder(); + debugInfoOutOfOrderBuilder.put("monitor.jvm.gc.overhead.info", info); + final int debug = randomIntBetween(info + 1, 99); + debugInfoOutOfOrderBuilder.put("monitor.jvm.gc.overhead.debug", debug); + debugInfoOutOfOrderBuilder.put("monitor.jvm.gc.overhead.warn", randomIntBetween(debug + 1, 100)); // or the test will fail for the wrong reason + execute(debugInfoOutOfOrderBuilder.build(), (command, interval) -> null, t -> { + assertThat(t, instanceOf(IllegalArgumentException.class)); + assertThat(t.getMessage(), containsString("[monitor.jvm.gc.overhead.info] must be greater than [monitor.jvm.gc.overhead.debug] [" + debug + "] but was [" + info + "]")); + }, true, null); + } + private static void execute(Settings settings, BiFunction> scheduler, Runnable asserts) throws InterruptedException { execute(settings, scheduler, null, false, asserts); } diff --git a/core/src/test/java/org/elasticsearch/monitor/jvm/JvmGcMonitorServiceTests.java b/core/src/test/java/org/elasticsearch/monitor/jvm/JvmGcMonitorServiceTests.java index 2c17fca7c8c..ab5b1ac4750 100644 --- a/core/src/test/java/org/elasticsearch/monitor/jvm/JvmGcMonitorServiceTests.java +++ b/core/src/test/java/org/elasticsearch/monitor/jvm/JvmGcMonitorServiceTests.java @@ -133,4 +133,43 @@ public class JvmGcMonitorServiceTests extends ESTestCase { verifyNoMoreInteractions(logger); } + public void testGcOverheadLogging() { + final JvmGcMonitorService.JvmMonitor.Threshold threshold = randomFrom(JvmGcMonitorService.JvmMonitor.Threshold.values()); + final int current = randomIntBetween(1, Integer.MAX_VALUE); + final long elapsed = randomIntBetween(current, Integer.MAX_VALUE); + final long seq = randomIntBetween(1, Integer.MAX_VALUE); + final ESLogger logger = mock(ESLogger.class); + when(logger.isWarnEnabled()).thenReturn(true); + when(logger.isInfoEnabled()).thenReturn(true); + when(logger.isDebugEnabled()).thenReturn(true); + JvmGcMonitorService.logGcOverhead(logger, threshold, current, elapsed, seq); + switch(threshold) { + case WARN: + verify(logger).isWarnEnabled(); + verify(logger).warn( + "[gc][{}] overhead, spent [{}] collecting in the last [{}]", + seq, + TimeValue.timeValueMillis(current), + TimeValue.timeValueMillis(elapsed)); + break; + case INFO: + verify(logger).isInfoEnabled(); + verify(logger).info( + "[gc][{}] overhead, spent [{}] collecting in the last [{}]", + seq, + TimeValue.timeValueMillis(current), + TimeValue.timeValueMillis(elapsed)); + break; + case DEBUG: + verify(logger).isDebugEnabled(); + verify(logger).debug( + "[gc][{}] overhead, spent [{}] collecting in the last [{}]", + seq, + TimeValue.timeValueMillis(current), + TimeValue.timeValueMillis(elapsed)); + break; + } + verifyNoMoreInteractions(logger); + } + } diff --git a/core/src/test/java/org/elasticsearch/monitor/jvm/JvmMonitorTests.java b/core/src/test/java/org/elasticsearch/monitor/jvm/JvmMonitorTests.java index 8d3ddeec84e..91862e9cd18 100644 --- a/core/src/test/java/org/elasticsearch/monitor/jvm/JvmMonitorTests.java +++ b/core/src/test/java/org/elasticsearch/monitor/jvm/JvmMonitorTests.java @@ -41,10 +41,12 @@ import static org.mockito.Mockito.when; public class JvmMonitorTests extends ESTestCase { + private static final JvmGcMonitorService.GcOverheadThreshold IGNORE = new JvmGcMonitorService.GcOverheadThreshold(0, 0, 0); + public void testMonitorFailure() { AtomicBoolean shouldFail = new AtomicBoolean(); AtomicBoolean invoked = new AtomicBoolean(); - JvmGcMonitorService.JvmMonitor monitor = new JvmGcMonitorService.JvmMonitor(Collections.emptyMap()) { + JvmGcMonitorService.JvmMonitor monitor = new JvmGcMonitorService.JvmMonitor(Collections.emptyMap(), IGNORE) { @Override void onMonitorFailure(Throwable t) { invoked.set(true); @@ -53,7 +55,7 @@ public class JvmMonitorTests extends ESTestCase { } @Override - synchronized void monitorLongGc() { + synchronized void monitorGc() { if (shouldFail.get()) { throw new RuntimeException("simulated"); } @@ -62,6 +64,10 @@ public class JvmMonitorTests extends ESTestCase { @Override void onSlowGc(final Threshold threshold, final long seq, final SlowGcEvent slowGcEvent) { } + + @Override + void onGcOverhead(Threshold threshold, long total, long elapsed, long seq) { + } }; monitor.run(); @@ -166,7 +172,7 @@ public class JvmMonitorTests extends ESTestCase { final AtomicInteger count = new AtomicInteger(); - JvmGcMonitorService.JvmMonitor monitor = new JvmGcMonitorService.JvmMonitor(gcThresholds) { + JvmGcMonitorService.JvmMonitor monitor = new JvmGcMonitorService.JvmMonitor(gcThresholds, IGNORE) { @Override void onMonitorFailure(Throwable t) { } @@ -198,6 +204,10 @@ public class JvmMonitorTests extends ESTestCase { } } + @Override + void onGcOverhead(Threshold threshold, long total, long elapsed, long seq) { + } + @Override long now() { return now.get(); @@ -213,7 +223,7 @@ public class JvmMonitorTests extends ESTestCase { now.set(start + TimeUnit.NANOSECONDS.convert(expectedElapsed, TimeUnit.MILLISECONDS)); jvmStats.set(monitorJvmStats); - monitor.monitorLongGc(); + monitor.monitorGc(); assertThat(count.get(), equalTo((youngGcThreshold ? 1 : 0) + (oldGcThreshold ? 1 : 0))); } @@ -235,14 +245,140 @@ public class JvmMonitorTests extends ESTestCase { 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); + final JvmStats.GarbageCollectors gcs = mock(JvmStats.GarbageCollectors.class); + final JvmStats.GarbageCollector[] collectors = new JvmStats.GarbageCollector[2]; + collectors[0] = youngCollector; + collectors[1] = oldCollector; + when(gcs.getCollectors()).thenReturn(collectors); + when(jvmStats.getGc()).thenReturn(gcs); when(jvmStats.getMem()).thenReturn(JvmStats.jvmStats().getMem()); return jvmStats; } + public void testMonitorGc() { + final int youngCollectionCount = randomIntBetween(1, 16); + final int youngCollectionIncrement = randomIntBetween(1, 16); + final int youngCollectionTime = randomIntBetween(1, 1 << 10); + final int youngCollectionTimeIncrement = randomIntBetween(1, 1 << 10); + final int oldCollectionCount = randomIntBetween(1, 16); + final int oldCollectionIncrement = randomIntBetween(1, 16); + final int oldCollectionTime = randomIntBetween(1, 1 << 10); + final int oldCollectionTimeIncrement = randomIntBetween(1, 1 << 10); + + final JvmStats.GarbageCollector lastYoungCollector = collector("young", youngCollectionCount, youngCollectionTime); + final JvmStats.GarbageCollector lastOldCollector = collector("old", oldCollectionCount, oldCollectionTime); + final JvmStats lastjvmStats = jvmStats(lastYoungCollector, lastOldCollector); + + final JvmStats.GarbageCollector currentYoungCollector = + collector("young", youngCollectionCount + youngCollectionIncrement, youngCollectionTime + youngCollectionTimeIncrement); + final JvmStats.GarbageCollector currentOldCollector = + collector("old", oldCollectionCount + oldCollectionIncrement, oldCollectionTime + oldCollectionTimeIncrement); + final JvmStats currentJvmStats = jvmStats(currentYoungCollector, currentOldCollector); + final long expectedElapsed = + randomIntBetween( + Math.max(youngCollectionTime + youngCollectionTimeIncrement, oldCollectionTime + oldCollectionTimeIncrement), + Integer.MAX_VALUE); + + final AtomicBoolean invoked = new AtomicBoolean(); + + final JvmGcMonitorService.JvmMonitor monitor = new JvmGcMonitorService.JvmMonitor(Collections.emptyMap(), IGNORE) { + + @Override + void onMonitorFailure(Throwable t) { + } + + @Override + void onSlowGc(Threshold threshold, long seq, SlowGcEvent slowGcEvent) { + } + + @Override + void onGcOverhead(Threshold threshold, long total, long elapsed, long seq) { + } + + @Override + void checkGcOverhead(long current, long elapsed, long seq) { + invoked.set(true); + assertThat(current, equalTo((long)(youngCollectionTimeIncrement + oldCollectionTimeIncrement))); + assertThat(elapsed, equalTo(expectedElapsed)); + } + + @Override + JvmStats jvmStats() { + return lastjvmStats; + } + }; + + monitor.monitorGcOverhead(currentJvmStats, expectedElapsed); + assertTrue(invoked.get()); + } + + private JvmStats.GarbageCollector collector(final String name, final int collectionCount, final int collectionTime) { + final JvmStats.GarbageCollector gc = mock(JvmStats.GarbageCollector.class); + when(gc.getName()).thenReturn(name); + when(gc.getCollectionCount()).thenReturn((long)collectionCount); + when(gc.getCollectionTime()).thenReturn(TimeValue.timeValueMillis(collectionTime)); + return gc; + } + + public void testCheckGcOverhead() { + final int debugThreshold = randomIntBetween(1, 98); + final int infoThreshold = randomIntBetween(debugThreshold + 1, 99); + final int warnThreshold = randomIntBetween(infoThreshold + 1, 100); + final JvmGcMonitorService.GcOverheadThreshold gcOverheadThreshold = + new JvmGcMonitorService.GcOverheadThreshold(warnThreshold, infoThreshold, debugThreshold); + + final JvmGcMonitorService.JvmMonitor.Threshold expectedThreshold; + int fraction = 0; + final long expectedCurrent; + final long expectedElapsed; + if (randomBoolean()) { + expectedThreshold = randomFrom(JvmGcMonitorService.JvmMonitor.Threshold.values()); + switch (expectedThreshold) { + case WARN: + fraction = randomIntBetween(warnThreshold, 100); + break; + case INFO: + fraction = randomIntBetween(infoThreshold, warnThreshold - 1); + break; + case DEBUG: + fraction = randomIntBetween(debugThreshold, infoThreshold - 1); + break; + } + } else { + expectedThreshold = null; + fraction = randomIntBetween(0, debugThreshold - 1); + } + + expectedElapsed = 100 * randomIntBetween(1, 1000); + expectedCurrent = fraction * expectedElapsed / 100; + + final AtomicBoolean invoked = new AtomicBoolean(); + final long expectedSeq = randomIntBetween(1, Integer.MAX_VALUE); + + final JvmGcMonitorService.JvmMonitor monitor = new JvmGcMonitorService.JvmMonitor(Collections.emptyMap(), gcOverheadThreshold) { + + @Override + void onMonitorFailure(final Throwable t) { + } + + @Override + void onSlowGc(Threshold threshold, long seq, SlowGcEvent slowGcEvent) { + } + + @Override + void onGcOverhead(final Threshold threshold, final long current, final long elapsed, final long seq) { + invoked.set(true); + assertThat(threshold, equalTo(expectedThreshold)); + assertThat(current, equalTo(expectedCurrent)); + assertThat(elapsed, equalTo(expectedElapsed)); + assertThat(seq, equalTo(expectedSeq)); + } + + }; + + monitor.checkGcOverhead(expectedCurrent, expectedElapsed, expectedSeq); + + assertThat(invoked.get(), equalTo(expectedThreshold != null)); + } + }