안녕하세요
오늘은 logback을 통해 로그를 관리하는 방법을 알아보겠습니다.
목차
- 로그 색상 바꾸기
- 프로필에 따라 로그 레벨 다르게 설정하기
- 로그 파일을 분할해서 저장하기
- JPA SQL을 로그 파일에 남기기
로그 출력 테스트를 하기 위해서 일단 테스트 컨트롤러를 하나 만들어볼까요?
일단 build.gradle에 아래 3개의 의존성을 추가하고
// @RestController에 필요
implementation 'org.springframework.boot:spring-boot-starter-web'
// @Slf4j에 필요
compileOnly 'org.projectlombok:lombok'
annotationProcessor 'org.projectlombok:lombok'
테스트 컨트롤러를 만들고 다음과 같이 다섯가지 레벨의 로그를 찍어봅시다.
package com.feelcoding.logbackdemo.controller;
import lombok.extern.slf4j.Slf4j;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RestController;
@RestController
@Slf4j
public class TestController {
@GetMapping("/test")
public void test() {
log.trace("TRACE!!");
log.debug("DEBUG!!");
log.info("INFO!!");
log.warn("WARN!!");
log.error("ERROR!!");
}
}
이 상태에서 실행을 하면 아래와 같이 로그가 찍히는 것을 볼 수 있습니다.
콘솔창을 clear한 후 아까 만들고 로그를 찍어 둔 API를 호출해보면
분명 로그를 5개 찍었는데 trace, debug레벨의 로그는 보이지 않고 info, warn, error레벨의 로그만 출력되는 것을 확인할 수 있습니다.
왜 그런 걸까요?
그 이유는 뒤에서 알아보도록 하고, 일단 제가 개발하면서 디버깅용으로 찍은 debug 레벨의 로그를 콘솔에서 보고 싶기 때문에 로그 레벨을 debug로 바꿔보겠습니다.
resources 폴더에 logback-spring.xml 파일을 만들고 아래와 같이 설정해줍니다.
<?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 - %msg%n</pattern>
</encoder>
</appender>
<root level="DEBUG">
<appender-ref ref="CONSOLE" />
</root>
</configuration>"CONSOLE"이라는 이름의 ConsoleAppender를 하나 만들고 기본 세팅(root)을 DEBUG 레벨로 지정하고 해당 appender를 사용한 것입니다.
Appender에는 ConsoleAppender, FileAppender, RollingFileAppender, SMTPAppender, DBAppender 등이 있습니다.
지금 저희가 쓸 ConsoleAppender는 로그를 콘솔에 출력하겠다는 것입니다.
이렇게 logback 설정을 해주고 난 뒤 다시 실행을 시켜보면 아까와 달리 debug 레벨의 로그들이 찍히는 것을 볼 수 있습니다.
API를 호출해봐도
이렇게 debug 레벨의 로그가 잘 출력됩니다.
그런데 불편한 점이 몇 가지 있습니다.
1. 내 프로젝트의 debug 레벨 로그만 보이는 것이 아니라 다른 프레임워크나 라이브러리에서 찍은 debug 레벨의 로그까지 다 보여서 내 로그를 보기가 힘듭니다.
2. 로그에 색깔이 없어서 보기가 힘들고 안 예쁩니다.
이제 이 불편한 점들을 하나씩 해결해볼까요?
우선 1번부터 해결해보겠습니다.
다른 라이브러리의 로그는 info 레벨로 보고 싶고 내 프로젝트의 로그만 debug 레벨로 조정하고 싶다면
위와 같이 <root> 태그의 level 속성을 "DEBUG"에서 "INFO"로 바꿔서 기본 로그 레벨을 info레벨로 변경해주고
아래 코드를 추가해줍니다. ("내 프로젝트 패키지명" 부분은 본인 프로젝트의 패키지명을 적어주시면 됩니다.)
<logger name="내 프로젝트 패키지명" level="DEBUG" />기본 로그 레벨은 info 레벨로 설정하지만 내 프로젝트 패키지에 해당하는 로그만 debug 레벨로 조정하겠다는 것입니다.
이렇게 하면 다른 라이브러리의 DEBUG 레벨 로그는 출력되지 않고 내 프로젝트의 debug 레벨 로그만 출력됩니다.
정말 그런지 확인해볼까요?
아까와 달리 스프링 프레임워크의 DEBUG 레벨의 로그는 보이지 않는 것을 확인할 수 있고
아까와 달리 org.springframework의 debug 레벨 로그는 출력되지 않고 제 프로젝트 패키지인 com.feelcoding.logbackdemo 패키지에 있는 로거에서만 debug 레벨의 로그가 출력되는 것을 볼 수 있습니다.
그럼 1번 문제점은 해결했고 2번 문제점을 해결해볼까요?
공식 문서에 따르면
%black", "%red", "%green", "%yellow", "%blue", "%magenta", "%cyan", "%white", "%gray", "%boldRed", "%boldGreen", "%boldYellow", "%boldBlue", "%boldMagenta", "%boldCyan", "%boldWhite" and "%highlight"
이렇게 17개의 색상을 지원한다고 합니다.
그럼 색깔을 바꿔볼까요?
예시로 보여주기 위해 최대한 다양한 색깔을 사용해 보았습니다. 날짜는 초록색, 스레드명은 보라색, 로거는 청록색, 로그 메시지에는 노란색, 로그 레벨은 로그 레벨에 따라 다른 색상을 출력해주는 highlight를 적용했습니다.
%green(%d{yyyy-MM-dd HH:mm:ss.SSS}) %magenta([%thread]) %highlight(%5level) %cyan(%logger) - %yellow(%msg%n)%색상명() 이렇게 감싸주면 됩니다.
아까와 달리 로그가 알록달록해졌습니다.
그런데 INFO, WARN, ERROR 등 로그 레벨을 나타내는 글자 색은 아까 아무런 설정을 해주지 않았을 때의 색이 더 예쁜 것 같은데... 바꿀 수 없을까요?
그럼 기본 설정이 어떻게 되어 있는지, 기본 설정이 되어 있는 곳을 찾아가봅시다.
Windows 사용자는 ctrl + n, Mac OS 사용자는 cmd + o를 누르고 우측 상단에 범위를 Files 탭에서 base.xml을 검색해봅시다. (base.xml이라고 입력하면 자동으로 범위가 All Places로 바뀔 것인데, 만약 나오지 않는다면 우측 상단의 범위를 All Places로 수정해보세요.)
해당 파일에 들어가보면
defaults.xml 파일을 include 했다는 것을 알 수 있습니다.
그러면 다시 검색을 해서 defaults.xml 파일에 가봅시다.
defaults.xml을 보면
여기에 clr이라는 이름으로 conversionRule이 선언되어 있고
로그 레벨을 지정하는 부분을 clr이라는 색으로 지정한 것을 볼 수 있습니다.
저는 로그 레벨을 해당 색으로 변경하고 logger만 cyan 색으로 하고 나머지는 그냥 기본 색으로 바꾸겠습니다.
<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
<conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter" />
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %clr(%5level) %cyan(%logger) - %msg%n</pattern>
</encoder>
</appender>
<logger name="com.feelcoding.logbackdemo" level="DEBUG" />
<root level="INFO">
<appender-ref ref="CONSOLE" />
</root>
</configuration>
로그 파일에 로그 기록하기
로그를 콘솔에만 출력하면 로그가 많이 찍혔을 때는 위쪽 로그가 보이지 않게 되기도 하고, 기록이 남지 않아 나중에 확인하기가 어려운 등 불편한 점이 많습니다.
그러면 이제 로그 파일에 저장을 해봅시다.
logback-spring.xml 파일에 FileAppender를 하나 추가해봅시다.
<appender name="FILE" class="ch.qos.logback.core.FileAppender">
<file>./log/testFile.log</file>
<encoder>
<pattern>%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %5level %logger - %msg%n</pattern>
</encoder>
</appender>"FILE"이라는 이름으로 FileAppender를 하나 만들고
<root level="INFO">
<appender-ref ref="CONSOLE" />
<appender-ref ref="FILE" />
</root>해당 appender를 root 레벨에 추가해줍니다.
프로젝트 디렉토리 아래 log라는 디렉토리 하위에 testFile.log라는 파일에 로그를 출력하겠다는 것입니다.
그리고 로그 출력 패턴은 아래와 같이 콘솔 appender와 동일하게 해주겠습니다.
%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %clr(%5level) %cyan(%logger) - %msg%n그런데 이렇게 동일한 문자열이 두 곳에서나 쓰였습니다. 해당 패턴을 복사해서 여러 곳에서 쓰기 보다는 해당 문자열을 변수로 뽑아볼까요?
<property name="LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %clr(%5level) %cyan(%logger) - %msg%n" />이렇게 LOG_PATTERN이라는 이름으로 변수를 뽑았습니다.
사용할 때는
${LOG_PATTERN}이렇게 사용하면 됩니다.
그리고 실행을 해보면
아까 지정해준 log 폴더의 testFile.log 파일에 가보면 이렇게 로그가 파일로 저장되어 있는 것을 볼 수 있습니다.
애플리케이션을 종료했다가 다시 실행하면
이렇게 기존 파일 내용의 마지막 부분에 이어서 써지는 것을 볼 수 있습니다.
여기서 잠깐!! 이렇게 로그를 파일에 저장할 때는 gitignore에 log 파일을 꼭 추가해주세요. 그렇지 않으면 불필요한 로그 파일들이 깃허브에 올라가게 됩니다.
그런데 ESC[32m, ESC[0;39m, ESC[36m과 같은 이상한 문자가 보입니다. 이것은 뭘까요?
https://stackoverflow.com/questions/53298918/strange-symbols-in-log-output
Strange symbols in log-output
I started to see strange output in my log files: 2018-11-14 14:04:21,180 [main] [34mINFO[0;39m com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown initiated... 2018-11-14 14:04:21,186...
stackoverflow.com
색깔을 나타내기 위한 이스케이프 문자라고 합니다.
글자 색이 있는 로그를 파일에 저장을 하면 이렇게 이스케이프 문자가 보여 로그를 읽기가 어려우니, 파일에 저장할 땐 글자 색깔을 없애볼까요?
기존 LOG_PATTERN을 CONSOLE_LOG_PATTERN으로 이름을 바꾸고 FILE_LOG_PATTERN이라는 이름으로 글자 색 없는 로그 패턴 변수를 추가했습니다.
<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
<conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter" />
<property name="CONSOLE_LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %clr(%5level) %cyan(%logger) - %msg%n" />
<property name="FILE_LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %5level %logger - %msg%n" />
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>${CONSOLE_LOG_PATTERN}</pattern>
</encoder>
</appender>
<appender name="FILE" class="ch.qos.logback.core.FileAppender">
<file>./log/testFile.log</file>
<encoder>
<pattern>${FILE_LOG_PATTERN}</pattern>
</encoder>
</appender>
<logger name="com.feelcoding.logbackdemo" level="DEBUG" />
<root level="INFO">
<appender-ref ref="CONSOLE" />
<appender-ref ref="FILE" />
</root>
</configuration>
그러고 나서 다시 실행을 해보면
이렇게 이스케이프 문자 없이 로그가 잘 찍혀있는 것을 볼 수 있습니다.
여러 파일에 나눠서 로그 기록하기
그런데 한 파일에만 계속 쓰다 보면 파일의 크기가 점점 커질 것이고 나중에 검색하기가 힘들어질 것입니다.
이럴 때 쓰는 것이 RollingFileAppender입니다.
RollingFileAppender는 FileAppender와 마찬가지로 파일에 로그를 쓰는 appender인데요,
FileAppender와 다른 점은 로그를 여러 파일에 나눠서 쓴다는 것입니다.
한 번 직접 사용해보면서 알아볼까요?
"FILE" 이라는 이름으로 지정했던 appender의 class를 FileAppender에서 RollingFileAppender로 변경하고
<file> 태그를 지우고 아래와 같이 <rollingPolicy> 태그를 추가해봅시다.
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<encoder>
<pattern>${FILE_LOG_PATTERN}</pattern>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>./log/%d{yyyy-MM-dd}.%i.log</fileNamePattern>
<maxFileSize>100MB</maxFileSize>
<maxHistory>30</maxHistory>
</rollingPolicy>
</appender>
로그를 /log 디렉토리 아래에 날짜.순번.log 라는 이름으로 로그 파일을 저장하고,
파일이 100MB가 넘으면 다음 파일에 저장하고,
로그 파일이 만들어진지 30일이 지나면 해당 파일을 삭제하겠다는 것입니다.
예를 들어 2023-02-13.0.log 파일에 로그가 많이 써져서 100MB가 넘으면 2023-02-13.1.log 파일에 기록을 하고, 그 다음 2023-02-13.2.log, 2023-02-13.3.log, ... 이런 식으로 파일 이름을 짓겠다는 것입니다. 그리고 30일 후인 2023년 3월 15일에 이 파일은 삭제될 것입니다.
한 번 실행해볼까요?
(저는 테스트를 위해 100MB를 10KB로 바꿔서 실행했습니다.)
이렇게 여러 파일에 나눠서 로그가 저장된 것을 볼 수 있습니다.
그럼 정말 10KB씩 나눠졌는지 확인해볼까요?
이렇게 10KB가 넘으면 파일이 나눠진 것을 확인할 수 있습니다.
프로필별 로그 관리하기
로컬 환경에서는 로그 레벨을 debug 레벨로 콘솔에만 출력하고 싶고,
dev와 staging 환경에서는 로그 레벨을 info 레벨로 설정하고 파일에 출력하고 싶고,
운영 환경에서는 로그 레벨을 error 레벨로 설정하고 싶다면 어떻게 해야 할까요?
프로필에 따라 다르게 로그를 관리하는 방법을 알아봅시다.
일단 logback-spring.xml 파일을 이렇게 바꿔줍니다.
<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
<conversionRule conversionWord="clr" converterClass="org.springframework.boot.logging.logback.ColorConverter" />
<property name="CONSOLE_LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %clr(%5level) %cyan(%logger) - %msg%n" />
<property name="FILE_LOG_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %5level %logger - %msg%n" />
<appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<pattern>${CONSOLE_LOG_PATTERN}</pattern>
</encoder>
</appender>
<appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<encoder>
<pattern>${FILE_LOG_PATTERN}</pattern>
</encoder>
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>./log/%d{yyyy-MM-dd}.%i.log</fileNamePattern>
<maxFileSize>100MB</maxFileSize>
<maxHistory>30</maxHistory>
</rollingPolicy>
</appender>
<springProfile name="local">
<logger name="com.feelcoding.logbackdemo" level="DEBUG" />
<root level="INFO">
<appender-ref ref="CONSOLE" />
</root>
</springProfile>
<springProfile name="dev|stg">
<root level="INFO">
<appender-ref ref="CONSOLE" />
<appender-ref ref="FILE" />
</root>
</springProfile>
<springProfile name="prod">
<root level="ERROR">
<appender-ref ref="CONSOLE" />
<appender-ref ref="FILE" />
</root>
</springProfile>
</configuration>딱 보면 감이 오시죠?
프로필이 local일 땐 debug 레벨로 콘솔에 출력하고
프로필이 dev나 stg일 땐 info 레벨로 콘솔과 파일에 출력하고
프로필이 prod일 땐 error 레벨로 콘솔과 파일에 출력하겠다는 것입니다.
로그 패턴 설정하기
맨 처음에 아무런 logback 설정을 하지 않고 실행했을 때 아래와 같이 출력되었는데요, 뭔가 이상한 점 없으신가요?
LogbackDemoApplication의 패키지는 com.feelcoding.logbackdemo인데, c.f.logbackdemo라고 출력된 것을 볼 수 있습니다.
뿐만 아니라, logback 설정을 해주고 난 뒤의 로그와 비교를 해보니
org.springframework.boot.web.embedded.tomcat도 o.s.b.w.embedded.tomcat으로,
org.apache.catalina.core.ContainerBase도 o.a.c.c.C로 나오는 등 패키지명과 클래스명이 생략된 것을 볼 수 있습니다.
왜 이렇게 출력되는 것일까요?
아까 봤던 defaults.xml 파일에 가봅시다.
%-40.40logger{39}라고 되어 있는 것을 볼 수 있습니다.
최대 39자까지 출력하고 39자를 넘으면 축약하겠다는 것입니다.
출처
https://logback.qos.ch/manual/index.html
https://docs.spring.io/spring-boot/docs/current/reference/html/features.html#features.logging