Skip to content

Commit

Permalink
Scale long task timers to the implementation's base time unit
Browse files Browse the repository at this point in the history
  • Loading branch information
jkschneider committed Sep 9, 2017
1 parent 71f7e0a commit 70925b3
Show file tree
Hide file tree
Showing 14 changed files with 70 additions and 60 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@
import java.util.Arrays;
import java.util.List;
import java.util.concurrent.Callable;
import java.util.concurrent.TimeUnit;
import java.util.function.Consumer;
import java.util.function.Supplier;

Expand Down Expand Up @@ -101,14 +102,15 @@ default void record(Runnable f) {
* Returns the current duration for an active task.
*
* @param task Id for the task to stop. This should be the value returned from {@link #start()}.
* @param unit The time unit to scale the returned value to.
* @return Duration for the task in nanoseconds. A -1 value will be returned for an unknown task.
*/
long duration(long task);
double duration(long task, TimeUnit unit);

/**
* Returns the cumulative duration of all current tasks in nanoseconds.
*/
long duration();
double duration(TimeUnit unit);

/**
* Returns the current number of tasks being executed.
Expand All @@ -119,7 +121,7 @@ default void record(Runnable f) {
default Iterable<Measurement> measure() {
return Arrays.asList(
new Measurement(() -> (double) activeTasks(), Statistic.Count),
new Measurement(() -> (double) duration(), Statistic.Total)
new Measurement(() -> duration(TimeUnit.NANOSECONDS), Statistic.Total)
);
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -91,18 +91,11 @@ default Runnable wrap(Runnable f) {
*/
double totalTime(TimeUnit unit);

/**
* The total time in nanoseconds of all recorded events since this timer was created.
*/
default double totalTimeNanos() {
return totalTime(TimeUnit.NANOSECONDS);
}

@Override
default Iterable<Measurement> measure() {
return Arrays.asList(
new Measurement(() -> (double) count(), Statistic.Count),
new Measurement(this::totalTimeNanos, Statistic.Total)
new Measurement(() -> totalTime(TimeUnit.NANOSECONDS), Statistic.Total)
);
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -20,10 +20,12 @@
import io.micrometer.core.instrument.Meter;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.noop.NoopLongTaskTimer;
import io.micrometer.core.instrument.util.TimeUtils;

import java.util.Collections;
import java.util.LinkedHashMap;
import java.util.Map;
import java.util.concurrent.TimeUnit;

public class CompositeLongTaskTimer extends AbstractMeter implements LongTaskTimer, CompositeMeter {
private final Map<MeterRegistry, LongTaskTimer> timers = Collections.synchronizedMap(new LinkedHashMap<>());
Expand Down Expand Up @@ -53,22 +55,22 @@ public long stop(long task) {
}

@Override
public long duration(long task) {
public double duration(long task, TimeUnit unit) {
synchronized (timers) {
return timers.values().stream()
.map(ltt -> ltt.duration(task))
.map(ltt -> ltt.duration(task, unit))
.reduce((t1, t2) -> t2 == -1 ? t1 : t2)
.orElse(NoopLongTaskTimer.INSTANCE.duration(task));
.orElse(NoopLongTaskTimer.INSTANCE.duration(task, unit));
}
}

@Override
public long duration() {
public double duration(TimeUnit unit) {
synchronized (timers) {
return timers.values().stream()
.map(LongTaskTimer::duration)
.map(ltt -> ltt.duration(unit))
.reduce((t1, t2) -> t2)
.orElse(NoopLongTaskTimer.INSTANCE.duration());
.orElse(NoopLongTaskTimer.INSTANCE.duration(unit));
}
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -102,7 +102,7 @@ private Histogram<?> registerHistogramCounterIfNecessary(Meter.Id id, Histogram.
protected LongTaskTimer newLongTaskTimer(Meter.Id id) {
LongTaskTimer ltt = new SimpleLongTaskTimer(id, clock);
registry.register(nameMapper.toHierarchicalName(id) + ".active", (Gauge<Integer>) ltt::activeTasks);
registry.register(nameMapper.toHierarchicalName(id) + ".duration", (Gauge<Long>) ltt::duration);
registry.register(nameMapper.toHierarchicalName(id) + ".duration", (Gauge<Double>) () -> ltt.duration(TimeUnit.NANOSECONDS));
return ltt;
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,8 @@

import io.micrometer.core.instrument.LongTaskTimer;

import java.util.concurrent.TimeUnit;

public class NoopLongTaskTimer extends NoopMeter implements LongTaskTimer {
public static NoopLongTaskTimer INSTANCE = new NoopLongTaskTimer();

Expand All @@ -33,12 +35,12 @@ public long stop(long task) {
}

@Override
public long duration(long task) {
public double duration(long task, TimeUnit unit) {
return -1;
}

@Override
public long duration() {
public double duration(TimeUnit unit) {
return 0;
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -20,9 +20,11 @@
import io.micrometer.core.instrument.LongTaskTimer;
import io.micrometer.core.instrument.Meter;
import io.micrometer.core.instrument.util.MeterEquivalence;
import io.micrometer.core.instrument.util.TimeUtils;

import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ConcurrentMap;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicLong;

public class SimpleLongTaskTimer extends AbstractMeter implements LongTaskTimer {
Expand Down Expand Up @@ -54,19 +56,19 @@ public long stop(long task) {
}

@Override
public long duration(long task) {
public double duration(long task, TimeUnit unit) {
Long startTime = tasks.get(task);
return (startTime != null) ? (clock.monotonicTime() - startTime) : -1L;
return (startTime != null) ? TimeUtils.nanosToUnit(clock.monotonicTime() - startTime, unit) : -1L;
}

@Override
public long duration() {
public double duration(TimeUnit unit) {
long now = clock.monotonicTime();
long sum = 0L;
for (long startTime : tasks.values()) {
sum += now - startTime;
}
return sum;
return TimeUtils.nanosToUnit(sum, unit);
}

@Override
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -15,10 +15,15 @@
*/
package io.micrometer.core.instrument.spectator;

import ch.qos.logback.core.util.TimeUtil;
import io.micrometer.core.instrument.AbstractMeter;
import io.micrometer.core.instrument.LongTaskTimer;
import io.micrometer.core.instrument.Meter;
import io.micrometer.core.instrument.util.MeterEquivalence;
import io.micrometer.core.instrument.util.TimeUtils;

import java.sql.Time;
import java.util.concurrent.TimeUnit;

public class SpectatorLongTaskTimer extends AbstractMeter implements LongTaskTimer {
private final com.netflix.spectator.api.LongTaskTimer timer;
Expand All @@ -39,13 +44,13 @@ public long stop(long task) {
}

@Override
public long duration(long task) {
return timer.duration(task);
public double duration(long task, TimeUnit unit) {
return TimeUtils.nanosToUnit(timer.duration(task), unit);
}

@Override
public long duration() {
return timer.duration();
public double duration(TimeUnit unit) {
return TimeUtils.nanosToUnit(timer.duration(), unit);
}

@Override
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,8 @@
import org.junit.jupiter.params.ParameterizedTest;
import org.junit.jupiter.params.provider.ArgumentsSource;

import java.util.concurrent.TimeUnit;

import static io.micrometer.core.instrument.MockClock.clock;
import static java.util.Collections.emptyList;
import static org.junit.jupiter.api.Assertions.assertAll;
Expand All @@ -35,15 +37,17 @@ void record(MeterRegistry registry) {
long tId = t.start();
clock(registry).addAndGetNanos(10);

assertAll(() -> assertEquals(10, t.duration()),
() -> assertEquals(10, t.duration(tId)),
() -> assertEquals(1, t.activeTasks()));
assertAll(() -> assertEquals(10, t.duration(TimeUnit.NANOSECONDS)),
() -> assertEquals(0.01, t.duration(TimeUnit.MICROSECONDS)),
() -> assertEquals(10, t.duration(tId, TimeUnit.NANOSECONDS)),
() -> assertEquals(0.01, t.duration(tId, TimeUnit.MICROSECONDS)),
() -> assertEquals(1, t.activeTasks()));

clock(registry).addAndGetNanos(10);
t.stop(tId);

assertAll(() -> assertEquals(0, t.duration()),
() -> assertEquals(-1, t.duration(tId)),
() -> assertEquals(0, t.activeTasks()));
assertAll(() -> assertEquals(0, t.duration(TimeUnit.NANOSECONDS)),
() -> assertEquals(-1, t.duration(tId, TimeUnit.NANOSECONDS)),
() -> assertEquals(0, t.activeTasks()));
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -57,7 +57,7 @@ void recordNegative(MeterRegistry registry) {
t.record(-42, TimeUnit.MILLISECONDS);

assertAll(() -> assertEquals(0L, t.count()),
() -> assertEquals(0, t.totalTimeNanos(), 1.0e-12));
() -> assertEquals(0, t.totalTime(TimeUnit.NANOSECONDS), 1.0e-12));
}

@DisplayName("zero times contribute to the count of overall events but do not add to total time")
Expand All @@ -69,7 +69,7 @@ void recordZero(MeterRegistry registry) {
clock(registry).addAndGet(1, TimeUnit.SECONDS);

assertAll(() -> assertEquals(1L, t.count()),
() -> assertEquals(0L, t.totalTimeNanos()));
() -> assertEquals(0L, t.totalTime(TimeUnit.NANOSECONDS)));
}

@DisplayName("record a runnable task")
Expand All @@ -83,7 +83,7 @@ void recordWithRunnable(MeterRegistry registry) throws Exception {
clock(registry).addAndGet(1, TimeUnit.SECONDS);
} finally {
assertAll(() -> assertEquals(1L, t.count()),
() -> assertEquals(10, t.totalTimeNanos() ,1.0e-12));
() -> assertEquals(10, t.totalTime(TimeUnit.NANOSECONDS) ,1.0e-12));
}
}

Expand All @@ -103,6 +103,6 @@ void recordCallableException(MeterRegistry registry) {
clock(registry).addAndGet(1, TimeUnit.SECONDS);

assertAll(() -> assertEquals(1L, t.count()),
() -> assertEquals(10, t.totalTimeNanos(), 1.0e-12));
() -> assertEquals(10, t.totalTime(TimeUnit.NANOSECONDS), 1.0e-12));
}
}
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,8 @@
import io.micrometer.core.instrument.util.MeterEquivalence;
import io.micrometer.prometheus.internal.CustomPrometheusLongTaskTimer;

import java.util.concurrent.TimeUnit;

public class PrometheusLongTaskTimer extends AbstractMeter implements LongTaskTimer {
private final CustomPrometheusLongTaskTimer.Child timer;

Expand All @@ -40,13 +42,13 @@ public long stop(long task) {
}

@Override
public long duration(long task) {
return timer.duration(task);
public double duration(long task, TimeUnit unit) {
return timer.duration(task, unit);
}

@Override
public long duration() {
return timer.duration();
public double duration(TimeUnit unit) {
return timer.duration(unit);
}

@Override
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -55,6 +55,7 @@ public String name(String name, Meter.Type type, String baseUnit) {
conventionName += "_total";
break;
case Timer:
case LongTaskTimer:
if(conventionName.endsWith("_duration")) {
conventionName += "_seconds";
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@
import io.micrometer.core.instrument.Clock;
import io.micrometer.core.instrument.Meter;
import io.micrometer.core.instrument.Tag;
import io.micrometer.core.instrument.util.TimeUtils;
import io.prometheus.client.Collector;

import java.util.Collection;
Expand All @@ -27,6 +28,7 @@
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.ConcurrentLinkedQueue;
import java.util.concurrent.ConcurrentMap;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicLong;
import java.util.stream.Stream;

Expand All @@ -36,6 +38,8 @@
public class CustomPrometheusLongTaskTimer extends Collector {
private final Clock clock;
private final String name;
private final String activeTasksName;
private final String durationName;
private final String description;
private final List<String> tagKeys;
private final Collection<Child> children = new ConcurrentLinkedQueue<>();
Expand All @@ -45,6 +49,9 @@ public CustomPrometheusLongTaskTimer(Meter.Id id, Clock clock) {
this.description = id.getDescription();
this.clock = clock;
this.tagKeys = id.getConventionTags().stream().map(Tag::getKey).collect(toList());

this.activeTasksName = name + "_active_count";
this.durationName = name + "_sum";
}

public Child child(Iterable<Tag> tags) {
Expand All @@ -65,19 +72,8 @@ public class Child implements CustomCollectorChild {
@Override
public Stream<MetricFamilySamples.Sample> collect() {
Stream.Builder<MetricFamilySamples.Sample> samples = Stream.builder();

List<String> activeTasksKeys = new LinkedList<>(tagKeys);
activeTasksKeys.add("statistic");
List<String> activeTasksValues = new LinkedList<>(tagValues);
activeTasksValues.add("active_tasks");
samples.add(new MetricFamilySamples.Sample(name, activeTasksKeys, activeTasksValues, activeTasks()));

List<String> durationKeys = new LinkedList<>(tagKeys);
durationKeys.add("statistic");
List<String> durationValues = new LinkedList<>(tagValues);
durationValues.add("duration");
samples.add(new MetricFamilySamples.Sample(name, durationKeys, durationValues, duration()));

samples.add(new MetricFamilySamples.Sample(activeTasksName, tagKeys, tagValues, activeTasks()));
samples.add(new MetricFamilySamples.Sample(durationName, tagKeys, tagValues, duration(TimeUnit.SECONDS)));
return samples.build();
}

Expand All @@ -97,18 +93,18 @@ public long stop(long task) {
}
}

public long duration(long task) {
public double duration(long task, TimeUnit unit) {
Long startTime = tasks.get(task);
return (startTime != null) ? (clock.monotonicTime() - startTime) : -1L;
return (startTime != null) ? TimeUtils.nanosToUnit(clock.monotonicTime() - startTime, unit) : -1L;
}

public long duration() {
public double duration(TimeUnit unit) {
long now = clock.monotonicTime();
long sum = 0L;
for (long startTime : tasks.values()) {
sum += now - startTime;
}
return sum;
return TimeUtils.nanosToUnit(sum, unit);
}

public int activeTasks() {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -108,7 +108,7 @@ void helpText() {
.contains("HELP summary my summary")
.contains("HELP gauge my gauge")
.contains("HELP counter_total my counter")
.contains("HELP long_task_timer my long task timer");
.contains("HELP long_task_timer_duration_seconds my long task timer");
}

private Condition<Enumeration<Collector.MetricFamilySamples>> withNameAndTagKey(String name, String tagKey) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -39,6 +39,7 @@ void formatTagKey() {
@Test
void unitsAreAppendedToTimers() {
assertThat(convention.name("timer", Meter.Type.Timer)).isEqualTo("timer_duration_seconds");
assertThat(convention.name("timer", Meter.Type.LongTaskTimer)).isEqualTo("timer_duration_seconds");
}

@Test
Expand Down

0 comments on commit 70925b3

Please sign in to comment.