You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@geode.apache.org by GitBox <gi...@apache.org> on 2021/04/19 21:24:08 UTC

[GitHub] [geode-benchmarks] upthewaterspout opened a new pull request #147: GEODE-9175: Logging progress of benchmarks as they are running

upthewaterspout opened a new pull request #147:
URL: https://github.com/apache/geode-benchmarks/pull/147


   Reducing the noise in the logging from our benchmark framework.
   
   Printing test log messages to stdout when running a benchmark, to watch the
   progress.
   
   Logging progress every 10 seconds in the yardstick task
   
   Reporting the throughput and latency every 10 seconds while running a
   benchmark. Each client currently reports it's own numbers.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [geode-benchmarks] upthewaterspout commented on a change in pull request #147: GEODE-9175: Logging progress of benchmarks as they are running

Posted by GitBox <gi...@apache.org>.
upthewaterspout commented on a change in pull request #147:
URL: https://github.com/apache/geode-benchmarks/pull/147#discussion_r617786441



##########
File path: harness/src/main/java/org/apache/geode/perftest/yardstick/YardstickTask.java
##########
@@ -107,6 +112,35 @@ public String defaultDescription() {
 
     runner.runBenchmark();
 
-    testDoneProbe.await();
+    Histogram lastHistogram = hdrHistogramProbe.getHistogram();
+    while (!testDoneProbe.await(10, TimeUnit.SECONDS)) {

Review comment:
       I'm not sure if there is a way we can pause yardstick during this measurement without just throwing away yardstick. I can do a test to see if there is any impact from this. I was originally thinking that since we only really care about relative performance, it doesn't matter if we impact the perf of both the baseline and the test versions.




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [geode-benchmarks] pivotal-jbarrett commented on a change in pull request #147: GEODE-9175: Logging progress of benchmarks as they are running

Posted by GitBox <gi...@apache.org>.
pivotal-jbarrett commented on a change in pull request #147:
URL: https://github.com/apache/geode-benchmarks/pull/147#discussion_r616985335



##########
File path: harness/src/main/java/org/apache/geode/perftest/yardstick/YardstickTask.java
##########
@@ -107,6 +112,35 @@ public String defaultDescription() {
 
     runner.runBenchmark();
 
-    testDoneProbe.await();
+    Histogram lastHistogram = hdrHistogramProbe.getHistogram();
+    while (!testDoneProbe.await(10, TimeUnit.SECONDS)) {
+      boolean warmupFinished = hdrHistogramProbe.isWarmupFinished();
+      // Create a histogram for the previous 10 second window
+      Histogram histogram = hdrHistogramProbe.getHistogram();
+      Histogram currentHistogram = histogram.copy();
+      if (histogram.getStartTimeStamp() == lastHistogram.getStartTimeStamp()) {
+        currentHistogram.subtract(lastHistogram);
+        currentHistogram.setStartTimeStamp(lastHistogram.getEndTimeStamp());
+      }
+
+      String prefix = warmupFinished ? "WORK" : "WARMUP";
+
+      // Log the histogram
+      logProgress(context, prefix, currentHistogram);
+
+      // Capture the current histogram
+      lastHistogram = histogram;
+    }
+    logProgress(context, "TOTAL", hdrHistogramProbe.getHistogram());

Review comment:
       Why don't tasks just invoke the logger directly? What is purpose of abstracting loging into this `logProgress` method on each task?

##########
File path: harness/src/main/java/org/apache/geode/perftest/yardstick/YardstickTask.java
##########
@@ -107,6 +112,35 @@ public String defaultDescription() {
 
     runner.runBenchmark();
 
-    testDoneProbe.await();
+    Histogram lastHistogram = hdrHistogramProbe.getHistogram();
+    while (!testDoneProbe.await(10, TimeUnit.SECONDS)) {

Review comment:
       I worry abut the performance impact of calculating the histogram every 10s for logging purposes. This will effectively steal a CPU every 10s to crunch some numbers without the framework accounting for it. if work and measurement was paused for each cycle that would be ok.




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [geode-benchmarks] nonbinaryprogrammer commented on a change in pull request #147: GEODE-9175: Logging progress of benchmarks as they are running

Posted by GitBox <gi...@apache.org>.
nonbinaryprogrammer commented on a change in pull request #147:
URL: https://github.com/apache/geode-benchmarks/pull/147#discussion_r620532745



##########
File path: harness/src/main/java/org/apache/geode/perftest/yardstick/YardstickTask.java
##########
@@ -107,6 +112,35 @@ public String defaultDescription() {
 
     runner.runBenchmark();
 
-    testDoneProbe.await();
+    Histogram lastHistogram = hdrHistogramProbe.getHistogram();
+    while (!testDoneProbe.await(10, TimeUnit.SECONDS)) {

Review comment:
       is calculating the histogram reliable in how long it takes? Does it take longer as we get more data? I could see how we'd account for it if it always takes the same amount of time, but a variable time doesn't seem possible to account for. I don't think we can assume that the relative performance impact would be the same between runs




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [geode-benchmarks] pivotal-jbarrett commented on a change in pull request #147: GEODE-9175: Logging progress of benchmarks as they are running

Posted by GitBox <gi...@apache.org>.
pivotal-jbarrett commented on a change in pull request #147:
URL: https://github.com/apache/geode-benchmarks/pull/147#discussion_r622523533



##########
File path: harness/src/main/java/org/apache/geode/perftest/yardstick/YardstickTask.java
##########
@@ -107,6 +112,35 @@ public String defaultDescription() {
 
     runner.runBenchmark();
 
-    testDoneProbe.await();
+    Histogram lastHistogram = hdrHistogramProbe.getHistogram();
+    while (!testDoneProbe.await(10, TimeUnit.SECONDS)) {

Review comment:
       I won't fight you in throwing out yardstick. We have measured so much variability in the framework itself. We have a no-op benchmark that swings by as much last 15%. That is all noise from yardstick. 




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [geode-benchmarks] upthewaterspout commented on a change in pull request #147: GEODE-9175: Logging progress of benchmarks as they are running

Posted by GitBox <gi...@apache.org>.
upthewaterspout commented on a change in pull request #147:
URL: https://github.com/apache/geode-benchmarks/pull/147#discussion_r617783376



##########
File path: harness/src/main/java/org/apache/geode/perftest/yardstick/YardstickTask.java
##########
@@ -107,6 +112,35 @@ public String defaultDescription() {
 
     runner.runBenchmark();
 
-    testDoneProbe.await();
+    Histogram lastHistogram = hdrHistogramProbe.getHistogram();
+    while (!testDoneProbe.await(10, TimeUnit.SECONDS)) {
+      boolean warmupFinished = hdrHistogramProbe.isWarmupFinished();
+      // Create a histogram for the previous 10 second window
+      Histogram histogram = hdrHistogramProbe.getHistogram();
+      Histogram currentHistogram = histogram.copy();
+      if (histogram.getStartTimeStamp() == lastHistogram.getStartTimeStamp()) {
+        currentHistogram.subtract(lastHistogram);
+        currentHistogram.setStartTimeStamp(lastHistogram.getEndTimeStamp());
+      }
+
+      String prefix = warmupFinished ? "WORK" : "WARMUP";
+
+      // Log the histogram
+      logProgress(context, prefix, currentHistogram);
+
+      // Capture the current histogram
+      lastHistogram = histogram;
+    }
+    logProgress(context, "TOTAL", hdrHistogramProbe.getHistogram());

Review comment:
       This logProgress is sending the log to the controller JVM. Those are the only logs that go to the console. The individual worker JVMs are just logging to their own log files.




-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org



[GitHub] [geode-benchmarks] upthewaterspout commented on pull request #147: GEODE-9175: Logging progress of benchmarks as they are running

Posted by GitBox <gi...@apache.org>.
upthewaterspout commented on pull request #147:
URL: https://github.com/apache/geode-benchmarks/pull/147#issuecomment-832977647


   I hit a failure with these changes when running the benchmarks. Still looking into this
   
   ```
   org.apache.geode.benchmark.tests.P2pPartitionedGetBenchmark > run() FAILED
       java.util.concurrent.CompletionException: java.lang.RuntimeException: java.lang.IllegalArgumentException: otherHistogram count (1) at value 676 is larger than this one's (0)
           at java.util.concurrent.CompletableFuture.encodeThrowable(CompletableFuture.java:273)
           at java.util.concurrent.CompletableFuture.completeThrowable(CompletableFuture.java:280)
           at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1643)
           at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
           at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
           at java.lang.Thread.run(Thread.java:748)
   
           Caused by:
           java.lang.RuntimeException: java.lang.IllegalArgumentException: otherHistogram count (1) at value 676 is larger than this one's (0)
               at org.apache.geode.perftest.jvms.rmi.Controller.lambda$onWorker$0(Controller.java:98)
               at java.util.concurrent.CompletableFuture$AsyncRun.run(CompletableFuture.java:1640)
               ... 3 more
   
               Caused by:
               java.lang.IllegalArgumentException: otherHistogram count (1) at value 676 is larger than this one's (0)
                   at org.HdrHistogram.AbstractHistogram.subtract(AbstractHistogram.java:795)
                   at org.apache.geode.perftest.yardstick.YardstickTask.run(YardstickTask.java:122)
                   at org.apache.geode.perftest.jvms.rmi.Worker.execute(Worker.java:36)
   
   ```


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

For queries about this service, please contact Infrastructure at:
users@infra.apache.org