424

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

@@ -6,6 +6,7 @@
 import com.microsoft.gctoolkit.event.GarbageCollectionTypes;
 import com.microsoft.gctoolkit.event.StatisticalSummary;
 import com.microsoft.gctoolkit.event.UnifiedStatisticalSummary;
+import com.microsoft.gctoolkit.event.jvm.SurvivorRecord;
 import com.microsoft.gctoolkit.time.DateTimeStamp;
 
 import java.util.Iterator;
@@ -36,6 +37,7 @@ public class G1Young extends G1RealPause {
     private StatisticalSummary workerTotal;
     private StatisticalSummary processedBuffersSummary;
     private boolean toSpaceExhausted = false;
+    private SurvivorRecord survivorRecord;
 
     private final Map<String, StatisticalSummary> parallelPhaseSummaries = new ConcurrentHashMap<>();
     private final Map<String, Double> phaseDurations = new ConcurrentHashMap<>();
@@ -196,6 +198,14 @@ public void addWorkerActivity(String group, StatisticalSummary statisticalSummar
             workerTotal = statisticalSummary;
     }
 
+    public void add(SurvivorRecord record) {
+        this.survivorRecord = record;
+    }
+
+    public SurvivorRecord getSurvivorRecord() {
+        return survivorRecord;
+    }
+
     public StatisticalSummary getWorkerOther() {
         return this.workerOther;
     }

api/src/main/java/com/microsoft/gctoolkit/event/generational/GenerationalGCPauseEvent.java

@@ -7,6 +7,7 @@
 import com.microsoft.gctoolkit.event.GarbageCollectionTypes;
 import com.microsoft.gctoolkit.event.MemoryPoolSummary;
 import com.microsoft.gctoolkit.event.ReferenceGCSummary;
+import com.microsoft.gctoolkit.event.jvm.SurvivorRecord;
 import com.microsoft.gctoolkit.time.DateTimeStamp;
 
 public abstract class GenerationalGCPauseEvent extends GenerationalGCEvent {
@@ -23,6 +24,7 @@ public abstract class GenerationalGCPauseEvent extends GenerationalGCEvent {
     private double stringTableProcessingTime;
     private double symbolAndStringTableProcessingTime;
     private BinaryTreeDictionary binaryTreeDictionary;
+    private SurvivorRecord survivorRecord;
 
     private CPUSummary cpuSummary;
 
@@ -114,6 +116,14 @@ public void addClassUnloadingAndStringTableProcessingDurations(double classUnloa
         this.symbolAndStringTableProcessingTime = symbolAndStringTable;
     }
 
+    public void add(SurvivorRecord record) {
+        this.survivorRecord = record;
+    }
+
+    public SurvivorRecord getSurvivorRecord() {
+        return survivorRecord;
+    }
+
     public double getClassUnloadingProcessingTime() {
         return this.classUnloadingProcessingTime;
     }

api/src/main/java/com/microsoft/gctoolkit/event/jvm/SurvivorRecord.java

@@ -16,8 +16,8 @@ public class SurvivorRecord extends JVMEvent {
     private int maxTenuringThreshold;
 
     // JDK bug, we have now seen a max tenuring threshold of 32, even 64
-    // Fold anything older than 15 back into the 15th slot
-    private ArrayList<Long> bytesAtAge = null;
+    // Fold anything older than maxTenuringThreshold back into the maxTenuringThreshold slot
+    private long[] bytesAtAge;
 
     public SurvivorRecord(DateTimeStamp timeStamp, long desiredOccupancy, int calculatedTenuringThreshold, int maxTenuringThreshold) {
         super(timeStamp, 0.0d);
@@ -56,31 +56,30 @@ public int getMaxTenuringThreshold() {
 
     public long getBytesAtAge(int age) {
         if (this.bytesAtAge == null) return 0L;
-        return this.bytesAtAge.get(age);
+        return this.bytesAtAge[age];
     }
 
     /*
      * There is a bug in the JVM that allows tenuring threshold to appear to be greater than 15.
-     * Fold anything greater than 15 into 15.
-     *
+     * Fold anything greater than maxTenuringThreshold into maxTenuringThreshold.
      */
     public void add(int age, long bytes) {
 
         if (bytesAtAge == null) {
-            bytesAtAge = new ArrayList<>();
-            bytesAtAge.add(0L); //throw away the first slow.
+            bytesAtAge = new long[maxTenuringThreshold+1];
+            bytesAtAge[0] = 0L; //throw away the first slot.
         }
 
         if (age <= maxTenuringThreshold) {
-            bytesAtAge.add(bytes);
+            bytesAtAge[age] = bytes;
         } else {
-            bytesAtAge.set(maxTenuringThreshold, bytesAtAge.get(maxTenuringThreshold) + bytes);
+            bytesAtAge[maxTenuringThreshold] += bytes;
         }
     }
 
-    public Long[] getBytesAtEachAge() {
+    public long[] getBytesAtEachAge() {
         if (bytesAtAge == null)
-            return new Long[0];
-        return bytesAtAge.toArray(new Long[0]);
+            return new long[0];
+        return bytesAtAge;
     }
 }

gclogs/pom.xml

@@ -17,7 +17,7 @@
     <packaging>pom</packaging>
 
     <properties>
-        <gctoolkit-testdata-version>1.0.10</gctoolkit-testdata-version>
+        <gctoolkit-testdata-version>1.0.12</gctoolkit-testdata-version>
     </properties>
 
     <build>

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

@@ -4,6 +4,7 @@
 
 import com.microsoft.gctoolkit.event.CPUSummary;
 import com.microsoft.gctoolkit.event.GCCause;
+import com.microsoft.gctoolkit.event.jvm.SurvivorRecord;
 import com.microsoft.gctoolkit.parser.jvm.Decorators;
 import com.microsoft.gctoolkit.time.DateTimeStamp;
 
@@ -15,6 +16,7 @@ public class ForwardReference {
     private double duration = -1.0d;
     private GCCause gcCause = GCCause.UNKNOWN_GCCAUSE;
     private CPUSummary cpuSummary = null;
+    SurvivorRecord survivorRecord = null;
 
     ForwardReference(Decorators decorators, int id) {
         this.gcID = id;
@@ -69,4 +71,17 @@ Decorators getDecorators() {
         return decorators;
     }
 
+    public void survivorRecord(SurvivorRecord survivorRecord) {
+        this.survivorRecord = survivorRecord;
+    }
+
+    public void addAgeBreakout(int age, long volume) {
+        if (this.survivorRecord == null)
+            return;
+        this.survivorRecord.add(age, volume);
+    }
+
+    public SurvivorRecord getSurvivorRecord() {
+        return this.survivorRecord;
+    }
 }

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

@@ -782,6 +782,8 @@ private G1Young buildYoung(G1Young collection) {
         if (toSpaceExhausted) collection.toSpaceExhausted();
         if (hasReferenceGCSummary())
             collection.add(generateReferenceGCSummary());
+        if (survivorRecord != null)
+            collection.add(survivorRecord);
         collection.addCPUSummary(getCPUSummary());
         return collection;
     }

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

@@ -15,6 +15,7 @@
 import com.microsoft.gctoolkit.event.g1gc.G1GCPauseEvent;
 import com.microsoft.gctoolkit.event.jvm.JVMEvent;
 import com.microsoft.gctoolkit.event.jvm.JVMTermination;
+import com.microsoft.gctoolkit.event.jvm.SurvivorRecord;
 import com.microsoft.gctoolkit.jvm.Diary;
 import com.microsoft.gctoolkit.message.ChannelName;
 import com.microsoft.gctoolkit.message.JVMEventChannel;
@@ -47,7 +48,7 @@
  * - pause time if it is reported or can be calculated
  * todo: me
  */
-public class UnifiedG1GCParser extends UnifiedGCLogParser implements UnifiedG1GCPatterns {
+public class UnifiedG1GCParser extends UnifiedGCLogParser implements UnifiedG1GCPatterns, TenuredPatterns {
 
     private static final Logger LOGGER = Logger.getLogger(UnifiedG1GCParser.class.getName());
 
@@ -154,6 +155,8 @@ public class UnifiedG1GCParser extends UnifiedGCLogParser implements UnifiedG1GC
         parseRules.put(REBUILD_FREELIST, this::noop);
         parseRules.put(NEW_CSET, this::noop);
         parseRules.put(RESIZE_TLAB, this::noop);
+        parseRules.put(TENURING_SUMMARY, this::tenuringSummary);
+        parseRules.put(TENURING_AGE_BREAKDOWN, this::tenuringAgeBreakout);
     }
 
     public UnifiedG1GCParser() {
@@ -672,6 +675,25 @@ private void fullStringSymbolTable(GCLogTrace trace, String line) {
 //        forwardReference.scrubStringSymbolTableDuration(trace.getMillisecondDurationInSeconds());
     }
 
+    /**
+     * Capture logged tenuring summary data
+     * @param trace
+     * @param line
+     */
+    private void tenuringSummary(GCLogTrace trace, String line) {
+        forwardReference.survivorRecord(new SurvivorRecord(getClock(), trace.getLongGroup(1), trace.getIntegerGroup(2), trace.getIntegerGroup(3)));
+    }
+
+    /**
+     * Capture logged age table data
+     * @param trace
+     * @param line
+     */
+    private void tenuringAgeBreakout(GCLogTrace trace, String line) {
+        notYetImplemented(trace,line);
+        forwardReference.addAgeBreakout(trace.getIntegerGroup(1), trace.getLongGroup(2));
+    }
+
     /**
      * records a concurrent phase of a concurrent cycle. After the event has been recorded, all other events
      * that occurred during the concurrent event will be recorded.
@@ -726,8 +748,6 @@ private void jvmExit(GCLogTrace trace, String s) {
     }
 
     private boolean ignoreFrequentlySeenButUnwantedLines(String line) {
-        if (line.contains("Desired survivor size")) return true;
-        if (line.contains("Age table with threshold")) return true;
         if (line.contains("safepoint")) return true;
         if (line.contains(") Skipped phase ")) return true;
         if (line.contains(" Total                          Min: ")) return true;
@@ -738,7 +758,7 @@ private boolean ignoreFrequentlySeenButUnwantedLines(String line) {
         if (line.contains(" StringTable Weak               Min:")) return true;
         if (line.contains(" ResolvedMethodTable Weak       Min:")) return true;
         if (line.contains(" JNI Weak                       Min:")) return true;
-        return line.contains(" - age ");
+        return false;
     }
 
     /**

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

@@ -25,6 +25,7 @@
 import com.microsoft.gctoolkit.event.generational.SystemGC;
 import com.microsoft.gctoolkit.event.generational.YoungGC;
 import com.microsoft.gctoolkit.event.jvm.JVMTermination;
+import com.microsoft.gctoolkit.event.jvm.SurvivorRecord;
 import com.microsoft.gctoolkit.jvm.Diary;
 import com.microsoft.gctoolkit.message.ChannelName;
 import com.microsoft.gctoolkit.message.JVMEventChannel;
@@ -63,7 +64,7 @@
  * - from, to, configured
  * - pause time if it is reported or can be calculated
  */
-public class UnifiedGenerationalParser extends UnifiedGCLogParser implements UnifiedGenerationalPatterns {
+public class UnifiedGenerationalParser extends UnifiedGCLogParser implements UnifiedGenerationalPatterns, TenuredPatterns {
 
     private static final Logger LOGGER = Logger.getLogger(UnifiedGenerationalParser.class.getName());
 
@@ -100,6 +101,8 @@ public class UnifiedGenerationalParser extends UnifiedGCLogParser implements Uni
         parseRules.put(JVM_EXIT, this::jvmExit);
         parseRules.put(END_OF_FILE, this::jvmExit);
         parseRules.put(METASPACE_DETAILED, this::metaSpaceDetails);
+        parseRules.put(TENURING_SUMMARY, this::tenuringSummary);
+        parseRules.put(TENURING_AGE_BREAKDOWN, this::tenuringAgeBreakout);
 
     }
 
@@ -229,6 +232,26 @@ private void youngDetails(GCLogTrace trace, String line) {
         pauseEvent.setHeap(trace.getOccupancyBeforeAfterWithMemoryPoolSizeSummary(2));
     }
 
+    /**
+     * Capture logged tenuring summary data
+     * @param trace
+     * @param line
+     */
+    private void tenuringSummary(GCLogTrace trace, String line) {
+        if ( pauseEvent != null)
+            pauseEvent.survivorRecord(new SurvivorRecord(getClock(), trace.getLongGroup(1), trace.getIntegerGroup(2), trace.getIntegerGroup(3)));
+    }
+
+    /**
+     * Capture logged age table data
+     * @param trace
+     * @param line
+     */
+    private void tenuringAgeBreakout(GCLogTrace trace, String line) {
+        if (pauseEvent != null)
+            pauseEvent.addAgeBreakout(trace.getIntegerGroup(1), trace.getLongGroup(2));
+    }
+
     /**
      * If the concurrentCyclePauseEvent has not been recorded, something has gone wrong and it's likely
      * that it doesn't have a consistent state. The default action is to lose it.
@@ -449,13 +472,14 @@ private GenerationalGCPauseEvent buildYoungEvent(GenerationalForwardReference fo
                 youngCollection = new PSYoungGen(forwardReference.getStartTime(), forwardReference.getGCCause(), forwardReference.getDuration());
                 break;
             default:
-                LOGGER.warning(forwardReference.getGarbageCollectionType() + " not recognized");
+                throw new IllegalStateException(forwardReference.getGarbageCollectionType() + " not recognized");
         }
 
         fillOutMemoryPoolData(youngCollection, forwardReference);
         fillOutMetaspaceData(youngCollection, forwardReference);
         youngCollection.add(forwardReference.getCPUSummary());
-        // add in reference processing
+        youngCollection.add(forwardReference.getSurvivorRecord());
+        // todo: add in reference processing
         return youngCollection;
     }
 
@@ -519,7 +543,7 @@ private GenerationalGCPauseEvent buildPauseEvent(GenerationalForwardReference fo
                 return buildInitialMark(forwardReference);
             case Remark:
                 return buildRemark(forwardReference);
-            case PSFull: //todo:
+            case PSFull:
             case FullGC:
             case Full:
                 return buildFullGC(forwardReference);
@@ -565,8 +589,7 @@ private boolean ignoreFrequentlySeenButUnwantedLines(String line) {
         if (line.contains("exit"))
             if (line.contains("used")) return true;
         if (line.contains("workers")) return true;
-        if (line.contains("Heap address")) return true;
-        return line.contains("Desired") || line.contains("Age table") || line.contains("- age ");
+        return line.contains("Heap address");
     }
 
     @Override

parser/src/test/java/com/microsoft/gctoolkit/parser/G1GCUnifiedParserRulesTest.java

@@ -12,7 +12,7 @@
 import static com.microsoft.gctoolkit.parser.CommonTestHelper.captureTest;
 import static org.junit.jupiter.api.Assertions.*;
 
-public class G1GCUnifiedParserRulesTest implements UnifiedG1GCPatterns {
+public class G1GCUnifiedParserRulesTest implements UnifiedG1GCPatterns, TenuredPatterns {
 
     /**
      * The rules are;
@@ -152,7 +152,9 @@ private void evaluate(GCParseRule rule, String string, boolean dump) {
             WEAK_PROCESSING,
             CLEANUP__FINALIZE_CONC_MARK,
             CONCURRENT_UNDO_CYCLE_START,
-            CONCURRENT_UNDO_CYCLE_END     // 70
+            CONCURRENT_UNDO_CYCLE_END ,    // 70
+            TENURING_SUMMARY,
+            TENURING_AGE_BREAKDOWN
     };
 
     /*
@@ -446,6 +448,12 @@ private void evaluate(GCParseRule rule, String string, boolean dump) {
             },
             {   // 70
                     "[155.836s][info ][gc          ] GC(2457) Concurrent Undo Cycle 49.351ms",
+            },
+            {   // 71
+                    "[10.749s][debug][gc,age       ] GC(0) Desired survivor size 1572864 bytes, new threshold 15 (max threshold 15)\n"
+            },
+            {   // 72
+                    "[10.754s][trace][gc,age       ] GC(0) - age   1:    2579584 bytes,    2579584 total"
             }
 
             // Remaining lines which may not need to be parsed...

parser/src/test/java/com/microsoft/gctoolkit/parser/GenerationalHeapParserRulesTest.java

@@ -9,7 +9,7 @@
 import static com.microsoft.gctoolkit.parser.CommonTestHelper.captureTest;
 import static org.junit.jupiter.api.Assertions.*;
 
-public class GenerationalHeapParserRulesTest implements SimplePatterns, SerialPatterns, ParallelPatterns, CMSPatterns, ICMSPatterns {
+public class GenerationalHeapParserRulesTest implements SimplePatterns, SerialPatterns, ParallelPatterns, CMSPatterns, ICMSPatterns, TenuredPatterns {
 
     private static final Logger LOGGER = Logger.getLogger(GenerationalHeapParserRulesTest.class.getName());
 
@@ -250,7 +250,9 @@ private void evaluate(GCParseRule rule, String string, boolean dump) {
 //            CMF_LARGE_BLOCK,
 //            //this rule must be evaluated before CONCURRENT_PHASE_END_BLOCK
 //            ABORT_PRECLEAN_DUE_TO_TIME_CLAUSE,
-            PRECLEAN_REFERENCE
+            PRECLEAN_REFERENCE,
+            TENURING_SUMMARY,
+            TENURING_AGE_BREAKDOWN
     };
 
     private String[][] lines = {
@@ -591,6 +593,12 @@ private void evaluate(GCParseRule rule, String string, boolean dump) {
 //            },
             {
                 "2016-04-01T15:03:42.171-0700: 11025.637: [Preclean SoftReferences, 0.0000530 secs]2016-04-01T15:03:42.172-0700: 11025.637: [Preclean WeakReferences, 0.0006860 secs]2016-04-01T15:03:42.172-0700: 11025.638: [Preclean FinalReferences, 0.0005450 secs]2016-04-01T15:03:42.173-0700: 11025.639: [Preclean PhantomReferences, 0.0000230 secs]2016-04-01T15:03:42.197-0700: 11025.663: [CMS-concurrent-preclean: 0.025/0.026 secs] [Times: user=0.04 sys=0.01, real=0.03 secs]"
+            },
+            {
+                "[10.749s][debug][gc,age       ] GC(0) Desired survivor size 1572864 bytes, new threshold 15 (max threshold 15)\n"
+            },
+            {
+                "[10.754s][trace][gc,age       ] GC(0) - age   1:    2579584 bytes,    2579584 total"
             }
     };
 }