[Spring] 에러로깅 - Logback 사용해서 에러 로그 파일 생성하기

🌱 들어가기 전

지금 프로젝트에서 에러 처리를 최대한 하고 있긴 하지만!

지난번 이미지 업로드 API를 올리면서 생각지 못한 S3와 관련된 에러나 환경변수 관련 에러가 터졌고, 그럴 때마다 실제 인스턴스에 들어가서 로그를 확인해야 하는 게 귀찮아서 이참에 에러 관리 로직을 전면 리팩토링해서 실시간으로 알 수 있도록 할 예정이다.

그러기 위해서 우선 에러 발생 시 따로 모아서 볼 수 있도록 에러 Log 파일을 만들어볼 것이다!

 

🔍 기존 에러 처리 로직

현재는 계정 관련 에러인 AuthException, 그 외 에러는 BaseException으로 만들어서 GlobalExceptionHandler에서 관리하고 있다.

AuthException, BaseException은 모두 상황마다 에러 Enum을 만들어뒀으므로 커스텀한 에러 응답 코드와 메세지가 뜰 것이고, 이외에 Exception이 발생할 경우 @Slf4j 로 log.warn()을 찍는다.

@ControllerAdvice
@Slf4j
public class GlobalExceptionHandlerV2 extends ResponseEntityExceptionHandler {

  @ExceptionHandler(AuthExceptionV2.class)
  public ResponseEntity<Object> handleAuthException(final AuthExceptionV2 exception) {
    final ErrorCode errorCode = exception.getErrorCode();
    return handleExceptionInternal(errorCode);
  }

  @ExceptionHandler(BaseExceptionV2.class)
  public ResponseEntity<Object> handleBaseException(final BaseExceptionV2 exception) {
    final ErrorCode errorCode = exception.getErrorCode();
    return handleExceptionInternal(errorCode, exception.getMessage());
  }
  
  @ExceptionHandler({Exception.class})
  public ResponseEntity<Object> handleAllException(Exception ex) {
    log.warn("handleAllException", ex);
    ErrorCode errorCode = CommonErrorCode.REQUEST_ERROR;
    return handleExceptionInternal(errorCode);
  }

 

만약 Exception 이 생기면 스프링을 띄울 때 콘솔에는 표시가 되지만 해당 로그가 따로 기록되지는 않는다.

 

 

🧐 로깅 라이브러리를 쓰는 이유는 무엇일까?

물론, 스프링에서 표준 출력을 통해 에러를 확인할 수도 있다.

아래는 log라이브러리, 표준출력, 표준에러출력 으로 exception 클래스를 출력했을 때 결과 비교이다.

log.warn("Exception", exception);
System.out.println(exception);
System.err.println(exception);

log로 출력했을 때보다 print로 출력했을 때, 정보가 거의 없이 Exception이름만 찍히게 된다.

에러가 어디서 발생했는지 확인하고 싶을 때 불편할 것 같다.

 

위 내용을 포함해서 표준 출력을 했을 경우 단점은 아래와 같다.

 

1️⃣ 로그가 저장되지 않고 휘발된다

: 로그가 표준 출력으로 출력된 뒤, 따로 파일에 저장할 수 없다.

 

2️⃣ 에러 발생 시 추적할 수 있는 정보가 남지 않는다

: 로그 발생 위치, 문제 수준 등 에러에 대한 정보가 출력되지 않는다.

 

3️⃣ 로그 출력 레벨을 사용할 수 없다

: 로그 라이브러리에서는 로그의 레벨을 TRACE, DEBUG, INFO, WARN, ERROR, FATAL 로 나누어 에러 발생시
레벨에 맞는 로그를 남길 수 있고, 로컬 환경과 프로덕션 환경에서 로그 출력 레벨을 다르게 설정할 수도 있다.
하지만 표준 출력으로 에러를 남길 경우 이렇게 로그 출력 레벨 설정을 할 수 없게 된다.

 

4️⃣ 성능 저하의 원인이 된다

: println()은 내부적으로 synchronized 를 사용하기 때문에 멀티 쓰레드 상황에서 오버헤드가 발생할 수 있다.

(내부적인 성능 저하의 원인이 궁금하다면 클릭)

 

🔍 Logback 이란?

앞에서 Slf4j를 이용해 Log를 남겼는데 Slf4j와 Logback은 각각 무엇일까?

 

Slf4j(Simple Logging Facade for Java)

다양한 로깅 프레임워크를 위한 추상화 계층을 제공하는 라이브러리이다.
즉, 개발자가 특정 로깅 라이브러리에 종속되지 않도록 하고, 다양한 로깅 프레임워크로 쉽게 전환할 수 있도록 돕는 역할을 한다.
Slf4j 자체는 실제 로깅을 처리하지 않으며, 로깅 인터페이스만을 정의하고 있다.
이를 통해 개발자는 코드를 작성할 때 Slf4j 인터페이스를 사용하고, 실제 로깅을 처리하는 구현체는 나중에 결정할 수 있다.

 

Logback

Slf4j의 대표적인 구현체 중 하나로, 효율적이고 유연한 로깅을 지원하는 로깅 프레임워크이다.
성능이 뛰어나고, 다양한 기능을 제공하며, 설정이 간단하기 때문에 많은 프로젝트에서 기본 로깅 프레임워크로 사용된다.

 

Slf4j는 로깅 인터페이스를 제공하고, Logback은 그 구현체로 동작한다.

즉, 개발자는 Slf4j API를 사용해 로그를 남기고, 실제 로그 기록은 Logback이 처리한다.

 

 

Logback은 스프링부트를 로딩할 시점에 로그 설정 파일이 프로젝트에 존재하는지 스캔한다.

• logback-spring.xml
• logback-spring.groovy
• logback.xml
• logback.groovy

위와 같은 우선순위로 스캔하는데 logback-spring.xml이 Spring Profile에 따라서 로그 레벨을 설정할 수도 있고,
Spring 환경 변수를 이용해 설정할 수도 있어서 Spring boot에 특화된 설정파일이다.

 

Logback 설정하기

그럼 로그파일을 만들어 로그를 기록하기 위해 Logback을 설정해보자!

스프링부트는 별도 dependency 설정을 하지 않아도 사용할 수 있다.

 

먼저 resources 폴더에 logback-spring.xml 파일을 생성한다

 

logbak-spring.xml 은 아래와 같이 3가지 속성으로 구분해서 해석할 수 있다.

• <property> : 변수를 선언할 수 있다. 로그를 찍는 패턴을 변수화해서 사용하거나 자주 쓰는 워딩을 변수화해서 사용한다.
• <appender> : 로그를 출력할 대상(콘솔, 파일 등)을 정할 수 있다. 즉 로그 메세지를 어디에 남길지 설정하는 것이다.
• <root> : 모든 로거의 상위 로거이며, 출력할 로그의 레벨을 설정하고, 생성한 appender를 지정한다.

<configuration>
  <property name="LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %5level %logger - %msg%n"/>
  <property name="LOG_FILE_NAME" value="oneit-log"/>
  <timestamp key="ToDay" datePattern="yyyy-MM-dd"/>

  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
      <Pattern>
        ${LOG_PATTERN}
      </Pattern>
    </layout>
  </appender>

  <appender name="FILE-INFO" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
      <fileNamePattern>
        ./logs/info-%d{yyyy-MM-dd}/${LOG_FILE_NAME}_%i.log
      </fileNamePattern>
      <maxFileSize>50MB</maxFileSize>
      <maxHistory>30</maxHistory>
    </rollingPolicy>
    <encoder>
      <pattern>${LOG_PATTERN}</pattern>
    </encoder>
  </appender>

  <appender name="FILE-ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <filter class="ch.qos.logback.classic.filter.LevelFilter">
      <level>ERROR</level>
      <onMatch>ACCEPT</onMatch>
      <onMismatch>DENY</onMismatch>
    </filter>
    <encoder>
      <pattern>${LOG_PATTERN}</pattern>
    </encoder>
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
      <fileNamePattern>
        ./logs/error-%d{yyyy-MM-dd}/${LOG_FILE_NAME}_%i.log
      </fileNamePattern>
      <maxFileSize>50MB</maxFileSize>
      <maxHistory>30</maxHistory>
      <totalSizeCap>3GB</totalSizeCap>
    </rollingPolicy>
  </appender>

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

</configuration>

• <property>
  • LOG PATTERN : 출력할 로그 메세지의 패턴을 지정
  • LOG FILE NAME : 로그파일의 이름을 지정(자체 서비스 명을 포함해서)
  • Today : 날짜 패턴을 지정
• <appender>
  • CONSOLE : ConsoleAppender 타입으로 CONSOLE에 출력되는 appender 생성
  • FILE INFO : RollingFileAppender 타입으로 로그 파일이 생성되며 INFO 이상의 레벨을 가진 로그를 출력하는 appender
  • FILE ERROR : RollingFileAppender 타입으로 로그 파일이 생성되며 ERROR 이상의 레벨을 가진 로그를 출력하는 appender
  (같은 File appender인데 로그의 레벨을 다르게 설정한 것은 이후 환경별 설정을 위해서이다)
• <root>
  • 루트 로거의 레벨은 INFO로 설정 ⇒ INFO 레벨 이상의 로그만 처리 (INFO / WARN / ERROR)
  • 생성한 appender들을 참조

이제 프로젝트를 실행해보았더니

아래와 같이 logs디렉토리에 날짜별로 로그 파일이 생성되는 것을 볼 수 있다.

 

로그 파일에도 이렇게 에러 로그가 잘 저장된다.

 

 

그런데 우리가 서비스를 운영하다보면 여러가지 환경에서 프로젝트가 실행된다.

 

우리 서비스의 경우 로컬환경, 개발서버, 운영서버 이렇게 3가지 환경이 있다.

로컬과 개발서버에서는 INFO레벨의 로그가 나와도 무방하지만,
운영서버에 INFO로그까지 나오면 너무 많은 로그가 찍혀 정작 중요한 ERROR 로그를 찾기 힘들어질 수 있다.

운영서버에서는 ERROR로그를 확인하는 게 가장 중요하기 때문에 INFO로그가 그걸 방해하게 둘 수 없다.

또한 로컬에서는 CONSOLE에 나오도록 설정하는 게 편리하지만 개발서버에서는 CONSOLE에 찍혀도 실시간 확인할 수 없기 때문에 오히려 불필요하다.

 

이렇게 환경별로 로그의 출력 레벨을 다르게 설정할 필요가 있다.

이를 위해서 info와 error를 따로 나누어 appender를 설정했는데 이제 환경별로 에러 로그를 다르게 설정해보자

 

환경별로 로그 다르게 설정하기

로컬 환경에서는 DEBUG 수준의 로그,

개발 서버 환경에서는 INFO 수준의 로그,

운영 서버 환경에서는 예상치 못한 에러가 남겨질 수 있도록 ERROR 로그를 남기도록 설정할 것이다.

그래서 console appender, file info appender, file error appender를 따로 분리한 뒤에

spring profile로 local, dev, prod마다 다른 appender를 설정해준다.

 

console appender

<included>
  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
    <layout class="ch.qos.logback.classic.PatternLayout">
      <Pattern>
        ${LOG_PATTERN}
      </Pattern>
    </layout>
  </appender>
</included>

 

 

file info appender

<included>
  <appender name="FILE-INFO" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
      <fileNamePattern>
        ./logs/dev-%d{yyyy-MM-dd}/${LOG_FILE_NAME}_%i.log
      </fileNamePattern>
      <maxFileSize>50MB</maxFileSize>
      <maxHistory>30</maxHistory>
    </rollingPolicy>
    <encoder>
      <pattern>${LOG_PATTERN}</pattern>
    </encoder>
  </appender>
</included>

 

file error appender

<included>
  <appender name="FILE-ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
    <filter class="ch.qos.logback.classic.filter.LevelFilter">
      <level>ERROR</level>
      <onMatch>ACCEPT</onMatch>
      <onMismatch>DENY</onMismatch>
    </filter>
    <encoder>
      <pattern>${LOG_PATTERN}</pattern>
    </encoder>
    <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
      <fileNamePattern>
        ./logs/prod-%d{yyyy-MM-dd}/${LOG_FILE_NAME}_%i.log
      </fileNamePattern>
      <maxFileSize>50MB</maxFileSize>
      <maxHistory>30</maxHistory>
      <totalSizeCap>3GB</totalSizeCap>
    </rollingPolicy>
  </appender>
</included>

 

 

위 파일들을 log디렉토리를 만들어 넣어준뒤에

logback-spring.xml 을 수정한다

<configuration>
  <property name="LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %5level %logger - %msg%n"/>
  <property name="LOG_FILE_NAME" value="oneit-log"/>
  <timestamp key="ToDay" datePattern="yyyy-MM-dd"/>

  <!--local-->
  <springProfile name="local">
    <include resource="log/console-appender.xml"/>
    <root level="INFO">
      <appender-ref ref="CONSOLE"/>
    </root>
  </springProfile>

  <!--dev-->
  <springProfile name="dev">
    <include resource="log/file-info-appender.xml"/>

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

    <logger level="DEBUG" name="org.hibernate.SQL">
      <appender-ref ref="FILE-INFO"/>
    </logger>

    <logger level="TRACE" name="org.hibernate.type.descriptor.sql.BasicBinder">
      <appender-ref ref="FILE-INFO"/>
    </logger>
  </springProfile>

  <!--prod-->
  <springProfile name="prod">
    <include resource="log/file-error-appender.xml"/>

    <root level="ERROR">
      <appender-ref ref="FILE-ERROR"/>
    </root>
  </springProfile>

</configuration>

 

로컬 환경에는 console-appender,

개발 서버 환경에는 file-info-appender,

운영 서버 환경에는 file-error-appender로 설정해주었다.

참고로 개발 서버 환경에는 쿼리와 쿼리에 바인딩되는 파라미터를 확인하기 위해 DEBUG, TRACE 레벨의 appender도 함께 추가했다.

 

 

🔗 레퍼런스

https://cl8d.tistory.com/96
https://hudi.blog/do-not-use-system-out-println-for-logging/
https://dveamer.github.io/backend/HowToUseSlf4j.html
https://blog.pium.life/server-logging/
https://logback.qos.ch/manual/layouts.html