개발을 할때 로깅은 개발자에게 여러 정보를 전달해주는 역할을 합니다. 개발자가 필요한 정보를 직접 로깅할 수도 있고 어플리케이션이 예상하지 않은 동작을 했을때 error 정보를 전달해주기도 합니다.
이렇게 중요한 log를 Java를 처음 배울때 사용하였던 System.out.println()
을 사용하면 될까요??
System.out.println("Invalid parameter");
로그는 시스템의 상태를 알려주는 정보이기 때문에 방대한 양을 담고 있습니다. 그런데 이런 로그를 System.out.println()
으로 찍게 되면 상세한 로그를 못 찍을 뿐만 아니라 방대한 정보를 효율적으로 관리할 수 없습니다. 그렇기 때문에 Spring에서는 SLF4J를 통해 logback 이나 log4j 와 같은 로깅 프레임워크를 사용합니다. System.out.println()
는 절대! 사용하면 안됩니다.
Springboot에서 spring-boot-starter-web 의존성을 받았다면 대표적으로 사용되는 logback, log4j 가 이미 dependency 되어 있습니다. 그렇기 때문에 아래와 같이 사용할 수 있습니다.
public class LogSample{
private static final Logger log = LoggerFactory.getLogger(LogSample.class);
public void testLog() {
log.info("log test");
}
}
private static final Logger log = LoggerFactory.getLogger(LogSample.class);
처럼 로깅할 해당 클래스 정보를 제공해서 사용할 수도 있지만 lombok을 gradle에 추가하셨다면 @Slf4j
어노테이션으로 더 간단하게 사용할 수도 있습니다.
@Slf4j
public class LogSample{
public void testLog() {
log.info("log test");
}
}
log를 찍을 때 주의 사항으로 +
을 사용하면 안되고 {}
으로 원하는 정보를 치환해서 찍어야 합니다.
'+'을 사용하게 되면 String 객체 문자열 덧셈 연산을 하기 때문에 성능에 악 영향을 미칩니다. 특히 로그는 방대한 정보를 만들기 때문에 더욱 사용하면 안됩니다.
@Slf4j
public class LogSample{
private int num = 5;
public void testLog() {
// 잘못된 사용 방법
//log.info("num check: " + num);
// 올바른 사용 방법
log.info("num check: {}", num);
log.error("error message : {}", e.getMessage());
}
}
SLF4J(Simple Logging Facade for Java)라는 이름에서 알 수 있듯이 파사드 패턴이 적용되어 logback, log4j와 같은 로깅에 대한 추상 레이어를 제공하는 추상화 로깅 라이브러리이다. 라이브버리이기 때문에 개발자가 로깅 프레임 워크를 지정해줘야 합니다.
그러면 굳이 SLF4J라는 추상 라이브러리를 사용하는 이유는 무엇일까?
만약 SLF4J없이 log4j를 사용하다가 치명적인 보안이슈가 발견되어 걷어내고 logback 으로 변경해야하는 경우가 생기면 log4j를 사용한 전체 코드를 수정해야할 것입니다. 하지만 추상 인터페이스를 사용함으로써 전체 코드를 수정하지 않고 로깅 프레임워크만 변경해주면 됩니다. 한마디로 객체지향 OCP원리를 적용한 방법이죠.
Slf4j 추상 인터페이스에 사용할 수 있는 구현체로 크게 log4j, logback, log4j2 3가지가 있습니다.
등장 순서도 log4j, logback, log4j2 입니다. log4j의 경우 개발이 중단되었기에 사용하지 않는다고 보시면 됩니다.
log4j2의 경우 가장 최신 로깅 프레임워크이며 가장 많은 기능을 제공하지만 본 글에서는 간단히 Logback
을 통해 log 설정을 해볼까 합니다.
Logback에서는 로그를 효율적으로 관리하기 위해 Log Level을 지정할 수 있습니다.
로그 레벨에는 7개가 존재합니다.
위로 갈수록 로그 level이 높다고 할 수 있으며 심각도가 큰, 중요한 정보를 나타냅니다. 특히 ERROR
의 경우 시스템이 정상적인 기능을 못했을 때 찍히는 로그입니다. FATAL의 경우 Error 보다 더 심각한 에러를 나타냅니다.
이 중에서 All 과 Trace는 거의 사용하지 않으며, Debug
는 운영 환경보다는 개발 환경에서 중요하지 않은 개발자가 확인용 정보로 사용합니다. 운영계에서 Debug 로깅을 할 경우 너무 많은 양의 로그가 찍히며 중요한 정보를 선별할 수 없고 너무 많은 용량의 로그 파일이 생성될 수 있기 때문입니다.
이제 Springboot에서 logback을 설정을 직접 해보겠습니다.
springboot 프로젝트 생성 뒤 resources 폴더 및에 logback-spring.xml 파일을 만들어 줍니다.
Springboot에서 application.properties(yml)에서 간단하게 logging 설정을 할 수 있지만 상세한 설정을 위해서는 logback-spring.xml 을 사용해야합니다.
# application.yml 에서 로깅 설정
logging:
level:
com.example.todolist: debug
org.hibernate.SQL: debug
org.hibernate.type: trace
logback-spring.xml은 크게 appender와 logger, root로 구성됩니다.
logger : <logger> 테그로 로그의 name 속성을 통해 class 별로 지역설정을 할 수 있으며 additivity 속성을 통해 log level을 상속 유무 설정이 가능합니다.
root : <root> 테그로 구성되며 logger 중에 전역 logger를 root로 따로 분리했다고 보시면 됩니다. 전역 설정이기때문에 name 속성이 없으며 level 속성을 통해 log level만 지정해주면 됩니다.
appender : <appender> 테그로 구성되며 log 메시지가 출력될 대상을 결정
가장 많이 사용되는 appender 속성은 ConsoleAppender
와 RollingFileAppender
입니다. 본 글에서도 두 appeder를 만들어 보도록 하겠습니다.
먼저 ConsoleAppender 를 전체 설정을 보도록 하겠습니다.
<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
<property name="CONSOLE_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} %magenta([%thread]) %highlight([%-3level]) %logger{5} - %msg %n" />
<!-- Console appender 설정 -->
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<Pattern>${CONSOLE_PATTERN}</Pattern>
</encoder>
</appender>
<logger name="jdbc" level="OFF" additive="false">
<appender-ref ref="STDOUT"/>
</logger>
<logger name="jdbc.sqlonly" level="DEBUG" additive="false" >
<appender-ref ref="STDOUT"/>
</logger>
<logger name="jdbc.sqltiming" level="OFF" additive="false" >
<appender-ref ref="STDOUT"/>
</logger>
<logger name="org.hibernate.SQL" level="DEBUG" additive="false">
<appender-ref ref="STDOUT"/>
</logger>
<logger name="com.example.todolist.controller" level="DEBUG" additive="false" >
<appender-ref ref="STDOUT"/>
</logger>
<logger name="com.example.todolist.service" level="DEBUG" additive="false" >
<appender-ref ref="STDOUT"/>
</logger>
<logger name="com.example.todolist.domain" level="DEBUG" additive="false" >
<appender-ref ref="STDOUT"/>
</logger>
<root level="INFO">
<appender-ref ref="STDOUT"/>
</root>
</configuration>
property 옵션의 경우 설정 파일에서 사용될 상수 변수라고 보시면 됩니다.
ConsoleAppender에서 로그 형식을 지정해준 뒤 콘솔에 찍고 싶은 logger에 appender를 추가해줬습니다. <appender> 하위의 encoder는 Appender에 포함되어 사용자가 지정한 형식으로 표현 될 로그메시지를 변환하는 역할을 담당하는 요소입니다.
pattern layout에 대한 설정은 https://logback.qos.ch/manual/layouts.html 참고 바랍니다.
간단하게 logger의 level
속성 테스트를 진행해보겠습니다.
<logger name="com.example.todolist.controller" level="DEBUG" additive="false" >
<appender-ref ref="STDOUT"/>
</logger>
위 로거는 controller 하위에 있는 파일에 로그 레벨을 DEBUG
로 설정되어 있습니다.
테스트 controller를 만들어 보겠습니다.
@Slf4j
@Controller
public class IndexController {
@GetMapping("/")
public String index(){
log.trace("TRACE!!");
log.debug("DEBUG!!");
log.info("INFO!!");
log.warn("WARN!!");
log.error("ERROR!!");
return "index";
}
}
그리고 해당 url을 호출하면 INFO보다 INFO를 포함한 상위 Log level만 console에 찍히는 것을 알 수 있습니다.
이와같이 log level을 이용하여 Log를 좀 더 효율적으로 관리할 수 있습니다.
이번엔 logger의 additive
속성 테스트를 진행해보겠습니다.
<logger name="com.example.todolist.controller" level="DEBUG" additive="true" >
<appender-ref ref="STDOUT"/>
</logger>
이제 다시 결과를 확인해보면 INFO 로그도 찍히는 것을 확인할 수 있습니다.
additive
란 상위 logger로부터 상속 여부를 의미합니다(기본 값 true). true로 설정되며 상위 logger의 설정 값을 상속 받아 자신의 logger에 설정된 값을 재적용 시키며, false일 경우 상속을 받지 않고 자신의 설정 값을 사용합니다.
여기선 root의 값을 상속받아 INFO level이 적용된 것을 볼 수 있습니다.
이번에도 RollingFileAppender를 위에서 만든 ConsoleAppender 설정에 추가한 전체 설정을 보도록 하겠습니다.
<?xml version="1.0" encoding="UTF-8" ?>
<configuration>
<property name="CONSOLE_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} %magenta([%thread]) %highlight([%-3level]) %logger{5} - %msg %n" />
<property name="ROLLING_PATTERN" value="%d{yyyy-MM-dd HH:mm:ss.SSS} %logger{5} - %msg %n" />
<property name="FILE_NAME" value="D:\\logs\\application.log" />
<property name="LOG_NAME_PATTERN" value="./logs/application-%d{yyyy-MM-dd-HH-mm}.%i.log" />
<property name="MAX_FILE_SIZE" value="10MB" />
<property name="TOTAL_SIZE" value="30MB" />
<property name="MAX_HISTORY" value="2" />
<!-- Console appender 설정 -->
<appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
<encoder>
<Pattern>${CONSOLE_PATTERN}</Pattern>
</encoder>
</appender>
<appender name="ROLLING_LOG_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
<encoder>
<pattern>${ROLLING_PATTERN}</pattern>
</encoder>
<file>${FILE_NAME}</file>
<rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
<fileNamePattern>${LOG_NAME_PATTERN}</fileNamePattern>
<maxHistory>${MAX_HISTORY}</maxHistory>
<maxFileSize>${MAX_FILE_SIZE}</maxFileSize>
<totalSizeCap>${TOTAL_SIZE}</totalSizeCap>
</rollingPolicy>
</appender>
<logger name="jdbc" level="OFF" additive="false">
<appender-ref ref="STDOUT"/>
<appender-ref ref="ROLLING_LOG_FILE"/>
</logger>
<logger name="jdbc.sqlonly" level="DEBUG" additive="false" >
<appender-ref ref="STDOUT"/>
<appender-ref ref="ROLLING_LOG_FILE"/>
</logger>
<logger name="jdbc.sqltiming" level="OFF" additive="false" >
<appender-ref ref="STDOUT"/>
<appender-ref ref="ROLLING_LOG_FILE"/>
</logger>
<logger name="org.hibernate.SQL" level="DEBUG" additive="false">
<appender-ref ref="STDOUT"/>
<appender-ref ref="ROLLING_LOG_FILE"/>
</logger>
<logger name="com.example.todolist.controller" level="INFO" additive="true" >
<appender-ref ref="STDOUT"/>
<appender-ref ref="ROLLING_LOG_FILE"/>
</logger>
<logger name="com.example.todolist.service" level="DEBUG" additive="false" >
<appender-ref ref="STDOUT"/>
<appender-ref ref="ROLLING_LOG_FILE"/>
</logger>
<logger name="com.example.todolist.domain" level="DEBUG" additive="false" >
<appender-ref ref="STDOUT"/>
<appender-ref ref="ROLLING_LOG_FILE"/>
</logger>
<root level="INFO">
<appender-ref ref="STDOUT"/>
<appender-ref ref="ROLLING_LOG_FILE"/>
</root>
</configuration>
RollingFileAppender는 FileAppender를 상속하여 로그 파일을 rollover 합니다. 여기서 rollover는 타깃 파일을 바꾸는 것으로 이해할 수 있습니다.
RollingFileAppender의 요소로 file과 rollingPolicy가 보입니다. 먼저 File 요소를 통해 log파일의 이름을 설정할 있습니다. 그리고 rollingPolicy를 설정해 rollover를 어떻게 실행할지를 정의합니다.
rollingPolicy에도 여러 종류가 있다. 몇가지만 살펴보면
이 중에서도 우린 가장 많이 사용하는 TimeBasedRollingPolicy를 상속받아 만들어진 SizeAndTimeBasedRollingPolicy을 사용하였습니다.
rollingPolicy 하위 요소를 살펴보면
fileNamePattern : 아카이브 되는 파일의 패턴을 지정할 수 있다.
maxHistory : 보관할 최대 파일 수를 제어하여 이전 파일을 삭제한다.
maxFileSize : 분할할 용량 사이즈를 의미한다.
totalSizeCap : 전체 파일 크기를 제어하며, 전체 크기 제한을 초과하면 가장 오래된 파일을 삭제한다.
totalSizeCap을 사용하기 위해서는 maxHistory 속성이 필수이며, maxHistory와 totalSizeCap의 우선순위는 maxHistory가 더 높다.
이제 테스트를 위해 어플리케이션을 간단히 조작한 뒤 지정한 경로를 확인해보면 log 파일이 생성된 것을 확인할 수 있습니다.
아카이브 되는 파일의 시간 기준은 fileNamePattern에 설정한 로그 시간 기준입니다. fileNamePattern에서 분으로 해놓았기 때문에 16분에 다시 확인해보면 아카이브 파일도 확인할 수 있습니다.
17분에 다시 확인하면 아카이브 파일이 하나 더 생성된 것을 확인할 수 있습니다.
18분에 다시 확인하면 아카이브 파일이 2개에서 늘어나진 않고 16분 17분에 만든 파일만 남아 있는 것을 볼 수 있습니다. 이는 maxHistory를 2로 설정해두었기 때문입니다.