org.HdrHistogram.Histogram Java Examples

public void runBenchmark() throws IOException
{
    while (true)
    {
        try (SocketChannel socketChannel = open())
        {
            logon(socketChannel);

            final TestRequestEncoder testRequest = setupTestRequest();
            final HeaderEncoder header = testRequest.header();
            final Histogram histogram = new Histogram(3);

            runWarmup(socketChannel, testRequest, header, histogram);

            parkAfterWarmup();

            runTimedRuns(socketChannel, testRequest, header, histogram);
        }
    }
}
 

private void longReport(final Histogram histogram, final String histogramTitle,
                        final PrintStream out) throws IOException
{
    final PrintWriter printWriter = new PrintWriter(out);
    printWriter.append(format("== %s ==%n", histogramTitle));
    printWriter.append(format("%-8s%20d%n", "mean", (long) histogram.getMean()));
    printWriter.append(format("%-8s%20d%n", "min", histogram.getMinValue()));
    printWriter.append(format("%-8s%20d%n", "50.00%", histogram.getValueAtPercentile(50.0d)));
    printWriter.append(format("%-8s%20d%n", "90.00%", histogram.getValueAtPercentile(90.0d)));
    printWriter.append(format("%-8s%20d%n", "99.00%", histogram.getValueAtPercentile(99.0d)));
    printWriter.append(format("%-8s%20d%n", "99.90%", histogram.getValueAtPercentile(99.9d)));
    printWriter.append(format("%-8s%20d%n", "99.99%", histogram.getValueAtPercentile(99.99d)));
    printWriter.append(format("%-8s%20d%n", "99.999%", histogram.getValueAtPercentile(99.999d)));
    printWriter.append(format("%-8s%20d%n", "99.9999%", histogram.getValueAtPercentile(99.9999d)));
    printWriter.append(format("%-8s%20d%n", "max", histogram.getMaxValue()));
    printWriter.append(format("%-8s%20d%n", "count", histogram.getTotalCount()));
    printWriter.append("\n");
    printWriter.flush();
}
 

/**
 * Discuss waiting strategy between calls. Sleeping seems to be very inaccurate
 * (see below). On the other hand calling System.nanoTime() a lot (especially from
 * different threads seems to impact its accuracy
 * http://shipilev.net/blog/2014/nanotrusting-nanotime/
 * On my system the overhead of LockSupport.park(long) seems to average at ~55 micros.
 * // Try to sleep for 1 nanosecond and measure how long it actually takes.
 * long start = System.nanoTime();
 * int i = 0;
 * while (i < 10000) {
 *   LockSupport.parkNanos(1);
 *   i++;
 * }
 * long end = System.nanoTime();
 * System.out.println((end - start) / 10000);
 */
@Override
public Histogram call() throws Exception {
  long now = System.nanoTime();
  long nextRpc = now;
  long i = 0;
  while (i < numRpcs) {
    now = System.nanoTime();
    if (nextRpc - now <= 0) {
      // TODO: Add option to print how far we have been off from the target delay in micros.
      nextRpc += nextDelay(targetQps);
      newRpc(stub);
      i++;
    }
  }

  waitForRpcsToComplete(1);

  return histogram;
}
 

void persist(long currentTimeMillis, String currentTimeString) {
    performanceLogWriter.write(
            currentTimeMillis,
            currentTimeString,
            totalOperationCount,
            intervalOperationCount,
            intervalThroughput);

    // dumps all the Histograms that have been collected to file.
    for (Map.Entry<String, Histogram> histogramEntry : intervalHistogramMap.entrySet()) {
        String probeName = histogramEntry.getKey();
        HistogramLogWriter histogramLogWriter = histogramLogWriterMap.get(probeName);
        if (histogramLogWriter == null) {
            histogramLogWriter = createHistogramLogWriter(probeName);
            histogramLogWriterMap.put(probeName, histogramLogWriter);
        }
        Histogram intervalHistogram = histogramEntry.getValue();
        histogramLogWriter.outputIntervalHistogram(intervalHistogram);
    }
}
 

protected Object[] buildRegularHistogramStatistics(Histogram intervalHistogram, Histogram accumulatedRegularHistogram) {
    return new Object[]{((intervalHistogram.getEndTimeStamp() / 1000.0) - logReader.getStartTimeSec()),
            // values recorded during the last reporting interval
            intervalHistogram.getTotalCount(),
            intervalHistogram.getValueAtPercentile(50.0) / config.outputValueUnitRatio,
            intervalHistogram.getValueAtPercentile(90.0) / config.outputValueUnitRatio,
            intervalHistogram.getMaxValue() / config.outputValueUnitRatio,
            // values recorded from the beginning until now
            accumulatedRegularHistogram.getTotalCount(),
            accumulatedRegularHistogram.getValueAtPercentile(50.0) / config.outputValueUnitRatio,
            accumulatedRegularHistogram.getValueAtPercentile(90.0) / config.outputValueUnitRatio,
            accumulatedRegularHistogram.getValueAtPercentile(99.0) / config.outputValueUnitRatio,
            accumulatedRegularHistogram.getValueAtPercentile(99.9) / config.outputValueUnitRatio,
            accumulatedRegularHistogram.getValueAtPercentile(99.99) / config.outputValueUnitRatio,
            accumulatedRegularHistogram.getMaxValue() / config.outputValueUnitRatio};
}
 

@Test
public void testHistogramSerialization() throws Exception {
    Histogram original = new Histogram(MAX_LATENCY, 4);
    populateHistogram(original);

    // serialize
    ByteArrayOutputStream byteArrayOutputStream = new ByteArrayOutputStream();
    ObjectOutputStream outputStream = new ObjectOutputStream(byteArrayOutputStream);
    outputStream.writeObject(original);
    byte[] bytes = byteArrayOutputStream.toByteArray();

    // de-serialize
    ByteArrayInputStream byteArrayInputStream = new ByteArrayInputStream(bytes);
    ObjectInputStream inputStream = new ObjectInputStream(byteArrayInputStream);
    Histogram read = (Histogram) inputStream.readObject();

    assertEquals(original, read);
    assertTrue(original.equals(read));
    assertEquals(original.hashCode(), read.hashCode());
    assertEquals(original.getNeededByteBufferCapacity(), read.getNeededByteBufferCapacity());
}
 

private SlidingWindowHistogram(Builder builder) {
    this.numberOfIntervals = builder.numberOfIntervals;
    this.intervalDurationMillis = builder.intervalDurationMillis;
    this.clock = builder.clock;

    this.aggregateHistogram = new Histogram(builder.lowestDiscernibleValue, builder.highestTrackableValue, builder.numberOfSignificantDigits);
    if (builder.autoResize) {
        this.aggregateHistogram.setAutoResize(true);
    }

    this.window = new IntervalBucket[this.numberOfIntervals];
    for (int i = 0; i < this.numberOfIntervals; i++) {
        this.window[i] = new IntervalBucket(this.aggregateHistogram, builder.lowestDiscernibleValue,
                builder.highestTrackableValue, builder.numberOfSignificantDigits, builder.autoResize);
    }

    this.lastUpdateTime = currentTimeMillis();
}
 

public Snapshot interval() {
  final IntervalCount requestCount = count.interval();
  final IntervalCount responseTimeCount = responseTime.interval();
  final Histogram h = latency.getIntervalHistogram(histogram);
  final long c = requestCount.count();
  final double x = requestCount.rate();
  final long satisfied = h.getCountBetweenValues(0, goalLatency);
  final long tolerating = h.getCountBetweenValues(goalLatency, goalLatency * 4);
  final double p50 = h.getValueAtPercentile(50) * 1e-6;
  final double p90 = h.getValueAtPercentile(90) * 1e-6;
  final double p99 = h.getValueAtPercentile(99) * 1e-6;
  final double p999 = h.getValueAtPercentile(99.9) * 1e-6;
  this.histogram = h;
  final double r, n, apdex;
  if (c == 0) {
    r = n = apdex = 0;
  } else {
    r = responseTimeCount.rate() / c * 1e-6;
    n = x * r;
    apdex = Math.min(1.0, (satisfied + (tolerating / 2.0)) / c);
  }
  return new AutoValue_Snapshot(c, x, n, r, p50, p90, p99, p999, apdex);
}
 

private Histogram aggregateHistograms(final Entry<String, List<Path>> entry) throws FileNotFoundException
{
    Histogram aggregate = null;

    for (final Path file : entry.getValue())
    {
        try (HistogramLogReader logReader = new HistogramLogReader(file.toFile()))
        {
            while (logReader.hasNext())
            {
                final Histogram histogram = (Histogram)logReader.nextIntervalHistogram();
                if (null == aggregate)
                {
                    aggregate = histogram;
                }
                else
                {
                    aggregate.add(histogram);
                }
            }
        }
    }

    return aggregate;
}
 

private void runTimedRuns(
    final SocketChannel socketChannel,
    final TestRequestEncoder testRequest,
    final HeaderEncoder header,
    final Histogram histogram)
    throws IOException
{
    histogram.reset();

    for (int i = 0; i < MESSAGES_EXCHANGED; i++)
    {
        exchangeMessage(socketChannel, testRequest, header, WARMUP_MESSAGES + i, histogram);
    }

    HistogramLogReader.prettyPrint(
        System.currentTimeMillis(), histogram, "Client in Micros", 1000);
}
 

/**
 * @param snapshotLatencies {@code true} if is needed to force the snapshot of the interval latencies at the end of a test
 */
void updateReport(final boolean snapshotLatencies) {
    final long reportTime = System.currentTimeMillis();
    if (snapshotLatencies || this.reportIntervalLatencies) {
        final Histogram intervalHistogram = this.worker.takeLatenciesSnapshot(this.intervalHistogram);
        //there are workers that doesn't support taking latencies histograms
        if (intervalHistogram != null) {
            //the first time the startTimeStamp is the first one: useful when aren't performed
            //snapshots of interval latencies
            if (this.intervalHistogram == null) {
                intervalHistogram.setStartTimeStamp(this.startReportingTime);
            } else {
                //if it is the first snapshot taken then it is from the beginning of the worker lifecycle
                intervalHistogram.setStartTimeStamp(this.lastReportTime);
            }
            intervalHistogram.setEndTimeStamp(reportTime);
            this.intervalHistogram = intervalHistogram;
        }
    }
    this.lastReportTime = reportTime;
}
 

public RuntimeStatisticsHolder(final Enum<E>[] results, final Enum<E>[] resultsReported,
                               final Set<StatisticsCollector> statisticsCollectors) {
  this.results = results;
  this.resultsReported = resultsReported;
  this.statisticsCollectors = statisticsCollectors;
  this.histograms = new RainfallHistogramSink<E>(new RainfallHistogramSink.Factory() {
    @Override
    public ConcurrentHashMap<Enum, Histogram> createHistograms() {
      ConcurrentHashMap<Enum, Histogram> histograms = new ConcurrentHashMap<Enum, Histogram>();
      for (Enum<E> result : results) {
        histograms.put(result, new ConcurrentHistogram(3));
      }
      return histograms;
    }
  });
}
 

public ResetByChunksAccumulator(Supplier<Recorder> recorderSupplier, int numberHistoryChunks, long intervalBetweenResettingMillis, Clock clock, Executor backgroundExecutor) {
    this.intervalBetweenResettingMillis = intervalBetweenResettingMillis;
    this.clock = clock;
    this.creationTimestamp = clock.currentTimeMillis();
    this.backgroundExecutor = backgroundExecutor;

    this.left = new Phase(recorderSupplier, creationTimestamp + intervalBetweenResettingMillis);
    this.right = new Phase(recorderSupplier, Long.MAX_VALUE);
    this.phases = new Phase[] {left, right};
    this.currentPhaseRef = new AtomicReference<>(left);


    this.historySupported = numberHistoryChunks > 0;
    if (historySupported) {
        this.archive = new ArchivedHistogram[numberHistoryChunks];
        for (int i = 0; i < numberHistoryChunks; i++) {
            Histogram archivedHistogram = HistogramUtil.createNonConcurrentCopy(left.intervalHistogram);
            this.archive[i] = new ArchivedHistogram(archivedHistogram, Long.MIN_VALUE);
        }
    } else {
        this.archive = null;
    }

    this.temporarySnapshotHistogram = HistogramUtil.createNonConcurrentCopy(left.intervalHistogram);
}
 

@Override
public synchronized void record(final Histogram histogram) {
    long maxRecordedValue = histogram.getValueAtPercentile(this.defaultPercentile);

    if (logger.isTraceEnabled()) {
        logger.trace("Checking the current latency: {} x {}", maxRecordedValue, getMaxValue());
    }

    if (maxRecordedValue > getMaxValue()) {
        logger.warn("The maximum recorded latency ({} us) exceeds the maximum allowed value of ({} us) at percentile",
                maxRecordedValue, getMaxValue());

        setEvalFailed();
    }

    mean = histogram.getMean();
}
 

private void printStats(Histogram histogram, long elapsedTime) {
  long latency50 = histogram.getValueAtPercentile(50);
  long latency90 = histogram.getValueAtPercentile(90);
  long latency95 = histogram.getValueAtPercentile(95);
  long latency99 = histogram.getValueAtPercentile(99);
  long latency999 = histogram.getValueAtPercentile(99.9);
  long latencyMax = histogram.getValueAtPercentile(100);
  long queriesPerSecond = histogram.getTotalCount() * 1000000000L / elapsedTime;

  StringBuilder values = new StringBuilder();
  values.append("Channels:                       ").append(config.channels).append('\n')
        .append("Outstanding RPCs per Channel:   ")
        .append(config.outstandingRpcsPerChannel).append('\n')
        .append("Server Payload Size:            ").append(config.serverPayload).append('\n')
        .append("Client Payload Size:            ").append(config.clientPayload).append('\n')
        .append("50%ile Latency (in micros):     ").append(latency50).append('\n')
        .append("90%ile Latency (in micros):     ").append(latency90).append('\n')
        .append("95%ile Latency (in micros):     ").append(latency95).append('\n')
        .append("99%ile Latency (in micros):     ").append(latency99).append('\n')
        .append("99.9%ile Latency (in micros):   ").append(latency999).append('\n')
        .append("Maximum Latency (in micros):    ").append(latencyMax).append('\n')
        .append("QPS:                            ").append(queriesPerSecond).append('\n');
  System.out.println(values);
}
 

private Histogram readHistogram(final Path file) throws FileNotFoundException
{
    final List<EncodableHistogram> histograms = new ArrayList<>();
    final HistogramLogReader logReader = new HistogramLogReader(file.toFile());
    try
    {
        while (logReader.hasNext())
        {
            histograms.add(logReader.nextIntervalHistogram());
        }
    }
    finally
    {
        logReader.close();
    }
    assertEquals(1, histograms.size());
    return (Histogram)histograms.get(0);
}
 

@Override
  public void summarize(final StatisticsHolder<E> statisticsHolder) {
//    sb.append(String.format(FORMAT, "Cache", "Type", "Txn_Count", "TPS", "Avg_Lat"))
    Enum<E>[] results = statisticsHolder.getResultsReported();
    for (Enum<E> result : results) {
      System.out.println("Percentiles distribution for result : " + result);
      try {
        Histogram histogram = statisticsHolder.fetchHistogram(result);
        try {
          histogram = histogram.copyCorrectedForCoordinatedOmission(1000L);
        } catch (Throwable t) {
          // again, inexplicably needed
        }
        histogram.outputPercentileDistribution(System.out, 5, 1000000d, false);
      } catch (Exception e) {
        e.printStackTrace();
      }
    }
  }
 

public LazyHistogram(Aggregate.Histogram hist) {
    ByteString encodedBytes = hist.getEncodedBytes();
    if (encodedBytes.isEmpty()) {
        List<Long> orderedRawValues = hist.getOrderedRawValueList();
        values = new long[orderedRawValues.size()];
        for (int i = 0; i < values.length; i++) {
            values[i] = orderedRawValues.get(i);
        }
        size = values.length;
    } else {
        histogram = Histogram.decodeFromByteBuffer(encodedBytes.asReadOnlyByteBuffer(), 0);
    }
}
 

private static void execute(
    int count,
    SimpleServiceGrpc.SimpleServiceStub simpleService,
    Histogram histogram,
    int concurrency,
    ExecutorService executor) {
  Flux.range(1, count)
      .publishOn(Schedulers.elastic())
      .flatMap(
          integer -> {
            long s = System.nanoTime();
            SimpleRequest request = SimpleRequest.newBuilder().setRequestMessage("hello").build();
            return Flux.create(
                sink -> {
                  simpleService.requestReply(
                      request,
                      new StreamObserver<SimpleResponse>() {
                        @Override
                        public void onNext(SimpleResponse value) {
                          sink.next(value);
                        }

                        @Override
                        public void onError(Throwable t) {
                          sink.error(t);
                        }

                        @Override
                        public void onCompleted() {
                          histogram.recordValue(System.nanoTime() - s);
                          sink.complete();
                        }
                      });
                });
          },
          concurrency)
      .blockLast();
}
 

/**
 * Constructor.
 *
 * @param h the HdrHistogram object into which values are written.
 * @param scale the value by which to divide the durationNanos field of each TimingEvent before
 *              recording it in the histogram. For example, to record milliseconds you would set
 *              the scale to 1,000,000, for microseconds you would use 1,000, and so on.
 */
public HdrHistogramRecorder(final Histogram h, long scale) {
  this.histogram = h;
  this.scale = scale;
  this.errorCount = 0;
  this.startNanos = System.nanoTime();
  this.endNanos = System.nanoTime();
  this.started = false;
}
 

private static void printAggregatedStats() {
    Histogram reportHistogram = cumulativeRecorder.getIntervalHistogram();

    log.info(
            "Aggregated latency stats --- Latency: mean: {} ms - med: {} - 95pct: {} - 99pct: {} - 99.9pct: {} - 99.99pct: {} - 99.999pct: {} - Max: {}",
            dec.format(reportHistogram.getMean()), reportHistogram.getValueAtPercentile(50),
            reportHistogram.getValueAtPercentile(95), reportHistogram.getValueAtPercentile(99),
            reportHistogram.getValueAtPercentile(99.9), reportHistogram.getValueAtPercentile(99.99),
            reportHistogram.getValueAtPercentile(99.999), reportHistogram.getMaxValue());
}
 

private Histogram getAggregateHistogram() {
    long currentTime = clock.tickMillis();
    purgeOldHistograms(currentTime);

    aggregateHistograms();
    return aggregateHistogram;
}
 

@Override
public synchronized Histogram get() throws InterruptedException {
  while (!isDone() && !isCancelled()) {
    wait();
  }

  if (isCancelled()) {
    throw new CancellationException();
  }

  return histogram;
}
 

/**
 * Start the QPS Client.
 */
public void run() throws Exception {
  if (config == null) {
    return;
  }

  SimpleRequest req = newRequest();

  List<ManagedChannel> channels = new ArrayList<>(config.channels);
  for (int i = 0; i < config.channels; i++) {
    channels.add(config.newChannel());
  }

  // Do a warmup first. It's the same as the actual benchmark, except that
  // we ignore the statistics.
  warmup(req, channels);

  long startTime = System.nanoTime();
  long endTime = startTime + TimeUnit.SECONDS.toNanos(config.duration);
  List<Histogram> histograms = doBenchmark(req, channels, endTime);
  long elapsedTime = System.nanoTime() - startTime;

  Histogram merged = merge(histograms);

  printStats(merged, elapsedTime);
  if (config.histogramFile != null) {
    saveHistogram(merged, config.histogramFile);
  }
  shutdown(channels);
}
 

private void assertHistogramContent(Histogram histogram, long... requiredValues) {
    assertEquals(histogram.getTotalCount(), requiredValues.length);

    for (long requiredValue : requiredValues) {
        if (!contains(histogram, requiredValue)) {
            fail("Value " + requiredValue + " not found in histogram");
        }
    }
}
 

public HdrData convertLog(final Histogram histogram) {
    HdrData ret = new HdrData();

    histogram.recordedValues().forEach(value -> addHdr(ret, value.getPercentile(),
            value.getDoubleValueIteratedTo() / unitRatio));

    return ret;
}
 

private Histogram merge(final List<File> encodedHistogramsGeneratedAfterWarmup)
{
    final Histogram histogram = HISTOGRAMS.createHistogram();

    encodedHistogramsGeneratedAfterWarmup.stream().forEach((file) -> {
        histogram.add(loadHistogram(file));
    });

    return histogram;
}
 

private void outputHistogram(final Histogram histogram, final int streamNumber, final String qualifier)
{
    try
    {
        try(final PrintStream printStream = new PrintStream(getHistogramOutputFile(commandLineArgs, streamNumber, qualifier)))
        {
            new HistogramLogWriter(printStream).outputIntervalHistogram(streamNumber, streamNumber + 1, histogram, 1d);
        }
    }
    catch (FileNotFoundException e)
    {
        throw new RuntimeException("Failed to write histogram", e);
    }
}
 

private static Histogram createResultHistogram(final List<Histogram> list, final long start, final long end) {
    final Histogram result = new Histogram(TimeUnit.SECONDS.toNanos(10), 3);
    result.setStartTimeStamp(start);
    result.setEndTimeStamp(end);
    for (final Histogram hist : list) {
        result.add(hist);
    }
    return result;
}
 

public static Histogram createNonConcurrentCopy(Histogram source) {
    if (source instanceof ConcurrentHistogram) {
        return new Histogram(source.getNumberOfSignificantValueDigits());
    } else if (source instanceof AtomicHistogram) {
        return new Histogram(
                source.getLowestDiscernibleValue(),
                source.getHighestTrackableValue(),
                source.getNumberOfSignificantValueDigits()
        );
    } else {
        throw new IllegalArgumentException("Unsupported histogram class " + source.getClass());
    }
}