criteo · jbkt · Mar 21, 2024
diff --git a/jvm-statistics/pom.xml b/jvm-statistics/pom.xml
@@ -51,5 +51,11 @@
             <version>${protobuf.version}</version>
             <scope>test</scope>
         </dependency>
+        <dependency>
+            <groupId>org.assertj</groupId>
+            <artifactId>assertj-core</artifactId>
+            <version>3.11.1</version>
+            <scope>test</scope>
+        </dependency>
     </dependencies>
 </project>
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
@@ -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
@@ -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,31 +14,35 @@
 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<GcEvent> gcEvents = new ArrayList<>();
+    private static final List<GcEvent> GC_EVENTS = new ArrayList<>();
 
 
     public ProtobufGCNotifications() {
         super(getNotificationListener());
     }
 
     static void handleHSNotification(Notification notification, Object handback) {
-        BiConsumer<Long, JVMStatisticsEventsProtos.GCStatisticsData> printer = (BiConsumer<Long, JVMStatisticsEventsProtos.GCStatisticsData>) handback;
-        GarbageCollectionNotificationInfo gcNotifInfo = GarbageCollectionNotificationInfo.from((CompositeData) notification.getUserData());
-        GcInfo gcInfo = gcNotifInfo.getGcInfo();
+        BiConsumer<Long, GCStatisticsData> printer = (BiConsumer<Long, GCStatisticsData>) 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
@@ -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: <pre>
+     * 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]
+     * </pre>
+     */
+    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();
     }
-}
+}
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
@@ -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
@@ -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
@@ -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
@@ -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;
-}
+}