AOP 문제해결 과정 - LikeLionTeam/BootHouse GitHub Wiki

✔상황

api 호출이 일정 시간 초과시 시간을 저장하는 기능 입니다.

✔문제 발생

콘솔에 호출 시간 로그는 찍히지만 실제 Log 데이터베이스에는 시간이 저장 되지 않고 있었습니다.

    @Around("execution(* likelion.eight.domain..*Service.*(..))") 
    public Object transactionLog(ProceedingJoinPoint joinPoint) throws Throwable{
        long startTime = clockHolder.systemMillis();

        try{
            log.info("[Transaction start] {}", joinPoint.getSignature());

            Object result = joinPoint.proceed();

            log.info("[Transaction commit] {}", joinPoint.getSignature());
            return result;
        }catch(Exception e){
            log.info("[Transaction rollback] {}", joinPoint.getSignature());
            throw e;
        }finally {

            String methodName = joinPoint.getSignature().toShortString();
            long executionTime = clockHolder.systemMillis() - startTime;
            log.info("long executionTime={}", executionTime);
            // 문제의 라인
            saveTxLog(methodName, executionTime);
        }
    }
    @Transactional
    public void saveTxLog(String methodName, long executionTime){
        if(executionTime > 99L){
            Log log = Log.create(methodName, executionTime);
            logRepository.save(log);
        }
    }

✔해결 과정

처음에는 코드 구현적인 부분에 문제가 있나 생각을 하였고 나중에 트랜잭션에 문제가 있다고 생각했습니다.
트랜잭션 옵션 Propagation.REQUIRES_NEW 을 도입 했습니다.

    @Around("execution(* likelion.eight.domain..*Service.*(..))")
    public Object transactionLog(ProceedingJoinPoint joinPoint) throws Throwable{
        long startTime = clockHolder.systemMillis();

        try{
            log.info("[Transaction start] {}", joinPoint.getSignature());

            Object result = joinPoint.proceed();

            log.info("[Transaction commit] {}", joinPoint.getSignature());
            return result;
        }catch(Exception e){
            log.info("[Transaction rollback] {}", joinPoint.getSignature());
            throw e;
        }finally {

            String methodName = joinPoint.getSignature().toShortString();
            long executionTime = clockHolder.systemMillis() - startTime;
            log.info("long executionTime={}", executionTime);
            // 문제의 라인
            saveTxLog(methodName, executionTime);
        }
    }
    // 트랜잭션 분리
    @Transactional(propagation = Propagation.REQUIRES_NEW)
    public void saveTxLog(String methodName, long executionTime){
        if(executionTime > 99L){
            Log log = Log.create(methodName, executionTime);
            logRepository.save(log);
        }
    }

하지만 결과는 같았고, 이때부터는 제가 알던 지식을 의심하지 않고 코드 구현이 잘못됐다고 생각하고 다른 부분만 계속해서 수정했었습니다. 결과는 똑같았고 ‘마지막으로 메서드를 아예 다른 객체로 분리해서 호출해 보자’라고 생각하였습니다.

Spring Aop 동작 방식의 깨달음으로 해결 하였습니다. @Around, @Transactional 어노테이션은 Aop 방식으로 동작 하는 어노테이션이 였고 Aop를 사용할 때는 크게 주의해야 할 부분이 있다는걸 알게 되었습니다.

Aop를 사용하는 객체는 프록시 형태로 스프링 컨테이너에 등록됩니다.
프록시가 Aop를 적용한 뒤에 실제 객체를 호출 하는 흐름인데 Aop가 적용된 객체에서 또 Aop관련 로직을 호출 할 경우 따로 참조하는 지칭이 없으면 this라는 키워드가 자동으로 붙기때문에 프록시 대신 실제 객체를 호출 하기 때문에 Aop적용이 되지 않습니다.

    @Around("execution(* likelion.eight.domain..*Service.*(..))")
    public Object transactionLog(ProceedingJoinPoint joinPoint) throws Throwable{
        long startTime = clockHolder.systemMillis();

        try{
            log.info("[Transaction start] {}", joinPoint.getSignature());

            Object result = joinPoint.proceed();

            log.info("[Transaction commit] {}", joinPoint.getSignature());
            return result;
        }catch(Exception e){
            log.info("[Transaction rollback] {}", joinPoint.getSignature());
            throw e;
        }finally {

            String methodName = joinPoint.getSignature().toShortString();
            long executionTime = clockHolder.systemMillis() - startTime;
            log.info("long executionTime={}", executionTime);
            // @Transactional이 선언된 별도의 LogService로 메서드를 분리해서 호출
            logService.saveTxLog(methodName, executionTime);
        }
    }

✔정리

메서드 내부에서 또 다른 메서드를 실행 했을 경우 개념적으로 외부 / 내부 트랜잭션이 있을 뿐 결국 실제 트랜잭션 1개에서 관리 되며 이걸 분리 하고 싶으면 @Transactional(propagation = Propagation.REQUIRES_NEW) 사용
메서드가 이중으로 구현 되어 있지만 Aop 기능을 활용 하고 싶다면 아예 다른 객체에 메서드를 옮긴뒤, 주입 받아서 사용해야한다.

Aop가 적용된 프록시를 호출 못하고 자바의 this 문법으로 인해 origin 객체 호출!