diff --git a/parser/src/main/java/com/microsoft/gctoolkit/parser/ZGCParser.java b/parser/src/main/java/com/microsoft/gctoolkit/parser/ZGCParser.java index 2083157f..d0e3a4d8 100644 --- a/parser/src/main/java/com/microsoft/gctoolkit/parser/ZGCParser.java +++ b/parser/src/main/java/com/microsoft/gctoolkit/parser/ZGCParser.java @@ -194,17 +194,33 @@ private void setForwardRefForPhase(ZGCPhase zgcPhase, ZGCForwardReference forwar private void cycleStart(GCLogTrace trace, String s) { ZGCCycleType type = ZGCCycleType.get(trace.getGroup(2)); + + if (diary.isGenerationalZGC()) { + // cycleStart ends up being called for ZGC logging with no details, but did not handle this situation. + // It is not clear if there is any differentiation between Young/Old Phases in no-details logging, so I've made + // an assumption here that we're strictly dealing with Young collections until we have sample logging otherwise. + if (ZGCCycleType.MAJOR.equals(type)) { + setForwardRefForPhase( + ZGCPhase.MAJOR_YOUNG, + new ZGCForwardReference(getClock(), trace.getLongGroup(1), trace.gcCause(3,0), type, ZGCPhase.MAJOR_YOUNG)); + } else if (ZGCCycleType.MINOR.equals(type)) { + setForwardRefForPhase( + ZGCPhase.MINOR_YOUNG, + new ZGCForwardReference(getClock(), trace.getLongGroup(1), trace.gcCause(3,0), type, ZGCPhase.MINOR_YOUNG)); + } + + } + if(type == ZGCCycleType.FULL){ setForwardRefForPhase( ZGCPhase.FULL, new ZGCForwardReference(getClock(), trace.getLongGroup(1), trace.gcCause(3,0), type, ZGCPhase.FULL) ); - } - else { + } else { // The cycle start message gives us the gc cause, which we need to create the GCEvent in generationStart // When we get a cycle start, store the gc cause for later use gcCauseMap.put(trace.getLongGroup(1), trace.gcCause(1, 2)); - } + } } private void generationStart(GCLogTrace trace, String line){ @@ -549,11 +565,39 @@ private void generationEnd(GCLogTrace trace, String s) { } private void memorySummary(GCLogTrace trace, String s) { - if(diary.isGenerationalZGC()){ + if (diary.isGenerationalZGC()) { long gcId = trace.getLongGroup(1); - gcCauseMap.remove(gcId); + + if (gcCauseMap.containsKey(gcId)) { + gcCauseMap.remove(gcId); + } + + // We use the lack of a MemorySummary in the forwardReference as a sign that this is the case and + // that we need to publish a Generational no-details event. + ZGCCycleType type = ZGCCycleType.get(trace.getGroup(2)); + ZGCForwardReference forwardReference = ZGCCycleType.MAJOR.equals(type) ? + getForwardRefForPhase(ZGCPhase.MAJOR_YOUNG) : + getForwardRefForPhase(ZGCPhase.MINOR_YOUNG); + + if (forwardReference != null && !forwardReference.hasMemorySummary()) { + forwardReference.setMemorySummary( + new ZGCMemorySummary( + trace.toKBytes(4), + trace.toKBytes(7))); + publish(forwardReference.getGCEVent(getClock())); + } } else { ZGCForwardReference forwardReference = getForwardRefForPhase(ZGCPhase.FULL); + + // For Legacy ZGC (Java 17, non-generational) with no details (gc instead of gc*), only a single line + // is logged per event. As such, getForwardRefForPhase will return NULL. + if (forwardReference == null) { + // Forward reference has not yet been created, so we'll create it now + ZGCCycleType type = ZGCCycleType.get(trace.getGroup(2)); + forwardReference = new ZGCForwardReference( + getClock(), trace.getLongGroup(1), trace.gcCause(3,0), type, ZGCPhase.FULL); + } + forwardReference.setMemorySummary( new ZGCMemorySummary( trace.toKBytes(4), @@ -884,6 +928,10 @@ public void setMemorySummary(ZGCMemorySummary summary) { this.memorySummary = summary; } + public boolean hasMemorySummary() { + return this.memorySummary != null; + } + public void setMetaspaceSummary(ZGCMetaspaceSummary summary) { this.metaspaceSummary = summary; } diff --git a/parser/src/test/java/com/microsoft/gctoolkit/parser/ZGCParserTest.java b/parser/src/test/java/com/microsoft/gctoolkit/parser/ZGCParserTest.java index ab8be0eb..8011de88 100644 --- a/parser/src/test/java/com/microsoft/gctoolkit/parser/ZGCParserTest.java +++ b/parser/src/test/java/com/microsoft/gctoolkit/parser/ZGCParserTest.java @@ -2,6 +2,7 @@ // Licensed under the MIT License. package com.microsoft.gctoolkit.parser; +import com.microsoft.gctoolkit.event.GCCause; import com.microsoft.gctoolkit.event.jvm.JVMEvent; import com.microsoft.gctoolkit.event.zgc.ZGCAllocatedSummary; import com.microsoft.gctoolkit.event.zgc.ZGCFullCollection; @@ -10,9 +11,14 @@ import com.microsoft.gctoolkit.event.zgc.ZGCMemoryPoolSummary; import com.microsoft.gctoolkit.event.zgc.ZGCMemorySummary; import com.microsoft.gctoolkit.event.zgc.ZGCMetaspaceSummary; +import com.microsoft.gctoolkit.event.zgc.ZGCOldCollection; +import com.microsoft.gctoolkit.event.zgc.ZGCPhase; import com.microsoft.gctoolkit.event.zgc.ZGCReclaimSummary; +import com.microsoft.gctoolkit.event.zgc.ZGCYoungCollection; import com.microsoft.gctoolkit.jvm.Diarizer; import com.microsoft.gctoolkit.parser.jvm.UnifiedDiarizer; +import com.microsoft.gctoolkit.time.DateTimeStamp; + import org.junit.jupiter.api.Test; import java.util.List; @@ -21,6 +27,8 @@ public class ZGCParserTest extends ParserTest { + final long M = 1024; + @Override protected Diarizer diarizer() { return new UnifiedDiarizer(); @@ -80,18 +88,18 @@ public void infoLevelZGCCycle() { assertEquals(zgc.getGcId(), 2L); assertEquals(0.0710d, zgc.getDuration(),0.001d); - assertEquals(toInt(32.121d, 1000), toInt(zgc.getDateTimeStamp().getTimeStamp(), 1000)); + assertEquals(toInt(32.121d, 1000), toInt(zgc.getDateTimeStamp().toSeconds(), 1000)); assertEquals("Metadata GC Threshold", zgc.getGCCause().getLabel()); // Durations - assertEquals(32.121d, zgc.getPauseMarkStartTimeStamp().getTimeStamp(), 0.001d); - assertEquals(32.122d, zgc.getConcurrentMarkTimeStamp().getTimeStamp(), 0.001d); - assertEquals(32.166d, zgc.getConcurrentMarkFreeTimeStamp().getTimeStamp(), 0.001d); - assertEquals(32.166d, zgc.getPauseMarkEndTimeStamp().getTimeStamp(), 0.001d); - assertEquals(32.167d, zgc.getConcurrentProcessNonStrongReferencesTimeStamp().getTimeStamp(), 0.002d); - assertEquals(32.172d, zgc.getConcurrentResetRelocationSetTimeStamp().getTimeStamp(), 0.001d); - assertEquals(32.172d, zgc.getConcurrentSelectRelocationSetTimeStamp().getTimeStamp(), 0.001d); - assertEquals(32.179d, zgc.getPauseRelocateStartTimeStamp().getTimeStamp(), 0.001d); - assertEquals(32.179d, zgc.getConcurrentRelocateTimeStamp().getTimeStamp(), 0.001d); + assertEquals(32.121d, zgc.getPauseMarkStartTimeStamp().toSeconds(), 0.001d); + assertEquals(32.122d, zgc.getConcurrentMarkTimeStamp().toSeconds(), 0.001d); + assertEquals(32.166d, zgc.getConcurrentMarkFreeTimeStamp().toSeconds(), 0.001d); + assertEquals(32.166d, zgc.getPauseMarkEndTimeStamp().toSeconds(), 0.001d); + assertEquals(32.167d, zgc.getConcurrentProcessNonStrongReferencesTimeStamp().toSeconds(), 0.002d); + assertEquals(32.172d, zgc.getConcurrentResetRelocationSetTimeStamp().toSeconds(), 0.001d); + assertEquals(32.172d, zgc.getConcurrentSelectRelocationSetTimeStamp().toSeconds(), 0.001d); + assertEquals(32.179d, zgc.getPauseRelocateStartTimeStamp().toSeconds(), 0.001d); + assertEquals(32.179d, zgc.getConcurrentRelocateTimeStamp().toSeconds(), 0.001d); assertEquals(toInt(0.023d, 1000), toInt(zgc.getPauseMarkStartDuration(), 1000)); assertEquals(toInt(44.623d, 1000), toInt(zgc.getConcurrentMarkDuration(), 1000)); @@ -133,7 +141,264 @@ public void infoLevelZGCCycle() { fail(t); } } + + @Test + void testLegacyZGCNoDetailsLines() { + String[] lines = { + // 0 - FullZGCCycle + "[1.295s][info][gc] GC(0) Garbage Collection (Metadata GC Threshold) 90M(1%)->58M(1%)", + + // 1 - FullZGCCycle + "[23.507s][info][gc] GC(3) Garbage Collection (Warmup) 826M(10%)->168M(2%)" + }; + + int expectedEventCount = 2; + + List jvmEvents = feedParser(lines); + assertEquals(expectedEventCount, jvmEvents.size()); + + // 0 - ZGCFullCollection + assertTrue(jvmEvents.get(0) instanceof ZGCFullCollection); + ZGCFullCollection evt0 = (ZGCFullCollection) jvmEvents.get(0); + assertEquals(evt0.getDateTimeStamp(), new DateTimeStamp(1.295)); + assertEquals(evt0.getGCCause(), GCCause.METADATA_GENERATION_THRESHOLD); + assertZGCMemorySummary(evt0.getMemorySummary(), 90*M, 58*M); + + // 1 - ZGCFullCollection + assertTrue(jvmEvents.get(1) instanceof ZGCFullCollection); + ZGCFullCollection evt1 = (ZGCFullCollection) jvmEvents.get(1); + assertEquals(new DateTimeStamp(23.507), evt1.getDateTimeStamp()); + assertEquals(GCCause.WARMUP, evt1.getGCCause()); + assertZGCMemorySummary(evt1.getMemorySummary(), 826*M, 168*M); + } + + @Test + void testLegacyDetailedEvent() { + String[] lines = { + "[1.641s][info][gc,start ] GC(0) Garbage Collection (Metadata GC Threshold)", + "[1.641s][info][gc,task ] GC(0) Using 5 workers", + "[1.641s][info][gc,phases ] GC(0) Pause Mark Start 0.006ms", + "[1.652s][info][gc,phases ] GC(0) Concurrent Mark 10.438ms", + "[1.652s][info][gc,phases ] GC(0) Pause Mark End 0.014ms", + "[1.652s][info][gc,phases ] GC(0) Concurrent Mark Free 0.001ms", + "[1.653s][info][gc,phases ] GC(0) Concurrent Process Non-Strong References 1.408ms", + "[1.654s][info][gc,phases ] GC(0) Concurrent Reset Relocation Set 0.000ms", + "[1.660s][info][gc,phases ] GC(0) Concurrent Select Relocation Set 5.975ms", + "[1.660s][info][gc,phases ] GC(0) Pause Relocate Start 0.011ms", + "[1.663s][info][gc,phases ] GC(0) Concurrent Relocate 3.001ms", + "[1.663s][info][gc,load ] GC(0) Load: 0.00/0.00/0.00", + "[1.663s][info][gc,mmu ] GC(0) MMU: 2ms/99.3%, 5ms/99.7%, 10ms/99.8%, 20ms/99.8%, 50ms/99.9%, 100ms/100.0%", + "[1.663s][info][gc,marking ] GC(0) Mark: 4 stripe(s), 2 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s) ", + "[1.663s][info][gc,marking ] GC(0) Mark Stack Usage: 32M", + "[1.663s][info][gc,nmethod ] GC(0) NMethods: 2721 registered, 0 unregistered", + "[1.663s][info][gc,metaspace] GC(0) Metaspace: 21M used, 21M committed, 1088M reserved", + "[1.663s][info][gc,ref ] GC(0) Soft: 4085 encountered, 0 discovered, 0 enqueued", + "[1.663s][info][gc,ref ] GC(0) Weak: 2166 encountered, 436 discovered, 349 enqueued", + "[1.663s][info][gc,ref ] GC(0) Final: 0 encountered, 0 discovered, 0 enqueued", + "[1.663s][info][gc,ref ] GC(0) Phantom: 909 encountered, 794 discovered, 410 enqueued", + "[1.663s][info][gc,reloc ] GC(0) Small Pages: 46 / 92M, Empty: 0M, Relocated: 11M, In-Place: 0", + "[1.663s][info][gc,reloc ] GC(0) Medium Pages: 1 / 32M, Empty: 0M, Relocated: 0M, In-Place: 0", + "[1.663s][info][gc,reloc ] GC(0) Large Pages: 0 / 0M, Empty: 0M, Relocated: 0M, In-Place: 0", + "[1.663s][info][gc,reloc ] GC(0) Forwarding Usage: 4M", + "[1.663s][info][gc,heap ] GC(0) Min Capacity: 8M(0%)", + "[1.663s][info][gc,heap ] GC(0) Max Capacity: 8094M(100%)", + "[1.663s][info][gc,heap ] GC(0) Soft Max Capacity: 8094M(100%)", + "[1.663s][info][gc,heap ] GC(0) Mark Start Mark End Relocate Start Relocate End High Low ", + "[1.663s][info][gc,heap ] GC(0) Capacity: 506M (6%) 506M (6%) 506M (6%) 506M (6%) 506M (6%) 506M (6%) ", + "[1.663s][info][gc,heap ] GC(0) Free: 7970M (98%) 7968M (98%) 7964M (98%) 8028M (99%) 8028M (99%) 7960M (98%) ", + "[1.663s][info][gc,heap ] GC(0) Used: 124M (2%) 126M (2%) 130M (2%) 66M (1%) 134M (2%) 66M (1%) ", + "[1.664s][info][gc,heap ] GC(0) Live: - 19M (0%) 19M (0%) 19M (0%) - - ", + "[1.664s][info][gc,heap ] GC(0) Allocated: - 2M (0%) 6M (0%) 9M (0%) - - ", + "[1.664s][info][gc,heap ] GC(0) Garbage: - 104M (1%) 104M (1%) 36M (0%) - - ", + "[1.664s][info][gc,heap ] GC(0) Reclaimed: - - 0M (0%) 67M (1%) - - ", + "[1.664s][info][gc ] GC(0) Garbage Collection (Metadata GC Threshold) 124M(2%)->66M(1%)" + }; + + int expectedEventCount = 1; + + List jvmEvents = feedParser(lines); + assertEquals(expectedEventCount, jvmEvents.size()); + + // 0 - ZGCFullCollection + // Note: this is just a light-weight check of the event object at this time to make sure there is no confusion between + // Legacy ZGC logging and Generational ZGC events with some of the changes added to support no-detail logging. + assertTrue(jvmEvents.get(0) instanceof ZGCFullCollection); + ZGCFullCollection evt0 = (ZGCFullCollection) jvmEvents.get(0); + assertEquals(new DateTimeStamp(1.641), evt0.getDateTimeStamp()); + assertEquals(GCCause.METADATA_GENERATION_THRESHOLD, evt0.getGCCause()); + assertEquals(ZGCPhase.FULL, evt0.getPhase()); + assertZGCMemorySummary(evt0.getMemorySummary(), 124*M, 66*M); + assertDoubleEquals(evt0.getDuration(), 1.664 - 1.641); + + } + + @Test + void testGenerationalZGCNoDetailsLines() { + String[] lines = { + // 0 - ZGCYoungCollection(Major) + "[4.252s][info][gc] GC(2) Major Collection (Metadata GC Threshold)", + "[4.366s][info][gc] GC(2) Major Collection (Metadata GC Threshold) 384M(5%)->186M(2%) 0.114s", + + // 1 - ZGCYoungCollection(Major) + "[36.326s][info][gc] GC(3) Major Collection (Warmup)", + "[36.423s][info][gc] GC(3) Major Collection (Warmup) 730M(9%)->258M(3%) 0.097s" + }; + + int expectedEventCount = 2; + + List jvmEvents = feedParser(lines); + assertEquals(jvmEvents.size(), expectedEventCount); + + // 0 - ZGCYoungCollection + assertTrue(jvmEvents.get(0) instanceof ZGCYoungCollection); + ZGCYoungCollection evt0 = (ZGCYoungCollection) jvmEvents.get(0); + assertEquals(new DateTimeStamp(4.252), evt0.getDateTimeStamp()); + assertEquals(GCCause.METADATA_GENERATION_THRESHOLD, evt0.getGCCause()); + assertEquals(ZGCPhase.MAJOR_YOUNG, evt0.getPhase()); + assertZGCMemorySummary(evt0.getMemorySummary(), 384*M, 186*M); + assertDoubleEquals(evt0.getDuration(), 0.114); + + // 1 - ZGCYoungCollection(Major) + assertTrue(jvmEvents.get(1) instanceof ZGCYoungCollection); + ZGCYoungCollection evt1 = (ZGCYoungCollection) jvmEvents.get(1); + assertEquals(new DateTimeStamp(36.326), evt1.getDateTimeStamp()); + assertEquals(GCCause.WARMUP, evt1.getGCCause()); + assertEquals(ZGCPhase.MAJOR_YOUNG, evt1.getPhase()); + assertZGCMemorySummary(evt1.getMemorySummary(), 730*M, 258*M); + assertDoubleEquals(evt1.getDuration(), 0.097); + } + + @Test + void testMajorGenerationalDetailedEvent() { + String[] lines = { + // 0 - + "[0.990s][info][gc ] GC(0) Major Collection (Metadata GC Threshold)", + "[0.990s][info][gc,task ] GC(0) Using 1 Workers for Young Generation", + "[0.990s][info][gc,task ] GC(0) Using 1 Workers for Old Generation", + "[0.990s][info][gc,phases ] GC(0) Y: Young Generation", + "[0.990s][info][gc,phases ] GC(0) Y: Pause Mark Start (Major) 0.011ms", + "[1.000s][info][gc,phases ] GC(0) Y: Concurrent Mark 9.935ms", + "[1.000s][info][gc,phases ] GC(0) Y: Pause Mark End 0.013ms", + "[1.001s][info][gc,phases ] GC(0) Y: Concurrent Mark Free 0.001ms", + "[1.001s][info][gc,phases ] GC(0) Y: Concurrent Reset Relocation Set 0.000ms", + "[1.006s][info][gc,reloc ] GC(0) Y: Using tenuring threshold: 1 (Computed)", + "[1.007s][info][gc,phases ] GC(0) Y: Concurrent Select Relocation Set 5.893ms", + "[1.007s][info][gc,phases ] GC(0) Y: Pause Relocate Start 0.012ms", + "[1.012s][info][gc,phases ] GC(0) Y: Concurrent Relocate 4.910ms", + "[1.012s][info][gc,alloc ] GC(0) Y: Mark Start Mark End Relocate Start Relocate End ", + "[1.012s][info][gc,alloc ] GC(0) Y: Allocation Stalls: 0 0 0 0 ", + "[1.012s][info][gc,load ] GC(0) Y: Load: 0.00 (0%) / 0.00 (0%) / 0.00 (0%)", + "[1.012s][info][gc,mmu ] GC(0) Y: MMU: 2ms/99.3%, 5ms/99.7%, 10ms/99.7%, 20ms/99.8%, 50ms/99.9%, 100ms/100.0%", + "[1.012s][info][gc,marking ] GC(0) Y: Mark: 1 stripe(s), 2 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s) ", + "[1.012s][info][gc,marking ] GC(0) Y: Mark Stack Usage: 32M", + "[1.012s][info][gc,nmethod ] GC(0) Y: NMethods: 2166 registered, 0 unregistered", + "[1.012s][info][gc,metaspace] GC(0) Y: Metaspace: 21M used, 21M committed, 1088M reserved", + "[1.012s][info][gc,reloc ] GC(0) Y: Candidates Selected In-Place Size Empty Relocated ", + "[1.012s][info][gc,reloc ] GC(0) Y: Small Pages: 27 20 0 54M 0M 5M ", + "[1.012s][info][gc,reloc ] GC(0) Y: Medium Pages: 1 0 0 32M 0M 0M ", + "[1.012s][info][gc,reloc ] GC(0) Y: Large Pages: 0 0 0 0M 0M 0M ", + "[1.012s][info][gc,reloc ] GC(0) Y: Forwarding Usage: 2M", + "[1.012s][info][gc,reloc ] GC(0) Y: Age Table:", + "[1.012s][info][gc,reloc ] GC(0) Y: Live Garbage Small Medium Large ", + "[1.012s][info][gc,reloc ] GC(0) Y: Eden 14M (0%) 71M (1%) 27 / 20 1 / 0 0 / 0 ", + "[1.012s][info][gc,heap ] GC(0) Y: Min Capacity: 8M(0%)", + "[1.012s][info][gc,heap ] GC(0) Y: Max Capacity: 8094M(100%)", + "[1.012s][info][gc,heap ] GC(0) Y: Soft Max Capacity: 7284M(90%)", + "[1.012s][info][gc,heap ] GC(0) Y: Heap Statistics:", + "[1.012s][info][gc,heap ] GC(0) Y: Mark Start Mark End Relocate Start Relocate End High Low ", + "[1.012s][info][gc,heap ] GC(0) Y: Capacity: 506M (6%) 506M (6%) 506M (6%) 506M (6%) 506M (6%) 506M (6%) ", + "[1.012s][info][gc,heap ] GC(0) Y: Free: 8008M (99%) 8006M (99%) 8006M (99%) 8040M (99%) 8040M (99%) 8000M (99%) ", + "[1.012s][info][gc,heap ] GC(0) Y: Used: 86M (1%) 88M (1%) 88M (1%) 54M (1%) 94M (1%) 54M (1%) ", + "[1.012s][info][gc,heap ] GC(0) Y: Young Generation Statistics:", + "[1.012s][info][gc,heap ] GC(0) Y: Mark Start Mark End Relocate Start Relocate End ", + "[1.012s][info][gc,heap ] GC(0) Y: Used: 86M (1%) 88M (1%) 88M (1%) 54M (1%) ", + "[1.012s][info][gc,heap ] GC(0) Y: Live: - 14M (0%) 14M (0%) 14M (0%) ", + "[1.012s][info][gc,heap ] GC(0) Y: Garbage: - 71M (1%) 71M (1%) 30M (0%) ", + "[1.012s][info][gc,heap ] GC(0) Y: Allocated: - 2M (0%) 2M (0%) 9M (0%) ", + "[1.012s][info][gc,heap ] GC(0) Y: Reclaimed: - - 0M (0%) 41M (1%) ", + "[1.012s][info][gc,heap ] GC(0) Y: Promoted: - - 0M (0%) 0M (0%) ", + "[1.012s][info][gc,heap ] GC(0) Y: Compacted: - - - 8M (0%) ", + "[1.012s][info][gc,phases ] GC(0) Y: Young Generation 86M(1%)->54M(1%) 0.022s", + + // 1 - + "[1.012s][info][gc,phases ] GC(0) O: Old Generation", + "[1.012s][info][gc,phases ] GC(0) O: Concurrent Mark 0.251ms", + "[1.012s][info][gc,phases ] GC(0) O: Pause Mark End 0.008ms", + "[1.013s][info][gc,phases ] GC(0) O: Concurrent Mark Free 0.155ms", + "[1.016s][info][gc,phases ] GC(0) O: Concurrent Process Non-Strong 3.677ms", + "[1.016s][info][gc,phases ] GC(0) O: Concurrent Reset Relocation Set 0.001ms", + "[1.018s][info][gc,phases ] GC(0) O: Concurrent Select Relocation Set 1.296ms", + "[1.018s][info][gc,task ] GC(0) O: Using 2 Workers for Old Generation", + "[1.062s][info][gc,task ] GC(0) O: Using 1 Workers for Old Generation", + "[1.062s][info][gc,phases ] GC(0) O: Concurrent Remap Roots 43.778ms", + "[1.062s][info][gc,phases ] GC(0) O: Pause Relocate Start 0.018ms", + "[1.062s][info][gc,phases ] GC(0) O: Concurrent Relocate 0.033ms", + "[1.062s][info][gc,alloc ] GC(0) O: Mark Start Mark End Relocate Start Relocate End ", + "[1.062s][info][gc,alloc ] GC(0) O: Allocation Stalls: 0 0 0 0 ", + "[1.062s][info][gc,load ] GC(0) O: Load: 0.00 (0%) / 0.00 (0%) / 0.00 (0%)", + "[1.062s][info][gc,mmu ] GC(0) O: MMU: 2ms/99.1%, 5ms/99.6%, 10ms/99.7%, 20ms/99.8%, 50ms/99.9%, 100ms/99.9%", + "[1.062s][info][gc,marking ] GC(0) O: Mark: 1 stripe(s), 1 proactive flush(es), 1 terminate flush(es), 0 completion(s), 0 continuation(s) ", + "[1.062s][info][gc,marking ] GC(0) O: Mark Stack Usage: 0M", + "[1.062s][info][gc,nmethod ] GC(0) O: NMethods: 1938 registered, 269 unregistered", + "[1.062s][info][gc,metaspace] GC(0) O: Metaspace: 21M used, 21M committed, 1088M reserved", + "[1.062s][info][gc,ref ] GC(0) O: Encountered Discovered Enqueued ", + "[1.062s][info][gc,ref ] GC(0) O: Soft References: 3704 0 0 ", + "[1.062s][info][gc,ref ] GC(0) O: Weak References: 1514 0 0 ", + "[1.062s][info][gc,ref ] GC(0) O: Final References: 0 0 0 ", + "[1.062s][info][gc,ref ] GC(0) O: Phantom References: 762 0 0 ", + "[1.062s][info][gc,heap ] GC(0) O: Min Capacity: 8M(0%)", + "[1.062s][info][gc,heap ] GC(0) O: Max Capacity: 8094M(100%)", + "[1.062s][info][gc,heap ] GC(0) O: Soft Max Capacity: 7284M(90%)", + "[1.062s][info][gc,heap ] GC(0) O: Heap Statistics:", + "[1.062s][info][gc,heap ] GC(0) O: Mark Start Mark End Relocate Start Relocate End High Low ", + "[1.062s][info][gc,heap ] GC(0) O: Capacity: 506M (6%) 506M (6%) 506M (6%) 506M (6%) 506M (6%) 506M (6%) ", + "[1.062s][info][gc,heap ] GC(0) O: Free: 8008M (99%) 8040M (99%) 8038M (99%) 8038M (99%) 8040M (99%) 8000M (99%) ", + "[1.062s][info][gc,heap ] GC(0) O: Used: 86M (1%) 54M (1%) 56M (1%) 56M (1%) 94M (1%) 54M (1%) ", + "[1.062s][info][gc,heap ] GC(0) O: Old Generation Statistics:", + "[1.062s][info][gc,heap ] GC(0) O: Mark Start Mark End Relocate Start Relocate End ", + "[1.062s][info][gc,heap ] GC(0) O: Used: 0M (0%) 0M (0%) 0M (0%) 0M (0%) ", + "[1.062s][info][gc,heap ] GC(0) O: Live: - 0M (0%) 0M (0%) 0M (0%) ", + "[1.062s][info][gc,heap ] GC(0) O: Garbage: - 0M (0%) 0M (0%) 0M (0%) ", + "[1.062s][info][gc,heap ] GC(0) O: Allocated: - 0M (0%) 0M (0%) 0M (0%) ", + "[1.062s][info][gc,heap ] GC(0) O: Reclaimed: - - 0M (0%) 0M (0%) ", + "[1.062s][info][gc,heap ] GC(0) O: Compacted: - - - 0M (0%) ", + "[1.062s][info][gc,phases ] GC(0) O: Old Generation 54M(1%)->56M(1%) 0.050s", + "[1.062s][info][gc ] GC(0) Major Collection (Metadata GC Threshold) 86M(1%)->56M(1%) 0.073s", + }; + + int expectedEventCount = 2; + + List jvmEvents = feedParser(lines); + assertEquals(jvmEvents.size(), expectedEventCount); + + // TODO: Only basic testing to make sure no extra events were being created by fixes for no-details logs. + + // 0 - ZGCYoungCollection + assertTrue(jvmEvents.get(0) instanceof ZGCYoungCollection); + ZGCYoungCollection evt0 = (ZGCYoungCollection) jvmEvents.get(0); + assertEquals(new DateTimeStamp(0.990), evt0.getDateTimeStamp()); + assertEquals(GCCause.METADATA_GENERATION_THRESHOLD, evt0.getGCCause()); + assertEquals(ZGCPhase.MAJOR_YOUNG, evt0.getPhase()); + assertZGCMemorySummary(evt0.getMemorySummary(), 86*M, 54*M); + assertDoubleEquals(evt0.getDuration(), 0.022); + // 1 - ZGCOldCollection(Major) + assertTrue(jvmEvents.get(1) instanceof ZGCOldCollection); + ZGCOldCollection evt1 = (ZGCOldCollection) jvmEvents.get(1); + assertEquals(new DateTimeStamp(1.012), evt1.getDateTimeStamp()); + assertEquals(GCCause.METADATA_GENERATION_THRESHOLD, evt1.getGCCause()); + assertEquals(ZGCPhase.MAJOR_OLD, evt1.getPhase()); + assertZGCMemorySummary(evt1.getMemorySummary(), 54*M, 56*M); + assertDoubleEquals(evt1.getDuration(), 0.050); + + } + + private void assertZGCMemorySummary(ZGCMemorySummary summary, long before, long after) { + assertNotNull(summary); + assertEquals(summary.getOccupancyBefore(), before); + assertEquals(summary.getOccupancyAfter(), after); + } + private boolean checkZGCMemoryPoolSummary(ZGCMemoryPoolSummary summary, long capacity, long free, long used) { return summary.getCapacity() == capacity && summary.getFree() == free && summary.getUsed() == used; }