[개발관련] JAVA_ SLF4J와 Logback에 대한 이해(+ServiceLoader)

 

들어가며

실무에서 로그의 중요성을 체감하고 있습니다. 이번에 개발한 스케줄러에 예외 및 로깅을 보완하는 김에 로그의 기본적인 개념과 Java진영의 로그 라이브러리인 SLF4J, 그리고 LogBack 대하여 알아보았습니다. 

로그(Log)의 의미

과거 항해일지 등을 통나무(Log)에 기록한 것에서 유래하여 기록하는 것을 로그라고 칭한다고 합니다.
개발 분야에서는 시스템이나 애플리케이션 등이 남긴 기록을 로그라고 부릅니다. 로그는 문제 해결의 단서가 되기 때문에 트러블 슈팅을 할 때 로그를 잘 보는 것과 개발을 할 때 로그를 잘 남기는 것이 굉장히 중요합니다.
로그의 예로는 OS에서 기록하는 Syslog, Apache Tomcat이 기록하는 catalina.out 등이 있습니다. 그리고 이클립스나 인텔리제이 IDE에서 직접 소스 코드를 실행시킬 때 콘솔 창에 표준 출력되는 정보도 로그에 해당합니다.

System.out.println()를 이용한 콘솔 로그

처음 Java 개발을 배울 때는 소스 코드의 동작을 확인하기 위하여 System.out.println() 메서드를 많이 사용 하였습니다. 하지만 System.out.println() 메서드는 표준 출력으로 동기방식인 스트림을 사용하기 때문에 많이 사용할 경우 애플리케이션의 성능에 영향을 줄 수 있습니다. 개발 시점에 소스의 흐름이나 할당된 데이터등을 확인할 때는 IDE에서 제공하는 디버깅 기능을 사용하는 것이 더 효율적이기 때문에 저는 System.out.println()을 잘 사용하지 않는 편입니다. 그리고 표준 출력 Stream을 File Stream으로 변경해주지 않는 이상 System.out.println() 메서드는 로그 정보를 파일에 기록해주지 않기 때문에 콘솔에 출력됐던 로그 메시지는 휘발되어 버립니다. 

Filewriter를 이용한 로그 파일의 저장

로그 기록을 통해 애플리케이션이 동작했던 과거의 발자취를 검토해보는 것이 중요합니다.  따라서 텍스트 형태의 로그 파일에 로그 정보를 추가(Append)해서 저장할 필요가 있습니다. 위에서 예시로 들었던 catalina.out 텍스트 파일이 로그 정보가 누적되는 로그 파일에 해당합니다. 한 편 로그 파일을 분할하거나 로그 파일을 비워주는 별도의 설정을 하지 않을 경우 catalina.out 로그 파일이 수 십 기가바이트 이상의 용량을 차지하는 경우도 있습니다.
별도의 라이브러리나 로그 프레임워크 없이 로그 파일을 저장하는 방법에는 java.io.FileWriter 를 사용하는 방법이 있습니다. FileWriter 생성자의 두 번째 파라미터인 append를 true로 설정하여 파일명이 같은 파일에 데이터를 누적하여 기록할 수 있습니다. 해당 소스를 공용 메서드화 하여 재사용하면 간단하게 로그 파일을 기록할 수 있습니다. app_log_20240525.log처럼 파일명에 오늘 날짜를 덧붙여서 로그 파일명을 설정하여 하루에 한 개의 로그 파일이 저장되도록 할 수 있습니다.

   public FileWriter(String fileName, boolean append) throws IOException {
        super(new FileOutputStream(fileName, append));
    } 

logWriter = new PrintWriter(new FileWriter(LOG_FILE_PATH, true), true);
logWriter.println("[" + getCurrentLogTime() + "] " + logMessage);

하지만 더 많은 로깅 기능을 위해서는  추가적인 구현이 필요합니다. 바퀴를 다시 발명하지 말라는 명언이 있습니다. 이미 잘 만들어진 로그 라이브러리를 사용하고 본인이 구현해야 하는 비지니스 로직 개발에 집중을 하는 것이 좋다고 생각합니다. Java 진영에는 이미 잘 만들어진 훌륭한 로그 라이브러리들이 있습니다. 

결론은 Logger 

Logger logger = LoggerFactory.getLogger(this.getClass());  // 현재 클래스명으로 로거 이름 설정

Java 개발자로서 로그를 간편하게 사용하기 위한 결론은 Logger 타입의 참조변수 logger를 만들어서 Logger가 제공하는 메서드를 사용하는 것입니다. 그리고 필요 시 로그 관련 설정만 별도로 해주면 끝입니다. 기본적으로 Logger의 로그는 콘솔에 표준 출력이 되고 로그 파일로도 저장이 가능합니다. 그렇다면 이렇게 편리한 기능을 제공하는 Logger 가 무엇인지 한번 알아보겠습니다.
Logger의 풀네임은 org.slf4j.Logger
LoggerFactory의 풀네임은 org.slf4j.LoggerFactory 입니다.

Java 진영 로그 라이브러리의 표준 인터페이스 SLF4J

Simple Logging Facade for Java
직역하자면 "Java를 위한 간단한 로깅 파사드" 정도가 되겠습니다. 여기에서 파사드란 건물의 정면을 뜻하는 단어입니다. GoF디자인 패턴 중 파사드 패턴을 생각해 볼 수 있습니다. 파사드 패턴이란 뒤 쪽에 복잡하고 거대한 기능이 있지만 사용자가 사용하는 앞 쪽에는 단순한 인터페이스를 두는 패턴을 말합니다. 건물의 정면은 비교적 단순하지만 그 내부는 복잡함을 뜻하는 것에서 유래한 용어입니다. SLF4J가 제공하는 Logger 클래스도 마찬가지입니다. 복잡한 구현에 비해 Logger가 제공하는 메서드를 사용하는 것은 정말 간단합니다.

SLF4J

SLF4J는 구현체가 아닌 인터페이스

그렇다면 이렇게 편리하게 사용할 수 있는 로그 기능은 전부 SLF4J에 구현이 되어 있을까요? 아닙니다. SLF4J의 명칭에서도 나타나듯이 SLF4J는 파사드(인터페이스)입니다. 그리고 인터페이스의 구현은 다른 라이브러리들이 담당합니다. 

사용자(개발자) 는 SLF4J에만 의존한다. (도식일 뿐 UML은 아닙니다.)

출처: SLF4J

일반적인 조합 SLF4J + Logback

일반적으로 많이 사용하는 조합은 SLF4J 인터페이스로 Logback 구현을 사용하는 것입니다. Logback은 Log4j라는 로깅 라이브러리의 후속이라고 합니다. Logback 외에도 로깅 기능을 지원하는 라이브러리들이 있는데 Reload4j라는 라이브러리도 있습니다. Reload4J도 Log4j 1.x 버전의 보안 취약점을 개선하기 위한 Log4j의 후속이라고 합니다. 그리고 순수 Java 라이브러리인 java.util.Logging도 있습니다. 줄여서 JUL이라고 칭합니다. 여러 종류의 로깅 라이브러리 구현체들이 존재합니다. 구현체를 직접 사용할 수도 있습니다. 하지만 클라이언트 코드에서는 구상이 아닌 추상(SLF4J)에 의존함으로써 소스 변경 없이 손쉽게 로깅 구현 라이브러리를 교체할 수가 있습니다. 

Java 로깅 라이브러리의 세팅

Gradle 또는 Maven의 빌드 도구를 통해 의존성 라이브러리를 추가하거나 직접 Classpath에 의존성 라이브러리를 추가해 줌으로써 로깅 라이브러리를 사용할 수 있습니다. 아래는 Logback 의존을 추가하기 전의 모습입니다. (Spring boot starter로 프로젝트를 생성하면서 Quartz, Lombok의존을 추가하였고 이후 Maven repository에서 Spring web 의존을 추가하였습니다.) jul-to-slf4j:2.0.13 의존성이 함께 추가가 되어 있었습니다.

Maven repository 에서 Logback 라이브러리를 추가해 주었습니다.

테스트로 Log4j 라이브러리도 추가해 주었습니다.

결론적으로는 Logback 의존성 라이브러리를 클래스패스에 추가해서 애플리케이션을 실행시켰을 때 SLF4J는 Logback을 구현체로 바인딩하였습니다.

SLF4J는 구현체를 어떻게 바인딩하는가?

Spring처럼 Bean 등록을 하는 것도 아니고 의존성 라이브러리를 추가하는 것만으로 구현체를 사용한다는 것이 굉장히 궁금한 부분이었습니다. 결론적으로 SLF4J 2.0.0이상 부터는 클래스패스에서 SLF4JServiceProvider 구현체를 찾아 객체 리스트를 반환 받고 그 중 첫번째 요소를 바인딩 대상으로 사용합니다. 해당 과정에서 java.util.ServiceLoader 기능에 의존합니다.
저는 SLF4J 2.0.3 버전을 사용하였고 2.0.0 버전부터는 ServiceLoader을 이용하여 로깅 구현체를 찾는다고 되어 있습니다.

ServiceLoader (Java SE 22 & JDK 22)

SLF4J에서 ServiceLoader를 사용하는 소스코드는 Logger객체를 반환하는 LoggerFactory에서 찾을 수 있습니다. LoggerFactory의 findServiceProviders() 메서드에서는 Provider를 명시하지 않은 경우에는 Classpath에서 SLF4JServiceProvider의 구현 클래스를 찾아서 List로 반환합니다. 그리고 bind() 메서드에서는 List의 첫 번째 요소와 바인딩처리를 합니다.

LoggerFactory.class findServiceProviders()

LoggerFactory.class bind()

 
한편, ServiceLoader를 이용하면 런타임 시 클래스패스에서 찾고자 하는 클래스의 객체를 얻을 수 있습니다. 아래에서는 mysql 내의 Clob클래스를 파라미터로 넣어 테스트를 진행하였고 Clob 타입의 객체를 얻을 수 있었습니다. 같은 원리로 LoggerFactory는 런타임 시 SLF4J의 인터페이스를 구현한 클래스를 클래스패스 내의 jar 파일 속에서 찾아 객체화하여 사용하는 것입니다.

ServiceLoader 테스트, classpath 에서 CLOB 클래스를 로드

한편, 아래의 설명과 같이 /META-INF/services 내에 Load 할 서비스를 명시하는 방법도 있습니다.

/META-INF/services

Classpath 내 jar파일 안에 SLF4JServiceProvider를 구현한 클래스가  있다면 모두 찾습니다.  그리고 그 중 첫번째 요소를 바인딩합니다.
SLF4JServiceProvider인터페이스는 아래와 같습니다.

SLF4JServiceProvider

Logback의 ch.qos.logback.classic.spi.LogbackServiceProvider는 SLF4JServiceProvider를 구현하고 있습니다.

SLF4JServiceProvider를 구현한 LogbackServiceProvider

 

Logback 로그 설정 XML 샘플

/resource 하위에 logback-test.xml 및 logback.xml 파일을 배치함으로써 Logback의 로깅 설정을 할 수 있습니다. XML의 내용은 아래와 같습니다.
 

<?xml version="1.0" encoding="UTF-8"?>
 
<configuration scan="true" scanPeriod="60 seconds">
 
    <property name="LOG_PATH" value="./log"/>
    <property name="LOG_FILE_NAME" value="app_log"/>
    <property name="ERR_LOG_FILE_NAME" value="err_log"/>
    <property name="LOG_PATTERN" value="%-5level %d{yy-MM-dd HH:mm:ss}[%thread] [%logger{0}:%line] - %msg%n"/>
 
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_PATH}/${LOG_FILE_NAME}.log</file>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>${LOG_PATTERN}</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_PATH}/${LOG_FILE_NAME}.%d{yyyy-MM-dd}_%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>10MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <maxHistory>14</maxHistory> 
        </rollingPolicy>
    </appender>
 
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>${LOG_PATTERN}</pattern>
        </encoder>
    </appender>
 
    <appender name="Error" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>error</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <file>${LOG_PATH}/${ERR_LOG_FILE_NAME}.log</file>
        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
            <pattern>${LOG_PATTERN}</pattern>
        </encoder> <!-- Rolling 정책 -->
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_PATH}/${ERR_LOG_FILE_NAME}.%d{yyyy-MM-dd}_%i.log</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>10MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
            <maxHistory>365</maxHistory>
        </rollingPolicy>
    </appender>
 
    <root level="${LOG_LEVEL}">
        <appender-ref ref="CONSOLE"/>
        <appender-ref ref="FILE"/>
        <appender-ref ref="Error"/>
    </root>
 
    <logger name="jdbc" level="OFF"/>
    <logger name="jdbc.connection" level="OFF"/>
    <logger name="jdbc.sqlonly" level="OFF"/>
    <logger name="jdbc.sqltiming" level="OFF"/>
    <logger name="jdbc.audit" level="OFF"/>
    <logger name="jdbc.resultset" level="OFF"/>
    <logger name="jdbc.resultsettable" level="OFF"/>
 
</configuration>
 

 

Logback이 설정 파일을 찾는 방법

Chapter 3: Configuration

Logback이 로깅 설정 파일을 찾는 절차입니다.

1. ServiceLoader로  컨피그 Java 클래스를 찾습니다.(ch.qos.logback.classic.spi.Configurator 구현체) 없으면
2. 직렬화객체모델 설정파일을 찾습니다.(logback.scmo, logback-test.scmo) 없으면
3. XML 설정파일을 찾습니다.(logback.xml, logback-test.xml) 없으면
4. BasicConfigurator로 기본설정을 합니다. (콘솔 출력)

래퍼런스에서는 설정파일 로딩 시간을 줄이려면 1번 서비스 프로바이더 설정을 하라고 추천하고 있습니다. 홈페이지에는 XML을 Java 클래스로 변환시켜 주는 변환기가 있습니다.

log4j.properties Translator

 
아래의 클래스를 참고하였습니다. 로그에서 실제로 해당 클래스에서 소스를 실행하고 순서대로 설정파일을 찾는 것을 확인할 수 있습니다.
ch.qos.logback.classic.util.ContextInitializer
ch.cos.logback.classic.LoggerContext

Logback 초기 설정파일 로그

Logback ContextInitializer

결론

1. Java진영에서는 SLF4J 로깅 인터페이스와 구현체의 로깅 설정 방법만 알면 로깅을 쉽게 쓸 수 있습니다.
2. SLF4J와 Logback 둘 다 java.util.ServiceLoader를 사용합니다.
3. SLF4J가 로깅 구현 라이브러리를 바인딩하는 원리를 이해하였습니다.
4. Logback이 설정 파일을 찾는 원리를 이해하였습니다. (ServiceLoader로 설정 시간을 절약해보기)

출처

https://www.slf4j.org/docs.html
https://logback.qos.ch/documentation.html
https://docs.oracle.com/en/java/javase/22/docs/api/java.base/java/util/ServiceLoader.html   

 

*잘못된 부분이 있을 경우 댓글로 알려주시면 감사하겠습니다.