CODETOOLS-7901375: Generate missing samples

Vladimir Sitnikov sitnikov.vladimir at gmail.com
Sat Apr 18 12:43:28 UTC 2015


Hi,

Please review a patch for "CODETOOLS-7901375 JMH and missing results:
treat them as zeroes, instead of blankly skipping over them".

I updated aggregation of secondaryResults in BenchmarkResult only.
Not sure what are "benchmarkResults".
Not sure if "thread aggregator" might miss results.

GCProfiler and GCProfilerTest are updated to test the fix.
It looks like GCProfiler can now "safely" be used without warmup =)

-- 
Regards,
Vladimir Sitnikov
-------------- next part --------------
# HG changeset patch
# User Vladimir Sitnikov <sitnikov.vladimir at gmail.com>
# Date 1429357829 -10800
#      Sat Apr 18 14:50:29 2015 +0300
# Node ID d57b9e02ec35c87e3af8865e239d429329b84a2f
# Parent  869982787a9213c3e6b19a04dac6eb5da81619cd
Generate zero results if some lables are missing in some iterations

diff -r 869982787a92 -r d57b9e02ec35 jmh-core-it/src/test/java/org/openjdk/jmh/it/profilers/GCProfilerTest.java
--- a/jmh-core-it/src/test/java/org/openjdk/jmh/it/profilers/GCProfilerTest.java	Thu Apr 16 23:04:20 2015 +0300
+++ b/jmh-core-it/src/test/java/org/openjdk/jmh/it/profilers/GCProfilerTest.java	Sat Apr 18 14:50:29 2015 +0300
@@ -38,7 +38,6 @@
 import org.openjdk.jmh.runner.RunnerException;
 import org.openjdk.jmh.runner.options.Options;
 import org.openjdk.jmh.runner.options.OptionsBuilder;
-import org.openjdk.jmh.runner.options.TimeValue;
 
 import java.util.ArrayList;
 import java.util.concurrent.TimeUnit;
@@ -47,13 +46,21 @@
  * Tests allocation profiler.
  */
 @OutputTimeUnit(TimeUnit.NANOSECONDS)
+ at Fork(1) // 0 to enable debugging
 public class GCProfilerTest {
 
     @Benchmark
+    @Warmup(iterations = 0)
+    @Measurement(iterations = 20, time = 10, timeUnit = TimeUnit.MILLISECONDS)
+    @BenchmarkMode(Mode.AverageTime)
+    public Object allocateObjectNoWarmup() {
+        return new Object();
+    }
+
+    @Benchmark
     @Warmup(iterations = 2)
-    @Measurement(iterations = 1, time = 1, timeUnit = TimeUnit.MILLISECONDS)
+    @Measurement(iterations = 2, time = 2, timeUnit = TimeUnit.SECONDS)
     @BenchmarkMode(Mode.AverageTime)
-    @Fork(1)
     public Object allocateObject() {
         return new Object();
     }
@@ -62,16 +69,14 @@
     @Warmup(iterations = 2)
     @Measurement(iterations = 5)
     @BenchmarkMode(Mode.SingleShotTime)
-    @Fork(1)
     public Object allocateObjectSingleShot() {
         return new Object();
     }
 
     @Benchmark
     @Warmup(iterations = 2)
-    @Measurement(iterations = 1)
+    @Measurement(iterations = 1, time = 2, timeUnit = TimeUnit.SECONDS)
     @BenchmarkMode(Mode.SampleTime)
-    @Fork(1)
     public Object allocateObjectSampleTime() {
         return new Object();
     }
@@ -87,7 +92,6 @@
         Options opts = new OptionsBuilder()
                 .include(Fixtures.getTestMask(this.getClass()))
                 .addProfiler(GCProfiler.class)
-                .measurementTime(TimeValue.seconds(2))
                 .build();
         new Runner(opts).run();
     }
diff -r 869982787a92 -r d57b9e02ec35 jmh-core/src/main/java/org/openjdk/jmh/profile/GCProfiler.java
--- a/jmh-core/src/main/java/org/openjdk/jmh/profile/GCProfiler.java	Thu Apr 16 23:04:20 2015 +0300
+++ b/jmh-core/src/main/java/org/openjdk/jmh/profile/GCProfiler.java	Sat Apr 18 14:50:29 2015 +0300
@@ -46,12 +46,9 @@
 import java.lang.reflect.Method;
 import java.util.ArrayList;
 import java.util.Collection;
-import java.util.Collections;
 import java.util.HashMap;
-import java.util.HashSet;
 import java.util.List;
 import java.util.Map;
-import java.util.Set;
 import java.util.concurrent.TimeUnit;
 
 public class GCProfiler implements InternalProfiler {
@@ -61,11 +58,9 @@
     private HotspotAllocationSnapshot beforeAllocated;
     private final NotificationListener listener;
     private volatile Multiset<String> churn;
-    private Set<String> observedSpaces;
 
     public GCProfiler() {
         churn = new HashMultiset<String>();
-        observedSpaces = Collections.synchronizedSet(new HashSet<String>());
 
         NotificationListener listener = null;
         try {
@@ -93,7 +88,6 @@
                                 // Reporting code uses observedSpaces, so it reports 0 even if we omit adding
                                 if (c > 0) {
                                     churn.add(name, c);
-                                    observedSpaces.add(name);
                                 }
                             }
                         }
@@ -169,18 +163,20 @@
                     "MB/sec", AggregationPolicy.AVG));
         } else {
             long allocated = newSnapshot.subtract(beforeAllocated);
-            // When no allocations measured, we still need to report results to avoid measurement bias.
+            // When no allocations measured, we still need to report results to avoid user confusion
             results.add(new ProfilerResult(Defaults.PREFIX + "gc.alloc.rate",
                             (afterTime != beforeTime) ?
                                     1.0 * allocated / 1024 / 1024 * TimeUnit.SECONDS.toNanos(1) / (afterTime - beforeTime) :
                                     Double.NaN,
                             "MB/sec", AggregationPolicy.AVG));
-            long allOps = iResult.getMetadata().getAllOps();
-            results.add(new ProfilerResult(Defaults.PREFIX + "gc.alloc.rate.norm",
-                            (allOps != 0) ?
-                                    1.0 * allocated / allOps :
-                                    Double.NaN,
-                            "B/op", AggregationPolicy.AVG));
+            if (allocated != 0) {
+                long allOps = iResult.getMetadata().getAllOps();
+                results.add(new ProfilerResult(Defaults.PREFIX + "gc.alloc.rate.norm",
+                                (allOps != 0) ?
+                                        1.0 * allocated / allOps :
+                                        Double.NaN,
+                                "B/op", AggregationPolicy.AVG));
+            }
         }
 
         results.add(new ProfilerResult(
@@ -189,13 +185,15 @@
                 "counts",
                 AggregationPolicy.SUM));
 
-        results.add(new ProfilerResult(
-                Defaults.PREFIX + "gc.time",
-                gcTime - beforeGCTime,
-                "ms",
-                AggregationPolicy.SUM));
+        if (gcCount != beforeGCCount || gcTime != beforeGCTime) {
+            results.add(new ProfilerResult(
+                    Defaults.PREFIX + "gc.time",
+                    gcTime - beforeGCTime,
+                    "ms",
+                    AggregationPolicy.SUM));
+        }
 
-        for (String space : observedSpaces) {
+        for (String space : churn.keys()) {
             double churnRate = (afterTime != beforeTime) ?
                     1.0 * churn.count(space) * TimeUnit.SECONDS.toNanos(1) / (afterTime - beforeTime) / 1024 / 1024 :
                     Double.NaN;
diff -r 869982787a92 -r d57b9e02ec35 jmh-core/src/main/java/org/openjdk/jmh/profile/ProfilerResult.java
--- a/jmh-core/src/main/java/org/openjdk/jmh/profile/ProfilerResult.java	Thu Apr 16 23:04:20 2015 +0300
+++ b/jmh-core/src/main/java/org/openjdk/jmh/profile/ProfilerResult.java	Sat Apr 18 14:50:29 2015 +0300
@@ -51,4 +51,8 @@
         return new ProfilerResultAggregator();
     }
 
+    @Override
+    protected ProfilerResult getZeroResult() {
+        return new ProfilerResult(label, 0, unit, policy);
+    }
 }
diff -r 869982787a92 -r d57b9e02ec35 jmh-core/src/main/java/org/openjdk/jmh/results/BenchmarkResult.java
--- a/jmh-core/src/main/java/org/openjdk/jmh/results/BenchmarkResult.java	Thu Apr 16 23:04:20 2015 +0300
+++ b/jmh-core/src/main/java/org/openjdk/jmh/results/BenchmarkResult.java	Sat Apr 18 14:50:29 2015 +0300
@@ -31,9 +31,7 @@
 import java.io.Serializable;
 import java.util.ArrayList;
 import java.util.Collection;
-import java.util.HashSet;
 import java.util.Map;
-import java.util.Set;
 import java.util.TreeMap;
 
 /**
@@ -101,26 +99,43 @@
     }
 
     public Map<String, Result> getSecondaryResults() {
-        Set<String> labels = new HashSet<String>();
-        for (IterationResult r : iterationResults) {
-            labels.addAll(r.getSecondaryResults().keySet());
+        // label -> collection of results
+        Multimap<String, Result> allSecondary = new HashMultimap<String, Result>();
+
+        // Build multiset of all results to capture if some labels are missing in some of the iterations
+        for (IterationResult ir : iterationResults) {
+            Map<String, Result> secondaryResults = ir.getSecondaryResults();
+            for (Map.Entry<String, Result> entry : secondaryResults.entrySet()) {
+                allSecondary.put(entry.getKey(), entry.getValue());
+            }
         }
 
         Map<String, Result> answers = new TreeMap<String, Result>();
-        for (String label : labels) {
-            Aggregator<Result> aggregator = null;
-            Collection<Result> results = new ArrayList<Result>();
-            for (IterationResult r : iterationResults) {
-                Result e = r.getSecondaryResults().get(label);
-                if (e != null) {
-                    results.add(e);
-                    aggregator = e.getIterationAggregator();
+
+        int totalIterations = iterationResults.size();
+        // Create "0" entries in case certain labels did not appear in some of the iterations
+        for (String label : allSecondary.keys()) {
+            Collection<Result> results = allSecondary.get(label);
+            Result firstResult = results.iterator().next();
+            Result emptyResult = firstResult.getZeroResult();
+            if (emptyResult != null) {
+                for (int i = results.size(); i < totalIterations; i++) {
+                    allSecondary.put(label, emptyResult);
                 }
             }
+            @SuppressWarnings("unchecked")
+            Aggregator<Result> aggregator = firstResult.getIterationAggregator();
+            if (aggregator == null) {
+                if (results.size() == 1) {
+                    answers.put(label, firstResult);
+                    continue;
+                }
+                throw new IllegalStateException("No aggregator for " + firstResult);
+            }
 
-            if (aggregator != null) {
-                answers.put(label, aggregator.aggregate(results));
-            }
+            // Note: should not use "results" here since the contents was just updated by "put" above
+            Result aggregate = aggregator.aggregate(allSecondary.get(label));
+            answers.put(label, aggregate);
         }
 
         for (String label : benchmarkResults.keys()) {
diff -r 869982787a92 -r d57b9e02ec35 jmh-core/src/main/java/org/openjdk/jmh/results/Result.java
--- a/jmh-core/src/main/java/org/openjdk/jmh/results/Result.java	Thu Apr 16 23:04:20 2015 +0300
+++ b/jmh-core/src/main/java/org/openjdk/jmh/results/Result.java	Sat Apr 18 14:50:29 2015 +0300
@@ -171,6 +171,15 @@
     protected abstract Aggregator<T> getIterationAggregator();
 
     /**
+     * Returns "0" result. This is used for un-biased aggregation of secondary results.
+     * For instance, profilers might omit results in some iterations, thus we should pretend there were 0 results.
+     * @return result that represents "empty" result, null if no sensible "empty" result can be created
+     */
+    protected T getZeroResult() {
+        return null;
+    }
+
+    /**
      * Result as represented by a String.
      *
      * @return String with the result and unit


More information about the jmh-dev mailing list