From 2a2535c048f0372a423e90828cd8f7f3aa5245ba Mon Sep 17 00:00:00 2001
From: chewiebug <jwu@gmx.ch>
Date: Mon, 10 Jun 2019 18:17:46 +0200
Subject: [PATCH] #216 also support parsing of phases for Serial, Parallel,
 CMS, G1 and Shenandoah collectors

---
 .../imp/DataReaderUnifiedJvmLogging.java      | 26 +++++++++--
 .../perf/gcviewer/model/AbstractGCEvent.java  | 18 ++++++++
 .../perf/gcviewer/UnittestHelper.java         |  3 +-
 .../gcviewer/imp/TestDataReaderUJLCMS.java    | 39 ++++++++++++++++
 .../gcviewer/imp/TestDataReaderUJLG1.java     | 40 ++++++++++++++++
 .../imp/TestDataReaderUJLParallel.java        | 46 +++++++++++++++++++
 .../gcviewer/imp/TestDataReaderUJLSerial.java | 31 +++++++++++++
 .../imp/TestDataReaderUJLShenandoah.java      | 39 ++++++++++++++++
 .../gcviewer/imp/TestDataReaderUJLZGC.java    | 46 +++++++++++--------
 .../SampleShenandoahAllocationFailure.txt     |  4 +-
 10 files changed, 265 insertions(+), 27 deletions(-)

diff --git a/src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderUnifiedJvmLogging.java b/src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderUnifiedJvmLogging.java
index 1b8073b0..a7f0c249 100644
--- a/src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderUnifiedJvmLogging.java
+++ b/src/main/java/com/tagtraum/perf/gcviewer/imp/DataReaderUnifiedJvmLogging.java
@@ -46,6 +46,7 @@
  * For more information about Shenandoah see: <a href="https://wiki.openjdk.java.net/display/shenandoah/Main">Shenandoah Wiki at OpenJDK</a>
  */
 public class DataReaderUnifiedJvmLogging extends AbstractDataReader {
+    // TODO also parse "Allocation Stall (main)" events
 
     // matches the whole line and extracts decorators from it (decorators always appear between [] and are independent of the gc algorithm being logged)
     // Input: [0.693s][info][gc           ] GC(0) Pause Init Mark 1.070ms
@@ -58,7 +59,7 @@ public class DataReaderUnifiedJvmLogging extends AbstractDataReader {
     // Regex: ^(?:\[(?<time>[0-9-T:.+]*)])?(?:\[(?<uptime>[^s]*)s])?\[(?<level>[^]]+)]\[(?:(?<tags>[^] ]+)[ ]*)][ ]GC\((?<gcnumber>[0-9]+)\)[ ](?<type>([-.a-zA-Z ()]+|[a-zA-Z1 ()]+))(?:(?:[ ](?<tail>[0-9]{1}.*))|$)
     //   note for the <type> part: easiest would have been to use [^0-9]+, but the G1 events don't fit there, because of the number in their name
     private static final Pattern PATTERN_DECORATORS = Pattern.compile(
-            "^(?:\\[(?<time>[0-9-T:.+]*)])?(?:\\[(?<uptime>[^s]*)s])?\\[(?<level>[^]]+)]\\[(?:(?<tags>[^] ]+)[ ]*)][ ]GC\\((?<gcnumber>[0-9]+)\\)[ ](?<type>[-.a-zA-Z: ()]+|[a-zA-Z1 ()]+)(?:(?:[ ](?<tail>[0-9]{1}.*))|$)"
+            "^(?:\\[(?<time>[0-9-T:.+]*)])?(?:\\[(?<uptime>[^s]*)s])?\\[(?<level>[^]]+)]\\[(?:(?<tags>[^] ]+)[ ]*)][ ]GC\\((?<gcnumber>[0-9]+)\\)[ ](?<type>(?:Phase [0-9]{1}: [a-zA-Z ]+)|[-.a-zA-Z: ()]+|[a-zA-Z1 ()]+)(?:(?:[ ](?<tail>[0-9]{1}.*))|$)"
     );
     private static final String GROUP_DECORATORS_TIME = "time";
     private static final String GROUP_DECORATORS_UPTIME = "uptime";
@@ -75,7 +76,7 @@ public class DataReaderUnifiedJvmLogging extends AbstractDataReader {
     private static final String PATTERN_MEMORY_STRING = "(([0-9]+)([BKMG])->([0-9]+)([BKMG])\\(([0-9]+)([BKMG])\\))";
 
     private static final String PATTERN_HEAP_MEMORY_PERCENTAGE_STRING = "(([0-9]+)([BKMG])[ ](\\([0-9]+%\\)))";
-    private static final String PATTERN_MEMORY_PERCENTAGE_STRING = "(([0-9]+)([BKMG])\\([0-9]+%\\)->([0-9]+)([BKMG])\\([0-9]+%\\))";
+    private static final String PATTERN_MEMORY_PERCENTAGE_STRING = "(([0-9]+)([BKMG])\\(([0-9]+)%\\)->([0-9]+)([BKMG])\\(([0-9]+)%\\))";
 
     // Input: 1.070ms
     // Group 1: 1.070
@@ -134,8 +135,10 @@ public class DataReaderUnifiedJvmLogging extends AbstractDataReader {
     private static final int GROUP_MEMORY_PERCENTAGE = 1;
     private static final int GROUP_MEMORY_PERCENTAGE_BEFORE = 2;
     private static final int GROUP_MEMORY_PERCENTAGE_BEFORE_UNIT = 3;
-    private static final int GROUP_MEMORY_PERCENTAGE_AFTER = 4;
-    private static final int GROUP_MEMORY_PERCENTAGE_AFTER_UNIT = 5;
+    private static final int GROUP_MEMORY_PERCENTAGE_BEFORE_PERCENTAGE = 4;
+    private static final int GROUP_MEMORY_PERCENTAGE_AFTER = 5;
+    private static final int GROUP_MEMORY_PERCENTAGE_AFTER_UNIT = 6;
+    private static final int GROUP_MEMORY_PERCENTAGE_AFTER_PERCENTAGE = 7;
 
     // Input: 300M (1%)
     // Group 1: 300M (1%)
@@ -251,7 +254,16 @@ private AbstractGCEvent<?> handleTagGcPhasesTail(ParseContext context, AbstractG
         AbstractGCEvent<?> parentEvent = context.getPartialEventsMap().get(event.getNumber() + "");
         if (parentEvent instanceof GCEventUJL) {
             returnEvent = parseTail(context, returnEvent, tail);
-            parentEvent.addPhase(returnEvent);
+            // ZGC logs concurrent events as phases of one gc event -> don't add them to the phases list
+            // to comply with the current GCViewer implementation, which expects concurrent events in a separate list.
+            // If later insights suggest keeping the concurrent events as part of one gc event, GCModel#add and
+            // maybe some renderers need to be adjusted
+            if (returnEvent.isConcurrent()) {
+                return returnEvent;
+            } else {
+                parentEvent.addPhase(returnEvent);
+                return null;
+            }
         }
 
         return null;
@@ -478,6 +490,10 @@ private void setMemoryWithPercentage(AbstractGCEvent<?> event, Matcher matcher)
                 Integer.parseInt(matcher.group(GROUP_MEMORY_PERCENTAGE_BEFORE)), matcher.group(GROUP_MEMORY_PERCENTAGE_BEFORE_UNIT).charAt(0), matcher.group(GROUP_MEMORY_PERCENTAGE)));
         event.setPostUsed(getDataReaderTools().getMemoryInKiloByte(
                 Integer.parseInt(matcher.group(GROUP_MEMORY_PERCENTAGE_AFTER)), matcher.group(GROUP_MEMORY_PERCENTAGE_AFTER_UNIT).charAt(0), matcher.group(GROUP_MEMORY_PERCENTAGE)));
+
+        if (event.getTotal() == 0 && Integer.parseInt(matcher.group(GROUP_MEMORY_PERCENTAGE_BEFORE_PERCENTAGE)) != 0) {
+            event.setTotal(event.getPostUsed() / Integer.parseInt(matcher.group(GROUP_MEMORY_PERCENTAGE_AFTER_PERCENTAGE)) * 100);
+        }
     }
 
     private void setDateStampIfPresent(AbstractGCEvent<?> event, String dateStampAsString) {
diff --git a/src/main/java/com/tagtraum/perf/gcviewer/model/AbstractGCEvent.java b/src/main/java/com/tagtraum/perf/gcviewer/model/AbstractGCEvent.java
index 91002a51..e6d02364 100644
--- a/src/main/java/com/tagtraum/perf/gcviewer/model/AbstractGCEvent.java
+++ b/src/main/java/com/tagtraum/perf/gcviewer/model/AbstractGCEvent.java
@@ -634,6 +634,19 @@ public String toString() {
         public static final Type UJL_PAUSE_YOUNG = new Type("Pause Young", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_MEMORY_PAUSE);
         public static final Type UJL_PAUSE_FULL = new Type("Pause Full", Generation.ALL, Concurrency.SERIAL, GcPattern.GC_MEMORY_PAUSE);
 
+        // unified jvm logging serial / cms event phase types
+        public static final Type UJL_SERIAL_PHASE_MARK_LIFE_OBJECTS = new Type("Phase 1: Mark live objects", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_PAUSE);
+        public static final Type UJL_SERIAL_PHASE_COMPUTE_NEW_OBJECT_ADDRESSES = new Type("Phase 2: Compute new object addresses", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_PAUSE);
+        public static final Type UJL_SERIAL_PHASE_ADJUST_POINTERS = new Type("Phase 3: Adjust pointers", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_PAUSE);
+        public static final Type UJL_SERIAL_PHASE_MOVE_OBJECTS = new Type("Phase 4: Move objects", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_PAUSE);
+
+        // unified jvm logging parallel event phase types
+        public static final Type UJL_PARALLEL_PHASE_MARKING = new Type("Marking Phase", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_PAUSE);
+        public static final Type UJL_PARALLEL_PHASE_SUMMARY = new Type("Summary Phase", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_PAUSE);
+        public static final Type UJL_PARALLEL_PHASE_ADJUST_ROOTS = new Type("Adjust Roots", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_PAUSE);
+        public static final Type UJL_PARALLEL_PHASE_COMPACTION = new Type("Compaction Phase", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_PAUSE);
+        public static final Type UJL_PARALLEL_PHASE_POST_COMPACT = new Type("Post Compact", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_PAUSE);
+
         // unified jvm logging cms / g1 event types
         public static final Type UJL_PAUSE_INITIAL_MARK = new Type("Pause Initial Mark", Generation.TENURED, Concurrency.SERIAL, GcPattern.GC_MEMORY_PAUSE, CollectionType.CONCURRENCY_HELPER);
         public static final Type UJL_PAUSE_REMARK = new Type("Pause Remark", Generation.TENURED, Concurrency.SERIAL, GcPattern.GC_MEMORY_PAUSE, CollectionType.CONCURRENCY_HELPER);
@@ -656,6 +669,11 @@ public String toString() {
         public static final Type UJL_G1_OLD = new Type("Old regions", Generation.TENURED, Concurrency.SERIAL, GcPattern.GC_REGION);
         public static final Type UJL_G1_HUMongous = new Type("Humongous regions", Generation.TENURED, Concurrency.SERIAL, GcPattern.GC_REGION);
 
+        public static final Type UJL_G1_PHASE_PRE_EVACUATE_COLLECTION_SET = new Type("Pre Evacuate Collection Set", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_PAUSE);
+        public static final Type UJL_G1_PHASE_EVACUATE_COLLECTION_SET = new Type("Evacuate Collection Set", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_PAUSE);
+        public static final Type UJL_G1_PHASE_POST_EVACUATE_COLLECTION_SET = new Type("Post Evacuate Collection Set", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_PAUSE);
+        public static final Type UJL_G1_PHASE_OTHER = new Type("Other", Generation.YOUNG, Concurrency.SERIAL, GcPattern.GC_PAUSE);
+
         // unified jvm logging shenandoah event types
         public static final Type UJL_SHEN_INIT_MARK = new Type("Pause Init Mark", Generation.TENURED, Concurrency.SERIAL, GcPattern.GC_PAUSE);
         public static final Type UJL_SHEN_FINAL_MARK = new Type("Pause Final Mark", Generation.TENURED, Concurrency.SERIAL, GcPattern.GC_MEMORY_PAUSE);
diff --git a/src/test/java/com/tagtraum/perf/gcviewer/UnittestHelper.java b/src/test/java/com/tagtraum/perf/gcviewer/UnittestHelper.java
index 11598a28..45e9bbc1 100644
--- a/src/test/java/com/tagtraum/perf/gcviewer/UnittestHelper.java
+++ b/src/test/java/com/tagtraum/perf/gcviewer/UnittestHelper.java
@@ -141,8 +141,7 @@ public static GCModel getGCModelFromLogFile(String fileName, FOLDER folderName,
             assertThat("reader from factory", reader.getClass().getName(), is(expectedDataReaderClass.getName()));
 
             GCModel model = reader.read();
-            // TODO: add support for "[gc,phases" in all gc algorithms
-            // assertThat("number of errors", handler.getCount(), is(0));
+            assertThat("number of errors", handler.getCount(), is(0));
             return model;
         }
     }
diff --git a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLCMS.java b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLCMS.java
index 95fa2266..31138213 100644
--- a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLCMS.java
+++ b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLCMS.java
@@ -1,9 +1,13 @@
 package com.tagtraum.perf.gcviewer.imp;
 
+import static org.hamcrest.Matchers.closeTo;
 import static org.hamcrest.Matchers.is;
 import static org.junit.Assert.assertThat;
 
+import java.io.ByteArrayInputStream;
 import java.io.IOException;
+import java.io.InputStream;
+import java.util.logging.Level;
 
 import com.tagtraum.perf.gcviewer.UnittestHelper;
 import com.tagtraum.perf.gcviewer.UnittestHelper.FOLDER;
@@ -11,6 +15,8 @@
 import com.tagtraum.perf.gcviewer.model.AbstractGCEvent.Generation;
 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;
 import org.junit.Test;
 
 /**
@@ -138,4 +144,37 @@ public void parseGcAllSafepointOsCpu() throws Exception {
         assertThat("event is start of concurrent collection", concurrentMarkWithPauseEvent.isConcurrentCollectionStart(), is(true));
     }
 
+    @Test
+    public void testParseFullGcWithPhases() throws Exception  {
+        TestLogHandler handler = new TestLogHandler();
+        handler.setLevel(Level.WARNING);
+        GCResource gcResource = new GcResourceFile("byteArray");
+        gcResource.getLogger().addHandler(handler);
+        InputStream in = new ByteArrayInputStream(
+                ("[0.315s][info][gc,start     ] GC(5) Pause Full (Allocation Failure)\n" +
+                "[0.315s][info][gc           ] GC(3) Concurrent Sweep 0.817ms\n" +
+                "[0.315s][info][gc,cpu       ] GC(3) User=0.00s Sys=0.00s Real=0.00s\n" +
+                "[0.315s][info][gc,phases,start] GC(5) Phase 1: Mark live objects\n" +
+                "[0.316s][info][gc,phases      ] GC(5) Phase 1: Mark live objects 1.154ms\n" +
+                "[0.316s][info][gc,phases,start] GC(5) Phase 2: Compute new object addresses\n" +
+                "[0.317s][info][gc,phases      ] GC(5) Phase 2: Compute new object addresses 0.391ms\n" +
+                "[0.317s][info][gc,phases,start] GC(5) Phase 3: Adjust pointers\n" +
+                "[0.317s][info][gc,phases      ] GC(5) Phase 3: Adjust pointers 0.575ms\n" +
+                "[0.317s][info][gc,phases,start] GC(5) Phase 4: Move objects\n" +
+                "[0.324s][info][gc,phases      ] GC(5) Phase 4: Move objects 6.493ms\n" +
+                "[0.324s][info][gc             ] GC(5) Pause Full (Allocation Failure) 119M->33M(150M) 9.509ms\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(2));
+        assertThat("event type", model.get(1).getExtendedType().getType(), is(Type.UJL_PAUSE_FULL));
+        assertThat("event pause", model.get(1).getPause(), closeTo(0.009509, 0.0000001));
+
+        assertThat("phases", model.getGcEventPhases().size(), is(4));
+        assertThat("phase 1", model.getGcEventPhases().get(Type.UJL_SERIAL_PHASE_MARK_LIFE_OBJECTS.getName()).getSum(), closeTo(0.001154, 0.0000001));
+    }
+
 }
diff --git a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLG1.java b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLG1.java
index deee20b6..e9b0d084 100644
--- a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLG1.java
+++ b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLG1.java
@@ -1,11 +1,15 @@
 package com.tagtraum.perf.gcviewer.imp;
 
+import static org.hamcrest.Matchers.closeTo;
 import static org.hamcrest.Matchers.equalTo;
 import static org.hamcrest.Matchers.is;
 import static org.junit.Assert.assertThat;
 
+import java.io.ByteArrayInputStream;
 import java.io.IOException;
+import java.io.InputStream;
 import java.util.Iterator;
+import java.util.logging.Level;
 
 import com.tagtraum.perf.gcviewer.UnittestHelper;
 import com.tagtraum.perf.gcviewer.UnittestHelper.FOLDER;
@@ -14,6 +18,8 @@
 import com.tagtraum.perf.gcviewer.model.AbstractGCEvent.Type;
 import com.tagtraum.perf.gcviewer.model.GCEventUJL;
 import com.tagtraum.perf.gcviewer.model.GCModel;
+import com.tagtraum.perf.gcviewer.model.GCResource;
+import com.tagtraum.perf.gcviewer.model.GcResourceFile;
 import org.junit.Test;
 
 /**
@@ -189,6 +195,40 @@ public void parseGcAllSafepointOsCpuWithToSpaceExhausted() throws Exception {
         testHeapSizing(gcEventUJL.getPerm(), "metaspace", 3648, 3648, 1056768);
     }
 
+    @Test
+    public void testParseGcWithPhases() throws Exception  {
+        TestLogHandler handler = new TestLogHandler();
+        handler.setLevel(Level.WARNING);
+        GCResource gcResource = new GcResourceFile("byteArray");
+        gcResource.getLogger().addHandler(handler);
+        InputStream in = new ByteArrayInputStream(
+                ("[0.200s][info][gc,start     ] GC(0) Pause Young (G1 Evacuation Pause)\n" +
+                "[0.200s][info][gc,task      ] GC(0) Using 4 workers of 4 for evacuation\n" +
+                "[0.207s][info][gc,phases    ] GC(0)   Pre Evacuate Collection Set: 0.0ms\n" +
+                "[0.207s][info][gc,phases    ] GC(0)   Evacuate Collection Set: 6.4ms\n" +
+                "[0.207s][info][gc,phases    ] GC(0)   Post Evacuate Collection Set: 0.3ms\n" +
+                "[0.207s][info][gc,phases    ] GC(0)   Other: 0.3ms\n" +
+                "[0.207s][info][gc,heap      ] GC(0) Eden regions: 14->0(8)\n" +
+                "[0.207s][info][gc,heap      ] GC(0) Survivor regions: 0->2(2)\n" +
+                "[0.207s][info][gc,heap      ] GC(0) Old regions: 0->11\n" +
+                "[0.207s][info][gc,heap      ] GC(0) Humongous regions: 0->0\n" +
+                "[0.207s][info][gc,metaspace ] GC(0) Metaspace: 3644K->3644K(1056768K)\n" +
+                "[0.207s][info][gc           ] GC(0) Pause Young (G1 Evacuation Pause) 14M->12M(128M) 7.033ms\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("event pause", model.get(0).getPause(), closeTo(0.007033, 0.0000001));
+
+        assertThat("phases", model.getGcEventPhases().size(), is(4));
+        assertThat("phase 1", model.getGcEventPhases().get(Type.UJL_G1_PHASE_PRE_EVACUATE_COLLECTION_SET.getName() + ":").getSum(), closeTo(0.0, 0.00001));
+        assertThat("phase 2", model.getGcEventPhases().get(Type.UJL_G1_PHASE_EVACUATE_COLLECTION_SET.getName() + ":").getSum(), closeTo(0.0064, 0.00001));
+    }
+
     private void testHeapSizing(AbstractGCEvent<?> event, String testName, int expectedBefore, int expectedAfter, int expectedTotal) {
         assertThat(testName + " before", event.getPreUsed(), is(expectedBefore));
         assertThat(testName + " after", event.getPostUsed(), is(expectedAfter));
diff --git a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLParallel.java b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLParallel.java
index 6068fefc..1100b678 100644
--- a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLParallel.java
+++ b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLParallel.java
@@ -1,9 +1,13 @@
 package com.tagtraum.perf.gcviewer.imp;
 
+import static org.hamcrest.Matchers.closeTo;
 import static org.hamcrest.Matchers.is;
 import static org.junit.Assert.assertThat;
 
+import java.io.ByteArrayInputStream;
 import java.io.IOException;
+import java.io.InputStream;
+import java.util.logging.Level;
 
 import com.tagtraum.perf.gcviewer.UnittestHelper;
 import com.tagtraum.perf.gcviewer.UnittestHelper.FOLDER;
@@ -11,6 +15,8 @@
 import com.tagtraum.perf.gcviewer.model.AbstractGCEvent.Generation;
 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;
 import org.junit.Test;
 
 /**
@@ -58,6 +64,8 @@ public void parseGcAllSafepointOsCpu() throws Exception {
         assertThat("amount of gc events", model.getGCPause().getN(), is(4));
         assertThat("amount of STW Full GC pause types", model.getFullGcEventPauses().size(), is(1));
         assertThat("amount of full gc events", model.getFullGCPause().getN(), is(4));
+        assertThat("amount of phase types", model.getGcEventPhases().size(), is(5));
+        assertThat("amount of events for phase 1 types", model.getGcEventPhases().get(Type.UJL_PARALLEL_PHASE_MARKING.getName()).getN(), is(4));
         assertThat("amount of concurrent pause types", model.getConcurrentEventPauses().size(), is(0));
 
         AbstractGCEvent<?> event1 = model.get(0);
@@ -90,4 +98,42 @@ public void parseGcAllSafepointOsCpu() throws Exception {
                 false);
     }
 
+    @Test
+    public void testParseFullGcWithPhases() throws Exception  {
+        TestLogHandler handler = new TestLogHandler();
+        handler.setLevel(Level.WARNING);
+        GCResource gcResource = new GcResourceFile("byteArray");
+        gcResource.getLogger().addHandler(handler);
+        InputStream in = new ByteArrayInputStream(
+                ("[1.499s][info][gc,start     ] GC(4) Pause Full (Ergonomics)\n" +
+                "[1.499s][info][gc,phases,start] GC(4) Marking Phase\n" +
+                "[1.504s][info][gc,phases      ] GC(4) Marking Phase 4.370ms\n" +
+                "[1.504s][info][gc,phases,start] GC(4) Summary Phase\n" +
+                "[1.504s][info][gc,phases      ] GC(4) Summary Phase 0.039ms\n" +
+                "[1.504s][info][gc,phases,start] GC(4) Adjust Roots\n" +
+                "[1.507s][info][gc,phases      ] GC(4) Adjust Roots 2.971ms\n" +
+                "[1.507s][info][gc,phases,start] GC(4) Compaction Phase\n" +
+                "[1.520s][info][gc,phases      ] GC(4) Compaction Phase 13.004ms\n" +
+                "[1.520s][info][gc,phases,start] GC(4) Post Compact\n" +
+                "[1.522s][info][gc,phases      ] GC(4) Post Compact 2.222ms\n" +
+                "[1.522s][info][gc,heap        ] GC(4) PSYoungGen: 5105K->0K(38400K)\n" +
+                "[1.522s][info][gc,heap        ] GC(4) ParOldGen: 79662K->45521K(87552K)\n" +
+                "[1.522s][info][gc,metaspace   ] GC(4) Metaspace: 15031K->15031K(1062912K)\n" +
+                "[1.522s][info][gc             ] GC(4) Pause Full (Ergonomics) 82M->44M(123M) 23.271ms\n" +
+                "[1.523s][info][gc,cpu         ] GC(4) User=0.05s Sys=0.00s Real=0.02s\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_FULL));
+        assertThat("event pause", model.get(0).getPause(), closeTo(0.023271, 0.0000001));
+
+        assertThat("phases", model.getGcEventPhases().size(), is(5));
+        assertThat("phase 1", model.getGcEventPhases().get(Type.UJL_PARALLEL_PHASE_MARKING.getName()).getSum(), closeTo(0.00437, 0.0000001));
+    }
+
+
 }
diff --git a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLSerial.java b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLSerial.java
index 9698cd89..709d1737 100644
--- a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLSerial.java
+++ b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLSerial.java
@@ -127,4 +127,35 @@ public void testParseUnknownGcType() throws Exception {
         assertThat("warning message", handler.getLogRecords().get(0).getMessage(), startsWith("Failed to parse gc event ("));
     }
 
+    @Test
+    public void testParseFullGcWithPhases() throws Exception  {
+        TestLogHandler handler = new TestLogHandler();
+        handler.setLevel(Level.WARNING);
+        GCResource gcResource = new GcResourceFile("byteArray");
+        gcResource.getLogger().addHandler(handler);
+        InputStream in = new ByteArrayInputStream(
+                ("[1.145s][info][gc,start     ] GC(4) Pause Full (Allocation Failure)"
+                + "\n[1.145s][info][gc,phases,start] GC(4) Phase 1: Mark live objects"
+                + "\n[1.149s][info][gc,phases      ] GC(4) Phase 1: Mark live objects 3.978ms"
+                + "\n[1.149s][info][gc,phases,start] GC(4) Phase 2: Compute new object addresses"
+                + "\n[1.151s][info][gc,phases      ] GC(4) Phase 2: Compute new object addresses 1.245ms"
+                + "\n[1.151s][info][gc,phases,start] GC(4) Phase 3: Adjust pointers"
+                + "\n[1.153s][info][gc,phases      ] GC(4) Phase 3: Adjust pointers 2.388ms"
+                + "\n[1.153s][info][gc,phases,start] GC(4) Phase 4: Move objects"
+                + "\n[1.156s][info][gc,phases      ] GC(4) Phase 4: Move objects 3.136ms"
+                + "\n[1.157s][info][gc             ] GC(4) Pause Full (Allocation Failure) 81M->17M(92M) 11.537ms"
+                ).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_FULL));
+        assertThat("event pause", model.get(0).getPause(), closeTo(0.011537, 0.0000001));
+
+        assertThat("phases", model.getGcEventPhases().size(), is(4));
+        assertThat("phase 1", model.getGcEventPhases().get(Type.UJL_SERIAL_PHASE_MARK_LIFE_OBJECTS.getName()).getSum(), closeTo(0.003978, 0.0000001));
+    }
+
 }
diff --git a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLShenandoah.java b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLShenandoah.java
index 242d1c1e..84b1a17e 100644
--- a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLShenandoah.java
+++ b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLShenandoah.java
@@ -6,8 +6,11 @@
 import static org.hamcrest.Matchers.startsWith;
 import static org.junit.Assert.assertThat;
 
+import java.io.ByteArrayInputStream;
 import java.io.IOException;
+import java.io.InputStream;
 import java.time.ZonedDateTime;
+import java.util.logging.Level;
 
 import com.tagtraum.perf.gcviewer.UnittestHelper;
 import com.tagtraum.perf.gcviewer.UnittestHelper.FOLDER;
@@ -16,6 +19,8 @@
 import com.tagtraum.perf.gcviewer.model.ConcurrentGCEvent;
 import com.tagtraum.perf.gcviewer.model.GCEvent;
 import com.tagtraum.perf.gcviewer.model.GCModel;
+import com.tagtraum.perf.gcviewer.model.GCResource;
+import com.tagtraum.perf.gcviewer.model.GcResourceFile;
 import com.tagtraum.perf.gcviewer.util.DateHelper;
 import org.junit.Test;
 
@@ -181,4 +186,38 @@ public void parseDateTimeStamps() throws Exception {
         assertThat("generation", event2.getGeneration(), is(AbstractGCEvent.Generation.TENURED));
     }
 
+    @Test
+    public void testParseFullGcWithPhases() throws Exception {
+        TestLogHandler handler = new TestLogHandler();
+        handler.setLevel(Level.WARNING);
+        GCResource gcResource = new GcResourceFile("byteArray");
+        gcResource.getLogger().addHandler(handler);
+        InputStream in = new ByteArrayInputStream(
+                ("[1,331s][info][gc,start          ] GC(0) Pause Full (System.gc())\n" +
+                "[1,332s][info][gc,phases,start   ] GC(0) Phase 1: Mark live objects\n" +
+                "[1,334s][info][gc,stringtable    ] GC(0) Cleaned string and symbol table, strings: 1755 processed, 19 removed, symbols: 23807 processed, 0 removed\n" +
+                "[1,334s][info][gc,phases         ] GC(0) Phase 1: Mark live objects 2,911ms\n" +
+                "[1,334s][info][gc,phases,start   ] GC(0) Phase 2: Compute new object addresses\n" +
+                "[1,335s][info][gc,phases         ] GC(0) Phase 2: Compute new object addresses 0,501ms\n" +
+                "[1,335s][info][gc,phases,start   ] GC(0) Phase 3: Adjust pointers\n" +
+                "[1,336s][info][gc,phases         ] GC(0) Phase 3: Adjust pointers 1,430ms\n" +
+                "[1,336s][info][gc,phases,start   ] GC(0) Phase 4: Move objects\n" +
+                "[1,337s][info][gc,phases         ] GC(0) Phase 4: Move objects 0,619ms\n" +
+                "[1,337s][info][gc                ] GC(0) Pause Full (System.gc()) 10M->1M(128M) 5,636ms\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_FULL));
+        assertThat("event pause", model.get(0).getPause(), closeTo(0.005636, 0.0000001));
+
+        assertThat("phases", model.getGcEventPhases().size(), is(4));
+        assertThat("phase 1",
+                model.getGcEventPhases().get(Type.UJL_SERIAL_PHASE_MARK_LIFE_OBJECTS.getName()).getSum(),
+                closeTo(0.002911, 0.0000001));
+    }
+
 }
diff --git a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLZGC.java b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLZGC.java
index e2432447..25bbb79c 100644
--- a/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLZGC.java
+++ b/src/test/java/com/tagtraum/perf/gcviewer/imp/TestDataReaderUJLZGC.java
@@ -16,6 +16,15 @@
  * Test unified java logging ZGC algorithm in OpenJDK 11
  */
 public class TestDataReaderUJLZGC {
+    private static final int CONCURRENT_MARK_INDEX = 0;
+    private static final int CONCURRENT_PROCESS_REFERENCES_INDEX = 1;
+    private static final int CONCURRENT_RESET_RELOCATION_SET_INDEX = 2;
+    private static final int CONCURRENT_DESTROY_DETACHED_PAGES_INDEX = 3;
+    private static final int CONCURRENT_SELECT_RELOCATION_SET_INDEX = 4;
+    private static final int CONCURRENT_PREPARE_RELOCATION_SET_INDEX = 5;
+    private static final int CONCURRENT_RELOCATE_INDEX = 6;
+
+
     private GCModel gcAllModel;
     private GCModel gcDefaultModel;
 
@@ -37,18 +46,18 @@ public void tearDown() {
 
     @Test
     public void testGcAll() {
-        assertThat("size", gcAllModel.size(), is(1));
+        assertThat("size", gcAllModel.size(), is(8));
         assertThat("amount of gc event types", gcAllModel.getGcEventPauses().size(), is(1));
         assertThat("amount of gc events", gcAllModel.getGCPause().getN(), is(1));
         assertThat("amount of full gc event types", gcAllModel.getFullGcEventPauses().size(), is(0));
-        assertThat("amount of gc phases event types", gcAllModel.getGcEventPhases().size(), is(10));
+        assertThat("amount of gc phases event types", gcAllModel.getGcEventPhases().size(), is(3));
         assertThat("amount of full gc events", gcAllModel.getFullGCPause().getN(), is(0));
-        assertThat("amount of concurrent pause types", gcAllModel.getConcurrentEventPauses().size(), is(0));
+        assertThat("amount of concurrent pause types", gcAllModel.getConcurrentEventPauses().size(), is(7));
     }
 
     @Test
     public void testGcAllGarbageCollection() {
-        AbstractGCEvent<?> garbageCollectionEvent = gcAllModel.get(0);
+        AbstractGCEvent<?> garbageCollectionEvent = gcAllModel.get(gcAllModel.size()-1);
         UnittestHelper.testMemoryPauseEvent(garbageCollectionEvent,
                 "Garbage Collection",
                 AbstractGCEvent.Type.UJL_ZGC_GARBAGE_COLLECTION,
@@ -60,7 +69,7 @@ public void testGcAllGarbageCollection() {
 
     @Test
     public void testGcAllPauseMarkStart() {
-        AbstractGCEvent<?> pauseMarkStartEvent = gcAllModel.get(0).getPhases().get(0);
+        AbstractGCEvent<?> pauseMarkStartEvent = gcAllModel.getGCEvents().next().getPhases().get(0);
         UnittestHelper.testMemoryPauseEvent(pauseMarkStartEvent,
                 "Pause Mark Start",
                 AbstractGCEvent.Type.UJL_ZGC_PAUSE_MARK_START,
@@ -72,7 +81,7 @@ public void testGcAllPauseMarkStart() {
 
     @Test
     public void testGcAllConcurrentMark() {
-        AbstractGCEvent<?> concurrentMarkEvent = gcAllModel.get(0).getPhases().get(1);
+        AbstractGCEvent<?> concurrentMarkEvent = gcAllModel.get(CONCURRENT_MARK_INDEX);
         UnittestHelper.testMemoryPauseEvent(concurrentMarkEvent,
                 "Concurrent Mark",
                 AbstractGCEvent.Type.UJL_ZGC_CONCURRENT_MARK,
@@ -84,7 +93,7 @@ public void testGcAllConcurrentMark() {
 
     @Test
     public void testGcAllPauseMarkEnd() {
-        AbstractGCEvent<?> pauseMarkEndEvent = gcAllModel.get(0).getPhases().get(2);
+        AbstractGCEvent<?> pauseMarkEndEvent = gcAllModel.getGCEvents().next().getPhases().get(1);
         UnittestHelper.testMemoryPauseEvent(pauseMarkEndEvent,
                 "Pause Mark End",
                 AbstractGCEvent.Type.UJL_ZGC_PAUSE_MARK_END,
@@ -96,7 +105,7 @@ public void testGcAllPauseMarkEnd() {
 
     @Test
     public void testGcAllConcurrentNonref() {
-        AbstractGCEvent<?> concurrentNonrefEvent = gcAllModel.get(0).getPhases().get(3);
+        AbstractGCEvent<?> concurrentNonrefEvent = gcAllModel.get(CONCURRENT_PROCESS_REFERENCES_INDEX);
         UnittestHelper.testMemoryPauseEvent(concurrentNonrefEvent,
                 "Concurrent Process Non-Strong References",
                 AbstractGCEvent.Type.UJL_ZGC_CONCURRENT_NONREF,
@@ -108,7 +117,7 @@ public void testGcAllConcurrentNonref() {
 
     @Test
     public void testGcAllConcurrentResetRelocSet() {
-        AbstractGCEvent<?> concurrentResetRelocSetEvent = gcAllModel.get(0).getPhases().get(4);
+        AbstractGCEvent<?> concurrentResetRelocSetEvent = gcAllModel.get(CONCURRENT_RESET_RELOCATION_SET_INDEX);
         UnittestHelper.testMemoryPauseEvent(concurrentResetRelocSetEvent,
                 "Concurrent Reset Relocation Set",
                 AbstractGCEvent.Type.UJL_ZGC_CONCURRENT_RESET_RELOC_SET,
@@ -120,7 +129,7 @@ public void testGcAllConcurrentResetRelocSet() {
 
     @Test
     public void testGcAllConcurrentDetachedPages() {
-        AbstractGCEvent<?> concurrentDetachedPagesEvent = gcAllModel.get(0).getPhases().get(5);
+        AbstractGCEvent<?> concurrentDetachedPagesEvent = gcAllModel.get(CONCURRENT_DESTROY_DETACHED_PAGES_INDEX);
         UnittestHelper.testMemoryPauseEvent(concurrentDetachedPagesEvent,
                 "Concurrent Destroy Detached Pages",
                 AbstractGCEvent.Type.UJL_ZGC_CONCURRENT_DETATCHED_PAGES,
@@ -132,7 +141,7 @@ public void testGcAllConcurrentDetachedPages() {
 
     @Test
     public void testGcAllConcurrentSelectRelocSet() {
-        AbstractGCEvent<?> concurrentSelectRelocSetEvent = gcAllModel.get(0).getPhases().get(6);
+        AbstractGCEvent<?> concurrentSelectRelocSetEvent = gcAllModel.get(CONCURRENT_SELECT_RELOCATION_SET_INDEX);
         UnittestHelper.testMemoryPauseEvent(concurrentSelectRelocSetEvent,
                 "Concurrent Select Relocation Set",
                 AbstractGCEvent.Type.UJL_ZGC_CONCURRENT_SELECT_RELOC_SET,
@@ -144,7 +153,7 @@ public void testGcAllConcurrentSelectRelocSet() {
 
     @Test
     public void testGcAllConcurrentPrepareRelocSet() {
-        AbstractGCEvent<?> concurrentPrepareRelocSetEvent = gcAllModel.get(0).getPhases().get(7);
+        AbstractGCEvent<?> concurrentPrepareRelocSetEvent = gcAllModel.get(CONCURRENT_PREPARE_RELOCATION_SET_INDEX);
         UnittestHelper.testMemoryPauseEvent(concurrentPrepareRelocSetEvent,
                 "Concurrent Prepare Relocation Set",
                 AbstractGCEvent.Type.UJL_ZGC_CONCURRENT_PREPARE_RELOC_SET,
@@ -156,7 +165,7 @@ public void testGcAllConcurrentPrepareRelocSet() {
 
     @Test
     public void testGcAllPauseRelocateStart() {
-        AbstractGCEvent<?> pauseRelocateStartEvent = gcAllModel.get(0).getPhases().get(8);
+        AbstractGCEvent<?> pauseRelocateStartEvent = gcAllModel.getGCEvents().next().getPhases().get(2);
         UnittestHelper.testMemoryPauseEvent(pauseRelocateStartEvent,
                 "Pause Relocate Start",
                 AbstractGCEvent.Type.UJL_ZGC_PAUSE_RELOCATE_START,
@@ -168,7 +177,7 @@ public void testGcAllPauseRelocateStart() {
 
     @Test
     public void testGcAllConcurrentRelocate() {
-        AbstractGCEvent<?> concurrentRelocateEvent = gcAllModel.get(0).getPhases().get(9);
+        AbstractGCEvent<?> concurrentRelocateEvent = gcAllModel.get(CONCURRENT_RELOCATE_INDEX);
         UnittestHelper.testMemoryPauseEvent(concurrentRelocateEvent,
                 "Concurrent Relocate",
                 AbstractGCEvent.Type.UJL_ZGC_CONCURRENT_RELOCATE,
@@ -206,7 +215,7 @@ public void testGcDefaultWarmup() {
                 "Warmup heap",
                 AbstractGCEvent.Type.UJL_ZGC_GARBAGE_COLLECTION,
                 0,
-                1024 * 208, 1024 * 164, 0,
+                1024 * 208, 1024 * 164, 1024 * 164 / 16 * 100,
                 AbstractGCEvent.Generation.TENURED,
                 false);
     }
@@ -218,7 +227,7 @@ public void testGcDefaultProactive() {
                 "Proactive heap",
                 AbstractGCEvent.Type.UJL_ZGC_GARBAGE_COLLECTION,
                 0,
-                1024 * 19804, 1024 * 20212, 0,
+                1024 * 19804, 1024 * 20212, 20212 * 1024 / 10 * 100,
                 AbstractGCEvent.Generation.TENURED,
                 false);
     }
@@ -230,7 +239,7 @@ public void testGcDefaultAllocationRate() {
                 "Allocation Rate heap",
                 AbstractGCEvent.Type.UJL_ZGC_GARBAGE_COLLECTION,
                 0,
-                1024 * 502, 1024 * 716, 0,
+                1024 * 502, 1024 * 716, 716 * 1024 / 70 * 100,
                 AbstractGCEvent.Generation.TENURED,
                 false);
     }
@@ -242,8 +251,9 @@ public void testDefaultGcSystemGc() {
                 "System.gc() heap",
                 AbstractGCEvent.Type.UJL_ZGC_GARBAGE_COLLECTION,
                 0,
-                1024 * 10124, 1024 * 5020, 0,
+                1024 * 10124, 1024 * 5020, 5020 * 1024 / 5 * 100,
                 AbstractGCEvent.Generation.TENURED,
                 false);
     }
+
 }
\ No newline at end of file
diff --git a/src/test/resources/openjdk/unified-jvm-logging/SampleShenandoahAllocationFailure.txt b/src/test/resources/openjdk/unified-jvm-logging/SampleShenandoahAllocationFailure.txt
index bac605be..2b8bcfd3 100644
--- a/src/test/resources/openjdk/unified-jvm-logging/SampleShenandoahAllocationFailure.txt
+++ b/src/test/resources/openjdk/unified-jvm-logging/SampleShenandoahAllocationFailure.txt
@@ -6,8 +6,8 @@
 [29.675s][info][gc,phases      ] GC(831) Phase 1: Mark live objects 17.256ms
 [29.675s][info][gc,phases,start] GC(831) Phase 2: Compute new object addresses
 [29.699s][info][gc,phases      ] GC(831) Phase 2: Compute new object addresses 23.568ms
-[29.699s][info][gc,phases,start] GC(831) Phase 2: Adjust pointers
-[29.725s][info][gc,phases      ] GC(831) Phase 2: Adjust pointers 26.061ms
+[29.699s][info][gc,phases,start] GC(831) Phase 3: Adjust pointers
+[29.725s][info][gc,phases      ] GC(831) Phase 3: Adjust pointers 26.061ms
 [29.725s][info][gc,phases,start] GC(831) Phase 4: Move objects
 [43.914s][info][gc,phases      ] GC(831) Phase 4: Move objects 14078.141ms
 [43.948s][info][gc             ] GC(831) Pause Full (Allocation Failure) 7943M->6013M(8192M) 14289.335ms
\ No newline at end of file