Spring AOP로 로깅하기 - 근데 이제 AspectJ를 곁들인

로깅(Logging)

로깅은 소프트웨어 개발에 있어서 디버깅, 성능 모니터링, 보안 감사 등 여러 분야에 사용됩니다.

실제 서비스 중인 애플리케이션에서 버그 발생 시, 로그가 중요한 힌트가 될 수 있기에

Service의 각 메서드의 호출 시 마다, 그리고 중요 포인트 마다 로그를 찍는 코드를 작성하였습니다.

 

 

 

v1. Logger를 통해 직접 로깅 남기기

 

private static final Logger log = LoggerFactory.getLogger(UserService.class);

public User getUser(Long id) {
    log.info("getUser Method called with id: {}", id);
    User user = userRepository.findById(id);
    return user;
}

 

첫 번째로, slf4j + logback 등으로 직접 로그를 찍는 코드를 남기는 방법입니다.

가장 단순하고 직관적이며, 개발자가 원하는 곳에 로그를 남길 수 있죠.

메서드의 특정 부분마다 로깅을 하는 것은 어쩔 수 없지만,

모든 메서드가 호출 시 마다 로그부터 찍도록 만들고 싶다면, 일괄처리를 통해 중복되는 코드를 줄일 수 있을 법한 느낌이 듭니다.

 

 

 

AOP(Aspect-Oriented Programming)

AOP(Aspect-Oriented Programming, 관점 지향 프로그래밍)은

핵심 비즈니스 로직과 공통 기능(횡단 관심사)를 분리하는 프로그래밍 패러다임 입니다.

트랜잭션 관리, 성능 측정, 보안 등 비즈니스 로직에서 반복적으로 사용되는 로직을 모듈화하여

유지보수성을 크게 향상시킬 수 있습니다.

 

로깅 또한 AOP를 사용하면 중복 코드를 줄이고 유지보수성을 높일 수 있을 것으로 기대할 수 있을 것 같네요.

 

 

v2. Aspect와 Pointcut 지정을 통한 Service 레이어 로깅

 

implementation 'org.springframework.boot:spring-boot-starter-aop'

스프링 AOP를 사용하기에 앞서, 위와 같이 의존성 추가가 필요합니다.

 

@Aspect
@Component
public class LoggingAspect {

    private static final Logger log = LoggerFactory.getLogger(LoggingAspect.class);

    // Service 레이어의 모든 메서드 실행 전에 로그 출력
    @Before("execution(* com.test.teststudio.service.*.*(..))")
    public void logBeforeMethod(JoinPoint joinPoint) {
        log.info("메서드 호출 전: {}", joinPoint.getSignature().toShortString());
    }

}

INFO 23656 --- [teststudio] [nio-8080-exec-5] com.test.teststudio.LoggingAspect        : 메서드 호출 전: UserService.getUser(..)

 

@Aspect를 통해 해당 클래스가 Aspect 임을 지정한 뒤,

@Before으로 포인트 컷 대상 메서드의 실행 직전에 호출될 메서드를 지정할 수 있습니다.

pointcut으로 저는 service 패키지에 있는 모든 클래스를 대상으로 지정해주었습니다.

 

이제, service 패키지에 있는 메서드들은 호출 직전 logBeforeMethod 메서드가 호출되어, 로그가 찍히게 됩니다.

여기서, 한 단계 나아가 매개 변수의 이름과 값 까지 출력한다면,

디버깅과 모니터링에 많은 도움이 될 것 같으니, 매개 변수의 이름과 값 또한 로깅해봅시다.

 

 

v3. AOP에서 매개 변수 이름과 값도 함께 로깅

@Aspect
@Component
public class LoggingAspect {

    private static final Logger log = LoggerFactory.getLogger(LoggingAspect.class);

    @Before("execution(* com.test.teststudio.service..*(..))")
    public void logBeforeMethod(JoinPoint joinPoint) {
        MethodSignature methodSignature = (MethodSignature) joinPoint.getSignature();
        Method method = methodSignature.getMethod();

        Object[] args = joinPoint.getArgs();
        Parameter[] parameters = method.getParameters();

        StringBuilder sb = new StringBuilder();

        for (int i = 0; i < args.length; i++) {
            sb.append(parameters[i].getName()).append(" : ").append(args[i]);
            if (i < args.length - 1) {
                sb.append(", ");
            }
        }

        log.info("클래스 : {}, 메서드 : {}, 파라미터 : {}", joinPoint.getTarget().getClass().getSimpleName(), method.getName(), sb.toString());
    }
}

 

@AllArgsConstructor
@Service
public class UserService {

    private final UserRepository userRepository;

    public User getUser(Long userId) {
        return userRepository.findById(userId);
    }

}

 

먼저, 제가 호출한 메서드는 UserSerivce의 getUser로, 위와 같습니다.

userId = 1로 호출을 해보겠습니다.

 

INFO 9768 --- [teststudio] [nio-8080-exec-3] com.test.teststudio.LoggingAspect        : 클래스 : UserService, 메서드 : getUser, 파라미터 : userId : 1

 

파라미터의 이름과 그 값 까지 모두 잘 출력이 된 모습입니다.

 

 

😮 매개 변수 이름이 제대로 불러와지지 않을 경우

 

[Gradle]

tasks.withType(JavaCompile) {
    options.compilerArgs << "-parameters"
}

 

[Maven]

<plugin>
    <groupId>org.apache.maven.plugins</groupId>
    <artifactId>maven-compiler-plugin</artifactId>
    <version>3.8.1</version>
    <configuration>
        <compilerArgs>
            <arg>-parameters</arg>
        </compilerArgs>
    </configuration>
</plugin>

 

 

자바, 컴파일러, 스프링 버전 혹은 기타 세팅에 따라 파라미터 이름을 제대로 가져오지 못할 수 있습니다.

자바 컴파일러가 컴파일 시 최적화를 위해 불필요한 메타데이터를 날려버리기 때문인데요.

위 옵션을 지정하여 파라미터 이름을 날리지 않도록 지정할 수 있습니다.

 

 

 

 

IntelliJ에서 [Settings] - [Build, Execution, Deployment] - [Build Tools] - [Gradle] 부분에서 위와 같이 

Gradle을 사용해 빌드해주도록 합시다.

 

🤔 컴파일 과정에서 최적화를 위해 파라미터 이름을 지우는데,
파라미터 이름을 남기면 최적화 측면에서 불리한 것 아닌가?

 

결론부터 말하자면, 큰 영향은 없을 것으로 예상됩니다.

1. - parameters 옵션은 컴파일 단계에서 영향을 주며, 런타임 환경에서는 영향을 미치지 않습니다.

2. 매개변수 이름이 남으므로 .class 파일 용량이 조금 커질 수 있으나, 고작 몇 KB 차이이므로 대규모 시스템이 아니라면 영향이 미미할 것으로 예상됩니다. 👍

 

 

 

v3-2. @ 어노테이션 방식으로 로깅 클래스 / 메서드 지정하기

기존 Aspect 표현 식 (ex> execution(* com.test.teststudio.service..*(..)) ) 대신

클래스 혹은 메서드에 어노테이션을 붙여 손쉽게 선택적으로 로깅 대상을 지정할 수 있습니다.

 

 

@Logging 어노테이션 정의

@Target({ElementType.TYPE, ElementType.METHOD})
@Retention(RetentionPolicy.RUNTIME)
public @interface Logging {
}

 

Aspect 어노테이션 방식으로 정의

@Aspect
@Component
public class LoggingAspect {

    private static final Logger log = LoggerFactory.getLogger(LoggingAspect.class);

    // @Logging이 붙은 클래스 또는 메서드에 AOP 적용
    @Before("@within(com.test.teststudio.Logging) || @annotation(com.test.teststudio.Logging)")
    public void logBeforeMethod(JoinPoint joinPoint) {
        MethodSignature methodSignature = (MethodSignature) joinPoint.getSignature();
        Method method = methodSignature.getMethod();

        Object[] args = joinPoint.getArgs();
        Parameter[] parameters = method.getParameters();

        StringBuilder sb = new StringBuilder();

        for (int i = 0; i < args.length; i++) {
            sb.append(parameters[i].getName()).append(" : ").append(args[i]);
            if (i < args.length - 1) {
                sb.append(", ");
            }
        }

        log.info("클래스 : {}, 메서드 : {}, 파라미터 : {}",
                joinPoint.getTarget().getClass().getSimpleName(),
                method.getName(), sb.toString());
    }
}

 

어노테이션 방식으로 포인트컷을 지정했습니다.

@within은 클래스 레벨에서 해당 어노테이션이 붙은 경우를,

@annotation은 메서드 레벨에서 해당 어노테이션이 붙은 경우를 지정하고,

|| 연산자로 or 조건으로 클래스 or 메서드 레벨 중 하나라도 어노테이션이 붙어 있을 경우 AOP가 작동하도록 지정합니다.

 

 

클래스 또는 메서드에 @Logging 어노테이션 지정

 

이제 클래스 혹은 메서드에 우리가 정의한 @Logging 어노테이션을 붙여,

손쉽게 선택적으로 로깅 대상을 지정할 수 있게 되었네요!

 

 

Spring AOP 로깅 방식의 한계

 

@Logging
public User getUser(Long userId) {
    testMethod(1);
    return userRepository.findById(userId);
}

@Logging
private void testMethod(int a) {

}

 

스프링의 AOP는 프록시 방식으로 적용되기 때문에,

private 메서드 혹은 같은 클래스 내 메서드를 호출할 경우 AOP가 작동하지 않습니다.

 

때문에 private 메서드 혹은 같은 클래스 내 메서드를 호출할 경우에는 AspectJ 사용을 고려해 볼 수 있습니다.

 

 

 

v4. AspectJ로 private 메서드도 AOP를 통한 Logging 적용시키기

Proxy 기반의 스프링 AOP와 달리, AspectJ는 컴파일 혹은 로드 타임에 바이트코드를 직접 수정하는 방식으로 이뤄집니다.

때문에 private 메서드나 같은 클래스 내 메서드를 호출할 경우에도 AOP가 동작합니다.

 

dependencies {
	implementation 'org.aspectj:aspectjrt:1.9.20.1'
	implementation 'org.aspectj:aspectjweaver'
}

bootRun {
    jvmArgs = ["-javaagent:${classpath.find { it.name.contains("aspectjweaver") }.absolutePath}"]
}

 

AspectJ 관련 의존성과 설정을 Gradle에 추가합니다.

 

<!DOCTYPE aspectj PUBLIC
        "-//AspectJ//DTD//EN"
        "https://www.eclipse.org/aspectj/dtd/aspectj.dtd">
<aspectj>
    <weaver options="-verbose">
        <!-- 모든 클래스에 적용 -->
        <include within="com.test.teststudio..*"/>
    </weaver>

    <aspects>
        <aspect name="com.test.teststudio.LoggingAspectV2"/>
    </aspects>
</aspectj>

 

main/resources/META-INF/aop.xml에 위 스프링 AOP 컨픽을 지정합니다.

 

클래스 : UserService, 메서드 : testMethod, 파라미터 : 1

 

정상적으로 로깅이 되는 모습이네요.

 

 

 

마치며

직접 로깅 코드를 삽입하여 로깅하는 방법부터,

스프링 AOP를 사용해 로깅이라는 공통 관심사(Cross-Cutting Concern)를

분리하여 비즈니스 로직 관련 코드로부터 로깅 관련 코드를 제거한 방법,

AspectJ를 사용해 private 메서드까지 로깅 AOP를 적용하는 방법까지 알아봤습니다.

 

로깅은 AOP의 대표적인 활용방법이며,

트랜잭션, 인증, 권한 검사, 예외 처리 등 여러 곳에 적용하여 공통 관심사를 분리할 수 있습니다.

AOP를 잘 활용하면 코드 재사용과 유지보수 측면에서 이점을 가질 수 있으나,

남용할 경우 프로그램의 흐름을 파악하는데 어려움이 생길 수 있으니,

현재 상황에 맞게 잘 활용해야 합니다.