[AOP] 로그 기능 적용 : 동적 프록시

Heechul Yoon·2022년 6월 6일

JDK 동적 프록시 Java Proxy Spring cglib log 동적 프록시 로그

문제

인터페이스를 사용한 프록시 패턴을 사용하면서 프록시를 적용하고자 하는 클래스 개수 n개 만큼 로깅 코드를 계속 생성해야하는 문제가 있었다. 프록시를 적용하고자 하는 클래스마다 인터페이스와 프록시 구체클래스를 만들어줘야 했기 때문이다. 이 문제를 해결하기 위해 JDK에서 제공하는 동적 프록시를 통해서 필요할 때 마다 프록시 객체를 생성해서 중복되는 부분을 제거해보자

JDK 동적 프록시

자바 자체에서 지원하는 프록시 객체를 생성하는 기능을 사용해보겠다.

@Configuration
public class DynamicProxyConfig {

    private final LogTracer logTracer;
    private static final String[] PATTERNS = { "get*" } [1]

    @Autowired
    public DynamicProxyConfig(LogTracer logTracer) {
        this.logTracer = logTracer;
    }

    @Bean
    IPostingController postingProxyController() {
		PostingController target = new PostingController();
        IPostingController proxy = (IPostingController) Proxy.newProxyInstance(
        	IPostingController.class.getClassLoader(),
        	new Class[] {IPostingController.class}, 
            new LogHandler(target, logTracer, PATTERNS);
        );
        
        return proxy;
    }
}

이제 config파일에서 직접 IPostingController 인터페이스를 구현하는 프록시 객체를 동적으로 생성해서 spring bean으로 생성해줘야 한다.
생성은 Proxy.newProxyInstance 정적 메서드를 사용해서 수행된다. 인자로는 해당 객체가 등록될 클래스 로더, 상속받을 인터페이스(인터페이스는 여러개를 상속받을 수 있으니 배열 형태를 가진다), 구현될때 구현체 안에서 실행할 핸들러를 넘겨주게 된다.
로깅 기능을 적용하고싶지 않은 메서드는 제외해주기 위해서 [1]과 같이 PATTERNS를 정의해주고 LogHandler를 생성할 때 같이 넘겨준다

import community.trace.logtrace.LogTracer;
import lombok.RequiredArgsConstructor;

import java.lang.reflect.InvocationHandler;
import java.lang.reflect.Method;

public class LogHandler implements InvocationHandler {

    private final Object target; // 비지니스 로직이 들어있는 객체
    private final String[] patterns;

    public LogTraceFilterHandler(Object target, String[] patterns) {
        this.target = target;
        this.patterns = patterns;
    }

    @Override
    public Object invoke(Object proxy, Method method, Object[] args) throws Throwable {
    	String methodName = method.getName();
        if (!PatternMatchUtils.simpleMatch(patterns, methodName)) {
            return method.invoke(target, args);
        } // [0]
        
        Long startTimeMs = System.currentTimeMillis(); // 시작
        Object result = method.invoke(target, args); // [1]
        Long endTimeMs = System.currentTimeMillis(); // 끝
        log.info("time - {}", endTimeMs - startTimeMs); // 걸린 시간

        return result;
        
    }
}

프록시 객체가 생성되고 실행할 핸들러를 만들어준다. 자바에서 제공하는 InvocationHandler 인터페이스를 구현해서 invoke라는 메서드에 프록시에서 해줄 기능(지금은 시간 로깅) 구현한다.
오버라이드 한 invoke매서드는 인터페이스를 통해서 들어온 메서드 식별자가 Method라는 타입의 매개변수로 들어온다. [0]에서 객체가 생성될 때 받아온 patterns를 가지고 로그를 찍지 않아도 될 매서드가 들어오면 그냥 target을 호출해준다. [1]에서 이 method 객체 안에있는(프록시 생성자로 부터 넘겨받은 인터페이스에 있는 메서드 중 하나) invoke를 실행해서 비지니스 로직을 실행한다. 첫번째 인자로 어떤 구체 클래스에서 실행할 메서드인지, 두번째로 그 메서드에서 사용할 매개변수를 넣어준다. 이것이 가능 한 이유는 위에서 newProxyInstance 를 통해서 프록시를 생성할 때, 어떤 인터페이스를 기반으로 구현할 것인지 이미 알고있기 때문이다.

실행 순서를 보면 위와같은 과정을 거쳐서 요청이 컨트롤러로 전달된다. 요청이 컨트롤러 까지 가는 도중에 LogHandler에서 시간측정 로깅이 수행 된다.

CGLIB

인터페이스가 없거나 굳이 인터페이스를 만들어줄 상황이 아니라면 오픈소스인 CGLIB를 사용할 수 있다.

public class TimeMethodInterceptor implements MethodInterceptor {
	private final Object target;
	public TimeMethodInterceptor(Object target) {
		this.target = target;
	}
    
	@Override
	public Object intercept(Object obj, Method method, Object[] args, MethodProxy proxy) throws Throwable {
		long startTime = System.currentTimeMillis();
		Object result = proxy.invoke(target, args);
		long endTime = System.currentTimeMillis();
        
		log.info("TimeProxy 종료 resultTime={}", endTime - startTime);
        
		return result;
	}
}

JDK 동적 프록시에서 InvocationHandler를 만들어서 newProxyInstance를 할때 인자로 넘겨줬다면, CGLIB에서는 MethodInterceptor를 만들어서 동일한 역할을 하도록 한다.

@Configuration
public class DynamicProxyConfig {

    @Bean
    IPostingController postingProxyController() {
		ConcreteService target = new PostingController();
 		Enhancer enhancer = new Enhancer(); [0]
 		enhancer.setSuperclass(PostingController.class); [1]
 		enhancer.setCallback(new TimeMethodInterceptor(target)); [2]
 		PostingController proxy = (PostingController) enhancer.create();
        
        return proxy;
    }
}

CGLIB에서는 Enhancer를 사용해서 타겟 클래스를 상속받는 동적 프록시를 생성한다. JDK동적프록시에서 인터페이스를 사용했다면 CGLIB에서는 [1]부모클래스를 설정해서 자식객체를 만들도록 한다. 그리고 [2]InvocationHandler대신 MethodHandler를 넘겨준다

핵심은 JDK 동적프록시는 타겟 클래스 마다 인터페이스를 만들어줘야 했지만, CGLIB를 사용하면 타겟클래스를 상속받는 프록시 객체를 만들어줄 수 있다는 장점이 있다

프록시 팩토리

인터페이스가 있는 클래스는 JDK동적프록시를 사용하고 클래스만 있는경우에는 CGLIB를 사용하기 때문에 어느 상황에 어떤것을 사용해야하는지 개발자가 정해주어야 하기 때문에 불편한점이 있다.
이제 스프링에서 제공하는 프록시 팩토리를 사용해서 인터페이스가 있는 클래스와 없는 클래스 구분 없이 상황에맞게 jdk 동적프록시를 생성하거나, CGLIB 프록시를 생성하는 프록시 팩토리를 사용해보겠다.

우선 프록시 팩토리에서는 advice와 pointcut과 advisor 개념이 사용된다.
advice와 pointcut 두개의 객체를 사용해서 advisor를 만들어주고, 앞으로 이 advisor를 사용하는 동적프록시를 만들게 될것이다.

Advice

인터페이스가 있고 없고의 상황에 따라 jdk동적 프록시 혹은 CGLIB를 만들어준다 했는데, jdk동적 프록시의 경우 InvocationHandler, CGLIB의 경우는 MethodInterceptor가 필요하다. 이 두개의 다른 객체를 동적으로 어떻게 빌드타임에 처리할 수 있을까의 의문이 생긴다.
프록시 팩토리에서는 이 문제를 Advice로 해결한다. 프록시 팩토리 사용자는 Advice가 타겟인 postingController를 호출하도록만 만들어주면 InvocationHandler 를 구현한 adviceInvocationHandler 혹은 MethodInterceptor를 구현한 adviceMethodInterceptor가 알아서 Advice 객체를 호출해준다.

이 개념을 가지고 Advice를 구현해보자

public class LogTraceAdvice implements MethodInterceptor {

    @Override
    public Object invoke(MethodInvocation invocation) throws Throwable {
        long startTime = System.currentTimeMillis();
		Object result = invocation.proceed(); // [1]
        long endTime = System.currentTimeMillis();

		log.info("TimeProxy 종료 resultTime={}", endTime - startTime);

		return result;
    }
}

편한것은 기존에 CGLIB의 MethodInterceptor 혹은 JDK동적프록시의 InvocationHandler에서 받아오던 Object proxy, Method method, Object[] args 이런 매개변수들이 하나의 invocation 객체에 들어가있다. 그리고 더 좋은것은 원래는 target 객체를 특정 시점에 주입시켜 줬는데, invocation 객체 안에서 target도 들고있기 때문에 target을 Advice쪽에서 주입받을 필요가 없어진다.
[1]에서 처럼 invocation.proceed() 를 해주면 알아서 target을 실행해서 반환값을 result에 Object형태로 넘겨준다

Advice인데 왜 MethodInterceptor를 상속받는지 의문일 수 있다. 여기서 MethodInterceptor는 CGLIB의 인터셉터가 아니라 org.aopalliance.intercept.MethodInterceptor 여기서 import해와야 한다. MethodInterceptor를 타고 들어가보면 결국 org.aopalliance.aop.Advice를 상속받고 있는 것을 알수 있다

Pointcut

포인트컷은 어디에 부가기능을 적용할지 필터링하는 객체이다. Advisor를 생성할 때 Advice와 함께 꼭 같이 넣어주어야 한다.

그림과같이 클라이언트에게 요청이 들어오면 프록시는 포인트컷으로 가서 먼저 이 요청이 프록시 적용대상인지 확인하고 적용대상이라면 advice로 이동해서 부가기능 수행 후 타겟을 호출한다. 포인트 컷을 확인해서 프록시 적용대상이 아니라면 바로 타겟으로 갈것이다.

설정 파일

@Configuration
public class ProxyFactoryConfigV2 {
    @Bean
    public OrderControllerV2 orderControllerV2(LogTrace logTrace) { // [0]
        OrderControllerV2 orderController = new
                OrderControllerV2(orderServiceV2(logTrace));
        ProxyFactory factory = new ProxyFactory(orderController);
        factory.addAdvisor(getAdvisor(logTrace));
        OrderControllerV2 proxy = (OrderControllerV2) factory.getProxy();
        return proxy;
    } 
    @Bean
    public OrderServiceV2 orderServiceV2(LogTrace logTrace) {
        OrderServiceV2 orderService = new
                OrderServiceV2(orderRepositoryV2(logTrace));
        ProxyFactory factory = new ProxyFactory(orderService);
        factory.addAdvisor(getAdvisor(logTrace));
        OrderServiceV2 proxy = (OrderServiceV2) factory.getProxy();
        return proxy;
    }
    @Bean
    public OrderRepositoryV2 orderRepositoryV2(LogTrace logTrace) {
        OrderRepositoryV2 orderRepository = new OrderRepositoryV2();
        ProxyFactory factory = new ProxyFactory(orderRepository);
        factory.addAdvisor(getAdvisor(logTrace));
        OrderRepositoryV2 proxy = (OrderRepositoryV2) factory.getProxy();
        return proxy;
    }
    private Advisor getAdvisor(LogTrace logTrace) { // [1]
        //pointcut
        NameMatchMethodPointcut pointcut = new NameMatchMethodPointcut();
        pointcut.setMappedNames("request*", "order*", "save*");
        //advice
        LogTraceAdvice advice = new LogTraceAdvice(logTrace);
        //advisor = pointcut + advice
        return new DefaultPointcutAdvisor(pointcut, advice);
    }
}

프록시 팩토리를 사용하기 위해서는 요청이 컨트롤러로 바로 들어오는게 아니라 프록시로 먼저 들어오기 때문에 관계를 설정해주어야 한다. 단점은 기존에 사용하던 컴포넌트 스캔을 사용할 수 없다는 점이다. 빈을 등록하는 시점이랑 컴포넌트 스캔을 하는 시점이 다르기 때문에 관계를 미리 정립할 수 없다. 따라서 config를 사용한다면 config안에서 모든 관계를 연결 시켜 주어야 한다.

[0] 에서 ProxyFactory를 생성할 때 target을 넘겨주고, advisor를 등록해준다.
[1] Advisor 생성을 보면 Pointcut 먼저 생성하고, 정의 해주었던 Advice객체를 생성해서 Advisor에 등록하는 것을 확인할 수 있다