Spring logback config

Trong spring boot thấy các tiền bối bảo rằng có nhiều cách cấu hình logging. Với mình thì mình thường làm là config trong file aplication.properties hay application.yml hoặc file logback.xml.
Nay mình chỉ tản mạn nói về cách dùng file logback.xml thôi. 😃)
Chúng ta cùng bắt đầu với một cấu hình Logback đơn giản tên là logback.xml được đặt trong resources folder như sau

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

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

  <root level="info">
    <appender-ref ref="STDOUT"/>
  </root>
 
</configuration>

Nó sẽ tạo ra một appender của class ConsoleAppender, config này sẽ ghi message ra màn hình console dạng System.out.print. Cùng với đó là một pattern được setup cho trình ghi console tuân thủ các ký hiệu:

  • %d : thời gian ghi message, có thể chấp nhận tất các các định dạng SimperDateFormat cho phép
  • %thread : tên thread ghi message
  • $-5level : level ghi log (các mức level có thể là trace, debug, info, warn, error)
  • %logger{36} : tên package class nơi log được ghi ra. Số 36 có ý nghĩa là lược ngắn tên package class trong trường hợp tên quá dài.
  • %M : tên của method nơi log được ghi ra
  • %msg: message chính
  • %n : ngắt dòng
  • %magenta() : đặt màu của message đầu ra trong dấu (), có thể chọn các màu khác
  • highlight() : đặt màu của message đầu ra trong dấu (), tùy thuộc vào level log (ví dụ ERROR là màu đỏ)

Một appender được tạo ra, sau đó được tham chiếu trong root logger. Trong ví dụ trên, level log được đặt là INFO, có nghĩa là nó chỉ xuất thông báo ở level INFO trở lên (INFO, WARN, ERROR), mức level log TRACE và DEBUG không được ghi ra. Cấp độ log level là TRACE -> DUBUG -> INFO -> WARN -> ERROR. Ví dụ

@Service
public class MyServiceImpl implements MyService {

  private static final Logger LOGGER = LoggerFactory.getLogger(MyServiceImpl.class);

  @Override
  public void doStuff(final String value) {
    LOGGER.trace("doStuff needed more information - {}", value);
    LOGGER.debug("doStuff needed to debug - {}", value);
    LOGGER.info("doStuff took input - {}", value);
    LOGGER.warn("doStuff needed to warn - {}", value);
    LOGGER.error("doStuff encountered an error with value - {}", value);
  }
}

với level rool là INFO log sẽ là

10-07-2019 13:32:18.549 [main] INFO  com.lankydan.service.MyServiceImpl.doStuff - doStuff took input - value
10-07-2019 13:32:18.549 [main] WARN  com.lankydan.service.MyServiceImpl.doStuff - doStuff needed to warn - value
10-07-2019 13:32:18.549 [main] ERROR com.lankydan.service.MyServiceImpl.doStuff - doStuff encountered an error with value - value

Nếu không muốn config bằng file logback.xml thì ta cũng có thể giữ config như trên trong file properties.application như sau

logging.level.root=info
logging.pattern.console=%d{dd-MM-yyyy HH:mm:ss.SSS} %magenta([%thread]) %highlight(%-5level) %logger.%M - %msg%n

Khi sử dụng file logback.xml thì cấu hình mặc định Logback của spring boot sẽ bị override, spring boot sẽ sử dụng cấu hình trong file logback.xml. Nếu ta muốn bao gồm cấu hình mặc định của spring boot thì ta cần thêm config dưới đây bên trong thẻ <configuration>

<include resource="org/springframework/boot/logging/logback/base.xml"/>    

Nếu muốn ghi log trong từng class ở level khác với root thì ta có thể xác định config ghi log cho từng class như sau

<logger name="com.lankydan.service.MyServiceImpl" level="debug">
  <appender-ref ref="STDOUT" />
</logger>    

Thử run lại và check console

10-07-2019 17:02:10.248 [main] DEBUG com.lankydan.service.MyServiceImpl.doStuff - doStuff needed to debug - value
10-07-2019 17:02:10.248 [main] DEBUG com.lankydan.service.MyServiceImpl.doStuff - doStuff needed to debug - value
10-07-2019 17:02:10.248 [main] INFO  com.lankydan.service.MyServiceImpl.doStuff - doStuff took input - value
10-07-2019 17:02:10.248 [main] INFO  com.lankydan.service.MyServiceImpl.doStuff - doStuff took input - value
10-07-2019 17:02:10.248 [main] WARN  com.lankydan.service.MyServiceImpl.doStuff - doStuff needed to warn - value
10-07-2019 17:02:10.248 [main] WARN  com.lankydan.service.MyServiceImpl.doStuff - doStuff needed to warn - value
10-07-2019 17:02:10.248 [main] ERROR com.lankydan.service.MyServiceImpl.doStuff - doStuff encountered an error with value - value
10-07-2019 17:02:10.248 [main] ERROR com.lankydan.service.MyServiceImpl.doStuff - doStuff encountered an error with value - value 

Như ta thấy thì mỗi message được ghi ra 2 lần, rõ ràng đây ko phải điều ta muốn. Để xử lý vấn đề này ta cần sử dụng thêm thông tin additivity="false vào cấu hình

<logger name="com.lankydan.service.MyServiceImpl" additivity="false" level="debug">
  <appender-ref ref="STDOUT" />
</logger>

Thử run lại lần nữa và check console sau khi thêm config additivity="false"

10-07-2019 17:40:47.818 [main] DEBUG com.lankydan.service.MyServiceImpl.doStuff - doStuff needed to debug - value
10-07-2019 17:40:47.834 [main] INFO  com.lankydan.service.MyServiceImpl.doStuff - doStuff took input - value
10-07-2019 17:40:47.834 [main] WARN  com.lankydan.service.MyServiceImpl.doStuff - doStuff needed to warn - value
10-07-2019 17:40:47.834 [main] ERROR com.lankydan.service.MyServiceImpl.doStuff - doStuff encountered an error with value - value

Thậm chí ngay cả khi setting root level là ERROR, bởi setting class level là DEBUG nên nó vẫn override setting ở root level và ghi ra log từ level DEBUG trở lên như bên trên.
Class level logging cũng có thể được viết trong file application.properties như sau:

logging.level.com.lankydan.service.MyServiceImpl=debug    

Package level logging cũng có thể được định nghĩa bằng cách sử dụng package name thay vì class name. Ví dụ

<logger name="com.lankydan.service" additivity="false" level="debug">
  <appender-ref ref="STDOUT" />
</logger>    

Config package level logging trong file application.properties như sau

logging.level.com.lankydan.service=debug    

Chúng ta cũng có thể tạo các thuộc tính trong file logback, nó như một biến và được sử dụng lại ở nhiều nơi chẳng hạn, ví dụ như tạo một biến đánh dấu một thư mục là đầu ra để ghi log vào đó

<property name="LOG_PATH" value="logs"/>    

LOG_PATH là một thuộc tính quan trọng đối với việc ghi log trong Spring boot. Giá trị của LOG_PATH sau đó có thể được truy cập sau đó bằng cách dùng ${LOG_PATH}. Config này có thể đạt được thông qua file application.properties như LOG_PATH

logging.path=logs

Để ghi log vào file, ta cần config FileAppender . Với việc sử dụng FileAppender, tất cả log sẽ được ghi vào một file, điều này có thể dẫn đến file sẽ rất lớn qua thời gian. Một cách khác là ta sử dụng RollingFileAppender

<appender name="SAVE-TO-FILE" class="ch.qos.logback.core.FileAppender">
  
  <file>${LOG_PATH}/log.log</file>

  <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
    <Pattern>
      %d{dd-MM-yyyy HH:mm:ss.SSS} [%thread] %-5level %logger{36}.%M - %msg%n
    </Pattern>
  </encoder>

</appender>    

Config này cũng tương tự việc config với ConsoleAppender ngoài việc loại bỏ mã màu ở pattern ghi log. Appender này được refer cũng tương tự như appender STDOUT

<logger name="com.lankydan.service.MyServiceImpl" additivity="false" level="debug">
  <appender-ref ref="SAVE-TO-FILE"/>
</logger>    

Config RollingFileAppender sẽ ghi log vào các file khác nhau tùy vào cấu hình, có thể là là tách ghi file log theo ngày, hoặc theo tháng (miễn là định dạng trong %d phù hợp với SimpleDateFormat cho phép, định dạng format trong cặp thẻ %d cũng sẽ quy định thời gian rolling, ví dụ "dd-MM-yyyy" sẽ rolling theo ngày hoặc "MM-yyyy" sẽ rolling theo tháng) hoặc khi kích thước file đạt tới giới hạn nào đó, hoặc kết hợp cả hai.
TimeBasedRollingPolicy dưới đây sẽ tạo một file log mới theo ngày. Tên file log sẽ kèm suffix là ngày ghi log.

<appender name="SAVE-TO-FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
  
  <file>${LOG_PATH}/log.log</file>
  
  <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
    <Pattern>
      %d{dd-MM-yyyy HH:mm:ss.SSS} [%thread] %-5level %logger{36}.%M - %msg%n
    </Pattern>
  </encoder>

  <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
    <fileNamePattern>
      ${LOG_PATH}/archived/log_%d{dd-MM-yyyy}.log
    </fileNamePattern>
    <maxHistory>10</maxHistory>
    <totalSizeCap>100MB</totalSizeCap>
  </rollingPolicy>

</appender>

Ví dụ trên cũng setting thêm các tham số maxHistory là thời gian chỉ định số ngày lưu trữ file trước khi chúng bị tự động xóa tính từ ngày ghi file log đó. totalSizeCap giới hạn kích thước tối đa của tất cả các file log lưu trữ, nó yêu cầu thuộc tính maxHistory đi kèm.

FixedWindowRollingPolicySizeAndTimeBasedRollingPolicy , mình có đọc qua nó nhưng thấy khá loằng ngoằng và theo ý hiểu của mình cũng ko hay được sử dụng như các kiểu config khác. Mọi người có thể đọc thêm tại đây

Bây giờ chúng ta cùng xem xét cách cấu hình nhiều appender trong một logger, vừa ghi log ra console vừa ghi log ra file.

<logger name="com.lankydan.service.MyServiceImpl" additivity="false" level="debug">
  <appender-ref ref="STDOUT"/>
  <appender-ref ref="SAVE-TO-FILE"/>
</logger>    

Một tính năng hữu ích nữa mà Spring Boot cung cấp khi sử dụng Logback là khả năng phân tách cấu hình giữa các môi trường. Vì vậy, nếu bạn muốn lưu vào file và in ra console trong môi trường develop của mình nhưng chỉ ghi ra file trong môi trường production thì điều này có thể đạt được một cách dễ dàng
<?xml version="1.0" encoding="UTF-8"?>
<configuration>

  <!-- config for STDOUT and SAVE-TO-FILE -->

  <springProfile name="dev">
    <root level="info">
      <appender-ref ref="STDOUT"/>
      <appender-ref ref="SAVE-TO-FILE"/>
    </root>
    <logger name="com.lankydan.service.MyServiceImpl" additivity="false" level="debug">
      <appender-ref ref="STDOUT"/>
      <appender-ref ref="SAVE-TO-FILE"/>
    </logger>
  </springProfile>

  <springProfile name="prod">
    <root level="info">
      <appender-ref ref="SAVE-TO-FILE"/>
    </root>
    <logger name="com.lankydan.service.MyServiceImpl" additivity="false" level="error">
      <appender-ref ref="SAVE-TO-FILE"/>
    </logger>
  </springProfile>

</configuration>    

Bước đầu tiên để làm việc này là đổi tên tệp logback.xml thành logback-spring.xml cho phép thẻ springProfile được sử dụng. Khi run project, để apply profile có 2 cách hoặc là đặt trong file application.properties hoặc khi run thì truyền thêm biến môi trường.
Đối với file application.properties ta config như sau:

spring.profiles.active=dev    

hoặc với VM option là

-Dspring.profiles.active=dev

Tương tự với production cũng nv.

Ta cũng có thể config trong 2 file tên là application-dev.propertiesapplication-prod.properties đó là các tập tin riêng cho từng môi trường. Theo quy ước đặt tên application-{environment}.properties với {environment} được thay thế bằng tên môi trường. Tùy thuộc vào các tùy chọn VM hoặc các biến môi trường của bạn, một trong số các biến này có thể được chọn giống như khi được thực hiện springProfiletrong logback-spring.xml. Dưới đây là các cấu hình tương đương cho đoạn mã trên.

application-dev.properties

logging.level.root=info
logging.level.com.lankydan.service=debug
logging.path=logs
logging.file=${logging.path}/log.log
logging.pattern.file=%d{dd-MM-yyyy HH:mm:ss.SSS} [%thread] %-5level %logger{36}.%M - %msg%n
logging.pattern.console=%d{dd-MM-yyyy HH:mm:ss.SSS} %magenta([%thread]) %highlight(%-5level) %logger.%M - %msg%n

application-prod.properties

logging.level.root=info
logging.level.com.lankydan.service=error
logging.path=logs
logging.file=${logging.path}/log.log
logging.pattern.file=%d{dd-MM-yyyy HH:mm:ss.SSS} [%thread] %-5level %logger{36}.%M - %msg%n
logging.pattern.console=    

Vừa rồi mình vừa hướng dẫn qua một số cách cấu hình Spring Logback, đây là những cấu hình đơn giản nhưng khá hay được sử dụng trong các dự án. Hi vọng bài viết này sẽ hữu ích với mọi người 😉