로깅 정책

Chocomilk
Dong-gle
Published in
13 min readSep 5, 2023

1. 로그백 설정 알아보기

스프링에선 기본적으로 Slf4j 인터페이스의 구현체인 Logback에 대한 의존성을 가지고 있습니다. 따라서 Logback을 기반으로 로깅 설정을 진행하였습니다. 설정은 logback-spring.xml을 통해 진행하였습니다.

본격적으로 동글이 적용한 로그백 설정에 대해서 설명하기 전, 간단하게 로그백 설정 기능들에 대해서 설명하겠습니다.

로그백 설정 기능에는 크게 Appender와 Filter가 존재합니다.

1.1. Appender란?

Appender는 쉽게 말해 어디에 출력할지 설정하는 속성입니다. 다음과 같은 설정들이 존재합니다.

  • FileAppender : 파일에 저장
  • RollingFileAppender : 파일에 일정한 시간주기 혹은 일정한 크기 이상이되면 파일에 저장
  • ConsoleFileAppender : 콘솔에 파일을 저장(출력)

1.2. Filter란?

Filter는 로그의 어떤 레벨을 특정하여 저장할 것인지 설정하는 속성입니다. 다음과 같은 설정들이 존재합니다.

  • LevelFilter : 특정 레벨만 저장
  • ThresholdFilter : 특정 레벨 이상을 저장

이제 동글에서 어떻게 로그백 설정을 하였는지 설명하겠습니다.

2. 로그백 설정 적용

2.1. local 환경

<springProfile name="local">
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>${CONSOLE_LOG_PATTERN}</pattern>
<charset>utf8</charset>
</encoder>
</appender>
<root level="info">
<appender-ref ref="CONSOLE"/>
</root>
</springProfile>

local 프로필은 개발자가 자신의 로컬 환경을 뜻합니다. 이 환경에서는 개발자가 IDE의 콘솔을 통해 어떤 로그가 발생했는지 알아야한다고 생각했기에 ConsoleAppender를 사용해 콘솔에 로그를 출력하도록 하였습니다.

기본 로그 레벨(root)은 info로 설정하였고, 이를 통해 info레벨 이상의 레벨인 info, warn, error 로그가 콘솔에 찍히게 됩니다. appender-ref 태그의 ref 속성에, 위에서 설정했던 appender의 name을 명시해주면 appender를 등록할 수 있습니다.

2.2. prod, dev 환경

<springProfile name="prod,dev">
<include resource="org/springframework/boot/logging/logback/defaults.xml"/>
<appender name="WARN_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>logs/warn/warn.log</file>
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>WARN</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%X{requestId}] [%X{requestUrl}] [%X{clientIP}] [%thread] %-5level %logger{36} - %msg%n</pattern>
<charset>utf8</charset>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>logs/warn/%d{yyyy-MM-dd}.%i.log</fileNamePattern>
<maxFileSize>100MB</maxFileSize>
<maxHistory>30</maxHistory>
<totalSizeCap>3GB</totalSizeCap>
</rollingPolicy>
</appender>

<appender name="ERROR_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>logs/error/error.log</file>
<filter class="ch.qos.logback.classic.filter.LevelFilter">
<level>ERROR</level>
<onMatch>ACCEPT</onMatch>
<onMismatch>DENY</onMismatch>
</filter>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%X{requestId}] [%X{requestUrl}] [%X{clientIP}] [%thread] %-5level %logger{36} - %msg%n</pattern>
<charset>utf8</charset>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>logs/error/%d{yyyy-MM-dd}.%i.log</fileNamePattern>
<maxFileSize>100MB</maxFileSize>
<maxHistory>30</maxHistory>
<totalSizeCap>3GB</totalSizeCap>
</rollingPolicy>
</appender>

<appender name="APPLICATION_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<file>logs/application/application.log</file>
<filter class="ch.qos.logback.classic.filter.ThresholdFilter">
<level>INFO</level>
</filter>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%X{requestId}] [%X{requestUrl}] [%X{clientIP}] [%thread] %-5level %logger{36} - %msg%n</pattern>
<charset>utf8</charset>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>logs/application/%d{yyyy-MM-dd}.%i.log</fileNamePattern>
<maxFileSize>100MB</maxFileSize>
<maxHistory>30</maxHistory>
<totalSizeCap>3GB</totalSizeCap>
</rollingPolicy>
</appender>
<root level="INFO">
<appender-ref ref="WARN_FILE"/>
<appender-ref ref="ERROR_FILE"/>
<appender-ref ref="APPLICATION_FILE"/>
</root>
</springProfile>

prod와 dev는 각각 운영과 개발 환경을 의미합니다. 이 환경에서는 애플리케이션을 서버에 배포하여 사용하기 때문에, 굳이 콘솔에 로그를 출력할 필요는 없습니다. 그저 로그를 파일에 저장하는 것이 사후에 어떤 일이 발생했는지 확인하는 데에 효과적일 것입니다.

Appender 설정

파일로 로그를 저장하는 설정인 FileAppenderRollingFileAppender 를 비교해보겠습니다.

RollingFileAppenderFileAppender와 비교해 다음과 같은 설정을 추가할 수 있습니다.

  1. TimeBasedRollingPolicy : 특정 시간마다 롤링
  2. FixedWindowRollingPolicy : 특정 용량에 도달하면 롤링
  3. SizeAndTimeBasedRollingPolicy : 특정 시간 + 특정 용량에 도달하면 롤링

롤링이란 현재 작성중인 파일을 다른 파일로 분리하여 저장한다고 생각하면 됩니다. 동글은 RollingFileAppender의 롤링 정책 중에서도 3번 SizeAndTimeBasedRollingPolicy을 선택하였는데, 이는 1번처럼 특정 시간마다 롤링을 할 수도 있고, 동시에 2번처럼 하나의 파일이 너무 커지지 않게 관리할 수 있기 때문이었습니다.

이를 통해 파일을 조금 더 관리하게 쉽게 하였습니다.

Filter 설정

동글에서는 로그를 다음과 같이 로그 레벨에 따라 로그 파일을 분리하였습니다.

  1. INFO 레벨 이상 (ThresholdFilter)
    → 애플리케이션의 전반적인 운영을 확인하기 위함
  2. WARN 레벨 (LevelFilter)
    → 클라이언트에서 발생하는 예외를 확인하기 위함
  3. ERROR 레벨 (LevelFilter)
    → 서버에서 발생하는 예외를 확인하기 위함

위와 같이 설정함으로써 원하는 레벨의 로그들만 모아서 볼 수 있게 하였습니다.

3. MDC 적용

추가적으로 사용자의 요청이 동글 애플리케이션 전반의 코드에서 어떤 영향을 미치는지 추적하기 위해 MDC를 사용했습니다.

3.1. 문제 상황

서버에서 하나의 요청은 쓰레드 풀에서 하나의 쓰레드를 할당 받아 처리하게 되는데, 문제는 하나의 쓰레드가 애플리케이션 전반에 거쳐 기록을 남기고 싶을 때, 다른 스레드의 기록도 섞여져서 남기 때문에 로그만 보고 특정 로그를 추적하기 어렵다는 점이었습니다.

운영을 할 때에 어떤 IP에서 어떤 URI로 접근했고, 한 요청에 어떤 동작들을 하였는지 로그를 추적하기 위해서 MDC를 적용하여 해결하고자 하였습니다.

3.2. MDC란?

MDC(Mapped Diagnostic Context)는 현재 실행중인 쓰레드에 정보를 넣고 관리할 수 있는 공간입니다. 즉, MDC는 쓰레드 로컬을 사용하는데, 쓰레드 로컬이란 해당 쓰레드에서만 사용하는 공간입니다.

아래와 같이 똑같은 쓰레드 로컬 변수에 대해서 ThreadAThreadB가 각각 “userA”와 “userB”를 저장하더라도, 값이 덮어씌워지지 않고 get()을 호출했을 때 온전한 값을 가져올 수 있습니다. 즉, 해당 쓰레드만 전용으로 사용할 수 있는 공간이라고 생각할 수 있습니다.

MDC 또한 이런 쓰레드 로컬을 사용하는데, 내부적으로 값을 Map으로 관리하고 있어 (key, value) 형태로 값을 저장할 수 있다는 특징을 가지고 있습니다.

3.3. MDC 적용

MDC 설정을 위한 인터셉터를 최전방에 배치하였고, 해당 인터셉터에서 requestId, requestUrl, clientIP 정보를 MDC를 활용해 쓰레드 로컬 변수에 넣어주었습니다.

requiestId에는 UUID를 저장하여 요청마다 고유한 값을 주었습니다. 이를 통해 하나의 요청이 애플리케이션에서 어떤 활동을 했는지 추적할 수 있게 하였습니다

requestUrl에는 어떤 자원을 요청했는지 나타내어, 사용자가 어떤 핸들러를 통해 들어왔는지 간단하게 확인할 수 있게 하였습니다.

clientIP에는 말 그대로 사용자의 IP 정보를 넣어주어, 어떤 IP에서 요청이 들어왔는지 쉽게 확인할 수 있게 하였습니다.

쓰레드 로컬 변수를 사용했다면 꼭 마지막에 값을 비워주어야 합니다. 쓰레드 풀을 사용하고 있는 상황에서 이전의 쓰레드가 사용했던 변수의 값이 있었는데 값을 비워주지 않고 풀에 반납하게 되면, 다음에 이 쓰레드를 사용하는 요청에서는 오염된 값을 사용할 여지가 있기 때문입니다. 따라서 인터셉터의 afterCopletion 메서드에서 MDC.clear()를 통해 쓰레드 로컬 변수 값을 해제해 주었습니다.

3.4. MDC 사용

인터셉터에서 하나의 요청에 대해 MDC 설정들을 모두 완료했습니다. 이제 이후의 애플리케이션 로직에서 log.info("requiestId = {}", MDC.get(requestId)) 을 호출하면 해당 쓰레드가 가지고 있는 고유한 값을 쓰레드 로컬에서 가져오게 됩니다.

하지만 문제는 로그를 찍을 때마다 MDC.get(~~)을 호출해줘야한다는 번거로움이 있습니다. 이를 로그백에서는 다음과 같은 로그 패턴 설정으로 해결할 수 있습니다.

<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%X{requestId}] [%X{requestUrl}] [%X{clientIP}] [%thread] %-5level %logger{36} - %msg%n</pattern>
<charset>utf8</charset>
</encoder>

%X{} 포맷으로 MDC에서 설정했던 key값을 넣어준다면, 로그를 찍을 때마다 해당 key에 대한 value들을 알아서 찍을 수 있습니다.

4. 정리

동글은 다음과 같은 로깅 시스템을 구축하였습니다.

  1. 프로파일별(local과 prod,dev)로 로그를 구분하여 출력할 수 있다.
  2. 로그를 레벨별로 응집도 있게 나눠서 관리할 수 있다.
  3. 로그를 날짜별로 나누어 관리할 수 있다.
  4. 하나의 로그 파일 용량이 매우 커지지 않게 관리할 수 있다.
  5. 사용자의 요청을 구분할 수 있고, 애플리케이션 전반에 어떤 영향을 미치는지 추적할 수 있다.

--

--