This is my 19th day of the August Genwen Challenge

This series code address: github.com/HashZhang/s…

We use SPI mechanism of Spring Boot to customize Undertow, mainly in the following two aspects:

  1. Response time statistics need to be turned on in accessLog.
  2. Each Http request is expected to be monitored by JFR without taking up too much space.

Let’s implement these two requirements in turn:

First, our framework should be developed according to the standard of the base component, using the Spring. factories spring Boot SPI mechanism introduced earlier in this series that automatically loads the configuration when we introduce the base component dependencies.

Then, whether or not to turn on response time statistics should depend on the accesslog format configured by the user (Undertow’s Accesslog configuration can be referenced in previous articles in this series).

That’s where we write the code. At present more unfortunately, Spring Boot docking Undertow did not directly configuration allows Undertow open the response time statistics, but it can through the way of realizing WebServerFactoryCustomizer interface, Customize the WebServerFactory that builds the WebServer. The underlying implementation principle is very simple (the following reference source: WebServerFactoryCustomizerBeanPostProcessor. Java) :

  • Specified in Spring BootWebServerFactoryCustomizerBeanPostProcessorthisBeanPostProcessor.
  • WebServerFactoryCustomizerBeanPostProcessor 的 postProcessBeforeInitializationMethod (that is, the method that will be called before all beans are initialized) if the Bean type isWebServerFactoryPass it as a parameter to the registered ownerWebServerFactoryCustomizerBean for customization.

Next, we implemented a custom WebServerFactoryCustomizer

DefaultWebServerFactoryCustomizer

package com.github.hashjang.spring.cloud.iiford.spring.cloud.webmvc.undertow; import io.undertow.UndertowOptions; import org.apache.commons.lang.StringUtils; import org.springframework.boot.autoconfigure.web.ServerProperties; import org.springframework.boot.web.embedded.undertow.ConfigurableUndertowWebServerFactory; import org.springframework.boot.web.server.WebServerFactoryCustomizer; public class DefaultWebServerFactoryCustomizer implements WebServerFactoryCustomizer<ConfigurableUndertowWebServerFactory> { private final ServerProperties serverProperties; public DefaultWebServerFactoryCustomizer(ServerProperties serverProperties) { this.serverProperties = serverProperties; } @Override public void customize(ConfigurableUndertowWebServerFactory factory) { String pattern = serverProperties.getUndertow() .getAccesslog().getPattern(); If the response time is printed in the accesslog configuration, Open a record request start time configure if (logRequestProcessingTiming (pattern)) {factory. AddBuilderCustomizers (builder - > builder.setServerOption( UndertowOptions.RECORD_REQUEST_START_TIME, true ) ); }} private Boolean logRequestProcessingTiming (String pattern) {/ / if there is no configuration accesslog, If (stringutils. isBlank(pattern)) {return false; } / / only % % D and T the two placeholders and response time, through the judgment / / other placeholder information, please refer to the series of articles before the return pattern. The contains (" % D ") | | the pattern, the contains (" % T "); }}Copy the code

Then we use the spring.factories SPI mechanism to register this class as a singleton Bean into our ApplicationContext, as shown in the following figure:

The reason for the extra layer of AutoConfiguration between Configuration and Spring.Factories is:

  1. Isolate SPI from Configuration and manage related Configuration in the same AutoConfiguration.
  2. @AutoConfigurationBeforeComments like this are valid only on the AutoConfiguration class loaded directly by SPI, and the isolation layer is for this purpose.

In previous articles in the series, we mentioned that we introduced a dependency on Prometheus. After this dependency is introduced, the response time, response code and exception will be counted at the end of each HTTP request when the response is returned, which is similar to:

http_server_requests_seconds_count{exception="None",method="POST",outcome="SUCCESS",status="200",uri="/query/orders",} 120796.0 http_server_requests_seconds_sum{exception="None",method="POST",outcome="SUCCESS",status="200",uri="/query/orders",} 33588.274025738 http_server_requests_seconds_max{exception="None",method="POST",outcome="SUCCESS",status="200",uri="/query/orders",} 0.1671125 http_server_requests_seconds_count{exception="MissingRequestHeaderException",method="POST",outcome="CLIENT_ERROR",status = "400", uri = "/ query/orders", 6.0} http_server_requests_seconds_sum{exception="MissingRequestHeaderException",method="POST",outcome="CLIENT_ERROR",status=" 400 ", uri = "/ query/orders", 0.947300794} http_server_requests_seconds_max{exception="MissingRequestHeaderException",method="POST",outcome="CLIENT_ERROR",status=" 400 ", uri = "/ query/orders", 0.003059704}Copy the code

As can be seen, the number of calls with exception, method, outcome, status and URI as keys, total time and maximum time are recorded from the beginning of the program to the present.

At the same time, also can match @ IO. Micrometer. Core. The annotation. The Timer annotations, custom monitoring and increases the Histogram, such as:

Effect / / @ Timer annotations to need to register an IO. Micrometer. Core. Aop. TimedAspect Bean and enable plane @ Bean public TimedAspect TimedAspect (MeterRegistry registry) { return new TimedAspect(registry); } @Timed(histogram=true) @RequestMapping("/query/orders") public xxxx xxxx() { ..... }Copy the code

This gives you additional statistics similar to bucket in addition to the above data:

http_server_requests_seconds_bucket{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/facts-center/quer Y/frontend/market - info, "le =" 0.001 ", 0.0} http_server_requests_seconds_bucket{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/facts-center/quer Y/frontend/market - info, "le =" 0.001048576 ", 0.0} http_server_requests_seconds_bucket{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/facts-center/quer Y/frontend/market - info, "le =" 0.001398101 ", 0.0} http_server_requests_seconds_bucket{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/facts-center/quer Y /frontend/market-info",le="0.001747626",} 0.0 // omit the middle time level http_server_requests_seconds_bucket{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/facts-center/quer Y/frontend/market - info, "le =" 30.0 ", 1.0} http_server_requests_seconds_bucket{exception="None",method="GET",outcome="SUCCESS",status="200",uri="/facts-center/quer Y/frontend/market - info, "le =" + Inf ", 1.0}Copy the code

The above statistics bring us the following inconvenience in analyzing the problem:

  1. Too much collection and analysis pressure: Grafana was used to collect indicator data reported by Prometheus, and the timing database of Grafana would store all the collected data. One path, one result, one exception, one method has a specific indicator. If there is an interface that takes the parameter as the path parameter, then this indicator is much more, such as putting userId into the path. We only focus on requests at the time of the problem, but we can’t predict when the problem will occur, so we can’t extract on demand, we have to collect and save all the time, which leads to too much stress.
  2. The index is not sensitive to pressure, so it cannot be used accurately to alarm: because the index is not cleared after collection, but has been collected from the beginning of the program. Therefore, as the program runs, the fluctuation of the performance of these indicators to the instantaneous pressure becomes smaller and smaller.

There is no elegant way to disable HTTP request response collection. The only way to disable it is through automatic scanning annotations, such as:

@springBootApplication (scanBasePackages = {"com.test"}); We can't use, exclude = WebMvcMetricsAutoConfiguration. Class)Copy the code

  • First of all, JFR collection is in-process, and the JVM has done a lot of optimization, so the performance cost is very small, and you can specify how many days or how many JFR records you want to keep (in a local temporary directory), which you can take at will.
  • In addition, we can put the information we are interested in into JFR events for flexible customization.
  • For a request that takes too long and does not respond, we can divide it into two JFR events: received request and request response.

Let’s define the two JFR events, one for receiving the request and the other for requesting the response:

HttpRequestReceivedJFREvent.java

package com.github.hashjang.spring.cloud.iiford.spring.cloud.webmvc.undertow.jfr; import jdk.jfr.Category; import jdk.jfr.Event; import jdk.jfr.Label; import jdk.jfr.StackTrace; import javax.servlet.ServletRequest; @Category({"Http Request"}) @Label("Http Request Received") @StackTrace(false) public class HttpRequestReceivedJFREvent Extends Event {// Request traceId from sleuth Private Final String traceId; // Request spanId from SLEuth Private Final String spanId; public HttpRequestReceivedJFREvent(ServletRequest servletRequest, String traceId, String spanId) { this.traceId = traceId; this.spanId = spanId; }}Copy the code

HttpRequestJFREvent.java

package com.github.hashjang.spring.cloud.iiford.spring.cloud.webmvc.undertow.jfr; import io.undertow.servlet.spec.HttpServletRequestImpl; import io.undertow.servlet.spec.HttpServletResponseImpl; import jdk.jfr.Category; import jdk.jfr.Event; import jdk.jfr.Label; import jdk.jfr.StackTrace; import javax.servlet.ServletRequest; import javax.servlet.ServletResponse; import java.util.Enumeration; @Category({"Http Request"}) @Label("Http Request") @StackTrace(false) public class HttpRequestJFREvent extends Event { Private final String method; Private final String path; Private final String query; // The requested traceId comes from sleuth private String traceId; // Request spanId, from sleuth private String spanId; Private String exception; Private int responseStatus; public HttpRequestJFREvent(ServletRequest servletRequest, String traceId, String spanId) { HttpServletRequestImpl httpServletRequest = (HttpServletRequestImpl) servletRequest; this.method = httpServletRequest.getMethod(); this.path = httpServletRequest.getRequestURI(); this.query = httpServletRequest.getQueryParameters().toString(); Enumeration<String> headerNames = httpServletRequest.getHeaderNames(); StringBuilder stringBuilder = new StringBuilder(); headerNames.asIterator().forEachRemaining(s -> stringBuilder.append(s).append(":").append(httpServletRequest.getHeader(s)).append("\n")); this.traceId = traceId; this.spanId = spanId; } public void setResponseStatus(ServletResponse servletResponse, Throwable throwable) { this.responseStatus = ((HttpServletResponseImpl) servletResponse).getStatus(); this.exception = throwable ! = null ? throwable.toString() : null; }}Copy the code

Then, we modeled on the front of closed WebMvcMetricsAutoConfiguration WebMvcMetricsFilter write our own Filter and modeled after registration, here we only show the core code:

JFRTracingFilter.java

@Override public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain filterChain) throws IOException, ServletException { HttpRequestJFREvent httpRequestJFREvent = null; Try {// Get traceId and spanId TraceContext context from sleuth = tracer.currentSPAN ().context(); String traceId = context.traceId(); String spanId = context.spanId(); / / received HttpRequestReceivedJFREvent request is created and submitted directly HttpRequestReceivedJFREvent HttpRequestReceivedJFREvent = new HttpRequestReceivedJFREvent(servletRequest, traceId, spanId); httpRequestReceivedJFREvent.commit(); httpRequestJFREvent = new HttpRequestJFREvent(servletRequest, traceId, spanId); httpRequestJFREvent.begin(); } catch (Exception e) { log.error("JFRTracingFilter-doFilter failed: {}", e.getMessage(), e); } Throwable throwable = null; try { filterChain.doFilter(servletRequest, servletResponse); } catch (IOException | ServletException t) { throwable = t; throw t; } finally {try {// httpRequestJFREvent if (httpRequestJFREvent! = null) { httpRequestJFREvent.setResponseStatus(servletResponse, throwable); httpRequestJFREvent.commit(); } } catch (Exception e) { log.error("JFRTracingFilter-doFilter final failed: {}", e.getMessage(), e); }}}Copy the code

We made two customizations for Undertow in this section: the need to turn on response time statistics in the AccessLog and monitor each Http request via JFR without taking up too much space. In the next section, we will begin to introduce the use and detailed configuration of our microservices registry, Eureka.

Wechat search “my programming meow” public account, a daily brush, easy to improve skills, won a variety of offers: