test/hotspot/jtreg/gc/z/TestGarbageCollectorMXBean.java

*** 32,48 ****
  
  import java.lang.management.ManagementFactory;
  import java.util.concurrent.atomic.AtomicInteger;
  import java.util.concurrent.atomic.AtomicLong;
  import javax.management.Notification;
! import javax.management.NotificationBroadcaster;
  import javax.management.NotificationListener;
  import javax.management.openmbean.CompositeData;
  
  import com.sun.management.GarbageCollectionNotificationInfo;
  
  public class TestGarbageCollectorMXBean {
      public static void main(String[] args) throws Exception {
          final long M = 1024 * 1024;
          final long initialCapacity = Long.parseLong(args[0]) * M;
          final long maxCapacity = Long.parseLong(args[1]) * M;
          final AtomicInteger cycles = new AtomicInteger();
--- 32,55 ----
  
  import java.lang.management.ManagementFactory;
  import java.util.concurrent.atomic.AtomicInteger;
  import java.util.concurrent.atomic.AtomicLong;
  import javax.management.Notification;
! import javax.management.NotificationEmitter;
  import javax.management.NotificationListener;
  import javax.management.openmbean.CompositeData;
  
  import com.sun.management.GarbageCollectionNotificationInfo;
  
  public class TestGarbageCollectorMXBean {
+     private static final long startTime = System.nanoTime();
+ 
+     private static void log(String msg) {
+         final String elapsedSeconds = String.format("%.3fs", (System.nanoTime() - startTime) / 1_000_000_000.0);
+         System.out.println("[" + elapsedSeconds + "] (" + Thread.currentThread().getName() + ") " + msg);
+     }
+ 
      public static void main(String[] args) throws Exception {
          final long M = 1024 * 1024;
          final long initialCapacity = Long.parseLong(args[0]) * M;
          final long maxCapacity = Long.parseLong(args[1]) * M;
          final AtomicInteger cycles = new AtomicInteger();
*** 65,167 ****
              final var endTime = info.getGcInfo().getEndTime();
              final var duration = info.getGcInfo().getDuration();
              final var memoryUsageBeforeGC = info.getGcInfo().getMemoryUsageBeforeGc().get("ZHeap");
              final var memoryUsageAfterGC = info.getGcInfo().getMemoryUsageAfterGc().get("ZHeap");
  
!             System.out.println(name + " (" + type + ")");
!             System.out.println("                  Id: " + id);
!             System.out.println("              Action: " + action);
!             System.out.println("               Cause: " + cause);
!             System.out.println("           StartTime: " + startTime);
!             System.out.println("             EndTime: " + endTime);
!             System.out.println("            Duration: " + duration);
!             System.out.println(" MemoryUsageBeforeGC: " + memoryUsageBeforeGC);
!             System.out.println("  MemoryUsageAfterGC: " + memoryUsageAfterGC);
!             System.out.println();
  
              if (name.equals("ZGC")) {
                  cycles.incrementAndGet();
              } else {
!                 System.out.println("ERROR: Name");
                  errors.incrementAndGet();
              }
  
              if (!action.equals("end of major GC")) {
!                 System.out.println("ERROR: Action");
                  errors.incrementAndGet();
              }
  
              if (memoryUsageBeforeGC.getInit() != initialCapacity) {
!                 System.out.println("ERROR: MemoryUsageBeforeGC.init");
                  errors.incrementAndGet();
              }
  
              if (memoryUsageBeforeGC.getUsed() > initialCapacity) {
!                 System.out.println("ERROR: MemoryUsageBeforeGC.used");
                  errors.incrementAndGet();
              }
  
              if (memoryUsageBeforeGC.getCommitted() != initialCapacity) {
!                 System.out.println("ERROR: MemoryUsageBeforeGC.committed");
                  errors.incrementAndGet();
              }
  
              if (memoryUsageBeforeGC.getMax() != maxCapacity) {
!                 System.out.println("ERROR: MemoryUsageBeforeGC.max");
                  errors.incrementAndGet();
              }
  
              if (!cause.equals("System.gc()")) {
!                 System.out.println("ERROR: Cause");
                  errors.incrementAndGet();
              }
  
              if (startTime > endTime) {
!                 System.out.println("ERROR: StartTime");
                  errors.incrementAndGet();
              }
  
              if (endTime - startTime != duration) {
!                 System.out.println("ERROR: Duration");
                  errors.incrementAndGet();
              }
          };
  
          // Collect garbage created at startup
          System.gc();
  
          // Register GC event listener
          for (final var collector : ManagementFactory.getGarbageCollectorMXBeans()) {
!             final NotificationBroadcaster broadcaster = (NotificationBroadcaster)collector;
!             broadcaster.addNotificationListener(listener, null, null);
          }
  
          final int minCycles = 5;
  
          // Run GCs
          for (int i = 0; i < minCycles; i++) {
              System.gc();
          }
  
!         // Wait at most 60 seconds
!         for (int i = 0; i < 60; i++) {
              Thread.sleep(1000);
              if (cycles.get() >= minCycles) {
!                 // All events received
                  break;
              }
          }
  
          final int actualCycles = cycles.get();
          final int actualErrors = errors.get();
  
!         System.out.println("   minCycles: " + minCycles);
!         System.out.println("actualCycles: " + actualCycles);
!         System.out.println("actualErrors: " + actualErrors);
  
          // Verify number of cycle events
!         if (cycles.get() < minCycles) {
              throw new Exception("Unexpected cycles");
          }
  
          // Verify number of errors
          if (actualErrors != 0) {
--- 72,177 ----
              final var endTime = info.getGcInfo().getEndTime();
              final var duration = info.getGcInfo().getDuration();
              final var memoryUsageBeforeGC = info.getGcInfo().getMemoryUsageBeforeGc().get("ZHeap");
              final var memoryUsageAfterGC = info.getGcInfo().getMemoryUsageAfterGc().get("ZHeap");
  
!             log(name + " (" + type + ")");
!             log("                  Id: " + id);
!             log("              Action: " + action);
!             log("               Cause: " + cause);
!             log("           StartTime: " + startTime);
!             log("             EndTime: " + endTime);
!             log("            Duration: " + duration);
!             log(" MemoryUsageBeforeGC: " + memoryUsageBeforeGC);
!             log("  MemoryUsageAfterGC: " + memoryUsageAfterGC);
!             log("");
  
              if (name.equals("ZGC")) {
                  cycles.incrementAndGet();
              } else {
!                 log("ERROR: Name");
                  errors.incrementAndGet();
              }
  
              if (!action.equals("end of major GC")) {
!                 log("ERROR: Action");
                  errors.incrementAndGet();
              }
  
              if (memoryUsageBeforeGC.getInit() != initialCapacity) {
!                 log("ERROR: MemoryUsageBeforeGC.init");
                  errors.incrementAndGet();
              }
  
              if (memoryUsageBeforeGC.getUsed() > initialCapacity) {
!                 log("ERROR: MemoryUsageBeforeGC.used");
                  errors.incrementAndGet();
              }
  
              if (memoryUsageBeforeGC.getCommitted() != initialCapacity) {
!                 log("ERROR: MemoryUsageBeforeGC.committed");
                  errors.incrementAndGet();
              }
  
              if (memoryUsageBeforeGC.getMax() != maxCapacity) {
!                 log("ERROR: MemoryUsageBeforeGC.max");
                  errors.incrementAndGet();
              }
  
              if (!cause.equals("System.gc()")) {
!                 log("ERROR: Cause");
                  errors.incrementAndGet();
              }
  
              if (startTime > endTime) {
!                 log("ERROR: StartTime");
                  errors.incrementAndGet();
              }
  
              if (endTime - startTime != duration) {
!                 log("ERROR: Duration");
                  errors.incrementAndGet();
              }
          };
  
          // Collect garbage created at startup
          System.gc();
  
          // Register GC event listener
          for (final var collector : ManagementFactory.getGarbageCollectorMXBeans()) {
!             final NotificationEmitter emitter = (NotificationEmitter)collector;
!             emitter.addNotificationListener(listener, null, null);
          }
  
          final int minCycles = 5;
  
          // Run GCs
          for (int i = 0; i < minCycles; i++) {
+             log("Starting GC " + i);
              System.gc();
          }
  
!         // Wait at most 90 seconds
!         for (int i = 0; i < 90; i++) {
!             log("Waiting...");
              Thread.sleep(1000);
+ 
              if (cycles.get() >= minCycles) {
!                 log("All events received!");
                  break;
              }
          }
  
          final int actualCycles = cycles.get();
          final int actualErrors = errors.get();
  
!         log("   minCycles: " + minCycles);
!         log("actualCycles: " + actualCycles);
!         log("actualErrors: " + actualErrors);
  
          // Verify number of cycle events
!         if (actualCycles < minCycles) {
              throw new Exception("Unexpected cycles");
          }
  
          // Verify number of errors
          if (actualErrors != 0) {