팀 프로젝트 Logback 로깅 환경 개선기 (환경 분리, 롤링 설정 등)

배경

지난 9월, 레벨4를 시작하며 팀 프로젝트에서 가장 우선시 했던 일은 로깅 환경 개선이었다.

 

기존에는 콘솔/파일 로그로 ERROR, WARN 레벨만 기록하고 있었다.

그와 동시에 개발, 운영 환경에 무관하게 콘솔 로그를 EC2내 log 파일로 기록하고 있었다.

콘솔 로그에는 hibernate의 sql 로그를 포함해 매우 많은 양의 로그가 빠르게 쌓였다.  

 

로그 모니터링을 하다보니 ERROR, WARN 레벨의 로그만 보고 상황을 파악하기란 쉽지 않았다.

그래서 콘솔 로그를 보려고 들어가면, 수많은 양의 로그를 화면에 출력하는 데에만 한 세월이 걸렸다.

계속해서 커지는 로그 파일의 용량 또한 문제였다.

 

그래서 파일 로그에 대한 용량 관리가 필수적임을 체감했고,

운영 환경 별로 필요한 로그들을 잘 정리해서 관리할 필요를 느꼈다.

또, 우리가 직접 남기는 커스텀 로그를 쉽게 확인하기 위해서는 로깅 환경 자체가 잘 짜여져 있어야겠다고 생각했다.

 

PR 링크로 확인하기

 

실행 환경 별 로깅 전략

그래서 정리된 환경 별 로깅 전략은 아래와 같았다.

 

• local: console 로깅
  • info 레벨 (+구성 파일에 설정한 hibernate SQL, BasicBinder)
• dev: file 로깅
  • debug 레벨
  • warn 레벨
  • error 레벨
  • hibernate (debug 레벨의 SQL 쿼리, trace 레벨의 파라미터 바인딩)
• prod: file 로깅
  • info 레벨 (커스텀 로그)
  • warn 레벨
  • error 레벨 + slack 알림
    (추가로, CloudWatch에서는 slow query log를 보여주고 있음을 참고할 것)

그런데 개발 환경에서 기본 제공되는 콘솔 로그를 확인할 수 없으니까, 인프라 단의 트러블 슈팅 시에 생각보다 불편한 경우가 많았다. 그래서 이후에 개발 환경에서도 콘솔 로그를 추가해주었다. 대신 파일 용량 관리만 잘 해주면 될 것 같다.

 

사이즈&시간 기반 롤링 적용

아래와 같이 Logback에서 제공해주는 용량 및 시간 기반 롤링을 적용하였다.

•  SizeAndTimeBasedRollingPolicy
  • 사이즈, 시간을 기준으로 삭제 옵션을 설정할 수 있다.
  • maxFileSize 파일 사이즈가 초과된 경우 기존 파일 대신 fileNamePattern에 따른 파일명을 가진 다음 파일에 로그를 저장
  • maxHistory 시간이 경과된 경우 삭제
    (file 태그의 옵션에 따라 일, 월, .. 단위 정해짐. 이 Policy에서는 최소 단위가 일이고 더 작은 단위로는 cron 표현식 구문과 함께 TimeBasedRollingPolicy를 사용해야 함)
  • totalSizeCap 필수 옵션은 아님. 로그 파일의 총 크기가 이 제한을 초과하면 새 로그 파일을 위한 공간을 확보하기 위해 이전 로그 파일이 삭제된다. 최대값은 1GB

예시로, 아래는 info 레벨의 로그를 file로 기록하는 Appender이다.
Appender는 Logback의 주요 요소 중, 로그메시지가 출력될 대상을 결정하는 요소이다.

    <appender name="FILE_INFO" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_PATH}/info/info.log</file>
        <filter class="ch.qos.logback.classic.filter.LevelFilter">
            <level>INFO</level>
            <onMatch>ACCEPT</onMatch>
            <onMismatch>DENY</onMismatch>
        </filter>
        <encoder>
            <pattern>${LOG_PATTERN_DEFAULT}</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
            <fileNamePattern>${LOG_PATH}/info/info-%d{yyyy-MM-dd}.%i.log</fileNamePattern>
            <maxFileSize>100MB</maxFileSize>
            <maxHistory>7</maxHistory>
            <totalSizeCap>1GB</totalSizeCap>
        </rollingPolicy>
    </appender>

 

설정파일 유지보수성 개선

기존에는 logback-spring.xml 파일 하나로 모든 설정을 하고 있었다.

안그래도 XML인데 여러 환경 별 설정이 들어가다보니, 내용을 이해하기도 어렵고 수정하기에도 불편했다.

그래서 include 태그를 이용하여 Appender를 로그 종류 별 xml파일로 만들어 분리했다.

 

<?xml version="1.0" encoding="UTF-8"?>

<configuration>
    <timestamp key="DATE_FORMAT" datePattern="yyyy-MM-dd"/>

    <springProperty name="LOG_PATH" source="logging.file.path"/>
    <property name="LOG_PATTERN_DEFAULT" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] ${PID} %5level %logger - %msg%n"/>
    <property name="LOG_PATTERN_COLORED"
              value="%green(%d{yyyy-MM-dd HH:mm:ss.SSS}) [%thread] ${PID} %highlight(%-5level) %cyan(%logger) - %msg%n"/>

    <include resource="logback/console-appender.xml"/>

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

    <springProfile name="dev">
        <include resource="logback/file-hibernate-appender.xml"/>
        <include resource="logback/file-debug-appender.xml"/>
        <include resource="logback/file-warn-appender.xml"/>
        <include resource="logback/file-error-appender.xml"/>

        <root level="INFO">
            <appender-ref ref="FILE_WARN"/>
            <appender-ref ref="FILE_ERROR"/>
        </root>

        <logger name="com.mapbefine.mapbefine" level="DEBUG">
            <appender-ref ref="FILE_DEBUG"/>
        </logger>
        <logger name="org.hibernate.SQL" level="DEBUG">
            <appender-ref ref="FILE_HIBERNATE"/>
        </logger>
    </springProfile>

    <springProfile name="prod">
        <include resource="logback/file-info-appender.xml"/>
        <include resource="logback/file-warn-appender.xml"/>
        <include resource="logback/file-error-appender.xml"/>
        <include resource="logback/slack-error-appender.xml"/>

        <root level="INFO">
            <appender-ref ref="FILE_WARN"/>
            <appender-ref ref="FILE_ERROR"/>
            <appender-ref ref="SLACK_ERROR"/>
        </root>

        <logger name="com.mapbefine.mapbefine" level="INFO">
            <appender-ref ref="FILE_INFO"/>
        </logger>
    </springProfile>
</configuration>

 

위와 같이 레벨 별로 로그를 확인할 수 있도록 파일 경로를 분리했다.

 

적용 과정

로그백 설정에 미숙한 상태라

로그 경로, 패턴, 색상 적용부터 시작해서 여러 작은 설정들이 잘 동작하는지 하나 하나 익혀가며 적용해야 했다.

뿐만 아니라

실행 환경 별로 의도한 레벨의 로그만 출력하는지,
실행 환경 별로 파일이 잘 만들어지는지, 기존 파일이 없어도 새로 만들어지는지
사이즈/시간 별 롤링이 잘 되는지 등등
매번 실행 환경이나 상황을 조성해 여러 가지를 직접 확인하는 게 꽤 번거로운 작업이었다.

그래서 팀 프로젝트에 바로 직접 적용하는 대신,

스터디용 Spring 프로젝트를 하나 만들어서 아래와 같이 간단한 테스트 코드를 실행하며 제대로 동작하는지 확인하는 방식으로 진행했다.

 

저장소 링크  https://github.com/yoondgu/logback-practice

package com.example.demo;

import org.junit.jupiter.api.DisplayName;
import org.junit.jupiter.api.Nested;
import org.junit.jupiter.api.Test;
import org.springframework.beans.factory.annotation.Autowired;
import org.springframework.boot.test.context.SpringBootTest;
import org.springframework.test.context.ActiveProfiles;

@SpringBootTest
public class LoggerTest {

    @Autowired
    protected LogController logController;

    @Nested
    class LocalLoggerTest {

        @DisplayName("local 환경: info 레벨의 console 로깅")
        @Test
        void console() {
            logController.logAllLevels("local");
        }
    }

    @Nested
    @ActiveProfiles(value = "dev")
    class DevLoggerTest {

        @DisplayName("dev 환경: error 레벨 file 로깅, warn 레벨의 file 로깅")
        @Test
        void consoleAndFile() {
            logController.logAllLevels("dev");
        }
    }

    @Nested
    @ActiveProfiles(value = "warn 레벨의 file 로깅, error 레벨의 file 로깅")
    class ProdLoggerTest {

        @Test
        void consoleAndFile() {
            logController.logAllLevels("prod");
        }
    }
}

 

package com.example.demo;

import lombok.extern.slf4j.Slf4j;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;

@RestController
@Slf4j
public class LogController {

    @GetMapping("/all")
    public void logAllLevels(String message) {
        log.trace("trace {}", message);
        log.debug("debug {}", message);
        log.info("info {}", message);
        log.warn("warn {}", message);
        log.error("error {}", message);
    }
}

 

 

적용 결과

콘솔 로그

파일 로그

 

이렇게 저장되는 파일 로그들을 이용해 AWS Cloudwatch를 사용해 어디서나 모니터링할 수 있게끔 환경을 구축해두었다.

슬랙 알림 로그

슬랙 알림은 치명적인 에러를 빠르게 확인하기 위해, 운영 서버의 에러 레벨 로그에 대해 발생한다.

참고 자료

적용하며 참고한 자료들이다.

깃허브 저장소에서 다른 프로젝트의 설정들을 참고하는 것도 도움이 많이 됐다. 

• [테코톡] 검프의 Logging #2
• https://github.com/Livenow14/slf4j-logback-lab
• springProfile 태그 사용법 - Spring 공식문서
• Logback Slack Appender 로 알림 받기