private static String getEncodedHistogram(Histogram combined) {
   ByteBuffer targetBuffer = ByteBuffer.allocate(combined.getNeededByteBufferCapacity());
   int compressedLength =
       combined.encodeIntoCompressedByteBuffer(targetBuffer, Deflater.BEST_COMPRESSION);
   byte[] compressedArray = Arrays.copyOf(targetBuffer.array(), compressedLength);
   return DatatypeConverter.printBase64Binary(compressedArray);
 }
  private static String createEncodedHistogram() {
    Random random = new Random();

    Histogram histogram = new Histogram(MAXIMUM_LATENCY, LATENCY_PRECISION);
    for (int i = 0; i < 10; i++) {
      histogram.recordValue(random.nextInt((int) MAXIMUM_LATENCY));
    }
    return getEncodedHistogram(histogram);
  }
Ejemplo n.º 3
0
  private static void pongHandler(
      final DirectBuffer buffer, final int offset, final int length, final Header header) {
    final long pingTimestamp = buffer.getLong(offset);
    final long rttNs = System.nanoTime() - pingTimestamp;

    HISTOGRAM.recordValue(rttNs);
  }
Ejemplo n.º 4
0
  private static void runPing(final String embeddedDirName) throws InterruptedException {
    final Aeron.Context ctx =
        new Aeron.Context()
            .availableImageHandler(EmbeddedPingPong::availablePongImageHandler)
            .aeronDirectoryName(embeddedDirName);

    System.out.println("Publishing Ping at " + PING_CHANNEL + " on stream Id " + PING_STREAM_ID);
    System.out.println("Subscribing Pong at " + PONG_CHANNEL + " on stream Id " + PONG_STREAM_ID);
    System.out.println("Message size of " + MESSAGE_LENGTH + " bytes");

    final FragmentAssembler dataHandler = new FragmentAssembler(EmbeddedPingPong::pongHandler);

    try (final Aeron aeron = Aeron.connect(ctx);
        final Publication pingPublication = aeron.addPublication(PING_CHANNEL, PING_STREAM_ID);
        final Subscription pongSubscription = aeron.addSubscription(PONG_CHANNEL, PONG_STREAM_ID)) {
      System.out.println("Waiting for new image from Pong...");

      PONG_IMAGE_LATCH.await();

      System.out.println(
          "Warming up... "
              + WARMUP_NUMBER_OF_ITERATIONS
              + " iterations of "
              + WARMUP_NUMBER_OF_MESSAGES
              + " messages");

      for (int i = 0; i < WARMUP_NUMBER_OF_ITERATIONS; i++) {
        roundTripMessages(
            dataHandler, pingPublication, pongSubscription, WARMUP_NUMBER_OF_MESSAGES);
      }

      Thread.sleep(100);
      final ContinueBarrier barrier = new ContinueBarrier("Execute again?");

      do {
        HISTOGRAM.reset();
        System.out.println("Pinging " + NUMBER_OF_MESSAGES + " messages");

        roundTripMessages(dataHandler, pingPublication, pongSubscription, NUMBER_OF_MESSAGES);

        System.out.println("Histogram of RTT latencies in microseconds.");
        HISTOGRAM.outputPercentileDistribution(System.out, 1000.0);
      } while (barrier.await());
    }
  }
Ejemplo n.º 5
0
 @Override
 public Histogram call(Histogram initialDistribution, Histogram distributionToAdd) {
   initialDistribution.add(distributionToAdd);
   return initialDistribution;
 }
Ejemplo n.º 6
0
  @Test
  public void testLatencyStats() throws Exception {

    SimplePauseDetector pauseDetector =
        new SimplePauseDetector(
            1000000L /* 1 msec sleep */,
            10000000L /* 10 msec reporting threshold */,
            3 /* thread count */,
            true /* verbose */);

    LatencyStats.setDefaultPauseDetector(pauseDetector);

    LatencyStats latencyStats = new LatencyStats();

    pauseDetector.skipConsensusTimeTo(TimeServices.nanoTime() + 115 * MSEC);

    TimeServices.moveTimeForward(5000L);
    TimeUnit.NANOSECONDS.sleep(1 * MSEC); // Make sure things have some time to propagate
    TimeServices.moveTimeForward(1000000L);
    TimeUnit.NANOSECONDS.sleep(1 * MSEC); // Make sure things have some time to propagate
    TimeServices.moveTimeForward(2000000L);
    TimeUnit.NANOSECONDS.sleep(1 * MSEC); // Make sure things have some time to propagate
    TimeServices.moveTimeForward(110000000L);
    TimeUnit.NANOSECONDS.sleep(1 * MSEC); // Make sure things have some time to propagate

    try {

      TimeUnit.NANOSECONDS.sleep(10 * MSEC); // Make sure things have some time to propagate

      long startTime = TimeServices.nanoTime();
      System.out.println(
          "@ "
              + (TimeServices.nanoTime() - startTime)
              + " nsec after start: startTime = "
              + startTime);

      long lastTime = startTime;
      for (int i = 0; i < 2000; i++) {
        pauseDetector.skipConsensusTimeTo(TimeServices.nanoTime() + (4 * MSEC));
        TimeServices.moveTimeForwardMsec(5);
        //                TimeUnit.NANOSECONDS.sleep(100000L); // Give things have some time to
        // propagate
        long now = TimeServices.nanoTime();
        latencyStats.recordLatency(now - lastTime);
        lastTime = now;
      }

      TimeUnit.NANOSECONDS.sleep(1 * MSEC); // Make sure things have some time to propagate

      // @ 10 sec from start
      System.out.println("\nForcing Interval Update:\n");
      latencyStats.forceIntervalSample();

      System.out.println("@ " + (TimeServices.nanoTime() - startTime) + " nsec after start:");
      System.out.println(
          "Estimated interval = "
              + latencyStats.getIntervalEstimator().getEstimatedInterval(lastTime));

      Histogram accumulatedHistogram = latencyStats.getAccumulatedHistogram();
      Histogram intervalHistogram = latencyStats.getIntervalHistogram();

      System.out.println(
          "Accumulated Average latency for 5msec sleeps: "
              + accumulatedHistogram.getMean()
              + ", count = "
              + accumulatedHistogram.getTotalCount());
      System.out.println(
          "Interval Average latency for 5msec sleeps: "
              + intervalHistogram.getMean()
              + ", count = "
              + intervalHistogram.getTotalCount());

      Assert.assertEquals(
          "Accumulated total count should be 2000", 2000, accumulatedHistogram.getTotalCount());

      System.out.println("Pausing detector threads for 5 seconds:");
      pauseDetector.stallDetectorThreads(0x7, 5000 * MSEC);
      TimeUnit.NANOSECONDS.sleep(1 * MSEC); // Make sure things have some time to propagate

      // @ 15 sec from start

      // Report without forcing interval measurement update:

      System.out.println("@ " + (TimeServices.nanoTime() - startTime) + " nsec after start:");
      System.out.println(
          "Estimated interval = "
              + latencyStats.getIntervalEstimator().getEstimatedInterval(TimeServices.nanoTime()));
      accumulatedHistogram = latencyStats.getAccumulatedHistogram();
      intervalHistogram = latencyStats.getIntervalHistogram();

      System.out.println(
          "Post-pause, pre-observation Accumulated Average latency for 5msec sleeps: "
              + accumulatedHistogram.getMean()
              + ", count = "
              + accumulatedHistogram.getTotalCount());
      System.out.println(
          "Post-pause, pre-observation Interval Average latency for 5msec sleeps: "
              + intervalHistogram.getMean()
              + ", count = "
              + intervalHistogram.getTotalCount());

      Assert.assertEquals(
          "Accumulated total count should be 2000", 2000, accumulatedHistogram.getTotalCount());

      // Still @ 15 sec from start
      System.out.println("\nForcing Interval Update:\n");
      latencyStats.forceIntervalSample();

      System.out.println("@ " + (TimeServices.nanoTime() - startTime) + " nsec after start:");
      System.out.println(
          "Estimated interval = "
              + latencyStats.getIntervalEstimator().getEstimatedInterval(TimeServices.nanoTime()));
      accumulatedHistogram = latencyStats.getAccumulatedHistogram();
      intervalHistogram = latencyStats.getIntervalHistogram();

      System.out.println(
          "Post-pause, post-observation Accumulated Average latency for 5msec sleeps: "
              + accumulatedHistogram.getMean()
              + ", count = "
              + accumulatedHistogram.getTotalCount());
      System.out.println(
          "Post-pause, post-observation Interval Average latency for 5msec sleeps: "
              + intervalHistogram.getMean()
              + ", count = "
              + intervalHistogram.getTotalCount());

      Assert.assertEquals(
          "Accumulated total count should be 2000", 2998, accumulatedHistogram.getTotalCount());

      pauseDetector.skipConsensusTimeTo(TimeServices.nanoTime() + (500 * MSEC));
      TimeServices.moveTimeForwardMsec(500);
      TimeUnit.NANOSECONDS.sleep(1 * MSEC); // Make sure things have some time to propagate

      // @ 15.5 sec from start
      System.out.println("\nForcing Interval Update:\n");
      latencyStats.forceIntervalSample();

      System.out.println("@ " + (TimeServices.nanoTime() - startTime) + " nsec after start:");
      System.out.println(
          "Estimated interval = "
              + latencyStats.getIntervalEstimator().getEstimatedInterval(TimeServices.nanoTime()));
      accumulatedHistogram = latencyStats.getAccumulatedHistogram();
      intervalHistogram = latencyStats.getIntervalHistogram();

      System.out.println(
          "Post-pause Accumulated Average latency for 5msec sleeps: "
              + accumulatedHistogram.getMean()
              + ", count = "
              + accumulatedHistogram.getTotalCount());
      System.out.println(
          "Post-pause Interval Average latency for 5msec sleeps: "
              + intervalHistogram.getMean()
              + ", count = "
              + intervalHistogram.getTotalCount());

      Assert.assertEquals(
          "Accumulated total count should be 2000", 2998, accumulatedHistogram.getTotalCount());

      pauseDetector.skipConsensusTimeTo(TimeServices.nanoTime() + (500 * MSEC));
      TimeServices.moveTimeForwardMsec(500);
      TimeUnit.NANOSECONDS.sleep(1 * MSEC); // Make sure things have some time to propagate

      // @ 16 sec from start
      System.out.println("\nForcing Interval Update:\n");
      latencyStats.forceIntervalSample();

      System.out.println("@ " + (TimeServices.nanoTime() - startTime) + " nsec after start:");
      System.out.println(
          "Estimated interval = "
              + latencyStats.getIntervalEstimator().getEstimatedInterval(TimeServices.nanoTime()));
      accumulatedHistogram = latencyStats.getAccumulatedHistogram();
      intervalHistogram = latencyStats.getIntervalHistogram();

      System.out.println(
          "Post-pause Accumulated Average latency for 5msec sleeps: "
              + accumulatedHistogram.getMean()
              + ", count = "
              + accumulatedHistogram.getTotalCount());
      System.out.println(
          "Post-pause Interval Average latency for 5msec sleeps: "
              + intervalHistogram.getMean()
              + ", count = "
              + intervalHistogram.getTotalCount());

      Assert.assertEquals(
          "Accumulated total count should be 2999", 2998, accumulatedHistogram.getTotalCount());

      pauseDetector.skipConsensusTimeTo(TimeServices.nanoTime() + (2000 * MSEC));
      TimeServices.moveTimeForwardMsec(2000);
      TimeUnit.NANOSECONDS.sleep(1 * MSEC); // Make sure things have some time to propagate

      // @ 18 sec from start
      System.out.println("\nForcing Interval Update:\n");
      latencyStats.forceIntervalSample();

      System.out.println("@ " + (TimeServices.nanoTime() - startTime) + " nsec after start:");
      System.out.println(
          "Estimated interval = "
              + latencyStats.getIntervalEstimator().getEstimatedInterval(TimeServices.nanoTime()));
      accumulatedHistogram = latencyStats.getAccumulatedHistogram();
      intervalHistogram = latencyStats.getIntervalHistogram();

      System.out.println(
          "Post-pause Accumulated Average latency for 5msec sleeps: "
              + accumulatedHistogram.getMean()
              + ", count = "
              + accumulatedHistogram.getTotalCount());
      System.out.println(
          "Post-pause Interval Average latency for 5msec sleeps: "
              + intervalHistogram.getMean()
              + ", count = "
              + intervalHistogram.getTotalCount());

      Assert.assertEquals(
          "Accumulated total count should be 2999", 2998, accumulatedHistogram.getTotalCount());

      for (int i = 0; i < 100; i++) {
        pauseDetector.skipConsensusTimeTo(TimeServices.nanoTime() + (5 * MSEC));
        TimeServices.moveTimeForwardMsec(5);
        long now = TimeServices.nanoTime();
        latencyStats.recordLatency(now - lastTime);
        lastTime = now;
      }

      pauseDetector.skipConsensusTimeTo(TimeServices.nanoTime() + (500 * MSEC));
      TimeServices.moveTimeForwardMsec(500);
      TimeUnit.NANOSECONDS.sleep(1 * MSEC); // Make sure things have some time to propagate

      // @ 19 sec from start
      System.out.println("\nForcing Interval Update:\n");
      latencyStats.forceIntervalSample();

      System.out.println("@ " + (TimeServices.nanoTime() - startTime) + " nsec after start:");
      System.out.println(
          "Estimated interval = "
              + latencyStats.getIntervalEstimator().getEstimatedInterval(TimeServices.nanoTime()));
      accumulatedHistogram = latencyStats.getAccumulatedHistogram();
      intervalHistogram = latencyStats.getIntervalHistogram();
      System.out.println(
          "Post-pause Accumulated Average latency for 5msec sleeps: "
              + accumulatedHistogram.getMean()
              + ", count = "
              + accumulatedHistogram.getTotalCount());
      System.out.println(
          "Post-pause Interval Average latency for 5msec sleeps: "
              + intervalHistogram.getMean()
              + ", count = "
              + intervalHistogram.getTotalCount());

      pauseDetector.skipConsensusTimeTo(TimeServices.nanoTime() + (500 * MSEC));
      TimeServices.moveTimeForwardMsec(500);
      TimeUnit.NANOSECONDS.sleep(1 * MSEC); // Make sure things have some time to propagate

      // @ 19.5 sec from start
      System.out.println("\nForcing Interval Update:\n");
      latencyStats.forceIntervalSample();

      System.out.println("@ " + (TimeServices.nanoTime() - startTime) + " nsec after start:");
      System.out.println(
          "Estimated interval = "
              + latencyStats.getIntervalEstimator().getEstimatedInterval(TimeServices.nanoTime()));
      accumulatedHistogram = latencyStats.getAccumulatedHistogram();
      intervalHistogram = latencyStats.getIntervalHistogram();
      System.out.println(
          "Post-pause Accumulated Average latency for 5msec sleeps: "
              + accumulatedHistogram.getMean()
              + ", count = "
              + accumulatedHistogram.getTotalCount());
      System.out.println(
          "Post-pause Interval Average latency for 5msec sleeps: "
              + intervalHistogram.getMean()
              + ", count = "
              + intervalHistogram.getTotalCount());

      Assert.assertEquals(
          "Accumulated total count should be 2000", 3098, accumulatedHistogram.getTotalCount());
    } catch (InterruptedException ex) {

    }

    latencyStats.stop();

    pauseDetector.shutdown();
  }