강력한 자바 오픈소스 로깅 프레임워크, logback 사용법 with example(스프링 부트에서 logback 가이드, logback-spring.xml 설정하기)

Logback 소개

Logback은 "자바 오픈소스 로깅 프레임워크"로 SLF4J의 구현체이자 스프링 부트의 기본 로그 객체다.

log4j, log4j2, JUL(java.util.logging)과 성능을 비교했을 때 logback은 훌륭한 성능을 보여준다.

그리고 결정적으로 자바 프로그램에서 로그를 사용할 때 가장 많이 사용되고 있기 때문에 알아두어야 한다.

Logback을 사용하기 위해서 아래의 모듈을 가져와야 한다. (maven 사용)

<!-- https://mvnrepository.com/artifact/ch.qos.logback/logback-classic -->
<dependency>
    <groupId>ch.qos.logback</groupId>
    <artifactId>logback-classic</artifactId>
    <version>1.2.3</version>
    <scope>test</scope>
</dependency>
 

* 스프링부트에서는 기본 로그이기 때문에 굳이 위의 dependency를 추가하지 않아도 사용가능하다.

spring-boot-starter-web 안에 spring-boot-starter-logging에 있다.

원래 Logback은 logback-core, logback-classic, logback-access로 구성되어있는데 logback-classic만 받아도 자동으로 내부에서 등록되어 있다.

logback을 이용해서 코드에서 로그를 찍을 때는 아래와 같이 간단하게 사용하면 된다.

package chapters.introduction;
 
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
 
public class HelloWorld1 {
  public static void main(String[] args) {
    Logger logger = LoggerFactory.getLogger("chapters.introduction.HelloWorld1");
 
    logger.trace("Hello world.");
    logger.debug("Hello world."); //debug level로 해당 메시지의 로그를 찍겠다.
    logger.info("Hello world.");
    logger.warn("Hello world.");
    logger.error("Hello world.");
  }
}

LoggerFactory에서 로거 객체를 불러온 후, 로거 객체를 이용해서 코드의 원하는 부분에 로그를 찍으면 된다.

사실 logging에서 중요한 부분은 무슨 내용을, 어디에, 어떻게 찍을 건지 관리하는 것이다.

logback은 그 부분을 따로 설정파일을 두어 세팅해놓고 사용은 위에서 본 것처럼 간단하게 사용한다.

---

Logback 설정 파일 관리하기

스프링이나 일반 자바프로그램의 경우는 보통 logback.xml 파일을 resources 디렉토리에 만들어서 참조한다.

그러나 스프링부트에서는 logback-spring.xml 파일을 만들어서 참조한다.

logback은 이 설정파일을 자동으로 찾는데 logback.groovy -> logback-test.xml -> logback.xml 순서로 찾고 없으면 디폴트 설정을 따른다.

* 스프링부트의 경우 조금 다르게 logback-spring.xml이라는 이름으로 설정하는데 그 이유는 logback.xml이라는 이름으로 이미 스프링부트가 설정되기 전에 로그백 관련 설정을 해버리기 때문에 logback.xml이라는 이름 대신 logback-spring.xml을 사용한다.

Logback 설정파일은 크게 두 부분(Appender, logger)으로 나뉜다.

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <property name="LOGS_ABSOLUTE_PATH" value="./logs" />
 
    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
        <layout class="ch.qos.logback.classic.PatternLayout">
            <Pattern>%d{HH:mm} %-5level %logger{36} - %msg%n</Pattern>
        </layout>
    </appender>
    <appender name="SAMPLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>[%d{yyyy-MM-dd HH:mm:ss}:%-3relative][%thread] %-5level %logger{35} - %msg%n</pattern>
        </encoder>
    </appender>
    <appender name="ROLLING" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOGS_ABSOLUTE_PATH}/logback.log</file>
        <encoder>
            <pattern>[%d{yyyy-MM-dd HH:mm:ss}:%-3relative][%thread] %-5level %logger{35} - %msg%n</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOGS_ABSOLUTE_PATH}/logback.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <!-- or whenever the file size reaches 100MB -->
                <maxFileSize>5MB</maxFileSize>
                <!-- kb, mb, gb -->
            </timeBasedFileNamingAndTriggeringPolicy>
            <maxHistory>30</maxHistory>
        </rollingPolicy>
    </appender>
    
    <logger name="com.apress.spring" level="DEBUG">
        <appender-ref ref="SAMPLE" />
    </logger>
    <logger name="com.apress.spring.jeongpro" level="INFO">
        <appender-ref ref="ROLLING" />
    </logger>
    <root level="INFO">
        <appender-ref ref="STDOUT" />
    </root>
</configuration>

appender는 어디에, 어떻게 로그를 찍을 것인지에 대한 설정을 하는 부분으로 위의 예시에는 "STDOUT", "SAMPLE", "ROLLING"으로 3개를 만들어보았고,

logger는 해당 appender들을 참조하며 해당 로거가 사용될 패키지와 로그레벨을 지정한다.

간단하게 위 설정파일을 먼저 분석해보겠다.

<property> 엘리먼트는 해당 설정파일에서 사용될 값을 정의하는 것으로, 위에서는 "LOGS_ABSOLUTE_PATH" 라고 로그가 쌓일 절대경로를 지정했다. (사실 값이 "./logs" 이기 때문에 상대경로다.)

<appender>의 경우 logback에서 지원하는 종류가 정해져있다.

* Appender 종류

ConsoleAppender : 콘솔에 로그를 찍는 방법

FileAppender : 파일에 로그를 찍는 방법

RollingFileAppender : 여러개의 파일을 순회하면서 로그를 찍는 방법

SMTPAppender : 로그를 메일에 찍어 보내는 방법

DBAppender : 데이터베이스에 로그를 찍는 방법

기타 SocketAppender, SSLSocketAppender등이 있다.

위의 예시에는 가장 자주 사용되는 Console 과 RollingFile Appender를 사용했다.

"STDOUT"의 방법의 경우 옛날식 코드고 요즘은 "SAMPLE" 처럼 사용한다.

* layout과 encoder의 차이점은 레이아웃은 들어오는 이벤트를 String으로 변환하고 이벤트가 기록될 때 제어할 수 없으며 이벤트를 일괄 처리로 집계할 수 없다.

반면에 encoder는 바이트를 소유하고 있는 appender가 관리하는 OutputStream에 쓸 시간과 내용을 완전히 제어할 수 있다.

FileAppender와 하위 클래스는 encoder를 필요로 하고 더 이상 layout은 사용하지 않는다.

내부에서 로그를 찍을 pattern을 정의한다.

패턴에 사용되는 각 요소가 의미하는 바는 아래에 정리한다.

* 패턴에 사용되는 요소

1. %Logger{length}

- Logger name을 축약할 수 있다. {length}는 최대 자리 수

2. %thread

- 현재 Thread 이름

3. %-5level

- 로그 레벨, -5는 출력의 고정폭 값

4. %msg

- 로그 메시지 (=%message)

5. %n

- new line

6. ${PID:-}

- 프로세스 아이디

기타

%d : 로그 기록시간

%p : 로깅 레벨

%F : 로깅이 발생한 프로그램 파일명

%M : 로깅일 발생한 메소드의 이름

%l : 로깅이 발생한 호출지의 정보

%L : 로깅이 발생한 호출지의 라인 수

%t : 쓰레드 명

%c : 로깅이 발생한 카테고리

%C : 로깅이 발생한 클래스 명

%m : 로그 메시지

%r : 애플리케이션 시작 이후부터 로깅이 발생한 시점까지의 시간

위에서 작성한 pattern 룰에 의해서 정의된 Appender는 <logger>가 참조해서 해당 로거를 사용하는 곳은 Appender설정대로 로그가 찍힌다.

<logger>는 appender-ref 엘리먼트로 appender를 참조하고 name속성으로 해당 패키지 이하에서는 해당 logger를 사용하게 지정한다. 또한 로그레벨을 지정해서 해당 로그 레벨 이하의 것만 찍게 만든다.

* 로그 레벨(Log level)

ERROR < WARN < INFO < DEBUG < TRACE

해당 레벨 이하의 것은 다 찍는다고 했다. 이 말은

INFO 레벨로 지정하면 INFO, WARN, ERROR 로그가 찍히고, WARN 레벨로 지정하면 WARN, ERROR 로그가 찍힌다.

FATAL은 없고 TRACE, DEBUG 레벨로 찍을 경우 로그가 상당히 많이 찍히므로 주의해야한다.

RollingFileAppender의 경우는 설정할 것이 많아 자세히 봐야한다.

여기서는 상관없지만 Rolling이 아닐 경우 <file> 엘리먼트로 어디에 어떤 이름의 파일로 기록할지를 설정해야한다.

그리고 똑같이 encoder안에 pattern을 정의한다.

RollingFile이기 때문에 Rolling 정책을 적어야한다.

<filePattern>으로 순서대로 작성될 파일명을 지정해주고, <maxFileSize>로 한 파일당 최대 크기를 지정한다.

참고로 파일을 입출력할 때 안에 있는 내용의 크기도 IO성능에 영향을 미치기 때문에 되도록이면 너무 크지 않은 사이즈로 지정하는 것이 좋다. (보통 10MB)

단위는 KB, MB, GB 3가지를 지정할 수 있고, RollingFile 이름 패턴에 .gz 이나 .zip을 입력할 경우 로그파일을 자동으로 압축해주는 기능도 있다. (.gz, .zip 이외의 확장자에 대해서는 압축기능이 없는 듯하다.)

<maxHistory>는 파일의 개수다.

예를들어서 maxHistory가 30이고 Rolling정책을 일 단위로 하면 30일동안만 저장되는 것이고 월 단위로 하면 30개월간 저장되는 것이다.

마찬가지로 이렇게 설정된 appender를 logger로 매핑하면 되는 것이다.

<root>는 <logger>와 같은데 최상위 패키지에 기본적으로 적용되는 것이라고 생각하면된다.

---

* Filter 기능

해당 패키지에 무조건 로그를 찍는 것말고도 필터링이 필요한 경우에 사용하는 기능이다.

간단하게 몇 가지만 확인하고 나머지는 메뉴얼을 확인해보자

<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/error.log</file>
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
        <fileNamePattern>Log/error-%d{yyyy-MM-dd}.%i.txt</fileNamePattern>
        <maxFileSize>100MB</maxFileSize>
        <maxHistory>60</maxHistory>
        <totalSizeCap>10GB</totalSizeCap>
    </rollingPolicy>
    <encoder>
        <pattern>%d{yyyy-MM-dd HH:mm:ss.SSS}[%-5level] : %msg%n</pattern>
    </encoder>
</appender>

레벨 필터를 추가해서 level이 error인 것만 찍게 만들었다.

레벨에 따라 다른 곳에 찍는 것도 가능하다.

<appender name="CONSOLE-DEVELOP" class="ch.qos.logback.core.ConsoleAppender">
    <filter class="ch.qos.logback.core.filter.EvaluatorFilter">
        <evaluator>
            <expression>
                if ( logger.startsWith("com.tistory.jeongpro") ){
                     return true;
                }
                return false;
            </expression>
        </evaluator>
        <OnMismatch>DENY</OnMismatch>
        <OnMatch>ACCEPT</OnMatch>
    </filter>
    <encoder>
        <charset>UTF-8</charset>
        <pattern>[%d] [%highlight(%-5level)] %logger[%cyan(%method:%line)] - %msg %n</pattern>
    </encoder> 
</appender>

위의 것은 EvaluatorFilter를 사용한 것으로 <expression>에 있는 표현식에 따라 해당되는 것만 출력할 수 있다.

여기서는 com.tistory.jeongpro 패키지로 시작하는 로거만 찍게 해놨는데 원하면 message.startsWith("jeongpro")로 로그메시지가 "jeongpro"로 시작하는지 검사할 수도 있고, logger.toUpperCase().contains("DAO")로 DAO가 포함되어있으면 DB의 내용이겠구나를 알고 필터링할 수도 있다.

---

* 참고 사항

- 부가 기능으로 Dynamic Reloading 기능을 지원하는데 <configuration scan="true" scanPeriod="30 seconds"> 라고 지정하면 30초 주기마다 해당 로그파일(logback-spring.xml)이 바뀌었는지 검사하고 바뀌었으면 프로그램 실행중에도 즉각 반영된다.

- <logger name="com.tistory.jeong-pro" level="DEBUG" additivity="false" /> 에서 additivity를 false로 하는 것은 해당 로거가 해당 패키지에서만 적용되고 하위 패키지에서는 적용되지 않는 것을 의미한다. (default = true)

- appender에서 로그 파일의 경로를 지정할 때 주의해야 할 것이 있다. 윈도우의 경우에 특유의 파일 생성 권한 문제가 생길 수 있다.

C:\ 나 C:\Program Files\ 같은 경우에는 권한없이는 생성이 어려워 로그 파일이 쌓일 디렉토리를 적절한 곳으로 지정할 필요가 있다.

- prudent 모드가 있는데 이것은 여러개의 JVM이 가동중인 상황에서 그 프로그램들이 하나의 파일에 로그를 수집하는 기능이 있는 모드다. 참고로 동시성 문제 때문에 성능이 떨어진다.

- application.properties파일같은 설정파일을 이용해서도 간단하게 logback 설정을 바꿀 수 있다.

디테일한 설정을 위해서는 따로 .xml파일을 작성하는 것이 좋고 간단하게만 바꿀 때는 yaml또는 properties파일에서 바꾸는 것이 좋아 보인다.

---

실제 테스트

실제 테스트에서는 위와 같이 패키지를 다르게해서 Appender를 이용한 로그 설정을 다르게 주는 방식을 택했다.

(참고로 테스트에서는 웹서비스만 하는것이 아니라 쓰레드마다 다르게 로그를 작성해야하는 이유가 있기 때문에 저렇게 테스트코드를 짰다.)

테스트 설정파일은 가장 상단의 예시와 같고 해당 로그를 찍는 클래스들은 위의 사용법대로 로그만 반복해서 찍는 것으로 테스트했다.

[스프링 부트 기본 로그 세팅의 모습]

[로그레벨을 DEBUG로 바꾼 모습]

[5MB로 RollingFileAppender를 사용한 모습]

[.gz으로 압축된 로그가 생성되는 모습]

참고로 로그파일을 쓰는 중에는 안보이고 하나의 압축파일이 완성되야 보였다.

SMTPAppender 샘플 코드를 가져왔다.

위 양식에 맞추어 넣고 SMTP 서버를 마련하면 잘 될 것이다.

---

* Logback 메뉴얼 : https://logback.qos.ch/manual/index.html

* 개인적인 생각으로 로그 내용을 육하원칙에 따라 찍으면 더 좋을 것 같고, 하나의 요소다가 ","(콤마)를 찍어서 구분하면(.csv파일 형식) 나중에 분석할 때도 유용할 것 같다.

참고 사이트

http://forgiveall.tistory.com/493

http://yongho1037.tistory.com/722