로그에 클래스, 메소드명 자동 출력하기

• 언어: JAVA
• Logging Framework: logback

팀 컨벤션 혹은 원활할 디버깅을 위해 로그에 클래스명과 메소드명을 출력하는 경우가 있다.

가장 쉬운 방법은 로그에 하드코딩으로 집어넣는 방법일 것이다.

log.info("[Class][Method] Message occurred.")

하지만 클래스, 메소드명이 바뀔 때마다 수동으로 챙겨줘야하는 불편함이 있다.

그래서 클래스, 메소드명을 자동으로 출력할 수 있는 2가지 방법을 소개한다.

log.info("method called");

2024-06-22 18:07:53.409 INFO 7905 --- [ main] d.h.s.methodlog.MethodLogService : [MethodLogService][log] method called

---

① 애노테이션으로

[장점] 로그 출력을 하고 싶은 클래스에 선택적으로 할 수 있다.

[단점] 로그 출력을 하고 싶은 클래스가 많다면 일일이 애노테이션 붙여주기 귀찮다. ② 번 방법에 비해 구현량이 많다.

사용법

@Slf4j
@ClassMethodLog
public class MethodLogService {
    public void log() {
        log.info("method called");
    }
}

2024-06-11 22:05:01.977 INFO 16000 --- [ main] d.h.s.methodlog.MethodLogService : [MethodLogService][log] method occurred

@ClassMethodLog 애노테이션을 달아주면 로그문에 “[클래스명][메소드명]” 이 접두어에 자동 출력된다.

구현 방법

(1) Annotation 만들기

ClassMethodLog.java

@Target({ElementType.TYPE})
@Retention(RetentionPolicy.RUNTIME)
public @interface ClassMethodLog {

}

@ClassMethodLog 라는 애노테이션이다. 클래스 레벨에 붙일 수 있다.

애노테이션을 생성할 때는 Class 가 아니라 Annotation 타입을 선택한다.

MethodLogAspect.java

@Aspect
@Component
@Slf4j
public class MethodLogAspect {

    @Around(value = "@within(dev.elsboo.springaopsample.methodlog.aop.ClassMethodLog)")
    public Object methodLog(ProceedingJoinPoint joinPoint) throws Throwable {

        MDC.put("classMethodName", String.format("[%s][%s] ", joinPoint.getTarget().getClass().getSimpleName(), joinPoint.getSignature().getName()));

        try {
            return joinPoint.proceed();
        } finally {
            MDC.remove("classMethodName"); 
        }
    }
}

• @ClassMethodLog 가 붙은 클래스의 모든 메소드에 기능을 적용한다. (weaving)
• AOP 를 활용해 애노테이션을 붙었을 때 어떻게 동작하게 할 것인지 구현한다. (advice)

<구현내용>

• MDC 라고 값을 담을 수 있는 컨텍스트가 있다. slf4j 에서 제공한다.
• MDC 에 담은 값은 logback.xml 에서 접근할 수 있다.
• MDC 에 key 가 classMethodName , value 가 “[클래스명][메소드명]” 를 넣는다.

(2) logback-spring.xml 에 넣어주기

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true">
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%clr(%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd HH:mm:ss.SSS}}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} %X{classMethodName} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}</pattern>
        </encoder>
    </appender>
    <root level="INFO">
        <appender-ref ref="STDOUT"/>
    </root>
</configuration>

• <pattern> 식 중간에 추가한 %X{classMethodName} 가 핵심이다.
• %X{classMethodName} : %X{} 는 MDC 필드를 출력해주고 없다면 출력하지 않는다. 애노테이션을 달아줄 경우 MDC에 classMethodName key 를 넣어주기 때문에 출력 가능하다.
• 기존 <pattern> 식은 org.springframework.boot.logging.logback.default.xml 에서 가져왔다.

---

② logback-spring.xml 설정파일만 변경

[장점] 선택적이 아닌 전체적으로 로깅 출력이 필요할 때 좋다. ① 번 방법에 비해 간단히 구현할 수 있다.

[단점] [자식 클래스]에서 [부모 클래스] 메소드를 호출하면 [부모 클래스]가 찍힌다. (밑에서 설명)

사용법

@Slf4j
public class MethodLogService {
    public void log() {
        log.info("method called");
    }
}

2024-06-11 22:05:01.977 INFO 16000 --- [ main] d.h.s.methodlog.MethodLogService : [MethodLogService][log():15] method occurred

클래스 변경 없이 클래스명, 메소드명, 메소드 라인이 출력된다.

구현 방법

logback-spring.xml 수정하기

기본 로그 포맷으로 출력할 때

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true">
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>%clr(%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd HH:mm:ss.SSS}}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}) %clr(${PID:- }){magenta} %clr(---){faint} %clr([%15.15t]){faint} %clr(%-40.40logger{39}){cyan} %clr(:){faint} [%C{0}][%M:%L] %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}</pattern>
        </encoder>
    </appender>
    <root level="INFO">
        <appender-ref ref="STDOUT"/>
    </root>
</configuration>

<pattern> 식 중간에 추가한 [%class{0}][%M:%L] 가 핵심이다.

• %class{0}, %M, %L 은 logback 이 제공하는 레이아웃이다.
• %class{0} : Class name
• %M : Method name
• %L : Line number

기존 <pattern> 식은 org.springframework.boot.logging.logback.default.xml  에서 가져왔다.

Json 으로 출력할 때

로그를 json 으로 출력해야하는 경우, LogstashEncoder 를 쓰는 방법도 있다. 하지만 LogstashEncoder 는 <pattern> 커스터마이징이 안 되기 때문에 사용할 수 없다. 대신 LoggingEventCompositeJsonEncoder 로 대체하면 json 으로 출력할 수도 있고 클래스, 메소드명을 자동으로 넣어줄 수도 있다.

<?xml version="1.0" encoding="UTF-8"?>
<configuration debug="true">
    <include resource="org/springframework/boot/logging/logback/defaults.xml"/>
    <include resource="org/springframework/boot/logging/logback/console-appender.xml"/>
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="net.logstash.logback.encoder.LoggingEventCompositeJsonEncoder">
            <providers>
                <!--timestamp 필드-->
                <timestamp>
                    <fieldName>timestamp</fieldName>
                    <pattern>yyyy-MM-dd HH:mm:ss.SSS</pattern>
                </timestamp>

                <!--@version 필드-->
                <version/>

                <!--message 필드-->
                <pattern>
                    <pattern>
                        {
                        "message": "[%class{0}][%M:%L] %m"
                        }
                    </pattern>
                </pattern>

                <!--logger_name 필드-->
                <loggerName/>

                <!--thread 필드-->
                <threadName>
                    <fieldName>thread</fieldName>
                </threadName>

                <!--level 필드-->
                <logLevel/>

                <!--level_value 필드-->
                <logLevelValue/>

                <!--exception 필드-->
                <stackTrace>
                    <fieldName>exception</fieldName>
                </stackTrace>

                <!--mdc 필드-->
                <mdc>
                    <fieldName>mdc</fieldName>
                </mdc>

                <!--mdc 필드에 현재 context 추가-->
                <context/>

                <!--caller_class_name, caller_method_name, caller_file_name, caller_line_number 필드-->
                <callerData/>
            </providers>
        </encoder>
    </appender>
    <root level="INFO">
        <appender-ref ref="STDOUT"/>
    </root>
</configuration>

<json 출력문>

{"timestamp":"2024-06-22 20:42:38.004","@version":"1","message":"[MethodLogService][log:13] method called","logger_name":"dev.elsboo.springaopsample.methodlog.MethodLogService","thread":"main","level":"INFO","level_value":20000,"mdc":{"classMethodName":"[MethodLogService][log] "},"caller_class_name":"dev.elsboo.springaopsample.methodlog.MethodLogService","caller_method_name":"log","caller_file_name":"MethodLogService.java","caller_line_number":13}

※ [자식 클래스]에서 [부모 클래스] 메소드를 호출하면 [부모 클래스]가 찍힌다.

[자식 클래스]에서 [부모 클래스] 메소드를 호출하는 시나리오에 대해 ① 애노테이션 기반과 ② logback-spring.xml 기반 결과 비교를 해볼 것이다.

상황

자식클래스

@Service
@Slf4j
@ClassMethodLog
public class ExtendsMethodLogService extends MethodLogService {
    public void log() {
        super.log();
    }
}

부모클래스

@Service
@Slf4j
@ClassMethodLog
public class MethodLogService {
    public void log() {
        log.info("method called");
    }
}

① 애노테이션 기반

2024-06-16 13:30:04.851 INFO 733 --- [ main] d.h.s.methodlog.MethodLogService : [ExtendsMethodLogService][log] method occurred

② logback-spring.xml 기반

2024-06-16 13:28:44.123 INFO 251 --- [ main] d.h.s.methodlog.MethodLogService : [MethodLogService][log:15] method occurred

→ ① 애노테이션 기반 이 더 정확하다

 

※ 위에 나온 코드는 깃에서 클론받아 테스트해볼 수 있다.

https://github.com/AwesomeHye/spring-aop-sample