You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@activemq.apache.org by cl...@apache.org on 2017/10/26 16:22:52 UTC

[1/3] activemq-artemis git commit: ARTEMIS-1476 Added HdrHistogram support with verbose SyncCalculation and synchronous writes

Repository: activemq-artemis
Updated Branches:
  refs/heads/master 77f52f40b -> 909222181


ARTEMIS-1476 Added HdrHistogram support with verbose SyncCalculation and synchronous writes


Project: http://git-wip-us.apache.org/repos/asf/activemq-artemis/repo
Commit: http://git-wip-us.apache.org/repos/asf/activemq-artemis/commit/c76369ac
Tree: http://git-wip-us.apache.org/repos/asf/activemq-artemis/tree/c76369ac
Diff: http://git-wip-us.apache.org/repos/asf/activemq-artemis/diff/c76369ac

Branch: refs/heads/master
Commit: c76369ac7ecfbcea55ed619866e0c3d5fc396d6a
Parents: 77f52f4
Author: Francesco Nigro <ni...@gmail.com>
Authored: Mon Oct 23 18:12:33 2017 +0200
Committer: Clebert Suconic <cl...@apache.org>
Committed: Thu Oct 26 11:47:38 2017 -0400

----------------------------------------------------------------------
 artemis-cli/pom.xml                             |  4 ++
 .../cli/commands/util/SyncCalculation.java      | 74 ++++++++++++++++----
 artemis-distribution/src/main/assembly/dep.xml  |  1 +
 pom.xml                                         | 10 +++
 4 files changed, 74 insertions(+), 15 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/activemq-artemis/blob/c76369ac/artemis-cli/pom.xml
----------------------------------------------------------------------
diff --git a/artemis-cli/pom.xml b/artemis-cli/pom.xml
index 6a4119f..a76f2e7 100644
--- a/artemis-cli/pom.xml
+++ b/artemis-cli/pom.xml
@@ -83,6 +83,10 @@
          <version>${commons.lang.version}</version>
       </dependency>
       <dependency>
+         <groupId>org.hdrhistogram</groupId>
+         <artifactId>HdrHistogram</artifactId>
+      </dependency>
+      <dependency>
         <groupId>com.sun.winsw</groupId>
         <artifactId>winsw</artifactId>
         <version>${winsw.version}</version>

http://git-wip-us.apache.org/repos/asf/activemq-artemis/blob/c76369ac/artemis-cli/src/main/java/org/apache/activemq/artemis/cli/commands/util/SyncCalculation.java
----------------------------------------------------------------------
diff --git a/artemis-cli/src/main/java/org/apache/activemq/artemis/cli/commands/util/SyncCalculation.java b/artemis-cli/src/main/java/org/apache/activemq/artemis/cli/commands/util/SyncCalculation.java
index 5cc6ab9..fa99c7b 100644
--- a/artemis-cli/src/main/java/org/apache/activemq/artemis/cli/commands/util/SyncCalculation.java
+++ b/artemis-cli/src/main/java/org/apache/activemq/artemis/cli/commands/util/SyncCalculation.java
@@ -21,8 +21,10 @@ import java.io.File;
 import java.io.IOException;
 import java.nio.ByteBuffer;
 import java.text.DecimalFormat;
+import java.util.Arrays;
 import java.util.concurrent.TimeUnit;
 
+import org.HdrHistogram.Histogram;
 import org.apache.activemq.artemis.core.io.IOCallback;
 import org.apache.activemq.artemis.core.io.SequentialFile;
 import org.apache.activemq.artemis.core.io.SequentialFileFactory;
@@ -40,9 +42,30 @@ import org.apache.activemq.artemis.utils.ReusableLatch;
  */
 public class SyncCalculation {
 
+   //uses nanoseconds to avoid any conversion cost: useful when performing operation on mapped journal without fsync or with RAM-like devices
+   private static final long MAX_FLUSH_NANOS = TimeUnit.SECONDS.toNanos(5);
+
    /**
-    * It will perform a write test of blockSize * bocks, sinc on each write, for N tries.
-    * It will return the lowest spent time from the tries.
+    * It will perform {@code tries} write tests of {@code blockSize * blocks} bytes and returning the lowest elapsed time to perform a try.
+    *
+    * <p>
+    * Please configure {@code blocks >= -XX:CompileThreshold} (ie by default on most JVMs is 10000) to favour the best JIT/OSR compilation (ie: Just In Time/On Stack Replacement)
+    * if the test is running on a temporary file-system (eg: tmpfs on Linux) or without {@code fsync}.
+    * <p>
+    * NOTE: The write latencies are provided only if {@code verbose && !(journalType == JournalType.ASYNCIO && !syncWrites)} (ie are used effective synchronous writes).
+    *
+    * @param datafolder  the folder where the journal files will be stored
+    * @param blockSize   the size in bytes of each write on the journal
+    * @param blocks      the number of {@code blockSize} writes performed on each try
+    * @param tries       the number of tests
+    * @param verbose     {@code true} to make the output verbose, {@code false} otherwise
+    * @param fsync       if {@code true} the test is performing full durable writes, {@code false} otherwise
+    * @param syncWrites  if {@code true} each write is performed only if the previous one is completed, {@code false} otherwise (ie each try will wait only the last write)
+    * @param fileName    the name of the journal file used for the test
+    * @param maxAIO      the max number of in-flight IO requests (if {@code journalType} will support it)
+    * @param journalType the {@link JournalType} used for the tests
+    * @return the lowest elapsed time (in {@link TimeUnit#MILLISECONDS}) to perform a try
+    * @throws Exception
     */
    public static long syncTest(File datafolder,
                                int blockSize,
@@ -55,32 +78,30 @@ public class SyncCalculation {
                                int maxAIO,
                                JournalType journalType) throws Exception {
       SequentialFileFactory factory = newFactory(datafolder, fsync, journalType, blockSize * blocks, maxAIO);
+      final boolean asyncWrites = journalType == JournalType.ASYNCIO && !syncWrites;
+      //the write latencies could be taken only when writes are effectively synchronous
+      final Histogram writeLatencies = (verbose && !asyncWrites) ? new Histogram(MAX_FLUSH_NANOS, 2) : null;
 
       if (verbose) {
          System.out.println("Using " + factory.getClass().getName() + " to calculate sync times, alignment=" + factory.getAlignment());
       }
       SequentialFile file = factory.createSequentialFile(fileName);
-
+      //to be sure that a process/thread crash won't leave the dataFolder with garbage files
+      file.getJavaFile().deleteOnExit();
       try {
+         final ByteBuffer bufferBlock = allocateAlignedBlock(blockSize, factory);
+
+         final int alignedBlockSize = bufferBlock.remaining();
+
          file.delete();
          file.open();
 
-         file.fill(blockSize * blocks);
+         file.fill(alignedBlockSize * blocks);
 
          file.close();
 
          long[] result = new long[tries];
 
-         byte[] block = new byte[blockSize];
-
-         for (int i = 0; i < block.length; i++) {
-            block[i] = (byte) 't';
-         }
-
-         ByteBuffer bufferBlock = factory.newBuffer(blockSize);
-         bufferBlock.put(block);
-         bufferBlock.position(0);
-
          final ReusableLatch latch = new ReusableLatch(0);
 
          IOCallback callback = new IOCallback() {
@@ -108,11 +129,19 @@ public class SyncCalculation {
             for (int i = 0; i < blocks; i++) {
                bufferBlock.position(0);
                latch.countUp();
+               long startWrite = 0;
+               if (writeLatencies != null) {
+                  startWrite = System.nanoTime();
+               }
                file.writeDirect(bufferBlock, true, callback);
 
                if (syncWrites) {
                   flushLatch(latch);
                }
+               if (writeLatencies != null) {
+                  final long elapsedWriteNanos = System.nanoTime() - startWrite;
+                  writeLatencies.recordValue(elapsedWriteNanos);
+               }
             }
 
             if (!syncWrites) flushLatch(latch);
@@ -127,6 +156,12 @@ public class SyncCalculation {
                System.out.println("Writes / millisecond = " + dcformat.format(writesPerMillisecond));
                System.out.println("bufferTimeout = " + toNanos(result[ntry], blocks, verbose));
                System.out.println("**************************************************");
+               if (writeLatencies != null) {
+                  System.out.println("Write Latencies Percentile Distribution in microseconds");
+                  //print latencies in us -> (ns * 1000d)
+                  writeLatencies.outputPercentileDistribution(System.out, 1000d);
+                  writeLatencies.reset();
+               }
             }
             file.close();
          }
@@ -157,8 +192,17 @@ public class SyncCalculation {
       }
    }
 
+   private static ByteBuffer allocateAlignedBlock(int blockSize, SequentialFileFactory factory) {
+      final ByteBuffer bufferBlock = factory.newBuffer(blockSize);
+      final byte[] block = new byte[bufferBlock.remaining()];
+      Arrays.fill(block, (byte) 't');
+      bufferBlock.put(block);
+      bufferBlock.position(0);
+      return bufferBlock;
+   }
+
    private static void flushLatch(ReusableLatch latch) throws InterruptedException, IOException {
-      if (!latch.await(5, TimeUnit.SECONDS)) {
+      if (!latch.await(MAX_FLUSH_NANOS, TimeUnit.NANOSECONDS)) {
          throw new IOException("Timed out on receiving IO callback");
       }
    }

http://git-wip-us.apache.org/repos/asf/activemq-artemis/blob/c76369ac/artemis-distribution/src/main/assembly/dep.xml
----------------------------------------------------------------------
diff --git a/artemis-distribution/src/main/assembly/dep.xml b/artemis-distribution/src/main/assembly/dep.xml
index 5770bce..3c16d8c 100644
--- a/artemis-distribution/src/main/assembly/dep.xml
+++ b/artemis-distribution/src/main/assembly/dep.xml
@@ -97,6 +97,7 @@
             <include>org.jgroups:jgroups</include>
             <include>org.apache.geronimo.specs:geronimo-json_1.0_spec</include>
             <include>org.apache.johnzon:johnzon-core</include>
+            <include>org.hdrhistogram:HdrHistogram</include>
          </includes>
          <!--excludes>
             <exclude>org.apache.activemq:artemis-website</exclude>

http://git-wip-us.apache.org/repos/asf/activemq-artemis/blob/c76369ac/pom.xml
----------------------------------------------------------------------
diff --git a/pom.xml b/pom.xml
index 73e39d4..74f206d 100644
--- a/pom.xml
+++ b/pom.xml
@@ -78,6 +78,7 @@
       <activemq5-version>5.14.5</activemq5-version>
       <apache.derby.version>10.11.1.1</apache.derby.version>
       <commons.beanutils.version>1.9.2</commons.beanutils.version>
+      <org.hdrhistogram.version>2.1.10</org.hdrhistogram.version>
       <commons.collections.version>3.2.2</commons.collections.version>
       <fuse.mqtt.client.version>1.14</fuse.mqtt.client.version>
       <guava.version>19.0</guava.version>
@@ -666,6 +667,15 @@
             <!-- License: Apache 2.0 -->
          </dependency>
 
+         <!-- needed by SyncCalculation -->
+         <!-- https://mvnrepository.com/artifact/org.hdrhistogram/HdrHistogram -->
+         <dependency>
+            <groupId>org.hdrhistogram</groupId>
+            <artifactId>HdrHistogram</artifactId>
+            <version>${org.hdrhistogram.version}</version>
+            <!-- License: Public Domain -->
+         </dependency>
+
          <dependency>
             <groupId>org.apache.openwebbeans</groupId>
             <artifactId>openwebbeans-impl</artifactId>


[3/3] activemq-artemis git commit: This closes #1605

Posted by cl...@apache.org.
This closes #1605


Project: http://git-wip-us.apache.org/repos/asf/activemq-artemis/repo
Commit: http://git-wip-us.apache.org/repos/asf/activemq-artemis/commit/90922218
Tree: http://git-wip-us.apache.org/repos/asf/activemq-artemis/tree/90922218
Diff: http://git-wip-us.apache.org/repos/asf/activemq-artemis/diff/90922218

Branch: refs/heads/master
Commit: 909222181a5d78b75a45f1085ad469728bbded45
Parents: 77f52f4 e34b787
Author: Clebert Suconic <cl...@apache.org>
Authored: Thu Oct 26 12:22:40 2017 -0400
Committer: Clebert Suconic <cl...@apache.org>
Committed: Thu Oct 26 12:22:40 2017 -0400

----------------------------------------------------------------------
 artemis-cli/pom.xml                             |   4 +
 .../cli/commands/util/SyncCalculation.java      | 100 ++++++++++++++++---
 artemis-distribution/src/main/assembly/dep.xml  |   1 +
 pom.xml                                         |  10 ++
 4 files changed, 101 insertions(+), 14 deletions(-)
----------------------------------------------------------------------



[2/3] activemq-artemis git commit: ARTEMIS-1476 Improving output on percentiles

Posted by cl...@apache.org.
ARTEMIS-1476 Improving output on percentiles


Project: http://git-wip-us.apache.org/repos/asf/activemq-artemis/repo
Commit: http://git-wip-us.apache.org/repos/asf/activemq-artemis/commit/e34b787a
Tree: http://git-wip-us.apache.org/repos/asf/activemq-artemis/tree/e34b787a
Diff: http://git-wip-us.apache.org/repos/asf/activemq-artemis/diff/e34b787a

Branch: refs/heads/master
Commit: e34b787a77fff072d8ad30154d90f6fcfff219ec
Parents: c76369a
Author: Clebert Suconic <cl...@apache.org>
Authored: Thu Oct 26 11:29:46 2017 -0400
Committer: Clebert Suconic <cl...@apache.org>
Committed: Thu Oct 26 12:20:17 2017 -0400

----------------------------------------------------------------------
 .../cli/commands/util/SyncCalculation.java      | 44 ++++++++++++++++----
 1 file changed, 36 insertions(+), 8 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/activemq-artemis/blob/e34b787a/artemis-cli/src/main/java/org/apache/activemq/artemis/cli/commands/util/SyncCalculation.java
----------------------------------------------------------------------
diff --git a/artemis-cli/src/main/java/org/apache/activemq/artemis/cli/commands/util/SyncCalculation.java b/artemis-cli/src/main/java/org/apache/activemq/artemis/cli/commands/util/SyncCalculation.java
index fa99c7b..c01506d 100644
--- a/artemis-cli/src/main/java/org/apache/activemq/artemis/cli/commands/util/SyncCalculation.java
+++ b/artemis-cli/src/main/java/org/apache/activemq/artemis/cli/commands/util/SyncCalculation.java
@@ -82,8 +82,21 @@ public class SyncCalculation {
       //the write latencies could be taken only when writes are effectively synchronous
       final Histogram writeLatencies = (verbose && !asyncWrites) ? new Histogram(MAX_FLUSH_NANOS, 2) : null;
 
+      if (journalType == JournalType.ASYNCIO && syncWrites) {
+         System.out.println();
+         System.out.println("*******************************************************************************************");
+         System.out.println("*** Notice: The recommendation for AsyncIO journal is to not use --sync-writes          ***");
+         System.out.println("***         The measures here will be useful to understand your device                  ***");
+         System.out.println("***         however the result here won't represent the best configuration option       ***");
+         System.out.println("*******************************************************************************************");
+         System.out.println();
+      }
+
       if (verbose) {
          System.out.println("Using " + factory.getClass().getName() + " to calculate sync times, alignment=" + factory.getAlignment());
+         if (writeLatencies == null) {
+            System.out.println("*** Use --sync-writes if you want to see a histogram for each write performed ***");
+         }
       }
       SequentialFile file = factory.createSequentialFile(fileName);
       //to be sure that a process/thread crash won't leave the dataFolder with garbage files
@@ -91,12 +104,13 @@ public class SyncCalculation {
       try {
          final ByteBuffer bufferBlock = allocateAlignedBlock(blockSize, factory);
 
-         final int alignedBlockSize = bufferBlock.remaining();
+         // making sure the blockSize matches the device
+         blockSize = bufferBlock.remaining();
 
          file.delete();
          file.open();
 
-         file.fill(alignedBlockSize * blocks);
+         file.fill(blockSize * blocks);
 
          file.close();
 
@@ -156,18 +170,32 @@ public class SyncCalculation {
                System.out.println("Writes / millisecond = " + dcformat.format(writesPerMillisecond));
                System.out.println("bufferTimeout = " + toNanos(result[ntry], blocks, verbose));
                System.out.println("**************************************************");
-               if (writeLatencies != null) {
-                  System.out.println("Write Latencies Percentile Distribution in microseconds");
-                  //print latencies in us -> (ns * 1000d)
-                  writeLatencies.outputPercentileDistribution(System.out, 1000d);
-                  writeLatencies.reset();
-               }
             }
             file.close();
+
+            if (ntry == 0 && writeLatencies != null) {
+               writeLatencies.reset(); // discarding the first one.. some warmup time
+            }
          }
 
          factory.releaseDirectBuffer(bufferBlock);
 
+         if (writeLatencies != null) {
+            System.out.println("Write Latencies Percentile Distribution in microseconds");
+            //print latencies in us -> (ns * 1000d)
+
+            System.out.println("*****************************************************************");
+            writeLatencies.outputPercentileDistribution(System.out, 1000d);
+            System.out.println();
+            System.out.println("*****************************************************************");
+            System.out.println("*** this may be useful to generate charts if you like charts: ***");
+            System.out.println("*** http://hdrhistogram.github.io/HdrHistogram/plotFiles.html ***");
+            System.out.println("*****************************************************************");
+            System.out.println();
+
+            writeLatencies.reset();
+         }
+
          long totalTime = Long.MAX_VALUE;
          for (int i = 0; i < tries; i++) {
             if (result[i] < totalTime) {