#204 improve gc event detection for G1 event names containing ()

Author: chewiebug

src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderTools.java

@@ -82,11 +82,15 @@ public ExtendedType parseTypeWithCause(String typeName) {
 
         AbstractGCEvent.Type gcType = AbstractGCEvent.Type.lookup(lookupTypeName);
         // the gcType may be null because there was a PrintGCCause flag enabled - if so, reparse it with the first parentheses set stripped
-        if (gcType == null) {
+        while (gcType == null && (lookupTypeName.contains("(") && lookupTypeName.contains(")"))) {
             // try to parse it again with the parentheses removed
             Matcher parenthesesMatcher = parenthesesPattern.matcher(lookupTypeName);
             if (parenthesesMatcher.find()) {
-                gcType = AbstractGCEvent.Type.lookup(parenthesesMatcher.replaceFirst(""));
+                lookupTypeName = parenthesesMatcher.replaceFirst("");
+                gcType = AbstractGCEvent.Type.lookup(lookupTypeName);
+            } else {
+                // is expected to never happen...
+                logger.warning("parenthesisMatcher does not match for '" + lookupTypeName + "', allthough string contains '(' + ')'");
             }
         }
 

src/main/java/com/tagtraum/perf/gcviewer/model/AbstractGCEvent.java

@@ -660,7 +660,6 @@ public String toString() {
         public static final Type UJL_CMS_CONCURRENT_OLD = new Type("Old", Generation.TENURED, Concurrency.CONCURRENT, GcPattern.GC_MEMORY);
 
         // unified jvm logging g1 event types
-        public static final Type UJL_G1_PAUSE_YOUNG = new Type("Pause Young (G1 Evacuation Pause)", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_MEMORY_PAUSE);
         public static final Type UJL_G1_PAUSE_MIXED = new Type("Pause Mixed", Generation.TENURED, Concurrency.SERIAL, GcPattern.GC_MEMORY_PAUSE);
         public static final Type UJL_G1_TO_SPACE_EXHAUSTED = new Type("To-space exhausted", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC);
         public static final Type UJL_G1_CONCURRENT_CYCLE = new Type("Concurrent Cycle", Generation.TENURED, Concurrency.CONCURRENT, GcPattern.GC_PAUSE);

src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLG1.java

@@ -221,7 +221,7 @@ public void testParseGcWithPhases() throws Exception  {
 
         assertThat("number of warnings", handler.getCount(), is(0));
         assertThat("number of events", model.size(), is(1));
-        assertThat("event type", model.get(0).getExtendedType().getType(), is(Type.UJL_G1_PAUSE_YOUNG));
+        assertThat("event type", model.get(0).getExtendedType().getType(), is(Type.UJL_PAUSE_YOUNG));
         assertThat("event pause", model.get(0).getPause(), closeTo(0.007033, 0.0000001));
 
         assertThat("phases", model.getGcEventPhases().size(), is(4));

src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLG1JDK11.java

@@ -11,6 +11,7 @@
 
 import com.tagtraum.perf.gcviewer.UnittestHelper;
 import com.tagtraum.perf.gcviewer.UnittestHelper.FOLDER;
+import com.tagtraum.perf.gcviewer.model.AbstractGCEvent.Type;
 import com.tagtraum.perf.gcviewer.model.GCModel;
 import com.tagtraum.perf.gcviewer.model.GCResource;
 import com.tagtraum.perf.gcviewer.model.GcResourceFile;
@@ -131,7 +132,36 @@ public void testFullGcWithPhases() throws Exception {
         assertThat("number of warnings", handler.getCount(), is(0));
         assertThat("number of events", model.size(), is(1));
         assertThat("total heap", model.get(0).getTotal(), is(128 * 1024));
-
     }
 
+    @Test
+    public void testPauseYoungConcurrentStartMetadataGcThreshold() throws Exception {
+        TestLogHandler handler = new TestLogHandler();
+        handler.setLevel(Level.WARNING);
+        GCResource gcResource = new GcResourceFile("byteArray");
+        gcResource.getLogger().addHandler(handler);
+        InputStream in = new ByteArrayInputStream(
+                ("[1.459s][info][gc,start      ] GC(1) Pause Young (Concurrent Start) (Metadata GC Threshold)\n" +
+                "[1.459s][info][gc,task       ] GC(1) Using 8 workers of 8 for evacuation\n" +
+                "[1.464s][info][gc,phases     ] GC(1)   Pre Evacuate Collection Set: 0.0ms\n" +
+                "[1.464s][info][gc,phases     ] GC(1)   Evacuate Collection Set: 4.1ms\n" +
+                "[1.464s][info][gc,phases     ] GC(1)   Post Evacuate Collection Set: 1.1ms\n" +
+                "[1.464s][info][gc,phases     ] GC(1)   Other: 0.4ms\n" +
+                "[1.464s][info][gc,heap       ] GC(1) Eden regions: 8->0(38)\n" +
+                "[1.465s][info][gc,heap       ] GC(1) Survivor regions: 3->1(3)\n" +
+                "[1.465s][info][gc,heap       ] GC(1) Old regions: 4->7\n" +
+                "[1.465s][info][gc,heap       ] GC(1) Humongous regions: 5->5\n" +
+                "[1.465s][info][gc,metaspace  ] GC(1) Metaspace: 20599K->20599K(1069056K)\n" +
+                "[1.465s][info][gc            ] GC(1) Pause Young (Concurrent Start) (Metadata GC Threshold) 19M->12M(256M) 5.774ms\n" +
+                "[1.465s][info][gc,cpu        ] GC(1) User=0.03s Sys=0.00s Real=0.00s\n")
+                    .getBytes());
+
+        DataReader reader = new DataReaderUnifiedJvmLogging(gcResource, in);
+        GCModel model = reader.read();
+
+        assertThat("number of warnings", handler.getCount(), is(0));
+        assertThat("number of events", model.size(), is(1));
+        assertThat("event type", model.get(0).getExtendedType().getType(), is(Type.UJL_PAUSE_YOUNG));
+        assertThat("total heap", model.get(0).getTotal(), is(256 * 1024));
+    }
 }