Merge pull request #719 from manolama/jvmstats

[core] Add the "measurement.trackjvm" property to measure JVM statistics

core/src/main/java/com/yahoo/ycsb/Client.java

@@ -47,6 +47,12 @@ class StatusThread extends Thread
   /** Counts down each of the clients completing. */
   private final CountDownLatch _completeLatch;
 
+  /** Stores the measurements for the run. */
+  private final Measurements _measurements;
+  
+  /** Whether or not to track the JVM stats per run */
+  private final boolean _trackJVMStats;
+  
   /** The clients that are running. */
   private final List<ClientThread> _clients;
 
@@ -56,8 +62,17 @@ class StatusThread extends Thread
   /** The interval for reporting status. */
   private long _sleeptimeNs;
 
+  /** JVM max/mins */
+  private int _maxThreads;
+  private int _minThreads = Integer.MAX_VALUE;
+  private long _maxUsedMem;
+  private long _minUsedMem = Long.MAX_VALUE;
+  private double _maxLoadAvg;
+  private double _minLoadAvg = Double.MAX_VALUE;
+  private long lastGCCount = 0;
+
   /**
-   * Creates a new StatusThread.
+   * Creates a new StatusThread without JVM stat tracking.
    *
    * @param completeLatch The latch that each client thread will {@link CountDownLatch#countDown()} as they complete.
    * @param clients The clients to collect metrics from.
@@ -67,14 +82,33 @@ class StatusThread extends Thread
    */
   public StatusThread(CountDownLatch completeLatch, List<ClientThread> clients,
                       String label, boolean standardstatus, int statusIntervalSeconds)
+  {
+    this(completeLatch, clients, label, standardstatus, statusIntervalSeconds, false);
+  }
+  
+  /**
+   * Creates a new StatusThread.
+   *
+   * @param completeLatch The latch that each client thread will {@link CountDownLatch#countDown()} as they complete.
+   * @param clients The clients to collect metrics from.
+   * @param label The label for the status.
+   * @param standardstatus If true the status is printed to stdout in addition to stderr.
+   * @param statusIntervalSeconds The number of seconds between status updates.
+   * @param trackJVMStats Whether or not to track JVM stats.
+   */
+  public StatusThread(CountDownLatch completeLatch, List<ClientThread> clients,
+                      String label, boolean standardstatus, int statusIntervalSeconds,
+                      boolean trackJVMStats)
   {
     _completeLatch=completeLatch;
     _clients=clients;
     _label=label;
     _standardstatus=standardstatus;
     _sleeptimeNs=TimeUnit.SECONDS.toNanos(statusIntervalSeconds);
+    _measurements = Measurements.getMeasurements();
+    _trackJVMStats = trackJVMStats;
   }
-
+  
   /**
    * Run and periodically report status.
    */
@@ -94,6 +128,10 @@ class StatusThread extends Thread
       long nowMs=System.currentTimeMillis();
 
       lastTotalOps = computeStats(startTimeMs, startIntervalMs, nowMs, lastTotalOps);
+      
+      if (_trackJVMStats) {
+        measureJVM();
+      }
 
       alldone = waitForClientsUntil(deadline);
 
@@ -102,6 +140,9 @@ class StatusThread extends Thread
     }
     while (!alldone);
 
+    if (_trackJVMStats) {
+      measureJVM();
+    }
     // Print the final stats.
     computeStats(startTimeMs, startIntervalMs, System.currentTimeMillis(), lastTotalOps);
   }
@@ -187,6 +228,83 @@ class StatusThread extends Thread
 
     return alldone;
   }
+
+  /** Executes the JVM measurements. */
+  private void measureJVM() {
+    final int threads = Utils.getActiveThreadCount();
+    if (threads < _minThreads) {
+      _minThreads = threads;
+    }
+    if (threads > _maxThreads) {
+      _maxThreads = threads;
+    }
+    _measurements.measure("THREAD_COUNT", threads);
+    
+    // TODO - once measurements allow for other number types, switch to using
+    // the raw bytes. Otherwise we can track in MB to avoid negative values 
+    // when faced with huge heaps.
+    final int usedMem = Utils.getUsedMemoryMegaBytes();
+    if (usedMem < _minUsedMem) {
+      _minUsedMem = usedMem;
+    }
+    if (usedMem > _maxUsedMem) {
+      _maxUsedMem = usedMem;
+    }
+    _measurements.measure("USED_MEM_MB", usedMem);
+    
+    // Some JVMs may not implement this feature so if the value is less than
+    // zero, just ommit it.
+    final double systemLoad = Utils.getSystemLoadAverage();
+    if (systemLoad >= 0) {
+      // TODO - store the double if measurements allows for them
+      _measurements.measure("SYS_LOAD_AVG", (int)systemLoad);
+      if (systemLoad > _maxLoadAvg) {
+        _maxLoadAvg = systemLoad;
+      }
+      if (systemLoad < _minLoadAvg) {
+        _minLoadAvg = systemLoad;
+      }
+    }
+     
+    final long gcs = Utils.getGCTotalCollectionCount();
+    _measurements.measure("GCS", (int)(gcs - lastGCCount));
+    lastGCCount = gcs;
+  }
+  
+  /** @return The maximum threads running during the test. */
+  public int getMaxThreads() {
+    return _maxThreads;
+  }
+  
+  /** @return The minimum threads running during the test. */
+  public int getMinThreads() {
+    return _minThreads;
+  }
+  
+  /** @return The maximum memory used during the test. */
+  public long getMaxUsedMem() {
+    return _maxUsedMem;
+  }
+  
+  /** @return The minimum memory used during the test. */
+  public long getMinUsedMem() {
+    return _minUsedMem;
+  }
+  
+  /** @return The maximum load average during the test. */
+  public double getMaxLoadAvg() {
+    return _maxLoadAvg;
+  }
+  
+  /** @return The minimum load average during the test. */
+  public double getMinLoadAvg() {
+    return _minLoadAvg;
+  }
+
+  /** @return Whether or not the thread is tracking JVM stats. */
+  public boolean trackJVMStats() {
+    return _trackJVMStats;
+  }
 }
 
 /**
@@ -474,6 +592,8 @@ public class Client
    */
   public static final String DO_TRANSACTIONS_PROPERTY = "dotransactions";
 
+  /** An optional thread used to track progress and measure JVM stats. */
+  private static StatusThread statusthread = null;
 
   public static void usageMessage()
   {
@@ -553,6 +673,16 @@ public class Client
       exporter.write("OVERALL", "RunTime(ms)", runtime);
       double throughput = 1000.0 * (opcount) / (runtime);
       exporter.write("OVERALL", "Throughput(ops/sec)", throughput);
+      
+      exporter.write("TOTAL_GCs", "Count", Utils.getGCTotalCollectionCount());
+      if (statusthread != null && statusthread.trackJVMStats()) {
+        exporter.write("MAX_MEM_USED", "MBs", statusthread.getMaxUsedMem());
+        exporter.write("MIN_MEM_USED", "MBs", statusthread.getMinUsedMem());
+        exporter.write("MAX_THREADS", "Count", statusthread.getMaxThreads());
+        exporter.write("MIN_THREADS", "Count", statusthread.getMinThreads());
+        exporter.write("MAX_SYS_LOAD_AVG", "Load", statusthread.getMaxLoadAvg());
+        exporter.write("MIN_SYS_LOAD_AVG", "Load", statusthread.getMinLoadAvg());
+      }
 
       Measurements.getMeasurements().exportMeasurements(exporter);
     } finally
@@ -894,8 +1024,6 @@ public class Client
       clients.add(t);
     }
 
-    StatusThread statusthread=null;
-
     if (status)
     {
       boolean standardstatus=false;
@@ -904,7 +1032,9 @@ public class Client
         standardstatus=true;
       }
       int statusIntervalSeconds = Integer.parseInt(props.getProperty("status.interval","10"));
-      statusthread=new StatusThread(completeLatch,clients,label,standardstatus,statusIntervalSeconds);
+      boolean trackJVMStats = props.getProperty(Measurements.MEASUREMENT_TRACK_JVM_PROPERTY, 
+          Measurements.MEASUREMENT_TRACK_JVM_PROPERTY_DEFAULT).equals("true");
+      statusthread=new StatusThread(completeLatch,clients,label,standardstatus,statusIntervalSeconds,trackJVMStats);
       statusthread.start();
     }
 

core/src/main/java/com/yahoo/ycsb/Utils.java

@@ -17,6 +17,10 @@
 
 package com.yahoo.ycsb;
 
+import java.lang.management.GarbageCollectorMXBean;
+import java.lang.management.ManagementFactory;
+import java.lang.management.OperatingSystemMXBean;
+import java.util.List;
 import java.util.Random;
 
 /**
@@ -174,4 +178,49 @@ public class Utils
       public static byte[] doubleToBytes(final double val) {
         return longToBytes(Double.doubleToRawLongBits(val));
       }
+      
+      /**
+       * Measure the estimated active thread count in the current thread group.
+       * Since this calls {@link Thread.activeCount} it should be called from the
+       * main thread or one started by the main thread. Threads included in the
+       * count can be in any state. 
+       * For a more accurate count we could use {@link Thread.getAllStackTraces().size()} 
+       * but that freezes the JVM and incurs a high overhead.
+       * @return An estimated thread count, good for showing the thread count
+       * over time.
+       */
+      public static int getActiveThreadCount() {
+        return Thread.activeCount();
+      }
+      
+      /** @return The currently used memory in bytes */
+      public static long getUsedMemoryBytes() {
+        final Runtime runtime = Runtime.getRuntime();
+        return runtime.totalMemory() - runtime.freeMemory();
+      }
+      
+      /** @return The currently used memory in megabytes. */
+      public static int getUsedMemoryMegaBytes() {
+        return (int)(getUsedMemoryBytes() / 1024 / 1024);
+      }
+      
+      /** @return The current system load average if supported by the JDK. 
+       * If it's not supported, the value will be negative. */
+      public static double getSystemLoadAverage() {
+        final OperatingSystemMXBean osBean = 
+            ManagementFactory.getOperatingSystemMXBean();
+        return osBean.getSystemLoadAverage();
+      }
+      
+      /** @return The total number of garbage collections executed for all 
+       * memory pools. */ 
+      public static long getGCTotalCollectionCount() {
+        final List<GarbageCollectorMXBean> gcBeans = 
+            ManagementFactory.getGarbageCollectorMXBeans();
+        long count = 0;
+        for (final GarbageCollectorMXBean bean : gcBeans) {
+          count += bean.getCollectionCount();
+        }
+        return count;
+      }
 }

core/src/main/java/com/yahoo/ycsb/measurements/Measurements.java

@@ -49,6 +49,9 @@ public class Measurements {
   
   public static final String MEASUREMENT_INTERVAL = "measurement.interval";
   private static final String MEASUREMENT_INTERVAL_DEFAULT = "op";
+  
+  public static final String MEASUREMENT_TRACK_JVM_PROPERTY = "measurement.trackjvm";
+  public static final String MEASUREMENT_TRACK_JVM_PROPERTY_DEFAULT = "false";
 
   static Measurements singleton=null;
   static Properties measurementproperties=null;

core/src/test/java/com/yahoo/ycsb/TestUtils.java

@@ -99,6 +99,19 @@ public class TestUtils {
     Utils.bytesToDouble(new byte[] { 0, 0, 0, 0, 0, 0, 0 });
   }
   
+  @Test
+  public void jvmUtils() throws Exception {
+    // This should ALWAYS return at least one thread.
+    assertTrue(Utils.getActiveThreadCount() > 0);
+    // This should always be greater than 0 or something is goofed up in the JVM.
+    assertTrue(Utils.getUsedMemoryBytes() > 0);
+    // Some operating systems may not implement this so we don't have a good
+    // test. Just make sure it doesn't throw an exception.
+    Utils.getSystemLoadAverage();
+    // This will probably be zero but should never be negative.
+    assertTrue(Utils.getGCTotalCollectionCount() >= 0);
+  }
+  
   /**
    * Since this version of TestNG doesn't appear to have an assertArrayEquals,
    * this will compare the two to make sure they're the same. 

workloads/workload_template

-# Copyright (c) 2012 YCSB contributors. All rights reserved.
+# Copyright (c) 2012-2016 YCSB contributors. All rights reserved.
 #
 # Licensed under the Apache License, Version 2.0 (the "License"); you
 # may not use this file except in compliance with the License. You
@@ -133,6 +133,16 @@ measurementtype=histogram
 # a new output file will be created.
 #measurement.raw.output_file = /tmp/your_output_file_for_this_run
 
+# JVM Reporting.
+#
+# Measure JVM information over time including GC counts, max and min memory
+# used, max and min thread counts, max and min system load and others. This
+# setting must be enabled in conjunction with the "-s" flag to run the status
+# thread. Every "status.interval", the status thread will capture JVM 
+# statistics and record the results. At the end of the run, max and mins will
+# be recorded.
+# measurement.trackjvm = false
+
 # The range of latencies to track in the histogram (milliseconds)
 histogram.buckets=1000
 
@@ -168,4 +178,4 @@ timeseries.granularity=1000
 # core_workload_insertion_retry_limit = 0
 #
 # the following number controls the interval between retries (in seconds):
-# core_workload_insertion_retry_interval = 3
+# core_workload_insertion_retry_interval = 3
\ No newline at end of file