feat: 로그 프록시 등록 과정을 BeanPostProcessor를 이용해 리팩토링

[tributetothemoon]

구현 기능

• 빈 컨테이너에서 인스턴스를 내리고 프록시를 올리는 과정을 삭제합니다.
• 대신, 빈 컨테이너에 등록되기 전에 프록시로 대체하는 과정을 진행합니다.
• 이 과정은 BeanPostProcessor, 빈 후처리기를 이용합니다.
• LogRegistry는 FindInstanceAndCreateLogProxy라는 이름으로 변경되었습니다.
• 여전히 LogMethodExecutionTime 어노테이션도 사용되고 있는데요, 이는 잠재적인 부작용의 존재 여부 때문입니다. 코드 리뷰 란에 이 부작용에 대해 설명해두었습니다. 당장에는 문제가 안 되지만, 해결 방안을 곰곰히 생각해보겠습니다.

공유하고 싶은 내용

• 개괄도
  

빈 후처리기의 진실

• 스프링 코어에 의해 생성된 모든 빈은 후처리기(BeanPostProcessor)에게 전달됩니다.
• 이 과정에서 필요에 의하다면 후처리(대표적으로 프록시)가 적용되어 빈 컨테이너에 인스턴스가 올라갑니다.
• 참고로 @PostConstruct 메소드도 InitDestroyAnnotationBeanPostProcessor라는 빈 후처리기에 전달 되었을 때 실행되는 원리입니다.

AOP와의 관계

• 소위 @Aspect 어노테이션을 붙여서 AOP를 적용하는 과정은 AnnotationAwareAspectJAutoProxyCreator라는 빈 후처리기의 행동을 지정하고 프록시를 적용하는 행위입니다.
• 어떠한 클래스와 메소드에 적용할 것인가를 PointCut으로 지정합니다.
• 어떠한 부가기능을 적용할 것인가를 지정하는데, 이는 Advice(org.aopalliance.intercept.MethodInterceptor)라는 객체를 만들어냅니다.
• PointCut + Advice 객체를 가지는 클래스가 곧 Advisor(org.springframework.aop.Advisor)가 됩니다.
• 이 Advisor와 타겟이 될 실제 인스턴스를 ProxyFactory에 넘기면, 해당 로직이 적용된 프록시가 생성됩니다.

    static Object createLogProxy(Object target, Class<?> typeToLog, String logGroup) {
        // Advisor 생성
        AspectJExpressionPointcutAdvisor advisor = new AspectJExpressionPointcutAdvisor();
      
        // 적용될 클래스와 메소드의 기준 설정, 내부적으로 PointCut 객체를 만들어냅니다.
        advisor.setExpression("execution(public * com.woowacourse.zzimkkong..*(..))");

        // 부가기능을 지정, ExecutionTimeLogAdvice는 수행 시간을 측정하라는 부가기능을 담고 있습니다.
        ExecutionTimeLogAdvice advice = new ExecutionTimeLogAdvice(typeToLog, logGroup);
        advisor.setAdvice(advice);

        // 프록시를 생성합니다.
        ProxyFactory proxyFactory = new ProxyFactory(target);
        proxyFactory.addAdvisor(advisor);
        proxyFactory.setProxyTargetClass(true);

        return proxyFactory.getProxy();
    }


    // 참고. ExecutionTimeLogAdvice 클래스 (LogAspect 내부로 감추었습니다.)
    private static class ExecutionTimeLogAdvice implements MethodInterceptor {
        private final Class<?> typeToLog;
        private final String logGroup;

        private ExecutionTimeLogAdvice(Class<?> typeToLog, String logGroup) {
            this.typeToLog = typeToLog;
            this.logGroup = logGroup;
        }

        @Override
        public Object invoke(MethodInvocation invocation) throws Throwable {
            long startTime = System.currentTimeMillis();
            
            // 타겟 인스턴스의 메소드를 실행합니다.
            final Object result = invocation.proceed();

            long endTime = System.currentTimeMillis();
            long timeTaken = endTime - startTime;

            Method method = invocation.getMethod();
            
            // LogAspect의 로거를 이용하여 로깅하라는 static 메소드
            logExecutionInfo(typeToLog, method, timeTaken, logGroup);

            return result;
        }
    }

Close #741

[tributetothemoon]

이 어노테이션이 붙은 하위 타입의 인스턴스가 존재한다면, 그에 대한 로그 프록시를 만들어내라는 의미입니다.

LogMethodExecutionTime과 구분을 해두었는데요, 가능하다면 LogMethodExecutionTime쪽이 후술할 부작용이 없기 때문입니다.

가능한 부작용

FindInstanceAndCreateLogProxy가 붙은 클래스는 Reflections라이브러리에 의해 제가 만든 빈후처리기에 인스턴스 변수로 등록됩니다.

private static class LogProxyPostProcessor implements BeanPostProcessor {
    private final Set<Class<?>> typesAnnotatedWith;

    protected LogProxyPostProcessor() {
        Reflections reflections = new Reflections("com.woowacourse.zzimkkong");
        typesAnnotatedWith = Collections.unmodifiableSet(reflections.getTypesAnnotatedWith(FindInstanceAndCreateLogProxy.class));
    }
// 생략

그리고 빈 후처리 과정에서, 이 인스턴스 변수를 루프로 돌면서 자신의 타입에 맞는 클래스를 찾고, 이 클래스 명으로 로깅하는 프록시를 만들어내게 됩니다.

@Override
public Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {
    return typesAnnotatedWith.stream()
            .filter(typeToLog -> typeToLog.isAssignableFrom(bean.getClass()))
            .findAny()
            .map(typeToLog -> createLogProxy(bean, typeToLog))
            .orElse(bean);
    }

문제는, 이 때 상속도가 꼬였다면(슈퍼타입과 서브타입 객체가 각각 모두 존재하는 상황이라면) 같은 클래스 명으로 로깅이 되는 참사가 일어날 수 있습니다.

예를 들어...

@Component
@FindInstanceAndCreateLogProxy
public class A {}

@Component
@FindInstanceAndCreateLogProxy
public class B extends A {}

이렇게 되어 있다면, B 인스턴스의 타입을 찾기 위해 루프를 돌다가, 운 안 좋게 A 타입이 지정되어 로깅이 되어버릴 수 있다는 의미입니다. (B 타입은 A의 서브타입이니까요...)

결국 두 클래스의 실행 메소드가 모두 A 클래스로 적용되어 로깅됩니다...

깔끔하게 해결할 수 있는 방안을 계속 생각해보겠습니다.

[sakjung]

설명이 너무 잘 되어있어서 이해가 잘 됐습니다!!! ㅋㅋㅋㅋ 이제 김김 AOP에 있어서 경지에 오른느낌인데요/...

이제 그럼 애플리케이션 컨텍스트가 완전히 띄워지기 전에 init된 bean을 프록시로 만들어서 컨텍스트에 최종 등록하고 애플리케이션 컨텍스트를 띄워주는 건가요?? 세부적인 흐름이 궁금해요

[sakjung]

음...혹시 postProcessAfterInit할때 filter에서 equal로 판단하면 괜찮지 않을까요?? 그럼 자식은 본인 클래스에 딱 일치하는 놈으로 찾아갈테고 부모는 자기 클래스에 맞는 클래스로 찾아갈 수 있을 것 같습니다!

Suggested change

	@Override
	public Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {
	return typesAnnotatedWith.stream()
	.filter(typeToLog -> typeToLog.isAssignableFrom(bean.getClass()))
	.findAny()
	.map(typeToLog -> createLogProxy(bean, typeToLog))
	.orElse(bean);
	}
	@Override
	public Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {
	return typesAnnotatedWith.stream()
	.filter(typeToLog -> typeToLog.equals(bean.getClass()))
	.findAny()
	.map(typeToLog -> createLogProxy(bean, typeToLog))
	.orElse(bean);
	}

[tributetothemoon]

자기와 정확하게 같은 클래스만 찾아가면 Data JPA 구현 클래스를 어사인할 수 없습니닷.
데타 JPA에 의해서 만들어지는 클래스는 예컨대 MemberRepository.class가 아니라 com.sun.proxy.$Proxy162 (implements MemberRepository) 이런 클래스에요. 할당 안 돼서 프록시가 적용되지 않을 겁니당

[sakjung]

아 그러네요 Repository는 프록시로 등록되네요! 음... 그럼 찐 타겟을 찾는 메서드를 만들어주는 건 어떨까요??
이해를 돕기 위한 코드로 간단하게 적어보겠슴다

Suggested change

	@Override
	public Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {
	return typesAnnotatedWith.stream()
	.filter(typeToLog -> typeToLog.isAssignableFrom(bean.getClass()))
	.findAny()
	.map(typeToLog -> createLogProxy(bean, typeToLog))
	.orElse(bean);
	}
	@Override
	public Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {
	return typesAnnotatedWith.stream()
	.filter(typeToLog -> typeToLog.equals(getTargetClass(bean)))
	.findAny()
	.map(typeToLog -> createLogProxy(bean, typeToLog))
	.orElse(bean);
	}
	private Class getTargetClass(Object proxy) throws Exception {
	if (AopUtils.isAopProxy(proxy)) {
	return ((Advised)proxy).getTargetSource().getTarget().getClass();
	} else {
	return proxy.getClass();
	}
	}

[tributetothemoon]

오 삭정 aop 마스터인가요?!

[tributetothemoon]

일단 위 방법은 여전히 프록시가 나옵니다 :)
프록시가 안 나올때까지 벗겨보면, SimpleJpaRepository가 나옵니다.

[tributetothemoon]

또한 equals로 두는 것은 영영 힘든게, Jpa는 인터페이스를 구현하는 클래스(B)를 런타임에 만들어냅니다.

하지만 제가 어노테이션을 붙일 수 있는 건 인터페이스(A) 밖에 없습니다.

결국 둘은 영영 같을 수 없습니다. 어렵네요😢

[tributetothemoon]

이제 그럼 애플리케이션 컨텍스트가 완전히 띄워지기 전에 init된 bean을 프록시로 만들어서 컨텍스트에 최종 등록하고 애플리케이션 컨텍스트를 띄워주는 건가요?? 세부적인 흐름이 궁금해요.

넹 잘 알고 계시네요. init() 메소드도 후처리기가 실행하고~ PointCut보고 적용되는 빈이면 프록시도 만들고 컨텍스트에 등록합니다. 이 과정을 계~속 반복해서 모든 빈들의 후처리가 끝나면 서버 구동 준비 끗

[dusdn1702]

멋지네요!!! 이해 완료했습니다!!!!✅

[sakjung]

✅ ZZIMKKONG SONARQUBE ✅

All passes! - Read the report here!

[sakjung]

매우.... 쉽지않네요 제안 하나 더 드려봐도 될까요.. 김김 너무 고생하네요 ㅠ

[sakjung]

와...빡세네요 ㅋㅋㅋㅋㅋㅋ 재밌네요 ㅋㅋ

IntelliJ에서 좀 끄적거려보다가 Advise 객체에 getProxiedInterfaces() 메서드를 쓰면 아래와 같은 interfaces 들이 나오더라구요

// ReservationRepository
com.woowacourse.zzimkkong.repository.ReservationRepository
org.springframework.data.repository.Repository
org.springframework.transaction.interceptor.TransactionalProxy

그래서 제 생각에는,
Repository들은 Spring Data JPA가 특별취급을 해서 좀 복잡하게 bean이 구성되잖아요? 그래서 얘들은 특별취급을 해줘도 괜찮을것 같다고 생각했어요 ㅋㅋ 너무 예외적인 케이스니까. 그래서 다음처럼 해보면 어떨까요?? 최대한 코드로 간단하게 적어볼게요. 참고만해서 김김이 적절하게 한 번 트라이 해봐주세요!

Suggested change

	@Override
	public Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {
	return typesAnnotatedWith.stream()
	.filter(typeToLog -> typeToLog.isAssignableFrom(bean.getClass()))
	.findAny()
	.map(typeToLog -> createLogProxy(bean, typeToLog))
	.orElse(bean);
	}
	@Override
	public Object postProcessAfterInitialization(Object bean, String beanName) throws BeansException {
	return typesAnnotatedWith.stream()
	.filter(typeToLog -> typeToLog.equals(getTargetClassOf(bean)))
	.findAny()
	.map(typeToLog -> createLogProxy(bean, typeToLog))
	.orElse(bean);
	}
	private Class getTargetClassOf(final Object bean) throws Exception {
	if (isRepository(bean)) {
	return Arrays.stream(((Advised) bean).getProxiedInterfaces())
	.filter(clazz -> clazz.getName().contains("zzimkkong"))
	.findAny()
	.orElseThrow(Exception::new);
	} else if (AopUtils.isAopProxy(bean)) { // 혹시모를 다른 proxy bean을 위한 분기
	return ((Advised) bean).getTargetClass();
	} else {
	return bean.getClass();
	}
	}
	private boolean isRepository(final Object bean) {
	return AopUtils.isJdkDynamicProxy(bean) && ((Advised) bean).getTargetClass().getName().contains("data.jpa.repository");
	}

이런식으로 가면 repository 문제는 해결될 수 있을 것같아요. 근데 혹시나 또 Spring Data JPA와 같은 케이스가 어디 있을 수 도 있다는 불안함이 있긴하네요. 근데 보통 Interface의 method execution time을 재지는 않기 때문에 JPA는 특이한 케이스라고 생각합니다. 그래서 이렇게해도 무방하지 않을까 생각했습니다.

[sakjung]

ㅇㅍㄹㅂ