Merge branch '318'

IT/src/main/java/com/microsoft/gctoolkit/integration/aggregation/CMSCycleAggregation.java

@@ -0,0 +1,38 @@
+package com.microsoft.gctoolkit.integration.aggregation;
+
+import com.microsoft.gctoolkit.aggregator.Aggregation;
+import com.microsoft.gctoolkit.aggregator.Collates;
+
+@Collates(CMSCycleAggregator.class)
+public class CMSCycleAggregation extends Aggregation {
+
+    private int initialMark = 0;
+    private int remark = 0;
+    private int concurrentEvent = 0;
+
+    public void initialMark() {
+        initialMark++;
+    }
+
+    public void remark() {
+        remark++;
+    }
+
+    public void concurrentEvent() {
+        concurrentEvent++;
+    }
+
+    public int getInitialMark() { return initialMark; }
+    public int getRemark() { return remark; }
+    public int getConcurrentEvent() { return concurrentEvent; }
+
+    @Override
+    public boolean hasWarning() {
+        return false;
+    }
+
+    @Override
+    public boolean isEmpty() {
+        return false;
+    }
+}

IT/src/main/java/com/microsoft/gctoolkit/integration/aggregation/CMSCycleAggregator.java

@@ -0,0 +1,38 @@
+package com.microsoft.gctoolkit.integration.aggregation;
+
+import com.microsoft.gctoolkit.aggregator.Aggregates;
+import com.microsoft.gctoolkit.aggregator.Aggregator;
+import com.microsoft.gctoolkit.aggregator.EventSource;
+import com.microsoft.gctoolkit.event.generational.CMSConcurrentEvent;
+import com.microsoft.gctoolkit.event.generational.CMSRemark;
+import com.microsoft.gctoolkit.event.generational.InitialMark;
+
+@Aggregates({EventSource.GENERATIONAL})
+public class CMSCycleAggregator extends Aggregator<CMSCycleAggregation> {
+
+    private InitialMark lastInitialMark = null;
+    private CMSRemark lastRemark = null;
+    public CMSCycleAggregator(CMSCycleAggregation results) {
+        super(results);
+        register(InitialMark.class, this::count);
+        register(CMSRemark.class, this::count);
+        register(CMSConcurrentEvent.class, this::count);
+    }
+
+    public void count(InitialMark event) {
+        if ( event.equals(lastInitialMark)) return;
+        lastInitialMark = event;
+        aggregation().initialMark();
+    }
+
+    public void count(CMSRemark event) {
+        System.out.println(event.toString());
+        if ( event.equals(lastRemark)) return;
+        lastRemark = event;
+        aggregation().remark();
+    }
+
+    public void count(CMSConcurrentEvent event) {
+        aggregation().concurrentEvent();
+    }
+}

IT/src/main/java/module-info.java

@@ -17,5 +17,6 @@
             com.microsoft.gctoolkit.integration.aggregation.PauseTimeSummary,
             com.microsoft.gctoolkit.integration.aggregation.CollectionCycleCountsSummary,
             com.microsoft.gctoolkit.integration.shared.OneRuntimeReport,
-            com.microsoft.gctoolkit.integration.shared.TwoRuntimeReport;
+            com.microsoft.gctoolkit.integration.shared.TwoRuntimeReport,
+            com.microsoft.gctoolkit.integration.aggregation.CMSCycleAggregation;
 }

IT/src/test/java/com/microsoft/gctoolkit/integration/CMSEventsTest.java

@@ -0,0 +1,59 @@
+package com.microsoft.gctoolkit.integration;
+
+import com.microsoft.gctoolkit.GCToolKit;
+import com.microsoft.gctoolkit.integration.aggregation.CMSCycleAggregation;
+import com.microsoft.gctoolkit.integration.io.TestLogFile;
+import com.microsoft.gctoolkit.io.GCLogFile;
+import com.microsoft.gctoolkit.io.SingleGCLogFile;
+import com.microsoft.gctoolkit.jvm.JavaVirtualMachine;
+import org.junit.jupiter.api.Assertions;
+import org.junit.jupiter.api.Tag;
+import org.junit.jupiter.api.Test;
+
+import java.io.IOException;
+import java.nio.file.Path;
+
+import static org.junit.jupiter.api.Assertions.fail;
+
+@Tag("modulePath")
+public class CMSEventsTest {
+    @Test
+    public void testMain() {
+        Path path = new TestLogFile("preunified/cms/parnew/details/scavangeBeforeRemarkWithReference.log").getFile().toPath();
+        analyze(path.toString());
+    }
+
+    public void analyze(String gcLogFile) {
+        /**
+         * GC log files can come in  one of two types: single or series of rolling logs.
+         * In this sample, we load a single log file.
+         * The log files can be either in text, zip, or gzip format.
+         */
+        GCLogFile logFile = new SingleGCLogFile(Path.of(gcLogFile));
+        GCToolKit gcToolKit = new GCToolKit();
+
+        /**
+         * This call will load all implementations of Aggregator that have been declared in module-info.java.
+         * This mechanism makes use of Module SPI.
+         */
+        gcToolKit.loadAggregationsFromServiceLoader();
+
+        /**
+         * The JavaVirtualMachine contains the aggregations as filled out by the Aggregators.
+         * It also contains configuration information about how the JVM was configured for the runtime.
+         */
+        JavaVirtualMachine machine = null;
+        try {
+            machine = gcToolKit.analyze(logFile);
+        } catch (IOException e) {
+            fail(e.getMessage());
+        }
+
+        machine.getAggregation(CMSCycleAggregation.class).ifPresent(cmsCycleCounts -> {
+            Assertions.assertEquals( 1, cmsCycleCounts.getInitialMark(), "Initial Mark events count");
+            //Assertions.assertEquals( 1, cmsCycleCounts.getRemark(), "Remark events count");
+            //Assertions.assertEquals( 4, cmsCycleCounts.getConcurrentEvent(), "concurrent phase events count");
+        });
+
+    }
+}

IT/src/test/java/com/microsoft/gctoolkit/integration/EndToEndIntegrationTest.java

@@ -62,7 +62,6 @@ public void analyze(String gcLogFile) {
                 .map(HeapOccupancyAfterCollectionSummary::get)
                 .ifPresent(summary -> {
                     summary.forEach((gcType, dataSet) -> {
-                        System.out.printf(message, gcType, dataSet.size());
                         switch (gcType) {
                             case DefNew:
                                 defNewCount = dataSet.size();

api/src/main/java/com/microsoft/gctoolkit/aggregator/EventSource.java

@@ -17,6 +17,12 @@ public enum EventSource {
      */
     GENERATIONAL(GENERATIONAL_HEAP_PARSER_OUTBOX),
     CMS_UNIFIED(GENERATIONAL_HEAP_PARSER_OUTBOX),
+
+    /**
+     * Events that come from the CMS collection cycles
+     * @deprecated use the GENERATIONAL event source instead.
+     */
+    @Deprecated(since="3.0.8", forRemoval=true)
     CMS_PREUNIFIED(CMS_TENURED_POOL_PARSER_OUTBOX),
     /**
      * Events come from the G1 collector.

api/src/main/java/com/microsoft/gctoolkit/event/g1gc/G1ConcurrentMark.java

@@ -24,7 +24,7 @@ public class G1ConcurrentMark extends G1GCConcurrentEvent {
      * @param duration duration of the event
      */
     public G1ConcurrentMark(DateTimeStamp timeStamp, double duration) {
-        super(timeStamp, GarbageCollectionTypes.ConcurrentMark, GCCause.GCCAUSE_NOT_SET, duration);
+        super(timeStamp, GarbageCollectionTypes.G1GCConcurrentMark, GCCause.GCCAUSE_NOT_SET, duration);
     }
 
     /**

api/src/main/java/com/microsoft/gctoolkit/io/GCLogFileZipSegment.java

@@ -54,7 +54,7 @@ public String getSegmentName() {
         return this.segmentName;
     }
 
-    private DateTimeStamp ageOfJVMAtLogStart() {
+    private void ageOfJVMAtLogStart() {
         if (startTime == null) {
             startTime = stream()
                     .filter(s -> ! s.contains(" file created "))
@@ -63,7 +63,6 @@ private DateTimeStamp ageOfJVMAtLogStart() {
                     .findFirst()
                     .orElse(new DateTimeStamp(-1.0d));
         }
-        return startTime;
     }
 
     private DateTimeStamp ageOfJVMAtLogEnd()  {

api/src/main/java/com/microsoft/gctoolkit/time/DateTimeStamp.java

@@ -30,7 +30,7 @@ public class DateTimeStamp implements Comparable<DateTimeStamp> {
     // In the case where we have timestamps, the epoch is start of JVM
     // In the case where we only have date stamps, the epoch is 1970:01:01:00:00:00.000::UTC+0
     // All calculations in GCToolKit make use of the double, timeStamp.
-    // Calculations are based on an startup Epoch of 0.000 seconds. This isn't always the case and
+    // Calculations are based on the startup Epoch of 0.000 seconds. This isn't always the case and
     // certainly isn't the case when only date stamp is present. In these cases, start time is estimated.
     // This is surprisingly difficult to do thus use of timestamp is highly recommended.
 
@@ -61,7 +61,7 @@ private static double ageFromString(String doubleFormat) {
 
     private static final String DECIMAL_POINT = "(?:\\.|,)";
     private static final String INTEGER = "\\d+";
-    private static final String DATE = "\\d{4}-\\d{2}-\\d{2}T\\d{2}:\\d{2}:\\d{2}\\.\\d{3}[\\+|\\-]\\d{4}";
+    private static final String DATE = "\\d{4}-\\d{2}-\\d{2}T\\d{2}:\\d{2}:\\d{2}\\.\\d{3}[+|-]\\d{4}";
     private static final String TIME = INTEGER + DECIMAL_POINT + "\\d{3}";
 
     // Unified Tokens
@@ -96,7 +96,7 @@ public static DateTimeStamp fromGCLogLine(String line) {
 
     /**
      * Provides a minimal date.
-     * @return
+     * @return a minimal date
      */
     public static DateTimeStamp baseDate() {
         return new DateTimeStamp(EPOC, 0.0d);
@@ -158,12 +158,23 @@ public DateTimeStamp(ZonedDateTime dateTime, double timeStamp) {
      * Return the time stamp value. Allows a consistent time stamp be available to all calculations.
      * @return The time stamp value, in decimal seconds.
      */
+    @Deprecated
     public double getTimeStamp() {
         if (!hasTimeStamp())
             return toEpochInMillis();
         return timeStamp;
     }
 
+    public double toMilliseconds() {
+        if (!hasTimeStamp())
+            return toEpochInMillis();
+        return timeStamp * 1000.0d;
+    }
+
+    public double toSeconds() {
+        return toMilliseconds() / 1000.0d;
+    }
+
     /**
      * Return the date stamp.
      * @return The date stamp, which may be {@code null}
@@ -175,7 +186,7 @@ public ZonedDateTime getDateTime() {
     /**
      * Return {@code true} if the date stamp is not {@code null}.
      * It is possible to have two DateTimeStamps from the same GC log, one with a DateStamp and one without.
-     * @return {@code true} if the the date stamp is not {@code null}.
+     * @return {@code true} if the date stamp is not {@code null}.
      */
     public boolean hasDateStamp() {
         return ! (getDateTime() == null || EPOC.equals(getDateTime()));

parser/src/main/java/com/microsoft/gctoolkit/parser/CMSPatterns.java

@@ -43,10 +43,12 @@ public interface CMSPatterns extends SharedPatterns {
     //12.986: [GC[1 CMS-initial-mark: 33532K(62656K)] 49652K(81280K), 0.0014191 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
     GCParseRule INITIAL_MARK = new GCParseRule("INITIAL_MARK", GC_PREFIX + "\\[1 CMS-initial-mark: " + OCCUPANCY_CONFIGURED + "\\] " + OCCUPANCY_CONFIGURED_PAUSE + "\\]");
     GCParseRule CONCURRENT_PHASE_START = new GCParseRule("CONCURRENT_PHASE_START", "^" + CMS_PHASE_START);
-    GCParseRule CONCURRENT_PHASE_END = new GCParseRule("CONCURRENT_PHASE_END", "^" + CMS_PHASE_END);
+
+    GCParseRule CONCURRENT_PHASE_END = new GCParseRule("CONCURRENT_PHASE_END", "^" + CMS_PHASE_END + "$");
+    GCParseRule CONCURRENT_PHASE_END_WITH_CPU_SUMMARY = new GCParseRule("CONCURRENT_PHASE_END", "^" + CMS_PHASE_END + " " + CPU_SUMMARY);
 
     GCParseRule CONCURRENT_PHASE_START_BLOCK = new GCParseRule("CONCURRENT_PHASE_START_BLOCK", CMS_PHASE_START);
-    GCParseRule CONCURRENT_PHASE_END_BLOCK = new GCParseRule("CONCURRENT_PHASE_END_BLOCK", CMS_PHASE_END);
+    GCParseRule CONCURRENT_PHASE_END_BLOCK = new GCParseRule("CONCURRENT_PHASE_END_BLOCK", CMS_PHASE_END + " " + CPU_SUMMARY);
     GCParseRule ABORT_PRECLEAN_DUE_TO_TIME_CLAUSE = new GCParseRule("ABORT_PRECLEAN_DUE_TO_TIME_CLAUSE", "^" + ABORT_PRECLEAN_DUE_TO_TIME_BLOCK);
 
     /********** Remark statements **********/
@@ -172,7 +174,7 @@ public interface CMSPatterns extends SharedPatterns {
     GCParseRule SERIAL_FULL = new GCParseRule("SERIAL_FULL", FULL_GC_PREFIX + SERIAL_TENURED_BLOCK + " " + BEFORE_AFTER_CONFIGURED + ", " + PERM_RECORD + ", " + PAUSE_TIME);
 
     //1.244: [Full GC (Metadata GC Threshold) 1.244: [Tenured: 11155K->92012K(21888K), 0.0399330 secs] 18738K->09212K(31680K), [Metaspace: 20778K->20778K(1067008K)], 0.0405118 secs] [Times: user=0.04 sys=0.00, real=0.04 secs]
-    GCParseRule SERIAL_FULL80 = new GCParseRule("SERIAL_FULL80", FULL_GC_PREFIX + SERIAL_TENURED_BLOCK + " " + BEFORE_AFTER_CONFIGURED + ", " + META_RECORD + ", " + PAUSE_TIME);
+    //GCParseRule SERIAL_FULL80 = new GCParseRule("SERIAL_FULL80", FULL_GC_PREFIX + SERIAL_TENURED_BLOCK + " " + BEFORE_AFTER_CONFIGURED + ", " + META_RECORD + ", " + PAUSE_TIME);
 
     //11.675: [GC 11.675: [ParNew: 3782K->402K(3904K), 0.0012156 secs]11.676: [Tenured: 8673K->6751K(8840K), 0.1268332 secs] 12373K->6751K(12744K), [Perm : 10729K->10675K(21248K)], 0.1281985 secs]
     //89.260: [GC 89.260: [ParNew: 19135K->19135K(19136K), 0.0000156 secs]89.260: [CMS: 105875K->107775K(107776K), 0.5703972 secs] 125011K->116886K(126912K), [CMS Perm : 15589K->15584K(28412K)], 0.5705219 secs]

parser/src/main/java/com/microsoft/gctoolkit/parser/CMSTenuredPoolParser.java

@@ -64,7 +64,6 @@ else if ((trace = SPLIT_REMARK.parse(line)) != null)
         else if ((trace = EndOfFile.parse(line)) != null) {
             super.publish(ChannelName.CMS_TENURED_POOL_PARSER_OUTBOX, new JVMTermination(getClock(), diary.getTimeOfFirstEvent()));
         }
-
     }
 
     /**