[UMC 3기] Vibecap

Google vision, youtube data api를 사용하는 기능을 구현한 뒤 배포했는데 에러가 발생했다.
Docker process를 ec2의 백그라운드에서 실행되기 때문에 디버깅을 위해 stdout으로 출력되는 로그를 볼 수 없다. 그래서 로그를 파일로 출력하도록 설정해야겠다고 생각하게 되었다.

TL;DR

slf4j

logging 프레임워크들을 통일된 방법으로 다룰 수 있도록 해주는 interface이다. slf4j가 제공하는 API를 사용하여 코드를 작성하면 런타임에 바인딩된 logging framework (구현체)가 실제 기능을 수행한다. Spring boot에서는 이 구현체로 기본적으로 logback을 사용한다.

Logback’s architecture

logback은 세 부분으로 나뉜다.

  • logback-core : 나머지 두 모듈을 위한 환경을 제공한다.
  • logback-classic : log4j의 상당히 개선된 버전이다.
  • logback-access : servlet container와 함께 동작하여 HTTP-access log 기능을 수행한다.
    (자세한 내용은 여기 참고)

여기서부터 logback은 logback-classic 모듈을 의미한다.

logback의 main class : Logger, Appender, Layout
이 세 가지 component들은 message type과 level에 따라 message를 기록(log)하고 출력 형태를 결정하는 기능을 제공한다.

Logger context

System.out.println을 사용하지 않고 Logging API를 사용하는 이유는 특정 정보는 기록하지 않으면서 다른 정보는 출력되도록 만들수 있기 때문이다.
이런 장점은 logging space라는 것을 필요로 한다. Logging space란 기록 가능한 모든 statement의 집합이다. 이 statement들은 개발자가 정한 기준에 의해 분류되어 있다. Logback-classic에서 분류는 logger들의 특징(inherent part)이다. LoggerContext에 의해 생성된 logger들은 tree 형태로 logger들을 관리한다.

Logger는 이름을 가지는 개체(entity)이다. 대소문자를 구별하며 계층적 이름 규칙을 가진다

logger의 이름은 조상의 이름에 . 을 붙여 만든다.
"com.foo"라는 logger는 "com.foo.Bar"라는 logger의 부모이다.

Root logger는 tree 구조의 계층적 logger들 중 최상위 logger이다. Tree의 시작이 되는 logger이다. 다른 logger들과 마찬가지로 이름을 통해 획득(생성)할 수 있다.

Logger rootLogger = LoggerFactory.getLogger(org.slf4j.Logger.ROOT_LOGGER_NAME);

Retrieving Loggers

동일한 이름에 대해 LoggerFactory.getLogger 메서드를 호출하면 항상 똑같은 객체에 대한 참조를 반환한다.
(singleton pattern)

Effective Level (Level Inheritence)

Logger는 ch.qos.logback.classic.Level에 정의된 level 중 하나를 배정받는다.
ERROR, WARN, INFO, Debug, Trace
명시적으로 logger의 레벨을 결정하지 않는 경우, 가장 가까운 ancestor의 level을 상속받는다. Root logger는 항상 level을 가진다. 기본 값은 DEBUG이다.

logger-tree

  • assigned level : 사용자가 명시적으로 배정한 level
  • effective level : 해당 logger가 결과적으로 배정된 level

Printing methods and basic selection rule

Printing method는 logging request의 level을 결정한다. 예를 들어 logger instance L에 대해 L.info("hello");는 INFO 레벨의 logging statement이다.

Basic Selection Rule

Logger의 effective level보다 높거나 같은 level의 logging request만 승인(enabled)된다.
레벨은 ERROR > WARN > INFO > DEBUG > TRACE 순서이다. (ERROR가 제일 높음)

Appenders and Layouts

Logger의 레벨에 따라 logging request를 선택적으로 출력하는 것은 프레임워크의 일부에 불과하다.

appender

Logback은 다수의 destination에 logging request를 출력할 수 있다.
Logback에서 출력의 도착지를 appender라고 한다.
Appender는 logger의 계층적 구조를 따라 상속된다.

현재(2023.1.22 기준) appender로 가능한 대상은 console, files, remote socket servers, MySQL, PostgreSQL, Oracle 등이다.

하나의 logger에 여러 개의 appender를 등록(attack)할 수 있다.

addAppender 메서드는 주어진 logger에 appender를 추가한다. 모든 enabled request들은 logger에 등록된 appender로 전달(forward)된다. 뿐만 아니라 상속받은 appender에도 전달된다. 예를 들어 root logger에 console appender가 등록되어 있다면 모든 enabled request들은 기본적으로 console에 출력된다. 이렇게 appender를 상속받는 기본 동작을 override할 수 있다. Additivity flag를 false로 설정하면 appender를 상속지 않을 수 있다.

formatting

logback의 layout은 logging request에 대한 formatting을 담당한다.
PatternLayout을 사용해 C언어의 printf와 비슷한 output format을 지정할 수 있다.
%-4relative [%thread] %-5level %logger{32} - %msg%n
176 [main] DEBUG manual.architecture.HelloWorld2 - Hello world. 와 유사한 결과를 출력한다.

  • %-4 : 문자가 출력될 너비 지정(4칸)
  • the 1st field(%relative) : 프로세스가 시작한 뒤 지금까지의 경과시간 (elapsed time)
  • the 2nd field(%thread) : log를 출력하는 쓰레드
  • the 3rd field(%level) : logging request의 레벨
  • the 4th field(%logger) : logger의 이름
  • 나머지 부분 : logging request의 메세지

Parameterize logging

logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));

위와 같은 코드는 overhead를 발생시킨다. Parameter로 전달된 메세지를 생성(constructor 실행)해야 하고 그 과정에서 i와 entry[i]를 String 객체로 변환해야 한다. 그리고 그 결과 생긴 문자열들을 합쳐야 하는 등의 비용이 발생한다. 이렇게 생성되더라도 메세지가 출력될것이라는 보장은 없다. (request level < logger level인 경우 출력되지 않기 때문)

이 문제는 아래와 같은 코드로 해결할 수 있다.

if (logger.isDebugEnabled()) {
	logger.debug("Entry number: " + i + " is " + String.valueOf(entry[i]));
}

실질적으로 isDebugEnabled 메서드가 소비하는 시간은 로그를 출력하는 시간의 1% 미만이기 때문에 overhead는 무시 할만하다.

위의 방법(isDebugEnabled)보다 편리한 message formatting 방법이 존재한다.

formatting for performance

Object entry = new SomeObject();
logger.debug("The entry is {}.", entry);

이렇게 코드를 작성하면 오직 logging request가 출력되는 경우에만 메세지를 생성(format)한다. 즉, disabled log statement에 대해서는 parameter contruction 비용이 발생하지 않는다.
entry 객체를 문자열로 변환하여 {} 자리에 삽입한다. {}는 두 개 이상 사용 가능하다.

logger.debug("The new entry is {}. It replaces {}.", entry, oldEntry);

3.2Ghz Pentium D 를 사용한 machine에서 log request는 일반적으로 20ns(1억분의 2초)정도 소모한다. (단, parameter construction cost는 고려하지 않았다)

logging request 처리 과정

#### under the hood *com.wombat*이라는 logger에 대해 `info` 메서드를 호출하면 내부적으로 다음과 같은 과정이 진행된다. 1. filter : 각 logging request를 `Marker`, `Level`, `Logger` 등의 정보를 참고하여 평가한다. filter chain의 결과에 따라 2단계로 진행할지, 3단계로 진행할지 또는 해당 request를 무시할지 결정한다. 2. basic selection rule 적용 3. `LoggingEvent` 객체 생성 : request의 모든 매개변수 값을 가지는 객체를 생성한다. 4. Invoking appenders : 모든 가능한 appender의 `doAppend` 메서드 호출. 5. formatting the output : 원칙적으로 appender가 logging event를 포맷팅하지만 일부 appender는 layout 객체에 위임(delegate)한다. 6. sending out the `LoggingEvent` : 각 appender에 의해 지정된 목적지로 전송된다.

적용

configuration

  1. /resources/logback-prod.xml 파일 생성
<?xml version="1.0" encoding="UTF-8" ?>

<configuration scan="true" scanPeriod="30 seconds">

    <!-- 변수 설정 -->
	<property name="LOG_DIR" value="/Users/mingeun/logs" />
	<property name="LOG_PATH" value="${LOG_DIR}/data.log" />

	<!-- console appender -->
	<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
		<encoder>
			<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS}[%5level] : %msg%n</pattern>
		</encoder>
	</appender>

	<!-- file appender -->
	<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
		<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
			<level>WARN</level>
		</filter>
		<file>${LOG_PATH}</file>
		<!-- 날짜별로 로그파일 생성(rollover daily) -->
		<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
			<fileNamePattern>${LOG_PATH}.%d{yyyyMMdd}</fileNamePattern>
			<maxHistory>30</maxHistory> <!-- 최대 30일까지 백업파일 보관-->
		</rollingPolicy>
		<encoder>
			<pattern>%d{yyyy-MM-dd HH:mm:ss} %-5level %logger{32} - %msg%n</pattern>
		</encoder>
	</appender>
	<root level="debug">
		<appender-ref ref="STDOUT" />
		<appender-ref ref="FILE" />
	</root>
</configuration>

FileAppender가 출력할 대상 파일은 존재하지 않으면 새로 생성된다. (중간의 디렉토리까지도 생성한다)

  1. application.properties
logging.config=classpath:logback-spring.xml` 추가

reference

Comments