diff --git a/jvm-statistics/pom.xml b/jvm-statistics/pom.xml index 7ac22e70..c94d0867 100644 --- a/jvm-statistics/pom.xml +++ b/jvm-statistics/pom.xml @@ -51,5 +51,11 @@ ${protobuf.version} test + + org.assertj + assertj-core + 3.11.1 + test + diff --git a/jvm-statistics/src/main/java/com/criteo/hadoop/garmadon/jvm/MXBeanHelper.java b/jvm-statistics/src/main/java/com/criteo/hadoop/garmadon/jvm/MXBeanHelper.java index daa3a8a4..2c5777b5 100644 --- a/jvm-statistics/src/main/java/com/criteo/hadoop/garmadon/jvm/MXBeanHelper.java +++ b/jvm-statistics/src/main/java/com/criteo/hadoop/garmadon/jvm/MXBeanHelper.java @@ -8,6 +8,9 @@ public class MXBeanHelper { public static final String MEMORY_POOL_METASPACE_HEADER = "metaspace"; public static final String MEMORY_POOL_COMPRESSEDCLASSPACE_HEADER = "compressedclassspace"; public static final String MEMORY_POOL_PERM_HEADER = "perm"; + public static final String MEMORY_POOL_CODE_HEAP_PROFILED_NMETHODS_HEADER = "CodeHeap 'profiled nmethods'"; + public static final String MEMORY_POOL_CODE_HEAP_NON_PROFILED_NMETHODS_HEADER = "CodeHeap 'non-profiled nmethods'"; + public static final String MEMORY_POOL_CODE_HEAP_NON_NMETHODS_HEADER = "CodeHeap 'non-nmethods'"; protected MXBeanHelper() { throw new UnsupportedOperationException(); diff --git a/jvm-statistics/src/main/java/com/criteo/hadoop/garmadon/jvm/ProtobufGCNotifications.java b/jvm-statistics/src/main/java/com/criteo/hadoop/garmadon/jvm/ProtobufGCNotifications.java index 0e7f55f6..f8929968 100644 --- a/jvm-statistics/src/main/java/com/criteo/hadoop/garmadon/jvm/ProtobufGCNotifications.java +++ b/jvm-statistics/src/main/java/com/criteo/hadoop/garmadon/jvm/ProtobufGCNotifications.java @@ -1,6 +1,5 @@ package com.criteo.hadoop.garmadon.jvm; -import com.criteo.hadoop.garmadon.event.proto.JVMStatisticsEventsProtos; import com.sun.management.GarbageCollectionNotificationInfo; import com.sun.management.GcInfo; @@ -15,10 +14,13 @@ import java.util.Map; import java.util.function.BiConsumer; +import static com.criteo.hadoop.garmadon.event.proto.JVMStatisticsEventsProtos.*; +import static com.criteo.hadoop.garmadon.jvm.MXBeanHelper.*; + public class ProtobufGCNotifications extends GCNotifications { private static final long MILLIS_MINUTE = 60000; - private static List gcEvents = new ArrayList<>(); + private static final List GC_EVENTS = new ArrayList<>(); public ProtobufGCNotifications() { @@ -26,20 +28,21 @@ public ProtobufGCNotifications() { } static void handleHSNotification(Notification notification, Object handback) { - BiConsumer printer = (BiConsumer) handback; - GarbageCollectionNotificationInfo gcNotifInfo = GarbageCollectionNotificationInfo.from((CompositeData) notification.getUserData()); - GcInfo gcInfo = gcNotifInfo.getGcInfo(); + BiConsumer printer = (BiConsumer) handback; + GarbageCollectionNotificationInfo gcNotificationInfo = + GarbageCollectionNotificationInfo.from((CompositeData) notification.getUserData()); + GcInfo gcInfo = gcNotificationInfo.getGcInfo(); GcEvent gcEvent = new GcEvent(gcInfo.getStartTime(), gcInfo.getEndTime()); long pauseTime = gcEvent.getPauseDuration(); - String collectorName = gcNotifInfo.getGcName(); + String collectorName = gcNotificationInfo.getGcName(); long serverStartTime = ManagementFactory.getRuntimeMXBean().getStartTime(); long timestamp = gcInfo.getStartTime() + serverStartTime; - String cause = gcNotifInfo.getGcCause(); - JVMStatisticsEventsProtos.GCStatisticsData.Builder builder = JVMStatisticsEventsProtos.GCStatisticsData.newBuilder(); + String cause = gcNotificationInfo.getGcCause(); + GCStatisticsData.Builder builder = GCStatisticsData.newBuilder(); builder.setPauseTime(pauseTime); - builder.setGcPauseRatio1Min((float) computeTotalPauseTime(gcEvents, gcEvent) / MILLIS_MINUTE * 100); - gcEvents.add(gcEvent); + builder.setGcPauseRatio1Min((float) computeTotalPauseTime(GC_EVENTS, gcEvent) / MILLIS_MINUTE * 100); + GC_EVENTS.add(gcEvent); builder.setCollectorName(collectorName); builder.setCause(cause); @@ -49,28 +52,34 @@ static void handleHSNotification(Notification notification, Object handback) { MemoryUsage before = memoryUsageBeforeGc.get(entry.getKey()); MemoryUsage after = entry.getValue(); switch (MXBeanHelper.normalizeName(entry.getKey())) { - case MXBeanHelper.MEMORY_POOL_CODE_HEADER: + case MEMORY_POOL_CODE_HEADER: // Java 8 only builder.setCodeBefore(before.getUsed()); builder.setCodeAfter(after.getUsed()); break; - case MXBeanHelper.MEMORY_POOL_PERM_HEADER: - case MXBeanHelper.MEMORY_POOL_METASPACE_HEADER: + case MEMORY_POOL_CODE_HEAP_PROFILED_NMETHODS_HEADER: // Java 9+ only + case MEMORY_POOL_CODE_HEAP_NON_PROFILED_NMETHODS_HEADER: // Java 9+ only + case MEMORY_POOL_CODE_HEAP_NON_NMETHODS_HEADER: // Java 9+ only + builder.setCodeBefore(builder.getCodeBefore() + before.getUsed()); + builder.setCodeAfter(builder.getCodeAfter() + after.getUsed()); + break; + case MEMORY_POOL_PERM_HEADER: + case MEMORY_POOL_METASPACE_HEADER: builder.setMetaspaceBefore(before.getUsed()); builder.setMetaspaceAfter(after.getUsed()); break; - case MXBeanHelper.MEMORY_POOL_EDEN_HEADER: + case MEMORY_POOL_EDEN_HEADER: builder.setEdenBefore(before.getUsed()); builder.setEdenAfter(after.getUsed()); break; - case MXBeanHelper.MEMORY_POOL_SURVIVOR_HEADER: + case MEMORY_POOL_SURVIVOR_HEADER: builder.setSurvivorBefore(before.getUsed()); builder.setSurvivorAfter(after.getUsed()); break; - case MXBeanHelper.MEMORY_POOL_OLD_HEADER: + case MEMORY_POOL_OLD_HEADER: builder.setOldBefore(before.getUsed()); builder.setOldAfter(after.getUsed()); break; - case MXBeanHelper.MEMORY_POOL_COMPRESSEDCLASSPACE_HEADER: + case MEMORY_POOL_COMPRESSEDCLASSPACE_HEADER: // ignore break; default: diff --git a/jvm-statistics/src/test/java/com/criteo/hadoop/garmadon/jvm/JVMStatisticsTest.java b/jvm-statistics/src/test/java/com/criteo/hadoop/garmadon/jvm/JVMStatisticsTest.java index 3b661f94..9fe0114e 100644 --- a/jvm-statistics/src/test/java/com/criteo/hadoop/garmadon/jvm/JVMStatisticsTest.java +++ b/jvm-statistics/src/test/java/com/criteo/hadoop/garmadon/jvm/JVMStatisticsTest.java @@ -1,5 +1,6 @@ package com.criteo.hadoop.garmadon.jvm; +import com.criteo.hadoop.garmadon.jvm.utils.JavaRuntime; import org.junit.Assert; import org.junit.Test; @@ -10,28 +11,75 @@ import java.util.regex.Pattern; public class JVMStatisticsTest { - private static final Pattern JVMSTATS_PATTERN = Pattern.compile("gc\\(.*\\)\\[count=\\d+, time=\\d+\\], gc\\(.*\\)\\[count=\\d+, time=\\d+\\], " + - "heap\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+\\], " + - "nonheap\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+\\], " + - "code\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+\\], " + - "metaspace\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+\\], " + - "compressedclassspace\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+\\], " + - "eden\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+\\], " + - "survivor\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+\\], " + - "old\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+\\], " + - "compile\\[count=\\d+, time=\\d+, invalidated=\\d+, failed=\\d+, threads=\\d+\\], " + - "threads\\[count=\\d+, daemon=\\d+, total=\\d+, internal=\\d+\\], " + - "class\\[loaded=\\d+, unloaded=\\d+, initialized=\\d+, loadtime=\\d+, inittime=\\d+, veriftime=\\d+\\], " + - "os\\[%loadavg=\\d+\\.\\d+, physicalfree=\\d+, physicaltotal=\\d+, swapfree=\\d+, swaptotal=\\d+, virtual=\\d+\\], " + - "cpu\\[cores=\\d+, %load=\\d+\\.\\d+\\], " + - "process\\[threads=\\d+, rss=\\d+, vsz=\\d+, %user=\\d+\\.\\d+, %sys=\\d+\\.\\d+, read=\\d+, written=\\d+.*\\], " + - "safepoints\\[count=\\d+, synctime=\\d+, totaltime=\\d+\\], " + - "synclocks\\[contendedlockattempts=\\d+, deflations=\\d+, futilewakeups=\\d+, inflations=\\d+, monextant=\\d+, notifications=\\d+, parks=\\d+\\].*"); - private static final Pattern GCSTATS_PATTERN = Pattern.compile(".* occurred at \\d+-\\d+-\\d+ \\d+:\\d+:\\d+.\\d+, took \\d+ms \\(System\\.gc\\(\\)\\) (eden|survivor|old)\\[[-+]\\d+\\]\\(\\d+->\\d+\\) (eden|survivor|old)\\[[-+]\\d+\\]\\(\\d+->\\d+\\).*"); - private static final Pattern MACHINESTATS_PATTERN = Pattern.compile("machinecpu\\[%user=\\d+\\.\\d+, %nice=\\d+\\.\\d+, %sys=\\d+\\.\\d+, %idle=\\d+\\.\\d+, %iowait=\\d+\\.\\d+, %irq=\\d+\\.\\d+, %softirq=\\d+\\.\\d+, %core0=\\d+\\.\\d+.*\\], memory\\[swap=\\d+, physical=\\d+\\], network\\[.*_rx=\\d+, .*_tx=\\d+, .*_pktrx=\\d+, .*_pkttx=\\d+, .*_errin=\\d+, .*_errout=\\d+.*\\], disk\\[.*_reads=\\d+, .*_readbytes=\\d+, .*_writes=\\d+, .*_writebytes=\\d+.*\\]"); + private static final Pattern JVM_8_STATS_PATTERN = Pattern.compile( + "gc\\(.*\\)\\[count=\\d+, time=\\d+], gc\\(.*\\)\\[count=\\d+, time=\\d+], " + + "heap\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "nonheap\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "code\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "metaspace\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "compressedclassspace\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "eden\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "survivor\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "old\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "compile\\[count=\\d+, time=\\d+, invalidated=\\d+, failed=\\d+, threads=\\d+], " + + "threads\\[count=\\d+, daemon=\\d+, total=\\d+, internal=\\d+], " + + "class\\[loaded=\\d+, unloaded=\\d+, initialized=\\d+, loadtime=\\d+, inittime=\\d+, veriftime=\\d+], " + + "os\\[%loadavg=\\d+\\.\\d+, physicalfree=\\d+, physicaltotal=\\d+, swapfree=\\d+, swaptotal=\\d+, virtual=\\d+], " + + "cpu\\[cores=\\d+, %load=\\d+\\.\\d+], " + + "process\\[threads=\\d+, rss=\\d+, vsz=\\d+, %user=\\d+\\.\\d+, %sys=\\d+\\.\\d+, read=\\d+, written=\\d+.*], " + + "safepoints\\[count=\\d+, synctime=\\d+, totaltime=\\d+], " + + "synclocks\\[contendedlockattempts=\\d+, deflations=\\d+, futilewakeups=\\d+, inflations=\\d+, monextant=\\d+, notifications=\\d+, parks=\\d+].*" + ); - private CountDownLatch latch = new CountDownLatch(1); - private AtomicBoolean isMatches = new AtomicBoolean(); + /** + * Example:
+     * gc(G1 Young Generation)[count=1, time=4], gc(G1 Old Generation)[count=0, time=0],
+     * heap[used=57512, committed=524288, init=524288, max=524288],
+     * nonheap[used=24389, committed=28480, init=7488, max=0],
+     * CodeHeap 'non-nmethods'[used=1234, committed=2496, init=2496, max=5700], metaspace[used=17129, committed=17792, init=0, max=0],
+     * metaspace[used=17129, committed=17792, init=0, max=0]
+     * CodeHeap 'profiled nmethods'[used=3748, committed=3776, init=2496, max=120028],
+     * compressedclassspace[used=1749, committed=1920, init=0, max=1048576],
+     * eden[used=53248, committed=326656, init=27648, max=0],
+     * old[used=168, committed=193536, init=496640, max=524288],
+     * survivor[used=4096, committed=4096, init=0, max=0],
+     * CodeHeap 'non-profiled nmethods'[used=526, committed=2496, init=2496, max=120032],
+     * compile[count=1554, time=1637, invalidated=0, failed=0, threads=4],
+     * threads[count=9, daemon=5, total=9, internal=20],
+     * class[loaded=2668, unloaded=0, initialized=2115, loadtime=1135, inittime=546, veriftime=293],
+     * os[%loadavg=28.0, physicalfree=57976, physicaltotal=33554432, swapfree=780288, swaptotal=6291456, virtual=37905728],
+     * cpu[cores=12, %load=14.524648],
+     * process[threads=36, rss=173312, vsz=37905728, %user=22.0, %sys=2.0, read=0, written=0],
+     * safepoints[count=146, synctime=1, totaltime=17],
+     * synclocks[contendedlockattempts=2, deflations=303, futilewakeups=0, inflations=305, monextant=2, notifications=3, parks=5]
+     * 
+ */ + private static final Pattern JVM_9_STATS_PATTERN = Pattern.compile( + "gc\\(.*\\)\\[count=\\d+, time=\\d+], gc\\(.*\\)\\[count=\\d+, time=\\d+], " + + "heap\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "nonheap\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "CodeHeap 'non-nmethods'\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "metaspace\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "CodeHeap 'profiled nmethods'\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "compressedclassspace\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "eden\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "old\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "survivor\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "CodeHeap 'non-profiled nmethods'\\[used=\\d+, committed=\\d+, init=\\d+, max=\\d+], " + + "compile\\[count=\\d+, time=\\d+, invalidated=\\d+, failed=\\d+, threads=\\d+], " + + "threads\\[count=\\d+, daemon=\\d+, total=\\d+, internal=\\d+], " + + "class\\[loaded=\\d+, unloaded=\\d+, initialized=\\d+, loadtime=\\d+, inittime=\\d+, veriftime=\\d+], " + + "os\\[%loadavg=\\d+\\.\\d+, physicalfree=\\d+, physicaltotal=\\d+, swapfree=\\d+, swaptotal=\\d+, virtual=\\d+], " + + "cpu\\[cores=\\d+, %load=\\d+\\.\\d+], " + + "process\\[threads=\\d+, rss=\\d+, vsz=\\d+, %user=\\d+\\.\\d+, %sys=\\d+\\.\\d+, read=\\d+, written=\\d+.*], " + + "safepoints\\[count=\\d+, synctime=\\d+, totaltime=\\d+], " + + "synclocks\\[contendedlockattempts=\\d+, deflations=\\d+, futilewakeups=\\d+, inflations=\\d+, monextant=\\d+, notifications=\\d+, parks=\\d+].*" + ); + private static final Pattern GCSTATS_PATTERN = Pattern.compile(".* occurred at \\d+-\\d+-\\d+ \\d+:\\d+:\\d+.\\d+, took \\d+ms \\(System\\.gc\\(\\)\\) {2}(eden|survivor|old)\\[[-+]\\d+]\\(\\d+->\\d+\\) (eden|survivor|old)\\[[-+]\\d+]\\(\\d+->\\d+\\).*"); + private static final Pattern MACHINESTATS_PATTERN = Pattern.compile("machinecpu\\[%user=\\d+\\.\\d+, %nice=\\d+\\.\\d+, %sys=\\d+\\.\\d+, %idle=\\d+\\.\\d+, %iowait=\\d+\\.\\d+, %irq=\\d+\\.\\d+, %softirq=\\d+\\.\\d+, %core0=\\d+\\.\\d+.*], memory\\[swap=\\d+, physical=\\d+], network\\[.*_rx=\\d+, .*_tx=\\d+, .*_pktrx=\\d+, .*_pkttx=\\d+, .*_errin=\\d+, .*_errout=\\d+.*], disk\\[.*_reads=\\d+, .*_readbytes=\\d+, .*_writes=\\d+, .*_writebytes=\\d+.*]"); + + private final CountDownLatch latch = new CountDownLatch(1); + private final AtomicBoolean isMatches = new AtomicBoolean(); private volatile String logLine; @Test @@ -88,7 +136,8 @@ public void delayStart() throws InterruptedException { private void assertJVMStatsLog(Long timestamp, String s) { logLine = s; - isMatches.set(JVMSTATS_PATTERN.matcher(s).matches()); + Pattern pattern = JavaRuntime.getVersion() == 8 ? JVM_8_STATS_PATTERN : JVM_9_STATS_PATTERN; + isMatches.set(pattern.matcher(s).matches()); latch.countDown(); } @@ -103,4 +152,4 @@ private void assertMachineStatsLog(Long timestamp, String s) { isMatches.set(MACHINESTATS_PATTERN.matcher(s).matches()); latch.countDown(); } -} \ No newline at end of file +} diff --git a/jvm-statistics/src/test/java/com/criteo/hadoop/garmadon/jvm/utils/JavaRuntime.java b/jvm-statistics/src/test/java/com/criteo/hadoop/garmadon/jvm/utils/JavaRuntime.java new file mode 100644 index 00000000..afd29de1 --- /dev/null +++ b/jvm-statistics/src/test/java/com/criteo/hadoop/garmadon/jvm/utils/JavaRuntime.java @@ -0,0 +1,55 @@ +package com.criteo.hadoop.garmadon.jvm.utils; + +public final class JavaRuntime { + + private static final Version VERSION = parseVersion(System.getProperty("java.version")); + + private JavaRuntime() { + } + + public static int getVersion() throws RuntimeException { + if (VERSION.versionNumber == -1) { + throw new RuntimeException("Could not parse Java version.", VERSION.parsingError); + } + return VERSION.versionNumber; + } + + static Version parseVersion(String version) { + try { + int versionNumber; + if (version.startsWith("1.")) { + versionNumber = Integer.parseInt(version.substring(2, 3)); + } else { + int dot = version.indexOf("."); + versionNumber = Integer.parseInt(version.substring(0, dot)); + } + return new Version(versionNumber); + } catch (RuntimeException e) { + return new Version(e); + } + } + + static final class Version { + + private final int versionNumber; + private final RuntimeException parsingError; + + private Version(int versionNumber) { + this.versionNumber = versionNumber; + this.parsingError = null; + } + + private Version(RuntimeException parsingError) { + this.versionNumber = -1; + this.parsingError = parsingError; + } + + public int getVersionNumber() { + return versionNumber; + } + + public RuntimeException getParsingError() { + return parsingError; + } + } +} diff --git a/jvm-statistics/src/test/java/com/criteo/hadoop/garmadon/jvm/utils/JavaRuntimeTest.java b/jvm-statistics/src/test/java/com/criteo/hadoop/garmadon/jvm/utils/JavaRuntimeTest.java new file mode 100644 index 00000000..4ddb97a0 --- /dev/null +++ b/jvm-statistics/src/test/java/com/criteo/hadoop/garmadon/jvm/utils/JavaRuntimeTest.java @@ -0,0 +1,31 @@ +package com.criteo.hadoop.garmadon.jvm.utils; + +import junit.framework.TestCase; + +import static com.criteo.hadoop.garmadon.jvm.utils.JavaRuntime.parseVersion; +import static org.assertj.core.api.Assertions.*; + +public class JavaRuntimeTest extends TestCase { + public void test_parse_1_8_x_as_8() { + JavaRuntime.Version version = parseVersion("1.8.0_362"); + assertThat(version.getVersionNumber()).isEqualTo(8); + assertThat(version.getParsingError()).isNull(); + } + + public void test_parse_11_x_as_11() { + JavaRuntime.Version version = parseVersion("11.0.16"); + assertThat(version.getVersionNumber()).isEqualTo(11); + assertThat(version.getParsingError()).isNull(); + } + + public void test_parsing_error() { + JavaRuntime.Version version = parseVersion("ABC"); + assertThat(version.getVersionNumber()).isEqualTo(-1); + assertThat(version.getParsingError()).isNotNull(); + } + + public void test_getVersion() { + assertThat(JavaRuntime.getVersion()).isGreaterThanOrEqualTo(8); + } + +} diff --git a/jvm-statistics/src/test/java/com/criteo/hadoop/garmadon/jvm/utils/package-info.java b/jvm-statistics/src/test/java/com/criteo/hadoop/garmadon/jvm/utils/package-info.java new file mode 100644 index 00000000..6925e19d --- /dev/null +++ b/jvm-statistics/src/test/java/com/criteo/hadoop/garmadon/jvm/utils/package-info.java @@ -0,0 +1,4 @@ +/** + * Utilities + */ +package com.criteo.hadoop.garmadon.jvm.utils; diff --git a/schema/src/main/protobuf/jvm_statistics_event.proto b/schema/src/main/protobuf/jvm_statistics_event.proto index 6dfad45b..13376bb6 100644 --- a/schema/src/main/protobuf/jvm_statistics_event.proto +++ b/schema/src/main/protobuf/jvm_statistics_event.proto @@ -27,9 +27,13 @@ message GCStatisticsData { int64 survivor_after = 7; int64 old_before = 8; int64 old_after = 9; + // Normally this is a Java 8 field only. So in Java 9+ this is the precomputed sum of + // code_heap_profiled_nmethods_before, code_heap_non_profiled_nmethods_before and code_heap_non_nmethods_before. int64 code_before = 10; + // Normally this is a Java 8 field only. So in Java 9+ this is the precomputed sum + // of code_heap_profiled_nmethods_after, code_heap_non_profiled_nmethods_after and code_heap_non_nmethods_after. int64 code_after = 11; int64 metaspace_before = 12; int64 metaspace_after = 13; float gc_pause_ratio_1_min = 14; -} \ No newline at end of file +}