Skip to content

Commit 8a476cf

Browse files
tjquinnotjquinno
authored
Improve some interceptor code paths in metrics (helidon-io#3251)
1 parent ec9823e commit 8a476cf

14 files changed

Lines changed: 208 additions & 87 deletions

File tree

‎metrics/metrics/src/main/java/io/helidon/metrics/ExemplarServiceManager.java‎

Lines changed: 13 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -35,10 +35,11 @@ class ExemplarServiceManager {
3535

3636
private static final List<ExemplarService> EXEMPLAR_SERVICES = collectExemplarServices();
3737

38+
private static final boolean IS_ACTIVE = !EXEMPLAR_SERVICES.isEmpty();
3839

39-
private static final Supplier<String> EXEMPLAR_SUPPLIER = EXEMPLAR_SERVICES.isEmpty()
40-
? () -> ""
41-
: () -> EXEMPLAR_SERVICES.stream()
40+
static final String INACTIVE_LABEL = "";
41+
42+
private static final Supplier<String> EXEMPLAR_SUPPLIER = () -> EXEMPLAR_SERVICES.stream()
4243
.map(ExemplarService::label)
4344
.filter(Predicate.not(String::isBlank))
4445
.collect(ExemplarServiceManager::labelsStringJoiner, StringJoiner::add, StringJoiner::merge)
@@ -58,7 +59,15 @@ private static StringJoiner labelsStringJoiner() {
5859
* @return exemplar string provided by the highest-priority service instance
5960
*/
6061
static String exemplarLabel() {
61-
return EXEMPLAR_SUPPLIER.get();
62+
return IS_ACTIVE ? EXEMPLAR_SUPPLIER.get() : INACTIVE_LABEL;
63+
}
64+
65+
/**
66+
*
67+
* @return whether exemplar handling is active or not
68+
*/
69+
static boolean isActive() {
70+
return IS_ACTIVE;
6271
}
6372

6473
private static List<ExemplarService> collectExemplarServices() {

‎metrics/metrics/src/main/java/io/helidon/metrics/ExponentiallyDecayingReservoir.java‎

Lines changed: 53 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -17,11 +17,16 @@
1717
package io.helidon.metrics;
1818

1919
import java.util.ArrayList;
20+
import java.util.List;
2021
import java.util.concurrent.ConcurrentSkipListMap;
22+
import java.util.concurrent.Executors;
23+
import java.util.concurrent.ScheduledExecutorService;
2124
import java.util.concurrent.ThreadLocalRandom;
2225
import java.util.concurrent.TimeUnit;
2326
import java.util.concurrent.atomic.AtomicLong;
2427
import java.util.concurrent.locks.ReentrantReadWriteLock;
28+
import java.util.logging.Level;
29+
import java.util.logging.Logger;
2530

2631
import static java.lang.Math.exp;
2732
import static java.lang.Math.min;
@@ -49,6 +54,49 @@ class ExponentiallyDecayingReservoir {
4954
private static final double DEFAULT_ALPHA = 0.015;
5055
private static final long RESCALE_THRESHOLD = TimeUnit.HOURS.toNanos(1);
5156

57+
/*
58+
* Avoid computing the current time in seconds during every reservoir update by updating its value on a scheduled basis.
59+
*/
60+
private static final long CURRENT_TIME_IN_SECONDS_UPDATE_INTERVAL_MS = 250;
61+
62+
private static final List<Runnable> CURRENT_TIME_IN_SECONDS_UPDATERS = new ArrayList<>();
63+
64+
private static final ScheduledExecutorService CURRENT_TIME_UPDATER_EXECUTOR_SERVICE = initCurrentTimeUpdater();
65+
66+
private static final Logger LOGGER = Logger.getLogger(ExponentiallyDecayingReservoir.class.getName());
67+
68+
private volatile long currentTimeInSeconds;
69+
70+
private static ScheduledExecutorService initCurrentTimeUpdater() {
71+
ScheduledExecutorService result = Executors.newSingleThreadScheduledExecutor();
72+
result.scheduleAtFixedRate(ExponentiallyDecayingReservoir::updateCurrentTimeInSecondsForAllReservoirs,
73+
CURRENT_TIME_IN_SECONDS_UPDATE_INTERVAL_MS,
74+
CURRENT_TIME_IN_SECONDS_UPDATE_INTERVAL_MS, TimeUnit.MILLISECONDS);
75+
return result;
76+
}
77+
78+
static void onServerShutdown() {
79+
CURRENT_TIME_UPDATER_EXECUTOR_SERVICE.shutdown();
80+
try {
81+
boolean stoppedNormally =
82+
CURRENT_TIME_UPDATER_EXECUTOR_SERVICE.awaitTermination(CURRENT_TIME_IN_SECONDS_UPDATE_INTERVAL_MS * 10,
83+
TimeUnit.MILLISECONDS);
84+
if (!stoppedNormally) {
85+
LOGGER.log(Level.WARNING, "Shutdown of current time updater timed out; continuing");
86+
}
87+
} catch (InterruptedException e) {
88+
LOGGER.log(Level.WARNING, "InterruptedException caught while stopping the current time updater; continuing");
89+
}
90+
}
91+
92+
private static void updateCurrentTimeInSecondsForAllReservoirs() {
93+
CURRENT_TIME_IN_SECONDS_UPDATERS.forEach(Runnable::run);
94+
}
95+
96+
private long computeCurrentTimeInSeconds() {
97+
return TimeUnit.MILLISECONDS.toSeconds(clock.milliTime());
98+
}
99+
52100
private final ConcurrentSkipListMap<Double, WeightedSnapshot.WeightedSample> values;
53101
private final ReentrantReadWriteLock lock;
54102
private final double alpha;
@@ -81,7 +129,9 @@ class ExponentiallyDecayingReservoir {
81129
this.alpha = alpha;
82130
this.size = size;
83131
this.count = new AtomicLong(0);
84-
this.startTime = currentTimeInSeconds();
132+
CURRENT_TIME_IN_SECONDS_UPDATERS.add(this::computeCurrentTimeInSeconds);
133+
currentTimeInSeconds = computeCurrentTimeInSeconds();
134+
this.startTime = currentTimeInSeconds;
85135
this.nextScaleTime = new AtomicLong(clock.nanoTick() + RESCALE_THRESHOLD);
86136
}
87137

@@ -90,7 +140,7 @@ public int size() {
90140
}
91141

92142
public void update(long value, String label) {
93-
update(value, currentTimeInSeconds(), label);
143+
update(value, currentTimeInSeconds, label);
94144
}
95145

96146
/**
@@ -143,10 +193,6 @@ public WeightedSnapshot getSnapshot() {
143193
}
144194
}
145195

146-
private long currentTimeInSeconds() {
147-
return TimeUnit.MILLISECONDS.toSeconds(clock.milliTime());
148-
}
149-
150196
private double weight(long t) {
151197
return exp(alpha * t);
152198
}
@@ -174,7 +220,7 @@ private void rescale(long now, long next) {
174220
try {
175221
if (nextScaleTime.compareAndSet(next, now + RESCALE_THRESHOLD)) {
176222
final long oldStartTime = startTime;
177-
this.startTime = currentTimeInSeconds();
223+
this.startTime = currentTimeInSeconds;
178224
final double scalingFactor = exp(-alpha * (startTime - oldStartTime));
179225
if (Double.compare(scalingFactor, 0) == 0) {
180226
values.clear();

‎metrics/metrics/src/main/java/io/helidon/metrics/HelidonMetric.java‎

Lines changed: 14 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
/*
2-
* Copyright (c) 2018, 2020 Oracle and/or its affiliates. All rights reserved.
2+
* Copyright (c) 2018, 2021 Oracle and/or its affiliates.
33
*
44
* Licensed under the Apache License, Version 2.0 (the "License");
55
* you may not use this file except in compliance with the License.
@@ -74,4 +74,17 @@ interface HelidonMetric extends Metric {
7474
* @return the metric's {@link Metadata}
7575
*/
7676
Metadata metadata();
77+
78+
/**
79+
* Returns whether the metric has been deleted.
80+
*
81+
* @return true if the metrics was removed from the registry; false otherwise
82+
*/
83+
boolean isDeleted();
84+
85+
/**
86+
* Mark this metric as deleted.
87+
*/
88+
void markAsDeleted();
89+
7790
}

‎metrics/metrics/src/main/java/io/helidon/metrics/MetricImpl.java‎

Lines changed: 13 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -125,6 +125,9 @@ private static Map<String, String> initEscapedCharsMap() {
125125
private final String registryType;
126126
private final Metadata metadata;
127127

128+
// Efficient check from interceptors to see if the metric is still valid
129+
private boolean isDeleted;
130+
128131
MetricImpl(String registryType, Metadata metadata) {
129132
this.metadata = metadata;
130133
this.registryType = registryType;
@@ -188,6 +191,16 @@ public void jsonMeta(JsonObjectBuilder builder, List<MetricID> metricIDs) {
188191
builder.add(getName(), metaBuilder);
189192
}
190193

194+
@Override
195+
public boolean isDeleted() {
196+
return isDeleted;
197+
}
198+
199+
@Override
200+
public void markAsDeleted() {
201+
isDeleted = true;
202+
}
203+
191204
static String jsonFullKey(String baseName, MetricID metricID) {
192205
return metricID.getTags().isEmpty() ? baseName
193206
: String.format("%s;%s", baseName,

‎metrics/metrics/src/main/java/io/helidon/metrics/MetricsSupport.java‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -430,6 +430,11 @@ public void update(Routing.Rules rules) {
430430
configureEndpoint(rules, rules);
431431
}
432432

433+
@Override
434+
protected void onShutdown() {
435+
ExponentiallyDecayingReservoir.onServerShutdown();
436+
}
437+
433438
private static KeyPerformanceIndicatorSupport.Context kpiContext(ServerRequest request) {
434439
return request.context()
435440
.get(KeyPerformanceIndicatorSupport.Context.class)

‎metrics/metrics/src/main/java/io/helidon/metrics/Registry.java‎

Lines changed: 23 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,5 @@
11
/*
2-
* Copyright (c) 2018, 2020 Oracle and/or its affiliates.
2+
* Copyright (c) 2018, 2021 Oracle and/or its affiliates.
33
*
44
* Licensed under the Apache License, Version 2.0 (the "License");
55
* you may not use this file except in compliance with the License.
@@ -82,6 +82,17 @@ public static Registry create(Type type) {
8282
return new Registry(type);
8383
}
8484

85+
/**
86+
* Indicates whether the specific metrics has been marked as deleted.
87+
*
88+
* @param metric the metric to check
89+
* @return true if it's a Helidon metric and has been marked as deleted; false otherwise
90+
*/
91+
public static boolean isMarkedAsDeleted(Metric metric) {
92+
return (metric instanceof HelidonMetric)
93+
&& ((HelidonMetric) metric).isDeleted();
94+
}
95+
8596
@Override
8697
public <T extends Metric> T register(String name, T metric) throws IllegalArgumentException {
8798
return registerUniqueMetric(name, metric);
@@ -225,12 +236,14 @@ public SimpleTimer simpleTimer(Metadata metadata, Tag... tags) {
225236
*/
226237
@Override
227238
public synchronized boolean remove(String name) {
228-
final List<MetricID> metricIDs = allMetricIDsByName.get(name);
229-
if (metricIDs == null) {
239+
final List<Map.Entry<MetricID, HelidonMetric>> doomedMetrics = getMetricsByName(name);
240+
if (doomedMetrics.isEmpty()) {
230241
return false;
231242
}
232-
final boolean result = metricIDs.stream()
233-
.map(metricID -> allMetrics.remove(metricID) != null)
243+
244+
final boolean result = doomedMetrics.stream()
245+
.peek(entry -> entry.getValue().markAsDeleted())
246+
.map(entry -> allMetrics.remove(entry.getKey()) != null)
234247
.reduce((a, b) -> a || b)
235248
.orElse(false);
236249
allMetricIDsByName.remove(name);
@@ -256,7 +269,11 @@ public synchronized boolean remove(MetricID metricID) {
256269
allMetadata.remove(metricID.getName());
257270
}
258271

259-
return allMetrics.remove(metricID) != null;
272+
HelidonMetric doomedMetric = allMetrics.remove(metricID);
273+
if (doomedMetric != null) {
274+
doomedMetric.markAsDeleted();
275+
}
276+
return doomedMetric != null;
260277
}
261278

262279
@Override

‎metrics/metrics/src/main/java/io/helidon/metrics/Sample.java‎

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -21,6 +21,8 @@
2121
*/
2222
interface Sample {
2323

24+
boolean IS_EXEMPLAR_HANDLING_ACTIVE = ExemplarServiceManager.isActive();
25+
2426
static Derived derived(double value, Sample.Labeled reference) {
2527
return new Derived.Impl(value, reference);
2628
}
@@ -30,7 +32,9 @@ static Derived derived(double value) {
3032
}
3133

3234
static Labeled labeled(long value) {
33-
return new Labeled.Impl(value, ExemplarServiceManager.exemplarLabel(), System.currentTimeMillis());
35+
return IS_EXEMPLAR_HANDLING_ACTIVE
36+
? new Labeled.Impl(value, ExemplarServiceManager.exemplarLabel(), System.currentTimeMillis())
37+
: new Labeled.Impl(value, ExemplarServiceManager.INACTIVE_LABEL, 0);
3438
}
3539

3640
/**

‎metrics/metrics/src/main/java/io/helidon/metrics/WeightedSnapshot.java‎

Lines changed: 5 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -321,6 +321,9 @@ public void dump(OutputStream output) {
321321

322322
/**
323323
* Labeled sample with a weight.
324+
*
325+
* If the label is empty, then this sample will never be an exemplar so we do not need to default the timestamp to the
326+
* current time.
324327
*/
325328
static class WeightedSample extends Labeled.Impl {
326329

@@ -335,11 +338,11 @@ static class WeightedSample extends Labeled.Impl {
335338
}
336339

337340
WeightedSample(long value, double weight, String label) {
338-
this(value, weight, System.currentTimeMillis(), label);
341+
this(value, weight, label.isEmpty() ? 0 : System.currentTimeMillis(), label);
339342
}
340343

341344
WeightedSample(long value) {
342-
this(value, 1.0, System.currentTimeMillis(), "");
345+
this(value, 1.0, 0, "");
343346
}
344347

345348
long getValue() {

‎microprofile/metrics/src/main/java/io/helidon/microprofile/metrics/InterceptorBase.java‎

Lines changed: 9 additions & 17 deletions
Original file line numberDiff line numberDiff line change
@@ -17,19 +17,18 @@
1717
package io.helidon.microprofile.metrics;
1818

1919
import java.lang.annotation.Annotation;
20-
import java.util.Map;
2120
import java.util.function.Consumer;
2221
import java.util.logging.Level;
2322
import java.util.logging.Logger;
2423

2524
import javax.inject.Inject;
2625
import javax.interceptor.InvocationContext;
2726

27+
import io.helidon.metrics.Registry;
2828
import io.helidon.microprofile.metrics.MetricsCdiExtension.MetricWorkItem;
2929
import io.helidon.servicecommon.restcdi.HelidonInterceptor;
3030

3131
import org.eclipse.microprofile.metrics.Metric;
32-
import org.eclipse.microprofile.metrics.MetricID;
3332
import org.eclipse.microprofile.metrics.MetricRegistry;
3433

3534
/**
@@ -53,8 +52,6 @@ abstract class InterceptorBase<M extends Metric> extends HelidonInterceptor.Base
5352
@Inject
5453
private MetricRegistry registry;
5554

56-
private Map<MetricID, Metric> metricsForVerification;
57-
5855
enum ActionType {
5956
PREINVOKE("preinvoke"), COMPLETE("complete");
6057

@@ -78,27 +75,22 @@ Class<? extends Annotation> annotationType() {
7875
return annotationType;
7976
}
8077

81-
Map<MetricID, Metric> metricsForVerification() {
82-
if (metricsForVerification == null) {
83-
metricsForVerification = registry.getMetrics();
84-
}
85-
return metricsForVerification;
86-
}
87-
8878
@Override
8979
public void preInvocation(InvocationContext context, MetricWorkItem workItem) {
9080
invokeVerifiedAction(context, workItem, this::preInvoke, ActionType.PREINVOKE);
9181
}
9282

9383
void invokeVerifiedAction(InvocationContext context, MetricWorkItem workItem, Consumer<M> action, ActionType actionType) {
94-
if (!metricsForVerification().containsKey(workItem.metricID())) {
84+
Metric metric = workItem.metric();
85+
if (Registry.isMarkedAsDeleted(metric)) {
9586
throw new IllegalStateException("Attempt to use previously-removed metric" + workItem.metricID());
9687
}
97-
Metric metric = workItem.metric();
98-
LOGGER.log(Level.FINEST, () -> String.format(
99-
"%s (%s) is accepting %s %s for processing on %s triggered by @%s",
100-
getClass().getSimpleName(), actionType, workItem.metric().getClass().getSimpleName(), workItem.metricID(),
101-
context.getMethod() != null ? context.getMethod() : context.getConstructor(), annotationType.getSimpleName()));
88+
if (LOGGER.isLoggable(Level.FINEST)) {
89+
LOGGER.log(Level.FINEST, String.format(
90+
"%s (%s) is accepting %s %s for processing on %s triggered by @%s",
91+
getClass().getSimpleName(), actionType, workItem.metric().getClass().getSimpleName(), workItem.metricID(),
92+
context.getMethod() != null ? context.getMethod() : context.getConstructor(), annotationType.getSimpleName()));
93+
}
10294
action.accept(metricType.cast(metric));
10395
}
10496

0 commit comments

Comments
 (0)