Logging 작업을 정리한 계기
지금 진행하고 있는 골키퍼 버전2 프로젝트를 개발하면서 구글 로그인 기능을 처음 구현했다. 처음 하는 거다보니 예상하지 못한 오류들이 많이 발생했고, 브레이크 포인트를 걸면서 확인해가기에는 오류가 너무 많았다. 그래서 Logging 작업을 철저히 해놓고 다시 오류를 고쳐나가기로 했다.
오류가 났는지 정확히 확인하기 위해서는 http 요청, 비즈니스 로직을 타면서 호출되는 Spring Bean, http 응답 정보를 기록해야 한다고 판단했다.
Logging 이란?
본론에 들어가기 전에, Logging이 뭔지부터 정의하고 넘어가보자. 요즘 핫한 ai 에게 Logging 이 뭐냐고 물어보면 이렇게 대답해준다.
Logging is the process of recording events or information in a computer system for the purpose of analysis, tracking, and debugging. It allows developers to monitor the behavior of their software, understand and diagnose issues, and gain insights into how it's being used. Logs can also be used for auditing, performance analysis, and security purposes.
-Chat GPT
한국말로 번역하면, “컴퓨터 시스템에서 발생하는 각종 이벤트나 정보들을 기록하는 작업으로 분석, 추적, 디버깅을 그 목적으로 한다.” 라고 번역할 수 있다.
Spring Boot 에서 Logging
Spring Boot, 정확히는 implementation 'org.springframework.boot:spring-boot-starter-web' 을 적용한 Spring MVC 웹 시스템에서 로그를 남길때 사용할 만한 기술들은 4가지 정도가 있다.
Filter
자바로 웹 개발을 할 때 사용되는 원천기술인 Servlet 스택에 포함된 요소이다. Servlet 컨테이너가 요청을 올바른 Servlet에 전달해 주기 전에, Filter를 거치게 된다. 그림으로 표현하면, 이런 식이다.
Spring Boot에서 Filter 의 동작 위치
즉, Spring 컨테이너와 무관한 내용들(http 요청)을 로그로 남기기에 적당한 위치라고 볼 수 있다.
Interceptor
Spring MVC Framework 에서 제공하는 기술로, 컨트롤러 실행 전후에 특정 작업을 추가할 수 있도록 하는 구성 요소이다. 다수의 컨트롤러에 대해 동일한 기능을 적용해야 할 때 사용할 수 있는 것이다. 그림으로 표현하면
인터셉터 동작과정
HandlerInterceptor 인터페이스
org.springframework.web.servlet.HandlerInterceptor 인터페이스를 구현하고, Spring 설정에 등록하면 사용할 수 있다.
HandlerInterceptor JavaDoc (Spring Boot v2.7.7)
preHandle
요청이 어떤 핸들러(컨트롤러를 포함하는 상위 개념. 여기선 컨트롤러로 대체해도 무방)로 매핑될지 결정된 후에, 해당 컨트롤러가 실행되기 전에 실행되는 메서드.
true를 반환하면 실행 체인의 다음 단계(다른 인터셉터나 핸들러)가 실행되고, false 를 반환하면 인터셉터가 실행 체인의 다음단계가 아니라 DispatcherServlet 으로 HttpServletRequest, HttpServletResponse 가 넘어간다.
preHandle JavaDoc (Spring Boot v2.7.7)
postHandle
핸들러가 실행된 이후, DispatcherServlet이 View 를 랜더링 하기 전(HttpservletResponse에 응답을 적기 전?)에 실행되는 메서드.
핸들러에서 예외가 던져진경우, 실행되지 않는다.
postHandle JavaDoc (Spring Boot v2.7.7)
afterCompletion
핸들러가 실행된 후 DispatcherServlet이 View 를 랜더링 한 후 실행된다. 실행체인이 종료된 뒤에 실행되므로, 적절한 리소스 정리가 가능하다.
핸들러에서 예외가 발생된경우에도 실행된다.
이 메서드가 속한 인터셉터의 preHandle 메서드가 제대로 실행되고 true 를 반환한 경우에만 실행된다.
afterCompletion JavaDoc (Spring Boot v2.7.7)
컨트롤러 실행 전의 요청, 실행 후의 응답을 로그로 남길때 사용할 수 있다.
Spring AOP
인터셉터가 핸들러의 실행 전후에 공통로직을 추가하는 기술인 반면, Spring AOP는 Spring 컨테이너가 관라하는 모든 Bean 의 실행 전후에 공통로직을 추가할 수 있는 기술이다. 상세한 내용은 다음 포스팅에서 다룰 생각이다.
스프링 컨테이너가 관리하는 Bean 들의 실행 흐름을 추적하는데 아주 적절하다.
AOP vs Interceptor 실행 순서
인터셉터로 프리핸들러가 설정되고, AOP 로 @Around 어노테이션을 적용했다면, 프리핸들러 → AOP → 포스트핸들러 순서로 동작한다.
ExceptionHandler
핸들러에서 발생하는 예외를 처리하는 기술이다. AOP나 인터셉터처럼 공통 로직을 처리하는 기술이지만, 이 것은 오직 예외처리만을 담당하는 기술이다. 따라서, 비즈니스 로직상 처리할 수 없는 예외가 발생할 경우 이 기술을 이용해 공통된 에러 응답을 보낼 수 있다.
핸들러에서 발생한 예외를 추적하는데 아주 적절하다.
중간정리
Table
Search
Spring Bean 실행흐름이나, 비즈니스 로직에서 발생한 예외를 기록하는 것은 저 기술들로 충분하지만,
요청이나 응답을 로그로 남기기 위해서는 HttpServletRequest와 HttpServletResponse 를 이해해야 한다.
HttpServletRequest,HttpServletResponse
각각 Servlet 스팩에서 사용자의 요청과 응답을 다루는 클래스이다.
각각 InputStream과 OutPutStream을 사용한다. 따라서, 이 Stream을 읽어들이면, 로그를 남길 수 있다.
이상한데?
InputStream은 한번 읽은 데이터를 보관하지 않고, OutPutStream 역시 출력한 데이터를 따로 보관하지 않는다. 따라서, 요청을 로그로 남기면 컨트롤러에서 요청을 읽을 수 없는 문제가 생긴다. 응답은 아예 HttpServletResponse 내부에서 로그를 남기는게 아니라면, 로그를 남기는게 불가능해보인다.
이 문제를 해결하려면, HttpServletRequest 내부의 InputStream을 백업해놓는다던지 하는 작업이 필요한데, 이런 작업들을 하는 클래스를 Spring이 제공한다.
ContentCachingRequestWrapper
클래스 이름에서 알 수 있듯이 이 클래스는 요청의 Content를 캐싱하고있다. 캐싱이기 때문에 애플리케이션이 Request의 Content 를 읽은적이 있어야 이 클래스를 통해 요청의 Content를 읽을 수 있다.
예를 들어 아래 코드처럼 사용하면,
@Component
@Slf4j
public class CustomServletWrappingFilter extends OncePerRequestFilter {
@Override
protected void doFilterInternal(HttpServletRequest request, HttpServletResponse response, FilterChain filterChain) throws ServletException, IOException {
ObjectMapper objectMapper = new ObjectMapper();
ContentCachingRequestWrapper wrappingRequest = new ContentCachingRequestWrapper(request);
ContentCachingResponseWrapper wrappingResponse = new ContentCachingResponseWrapper(response);
log.info("필터 처음 = 아직 content를 읽은적 없음"+objectMapper.readTree(wrappingRequest.getContentAsByteArray())+"");
filterChain.doFilter(wrappingRequest, wrappingResponse);
log.info("필터 끝 = content를 읽은적 있음"+objectMapper.readTree(wrappingRequest.getContentAsByteArray())+"");
wrappingResponse.copyBodyToResponse();
}
}
Java
복사
이렇게 처음 Request Content 를 읽은 부분은 로그가 찍히지 않는 것을 알 수 있다.
ContentCachingResponseWrapper
클래스 이름에서 알 수 있듯이 이 클래스는 응답의 Content 를 캐싱하고있다. 당연하게도, 응답을 작성하기 전에는 응답을 읽을 수 없으므로 Filter 를 사용할 경우 후처리에, 인터셉터를 사용할 경우 afterCompletion 에서 읽어야 의미가 있다.
결론
Filter와 Spring AOP, ExceptionHandler 를 이용해 로그를 남겼다.
ResponseLoggerFilter
전체 코드
우선, 각 요청을 구분할 고유 ID 인 uuid 를 생성해 request에 집어넣어주었다.
String uuid = UUID.randomUUID().toString();
request.setAttribute("uuid",uuid);
Java
복사
그 후 이 뒤로 호출될 컨트롤러나 aop 등에서 ContentCachingRequestWrapper ,ContentCachingResponseWrapper 를 사용할 수 있도록 감싸서 전달해주었다.
ContentCachingRequestWrapper wrappingRequest = new ContentCachingRequestWrapper(request);
ContentCachingResponseWrapper wrappingResponse = new ContentCachingResponseWrapper(response);
filterChain.doFilter(wrappingRequest, wrappingResponse);
Java
복사
filterChain.doFilter(wrappingRequest, wrappingResponse); 을 통해 컨트롤러와 AOP 가 실행되고 나서 응답의 로그를 찍어주었다.
ObjectMapper objectMapper = new ObjectMapper();
String type="Response ===> uuid = ";
log.info("{}{} {}",type,uuid,"headers start");
Collection<String> headerNames = response.getHeaderNames();
for (String headerName : headerNames) {
String header = response.getHeader(headerName);
log.info("{}{} {}: {}",type,uuid,headerName,header);
}
log.info("{}{} {}",type,uuid,"headers end");
log.info("{}{}, Response Body : {}",type, uuid, objectMapper.readTree(wrappingResponse.getContentAsByteArray()));
wrappingResponse.copyBodyToResponse();
Java
복사
BusinessLogicLogger
전체 코드
String className = joinPoint.getSignature().getDeclaringTypeName();
String methodName = joinPoint.getSignature().getName();
String type;
if (className.contains("Controller")) {
printRequest();
type = "Controller ";
} else if (className.contains("Service")) {
type = "Service";
} else if (className.contains("Repository")) {
type = "Repository";
} else {
type = "";
}
HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getRequest();
String uuid = (String)request.getAttribute("uuid");
log.info("{} {} {} ===> {}.{}()","Request ===> uuid = ",uuid,type,className,methodName);
Java
복사
Spring AOP 를 이용해 Controller, Service, Repository 의 실행 로그를 찍을 수 있도록 했다.
