log4j2 도입

터놓고 서비스를 개발하면서 배포환경에서는 콘솔에 로그를 남길 수 없었습니다.

콘솔에 로그를 남기면 휘발되기도 하고 나중에 확인하기 어려웠습니다.

그래서 log파일로 남기기로 결정했습니다.

 

logging 프레임워크 선택


사용할만한 로깅 프레임워크 구현체는 log4j, logback, log4j2 였습니다.

헷갈릴만한 용어정리


sl4j(Simple Logging Facade For Java)

  • 로깅 프레임워크가 아니라 logger의 인터페이스이다.

slf4j를 이용하면 코드를 일정하게 유지하면서 구현체의 전환을 통해 다른 로깅 프레임워크로의 전환을 쉽고 간단하게 할 수 있습니다.



log4j

가장 오래된 로깅 프레임워크입니다.

2015년 기준으로 개발이 중단되었습니다.



logback

log4j보다는 이후에 출시되어 가장 널리 사용되고 있는 로깅프레임워크입니다.

Springboot환경에서 spring-boot-starter-web 안에 spring-boot-starter-logging안에 logback이 기본적으로 포함되어 있습니다.

  • log4j에 비해 향상된 필터링기능 제공
  • 로그 레벨 변경에 대해 서버 재시작 없이 자동 리로딩 기능을 지원

log4j2

가장 최신에 나온 로깅 프레임워크로써 log4j의 다음버전입니다.

  • logback처럼 필터링 기능, 자동 리로딩 지원
  • logback과 달리 Multi Thread 환경에서 비동기 로거
    • 처리량이 더 많고 대기 시간이 더 짧다.

로깅 프레임워크 선택


log4j 는 log4j 취약점 이슈가 발견됨. → 제외

참고

게다가 오래되기도 했고 새로 의존성 등록할 바에 springboot의 기본 logback을 사용하는 것이 좋아보입니다.



logback vs log4j2

logback

  • 아무설정을 하지 않아도 편리하게 사용할 수 있다.
  • 우리 규모의 프로젝트에서는 log4j2와 성능이 크게 차이가 나지 않는다.

log4j2

  • 로깅을 도입해보는 경험을 할 수 있다.
    • 설정파일을 자세하게 설정해볼 수 있다.
  • 처리량이 많을 수록 성능이 크게 차이난다.

스크린샷 2022-07-30 15 41 09

새로운 로깅 프레임워크 구현체로 갈아끼워넣는 경험도 해보면 좋을 것 같고,

log4j2가 logback보다는 대부분의 상황에서 성능이 더 좋기 때문에 한번 도입해보는 것도 가치가 있겠다고 생각했습니다.



log4j2 도입하기


build.gradle

  1. build.gradle 내의 logback을 제외하도록(exclude springboot-starter-logger) 설정
configurations {
    asciidoctorExtensions
    compileOnly {
        extendsFrom annotationProcessor
    }
    all {
        exclude group: 'org.springframework.boot', module: 'spring-boot-starter-logging'
    }
}

 

  1. build.gradle 내의 log4j2 설치
dependency{
.
.
.
// logging
    implementation 'org.springframework.boot:spring-boot-starter-log4j2'

}



yml

...
logging:
  config: classpath:log4j2-local.xml
...



xml파일 추가

<?xml version="1.0" encoding="UTF-8"?>
<Configuration status="debug" monitorInterval="5">
    <!--공통 속성 설정 -->
    <Properties>
        <Property name="logFileName">local</Property>
        <Property name="consoleLayout">[%d{yyyy-MM-dd HH:mm:ss}] [%-5p] [%c{1}:%L] - %m%n</Property>
        <Property name="layoutPattern">%style{%d{yyyy/MM/dd HH:mm:ss,SSS}}{cyan} %highlight{[%-5p]}{FATAL=bg_red, ERROR=red, INFO=green, DEBUG=blue}  [%C] %style{[%t]}{yellow}- %m%n</Property>
        <Property name="fileLayout">%d [%t] %-5level %c(%M:%L) - %m%n</Property>
    </Properties>

    <!-- Log Appender 설정 -->
    <Appenders>
        <Console name="console" target="SYSTEM_OUT">
            <PatternLayout pattern="${layoutPattern}" disableAnsi = "false"/>
        </Console>
        <!--ConsoleAppender, RollingFileAppneder -->
        <RollingFile name="file"
                     fileName="logs/${logFileName}.log"
                     filePattern="logs/${logFileName}.%d{yyyy-MM-dd-hh}.log">
            <PatternLayout pattern="${fileLayout}" />
            <Policies>
                <TimeBasedTriggeringPolicy
                        modulate="true"
                        interval="1" /><!-- 시간별 로그 파일 생성-->
            </Policies>
            <DefaultRolloverStrategy max="5" fileIndex="min" > <!-- 롤링 파일 5개 까지 생성 -->
                <Delete basePath="/logs" maxDepth="3">
                    <IfLastModified age="3d" />
                </Delete>
            </DefaultRolloverStrategy>
        </RollingFile>

        <RollingFile name="sql_log"
                     fileName="logs/sql.log"
                     filePattern="logs/sql.%d{yyyy-MM-dd-hh}.log">
            <PatternLayout pattern="${fileLayout}" />
            <Policies>
                <TimeBasedTriggeringPolicy
                        modulate="true"
                        interval="1" /><!-- 시간별 로그 파일 생성-->
            </Policies>
            <DefaultRolloverStrategy max="5" fileIndex="min" > <!-- 롤링 파일 5개 까지 생성 -->
                <Delete basePath="/logs" maxDepth="3">
                    <IfLastModified age="3d" />
                </Delete>
            </DefaultRolloverStrategy>
        </RollingFile>

        <RollingFile name="sql_basicBinder_log"
                     fileName="logs/sql_basicBinder.log"
                     filePattern="logs/sql_basicBinder.%d{yyyy-MM-dd-hh}.log">
            <PatternLayout pattern="${fileLayout}" />
            <Policies>
                <TimeBasedTriggeringPolicy
                        modulate="true"
                        interval="1" /><!-- 시간별 로그 파일 생성-->
            </Policies>
            <DefaultRolloverStrategy max="5" fileIndex="min" > <!-- 롤링 파일 5개 까지 생성 -->
                <Delete basePath="/logs" maxDepth="3">
                    <IfLastModified age="3d" />
                </Delete>
            </DefaultRolloverStrategy>
        </RollingFile>

    </Appenders>

    <!--TRACE > DEBUG > INFO > WARN > ERROR > FATAL -->
    <!--Log가 찍힐 대상 설정.-->
    <Loggers>
        <!-- 스프링 프레임워크에서 찍는건 level을 info로 설정 -->
        <logger name="org.springframework" level="info" additivity="false" >
            <AppenderRef ref="console" />
        </logger>

        <!-- sql 파라미터 표시 설정 -->
        <logger name="org.hibernate.SQL" level="debug" additivity="false">
            <AppenderRef ref="console" />
        </logger>
        <logger name="org.hibernate.type.descriptor.sql.BasicBinder" level="trace" additivity="false">
            <AppenderRef ref="console" />
        </logger>

        <!-- ROOT logger-->
        <Root level="info"></Root>
    </Loggers>
</Configuration>



xml 설정

Property

각 공통속성을 설정하는 부분입니다. - 변수라고 생각하면 편합니다.

설정에 이름을 붙여놓고 Appender에서 속성을 추가해줄 수 있습니다.



layout

로그 이벤트를 포매팅할 규칙입니다.

  • 규칙들
    • %c, %logger : 해당 로그를 쓰는 로거의 이름.
    • %C, %class : 해당 로그를 요청한 클래스 이름
    • %d, %date : 해당 로그가 발생한 시간
    • %enc, %encode : 특정 언어에서의 출력을 위한 문자 인코딩
    • %ex, %exception, %throwable : 예외 로그. 길이를 설정할 수 있음.
    • %F, %file : 해당 로그가 발생한 클래스 파일명
    • %l, %location : 해당 로그가 발생한 클래스명.메소드명(파일:라인)
    • %L, %line : 해당 로그가 발생한 라인 번호
    • %m, %msg, %message : 로그문에 전달된 메시지
    • %n : 줄바꿈
    • %p, %level : 로그 레벨
    • %r, %relative : 로그 처리시간
    • %t, %thread : 해당 로그가 발생한 스레드명
    • %style{pattern}{ANSI style} : ANSI를 사용해 특정 패턴을 스타일링함
    • %highlight{pattern}{style} : 로그 레벨명을 ANSI 색깔로 하이라이트

<Properties>
    <Property name="logFileName">local</Property>
    <Property name="consoleLayout">[%d{yyyy-MM-dd HH:mm:ss}] [%-5p] [%c{1}:%L] - %m%n</Property>
    <Property name="layoutPattern">%style{%d{yyyy/MM/dd HH:mm:ss,SSS}}{cyan} %highlight{[%-5p]}{FATAL=bg_red, ERROR=red, INFO=green, DEBUG=blue}  [%C] %style{[%t]}{yellow}- %m%n</Property>
    <Property name="fileLayout">%d [%t] %-5level %c(%M:%L) - %m%n</Property>
</Properties>



Appenders

로그 어디에 어떻게 기록할지 설정해주는 곳입니다.

console : console에 어떻게 로그를 출력할지 설정합니다.

RollingFile : 로그 파일에 어떻게 로그를 출력할지 설정합니다.

로그파일을 한 파일에 계속 저장하면 파일이 너무 커지거나 파일이 날아가면 모든 로그가 날아갑니다. 그래서

TimeBasedTriggeringPolicy : (시간기반 로그파일생성정책 트리거) <FilePattern/> 에 설정된 날짜 및 시간 패턴을 기반으로 로그 파일을 롤오버합니다.

날짜/시간패턴 기술 Intervale 속성 예
% d {yyyy-MM-dd-hh-mm} .log.zip 매분마다 로그 파일 롤링 interval = 2이면 2 분마다 롤오버가 발생합니다.예 : 2017-07-26-09-57.log.zip , 2017-07-26-09-59.log.zip , 2017-07-26-10-01.log.zip , 2017-07-26- 10-03.log.zip 등 ..
% d {yyyy-MM-dd-hh} .log.zip 로그 파일을 매 시간 롤업 interval = 4이면 4 시간마다 롤오버가 발생합니다.예 : 2017-07-26-09.log.zip , 2017-07-26-10.log.zip , 2017-07-26-11.log.zip 등
% d {yyyy-MM-dd} .log.zip 매일 로그 파일 롤링 interval = 1이면 롤오버가 매일 발생합니다.예 : 2017-07-26.log.zip , 2017-07-27.log.zip 등
<!-- Log Appender 설정 -->
<Appenders>
    <Console name="console" target="SYSTEM_OUT">
        <PatternLayout pattern="${layoutPattern}" disableAnsi = "false"/>
    </Console>
    <!--ConsoleAppender, RollingFileAppneder -->
    <RollingFile name="file"
                 fileName="logs/${logFileName}.log"
                 filePattern="logs/${logFileName}.%d{yyyy-MM-dd-hh}.log">
        <PatternLayout pattern="${fileLayout}" />
        <Policies>
            <TimeBasedTriggeringPolicy
                    modulate="true"
                    interval="1" /><!-- 시간별 로그 파일 생성-->
        </Policies>
        <DefaultRolloverStrategy max="5" fileIndex="min" > <!-- 롤링 파일 5개 까지 생성 -->
            <Delete basePath="/logs" maxDepth="3">
                <IfLastModified age="3d" />
            </Delete>
        </DefaultRolloverStrategy>
    </RollingFile>

    <RollingFile name="sql_log"
                 fileName="logs/sql.log"
                 filePattern="logs/sql.%d{yyyy-MM-dd-hh}.log">
        <PatternLayout pattern="${fileLayout}" />
        <Policies>
            <TimeBasedTriggeringPolicy
                    modulate="true"
                    interval="1" /><!-- 시간별 로그 파일 생성-->
        </Policies>
        <DefaultRolloverStrategy max="5" fileIndex="min" > <!-- 롤링 파일 5개 까지 생성 -->
            <Delete basePath="/logs" maxDepth="3">
                <IfLastModified age="3d" />
            </Delete>
        </DefaultRolloverStrategy>
    </RollingFile>

    <RollingFile name="sql_basicBinder_log"
                 fileName="logs/sql_basicBinder.log"
                 filePattern="logs/sql_basicBinder.%d{yyyy-MM-dd-hh}.log">
        <PatternLayout pattern="${fileLayout}" />
        <Policies>
            <TimeBasedTriggeringPolicy
                    modulate="true"
                    interval="1" /><!-- 시간별 로그 파일 생성-->
        </Policies>
        <DefaultRolloverStrategy max="5" fileIndex="min" > <!-- 롤링 파일 5개 까지 생성 -->
            <Delete basePath="/logs" maxDepth="3">
                <IfLastModified age="3d" />
            </Delete>
        </DefaultRolloverStrategy>
    </RollingFile>

</Appenders>



Loggers

로그가 찍힐 대상을 설정하는 곳입니다.

  • level : 로그레벨 설정
  • additivity : 중복로그를 중복해서 표시해줄지 설정
  • AppenderRef : appender를 설정
<!--TRACE > DEBUG > INFO > WARN > ERROR > FATAL -->
<!--Log가 찍힐 대상 설정.-->
<Loggers>
    <!-- 스프링 프레임워크에서 찍는건 level을 info로 설정 -->
    <logger name="org.springframework" level="info" additivity="false" >
        <AppenderRef ref="console" />
    </logger>

    <!-- sql 파라미터 표시 설정 -->
    <logger name="org.hibernate.SQL" level="debug" additivity="false">
        <AppenderRef ref="console" />
    </logger>
    <logger name="org.hibernate.type.descriptor.sql.BasicBinder" level="trace" additivity="false">
        <AppenderRef ref="console" />
    </logger>

    <!-- ROOT logger-->
    <Root level="info"></Root>
</Loggers>



로그 보기


스크린샷 2022-07-30 15 42 06

개발서버에서 저희 로그파일은 3가지 종류입니다.

  • local : 스프링에서 띄우는 로그 저장
  • sql : 쿼리문 저장
  • sql_basicBinder : 쿼리문에 바인딩된 쿼리파라미터 저장

항상 최신버전은 아무 날짜도 적히지 않은 파일에 저장됩니다.

해당 파일이 특정한 시간이나 용량이 되면 로그파일 이름에 날짜가 붙으며 로그파일이 저장됩니다.

그래서 서버에 어떤 오류가 발생했는지 확인하려면 local.log, sql.log, sql_basicBinder.log 처럼 날짜 정보가 붙지 않은 파일을 보면 알 수 있습니다.

현재 개발서버의 시간 기준이 UTC이기때문에 로그파일을 보기가 힘들어서 KST(한국표준시간)으로 변경하였습니다. (2022/07/30)

스크린샷 2022-07-30 15 42 26