Custom API Request & Response Logging in spring boot.
When we create RESTFul APIs in spring boot application in microservices environment. It becomes essential to log incoming API request and response and push it to centralized logging system such as Splunk or ELK for debugging. Also all the logs related to one request should have some common id to relate them. In this post we are going to solve these problems.
1. Create RESTFul API
Let’s create a RestController to expose RESTFul API
@RestController
@RequestMapping("/posts")
public class PostController {
@GetMapping
public List<Post> getAllPosts() {
return Arrays.asList(new Post[] {
new Post[] { new Post("spring", "Spring Boot", "All about Spring boot microservice"),
new Post("java", "Java", "Learn Streams in Java"),
new Post("javascript", "JavaScript", "Whats new in ES6")
});
}
}
2. Create API Logger
At this point we have exposed API but we haven’t logged it yet. Let’s create an API logger which is having following configurable properties:-
- app.api.logging.enable If true then api logger will be enabled and log all api request and response
- app.api.logging.url-patterns If provided in a comma separated url patterns, only those api request and response will be logged. default value is ’*’ means all api request and response will be printed
- app.api.logging.requestIdParamName If provided request parameter in incoming api request will be logged across all logs to serve that request. default value is requestId. If not provided, new request id (uuid) will be generated to log across all logs.
import org.springframework.beans.factory.annotation.Value;
import org.springframework.boot.autoconfigure.condition.ConditionalOnExpression;
import org.springframework.boot.web.servlet.FilterRegistrationBean;
import org.springframework.context.annotation.Bean;
import org.springframework.stereotype.Component;
@Component
@ConditionalOnExpression("${app.api.logging.enable:true}")
public class ApiLoggingFilterConfig {
@Value("${app.api.logging.url-patterns:*}")
private String[] urlPatterns;
@Value("${app.api.logging.requestIdParamName:requestId}")
private String requestIdParamName;
@Bean
public FilterRegistrationBean<ApiLoggingFilter> loggingFilter() {
FilterRegistrationBean<ApiLoggingFilter> registrationBean = new FilterRegistrationBean<>();
registrationBean.setFilter(new ApiLoggingFilter(requestIdParamName));
registrationBean.addUrlPatterns(urlPatterns);
return registrationBean;
}
}
Now we will create ApiLoggingFilter
which is nothing but a Servlet Filter. This filter intercepts all api request and response and log them. It also make use of slf4j MDC to print requestId across all the logs serve that request. ApiLoggingFilter
class is long. you can expand below to see code.
Click to expand ApiLoggingFilter
import java.io.BufferedReader;
import java.io.ByteArrayInputStream;
import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.io.InputStream;
import java.io.InputStreamReader;
import java.io.OutputStream;
import java.io.PrintWriter;
import java.util.Collection;
import java.util.Enumeration;
import java.util.HashMap;
import java.util.Locale;
import java.util.Map;
import java.util.UUID;
import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.ReadListener;
import javax.servlet.ServletException;
import javax.servlet.ServletInputStream;
import javax.servlet.ServletOutputStream;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.WriteListener;
import javax.servlet.http.Cookie;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletRequestWrapper;
import javax.servlet.http.HttpServletResponse;
import org.apache.commons.io.output.TeeOutputStream;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.slf4j.MDC;
public class ApiLoggingFilter implements Filter {
private static final Logger LOGGER = LoggerFactory.getLogger(ApiLoggingFilter.class);
private String requestIdParamName;
ApiLoggingFilter(String requestIdParamName) {
this.requestIdParamName = requestIdParamName;
}
@Override
public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain)
throws IOException, ServletException {
try {
HttpServletRequest httpServletRequest = (HttpServletRequest) request;
HttpServletResponse httpServletResponse = (HttpServletResponse) response;
Map<String, String> requestMap = this.getTypesafeRequestMap(httpServletRequest);
BufferedRequestWrapper bufferedRequest = new BufferedRequestWrapper(httpServletRequest);
BufferedResponseWrapper bufferedResponse = new BufferedResponseWrapper(httpServletResponse);
String requestId = requestMap.containsKey(requestIdParamName) ? requestMap.get(requestIdParamName)
: UUID.randomUUID().toString();
MDC.put("REQUEST_ID", requestId);
final StringBuilder logRequest = new StringBuilder("HTTP ").append(httpServletRequest.getMethod())
.append(" \"").append(httpServletRequest.getServletPath()).append("\" ").append(", parameters=")
.append(requestMap).append(", body=").append(bufferedRequest.getRequestBody())
.append(", remote_address=").append(httpServletRequest.getRemoteAddr());
LOGGER.info(logRequest.toString());
try {
chain.doFilter(bufferedRequest, bufferedResponse);
} finally {
final StringBuilder logResponse = new StringBuilder("HTTP RESPONSE ")
.append(bufferedResponse.getContent());
LOGGER.info(logResponse.toString());
MDC.clear();
}
} catch (Throwable a) {
LOGGER.error(a.getMessage());
}
}
private Map<String, String> getTypesafeRequestMap(HttpServletRequest request) {
Map<String, String> typesafeRequestMap = new HashMap<String, String>();
Enumeration<?> requestParamNames = request.getParameterNames();
while (requestParamNames.hasMoreElements()) {
String requestParamName = (String) requestParamNames.nextElement();
String requestParamValue;
if (requestParamName.equalsIgnoreCase("password")) {
requestParamValue = "********";
} else {
requestParamValue = request.getParameter(requestParamName);
}
typesafeRequestMap.put(requestParamName, requestParamValue);
}
return typesafeRequestMap;
}
private static final class BufferedRequestWrapper extends HttpServletRequestWrapper {
private ByteArrayInputStream bais = null;
private ByteArrayOutputStream baos = null;
private BufferedServletInputStream bsis = null;
private byte[] buffer = null;
public BufferedRequestWrapper(HttpServletRequest req) throws IOException {
super(req);
// Read InputStream and store its content in a buffer.
InputStream is = req.getInputStream();
this.baos = new ByteArrayOutputStream();
byte buf[] = new byte[1024];
int read;
while ((read = is.read(buf)) > 0) {
this.baos.write(buf, 0, read);
}
this.buffer = this.baos.toByteArray();
}
@Override
public ServletInputStream getInputStream() {
this.bais = new ByteArrayInputStream(this.buffer);
this.bsis = new BufferedServletInputStream(this.bais);
return this.bsis;
}
String getRequestBody() throws IOException {
BufferedReader reader = new BufferedReader(new InputStreamReader(this.getInputStream()));
String line = null;
StringBuilder inputBuffer = new StringBuilder();
do {
line = reader.readLine();
if (null != line) {
inputBuffer.append(line.trim());
}
} while (line != null);
reader.close();
return inputBuffer.toString().trim();
}
}
private static final class BufferedServletInputStream extends ServletInputStream {
private ByteArrayInputStream bais;
public BufferedServletInputStream(ByteArrayInputStream bais) {
this.bais = bais;
}
@Override
public int available() {
return this.bais.available();
}
@Override
public int read() {
return this.bais.read();
}
@Override
public int read(byte[] buf, int off, int len) {
return this.bais.read(buf, off, len);
}
@Override
public boolean isFinished() {
return false;
}
@Override
public boolean isReady() {
return true;
}
@Override
public void setReadListener(ReadListener readListener) {
}
}
public class TeeServletOutputStream extends ServletOutputStream {
private final TeeOutputStream targetStream;
public TeeServletOutputStream(OutputStream one, OutputStream two) {
targetStream = new TeeOutputStream(one, two);
}
@Override
public void write(int arg0) throws IOException {
this.targetStream.write(arg0);
}
public void flush() throws IOException {
super.flush();
this.targetStream.flush();
}
public void close() throws IOException {
super.close();
this.targetStream.close();
}
@Override
public boolean isReady() {
return false;
}
@Override
public void setWriteListener(WriteListener writeListener) {
}
}
public class BufferedResponseWrapper implements HttpServletResponse {
HttpServletResponse original;
TeeServletOutputStream tee;
ByteArrayOutputStream bos;
public BufferedResponseWrapper(HttpServletResponse response) {
original = response;
}
public String getContent() {
return bos.toString();
}
public PrintWriter getWriter() throws IOException {
return original.getWriter();
}
public ServletOutputStream getOutputStream() throws IOException {
if (tee == null) {
bos = new ByteArrayOutputStream();
tee = new TeeServletOutputStream(original.getOutputStream(), bos);
}
return tee;
}
@Override
public String getCharacterEncoding() {
return original.getCharacterEncoding();
}
@Override
public String getContentType() {
return original.getContentType();
}
@Override
public void setCharacterEncoding(String charset) {
original.setCharacterEncoding(charset);
}
@Override
public void setContentLength(int len) {
original.setContentLength(len);
}
@Override
public void setContentLengthLong(long l) {
original.setContentLengthLong(l);
}
@Override
public void setContentType(String type) {
original.setContentType(type);
}
@Override
public void setBufferSize(int size) {
original.setBufferSize(size);
}
@Override
public int getBufferSize() {
return original.getBufferSize();
}
@Override
public void flushBuffer() throws IOException {
tee.flush();
}
@Override
public void resetBuffer() {
original.resetBuffer();
}
@Override
public boolean isCommitted() {
return original.isCommitted();
}
@Override
public void reset() {
original.reset();
}
@Override
public void setLocale(Locale loc) {
original.setLocale(loc);
}
@Override
public Locale getLocale() {
return original.getLocale();
}
@Override
public void addCookie(Cookie cookie) {
original.addCookie(cookie);
}
@Override
public boolean containsHeader(String name) {
return original.containsHeader(name);
}
@Override
public String encodeURL(String url) {
return original.encodeURL(url);
}
@Override
public String encodeRedirectURL(String url) {
return original.encodeRedirectURL(url);
}
@SuppressWarnings("deprecation")
@Override
public String encodeUrl(String url) {
return original.encodeUrl(url);
}
@SuppressWarnings("deprecation")
@Override
public String encodeRedirectUrl(String url) {
return original.encodeRedirectUrl(url);
}
@Override
public void sendError(int sc, String msg) throws IOException {
original.sendError(sc, msg);
}
@Override
public void sendError(int sc) throws IOException {
original.sendError(sc);
}
@Override
public void sendRedirect(String location) throws IOException {
original.sendRedirect(location);
}
@Override
public void setDateHeader(String name, long date) {
original.setDateHeader(name, date);
}
@Override
public void addDateHeader(String name, long date) {
original.addDateHeader(name, date);
}
@Override
public void setHeader(String name, String value) {
original.setHeader(name, value);
}
@Override
public void addHeader(String name, String value) {
original.addHeader(name, value);
}
@Override
public void setIntHeader(String name, int value) {
original.setIntHeader(name, value);
}
@Override
public void addIntHeader(String name, int value) {
original.addIntHeader(name, value);
}
@Override
public void setStatus(int sc) {
original.setStatus(sc);
}
@SuppressWarnings("deprecation")
@Override
public void setStatus(int sc, String sm) {
original.setStatus(sc, sm);
}
@Override
public String getHeader(String arg0) {
return original.getHeader(arg0);
}
@Override
public Collection<String> getHeaderNames() {
return original.getHeaderNames();
}
@Override
public Collection<String> getHeaders(String arg0) {
return original.getHeaders(arg0);
}
@Override
public int getStatus() {
return original.getStatus();
}
}
}
3. application.yml
Let’s setup properties related to ApiLoggingFilterConfig
file in .properties or .yml file
- We have enabled api logger app.api.logging.enabled=true
- We have given comma separated url-patterns for which we want to print all api request and response app.api.logging.url-patterns=/posts/*,/users/*
- We have given requestIdParamName whose value will be printed in api request and response. If parameter is not there then uuid will be generated and printed.
- Last but not least, we have changed default logging pattern of spring boot to print REQUEST_ID
Default Spring Boot Logging Pattern is as follows:-"%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}"
app:
api:
logging:
enable: true
url-patterns: "/users/*,/posts/*"
requestIdParamName: reqId
logging:
level:
root: INFO
com.abc.demo: DEBUG
pattern:
console: "%clr(%d{yyyy-MM-dd HH:mm:ss.SSS}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%8.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %X{REQUEST_ID} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}"
4. Logs
That’s it. Let’s execute some RESTFul API and look at the logs:-
http://localhost:8080/posts?reqId=1234
2020-04-23 21:09:44.107 - INFO 3240 --- ApiLoggingFilter: 1234 HTTP GET "/posts" , parameters={requestId=1234}, body=, remote_address=0:0:0:0:0:0:0:1
2020-04-23 21:09:44.110 - INFO 3240 --- ApiLoggingFilter: 1234 HTTP RESPONSE [{"id":1,"title":"Spring Boot","body":"All about Spring boot microservice"},{"id":2,"title":"Java","body":"Learn Streams in Java"},{"id":3,"title":"JavaScript","body":"Whats new in ES6"}]
http://localhost:8080/posts
When reqId is not passed as parameter, default uuid will be printed across all logs
2020-04-23 21:09:44.107 - INFO 3240 --- ApiLoggingFilter: 754be6a6-b00a-4c98-b681-2d0041b4f72c HTTP GET "/posts" , parameters={requestId=1234}, body=, remote_address=0:0:0:0:0:0:0:1
2020-04-23 21:09:44.110 - INFO 3240 --- ApiLoggingFilter: 754be6a6-b00a-4c98-b681-2d0041b4f72c HTTP RESPONSE [{"id":1,"title":"Spring Boot","body":"All about Spring boot microservice"},{"id":2,"title":"Java","body":"Learn Streams in Java"},{"id":3,"title":"JavaScript","body":"Whats new in ES6"}]
5. Summary
We saw in this post that how we can create custom logger to print API request and response. Also incoming request can have requestId parameter which can be printed across all the logs which serves that request. This parameter can be further passed down in downstream microservices to further print it in the logs. This way a request can be tracked end to end from the logs.
Please find the complete source code of custom logging API on github springboot-microservice