Logging 구현 정리

[jaejae-yoo]

로깅이란?

로깅은 시스템이 실행될 때, 시간의 경과에 따라 시스템의 상태 및 동작 정보를 기록하는 것을 말합니다.

• 로깅이 필요한 이유
  • 애플리케이션에 문제가 발생했을 경우, 문제를 파악하기 위해서는 당시의 동작 및 상태 정보가 필요합니다.
  • 사용자 로그 데이터를 활용할 수 있습니다.

SLF4J

Logger 추상체로 slf4j는 logback이나 log4j2와 같은 로깅 프레임워크의 인터페이스의 역할을 합니다.

Logback

로깅 프레임워크 중 하나로 SLF4J의 구현체이다.
Logback 은 log4j 이후에 출시된 Java 기반 Logging Framework 중 하나로 가장 널리 사용되고 있다

Logback 구조

Logback은 logback-core, logback-classic, logback-access 세 가지의 모듈로 이루어져 있습니다. (logback-core는 다른 두 모듈을 위한 기반 역할을 합니다.)
Logback은 Logger, Appender, Layout 세 가지 주요 클래스로 구성되어 있는데요. (Logger 클래스는 logback-classic 모듈에 속하며, Appender와 Layout은 logback-core에 속해 있습니다.)
이 세 가지 컴포넌트 타입은 개발자가 메시지 타입이나 레벨에 따라 로그를 기록할 수 있도록 하고, 런타임시에 어떤 형식으로 어디에 기록이 될지 제어할 수 있도록 합니다.

Logger Context

System.out.println 으로 출력을 하는 것에 비해 로깅 API가 갖는 이점 중 하나는 환경에 따라 특정 로그를 활성화/비활성화할 수 있다는 점입니다.
모든 단일 logger는 로거를 만드는 LoggerContext에 연결이 됩니다.

Named Hierarchy

Logger는 이름 규칙에 따라 계층을 파악할 수 있습니다.
Logger 이름 뒤에 dot(.)이 있으면 dot 이전의 이름을 가진 로거가 상위 로거입니다.
예를 들어, com.woowacourse.moamoa 라는 로거가 있고, com.woowacourse.moamoa.study 라는 로거가 있다면, com.woowacourse.moamoa 가 상위 로거입니다.

Level Inheritance

로거에는 레벨이 할당되기 때문에, 계층 구조에서 레벨 상속이 어떻게 이루어지는지 알아보도록 하겠습니다.

로거 X에 할당된 레벨은 INFO 인데요.
이를 상속한 X.Y는 할당한 Level이 없기 때문에 상속한 X 로거의 Level(INFO)을 상속하게 됩니다.
반면에 X.Y.Z는 로거 X.Y를 상속했지만, 할당된 ERROR Level이 존재하기 때문에 해당 레벨로 지정됩니다.

또한 로그의 레벨은 TRACE < DEBUG(SQL 로깅) < INFO < WARN < ERROR 이며 지정된 레벨 이하는 기록되지 않습니다.
예를 들어 로그 레벨이 INFO인 로거는 INFO, WARN, ERROR 레벨의 로그만 기록되는 것입니다.

Appenders

<appender name="WARN_LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
	//..
</appender>

<appender name="DEBUG_LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
	//..
</appender>

로그 파일에 작성했던 appender 중 일부인데요.
위에서 확인하실 수 있듯이 하나가 아닌, 여러 appender를 선언하여 원하는 로그를 기록할 수 있습니다.
여러 appender는 어떠한 동작으로 기록이 되는 것인지 알아보겠습니다.

Logback은 로그를 작성하는 작업을 Appender에게 위임하는데요.
Appender로 이용되기 위해서는 Appender 인터페이스를 구현해야 합니다.

따라서 AppenderBase 추상 클래스에서 Appender를 구현하고 있습니다.

AppenderBase 클래스에서는 다른 Appender가 사용할 기본적인 기능(name, activation status, layout and filters)들을 제공합니다.

여기서 AppenderBase 클래스의 doAppend() 메서드를 확인해 보시면 synchronized인 것을 확인할 수 있는데요.
따라서 위에서처럼 여러 appender들을 생성하여 동작하더라도, 안전하게 로깅 작업을 수행할 수 있었던 것입니다.
그리고 메서드의 this.append(eventObject); 부분에서 로그를 알맞는 곳에 실제로 추가하는 작업을 수행합니다.

Logback-core

Logback-core는 다른 logback 모듈의 기반이 되는 구성 요소들을 제공하는데요. Logback-core에서 제공하는 OutputStreamAppender, ConsoleAppender, FileAppender에 대해서 알아 보겠습니다.

OutputStreamAppender

OutputStreamAppender는 OutputStream에 로그 이벤트를 추가합니다.
일반적으로 해당 Appender를 직접적으로 사용하지 않고, ConsoleAppender와 FileAppender의 상위 클래스로 기본적인 세팅을 제공하고 있습니다.

ConsoleAppender

<appender name="STDOUT" 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>

<root level="INFO">
	<appender-ref ref="STDOUT"/>
</root>

ConsoleAppender는 System.out 또는 System.err를 이용하여 콘솔에 로그를 추가합니다.
ConsoleAppender는 사용자가 지정한 encoder를 통해 이벤트의 format을 지정합니다.

• property
  • encoder(Encoder): 로그 이벤트가 기록되는 방식
  • target(String, default: System.out): System.out or System.err
  • withJans(boolean, defalt: false)i: 콘솔 출력에 color 지원 여부

FileAppender

FileAppender는 파일에 로그를 추가합니다.

• property
  • append(boolean, default: true): true이면 존재하는 파일 뒤에 이어 붙입니다. false일 경우 기존 파일의 내용을 덮어씁니다.
  • file(String): 출력할 파일의 이름. 파일이 존재하지 않으면 생성합니다.
  • encoder(Encoder): 로그 이벤트가 기록되는 방식
  • prodent(boolean, default: false): true일 경우 타겟 파일을 다른 JVM에서 참조하고 있더라도 안전하게 작성할 수 있도록 합니다. prudent mode를 사용할 경우 false인 경우보다 write에 3배의 비용이 소요되게 됩니다.

RollingFileAppender

<appender name="DEBUG_LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
	//...
	<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
	    <fileNamePattern>./was-logs/debug.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
	    <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
	        <maxFileSize>100MB</maxFileSize>
	    </timeBasedFileNamingAndTriggeringPolicy>
	    <maxHistory>7</maxHistory>
	</rollingPolicy>
</appender>

RollingFileAppender는 FileAppender를 상속하여, 로그 파일을 rollover(일정 조건에 다다르면, 기록하던 대상 파일을 다른 파일로 바꾸는 것) 할 수 있도록 합니다.

• property
  • triggeringPolicy(TriggeringPolicy): rollover 활성화 기준
  • rollingPolicy(RollingPolicy): rollover 발생 시 RollingFileAppender의 동작
  • append(boolean, default: true): fileAppender와 동일
  • file(String): fileAppender와 동일
  • encoder(Encoder): fileAppender와 동일
  • prodent(boolean, default: false): fileAppender와 동일. TimeBasedRollingPolicy인데 prudent mode일 경우 파일 압축이 불가능하고, file 속성을 설정할 수 없다.
    TimeBasedRollingPolicy는 시간에 기반하여 rollover 기준을 정의할 수 있습니다.
    기록될 로그 파일들의 패턴을 정의하는 fileNamePattern 속성(String, default: %d: yyyy-MM-dd)이 필수입니다.

LevelFilter

<filter class="ch.qos.logback.classic.filter.LevelFilter">
    <level>DEBUG</level>
    <onMatch>ACCEPT</onMatch>
    <onMismatch>ACCEPT</onMismatch>
</filter>

LevelFilter는 지정한 level과 같은 level 로그 이벤트를 필터링합니다.
로그 이벤트가 지정한 level과 같다면 onMatch, 같지 않다면 onMismatch에 따른 FilterReply를 수행합니다.

• FilterReply
  • ACCEPT: 로그 이벤트를 정상적으로 동작시키고, 남아있는 Filter에 대해 검증하지 않는다.
  • DENY: 로그 이벤트 동작을 취소
  • NEUTRAL: 다음 Filter에게 검증을 넘긴다. 만약 남아있는 filter가 없다면 로그 이벤트가 정상적으로 동작된다.

텍스트로 읽었을 때, 어떻게 동작하는지 잘 와닿지 않을 수 있을 것 같아 직접 테스트를 해보았습니다.

1) level이 DEBUG이고, onMatch와 onMismatch가 모두 ACCEPT인 경우

단순한 GET 요청을 보냈을 경우 기록된 로그인데요. 기록된 로그 level을 보시면 DEBUG 이외에도 INFO 레벨도 기록이 된 것을 확인하실 수 있습니다. 즉, DEBUG 레벨이 아니더라도 onMicmatch가 ACCEPT이기 때문에 다른 레벨도 기록되는 것입니다.

2) level이 DEBUG이고, onMismatch가 DENY인 경우

반면에 같은 GET 요청을 보냈어도 onMismatch가 DENY이기 때문에, DEBUG가 아닌 다른 레벨의 로그는 작성되지 않은 것을 확인해 볼 수 있습니다.

Layout

로그 이벤트를 문자열로 변환하는 역할을 합니다.

<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
        <Pattern>[%d{yyyy-MM-dd HH:mm:ss}:%-3relative][%thread] %-5level %logger{36} - %msg%n</Pattern>
    </layout>
</appender>
PatternLayout

로그 이벤트를 입력한 문자열 패턴에 맞추어 변환합니다.

References

https://logback.qos.ch/manual/introduction.html
https://livenow14.tistory.com/64
https://tecoble.techcourse.co.kr/post/2021-08-07-logback-tutorial/