[Spring] AOP, Custom Annotation으로 코드 성능 측정하기

문제 상황

• 개발을 하다보면 코드 성능을 측정해야하는 경우가 생깁니다. 그리고 가장 보편적인 경우는 코드의 수행시간을 측정하는 것입니다.
• 기존에는 직접 코드 내에 성능 측정 로직을 작성하여 이를 측정하고 있었습니다.

@Test 
public void testLikeRepositoryFindByUsersAndLikeTypeAndLikedId() { 
	Users users = usersRepository.findByNickname("test0").get(); 
    long startTime = System.currentTimeMillis(); 
    likeRepository.findByUsersAndLikeTypeAndLikedId(users,LikeEnum.ITEM, Long.valueOf(1)); 
    long endTime = System.currentTimeMillis(); 
    long executionTime = endTime - startTime; 
    System.out.println("첫번째 Execution time: " + executionTime + " milliseconds"); 
}

기존 코드의 문제점

• 측정하고자 하는 로직의 시작과 끝에 측정 기준점을 일일히 세팅해야 합니다.
• 측정항목이 늘어날수록 코드의 반복이 늘어납니다.
• 시간 측정 로직과 비즈니스 로직이 혼재할 가능성이 높습니다.
• 시간 측정 로직이 변경될 경우 모든 로직을 찾아다니며 하나하나 변경해야 하기 때문에 유지보수의 비효율로 이어집니다.

따라서 기존 코드를 AOP를 사용하여 리팩토링하기로 결심하였습니다.

해결방법(AOP)

• AOP란 로직에 관점을 부여하는 프로그래밍입니다.
• 어떤 로직이 핵심 기능을 수행하고 어떤 로직은 부가적인 기능을 수행하는지 관점을 부여하여 분리합니다.
• 저희 코드에서 성능 측정 로직은 서비스의 부가적인 기능이지 핵심 기능이 아닙니다. 따라서 이를 AOP로 분리할 수 있습니다.

AOP를 스프링 빈에 등록하는 2가지 방법

• AOP는 작성한 클래스에 @Component를 추가하여 컴포넌트 스캔을 이용하거나 Config 파일을 이용하여 스프링 빈에 직접 등록할 수 있습니다.

1. @Component를 이용한 컴포넌트 스캔:

@Component  
@Aspect  
public class TimeTraceAop {  

    Logger logger = LoggerFactory.getLogger(TimeTraceAop.class);  

    public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {  
        long start = System.currentTimeMillis();  
        try {  
            return joinPoint.proceed();  
        } finally {  
            long finish = System.currentTimeMillis();  
            long timeMs = finish - start;  
            logger.info("END: {} {}ms", joinPoint, timeMs);  
        }  
    }  
}

• 장점:
  • 간단하고 빠르게 설정할 수 있습니다. 클래스에 @Component 어노테이션만 추가하면 됩니다.
  • 자동으로 빈으로 등록되므로 추가 구성이 필요하지 않습니다.
    • 패키지 스캔을 사용하므로 새로운 AOP 관점을 추가할 때 빈 등록을 걱정할 필요가 없습니다.
• 단점:
  • 애플리케이션의 규모가 커질수록 스캔에 대한 오버헤드가 발생할 수 있습니다.
  • 외부 라이브러리나 다른 모듈에 대한 AOP 관점을 적용하기 어려울 수 있습니다.

2. @Configuration 파일에 직접 빈 등록:

@Bean
public TimeTraceAop timeTraceAop() {
    return new TimeTraceAop();
}

• 장점:
  • 빈을 명시적으로 구성하므로 어떤 빈이 어디서 온 것인지 명확합니다.
    • 외부 라이브러리에 대한 AOP 관점을 쉽게 적용할 수 있습니다.
• 단점:
  • 빈을 등록하는 작업이 수동으로 이루어져야 하므로 초기 설정이 조금 더 복잡할 수 있습니다.
  • 빈을 추가하거나 변경할 때 Java Config 파일을 수정해야 합니다.

이러한 장단점을 고려하였을 때 소규모 애플리케이션인 저희 프로젝트에는 컴포넌트 스캔 방식이 적합하다고 판단하여 이를 적용하였습니다.

AOP 객체가 동작하는 원리

• 김영한님 강의자료에서 가져온 사진입니다.
• AOP가 @Component 방식 또는 Config 파일을 통해 스프링 빈으로 등록되면, 기존의 의존 관계 사이에 유사 객체가 생성됩니다.
• 유사 객체는 는 프록시를 이용해 만들어지고 실제 객체보다 먼저 실행됩니다. 프록시가 대리, 대신이라는 의미를 지닌 것 처럼, 실제 객체가 동작하기 앞서 필요한 기능을 실행하고, 내부 로직을 따라 joinPoint.proceed()가 실행되면, 그 때 실제 객체가 동작합니다.

해결방법(annotation)

• 성능측정을 모든 service에서 실행하고 싶은 것이 아닌 특정한 함수에서만 실행하고 싶었습니다.
• 따라서 커스텀 어노테이션을 만들어 이를 적용하는 방식을 생각해보았습니다.

Custom Annotation을 만들 때의 규칙

1. annotation type은 @interface로 정의해야합니다. 모든 어노테이션은 자동적으로 java.lang.Annotation 인터페이스를 상속하기 때문에 다른 클래스나 인터페이스를 상속 받으면 안됩니다.
2. 파라미터 멤버들의 접근자는 public이거나 default여야만 합니다.
3. 파라미터 멤버들은 byte,short,char,int,float,double,boolean,의 기본타입과 String, Enum, Class, 어노테이션만 사용할 수 있습니다.

• 다음과 같은 규칙을 지켜 성능 측정을 위한 custom annotation을 만들었습니다.

  @Target(ElementType.METHOD)  
  @Retention(RetentionPolicy.RUNTIME)  
  public @interface LogExecutionTime {  
  }

• @Target(ElementType.METHOD): 이 어노테이션을 메소드에 적용할 수 있도록 지정합니다. 즉, 메소드에만 @LogExecutionTime 어노테이션을 사용할 수 있습니다.
• @Retention(RetentionPolicy.RUNTIME): 이 어노테이션 정보가 런타임 시에도 유지되어야 함을 나타냅니다. 이것은 리플렉션(reflection)을 사용하여 런타임에서 어노테이션 정보에 접근할 수 있도록 해줍니다.

해결방법(currentTimeMillis vs 라이브러리)

• 처음에 성능 측정을 한다고 했을 때 가장 먼저 생각난 방식은 System.currentTimeMillis() 이다. 하지만 조사해보니 성능측정에는 적합하지 않다는 글들을 찾아볼 수 있었습니다.
• wall-clock time이기 때문에 다른 작업의 영향을 받거나 시스템의 시간을 변경하는 경우 등 측정 결과에 영향을 줄 수 있는 요소들이 있기 때문이라고 합니다.
• 따라서 스프링 프레임워크에서 제공하는 라이브러리인 StopWatch 클래스를 사용하여 시간을 측정하는 방식으로 코드 구현 방식을 변경하였습니다.
  • 아무래도 스프링에서 공식적으로 제공해주는 시간 측정 라이브러리를 사용하는게 더 낫지 않을까해서요

마치면서

• 최종적으로 작성한 코드는 다음과 같습니다.

@Component  
@Aspect  
public class TimeTraceAop {  
  
	Logger logger = LoggerFactory.getLogger(TimeTraceAop.class);  
  
	@Around("@annotation(LogExecutionTime)")  
	public Object logExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {  
		StopWatch stopWatch = new StopWatch();  
		stopWatch.start();  
		try {  
			return joinPoint.proceed();  
		} finally {  
			stopWatch.stop();  
			logger.info(stopWatch.prettyPrint());  
		}  
	}  
}

@Target(ElementType.METHOD)  
@Retention(RetentionPolicy.RUNTIME)  
public @interface LogExecutionTime {  
}

• 잘 측정되는 것을 확인할 수 있습니다. 😍
• 성능을 마구마구 측정하고 마구마구 개선해봅시다.

참조

• 김영한 스프링 입문 - 코드로 배우는 스프링 부트, 웹 MVC, DB 접근 기술 강의
• https://madplay.github.io/post/measure-elapsed-time-in-java