I need a title (#344)

* bug: intermediate commit to allow work on another bug

* bug: add more robust handling of IllegalArgumentException in GCToolKit::analyize

* tidy: remove debug to stdout to logging framework

* refactor: Ensure DateTimeStamp cannot be malformed and it behaves if the timestamp is missing

* refactor: update pom for new GC log test data bundle

* tidy: address comments from PR

* Update parser/src/main/java/com/microsoft/gctoolkit/parser/GCLogParser.java

* feature: first push to combine CMS parser with GenerationalHeapParser

* depreciate: depreciated the CMS preunified event source

* refactor: get all tests to pass

* refactor: continue to get tests to pass

* refactor: continue to get tests to pass

* refactor: collapse CMS phases parser into generational parser

* refactor: GenerationalHeapParser was duplicating CMF failures under certain conditions

* refactor: ensure GC log is closed when discovering the format

* refactor: add test for reported bug

* refactor: add ability to parse very simple logs preunified logs

* refactor: remove no longer needed print statement

* refactor: tidy from review

---------

Co-authored-by: Martijn Verburg <[email protected]>

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

@@ -7,6 +7,7 @@
 import com.microsoft.gctoolkit.event.generational.CMSRemark;
 import com.microsoft.gctoolkit.event.generational.InitialMark;
 
+
 @Aggregates({EventSource.GENERATIONAL})
 public class CMSCycleAggregator extends Aggregator<CMSCycleAggregation> {
 
@@ -26,7 +27,6 @@ public void count(InitialMark event) {
     }
 
     public void count(CMSRemark event) {
-        System.out.println(event.toString());
         if ( event.equals(lastRemark)) return;
         lastRemark = event;
         aggregation().remark();

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

@@ -51,8 +51,8 @@ public void analyze(String gcLogFile) {
 
         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");
+            Assertions.assertEquals( 1, cmsCycleCounts.getRemark(), "Remark events count");
+            Assertions.assertEquals( 5, cmsCycleCounts.getConcurrentEvent(), "concurrent phase events count");
         });
 
     }

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

@@ -127,8 +127,8 @@ public final String endOfData() {
      * @throws IOException Thrown from reading the stream.
      */
     private TripleState discoverFormat() {
-        try {
-            boolean isUnified = firstNLines(stream(), SHOULD_HAVE_SEEN_A_UNIFIED_DECORATOR_BY_THIS_LINE_IN_THE_LOG)
+        try (Stream<String> stream = stream()) {  // contribution from MansuyDavid @github
+            boolean isUnified = firstNLines(stream, SHOULD_HAVE_SEEN_A_UNIFIED_DECORATOR_BY_THIS_LINE_IN_THE_LOG)
                     .map(LINE_STARTS_WITH_DECORATOR::matcher)
                     .anyMatch(Matcher::find);
             return TripleState.valueOf(isUnified);

api/src/main/java/com/microsoft/gctoolkit/jvm/Diarizer.java

@@ -22,8 +22,6 @@ public interface Diarizer {
 
     boolean completed();
 
-    void fillInKnowns();
-
     boolean diarize(String line);
 
 }

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

@@ -76,13 +76,28 @@ public String getDateStamp() {
         }
     }
 
+    /**
+     *
+     * @return the date timestamp paring found at the beginning of the GC log line.
+     */
     public DateTimeStamp getDateTimeStamp() {
         return getDateTimeStamp(1);
     }
 
-    public DateTimeStamp getDateTimeStamp(int index) {
+    /**
+     * If a line contains multiple date timestamp group pairing then return the nth pair.
+     * The following example contains 3 different date timestamps. index of 1 yields 57724.218
+     * whereas index 3 yields 2010-04-21T10:45:[email protected]
+     * <code>
+     *     57724.218: [Full GC 57724.218: [CMS2010-04-21T10:45:33.367+0100: 57724.319: [CMS-concurrent-mark: 2.519/2.587 secs]
+     * <code/>
+     * one time stamp or a date timestamp pairing
+     * @param nth is date timestamp field pair to be returned
+     * @return the nth date timestamp pairing
+     */
+    public DateTimeStamp getDateTimeStamp(int nth) {
         Matcher matcher = DATE_TIME_STAMP_RULE.matcher(trace.group(0));
-        for (int i = 0; i < index - 1; i++)
+        for (int i = 0; i < nth - 1; i++)
             if (!matcher.find())
                 break;
         if (matcher.find()) {

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

@@ -488,6 +488,7 @@ private void parNewFLSTime(GCLogTrace trace, String line) {
             MemoryPoolSummary heap = new MemoryPoolSummary(heapForwardReference.getOccupancyBeforeCollection(), heapForwardReference.getSizeAfterCollection(), heapForwardReference.getOccupancyBeforeCollection(), heapForwardReference.getSizeAfterCollection());
             FullGC fullGc = new FullGC(fullGCTimeStamp, gcCauseForwardReference, trace.getDuration());
             fullGc.add(heap);
+            fullGc.add(extractCPUSummary(line));
             publish(fullGc);
         } else
             LOGGER.warning("Unable to parse -> " + trace);
@@ -1173,6 +1174,7 @@ public void fullGCInterruptsConcurrentPhase(GCLogTrace trace, String line) {
         fullGCTimeStamp = getClock();
         garbageCollectionTypeForwardReference = GarbageCollectionTypes.FullGC;
         gcCauseForwardReference = trace.gcCause();
+        endOfConcurrentPhase(trace,trace.getDateTimeStamp(3), 5);
     }
 
     public void fullGCReferenceConcurrentModeFailure(GCLogTrace trace, String line) {
@@ -2054,6 +2056,8 @@ private void log(String line) {
 //        if (line.startsWith("}")) return;
 //        if (line.startsWith("Heap")) return;
 //        if (line.startsWith("[Times: user")) return;
+        if ( line.startsWith("Metaspace       used")) return;
+        if ( line.startsWith("class space    used")) return;
         if (line.startsWith("par new generation   total")) return;
 //        if (line.startsWith("concurrent mark-sweep generation total")) return;
         if (line.startsWith("concurrent-mark-sweep perm gen total")) return;
@@ -2068,6 +2072,7 @@ private void log(String line) {
 //        if (line.contains("Large block")) return;
 //
 //        GCToolKit.LOG_DEBUG_MESSAGE(() -> "GenerationalHeapParser missed: " + line);
+        if (line.contains("CMSCMS: Large block")) return;
         LOGGER.log(Level.WARNING, "Missed: {0}", line);
 
     }
@@ -2119,6 +2124,9 @@ private void endOfConcurrentPhase(GCLogTrace trace, DateTimeStamp timeStamp, int
         double cpuTime = trace.getDoubleGroup(4 + offset);
         double wallTime = trace.getDoubleGroup(5 + offset);
         double duration = timeStamp.toSeconds() - startOfConcurrentPhase.toSeconds();
+        // The wallTime measure is a very good estimate of duration.
+        if ( duration == Double.NaN)
+            duration = wallTime;
         if ("mark".equals(phase))
             publish(new ConcurrentMark(startOfConcurrentPhase, duration, cpuTime, wallTime));
         else if ("preclean".equals(phase))
@@ -2158,12 +2166,12 @@ private void clear() {
     }
 
     public void publish( JVMEvent event, boolean drain, boolean clear) {
+        publish(event,clear);
         if (drain) {
             for( GenerationalGCPauseEvent pauseEvent : queue)
                 publish(pauseEvent, false);
             queue.clear();
         }
-        publish(event,clear);
     }
 
     public void publish(JVMEvent event, boolean clear) {