Skip to content

Commit

Permalink
Mechanism to record timings for webmvc endpoints covered by @Exceptio…
Browse files Browse the repository at this point in the history 
…nHandler (fixes #56)
  • Loading branch information
@jkschneider
jkschneider committed Aug 3, 2017
1 parent 1604d05 commit c124bda
Show file tree
Hide file tree
Showing 6 changed files with 273 additions and 145 deletions.
2 changes: 1 addition & 1 deletion micrometer-spring-legacy/src/main/java/io/micrometer/spring/MetricsConfiguration.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -43,7 +43,7 @@ public TagFormatter tagFormatter() {

@Configuration
@ConditionalOnWebApplication
@Import(InstrumentServletRequestConfiguration.class)
@Import(MetricsServletRequestConfiguration.class)
static class WebMvcConfiguration {}

/**
Expand Down
41 changes: 20 additions & 21 deletions ...nstrumentServletRequestConfiguration.java → ...g/MetricsServletRequestConfiguration.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -15,15 +15,15 @@
*/
package io.micrometer.spring;

import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.spring.web.ControllerMetrics;
import io.micrometer.spring.web.MetricsHandlerInterceptor;
import io.micrometer.spring.web.WebmvcTagConfigurer;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.autoconfigure.condition.ConditionalOnMissingBean;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.core.env.Environment;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.TagFormatter;
import org.springframework.web.servlet.config.annotation.InterceptorRegistry;
import org.springframework.web.servlet.config.annotation.WebMvcConfigurerAdapter;

Expand All @@ -33,33 +33,32 @@
* @author Jon Schneider
*/
@Configuration
class InstrumentServletRequestConfiguration extends WebMvcConfigurerAdapter {
@Autowired
MeterRegistry registry;

@Autowired(required = false)
WebmvcTagConfigurer tagConfigurer;

class MetricsServletRequestConfiguration extends WebMvcConfigurerAdapter {
@Bean
@ConditionalOnMissingBean(WebmvcTagConfigurer.class)
WebmvcTagConfigurer webmvcTagConfigurer() {
if(tagConfigurer != null)
return tagConfigurer;
this.tagConfigurer = new WebmvcTagConfigurer();
return this.tagConfigurer;
return new WebmvcTagConfigurer();
}

@Autowired
Environment environment;

@Bean
MetricsHandlerInterceptor webMetricsInterceptor() {
return new MetricsHandlerInterceptor(registry, webmvcTagConfigurer(),
ControllerMetrics controllerMetrics(MeterRegistry registry, WebmvcTagConfigurer configurer, Environment environment) {
return new ControllerMetrics(registry, configurer,
environment.getProperty("spring.metrics.web.server_requests.name", "http_server_requests"));
}

@Override
public void addInterceptors(InterceptorRegistry registry) {
registry.addInterceptor(webMetricsInterceptor());
@Bean
MetricsHandlerInterceptor webMetricsInterceptor(ControllerMetrics controllerMetrics) {
return new MetricsHandlerInterceptor(controllerMetrics);
}

@Configuration
class MetricsServletRequestInterceptorConfiguration extends WebMvcConfigurerAdapter {
@Autowired
MetricsHandlerInterceptor handlerInterceptor;

@Override
public void addInterceptors(InterceptorRegistry registry) {
registry.addInterceptor(handlerInterceptor);
}
}
}
143 changes: 143 additions & 0 deletions micrometer-spring-legacy/src/main/java/io/micrometer/spring/web/ControllerMetrics.java
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,143 @@
/**
* Copyright 2017 Pivotal Software, Inc.
*
* 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.micrometer.spring.web;

import io.micrometer.core.annotation.Timed;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.Tag;
import io.micrometer.core.instrument.Timer;
import io.micrometer.core.instrument.stats.quantile.WindowSketchQuantiles;
import io.micrometer.core.instrument.util.AnnotationUtils;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.springframework.web.method.HandlerMethod;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.lang.reflect.Method;
import java.util.Collections;
import java.util.Map;
import java.util.Set;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.TimeUnit;
import java.util.stream.Collectors;
import java.util.stream.IntStream;

import static java.util.stream.Collectors.toSet;

/**
* @author Jon Schneider
*/
public class ControllerMetrics {
private static final String TIMING_REQUEST_ATTRIBUTE = "micrometer.requestStartTime";
private static final String HANDLER_REQUEST_ATTRIBUTE = "micrometer.handler";

private static final Log logger = LogFactory.getLog(ControllerMetrics.class);

private final MeterRegistry registry;
private final WebmvcTagConfigurer tagConfigurer;
private final String metricName;
private final Map<Timed, Long> longTaskTimerIds = new ConcurrentHashMap<>();

public ControllerMetrics(MeterRegistry registry,
WebmvcTagConfigurer tagConfigurer,
String metricName) {
this.registry = registry;
this.tagConfigurer = tagConfigurer;
this.metricName = metricName;
}

public void preHandle(HttpServletRequest request, HandlerMethod handler) {
request.setAttribute(TIMING_REQUEST_ATTRIBUTE, System.nanoTime());
request.setAttribute(HANDLER_REQUEST_ATTRIBUTE, handler);

longTaskTimed(handler).forEach(t -> {
if(t.value().isEmpty()) {
logger.warn("Unable to perform metrics timing on " + handler.getShortLogMessage() + ": @Timed annotation must have a value used to name the metric");
return;
}
longTaskTimerIds.put(t, registry.longTaskTimer(t.value(), tagConfigurer.httpLongRequestTags(request, handler)).start());
});
}

public void record(HttpServletRequest request, HttpServletResponse response, Throwable ex) {
Long startTime = (Long) request.getAttribute(TIMING_REQUEST_ATTRIBUTE);
Object handler = request.getAttribute(HANDLER_REQUEST_ATTRIBUTE);

long endTime = System.nanoTime();

// complete any LongTaskTimer tasks running for this method
longTaskTimed(handler).forEach(t -> {
if(!t.value().isEmpty()) {
registry.longTaskTimer(t.value(), tagConfigurer.httpLongRequestTags(request, handler)).stop(longTaskTimerIds.remove(t));
}
});

// record Timer values
timed(handler).forEach(t -> {
String name = metricName;
if (!t.value().isEmpty()) {
name = t.value();
}

Timer.Builder timerBuilder = registry.timerBuilder(name)
.tags(tagConfigurer.httpRequestTags(request, response, ex));

String[] extraTags = t.extraTags();
if (extraTags.length > 0) {
if (extraTags.length % 2 != 0) {
if (logger.isErrorEnabled()) {
Method method = ((HandlerMethod) handler).getMethod();
String target = method.getDeclaringClass().getName() + "." + method.getName();
logger.error("@Timed extraTags array on method " + target + " size must be even, it is a set of key=value pairs");
}
} else {
timerBuilder = timerBuilder.tags(IntStream.range(0, extraTags.length / 2)
.mapToObj(i -> Tag.of(extraTags[i], extraTags[i + 1]))
.collect(Collectors.toList()));
}
}

if(t.quantiles().length > 0) {
timerBuilder = timerBuilder.quantiles(WindowSketchQuantiles.quantiles(t.quantiles()).create());
}

timerBuilder.create().record(endTime - startTime, TimeUnit.NANOSECONDS);
});
}

private Set<Timed> longTaskTimed(Object m) {
if(!(m instanceof HandlerMethod))
return Collections.emptySet();

Set<Timed> timed = AnnotationUtils.findTimed(((HandlerMethod) m).getMethod()).filter(Timed::longTask).collect(toSet());
if (timed.isEmpty()) {
return AnnotationUtils.findTimed(((HandlerMethod) m).getBeanType()).filter(Timed::longTask).collect(toSet());
}
return timed;
}

private Set<Timed> timed(Object m) {
if(!(m instanceof HandlerMethod))
return Collections.emptySet();

Set<Timed> timed = AnnotationUtils.findTimed(((HandlerMethod) m).getMethod()).filter(t -> !t.longTask()).collect(toSet());
if (timed.isEmpty()) {
return AnnotationUtils.findTimed(((HandlerMethod) m).getBeanType()).filter(t -> !t.longTask()).collect(toSet());
}
return timed;
}
}
124 changes: 5 additions & 119 deletions ...meter-spring-legacy/src/main/java/io/micrometer/spring/web/MetricsHandlerInterceptor.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -15,149 +15,35 @@
*/
package io.micrometer.spring.web;

import io.micrometer.core.annotation.Timed;
import io.micrometer.core.instrument.MeterRegistry;
import io.micrometer.core.instrument.Tag;
import io.micrometer.core.instrument.Timer;
import io.micrometer.core.instrument.util.AnnotationUtils;
import io.micrometer.core.instrument.stats.quantile.WindowSketchQuantiles;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.method.HandlerMethod;
import org.springframework.web.servlet.handler.HandlerInterceptorAdapter;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import java.lang.reflect.Method;
import java.util.Collections;
import java.util.Map;
import java.util.Set;
import java.util.concurrent.ConcurrentHashMap;
import java.util.concurrent.TimeUnit;
import java.util.stream.Collectors;
import java.util.stream.IntStream;

import static java.util.stream.Collectors.toSet;
import static org.springframework.web.context.request.RequestAttributes.SCOPE_REQUEST;

/**
* Intercepts incoming HTTP requests and records metrics about execution time and results.
*
* @author Jon Schneider
*/
public class MetricsHandlerInterceptor extends HandlerInterceptorAdapter {
private final ControllerMetrics controllerMetrics;

private static final Log logger = LogFactory.getLog(MetricsHandlerInterceptor.class);
private static final String TIMING_REQUEST_ATTRIBUTE = "requestStartTime";

private final MeterRegistry registry;
private final WebmvcTagConfigurer tagConfigurer;
private final String metricName;

private final Map<Timed, Long> longTaskTimerIds = new ConcurrentHashMap<>();

public MetricsHandlerInterceptor(MeterRegistry registry,
WebmvcTagConfigurer tagConfigurer,
String metricName) {
this.registry = registry;
this.tagConfigurer = tagConfigurer;
this.metricName = metricName;
public MetricsHandlerInterceptor(ControllerMetrics controllerMetrics) {
this.controllerMetrics = controllerMetrics;
}

@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response,
Object handler) throws Exception {
longTaskTimed(handler).forEach(t -> {
if(t.value().isEmpty()) {
logger.warn("Unable to perform metrics timing on " + ((HandlerMethod) handler).getShortLogMessage() + ": @Timed annotation must have a value used to name the metric");
return;
}
longTaskTimerIds.put(t, registry.longTaskTimer(t.value(), tagConfigurer.httpLongRequestTags(request, handler)).start());
});

RequestContextHolder.getRequestAttributes().setAttribute(TIMING_REQUEST_ATTRIBUTE,
System.nanoTime(), SCOPE_REQUEST);
controllerMetrics.preHandle(request, (HandlerMethod) handler);
return super.preHandle(request, response, handler);
}

@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response,
Object handler, Exception ex) throws Exception {
RequestContextHolder.getRequestAttributes().setAttribute("exception", ex,
SCOPE_REQUEST);

Long startTime = (Long) RequestContextHolder.getRequestAttributes().getAttribute(
TIMING_REQUEST_ATTRIBUTE, SCOPE_REQUEST);
if (startTime != null)
recordMetric(request, response, handler, startTime);

controllerMetrics.record(request, response, ex);
super.afterCompletion(request, response, handler, ex);
}

private void recordMetric(HttpServletRequest request, HttpServletResponse response,
Object handler, Long startTime) {
long endTime = System.nanoTime();

// complete any LongTaskTimer tasks running for this method
longTaskTimed(handler).forEach(t -> {
if(!t.value().isEmpty()) {
registry.longTaskTimer(t.value(), tagConfigurer.httpLongRequestTags(request, handler)).stop(longTaskTimerIds.remove(t));
}
});

// record Timer values
timed(handler).forEach(t -> {
String name = metricName;
if (!t.value().isEmpty()) {
name = t.value();
}

Timer.Builder timerBuilder = registry.timerBuilder(name)
.tags(tagConfigurer.httpRequestTags(request, response));

String[] extraTags = t.extraTags();
if (extraTags.length > 0) {
if (extraTags.length % 2 != 0) {
if (logger.isErrorEnabled()) {
Method method = ((HandlerMethod) handler).getMethod();
String target = method.getDeclaringClass().getName() + "." + method.getName();
logger.error("@Timed extraTags array on method " + target + " size must be even, it is a set of key=value pairs");
}
} else {
timerBuilder = timerBuilder.tags(IntStream.range(0, extraTags.length / 2)
.mapToObj(i -> Tag.of(extraTags[i], extraTags[i + 1]))
.collect(Collectors.toList()));
}
}

if(t.quantiles().length > 0) {
timerBuilder = timerBuilder.quantiles(WindowSketchQuantiles.quantiles(t.quantiles()).create());
}

timerBuilder.create().record(endTime - startTime, TimeUnit.NANOSECONDS);
});
}

private Set<Timed> longTaskTimed(Object m) {
if(!(m instanceof HandlerMethod))
return Collections.emptySet();

Set<Timed> timed = AnnotationUtils.findTimed(((HandlerMethod) m).getMethod()).filter(Timed::longTask).collect(toSet());
if (timed.isEmpty()) {
return AnnotationUtils.findTimed(((HandlerMethod) m).getBeanType()).filter(Timed::longTask).collect(toSet());
}
return timed;
}

private Set<Timed> timed(Object m) {
if(!(m instanceof HandlerMethod))
return Collections.emptySet();

Set<Timed> timed = AnnotationUtils.findTimed(((HandlerMethod) m).getMethod()).filter(t -> !t.longTask()).collect(toSet());
if (timed.isEmpty()) {
return AnnotationUtils.findTimed(((HandlerMethod) m).getBeanType()).filter(t -> !t.longTask()).collect(toSet());
}
return timed;
}
}
Loading

0 comments on commit c124bda

Please sign in to comment.