간단하게 스프링에서 로깅 남기기

Overview

안녕하세요. 이번 시간에는 도커로 배포하는 스프링 애플리케이션에 로깅을 간단하게 남기는 법을 알아보도록 하겠습니다.

여러분은 System.out.println으로 디버깅이나 로깅을 남겨오지는 않으셨나요. System.out.println으로 로깅을 찍고 톰캣을 통해 애플리케이션을 배포할 경우 내부적으로는 catalina.out에 로그가 기록이 되어 {tomcat경로}/logs/경로에서 확인이 가능합니다.

하지만 System.out.println으로 로깅을 남기는 법은 가장 쉽고 간단한 방법이나 여러 불편한 점이 존재합니다.

1. 로그 분리가 불가능

System.out.println을 사용하면 로그가 무조건 무조건 출력됩니다. 로깅 레벨을 지정할 수 없어 운영환경에서도 디버깅 로그가 출력되는 등 불필요한 로그를 보여주어야 합니다.

2. 로그를 분석할 최소한의 정보가 없음

로그를 보고 분석하려면 날짜, 시간, 위험 수준 등의 최소한의 정보를 보여주어야 합니다.

저희는 다음과 같은 불편함을 해소하기 위해 LogBack 프레임워크를 이용해 로깅을 남겨보도록 하겠습니다.

LogBack을 사용할 경우 우리는 로그가 남기는 형식을 지정할 수 있으며(날짜, 시간 등) 로깅 레벨을 지정하여 상황에 따라 디버깅 등의 로그가 보여지고 안보여지게끔 할 수 있습니다.

로그 찍어보기

굉장히 쉽습니다! 먼저 로그를 찍고자 하는 코드에 LoggerFactory에서 Logger를 불러오고, 불러온 logger를 이용해 원하는 부분에 System.out.println을 찍듯이 로그를 기록하면 됩니다.

롬복을 사용하는 경우, 상위에 @slf4j 어노테이션을 대신 사용할 수 있습니다.

public class TestController {
	private static final Logger logger = LoggerFactory.getLogger(TestController.class);

	@GetMapping("/log")
    public void log() {
        logger.info("로그를 기록하겠습니다.");
    }
}

앞서 저희는 로그를 분리하고 원하면 출력되지 않게끔 할 수 있다 하였습니다. 이를 루트로거의 로그 레벨을 지정하거나 설정파일의 filter을 설정하여 구현합니다. 먼저 로그 레벨부터 알아보도록 하겠습니다.

1. Logging Level 지정 후 출력

• FATAL
• ERROR
• WARN
• INFO
• DEBUG
• TRACE

레벨은 TRACE > DEBUG > INFO > WARN > ERROR > FATAL 순으로 높아집니다.

만약 루트 로거를 INFO로 셋팅하면 그보다 레벨이 같거나 높은 INFO, WARN, ERROR, FATAL이 기록됩니다.
이러한 레벨 지정을 사용하면 언제 어디서 어떤 정보를 기록할지 쉽게 필터링 할 수 있습니다.

logger.trace("Trace log");
logger.debug("Debug log");
logger.info("Info log");
logger.error("Error log");
logger.warn("Warn log");
logger.fatal("Fatal log");

2. logback-spring.xml 작성

이와 같이 로그를 기록하고 별도의 로그 설정 파일을 작성하지 않으면 스프링에서는 default configuration 정책에 따라 로그를 기록합니다.

하지만 저희는 단순히 콘솔에 찍는 것만이 아닌 로그 파일을 별도로 남기고 싶습니다. 그러기 위해서 ..main/resources/ 경로에 logback-spring.xml의 로그 설정 파일을 작성합니다.

<?xml version="1.0" encoding="UTF-8"?>
<configuration>
    <!-- 이 곳에 추가할 properties를 넣는다. -->
    <property name="LOGS_ABSOLUTE_PATH" value="/var/log"/> <!-- docker run 시 볼륨 매핑해주기 -->

    <!-- appender(어디에 출력할 지)에서 콘솔에 출력되는 형식을 지정한다. -->
    <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>

    <springProfile name="prod"><!-- profile prod 에서만 동작해서 파일에 기록하도록 -->
        <!-- Info 레벨의 이름을 가진 로그를 저장할 방식을 지정한다. -->
        <appender name="INFO_LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">

            <file>${LOGS_ABSOLUTE_PATH}/info.log</file> <!-- 파일을 저장할 경로를 정한다, 도커 사용 시 볼륨매핑 해주어야함 -->
            <!-- filters 종류 키워드로 확인 -->
            <filter class="ch.qos.logback.classic.filter.LevelFilter"> <!-- 지정한 레벨과 같은 로그이벤트 필터링 수행 -->
                <level>INFO</level>
                <onMatch>ACCEPT</onMatch> <!-- 해당 레벨만 기록한다. -->
                <onMismatch>DENY</onMismatch> <!-- 지정 레벨과 맞지 않으면 onMisMatch 에 지정에 따라 수행, DENY -> print 하지않음 -->
            </filter> <!-- 레벨별 필터링이 필요없을 경우 filter class 관련된 부분을 삭제하면 됨-->
            <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}/was-logs/info/info.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern> <!-- 해당 패턴 네이밍으로 이전 파일이 기록됨 -->
                <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                    <maxFileSize>100MB</maxFileSize> <!-- 한 파일의 최대 용량 -->
                </timeBasedFileNamingAndTriggeringPolicy>
                <maxHistory>60</maxHistory> <!-- 한 파일의 최대 저장 기한 -->
                <totalSizeCap>1GB</totalSizeCap> <!-- 전체 로그파일 크기 제한, 1기가 넘으면 오래된거 삭제 -->
            </rollingPolicy>
        </appender>
        <appender name="WARN_OR_MORE_LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">

            <file>${LOGS_ABSOLUTE_PATH}/warn-or-more.log</file>
            <filter class="ch.qos.logback.classic.filter.ThresholdFilter"> <!-- 지정레벨 이상의 로그만 print 하는 필터 -->
                <level>WARN</level>
            </filter>
            <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}/was-logs/warn-or-more/warn-or-more.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
                <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                    <maxFileSize>100MB</maxFileSize>
                </timeBasedFileNamingAndTriggeringPolicy>
                <maxHistory>60</maxHistory> <!-- 한 파일의 최대 저장 기한 -->
                <totalSizeCap>1GB</totalSizeCap> <!-- 전체 로그파일 크기 제한, 1기가 넘으면 오래된거 삭제 -->
            </rollingPolicy>
        </appender>
    </springProfile>

    <!-- 루트로거 구성, 루트로그의 기본 수준을 INFO로 지정, info 이상만 print -->
    <root level="INFO">
        <springProfile name="!prod">
            <!-- 각 appender는 루트 로거에 추가 -->
            <appender-ref ref="STDOUT"/>
        </springProfile>
        <springProfile name="prod">
            <!-- 각 appender는 루트 로거에 추가 -->
            <appender-ref ref="STDOUT"/>
            <appender-ref ref="WARN_OR_MORE_LOG"/>
            <appender-ref ref="INFO_LOG"/>
        </springProfile>
    </root>
</configuration>

로컬에서 개발할 땐 파일을 생성하면 안되겠죠. 콘솔에 출력은 무조건 하지만 파일을 생성해서 로그를 기록하는 것은 <springProfile/>을 통해 profile이 prod일 때만 파일 기록을 하도록 하였습니다.

LOGS_ABSOLUTE_PATH는 도커 컨테이너 내부 로그 파일이 저장될 경로를 지정하는 것입니다. 호스트볼륨과 매핑이 필요합니다.

appender

Appender 는 로그의 출력 위치를 지정해줍니다.

ConsoleAppender : 콘솔에 출력
FileAppender : 파일에 출력
RollingFileAppender : 조건에 따라 파일에 출력
DailyRollingFileAppender : 매일 조건에 따라 파일에 출력
JDBCAppender : RDB 테이블에 출력

springProfile

프로파일이 무엇인지에 따라 동작가능하게끔 설정합니다.

rollingPolicy

로그파일이 한도끝도 없이 생성되면 어찌될까요. 디스크 저장공간이 부족해져 언젠간 터질 것입니다. 이를 방지하기 위해 rollingPolicy 정책을 설정합니다.

filter

로그 레벨을 필터링하는 조건을 설정할 수 있습니다.

LevelFilter를 사용할 경우 onMatch와 onMismatch를 사용하여 level인 경우와 아닌 경우를 필터링합니다.

ThresholdFilter를 사용할 경우 지정 레벨 이상의 로그만 필터링합니다.

encoder

로그의 출력 형식을 지정합니다.

root

루트 로거를 구성해주어야 합니다. 저는 기본 루트 레벨을 INFO로 지정해주어 info 이상의 로그는 기록되게끔 하였습니다.

springProfile을 이용해 프로파일이 prod가 아니라면 appender-ref를 통해 STDOUT이라는 이름을 가진 appender를 사용하여 콘솔에 출력되게끔 하고
프로파일이 prod라면 WARN_OR_MORE_LOG와 INFO_LOG 이름을 가진 appender을 추가로 사용하여 콘솔에도 출력하고 파일에도 기록되게끔 하였습니다.

도커를 사용하는 경우

Dockerfile 수정

# Dockerfile
...
VOLUME ["/var/log"]
...

VOLUME 옵션을 주어 컨테이너 내부 /var/log 경로를 호스트에 저장되도록 합니다. 이경우 /var/lib/docker 쪽에 해당 컨테이너 경로에 저장됩니다.

docker run

docker run ... -v {저장되길 원하는 호스트 경로}:/var/log ...

docker run 시 -v 옵션은 볼륨을 매핑하는 옵션입니다. -v 옵션을 통해 호스트 경로를 컨테이너의 /var/log 경로에 매핑합니다.

ELK Stack

이 방식은 문제점이 있습니다. MSA 아키텍처를 도입한 경우 마이크로서비스 별로 로그파일이 기록됩니다. 이럴 경우 서로 다른 개별 마이크로서비스에서 발생하는 로그를 연결지어 트랜잭션의 처음부터 끝까지 순서대로 추적해내는 것은 매우 어려운 일이 됩니다.

로그를 중앙으로 수집해주는 중앙 집중식 로깅 방법이 필요합니다. 이를 ELK Stack(Logstash 대신 fluentd)을 이용해 많이 구현합니다.

LogBack과 ELK Stack을 연동하는 예제는 많으니 참고 바랍니다.