스프링부트 서비스에 LOG 남기기 (with. Logback)

 

 

이직 후 맡은 첫 작업은 LOG 였다.

 

서비스 분석을 위해 코드를 처음 까봤을 때 굉장히 당황스러웠던 게 몇가지 있었는데, 그중 대표적인게 로그 부분이었다.

 

당황스럽게도, 남기고 있는 로그들은 전부 디버그 수준에서 남길만한 정보들만 남기고 있었다.

if (oldUser != null) {
    log.info("이미 존재하는 사용자입니다. user : {} oldUser : {} ", user, oldUser);
    userResponseDTO.setCode(-1);
    userResponseDTO.setErrorMsg("이미 존재하는 사용자입니다.");
    return userResponseDTO;
}

위와 같은 메시지들이 json 형태도 아닌 일반 cout 형태로 출력되고 있었다.

 

이런 로그들은 서비스를 운영하고 모니터링 하는데 아무런 도움이 되지 않는다.

 

운영과 모니터링에 있어서 좀 더 의미있는 LOG를 남기기 위해서 바로 작업을 시작했다.

 

어떤 라이브러리를 사용할 것인가?

스프링프레임워크에서 보편적으로 사용되는 로깅 라이브러리로는 slf4j가 있다.

 

slf4j는 별도의 설정없이 @slf4j 어노테이션만 남겨도 로깅을 설정할 수 있는 장점이 있다.

 

간단한 변수 선언만으로 사용할 수 있는데, LoggerFactory 클래스에서 다양한 로깅 관련 기능들을 제공한다.

final static Logger logger = LoggerFactory.getLogger(UserService.class);

하지만 로그에 좀 더 다양한 정보를 남기기 위해서, 자바에서는 대표적으로 두 개의 라이브러리를 사용한다.

 

log4j2 vs logback

 

나는 이번에 logback을 선택했다.

 

사실 두 라이브러리가 엄청난 차이가 있진 않다.

 

하지만 logback은 springboot에서 기본적으로 제공하기 때문에, 별도의 라이브러리 설치가 필요 없다.

 

log4j2도 logback만큼 많이쓰인다고 하지만,

 

log4j 해킹 사건 이후로 사용하기가 꺼려지기도 하고, 외부 라이브러리의 설치가 필요해 logback으로 선택했다.

 

Logback 설정하기

우선 인프라 담당하시는 분의 요구 사항은 로그는 json 형태로 남겨주세요 였다.

 

일단, 로컬에 출력하는 형식과 dev 이상에서 사용할 로그 형식을 나눴다.

 

dev 이상의 프로파일에서 전역적으로 사용할 로그는 디폴트 경로인 resources/logback-spring.xml에 설정했고,

 

로컬은 별도의 경로를 application.yml에 설정했다.

logging:
  config: classpath:local/logback-spring.xml

디폴트 경로를 사용할 경우 별도의 설정을 할 필요가 없다.

 

출력하기

그냥 console에만 출력하는 방식과 텍스트 파일 형식으로 남기는 방식이 있다.

 

먼저 텍스트 파일 형식으로 남기는 방식을 알아보자.

<configuration>
    <property name="LOG_PATH" value=[YOUR PATH]/>

    <property name="LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss} [%thread] %-5level %logger{36} - %msg%n"/>

    <appender name="serviceLog" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>${LOG_PATH}/serviceLog</file>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>${LOG_PATH}/log.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
            <maxHistory>7</maxHistory>
            <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
                <maxFileSize>10MB</maxFileSize>
            </timeBasedFileNamingAndTriggeringPolicy>
        </rollingPolicy>
        <encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
            <layout class="ch.qos.logback.contrib.json.classic.JsonLayout">
                <jsonFormatter
                        class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter">
                    <prettyPrint>true</prettyPrint>
                </jsonFormatter>
                <timestampFormat>yyyy-MM-dd' 'HH:mm:ss.SSS</timestampFormat>
                <timestampFormatTimezoneId>Asia/Seoul</timestampFormatTimezoneId>
                <appendLineSeparator>true</appendLineSeparator>
            </layout>
        </encoder>
    </appender>

    <logger name="serviceLog">
        <appender-ref ref="serviceLog"/>
    </logger>

</configuration>

xml이 좀 어지러운데, 위 파일을 뜯어보면 크게 appender와 endcoder로 나뉜다.

 

Appender

Appender는 로그를 어떻게 이어붙일까? 를 명시한다.

 

Appender에는 여러 종류가 있는데, 파일 형식으로 로그를 남기는 Appender는 FileAppender, RollingFileAppender가 있다.

 

FileAppender는 로그의 길이, 크기에 따라 파일을 분리할 수 없기 때문에 RollingFileAppender를 사용했다.

 

RollingFileAppender는 파일을 어떻게 분리해서 남길까를 추가적으로 명시할 수 있다.

 

위 xml에서

<rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
    <fileNamePattern>${LOG_PATH}/log.%d{yyyy-MM-dd}.%i.log.gz</fileNamePattern>
    <maxHistory>7</maxHistory>
    <timeBasedFileNamingAndTriggeringPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedFNATP">
        <maxFileSize>10MB</maxFileSize>
    </timeBasedFileNamingAndTriggeringPolicy>
</rollingPolicy>

maxHistory는 7일 간만 남긴다는 의미이다.(7일이 지난 파일은 삭제),

 

timeBasedFileNameingAndTriggeringPolicy는 파일의 최대 크기가 10MB를 초과하면 log.2023-05-25.0.log.gz 와 같은 형태로 i(index)가 증가하면서 파일이 남게 된다.

 

여기서 문제는 7일 이후에 삭제되는 파일들인데, 삭제를 막기 위해서는 LogRotate와 같은 툴을 이용해서 파일을 이동시키면 로그 수집에 도움을 줄 수 있다.

 

Encoder

다음은 Encoder 부분인데,

<encoder class="ch.qos.logback.core.encoder.LayoutWrappingEncoder">
    <layout class="ch.qos.logback.contrib.json.classic.JsonLayout">
        <jsonFormatter
                class="ch.qos.logback.contrib.jackson.JacksonJsonFormatter">
            <prettyPrint>true</prettyPrint>
        </jsonFormatter>
        <timestampFormat>yyyy-MM-dd HH:mm:ss.SSS</timestampFormat>
        <timestampFormatTimezoneId>Asia/Seoul</timestampFormatTimezoneId>
        <appendLineSeparator>true</appendLineSeparator>
    </layout>
</encoder>

JsonPretty하게 출력하고, 타임존을 서울로 설정해서 타임스탬프를 남겨줘라는 의미이다.

 

여러 종류의 layout이 있지만 Json 방식의 출력을 해야해서 JsonLayout을 선택했다.

 

위는 dev 이상의 서버에서 설정한 방법인데, 로컬엔 굳이 파일을 남길 필요가 없었기 때문에 아래와 같이 설정했다.

 

ConsoleAppender로 간단히 출력하도록 설정했다.

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

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

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

 

위 설정의 문제점...

객체를 로그에 저장하려고 json 변환을 해서 쓰려고하다보니 자꾸 escape문자가 자동으로 남는 현상이 있었다.

 

그리고 유연성이 너무 없었다. 넣고 싶은 정보들이 있는데, 현재 방식으로는 어떤 정보를 추가할 수가 없었다.

 

그래서 고민하다가 logstash.encoder라는 라이브러리를 추가해서 사용했다.

 

build.gradle

implementation 'net.logstash.logback:logstash-logback-encoder:6.6'

<configuration>
    <appender name="SERVICE_LOG" class="ch.qos.logback.core.ConsoleAppender">
        <encoder class="net.logstash.logback.encoder.LogstashEncoder">
            <fieldNames>
                <thread>[ignore]</thread>
                <version>[ignore]</version>
                <message>[ignore]</message>
                <levelValue>[ignore]</levelValue>
            </fieldNames>
        </encoder>
    </appender>

    <logger name="serviceLog">
        <appender-ref ref="SERVICE_LOG"/>
    </logger>
</configuration>

위와 같이 디폴트로 들어가는 정보들을 제외할 수 있다.

 

또 자바 코드 단에서 로그에 들어갈 정보를 추가할 수 있다.

final static Logger serviceLogger = LoggerFactory.getLogger("serviceLog");

Map<String,Object> logMessageMap = new HashMap<>();
logMessageMap.put("id", userId);
logMessageMap.put("url", uri);
logMessageMap.put("message", message);
logMessageMap.put("code", code);

serviceLogger.info("{}", entries(logMessageMap));

이런 식으로 logger를 불러와 필요한 정보들을 객체 형식으로 덧 붙일 수 있다.

 

사실상 이 기능 때문에, logstash-encoder 라이브러리를 사용했다.

 

추가적인 정보들은 logstash-encoder github에서 확인할 수 있다.

 

마치며

코드 분석을 하면서 정말 화가 많이 났다.

 

로그를 남기는 게 필요한걸 알긴 했는지, 로그를 남기긴 했는데 구현한 위치마다 다른 방식을 사용했다.

 

어떤 곳은 한글로 어떤 곳은 영어로, 변수를 남길 때도 있고 안 남길 때도 있고, 어떤 곳에는 log.error를 사용했고, 어떤 곳에는 log.debug를 사용했다.

 

초기 시스템을 SI에 맡겨서 개발했다고는 들었는데, 정말 그러지 맙시다....

 

적어도 통일은 해야죠.

 

또 무슨 매서드를 통과 했다는 건, 왜 로그에 남겼는지 그것도 왜 info level로 남긴건지 도무지 이해를 할 수가 없었다.

 

로그를 왜 남기나? 를 한번쯤은 생각해봤으면 이런 결과가 안나왔을 텐데..