From cbe36cd82cecc63512710fc18596104d3a648a5d Mon Sep 17 00:00:00 2001
From: Chris Larsen <clarsen@yahoo-inc.com>
Date: Mon, 25 Apr 2016 20:48:43 -0700
Subject: [PATCH] [core] Add the Utils.getGCTotalTime() method for showing how
long the JVM spent in GC. It now prints the time and percent of time in the
final output. Also fix cases where the garbage collector implementation
returns -1 if the count or time isn't implemented.
---
core/src/main/java/com/yahoo/ycsb/Client.java | 7 +++++++
core/src/main/java/com/yahoo/ycsb/Utils.java | 17 +++++++++++++++++
.../src/test/java/com/yahoo/ycsb/TestUtils.java | 2 ++
3 files changed, 26 insertions(+)
diff --git a/core/src/main/java/com/yahoo/ycsb/Client.java b/core/src/main/java/com/yahoo/ycsb/Client.java
index c7ff4952..0e099118 100644
--- a/core/src/main/java/com/yahoo/ycsb/Client.java
+++ b/core/src/main/java/com/yahoo/ycsb/Client.java
@@ -76,6 +76,7 @@ class StatusThread extends Thread
private double _maxLoadAvg;
private double _minLoadAvg = Double.MAX_VALUE;
private long lastGCCount = 0;
+ private long lastGCTime = 0;
/**
* Creates a new StatusThread without JVM stat tracking.
@@ -274,7 +275,10 @@ class StatusThread extends Thread
final long gcs = Utils.getGCTotalCollectionCount();
_measurements.measure("GCS", (int)(gcs - lastGCCount));
+ final long gcTime = Utils.getGCTotalTime();
+ _measurements.measure("GCS_TIME", (int)(gcTime - lastGCTime));
lastGCCount = gcs;
+ lastGCTime = gcTime;
}
/** @return The maximum threads running during the test. */
@@ -693,6 +697,9 @@ public class Client
exporter.write("OVERALL", "Throughput(ops/sec)", throughput);
exporter.write("TOTAL_GCs", "Count", Utils.getGCTotalCollectionCount());
+ final long gcTime = Utils.getGCTotalTime();
+ exporter.write("TOTAL_GC_TIME", "Time(ms)", gcTime);
+ exporter.write("TOTAL_GC_TIME_%", "Time(%)", ((double)gcTime / runtime) * (double)100);
if (statusthread != null && statusthread.trackJVMStats()) {
exporter.write("MAX_MEM_USED", "MBs", statusthread.getMaxUsedMem());
exporter.write("MIN_MEM_USED", "MBs", statusthread.getMinUsedMem());
diff --git a/core/src/main/java/com/yahoo/ycsb/Utils.java b/core/src/main/java/com/yahoo/ycsb/Utils.java
index 21990677..a6af3e17 100644
--- a/core/src/main/java/com/yahoo/ycsb/Utils.java
+++ b/core/src/main/java/com/yahoo/ycsb/Utils.java
@@ -219,8 +219,25 @@ public class Utils
ManagementFactory.getGarbageCollectorMXBeans();
long count = 0;
for (final GarbageCollectorMXBean bean : gcBeans) {
+ if (bean.getCollectionCount() < 0) {
+ continue;
+ }
count += bean.getCollectionCount();
}
return count;
}
+
+ /** @return The total time, in milliseconds, spent in GC. */
+ public static long getGCTotalTime() {
+ final List<GarbageCollectorMXBean> gcBeans =
+ ManagementFactory.getGarbageCollectorMXBeans();
+ long time = 0;
+ for (final GarbageCollectorMXBean bean : gcBeans) {
+ if (bean.getCollectionTime() < 0) {
+ continue;
+ }
+ time += bean.getCollectionTime();
+ }
+ return time;
+ }
}
diff --git a/core/src/test/java/com/yahoo/ycsb/TestUtils.java b/core/src/test/java/com/yahoo/ycsb/TestUtils.java
index 71213137..f9fddf76 100644
--- a/core/src/test/java/com/yahoo/ycsb/TestUtils.java
+++ b/core/src/test/java/com/yahoo/ycsb/TestUtils.java
@@ -110,6 +110,8 @@ public class TestUtils {
Utils.getSystemLoadAverage();
// This will probably be zero but should never be negative.
assertTrue(Utils.getGCTotalCollectionCount() >= 0);
+ // Could be zero similar to GC total collection count
+ assertTrue(Utils.getGCTotalTime() >= 0);
}
/**
--
GitLab