Java Springboot AOP를 통한 로그 출력 및 파일화(메서드 이름을 활용)

 

이 글에서는 Springboot 프로젝트를 진행하면서 AOP를 통해 로그 출력을 하는 과정을 담았다. AOP에 대한 개념적인 부분은 별도의 참고 URL로 표기하였고 활용 위주로 작성하였다.

 

글을 작성하기 전 간단하게 AOP를 통해 로그 처리를 한 소감을 말하자면 정말 말도 안 되게 유용한 기능이라고 생각한다. 처음에는 그냥 메서드마다 로직 사이에 log.info를 추가하기만 하면 되는 것을 뭐 하러 코드까지 늘리면서 다른 AOP 클래스를 생성할까? 하고 의구심이 들었다.

하지만 구현해놓고 수정할 일이 있어 메서드를 수정할 때 log출력에 관한 부분은 하나도 신경을 쓰지 않고 메인 로직을 수정할 수 있었다. 이게 AOP를 사용하는 진정한 장점이라는 것을 깨달았다.

다음 프로젝트에서도 계속 AOP를 통해 로그처리를 계속해야겠다고 생각했다.

 

들어가기

서비스에서 가장 중요한 것 중 하나는 로그를 저장하는 것이다. 사용자가 어떤 행동을 했는지 기록을 해둬야 나중에 문제가 생기지 않기 때문이다.

하지만 개발자들은 주요 로직을 작성하면서 로그까지 신경쓰고 싶지가 않을 것이다. 이럴 때 필요한 것이 AOP(Aspect-Oriented Programming)이다. AOP는 관점 지향 프로그래밍으로 주요 로직으로부터 관심사를 분리하여 개발하는 것이다. 즉, 주요 로직을 개발하면서 외부 관심사를 신경 쓸 필요가 없고, 관심사들은 별도로 구현하는 것이다. 관심사는 Aspect이며 이는 추상적인 개념이고 이를 구현한 코드가 Advice이다. 

AOP에 대한 자세한 내용은 https://khdscor.tistory.com/44를 참고하길 바란다. 

이 글에서는 게시글 작성, 삭제, 수정 등 비지니스 메서드 이름으로 무엇을 실행하는지 구분하고 회원번호, 게시글 번호를 활용하여 하나의 log 출력 하나의 Advice로 진행할 예정이다.

메서드를 진행하면 아래와 같이 로그가 출력될 것이다. 

 

 AOP 설정

우선 AOP 설정을 하여 주된 로직에 붙일 파일을 작성할 것이다. 실제 프로젝트에 적용한 것을 설명할 것이고, controller 실행 전후로 로그를 출력하도록 할 것이다. 우선 아래와 같이 어노테이션을 설정한다.

@Aspect
@Component
@Slf4j
public class ArticleLogAdvice {
}

 

@Aspect는 Aspect(관심사)들을 작성할 수 있도록 하는 어노테이션이다. @Component는 bean으로 등록해 주고 Slf4j는 로그분석 프레임워크인 logback의 기능 중 하나로 별도로 추가하지 않아도 바로 어노테이션을 사용 가능하다.

 

 

PointCut 설정

Pointcut는 어떤 관심사를 어느 위치에 결합할 것인지를 결정하는 설정이다. Pointcut은 다양한 형태로 선언해서 사용될 수 있는데 주로 사용되는 설정 아래와 같다.

• execution(@execution): 메서드를 기준으로 Pointcut를 설정한다.
• within(@within): 특정한 타입(클래스)을 기준으로 Pointcut을 설정한다.
• this: 주어진 인터페이스를 구현한 객체를 대상으로 Pointcut을 설정한다.
• args(@args): 특정한 파라미터를 가지는 대상들만을 Pointcut으로 설정한다.
• @annotation: 특정한 어노테이션이 적용된 대상들만을 Pointcut으로 설정한다. 

 

나는 어노테이션 방식을 선택하였다. AOP 클래스에 아래와 같이PointCut를 만들어두자.

 @Pointcut("@annotation(foot.footprint.global.aop.article.ArticleLog)")
    public void articleLogRecord() {
    }

 

위 코드를 보면 @annotation 다음 괄호에 어노테이션을 지정해 두면, 해당 어노테이션을 붙인 대상들에 AOP 로직을 발생시킨다. 그런데 ArticleLog라는 어노테이션이 springboot에 존재하는 것인가? 

아니다. AriticleLog은 직접 제작한 커스텀 어노테이션이다. 

 

커스텀 어노테이션 구현

어노테이션을 커스텀할 때 필요한 것은 meta-annotation이다. meta-annotation는 다른 어노테이션에서도 사용되는 annotation이며 아래의 코드에선 @Retention과 @Target가 이에 해당한다.

//AOP를 위해 생성한 커스텀 어노테이션
@Retention(RetentionPolicy.RUNTIME)
@Target(ElementType.METHOD)
public @interface ArticleLog {

}

//아래는 자주사용하는 service 어노테이션
@Target(ElementType.TYPE)
@Retention(RetentionPolicy.RUNTIME)
@Documented
@Component
public @interface Service {

	...
}

 

@Target 은 Java compiler 가 annotation 이 어디에 적용될지 결정하기 위해 사용된다.

예를 들어 위에서 사용한 @Service 의 ElementType.TYPE 은 해당 Annotation 은 타입 선언 시 사용한다는 의미이며  TYPE은 클래스 / 인터페이스 / 열거 타입(enum)을 뜻한다.

그리고 커스텀 어노테이션 @ArticleLog에서는 METHOD를 사용했는데 이는 메서드 선언 시 사용한다는 의미이다.

기타 종류는 아래와 같다.

ElementType.PACKAGE : 패키지 선언
ElementType.TYPE : 타입 선언(클래스/인터페이스/Enum)
ElementType.ANNOTATION_TYPE : 어노테이션 타입 선언
ElementType.CONSTRUCTOR : 생성자 선언
ElementType.FIELD : 멤버 변수 선언
ElementType.LOCAL_VARIABLE : 지역 변수 선언
ElementType.METHOD : 메서드 선언
ElementType.PARAMETER : 전달인자 선언
ElementType.TYPE_PARAMETER : 전달인자 타입 선언
ElementType.TYPE_USE : 타입 선언

 

@Retetion는 Annotation이 실제로 적용되고 유지되는 범위를 의미한다. 일반적으로 컴파일 이후에도 JVM에서 참조가 가능한 RUNTIME으로 지정한다.

종류는 아래와 같다.

RetentionPolicy.RUNTIME
RetentionPolicy.SOURCE
RetentionPolicy.CLASS

 

RetentionPolicy.RUNTIME는 컴파일 이후에도 JVM에 의해서 계속 참조가 가능하다. 이름 그대로 런타임 때도 계속 유지된다.

RetentionPolicy.SOURCE 은 컴파일 전까지만 유효하다. 즉, 컴파일 이후에는 사라지게 된다. 이름 그대로 소스파일 즉,. java 파일로서만 유지가 되고 런타임 중에는 유지되지 않는다. 예를 들어 @Getter나 @AllArgContructor는. java 상에서는 어노테이션이 존재하지만 컴파일한 후에는 어노테이션이 사라지고 get메서드와 생성자 코드가 추가되는 것이다.

RetentionPolicy.CLASS는 컴파일러가 클래스 파일까지만 유효하다. SORUCE와 큰차이가 있나 싶은데 

https://jeong-pro.tistory.com/234 의 첫 댓글에서 자세한 설명이 나와있다. 예를 들면 CLASS로 하는 것 중 Lombok 중 @NonNull 이란 것이 있다. 이 어노테이션을 부착한 필드에는 null 값을 넣으면 안 되는 것이다. 우리가 알아야 할 점은 Maven/Gradle로 다운받은 라이브러리와 같이 jar 파일에는 소스가 포함되어있지 않다는 점이다. class 파일만 포함되어었다.  즉, class 파일만 존재하는 라이브러리 같은 경우에도 타입체커, IDE 부가 기능 등을 사용하기 위해서는 CLASS 정책이 필요하다. SOURCE 정책으로 사용한다면 컴파일된 라이브러리의 jar 파일에는 어노테이션 정보가 없기 때문이다.

 

이렇게 @Target와 @Retetion을 붙여서 간단한 커스텀 어노테이션을 작성하였다. 이를 기반으로 Pointcut도 작성을 하였으므로 이제 Pointcut이 위치하는 곳(여기서는 지정한 어노테이션이 붙여진 메서드)에서 동작 위치(주요 로직의 전, 후 등)와 내용을 추가해야 한다.

 

Advice 작성

관심사는 Aspect이며 이는 추상적인 개념이고 이를 구현한 코드가 Advice이다. 

아래의 코드를 봐보자.

@Around("articleLogRecord()")
    public Object articleLogRecord(ProceedingJoinPoint pjp) throws Throwable {
       
    }

 

@Around 안에 위에서 설정한 pointcut 메서드 명을 담았다. 지정한 pointcut를 적용한다는 것이고

Advice는 동작 위치에 따라 아래와 같이 구분한다.

• Before Advice: Target의 JoinPoint를 호출하기 전에 실행되는 코드이다. 실행 자체에는 관여할 수 없다.
• After Returning Advice: 모든 실행이 정상적으로 이루어진 후에 동작하는 코드이다.
• After Throwing Advice: 예외가 발생한 뒤에 동작하는 코드이다.
• After Advice: 정상적으로 실행되거나 예외가 발생했을 때 구분 없이 실행되는 코드이다.
• Around Advice: 메서드의 실행 자체를 제어할 수 있는 가장 강력한 코드이다. 직접 대상 메서드를 호출하고 결과나 예외를 처리할 수 있다.

즉, @Around는 코드 내에서 pointcut에서 지정한 비즈니스 메서드를 직접 실행하는 것이기에 메서드 실행 전과 후에 로그를 출력할 수 있다. 

매개변수에 ProceedingJoinPoint 객체가 무엇인지 궁금할 수 있다.

 

Around Advice 메서드에서 비즈니스 메서드 호출을 무조건 해야 한다. Around Advice가 비지니스 호출을 가로챘기 때문에 Around Advice에서 비지니스 호출을 해 주지 않으면 비지니스 메서드는 실행이 않되는 것이다. 그렇다면 Around Advice 내에서 비지니스 메서드의 정보를 가지고 있어야 하는데, 이 정보를 스프링 컨테이너가 Around Advice 메서드로 넘겨준다. 그것이 ProceedingJoinPoint 객체이다.

 

아래와 같이 pjp.proceed()를 실행하면 비지니스 메서드가 실행이 되는 것이고 실행한 결과 값이 value 값에 담기는 것이다. 마지막에 이를 리턴하면 된다. 

Object value = pjp.proceed();
return value;

 

이제 Advice 코드를 작성해 보자. 

비지니스 메서드 실행 전 "회원 (회원 번호)가 게시글 (게시글 번호)에 (비즈니스 메서드 이름)을 시도하였습니다." 로그를 출력하고 실행 후 "회원 (회원번호)에 의해 게시글 (게시글 번호)에 (비지니스 메서드 이름)가 실행되었습니다."를 출력하고 싶다. 그래서 메서드 실행 중 에러가 생기면 시도하였다는 로그만 출력되고 에러메시디가 출력이 될 것이다. 

여기서 동적인 부분은 '회원 번호', '게시글 번호', '비즈니스 메서드 이름'이다. 어느 회원이 어느 게시글에 무엇(메서드 이름)을 실행하는 지이다.

여기서 중요한 것이 ProceedingJoinPoint 객체이다.

 

먼저 확인할 부분은 메서드의 이름이다.

MethodSignature signature = (MethodSignature) pjp.getSignature();
Method method = signature.getMethod();
String name = method.getName();

ProceedingJoinPoint  객체 pjp에서 MethodSignature을 추출한다. signature는 메서드의 정보를 가지고 있고 이러한 메서드는 리턴타입, 이름, 매개변수 등 메서드의 정보를 가지고 있기에 실행하는 비즈니스 메서드의 이름을 얻을 수 있다. 

 

그다음은 회원 번호와 게시글 번호를 확인해야 한다. 그전에 우선 비즈니스 메서드의 request부분을 봐보자.

@ArticleLog
@DeleteMapping("/{articleId}")
public ResponseEntity<Void> deleteArticle(@PathVariable Long articleId,
    @AuthenticationPrincipal CustomUserDetails userDetails) {
    deleteArticleService.delete(articleId, userDetails.getId());

    return ResponseEntity.noContent()
        .build();
}

 

request 부분은  accessToken으로 받는 accessToken과 articleId이다. 이 정보들을 Around로 가져올 것이다. 

	MethodSignature signature = (MethodSignature) pjp.getSignature();
	Method method = signature.getMethod();
	Long memberId = null;
        Long articleId = null;
        Object[] parameterValues = pjp.getArgs();
        for (int i = 0; i < parameterValues.length; i++) {
            if (method.getParameters()[i].getName().equals("articleId")) {
                articleId = (Long) parameterValues[i];
                continue;
            }
            if (method.getParameters()[i].getName().equals("userDetails")) {
                CustomUserDetails userDetails = (CustomUserDetails) parameterValues[i];
                if (userDetails != null) {
                    memberId = userDetails.getId();
                }
            }
        }

 

위에서 설명했다시피 method는 메서드의 정보를 가지고 있기 때문에 method의 매개변수 정보를 가지고 있다. 그리고 pjp.getArgs()를 통해 매개변수의 실제 값을 가져온다. for문으로 반복 시 각각의 정보의 순서는 동일하기에 하나의 for문으로 해결할 수 있다.

for 문으로 매개변수들 중 원하는 이름을 찾고 각각의 값을 미리 지정한 값에 저장하면 끝이다. 

 

마지막으로 확인할 것은 로그 출력 및 비즈니스 메서드 실행 부분이다. 

	log.info("회원번호 " + memberId + "가 " + "게시글 " + articleId + "에 " + method.getName()
            + "를 시도하였습니다.");
        Object value = pjp.proceed();
        log.info("회원번호 " + memberId + "에 의해 " + "게시글 " + articleId + "에 " + method.getName()
            + "가 실행되였습니다.");
        return value;

 

pjp.proceed()를 통해 비지니스 메서드를 실행해 주고 주어진 정보를 통해 메서드 실행 전과 후에 로그를 출력하도록 하였다. 그리고 value 값을 리턴하는 것으로 Around 코드를 모두 작성하였다. 

 

아래는 전체적인 코드이다. 

@Aspect
@Component
@Slf4j
public class ArticleLogAdvice {

    @Pointcut("@annotation(foot.footprint.global.aop.article.ArticleLog)")
    public void articleLogRecord() {
    }

    @Around("articleLogRecord()")
    public Object articleLogRecord(ProceedingJoinPoint pjp) throws Throwable {
        Object[] parameterValues = pjp.getArgs();
        MethodSignature signature = (MethodSignature) pjp.getSignature();
        Method method = signature.getMethod();
        Long memberId = null;
        Long articleId = null;
        for (int i = 0; i < parameterValues.length; i++) {
            if (method.getParameters()[i].getName().equals("articleId")) {
                articleId = (Long) parameterValues[i];
                continue;
            }
            if (method.getParameters()[i].getName().equals("userDetails")) {
                CustomUserDetails userDetails = (CustomUserDetails) parameterValues[i];
                if (userDetails != null) {
                    memberId = userDetails.getId();
                }
            }
        }
        log.info("회원번호 " + memberId + "가 " + "게시글 " + articleId + "에 " + method.getName()
            + "를 시도하였습니다.");
        Object value = pjp.proceed();
        log.info("회원번호 " + memberId + "에 의해 " + "게시글 " + articleId + "에 " + method.getName()
            + "가 실행되였습니다.");
        return value;
    }
}

 

 

출력 결과

아래는 실행된 화면이다. edit(수정)과 delete(삭제)를 실행해 보았다.

 

예외가 발생하면 아래와 같이 시도하였다는 로그만 출력되고 throw로 지정한 메시지가 출력될 것이다. 

 

 

위의 예시대로만이 아니라 다른 방식을 로그를 출력할 수도 있다. 아래는 글쓰기 예시이다.

 

request에서 작성한 글의 제목을 가져온 것이다.

 

 

 

 

참고자료

https://velog.io/@kiiiyeon/스프링부트-AOP를-구현하여-Log-남겨보기

[스프링부트] AOP를 구현하여 Log 남겨보기

 

https://shinsunyoung.tistory.com/67

SpringBoot의 AOP을 이용해서 로그 남기기

 

https://alwayspr.tistory.com/34

AOP에 걸린 Method의 Parameter 이름 가져오기

 

https://sanghye.tistory.com/39

[Spring] Meta Annotation 이란?(@Target, @Retention)

 

https://pgnt.tistory.com/103

[SpringBoot] AOP AspectJ @Aspect 적용하기 @Pointcut, @Around, @Before, @AfterReturning, @After, @AfterThrowing, example code