-
Notifications
You must be signed in to change notification settings - Fork 4
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
요청, 응답 로그 설정 #481
요청, 응답 로그 설정 #481
Conversation
53f297e
to
a2388f1
Compare
# Conflicts: # backend/build.gradle # backend/src/main/java/com/votogether/global/config/WebMvcConfig.java # backend/src/main/resources/application.yml # backend/src/test/java/com/votogether/domain/auth/controller/AuthControllerTest.java # backend/src/test/java/com/votogether/domain/post/controller/PostCommentControllerTest.java # backend/src/test/java/com/votogether/domain/post/controller/PostControllerTest.java # backend/src/test/java/com/votogether/domain/report/controller/ReportCommandControllerTest.java # backend/src/test/resources/application.yml
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
아예 처음 보는 흐름들이 많았어서 파악하는데에만 하루종일 걸렸네요 ㅋㅋ..
파악해가면서 굉장히 흥미로운 부분들이 많아서 재밌었어요.
몇 가지 코멘트 남겼습니다.
public WebMvcConfig(final JwtAuthorizationArgumentResolver jwtAuthorizationArgumentResolver) { | ||
this.jwtAuthorizationArgumentResolver = jwtAuthorizationArgumentResolver; | ||
@Bean | ||
public FilterRegistrationBean<CorsFilter> corsFilterRegistrationBean() { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Q
해당 메서드에서 LOCALHOST_FRONTEND url에 대한 cors 설정을 하는 것으로 보이네요. 그런데 이미 addCorsMappings() 메서드에서 CorsRegistry에 LOCALHOST_FRONTEND에 대한 CORS 설정이 되어있는데 여기서도 설정을 한 번 더 하는 이유가 궁금합니다!
혹시 setOrder(0)을 통해 가장 먼저 해당 필터를 거치게 하기 위한 것인지, 그게 맞다면 왜 그렇게 하는 것인지, 아니면 따로 더 설정해줘야 하는 부분들이 있어서 그런지, 아니면 아예 다른 이유가 따로 있는 것인지 궁금해요!
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
개발 환경, 운영 환경에서는 CORS
를 허용해주는 역할을 하고 있는 Nginx
를 리버스 프록시 서버로 두고 있기 때문에 애플리케이션 자체적으로 CORS 설정이 필요하지 않습니다!
하지만 로컬에서 8080
포트로 스프링 부트 애플리케이션을 실행시키는 경우, 리버스 프록시 서버가 없기 때문에 localhost:3000
에서 실행되는 프론트 요청에 대해 CORS 에러가 발생하게 되었습니다. 분명히 CorsRegistry
를 설정했음에도 왜 CORS 에러가 발생하는지 궁금하여 이에 대해 알아보게 되었습니다.
현재 저희는 인증을 위해 JwtFilter
를 사용하고 있습니다! 클라이언트의 요청이 들어오면 필터 -> 서블릿 -> 인터셉터 -> 핸들러 순으로 요청이 전달되는데, CorsRegistry는 DispatcherServlet
이 실행시키기 때문에 필터에서 요청이 전달되지 않으면 CORS 에러가 발생하게 됩니다.
현재 JwtFilter에는 Preflight
요청에 대한 처리가 되어있지 않아서 토큰이 존재하지 않다는 에러를 발생시키게 되고 CorsRegistry까지 요청이 전달되지 못합니다. 따라서 문제를 해결하기 위해 가장 앞단에 CorsFilter
를 두어 이에 대한 처리가 가능하도록 설정하였습니다 :)
@Component | ||
public class MemberIdHolder { | ||
|
||
@Setter |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Q
사소한 거지만, @Setter를 필드에 직접적으로 붙이신 이유가 있나요?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
필드가 1개 밖에 존재하지 않기 때문에 클래스 레벨에 붙여도 괜찮을 것 같아요 🤓
추후에 필드가 추가되더라도 원하는 필드에서만 세터가 동작하도록 하기 위해 필드 위에 명시적으로 붙여주었습니다 !
final TokenPayload tokenPayload = tokenProcessor.parseToken(tokenWithoutType); | ||
memberIdHolder.setId(tokenPayload.memberId()); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Q
어차피 여러 사용자가 요청을 보낼 때마다 MemberIdHolder의 id가 계속해서 바뀔 것 같은데, 사용자가 요청을 보낼 때마다 memberIdHolder에 해당 사용자의 id를 set 하는 이유가 궁금합니다.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@RequestScope
와 관련있습니다 !
private final QueryCount queryCount; | ||
|
||
@Override | ||
public Object invoke(final MethodInvocation invocation) throws Throwable { |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
P2
아까 같이 얘기했던 것처럼 해당 메서드의 로직을 ConnectionMethodInterceptor의 invoke 메서드에 합쳐도 괜찮을 것 같다는 생각이 드네요. 또 한편으로는 역할을 나눠서 응집도를 높인다는 관점에선 현재 로직도 나쁘지 않다는 생각도 드네요.
다즐의 의견이 궁금합니다 :)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
같이 얘기를 나눴던 대로 하나의 로직으로 합쳐도 괜찮을 것 같다는 생각이 들어요 !
2가지 방법 모두 괜찮은 방법이라고 생각이 들어서 결정하기 힘들기 때문에 우선은 그대로 가는 방향이 좋을 것 같아요 ㅎㅎ
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
으어 코드가 너무 어려워요 ㅓㅏㅏㅏㅜㅡㅏㅜㅏㅓ
전체적으로 코드에 대한 것보다는 로그 출력과 관련해서 간단하게 저의 의견을 남겨보았습니다!
aop구현하시느라 고생하셨어요~
if (CorsUtils.isPreflightRequest(request)) { | ||
return true; | ||
} | ||
final LogContext logContext = new LogContext(LogId.from(memberIdHolder)); | ||
logContextHolder.setLogContext(logContext); | ||
if (handler instanceof HandlerMethod) { | ||
final RequestLog requestLog = new RequestLog(logContext.getLogId(), request); | ||
requestLog.put("Controller Method", handlerMethod((HandlerMethod) handler)); | ||
log.info("[Web Request START] : [\n{}]", requestLog); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
|
||
public void methodReturn(final String className, final String methodName) { | ||
final LogContext logContext = logContextHolder.getLogContext(); | ||
log.info("[{}] {} time={}ms", |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
|
||
public void increaseMethodCall() { | ||
++methodDepth; | ||
} | ||
|
||
public void decreaseMethodCall() { | ||
--methodDepth; | ||
} | ||
|
||
public String depthPrefix(final String prefix) { | ||
if (methodDepth == 1) { | ||
return BAR + prefix; | ||
} | ||
|
||
final String bar = BAR + BLANK.repeat(prefix.length()); | ||
final String repeatedBar = bar.repeat(methodDepth - 1); | ||
return repeatedBar + BAR + prefix; | ||
} | ||
|
||
public String getLogId() { | ||
return logId.getId(); | ||
} | ||
|
||
public long totalTakenTime() { | ||
return System.currentTimeMillis() - startTimeMillis; | ||
} |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Q.
여기 클래스에서 메서드가 호출될때마다 스택같은곳에 호출시간을 쌓아놓고
메서드가 리턴될때 해당 메서드의 실행시간을 계산해서 로그로 출력해주는것 방식은 어떤것 같나요??
log.info("[{}] {} time={}ms", | ||
logContext.getLogId(), | ||
formattedClassAndMethod(logContext.depthPrefix(RETURN_PREFIX), className, methodName), | ||
logContext.totalTakenTime() |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Q.
메서드호출이 끝난 시점을 구간기록과 같은 방식으로 로그로 출력하고 있는데
호출이 끝나는 시점을 로그로 남기는것 보다 해당 메서드가 호출되고 리턴되기까지의 시간을 로그로 남기는게 더 의미있다고 생각이 들었는데 이 방법으로 로그를 남기는건 어떤것 같나요?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
좋은 방법인 것 같습니다 ㅎㅎ 감사합니다
말씀해주신 방법대로 스택을 이용해서 메서드별 실행 시간을 확인할 수 있도록 구현하였는데, ms
단위여서 아주 작은 오차들이 발생하더라구요. 0.01
초 단위의 아주 작은 오차들이여서 괜찮을 것 같다는 생각이 들었는데 이 부분에 대해서는 어떻게 생각하시나요?!
|
||
public static boolean isPreflightRequest(final HttpServletRequest request) { | ||
return HttpMethod.OPTIONS.matches(request.getMethod()); | ||
} |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
P3
유틸클래스 생성자는 private으로 막아두면 좋을거같아요! + final 클래스까지..?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
꼼꼼한 리뷰 좋아요 👍
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
무시무시하고 어려운 AOP를 통해 요청, 응답 로그를 멋지게 구현해주셨군요 👍🏻
작성하시느라 고생 많으셨습니다 다즐 ㅎㅎ
이해하기 어려운 부분이 많아서 코멘트가 거의 질문인 것 같아요...
흐름을 대충은 이해했는데 세부적인 부분까지 이해하기가 정말 어렵네요.
부탁을 하나 드리고 싶은데, 전체적인 흐름을 한번 정리하여 나타내주실 수 있을까요?
추후에 다시 코드를 보면 이해하기 어려울 것 같다는 생각이 들었어요.
이후에 다시 확인할 떄 흐름도 같은 것이 있으면 이해하기 훨씬 수월할 것 같다고 느꼈어요.
추가적으로 질문이 생기면 코멘트 남기겠습니다 :)
@@ -22,13 +22,14 @@ repositories { | |||
} | |||
|
|||
dependencies { | |||
implementation 'org.springframework.boot:spring-boot-starter-web' | |||
implementation 'org.springframework.boot:spring-boot-starter-webflux' |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Q
어떤 이유로 webflux의존성을 추가하셨나요?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
운영 환경에서 error
레벨의 로그가 남겨지면 즉각 대응이 필요한 상황이기에 이를 바로 알리기 위해 슬랙 알림이 필요하였습니다!
저희는 Logback
이 아닌 Log4j2
를 사용하고 있기 때문에 Logback
의 SlackAppender
라이브러리를 사용할 수 없었습니다. Log4j2
도 SlackAppender
라이브러리가 존재하는지 찾아보았으나, 오래된 라이브러리만 존재했고 적절한 라이브러리를 찾을 수 없어서 직접 구현해서 사용하기로 결정하였습니다. 마침 직접 구현해서 사용한 분이 정리한 글이 있어 해당 글을 참고하였습니다.
슬랙 알림을 보내기 위해 HTTP 통신이 필요한 상황에서 3가지의 선택지가 존재했습니다.
RestTemplate
WebClient
FeignClient
RestTemplate, FeignClient는 기본적으로 Blocking 방식으로 동작하기 때문에 슬랙 알림을 위해 제어권을 뺏기게 되는 상황으로 성능에 영향을 줄 수 있습니다. 알림은 비동기로 처리해도 되는 로직이기에 비동기를 지원하는 WebClient의 선택이 필요했고, 이를 사용하기 위해 webflux
의존성을 추가하게 되었습니다 :)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
기존에 존재하는 web
의존성과 충돌이 나지 않을까라는 걱정도 했던 것 같아요.
2개의 의존성이 모두 존재하는 경우, 스프링 부트 애플리케이션은 SERVLET
방식을 선택하기 때문에 Netty
서버가 아닌 Tomcat
서버로 동작하게 되는 것을 문서를 통해 확인할 수 있었고, Tomcat 서버로 가동하면서 WebClient 기술만 사용할 수 있다는 것도 알게 되었습니다!
config.addAllowedOrigin(LOCALHOST_FRONTEND); | ||
config.addAllowedHeader("*"); | ||
config.addAllowedMethod("*"); | ||
config.setMaxAge(6000L); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Q
100분으로 설정하신 이유가 있나요?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
로컬에서만 사용되는 기능이기 때문에 큰 의도없이 설정한 값입니다!
해당 값을 어느 정도로 하면 좋을까요? 🤔
<!-- <Logger name="org.hibernate.SQL" level="debug">--> | ||
<!-- <AppenderRef ref="ConsoleAppender"/>--> | ||
<!-- </Logger>--> | ||
|
||
<Logger name="org.hibernate.orm.jdbc.bind" level="trace"> | ||
<AppenderRef ref="ConsoleAppender"/> | ||
</Logger> | ||
<!-- <Logger name="org.hibernate.orm.jdbc.bind" level="trace">--> | ||
<!-- <AppenderRef ref="ConsoleAppender"/>--> | ||
<!-- </Logger>--> | ||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Q
주석으로 남겨두신 이유가 있을까요?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
해당 로거를 제거할 때 추후에 필요한 상황이 있지 않을까라는 생각에 주석으로 남겨두었던 것 같습니다.
현재 로그 기능이 정상적으로 동작하는 것을 확인했고 아직 추가적인 로그 데이터가 필요하지 않은 상황이라고 판단되기 때문에 주석 처리되어있는 로거들을 제거하는 방향으로 수정하였습니다 !
import org.springframework.web.context.annotation.RequestScope; | ||
|
||
@Getter | ||
@RequestScope |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Q
@RequestScope
을 사용하면 클라이언트 별로 구분할 수 있어 로깅을 쉽게할 수 있다는 장점이 있는 것 같은데, 어떤 단점이 존재하는지 궁금합니다.
또한 어떤 클래스에 해당 어노테이션을 붙여야하는지도 궁금합니다.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
우선 요청마다 데이터가 구분되어야 하는 상황에서 해당 어노테이션 사용을 고려해볼 수 있을 것 같아요! 이와 비교해볼 선택지는 ThreadLocal
이 있을 것 같습니다.
톰캣은 HTTP 요청을 처리하기 위해 요청 당 1개의 스레드를 사용하기에 2개 다 괜찮은 선택지라고 생각되지만, ThreadLocal
는 아래와 같은 단점이 존재합니다.
- ThreadLocal에 저장된 변수 값들이 스레드가 다시 재사용될 때까지 메모리에 남아있을 수 있기 때문에 사용이 끝난 ThreadLocal 값은 적절히 제거가 필요하다.
@RequestScope
는 요청동안 유지되는 Bean이고 요청이 종료되면 자동으로 메모리에서 할당이 해지되는 값이기 때문에 위와 같은 문제를 걱정할 필요가 없기에 해당 방법을 선택해서 구현하게 되었습니다.
단점이라고 한다면 아래의 단점이 존재할 것 같아요 !
- 요청마다
Bean
이 생성되고 소멸하는 오버헤드가 존재한다.- Bean 내부에 많은 것들을 포함하고 있으면 오버헤드가 큰 문제가 발생할 수 있겠지만 현재는 몇 개의 작은 필드들만 저장하고 있기 때문에 큰 오버헤드는 들지 않을 것이라 생각해요 :)
|
||
private final Logger logger; | ||
|
||
@Pointcut("@within(org.springframework.web.bind.annotation.RestController)") |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
이 어노테이션은 어떤 역할을 하나요?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Pointcut
을 설정하여 AOP
를 통해 수행될 작업을 어느 곳에 적용할지를 결정할 수 있습니다.
Pointcut 표현식이 존재하는데, 위의 표현식은 RestController
어노테이션을 가진 곳에 적용한다는 의미를 가지고 있습니다 !
|
||
private final LogId logId; | ||
private final long startTimeMillis; | ||
private int methodDepth = 0; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Q
필드 명은 methodDepth
로 사용하고 계신데, 메서드 명은 MethodCall
로 사용하고 있는 이유가 있을까요?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
메서드가 호출될 때마다 메서드 호출 스택의 깊이가 깊어지기 때문에 서로 다른 의미를 가지고 있습니다 !
각각의 행위를 잘 드러내는 메서드명과 필드명을 사용하고자 했습니다 🤓
) | ||
.compress(true); | ||
|
||
final WebClient webClient = WebClient.builder() |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Q
WebClient
를 사용하기 위해서는 항상 HttpClient
를 함께 사용해야하나요?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
저도 이번에 처음 사용해본 기술이라 블로그를 최대한 참고하여 작성했던 것 같아요 🤓
WebClient
에 필요한 데이터를 설정하는 부분으로 이해했기에 항상 HttpClient
를 함께 사용하는 것 같지는 않습니다 !
@@ -0,0 +1,11 @@ | |||
package com.votogether.global.log.log4j2; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Q
이 패키지의 이름은 왜 log4j2인가요?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
요청, 응답 로그에 사용되는 클래스들이 아닌 log4j2
가 발생시키는 로그에 대한 슬랙 알림을 위한 클래스들이 모여있는 패키지이기 때문에 패키지명을 log4j2
로 정하였습니다 !
@Autowired | ||
MockMvc mockMvc; | ||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Q
사용하신 이유가 있을까요?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@WebMvcTest
와 같은 테스트 환경을 사용하지 않고 @InjectMocks
와 @Mock
으로 구성된 테스트 환경을 사용할 때는 RestAssuredMockMvc
의 standaloneSetup
메서드를 통해 테스트 환경을 만들어주는 것이 테스트에서 필요한 의존성만 가져갈 수 있는 방법입니다.
저희 프로젝트에서 Presentation
계층의 테스트는 @WebMvcTest 환경을 사용하고 있기 때문에 해당 환경에 알맞은 애플리케이션 컨텍스트가 생성되어 있고 이미 구성된 애플리케이션 컨텍스트를 활용하는 것이 좋다고 생각하였습니다. 이를 위해 MockMvc 의존성을 주입받아 RestAssuredMockMvc에 세팅해주는 작업을 진행하였습니다 !
protected void mockingLog() { | ||
given(requestLogInterceptor.preHandle(any(), any(), any())).willReturn(true); | ||
} | ||
|
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Q
어떤 역할을 하나요?
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
@WebMvcTest
를 사용하기에 빈으로 등록되어 있는 인터셉터에 대한 동작도 실행되게 됩니다. 인터셉터도 실제 빈으로 동작하게 하기 위해서는 인터섭터에서 주입받고 있는 객체들에 대한 의존성 주입도 필요하게 되고, 저희가 테스트해야할 컨트롤러의 로직보다 인터셉터 세팅에 더 많은 리소스가 들어가게 됩니다.
따라서 본질적으로 테스트하고자 하는 부분에 집중하고자 인터셉터 로직은 mocking
을 통해 처리하였습니다 :)
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
고생하셨습니다!
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
고생하셨습니다~~!
🔥 연관 이슈
📝 작업 요약
요청, 응답에서 발생하는 데이터에 대한 로그를 설정하였습니다.
⏰ 소요 시간
15시간
🔎 작업 상세 설명
JSON
요청은 입력 스트림의 바이트를 저장해두고 해당 바이트를 해석해서 사용할 수 있지만, 멀티 파트 요청에서 사용되는Part
는 바운더리를 추출하고 파싱하고 다시Part
를 만드는 과정이 매우 복잡하기 때문에 이를 저장하고 복원하는 것이 매우 어려운 작업입니다.Part
데이터는 로그에서 제외시키도록 하였고, 나머지 요청 흐름에서 발생하는 정보에 대해서만 로그를 남길 수 있도록 하였습니다.🌟 논의 사항
로그 레벨과 사용하지 않는 로그에 대해서는 조금 더 얘기가 필요할 것 같아요 :)