AOP(Aspect Oriented Programming) 활용하여 함수 실행시간 로깅 처리해보기
안녕하세요! 세미나 허브 프로젝트를 진행하고 있는 passionfruit200 입니다.
이번 글에서는 세미나 허브 프로젝트를 진행하며, Method의 로깅처리를 직접 해야만 했었던 일을 Spring AOP를 활용한 관심사 분리를 통해 코드를 짧게하고, 손쉽게 처리할 수 있는 방안을 적용하여 글을 작성하게 되었습니다.
아래 그림은 Spring AOP가 필요한 상황을 표현해보았습니다.
1000개의 로깅로직 때문에 개발자의 효율성이 떨어지는것은 막아야합니다.
Spring AOP란 무엇일까?
AOP(Aspect Oriented Programming)는 관점지향 프로그래밍이라는 의미입니다. 이때 관점 Aspect의 단어는 상당히 추상적이기에 직관적으로 이해하기는 어렵습니다. 그렇기에 관점이라는 말 대신에 '관심사(Concern)'라는 말로도 이해할 수 있습니다. '관심사'는 개발 시 개발자가 관심을 가지고서 신경써야 하는 부분들을 의미합니다.
예를 들어, 로깅, 트랜잭션 관리, 보안 등은 여러 모듈에서 공통적으로 발생하는 관심사입니다. AOP를 이용하면 이러한 관심사를 핵심 비즈니스 로직과 분리하여 각 모듈에서 독립적으로 다룰 수 있습니다. 이는 코드의 가독성을 높이고 중복을 줄여줍니다.
그림을 보면, Program Flow와 함께 세미나허브의 회원 API, 세미나 API, 세미나 신청 API의 API에서 주요 핵심로직이 존재합니다.
이 각각의 핵심 로직에서 공통로직이자 횡단관심사인 로깅처리는 핵심 로직이 아닌, 모든 API에 공통으로 들어가는 공통로직이기에 반복된 코드가 들어가면 매우 비효율적인 코드입니다. 개발자에게 있어서 반복된 코드로 인한 효율성 저하는 반드시 고쳐주고 싶은 점입니다.
이러한 공통로직을 Spring에서는 Spring AOP를 활용하여 해결할 수 있도록 도와줍니다.
Spring Filter, Interceptor, AOP 흐름
Spring의 큰 그림에서 HttpRequest에서 HttpResponse로 반환되기까지의 흐름을 아래의 그림으로 표현해보았습니다.
흐름을 단순하게 확인해보면, Request가 Filter -> DispatcherServlet -> Interceptor -> AOP -> Controller ->AOP -> Interceptor -> DispatcherServlet -> Filter ->HttpServletResponse와 같은 흐름으로 이해할 수 잇습니다.
그림상에서 Spring AOP는 Controller에 들어가기 바로 전, 후에 위치하고 있는데요.
그렇기 때문에 로깅로직에 효과적으로 사용될 수 있고, 인증/인가, 트랜잭션에 사용되기에 용이합니다.
코드와 사용되는 간단 예시
이번에는 실제 코드와 함께 로깅/로직을 적용한 예시를 확인해보겠습니다.
지금까지는 Spring을 활용하여 각 함수의 실행시간을 측정할때,
아래와 같이 startTime과 endTime을 모두 구해서 함수의 실행시간을 직접 처리하였습니다.
@DisplayName("dummyInsertWithJdbcTemplate")
@Test
public void dummyInsertWithJdbcTemplate(){
List<Member_SeminarDTO> member_seminarDTOList = new LinkedList<>();
for(int i=1;i<11; i++){
for(int j=1;j<10001;j++){
Member_SeminarDTO memberSeminarDTO = Member_SeminarDTO.builder()
.member_no((long) i)
.seminar_no((long) j)
.build();
member_seminarDTOList.add(memberSeminarDTO);
}
}
Long startTime = System.currentTimeMillis();
memberSeminarQuerydslRepository.jdbcBulkInsert(member_seminarDTOList);
Long endTime = System.currentTimeMillis();
System.out.println("Execution Time:"+ (endTime - startTime) + "ms");
}
Spring AOP를 적용한 이후에는 아래처럼 로깅처리 로직을 제외하고도 로깅이 될 수 있도록 할 수 있습니다.
@DisplayName("dummyInsertWithJdbcTemplate")
@Test
public void dummyInsertWithJdbcTemplate(){
List<Member_SeminarDTO> member_seminarDTOList = new LinkedList<>();
for(int i=1;i<11; i++){
for(int j=1;j<10001;j++){
Member_SeminarDTO memberSeminarDTO = Member_SeminarDTO.builder()
.member_no((long) i)
.seminar_no((long) j)
.build();
member_seminarDTOList.add(memberSeminarDTO);
}
}
memberSeminarQuerydslRepository.jdbcBulkInsert(member_seminarDTOList);
}AOP 의 구성요소 및 작동방식
AOP의 주요 구성 요소로는 Advice(조언), Pointcut(적용 지점), Joinpoint(결합 지점), Target(실제 실행할 메소드)등이 있습니다. AOP는 설명으로만 이해하기 상당히 어렵습니다. 아래의 코드 구현 부를 먼저 보시고서 어떻게 돌아가는지 알고보신다면 이해하는데 도움이 됩니다.
주요 구성에 대해 간략하게 정리하면 다음과 같습니다.
Advice는 관심사를 어떻게 처리할지 정의하고,
Pointcut은 어떤 지점에서 Advice를 적용할지를 정의합니다.
Joinpoint는 코드 실행 중 결합이 일어나는 지점을 나타냅니다. 즉 Target과 결합이 일어나는 부분입니다.
Target은 실제 비즈니스 로직이 실행되는 부분입니다.
조금 더 구체적으로 살펴보면,
- Advice (조언): Advice는 특정 관심사를 어떻게 처리할지를 정의하는 부분입니다. 프로그램 실행 중에 특정 지점에서 실행되어 횡단 관심사를 적용하는 로직을 담고 있습니다. Advice에는 여러 종류가 있으며, 주요한 종류로는
- Before Advice (메서드 실행 전) : Target의 JoinPoint를 호출하기 전에 실행되는 코드입니다. 코드의 실행 자체에는 관여할 수 없습니다.
- After Returning Advice (메서드 실행 후) : 모든 실행이 정상적으로 이루어진 후에 동작하는 코드입니다.
- After Throwing Advice ( 예외 발생 후 ) : 예외가 발생한 뒤에 동작하는 코드입니다.
- After Advice (메서드 후 || 예외발생 후) : 정상적으로 실행되거나 예외가 발생했을때 구분 없이 실행되는 코드입니다.
- Around Advice (메서드 실행 전후에 조작 가능) : 메서드의 실행 자체를 제어할 수 있는 가장 강력한 코드입니다. 직접 대상 메서드를 호출하고 결과나 예외를 처리할 수 있습니다.
- Pointcut (적용 지점): Pointcut은 Advice가 적용될 메서드나 코드의 위치를 정의합니다. 특정 관심사를 어디에 적용할 것인지를 결정하는데 사용됩니다. 메서드 이름, 클래스 이름, 특정 패키지 등과 같은 기준을 사용하여 정의됩니다. Pointcut은 Advice가 적용될 수 있는 지점을 식별하는 역할을 합니다.
- execution(@execution) : 메서드를 기준으로 Point cut을 설정합니다.
- within(@within) : 특정한 타입(클래스)을 기준으로 Pointcut을 설정합니다.
- this : 주어진 인터페이스를 구현한 객체를 대상으로 Pointcut을 설정합니다.
- args(@args) : 특정한 파라미터를 가지는 대상들만을 Pointcut으로 설정합니다.
- @annotation : 특정한 어노테이션이 적용된 대상들만을 Pointcut으로 설정합니다.
- Joinpoint (결합 지점): Joinpoint는 Advice가 적용되는 실제 지점을 나타냅니다. 프로그램 실행 중에 결합이 일어나는 특정 지점이며, 이 지점에서 Advice가 적용됩니다. 메서드 호출, 필드 접근, 예외 발생 등이 Joinpoint의 예시입니다. Advice는 이러한 Joinpoint에서 실행되어 관심사를 처리합니다.
이번글에서는 AOP(Aspect Oriented Programming)을 활용하여 모든 함수의 실행시마다 Paramter를 확인하고, 실행시간을 검사해주는 AOP 로직을 추가해보겠습니다.
일반적으로 Java에서 AOP를 적용하면서는 주로 Service Level에 도입하지만, 이번 글에서는 모든 Controller, Service, Repository에 모든 실행로그를 남겨보는 작업을 진행해보려고 합니다.
코드로 구현해보기
1. Build Gralde에 AOP 적용을 위한 의존성을 추가합니다.
implementation group: 'org.springframework.boot', name: 'spring-boot-starter-aop', version: '3.2.0'
저는 Spring Boot 3.0.2 를 사용하고 있습니다.
2. AOP Class 를 생성
LogAdvice.java
아래의 코드는 스프링 AOP(Aspect-Oriented Programming)를 사용하여 메서드 실행 시간을 로깅하고, 메서드 파라미터와 예외를 처리하는 간단한 로깅 어드바이스(Advice)를 구현한 것입니다.
@Aspect
@Log4j2
@Component
public class LogAdvice {
// @Before( "execution(* com.seminarhub..*(..))")
// public void logBefore(ProceedingJoinPoint proceedingJoinPoint){
// log.info("========================");
// }
@Around( "execution(* com.seminarhub..*(..))")
public Object logTime(ProceedingJoinPoint proceedingJoinPoint){
log.info("========================");
long start = System.currentTimeMillis();
log.info("Target: " + proceedingJoinPoint.getTarget());
log.info("Param: " + Arrays.toString(proceedingJoinPoint.getArgs()));
//invoke Method
Object result = null;
try{
result = proceedingJoinPoint.proceed();
} catch (Throwable e){
e.printStackTrace();
}
long end = System.currentTimeMillis();
log.info("TIME: "+ ( end - start ));
return result;
}
@AfterThrowing(pointcut = "execution(* com.seminarhub..*(..))", throwing = "exception")
public void logException(Exception exception){
log.info("Exception Found");
log.info("exception: "+exception);
}
}
아래는 코드의 로직 설명입니다:
- @Aspect: 이 어노테이션은 해당 클래스가 Aspect 역할을 한다는 것을 나타냅니다. Aspect는 여러 관심사를 모듈화하고, 각 관심사를 각각의 모듈로 분리하는 프로그래밍 패러다임입니다.
- @Log4j2: Lombok 어노테이션으로, Log4j2 로깅을 위하여 사용합니다.
- @Component: 스프링에게 해당 클래스를 빈으로 등록하라는 표시입니다. 이로써 스프링 컨테이너는 이 클래스를 관리하고 필요한 곳에서 주입할 수 있습니다.
- @Around: 이 어드바이스는 대상 메서드를 감싸고, 메서드 실행 전과 후에 추가적인 동작을 수행합니다. 여기서는 메서드 실행 전에 시작 시간을 기록하고, 실행 후에 종료 시간을 기록하며, 실행에 걸린 시간을 로깅합니다.
- ProceedingJoinPoint: AOP에서 조인 포인트(Join Point)를 나타내는 객체입니다. 조인 포인트는 프로그램의 실행 중 특정한 지점을 나타냅니다. @Around 어드바이스에서는 proceed() 메서드를 호출하여 대상 메서드의 실행을 계속합니다.
- 로깅 및 시간 측정:
- log.info("========================");: 간단한 구분선을 로깅합니다.
- System.currentTimeMillis(): 현재 시간을 밀리초 단위로 가져옵니다.
- proceedingJoinPoint.getTarget(): 대상 메서드가 속한 객체를 가져옵니다.
- proceedingJoinPoint.getArgs(): 대상 메서드의 인자들을 가져옵니다.
- 예외 발생 시 @AfterThrowing 어드바이스에서는 예외를 로깅합니다.
메서드의 실행 시간이나 파라미터를 로깅해보겠습니다. 이를 통해 이전에 직접적으로 Test코드에서 시간을 작성하는 코드를 자동화할 수 있습니다.
2. 테스트를 위해 Service Class 생성
SeminarService.java
간단하게 str을 입력받고 출력하는 Service 클래스를 생성했습니다.
public interface SeminarService {
/**
* Description : AOP Test
*
*/
String printOutString(String str);
}
SeminarServiceImpl.java
printOutString을 구현합니다.
@Service
@Log4j2
@RequiredArgsConstructor
public class SeminarServiceImpl implements SeminarService{
@Override
public String printOutString(String str){
if (str == null || str.isEmpty()) {
throw new IllegalArgumentException("Input string should not be null or empty");
}
return str;
}
}
위의 코드에서 str == null, str.isEmpty 일경우 에러를 발생하도록 처리했습니다.
이는 이후에 AOP에서 적용하는 에러처리도 함께 적용해보기 위해 넣어본 것 입니다.
3. 테스트를 위한 SeminarServiceTests 클래스
SeminarServiceTests.java
@SpringBootTest
public class SeminarServiceTests {
@Autowired
private SeminarService seminarService;
@Test
public void testClass(){
System.out.println(seminarService.printOutString("helloAOP"));
// System.out.println(seminarService.printOutString(""));
}
}
아래의 코드를 통해 우리가 실행하는 객체의 정보와 Parameter, Time을 모두 계산하는 모습을 볼 수 있습니다.
에러 발생상황.
@SpringBootTest
public class SeminarServiceTests {
@Autowired
private SeminarService seminarService;
@Test
public void testClass(){
System.out.println(seminarService.printOutString("helloAOP"));
System.out.println(seminarService.printOutString(""));
}
}추가적으로 만약 str에 "" 값을 넣어둔다면 에러 처리를 하게됩니다.
마무리
이로써 AOP를 활용하여 기본적인 로깅처리를 진행해보았습니다.
실무에서 정말 많은 함수들이 사용될텐데 이떄 이 AOP를 활용하여 각 함수들의 장애처리나 실행시간을 AOP라는 일종의 인터셉터로 한번에 관심사를 횡단분리하여 처리하니, 매우 효과적인 방식입니다.
앞으로 코드에서 시간 계산이 필요할떄 불필요한 코드가 필요없어져서 좋습니다.