How to log your requests with Spring Boot Microservices - Part I

Spring Boot is a good framework to create a microservices architecture, but if you use this kind of architecture in your application you need to log very well your requests. Today I’ll show you how to properly log your requests

First of all you need to assign an unique id to your request. To do this we are going to create a filter that search for a header in our request to use it as id and if it doesn’t exist it will create it

import javax.servlet.*;
import javax.servlet.http.HttpServletRequest;
import java.io.IOException;
import java.util.UUID;

public class RequestFilter implements Filter {

    public static final String REQUEST_HEADER_NAME = "X-REQUEST-UUID";

    @Override
    public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException {

        HttpServletRequest httpServletRequest = (HttpServletRequest) request;
        String id = httpServletRequest.getHeader(REQUEST_HEADER_NAME);

        if (id == null || "".equals(id)) {
            peticion = UUID.randomUUID().toString();
        }

        RequestContext.getContext().setId(id);

        chain.doFilter(request, response);
    }

    @Override
    public void init(FilterConfig filterConfig) throws ServletException {
    }

    @Override
    public void destroy() {
    }
}

We need another class, RequestContext. This class will create a thread-local variable named id. We’ll use this variable to append it to our microservice log

public class RequestContext {

    private static final ThreadLocal<RequestContext> CONTEXT = new ThreadLocal<>();

    private String id;

    public static RequestContext getContext() {
        RequestContext result = CONTEXT.get();

        if (result == null) {
            result = new RequestContext();
            CONTEXT.set(result);
        }

        return result;
    }

    public String getId() {
        return id;
    }

    public void setId(String id) {
        this.id = id;
    }
}

Let’s configure Spring Boot to pass the id from one service to another

import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.context.embedded.FilterRegistrationBean;
import org.springframework.context.annotation.Bean;
import org.springframework.context.annotation.Configuration;
import org.springframework.http.client.ClientHttpRequestInterceptor;
import org.springframework.web.client.RestTemplate;

import javax.annotation.PostConstruct;
import java.util.List;

@Configuration
public class RequestLoggingAutoConfiguration {

    @Autowired
    private RestTemplate restTemplate;

    @Bean
    public FilterRegistrationBean getPeticionFilter() {

        FilterRegistrationBean registration = new FilterRegistrationBean();
        registration.setFilter(new RequestFilter());
        registration.addUrlPatterns("/*");
        registration.setName("requestFilter");

        return registration;
    }

    @PostConstruct
    public void addInterceptors() {
        List<ClientHttpRequestInterceptor> interceptors = restTemplate.getInterceptors();
        interceptors.add(new RequestInterceptor());
        restTemplate.setInterceptors(interceptors);
    }
}

Now in every request made to our service or from our service we’ll have an unique id to use it. We need to use it now to write in our logs the id and track our flow

We’ll create two classes to log our id automatically with logback. First a ClassicConverter

import ch.qos.logback.classic.pattern.ClassicConverter;
import ch.qos.logback.classic.spi.ILoggingEvent;

public class PeticionConverter extends ClassicConverter {

    @Override
    public String convert(ILoggingEvent event) {
        String id = RequestContext.getContext().getId();
        return id == null ? "---" : id;
    }
}

And then a PatternLayoutEncoder

import ch.qos.logback.classic.PatternLayout;
import ch.qos.logback.classic.encoder.PatternLayoutEncoder;

public class RequestPatternLayoutEncoder extends PatternLayoutEncoder {

    public static final String REQUEST_PATTERN = "reqId";

    public void start() {
        PatternLayout patternLayout = new PatternLayout();
        patternLayout.getDefaultConverterMap().put(REQUEST_PATTERN, RequestConverter.class.getName());
        patternLayout.setContext(context);
        patternLayout.setPattern(getPattern());
        patternLayout.setOutputPatternAsHeader(outputPatternAsHeader);
        patternLayout.start();
        this.layout = patternLayout;
        this.started = true;
    }
}

One more thing and we are done, a logback config file

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/base.xml"/>
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender"/>
        <encoder class="com.example.test.logback.RequestPatternLayoutEncoder">
            <charset>utf-8</charset>
            <Pattern>%d{HH:mm:ss.SSS} %reqId [%p] %c - %m%n</Pattern>
        </encoder>
    </appender>
</configuration>

Our logs will be like this

2016:08:29:18:27.543 59554cfb-bec9-4306-8be1-d3b3effafc6c DEBUG myclass.MyService - Hello World!

When we made a call to another service we will see the same id so we can track our requests

In the next post we’ll see how to log the HTTP information from our requests and response in our service and in the services that we are calling

How to log your requests with Spring Boot Microservices – Part I