[JAVA] Output request and response log in Spring Boot

I wrote a filter that outputs request and response logs in Spring Boot, so I will share it.

[Original] 1

Difference from the original

╩╗AbstractRequestLoggingFilterandCommonsRequestLoggingFilter` are referenced.

I want you to pick up and filter log files with Zabbix

import java.io.IOException;
import java.util.ArrayList;
import java.util.Arrays;
import java.util.Collection;
import java.util.Collections;
import java.util.LinkedHashMap;
import java.util.List;
import java.util.Map;

import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import javax.servlet.http.Part;

import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.http.HttpStatus;
import org.springframework.http.MediaType;
import org.springframework.security.core.context.SecurityContext;
import org.springframework.security.core.context.SecurityContextHolder;
import org.springframework.util.FileCopyUtils;
import org.springframework.util.StringUtils;
import org.springframework.web.filter.OncePerRequestFilter;
import org.springframework.web.util.ContentCachingRequestWrapper;
import org.springframework.web.util.ContentCachingResponseWrapper;

import com.fasterxml.jackson.core.JsonProcessingException;
import com.fasterxml.jackson.databind.JsonNode;
import com.fasterxml.jackson.databind.ObjectMapper;
import com.fasterxml.jackson.databind.node.NullNode;

public class RequestResponseLoggingFilter extends OncePerRequestFilter {
    private static final List<MediaType> VISIBLE_TYPES = Arrays.asList(
                    MediaType.valueOf("text/*"),
                    MediaType.APPLICATION_FORM_URLENCODED,
                    MediaType.APPLICATION_JSON,
                    MediaType.APPLICATION_XML,
                    MediaType.valueOf("application/*+json"),
                    MediaType.valueOf("application/*+xml"),
                    MediaType.MULTIPART_FORM_DATA
                );
    private static final List<MediaType> FORM_TYPES = Arrays.asList(
                    MediaType.APPLICATION_FORM_URLENCODED,
                    MediaType.MULTIPART_FORM_DATA
                    );
    private final ThreadLocal<Map<String, Object>> localParams = ThreadLocal.withInitial(() -> new LinkedHashMap<>());

    @Autowired
    private ObjectMapper mapper;

    @Override
    protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
                    throws ServletException, IOException {
        if (isAsyncDispatch(request)) {
            filterChain.doFilter(request, response);
        } else {
            doFilterWrapped(wrapRequest(request), wrapResponse(response), filterChain);
        }
    }

    protected void doFilterWrapped(ContentCachingRequestWrapper request, ContentCachingResponseWrapper response, FilterChain filterChain) throws ServletException, IOException {
        try {
            beforeRequest(request, response);
            filterChain.doFilter(request, response);
        }
        finally {
            afterRequest(request, response);
            outputParams();
            localParams.remove();
            response.copyBodyToResponse();
        }
    }

    protected void beforeRequest(ContentCachingRequestWrapper request, ContentCachingResponseWrapper response) {
        if (logger.isDebugEnabled()) {
            throwable("logRequestHeader", () -> logRequestHeader(request));
        }
    }

    protected void afterRequest(ContentCachingRequestWrapper request, ContentCachingResponseWrapper response) {
        if (logger.isDebugEnabled()) {
            throwable("logRequestBody", () -> logRequestBody(request));
            throwable("logResponse", () -> logResponse(response));
        }
    }

    private void logRequestHeader(ContentCachingRequestWrapper request) {
        localParams.get().put("client", request.getRemoteAddr());
        String queryString = request.getQueryString();
        if (queryString == null) {
            localParams.get().put("request", request.getMethod() + " " + request.getRequestURI());
        }
        else {
            localParams.get().put("request", request.getMethod() + " " + request.getRequestURI() + "?" + queryString);
        }
        Map<String, List<String>> headers = new LinkedHashMap<>();
        Collections.list(request.getHeaderNames()).forEach(headerName ->
            Collections.list(request.getHeaders(headerName)).forEach(headerValue -> {
                if (headers.containsKey(headerName)) {
                    headers.get(headerName).add(headerValue);
                }
                else {
                    headers.put(headerName, new ArrayList<>());
                    headers.get(headerName).add(headerValue);
                }
            }));
        localParams.get().put("requestHeaders", headers);
        SecurityContext ctx = SecurityContextHolder.getContext();
        if (null != ctx) {
            localParams.get().put("authentication", convertTo(ctx.getAuthentication()));
        }
     }

    private void logRequestBody(ContentCachingRequestWrapper request) throws ServletException, IOException {
        Collection<Part> parts = getRequestParts(request);
        if (parts.isEmpty()) {
            byte[] content = request.getContentAsByteArray();
            if (content.length > 0) {
                logContent(content, request.getContentType(), request.getCharacterEncoding(), "requestBody");
            }
            else {
                localParams.get().put("requestBody", "[empty body]");
            }
        }
        else {
            Map<String, Object> contents = new LinkedHashMap<>();
            parts.stream().forEach(p -> {
                String name = p.getName();
                try {
                    byte[] content = FileCopyUtils.copyToByteArray(p.getInputStream());
                    contents.put(name, logContent(content, p.getContentType(), "UTF-8"));
                }
                catch (IOException e) {
                    String fileName = p.getSubmittedFileName();
                    if (StringUtils.hasText(fileName)) {
                        contents.put(name, String.format("fileName[%s]", fileName));
                    }
                    else {
                        contents.put(name, String.format("IOException[%s]", e.getMessage()));
                    }
                }
            });
            localParams.get().put("requestBody", contents);
        }
    }

    private Collection<Part> getRequestParts(ContentCachingRequestWrapper request) throws ServletException, IOException {
        MediaType mediaType = getMediaType(request.getContentType());
        boolean isPost = FORM_TYPES.stream().anyMatch(formType -> formType.includes(mediaType));
        return isPost ? request.getParts() : Collections.emptyList();
    }

    private void logResponse(ContentCachingResponseWrapper response) {
        int status = response.getStatus();
        localParams.get().put("response", status + " " + HttpStatus.valueOf(status).getReasonPhrase());
        Map<String, List<String>> headers = new LinkedHashMap<>();
        response.getHeaderNames().forEach(headerName ->
            response.getHeaders(headerName).forEach(headerValue -> {
                if (headers.containsKey(headerName)) {
                    headers.get(headerName).add(headerValue);
                }
                else {
                    headers.put(headerName, new ArrayList<>());
                    headers.get(headerName).add(headerValue);
                }
            }));
        localParams.get().put("responseHeaders", headers);
        byte[] content = response.getContentAsByteArray();
        if (content.length > 0) {
            logContent(content, response.getContentType(), response.getCharacterEncoding(), "responseBody");
        }
    }

    private void logContent(byte[] content, String contentType, String contentEncoding, String key) {
        localParams.get().put(key, logContent(content, contentType, contentEncoding));
    }

    private Object logContent(byte[] content, String contentType, String contentEncoding) {
        MediaType mediaType = getMediaType(contentType);
        boolean visible = VISIBLE_TYPES.stream().anyMatch(visibleType -> visibleType.includes(mediaType));
        boolean json = mediaType.getSubtype().contains("json");
        if (visible) {
            try {
                String contentString = new String(content, contentEncoding);
                if (json) {
                    return mapper.readTree(contentString);
                }
                else {
                    return contentString;
                }
            }
            catch (IOException e) {
                return String.format("[%d bytes content]", content.length);
            }
        }
        else {
            return String.format("[%d bytes content]", content.length);
        }
    }

    private MediaType getMediaType(String contentType) {
        try {
            return MediaType.valueOf(contentType);
        }
        catch (IllegalArgumentException e) {
            return null;
        }
    }

    private void outputParams() {
        logger.debug(unparse(mapper, localParams.get()));
    }

    private JsonNode convertTo(Object obj) {
        NullNode node = mapper.getDeserializationConfig().getNodeFactory().nullNode();
        if (null == obj) {
            return node;
        }
        try {
            return mapper.readTree(mapper.writeValueAsString(obj));
        }
        catch (IOException e) {
            return node;
        }
    }

    private void throwable(String key, ThrowableExecutor method) {
        try {
            method.apply();
        }
        catch (Exception e) {
            localParams.get().put(key, String.format("%s[%s]", e.getClass().getSimpleName(), e.getMessage()));
        }
    }

    public static String unparse(ObjectMapper mapper, Object obj) {
        if (null == obj) {
            return "null";
        }
        if (null == mapper) {
            return String.valueOf(obj);
        }
        try {
            return mapper.writeValueAsString(obj);
        } catch (JsonProcessingException e) {
            return e.getMessage();
        }
    }

    private static ContentCachingRequestWrapper wrapRequest(HttpServletRequest request) {
        if (request instanceof ContentCachingRequestWrapper) {
            return (ContentCachingRequestWrapper) request;
        } else {
            return new ContentCachingRequestWrapper(request);
        }
    }

    private static ContentCachingResponseWrapper wrapResponse(HttpServletResponse response) {
        if (response instanceof ContentCachingResponseWrapper) {
            return (ContentCachingResponseWrapper) response;
        } else {
            return new ContentCachingResponseWrapper(response);
        }
    }

    public static interface ThrowableExecutor {
        void apply() throws Exception;
    }
}

logback-spring.xml

logback-spring.xml


<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <include resource="org/springframework/boot/logging/logback/base.xml" />

    <appender name="REQUEST_LOGGING_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_PATH}/requestLogging.log</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_PATH}/requestLogging.log.%d{yyyyMMdd}.gz</fileNamePattern>
            <maxHistory>30</maxHistory>
        </rollingPolicy>
        <encoder>
            <charset>UTF-8</charset>
            <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%t]%X{request_thread} %logger{45}:%L - %msg %n</pattern>
        </encoder>
    </appender>

    <logger name="RequestResponseLoggingFilter" level="DEBUG">
        <appender-ref ref="REQUEST_LOGGING_FILE"/>
    </logger>
</configuration>

spring-boot: run settings

pom.xml


<plugin>
    <groupId>org.springframework.boot</groupId>
    <artifactId>spring-boot-maven-plugin</artifactId>
    <configuration>
        <executable>true</executable>
        <mainClass>Application</mainClass>
        <jvmArguments>
            -Dlogging.config=file:${project.build.outputDirectory}/logback-spring.xml
            -Dlogging.path=${project.build.directory}/log
        </jvmArguments>
        <includeSystemScope>true</includeSystemScope>
    </configuration>
</plugin>

Since the format is JSON, it can be formatted with jq

% tail -n 20 requestLogging.log|grep '/v1/info'|tail -n 1 |cut -d" " -f 7- |jq .

{
  "client": "0:0:0:0:0:0:0:1",
  "request": "GET /v1/info",
  "requestHeaders": {
    "host": [
      "localhost:8080"
    ],
    "user-agent": [
      "curl/7.54.0"
    ],
    "accept": [
      "*/*"
    ]
  },
  "authentication": {
    "authorities": [
      {
        "authority": "ROLE_ANONYMOUS"
      }
    ],
    "details": {
      "remoteAddress": "0:0:0:0:0:0:0:1",
      "sessionId": null
    },
    "authenticated": true,
    "principal": "anonymousUser",
    "keyHash": -184817062,
    "credentials": "",
    "name": "anonymousUser"
  },
  "requestBody": "[empty body]",
  "response": "200 OK",
  "responseHeaders": {
    "X-Content-Type-Options": [
      "nosniff"
    ],
    "X-XSS-Protection": [
      "1; mode=block"
    ],
    "Cache-Control": [
      "no-cache, no-store, max-age=0, must-revalidate"
    ],
    "Pragma": [
      "no-cache"
    ],
    "Expires": [
      "0"
    ],
    "X-Frame-Options": [
      "DENY"
    ]
  },
  "responseBody": "git info\n commit\n   branch: setup-logger\n   id: <commit>\n   time: 2018-04-05T21:27:51+09:00\n build\n   host: Macmini.local\n   time: 2018-04-05T23:29:45+09:00\n"
}

[Performance !?] 1

Applying this filter temporarily holds the response body in memory, which consumes more memory. Also, if it returns a large response, performance will suffer. Therefore, it is better to limit it to debugging purposes.

The current state of the backend Rest API is log >>> (insurmountable wall) >>> memory and performance

Recommended Posts

Output request and response log in Spring Boot
Output Spring Boot log in json format
Log output of WebServiceTemplate request / response
Spring Boot Whitelabel Error Page and JSON Response
Request parameter log output sample Java & Spring MVC
Set context-param in Spring Boot
Spring Boot 2 multi-project in Gradle
Log out RestTemplate request / response
Major changes in Spring Boot 1.5
NoHttpResponseException in Spring Boot + WireMock
Output embedded Tomcat access log to standard output with Spring Boot
How to call and use API in Java (Spring Boot)
Get error information using DefaultErrorAttributes and ErrorAttributeOptions in Spring Boot 2.3
Response header may not be output correctly in Spring Security 4.1
Spring Boot Hello World in Eclipse
Spring Boot application development in Eclipse
Write test code in Spring Boot
Log output to file in Java
Implement REST API in Spring Boot
Spring profile function, and Spring Boot application.properties
What is @Autowired in Spring boot?
Implement Spring Boot application in Gradle
Spring Data JPA SQL log output
Thymeleaf usage notes in Spring Boot
Easily develop web applications with STS and Spring Boot. In 10 minutes.
Change Spring Boot REST API request / response from CamelCase to SankeCase
Uploading and downloading files using Ajax in Spring Boot (without JQuery)
Compare Hello, world! In Spring Boot with Java, Kotlin and Groovy
Enable log output to both file and console using log4j in Eclipse.
Create a Spring Boot project in intellij and exit immediately after launching
Output system log by Spring AOP technology
Launch (old) Spring Boot project in IntelliJ
Convert request parameter to Enum in Spring
Build Spring Boot + Docker image in Gradle
Static file access priority in Spring boot
Local file download memorandum in Spring Boot
HTTPS with Spring Boot and Let's Encrypt
Create Java Spring Boot project in IntelliJ
Loosen Thymeleaf syntax checking in Spring Boot
[Practice! ] Display Hello World in Spring Boot
Use DynamoDB query method in Spring Boot
To write Response data directly in Spring
DI SessionScope Bean in Spring Boot 2 Filter
Add spring boot and gradle to eclipse
Change session timeout time in Spring Boot
File output bean as JSON in spring
Until custom validation by annotation is implemented in Spring Framework and message is output
SameSite cookie in Spring Boot (Spring Web MVC + Tomcat)
Multipart request response by HttpURLConnection (and Apache Commons)
Just input and output images with Spring MVC
Test controller with Mock MVC in Spring Boot
Asynchronous processing with regular execution in Spring Boot
Publish MySQL externally and log in on Ubuntu
Run a Spring Boot project in VS Code
Prepare for log output using log4j in Eclipse.
Various correspondence table of Spring Framework and Spring Boot
Use Servlet filter in Spring Boot [Spring Boot 1.x, 2.x compatible]
How to add a classpath in Spring Boot
Java tips-Create a Spring Boot project in Gradle
How to bind to property file in Spring Boot
Annotations used in Spring Boot task management tool