Skip to content

Commit

Permalink
Correct Prometheus output for timer and JSON output for SimpleTimer (…
Browse files Browse the repository at this point in the history
…2.x) (#4242)

* Correct Prometheus output for timer and JSON output for SimpleTimer; add tests

Signed-off-by: tim.quinn@oracle.com <tim.quinn@oracle.com>
  • Loading branch information
tjquinno committed May 23, 2022
1 parent bfdec46 commit bb31c26
Show file tree
Hide file tree
Showing 5 changed files with 339 additions and 56 deletions.
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
/*
* Copyright (c) 2020, 2021 Oracle and/or its affiliates.
* Copyright (c) 2020, 2022 Oracle and/or its affiliates.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
Expand Down Expand Up @@ -127,9 +127,11 @@ public String prometheusValue() {

@Override
public void jsonData(JsonObjectBuilder builder, MetricID metricID) {
double scaledElapsedTime = ((double) getElapsedTime().toNanos()) / conversionFactor();

JsonObjectBuilder myBuilder = JSON.createObjectBuilder()
.add(jsonFullKey("count", metricID), getCount())
.add(jsonFullKey("elapsedTime", metricID), elapsedTimeInSeconds());
.add(jsonFullKey("elapsedTime", metricID), scaledElapsedTime);
builder.add(metricID.getName(), myBuilder);
}

Expand Down
57 changes: 11 additions & 46 deletions metrics/metrics/src/main/java/io/helidon/metrics/HelidonTimer.java
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
/*
* Copyright (c) 2018, 2021 Oracle and/or its affiliates.
* Copyright (c) 2018, 2022 Oracle and/or its affiliates.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
Expand Down Expand Up @@ -27,7 +27,6 @@
import org.eclipse.microprofile.metrics.Meter;
import org.eclipse.microprofile.metrics.MetricID;
import org.eclipse.microprofile.metrics.MetricType;
import org.eclipse.microprofile.metrics.MetricUnits;
import org.eclipse.microprofile.metrics.Snapshot;
import org.eclipse.microprofile.metrics.Timer;

Expand Down Expand Up @@ -113,15 +112,23 @@ DisplayableLabeledSnapshot snapshot(){
@Override
public void prometheusData(StringBuilder sb, MetricID metricID, boolean withHelpType) {

PrometheusName name = PrometheusName.create(this, metricID);
// In Prometheus, times are always expressed in seconds. So force the TimeUnits value accordingly, ignoring
// whatever units were specified in the timer's metadata.
PrometheusName name = PrometheusName.create(this, metricID, TimeUnits.PROMETHEUS_TIMER_CONVERSION_TIME_UNITS);

appendPrometheusTimerStatElement(sb, name, "rate_per_second", withHelpType, "gauge", getMeanRate());
appendPrometheusTimerStatElement(sb, name, "one_min_rate_per_second", withHelpType, "gauge", getOneMinuteRate());
appendPrometheusTimerStatElement(sb, name, "five_min_rate_per_second", withHelpType, "gauge", getFiveMinuteRate());
appendPrometheusTimerStatElement(sb, name, "fifteen_min_rate_per_second", withHelpType, "gauge", getFifteenMinuteRate());

DisplayableLabeledSnapshot snap = snapshot();
appendPrometheusHistogramElements(sb, name, withHelpType, getCount(), snap);
// We know these are all times so force the output to seconds.
appendPrometheusHistogramElements(sb,
name,
TimeUnits.PROMETHEUS_TIMER_CONVERSION_TIME_UNITS,
withHelpType,
getCount(),
snap);
}

@Override
Expand Down Expand Up @@ -154,48 +161,6 @@ public void jsonData(JsonObjectBuilder builder, MetricID metricID) {
builder.add(metricID.getName(), myBuilder);
}

private long conversionFactor() {
Units units = getUnits();
String metricUnit = units.getMetricUnit();
if (metricUnit == null) {
return 1;
}
long divisor = 1;
switch (metricUnit) {
case MetricUnits.NANOSECONDS:
divisor = 1;
break;

case MetricUnits.MICROSECONDS:
divisor = 1000;
break;

case MetricUnits.MILLISECONDS:
divisor = 1000 * 1000;
break;

case MetricUnits.SECONDS:
divisor = 1000 * 1000 * 1000;
break;

case MetricUnits.MINUTES:
divisor = 1000 * 1000 * 1000 * 60;
break;

case MetricUnits.HOURS:
divisor = 1000 * 1000 * 1000 * 60 * 60;
break;

case MetricUnits.DAYS:
divisor = 1000 * 1000 * 1000 * 60 * 60 * 24;
break;

default:
divisor = 1;
}
return divisor;
}

void appendPrometheusTimerStatElement(StringBuilder sb,
PrometheusName name,
String statName,
Expand Down
69 changes: 61 additions & 8 deletions metrics/metrics/src/main/java/io/helidon/metrics/MetricImpl.java
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
/*
* Copyright (c) 2018, 2021 Oracle and/or its affiliates.
* Copyright (c) 2018, 2022 Oracle and/or its affiliates.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
Expand Down Expand Up @@ -93,7 +93,7 @@ private static String bsls(String s) {
addTimeConverter(MetricUnits.HOURS, TimeUnit.HOURS);
addTimeConverter(MetricUnits.DAYS, TimeUnit.DAYS);

addConverter(new Units(MetricUnits.BITS, "bytes", o -> (double) o / 8));
addConverter(new Units(MetricUnits.BITS, "bytes", o -> ((Number) o).doubleValue() / 8));
addByteConverter(MetricUnits.KILOBITS, KILOBITS);
addByteConverter(MetricUnits.MEGABITS, MEGABITS);
addByteConverter(MetricUnits.GIGABITS, GIGABITS);
Expand Down Expand Up @@ -200,6 +200,47 @@ static String jsonFullKey(MetricID metricID) {
return jsonFullKey(metricID.getName(), metricID);
}

long conversionFactor() {
Units units = getUnits();
String metricUnit = units.getMetricUnit();
if (metricUnit == null) {
return 1;
}
long divisor = 1;
switch (metricUnit) {
case MetricUnits.NANOSECONDS:
divisor = 1;
break;

case MetricUnits.MICROSECONDS:
divisor = 1000;
break;

case MetricUnits.MILLISECONDS:
divisor = 1000 * 1000;
break;

case MetricUnits.SECONDS:
divisor = 1000 * 1000 * 1000;
break;

case MetricUnits.MINUTES:
divisor = 1000 * 1000 * 1000 * 60;
break;

case MetricUnits.HOURS:
divisor = 1000 * 1000 * 1000 * 60 * 60;
break;

case MetricUnits.DAYS:
divisor = 1000 * 1000 * 1000 * 60 * 60 * 24;
break;

default:
divisor = 1;
}
return divisor;
}

protected String toStringDetails() {
return "";
Expand Down Expand Up @@ -321,6 +362,16 @@ void appendPrometheusHistogramElements(StringBuilder sb, MetricID metricID,
void appendPrometheusHistogramElements(StringBuilder sb, PrometheusName name,
boolean withHelpType, long count, DisplayableLabeledSnapshot snap) {

appendPrometheusHistogramElements(sb, name, getUnits(), withHelpType, count, snap);
}

void appendPrometheusHistogramElements(StringBuilder sb,
PrometheusName name,
Units units,
boolean withHelpType,
long count,
DisplayableLabeledSnapshot snap) {

// # TYPE application:file_sizes_mean_bytes gauge
// application:file_sizes_mean_bytes 4738.231
appendPrometheusElement(sb, name, "mean", withHelpType, "gauge", snap.mean());
Expand Down Expand Up @@ -352,12 +403,12 @@ void appendPrometheusHistogramElements(StringBuilder sb, PrometheusName name,

// application:file_sizes_bytes{quantile="0.5"} 4201
// for each supported quantile
prometheusQuantile(sb, name, getUnits(), "0.5", snap.median());
prometheusQuantile(sb, name, getUnits(), "0.75", snap.sample75thPercentile());
prometheusQuantile(sb, name, getUnits(), "0.95", snap.sample95thPercentile());
prometheusQuantile(sb, name, getUnits(), "0.98", snap.sample98thPercentile());
prometheusQuantile(sb, name, getUnits(), "0.99", snap.sample99thPercentile());
prometheusQuantile(sb, name, getUnits(), "0.999", snap.sample999thPercentile());
prometheusQuantile(sb, name, units, "0.5", snap.median());
prometheusQuantile(sb, name, units, "0.75", snap.sample75thPercentile());
prometheusQuantile(sb, name, units, "0.95", snap.sample95thPercentile());
prometheusQuantile(sb, name, units, "0.98", snap.sample98thPercentile());
prometheusQuantile(sb, name, units, "0.99", snap.sample99thPercentile());
prometheusQuantile(sb, name, units, "0.999", snap.sample999thPercentile());

}

Expand Down Expand Up @@ -476,6 +527,8 @@ private TimeUnits(String metricUnit, TimeUnit timeUnit) {
super(metricUnit, "seconds", timeConverter(timeUnit));
}

static final TimeUnits PROMETHEUS_TIMER_CONVERSION_TIME_UNITS = new TimeUnits("seconds", TimeUnit.NANOSECONDS);

static Function<Object, Object> timeConverter(TimeUnit from) {
switch (from) {
case NANOSECONDS:
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,173 @@
/*
* Copyright (c) 2022 Oracle and/or its affiliates.
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*
*/
package io.helidon.metrics;

import java.time.Duration;
import java.time.temporal.ChronoUnit;
import java.util.concurrent.TimeUnit;
import java.util.regex.Matcher;
import java.util.regex.Pattern;

import javax.json.Json;
import javax.json.JsonNumber;
import javax.json.JsonObject;
import javax.json.JsonObjectBuilder;

import org.eclipse.microprofile.metrics.Metadata;
import org.eclipse.microprofile.metrics.MetricID;
import org.eclipse.microprofile.metrics.MetricType;
import org.eclipse.microprofile.metrics.MetricUnits;
import org.junit.jupiter.api.Test;
import org.junit.platform.commons.JUnitException;

import static io.helidon.metrics.HelidonMetricsMatcher.withinTolerance;

import static org.hamcrest.MatcherAssert.assertThat;
import static org.hamcrest.Matchers.is;
import static org.hamcrest.Matchers.notNullValue;

public class OutputUnitConversionTest {

private static final String TIMER_NAME = "myTimer";
private static MetricID TIMER_METRIC_ID;

private static final String SIMPLE_TIMER_NAME = "mySimpleTimer";
private static MetricID SIMPLE_TIMER_METRIC_ID;

private static final int TIMER_UPDATE_INCREMENT_MICRO_SECONDS = 120; // microseconds

private HelidonTimer prepTimer() {
TIMER_METRIC_ID = new MetricID(TIMER_NAME);
TestClock clock = TestClock.create();
HelidonTimer result = HelidonTimer.create("application", Metadata.builder()
.withName(TIMER_NAME)
.withUnit(MetricUnits.MILLISECONDS)
.withType(MetricType.TIMER)
.build(),
clock);
clock.addNanos(1, TimeUnit.MICROSECONDS);
result.update(TIMER_UPDATE_INCREMENT_MICRO_SECONDS, TimeUnit.MICROSECONDS);

// Advance the clock so most-recent-whole-minute stats have meaning.
clock.addNanos(1, TimeUnit.MINUTES);
return result;
}

private HelidonSimpleTimer prepSimpleTimer() {
SIMPLE_TIMER_METRIC_ID = new MetricID(SIMPLE_TIMER_NAME);
TestClock clock = TestClock.create();
HelidonSimpleTimer result = HelidonSimpleTimer.create("application", Metadata.builder()
.withName(SIMPLE_TIMER_NAME)
.withUnit(MetricUnits.MILLISECONDS)
.withType(MetricType.SIMPLE_TIMER)
.build(),
clock);
clock.addNanos(1, TimeUnit.MICROSECONDS);
result.update(Duration.of(TIMER_UPDATE_INCREMENT_MICRO_SECONDS, ChronoUnit.MICROS));

// Advance the clock.
clock.addNanos(1, TimeUnit.MINUTES);
return result;
}

@Test
void testPrometheusTimerConversion() {

StringBuilder prometheusSB = new StringBuilder();
HelidonTimer hTimer = prepTimer();
hTimer.prometheusData(prometheusSB, TIMER_METRIC_ID, false);
double expectedValue = 0.000120D;
// The Prometheus exposition format always represents time in seconds.
for (String suffix : new String[] {"_mean_seconds",
"_seconds{quantile=\"0.5\"}",
"_seconds{quantile=\"0.75\"}",
"_seconds{quantile=\"0.95\"}",
"_seconds{quantile=\"0.98\"}",
"_seconds{quantile=\"0.99\"}",
"_seconds{quantile=\"0.999\"}"
}) {
String label = "application_" + TIMER_NAME + suffix;
double v = valueAfterLabel(prometheusSB.toString(), label);
assertThat("Prometheus data for " + label, v, is(expectedValue));
}
}

@Test
void testPrometheusSimpleTimerConversion() {
StringBuilder prometheusSB = new StringBuilder();
HelidonSimpleTimer hSimpleTimer = prepSimpleTimer();
hSimpleTimer.prometheusData(prometheusSB, SIMPLE_TIMER_METRIC_ID, false);
// We updated the simple timer by 120 microseconds. Although the simple timer units were set to ms, Prometheus output
// always is in seconds (for times).
Duration expectedElapsedTime = Duration.of(TIMER_UPDATE_INCREMENT_MICRO_SECONDS, ChronoUnit.MICROS);
double expectedElapsedTimeInSeconds = expectedElapsedTime.toNanos() / 1000.0 / 1000.0 / 1000.0;
String label = "application_" + SIMPLE_TIMER_NAME + "_elapsedTime_seconds";
double v = valueAfterLabel(prometheusSB.toString(), label);
assertThat("SimpleTimer Prometheths elapsed time", v, is(withinTolerance(expectedElapsedTimeInSeconds)));
}

@Test
void testTimerJsonOutput() {

HelidonTimer hTimer = prepTimer();
JsonObjectBuilder builder = Json.createObjectBuilder();
hTimer.jsonData(builder, TIMER_METRIC_ID);

JsonObject json = builder.build()
.getJsonObject(TIMER_NAME);
assertThat("Metric JSON object", json, notNullValue());

// We updated timer by 120 microseconds. The timer units are ms, so the reported values should be 0.120 because
// JSON output honors the units in the metric's metadata.
double expectedValue = TIMER_UPDATE_INCREMENT_MICRO_SECONDS / 1000.0;
for (String suffix : new String[] {"mean", "p50", "p75", "p95", "p98", "p99", "p999"}) {
JsonNumber number = json.getJsonNumber(suffix);
assertThat("JsonNumber for data item " + suffix, number, notNullValue());
assertThat("JSON value for " + suffix, number.doubleValue(), is(expectedValue));
}
}

@Test
void testSimpleTimerJsonOutput() {
HelidonSimpleTimer hSimpleTimer = prepSimpleTimer();
JsonObjectBuilder builder = Json.createObjectBuilder();
hSimpleTimer.jsonData(builder, SIMPLE_TIMER_METRIC_ID);

JsonObject json = builder.build()
.getJsonObject(SIMPLE_TIMER_NAME);
assertThat("Metric JSON object", json, notNullValue());

// We updated the simple timer by 120 microseconds. The simple timer units were set to ms, so the reported value should
// be 0.120 because JSON output honors the units in the metric's metadata.
Duration expectedElapsedTime = Duration.of(TIMER_UPDATE_INCREMENT_MICRO_SECONDS, ChronoUnit.MICROS);
double expectedElapsedTimeInMillis = expectedElapsedTime.toNanos() / 1000.0 / 1000.0;
assertThat("SimpleTimer elapsed time", hSimpleTimer.getElapsedTime(), is(expectedElapsedTime));
JsonNumber number = json.getJsonNumber("elapsedTime");
assertThat("JsonNumber for elapsedTime", number, notNullValue());
assertThat("JSON value for elapsedTime", number.doubleValue(), is(withinTolerance(expectedElapsedTimeInMillis)));
}

private double valueAfterLabel(String wholeString, String label) {
Pattern pattern = Pattern.compile("^" + Pattern.quote(label) + "\\s*(\\S*)$", Pattern.MULTILINE);
Matcher matcher = pattern.matcher(wholeString);
if (!matcher.find()) {
throw new JUnitException("Unable to find value with label " + label + " in string " + wholeString);
}
String valueText = matcher.group(1);
return Double.parseDouble(valueText);
}
}
Loading

0 comments on commit bb31c26

Please sign in to comment.