์ง๋ ํฌ์คํ
์์ ์์ฒญ๊ณผ ์๋ต์ ๋ํ ๋ก๊ทธ๋ฅผ ๋จ๊ธฐ๋ ๋ฒ์ ๋ํด์ ์์๋ณด์์๋๋ฐ์
์ด์ด์ ์ด๋ฒ์๋ ์ถ๋ ฅ๋๋ ๋ก๊ทธ๋ฉ์์ง์ ๋ด์ฉ์ ๋ฐ๊ฟ๋ณด๋ ค๊ณ ํฉ๋๋ค.
ํน์๋ผ๋ ๊ฒ์์ผ๋ก ์ด ํฌ์คํ
์ ๋จผ์ ๋ณด๊ฒ๋์๋ ๋ถ์ ์๋ ํฌ์คํ
์ ๋จผ์ ์ฝ์ด๋ณด์๊ธธ ์ถ์ฒ๋๋ฆฝ๋๋ค.
[5๋ถ์ฝ๋ฉ] Filter๋ฅผ ์ด์ฉํ ์์ฒญ,์๋ต ๋ก๊น
(How to log request, response info inlcuding payload using filter) - (1/2)
๋ก๊ทธ ๋ฉ์์ง ๋ด๋ง๋๋ก ๊พธ๋ฏธ๊ธฐ
์ฐ์ ์ง๋ ์๊ฐ์ ๋ง์ง๋ง์ผ๋ก ํ์ธํ ๋ก๊ทธ ์ถ๋ ฅ ๋ด์ฉ์ ๋ค์ ํ์ธํด๋ณด๋ฉด ์๋์ ๊ฐ์ต๋๋ค.
2022-09-16 07:32:49.190 INFO 31518 --- [nio-8080-exec-5] c.k.demo.filter.RequestLoggingFilter : Before request [POST /test/request-body-log, client=0:0:0:0:0:0:0:1]
2022-09-16 07:32:49.226 INFO 31518 --- [nio-8080-exec-5] c.k.demo.filter.RequestLoggingFilter : After request [POST /test/request-body-log, client=0:0:0:0:0:0:0:1, payload={
"id":1000,
"name":"์ผ์ด์น",
"age":20
}]
๊ทธ๋ผ ์ ๋ฉ์์ง๋ฅผ ์ด๋ป๊ฒ ๋ฐ๊ฟ ์ ์์์ง ํ๋ฒ ์์๋ณผ๊ฒ์.
์์ฒญ/์๋ต ๋ก๊น
์ ์ํด์ ์ฐ๋ฆฌ๋ AbstractRequestLoggingFilter ๋ฅผ ์์ํ์ฌ ํํฐ๋ฅผ ํ๋ ๋ง๋ค์์์ต๋๋ค.
๋ก๊ทธ ๋ฉ์์ง๋ฅผ ๋ฐ๊พธ๋ ค๋ฉด ์ ํด๋์ค์์ ์ด๋ค ๋ฉ์๋๋ค์ ์ ๊ณตํ๊ณ ์๋์ง ๋ค์ฌ๋ค๋ด์ผ ํฉ๋๋ค.
AbstractRequestLoggingFilter๋ฅผ ๊น๋ณด๋ฉด ์๋ ๋ฉ์๋๋ฅผ ์ค๋ฒ๋ผ์ด๋ํด์ ์ฌ์ ์ํ๊ณ ์๋ ๊ฒ์ ๋ณผ ์ ์์ต๋๋ค.
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
doFilterInternal ๋ฉ์๋์์ ํ๋ ์ผ์ ์์ฒญ์ ๋ํ ๋น์ฆ๋์ค ๋ก์ง์ด ์คํ๋๊ธฐ ์ ํ๋ก ๋ก๊ทธ๋ฅผ ๋จ๊ธฐ๋ ๊ฒ์
๋๋ค.
์ฝ๋๋ฅผ ์ ์ ์ดํด๋ณผ๊ฒ์
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
throws ServletException, IOException {
boolean isFirstRequest = !isAsyncDispatch(request);
HttpServletRequest requestToUse = request;
if (isIncludePayload() && isFirstRequest && !(request instanceof ContentCachingRequestWrapper)) {
requestToUse = new ContentCachingRequestWrapper(request, getMaxPayloadLength());
}
boolean shouldLog = shouldLog(requestToUse);
if (shouldLog && isFirstRequest) {
beforeRequest(requestToUse, getBeforeMessage(requestToUse));
}
try {
filterChain.doFilter(requestToUse, response);
}
finally {
if (shouldLog && !isAsyncStarted(requestToUse)) {
afterRequest(requestToUse, getAfterMessage(requestToUse));
}
}
}
beforeRequest(requestToUse, getBeforeMessage(requestToUse)) ์์ Before request ... ๋ก๊ทธ๋ฅผ ๋จ๊ธฐ๊ณ ์๊ณ
afterRequest(requestToUse, getAfterMessage(requestToUse)) ์์ After request ... ๋ก๊ทธ๋ฅผ ๋จ๊ธฐ๊ณ ์์ต๋๋ค.
๋ฐ๋ผ์ ์ฐ๋ฆฌ๊ฐ ์ํ๋๋๋ก ๋ฉ์์ง์ ๋ด์ฉ์ ๋ฐ๊พธ๋ ค๋ฉด ์ ๋ ๊ตฐ๋ฐ๋ฅผ ์์ ํด์ฃผ๋ฉด ๋ฉ๋๋ค.
์ฐ์ ๋ก๊ทธ ๋ฉ์์ง์ ๋ํ ์์ ์๊ตฌ์ฌํญ์ด ์๋์ ๊ฐ๋ค๊ณ ๊ฐ์ ํด๋ณด๊ฒ ์ต๋๋ค.
- ํธ์ถ๋ฐ์ API ์ ๋ณด์ ํด๋ผ์ด์ธํธIP ์ ๋ณด๋ฅผ ์ค๋ณต ์ถ๋ ฅ ํ์ง ์๋๋ค
- ํธ์ถ๋ฐ์ API uri ์ ํด๋ผ์ด์ธํธIP, payload ์ ๋ณด๋ before request ์์ ๋จ๊ธด๋ค. ๐
- after request ์๋ ์๋ต์์์๊ฐ๊ณผ http status ์ฝ๋๊ฐ์ ๋จ๊ธด๋ค.
- ์ต์ข
์ ์ผ๋ก ์ถ๋ ฅ๋๋ ๋ชจ์ต์ ๋ค์๊ณผ ๊ฐ๋ค.
2022-09-16 08:28:08.053 INFO 41196 --- [nio-8080-exec-2] c.k.demo.filter.RequestLoggingFilter : REQ: POST uri=/test/request-body-log;client=0:0:0:0:0:0:0:1;payload={
"id":1000,
"name":"์ผ์ด์น",
"age":20
}
2022-09-16 08:28:08.076 INFO 41196 --- [nio-8080-exec-2] c.k.demo.filter.RequestLoggingFilter : RES: 22ms, 400
์, ์ด์ ์ ์๊ตฌ์ฌํญ์ ๋ง๊ฒ ์ฐ๋ฆฌ์ ํํฐํด๋์ค๋ฅผ ์์ ํด๋ณด๊ฒ ์ต๋๋ค.
RequestLoggingFilter ํด๋์ค์ ์๋ ์ฝ๋๋ฅผ ์ถ๊ฐํด์ฃผ์ธ์.
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
throws ServletException, IOException {
boolean isFirstRequest = !isAsyncDispatch(request);
HttpServletRequest requestToUse = request;
if (isIncludePayload() && isFirstRequest && !(request instanceof ContentCachingRequestWrapper)) {
requestToUse = new ContentCachingRequestWrapper(request);
}
long start = System.currentTimeMillis();
if (isFirstRequest) {
beforeRequest(requestToUse, getBeforeMessage(requestToUse));
}
try {
filterChain.doFilter(requestToUse, response);
} finally {
if (!isAsyncStarted(requestToUse)) {
afterRequest(requestToUse, getAfterMessage(System.currentTimeMillis() - start, response.getStatus()));
}
}
}
private String getBeforeMessage(HttpServletRequest request) {
return createMessage(request, "REQ: ", "");
}
private String getAfterMessage(long elapsed, int status) {
return "RES: " + elapsed + "ms, " + status;
}
AbstractRequestLoggingFilter ์ ๊ตฌํ๋์ด์๋ doFilterInternal ๋ฉ์๋ ๋ด์ฉ์ ๊ทธ๋๋ก ๊ฐ์ง๊ณ ์์ beforeRequest์ afterRequest ๋ฉ์๋์ ๋ ๋ฒ์งธ ํ๋ผ๋ฏธํฐ๋ก ์ ๋ฌํ๋ message ๋ฅผ ์กฐ๋ฆฝํ๋ ๋ฉ์๋๋ฅผ ์ง์ ๊ตฌํํฉ๋๋ค. getBeforeMessage์ createMessage๋ superํด๋์ค, ์ฆ, AbstractRequestLoggingFilter ์์ ์ ๊ณตํ๋ ๊ฒ์ ๊ทธ๋๋ก ์ฌ์ฉํฉ๋๋ค. createMessage ์์๋ prefix์ suffix ๊ทธ๋ฆฌ๊ณ request ์ ๋ณด๋ฅผ ๊ฐ์ง๊ณ ๋ฉ์์ง๋ฅผ ์์์ ๋ง๋ค์ด ์ค๋๋ค. payload๋ ์ญ์ ์ฌ๊ธฐ ํฌํจ๋์ด์์ฃ .
์, ๊ทธ๋ผ ์ฑ์ ์ฌ๊ธฐ๋ํ๊ณ ๋ก๊น
์ด ์ด๋ป๊ฒ ๋๋์ง ๋ณด๊ฒ ์ต๋๋ค.
2022-09-16 08:39:20.270 INFO 43287 --- [nio-8080-exec-1] c.k.demo.filter.RequestLoggingFilter : REQ: POST /test/request-body-log, client=0:0:0:0:0:0:0:1
2022-09-16 08:39:20.306 INFO 43287 --- [nio-8080-exec-1] c.k.demo.filter.RequestLoggingFilter : RES: 35ms, 200
์๊ตฌ์ฌํญ ๋๋ถ๋ถ์ด ๋ฐ์๋ ๊ฒ์ ํ์ธํ ์ ์์ต๋๋ค. ์ด๋ผ? ๊ทผ๋ฐ payload ๊ฐ request ๋ก๊ทธ์์ ๋น ์ ธ์์ต๋๋ค.
๋ถ๋ช
after message ๋ก๊ทธ๊ฐ ์ถ๋ ฅ๋ ๋๋ ์ ์ถ๋ ฅ์ด ๋์๋๋ฐ ๋ง์ด์ฃ . ๋๊ฐ์ createMessage ๋ฉ์๋๋ฅผ ์ด์ฉํ๋๋ฐ before request ์์๋ payload๊ฐ ์ถ๋ ฅ์ด ์๋ฉ๋๋ค ใ
ใ
ํ์ธํด๋ณด๋ AbstractRequestLoggingFilter.getMessagePayload ์์ ์๋ wrapper ๊ฐ null ๋ก ๋ฐํ์ด ๋๊ณ ์์์ต๋๋ค.
ContentCachingRequestWrapper wrapper =
WebUtils.getNativeRequest(request, ContentCachingRequestWrapper.class);
res๋ก๊ทธ์์๋ ์ ๋์ค๋๊ฒ req๋ก๊ทธ์์ ์ถ๋ ฅํ๋ ค๋ null์ด ๋ฐํ์ด ๋ฉ๋๋ค.
์ด๊ฑธ ํด๊ฒฐํ๋ ค๋ฉด ์ถ๊ฐ์ ์ธ ์์
์ด ํ์ํ๋ฐ ์ฐ์ ์๋ ๋ ๊ฐ์ ํด๋์ค๋ฅผ ์ถ๊ฐํด์ค๋๋ค.
package com.keichee.demo.filter;
import org.springframework.stereotype.Component;
import org.springframework.web.filter.GenericFilterBean;
import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;
import java.io.IOException;
@Component
public class RequestBodyCacheFilter extends GenericFilterBean {
@Override
public void doFilter(ServletRequest servletRequest, ServletResponse servletResponse, FilterChain chain)
throws IOException, ServletException {
chain.doFilter(new RequestBodyCacheWrapper((HttpServletRequest) servletRequest), servletResponse);
}
}
package com.keichee.demo.filter;
import lombok.extern.slf4j.Slf4j;
import javax.servlet.ReadListener;
import javax.servlet.ServletInputStream;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletRequestWrapper;
import java.io.*;
import java.nio.charset.StandardCharsets;
@Slf4j
public class RequestBodyCacheWrapper extends HttpServletRequestWrapper {
private final ByteArrayInputStream byteArrayInputStream;
public RequestBodyCacheWrapper(HttpServletRequest request) throws IOException {
super(request);
InputStream is = super.getInputStream();
byteArrayInputStream = new ByteArrayInputStream(is.readAllBytes());
}
@Override
public ServletInputStream getInputStream() {
byteArrayInputStream.reset();
return new MyServletInputStream(byteArrayInputStream);
}
@Override
public BufferedReader getReader() {
byteArrayInputStream.reset();
return new BufferedReader(new InputStreamReader(byteArrayInputStream, StandardCharsets.UTF_8));
}
private static class MyServletInputStream extends ServletInputStream {
private final InputStream is;
public MyServletInputStream(InputStream bis) {
is = bis;
}
@Override
public int read() throws IOException {
return is.read();
}
@Override
public int read(byte[] b) throws IOException {
return is.read(b);
}
@Override
public boolean isFinished() {
return false;
}
@Override
public boolean isReady() {
return false;
}
@Override
public void setReadListener(ReadListener readListener) {
}
}
}
์ด์ ๋ค์ RequestLoggingFilter ํด๋์ค๋ก ๋์์์ AbstractRequestLoggingFilter.createMessage ๋ฉ์๋๋ฅผ ๊ทธ๋๋ก ๋ณต์ฌํด์ ๊ฐ์ง๊ณ ์ต๋๋ค. ๊ทธ๋ฆฌ๊ณ getMessagePayload ๋ถ๋ถ์ ์๋์ ๊ฐ์ด ์์ ํด์ฃผ์ธ์. ๋ค๋ฅธ ๋ถ๋ถ์ ๊ทธ๋๋ก ๋๋ก๋๋ค.
String payload = null;
try {
payload = new String(request.getInputStream().readAllBytes(), StandardCharsets.UTF_8);
} catch (IOException e) {
log.error("failed to read payload", e);
}
์์ ์ด ์๋ฃ๋ createMessage ๋ฉ์๋๋ ์๋์ ๊ฐ์ต๋๋ค.
@Override
protected String createMessage(HttpServletRequest request, String prefix, String suffix) {
StringBuilder msg = new StringBuilder();
msg.append(prefix);
msg.append(request.getMethod()).append(' ');
msg.append(request.getRequestURI());
if (isIncludeQueryString()) {
String queryString = request.getQueryString();
if (queryString != null) {
msg.append('?').append(queryString);
}
}
if (isIncludeClientInfo()) {
String client = request.getRemoteAddr();
if (StringUtils.hasLength(client)) {
msg.append(", client=").append(client);
}
HttpSession session = request.getSession(false);
if (session != null) {
msg.append(", session=").append(session.getId());
}
String user = request.getRemoteUser();
if (user != null) {
msg.append(", user=").append(user);
}
}
if (isIncludeHeaders()) {
HttpHeaders headers = new ServletServerHttpRequest(request).getHeaders();
if (getHeaderPredicate() != null) {
Enumeration<String> names = request.getHeaderNames();
while (names.hasMoreElements()) {
String header = names.nextElement();
if (!getHeaderPredicate().test(header)) {
headers.set(header, "masked");
}
}
}
msg.append(", headers=").append(headers);
}
if (isIncludePayload()) {
String payload = null;
try {
payload = new String(request.getInputStream().readAllBytes(), StandardCharsets.UTF_8);
} catch (IOException e) {
log.error("failed to read payload", e);
}
if (payload != null) {
msg.append(", payload=").append(payload);
}
}
msg.append(suffix);
return msg.toString();
}
๋ง์ง๋ง์ผ๋ก doFilterInternal ๋ฉ์๋ ๋ก์ง ์ค filterChain.doFilter์์ ์ฌ์ฉํ๋ request ๊ฐ์ฒด๋ฅผ ContentCachingRequestWrapper ๊ฐ ์๋ ๋ฉ์๋ ํ๋ผ๋ฏธํฐ๋ก ์ ๋ฌ๋ฐ์ request๋ฅผ ๊ทธ๋๋ก ์ฌ์ฉํ๋๋ก ์์ ํฉ๋๋ค. (reuqestToUse -> request)
์ต์ข
์ ์ผ๋ก RequestLoggingFilter ํด๋์ค์ ์์ค์ฝ๋๋ ๋ค์๊ณผ ๊ฐ์ต๋๋ค.
package com.keichee.demo.filter;
import lombok.extern.slf4j.Slf4j;
import org.springframework.http.HttpHeaders;
import org.springframework.http.server.ServletServerHttpRequest;
import org.springframework.util.StringUtils;
import org.springframework.web.filter.AbstractRequestLoggingFilter;
import org.springframework.web.util.ContentCachingRequestWrapper;
import javax.servlet.FilterChain;
import javax.servlet.ServletException;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;
import javax.servlet.http.HttpSession;
import java.io.IOException;
import java.nio.charset.StandardCharsets;
import java.util.Enumeration;
@Slf4j
public class RequestLoggingFilter extends AbstractRequestLoggingFilter {
@Override
protected void beforeRequest(HttpServletRequest request, String message) {
logger.info(message);
}
@Override
protected void afterRequest(HttpServletRequest request, String message) {
logger.info(message);
}
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain)
throws ServletException, IOException {
boolean isFirstRequest = !isAsyncDispatch(request);
HttpServletRequest requestToUse = request;
if (isIncludePayload() && isFirstRequest && !(request instanceof ContentCachingRequestWrapper)) {
requestToUse = new ContentCachingRequestWrapper(request);
}
long start = System.currentTimeMillis();
if (isFirstRequest) {
beforeRequest(requestToUse, getBeforeMessage(requestToUse));
}
try {
filterChain.doFilter(request, response);
} finally {
if (!isAsyncStarted(requestToUse)) {
afterRequest(requestToUse, getAfterMessage(System.currentTimeMillis() - start, response.getStatus()));
}
}
}
private String getBeforeMessage(HttpServletRequest request) {
return createMessage(request, "REQ: ", "");
}
private String getAfterMessage(long elapsed, int status) {
return "RES: " + elapsed + "ms, " + status;
}
@Override
protected String createMessage(HttpServletRequest request, String prefix, String suffix) {
StringBuilder msg = new StringBuilder();
msg.append(prefix);
msg.append(request.getMethod()).append(' ');
msg.append(request.getRequestURI());
if (isIncludeQueryString()) {
String queryString = request.getQueryString();
if (queryString != null) {
msg.append('?').append(queryString);
}
}
if (isIncludeClientInfo()) {
String client = request.getRemoteAddr();
if (StringUtils.hasLength(client)) {
msg.append(", client=").append(client);
}
HttpSession session = request.getSession(false);
if (session != null) {
msg.append(", session=").append(session.getId());
}
String user = request.getRemoteUser();
if (user != null) {
msg.append(", user=").append(user);
}
}
if (isIncludeHeaders()) {
HttpHeaders headers = new ServletServerHttpRequest(request).getHeaders();
if (getHeaderPredicate() != null) {
Enumeration<String> names = request.getHeaderNames();
while (names.hasMoreElements()) {
String header = names.nextElement();
if (!getHeaderPredicate().test(header)) {
headers.set(header, "masked");
}
}
}
msg.append(", headers=").append(headers);
}
if (isIncludePayload()) {
String payload = null;
try {
payload = new String(request.getInputStream().readAllBytes(), StandardCharsets.UTF_8);
} catch (IOException e) {
log.error("failed to read payload", e);
}
if (payload != null) {
msg.append(", payload=").append(payload);
}
}
msg.append(suffix);
return msg.toString();
}
}
์, ์ด์ ์ฑ์ ์ฌ๊ธฐ๋ํ๊ณ ๋ค์ API๋ฅผ ํธ์ถํด๋ณด๊ฒ ์ต๋๋ค.
2022-09-16 10:04:36.918 DEBUG 57590 --- [ main] com.keichee.demo.DemoLoggingApplication : Running with Spring Boot v2.7.3, Spring v5.3.22
2022-09-16 10:04:36.918 INFO 57590 --- [ main] com.keichee.demo.DemoLoggingApplication : The following 1 profile is active: "local"
2022-09-16 10:04:37.301 DEBUG 57590 --- [ main] c.k.demo.filter.RequestBodyCacheFilter : Filter 'requestBodyCacheFilter' configured for use
2022-09-16 10:04:37.301 DEBUG 57590 --- [ main] c.k.demo.filter.RequestLoggingFilter : Filter 'loggingFilter' configured for use
2022-09-16 10:04:37.416 INFO 57590 --- [ main] com.keichee.demo.DemoLoggingApplication : Started DemoLoggingApplication in 0.642 seconds (JVM running for 0.873)
2022-09-16 10:04:39.588 INFO 57590 --- [nio-8080-exec-2] c.k.demo.filter.RequestLoggingFilter : REQ: POST /test/request-body-log, client=0:0:0:0:0:0:0:1, payload={
"id":1000,
"name":"์ผ์ด์น",
"age":20
}
2022-09-16 10:04:39.627 INFO 57590 --- [nio-8080-exec-2] c.k.demo.filter.RequestLoggingFilter : RES: 40ms, 200
request payload๊ฐ ์ ์์ ์ผ๋ก ์ถ๋ ฅ๋๋ ๊ฒ์ ํ์ธํ ์ ์์ต๋๋ค. ์๋ต status๋ 200์ด ๋์จ๊ฒ์ ํ์ธํ์ต๋๋ค.
์, ์ ๋ฐ๋ผ ์ค์
จ๋์?
์ด ๋ถ๋ถ์ trickyํ ๋ถ๋ถ์ด๋ผ ๋น์ฆ๋์ค ๋ก์ง์ด ์คํ๋๊ธฐ ์ ์ request body๋ฅผ ์ถ๋ ฅํ๋ ๋ถ๋ถ์์ ์ ๋ฅผ ๋จน๋ ๋ถ๋ค์ด ๋ง์ต๋๋ค. stackoverflow์์ ํด๊ฒฐ์ฑ
์ ์ฐพ๊ธฐ๋ ํ๋ค๋๊ตฐ์. ์๋ํ๊ฑด์ง๋ ๋ชจ๋ฅด๊ฒ ์ผ๋ springboot์ ๋ด์ฅ๋ tomcat์ request body๋ฅผ ํ๋ฒ๋ง ์ฝ์ด์ ์ธ ์ ์๋๋ก ์ ํ(?)๋์ด์๊ธฐ ๋๋ฌธ์ ์๋ชป ์ค์ ํ๋ฉด ๋ก๊ทธ์๋ payload๊ฐ ์ ์ถ๋ ฅ๋์ง๋ง ๋น์ฆ๋์ค๋ก์ง ์คํ์ request body๋ฅผ ๋ชป ์ฝ์ด์์ 400 bad request๊ฐ ๋ฐ์ํ๊ธฐ๋ ํฉ๋๋ค.
์ด์์ผ๋ก request, response ๋ก๊ทธ๋ฅผ ๋ด๋ง๋๋ก ๋ฐ๊ฟ๋ณด๋ ๋ฐฉ๋ฒ์ ๋ํด์ ์์๋ณด์์ต๋๋ค.
์ฝ์ด์ฃผ์
์ ๊ฐ์ฌํฉ๋๋ค~ ๐
์ข์์ ๊พน ๋๋ฌ์ฃผ๊ณ ๊ฐ์ธ์~
