I wrote a filter that outputs request and response logs in Spring Boot, so I will share it.
[Original] 1
Difference from the original
RuntimeExceptionGenericFilterBeanʻ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