Spring AOP를 사용하여 @Slf4j 로 로깅하기

도비·2023년 10월 28일
Slf4jSpring boot
0

Spring Boot

목록 보기
4/13
post-thumbnail

이 글에서는 Slf4j와 Logback을 사용하여 로깅을 하는 것을 기록합니다.
사이드 프로젝트를 진행하면서 리퀘스트 리스폰스 객체를 nohup파일에 들어가서 보는 것이 번거로웠고, 객체 자체를 로깅할 수 있으면 좋겠다라는 생각을 했다. 그래서 구현하게 된 로깅!! 지금부터 시작합니다.

AOP 간단히 살펴보기

Spring AOP는 런타임 시점에 적용하는 방식을 사용한다.
런타임 시점에 AOP를 적용한다는 것은 컴파일, 클래스 로딩, main() 메서드의 실행 이후에 자바가 제공하는 범위 내에 부가 기능을 적용하는 방식이다.
프록시를 통해 부가 기능을 적용하며, 프록시는 메서드 실행 시점에서만 다음 타겟을 호출할 수 있기 때문에 런타임 시점에 부가 기능을 적용하는 방식은 메서드의 실행 시점으로 제한된다.

Spring AOP 용어 및 개념

  • Aspect
    공통 기능
    어드바이스 + 포인트 컷을 모듈화한 애플리케이션의 횡단 기능
  • Joint Point
    애플리케이션 실행 흐름에서의 특정 포인트
    AOP를 적용할 수 있는 모든 지점(스프링에서는 메서드 실행 지점으로 제한)
  • Advice
    조인포인트에서 실행되는 코드 즉 부가기능
    Aspect를 언제 핵심 코드에 적용할 지 정의
    - Before 조인포인트 실행 이전에 실행, 일반적으로 리턴타입 void
    - After returning 조인포인트 완료후 실행 (ex. 메서드가 예외없이 실행될 때)
    - After Throwing 메서드가 예외를 던지는 경우 실행
    - After (finally) 조인포인트의 동작과 관계없이 실행
    - Around 메서드 호출 전후에 수행(조인포인트 실행 여부 선택, 반환 값 변환, 예외 변환, try~catch~finally 구문 처리 가능 등), 가장 강력한 어드바이스이다.
  • Pointcut
    조인포인트 중 어드바이스가 적용될 지점을 선별하는 기능
    주로 AspectJ 표현식으로 지정한다.
  • Target
    - 핵심 기능을 담을 모듈 (부가 기능 부여 대상)
    • Advice를 받는 객체이고, 포인트 컷으로 결정된다.
  • Advisor
    스프링 AOP에서만 쓰는 용어로, 하나의 어드바이스와 하나의 포인트컷으로 구성된 에스팩트를 특별하게 지칭하는 말이다

Slf4j

Slf4j는 Simple Loggin Facade for Java의 약자로 라이브러리 인터페이스 역할이다. Logback은 실질적인 로깅 라이브러리 구현체로, Slf4j는 Logback을 사용하기 쉽게 포장하는 역할을 한다.

Slf4j는 퍼사드 패턴(Facade Pattern) 및 추상화를 통해 로깅 기능을 제공한다.

퍼사드 패턴이란, 어떤 서브시스템의 일련의 인터페이스에 대한 통합된 인터페이스를 제공해주는 패턴. 퍼사드에서 고수준 인터페이스를 정의하기 때문에 서브시스템을 더 쉽게 사용할 수 있음.

Slf4j를 사용함으로서 기존에 사용하는 로깅 시스템을 교채하고 싶을 떄, 소스 코드를
수정하지 않고도 gradle, maven의 의존성 설정만 바꾸면 손쉽게 적용할 수 있다.

구현하기

dependency 추가


	implementation 'org.springframework.boot:spring-boot-starter-aop'

@EnableAspectJAutoProxy 추가

Application 클래스 위에 어노테이션을 붙여준다.

LoggingAspect 클래스 생성

@Aspect
@Component
@Slf4j
public class LoggingAspect {
...
}

Pointcut 설정 - 특정 기능을 적용시킬 그룹을 설정

@Pointcut("execution(* {폴더경로}.controller..*(..)) || execution(* {폴더경로}.common.advice..*(..))")
public void controllerExecute() {
    }

controller가 호출당할 때와, 에러를 처리하는 controller adivce에서 이 기능을 적용시키기 위해 다음과 같이 작성했다.

Around 적용

위에 언급한 것처럼, Around는 메서드 호출 전후에 수행을 하게 해주는 Aspect 적용 기법이다.
위에 controller가 실행될 때 적용해주기로 pointcut을 적용해놨으니, 이렇게 작성하면 된다.

 @Around("{폴더경로}.LoggingAspect.controllerExecute()")
public Object requestLogging(ProceedingJoinPoint proceedingJoinPoint) throws Throwable {
      //...
}

여기서 전달받는 ProceedingJointPoint가 뭘까?

public interface ProceedingJoinPoint extends JoinPoint {

위와 같이 ProceedingJointPoint는 JointPoint를 상속받은 객체이다.
ProceedingJointPoint는 Around에서만 지원되는 joinPoint이다.
우리는 response객체를 로깅하기 위해 후에 이 ProceedigJoinPoint 를 이용해볼 것이다.
이렇게 로깅을 위한 AOP 적용은 끝났다.

이제 세부사항을 정의해보자.

리퀘스트 로깅하기

Request 로깅을 위에서 정의해준 메소드 한 곳에서 처리하려고 한다. 단순히 스프링 내부에서 로깅을 해주면 HTTP는 Spring 외부 영역에서 시작하는, 웹 서버 레이어에서 일어나는 작업이기 때문에 만약 Spring 내부 Aspect를 실행하기 전에 오류가 난다면 HTTP 요청 로그를 남기지 못하게 된다.

그래서 우리는 Filter에서 HTTP 로그를 남길 것이다.

그러면 HTTP에 접근하려면 어떻게 해야할까?

  1. TeeFilter
    Logback에서 지원하는 TeeFilter는 HTTP Request와 Response를 로깅해준다. 하지만 공식 문서에서 해당 Filter를 실 운영환경에서의 사용을 권장하고 있지 않기 때문에 적용하지는 않았다.

  2. HandlerInterceptorAdapter
    참고로 Spring 5.3 이후부터는 Deprecated 되었으므로 직접 HandlerInterceptor 또는 AsyncHandlerInterceptor를 구현해야한다.
    하지만 HandlerInterceptorAdapter는 한번 읽어들인 HTTP Request가 소비되어 사라진다는 점에서 로깅을 남기는 목적으로는 적합하지 않다. 이렇게 되면 Controller에서 Request를 받지 못해 오류가 난다.

  1. ContentCachingRequestWrapper
    ContentCachingRequestWrapper를 사용해 Logging Filter를 만든다면 HTTP Request를 여러 번 읽어들일 수 있다.

우선 이 Wrapper 클래스를 이용해 Filter를 등록해준다.

@Component
public class CustomServletWrappingFilter extends OncePerRequestFilter {
    @Override
    protected void doFilterInternal(final HttpServletRequest request,
                                    final HttpServletResponse response,
                                    final FilterChain chain) throws ServletException, IOException {
        ContentCachingRequestWrapper requestWrapper = new ContentCachingRequestWrapper(request);
        ContentCachingResponseWrapper responseWrapper = new ContentCachingResponseWrapper(response);

        chain.doFilter(requestWrapper, responseWrapper);

        responseWrapper.copyBodyToResponse();
    }
}

OncePerRequestFilter를 상속받아 한 request당 한번의 실행만 되도록 보장하였다. spring bean으로 등록해두면 Filter 적용은 끝난다.
wrappingResponse.copyBodyToResponse()로 실제 response body에다가 값을 넣어주어야 한다. 이 코드를 안넣어주면 클라이언트가 아무 응답도 받지 못하게 된다.

그리고 우리는 이 필터를 등록해줘야하는데,
HttpRequestConfig 파일을 통해 필터로 등록해준다.

@Configuration
public class HttpRequestConfig {
    @Bean
    public FilterRegistrationBean reReadableRequestFilter() {
        FilterRegistrationBean filterRegistrationBean = new FilterRegistrationBean(new CustomServletWrappingFilter());

        filterRegistrationBean.setUrlPatterns(Arrays.asList("/*"));
        return filterRegistrationBean;
    }
}

/* -> 모든 url에 대한 요청에 필터를 등록한다.

필터를 구현하고 등록해주었다면, 이제 로깅을 할 차례이다.

위에 만들어주었던 requestLogging()메서드 내부에 HttpServletRequest를 받아오고 CachingWrapper클래스로 전환해준다음, ObjectMapper를 통해 리퀘스트를 변환하는 코드를 추가한다. 

HttpServletRequest request = ((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getRequest();
final ContentCachingRequestWrapper cachingRequest = (ContentCachingRequestWrapper) request;
long startAt = System.currentTimeMillis();
Object returnValue = proceedingJoinPoint.proceed(proceedingJoinPoint.getArgs());
//proceedingJoinPoint의 proceed를 활용해 result를 받아온다.
long endAt = System.currentTimeMillis();
log.info("================================================NEW===============================================");
log.info("====> Request: {} {} ({}ms)\n *Header = {}", request.getMethod(), request.getRequestURL(), endAt - startAt, getHeaders(request));
if ("POST".equalsIgnoreCase(request.getMethod())) {
//	post 요청일 경우 body 로깅
	log.info("====> Body: {}", objectMapper.readTree(cachingRequest.getContentAsByteArray()));
}
if (returnValue != null) {
      log.info("====> Response: {}", returnValue);
}
log.info("================================================END===============================================");
return returnValue;

이제 이렇게 로그가 찍히면 "다"가 아니고!
우린 로그를 찍어 파일로 저장을 해야한다.

logback-spring.xml 파일을 통한 로깅 설정

logback-spring.xml 파일은 로그성 데이터에 대한 상세 설정이 필요할 때 사용되는 파일이다. 스프링 부트는 src/main/resources 경로에 있는 해당 파일을 참조해서 로그에 대한 설정을 하게 된다.

이때, 스프링 부트에서 로깅 관련 설정을 읽어 들이는 순서를 알아보자.

  1. classpath(resources 디렉터리 아래)에 logback-spring.xml 파일이 있으면 해당 파일의 설정을 읽는다.
  2. logback-spring.xml 파일이 없는 경우 .properties(또는 .yml) 파일의 설정을 읽는다.
  3. logback-spring.xml 파일과 .properties(또는 .yml) 파일이 동시에 있을 경우 .properties(또는 .yml) 파일의 설정이 적용된 후 logback-spring.xml 파일의 설정이 적용된다.

로그의 레벨은 아래와 같으며, 지정된 레벨 이하의 메서드 호출은 기록되지 않는다.
TRACE < DEBUG < INFO < WARN < ERROR
예를 들어 INFO 레벨로 지정한 로거는 INFO, WARN, ERROR 로그만 기록하게 된다.

참고해서 logback-spring.xml파일을 작성해보자.

<configuration>
    <timestamp key="BY_DATE" datePattern="yyyy-MM-dd"/>
  	<!-- 로깅 테마 -->
    <property name="LOG_PATTERN"
              value="[%d{yyyy-MM-dd HH:mm:ss}:%-4relative] %green([%thread]) %highlight(%-5level) %boldWhite([%C.%M:%yellow(%L)]) - %msg%n"/>

    <springProfile name="local">
        <include resource="console-appender.xml"/>
		<!-- 로컬 서버에서는 appender를 통해 콘솔에 출력-->
        <root level="INFO">
          	<!-- ref="appender name(CONSOLE) 지정" -->
            <appender-ref ref="CONSOLE"/>
        </root>
    </springProfile>

  	<!-- 로컬이 아닌 서버에서는(즉 배포 서버 set1, set2) appender를 통해 파일에 저장-->
    <springProfile name="!local">
        <include resource="file-info-appender.xml"/>
        <include resource="file-error-appender.xml"/>

        <root level="INFO">
            <appender-ref ref="FILE-INFO"/>
            <appender-ref ref="FILE-ERROR"/>
        </root>
    </springProfile>

</configuration>

그리고 console-appender.xml는 다음과 같다.
이 xml파일은 로컬에서 서버를 구동할 때 로그를 콘솔에 찍어주기 위함이다.

<included>
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>${LOG_PATTERN}</pattern>
        </encoder>
    </appender>
</included>

그리고 배포서버에서 요청과, error 로그를 저장하기 위한 xml파일은 다음과 같다.
file-info-appender.xml

<appender name="FILE-INFO" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>/home/ubuntu/app/logs/info/info-${BY_DATE}.log</file>
        <filter class = "ch.qos.logback.classic.filter.LevelFilter">
            <level>INFO</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <encoder>
            <pattern>${LOG_PATTERN}</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern> /home/ubuntu/app/logs/info/info-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <maxHistory>30</maxHistory>
            <totalSizeCap>3GB</totalSizeCap>
            <maxFileSize>10MB</maxFileSize>
        </rollingPolicy>
    </appender>
</included>

file-error-appender.xml

<included>
  <!-- 에러의 경우 파일에 로그 처리 -->
    <appender name="FILE-ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
 		<!--로그파일의 위치 정의-->
      <file>/home/ubuntu/app/logs/error/error-${BY_DATE}.log</file>
        <filter class = "ch.qos.logback.classic.filter.LevelFilter">
            <level>ERROR</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <encoder>
            <pattern>${LOG_PATTERN}</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern> /home/ubuntu/app/logs/error/error-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
          <!-- 로그파일들의 총 용량, 보관 기간 제한 -->
            <maxHistory>30</maxHistory>
            <totalSizeCap>3GB</totalSizeCap>
            <maxFileSize>10MB</maxFileSize>
        </rollingPolicy>
    </appender>
</included>

정리해보자면,
Logback 구성 파일의 기본적인 구조는 크게 appender, logger, root로 나뉜다.

Appender

'Appender'는 로그의 형태를 설정하는 것으로 로그 메시지를 콘솔에 출력할 것인지, 파일에 출력할 것인지에 대한 출력 대상과 함께 세부적인 설정이 담기게 된다.
Logback은 로그 이벤트를 쓰는 작업을 Appender에게 위임한다.
Appender는 로그 메시지가 출력될 대상을 결정하는 요소이며 ConsoleAppender, FileAppender, RollingFileAppender 등이 있다.

Logger

'Logger'는 appender-ref 요소를 포함할 수 있으며, appender-ref를 통해 참조된 Appender를 해당 로거에 추가하는 방식이다.

root

Logger가 특정 역영에 대한 로깅을 설정하는 것이라면 'Root'는 전체 영역에 대한 로깅 설정을 하는 것으로 Logger의 상위에 있다고 볼 수 있다.
(Logger는 여러 개를 가질 수 있지만 Root는 최대 하나만 가질 수 있음)

xml 파일에 관해서는 아래 링크를 통해 더 자세히 알아보면 좋을 것 같다!
https://wildeveloperetrain.tistory.com/302

profile
도비
하루에 한 걸음씩
이전 포스트

@Transactional 어노테이션 🔫 정리

다음 포스트

스프링 빈과 관련하여..

0개의 댓글